home-assistant / operating-system

:beginner: Home Assistant Operating System
Apache License 2.0
5.09k stars 994 forks source link

Virtualbox time drift due to missing guest additions #1540

Open tetsuo55 opened 3 years ago

tetsuo55 commented 3 years ago

Hardware Environment

I'm using virtualbox on windows 10

Home Assistant OS release:

tetsuo55 commented 3 years ago

i found this other repo that has automated updates and is way more recent but its in ruby

https://github.com/dotless-de/vagrant-vbguest

agners commented 3 years ago

What host operating system are you using? What is the setting of "Paravirtualization Interface" in you virtual machine? Does your host has hardware acceleration and is it enabled?

I just tried to reproduce this here, and my virtual machine clock is second accurate even after 6h+. I wonder if this maybe only is a problem in certain environments?

The cause is that virtualbox requires guest additions to be able to communicate with the host and those aren't included.

Linux recently added some "native" VirtualBox drivers: https://cateee.net/lkddb/web-lkddb/VBOXGUEST.html. But I don't think that this is enough to get RTC synchronization going.

tetsuo55 commented 3 years ago

Host is windows 10 x64 interface is set to standard with nested pages checked hardware acceleration is enabled but my cpu doesnt support SLAT so hyperv does not work

that kernel driver is the module that guest additions would install but its only a small part of the whole. https://forums.whonix.org/t/virtualbox-guest-additions-being-upstreamed-to-linux-kernel-org/8785/2

we need the full guest additions to make time work for everyone.

edit: i should clarify that any time command you run in template tester will display the correct time, its time based automations that fail

set an automation that sends you a message with that set time and compare to the delivery timestamp screenshot of broken messages image correct time being shown in home assistant interface image

tetsuo55 commented 3 years ago

@agners is there anything I can do to help? I really need time based automations

agners commented 3 years ago

correct time being shown in home assistant interface

@tetsuo55 oh that is super weird. I fear that syncing time will then not even help...

Can you add the current time to the message (using {{ now() }})? I wonder if at the time the message get sent (from the automation) the time is really off or just the automation triggered at a completely wrong time.

tetsuo55 commented 3 years ago

I have appended all the messages with system time and created a new one as a quick test IMG_20210920_131154

agners commented 3 years ago

Can you attach the trace of this automation?

tetsuo55 commented 3 years ago

I think i got it figured out. Without the guest additions the guest is unable to synchronize the CPU clocks. The CPU speeds are wrong inside hassos causing the internal clocks to tick at the wrong speed, while time synchronisation keeps correcting the displayed time, hiding the actual drift.

As for the trace I'll have to wait for the next one because i rebooted the server to figure out this issue.

Which brings us back to full guest additions, this should provide the bits needed for cpu clock synching, although i can't find the document i read that in again

tetsuo55 commented 3 years ago

I have found something to test, maybe the paravirtualization has to be set to kvm

tetsuo55 commented 3 years ago

Unfortunately the kvm mode didn't help, maybe made it even worse.

id: '1630511868414'
alias: time trigger test a
description: ''
trigger:
  - platform: time
    at: '04:00'
condition: []
action:
  - service: notify.telegram
    data:
      message: this is the 04:00 test {{ now() }}
mode: single
this:
  entity_id: automation.time_trigger_test_a
  state: 'on'
  attributes:
    last_triggered: '2021-09-19T06:06:17.420544+00:00'
    mode: single
    current: 0
    id: '1630511868414'
    friendly_name: time trigger test a
  last_changed: '2021-09-20T16:36:55.557737+00:00'
  last_updated: '2021-09-20T16:36:55.557737+00:00'
  context:
    id: e0ccf26c8b7b63d32f91141dc1f59aa0
    parent_id: null
    user_id: null
trigger:
  id: '0'
  idx: '0'
  platform: time
  now: '2021-09-21T08:20:55.280725+02:00'
  description: time
  entity_id: null

IMG_20210921_095051

guignol8220 commented 3 years ago

Please add me to the list of people having the same issue. Any time triggered automation I have in NodeRed and HA are not anymore reliable.

Problem appeared (for me) around 1-2 month. After spending quit some time investigating by downgrading different part of my systems and trying fresh image/install, I can now says that the problem is solely related to release 6.3. Everything work fine with a clean 6.2 install, but I get unsync time with clean install of 6.3.

extra info: I'm running HA OS inside a VirtualBox, which run on Ubuntu

agners commented 3 years ago

