Error while setting up control4 platform for light

[garyak]

Updated the light.py file. After the reintegration, a C4 switch appeared as a unknown device with class light. The lights no longer function correctly. Lights turn On, but the UI displays "Failed to call service light/turn_on 224" when attempting to dim or turn Off. These errors now appear in the log:

2020-08-16 03:19:52 ERROR (MainThread) [homeassistant.components.light] Error while setting up control4 platform for light
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/helpers/entity_platform.py", line 192, in _async_setup_platform
    await asyncio.gather(*pending)
  File "/usr/src/homeassistant/homeassistant/helpers/entity_platform.py", line 301, in async_add_entities
    await asyncio.gather(*tasks)
  File "/usr/src/homeassistant/homeassistant/helpers/entity_platform.py", line 474, in _async_add_entity
    entity.async_write_ha_state()
  File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 281, in async_write_ha_state
    self._async_write_ha_state()
  File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 305, in _async_write_ha_state
    sstate = self.state
  File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 595, in state
    return STATE_ON if self.is_on else STATE_OFF
  File "/config/custom_components/control4/light.py", line 170, in is_on
    return self._coordinator.data[self._idx]["value"] > 0
KeyError: 224
2020-08-16 03:19:52 ERROR (MainThread) [homeassistant.components.light] control4: Error on device update!
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/helpers/entity_platform.py", line 335, in _async_add_entity
    await entity.async_device_update(warning=False)
  File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 454, in async_device_update
    await self.async_update()  # type: ignore
  File "/config/custom_components/control4/__init__.py", line 224, in async_update
    await self._coordinator.async_request_refresh()
  File "/usr/src/homeassistant/homeassistant/helpers/update_coordinator.py", line 125, in async_request_refresh
    await self._debounced_refresh.async_call()
  File "/usr/src/homeassistant/homeassistant/helpers/debounce.py", line 60, in async_call
    await self.hass.async_add_job(self.function)  # type: ignore
  File "/usr/src/homeassistant/homeassistant/helpers/update_coordinator.py", line 192, in async_refresh
    update_callback()
  File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 281, in async_write_ha_state
    self._async_write_ha_state()
  File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 305, in _async_write_ha_state
    sstate = self.state
  File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 595, in state
    return STATE_ON if self.is_on else STATE_OFF
  File "/config/custom_components/control4/light.py", line 170, in is_on
    return self._coordinator.data[self._idx]["value"] > 0
KeyError: 224
2020-08-16 03:19:57 ERROR (MainThread) [homeassistant] Error doing job: Task exception was never retrieved
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/helpers/update_coordinator.py", line 118, in _handle_refresh_interval
    await self.async_refresh()
  File "/usr/src/homeassistant/homeassistant/helpers/update_coordinator.py", line 192, in async_refresh
    update_callback()
  File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 281, in async_write_ha_state
    self._async_write_ha_state()
  File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 305, in _async_write_ha_state
    sstate = self.state
  File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 595, in state
    return STATE_ON if self.is_on else STATE_OFF
  File "/config/custom_components/control4/light.py", line 170, in is_on
    return self._coordinator.data[self._idx]["value"] > 0
KeyError: 224

The Task exception error repeats every poll. Screenshots;

[lawtancool]

@garyak I've made another change, please redownload and try again.

I'm trying a different way of determining whether a light supports dimming or not - please check to see if the lights that support dimming dim and the ones that do not support dimming do not.

[garyak]

Lights on the C4 dimmers work again. They turn On/Off and dim using the Light Card. They don't retain their settings though. Getting lots of these:

2020-08-16 13:18:55 ERROR (MainThread) [homeassistant.components.light] Error while setting up control4 platform for light
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/helpers/entity_platform.py", line 192, in _async_setup_platform
    await asyncio.gather(*pending)
  File "/usr/src/homeassistant/homeassistant/helpers/entity_platform.py", line 301, in async_add_entities
    await asyncio.gather(*tasks)
  File "/usr/src/homeassistant/homeassistant/helpers/entity_platform.py", line 474, in _async_add_entity
    entity.async_write_ha_state()
  File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 281, in async_write_ha_state
    self._async_write_ha_state()
  File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 305, in _async_write_ha_state
    sstate = self.state
  File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 595, in state
    return STATE_ON if self.is_on else STATE_OFF
  File "/config/custom_components/control4/light.py", line 163, in is_on
    return self._coordinator.data[self._idx]["value"] > 0
