In unit tests, OneShotTimer is not playing nicely with ScopedMockTimeMessageLoopTaskRunner |
|||||
Issue description
ToT as of June 23
OS: Linux (development desktop)
I'm working to get time-awareness built into our team's unit tests. I hooked up a ScopedMockTimeMessageLoopTaskRunner to a prototype test, but saw some weird behavior. I think I've distilled the failure down to a simple form.
Basically, if I start a one-shot timer twice (at the same time), the bound callback doesn't execute until twice the requested timeout period.
*something* appears to execute after the first time period, possibly a cancelled version of the first callback, but the body of the callback I queued doesn't run until a second period has elapsed.
The test looks like this:
#include "base/memory/ptr_util.h"
#include "testing/gmock/include/gmock/gmock.h"
#include "testing/gtest/include/gtest/gtest.h"
#include "base/test/scoped_mock_time_message_loop_task_runner.h"
TEST(SampleTest, Case) {
base::MessageLoop message_loop_;
base::ScopedMockTimeMessageLoopTaskRunner task_runner_;
base::OneShotTimer timer_;
timer_.Start(FROM_HERE, base::TimeDelta::FromSeconds(10),
base::Bind([]() { LOG(INFO) << "Done!"; }));
timer_.Start(FROM_HERE, base::TimeDelta::FromSeconds(10),
base::Bind([]() { LOG(INFO) << "Done!"; }));
task_runner_->FastForwardBy(base::TimeDelta::FromSeconds(11));
task_runner_->FastForwardBy(base::TimeDelta::FromSeconds(11));
}
I dropped some debug prints into the test message loop code, and in essence, see this:
Start timer for 10 s.
Start timer for 10 s.
Fast forwarding by 11 s
Task should run at: 10000000 bogo-microseconds
Running task!
Ran task!
Fast forwarding by 11 s
Task should run at: 19999777 bogo-microseconds
Running task!
Done!
Ran task!
There's certainly a chance that I'm misusing the test message loop, or the timer, but to me it seems like there's something fishy with the mock task runner.
Let me know if I can supply any more information!
,
Jun 26 2017
This is fallout of the base::Timer implementation @ https://cs.chromium.org/chromium/src/base/timer/timer.cc?rcl=6a99b678a21703b15f0886acddfd24e4171b878d&l=239 Mocking time only affects the main MessageLoop (i.e. delayed tasks posted to it). If base::Timer is restarted you'll get |desired_run_time_ > scheduled_run_time_| which will make base::Timer check Now() directly -- not the mocked Now(). base::Timer already supports being passed a custom TickClock but this has to be done explicitly which can require unfortunate plumbing. I'd take a change to add Timer::ScopedTickClock Timer::SetScopedTickClockForTesting(TickClock* tick_clock); to base::Timer. This would register |tick_clock| in timer.cc's anonymous namespace in the scope of the returned move-only Timer::ScopedTickClock. It would be called unconditionally by ScopedMockTimeMessageLoopTaskRunner with it's MockTickClock. base::Timer::Now() would default to it if it's specified.
,
Jun 27 2017
Thanks for that assessment. I think the "unfortunate plumbing" hits the nail on the head. I'll assign this back to myself, and work on adding this capability. Might take me a bit of thinking to completely grok your suggestion.
,
Jun 27 2017
Awesome! If it helps grokking: base::SequenceToken uses the same kind of scoped object (albeit being specific to the current thread whereas we want to set it in the global scope).
,
Jul 10 2017
,
Aug 8 2017
gab@, our framework's timing system has gone towards animation ticks rather than timers. Fixing this isn't going to buy us anything from a testing perspective. Based on above, do you think anyone else would benefit significantly? If so, I can try to still make this change. Otherwise, I'd prefer to close it off and revisit if we need to...
,
Aug 8 2017
go/scoped-task-environment is my long term vision for this (and many other task testing environment woes). Ultimately I want unit tests to have a mock clock for everything by default. Everything we do in the meantime is patch work as needed, so you can close this if you don't need it anymore Le mar. 8 août 2017 15 h 09, cjgrant via monorail < monorail+v2.3687040017@chromium.org> a écrit :
,
Aug 8 2017
A more complete long-term vision sounds awesome. The go/ link you included appears broken though. Could you patch it? I'd love to give it a read. As you indicated, I'll close this bug down.
,
Aug 9 2017
Here's the full link to the public doc (the register go link might have been without the dashes..?) : https://docs.google.com/a/chromium.org/document/d/1QabRo8c7D9LsYY3cEcaPQbOCLo8Tu-6VLykYXyl3Pkk/edit?usp=drivesdk |
|||||
►
Sign in to add a comment |
|||||
Comment 1 by cjgrant@chromium.org
, Jun 24 2017