New issue
Advanced search Search tips
Note: Color blocks (like or ) mean that a user may not be available. Tooltip shows the reason.

Issue 723225 link

Starred by 2 users

Issue metadata

Status: Archived
Owner: ----
Closed: Jan 10
Cc:
EstimatedDays: ----
NextAction: ----
OS: Windows
Pri: 3
Type: Bug



Sign in to add a comment

Some tests fail when using low-resolution timers

Project Member Reported by brucedaw...@chromium.org, May 17 2017

Issue description

There are some Chromium tests that assume that time will have elapsed between subsequent calls to Time::Now(). However one some machines this is not guaranteed. If QueryPerformanceCounter is not deemed suitable (see InitializeNowFunctionPointer()) then timeGetTime will be used. The resolution of this function is 1 ms at best but can be as low as 15.6 ms. If this function is modified to force RolloverProtectedNow to be used then this test will fail about half the time:

webkit_unit_tests.exe --gtest_filter=ImageResourceTest.FetchAllowPlaceholderFullResponseDecodeSuccess

The failure is:
d:\src\chromium\src\third_party\webkit\source\core\loader\resource\imageresourcetest.cpp(1482): error: Value of: image_resource->ShouldShowPlaceholder()
  Actual: false
Expected: true

Your mileage may vary (it depends on machine speed and many other factors) so the odds of a test failure can be increased by modifying RolloverProtectedNow() like this:

< now = g_tick_function();
> now = g_tick_function() & ~0xF;

By zeroing out the bottom four bits of the timer we reduce its resolution to 16 ms, which is close to what some customers get. The test should now fail virtually 100% of the time. In short, the test expects that a resource will have expired but since, according to timeGetTime(), no time has elapsed the resource has not expired.


Another test failure (not yet reproduced) comes from:

content_unittests.exe --gtest_filter=PaymentManagerTest.KeysOfPaymentInstruments
f:\chrome\src\content\browser\payments\payment_manager_unittest.cc(334): error: Value of: keys.size()
  Actual: 1
Expected: 3U

 
Cc: m...@chromium.org
Running a test CL to see if there are any others worth investigating:
crrev.com/2888833002
Cc: stanisc@chromium.org
The test run at crrev.com/2888833002 shows *dozens* of failures (over a hundred?) when the timer resolution is lowered. Should we try to fix these in some way? How do we determine which of these failures represent issues that our customers might hit in the field?

Stan - I noticed two failures in gpu_ipc_service_unittests that you should probably look at:

.\gpu_ipc_service_unittests.exe --brave-new-test-launcher --test-launcher-bot-mode

[ RUN      ] GpuVSyncProviderTest.VSyncSignalTest
e:\b\c\b\win\src\gpu\ipc\service\gpu_vsync_provider_unittest_win.cc(173): error: Expected: (timestamp) > (previous_vsync_timestamp_), actual: 14170704000 bogo-microseconds vs 14170704000 bogo-microseconds
[  FAILED  ] GpuVSyncProviderTest.VSyncSignalTest (643 ms)
[9/10] GpuVSyncProviderTest.VSyncSignalTest (643 ms)
[ RUN      ] GpuVSyncProviderTest.VSyncMonotonicTimestampTest
gpu\ipc\service\gpu_vsync_provider_unittest_win.cc(173): error: Expected: (timestamp) > (previous_vsync_timestamp_), actual: 14171040000 bogo-microseconds vs 14171040000 bogo-microseconds
...
[  FAILED  ] GpuVSyncProviderTest.VSyncMonotonicTimestampTest (848 ms)


It may be that we decide not to do anything here, especially given the volume of test failures, but I wanted to at least discuss the issues.

Note that some of the test failures are actually crashes that are caused by unexpectedly low timer resolution. These are *probably* test-only crashes, but ...

See https://codereview.chromium.org/2859803002/#msg20 for a failure that may indicate a real problem rather than just a test failure.
Thanks for bringing this to my attention. I've filed a separate  issue 723937  for GpuVSyncProviderTest.VSyncSignalTest.

Comment 5 by m...@chromium.org, May 18 2017

Cc: sullivan@chromium.org
[+cc sullivan@, regarding idea for perf testing for this issue (below)]

A little history: A couple years back, I worked out a timing bug that RCR'ed to this exact problem. At the time, I had suggested spinning-up a perf bot that ran on hardware where Windows could not provide the 1us clock. I think that request eventually was decided as a "no" because it would require provisioning/maintaining rather obsolete hardware just to run one tab mirroring perf test with the 16ms clock.

However, you've already provided a much better wish-I-had-thought-of-it(TM) solution: We could introduce a special build variant for the perf bots that masks out the lower bits of the high-res time values to simulate a low-res clock. Then, use this special build to run a suite of perf tests (compositor and other core functionality) in our existing fleet, to ensure there are no issues for users running older hardware.

According to this code comment I wrote back in Aug 2015, approx 28% of Windows users were using the low-res clock: https://cs.chromium.org/chromium/src/base/time/time_win.cc?rcl=a5c3f31d1816d1b0eb1db5885696d844c35208ac&l=498
 Generally, these are users whose machines were purchased with Windows Vista or earlier pre-installed. So, I'd expect the number to be much lower today, but probably not zero.

Comment 6 by zino@chromium.org, May 23 2017

Hi, Thank you for this information.

BTW, where does the following logs come from?

content_unittests.exe --gtest_filter=PaymentManagerTest.KeysOfPaymentInstruments
f:\chrome\src\content\browser\payments\payment_manager_unittest.cc(334): error: Value of: keys.size()
  Actual: 1
Expected: 3U

Even if the time is always the same value, above assert can not fail I think.
Because the time is used for data ordering only. At least the size of result should be 3U.
When I build using the test CL (crrev.com/2888833002) and run the test I get the predicted failure:

>out\debug\content_unittests.exe --gtest_filter=PaymentManagerTest.KeysOfPaymentInstruments
IMPORTANT DEBUGGING NOTE: batches of tests are run inside their
own process. For debugging a test inside a debugger, use the
--gtest_filter=<your_test_name> flag along with
--single-process-tests.
Using sharding settings from environment. This is shard 0/1
Using 1 parallel jobs.
Note: Google Test filter = PaymentManagerTest.KeysOfPaymentInstruments
[==========] Running 1 test from 1 test case.
[----------] Global test environment set-up.
[----------] 1 test from PaymentManagerTest
[ RUN      ] PaymentManagerTest.KeysOfPaymentInstruments
d:\src\chromium\src\content\browser\payments\payment_manager_unittest.cc(302): error:       Expected: 3U
      Which is: 3
To be equal to: keys.size()
      Which is: 1
[  FAILED  ] PaymentManagerTest.KeysOfPaymentInstruments (100 ms)


My understanding is that time is being used as a key to a set or map which means that it isn't just used for ordering, it's used for uniqueness. I have not verified the details, but the failure is 100% reproducible with the test CL so it should be easy to investigate.

I used these build settings, but I'm not sure any of them matter:

is_component_build = false
is_debug = true
target_cpu = "x86"
enable_nacl = false
use_goma = true
Status: Archived (was: Untriaged)
Archiving P3s older than 1 year with no owner or component.

Sign in to add a comment