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
72.63k stars 30.38k forks source link

GE ZigBee Lighting Switch 45856GE improperly detected #11847

Closed igorbernstein closed 6 years ago

igorbernstein commented 6 years ago

Make sure you are running the latest version of Home Assistant before reporting an issue.

You should only file an issue if you found a bug. Feature and enhancement requests should go in the Feature Requests section of our community forum:

Home Assistant release (hass --version): 0.61.1

Python release (python3 --version): Python 3.6.4

Component/platform: zha/os x

Description of problem: Device: GE ZigBee Wireless Smart Lighting Control Switch 45856GE Controller: Linear HUSBZB-1

What works: Home assistant is able to discover the device and it appears in the dashboard as Jasco Products 45856. Toggling it in the dashboard correctly controls the switch.

What doesn't: It doesn't appear that home assistant can read the current status of the switch. Physically changing the state of the switch doesn't update the dashboard.

I'm fairly new to home automation, but I believe the issue is that the switch presents itself as 2 endpoints, where one endpoint is used for writing state and the other is used for reading state.

Output from bellows devices -D $PWD/.homeassistant/zigbee.db

Device:
  NWK: 0x0cd8
  IEEE: 00:22:a3:00:00:1f:37:68
  Endpoints:
    1: profile=0x104, device_type=DeviceType.ON_OFF_LIGHT
      Input Clusters:
        Basic (0)
        Identify (3)
        Groups (4)
        Scenes (5)
        On/Off (6)
        Metering (1794)
        Diagnostic (2821)
      Output Clusters:
        Time (10)
        Ota (25)
    2: profile=0x104, device_type=DeviceType.ON_OFF_LIGHT_SWITCH
      Input Clusters:
        Basic (0)
        Identify (3)
        Diagnostic (2821)
      Output Clusters:
        Identify (3)
        On/Off (6)

Expected: No errors during zha.permit and the dashboard to reflect manually changed state of the switch.

Problem-relevant configuration.yaml entries and steps to reproduce:

zha:
  usb_path: /dev/tty.GoControl_zigbee
  database_path: /Users/igor/.homeassistant/zigbee.db

logger:
  default: debug
  1. Install a GE ZigBee Wireless Smart Lighting Control Switch 45856GE into a wall
  2. Install zigbee drivers on a macbook (2016 mbp w. osx 10.13.2): https://www.silabs.com/products/development-tools/software/usb-to-uart-bridge-vcp-drivers
  3. Connect a Linear HUSBZB-1
  4. brew install python3
  5. Install homeassistant via pip (I used a virtualenv using virtfualfish)
  6. hass --open-ui
  7. permit zigbee join via zha.permit service call

Traceback (if applicable): When adding the switch to hass via zha.permit, I can see errors in the logs:

Traceback (most recent call last):
  File "/Users/igor/.virtualenvs/homeassistant/lib/python3.6/site-packages/bellows/zigbee/endpoint.py", line 141, in __getattr__
    return self._cluster_attr[name]
KeyError: 'on_off'

Additional info: Output from logs:

