Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

API shows light is on but it is off and should be off #1720

Closed
nickehallgren opened this issue Jul 31, 2019 · 11 comments
Closed

API shows light is on but it is off and should be off #1720

nickehallgren opened this issue Jul 31, 2019 · 11 comments
Labels

Comments

@nickehallgren
Copy link

Hi,

I bought the Conbee 2 and started rebuilding my homeautomation system. I installed the Phoscon App on a Raspberry Pi 3B and setup all my Ikea lights and remotes/motion sensor in the Phoscon App (no groups no nothing in the app). Then I started using node-red to control everything. Everything works perfectly but I think I have found a bug. The motion sensor should turn on the entrance light when somebody enters and that works. But when I started building the UI (using node-red-ui) I noticed that when the motion sensor turns on the wanted light the API show that also another light turns on even if it is not. What could be the problem?

This how it looks before I walk pass the motion sensor

3: {
ctmax: 454,
ctmin: 250,
etag: "0da75875444f6d94fbd57307f1f6c26a",
hascolor: true,
manufacturername: "IKEA of Sweden",
modelid: "TRADFRI bulb E27 WS opal 980lm",
name: "Entrance lamp",
state: {
alert: "none",
bri: 77,
colormode: "xy",
ct: 250,
on: false,
reachable: true
},
swversion: "1.2.217",
type: "Color temperature light",
uniqueid: "00:0b:57:ff:fe:8d:3a:ab-01"
},
4: {
ctmax: 454,
ctmin: 250,
etag: "19abc1d69e30588beed8204d24d3d283",
hascolor: true,
manufacturername: "IKEA of Sweden",
modelid: "TRADFRI bulb E27 CWS opal 600lm",
name: "Bedroom1 Rooflight",
state: {
alert: "none",
bri: 254,
colormode: "xy",
effect: "none",
hue: 0,
on: false,
reachable: true,
sat: 0,
xy: [
0.3908,
0.1571
]
},
swversion: "1.3.009",
type: "Color light",
uniqueid: "d0:cf:5e:ff:fe:d9:65:62-01"
}

and after, light 3 should be on and is and light 4 should be off and is but the API output shows on: true

3: {
ctmax: 454,
ctmin: 250,
etag: "ca32bc546c6cef2729c868e856f73fd5",
hascolor: true,
manufacturername: "IKEA of Sweden",
modelid: "TRADFRI bulb E27 WS opal 980lm",
name: "Entrance lamp",
state: {
alert: "none",
bri: 77,
colormode: "xy",
ct: 250,
on: true,
reachable: true
},
swversion: "1.2.217",
type: "Color temperature light",
uniqueid: "00:0b:57:ff:fe:8d:3a:ab-01"
},
4: {
ctmax: 454,
ctmin: 250,
etag: "ca32bc546c6cef2729c868e856f73fd5",
hascolor: true,
manufacturername: "IKEA of Sweden",
modelid: "TRADFRI bulb E27 CWS opal 600lm",
name: "Bedroom1 Rooflight",
state: {
alert: "none",
bri: 254,
colormode: "xy",
effect: "none",
hue: 0,
on: true,
reachable: true,
sat: 0,
xy: [
0.3908,
0.1571
]
},
swversion: "1.3.009",
type: "Color light",
uniqueid: "d0:cf:5e:ff:fe:d9:65:62-01"
}

Thanks in advance!
Nicke

@Smanar
Copy link
Collaborator

Smanar commented Jul 31, 2019

Hello, have you something like websocket log (less informations but easy to obtain) or deconz event log ?

@nickehallgren
Copy link
Author

Hi Smanar,

I managed to get deCONZ to log and here is the result: The motion happens at 20:30:53:579 but I got confused on who tells who to do what. The RPi is 127.0.0.1 and .168.100 is from where I access node-red.

GET /api/302/config/wifi/ HTTP/1.1
Host: 127.0.0.1
User-Agent: curl/7.64.0
Accept: */*


20:30:51:938 HTTP API GET /api/302/config/wifi/ - 127.0.0.1
20:30:51:939 {"active":null,"eth0":null,"ip":"192.168.8.1","lastupdated":0,"name":null,"pw":null,"state":"not-configured","type":"accesspoint","wifi":"not-configured","wifiavailable":[],"wifichannel":"1","wifiip":"192.168.8.1","wifiname":null,"wifitype":"accesspoint","wlan0":null,"workingname":null,"workingpw":null,"workingtype":null}
20:30:51:940 http client (127.0.0.1) handled 1 requests
20:30:51:940 ~http client 0x0x1358f48
20:30:52:090 poll node 00:0d:6f:ff:fe:f1:2e:ae-01
20:30:52:090 Poll light node Outlet 1
20:30:52:143 Poll APS request to 0x000D6FFFFEF12EAE cluster: 0x0006 dropped, values are fresh enough
20:30:53:036 HTTP client hdr detected:
GET /api/302/config/wifi/ HTTP/1.1
Host: 127.0.0.1
User-Agent: curl/7.64.0
Accept: */*


