search

wpietri / sucks

Simple command-line script for the Ecovacs series of robot vacuums
GNU General Public License v3.0
281 stars 104 forks source link

sucks error handling #52

Open furlongm opened 6 years ago

furlongm commented 6 years ago

My N79s is malfunctioning according to app. Sucks previously worked correctly so I gave it a try. Looks like sucks doesn't handle errors? Using sucks 0.9.3

$ sucks clean 10
sleekxmpp.basexmpp WARNING  fulljid property deprecated. Use boundjid.resource
sleekxmpp.xmlstream.cert WARNING  Could not find pyasn1 and pyasn1_modules. SSL certificate COULD NOT BE VERIFIED.
sleekxmpp.xmlstream.cert WARNING  Could not find pyasn1 and pyasn1_modules. SSL certificate expiration COULD NOT BE VERIFIED.
performing clean command
waiting for 600.0s
sleekxmpp.xmlstream.xmlstream ERROR    Error processing stream handler: general
Traceback (most recent call last):
  File "/home/furlongm/src/sucks/lib/python3.6/site-packages/sleekxmpp/xmlstream/xmlstream.py", line 1686, in _event_runner
    handler.run(args[0])
  File "/home/furlongm/src/sucks/lib/python3.6/site-packages/sleekxmpp/xmlstream/handler/callback.py", line 76, in run
    self._pointer(payload)
  File "/home/furlongm/src/sucks/lib/python3.6/site-packages/sucks/__init__.py", line 458, in _handle_ctl
    s(as_dict)
  File "/home/furlongm/src/sucks/lib/python3.6/site-packages/sucks/__init__.py", line 289, in _handle_ctl
    getattr(self, method)(ctl)
  File "/home/furlongm/src/sucks/lib/python3.6/site-packages/sucks/__init__.py", line 292, in _handle_error
    error = event['error']
KeyError: 'error'
sleekxmpp.stanza.rootstanza ERROR    Error handling {jabber:client}iq stanza
Traceback (most recent call last):
  File "/home/furlongm/src/sucks/lib/python3.6/site-packages/sleekxmpp/xmlstream/xmlstream.py", line 1686, in _event_runner
    handler.run(args[0])
  File "/home/furlongm/src/sucks/lib/python3.6/site-packages/sleekxmpp/xmlstream/handler/callback.py", line 76, in run
    self._pointer(payload)
  File "/home/furlongm/src/sucks/lib/python3.6/site-packages/sucks/__init__.py", line 458, in _handle_ctl
    s(as_dict)
  File "/home/furlongm/src/sucks/lib/python3.6/site-packages/sucks/__init__.py", line 289, in _handle_ctl
    getattr(self, method)(ctl)
  File "/home/furlongm/src/sucks/lib/python3.6/site-packages/sucks/__init__.py", line 292, in _handle_error
    error = event['error']
KeyError: 'error'
wpietri commented 6 years ago

Hi, @furlongm! Thanks for reporting this. What would you like it to do in this situation?And could you re-run this with the --debug flag so we can see more detail?

furlongm commented 6 years ago

Maybe just catch the error? I've already performed a factory reset on my unit which solved the issue so can't offer any more debugging output, sorry!

wpietri commented 5 years ago

Ok. Looking at the code, it seems like this is making it to the error handler, but doesn't have the structure expected. If someone could collect actual examples of errors like this, that would be handy.

jgthornburgh commented 5 years ago 
2018-11-12 21:46:19 DEBUG (read_thread) [sleekxmpp.xmlstream.xmlstream] Event triggered: ssl_cert
2018-11-12 21:46:19 ERROR (read_thread) [sleekxmpp.basexmpp] day is out of range for month
Traceback (most recent call last):
  File "/usr/local/lib/python3.6/site-packages/sleekxmpp/xmlstream/xmlstream.py", line 1492, in _process
    if not self.__read_xml():
  File "/usr/local/lib/python3.6/site-packages/sleekxmpp/xmlstream/xmlstream.py", line 1564, in __read_xml
    self.__spawn_event(xml)
  File "/usr/local/lib/python3.6/site-packages/sleekxmpp/xmlstream/xmlstream.py", line 1632, in __spawn_event
    handler.prerun(stanza_copy)
  File "/usr/local/lib/python3.6/site-packages/sleekxmpp/xmlstream/handler/callback.py", line 64, in prerun
    self.run(payload, True)
  File "/usr/local/lib/python3.6/site-packages/sleekxmpp/xmlstream/handler/callback.py", line 76, in run
    self._pointer(payload)
  File "/usr/local/lib/python3.6/site-packages/sleekxmpp/features/feature_starttls/starttls.py", line 64, in _handle_starttls_proceed
    if self.xmpp.start_tls():
  File "/usr/local/lib/python3.6/site-packages/sleekxmpp/xmlstream/xmlstream.py", line 889, in start_tls
    cert.verify(self._expected_server_name, self._der_cert)
  File "/usr/local/lib/python3.6/site-packages/sleekxmpp/xmlstream/cert.py", line 133, in verify
    not_before, not_after = extract_dates(raw_cert)
  File "/usr/local/lib/python3.6/site-packages/sleekxmpp/xmlstream/cert.py", line 111, in extract_dates
    not_before = datetime.strptime(not_before, '%Y%m%d%H%M%SZ')
  File "/usr/local/lib/python3.6/_strptime.py", line 565, in _strptime_datetime
    tt, fraction = _strptime(data_string, format)
  File "/usr/local/lib/python3.6/_strptime.py", line 528, in _strptime
    datetime_date(year, 1, 1).toordinal() + 1
ValueError: day is out of range for month
2018-11-12 21:46:19 DEBUG (read_thread) [sleekxmpp.xmlstream.xmlstream] reconnecting...
2018-11-12 21:46:19 DEBUG (read_thread) [sleekxmpp.xmlstream.xmlstream] Event triggered: session_end
2018-11-12 21:46:19 DEBUG (read_thread) [sleekxmpp.xmlstream.xmlstream] SEND (IMMED): </stream:stream>
2018-11-12 21:46:19 INFO (read_thread) [sleekxmpp.xmlstream.xmlstream] Waiting for </stream:stream> from server

2018-11-12 21:46:23 DEBUG (read_thread) [sleekxmpp.xmlstream.xmlstream] Event triggered: disconnected
2018-11-12 21:46:23 DEBUG (read_thread) [sleekxmpp.thirdparty.statemachine]  ==== TRANSITION connected -> disconnected
2018-11-12 21:46:23 DEBUG (read_thread) [sleekxmpp.xmlstream.xmlstream] connecting...
2018-11-12 21:46:23 DEBUG (read_thread) [sleekxmpp.xmlstream.xmlstream] Waiting 2.0516701351823814 seconds before connecting.
2018-11-12 21:46:26 DEBUG (read_thread) [sleekxmpp.xmlstream.xmlstream] No remaining DNS records to try.
2018-11-12 21:46:26 DEBUG (read_thread) [sleekxmpp.xmlstream.xmlstream] Waiting 3.731988809865896 seconds before connecting.
wpietri commented 5 years ago

I think, @jgthornburgh, you want #45 instead.

retikulumx commented 5 years ago 
xxx@raspi:~$ sucks clean 5
sleekxmpp.basexmpp WARNING  fulljid property deprecated. Use boundjid.resource
sleekxmpp.xmlstream.cert WARNING  Could not find pyasn1 and pyasn1_modules. SSL certificate COULD NOT BE VERIFIED.
sleekxmpp.xmlstream.cert WARNING  Could not find pyasn1 and pyasn1_modules. SSL certificate expiration COULD NOT BE VERIFIED.
performing clean command
sleekxmpp.xmlstream.handler.waiter WARNING  Timed out waiting for IqWait_04cac719-e372-45d1-ade2-323acfef9e6f-3
Traceback (most recent call last):
  File "/home/xxx/.local/bin/sucks", line 10, in <module>
    sys.exit(cli())
  File "/home/xxx/.local/lib/python3.7/site-packages/click/core.py", line 764, in __call__
    return self.main(*args, **kwargs)
  File "/home/xxx/.local/lib/python3.7/site-packages/click/core.py", line 717, in main
    rv = self.invoke(ctx)
  File "/home/xxx/.local/lib/python3.7/site-packages/click/core.py", line 1164, in invoke
    return _process_result(rv)
  File "/home/xxx/.local/lib/python3.7/site-packages/click/core.py", line 1102, in _process_result
    **ctx.params)
  File "/home/xxx/.local/lib/python3.7/site-packages/click/core.py", line 555, in invoke
    return callback(*args, **kwargs)
  File "/home/xxx/.local/lib/python3.7/site-packages/sucks/cli.py", line 219, in run
    vacbot.run(action.vac_command)
  File "/home/xxx/.local/lib/python3.7/site-packages/sucks/__init__.py", line 416, in run
    self.send_command(action.to_xml())
  File "/home/xxx/.local/lib/python3.7/site-packages/sucks/__init__.py", line 413, in send_command
    self.xmpp.send_command(xml, self._vacuum_address())
  File "/home/xxx/.local/lib/python3.7/site-packages/sucks/__init__.py", line 482, in send_command
    c.send()
  File "/home/xxx/.local/lib/python3.7/site-packages/sleekxmpp/stanza/iq.py", line 233, in send
    raise IqTimeout(self)
sleekxmpp.exceptions.IqTimeout: <iq id="04cac719-e372-45d1-ade2-323acfef9e6f-3" to="E0000997018609472545@123.ecorobot.net/atom" from="darljsjdfce87a1c@ecouser.net/ae074a7eb5c3cc9526af0783cf87a18a" type="set"><query xmlns="com:ctl"><ctl td="Clean"><clean type="auto" speed="standard" /></ctl></query></iq>
wpietri commented 5 years ago

I take it, @retikulumx, you're suggesting this error message could be better. Could you say what's actuall going on here?

retikulumx commented 5 years ago

Yeah, this error message tells us, that pyasn1 and pyasn1_modules are missing and SSL certificates couldn't be verified because of that. Stupid: Installing those modules leads to the next problem: Some certificate/s is/are outdated and this is a blocker for sucks. I didn't have time yet to inspect it further (which certificate is actually outdated/self signed)...

chennin commented 4 years ago

Ok. Looking at the code, it seems like this is making it to the error handler, but doesn't have the structure expected. If someone could collect actual examples of errors like this, that would be handy.

To try to get back to the original error, is this (the first line) what you are looking for?

2020-01-03 19:29:30 DEBUG (read_thread) [sleekxmppfs.xmlstream.xmlstream] RECV: <iq to="xxxx@ecouser.net/xxxx" type="set" id="5797" from="xxxx@126.ecorobot.net/atom"><query xmlns="com:ctl"><ctl td="error" errno="111" /></query></iq>
2020-01-03 19:29:30 ERROR (event_thread_0) [sleekxmppfs.xmlstream.xmlstream] Error processing stream handler: general
Traceback (most recent call last):
  File "/home/hass/venv-20191214/lib/python3.7/site-packages/sleekxmppfs/xmlstream/xmlstream.py", line 1686, in _event_runner
    handler.run(args[0])
  File "/home/hass/venv-20191214/lib/python3.7/site-packages/sleekxmppfs/xmlstream/handler/callback.py", line 76, in run
    self._pointer(payload)
  File "/home/hass/venv-20191214/lib/python3.7/site-packages/sucks/__init__.py", line 458, in _handle_ctl
    s(as_dict)
  File "/home/hass/venv-20191214/lib/python3.7/site-packages/sucks/__init__.py", line 289, in _handle_ctl
    getattr(self, method)(ctl)
  File "/home/hass/venv-20191214/lib/python3.7/site-packages/sucks/__init__.py", line 292, in _handle_error
    error = event['error']
KeyError: 'error'
2020-01-03 19:29:30 ERROR (event_thread_0) [sleekxmppfs.stanza.rootstanza] Error handling {jabber:client}iq stanza
Traceback (most recent call last):
  File "/home/hass/venv-20191214/lib/python3.7/site-packages/sleekxmppfs/xmlstream/xmlstream.py", line 1686, in _event_runner
    handler.run(args[0])
  File "/home/hass/venv-20191214/lib/python3.7/site-packages/sleekxmppfs/xmlstream/handler/callback.py", line 76, in run
    self._pointer(payload)
  File "/home/hass/venv-20191214/lib/python3.7/site-packages/sucks/__init__.py", line 458, in _handle_ctl
    s(as_dict)
  File "/home/hass/venv-20191214/lib/python3.7/site-packages/sucks/__init__.py", line 289, in _handle_ctl
    getattr(self, method)(ctl)
  File "/home/hass/venv-20191214/lib/python3.7/site-packages/sucks/__init__.py", line 292, in _handle_error
    error = event['error']
KeyError: 'error'
2020-01-03 19:29:30 DEBUG (send_thread) [sleekxmppfs.xmlstream.xmlstream] SEND: <iq to="xxxx@126.ecorobot.net/atom" type="error" id="5797"><error type="cancel"><undefined-condition xmlns="urn:ietf:params:xml:ns:xmpp-stanzas" /><text xmlns="urn:ietf:params:xml:ns:xmpp-stanzas">SleekXMPP got into trouble.</text></error></iq>
2020-01-03 19:29:30 ERROR (event_thread_0) [sleekxmppfs.basexmpp] 'error'
Traceback (most recent call last):
  File "/home/hass/venv-20191214/lib/python3.7/site-packages/sleekxmppfs/xmlstream/xmlstream.py", line 1686, in _event_runner
    handler.run(args[0])
  File "/home/hass/venv-20191214/lib/python3.7/site-packages/sleekxmppfs/xmlstream/handler/callback.py", line 76, in run
    self._pointer(payload)
  File "/home/hass/venv-20191214/lib/python3.7/site-packages/sucks/__init__.py", line 458, in _handle_ctl
    s(as_dict)
  File "/home/hass/venv-20191214/lib/python3.7/site-packages/sucks/__init__.py", line 289, in _handle_ctl
    getattr(self, method)(ctl)
  File "/home/hass/venv-20191214/lib/python3.7/site-packages/sucks/__init__.py", line 292, in _handle_error
    error = event['error']
KeyError: 'error'
2020-01-03 19:29:30 DEBUG (read_thread) [sleekxmppfs.xmlstream.xmlstream] RECV: <iq to="xxxx@ecouser.net/xxxx" type="set" id="5798" from="xxxx@126.ecorobot.net/atom"><query xmlns="com:ctl"><ctl td="CleanReport"><clean type="stop" /></ctl></query></iq>
2020-01-03 19:29:30 DEBUG (event_thread_0) [sucks] *** clean_status = stop fan_speed = None

DEEBOT N79, sucks==0.9.4, Python 3.7.5 virtual env, Ubuntu 18.04, via Home Assistant, and I've set the following components to debug logging: homeassistant.components.vacuum.ecovacs, sucks, sleekxmppfs.stanza.rootstanza, sleekxmppfs.xmlstream.xmlstream, sleekxmppfs.basexmpp