sbidy / wiz_light

A WiZ Light integration for Home Assistant
MIT License
341 stars 68 forks source link

Firmware 1.21.0 Issues #62

Closed meyerrj closed 3 years ago

meyerrj commented 3 years ago

Firmware 1.21.0 Issues

Bulb Information

{"method":"getSystemConfig","env":"pro","result":{"mac":"a8bb50471a08","homeId":724525,"roomId":1097753,"moduleName":"ESP03_SHRGB1C_01","fwVersion":"1.21.0","groupId":0,"drvConf":[60,1],"ewf":[200,255,150,255,0,0,40],"ewfHex":"c8ff96ff000028","ping":0}}

Additional Info

I have four bulbs with a Model ID of B23065, other bulbs in the home are Model ID 23007.

Since the firmware was updated to 1.21.0 a few days ago, there have been timeouts and other issues with home assistant with the B23065 bulbs.

At times home assistant will see these bulbs as unavailable and cannot update or change their status. The only way I've been able to "fix" it is to kill the power to the bulb itself, wait, and turn it back on. After a few seconds they will show up as available again, until the next timeout.

During some automations, I'm also getting the following stack trace below in the logs:

Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 278, in async_update_ha_state
    await self.async_device_update()
  File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 474, in async_device_update
    raise exc
  File "/config/custom_components/wiz_light/light.py", line 201, in async_update
    self.update_brightness()
  File "/config/custom_components/wiz_light/light.py", line 234, in update_brightness
    if self._light.state.get_brightness() is None:
  File "/usr/local/lib/python3.8/site-packages/pywizlight/bulb.py", line 197, in get_brightness
    return self.percent_to_hex(self.pilotResult['dimming'])
KeyError: 'dimming'
sbidy commented 3 years ago

Oh that's bad. So it seems to be a change in the UDP AIP of the bulb firmware. Can you please fire a nc with {"method":"getPilot","params":{}} as parameter:

echo '{"method":"getPilot","params":{}}' | nc -u -w 1 <YOU BULB IP> 38899

So this should be return the state of the bulb. Please turn on the bulb via App and test this nc.

meyerrj commented 3 years ago

This is the output I'm getting currently on four of the bulbs:

{"method":"getPilot","env":"pro","result":{"mac":"a8bb50471a08","rssi":-66,"src":"","state":true,"sceneId":6,"dimming":50}}