KeyError: 223

New device has appeared:

The Sunfire Amp is a C4 remote switch controlling AC power to the amp. Not sure if the wireless_outlet_switch is the same device. I'm only using one in my installation.

[garyak]

I created a card for the Sunfire Amp entity and can switch the amp on/off. I get a "Failed to call service light_on/off 223 for each action.

Sunfire Amp and the wireless switch controlling it are separate entities in the Composer project.

[lawtancool]

Lights on the C4 dimmers work again. They turn On/Off and dim using the Light Card. They don't retain their settings though.

@garyak What do you mean by "they don't retain their settings"?

It seems that the switch devices might be using a different Control4 API variable to show their state. I've updated the custom component again to provide more logging - please redownload and try again.

[garyak]

The Hue lights retain their settings between illumination events. So, if I set the illumination value to 50% then shutoff the light. Next time I turn the light On, it turns On at 50% without automation. I'll update and report back.

UPDATE:

Lights work as expected. On/Off/Dim. Sunfire switches On/Off using entities card. Wireless Outlet was not configured. Error log shows:

2020-08-16 16:10:19 ERROR (MainThread) [custom_components.control4.light] Couldn't get light state data for Wireless Outlet Switch, skipping setup. Available item variables: <coroutine object C4Director.getItemVariables at 0x7f5bca6ecbc0>

No other errors related to C4 appear in the HA log (level set to error).

[lawtancool]

2020-08-16 16:10:19 ERROR (MainThread) [custom_components.control4.light] Couldn't get light state data for Wireless Outlet Switch, skipping setup. Available item variables: <coroutine object C4Director.getItemVariables at 0x7f5bca6ecbc0>

Sorry @garyak I made a typo in the new logging code 🤦‍♂️ Can you redownload and try it again?

The Hue lights retaining their settings is probably just a Hue/Control4 function - Home Assistant is not supposed to do that, as far as I know.

[garyak]

Lights and switch still working as expected. I'm not testing inclusion in scenes or automation, but based on current behavior, I'd expect the lights to function normally with a service call. Setting retention doesn't come into play there. Here's what's in the log now:

2020-08-16 17:03:23 ERROR (MainThread) [custom_components.control4.light] Couldn't get light state data for Wireless Outlet Switch, skipping setup. Available item variables: [
 {
  "id": 223,
  "varName": "Outlet 1 Minutes On",
  "type": "Number",
  "hidden": 0,
  "value": 0,
  "variableId": 1000,
  "name": "Wireless Outlet Switch",
  "roomName": "AV Rack"
 },
 {
  "id": 223,
  "varName": "Outlet 1 Minutes Off",
  "type": "Number",
  "hidden": 0,
  "value": 4661,
  "variableId": 1001,
  "name": "Wireless Outlet Switch",
  "roomName": "AV Rack"
 },
 {
  "id": 223,
  "varName": "Outlet 1 Minutes On Today",
  "type": "Number",
  "hidden": 0,
  "value": 0,
  "variableId": 1002,
  "name": "Wireless Outlet Switch",
  "roomName": "AV Rack"
 },
 {
  "id": 223,
  "varName": "Outlet 2 Minutes On",
  "type": "Number",
  "hidden": 0,
  "value": 0,
  "variableId": 1003,
  "name": "Wireless Outlet Switch",
  "roomName": "AV Rack"
 },
 {
  "id": 223,
  "varName": "Outlet 2 Minutes Off",
  "type": "Number",
  "hidden": 0,
  "value": 4661,
  "variableId": 1004,
  "name": "Wireless Outlet Switch",
  "roomName": "AV Rack"
 },
 {
  "id": 223,
  "varName": "Outlet 2 Minutes On Today",
  "type": "Number",
  "hidden": 0,
  "value": 0,
  "variableId": 1005,
  "name": "Wireless Outlet Switch",
  "roomName": "AV Rack"
 }
]

[lawtancool]

@garyak From the log output, it seems that the Wireless Outlet doesn't provide any variables that can tell Home Assistant whether its on or not.