2018-01-21 12:14:43 INFO (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: domain=zha, service=permit, service_data=, service_call_id=4438681136-2>
2018-01-21 12:14:43 INFO (MainThread) [homeassistant.components.zha] Permitting joins for 60s
2018-01-21 12:14:43 DEBUG (MainThread) [bellows.ezsp] Send command permitJoining
2018-01-21 12:14:43 DEBUG (MainThread) [bellows.uart] Sending: b'0152218a688b057e'
2018-01-21 12:14:43 DEBUG (MainThread) [bellows.uart] Data frame: b'1152a18a5443da7e'
2018-01-21 12:14:43 DEBUG (MainThread) [bellows.uart] Sending: b'82503a7e'
2018-01-21 12:14:43 DEBUG (MainThread) [bellows.ezsp] Application frame 34 (permitJoining) received
2018-01-21 12:14:43 INFO (MainThread) [homeassistant.core] Bus:Handling <Event service_executed[L]: service_call_id=4438681136-2>
2018-01-21 12:14:43 DEBUG (MainThread) [homeassistant.components.websocket_api] WS 4476368320: Sending {'id': 11, 'type': 'result', 'success': True, 'result': None}
2018-01-21 12:14:52 DEBUG (MainThread) [bellows.uart] Data frame: b'2152b18c0b9b7d8546944a868855904a63b1bc157e'
2018-01-21 12:14:52 DEBUG (MainThread) [bellows.uart] Sending: b'83401b7e'
2018-01-21 12:14:52 DEBUG (MainThread) [bellows.ezsp] Application frame 36 (trustCenterJoinHandler) received
2018-01-21 12:14:52 INFO (MainThread) [bellows.zigbee.application] Device 0xb15f (00:22:a3:00:00:1f:37:68) left the network
2018-01-21 12:14:52 DEBUG (MainThread) [bellows.uart] Data frame: b'3152b18c0b9b7d8546944a868855904a63b14eea7e'
2018-01-21 12:14:52 DEBUG (MainThread) [bellows.uart] Sending: b'8430fc7e'
2018-01-21 12:14:52 DEBUG (MainThread) [bellows.ezsp] Application frame 36 (trustCenterJoinHandler) received
2018-01-21 12:14:52 INFO (MainThread) [bellows.zigbee.application] Device 0xb15f (00:22:a3:00:00:1f:37:68) left the network
2018-01-21 12:14:52 DEBUG (MainThread) [bellows.uart] Data frame: b'4152b18c0b9b7d8546944a868855904a63b1b2557e'
2018-01-21 12:14:52 DEBUG (MainThread) [bellows.uart] Sending: b'8520dd7e'
2018-01-21 12:14:52 DEBUG (MainThread) [bellows.ezsp] Application frame 36 (trustCenterJoinHandler) received
2018-01-21 12:14:52 INFO (MainThread) [bellows.zigbee.application] Device 0xb15f (00:22:a3:00:00:1f:37:68) left the network
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.uart] Data frame: b'5152b18c8c267d8546944a86885593499c4e7db97e'
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.uart] Sending: b'8610be7e'
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.ezsp] Application frame 36 (trustCenterJoinHandler) received
2018-01-21 12:14:54 INFO (MainThread) [bellows.zigbee.application] Device 0x0cd8 (00:22:a3:00:00:1f:37:68) joined the network
2018-01-21 12:14:54 INFO (MainThread) [bellows.zigbee.device] [0x0cd8] Discovering endpoints
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.uart] Sending: b'1653219c54f219b259914a25aa1593499c4f26a8ec166bed8c7e'
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.uart] Data frame: b'6253a19c543ae5507e'
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.uart] Sending: b'87009f7e'
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.uart] Data frame: b'7253b1f18c267d8546944a8688556d8c9c77247e'
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.uart] Sending: b'8070787e'
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.ezsp] Application frame 89 (incomingRouteRecordHandler) received
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.uart] Data frame: b'0253b1f18c267d8546944a8688556d8d9c1e127e'
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.uart] Sending: b'8160597e'
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.ezsp] Application frame 89 (incomingRouteRecordHandler) received
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.uart] Data frame: b'1253b5ca3c1d0ab2593768250ee57e'
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.uart] Sending: b'82503a7e'
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.ezsp] Application frame 98 (incomingSenderEui64Handler) received
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.uart] Data frame: b'2253b1ed502a15a159944a2dae5592886388ffa712316b0a25ca0bbee37e3f04c9cd505cb57e'
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.uart] Sending: b'83401b7e'
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.zigbee.zdo] [0x0cd8:zdo] ZDO request 0x0013: [3288, 00:22:a3:00:00:1f:37:68, 142]
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.uart] Data frame: b'3253b1ed542a15b7d9944a65ab5592896389ffa71231608afd1e6f8bfd7c45277e'
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.uart] Sending: b'8430fc7e'
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.uart] Data frame: b'4253b19754f219b259914a25aa1593499c5e26abed395a7e'
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.uart] Sending: b'8520dd7e'
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received
2018-01-21 12:14:54 INFO (MainThread) [bellows.zigbee.device] [0x0cd8] Discovered endpoints: [1, 2]
2018-01-21 12:14:54 INFO (MainThread) [bellows.zigbee.endpoint] [0x0cd8:1] Discovering endpoint information
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.uart] Sending: b'2550219c54f219b259904a25aa1593499c4c25afef166b8ae23a7e'
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.uart] Data frame: b'5350a19c543b718f7e'
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.uart] Sending: b'8610be7e'
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.uart] Data frame: b'6350b1f18c267d8546944a8688556d819ce7d67e'
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.uart] Sending: b'87009f7e'
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.ezsp] Application frame 89 (incomingRouteRecordHandler) received
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.uart] Data frame: b'7350b1f18c267d8546944a8688556d819cf9d77e'
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.uart] Sending: b'8070787e'
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.ezsp] Application frame 89 (incomingRouteRecordHandler) received
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.uart] Data frame: b'0350b1ed542a15b6d9944a65ab55928b6288ffa712317889fd1e6f93fd7a3ea7eacdd96f8ffcc7dfd5d7698a4626a2ee7139afea6c821c927e'
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.uart] Sending: b'8160597e'
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.uart] Data frame: b'1350b19754f219b259904a25aa1593499c5f25abed0b537e'
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.uart] Sending: b'82503a7e'
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received
2018-01-21 12:14:54 INFO (MainThread) [bellows.zigbee.endpoint] [0x0cd8:1] Discovered endpoint information: <SimpleDescriptor endpoint=1 profile=260 device_type=256 device_version=0 input_clusters=[0, 3, 4, 5, 6, 2821, 1794] output_clusters=[10, 25]>
2018-01-21 12:14:54 INFO (MainThread) [bellows.zigbee.endpoint] [0x0cd8:2] Discovering endpoint information
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.uart] Sending: b'3251219c54f219b259904a25aa1593499c4d24afee166b89f97d5d7e'
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.uart] Data frame: b'2451a19c543866607e'
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.uart] Sending: b'83401b7e'
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.uart] Data frame: b'3451b1f18c267d8546944a8688556d819c5b597e'
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.uart] Sending: b'8430fc7e'
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.ezsp] Application frame 89 (incomingRouteRecordHandler) received
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.uart] Data frame: b'4451b1f18c267d8546944a8688556d809c326f7e'
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.uart] Sending: b'8520dd7e'
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.ezsp] Application frame 89 (incomingRouteRecordHandler) received
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.uart] Data frame: b'5451b1ed542a15b6d9944a65ab55928a6386ffa712317088fd1e6f9bfe7a3ea4eacddd6f8ffcc7deded06a8c4023f3b87e'
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.uart] Sending: b'8610be7e'
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.uart] Data frame: b'6451b19754f219b259904a25aa1593499c5c24abed038c7e'
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.uart] Sending: b'87009f7e'
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received
2018-01-21 12:14:54 INFO (MainThread) [bellows.zigbee.endpoint] [0x0cd8:2] Discovered endpoint information: <SimpleDescriptor endpoint=2 profile=260 device_type=259 device_version=0 input_clusters=[0, 3, 2821] output_clusters=[3, 6]>
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.uart] Sending: b'4756219c54f219b658944a24ab1593499c4a23acedca678ffdc3630bb47e'
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.uart] Data frame: b'7556a19c543924a17e'
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.uart] Sending: b'8070787e'
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.uart] Data frame: b'0556b1f18c267d8546944a8688556d8c9c777b7e'
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.uart] Sending: b'8160597e'
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.ezsp] Application frame 89 (incomingRouteRecordHandler) received
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.uart] Data frame: b'1556b1f18c267d8546944a8688556d8f9c3c297e'
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.uart] Sending: b'82503a7e'
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.ezsp] Application frame 89 (incomingRouteRecordHandler) received
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.uart] Data frame: b'2556b1ed542e14b259954b65ab55928d6388ffa712314783f9c76789fc3c31ed8abebd00afafb5b4b1a70af83526a9ec343e91df4db777129d7e'
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.uart] Sending: b'83401b7e'
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.uart] Data frame: b'3556b19754f219b658944a24ab1593499c5d23abed09887e'
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.uart] Sending: b'8430fc7e'
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received
2018-01-21 12:14:54 INFO (MainThread) [homeassistant.loader] Loaded light from homeassistant.components.light
2018-01-21 12:14:54 INFO (MainThread) [homeassistant.setup] Setting up light
2018-01-21 12:14:54 INFO (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=light, service=turn_on>
2018-01-21 12:14:54 INFO (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=light, service=turn_off>
2018-01-21 12:14:54 INFO (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=light, service=toggle>
2018-01-21 12:14:54 INFO (MainThread) [homeassistant.setup] Setup of domain light took 0.0 seconds.
2018-01-21 12:14:54 INFO (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=light>
2018-01-21 12:14:54 INFO (MainThread) [homeassistant.core] Bus:Handling <Event platform_discovered[L]: service=load_platform.light, platform=zha, discovered=discovery_key=00:22:a3:00:00:1f:37:68-1>
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast
2018-01-21 12:14:54 DEBUG (MainThread) [homeassistant.components.websocket_api] WS 4476268784: Sending {'id': 4, 'type': 'event', 'event': {'event_type': 'service_registered', 'data': {'domain': 'light', 'service': 'turn_on'}, 'origin': 'LOCAL', 'time_fired': datetime.datetime(2018, 1, 21, 17, 14, 54, 592471, tzinfo=<UTC>)}}
2018-01-21 12:14:54 DEBUG (MainThread) [homeassistant.components.websocket_api] WS 4476268784: Sending {'id': 4, 'type': 'event', 'event': {'event_type': 'service_registered', 'data': {'domain': 'light', 'service': 'turn_off'}, 'origin': 'LOCAL', 'time_fired': datetime.datetime(2018, 1, 21, 17, 14, 54, 593102, tzinfo=<UTC>)}}
2018-01-21 12:14:54 DEBUG (MainThread) [homeassistant.components.websocket_api] WS 4476268784: Sending {'id': 4, 'type': 'event', 'event': {'event_type': 'service_registered', 'data': {'domain': 'light', 'service': 'toggle'}, 'origin': 'LOCAL', 'time_fired': datetime.datetime(2018, 1, 21, 17, 14, 54, 593801, tzinfo=<UTC>)}}
2018-01-21 12:14:54 DEBUG (MainThread) [homeassistant.components.websocket_api] WS 4476268784: Sending {'id': 3, 'type': 'event', 'event': {'event_type': 'component_loaded', 'data': {'component': 'light'}, 'origin': 'LOCAL', 'time_fired': datetime.datetime(2018, 1, 21, 17, 14, 54, 594699, tzinfo=<UTC>)}}
2018-01-21 12:14:54 DEBUG (MainThread) [homeassistant.components.websocket_api] WS 4476368320: Sending {'id': 5, 'type': 'event', 'event': {'event_type': 'service_registered', 'data': {'domain': 'light', 'service': 'turn_on'}, 'origin': 'LOCAL', 'time_fired': datetime.datetime(2018, 1, 21, 17, 14, 54, 592471, tzinfo=<UTC>)}}
2018-01-21 12:14:54 DEBUG (MainThread) [homeassistant.components.websocket_api] WS 4476368320: Sending {'id': 5, 'type': 'event', 'event': {'event_type': 'service_registered', 'data': {'domain': 'light', 'service': 'turn_off'}, 'origin': 'LOCAL', 'time_fired': datetime.datetime(2018, 1, 21, 17, 14, 54, 593102, tzinfo=<UTC>)}}
2018-01-21 12:14:54 DEBUG (MainThread) [homeassistant.components.websocket_api] WS 4476368320: Sending {'id': 5, 'type': 'event', 'event': {'event_type': 'service_registered', 'data': {'domain': 'light', 'service': 'toggle'}, 'origin': 'LOCAL', 'time_fired': datetime.datetime(2018, 1, 21, 17, 14, 54, 593801, tzinfo=<UTC>)}}
2018-01-21 12:14:54 DEBUG (MainThread) [homeassistant.components.websocket_api] WS 4476368320: Sending {'id': 4, 'type': 'event', 'event': {'event_type': 'component_loaded', 'data': {'component': 'light'}, 'origin': 'LOCAL', 'time_fired': datetime.datetime(2018, 1, 21, 17, 14, 54, 594699, tzinfo=<UTC>)}}
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.uart] Sending: b'5457219c54f219b658944a27a81593499c4b22acedcb678ffdc36314907e'
2018-01-21 12:14:54 INFO (MainThread) [homeassistant.loader] Loaded light.zha from homeassistant.components.light.zha
2018-01-21 12:14:54 INFO (MainThread) [homeassistant.components.light] Setting up light.zha
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.uart] Data frame: b'4657a19c543e1f7b7e'
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.uart] Sending: b'8520dd7e'
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.uart] Sending: b'6554219c54f219b658924a24ab1593499c4821aeedc8678bfd776d7e'
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.uart] Data frame: b'5754a19c543fbeac7e'
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.uart] Sending: b'8610be7e'
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.uart] Data frame: b'6754b1f18c267d8546944a8688556d8e9c34b27e'
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.uart] Sending: b'87009f7e'
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.ezsp] Application frame 89 (incomingRouteRecordHandler) received
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.uart] Data frame: b'7754b1f18c267d8546944a8688556d8c9c4cd17e'
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.uart] Sending: b'8070787e'
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.ezsp] Application frame 89 (incomingRouteRecordHandler) received
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.uart] Data frame: b'0754b1f18c267d8546944a8688556d889cda127e'
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.uart] Sending: b'8160597e'
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.ezsp] Application frame 89 (incomingRouteRecordHandler) received
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.uart] Data frame: b'1754b1f18c267d8546944a8688556df69cef457e'
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.uart] Sending: b'82503a7e'
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.ezsp] Application frame 89 (incomingRouteRecordHandler) received
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.uart] Data frame: b'2754b1ed542e14b259964865ab55928c63f1ffa712314783f8c76789fc3c31ed8abebd00afafb5b4b1a70af83526a9ec343e91df4db7774c467e'
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.uart] Sending: b'83401b7e'
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.uart] Data frame: b'3754b19754f219b658944a27a81593499c5a22abed23b57e'
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.uart] Sending: b'8430fc7e'
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received
2018-01-21 12:14:54 INFO (MainThread) [homeassistant.core] Bus:Handling <Event platform_discovered[L]: service=load_platform.light, platform=zha, discovered=discovery_key=00:22:a3:00:00:1f:37:68-2>
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.uart] Data frame: b'4754b1ed542e14b459954b65ab55928f638dffa712316f83fbc76389fc6e3f483c7e'
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.uart] Sending: b'8520dd7e'
2018-01-21 12:14:54 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received
2018-01-21 12:14:54 INFO (MainThread) [homeassistant.components.light] Setting up light.zha
2018-01-21 12:14:54 ERROR (MainThread) [homeassistant.components.light] Error on device update!
Traceback (most recent call last):
  File "/Users/igor/.virtualenvs/homeassistant/lib/python3.6/site-packages/bellows/zigbee/endpoint.py", line 141, in __getattr__
    return self._cluster_attr[name]
