Automation time not working correctly

ok thanks Phil, Downloading ubuntu. Will post results tomorrow

1 Like

You’re keeping us in suspense! :pleading_face: Were you able to try it yet on Ubuntu on VBox? If so, what were the results?

Sorry Phil, I have had visitors up until this morning. I have installed Ubuntu. it took ages. the result was
td: 10.000000238, md: 9.999999003, diff: -0.000001235, ratio: 1.000
It still a ratio of 1 but quite a drift after 10 seconds…

I have now installed a test version of HA on my newer iMac as a virtual machine. It runs ok; the timing for my test relay is within less than a second. I will add everything I had on the mac mini version today and test the sunset tonight.
Chris

No problem. Just curious what the ultimate cause is, in case it’s something in how HA (or probably more likely HA OS) is configured or is run on a Mac.

Why do you say it was quite a drift? After 10 seconds it was only off by about a microsecond. Can’t ask for much more than that. (That is basically in the noise.)

So, it looks like macmini native is ok. Ubuntu on macmini on VBox is ok. It’s only HA / HA OS on macmini on VBox that isn’t working correctly. My best guess at this point is it’s not HA, so it must be HA OS, or at least some portion of the environment that the HA OS image creates to run HA within. I’m starting to wonder if maybe the core team has modified the Python run-time environment such that time.monotonic() isn’t working correctly on macmini/VBox…

Yes you are correct. The drift is ok (I was rushing to reply to your post). My new HA vm on my Imac is still running very good. I will continue to use and test it. The Imac is much faster than the mac mini. This is really noticeable when compiling code using esphome. I will keep the HA on the mac mini to see if the cause can be found.

1 Like

Ok, I asked one of the core team members for some help. He pointed me to the following:

System time leaps in VirtualBox guests (laurentiupancescu.com)

Interestingly, the blog even mentions the Mac Mini!

It would seem that HA OS is (probably???) choosing to use TSC for the clock base that ultimately time.monotonic() uses, whereas Ubuntu must be choosing something different. Further, it would seem that the TSC on your Mac Mini is not of the “invariant” type, meaning it probably stops when the CPU is idle, causing time.monotonic(), and hence hass.loop.time(), to get further and further behind real wall time (and time.time()) the longer the system runs. It is interesting, though, that it always seems to be a factor of 2x. Hmm… Maybe HA OS is picking some other clock source that is unique to VBox, which just happens to be running at 1/2 real speed as opposed to the clock that Ubuntu chooses.

It would be helpful if you could run the following command from Ubuntu and HA OS (both running on VBox):

for clk in available current; do cat /sys/devices/system/clocksource/*/${clk}_clocksource; done

FWIW, when I run this command on my (native) Ubuntu system and within the docker container that is running HA, I get:

$ for clk in available current; do cat /sys/devices/system/clocksource/*/${clk}_clocksource; done
tsc hpet acpi_pm
tsc
$ docker compose exec homeassistant bash
bash-5.1# for clk in available current; do cat /sys/devices/system/clocksource/*/${clk}_clocksource; done
tsc hpet acpi_pm
tsc

FWIW, my system is using an Intel(R) Core™ i7-2760QM CPU (from /proc/cpuinfo).

2 Likes
ubuntu vm on mac mini

kvm-clock tsc acpi_pm

kvm-clock

Intel(R) Core(TM)2 Duo CPU P8600 @ 2.40GHz

HA vm on mac mini

kvm-clock tsc acpi_pm

kvm-clock

Intel(R) Core(TM)2 Duo CPU P8600 @ 2.40GHz

Hmm. I wasn’t expecting Ubuntu and HA OS to have picked the same clock source. Maybe my latest test was invalid since it never slept, it just spun in a loop for 10 seconds instead, which would have avoided the TSC from stopping (which, I guess, kvm-clock is based on???)

I suppose you could try some of those experiments in the blog, but maybe you could try one of the suggestions at the end of the blog. E.g., change the clock source to acpi_pm (not exactly sure how to do that), or change the “paravirtualization interface” to none (again, not exactly sure how to do that.)