{"method":"getPilot","env":"pro","result":{"mac":"a8bb5047a92e","rssi":-72,"src":"","state":true,"sceneId":6,"dimming":50}

{"method":"getPilot","env":"pro","result":{"mac":"a8bb50ced4d6","rssi":-66,"src":"","state":true,"sceneId":6,"dimming":50}}

{"method":"getPilot","env":"pro","result":{"mac":"a8bb5046db06","rssi":-66,"src":"","state":true,"sceneId":6,"dimming":50}}
meyerrj commented 3 years ago

The stack trace error may be related to another bulb in the group the automation was targeting... I assumed it was the four bulbs that were timing out, but I can see where this one is missing the dimming key.

{"method":"getSystemConfig","env":"pro","result":{"mac":"a8bb50c7c741","homeId":724525,"roomId":1439578,"moduleName":"ESP01_SHRGB1C_31","fwVersion":"1.21.0","groupId":0,"drvConf":[33,1],"ewf":[255,250,150,255,0,0,40],"ewfHex":"fffa96ff000028","ping":0}

Running the same check on this bulb (before doing anything via the app):

{"method":"getPilot","env":"pro","result":{"mac":"a8bb50ae81e8","rssi":-79,"src":"","state":false,"sceneId":9}}

After turning it off and on again via the WiZ app I got this:

{"method":"getPilot","env":"pro","result":{"mac":"a8bb50ae81e8","rssi":-79,"src":"","state":true,"sceneId":29,"dimming":100}}

When turned off via the WiZ app and polled, the dimming key remains:

{"method":"getPilot","env":"pro","result":{"mac":"a8bb50ae81e8","rssi":-79,"src":"","state":false,"sceneId":29,"dimming":100}}
sbidy commented 3 years ago

Thank you for report - I'll try to update my bulb to that FW. I have to test all request types form the pywizlight library. Maybe I have to update the lib.

meyerrj commented 3 years ago

Sounds good!

I'll wait for the next "timeout" to occur with the other bulbs and see what the getPilot output is at that time as well.

If there are any other commands I can run against them, just let me know.

sbidy commented 3 years ago

So it seems to be another issue. I'm on the 1.21.0 FW and all features seems to be working without issues or timeouts .

I try to reproduce this error.

meyerrj commented 3 years ago

The "timeout" issue has been fairly intermittent for me, maybe once or twice a day... I've been keeping an eye on my HA since this morning to see if it happens again, but it may not happen until later this evening for me.

ChrisLizon commented 3 years ago

@sbidy I have one bulb on 1.20.0 (not internet connected) and 1.21.0 (connected to internet) and both seem to be working. Not sure if there's anything that may need to be compared.

I do know that where my office is where my wiz bulbs are installed, it's kinda hit or miss if they connect to one AP or the other in my setup. I have noticed that occasionally I have to reboot the one connected to my IoT Vlan, and I always assumed it's because they are stuck trying to connect to the farthest AP. Since I set up the test AP which I use for wireshark, that bulb never seems to go offline (it's only 1.5m from the AP).

mwwgithub commented 3 years ago

It might be worth reducing the transmit power of one or both of your APs just slightly to allow your IOT devices to make a better decision.

On Fri, Dec 18, 2020 at 1:16 PM ChrisLizon notifications@github.com wrote:

@sbidy https://github.com/sbidy I have one bulb on 1.20.0 (not internet connected) and 1.21.0 (connected to internet) and both seem to be working. Not sure if there's anything that may need to be compared.

I do know that where my office is where my wiz bulbs are installed, it's kinda hit or miss if they connect to one AP or the other in my setup. I have noticed that occasionally I have to reboot the one connected to my IoT Vlan, and I always assumed it's because they are stuck trying to connect to the farthest AP. Since I set up the test AP which I use for wireshark, that bulb never seems to go offline (it's only 1.5m from the AP).

— You are receiving this because you are subscribed to this thread. Reply to this email directly, view it on GitHub https://github.com/sbidy/wiz_light/issues/62#issuecomment-748240316, or unsubscribe https://github.com/notifications/unsubscribe-auth/AJNWE2OTA3YUAWLQ33KO7DLSVOL6PANCNFSM4VBJ4KSA .

meyerrj commented 3 years ago

Looks like it happened again this morning.

Logger: homeassistant.helpers.entity
Source: custom_components/wiz_light/light.py:234
First occurred: December 17, 2020, 7:52:19 PM (5346 occurrences)
Last logged: 12:31:28 PM

Update for light.office_fan_light_01 fails
Update for light.office_fan_light_02 fails
Update for light.office_fan_light_03 fails
Update for light.office_fan_light_04 fails
Update for light.living_room_lamp_01 fails

Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 278, in async_update_ha_state
    await self.async_device_update()
  File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 474, in async_device_update
    raise exc
  File "/config/custom_components/wiz_light/light.py", line 201, in async_update
    self.update_brightness()
  File "/config/custom_components/wiz_light/light.py", line 234, in update_brightness
    if self._light.state.get_brightness() is None:
  File "/usr/local/lib/python3.8/site-packages/pywizlight/bulb.py", line 197, in get_brightness
    return self.percent_to_hex(self.pilotResult['dimming'])
KeyError: 'dimming'

The info for those bulbs:

Office fan lights in order:
"method":"getSystemConfig","env":"pro","result":{"mac":"a8bb50471a08","homeId":724525,"roomId":1097753,"moduleName":"ESP03_SHRGB1C_01","fwVersion":"1.21.0","groupId":0,"drvConf":[60,1],"ewf":[200,255,150,255,0,0,40],"ewfHex":"c8ff96ff000028","ping":0}}

{"method":"getPilot","env":"pro","result":{"mac":"a8bb50471a08","rssi":-72,"src":"","state":true,"sceneId":9}}

{"method":"getSystemConfig","env":"pro","result":{"mac":"a8bb5047a92e","homeId":724525,"roomId":1097753,"moduleName":"ESP03_SHRGB1C_01","fwVersion":"1.21.0","groupId":0,"drvConf":[60,1],"ewf":[200,255,150,255,0,0,40],"ewfHex":"c8ff96ff000028","ping":0}}

{"method":"getPilot","env":"pro","result":{"mac":"a8bb5047a92e","rssi":-68,"src":"","state":true,"sceneId":9}}

{"method":"getSystemConfig","env":"pro","result":{"mac":"a8bb50ced4d6","homeId":724525,"roomId":1097753,"moduleName":"ESP03_SHRGB1C_01","fwVersion":"1.21.0","groupId":0,"drvConf":[60,1],"ewf":[200,255,150,255,0,0,40],"ewfHex":"c8ff96ff000028","ping":0}}

{"method":"getPilot","env":"pro","result":{"mac":"a8bb50ced4d6","rssi":-69,"src":"","state":true,"sceneId":9}}

{"method":"getSystemConfig","env":"pro","result":{"mac":"a8bb5046db06","homeId":724525,"roomId":1097753,"moduleName":"ESP03_SHRGB1C_01","fwVersion":"1.21.0","groupId":0,"drvConf":[60,1],"ewf":[200,255,150,255,0,0,40],"ewfHex":"c8ff96ff000028","ping":0}}

{"method":"getPilot","env":"pro","result":{"mac":"a8bb5046db06","rssi":-69,"src":"","state":true,"sceneId":9}}
Living Room Lamp
{"method":"getSystemConfig","env":"pro","result":{"mac":"a8bb50c7c741","homeId":724525,"roomId":1439578,"moduleName":"ESP01_SHRGB1C_31","fw
Version":"1.21.0","groupId":0,"drvConf":[33,1],"ewf":[255,250,150,255,0,0,40],"ewfHex":"fffa96ff000028","ping":0}}

{"method":"getPilot","env":"pro","result":{"mac":"a8bb50c7c741","rssi":-59,"src":"","state":true,"sceneId":6,"dimming":75}}

The fan lights are currently on, as is the lamp. Home Assistant shows the fan bulbs as off right now:

image

Using the WiZ app, I can see that the fan bulbs are currently on with the Wake up effect still applied. HA sees them as off though.

Overall, it looks like the issue is that since the firmware update, dimming may be an optional keyword in the pilot response.

sbidy commented 3 years ago

I think in case of this exception the status update will stucked. Thats maybe the reason why the bulb will be displayed as offline.

Can you maybe ping the bulb continuuesly to check if the is an general network issue?

The app will use another connection interface (Rest API with HTTPS).

meyerrj commented 3 years ago

I agree that it might just be the dimming exception resulting in HA thinking the bulbs are no longer available or offline.

I've pinged the various bulbs for several minutes, but no packet loss, and response times have been <= 22ms, averaging about 5ms.

sbidy commented 3 years ago

OK, so please try to ping the bulb for a longer time (24h). It is really difficult for me to reproduce such an issue.

I'm note sure if this is a problem of the bulb or HA. I will have a look into the exception handling. Because normally if the bulb is offline the UDP call will run into a timeout and another exception will popup.

But I have an idea what's maybe happened. The bulb can also return a error messsag as json and this will currently not parsed and handheld correctly in the pywizlight.

TravisRoy commented 3 years ago

I have some Model ID 23007 A19 bulbs that have updated to that firmware. No issues to report so far.

meyerrj commented 3 years ago

Here's my ping results, it's been a little over 23 hours.

83145 packets transmitted, 83085 received, 0% packet loss, time 83292256ms
rtt min/avg/max/mdev = 1.943/6.783/1383.649/12.987 ms, pipe 2

83157 packets transmitted, 83157 received, 0% packet loss, time 83302869ms
rtt min/avg/max/mdev = 1.922/6.432/1073.718/12.384 ms, pipe 2

83162 packets transmitted, 83160 received, 0% packet loss, time 83308480ms
rtt min/avg/max/mdev = 1.863/6.043/1176.736/12.709 ms, pipe 2

83167 packets transmitted, 83128 received, 0% packet loss, time 83313675ms
rtt min/avg/max/mdev = 1.878/6.802/1619.599/14.749 ms, pipe 2

The error did happen again today for me. I also think I found something in my automation script that might be related.

When setting the effect to Wake up, I was also setting brightness: 128 on the fan bulbs, but not on the lamp. Maybe there's an issue with setting the brightness with certain effects, especially for those that transition like Wake up, Sunset, or Bedtime?

I'm going to see if removing the brightness setting fixes things for tomorrow.

chrisbl01 commented 3 years ago

I'm having the same issue now after doing a fresh install of HA, I have the same mix of bulb types as well (B23065, 230007) all on the 1.21.0 firmware. I can delete a bulb, re-add (wiz app) and about 2min later it goes 'unavailable" in HA. I don't have any automations set and at the moment few integrations, just enough to keep the wife from killing me....for someone who doesn't like my new hobby she sure gets upset when these things don't turn on automatically and she has to touch a switch LOL.

sbidy commented 3 years ago

Now should be fixed. Please update the integration to Version 0.2 in the Releases.

Issue: The problem was, that proactive scenes are not returning a dim value. That why the exception was thrown an the bulb remains in "Unknown". For example the "Night Lite" returns:

{"method":"getPilot","env":"pro","result":{"mac":"a8bb5006033d","rssi":-62,"src":"","state":true,"sceneId":14}}

Fix Update to the integration Version 0.2 or update manually the pywizlight to the version 0.3.8.

References bug fix: 'dimming' param is not returned in progressive scenes like w… https://github.com/sbidy/pywizlight/pull/32