search

home-assistant / core

:house_with_garden: Open source home automation that puts local control and privacy first.
https://www.home-assistant.io
Apache License 2.0
69.83k stars 28.95k forks source link

Xbee AttributeError: 'XBee' object has no attribute '_handle_many_to_one_rri' #22111

Closed StyxyDog closed 5 years ago

StyxyDog commented 5 years ago

Home Assistant release with the issue:

0.89.2

Last working Home Assistant release (if known):

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

Hass.io Component/platform:

zha

Description of problem: I've been using the conbee, but thought I'd have another go at getting the xbee working. Things must have moved on in zha development because it added first time. I've had some success adding my devices, but they are not reliable. Even if a device is added it is not very responsive, some devices are. I'm seeing an error.

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

Traceback (if applicable):

2019-03-16 12:57:54 ERROR (MainThread) [homeassistant.core] Error doing job: Exception in callback <bound method SerialTransport._read_ready of SerialTransport(<uvloop.Loop running=True closed=False debug=False>, <zigpy_xbee.uart.Gateway object at 0x6e222910>, Serial<id=0x6e222890, open=True>(port='/dev/ttyUSB0', baudrate=57600, bytesize=8, parity='N', stopbits=1, timeout=0, xonxoff=False, rtscts=False, dsrdtr=False))>
Traceback (most recent call last):
  File "uvloop/cbhandles.pyx", line 62, in uvloop.loop.Handle._run
  File "/usr/local/lib/python3.7/site-packages/serial_asyncio/__init__.py", line 106, in _read_ready
    self._protocol.data_received(data)
  File "/config/deps/lib/python3.7/site-packages/zigpy_xbee/uart.py", line 74, in data_received
    self.frame_received(frame)
  File "/config/deps/lib/python3.7/site-packages/zigpy_xbee/uart.py", line 82, in frame_received
    self._api.frame_received(frame)
  File "/config/deps/lib/python3.7/site-packages/zigpy_xbee/api.py", line 264, in frame_received
    getattr(self, '_handle_%s' % (command, ))(data)
AttributeError: 'XBee' object has no attribute '_handle_many_to_one_rri'

Additional information:

Adminiuga commented 5 years ago

What XBee module HW version are you using? What firmware version are you using?

I'm wondering what made all these new frames to appear, as route indicator or handle_many_to_on_rri handlers were not in the original code

Adminiuga commented 5 years ago

Can you also please enable debug level for zigpy_xbee: debug component and post the logs here. I'd like to see what UART is sending for those frames.

StyxyDog commented 5 years ago

Hi @Adminiuga I'll try to get you the firmware version and other information later today. I removed the existing zha (conbee) integration, restarted ha, then re added the integration this time choosing the xbee option. I've been through the same process again, but I'm getting similar results. I wonder if some sort of configuration is being retained when removing and reconfiguring? I'm going to try a clean install on another device and see if I can reproduce the errors. Not sure if this is useful...

2019-03-17 10:47:46 DEBUG (MainThread) [zigpy_xbee.zigbee.application] Zigbee request seq 22
2019-03-17 10:47:46 DEBUG (MainThread) [zigpy_xbee.api] Sequenced command: tx_explicit (00:1e:5e:09:02:2b:79:f8, 49767, 9, 9, 6, 260, 0, 32, b'\x01\x16\x01')
2019-03-17 10:47:46 DEBUG (MainThread) [zigpy_xbee.api] Command tx_explicit (38, 00:1e:5e:09:02:2b:79:f8, 49767, 9, 9, 6, 260, 0, 32, b'\x01\x16\x01')
2019-03-17 10:47:49 DEBUG (MainThread) [zigpy_xbee.zigbee.application] Zigbee request seq 23
2019-03-17 10:47:49 DEBUG (MainThread) [zigpy_xbee.api] Sequenced command: tx_explicit (00:1e:5e:09:02:2b:79:f8, 49767, 9, 9, 6, 260, 0, 32, b'\x01\x17\x00')
2019-03-17 10:47:49 DEBUG (MainThread) [zigpy_xbee.api] Command tx_explicit (39, 00:1e:5e:09:02:2b:79:f8, 49767, 9, 9, 6, 260, 0, 32, b'\x01\x17\x00')
2019-03-17 10:47:51 DEBUG (MainThread) [zigpy_xbee.uart] Frame received: b'\x8b&\xff\xfd\x00$\x02'
2019-03-17 10:47:51 DEBUG (MainThread) [zigpy_xbee.api] Frame received: tx_status
2019-03-17 10:47:51 DEBUG (MainThread) [zigpy_xbee.api] tx_status: [38, 65533, 0, 36, 2]
2019-03-17 10:47:52 DEBUG (MainThread) [zigpy_xbee.uart] Frame received: b'\x91\x00\x1e^\t\x02+y\xf8~\xed\t\t\x00\x06\x01\x04!\x08\x17\x0b\x00\x00'
2019-03-17 10:47:52 DEBUG (MainThread) [zigpy_xbee.api] Frame received: explicit_rx_indicator
2019-03-17 10:47:52 DEBUG (MainThread) [zigpy_xbee.api] _handle_explicit_rx: opts=33
2019-03-17 10:47:52 DEBUG (MainThread) [zigpy_xbee.uart] Frame received: b"\x8b'~\xed\x00\x00\x00"
2019-03-17 10:47:52 DEBUG (MainThread) [zigpy_xbee.api] Frame received: tx_status
2019-03-17 10:47:52 DEBUG (MainThread) [zigpy_xbee.api] tx_status: [39, 32493, 0, 0, 0]
2019-03-17 10:47:55 DEBUG (MainThread) [zigpy_xbee.uart] Frame received: b'\xa3\x00\x1e^\t\x02+y\xf8~\xed\x00'
2019-03-17 10:47:55 DEBUG (MainThread) [zigpy_xbee.api] Frame received: many_to_one_rri
2019-03-17 10:47:55 ERROR (MainThread) [homeassistant.core] Error doing job: Exception in callback <bound method SerialTransport._read_ready of SerialTransport(<uvloop.Loop running=True closed=False debug=False>, <zigpy_xbee.uart.Gateway object at 0x70d7ceb0>, Serial<id=0x70d7ced0, open=True>(port='/dev/ttyUSB0', baudrate=57600, bytesize=8, parity='N', stopbits=1, timeout=0, xonxoff=False, rtscts=False, dsrdtr=False))>
Traceback (most recent call last):
  File "uvloop/cbhandles.pyx", line 62, in uvloop.loop.Handle._run
  File "/usr/local/lib/python3.7/site-packages/serial_asyncio/__init__.py", line 106, in _read_ready
    self._protocol.data_received(data)
  File "/config/deps/lib/python3.7/site-packages/zigpy_xbee/uart.py", line 74, in data_received
    self.frame_received(frame)
  File "/config/deps/lib/python3.7/site-packages/zigpy_xbee/uart.py", line 82, in frame_received
    self._api.frame_received(frame)
  File "/config/deps/lib/python3.7/site-packages/zigpy_xbee/api.py", line 264, in frame_received
    getattr(self, '_handle_%s' % (command, ))(data)