Can you screenshot what the Outlet looks like in the official Control4 app? It would be interesting to see if it can display the on/off state or not.

[lawtancool]

Actually @garyak I've pushed another change to the custom component that dumps info about all the devices on your Control4 controller into the error log, could you redownload and post the error output? (warning: it will be very long)

This should help me investigate how the Wireless Outlet works - it seems to be different than the normal lights.

[garyak]

The outlet isn't displayed on the C4 app. I'm getting status indirectly through the Sunfire Amp. The switch serves as the power switch for the amp. These are the switch properties displayed in composer:

It is a single-purpose device. I'm sure others have a need for direct control, but I don't. Right now the switch doesn't appear in integrations or entities. I can live without it. I'll continue to help test to determine whether or not you can access its status directly.

[garyak]

ha.log

[lawtancool]

@garyak Thanks for the log! Your setup that ties the outlet switch to the Sunfire AMP probably removes the ability to control it directly - the AMP has all the properties that would usually be on the switch itself.

As long as everything else works fine, I think this issue can be closed. Users who don't tie their outlets to other devices should be able to control them directly with the code I've written.

[garyak]

Thanks for you work on this. Could you post a replacement light.py that produces the minimum of log contents? I'd sure like to have more control over my C4 setup. I'm certain I'm not alone in that desire. :-)

[lawtancool]

@garyak I've pushed a change that removes the unnecessary logging. It'll also be part of Home Assistant codebase soon (hopefully) https://github.com/home-assistant/core/pull/38952

[garyak]

I'm moving to a HassOS installation today. Setup with the latest 114.3 Control4 integration. I'm getting similar errors to those I saw on the Supervised installation:

2020-08-22 17:13:20 ERROR (MainThread) [homeassistant.config_entries] Error setting up entry control4_ea5_000FFF1B47F9 for control4
Traceback (most recent call last):
  File "/usr/local/lib/python3.8/site-packages/pyControl4/account.py", line 71, in __sendAccountAuthRequest
    async with self.session.post(
  File "/usr/local/lib/python3.8/site-packages/aiohttp/client.py", line 1012, in __aenter__
    self._resp = await self._coro
  File "/usr/local/lib/python3.8/site-packages/aiohttp/client.py", line 504, in _request
    await resp.start(conn)
  File "/usr/local/lib/python3.8/site-packages/aiohttp/client_reqrep.py", line 847, in start
    message, payload = await self._protocol.read()  # type: ignore  # noqa
  File "/usr/local/lib/python3.8/site-packages/aiohttp/streams.py", line 591, in read
    await self._waiter
asyncio.exceptions.CancelledError

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/config_entries.py", line 222, in async_setup
    result = await component.async_setup_entry(  # type: ignore
  File "/usr/src/homeassistant/homeassistant/components/control4/__init__.py", line 59, in async_setup_entry
    await account.getAccountBearerToken()
  File "/usr/local/lib/python3.8/site-packages/pyControl4/account.py", line 145, in getAccountBearerToken
    data = await self.__sendAccountAuthRequest()
  File "/usr/local/lib/python3.8/site-packages/pyControl4/account.py", line 75, in __sendAccountAuthRequest
    return await resp.text()
  File "/usr/local/lib/python3.8/site-packages/async_timeout/__init__.py", line 45, in __exit__
    self._do_exit(exc_type)
  File "/usr/local/lib/python3.8/site-packages/async_timeout/__init__.py", line 92, in _do_exit
    raise asyncio.TimeoutError
asyncio.exceptions.TimeoutError

These errors had gone away on HA Supervised on Ubuntu, Docker_CE, HAOS-64 4.12, and HA 114.3. I'm running on a RPi 3b+. Created sensors/switches remain available until restart, at which point they are unavailable when HA comes back up. Need to redo the integration for the entities to become available again. When available, the dimmers and switch work as expected.

[lawtancool]

@garyak This just looks like the connection to the Control4 servers timed out before it could login. If this only happens on HassOS I'd be inclined to think its a OS issue.

It could also be Control4 servers having a temporary outage/glitch - does this still happen?

[garyak]

I've moved the installation back to the NUC. The start-up errors no longer appear in the HA Log. All software and configurations are identical. So far haven't had to redo the integration. I'll close this again and hopefully everything will continue to work.