Another issue seems to have creeped up. Has anybody had this issue? All lights seem to go unavailable a few times each hour:
Yes some people have this issue. We haven’t been able to conclude a specific cause or common set up traits
I see it every day, for the last month. I have noticed that cpu usage get higher when this happens and it helps a lot to restart deconz. It also happens in the evening when my circadian lighting start to adjust the lights every 5 minutes.
13:11:41:122 don't close database yet, keep open for 900 seconds
13:11:41:161 verified group capacity: 255 and group count: 1 of LightNode 0xd0cf5efffed98853
13:11:41:161 0xd0cf5efffed98853 found group 0xFFF0
13:11:41:213 Remove websocket 172.30.32.1:46792 after error Unknown error
13:11:41:214 no button map for: SML001 ep: 0x02 cl: 0x0406 cmd: 0x0A pl[0]: 000
13:11:41:214 ZCL attribute report 0x0017880106F42A22 for cluster: 0x0406, ep: 0x02, frame control: 0x08, mfcode: 0x0000
13:11:41:215 no button map for: SML001 ep: 0x02 cl: 0x0406 cmd: 0x0A pl[0]: 000
13:11:41:215 ZCL attribute report 0x0017880106F42A22 for cluster: 0x0406, ep: 0x02, frame control: 0x18, mfcode: 0x0000
13:11:41:231 Current channel 11
13:11:41:241 Device TTL 2024 s flags: 0x7
13:11:42:337 no button map for: KADRILJ roller blind ep: 0x01 cl: 0x0000 cmd: 0x0A pl[0]: 000
13:11:42:337 ZCL attribute report 0xD0CF5EFFFED99467 for cluster: 0x0000, ep: 0x01, frame control: 0x08, mfcode: 0x0000
13:11:42:422 no button map for: KADRILJ roller blind ep: 0x01 cl: 0x0000 cmd: 0x0A pl[0]: 000
13:11:42:422 ZCL attribute report 0xD0CF5EFFFED99467 for cluster: 0x0000, ep: 0x01, frame control: 0x08, mfcode: 0x0000
13:11:53:171 don't close database yet, keep open for 900 seconds
13:11:55:469 New websocket 172.30.32.1:60670 (state: 3)
13:11:57:389 0x24FD5B00010CD850 force poll (2)
13:11:57:701 0x24FD5B00010CD850 force poll (2)
13:11:58:370 0x24FD5B00010CD850 force poll (2)
Looks like there are issues with HA and deconz is loosing connection to HA because of these HA issues
2020-09-14 13:08:51 ERROR (MainThread) [graphql_subscription_manager] Connection error
Traceback (most recent call last):
File "/usr/local/lib/python3.8/site-packages/websockets/protocol.py", line 827, in transfer_data
message = await self.read_message()
File "/usr/local/lib/python3.8/site-packages/websockets/protocol.py", line 895, in read_message
frame = await self.read_data_frame(max_size=self.max_size)
File "/usr/local/lib/python3.8/site-packages/websockets/protocol.py", line 971, in read_data_frame
frame = await self.read_frame(max_size)
File "/usr/local/lib/python3.8/site-packages/websockets/protocol.py", line 1047, in read_frame
frame = await Frame.read(
File "/usr/local/lib/python3.8/site-packages/websockets/framing.py", line 105, in read
data = await reader(2)
File "/usr/local/lib/python3.8/asyncio/streams.py", line 721, in readexactly
raise exceptions.IncompleteReadError(incomplete, n)
asyncio.exceptions.IncompleteReadError: 0 bytes read on a total of 2 expected bytes
The above exception was the direct cause of the following exception:
Traceback (most recent call last):
File "/usr/local/lib/python3.8/site-packages/graphql_subscription_manager/__init__.py", line 101, in running
msg = await asyncio.wait_for(self.websocket.recv(), timeout=30)
File "/usr/local/lib/python3.8/asyncio/tasks.py", line 483, in wait_for
return fut.result()
File "/usr/local/lib/python3.8/site-packages/websockets/protocol.py", line 509, in recv
await self.ensure_open()
File "/usr/local/lib/python3.8/site-packages/websockets/protocol.py", line 803, in ensure_open
raise self.connection_closed_exc()
websockets.exceptions.ConnectionClosedError: code = 1006 (connection closed abnormally [internal]), no reason
2020-09-14 13:09:46 ERROR (MainThread) [graphql_subscription_manager] Connection error
Traceback (most recent call last):
File "/usr/local/lib/python3.8/site-packages/websockets/protocol.py", line 827, in transfer_data
message = await self.read_message()
File "/usr/local/lib/python3.8/site-packages/websockets/protocol.py", line 895, in read_message
frame = await self.read_data_frame(max_size=self.max_size)
File "/usr/local/lib/python3.8/site-packages/websockets/protocol.py", line 971, in read_data_frame
frame = await self.read_frame(max_size)
File "/usr/local/lib/python3.8/site-packages/websockets/protocol.py", line 1047, in read_frame
frame = await Frame.read(
File "/usr/local/lib/python3.8/site-packages/websockets/framing.py", line 105, in read
data = await reader(2)
File "/usr/local/lib/python3.8/asyncio/streams.py", line 721, in readexactly
raise exceptions.IncompleteReadError(incomplete, n)
asyncio.exceptions.IncompleteReadError: 0 bytes read on a total of 2 expected bytes
The above exception was the direct cause of the following exception:
Traceback (most recent call last):
File "/usr/local/lib/python3.8/site-packages/graphql_subscription_manager/__init__.py", line 101, in running
msg = await asyncio.wait_for(self.websocket.recv(), timeout=30)
File "/usr/local/lib/python3.8/asyncio/tasks.py", line 483, in wait_for
return fut.result()
File "/usr/local/lib/python3.8/site-packages/websockets/protocol.py", line 509, in recv
await self.ensure_open()
File "/usr/local/lib/python3.8/site-packages/websockets/protocol.py", line 803, in ensure_open
raise self.connection_closed_exc()
websockets.exceptions.ConnectionClosedError: code = 1006 (connection closed abnormally [internal]), no reason
2020-09-14 13:11:05 ERROR (MainThread) [graphql_subscription_manager] 504 - "<!DOCTYPE html>\n<html>\n<head>\n<title>Error</title>\n<style>\n body {\n width: 35em;\n margin: 0 auto;\n font-family: Tahoma, Verdana, Arial, sans-serif;\n }\n</style>\n</head>\n<body>\n<h1>An error occurred.</h1>\n<p>Sorry, the page you are looking for is currently unavailable.<br/>\nPlease try again later.</p>\n<p>If you are the system administrator of this resource then you should check\nthe error log for details.</p>\n<p><em>Faithfully yours, nginx.</em></p>\n</body>\n</html>\n"
2020-09-14 13:11:05 ERROR (MainThread) [graphql_subscription_manager] Connection error
Traceback (most recent call last):
File "/usr/local/lib/python3.8/site-packages/graphql_subscription_manager/__init__.py", line 101, in running
msg = await asyncio.wait_for(self.websocket.recv(), timeout=30)
File "/usr/local/lib/python3.8/asyncio/tasks.py", line 483, in wait_for
return fut.result()
File "/usr/local/lib/python3.8/site-packages/websockets/protocol.py", line 509, in recv
await self.ensure_open()
File "/usr/local/lib/python3.8/site-packages/websockets/protocol.py", line 812, in ensure_open
raise self.connection_closed_exc()
websockets.exceptions.ConnectionClosedError: code = 1011 (unexpected error), no reason
2020-09-14 13:11:22 ERROR (MainThread) [homeassistant.components.tibber.sensor] {'message': 'RequestError: Error: getaddrinfo ENOTFOUND tibber_customer.dev', 'locations': [{'line': 3, 'column': 15}], 'path': ['liveMeasurement'], 'extensions': {'code': 'INTERNAL_SERVER_ERROR', 'exception': {'innerError': {'errno': 'ENOTFOUND', 'code': 'ENOTFOUND', 'syscall': 'getaddrinfo', 'hostname': 'tibber_customer.dev'}}}}
2020-09-14 13:11:40 WARNING (MainThread) [homeassistant.components.threshold.binary_sensor] State is not numerical
Have you tried disabling the graphql related integrations? Deconz isn’t using anything related to that, but perhaps it is starving the async listeners?
No, I haven’t tried that, but of course thinking about it. I have to check out the Microsoft ToDo and the Tibber integrations.
My sd card failed recently. I moved to hassOS 5.2 on a ssd drive restoring a snapshot of system. Now my deconz with conbee II won’t connect to anything. In the logs it just keeps repeating:
18:26:40:680 channel 15 does not match channel mask 0x00100000 (TODO)
18:26:40:680 channel is 15 but should be 20, start channel change
18:26:40:680 Skip automatic channel change, TODO warn user
18:26:48:690 don’t close database yet, keep open for 900 seconds
If I try manually setting a channel it reverts back. Any solutions?
This is the log from last evening when lights and sensors started to get unavailable for 10 seconds and repeating that a few times.
21:40:16:298 delay sending request 247 dt 1 ms to 0x0017880103C7C675, ep: 0x0B cluster: 0x0300 onAir: 1
21:40:16:298 delay sending request 43 dt 1 ms to 0x0017880106320C99, ep: 0x0B cluster: 0x0008 onAir: 1
21:40:16:464 don't close database yet, keep open for 900 seconds
21:40:16:467 delay sending request 243 dt 1 ms to 0x0017880104A78379, ep: 0x0B cluster: 0x0008 onAir: 1
21:40:16:467 delay sending request 247 dt 1 ms to 0x0017880103C7C675, ep: 0x0B cluster: 0x0300 onAir: 1
21:40:16:467 delay sending request 43 dt 1 ms to 0x0017880106320C99, ep: 0x0B cluster: 0x0008 onAir: 1
21:40:16:491 delay sending request 243 dt 1 ms to 0x0017880104A78379, ep: 0x0B cluster: 0x0008 onAir: 1
21:40:16:491 delay sending request 247 dt 1 ms to 0x0017880103C7C675, ep: 0x0B cluster: 0x0300 onAir: 1
21:40:16:491 delay sending request 43 dt 1 ms to 0x0017880106320C99, ep: 0x0B cluster: 0x0008 onAir: 1
21:40:16:555 delay sending request 243 dt 1 ms to 0x0017880104A78379, ep: 0x0B cluster: 0x0008 onAir: 1
21:40:16:555 delay sending request 247 dt 1 ms to 0x0017880103C7C675, ep: 0x0B cluster: 0x0300 onAir: 1
21:40:16:555 delay sending request 43 dt 1 ms to 0x0017880106320C99, ep: 0x0B cluster: 0x0008 onAir: 1
21:40:16:655 delay sending request 243 dt 1 ms to 0x0017880104A78379, ep: 0x0B cluster: 0x0008 onAir: 1
21:40:16:655 delay sending request 247 dt 1 ms to 0x0017880103C7C675, ep: 0x0B cluster: 0x0300 onAir: 1
21:40:16:655 delay sending request 43 dt 1 ms to 0x0017880106320C99, ep: 0x0B cluster: 0x0008 onAir: 1
21:40:16:755 delay sending request 243 dt 1 ms to 0x0017880104A78379, ep: 0x0B cluster: 0x0008 onAir: 1
21:40:16:755 delay sending request 247 dt 1 ms to 0x0017880103C7C675, ep: 0x0B cluster: 0x0300 onAir: 1
21:40:16:755 delay sending request 43 dt 1 ms to 0x0017880106320C99, ep: 0x0B cluster: 0x0008 onAir: 1
21:40:16:855 delay sending request 243 dt 2 ms to 0x0017880104A78379, ep: 0x0B cluster: 0x0008 onAir: 1
21:40:16:855 delay sending request 247 dt 2 ms to 0x0017880103C7C675, ep: 0x0B cluster: 0x0300 onAir: 1
21:40:16:855 delay sending request 43 dt 2 ms to 0x0017880106320C99, ep: 0x0B cluster: 0x0008 onAir: 1
21:40:16:961 delay sending request 243 dt 2 ms to 0x0017880104A78379, ep: 0x0B cluster: 0x0008 onAir: 1
21:40:16:961 delay sending request 247 dt 2 ms to 0x0017880103C7C675, ep: 0x0B cluster: 0x0300 onAir: 1
21:40:16:961 delay sending request 43 dt 2 ms to 0x0017880106320C99, ep: 0x0B cluster: 0x0008 onAir: 1
21:40:17:029 send move to color temperature 500 to 0x00178801043E793B
21:40:17:029 delay sending request 243 dt 2 ms to 0x0017880104A78379, ep: 0x0B cluster: 0x0008 onAir: 1
21:40:17:029 delay sending request 247 dt 2 ms to 0x0017880103C7C675, ep: 0x0B cluster: 0x0300 onAir: 1
21:40:17:029 delay sending request 43 dt 2 ms to 0x0017880106320C99, ep: 0x0B cluster: 0x0008 onAir: 1
21:40:17:034 send move to color temperature 500 to 0x00178801044BECEF
21:40:17:035 delay sending request 243 dt 2 ms to 0x0017880104A78379, ep: 0x0B cluster: 0x0008 onAir: 1
21:40:17:035 delay sending request 247 dt 2 ms to 0x0017880103C7C675, ep: 0x0B cluster: 0x0300 onAir: 1
21:40:17:035 delay sending request 43 dt 2 ms to 0x0017880106320C99, ep: 0x0B cluster: 0x0008 onAir: 1
21:40:17:035 delay sending request 78 dt 0 ms to 0x00178801043E793B, ep: 0x0B cluster: 0x0008 onAir: 1
21:40:17:035 delay sending request 79 dt 0 ms to 0x00178801043E793B, ep: 0x0B cluster: 0x0300 onAir: 1
21:40:17:051 send move to color temperature 500 to 0x001788010842A14C
21:40:17:051 5 running tasks, wait
21:40:17:054 5 running tasks, wait
21:40:17:077 send move to color temperature 500 to 0x0017880106A20C0D
21:40:17:077 5 running tasks, wait
21:40:17:093 5 running tasks, wait
21:40:17:094 send move to color temperature 500 to 0xD0CF5EFFFE6D2652
21:40:17:094 5 running tasks, wait
21:40:17:095 5 running tasks, wait
21:40:17:095 failed to add task 301971 type: 14, too many tasks
21:40:17:095 failed to add task 301972 type: 11, too many tasks
21:40:17:095 5 running tasks, wait
21:40:17:102 failed to add task 301974 type: 14, too many tasks
21:40:17:102 failed to add task 301975 type: 11, too many tasks
21:40:17:102 send move to color temperature 500 to 0x001788010457159C
21:40:17:102 failed to add task 301976 type: 6, too many tasks
21:40:17:102 5 running tasks, wait
21:40:17:114 failed to add task 301978 type: 14, too many tasks
21:40:17:114 failed to add task 301979 type: 11, too many tasks
21:40:17:114 send move to color temperature 500 to 0x001788010838F156
21:40:17:114 failed to add task 301980 type: 6, too many tasks
21:40:17:114 5 running tasks, wait
21:40:17:125 failed to add task 301982 type: 14, too many tasks
21:40:17:125 failed to add task 301983 type: 11, too many tasks
21:40:17:125 send move to color temperature 500 to 0x00178801064FC54B
21:40:17:125 failed to add task 301984 type: 6, too many tasks
21:40:17:125 5 running tasks, wait
21:40:17:155 5 running tasks, wait
21:40:17:254 5 running tasks, wait
21:40:17:363 5 running tasks, wait
21:40:17:497 5 running tasks, wait
21:40:17:555 5 running tasks, wait
21:40:17:655 5 running tasks, wait
21:40:17:755 5 running tasks, wait
21:40:17:855 5 running tasks, wait
21:40:17:955 5 running tasks, wait
21:40:18:055 5 running tasks, wait
21:40:18:154 5 running tasks, wait
21:40:18:255 5 running tasks, wait
21:40:18:370 5 running tasks, wait
21:40:18:454 5 running tasks, wait
21:40:18:554 5 running tasks, wait
21:40:18:655 5 running tasks, wait
21:40:18:755 5 running tasks, wait
21:40:18:857 5 running tasks, wait
21:40:18:955 5 running tasks, wait
21:40:19:055 5 running tasks, wait
21:40:19:155 5 running tasks, wait
21:40:19:255 5 running tasks, wait
21:40:19:355 5 running tasks, wait
21:40:19:454 5 running tasks, wait
21:40:19:555 5 running tasks, wait
21:40:19:655 5 running tasks, wait
21:40:19:755 5 running tasks, wait
21:40:19:855 5 running tasks, wait
21:40:19:956 5 running tasks, wait
21:40:20:055 5 running tasks, wait
21:40:20:155 5 running tasks, wait
21:40:20:255 5 running tasks, wait
21:40:20:355 5 running tasks, wait
21:40:20:455 5 running tasks, wait
21:40:20:554 5 running tasks, wait
21:40:20:655 5 running tasks, wait
21:40:20:755 5 running tasks, wait
21:40:20:855 5 running tasks, wait
21:40:20:955 5 running tasks, wait
Is anyone else having problems with states in deconz not reflecting reality? I added all my lights (around 45 bulbs) yesterday afternoon and I’ve already had this problem twice, that suddenly 80% of my lights gets in the “on” state while they are actually off… Why is that ?
How do you disable VNC? I already removed all the ports but it’s still available via ingress. The logs show that it always stops the add on after randomly opening the vnc server when I don’t even use it.
I was not able to find it
Have you seen this new Blog entry
https://community.home-assistant.io/t/the-supervisor-joins-the-party/
Just Look for “Improve add-on availability with the new watchdog feature”
Yes, but that’s a workaround, not a fix …
Should be fixed
1 Like
Hello everyone!
I was wondering, how do you people with deCONZ and ConBee 2 handle situations caused by power outages? There was a big storm yesterday which caused some power loss problems (only 7 minutes without power, but during that time, power came back for 0,5 seconds or so and then off again quite a few times). After the power came back, ALL my Ikea Tradfri lights and one Ikea remote as well were unresponsive. Lights were all on but I couldn’t control them anymore via Home Assistant or PhosCon interface (I later noticed that I didn’t have updated my HASS plugin for a while, nowadays it’s possible to use either PhosCon or DeConz).
All light entities and that one zigbee remote were grey, and the only way I could get my lights back working was to delete all entities and then do the discovery and pairing again.
So, if power outage resets all zigbee lights, is there some reliable way to easily restore them without adding them again one by one?
There must be something wrong. Never happened with my own system when there is a powerloss or I unplug my RBPi for any reason.
It doesn’t happen if I switch power off from my Raspberry, or, if someone accidentally switches lamp off from wall switch (normally they are always on so that automation can work). And so, normal power outage where power goes off and then returns after X minutes/hours, it doesn’t break the system. But this power loss, although only lasted for 7 minutes, was such as power flickered on and off every now and then during that time, so maybe that resetted something. At least it resetted all my Sonoffs as well, but that’s different system and I found a way to prevent that in the future, but I wonder if I can prevent it somehow on PhosCon / DeConz side as well? 
For the RaspB, it is good to use a UPS. There are small solutions available, which keeps the raspi up for at least 30 minutes. Enough time to shut it regularly down.
This one for example: https://www.amazon.de/dp/B082TGLD2Q/?coliid=I2KBGK7ZQA923&colid=3098H133FSQ3A&psc=1&ref_=lv_ov_lig_dp_it
The bulbs have no problem with power lost.
Sure, and I have UPS with my raspberry. It kept the power whole time. The problem was with light bulbs. Not sure if it’s Ikea Trådfri spesific but then again, I don’t have any other manufacturers light bulbs so cannot compare…
Note after a power-loss nothing gets reset or is lost, albeit many people falsely believe that and start to reset their devices.
In case that after a power-loss or a new firmware update the network appears to be not responsive:
- Check that deCONZ is actually connected to RaspBee / ConBee, that is if the firmware version is shown in Phoscon App > Settings > Gateway. If not restarting the integration / container should bring it back.
- If connected but devices aren’t responsive yet… wait. Give if a few minutes. Likely the firmware Zigbee Frame Counter needs to catch up to get the value it had before the power-loss.
#2 Wasn’t a problem with older ZLL devices (which ignore the frame counter as per spec) but has become now with newer devices which ignore commands from the coordinator with an lower frame counter to prevent replay attacks. Recent firmware versions improved the frame counter handling but it isn’t optimal yet and can cause a delay after hard power-loss, which will be solved finally in upcoming versions.
Very important: In 99.999% of all cases there is no reason to reset all devices. The Zigbee configuration is stored in NVRAM of ConBee/RaspBee as well as each device.
1 Like
Only thing i can think of is that your lights (tradfri devices) have all been reset to default
As the way to reset the Tradfri devices is by disconnecting and connecting the power 6 times.
And like you said the power switched on and of a couple of times very fast.
An easy way to keep your Pi powered is with and USB Power bank between the pi and charger but i don’t think your problem lies in there.
Ah ok, I do not have Tadfri. My hue, Tint and Innr bulbs have no problem with power lost.
Happend two times last month due to uncarful electricians