amelchio / eternalegypt

Python API for Netgear LTE modems
MIT License
32 stars 22 forks source link

Lots of keyerrors, even though the data appears to be there #4

Closed sofar closed 6 years ago

sofar commented 6 years ago

I'm seeing lots of log output.

Aug 26 23:04:41 allie hass[323]: KeyError: 'wwan'
Aug 26 23:05:12 allie hass[323]: 2018-08-26 23:05:12 ERROR (MainThread) [homeassistant.helpers.entity] Update for sensor.netgear_lte_usage fails
Aug 26 23:05:12 allie hass[323]: Traceback (most recent call last):
Aug 26 23:05:12 allie hass[323]:   File "/usr/lib/python3.7/site-packages/homeassistant/helpers/entity.py", line 199, in async_update_ha_state
Aug 26 23:05:12 allie hass[323]:     yield from self.async_device_update()
Aug 26 23:05:12 allie hass[323]:   File "/usr/lib/python3.7/site-packages/homeassistant/helpers/entity.py", line 320, in async_device_update
Aug 26 23:05:12 allie hass[323]:     yield from self.async_update()
Aug 26 23:05:12 allie hass[323]:   File "/usr/lib/python3.7/site-packages/homeassistant/components/sensor/netgear_lte.py", line 53, in async_update
Aug 26 23:05:12 allie hass[323]:     await self.modem_data.async_update()
Aug 26 23:05:12 allie hass[323]:   File "/usr/lib/python3.7/site-packages/homeassistant/components/netgear_lte.py", line 47, in async_update
Aug 26 23:05:12 allie hass[323]:     information = await self.modem.information()
Aug 26 23:05:12 allie hass[323]:   File "/usr/lib/python3.7/site-packages/eternalegypt/eternalegypt.py", line 119, in information
Aug 26 23:05:12 allie hass[323]:     result.usage = data['wwan']['dataUsage']['generic']['dataTransferred']
Aug 26 23:05:12 allie hass[323]: KeyError: 'wwan'

However, whenever I dump the data, wwan.dataUsage.generic.dataTransferred seems to be OK. Perhaps the model went offline for a second, or the connection disappeared? I have very spotty cell service.

amelchio commented 6 years ago

Thanks, so we should guard against that.

Is the KeyError only for wwan or other data as well?

sofar commented 6 years ago

Only seeing it for wwan thus far...

amelchio commented 6 years ago

I am unable to reproduce this. I tried removing my SIM card but the wwan field was still returned albeit with dummy values.

Can you try adding this patch to dump the response when it happens? I don't want to add this permanently since some of the data could be sensitive and you never know where logs end up.

--- a/eternalegypt/eternalegypt.py
+++ b/eternalegypt/eternalegypt.py
@@ -128,6 +128,10 @@ class LB2120:
             async with self.websession.get(url) as response:
                 data = json.loads(await response.text())

+                if 'wwan' not in data:
+                    _LOGGER.warning("Invalid data: %s", data)
+                    return result
+
                 result.usage = data['wwan']['dataUsage']['generic']['dataTransferred']
                 result.upstream = data['failover']['backhaul']
                 result.serial_number = data['general']['FSN']
sofar commented 6 years ago

Testing... will let it run for a few days, it seems to be highly dependent on bad signal, and the past few days my signal has been solid :)

sofar commented 6 years ago

sigh, I don't know what happened, but an update to home assistant completely fried the extra sensors I had added, so now my netgear module is entirely broken, which means I can't test this because eternalegypt isn't getting called regularly by home assistant. I've tried patching netgear_lte.py in /sensors/ but nothing I do makes it load, it's all weird errors to me...

And so I'm back to zero, and this is starting to feel like a bit of a time waste :(

amelchio commented 6 years ago

Not quite back to zero, I just pushed a new release with your additions to eternalegypt 👍. If you are willing to update the documentation, I can add the new sensor types to Home Assistant before the next release.

If we find the cause of this issue, we can make another release with a fix.

sofar commented 6 years ago

Give me a few days to get back to this...!

sofar commented 6 years ago

Getting some of these now, due to the debug prints we've added:

