Automations (that use state conditions?) broke with 0.115.3 upgrade

mattcantu · September 27, 2020, 8:00am

I’m running HA in a python venv on a raspi 3b+. I upgraded HA from 0.114.4 to 0.115.3 on Friday evening, and a bunch of different things broke. Rather than try to cover them all in one post, I’m hoping to get help with the most pressing issue.

I have Insteon switches throughout the house. I’ve been using insteon-mqtt for a couple years (no recent changes on that front). Most switches trigger automations to turn on hue lights. For example, if I toggle the Insteon switch named switch.kitchen_island from Off to On, it should trigger the following automation:

<snip>
  # Kitchen Island On
  - id: a_kitchen_island_on
    alias: Kitchen Island On
    initial_state: "on"
    trigger:
      - platform: state
        entity_id: switch.kitchen_island
        from: "off"
        to: "on"
    condition:
      - condition: state
        entity_id: input_boolean.kitchen_island_bool
        state: "off"
    action:
      - service: hue.hue_activate_scene
        data:
          group_name: 'Kitchen Island'
          scene_name: 'Concentrate'
      - service: light.turn_on
        data:
          entity_id: light.kitchen_island
          brightness_pct: 100
<snip>

I see the mqtt activity in the home-assistant.log when I enable debug…

<snip>
2020-09-26 17:09:01 DEBUG (Thread-5) [paho.mqtt.client] Received PUBLISH (d0, q0, r0, m0), 'insteon/<REDACTED>/state', ...  (2 bytes)
2020-09-26 17:09:01 DEBUG (MainThread) [homeassistant.components.mqtt] Received message on insteon/<REDACTED>/state: b'ON'
2020-09-26 17:09:01 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=switch.kitchen_island, old_state=<state switch.kitchen_island=off; friendly_name=Kitchen Island @ 2020-09-26T16:55:18.723421-07:00>, new_state=<state switch.kitchen_island=on; friendly_name=Kitchen Island @ 2020-09-26T17:09:01.833860-07:00>>
<snip>

…so I don’t think the problem is with the insteon-mqtt integration.

If I go to Developer Tools > States in the the HA web frontend, click on the “i” symbol to the left of switch.kitchen_island, and then toggle the switch from off to on, the automation doesn’t trigger either… though the LEDs on the Insteon switch do indicate that the switch has been turned on via the GUI.

I’m stuck at this point, so figured I’d post here for some assistance.

A couple things to note, since I’m not sure if they are related to the problem above.

Since the upgrade to 0.115.3, Home Assistant hasn’t finished loading. I see “Home Assistant is starting, not everything will be available until it is finished.” in the GUI. I let HA run overnight, and it the message was still there Saturday morning. I’ve since rebooted many times throughout the day while attempting to troubleshoot these issues. I don’t see any obvious errors in home-assistant.log.
Since the upgrade to 0.115.3, the recorder no longer makes changes to the database. I had been running mariadb on my raspi prior to the upgrade. In an attempt to troubleshoot the issue, I created a new mariadb on a Synology NAS and updated HA to use the new db. Four tables were created by HA after I updated the config to point to the synology and restarted HA. HA adds a new row to the recorder_runs table with every reboot. The schema_changes table has a single row. The events table and states table have 0 rows, even though plenty of states have changed throughout the day.

Is it possible the automation is failing because of the state condition and the fact that the recorder doesn’t appear to be keeping track of state at the moment?

Anyone have any tips on how to proceed?

petro · September 27, 2020, 11:30am

You have to wait for home assistant to fully start. If it never fully starts, thats where you should start debugging.

mattcantu · September 27, 2020, 8:19pm

Thanks, @petro! That at least gives me a good starting point.

Is there a particular log level you suggest I use to troubleshoot this? So far I’ve tried debug and info, and didn’t see any obvious errors (e.g. no tracebacks) indicating that HA is having trouble starting. I only see “Home Assistant is starting, not everything will be available until it is finished.” in the GUI.

Here are warnings and errors from info level:

$ grep 'ERROR' home-assistant.log

$ grep 'WARNING' home-assistant.log 
2020-09-27 13:09:29 WARNING (MainThread) [homeassistant.loader] You are using a custom integration for senseme which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you experience issues with Home Assistant.
2020-09-27 13:09:31 WARNING (Recorder) [homeassistant.components.recorder] Ended unfinished session (id=13 from 2020-09-27 20:06:48)
2020-09-27 13:09:46 WARNING (MainThread) [homeassistant.setup] Setup of zeroconf is taking over 10 seconds.
2020-09-27 13:09:48 WARNING (MainThread) [homeassistant.components.binary_sensor] Setup of binary_sensor platform mqtt is taking over 10 seconds.
2020-09-27 13:09:48 WARNING (MainThread) [homeassistant.components.light] Setup of light platform mqtt is taking over 10 seconds.
2020-09-27 13:09:48 WARNING (MainThread) [homeassistant.components.switch] Setup of switch platform mqtt is taking over 10 seconds.

I’ll temporarily turn off the sensme integration, though it worked fine before the upgrade. Then I’ll look into the errors for homeassistant.components.binary_sensor, homeassistant.components.light, and homeassistant.components.switch. Then I’ll do some more searching through the forums to see if there are other related threads, but none of the things I read yesterday seemed relevant (at the time).

P.S. I had gone over the breaking changes for 0.115.3. The only thing that stood out were changes to templates. A bunch of my template sensors did break, but they aren’t throwing any errors in the log file. They just show as unavailable in Developer Tools > States > Entity > State. I figured I’d try to tackle the issue with my automations before fixing the templates.

mattcantu · September 27, 2020, 11:24pm

Well, I deleted the senseme integration, and also commented out the majority of configuration.yaml. It is very bare bones at this point. After restarting HA, it still never finishes loading and doesn’t throw any errors.

I’m not seeing any errors in info or debug. If there were errors in the logs, at least I’d be able to attempt to troubleshoot.

Should HA be throwing errors if it can’t finish the startup process? If so, what log level should they appear in?

mattcantu · September 29, 2020, 2:18am

In case anyone is still following along. After burning 8+ hours troubleshooting, I realized I could have just started over. I would love to know why a seemingly simple upgrade borked my system, but the logs weren’t any help.

I’m up and running again. I stopped the service, moved the .homeassistant folder to .homeassistant2, and slowly added sections of my config over to the newly recreated .homeassistant folder. I used this as an opportunity to remove some cruft from my config, but I did copy over the automations verbatim and they are working just fine.

Oh well. Overall, I’ve had a pretty good run with Home Assistant these past few years. I’ll chalk this up to gremlins, and knock on wood that I don’t get bit again anytime soon.