20:30:53:036 HTTP API GET /api/302/config/wifi/ - 127.0.0.1
20:30:53:036 {"active":null,"eth0":null,"ip":"192.168.8.1","lastupdated":0,"name":null,"pw":null,"state":"not-configured","type":"accesspoint","wifi":"not-configured","wifiavailable":[],"wifichannel":"1","wifiip":"192.168.8.1","wifiname":null,"wifitype":"accesspoint","wlan0":null,"workingname":null,"workingpw":null,"workingtype":null}
20:30:53:037 http client (127.0.0.1) handled 1 requests
20:30:53:037 ~http client 0x0x13a5250
20:30:53:090 poll node 00:0b:57:ff:fe:33:da:14-01
20:30:53:090 Poll light node Livingroom Floorlamp
20:30:53:142 Poll APS request to 0x000B57FFFE33DA14 cluster: 0x0006 dropped, values are fresh enough
20:30:53:458 Poll APS request to 0x000B57FFFE33DA14 cluster: 0x0008 dropped, values are fresh enough
20:30:53:470 void deCONZ::zmNode::setFetched(deCONZ::RequestId, bool) fetched item: 8, node: 0x0000
20:30:53:579 button 1002 On with timed off
20:30:53:579 Force binding of attribute reporting for sensor Entrance Motion
20:30:53:582 discard sensor config push for config/delay (already pushed)
20:30:53:584 Websocket 192.168.1.100:54644 send message: {"e":"changed","id":"3","r":"sensors","state":{"dark":true,"lastupdated":"2019-07-31T20:30:53","presence":true},"t":"event","uniqueid":"14:b4:57:ff:fe:3e:a9:b7-01-0006"} (ret = 2124017088)
20:30:53:584 Websocket 127.0.0.1:53616 send message: {"e":"changed","id":"3","r":"sensors","state":{"dark":true,"lastupdated":"2019-07-31T20:30:53","presence":true},"t":"event","uniqueid":"14:b4:57:ff:fe:3e:a9:b7-01-0006"} (ret = 2124017088)
20:30:53:586 discard sensor state push for 3: state/presence (already pushed)
20:30:53:587 discard sensor state push for 3: state/lastupdated (already pushed)
20:30:53:588 Websocket 192.168.1.100:54644 send message: {"e":"changed","id":"1","r":"lights","state":{"alert":null,"on":true,"reachable":true},"t":"event","uniqueid":"00:0d:6f:ff:fe:f1:2e:ae-01"} (ret = 139)
20:30:53:589 Websocket 127.0.0.1:53616 send message: {"e":"changed","id":"1","r":"lights","state":{"alert":null,"on":true,"reachable":true},"t":"event","uniqueid":"00:0d:6f:ff:fe:f1:2e:ae-01"} (ret = 139)
20:30:53:590 Websocket 192.168.1.100:54644 send message: {"e":"changed","id":"3","r":"lights","state":{"alert":null,"bri":77,"colormode":"ct","ct":250,"on":true,"reachable":true},"t":"event","uniqueid":"00:0b:57:ff:fe:8d:3a:ab-01"} (ret = 174)
20:30:53:590 Websocket 127.0.0.1:53616 send message: {"e":"changed","id":"3","r":"lights","state":{"alert":null,"bri":77,"colormode":"ct","ct":250,"on":true,"reachable":true},"t":"event","uniqueid":"00:0b:57:ff:fe:8d:3a:ab-01"} (ret = 174)
20:30:53:592 Websocket 192.168.1.100:54644 send message: {"e":"changed","id":"4","r":"lights","state":{"alert":null,"bri":254,"colormode":"xy","hue":0,"on":true,"reachable":true,"sat":0,"x":25611,"xy":[0.3908,0.1571],"y":10295},"t":"event","uniqueid":"d0:cf:5e:ff:fe:d9:65:62-01"} (ret = 223)
20:30:53:593 Websocket 127.0.0.1:53616 send message: {"e":"changed","id":"4","r":"lights","state":{"alert":null,"bri":254,"colormode":"xy","hue":0,"on":true,"reachable":true,"sat":0,"x":25611,"xy":[0.3908,0.1571],"y":10295},"t":"event","uniqueid":"d0:cf:5e:ff:fe:d9:65:62-01"} (ret = 223)
20:30:53:594 discard sensor state push for 3: state/presence (already pushed)
20:30:53:595 discard sensor state push for 3: state/lastupdated (already pushed)
20:30:53:620 HTTP client hdr detected:
PUT /api/D52D58761B/lights/3/state HTTP/1.1
Content-Type: application/json
Content-Length: 29
host: 127.0.0.1
Connection: close