Invalid data: {'custom': {'end': 0}, 'webd': {'adminPassword': '****************', 'hideAdminPassword': True, 'end': ''}, 'lcd': {'end': ''}, 'sim': {'pin': {'end': ''}, 'puk': {}, 'mep': {}, 'end': ''}, 'sms': {'end': ''}, 'session': {'userRole': 'Guest', 'lang': 'en', 'secToken': '****'}, 'general': {'defaultLanguage': 'en', 'activated': True, 'TCAaccepted': True, 'verMajor': 1000, 'verMinor': 0, 'environment': 'Application', 'currTime': 1219971667, 'deviceName': 'LB1120', 'factoryResetStatus': 'NotStarted', 'setupCompleted': True, 'languageSelected': False, 'systemAlertList': {'list': [{}], 'count': 0}, 'apiVersion': '2.0', 'companyName': 'NETGEAR', 'configURL': '/Forms/config', 'profileURL': '/Forms/profile', 'pinChangeURL': '/Forms/pinChange', 'portCfgURL': '/Forms/portCfg', 'portFilterURL': '/Forms/portFilter', 'wifiACLURL': '/Forms/wifiACL', 'supportedLangList': [{'id': 'en', 'isCurrent': 'true', 'isDefault': 'true', 'label': 'English', 'token1': '/romfs/lcd/en_us.tr', 'token2': ''}, {'id': 'de_DE', 'isCurrent': 'false', 'isDefault': 'false', 'label': 'Deutsch (German)', 'token1': '/romfs/lcd/de_de.tr', 'token2': ''}, {'id': 'ar_AR', 'isCurrent': 'false', 'isDefault': 'false', 'label': 'العربية (Arabic)', 'token1': '/romfs/lcd/ar_AR.tr', 'token2': ''}, {'id': 'es_ES', 'isCurrent': 'false', 'isDefault': 'false', 'label': 'Español (Spanish)', 'token1': '/romfs/lcd/es_es.tr', 'token2': ''}, {'id': 'fr_FR', 'isCurrent': 'false', 'isDefault': 'false', 'label': 'Français (French)', 'token1': '/romfs/lcd/fr_fr.tr', 'token2': ''}, {'id': 'it_IT', 'isCurrent': 'false', 'isDefault': 'false', 'label': 'Italiano (Italian)', 'token1': '/romfs/lcd/it_it.tr', 'token2': ''}, {'id': 'pl_PL', 'isCurrent': 'false', 'isDefault': 'false', 'label': 'Polski (Polish)', 'token1': '/romfs/lcd/pl_pl.tr', 'token2': ''}, {'id': 'ru_RU', 'isCurrent': 'false', 'isDefault': 'false', 'label': 'Pусский (Russian)', 'token1': '/romfs/lcd/ru_ru.tr', 'token2': ''}, {'id': 'fi_FI', 'isCurrent': 'false', 'isDefault': 'false', 'label': 'Suomi (Finnish)', 'token1': '/romfs/lcd/fi_fi.tr', 'token2': ''}, {'id': 'sv_SE', 'isCurrent': 'false', 'isDefault': 'false', 'label': 'Svenska (Swedish)', 'token1': '/romfs/lcd/sv_se.tr', 'token2': ''}, {'id': 'tu_TU', 'isCurrent': 'false', 'isDefault': 'false', 'label': 'Türkçe (Turkish)', 'token1': '/romfs/lcd/tu_tu.tr', 'token2': ''}, {}]}, 'power': {'PMState': 'Init', 'SmState': 'Online', 'autoOff': {'onUSBdisconnect': {'end': ''}, 'onIdle': {'timer': {'end': ''}}}, 'standby': {'onIdle': {'timer': {'end': ''}}}, 'autoOn': {'end': ''}, 'resetRequired': 'NoResetRequired', 'lpm': False, 'end': ''}, 'wwanadv': {'end': ''}, 'wifi': {'wps': {'end': ''}, 'guest': {'DHCP': {'range': {'end': ''}}}, 'end': ''}, 'router': {'hostName': 'LB1120', 'domainName': 'mhs', 'end': ''}, 'fota': {'fwupdater': {'end': ''}}, 'failover': {'supported': False, 'end': ''}, 'eventlog': {'end': 0}, 'ui': {'end': 0}}
6:00 PM components/netgear_lte.py (WARNING)
Error doing job: Task exception was never retrieved
6:00 PM components/sensor/netgear_lte.py (ERROR)
Invalid data: {'custom': {'end': 0}, 'webd': {'adminPassword': '****************', 'hideAdminPassword': True, 'end': ''}, 'lcd': {'end': ''}, 'sim': {'pin': {'end': ''}, 'puk': {}, 'mep': {}, 'end': ''}, 'sms': {'end': ''}, 'session': {'userRole': 'Guest', 'lang': 'en', 'secToken': '****'}, 'general': {'defaultLanguage': 'en', 'activated': True, 'TCAaccepted': True, 'verMajor': 1000, 'verMinor': 0, 'environment': 'Application', 'currTime': 1219971636, 'deviceName': 'LB1120', 'factoryResetStatus': 'NotStarted', 'setupCompleted': True, 'languageSelected': False, 'systemAlertList': {'list': [{}], 'count': 0}, 'apiVersion': '2.0', 'companyName': 'NETGEAR', 'configURL': '/Forms/config', 'profileURL': '/Forms/profile', 'pinChangeURL': '/Forms/pinChange', 'portCfgURL': '/Forms/portCfg', 'portFilterURL': '/Forms/portFilter', 'wifiACLURL': '/Forms/wifiACL', 'supportedLangList': [{'id': 'en', 'isCurrent': 'true', 'isDefault': 'true', 'label': 'English', 'token1': '/romfs/lcd/en_us.tr', 'token2': ''}, {'id': 'de_DE', 'isCurrent': 'false', 'isDefault': 'false', 'label': 'Deutsch (German)', 'token1': '/romfs/lcd/de_de.tr', 'token2': ''}, {'id': 'ar_AR', 'isCurrent': 'false', 'isDefault': 'false', 'label': 'العربية (Arabic)', 'token1': '/romfs/lcd/ar_AR.tr', 'token2': ''}, {'id': 'es_ES', 'isCurrent': 'false', 'isDefault': 'false', 'label': 'Español (Spanish)', 'token1': '/romfs/lcd/es_es.tr', 'token2': ''}, {'id': 'fr_FR', 'isCurrent': 'false', 'isDefault': 'false', 'label': 'Français (French)', 'token1': '/romfs/lcd/fr_fr.tr', 'token2': ''}, {'id': 'it_IT', 'isCurrent': 'false', 'isDefault': 'false', 'label': 'Italiano (Italian)', 'token1': '/romfs/lcd/it_it.tr', 'token2': ''}, {'id': 'pl_PL', 'isCurrent': 'false', 'isDefault': 'false', 'label': 'Polski (Polish)', 'token1': '/romfs/lcd/pl_pl.tr', 'token2': ''}, {'id': 'ru_RU', 'isCurrent': 'false', 'isDefault': 'false', 'label': 'Pусский (Russian)', 'token1': '/romfs/lcd/ru_ru.tr', 'token2': ''}, {'id': 'fi_FI', 'isCurrent': 'false', 'isDefault': 'false', 'label': 'Suomi (Finnish)', 'token1': '/romfs/lcd/fi_fi.tr', 'token2': ''}, {'id': 'sv_SE', 'isCurrent': 'false', 'isDefault': 'false', 'label': 'Svenska (Swedish)', 'token1': '/romfs/lcd/sv_se.tr', 'token2': ''}, {'id': 'tu_TU', 'isCurrent': 'false', 'isDefault': 'false', 'label': 'Türkçe (Turkish)', 'token1': '/romfs/lcd/tu_tu.tr', 'token2': ''}, {}]}, 'power': {'PMState': 'Init', 'SmState': 'Online', 'autoOff': {'onUSBdisconnect': {'end': ''}, 'onIdle': {'timer': {'end': ''}}}, 'standby': {'onIdle': {'timer': {'end': ''}}}, 'autoOn': {'end': ''}, 'resetRequired': 'NoResetRequired', 'lpm': False, 'end': ''}, 'wwanadv': {'end': ''}, 'wifi': {'wps': {'end': ''}, 'guest': {'DHCP': {'range': {'end': ''}}}, 'end': ''}, 'router': {'hostName': 'LB1120', 'domainName': 'mhs', 'end': ''}, 'fota': {'fwupdater': {'end': ''}}, 'failover': {'supported': False, 'end': ''}, 'eventlog': {'end': 0}, 'ui': {'end': 0}}
6:00 PM components/netgear_lte.py (WARNING)
Error doing job: Task exception was never retrieved
5:59 PM components/sensor/netgear_lte.py (ERROR)
amelchio commented 6 years ago

'session': {'userRole': 'Guest'

This is interesting. I get output like that when I use a wrong password so it seems like the session is lost. Does Home Assistant recover once it gets into this state?

sofar commented 6 years ago

nope. a restart of hass is needed to kick it beyond. Perhaps it's hanging on to the session token too long?

amelchio commented 6 years ago

Okay, power cycling the modem gives the KeyError so that's one way to reproduce this issue even if it is not how you got it.

I will add some error handling and reconnect logic to handle this situation.

amelchio commented 6 years ago

This should be fixed in Home Assistant 0.79 when it lands.