[Bug 53171] New: advapi32:registry - test_performance_keys() sometimes fails due to time going backwards!

[WineHQ Bugzilla]

https://bugs.winehq.org/show_bug.cgi?id=53171

            Bug ID: 53171
           Summary: advapi32:registry - test_performance_keys() sometimes
                    fails due to time going backwards!
           Product: Wine
           Version: unspecified
          Hardware: x86-64
                OS: Windows
            Status: NEW
          Severity: normal
          Priority: P2
         Component: advapi32
          Assignee: wine-bugs at winehq.org
          Reporter: fgouget at codeweavers.com

advapi32:registry - test_performance_keys() sometimes fails due to time going
backwards:

registry.c:3757: Test failed: key FFFFFFFF80000004: value (null): got times
132999520626290092, 132999520626290092, 132967560392269933
registry.c:3763: Test failed: key FFFFFFFF80000004: value (null): got times
132999520626290092, 132999520626290000, 132967560392269933

https://test.winehq.org/data/patterns.html#advapi32:registry

This failure is pretty rate: I only found 4 cases (~0.9%):
win2009_newtb-w1064-tsign, win21H1_newtb-w10pro64-mx-MX, 2x
win21H2_fgtb-w10pro64.

The failure lines above happened on w10pro64-mx-MX on 2022-06-17. Here are the
corresponding timestamps:

systime1   = 132999520626290092 = 2022-06-17 15:07:42.629009
file_time  = 132999520626290000 = 2022-06-17 15:07:42.629000
systime2   = 132967560392269933 = 2022-05-11 15:20:39.226993

file_time is a little lower than systime1 which is normal due to its
granularity.

What is totally wrong however is that systime2 is way lower than systime1. The
interesting part is that the live snapshot was created on 2022-05-11 which
matches systime2. This scenario is confirmed it two of the other instances; the
snapshot creation time for the last case is unknown but a match with systime2
is plausible.

After restoring the VM from the live snapshot LibvirtTool sets the VM time
through TestAgent::SetTime():
https://gitlab.winehq.org/winehq/tools/-/blob/master/testbot/bin/LibvirtTool.pl#L610
https://gitlab.winehq.org/winehq/tools/-/blob/master/testbot/src/testagentd/platform_windows.c#L279

So it looks like in rare cases the system time gets reset backwards precisely
between this test's two NtQuerySystemTime() calls, which is really unlucky...
or lucky: maybe it happens in other cases causing less obvious failures.

I don't know if TestAgentd sets the time wrong, if there's something wrong with
Windows, or if this is an artifact of the QEmu clocks:

    <clock offset='localtime'>
      <timer name='rtc' tickpolicy='delay'/>
      <timer name='pit' tickpolicy='delay'/>
      <timer name='hpet' present='yes'/>
      <timer name='hypervclock' present='yes'/>
    </clock>

-- 
Do not reply to this email, post in Bugzilla using the
above URL to reply.
You are receiving this mail because:
You are watching all bug changes.