Core: Timer got out of sync. Resetting

Created on 16 Apr 2017  ·  107Comments  ·  Source: home-assistant/core

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.42-DEV

Python release (python3 --version):

Component/platform: Core

Description of problem:
In the recent versions I have been getting this a lot in log.

17-04-16 03:55:26 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting
17-04-16 04:17:37 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting
17-04-16 04:20:42 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting
17-04-16 04:52:41 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting
17-04-16 05:04:35 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting
17-04-16 05:47:22 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting
17-04-16 06:07:44 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting

Expected:
No entry in log.

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




    1. 2.
  1. 3.

Traceback (if applicable):


Additional info:

Most helpful comment

Let me explain a bit what it means for the timer to get out of sync:

Home Assistant fires a time changed event every second. That is what makes the system tick. Every time when it fires an event, it will schedule itself to fire the next event. The event loop is supposed to just contain very small tasks so that we get to firing the next time event on time.

Sometimes code will not behave correctly and it does for example I/O inside the event loop. I/O is doing actual physical work and thus can add slowdowns. If the system is slowed down _too_ much, by the time we have to fire an event, it's actually already time for the next event. (note, this error also happens if your system goes into standby or suspends via hibernation)

If you're interested, the code is actually only 15 lines: https://github.com/home-assistant/home-assistant/blob/dev/homeassistant/core.py#L1107-L1122

All 107 comments

Running 0.42.3 and getting a lot of these too, come in blocks of three about every 2 to 3 minutes.

17-04-16 21:47:28 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting
17-04-16 21:47:30 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting
17-04-16 21:47:32 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting
17-04-16 21:49:05 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting
17-04-16 21:49:15 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting
17-04-16 21:49:18 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting
17-04-16 21:49:33 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting
17-04-16 21:49:35 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting
17-04-16 21:49:40 WARNING (MainThread) [homeassistant.components.media_player] Updating sonos media_player took longer than the scheduled update interval 0:00:10
17-04-16 21:49:50 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting
17-04-16 21:49:53 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting
17-04-16 21:50:01 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting
17-04-16 21:50:15 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting

Running on a Pi 2 bang up to date, with z-wave module.
Running top shows that I am not hitting the CPU too hard, max of 80%

Regards

Dave

I have the exact same issue on a Pi3 and I've had it for a while. It's flooding my log.

I have this same issue with hass installed in a VM

+1

Also here:

Apr 20 22:06:17 tower hass[10946]: ERROR:homeassistant.core:Timer got out of sync. Resetting
...
Apr 20 22:14:31 tower hass[10946]: ERROR:homeassistant.core:Timer got out of sync. Resetting
Apr 20 22:15:00 tower hass[10946]: ERROR:homeassistant.core:Timer got out of sync. Resetting
Apr 20 22:18:11 tower hass[10946]: ERROR:homeassistant.core:Timer got out of sync. Resetting
Apr 20 22:24:22 tower hass[10946]: ERROR:homeassistant.core:Timer got out of sync. Resetting
Apr 20 22:26:32 tower hass[10946]: ERROR:homeassistant.core:Timer got out of sync. Resetting

Same here on pi3

Same here, pi2. Hassbian image, all up to date.

I fixed deleting 350Mb of Database and removing History Statistics Sensor from configuration.

+1 on pi3

Given the hardware the errors happen on, it seems like any platform without an real time clock (RTC) has a problem? RasPis do not have an RTC, and I am not 100% sure on what my VMs do for their RTC

same here on Pi3

I have the same problem on a fresh install of Home Assistant 0.43.2 with only 2 media player's setup and presence detection through my netgear:

17-04-29 21:05:48 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting
17-04-29 21:08:59 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting

@irltankman where is hass installed on? what kind of machine?

Raspberry Pi Model B (Rev 2.0, 512Mb)

I have disabled my samsung TV's (my 6 series using websockets wasn't responding to commands from HA anyway) and the issue appears to have gone away. Issue with samungtv mediaplayer maybe?

Same here. RPI 3.

I see this message each time I select the History or Logbook on my RPi3 with 0.51.1

I had hoped adding samsung_tv to the ignore list for discovery would help things, but it hasn't

There hasn't been any activity on this issue recently. Due to the high number of incoming GitHub notifications, we have to clean some of the old issues, as many of them have already been resolved with the latest updates.

Please make sure to update to the latest Home Assistant version and check if that solves the issue. Let us know if that works for you by adding a comment :+1:

0.55 still happening:

    Line 3210: 2017-10-18 23:17:32 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting
    Line 9469: 2017-10-19 04:27:49 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting
    Line 20047: 2017-10-19 12:52:13 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting
    Line 30858: 2017-10-19 20:56:30 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting
    Line 31097: 2017-10-19 20:56:33 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting
2017-10-20 23:03:58 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting
2017-10-20 23:04:47 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting

The first line was caused by loading the History page. The second line was caused by loading the Logbook page. Running Home Assistant 0.55.x with an external MariaDB (MySQL) instance for the recorder.

0.57.2 - Still happening.

Nov 18 05:03:02 Carlo-Pi hass[31296]: 2017-11-18 05:03:02 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting
Nov 18 05:03:52 Carlo-Pi hass[31296]: 2017-11-18 05:03:52 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting
Nov 18 05:04:04 Carlo-Pi hass[31296]: 2017-11-18 05:04:04 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting

0.58 - Still happening on a Synology NAS running the official home assistant image on Docker.

Same issue on my Synology NAS running the official docker image. I notice slow responds from Home Assistant (up to 30 seconds delay in any automations for example) and very high memory usage (4GB in use). Simple reset of the docker container solves it but it can happen again anytime. I'll try to do some more investigating but so far I did not see anything

