Skip to content

Commit

Permalink
GuardDog: Test: Fix race in mocked time source. (#719)
Browse files Browse the repository at this point in the history 
The guard dog test made additional EXPECT_CALLs to update the time the
mocked time source should return after the mocked object was passed to
the GD thread.  Doing additional EXPECT_CALLs in this way is NOT thread
safe and resulted in 0.5-1% of tests failing when many were executed in
parallel.

The solution is to make the expect call action be to invoke a lambda
that shares access to a safe atomic updated in the main test thread.
  • Loading branch information
@dnoe @mattklein123
dnoe authored and mattklein123 committed Apr 8, 2017
1 parent 2777b3f commit 96edf4f
Showing 1 changed file with 27 additions and 24 deletions.
51 changes: 27 additions & 24 deletions test/server/guarddog_impl_test.cc
View file
Original file line number Diff line number Diff line change
Expand Up @@ -24,21 +24,23 @@ namespace Server {
class GuardDogDeathTest : public testing::Test {
protected:
GuardDogDeathTest()
: config_kill_(1000, 1000, 100, 1000), config_multikill_(1000, 1000, 1000, 500),
time_point_(std::chrono::system_clock::now()) {}
: config_kill_(1000, 1000, 100, 1000), config_multikill_(1000, 1000, 1000, 500) {
ON_CALL(time_source_, currentSystemTime())
.WillByDefault(testing::Invoke([&]() {
return std::chrono::system_clock::time_point(std::chrono::milliseconds(mock_time_));
}));
}

/**
* This does everything but the final forceCheckForTest() that should cause
* death for the single kill case.
*/
void SetupForDeath() {
InSequence s;
EXPECT_CALL(time_source_, currentSystemTime()).WillRepeatedly(testing::Return(time_point_));
guard_dog_.reset(new GuardDogImpl(fakestats_, config_kill_, time_source_));
unpet_dog_ = guard_dog_->createWatchDog(0);
guard_dog_->forceCheckForTest();
time_point_ += std::chrono::milliseconds(500);
EXPECT_CALL(time_source_, currentSystemTime()).WillRepeatedly(testing::Return(time_point_));
mock_time_ += 500;
}

/**
Expand All @@ -47,21 +49,19 @@ class GuardDogDeathTest : public testing::Test {
*/
void SetupForMultiDeath() {
InSequence s;
EXPECT_CALL(time_source_, currentSystemTime()).WillRepeatedly(testing::Return(time_point_));
guard_dog_.reset(new GuardDogImpl(fakestats_, config_multikill_, time_source_));
auto unpet_dog_ = guard_dog_->createWatchDog(0);
guard_dog_->forceCheckForTest();
auto second_dog_ = guard_dog_->createWatchDog(1);
guard_dog_->forceCheckForTest();
time_point_ += std::chrono::milliseconds(501);
EXPECT_CALL(time_source_, currentSystemTime()).WillRepeatedly(testing::Return(time_point_));
mock_time_ += 501;
}

NiceMock<Configuration::MockMain> config_kill_;
NiceMock<Configuration::MockMain> config_multikill_;
NiceMock<Stats::MockStore> fakestats_;
MockSystemTimeSource time_source_;
std::chrono::system_clock::time_point time_point_;
std::atomic<unsigned int> mock_time_;
std::unique_ptr<GuardDogImpl> guard_dog_;
WatchDogSharedPtr unpet_dog_;
WatchDogSharedPtr second_dog_;
Expand Down Expand Up @@ -108,7 +108,6 @@ TEST_F(GuardDogAlmostDeadTest, NearDeathTest) {
// This ensures that if only one thread surpasses the multiple kill threshold
// there is no death. The positive case is covered in MultiKillDeathTest.
InSequence s;
EXPECT_CALL(time_source_, currentSystemTime()).WillRepeatedly(testing::Return(time_point_));
GuardDogImpl gd(fakestats_, config_multikill_, time_source_);
auto unpet_dog = gd.createWatchDog(0);
auto pet_dog = gd.createWatchDog(1);
Expand All @@ -117,40 +116,43 @@ TEST_F(GuardDogAlmostDeadTest, NearDeathTest) {
// only one is nonresponsive, so there should be no kill (single kill
// threshold of 1s is not reached).
for (int i = 0; i < 6; i++) {
time_point_ += std::chrono::milliseconds(100);
EXPECT_CALL(time_source_, currentSystemTime()).WillRepeatedly(testing::Return(time_point_));
mock_time_ += 100;
pet_dog->touch();
gd.forceCheckForTest();
}
}

class GuardDogMissTest : public testing::Test {
protected:
GuardDogMissTest() : config_miss_(500, 1000, 0, 0), config_mega_(1000, 500, 0, 0) {}
GuardDogMissTest() : config_miss_(500, 1000, 0, 0), config_mega_(1000, 500, 0, 0) {
ON_CALL(time_source_, currentSystemTime())
.WillByDefault(testing::Invoke([&]() {
return std::chrono::system_clock::time_point(std::chrono::milliseconds(mock_time_));
}));
}

NiceMock<Configuration::MockMain> config_miss_;
NiceMock<Configuration::MockMain> config_mega_;
Stats::IsolatedStoreImpl stats_store_;
MockSystemTimeSource time_source_;
std::chrono::system_clock::time_point time_point_;
std::atomic<unsigned int> mock_time_;
};

TEST_F(GuardDogMissTest, MissTest) {
// This test checks the actual collected statistics after doing some timer
// advances that should and shouldn't increment the counters.
EXPECT_CALL(time_source_, currentSystemTime()).WillRepeatedly(testing::Return(time_point_));
GuardDogImpl gd(stats_store_, config_miss_, time_source_);
// We'd better start at 0:
EXPECT_EQ(0UL, stats_store_.counter("server.watchdog_miss").value());
auto unpet_dog = gd.createWatchDog(0);
// At 300ms we shouldn't have hit the timeout yet:
time_point_ += std::chrono::milliseconds(300);
EXPECT_CALL(time_source_, currentSystemTime()).WillRepeatedly(testing::Return(time_point_));
mock_time_ += 300;
// EXPECT_CALL(time_source_, currentSystemTime()).WillRepeatedly(testing::Return(time_point_));
gd.forceCheckForTest();
EXPECT_EQ(0UL, stats_store_.counter("server.watchdog_miss").value());
// This should push it past the 500ms limit:
time_point_ += std::chrono::milliseconds(250);
EXPECT_CALL(time_source_, currentSystemTime()).WillRepeatedly(testing::Return(time_point_));
mock_time_ += 250;
// EXPECT_CALL(time_source_, currentSystemTime()).WillRepeatedly(testing::Return(time_point_));
gd.forceCheckForTest();
EXPECT_EQ(1UL, stats_store_.counter("server.watchdog_miss").value());
gd.stopWatching(unpet_dog);
Expand All @@ -160,19 +162,20 @@ TEST_F(GuardDogMissTest, MissTest) {
TEST_F(GuardDogMissTest, MegaMissTest) {
// This test checks the actual collected statistics after doing some timer
// advances that should and shouldn't increment the counters.
EXPECT_CALL(time_source_, currentSystemTime()).WillRepeatedly(testing::Return(time_point_));
ON_CALL(time_source_, currentSystemTime())
.WillByDefault(testing::Invoke([&]() {
return std::chrono::system_clock::time_point(std::chrono::milliseconds(mock_time_));
}));
GuardDogImpl gd(stats_store_, config_mega_, time_source_);
auto unpet_dog = gd.createWatchDog(0);
// We'd better start at 0:
EXPECT_EQ(0UL, stats_store_.counter("server.watchdog_mega_miss").value());
// This shouldn't be enough to increment the stat:
time_point_ += std::chrono::milliseconds(499);
EXPECT_CALL(time_source_, currentSystemTime()).WillRepeatedly(testing::Return(time_point_));
mock_time_ += 499;
gd.forceCheckForTest();
EXPECT_EQ(0UL, stats_store_.counter("server.watchdog_mega_miss").value());
// Just 2ms more will make it greater than 500ms timeout:
time_point_ += std::chrono::milliseconds(2);
EXPECT_CALL(time_source_, currentSystemTime()).WillRepeatedly(testing::Return(time_point_));
mock_time_ += 2;
gd.forceCheckForTest();
EXPECT_EQ(1UL, stats_store_.counter("server.watchdog_mega_miss").value());
gd.stopWatching(unpet_dog);
Expand Down

0 comments on commit 96edf4f

Please sign in to comment.