I guess the bottom line is not so much that the Mac Mini is “underpowered”, but maybe rather that it’s TSC is not invariant, and you got bit by a bug in VBox???

I will be the first to admit my Mac mini is underpowered. But, it runs my security camera software, indigo6 (controlling my soon to be replaced X10 stuff) and no problems with HA apart from the timing issue. I am sure there will be a minimum hardware spec for HA; perhaps this is it?
Tomorrow I will change the paravirtualization setting (it’s in the vm setup) and test.
Nice to do some cscript today :smile: I first started cscript about 30 years ago on SunOS

On my working iMac using KVM:-
paravirtualization = kvm
tsc kvm-clock acpi_pm
tsc

paravirtualization = default
tsc lvm-clock acpi_pm
tsc

paravirtualization = none
tsc acpi_pm
tsc

paravirtualization = legacy
tsc acpi_pm
tsc

paravirtualization = minimal
tsc acpi_pm
tsc

Found this
https://docs.oracle.com/en/virtualization/virtualbox/6.0/admin/fine-tune-timers.html
I an using VB 6.0.22

That’s very interesting. I’m guessing you installed the guest additions in Ubuntu, but not in HA OS (on the Mac Mini, that is)???

Interesting that there is a parameter to speed up or slow down the guest clock. If that was set to half rate in the HA OS guest, that could definitely explain the problem. Then again, I can’t imagine you specifically did that, and I can’t imagine that’s the default.

FWIW, I happen to also have a Core2 Duo based PC (it’s an old Dell laptop), that I’m running Ubuntu on. So far, I’ve been using it to run HA in docker containers, but I can try installing VBox, too, and see if I can reproduce your experience.

Also, I’m going to tweak the test Python script to use a thread sleep instead of a spin loop. I wonder if that will affect any of the results, especially on the Core2 Duo based machines.

FWIW, the updated Python script is:

import sys
import time
def test(sleep_time):
    t0 = time.time()
    m0 = time.monotonic()
    time.sleep(sleep_time)
    t1 = time.time()
    m1 = time.monotonic()
    td = t1 - t0
    md = m1 - m0
    print(f"td: {td:0.9f}, md: {md:0.9f}, diff: {md - td:0.9f}, ratio: {md/td:0.3f}")
if __name__ == "__main__":
    test(float(sys.argv[1]) if len(sys.argv) == 2 else 10)

It uses time.sleep() to suspend the calling thread. The default is 10 seconds, but you can pass a number to the script to specify the number of seconds, e.g.:

python3 clock_test.py 60

Also FWIW, on my Core2 Duo based laptop running Ubuntu natively, the clock sources & choice are (both natively, and inside a HA container):

hpet acpi_pm
hpet

No TSC at all. And I’ve never noticed time-based stuff being off in HA (running in a container), although I can’t say I’ve paid much attention to it, either.

I’ve just finished installing VBox 6.1.36 and downloading the Ubuntu image on this Core2 Duo machine. I’ll let you know what I find after creating Ubuntu and HA OS VMs.

I created VBox VMs on my Core2 Duo machine in which to run Ubuntu and HA OS. On Ubuntu it seems the clocks are ok. The sources are:

kvm-clock tsc acpi_pm
kvm-clock

On HA OS, I couldn’t figure out how to run commands from an OS command line (and the ha cli doesn’t seem to allow it), so I enhanced my clock drift custom integration to do it. I also added separate clock ratio and clock source sensors. The results on HA OS:

2023-02-16 14:40:26.831 INFO (SyncWorker_4) [custom_components.clock_drift] available: kvm-clock, tsc, acpi_pm
2023-02-16 14:40:26.831 INFO (SyncWorker_4) [custom_components.clock_drift] current: kvm-clock
2023-02-16 14:41:01.255 INFO (MainThread) [custom_components.clock_drift] time_delta = 10.000435829, loop_time_delta = 10.000433336, drift = -0.000002493, ratio = 1.000
2023-02-16 14:47:39.992 INFO (MainThread) [custom_components.clock_drift] time_delta = 408.735368252, loop_time_delta = 310.005375799, drift = -98.729992453, ratio = 0.758
2023-02-16 14:54:24.314 INFO (MainThread) [custom_components.clock_drift] time_delta = 813.058246613, loop_time_delta = 610.006696230, drift = -203.051550383, ratio = 0.750

