New issue
Advanced search Search tips

Issue 757477 link

Starred by 2 users

Issue metadata

Status: Fixed
Owner:
Closed: Aug 2017
Components:
EstimatedDays: ----
NextAction: ----
OS: Fuchsia
Pri: 3
Type: Bug

Blocking:
issue 738275



Sign in to add a comment

ThreadTicks.ThreadNow in base_unittests failed on Fuchsia

Project Member Reported by scottmg@chromium.org, Aug 21 2017

Issue description

This was a local run while trying to soak for another flake.

[00129.712] 02596.02623> [ RUN      ] ThreadTicks.ThreadNow
[00129.712] 02596.02623> ../../base/time/time_unittest.cc:726: Failure
[00129.712] 02596.02623> Expected: (difference.InMicroseconds()) >= (9000), actual: 4486 vs 9000
[00129.712] 02596.02623> [  FAILED  ] ThreadTicks.ThreadNow (23 ms)

 
This is checking ThreadTicks::Now vs TimeTicks::Now. I don't actually see why it would have failed, but there's also no reason that it should work since MX_CLOCK_UTC could change arbitrarily.

Comment 2 by w...@chromium.org, Aug 21 2017

Time::Now() is the wall-clock; TimeTicks is the monotonic/up-time clock, so
this should still work.

However, this test is sensitive to the QEMU multi-core emulation - we can
end up taking ThreadTicks::Now(), then QEMU interrupts our CPU core to run
a different one, and then when we come back ThreadTicks *and* TimeTicks
have jumped forward, so as far as the OS is concerned, the thread was
running for all of that time.
I don't think it generally makes sense, as wall-clock can jump, right? https://fuchsia.googlesource.com/magenta/+/HEAD/kernel/lib/syscalls/syscalls_magenta.cpp#86

Comment 4 by w...@chromium.org, Aug 21 2017

Re #3: The ThreadNow test https://cs.chromium.org/chromium/src/base/time/time_unittest.cc?type=cs&l=709) tests ThreadTicks against TimeTicks, i.e. MX_CLOCK_THREAD against MX_CLOCK_MONOTONIC.  MX_CLOCK_THREAD will be based off the same underlying clock as MX_CLOCK_MONOTONIC, I'd assume, so they make sense to compare.

However, because we're emulating multiple CPU cores on a single core with our current QEMU configuration, it is possible for one logical core to be pre-empted for a non-trivial amount of time while QEMU emulates a different core. Since there's only a single monotonic clock, that means that that core will see the underlying monotonic clock jump forward, causing the OS' thread-time measure to be wrong - as though a single CPU instruction had taken several milliseconds, in effect.

Oh derp, I read the right things, but then looked at what TimeTicks::Now and Time::Now were retrieving, rather than ThreadTicks and TimeTicks.

...

...

OK, I think I finally understand. :p and I think I agree we should change to -smp 1. I'll send you a CL.
Project Member

Comment 6 by bugdroid1@chromium.org, Aug 21 2017

The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/764d4f47288e3f4df439f4afecbd458a31661503

commit 764d4f47288e3f4df439f4afecbd458a31661503
Author: Scott Graham <scottmg@chromium.org>
Date: Mon Aug 21 21:30:41 2017

fuchsia: Set -smp 1 when running w/o KVM

Bug:  757477 
Change-Id: I6aa65911f74e194673744575698c4b9abca06fee
Reviewed-on: https://chromium-review.googlesource.com/624667
Commit-Queue: Scott Graham <scottmg@chromium.org>
Commit-Queue: Wez <wez@chromium.org>
Reviewed-by: Wez <wez@chromium.org>
Reviewed-by: Nico Weber <thakis@chromium.org>
Cr-Commit-Position: refs/heads/master@{#496066}
[modify] https://crrev.com/764d4f47288e3f4df439f4afecbd458a31661503/build/fuchsia/runner_common.py

Status: Fixed (was: Assigned)
"In theory"

Sign in to add a comment