Unable to parse json from Philips Eyecare

[OleksandrBerchenko]

Home Assistant release with the issue:

0.84.6

Last working Home Assistant release (if known):

n/a

Operating environment (Hass.io/Docker/Windows/etc.):

Virtualenv on Raspberry Pi

Component/platform:

https://www.home-assistant.io/components/light.xiaomi_miio/

Description of problem:

From time to time I see the following error in the log:

2019-01-10 04:54:51 ERROR (Thread-11) [miio.protocol] unable to parse json '{"result":[net],"id":1960}': Expecting value: line 1 column 12 (char 11)
2019-01-10 04:54:51 ERROR (MainThread) [homeassistant.helpers.entity] Update for light.philips_ambient_light fails

That response should be handled properly (at least to avoid an ugly traceback in the log).

Problem-relevant configuration.yaml entries and (fill out even if it seems unimportant):

light:
  - platform: xiaomi_miio
    name: philips
    scan_interval: 60
    model: philips.light.sread1
    host: 192.168.1.89
    token: 202e0609b23d38d15103a9de3075b7a2

Traceback (if applicable):

2019-01-10 04:54:51 ERROR (MainThread) [homeassistant.helpers.entity] Update for light.philips_ambient_light fails
Traceback (most recent call last):
  File "/srv/homeassistant/lib/python3.5/site-packages/homeassistant/helpers/entity.py", line 221, in async_update_ha_state
    await self.async_device_update()
  File "/srv/homeassistant/lib/python3.5/site-packages/homeassistant/helpers/entity.py", line 347, in async_device_update
    await self.async_update()
  File "/srv/homeassistant/lib/python3.5/site-packages/homeassistant/components/light/xiaomi_miio.py", line 721, in async_update
    state = await self.hass.async_add_executor_job(self._light.status)
  File "/usr/lib/python3.5/asyncio/futures.py", line 380, in __iter__
    yield self  # This tells Task to wait for completion.
  File "/usr/lib/python3.5/asyncio/tasks.py", line 304, in _wakeup
    future.result()
  File "/usr/lib/python3.5/asyncio/futures.py", line 293, in result
    raise self._exception
  File "/usr/lib/python3.5/concurrent/futures/thread.py", line 55, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/srv/homeassistant/lib/python3.5/site-packages/miio/philips_eyecare.py", line 125, in status
    properties
  File "/srv/homeassistant/lib/python3.5/site-packages/miio/device.py", line 265, in send
    self.__id = m.data.value["id"]
TypeError: 'NoneType' object is not subscriptable

Additional information:

[OleksandrBerchenko]

One more error and traceback:

2019-01-12 02:35:38 ERROR (Thread-18) [miio.protocol] unable to parse json '{"result":["off",40,"off","on",41,"off"net],"id":3116}': Expecting ',' delimiter: line 1 column 40 (char 39)
2019-01-12 02:35:38 ERROR (MainThread) [homeassistant.helpers.entity] Update for light.philips_ambient_light fails
Traceback (most recent call last):
  File "/srv/homeassistant/lib/python3.5/site-packages/homeassistant/helpers/entity.py", line 221, in async_update_ha_state
    await self.async_device_update()
  File "/srv/homeassistant/lib/python3.5/site-packages/homeassistant/helpers/entity.py", line 347, in async_device_update
    await self.async_update()
  File "/srv/homeassistant/lib/python3.5/site-packages/homeassistant/components/light/xiaomi_miio.py", line 721, in async_update
    state = await self.hass.async_add_executor_job(self._light.status)
  File "/usr/lib/python3.5/asyncio/futures.py", line 380, in __iter__
    yield self  # This tells Task to wait for completion.
  File "/usr/lib/python3.5/asyncio/tasks.py", line 304, in _wakeup
    future.result()
  File "/usr/lib/python3.5/asyncio/futures.py", line 293, in result
    raise self._exception
  File "/usr/lib/python3.5/concurrent/futures/thread.py", line 55, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/srv/homeassistant/lib/python3.5/site-packages/miio/philips_eyecare.py", line 125, in status
    properties
  File "/srv/homeassistant/lib/python3.5/site-packages/miio/device.py", line 265, in send
    self.__id = m.data.value["id"]
TypeError: 'NoneType' object is not subscriptable

[moskovskiy82]

same here. everything works but sometimes get an error of

2019-01-12 21:27:08 ERROR (SyncWorker_5) [miio.protocol] unable to parse json '{"result":[net],"id":937}': Expecting value: line 1 column 12 (char 11) 2019-01-12 21:27:08 ERROR (MainThread) [homeassistant.helpers.entity] Update for light.kids_philips fails

[OleksandrBerchenko]

Obviously, {"result":[net],"id":937} is not a valid JSON (what is net?) So, the original issue is on the device side. Anyway, Device.send() should be ready that this line returns None:

m = Message.parse(data, token=self.token)

and to raise DeviceException (or something like that).

[syssi]

@moskovskiy82 This happens if you block the internet access of the device.

[syssi]

@OleksandrBerchenko Could you provide all commands/requests which are failing?

[OleksandrBerchenko]

@syssi I don't have other examples: it happens only with my Philips Eyecare lamp (to be precisely, with its ambient_light part). The error is always the same: the code can't parse incorrect JSON that contains net and fails because doesn't handle None correctly.