AttributeError: 'XBee' object has no attribute '_handle_many_to_one_rri'
StyxyDog commented 5 years ago

I'm using and xbee s2c (as labelled on device). Here is a screen shot of the device config... xbee

StyxyDog commented 5 years ago

A little more information. Fresh install on a different pi (same xbee). Just configured zha and added 1 device. Same error here is log from start

2019-03-17 11:52:43 INFO (MainThread) [homeassistant.setup] Setup of domain logger took 0.0 seconds.
2019-03-17 11:52:43 INFO (MainThread) [homeassistant.setup] Setting up http
2019-03-17 11:52:43 INFO (MainThread) [homeassistant.setup] Setup of domain http took 0.1 seconds.
2019-03-17 11:52:43 INFO (MainThread) [homeassistant.setup] Setting up lovelace
2019-03-17 11:52:43 INFO (MainThread) [homeassistant.setup] Setup of domain lovelace took 0.0 seconds.
2019-03-17 11:52:43 INFO (MainThread) [homeassistant.setup] Setting up system_log
2019-03-17 11:52:43 INFO (MainThread) [homeassistant.setup] Setup of domain system_log took 0.0 seconds.
2019-03-17 11:52:43 INFO (MainThread) [homeassistant.setup] Setting up api
2019-03-17 11:52:43 INFO (MainThread) [homeassistant.setup] Setting up websocket_api
2019-03-17 11:52:43 INFO (MainThread) [homeassistant.setup] Setup of domain websocket_api took 0.0 seconds.
2019-03-17 11:52:43 INFO (MainThread) [homeassistant.setup] Setting up auth
2019-03-17 11:52:43 INFO (MainThread) [homeassistant.setup] Setup of domain auth took 0.0 seconds.
2019-03-17 11:52:43 INFO (MainThread) [homeassistant.setup] Setting up onboarding
2019-03-17 11:52:43 INFO (MainThread) [homeassistant.setup] Setup of domain api took 0.1 seconds.
2019-03-17 11:52:43 INFO (MainThread) [homeassistant.setup] Setup of domain onboarding took 0.0 seconds.
2019-03-17 11:52:43 INFO (MainThread) [homeassistant.setup] Setting up frontend
2019-03-17 11:52:46 INFO (MainThread) [homeassistant.setup] Setup of domain frontend took 2.5 seconds.
2019-03-17 11:52:46 INFO (MainThread) [homeassistant.setup] Setup of domain recorder took 3.3 seconds.
2019-03-17 11:52:46 INFO (MainThread) [homeassistant.setup] Setting up history
2019-03-17 11:52:46 INFO (MainThread) [homeassistant.setup] Setup of domain history took 0.0 seconds.
2019-03-17 11:52:46 INFO (MainThread) [homeassistant.loader] Loaded sensor.yr from homeassistant.components.sensor.yr
2019-03-17 11:52:46 INFO (MainThread) [homeassistant.setup] Setting up sensor
2019-03-17 11:52:46 INFO (MainThread) [homeassistant.loader] Loaded google from homeassistant.components.google
2019-03-17 11:52:46 INFO (MainThread) [homeassistant.loader] Loaded google.tts from homeassistant.components.google.tts
2019-03-17 11:52:46 INFO (MainThread) [homeassistant.setup] Setting up zha
2019-03-17 11:52:46 INFO (MainThread) [homeassistant.setup] Setup of domain zha took 0.0 seconds.
2019-03-17 11:52:47 INFO (MainThread) [homeassistant.setup] Setting up discovery
2019-03-17 11:52:47 INFO (MainThread) [homeassistant.setup] Setup of domain discovery took 0.1 seconds.
2019-03-17 11:52:47 INFO (MainThread) [homeassistant.setup] Setting up map
2019-03-17 11:52:47 INFO (MainThread) [homeassistant.setup] Setup of domain map took 0.0 seconds.
2019-03-17 11:52:47 INFO (MainThread) [homeassistant.setup] Setting up zone
2019-03-17 11:52:47 INFO (MainThread) [homeassistant.setup] Setup of domain zone took 0.0 seconds.
2019-03-17 11:52:47 INFO (MainThread) [homeassistant.setup] Setting up sun
2019-03-17 11:52:47 INFO (MainThread) [homeassistant.setup] Setup of domain sun took 0.1 seconds.
2019-03-17 11:52:47 INFO (MainThread) [homeassistant.setup] Setting up person
2019-03-17 11:52:47 INFO (MainThread) [homeassistant.setup] Setting up group
2019-03-17 11:52:47 INFO (MainThread) [homeassistant.setup] Setup of domain group took 0.0 seconds.
2019-03-17 11:52:47 INFO (MainThread) [homeassistant.setup] Setting up updater
2019-03-17 11:52:47 INFO (MainThread) [homeassistant.setup] Setup of domain updater took 0.0 seconds.
2019-03-17 11:52:47 INFO (MainThread) [homeassistant.components.sensor] Setting up sensor.yr
2019-03-17 11:52:47 DEBUG (MainThread) [zigpy_xbee.uart] Connection made
2019-03-17 11:52:47 DEBUG (MainThread) [zigpy_xbee.api] AT command: AP (2,)
2019-03-17 11:52:47 DEBUG (MainThread) [zigpy_xbee.api] Command at (1, b'AP', b'\x02')
2019-03-17 11:52:47 INFO (MainThread) [homeassistant.setup] Setting up device_tracker
2019-03-17 11:52:47 INFO (MainThread) [homeassistant.setup] Setting up conversation
2019-03-17 11:52:47 INFO (MainThread) [homeassistant.setup] Setup of domain conversation took 0.0 seconds.
2019-03-17 11:52:47 INFO (MainThread) [homeassistant.setup] Setting up webhook
2019-03-17 11:52:47 INFO (MainThread) [homeassistant.setup] Setup of domain webhook took 0.0 seconds.
2019-03-17 11:52:47 INFO (MainThread) [homeassistant.setup] Setting up system_health
2019-03-17 11:52:47 INFO (MainThread) [homeassistant.setup] Setup of domain system_health took 0.0 seconds.
2019-03-17 11:52:47 INFO (MainThread) [homeassistant.setup] Setting up automation
2019-03-17 11:52:47 INFO (MainThread) [homeassistant.setup] Setup of domain automation took 0.0 seconds.
2019-03-17 11:52:47 INFO (MainThread) [homeassistant.setup] Setting up tts
2019-03-17 11:52:47 INFO (MainThread) [homeassistant.setup] Setting up script
2019-03-17 11:52:47 INFO (MainThread) [homeassistant.setup] Setup of domain script took 0.0 seconds.
2019-03-17 11:52:47 INFO (MainThread) [homeassistant.setup] Setting up config
2019-03-17 11:52:47 INFO (MainThread) [homeassistant.setup] Setting up cloud
2019-03-17 11:52:47 INFO (MainThread) [homeassistant.setup] Setup of domain cloud took 0.0 seconds.
2019-03-17 11:52:47 INFO (MainThread) [homeassistant.setup] Setting up logbook
2019-03-17 11:52:47 INFO (MainThread) [homeassistant.setup] Setup of domain logbook took 0.0 seconds.
2019-03-17 11:52:47 DEBUG (MainThread) [zigpy_xbee.uart] Frame received: b'\x88\x01AP\x00'
2019-03-17 11:52:47 DEBUG (MainThread) [zigpy_xbee.api] Frame received: at_response
2019-03-17 11:52:47 INFO (MainThread) [homeassistant.loader] Loaded config.area_registry from homeassistant.components.config.area_registry
2019-03-17 11:52:47 INFO (MainThread) [homeassistant.loader] Loaded config.script from homeassistant.components.config.script
2019-03-17 11:52:47 INFO (MainThread) [homeassistant.loader] Loaded config.core from homeassistant.components.config.core
2019-03-17 11:52:47 INFO (MainThread) [homeassistant.loader] Loaded config.customize from homeassistant.components.config.customize
2019-03-17 11:52:47 INFO (MainThread) [homeassistant.loader] Loaded config.device_registry from homeassistant.components.config.device_registry
2019-03-17 11:52:47 INFO (MainThread) [homeassistant.loader] Loaded config.entity_registry from homeassistant.components.config.entity_registry
2019-03-17 11:52:47 INFO (MainThread) [homeassistant.loader] Loaded config.auth from homeassistant.components.config.auth
2019-03-17 11:52:47 INFO (MainThread) [homeassistant.loader] Loaded config.auth_provider_homeassistant from homeassistant.components.config.auth_provider_homeassistant
2019-03-17 11:52:47 INFO (MainThread) [homeassistant.loader] Loaded config.group from homeassistant.components.config.group
2019-03-17 11:52:47 INFO (MainThread) [homeassistant.loader] Loaded config.hassbian from homeassistant.components.config.hassbian
2019-03-17 11:52:47 INFO (MainThread) [homeassistant.loader] Loaded config.automation from homeassistant.components.config.automation
2019-03-17 11:52:47 INFO (MainThread) [homeassistant.loader] Loaded config.config_entries from homeassistant.components.config.config_entries
2019-03-17 11:52:47 ERROR (MainThread) [homeassistant.components.device_tracker] Unable to load /config/known_devices.yaml: Config file not found: /config/known_devices.yaml
2019-03-17 11:52:47 INFO (MainThread) [homeassistant.setup] Setup of domain device_tracker took 0.3 seconds.
2019-03-17 11:52:47 DEBUG (MainThread) [zigpy_xbee.api] AT command: AO (3,)
2019-03-17 11:52:47 DEBUG (MainThread) [zigpy_xbee.api] Command at (2, b'AO', b'\x03')
2019-03-17 11:52:47 DEBUG (MainThread) [zigpy_xbee.uart] Frame received: b'\x88\x02AO\x00'
2019-03-17 11:52:47 DEBUG (MainThread) [zigpy_xbee.api] Frame received: at_response
2019-03-17 11:52:47 INFO (MainThread) [homeassistant.setup] Setting up mobile_app
2019-03-17 11:52:47 INFO (MainThread) [homeassistant.setup] Setup of domain config took 0.2 seconds.
2019-03-17 11:52:47 DEBUG (MainThread) [zigpy_xbee.api] AT command: SH ()
2019-03-17 11:52:47 DEBUG (MainThread) [zigpy_xbee.api] Command at (3, b'SH', b'')
2019-03-17 11:52:47 INFO (MainThread) [homeassistant.setup] Setup of domain tts took 0.3 seconds.
2019-03-17 11:52:47 INFO (MainThread) [homeassistant.setup] Setup of domain mobile_app took 0.0 seconds.
2019-03-17 11:52:47 INFO (MainThread) [homeassistant.setup] Setup of domain person took 0.5 seconds.
2019-03-17 11:52:47 DEBUG (MainThread) [zigpy_xbee.uart] Frame received: b'\x88\x03SH\x00\x00\x13\xa2\x00'
2019-03-17 11:52:47 DEBUG (MainThread) [zigpy_xbee.api] Frame received: at_response
2019-03-17 11:52:47 INFO (MainThread) [homeassistant.setup] Setting up default_config
2019-03-17 11:52:47 INFO (MainThread) [homeassistant.setup] Setup of domain default_config took 0.0 seconds.
2019-03-17 11:52:47 DEBUG (MainThread) [zigpy_xbee.api] AT command: SL ()
2019-03-17 11:52:47 DEBUG (MainThread) [zigpy_xbee.api] Command at (4, b'SL', b'')
2019-03-17 11:52:47 DEBUG (MainThread) [zigpy_xbee.uart] Frame received: b'\x88\x04SL\x00AO<\x11'
2019-03-17 11:52:47 DEBUG (MainThread) [zigpy_xbee.api] Frame received: at_response
2019-03-17 11:52:47 DEBUG (MainThread) [zigpy_xbee.zigbee.application] Read local IEEE address as 00:13:a2:00:41:4f:3c:11
2019-03-17 11:52:47 DEBUG (MainThread) [zigpy_xbee.api] AT command: AI ()
2019-03-17 11:52:47 DEBUG (MainThread) [zigpy_xbee.api] Command at (5, b'AI', b'')
2019-03-17 11:52:47 DEBUG (MainThread) [zigpy_xbee.uart] Frame received: b'\x88\x05AI\x00\x00'
2019-03-17 11:52:47 DEBUG (MainThread) [zigpy_xbee.api] Frame received: at_response
2019-03-17 11:52:47 DEBUG (MainThread) [zigpy_xbee.api] AT command: MY ()
2019-03-17 11:52:47 DEBUG (MainThread) [zigpy_xbee.api] Command at (6, b'MY', b'')
2019-03-17 11:52:47 DEBUG (MainThread) [zigpy_xbee.uart] Frame received: b'\x88\x06MY\x00\x00\x00'
2019-03-17 11:52:47 DEBUG (MainThread) [zigpy_xbee.api] Frame received: at_response
2019-03-17 11:52:47 DEBUG (MainThread) [zigpy_xbee.api] AT command: EE ()
2019-03-17 11:52:47 DEBUG (MainThread) [zigpy_xbee.api] Command at (7, b'EE', b'')
2019-03-17 11:52:47 DEBUG (MainThread) [zigpy_xbee.uart] Frame received: b'\x88\x07EE\x00\x01'
2019-03-17 11:52:47 DEBUG (MainThread) [zigpy_xbee.api] Frame received: at_response
2019-03-17 11:52:47 DEBUG (MainThread) [zigpy_xbee.api] AT command: EO ()
2019-03-17 11:52:47 DEBUG (MainThread) [zigpy_xbee.api] Command at (8, b'EO', b'')
2019-03-17 11:52:47 DEBUG (MainThread) [zigpy_xbee.uart] Frame received: b'\x88\x08EO\x00\x02'
2019-03-17 11:52:47 DEBUG (MainThread) [zigpy_xbee.api] Frame received: at_response
2019-03-17 11:52:47 DEBUG (MainThread) [zigpy_xbee.api] AT command: ZS ()
2019-03-17 11:52:47 DEBUG (MainThread) [zigpy_xbee.api] Command at (9, b'ZS', b'')
2019-03-17 11:52:47 DEBUG (MainThread) [zigpy_xbee.uart] Frame received: b'\x88\tZS\x00\x02'
2019-03-17 11:52:47 DEBUG (MainThread) [zigpy_xbee.api] Frame received: at_response
2019-03-17 11:52:47 DEBUG (MainThread) [zigpy_xbee.api] AT command: NJ (0,)
2019-03-17 11:52:47 DEBUG (MainThread) [zigpy_xbee.api] Command at (10, b'NJ', b'\x00')
2019-03-17 11:52:47 DEBUG (MainThread) [zigpy_xbee.uart] Frame received: b'\x88\nNJ\x00'
2019-03-17 11:52:47 DEBUG (MainThread) [zigpy_xbee.api] Frame received: at_response
2019-03-17 11:52:47 DEBUG (MainThread) [zigpy_xbee.api] AT command: SP (768,)
2019-03-17 11:52:47 DEBUG (MainThread) [zigpy_xbee.api] Command at (11, b'SP', b'\x03\x00')
2019-03-17 11:52:47 DEBUG (MainThread) [zigpy_xbee.uart] Frame received: b'\x88\x0bSP\x00'
2019-03-17 11:52:47 DEBUG (MainThread) [zigpy_xbee.api] Frame received: at_response
2019-03-17 11:52:47 DEBUG (MainThread) [zigpy_xbee.api] AT command: SN (667,)
2019-03-17 11:52:47 DEBUG (MainThread) [zigpy_xbee.api] Command at (12, b'SN', b'\x02\x9b')
2019-03-17 11:52:47 DEBUG (MainThread) [zigpy_xbee.uart] Frame received: b'\x88\x0cSN\x00'
2019-03-17 11:52:47 DEBUG (MainThread) [zigpy_xbee.api] Frame received: at_response
2019-03-17 11:52:47 DEBUG (MainThread) [zigpy_xbee.api] AT command: ID ()
2019-03-17 11:52:47 DEBUG (MainThread) [zigpy_xbee.api] Command at (13, b'ID', b'')
2019-03-17 11:52:47 DEBUG (MainThread) [zigpy_xbee.uart] Frame received: b'\x88\rID\x00\x00\x00\x00\x00\x00\x00\x00\x00'
2019-03-17 11:52:47 DEBUG (MainThread) [zigpy_xbee.api] Frame received: at_response
2019-03-17 11:52:47 DEBUG (MainThread) [zigpy_xbee.zigbee.application] Extended PAN ID: 0x0000000000000000
2019-03-17 11:52:47 DEBUG (MainThread) [zigpy_xbee.api] AT command: OP ()
2019-03-17 11:52:47 DEBUG (MainThread) [zigpy_xbee.api] Command at (14, b'OP', b'')
2019-03-17 11:52:47 DEBUG (MainThread) [zigpy_xbee.uart] Frame received: b'\x88\x0eOP\x00\x11\x1a\x1d\xc9\xa8c\xca\x18'
2019-03-17 11:52:47 DEBUG (MainThread) [zigpy_xbee.api] Frame received: at_response
2019-03-17 11:52:47 DEBUG (MainThread) [zigpy_xbee.zigbee.application] Operating Extended PAN ID: 0x111a1dc9a863ca18
2019-03-17 11:52:47 DEBUG (MainThread) [zigpy_xbee.api] AT command: OI ()
2019-03-17 11:52:47 DEBUG (MainThread) [zigpy_xbee.api] Command at (15, b'OI', b'')
2019-03-17 11:52:47 DEBUG (MainThread) [zigpy_xbee.uart] Frame received: b'\x88\x0fOI\x00y0'
2019-03-17 11:52:47 DEBUG (MainThread) [zigpy_xbee.api] Frame received: at_response
2019-03-17 11:52:47 DEBUG (MainThread) [zigpy_xbee.zigbee.application] PAN ID: 0x7930
2019-03-17 11:52:47 DEBUG (MainThread) [zigpy_xbee.api] AT command: CE ()
2019-03-17 11:52:47 DEBUG (MainThread) [zigpy_xbee.api] Command at (16, b'CE', b'')
2019-03-17 11:52:47 DEBUG (MainThread) [zigpy_xbee.uart] Frame received: b'\x88\x10CE\x00\x01'
2019-03-17 11:52:47 DEBUG (MainThread) [zigpy_xbee.api] Frame received: at_response
2019-03-17 11:52:48 DEBUG (MainThread) [zigpy_xbee.zigbee.application] Coordinator enabled
2019-03-17 11:52:48 INFO (MainThread) [homeassistant.loader] Loaded binary_sensor from homeassistant.components.binary_sensor
2019-03-17 11:52:48 INFO (MainThread) [homeassistant.setup] Setting up binary_sensor
2019-03-17 11:52:48 INFO (MainThread) [homeassistant.setup] Setup of domain binary_sensor took 0.0 seconds.
2019-03-17 11:52:48 INFO (MainThread) [homeassistant.loader] Loaded fan from homeassistant.components.fan
2019-03-17 11:52:48 INFO (MainThread) [homeassistant.loader] Loaded light from homeassistant.components.light
2019-03-17 11:52:48 INFO (MainThread) [homeassistant.loader] Loaded switch from homeassistant.components.switch
2019-03-17 11:52:48 INFO (MainThread) [homeassistant.loader] Loaded zha.binary_sensor from homeassistant.components.zha.binary_sensor
2019-03-17 11:52:48 INFO (MainThread) [homeassistant.setup] Setting up fan
2019-03-17 11:52:48 INFO (MainThread) [homeassistant.setup] Setup of domain fan took 0.0 seconds.
2019-03-17 11:52:48 INFO (MainThread) [homeassistant.setup] Setting up light
2019-03-17 11:52:48 INFO (MainThread) [homeassistant.setup] Setting up switch
2019-03-17 11:52:48 INFO (MainThread) [homeassistant.setup] Setup of domain switch took 0.0 seconds.
2019-03-17 11:52:48 INFO (MainThread) [homeassistant.components.binary_sensor] Setting up binary_sensor.zha
2019-03-17 11:52:48 INFO (MainThread) [homeassistant.loader] Loaded zha.fan from homeassistant.components.zha.fan
2019-03-17 11:52:48 INFO (MainThread) [homeassistant.loader] Loaded zha.switch from homeassistant.components.zha.switch
2019-03-17 11:52:48 INFO (MainThread) [homeassistant.setup] Setup of domain light took 0.0 seconds.
2019-03-17 11:52:48 INFO (MainThread) [homeassistant.loader] Loaded zha.light from homeassistant.components.zha.light
2019-03-17 11:52:48 INFO (MainThread) [homeassistant.components.fan] Setting up fan.zha
2019-03-17 11:52:48 INFO (MainThread) [homeassistant.components.switch] Setting up switch.zha
2019-03-17 11:52:48 INFO (MainThread) [homeassistant.components.light] Setting up light.zha
2019-03-17 11:52:48 INFO (MainThread) [homeassistant.setup] Setup of domain sensor took 2.0 seconds.
2019-03-17 11:52:48 INFO (MainThread) [homeassistant.loader] Loaded zha.sensor from homeassistant.components.zha.sensor
2019-03-17 11:52:48 INFO (MainThread) [homeassistant.components.sensor] Setting up sensor.zha
2019-03-17 11:52:48 INFO (MainThread) [homeassistant.bootstrap] Home Assistant initialized in 7.50s
2019-03-17 11:52:48 INFO (MainThread) [homeassistant.core] Starting Home Assistant
2019-03-17 11:52:48 INFO (MainThread) [homeassistant.components.discovery] Found new service: hassio {}
2019-03-17 11:52:48 INFO (MainThread) [homeassistant.core] Timer:starting
2019-03-17 11:52:48 INFO (MainThread) [homeassistant.loader] Loaded hassio from homeassistant.components.hassio
2019-03-17 11:52:48 INFO (MainThread) [homeassistant.setup] Setting up hassio
2019-03-17 11:52:48 INFO (MainThread) [homeassistant.loader] Loaded panel_custom from homeassistant.components.panel_custom
2019-03-17 11:52:48 INFO (MainThread) [homeassistant.setup] Setup of domain hassio took 0.1 seconds.
2019-03-17 11:52:53 INFO (MainThread) [homeassistant.components.http.view] Serving /api/websocket to 192.168.1.70 (auth: False)
2019-03-17 11:52:53 INFO (MainThread) [homeassistant.loader] Loaded persistent_notification from homeassistant.components.persistent_notification
2019-03-17 11:52:53 INFO (MainThread) [homeassistant.loader] Loaded homematicip_cloud from homeassistant.components.homematicip_cloud
2019-03-17 11:52:53 INFO (MainThread) [homeassistant.loader] Loaded locative from homeassistant.components.locative
2019-03-17 11:52:53 INFO (MainThread) [homeassistant.loader] Loaded dialogflow from homeassistant.components.dialogflow
2019-03-17 11:52:53 INFO (MainThread) [homeassistant.loader] Loaded esphome from homeassistant.components.esphome
2019-03-17 11:52:54 INFO (MainThread) [homeassistant.loader] Loaded hangouts from homeassistant.components.hangouts
2019-03-17 11:52:54 INFO (MainThread) [homeassistant.loader] Loaded upnp from homeassistant.components.upnp
2019-03-17 11:52:54 INFO (MainThread) [homeassistant.loader] Loaded ipma from homeassistant.components.ipma
2019-03-17 11:52:55 INFO (MainThread) [homeassistant.loader] Loaded deconz from homeassistant.components.deconz
2019-03-17 11:52:55 INFO (MainThread) [homeassistant.loader] Loaded owntracks from homeassistant.components.owntracks
2019-03-17 11:52:55 INFO (MainThread) [homeassistant.loader] Loaded unifi from homeassistant.components.unifi
2019-03-17 11:52:55 INFO (MainThread) [homeassistant.loader] Loaded twilio from homeassistant.components.twilio
2019-03-17 11:52:55 INFO (MainThread) [homeassistant.loader] Loaded daikin from homeassistant.components.daikin
2019-03-17 11:52:55 INFO (MainThread) [homeassistant.loader] Loaded lifx from homeassistant.components.lifx
2019-03-17 11:52:55 INFO (MainThread) [homeassistant.loader] Loaded zwave from homeassistant.components.zwave
2019-03-17 11:52:55 INFO (MainThread) [homeassistant.loader] Loaded luftdaten from homeassistant.components.luftdaten
2019-03-17 11:52:55 INFO (MainThread) [homeassistant.loader] Loaded cast from homeassistant.components.cast
2019-03-17 11:52:55 INFO (MainThread) [homeassistant.loader] Loaded ios from homeassistant.components.ios
2019-03-17 11:52:55 INFO (MainThread) [homeassistant.loader] Loaded mailgun from homeassistant.components.mailgun
2019-03-17 11:52:55 INFO (MainThread) [homeassistant.loader] Loaded smartthings from homeassistant.components.smartthings
2019-03-17 11:52:55 INFO (MainThread) [homeassistant.loader] Loaded sonos from homeassistant.components.sonos
2019-03-17 11:52:55 INFO (MainThread) [homeassistant.loader] Loaded ambient_station from homeassistant.components.ambient_station
2019-03-17 11:52:55 INFO (MainThread) [homeassistant.loader] Loaded hue from homeassistant.components.hue
2019-03-17 11:52:56 INFO (MainThread) [homeassistant.loader] Loaded tellduslive from homeassistant.components.tellduslive
2019-03-17 11:52:56 INFO (MainThread) [homeassistant.loader] Loaded mqtt from homeassistant.components.mqtt
2019-03-17 11:52:56 INFO (MainThread) [homeassistant.loader] Loaded tradfri from homeassistant.components.tradfri
2019-03-17 11:52:56 INFO (MainThread) [homeassistant.loader] Loaded emulated_roku from homeassistant.components.emulated_roku
2019-03-17 11:52:56 INFO (MainThread) [homeassistant.loader] Loaded ps4 from homeassistant.components.ps4
2019-03-17 11:52:56 INFO (MainThread) [homeassistant.loader] Loaded openuv from homeassistant.components.openuv
2019-03-17 11:52:56 INFO (MainThread) [homeassistant.loader] Loaded geofency from homeassistant.components.geofency
2019-03-17 11:52:56 INFO (MainThread) [homeassistant.loader] Loaded ifttt from homeassistant.components.ifttt
2019-03-17 11:52:56 INFO (MainThread) [homeassistant.loader] Loaded toon from homeassistant.components.toon
2019-03-17 11:52:56 INFO (MainThread) [homeassistant.loader] Loaded nest from homeassistant.components.nest
2019-03-17 11:52:56 INFO (MainThread) [homeassistant.loader] Loaded smhi from homeassistant.components.smhi
2019-03-17 11:52:56 INFO (MainThread) [homeassistant.loader] Loaded simplisafe from homeassistant.components.simplisafe
2019-03-17 11:52:56 INFO (MainThread) [homeassistant.loader] Loaded tplink from homeassistant.components.tplink
2019-03-17 11:52:56 INFO (MainThread) [homeassistant.loader] Loaded point from homeassistant.components.point
2019-03-17 11:52:56 INFO (MainThread) [homeassistant.loader] Loaded rainmachine from homeassistant.components.rainmachine
2019-03-17 11:52:56 INFO (MainThread) [homeassistant.loader] Loaded gpslogger from homeassistant.components.gpslogger
2019-03-17 11:52:56 DEBUG (MainThread) [zigpy_xbee.uart] Frame received: b'\xa3\x00\x1e^\t\x02+y\xf8~\xed\x00'
2019-03-17 11:52:56 DEBUG (MainThread) [zigpy_xbee.api] Frame received: many_to_one_rri
2019-03-17 11:52:56 ERROR (MainThread) [homeassistant.core] Error doing job: Exception in callback <bound method SerialTransport._read_ready of SerialTransport(<uvloop.Loop running=True closed=False debug=False>, <zigpy_xbee.uart.Gateway object at 0x734dc290>, Serial<id=0x734dc2b0, open=True>(port='/dev/ttyUSB0', baudrate=57600, bytesize=8, parity='N', stopbits=1, timeout=0, xonxoff=False, rtscts=False, dsrdtr=False))>
Traceback (most recent call last):
  File "uvloop/cbhandles.pyx", line 62, in uvloop.loop.Handle._run
  File "/usr/local/lib/python3.7/site-packages/serial_asyncio/__init__.py", line 106, in _read_ready
    self._protocol.data_received(data)
  File "/usr/local/lib/python3.7/site-packages/zigpy_xbee/uart.py", line 74, in data_received
    self.frame_received(frame)
  File "/usr/local/lib/python3.7/site-packages/zigpy_xbee/uart.py", line 82, in frame_received
    self._api.frame_received(frame)
  File "/usr/local/lib/python3.7/site-packages/zigpy_xbee/api.py", line 264, in frame_received
    getattr(self, '_handle_%s' % (command, ))(data)