@tetsuo55 from what I can tell in your system, the system time is correct, its just the automation is triggered too late: E.g. You received the message at 8:20, and the message got generated at 8:20:55.289736. The question is, why did the system did not wake up at 8:00 and send it back then?

@tetsuo55 can you confirm @guignol8220's observation? E.g. does it help for you to roll back to 6.2? (You can use ha os update --version 6.2)

guignol8220 commented 3 years ago

for info, such a simple automation is enough to demonstrate the error. I use a basic time_patern that trigger every round 10 min or hours. If I run the same automation inside a fresh 6.2 or 6.1, it run exactly at the expected time, but if I run the same automation inside a fresh 6.3 or 6.4, the trigger time is always later by a few second or up to 40-50 min some times. what is even more confusing is that the time in the logs is actually correct (by that I mean that when it says that the action was triggered at 19:40:14, this is correct time). Seams like the clock used for trigger action use a different clock than the one used for tagging the logs.

here is supposed to trigger at every round 10min (19:40:00 in this case), but got triggered 14 second to late image

here is supposed to trigger every round hours (10:00:00) but got tirgger 12 min later... image

tetsuo55 commented 3 years ago

@tetsuo55 from what I can tell in your system, the system time is correct, its just the automation is triggered too late: E.g. You received the message at 8:20, and the message got generated at 8:20:55.289736. The question is, why did the system did not wake up at 8:00 and send it back then?

@tetsuo55 can you confirm @guignol8220's observation? E.g. does it help for you to roll back to 6.2? (You can use ha os update --version 6.2)

I'm pretty sure i had the issue on 6.1, but i will test this anyway

tetsuo55 commented 3 years ago

Same issue on 6.2

this is the 16:00 test system time is 2021-09-23 16:11:55.672817+02:00 the trigger time is2021-09-23 16:11:55.666064+02:00

@agners , can you make a test build with that buildroot addon thing? Or maybe a way to install the virtual box additions? I've read dozens of pages where this was resolved by installing the additions (we currently only have 1/2 of the additions in form of the kernel parts)

tetsuo55 commented 3 years ago

I found another package, for fedora Linux which is fully up to date. https://src.fedoraproject.org/rpms/virtualbox-guest-additions/blob/f33/f/virtualbox-guest-additions.spec

butako commented 3 years ago

I faced the same problem. Running HA OS inside VirtualBox upon Ubuntu, automations triggered by time would drift by many minutes. This solved it for me: https://community.home-assistant.io/t/timebased-automations-completely-out-of-sync/302083/5 I switched “Paravirtualization Interface” to None and the time automations have been accurate since.

guignol8220 commented 3 years ago

Thanks for sharing @butako! I’m running the almost same setup as you (differences is it is running on a macmini late 2009). I did reverted 1 week ago my “production” HA to 6.2 and all time based automation are working as it should. but reading your comment, I dared yesterday pressing the update button to 6.4, and desactivated in same time in VirtalBox what you point out, and so fare no issues!!

tetsuo55 commented 3 years ago

I will disable paravirtualization for now too then. But it's not the proper solution to this issue as we're giving up a lot of performance

agners commented 3 years ago

Agreed disabling paravirtualization is not ideal as a long term solution.

What is a bit puzzling to me is that we supported Virtual Box since quite some time, but it only seems to crop up now? Which begs the question, did something change which makes it show up today?

I'll try porting the VirtualBox guest addition to Buildroot/HAOS, but its not on-top of my todo list right now.

tetsuo55 commented 3 years ago

Yeah that is strange, I'm a new user of home assistant and this was my first attempt at using time of day based automations so i can't speak for how things were before

ioctl2 commented 2 years ago

The incomplete virtualbox support also has the effect that detailed memory utilization is not available host-side: image

Zi0mele commented 1 year ago

Did anyone find a solution to this problem? I'm experiencing it with HA OS 9.5, core 2023.4.2, on a MacOS Monterey (Installed with OCLP on a 2009 macbook 5,2). It did not present right away after the installation, It started around the daylight saving time change. Disabling the paravirtualization worked, but it spiked the cpu usage in HA (from 1-2% to 12-13%) and now I have some temperature issues with the macbook. I've tried setting the paravirtualization to "minimal" instead of "none"; it did not affect the time, but it did not affact the cpu usage eaither. Suggestions?

EDIT: I'm running VirtualBox 6.1.44. I can't get MacOS to prompt me to allow the kernel modification when installing VirtualBox 7, So I can't upgrade to that, for the moment.

tetsuo55 commented 1 year ago

The only solution is for the guess additions to be added to ha os