I'm not experiencing high memory usage but rather high CPU usage (60%+).

Seeing this on 0.58.1 on a Pi 3, AIO install.

Same for me using 0.58.1 using Pi3 B using Debian 9.1 Stretch & AIO install:

2017-11-25 01:35:28 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting
2017-11-25 01:36:39 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting
2017-11-25 01:37:00 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting

Happened for me tonight, for first time.
0.58.1 on Debian / Orange Pi

Same thing with a RPI3 native installation, Linear HUSBZB-1 (zwave usb controller), one zwave device configured, 4 chromecast, 1 apple tv, Plex, mqtt sensors, NEST thermostat, and dd-wrt presence.

I got the samme issue when i was setting a timer for my switch. I used "wait"and it started filling the log. When i changed to "delay" instead the log errors seems to have stopped?

PI3 0.59.2 HassIO

I get a LOT of these errors. I do use wait_template a lot in my automation as well. Wonder if there is a correlation. The RPI is getting increasingly slow.. noticeably slow when performing actions. Hopefully some headway can be made with this issue.

0.59.2

I just started getting these errors after migration to 0.60. I previously seen these when I tried to enable BLE tracker (reason why I didn't use it), but now it's back. Also "climate" component is now responding slower "Setup of climate is taking over 10 seconds.".

I think 0.60 degraded something for RPI users. I use RPI 3 with HassIO.

eh, it isn't just RPI users, I'm running Ubuntu and this came out of nowhere. I've added nothing to my configuration since 0.50 and this started happening. I took out my chromecast thinking maybe discovery of it was causing the problem and I woke up this morning to my lights taking 30 seconds to turn on after I entered the room.

True, I'm running Hass om a pretty powerful NAS and it's happening to me too. Cpu and memory usage go high and the whole house is responding slow. Happens to me now 3 times a day so making it a but unusable. Currently I'm on a debug hunt. The issue is perfectly reproducible if you add some long running call in a module/component so I'm pretty sure the culprit is somewhere in a component misbehaving and/or combination with automations.

I'm currently testing by enabling/disabling components one-by-one until I find which one is blocking. Bit time consuming but so be it. I'd suggest others to do the same, after all this is a community driven product, right.

I can trigger it, just by opening history or logbook.

0.60
2017-12-22 00:23:41 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting

Same for me driving me up the wall moved from Hassio zero issues to Hassbian moving my config over system becomes laggy unstable automation won’t run or take a long time to do so. I’m on hassbian 0.60
Lots of random timer out of sync errors

I think I found the problem with mine. I was getting these errors starting with 0.60.0.

When I upgraded to 0.59 I added:

frontend:
  javascript_version: latest

When I upgraded to 0.60 I removed it because of a documented issue with ios and I had:

frontend:

This caused some other problems as well as it seems it parses User-Agent to determine what your browser supports so now I moved to:

frontend:
  javascript_version: es5

After using the last config I noticed all the Timer got out of sync. Resetting disappeared.

I'm not sure if it's the same for everyone, but for me it solved the problem.

Edit 1: It seems there are two other issues that might be linked to this one and the performance problem #11201 and #11234

PS:
I'm running HassIO on a Raspberry PI 3
I'm using bluetooth scanner (not the BLE one)
I've removed MiFlora since last version as that caused other problems (waiting for a fix that is in pipeline)
My configuration is using packages (packages: !include_dir_named packages)
I have ios phones and I'm using xiaomi_aqara devices

I wish this fixed mine but it didn’t. :(

.

Check out my virtualization blog at www.vCloudInfo.comhttp://www.vCloudInfo.com!
Follow me : Twitter: @ccostan | FaceBook.comhttp://FaceBook.comVMwareInfo

On Dec 26, 2017, at 2:52 PM, ciotlosm <[email protected]notifications@github.com> wrote:

I think I found the problem with mine. I was getting these errors starting with 0.60.0.

When I upgraded to 0.59 I added:

frontend:
javascript_version: latest

When I upgraded to 0.60 I removed it because of a documented issuehttps://na01.safelinks.protection.outlook.com/?url=https%3A%2F%2Fgithub.com%2Fhome-assistant%2Fhome-assistant%2Fissues%2F11234&data=02%7C01%7CCarlo.Costanzo%40ipm.com%7Cbae5993a8acc4ad7813508d54c9a3a86%7C192fb3aaa4a64b9992a744a240ffed4f%7C0%7C0%7C636499147663130730&sdata=5BbWsrpYD27jfgyMxonVdZ6WzWebcXxpccos1ZxwLV0%3D&reserved=0 with ios and I had:

frontend:

This caused some other problems as well as it seems it parses User-Agent to determine what your browser supports so now I moved to:

frontend:
javascript_version: es5

After using the last config I noticed all the Timer got out of sync. Resetting disappeared.

I'm not sure if it's the same for everyone, but for me it solved the problem.


You are receiving this because you commented.
Reply to this email directly, view it on GitHubhttps://na01.safelinks.protection.outlook.com/?url=https%3A%2F%2Fgithub.com%2Fhome-assistant%2Fhome-assistant%2Fissues%2F7133%23issuecomment-354006633&data=02%7C01%7CCarlo.Costanzo%40ipm.com%7Cbae5993a8acc4ad7813508d54c9a3a86%7C192fb3aaa4a64b9992a744a240ffed4f%7C0%7C0%7C636499147663130730&sdata=4o8dB1Af4dyBa2Hnq7g5L%2Fzc%2FNq3IYeVw%2BGSSOXvg78%3D&reserved=0, or mute the threadhttps://na01.safelinks.protection.outlook.com/?url=https%3A%2F%2Fgithub.com%2Fnotifications%2Funsubscribe-auth%2FACD3NGIdsz4caGh-tMWKJnhHr1AhDM57ks5tEU6JgaJpZM4M-llr&data=02%7C01%7CCarlo.Costanzo%40ipm.com%7Cbae5993a8acc4ad7813508d54c9a3a86%7C192fb3aaa4a64b9992a744a240ffed4f%7C0%7C0%7C636499147663130730&sdata=RaPr%2FB%2Fi%2BYq4DszQi27IChMAO4atxG60OuWh6A2tooM%3D&reserved=0.

Same issue here with .60

2017-12-28 14:50:53 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting
2017-12-28 15:27:37 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting
2017-12-28 15:29:54 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting
2017-12-28 15:37:47 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting
2017-12-28 16:09:55 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting
2017-12-28 16:29:18 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting
2017-12-28 19:30:05 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting

Same issue with 0.58, 059 and 0.60 HASS.io on Raspberry Pi 3.
Tryed also with a ultra fast SD, the problem is come out also after a clean installation.

@CCOSTAN I tried that, and I thought it worked, but at 10PM last night the Timer got out of sync errors came back (so, it lasted a good bit longer than before).

Ive got the same output to the logfile running on rp3. Seems like the issue appears more often the more components I'm adding

This is not an ideal solution but I have much less of these errors after removing the snmp sensors from configuration.

I'm getting the same error with 60.1 on a pi3. It seems to be related to calling a shell_command:
play_sound: sudo omxplayer /usr/share/sounds/alsa/sound.mp3

I'm getting the error on 61.1. Not sure what the cause is in my setup. Can the error be any more detailed?

The issue will happen if one or more components hold up the event loop. So they're doing some stuff that takes time while it should't. In that case the event loop gets out of drift resulting in these errors. I was able to completely fix the issues by checking each and every script, automation and component for errors and prevent stuff from long running calls/actions. Also watch out if you're using Homebridge because I have seen multiple times that one was causing the issue when started before hass itself. A simple restart of homebridge after hass start/restart fixed it and making sure Homebridge only receives updated for components that are really needed.

@marcelveldt what's the best way of tracking down the culprit? I don't exactly know how long each automation/script/service will take.

Well, I just went into trouble of disabling all stuff and enable it one-by-one.
For me it was a combination of Homebridge and some advanced automations/scripts I wrote. In the process I came across a few modules that are not properly async written but it seems that hass takes care of wrapping that into some async helpers itself.

I am seeing this problem in 0.62 running on a freebsd box. Causing my zha service to flake out which requires a restart :|

Seems to have gotten worse in 0.62 so will likely downgrade, or maybe start disabling components to try and figure out which one is causing the problem.

I started with fresh installation of 0.62.1 and I still receive...

2018-02-03 07:52:24 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting

There is no added components, no changes to the configuration file. Just fresh installation.

Same problem, just installed and almost immediately there was an error :(
Raspberry Pi 3 + hass.io, last version 0.63.3

I have the same error (and as aresult slow reaction to the commands) when I run HomeAsisstant for many days. My solution currrently is to restart HA every night.

I have the same error when I start my HA 0.64 (I had the same problem on the 0.63, too).

My "tail -f ~homeassistant/.homeassistant/home-assistant.log" output:
2018-02-26 16:38:13 WARNING (MainThread) [homeassistant.setup] Setup of recorder is taking over 10 seconds.
2018-02-26 16:39:14 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting
2018-02-26 16:40:47 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting

I'm seeing this error regularly (around 5 times per hour). It's happening on 0.64, but was happening on a number of earlier releases as well. I'm using a Raspberry Pi3 with HA running in a python virtualenv.
In my case, it's not related to running HA for many days - I just restarted earlier today (to upgrade to 0.64) and it started happening right away

I'm curious - how is everyone running their instance of hass?

My setup: python virtualenv on Debian inside LXC on my Turris 1.1 router

@cmsimike In a Docker container on a Intel j1900 Dual Core 2.0GHz NUC.

@cmsimike I'm using hass on my RPi3 inside a virtualenv using Python 3.5.3 running kernel Linux HAPi3 4.9.35-v7+ #1014 SMP

hass.io on Rpi2B+

Hass.io on a Pi 3

On Tue, 27 Feb 2018 at 21:38, irltankman notifications@github.com wrote:

hass.io on Rpi2B+


You are receiving this because you commented.
Reply to this email directly, view it on GitHub
https://github.com/home-assistant/home-assistant/issues/7133#issuecomment-368876979,
or mute the thread
https://github.com/notifications/unsubscribe-auth/ADwn2x3mb1MBSZyqsOOWaVS9-BO-181jks5tZAVcgaJpZM4M-llr
.

>

Regards,

Andrew Munday

My setup is: Python virtualenv on Raspbian (stretch) on my old Raspberry Pi Model B Rev 2 ;-)

Im running 0.64.0 in Mac OSX 10.13.
Get it both in plain command line hass and hass --script macos install

2018-02-28 00:06:35 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting
2018-02-28 00:06:37 WARNING (MainThread) [homeassistant.components.binary_sensor] Updating ring binary_sensor took longer than the scheduled update interval 0:00:05
2018-02-28 00:06:46 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting
2018-02-28 00:06:50 WARNING (MainThread) [homeassistant.components.sensor] Updating vera sensor took longer than the scheduled update interval 0:00:05
2018-02-28 00:06:50 WARNING (MainThread) [homeassistant.components.binary_sensor] Updating ring binary_sensor took longer than the scheduled update interval 0:00:05
2018-02-28 00:06:50 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting

DS216j (DSM6.1, no docker)
Python3.5 with newest HA
report this error after using Bluetooth LE Tracker.

I'm also having this issue. Many times a day. Version 0.63.1 on Linux amd64.

Same issue, in most cases home-assistant becomes unresponsive and cpu spikes to 100%

Using version docker version of 0.64.3 on arch linux.

It's resulting in timer automations not working:

trigger:
     - platform: time
       minutes: '/1'
       seconds: 00

Same issue on 0.64.3 running in a virtual Ubuntu install with 1 CPU and 512MB of RAM.

I also have a trigger that fires off every 5 minutes.

trigger:
    platform: time
    minutes: '/5'
    seconds: 0

Previously I was on 0.63.3, which did not have the timer out of sync issue.

To see if this is a memory issue, I just updated the virtual server to have 1GB of RAM and 2 CPU. I'll monitor for today and will update here at end of day with results.

Let me know if there is anything else I can share about my server or install. Thanks!

Adding additional 512MB of RAM solved this issue for me. It seems that 0.64.3 just needs more resources than the previous version.

I'm not complaining, as 1GB total RAM is very acceptable and is in line with what a Pi 3 would have anyways, if I were to run HA on a Pi.

How did you do that

On 7 March 2018 at 23:30, nordicblue notifications@github.com wrote:

Adding additional 512MB of RAM solved this issue for me. It seems that
0.64.3 just needs more resources than the previous version.

I'm not complaining, as 1GB total RAM is very acceptable and is in line
with what a Pi 3 would have anyways, if I were to run HA on a Pi.


You are receiving this because you were mentioned.
Reply to this email directly, view it on GitHub
https://github.com/home-assistant/home-assistant/issues/7133#issuecomment-371323040,
or mute the thread
https://github.com/notifications/unsubscribe-auth/Aa5YZYREo7LLI2UlTNHsQnHNn4Y_Cmu7ks5tcG2KgaJpZM4M-llr
.

I'd be surprised if this issue is memory related. I have 16GB available and am seeing this issue once or twice a day.

@irltankman, I have a home server, a HP server, which runs VMWare ESXi. By using VMWare, I can run multiple servers on a single computer and one of those is a dedicated Home Assistant server running Ubuntu. So, with the use of VMWare, I can choose to assign as little RAM or as much RAM (as much as the server has) to any of the virtual servers running on my home server.

@jrkoiter, you are correct. Overnight, I received 5 new log entries of timer out of sync. Adding the memory did seem to help, as the entries are far fewer than before. But, this might be a coincidence. I reviewed the ESXi logs, for the VM CPU and RAM usage during the times that the log entries came in, and they are both low. CPU under 2% and memory under 25%.

Back to the drawing board...

@nordicblue I am running a very similar setup on a Dell server (Ubuntu VM on ESXi) and don’t have the error messages anymore. I used to see them all the time when running on a Raspberry Pi 3.

This is indeed a very strange issue.

@junior466: Just curious, how many CPU and how much RAM do you have allocated to your VM?

I have also seen this error disappear after moving from a raspberry pi to my old plex server.

i5 2nd gen, 6gb of RAM and SSD....running ubuntu server 17.10...hass installed in a venv python 3.6.3

@nordicblue I have 1 CPU, 2GB or RAM and 25GB of hard drive space. I have also allocated 10MB for video memory. Just in case you want to try the exact setup and see where it goes.

Thanks, @junior466. It's worth a shot. Worst case, if it still happens, I'll scale it back down again.

I'll let it run for a day or so and report back.

2 CPU, 2GB of RAM, 10MB of video and 32GB of storage, it happened once in 20 hours. Unless it is coincidence, it seems to get better with more resources on the server. No guarantee without additional troubleshooting, though.

It doesn't seem that anything stops working because of these errors.

They also always seem to accompany "Unable to find service home_assistant/turn_off". Anyone else see the same in their logs?

2018-03-09 06:14:22 WARNING (MainThread) [homeassistant.core] Unable to find service home_assistant/turn_off
2018-03-09 06:25:37 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting
2018-03-09 06:37:33 WARNING (MainThread) [homeassistant.core] Unable to find service home_assistant/turn_off
2018-03-09 06:51:13 WARNING (MainThread) [homeassistant.core] Unable to find service home_assistant/turn_off
2018-03-09 07:04:05 WARNING (MainThread) [homeassistant.core] Unable to find service home_assistant/turn_off

Let me explain a bit what it means for the timer to get out of sync:

Home Assistant fires a time changed event every second. That is what makes the system tick. Every time when it fires an event, it will schedule itself to fire the next event. The event loop is supposed to just contain very small tasks so that we get to firing the next time event on time.

Sometimes code will not behave correctly and it does for example I/O inside the event loop. I/O is doing actual physical work and thus can add slowdowns. If the system is slowed down _too_ much, by the time we have to fire an event, it's actually already time for the next event. (note, this error also happens if your system goes into standby or suspends via hibernation)

If you're interested, the code is actually only 15 lines: https://github.com/home-assistant/home-assistant/blob/dev/homeassistant/core.py#L1107-L1122

Thanks, @balloob , I appreciate the explanation and it makes sense. In a nutshell, something I have in my automations, for example, is getting hung and unable to complete itself in 1 second. Each automation does not spawn its own thread? Is there any way of troubleshooting what is causing the issue?

It makes sense that me adding on additional CPU and RAM helped the situation, as the system has additional resources to process everything that it needs to do. I changed the automation I had previously:

trigger:
    platform: time
    minutes: '/5'
    seconds: 0

to:

trigger:
    platform: template
    value_template: '{{ states.sensor.time.state == states.sensor.tv_off_time.state }}'

which helped. In the past 30 hours, I had 1 timer out of sync in the logs.

The other item that I continue to see is:

[homeassistant.components.media_player] Updating roku media_player took longer than the scheduled update interval 0:00:10

Which might also have something to do with the timer getting stuck/taking too long. Going to comment out all media players and see if the warnings go away completely.

So when a timer goes out of sync, a time trigger might actually be skipped. A state change will never fail. Always prefer state listeners over time listeners. There are just less state changes than time changes on average.

The update interval error is actually not related. It means that it takes us longer than the update interval (10 seconds in this case) to fetch the state from a Roku. If it wasn't for this guard (and warning), we would start another update process before the old one would be complete which would eventually lead up to a clogged system.

Automations don't spawn their own threads but you could have an action that calls a service that uses a thread. However, threads are run outside of the event loop and should not cause timer sync errors (unless you go 100% cpu or something).

Thank you @balloob for the explanation. Does this mean that an automation can't cause this error unless it's because the action clogs the cpu?
If there is no peak at ram or cpu,
is there anything we can check to try to find the culprit/culprits? Templates, specific components etc?

The automation itself won't cause it. That's all implemented in async with small tasks. And we can run a lot of small tasks. Don't take my word for it, run the benchmarks: hass --script benchmark will show you all the available benchmarks. We have ones for million state changed, time changed etc. On my 6yr old Mac a million state changed events takes around 8 seconds 👍

If you suspect some piece of code doing work inside the event loop, you can put the event loop in debug mode to figure it out. Note that this will slow down the whole system so don't run it all the time in this mode.

To enable debug mode, either set environment variable PYTHONASYNCIODEBUG=1 or from a custom component call hass.loop.set_debug(True).

If you run Home Assistant from the command line, setting environment variable will look like this:

 PYTHONASYNCIODEBUG=1 hass

This all great information. I will play around with debug tomorrow, to see if I can find the culprit.

Something is definitely off with my configuration, I'm pretty sure, as I am now also getting errors (randomly) for:

''Unable to find service home_assistant/turn_off''

@balloob, you are awesome for taking the time to answer everyone's questions.

home_assistant/turn_off -> I suspect this to be a misconfiguration on your end. The service is called homeassistant/turn_off.

Thanks again @balloob
I am running HassIO, how can I set the debug mode for the loop there?
Is it possible through the logger? I can access the command line through ssh, but don`t know what to write.

You can create a custom component. From the top of my head (so untested):

Create a file <config>/custom_components/enable_debug.py

In the file, add:

DOMAIN = 'enable_debug'

async def async_setup(hass, config):
    hass.loop.set_debug(True)
    return True

Then add to your configuration.yaml:

enable_debug:

home_assistant/turn_off -> I suspect this to be a misconfiguration on your end. The service is called homeassistant/turn_off.

That it was, It was on an automation that does not get used often. Fixed.

@balloob Thank you so much!

What I got is:

2018-03-12 17:43:41 WARNING (MainThread) [asyncio] Executing <Task finished coro=<async_enable_automation() done, defined at /usr/lib/python3.6/site-packages/homeassistant/components/automation/__init__.py:299> result=None created at /usr/lib/python3.6/site-packages/homeassistant/core.py:222> took 0.297 seconds
2018-03-12 17:43:45 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting
2018-03-12 17:43:45 ERROR (SyncWorker_5) [homeassistant.components.sensor.cert_expiry] Cannot connect to xxxxx.xxx.xxx
2018-03-12 17:43:45 WARNING (MainThread) [asyncio] Executing <Task finished coro=<Entity.async_update_ha_state() done, defined at /usr/lib/python3.6/site-packages/homeassistant/helpers/entity.py:186> result=None created at /usr/lib/python3.6/site-packages/homeassistant/core.py:218> took 0.478 seconds
2018-03-12 17:43:53 WARNING (MainThread) [asyncio] Executing <Task finished coro=<Group._async_state_changed_listener() done, defined at /usr/lib/python3.6/site-packages/homeassistant/components/group/__init__.py:576> result=None created at /usr/lib/python3.6/site-packages/homeassistant/core.py:222> took 0.858 seconds
2018-03-12 17:43:54 WARNING (MainThread) [asyncio] Executing <Task finished coro=<EntityPlatform._async_add_entity() done, defined at /usr/lib/python3.6/site-packages/homeassistant/helpers/entity_platform.py:175> result=None created at /usr/lib/python3.6/asyncio/tasks.py:311> took 0.510 seconds
2018-03-12 17:43:55 WARNING (MainThread) [asyncio] Executing <Task finished coro=<Entity.async_update_ha_state() done, defined at /usr/lib/python3.6/site-packages/homeassistant/helpers/entity.py:186> result=None created at /usr/lib/python3.6/site-packages/homeassistant/core.py:218> took 0.905 seconds
2018-03-12 17:43:55 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting
2018-03-12 17:43:55 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.varmekabel_kjokken_tid_365 is taking over 10 seconds
2018-03-12 17:43:56 WARNING (MainThread) [asyncio] Executing <Task finished coro=<Entity.async_update_ha_state() done, defined at /usr/lib/python3.6/site-packages/homeassistant/helpers/entity.py:186> result=None created at /usr/lib/python3.6/asyncio/tasks.py:311> took 0.474 seconds
2018-03-12 17:43:57 WARNING (MainThread) [asyncio] Executing <Task finished coro=<AutomationEntity.async_trigger() done, defined at /usr/lib/python3.6/site-packages/homeassistant/components/automation/__init__.py:329> result=None created at /usr/lib/python3.6/site-packages/homeassistant/core.py:222> took 0.981 seconds
2018-03-12 17:43:57 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting
2018-03-12 17:43:58 WARNING (MainThread) [asyncio] Executing <Task finished coro=<EntityPlatform._async_add_entity() done, defined at /usr/lib/python3.6/site-packages/homeassistant/helpers/entity_platform.py:175> result=None created at /usr/lib/python3.6/asyncio/tasks.py:311> took 0.509 seconds
2018-03-12 17:44:00 WARNING (MainThread) [asyncio] Executing <Task finished coro=<Entity.async_update_ha_state() done, defined at /usr/lib/python3.6/site-packages/homeassistant/helpers/entity.py:186> result=None created at /usr/lib/python3.6/site-packages/homeassistant/core.py:218> took 0.401 seconds
2018-03-12 17:44:00 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting
2018-03-12 17:44:00 WARNING (MainThread) [asyncio] Executing <Task finished coro=<Entity.async_update_ha_state() done, defined at /usr/lib/python3.6/site-packages/homeassistant/helpers/entity.py:186> result=None created at /usr/lib/python3.6/site-packages/homeassistant/core.py:218> took 0.367 seconds
2018-03-12 17:44:16 WARNING (MainThread) [asyncio] Executing <Task finished coro=<Entity.async_update_ha_state() done, defined at /usr/lib/python3.6/site-packages/homeassistant/helpers/entity.py:186> result=None created at /usr/lib/python3.6/site-packages/homeassistant/core.py:218> took 0.310 seconds
2018-03-12 17:44:16 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting
2018-03-12 17:44:16 WARNING (MainThread) [asyncio] Executing <Task finished coro=<Entity.async_update_ha_state() done, defined at /usr/lib/python3.6/site-packages/homeassistant/helpers/entity.py:186> result=None created at /usr/lib/python3.6/asyncio/tasks.py:311> took 0.277 seconds

Seems like it doesn`t pass a second, but still throws an error.

Edit: Don`t know if this finds the culprit. Seems like I got a lot of the errors because I use the debug mode, got only one at startup when disabling the custom component.

@zepixir do you have some massive groups and triggers that listen to a lot of entities?

@balloob are you meaning size of a single group? All lights group is quite large. Yes, have some automations that have a lot of triggers. Is it better to split it up in single automations or at least fewer triggers?

Nah, you shouldn't have to. Our system shouldn't choke on it instead.

What I got so far is when either my custom component for hue sensors is active, or all my automations active, I get the error. Have not yet managed to get the error after 4-5 restarts if both of them isn't active. Will go back to rest-sensor for the hue sensors, and disabling some automations to try to find the culprit/culprits throughout the week. But this is not 100%, since the error not always shows even with all the automations or custom component is enabled. But will update if I find what's causing it.

Hello.
I'm running HassIO on a Raspberry PI 3
Since I upgraded from 0.65.4 to 0.65.5:

Timer got out of sync. Resetting
6:16 PM core.py (ERROR)
Timer got out of sync. Resetting
6:13 PM core.py (ERROR)
Timer got out of sync. Resetting
6:08 PM core.py (ERROR)
Timer got out of sync. Resetting
6:02 PM core.py (ERROR)
Timer got out of sync. Resetting
5:57 PM core.py (ERROR)
Timer got out of sync. Resetting
5:51 PM core.py (ERROR)
Timer got out of sync. Resetting
5:51 PM core.py (ERROR)
Timer got out of sync. Resetting
5:46 PM core.py (ERROR)
Timer got out of sync. Resetting
5:40 PM core.py (ERROR)
Timer got out of sync. Resetting
5:35 PM core.py (ERROR)
Timer got out of sync. Resetting
5:29 PM core.py (ERROR)
Timer got out of sync. Resetting
5:24 PM core.py (ERROR)
Timer got out of sync. Resetting
5:18 PM core.py (ERROR)
Timer got out of sync. Resetting
5:13 PM core.py (ERROR)
Timer got out of sync. Resetting
5:08 PM core.py (ERROR)
Timer got out of sync. Resetting
5:07 PM core.py (ERROR)
Timer got out of sync. Resetting
5:02 PM core.py (ERROR)
Timer got out of sync. Resetting
4:57 PM core.py (ERROR)
Timer got out of sync. Resetting
4:57 PM core.py (ERROR)
Timer got out of sync. Resetting
4:51 PM core.py (ERROR)
Timer got out of sync. Resetting
4:46 PM core.py (ERROR)
Timer got out of sync. Resetting
4:43 PM core.py (ERROR)
Timer got out of sync. Resetting
4:40 PM core.py (ERROR)
Timer got out of sync. Resetting
4:35 PM core.py (ERROR)
Timer got out of sync. Resetting
4:29 PM core.py (ERROR)
Timer got out of sync. Resetting
4:24 PM core.py (ERROR)
Timer got out of sync. Resetting
4:24 PM core.py (ERROR)
Timer got out of sync. Resetting
4:18 PM core.py (ERROR)
Timer got out of sync. Resetting
4:13 PM core.py (ERROR)
Timer got out of sync. Resetting
4:13 PM core.py (ERROR)
Timer got out of sync. Resetting
4:07 PM core.py (ERROR)

I am getting timer out of sync error when when MQTT is enabled.

Timer got out of sync. Resetting
7:25 PM core.py (ERROR)
Timer got out of sync. Resetting
7:24 PM core.py (ERROR)
Timer got out of sync. Resetting
7:19 PM core.py (ERROR)
Timer got out of sync. Resetting
7:16 PM core.py (ERROR)
Timer got out of sync. Resetting
7:14 PM core.py (ERROR)
Timer got out of sync. Resetting
7:07 PM core.py (ERROR)
Timer got out of sync. Resetting
7:07 PM core.py (ERROR)

If it helps any I'm getting the same, currently on Home Assistant 0.65.6 on a pi3 installed via allin1. I turned on logger to check I've got HA's MQTT picking up the messages correctly and noticed Timer out of sync errors which I had none of before. When I receive a mqtt message I instantly get a timer reset, I can reproduce this at will.

2018-04-17 17:16:03 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting
2018-04-17 17:16:03 DEBUG (MainThread) [homeassistant.components.mqtt] Received message on pihole: b'49'
2018-04-17 17:16:14 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting
2018-04-17 17:16:14 DEBUG (MainThread) [homeassistant.components.mqtt] Received message on pihole: b'55'

I have same problem.
Timer got out of sync. Resetting 4:38 PM core.py (ERROR)
Timer got out of sync. Resetting 4:05 PM core.py (ERROR)
Timer got out of sync. Resetting 4:05 PM core.py (ERROR)
Error doing job: Task was destroyed but it is pending! 4:05 PM core.py (ERROR)
Timer got out of sync. Resetting 4:05 PM core.py (ERROR)

r Pi 3 B
Home Assistant 0.67.1

image

This is happening to me when I installed the dlib component.

Just as a note here: if you run CPU intensive processes, like dlib, and your machine is not powerful, Home Assistant's timer will also get out of sync.

+1

Is there a way to debug this in more detail @balloob ? I also get this error every now and the. I don't run anything special that should use much CPU. Running latest hass.io

Timer got out of sync. Resetting
1:54 PM core.py (ERROR)
Timer got out of sync. Resetting
1:33 PM core.py (ERROR)
Timer got out of sync. Resetting
1:18 PM core.py (ERROR)
Heartbeat timeout, resetting connection
1:02 PM /usr/lib/python3.6/site-packages/pychromecast/socket_client.py (WARNING)
Timer got out of sync. Resetting
12:03 PM core.py (ERROR)
Heartbeat timeout, resetting connection
11:47 AM /usr/lib/python3.6/site-packages/pychromecast/socket_client.py (WARNING)
Timer got out of sync. Resetting
11:37 AM core.py (ERROR)
Timer got out of sync. Resetting
11:36 AM core.py (ERROR)
Timer got out of sync. Resetting
11:00 AM core.py (ERROR)
Timer got out of sync. Resetting
10:37 AM core.py (ERROR)
Timer got out of sync. Resetting
10:27 AM core.py (ERROR)
Timer got out of sync. Resetting
10:22 AM core.py (ERROR)
Timer got out of sync. Resetting
10:03 AM core.py (ERROR)

@balloob Thanks for the hass.loop.set_debug(True) tip.
It helped find out the cause for my Timer got out of sync. Resetting messages.
Turns out I had a custom components test file I had completely forgot about and was taking more the a second to update.

@balloob

I have been having this issue for a while where 1 Timer out of sync happens after a restart. I happen to be testing something else and noticed that when I disabled all of my template sensors, the Timer out of sync did not re-appear. After enabling debugging I noticed that when template sensors are enabled, I get this many tasks for the below...

2018-06-22 13:07:03 WARNING (MainThread) [asyncio] Executing <Task finished coro=<Entity.async_update_ha_state() done, defined at /usr/src/app/homeassistant/helpers/entity.py:179> result=None created at /usr/src/app/homeassistant/core.py:219> took 0.121 seconds
2018-06-22 13:07:03 WARNING (MainThread) [asyncio] Executing <Task finished coro=<Entity.async_update_ha_state() done, defined at /usr/src/app/homeassistant/helpers/entity.py:179> result=None created at /usr/src/app/homeassistant/core.py:219> took 0.124 seconds
2018-06-22 13:07:04 WARNING (MainThread) [asyncio] Executing <Task finished coro=<Entity.async_update_ha_state() done, defined at /usr/src/app/homeassistant/helpers/entity.py:179> result=None created at /usr/src/app/homeassistant/core.py:219> took 0.133 seconds
2018-06-22 13:07:05 WARNING (MainThread) [asyncio] Executing <Task finished coro=<Entity.async_update_ha_state() done, defined at /usr/src/app/homeassistant/helpers/entity.py:179> result=None created at /usr/src/app/homeassistant/core.py:219> took 0.133 seconds
2018-06-22 13:07:05 WARNING (MainThread) [asyncio] Executing <Task finished coro=<Entity.async_update_ha_state() done, defined at /usr/src/app/homeassistant/helpers/entity.py:179> result=None created at /usr/src/app/homeassistant/core.py:219> took 0.154 seconds
2018-06-22 13:07:06 WARNING (MainThread) [asyncio] Executing <Task finished coro=<Entity.async_update_ha_state() done, defined at /usr/src/app/homeassistant/helpers/entity.py:179> result=None created at /usr/src/app/homeassistant/core.py:219> took 0.167 seconds
2018-06-22 13:07:08 WARNING (MainThread) [asyncio] Executing <Task finished coro=<Entity.async_update_ha_state() done, defined at /usr/src/app/homeassistant/helpers/entity.py:179> result=None created at /usr/src/app/homeassistant/core.py:219> took 0.150 seconds
2018-06-22 13:07:09 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting

But when I disable template sensors, I only get this...

2018-06-22 13:13:28 WARNING (MainThread) [asyncio] Executing <Task finished coro=<Entity.async_update_ha_state() done, defined at /usr/src/app/homeassistant/helpers/entity.py:179> result=None created at /usr/src/app/homeassistant/core.py:219> took 0.105 seconds
2018-06-22 13:13:28 WARNING (MainThread) [asyncio] Executing <Task finished coro=<Entity.async_update_ha_state() done, defined at /usr/src/app/homeassistant/helpers/entity.py:179> result=None created at /usr/src/app/homeassistant/core.py:219> took 0.116 seconds

No Timer out of sync!

UPDATE: Did some tests and here is what I did...

Disabled Zwave and restarted - Still had "Timer out of sync"
Disabled all template sensors - No "Timer out of sync"
Added in each template sensor in groups to about 90% of them and restarted - No "Timer out of sync"
Added remaining 10% of template sensors to the config and restarted - Got "Timer out of sync"
Removed 5 template sensors (Randomly) - No "Timer out of sync".
Re-enabled zwave - Got "Timer out of sync".

I also tried other various scenarios of trying to find a bad template config or something to pin point. Didn't matter what sensors I replaced or removed.

So it seems that no specific config or sensor is tripping things. I think in some way I am over taxing HA when it starts up. I don't get any out of sync issues after the first one on restart unless I bog down the host with a high CPU which is only when I'm testing something on a very very rare occasion.

I run an I5 NUC with 16G RAM so there should be plenty of horse left.

The only thing that sticks out is that section of tasks that repeat and ultimately end up in an out of sync issue.

I was having the same problem on a VM with 2gbs of ram. So i did a bit of research from all existing forums i could find, this would be my concise answer to the issue (in quotes are other usefull users comments, the rest is written):

Introduction:

Maybe you already know all or parts of what I am going to write but this is, in my opinion, the complete description of the problem :

"Let me explain a bit what it means for the timer to get out of sync:

Home Assistant fires a time changed event every second. That is what makes the system tick."_(=count time and trigger time specific actions)_ "Every time when it fires an event, it will schedule itself to fire the next event. The event loop is supposed to just contain very small tasks so that we get to firing the next time event on time." _If the tasks take too long, the async timer will run behind and trigger the 'timer got out of sync. resetting' exception and it will restart the timer._

"In other words, sometimes code will not behave correctly and it does for example I/O inside the event loop. I/O is doing actual physical work and thus can add slowdowns. If the system is slowed down too much, by the time we have to fire an event, it's actually already time for the next event. (note, this error also happens if your system goes into standby or suspends via hibernation).
Every minute the system must update the timer, if a process is running longer than a minute the error occures."

Now, this problem appears for a lot of people, there are at least three main miltiple page forum threads on it:

https://github.com/home-assistant/home-assistant/issues/7133
https://community.home-assistant.io/t/timer-got-out-of-sync-resetting-is-there-a-solution/42890/33
https://github.com/home-assistant/home-assistant/issues/12545

Solution:

(1) It seems that in about half of the cases it is caused by some error in code, memory leak, or error in a component causing 100% usage of either CPU or RAM. If this is your case, the solutoin would be to turn of one half of the components and check if the error is still going to come up, if not, disable the other half of the components and see again. Than repeat the process untill you can eliminate one component that triggers the error.

(2)The second possible cause is the size of the component history database. When MySQL runs the purge of the databse the whole system seems to slow down, if the DB is anyting around 0,5-2GB this is probably the cause to this whole issue. The solution is to either set up the components to store less data in the history DB or store less days worth of data. You can check if this is the issue by opening the history in the frontend, if it loggs the "Timer got out of sync" error at the same time you open the history than this is your case.

Hope this helps.

I went through a refactoring of my automations.yaml file and reduced the size from over 12k lines down to 6700. Around the 8k mark and restarting HA, the Timer out of sync stopped appearing. Like I mentioned in my post above, the only real time I'd get this error was on startup. Rarely/Seldom while running in normal state. Maybe if I was doing some heavy processing or something else while testing but never at idle or normal running state. Only at startup of HA. Seems maybe the sheer size of my automations.yaml file hit a limit somewhere and kicked off the out of sync issue. But either way, figured I'd share this here.

I'm also hitting this on startup though after reading the thread it could be something to do with the ring sensor taking so long to setup.

2018-08-12 23:34:50 WARNING (MainThread) [homeassistant.components.sensor] Setup of platform ring is taking over 10 seconds.
2018-08-12 23:35:14 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting

Incase it matters:
Version: 0.75.0.dev0
Automation Lines : 127
OS: FreeBSD 11.0-RELEASE-p1 (HA running inside Jail)

I have have this bug too on Orange Pi docker. Fresh install, nothing changed.
It seems to be random. Sometimes, I just navigate on the web interface and it does it.
I don't know if it is related but I have Unable to connect too while this happens.

2018-09-13 14:19:33 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting

OS : Armbian Ubuntu 18.04 - 4.14.65-sunxi

What practical problems could having this issue cause? I’ve been getting it for a while now and am just wondering how much I need to spend energy fixing it?

I always got this error once or twice on start up, no problems.... But with 0.80.0 I am now getting a constant stream of them and always paired with this media update warning:

2018-10-15 08:12:23 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting
2018-10-15 08:13:24 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting
2018-10-15 08:14:25 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting
2018-10-15 08:15:26 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting
2018-10-15 08:16:27 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting
2018-10-15 08:16:37 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting
2018-10-15 08:16:38 WARNING (MainThread) [homeassistant.components.media_player] Updating soundtouch media_player took longer than the scheduled update interval 0:00:10
2018-10-15 08:16:38 WARNING (MainThread) [homeassistant.components.media_player] Updating squeezebox media_player took longer than the scheduled update interval 0:00:10
2018-10-15 08:16:38 WARNING (MainThread) [homeassistant.components.media_player] Updating samsungtv media_player took longer than the scheduled update interval 0:00:10

everything still seems to function so far, not sure if this is a problem or not.

Was this page helpful?
0 / 5 - 0 ratings