Update to 69.0/1: how to debug config error Hassio/Hue setup

HI,

since updating to 69.0 and now 69.1 Hassio won’t load anymore. Keep getting this:

47

in the homeassistant.log this is repeated on every boot:

018-05-02 23:44:04 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting
2018-05-02 23:44:06 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting
2018-05-02 23:44:07 INFO (MainThread) [homeassistant.setup] Setting up hassio
2018-05-02 23:44:12 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting
2018-05-02 23:44:14 ERROR (MainThread) [homeassistant.core] Error doing job: Task exception was never retrieved
Traceback (most recent call last):
  File "/usr/lib/python3.6/site-packages/homeassistant/helpers/entity.py", line 222, in async_update_ha_state
    attr = self.state_attributes or {}
  File "/usr/lib/python3.6/site-packages/homeassistant/components/weather/__init__.py", line 113, in state_attributes
    ATTR_WEATHER_HUMIDITY: round(self.humidity)
TypeError: type NoneType doesn't define __round__ method
2018-05-02 23:44:16 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting
2018-05-02 23:44:19 ERROR (MainThread) [homeassistant.components.light.hue] Unable to reach bridge 192.168.1.212
2018-05-02 23:44:19 WARNING (MainThread) [homeassistant.setup] Setup of hassio is taking over 10 seconds.
2018-05-02 23:44:19 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting
2018-05-02 23:44:20 ERROR (MainThread) [homeassistant.components.hassio.handler] Timeout on /supervisor/ping request
2018-05-02 23:44:20 ERROR (MainThread) [homeassistant.components.hassio] Not connected with Hass.io
2018-05-02 23:44:20 INFO (MainThread) [homeassistant.setup] Setup of domain hassio took 13.1 seconds.
2018-05-02 23:44:20 ERROR (MainThread) [homeassistant.setup] Setup failed for hassio: Component failed to initialize.
2018-05-02 23:44:25 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting
2018-05-02 23:44:28 ERROR (MainThread) [homeassistant.core] Error doing job: Task was destroyed but it is pending!
2018-05-02 23:44:31 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting
2018-05-02 23:44:33 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting

looks like it has to do with the new Philips Hue implementation, but im not sure. Could be the other way round, that Hue is frustrated by the Hassio issues. They seem related, and causing Hue to not see the lights intermittently, and showing unavailable (not beschikbaar):

while in fact the Hue hub is visible and connectable all the way:

01

My update was done from a fine working setup on 67.1 , with Hassio loaded in the frontend.

What could i do to see whats wrong? Ive set the logger to debug on hassio and setup, so no more detail is to be expected here I guess.

thanks, Marius

Looks like the weather component is causing the issues. Turn on debug and see what other info you get

this specific weather error is already reported on github, no progress is being made unfortunately. I did find out is has to do with the Buienradar platform, as taking that out (and leaving yweather and open weathermap, and the custom weather card seem not to cause further issues)
Ive change the other environmental sensors (mold indicator, windchill sensors etc) to use yweahter, and that works even better, since that is populated quicker.

this error now continues to flood the log:

2018-05-03 23:57:01 ERROR (MainThread) [homeassistant.core] Error doing job: Exception in callback <function async_track_point_in_utc_time.<locals>.point_in_time_listener at 0x6df05c48>
Traceback (most recent call last):
  File "uvloop/cbhandles.pyx", line 49, in uvloop.loop.Handle._run
  File "/usr/lib/python3.6/site-packages/homeassistant/helpers/event.py", line 211, in point_in_time_listener
    hass.async_run_job(action, now)
  File "/usr/lib/python3.6/site-packages/homeassistant/core.py", line 248, in async_run_job
    target(*args)
  File "/usr/lib/python3.6/site-packages/homeassistant/helpers/script.py", line 95, in async_script_delay
    self._async_listener.remove(unsub)
ValueError: list.remove(x): x not in list

and the Hassio issue is still there…

Have you tried stripping back your config and starting it with nothing to see if the error persists?

no full stripping back yet, but I did take out the latest changes before upgrading to 0.69 and 0.69.1 with a working Hassio implementation.
Issues in Hassio and Hue came following the update.

through a total fluke (unfortunately not which…) suddenly all my entities were displayed as if not configured with a default_view, with all their little icons on the home page…
Only positive side was that suddenly Hassio was appearing in the left side bar. It still is there ! (…)

having checked all parts of my setup, I must confess I am completely in the dark as to why Hassio won’t appear in regular business. Everything seems to work as it should, aside from the Hue issue mentioned above.

Only thing that might hint to an error somewhere is this line:

[homeassistant.components.hassio.handler] Timeout on /supervisor/ping request

How could i find out more about this error? What could possibly be causing it?

Not sure to be honest.

starting to think it might be a router issue… had asuswrt issues before the upgrade to 69.1

just as a security check: Ive just deleted the pf on the router from duckdns 8123 to 8123, leaving only 443 for Letsencrypt, and have the base-url in my config set as domain.duckdns.org. Without the :8123 port indicator.

Is that correct?
Hassio seems to be quite responsive, and can be reached form the outside…

Had to ditch Influxdb for the moment, as i think it caused horrible connection time outs, I’ve indeed seen disappearing afterwards.

update 3:
cheered too soon… took only 2 reboots to kill Hassio again, without even changing anything in the files, other than updating 2 add-on’s in the Hassio system…

#bangingheadagainstthewall

update 2:
lo and behold, ive got Hassio!
in a desperate attempt to comment out extra settings in the configuration.yaml, I commented out weather: pointing the a weather.yaml file with contents:

#- platform: openweathermap
#  api_key: !secret openweather_key

- platform: yweather
  name: Home

#- platform: yweather
#  name: Weer

#- platform: buienradar
#  name: !secret buienradar_station

This worked just fine for the only left yweather component , which in itself was customized via the
- /local/custom_ui/custom-weather-card.html
tis custom card was the best of the weather cards sofar, even better than the new weather card in Hassio…

maybe theres a setting in that configuration blocking Hassio, and still allowing the card to be configured. Further investigating is to be done…

anyways, for completeness sake here’s he relevant bit of the log:

2018-05-21 00:38:23 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting
2018-05-21 00:38:26 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting
2018-05-21 00:38:29 INFO (MainThread) [homeassistant.setup] Setting up hassio
2018-05-21 00:38:30 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting
2018-05-21 00:38:33 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting
2018-05-21 00:38:37 ERROR (MainThread) [homeassistant.components.light.hue] Unable to reach bridge 192.168.1.212
2018-05-21 00:38:39 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting
2018-05-21 00:38:40 WARNING (MainThread) [homeassistant.setup] Setup of hassio is taking over 10 seconds.
2018-05-21 00:38:45 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting
2018-05-21 00:38:50 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting
2018-05-21 00:38:54 ERROR (MainThread) [homeassistant.core] Error doing job: Task was destroyed but it is pending!
2018-05-21 00:38:55 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting
2018-05-21 00:38:59 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting
2018-05-21 00:39:01 INFO (MainThread) [homeassistant.setup] Setup of domain hassio took 31.4 seconds.
2018-05-21 00:39:02 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting
2018-05-21 00:39:05 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting
2018-05-21 00:39:08 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting
2018-05-21 00:39:16 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting
2018-05-21 00:39:19 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting
2018-05-21 00:39:24 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting

update 1:

having checked and rechecked the full setup, disabled most anything, and reorganized into packages for easy en/disabling parts, I still cant get Hassio to initiate. Separated it from the Hue issues that also still are there, ive disabled that now completely, and have this a the end of the startup:

2018-05-20 23:33:10 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting
2018-05-20 23:33:13 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting
2018-05-20 23:33:18 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting
2018-05-20 23:33:21 INFO (MainThread) [homeassistant.setup] Setting up hassio
2018-05-20 23:33:22 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting
2018-05-20 23:33:24 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting
2018-05-20 23:33:26 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting
2018-05-20 23:33:29 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting
2018-05-20 23:33:31 WARNING (MainThread) [homeassistant.setup] Setup of hassio is taking over 10 seconds.
2018-05-20 23:33:32 ERROR (MainThread) [homeassistant.components.hassio.handler] Timeout on /supervisor/ping request
2018-05-20 23:33:32 ERROR (MainThread) [homeassistant.components.hassio] Not connected with Hass.io
2018-05-20 23:33:32 INFO (MainThread) [homeassistant.setup] Setup of domain hassio took 11.1 seconds.
2018-05-20 23:33:32 ERROR (MainThread) [homeassistant.setup] Setup failed for hassio: Component failed to initialize.
2018-05-20 23:33:35 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting
2018-05-20 23:33:42 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting
2018-05-20 23:33:45 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting
2018-05-20 23:33:48 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting
2018-05-20 23:33:50 ERROR (MainThread) [homeassistant.core] Error doing job: Task was destroyed but it is pending!
2018-05-20 23:33:50 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting

Im completely out of ideas what to do, or how to proceed investigating the error. Any thoughts would be appreciated…

Btw, other than the Hue problems, my full setup seems to work just fine, except for exactly 1 automation at startup. I take it this stems from the timer out of sync error, since when i run the automation manually it works just as it should.
again, all this started after upgrading to .69 and .69.1 before which Hue was implemented differently, and worked beautifully…
this is the automation:

# Startup
- alias: 'Opstart'
  id: '1511601488028'
  initial_state: 'on'
  trigger:
    platform: homeassistant
    event: start
  condition: []
  action:
    - delay: 00:00:03
    - service: homeassistant.turn_on
      entity_id: script.opstart
    - delay: 00:00:03
    - service: homeassistant.turn_on
      entity_id: script.mode_normal
    - delay: 00:00:02
    - service: notify.notify
      data:
        message: Startup went fine.
    - delay: 00:00:02
    - condition: state
      entity_id: input_boolean.notify_notify
      state: 'on'
    - service: notify.marijn
      data_template:
        message: 'HomeAssistant is back up and running since 
        {{ as_timestamp(now()) | timestamp_custom("%d %b %X") }} and it is 
        {{ states.sensor.rsd_temperature.state}} degrees.'
        data:
          push:
            sound: "US-EN-Morgan-Freeman-Welcome-Home.wav"

I do get to see the message: Startup went fine, and the notify.marijn is done, but the intermediate scripts aren’t run, and the push:sound isnt executed either.