AttributeError: 'XBee' object has no attribute '_handle_many_to_one_rri'
2019-03-17 11:53:01 INFO (MainThread) [homeassistant.components.discovery] Unknown service discovered: webos_tv {'host': '192.168.1.82', 'port': 1910, 'ssdp_description': 'http://192.168.1.82:1910/', 'name': '[LG] webOS TV UH750V', 'model_name': 'LG Smart TV', 'model_number': '55UH750V-ZA', 'serial': None, 'manufacturer': 'LG Electronics', 'udn': 'uuid:b7a83cfe-c173-4294-7c04-2c1462285572', 'upnp_device_type': 'urn:schemas-upnp-org:device:Basic:1'}
2019-03-17 11:53:01 INFO (MainThread) [homeassistant.components.discovery] Unknown service discovered: dlna_dmr {'host': '192.168.1.82', 'port': 1206, 'ssdp_description': 'http://192.168.1.82:1206/', 'name': '[LG] webOS TV UH750V', 'model_name': 'LG TV', 'model_number': '1.0', 'serial': None, 'manufacturer': 'LG Electronics.', 'udn': 'uuid:7ea77460-d3e0-5a0d-e0d1-83fa8a853cfa', 'upnp_device_type': 'urn:schemas-upnp-org:device:MediaRenderer:1'}
2019-03-17 11:53:40 INFO (MainThread) [homeassistant.components.http.view] Serving /api/hassio/app/entrypoint.js to 192.168.1.70 (auth: False)
2019-03-17 11:53:40 INFO (MainThread) [homeassistant.components.http.view] Serving /api/hassio/app/chunk.f32f3c841cc3e1d081f7.js to 192.168.1.70 (auth: False)
2019-03-17 11:53:40 INFO (MainThread) [homeassistant.components.http.view] Serving /api/hassio/app/chunk.8c049a124b9397e54c16.js to 192.168.1.70 (auth: False)
2019-03-17 11:53:40 INFO (MainThread) [homeassistant.components.http.view] Serving /api/hassio/app/chunk.c1ac97370d72bce0a835.js to 192.168.1.70 (auth: False)
2019-03-17 11:53:40 INFO (MainThread) [homeassistant.components.http.view] Serving /api/hassio/app/chunk.d0eb7b86b775838caf5e.js to 192.168.1.70 (auth: False)
2019-03-17 11:53:41 INFO (MainThread) [homeassistant.components.http.view] Serving /api/hassio/supervisor/info to 192.168.1.70 (auth: True)
2019-03-17 11:53:41 INFO (MainThread) [homeassistant.components.http.view] Serving /api/hassio/host/info to 192.168.1.70 (auth: True)
2019-03-17 11:53:41 INFO (MainThread) [homeassistant.components.http.view] Serving /api/hassio/homeassistant/info to 192.168.1.70 (auth: True)
2019-03-17 11:53:41 INFO (MainThread) [homeassistant.components.http.view] Serving /api/hassio/app/chunk.0853908528652fbc5d4f.js to 192.168.1.70 (auth: False)
2019-03-17 11:53:41 INFO (MainThread) [homeassistant.components.http.view] Serving /api/hassio/app/chunk.9e3883f96f68b3ce89f5.js to 192.168.1.70 (auth: False)
2019-03-17 11:53:43 INFO (MainThread) [homeassistant.components.http.view] Serving /api/hassio/addons/core_configurator/info to 192.168.1.70 (auth: True)
2019-03-17 11:53:43 INFO (MainThread) [homeassistant.components.http.view] Serving /api/hassio/addons/core_configurator/logs to 192.168.1.70 (auth: True)
2019-03-17 11:53:44 INFO (MainThread) [homeassistant.components.http.view] Serving /api/services to 172.30.32.2 (auth: True)
2019-03-17 11:53:44 INFO (MainThread) [homeassistant.components.http.view] Serving /api/events to 172.30.32.2 (auth: True)
2019-03-17 11:53:44 INFO (MainThread) [homeassistant.components.http.view] Serving /api/states to 172.30.32.2 (auth: True)
2019-03-17 11:53:54 DEBUG (MainThread) [zigpy_xbee.uart] Frame received: b'\xa3\x00\x1e^\t\x02+y\xf8~\xed\x00'
2019-03-17 11:53:54 DEBUG (MainThread) [zigpy_xbee.api] Frame received: many_to_one_rri
2019-03-17 11:53:54 ERROR (MainThread) [homeassistant.core] Error doing job: Exception in callback <bound method SerialTransport._read_ready of SerialTransport(<uvloop.Loop running=True closed=False debug=False>, <zigpy_xbee.uart.Gateway object at 0x734dc290>, Serial<id=0x734dc2b0, open=True>(port='/dev/ttyUSB0', baudrate=57600, bytesize=8, parity='N', stopbits=1, timeout=0, xonxoff=False, rtscts=False, dsrdtr=False))>
Traceback (most recent call last):
  File "uvloop/cbhandles.pyx", line 62, in uvloop.loop.Handle._run
  File "/usr/local/lib/python3.7/site-packages/serial_asyncio/__init__.py", line 106, in _read_ready
    self._protocol.data_received(data)
  File "/usr/local/lib/python3.7/site-packages/zigpy_xbee/uart.py", line 74, in data_received
    self.frame_received(frame)
  File "/usr/local/lib/python3.7/site-packages/zigpy_xbee/uart.py", line 82, in frame_received
    self._api.frame_received(frame)
  File "/usr/local/lib/python3.7/site-packages/zigpy_xbee/api.py", line 264, in frame_received
    getattr(self, '_handle_%s' % (command, ))(data)