KeyError: 'on_off'

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/Users/igor/.virtualenvs/homeassistant/lib/python3.6/site-packages/homeassistant/helpers/entity_component.py", line 217, in async_add_entity
    yield from entity.async_device_update(warning=False)
  File "/Users/igor/.virtualenvs/homeassistant/lib/python3.6/site-packages/homeassistant/helpers/entity.py", line 304, in async_device_update
    yield from self.async_update()
  File "/Users/igor/.virtualenvs/homeassistant/lib/python3.6/site-packages/homeassistant/components/light/zha.py", line 158, in async_update
    result = yield from zha.safe_read(self._endpoint.on_off, ['on_off'])
  File "/Users/igor/.virtualenvs/homeassistant/lib/python3.6/site-packages/bellows/zigbee/endpoint.py", line 143, in __getattr__
    raise AttributeError
AttributeError
2018-01-21 12:14:54 INFO (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: domain=group, service=set, service_data=object_id=all_lights, name=all lights, entities=[], visible=False, service_call_id=4438681136-3>
2018-01-21 12:14:54 INFO (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=group.all_lights, old_state=None, new_state=<state group.all_lights=unknown; entity_id=[], order=0, auto=True, friendly_name=all lights, hidden=True, assumed_state=False @ 2018-01-21T12:14:54.739909-05:00>>
2018-01-21 12:14:54 INFO (MainThread) [homeassistant.core] Bus:Handling <Event service_executed[L]: service_call_id=4438681136-3>
2018-01-21 12:14:54 DEBUG (MainThread) [homeassistant.components.websocket_api] WS 4476268784: Sending {'id': 2, 'type': 'event', 'event': {'event_type': 'state_changed', 'data': {'entity_id': 'group.all_lights', 'old_state': None, 'new_state': <state group.all_lights=unknown; entity_id=[], order=0, auto=True, friendly_name=all lights, hidden=True, assumed_state=False @ 2018-01-21T12:14:54.739909-05:00>}, 'origin': 'LOCAL', 'time_fired': datetime.datetime(2018, 1, 21, 17, 14, 54, 739938, tzinfo=<UTC>)}}
2018-01-21 12:14:54 DEBUG (MainThread) [homeassistant.components.websocket_api] WS 4476368320: Sending {'id': 2, 'type': 'event', 'event': {'event_type': 'state_changed', 'data': {'entity_id': 'group.all_lights', 'old_state': None, 'new_state': <state group.all_lights=unknown; entity_id=[], order=0, auto=True, friendly_name=all lights, hidden=True, assumed_state=False @ 2018-01-21T12:14:54.739909-05:00>}, 'origin': 'LOCAL', 'time_fired': datetime.datetime(2018, 1, 21, 17, 14, 54, 739938, tzinfo=<UTC>)}}
2018-01-21 12:14:56 DEBUG (MainThread) [bellows.uart] Data frame: b'5754b1f18c267d8546944a8688556d809c35be7e'
2018-01-21 12:14:56 DEBUG (MainThread) [bellows.uart] Sending: b'8610be7e'
2018-01-21 12:14:56 DEBUG (MainThread) [bellows.ezsp] Application frame 89 (incomingRouteRecordHandler) received
2018-01-21 12:14:56 DEBUG (MainThread) [bellows.uart] Data frame: b'6754b1f18c267d8546944a8688556d819c248c7e'
2018-01-21 12:14:56 DEBUG (MainThread) [bellows.uart] Sending: b'87009f7e'
2018-01-21 12:14:56 DEBUG (MainThread) [bellows.ezsp] Application frame 89 (incomingRouteRecordHandler) received
2018-01-21 12:14:56 DEBUG (MainThread) [bellows.uart] Data frame: b'7754b1ed542e14b459954b65ab55928e6388ffa712316f83fbc76389fc6e3fc2747e'
2018-01-21 12:14:56 DEBUG (MainThread) [bellows.uart] Sending: b'8070787e'
2018-01-21 12:14:56 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received
2018-01-21 12:14:56 DEBUG (MainThread) [bellows.zigbee.application] Invalid state on future - probably duplicate response: FINISHED: <Future finished result=[[<ReadAttribu...e=Bool.false>]]>
2018-01-21 12:14:56 DEBUG (MainThread) [bellows.uart] Data frame: b'0754b19754f219b658924a24ab1593499c5b21abed18927e'
2018-01-21 12:14:56 DEBUG (MainThread) [bellows.uart] Sending: b'8160597e'
2018-01-21 12:14:56 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received
2018-01-21 12:14:56 INFO (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=light.jasco_products_45856_001f3768_1, old_state=None, new_state=<state light.jasco_products_45856_001f3768_1=off; friendly_name=Jasco Products 45856, supported_features=0 @ 2018-01-21T12:14:56.287232-05:00>>
2018-01-21 12:14:56 DEBUG (MainThread) [homeassistant.components.websocket_api] WS 4476268784: Sending {'id': 2, 'type': 'event', 'event': {'event_type': 'state_changed', 'data': {'entity_id': 'light.jasco_products_45856_001f3768_1', 'old_state': None, 'new_state': <state light.jasco_products_45856_001f3768_1=off; friendly_name=Jasco Products 45856, supported_features=0 @ 2018-01-21T12:14:56.287232-05:00>}, 'origin': 'LOCAL', 'time_fired': datetime.datetime(2018, 1, 21, 17, 14, 56, 287262, tzinfo=<UTC>)}}
2018-01-21 12:14:56 DEBUG (MainThread) [homeassistant.components.websocket_api] WS 4476368320: Sending {'id': 2, 'type': 'event', 'event': {'event_type': 'state_changed', 'data': {'entity_id': 'light.jasco_products_45856_001f3768_1', 'old_state': None, 'new_state': <state light.jasco_products_45856_001f3768_1=off; friendly_name=Jasco Products 45856, supported_features=0 @ 2018-01-21T12:14:56.287232-05:00>}, 'origin': 'LOCAL', 'time_fired': datetime.datetime(2018, 1, 21, 17, 14, 56, 287262, tzinfo=<UTC>)}}
2018-01-21 12:14:56 INFO (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: domain=group, service=set, service_data=object_id=all_lights, name=all lights, entities=['light.jasco_products_45856_001f3768_1'], visible=False, service_call_id=4438681136-4>
2018-01-21 12:14:56 INFO (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=group.all_lights, old_state=<state group.all_lights=unknown; entity_id=[], order=0, auto=True, friendly_name=all lights, hidden=True, assumed_state=False @ 2018-01-21T12:14:54.739909-05:00>, new_state=None>
2018-01-21 12:14:56 INFO (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=group.all_lights, old_state=None, new_state=<state group.all_lights=off; entity_id=('light.jasco_products_45856_001f3768_1',), order=0, auto=True, friendly_name=all lights, hidden=True, assumed_state=False @ 2018-01-21T12:14:56.293926-05:00>>
2018-01-21 12:14:56 INFO (MainThread) [homeassistant.core] Bus:Handling <Event service_executed[L]: service_call_id=4438681136-4>
2018-01-21 12:14:56 DEBUG (MainThread) [homeassistant.components.websocket_api] WS 4476268784: Sending {'id': 2, 'type': 'event', 'event': {'event_type': 'state_changed', 'data': {'entity_id': 'group.all_lights', 'old_state': <state group.all_lights=unknown; entity_id=[], order=0, auto=True, friendly_name=all lights, hidden=True, assumed_state=False @ 2018-01-21T12:14:54.739909-05:00>, 'new_state': None}, 'origin': 'LOCAL', 'time_fired': datetime.datetime(2018, 1, 21, 17, 14, 56, 292109, tzinfo=<UTC>)}}
2018-01-21 12:14:56 DEBUG (MainThread) [homeassistant.components.websocket_api] WS 4476268784: Sending {'id': 2, 'type': 'event', 'event': {'event_type': 'state_changed', 'data': {'entity_id': 'group.all_lights', 'old_state': None, 'new_state': <state group.all_lights=off; entity_id=('light.jasco_products_45856_001f3768_1',), order=0, auto=True, friendly_name=all lights, hidden=True, assumed_state=False @ 2018-01-21T12:14:56.293926-05:00>}, 'origin': 'LOCAL', 'time_fired': datetime.datetime(2018, 1, 21, 17, 14, 56, 293951, tzinfo=<UTC>)}}
2018-01-21 12:14:56 DEBUG (MainThread) [homeassistant.components.websocket_api] WS 4476368320: Sending {'id': 2, 'type': 'event', 'event': {'event_type': 'state_changed', 'data': {'entity_id': 'group.all_lights', 'old_state': <state group.all_lights=unknown; entity_id=[], order=0, auto=True, friendly_name=all lights, hidden=True, assumed_state=False @ 2018-01-21T12:14:54.739909-05:00>, 'new_state': None}, 'origin': 'LOCAL', 'time_fired': datetime.datetime(2018, 1, 21, 17, 14, 56, 292109, tzinfo=<UTC>)}}
2018-01-21 12:14:56 DEBUG (MainThread) [homeassistant.components.websocket_api] WS 4476368320: Sending {'id': 2, 'type': 'event', 'event': {'event_type': 'state_changed', 'data': {'entity_id': 'group.all_lights', 'old_state': None, 'new_state': <state group.all_lights=off; entity_id=('light.jasco_products_45856_001f3768_1',), order=0, auto=True, friendly_name=all lights, hidden=True, assumed_state=False @ 2018-01-21T12:14:56.293926-05:00>}, 'origin': 'LOCAL', 'time_fired': datetime.datetime(2018, 1, 21, 17, 14, 56, 293951, tzinfo=<UTC>)}}
igorbernstein commented 6 years ago

I think I figured out what the underlying issue is. This light switch is exposed as 2 endpoints: a light and a switch. The light endpoint contains the main input (server) clusters for turning the light on/off and tracking its state. The switch endpoint on the other hand, only implements the On/Off client, which I'm guessing is meant to be used in a 3 way configuration where it acts as a satellite switch.

The zha component blindly reads the cluster config from bellows: https://github.com/home-assistant/home-assistant/blob/8f083e17f89750d8593ae261b6016112b353dfff/homeassistant/components/zha/const.py#L50

Which doesn't distinguish between server & client clusters and returns the OnOff cluster: https://github.com/rcloran/bellows/blob/4cf12375111f3333d04c00159b07b0b004cc0538/bellows/zigbee/profiles/zha.py#L65

This will end up being used in device initialization, causing the zigbee switch device type to be mapped to a light:

https://github.com/home-assistant/home-assistant/blob/8f083e17f89750d8593ae261b6016112b353dfff/homeassistant/components/zha/__init__.py#L154-L156

As opposed to a switch.

I think the correct way to fix this is to stop depending on bellows for the static mapping information and instead use the input (server) clusters that are reported by zigbee instead. Please let me know if this is something that you'd want a patch for or if the current static mapping behavior is done on purpose. An alternative solution would be to patch bellows to split out the input (server) clusters from the output (client) clusters and use only the input (server) clusters)

ping @rcloran

igorbernstein commented 6 years ago

After a bit more digging, I can't figure out how one would even configure the light switch client on the second endpoint. I would like to hide that endpoint from home assistant altogether. So as a separate change, I was wondering if it would make sense to add "hidden" or "ignored" component value in zha/const.py (alongside the existing light, switch and binary_sensor) that can be configured in my configuration.yaml#zha.device_config.

rcloran commented 6 years ago

The light/switch detection won’t change much functionality. The only difference I can think of is that I added state read on startup from HA lights, but not switches.

It’s unusual for the device to report its state on one endpoint while being controlled on another. In fact, I’m fairly sure it’s not in spec to report the light switch profile but not have an OnOff input cluster.

The problem is that HA creates the platform device for the non-conforming endpoint, even though it doesn’t have the required clusters:

https://github.com/home-assistant/home-assistant/blob/dev/homeassistant/components/zha/__init__.py#L204

It then throws inside the component, which assumes that the OnOff (input) cluster exists.

I think it’d be easiest to add a notion of “required clusters” to the HA components, and not try and create the device if they’re not implemented.

Adminiuga commented 6 years ago

I can confirm the similar behavior/issue with 45857GE dimmer. python --version Python 3.5.3

hass --version 0.62.1

component/platform zha/Debian stretch, armhv arch (Raspberry Pi)

Traceback (most recent call last):
  File "/home/lex/homeassistant/lib/python3.5/site-packages/bellows/zigbee/endpoint.py", line 141, in __getattr__
    return self._cluster_attr[name]
KeyError: 'on_off'

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/home/lex/homeassistant/lib/python3.5/site-packages/homeassistant/helpers/entity_component.py", line 397, in _async_add_entity
    yield from entity.async_device_update(warning=False)
  File "/home/lex/homeassistant/lib/python3.5/site-packages/homeassistant/helpers/entity.py", line 306, in async_device_update
    yield from self.async_update()
  File "/home/lex/homeassistant/lib/python3.5/site-packages/homeassistant/components/light/zha.py", line 158, in async_update
    result = yield from zha.safe_read(self._endpoint.on_off, ['on_off'])
  File "/home/lex/homeassistant/lib/python3.5/site-packages/bellows/zigbee/endpoint.py", line 143, in __getattr__
    raise AttributeError
AttributeError

Here's output for bellows devices

Device:
  NWK: 0xe147
  IEEE: 00:22:a3:00:00:1c:6e:6d
  Endpoints:
    1: profile=0x104, device_type=DeviceType.DIMMABLE_LIGHT
      Input Clusters:
        Basic (0)
        Identify (3)
        Groups (4)
        Scenes (5)
        On/Off (6)
        Level control (8)
        Metering (1794)
        Diagnostic (2821)
      Output Clusters:
        Time (10)
        Ota (25)
    2: profile=0x104, device_type=DeviceType.DIMMER_SWITCH
      Input Clusters:
        Basic (0)
        Identify (3)
        Diagnostic (2821)
      Output Clusters:
        Identify (3)
        On/Off (6)
        Level control (8)

I can turn off the lights and control the dimming level, but I can't turn the lights on using HA.

igorbernstein2 commented 6 years ago

Looking at Section 2.3.1 On/Off Switch in this doc: https://www.nxp.com/docs/en/user-guide/JN-UG-3076.pdf

It doesn't seem like the switch device type is supposed to implement any server clusters other then Basic & Identify. However they are required to implement an On/Off client cluster. While lights are required to implement an On/Off server cluster. I think you are supposed to be able to bind an On/Off client cluster to an On/Off server cluster. And the switch will act like a command generator using its On/Off client clusters to send commands to server clusters on a light's On/Off. Which would enable you to implement a 3-way switch over zigbee.

If I'm correct in this interpretation, then I don't think it's useful to export switches to home assistant.

Have you encountered devices that report themselves as On/Off Light Switch (0x0103) or Dimmer Switch(0x0104) or Colour Dimmer Switch (0x0105) that have On/Off server clusters?

Note: server = input cluster, client = output cluster

igorbernstein2 commented 6 years ago

The binding section on page 16 of this doc, seems to confirm my suspicion: https://products.currentbyge.com/sites/products.currentbyge.com/files/document_file/DT200-GE-Zigbee-Primer-Whitepaper.pdf

It seems like zigbee switches are closer to HA's binary sensors then HA lights or HA switches

rcloran commented 6 years ago

Right - I was confusing lights and light switches. I don't have one of these devices, so I can't test any code. Happy to review a PR, though.

kdjordjev commented 6 years ago

@igorbernstein . and @rcloran Sorry did not see this post and created this issue.

Do you have any insight on why i can not turn it on and 45857GE is not triggered when operated remotely? Thanks

Adminiuga commented 6 years ago

Check https://github.com/home-assistant/home-assistant/pull/12924

On Fri, Apr 13, 2018, 00:52 kdjordjev notifications@github.com wrote:

@igorbernstein https://github.com/igorbernstein . and @rcloran https://github.com/rcloran Sorry did not see this post and created this issue https://github.com/home-assistant/home-assistant/issues/13766.

Do you have any insight on why i can not turn it on and 45857GE is not triggered when operated remotely? Thanks

— You are receiving this because you commented. Reply to this email directly, view it on GitHub https://github.com/home-assistant/home-assistant/issues/11847#issuecomment-381023177, or mute the thread https://github.com/notifications/unsubscribe-auth/AFjmcEH9Dh3MZW8yJKXBeF0CHYfD9hx7ks5toC8UgaJpZM4Rl5-v .

kdjordjev commented 6 years ago

Thank you @Adminiuga . this worked for me. I can turn the light off. However the light component in hass.io does not respond to manual operation of the dimmer. It stays in previous state Is this expected. How to fix it?

Adminiuga commented 6 years ago

However the light component in hass.io does not respond to manual operation of the dimmer. It stays in previous state

Yep, same here. async_update() in light/zha.py component should pull the latest state eventually, but right now it is not tied up directly to the operation of the wall switch. I was thinking about adding "attribute reporting" to the zha lights, to make the state update more dynamic.

alternatively you could try "zha: Support switches/buttons/remotes" pull request with should give you a "binary_switch" in HA for 45857GE which you could tie to your lights (or any other lights) using automation. Something like:

  1. turn on the wall switch -> turns on physical lights + updates binary switch in HA
  2. automation in HA turns on the lights based on the binary switch (the lights which are already on)