The clock sources are the same as for Ubuntu. But, the loop time clock (aka time.monotonic()) seems to be running at about 75% of what it should be.

So, still not quite sure why Ubuntu seems to cope with VBox ok, but HA OS doesn’t. (Or maybe my tests are still invalid, or misleading, in some way.)

I’ll also do some experimenting with the VBox settings. I pretty much followed HA’s install instructions, and otherwise used default settings. Same for the VM in which I run Ubuntu, mostly default settings.

UPDATE:

HA OS VBox VM Paravirtualization Interface set to Legacy (as opposed to Default, which was the original setting):

2023-02-16 15:20:43.226 INFO (SyncWorker_3) [custom_components.clock_drift] available: acpi_pm
2023-02-16 15:20:43.226 INFO (SyncWorker_3) [custom_components.clock_drift] current: acpi_pm
2023-02-16 15:21:18.440 INFO (MainThread) [custom_components.clock_drift] time_delta = 9.997395039, loop_time_delta = 9.997427959, drift = 0.000032920, ratio = 1.000
2023-02-16 15:26:18.468 INFO (MainThread) [custom_components.clock_drift] time_delta = 310.024753571, loop_time_delta = 310.028733583, drift = 0.003980012, ratio = 1.000
2023-02-16 15:31:18.463 INFO (MainThread) [custom_components.clock_drift] time_delta = 610.021503687, loop_time_delta = 610.021544598, drift = 0.000040911, ratio = 1.000

Seems to have solved the problem. Notice the kvm-clock & tsc options are no longer available and it’s now using the only available option, acpi_pm.

1 Like
new clock_drift installed. How do I get the info 2023-02 etc. above please?

Those are in the log (i.e., home-assistant.log.) By default, the logger is set to warning level, I believe. So, if you haven’t changed that, you first need to set the default logger level to info. You can do that in configuration.yaml, or you can do it via a service call. (Search on the services page for logger.) Then, you can either look in home-assistant.log, or load the full log on the log page, and then enter “clock” in the search field.

But, that info is also available in three sensors: sensor.clock_drift, sensor.clock_ratio & sensor.clock_source (including its available attribute.)

FYI, there is a new version of HAOS coming (v10), that is based on a newer Linux kernel (6.1.) I just tried a dev build and it also seems to have solved the problem. Works just fine using kvm-clock, VBox’s default guest clock. So, ultimately, you’ll have two ways to run HAOS on the Mac Mini: use VBox legacy paravirtualization interface, and/or upgrading to HAOS 10 when it becomes generally available.

in answer to above, 2 days ago; I have not set anything apart from following the vm guide.
below is cat homeassistant.log | grep clock_drift
2023-02-18 12:12:12.094 WARNING (SyncWorker_0) [homeassistant.loader] We found a custom integration clock_drift 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
2023-02-18 12:13:03.562 INFO (MainThread) [homeassistant.setup] Setting up clock_drift
2023-02-18 12:13:03.565 INFO (MainThread) [homeassistant.setup] Setup of domain clock_drift took 0.0 seconds
2023-02-18 12:13:04.372 INFO (SyncWorker_1) [custom_components.clock_drift] available: acpi_pm
2023-02-18 12:13:04.373 INFO (SyncWorker_1) [custom_components.clock_drift] current: acpi_pm
2023-02-18 12:13:47.438 INFO (MainThread) [custom_components.clock_drift] time_delta = 10.007056236, loop_time_delta = 10.007058480, drift = 0.000002244, ratio = 1.000
2023-02-18 12:18:47.446 INFO (MainThread) [custom_components.clock_drift] time_delta = 310.014492273, loop_time_delta = 310.014515385, drift = 0.000023112, ratio = 1.000

That’s on the Mac Mini with legacy paravirtualization?

Yes as directed :slight_smile: