microsoft / cppwinrt

C++/WinRT
MIT License
1.67k stars 239 forks source link

Improve error reporting for clock test #1248

Closed kennykerr closed 1 year ago

kennykerr commented 1 year ago

This test fails intermittently but it's hard to tell what's wrong since the error report doesn't include the failing values. This just ensures that we can see the values when it fails and perhaps gain some more insight in the failure.

alvinhochun commented 1 year ago

https://github.com/microsoft/cppwinrt/actions/runs/3719133191/jobs/6307790757#step:8:85

 4: -------------------------------------------------------------------------------
4: clock, time_t
4: -------------------------------------------------------------------------------
4: D:\a\cppwinrt\cppwinrt\test\old_tests\UnitTests\clock.cpp:67
4: ...............................................................................
4: 
4: D:\a\cppwinrt\cppwinrt\test\old_tests\UnitTests\clock.cpp:80: FAILED:
4:   REQUIRE( diff < 1000 )
4: with expansion:
4:   1001 (0x3e9) < 1000 (0x3e8)

Still have no idea why this fails randomly...

alvinhochun commented 1 year ago

Ah, I have a suspicion: time(nullptr) has one-second resolution. Even when it is called at the 999th millisecond, the value it returns should be rounded down. If it was called first, it is possible that, when calling clock::now() the wall clock has ticked to the next second. This way, the difference between the two timestamp can slightly exceed 1000 milliseconds when unlucky.

The diff is calculated by abs(clock::now() - clock::from_time_t(time(nullptr))) in the same statement. I think because the order of evaluation is unspecified, the scenario described above may happen.