AttributeError: 'XBee' object has no attribute '_handle_many_to_one_rri'
StyxyDog commented 5 years ago

As far as I can tell this only occurs when a certain device is paired. Its a Hive Active Plug, but it shows in HA as computime slp2b.

StyxyDog commented 5 years ago

So after a bit of investigation today I think I can report that the error was caused by a single device. However I have an issue with moving from one zha configuration to another. If I remove zha (deconz) and install zha (xbee) despite being able to add and reconfigure devices, they just don't work. However on a fresh install the devices will work with xbee. So I've no idea how to troubleshoot or report that sort of an issue. If its just me and this isn;t a general issue then rather than waste people's time and energy I think I'll just stick with the conbee. The only way I can see the xbee working for me is to rebuild the system (rather than restore it).

I see a lot of this sort of error: 

2019-03-17 17:23:27 DEBUG (MainThread) [zigpy_xbee.uart] Frame received: b'\x91\xff\xff\xff\xff\xff\xff\xff\xff\x9b\xa1\x01\x01\x04\x06\x01\x04\x00\x18#\n\x00\x00\x18\x01'
2019-03-17 17:23:27 DEBUG (MainThread) [zigpy_xbee.api] Frame received: explicit_rx_indicator
2019-03-17 17:23:27 DEBUG (MainThread) [zigpy_xbee.api] _handle_explicit_rx: opts=0
2019-03-17 17:23:27 ERROR (MainThread) [homeassistant.core] Error doing job: Exception in callback <bound method SerialTransport._read_ready of SerialTransport(<uvloop.Loop running=True closed=False debug=False>, <zigpy_xbee.uart.Gateway object at 0x70d46fd0>, Serial<id=0x70d46ff0, open=True>(port='/dev/ttyUSB0', baudrate=57600, bytesize=8, parity='N', stopbits=1, timeout=0, xonxoff=False, rtscts=False, dsrdtr=False))>
Traceback (most recent call last):
  File "uvloop/cbhandles.pyx", line 62, in uvloop.loop.Handle._run
  File "/usr/local/lib/python3.7/site-packages/serial_asyncio/__init__.py", line 106, in _read_ready
    self._protocol.data_received(data)
  File "/config/deps/lib/python3.7/site-packages/zigpy_xbee/uart.py", line 74, in data_received
    self.frame_received(frame)
  File "/config/deps/lib/python3.7/site-packages/zigpy_xbee/uart.py", line 82, in frame_received
    self._api.frame_received(frame)
  File "/config/deps/lib/python3.7/site-packages/zigpy_xbee/api.py", line 264, in frame_received
    getattr(self, '_handle_%s' % (command, ))(data)
  File "/config/deps/lib/python3.7/site-packages/zigpy_xbee/api.py", line 302, in _handle_explicit_rx_indicator
    self._app.handle_rx(*data)
  File "/config/deps/lib/python3.7/site-packages/zigpy_xbee/zigbee/application.py", line 162, in handle_rx
    tsn, command_id, is_reply, args = self.deserialize(device, src_ep, cluster_id, data)
  File "/config/deps/lib/python3.7/site-packages/zigpy/application.py", line 74, in deserialize
    return sender.deserialize(endpoint_id, cluster_id, data)
  File "/config/deps/lib/python3.7/site-packages/zigpy/device.py", line 98, in deserialize
    return self.endpoints[endpoint_id].deserialize(cluster_id, data)
KeyError: 1
2019-03-17 17:23:27 DEBUG (MainThread) [zigpy_xbee.uart] Frame received: b'\x91\xff\xff\xff\xff\xff\xff\xff\xff\x9b\xa1\x01\x01\x04\x00\x01\x04\x00\x18$\n\x00\x00!\x18\x00'
Traceback (most recent call last):
  File "uvloop/cbhandles.pyx", line 62, in uvloop.loop.Handle._run
  File "/usr/local/lib/python3.7/site-packages/serial_asyncio/__init__.py", line 106, in _read_ready
    self._protocol.data_received(data)
  File "/config/deps/lib/python3.7/site-packages/zigpy_xbee/uart.py", line 74, in data_received
    self.frame_received(frame)
  File "/config/deps/lib/python3.7/site-packages/zigpy_xbee/uart.py", line 82, in frame_received
    self._api.frame_received(frame)
  File "/config/deps/lib/python3.7/site-packages/zigpy_xbee/api.py", line 264, in frame_received
    getattr(self, '_handle_%s' % (command, ))(data)
  File "/config/deps/lib/python3.7/site-packages/zigpy_xbee/api.py", line 302, in _handle_explicit_rx_indicator
    self._app.handle_rx(*data)
  File "/config/deps/lib/python3.7/site-packages/zigpy_xbee/zigbee/application.py", line 162, in handle_rx
    tsn, command_id, is_reply, args = self.deserialize(device, src_ep, cluster_id, data)
  File "/config/deps/lib/python3.7/site-packages/zigpy/application.py", line 74, in deserialize
    return sender.deserialize(endpoint_id, cluster_id, data)
  File "/config/deps/lib/python3.7/site-packages/zigpy/device.py", line 98, in deserialize
    return self.endpoints[endpoint_id].deserialize(cluster_id, data)
KeyError: 1
prairiesnpr commented 5 years ago

I started getting this error when I added an xbee3 to the network. Even though I have disabled the many to one routing option. See: https://www.digi.com/resources/documentation/Digidocs/90001942-13/concepts/c_many_to_one_routing.htm It still sends requests to the coordinator. It expects a function in zigpy-xbee/api.py titled "_handle_many_to_one_rri". I added the function and set it to log the request in order to avoid the error.

dmulcahey commented 5 years ago

@Adminiuga should we add this function to zigpy-xbee as a no-op? Maybe have @prairiesnpr PR his change so that others can avoid the error?

StyxyDog commented 5 years ago

I gave up on the xbee. I still have it if needed for testing, but as no one else seems to have this issue I think we can close it. Thanks anyway.

Adminiuga commented 5 years ago

@StyxyDog BTW this was supposed to be fixed in 0.91.x