20:30:53:620 HTTP API PUT /api/D52D58761B/lights/3/state - 127.0.0.1
20:30:53:620 Text Data: 	{"ct":250,"bri":77,"on":true}
20:30:53:620 ApiMode: 0
20:30:53:621 ~Resource() /groups 0x7e99eaf8
20:30:53:621 add task 211 type 11 to 0x000B57FFFE8D3AAB cluster 0x0008 req.id 126
20:30:53:621 ~Resource() /groups 0x7e99eaf8
20:30:53:621 add task 212 type 5 to 0x000B57FFFE8D3AAB cluster 0x0300 req.id 127
20:30:53:622 [{"success":{"/lights/3/state/on":true}},{"success":{"/lights/3/state/bri":77}},{"success":{"/lights/3/state/ct":250}}]
20:30:53:623 Websocket 192.168.1.100:54644 send message: {"e":"changed","id":"3","r":"lights","state":{"alert":null,"bri":77,"colormode":"xy","ct":250,"on":true,"reachable":true},"t":"event","uniqueid":"00:0b:57:ff:fe:8d:3a:ab-01"} (ret = 174)
20:30:53:624 Websocket 127.0.0.1:53616 send message: {"e":"changed","id":"3","r":"lights","state":{"alert":null,"bri":77,"colormode":"xy","ct":250,"on":true,"reachable":true},"t":"event","uniqueid":"00:0b:57:ff:fe:8d:3a:ab-01"} (ret = 174)
20:30:53:626 http client (127.0.0.1) handled 1 requests
20:30:53:626 ~http client 0x0x13c7b98
20:30:53:665 delay sending request 127 dt 0 ms to 0x000B57FFFE8D3AAB, cluster 0x0300
20:30:53:665 delay sending request 127 cluster 0x0300 to 0x000b57fffe8d3aab
20:30:53:707 	0x000B57FFFE8D3AAB force poll (2)
20:30:53:707 Erase task req-id: 126, type: 11 zcl seqno: 49 send time 0, profileId: 0x0104, clusterId: 0x0008
20:30:53:713 Node data 0x000b57fffe8d3aab profileId: 0x0104, clusterId: 0x0006
20:30:53:713 update ZCL value 0x0006/0x0000 for 0x000B57FFFE8D3AAB after 23 s
20:30:53:713 ZCL attribute report 0x000B57FFFE8D3AAB for cluster 0x0006, ep 0x01
20:30:53:713 	payload: 00001001
20:30:53:764 Set sensor check interval to 100 milliseconds
20:30:53:765 binding/unbinding timeout srcAddr: B57FFFE8D3AAB, retry
20:30:53:808 	0x000B57FFFE8D3AAB force poll (2)
20:30:53:808 Erase task req-id: 127, type: 5 zcl seqno: 50 send time 1, profileId: 0x0104, clusterId: 0x0300
20:30:53:814 Node data 0x000b57fffe8d3aab profileId: 0x0104, clusterId: 0x0300
20:30:53:814 update ZCL value 0x0300/0x0008 for 0x000B57FFFE8D3AAB after 23 s
20:30:53:815 ZCL attribute report 0x000B57FFFE8D3AAB for cluster 0x0300, ep 0x01
20:30:53:815 	payload: 08003001
20:30:53:860 Bind response success for 0x000b57fffe8d3aab cluster 0x0300
20:30:53:861 skip configure report for cluster: 0x0300 attr: 0x0003 of node 0x000B57FFFE8D3AAB (wait reading or unsupported)
20:30:53:861 skip configure report for cluster: 0x0300 attr: 0x0004 of node 0x000B57FFFE8D3AAB (wait reading or unsupported)
20:30:53:861 configure reporting rq seq 52 for 0x000B57FFFE8D3AAB, attribute 0x0300/0x0007
20:30:53:861 configure reporting rq seq 52 for 0x000B57FFFE8D3AAB, attribute 0x0300/0x0008
20:30:53:960 ZCL configure reporting rsp seq: 52 0x000B57FFFE8D3AAB for cluster 0x0300 attr 0x0007 status 0x00
20:30:53:960 ZCL configure reporting rsp seq: 52 0x000B57FFFE8D3AAB for cluster 0x0300 attr 0x0008 status 0x00
20:30:54:051 Bind response success for 0x000b57fffe8d3aab cluster 0x0000
20:30:54:122 HTTP client hdr detected:
GET /api/302/config/wifi/ HTTP/1.1
Host: 127.0.0.1
User-Agent: curl/7.64.0
Accept: */*

@nickehallgren
Copy link
Author

nickehallgren commented Aug 1, 2019

I started from scratch and just added all lights with on/off buttons. Then inserted the motion sensor and the event listener. The API shows all lights are off, after the motion sensor (not connected) is triggered all lights show that they are on by the API (and you can also see the event gets triggered) but they are not. Can anyone reproduce this?

node

@Smanar
Copy link
Collaborator

Smanar commented Aug 1, 2019

And you haven't changed something in phoscon ? No groups ?
If you disable node-red, bulbs never change, and no more websocket return, if you trigger the motion sensor ?

I can't understand what can make the api send a change notification but without change in reality ...

@nickehallgren
Copy link
Author

Phoscon looks empty I made some groups at first but I deleted them. Every time I enter the mainpage it asks me to Create first group. But it seems like the remote made a light group (see below). I tried with node-red closed and all lights turns on in the API when activating the motion sensor (but the lights stay off) so it is not node-red related. What else can I check?

This is the output from the API for groups:

{
42949: {
action: {
bri: 127,
colormode: "hs",
ct: 0,
effect: "none",
hue: 0,
on: false,
sat: 127,
scene: null,
xy: [
0,
0
]
},
devicemembership: [
"2"
],
etag: "9640758c6849e523b85cf33436e8095c",
id: "42949",
lights: [ ],
name: "TRADFRI remote control 2",
scenes: [ ],
state: {
all_on: false,
any_on: false
},
type: "LightGroup"
}
}

@Smanar
Copy link
Collaborator

Smanar commented Aug 1, 2019

Yeah it's normal for the remote, I have same.
But for your problem, I am as curious than you ^^.
You can check in deconz the bulb state in cluster 0006 (if you have GUI version), but I m almost sure it will be good, perhaps a bug in the API, but it's strange you are the only one with this problem, it s rather critic as bug.

@nickehallgren
Copy link
Author

Yeah it is really weird. I'm running headless but ssh -X to the rescue. Wow, the deCONZ X app is amazing compared to the web interface :) So many ways to f**k up things :). But as you suspected the 0006 cluster shows exactly what the lamp is doing so it shows the right value... So might be a bug then?

@Smanar
Copy link
Collaborator

Smanar commented Aug 2, 2019

I think yes, it can't come from node-red, and you have a clean phoscon config, but it's holidays period ^^, need to wait for a dev.

@nickehallgren
Copy link
Author

I just did a complete re-install of my system to be sure that I didn't change anything that I had forgot and I got the same results.

I started with the 2019-07-10-raspbian-buster-lite image on a RPi 3B
did a update&upgrade
installed node+node-red as instucted here https://nodered.org/docs/getting-started/raspberrypi

bash <(curl -sL https://raw.githubusercontent.com/node-red/raspbian-deb-package/master/resources/update-nodejs-and-nodered)

then followed the instructions here https://phoscon.de/en/conbee/install#raspbian to step 5 then

sudo systemctl enable deconz
sudo systemctl disable deconz-gui
sudo systemctl stop deconz-gui

and a reboot, using node-red-contrib-deconz to control. Let's hope the devs find the problem because now the re-building of my homeautomation has stopped:(

But still, thanks for the amazing sw & hw!

@Smanar
Copy link
Collaborator

Smanar commented Aug 10, 2019

I think I have found another issue, with the same bug than you #1676 , your motion detector is the ikea one ?
But without solution yet.

@stale
Copy link

stale bot commented Dec 8, 2019

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs. Thank you for your contributions.

@stale stale bot added the stale label Dec 8, 2019
@stale stale bot closed this as completed Dec 15, 2019
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

No branches or pull requests

2 participants