Thanks!

[syssi]

I'm asking because you postet two different responses:

2019-01-10 04:54:51 ERROR (Thread-11) [miio.protocol] unable to parse json '{"result":[net],"id":1960}': Expecting value: line 1 column 12 (char 11)
2019-01-12 02:35:38 ERROR (Thread-18) [miio.protocol] unable to parse json '{"result":["off",40,"off","on",41,"off"net],"id":3116}': Expecting ',' delimiter: line 1 column 40 (char 39)

Does the position of "net" shift randomly?

# f.e.
["off",40,"off","on",41,"off"net]
["off",40,"off","on",41net]
["off",40,"off","on"net]
["off",40,"off"net]
["off",40net]
["off"net]
[net]

[OleksandrBerchenko]

@syssi All errors that I have for the last week:

2019-02-14 04:41:57 ERROR (Thread-18) [miio.protocol] unable to parse json '{"result":["off",40net],"id":276}': Expecting ',' delimiter: line 1 column 20 (char 19)
2019-02-15 23:09:58 ERROR (Thread-3) [miio.protocol] unable to parse json '{"result":["off",40,"off","on"net],"id":610}': Expecting ',' delimiter: line 1 column 31 (char 30)
2019-02-16 00:57:43 ERROR (Thread-20) [miio.protocol] unable to parse json '{"result":[net],"id":772}': Expecting value: line 1 column 12 (char 11)
2019-02-16 04:53:31 ERROR (Thread-5) [miio.protocol] unable to parse json '{"result":[net],"id":1322}': Expecting value: line 1 column 12 (char 11)
2019-02-17 12:30:15 ERROR (Thread-13) [miio.protocol] unable to parse json '{"result":["off"net],"id":2094}': Expecting ',' delimiter: line 1 column 17 (char 16)

So, the answer is probably "yes".

Thanks!

[syssi]

@OleksandrBerchenko Did you block the internet access of your light or is your internet connection unstable?

[OleksandrBerchenko]

@syssi My connection is relatively stable, but from to time any device may be disconnected. My Philips Eyecare was never reported as unavailable (I have monitoring in place), but I'm not aware about possible retry logic under the hood.

Thanks!

[syssi]

@OleksandrBerchenko We are talking about a firmware issue here. The microcontroller of the device breaks the JSON payload sometimes. Presumably on bad or blocked network/internet connection. I will try to detect and discard these messages in future as workaround.

[stale[bot]]

There hasn't been any activity on this issue recently. Due to the high number of incoming GitHub notifications, we have to clean some of the old issues, as many of them have already been resolved with the latest updates. Please make sure to update to the latest Home Assistant version and check if that solves the issue. Let us know if that works for you by adding a comment 👍 This issue now has been marked as stale and will be closed if no further activity occurs. Thank you for your contributions.

[OleksandrBerchenko]

Yes, I see those error messages in the log every day.

Thanks!

[maxmib]

same problem with my philips eyecare lamp

[stale[bot]]

There hasn't been any activity on this issue recently. Due to the high number of incoming GitHub notifications, we have to clean some of the old issues, as many of them have already been resolved with the latest updates. Please make sure to update to the latest Home Assistant version and check if that solves the issue. Let us know if that works for you by adding a comment 👍 This issue now has been marked as stale and will be closed if no further activity occurs. Thank you for your contributions.

[OleksandrBerchenko]

Yes, it's still actual.

Thanks!

[stale[bot]]

There hasn't been any activity on this issue recently. Due to the high number of incoming GitHub notifications, we have to clean some of the old issues, as many of them have already been resolved with the latest updates. Please make sure to update to the latest Home Assistant version and check if that solves the issue. Let us know if that works for you by adding a comment 👍 This issue now has been marked as stale and will be closed if no further activity occurs. Thank you for your contributions.

[OleksandrBerchenko]

Yes, it's still actual.

Thanks!

[stale[bot]]

There hasn't been any activity on this issue recently. Due to the high number of incoming GitHub notifications, we have to clean some of the old issues, as many of them have already been resolved with the latest updates. Please make sure to update to the latest Home Assistant version and check if that solves the issue. Let us know if that works for you by adding a comment 👍 This issue now has been marked as stale and will be closed if no further activity occurs. Thank you for your contributions.

[OleksandrBerchenko]

Yes, it's still actual.

Thanks!

[stale[bot]]

There hasn't been any activity on this issue recently. Due to the high number of incoming GitHub notifications, we have to clean some of the old issues, as many of them have already been resolved with the latest updates. Please make sure to update to the latest Home Assistant version and check if that solves the issue. Let us know if that works for you by adding a comment 👍 This issue now has been marked as stale and will be closed if no further activity occurs. Thank you for your contributions.

[OleksandrBerchenko]

Yes, it's still actual.

Thanks!

[rytilahti]

This fixed the mishandling of failed discovery: https://github.com/rytilahti/python-miio/pull/731 . The incorrect JSON is not handled at the moment anyway, but maybe the upstream device class should be changed to filter out (or strip the 'net' away and use the rest information) such invalid responses.

[OleksandrBerchenko]

It looks like I did not get any new errors since 2020-07-04. Probably something fixed or just muted this error.

I think it may be closed now.

[rytilahti]

Great, thanks for reporting back, let's close it!