1 files changed, 314 insertions, 6 deletions

diff --git a/src/build_test.cc b/src/build_test.cc
index 4ef62b2..3908761 100644
--- a/src/build_test.cc
+++ b/src/build_test.cc
@@ -611,6 +611,7 @@ bool FakeCommandRunner::StartCommand(Edge* edge) {
       fs_->WriteFile(edge->outputs_[0]->path(), content);
   } else if (edge->rule().name() == "touch-implicit-dep-out") {
     string dep = edge->GetBinding("test_dependency");
+    fs_->Tick();
     fs_->Create(dep, "");
     fs_->Tick();
     for (vector<Node*>::iterator out = edge->outputs_.begin();
@@ -627,7 +628,12 @@ bool FakeCommandRunner::StartCommand(Edge* edge) {
     fs_->Create(dep, "");
   } else if (edge->rule().name() == "generate-depfile") {
     string dep = edge->GetBinding("test_dependency");
+    bool touch_dep = edge->GetBindingBool("touch_dependency");
     string depfile = edge->GetUnescapedDepfile();
+    if (touch_dep) {
+      fs_->Tick();
+      fs_->Create(dep, "");
+    }
     string contents;
     for (vector<Node*>::iterator out = edge->outputs_.begin();
          out != edge->outputs_.end(); ++out) {
@@ -635,6 +641,20 @@ bool FakeCommandRunner::StartCommand(Edge* edge) {
       fs_->Create((*out)->path(), "");
     }
     fs_->Create(depfile, contents);
+  } else if (edge->rule().name() == "long-cc") {
+    string dep = edge->GetBinding("test_dependency");
+    string depfile = edge->GetUnescapedDepfile();
+    string contents;
+    for (vector<Node*>::iterator out = edge->outputs_.begin();
+        out != edge->outputs_.end(); ++out) {
+      fs_->Tick();
+      fs_->Tick();
+      fs_->Tick();
+      fs_->Create((*out)->path(), "");
+      contents += (*out)->path() + ": " + dep + "\n";
+    }
+    if (!dep.empty() && !depfile.empty())
+      fs_->Create(depfile, contents);
   } else {
     printf("unknown command\n");
     return false;
@@ -690,6 +710,18 @@ bool FakeCommandRunner::WaitForCommand(Result* result) {
   else
     result->status = ExitSuccess;
 
+  // This rule simulates an external process modifying files while the build command runs.
+  // See TestInputMtimeRaceCondition and TestInputMtimeRaceConditionWithDepFile.
+  // Note: only the first and third time the rule is run per test is the file modified, so
+  // the test can verify that subsequent runs without the race have no work to do.
+  if (edge->rule().name() == "long-cc") {
+    string dep = edge->GetBinding("test_dependency");
+    if (fs_->now_ == 4)
+      fs_->files_[dep].mtime = 3;
+    if (fs_->now_ == 10)
+      fs_->files_[dep].mtime = 9;
+  }
+
   // Provide a way for test cases to verify when an edge finishes that
   // some other edge is still active.  This is useful for test cases
   // covering behavior involving multiple active edges.
@@ -1471,7 +1503,7 @@ TEST_F(BuildWithLogTest, ImplicitGeneratedOutOfDate) {
 TEST_F(BuildWithLogTest, ImplicitGeneratedOutOfDate2) {
   ASSERT_NO_FATAL_FAILURE(AssertParse(&state_,
 "rule touch-implicit-dep-out\n"
-"  command = touch $test_dependency ; sleep 1 ; touch $out\n"
+"  command = sleep 1 ; touch $test_dependency ; sleep 1 ; touch $out\n"
 "  generator = 1\n"
 "build out.imp: touch-implicit-dep-out | inimp inimp2\n"
 "  test_dependency = inimp\n"));
@@ -1497,6 +1529,29 @@ TEST_F(BuildWithLogTest, ImplicitGeneratedOutOfDate2) {
   EXPECT_TRUE(builder_.AddTarget("out.imp", &err));
   EXPECT_TRUE(builder_.AlreadyUpToDate());
   EXPECT_FALSE(GetNode("out.imp")->dirty());
+
+  command_runner_.commands_ran_.clear();
+  state_.Reset();
+  builder_.Cleanup();
+  builder_.plan_.Reset();
+
+  fs_.Tick();
+  fs_.Create("inimp", "");
+
+  EXPECT_TRUE(builder_.AddTarget("out.imp", &err));
+  EXPECT_FALSE(builder_.AlreadyUpToDate());
+
+  EXPECT_TRUE(builder_.Build(&err));
+  EXPECT_TRUE(builder_.AlreadyUpToDate());
+
+  command_runner_.commands_ran_.clear();
+  state_.Reset();
+  builder_.Cleanup();
+  builder_.plan_.Reset();
+
+  EXPECT_TRUE(builder_.AddTarget("out.imp", &err));
+  EXPECT_TRUE(builder_.AlreadyUpToDate());
+  EXPECT_FALSE(GetNode("out.imp")->dirty());
 }
 
 TEST_F(BuildWithLogTest, NotInLogButOnDisk) {
@@ -1800,6 +1855,52 @@ TEST_F(BuildWithLogTest, RestatMissingInput) {
   ASSERT_EQ(restat_mtime, log_entry->mtime);
 }
 
+TEST_F(BuildWithLogTest, RestatInputChangesDueToRule) {
+  ASSERT_NO_FATAL_FAILURE(AssertParse(&state_,
+"rule generate-depfile\n"
+"  command = sleep 1 ; touch $touch_dependency; touch $out ; echo \"$out: $test_dependency\" > $depfile\n"
+"build out1: generate-depfile || cat1\n"
+"  test_dependency = in2\n"
+"  touch_dependency = 1\n"
+"  restat = 1\n"
+"  depfile = out.d\n"));
+
+  // Perform the first build. out1 is a restat rule, so its recorded mtime in the build
+  // log should be the time the command completes, not the time the command started. One
+  // of out1's discovered dependencies will have a newer mtime than when out1 started
+  // running, due to its command touching the dependency itself.
+  string err;
+  EXPECT_TRUE(builder_.AddTarget("out1", &err));
+  ASSERT_EQ("", err);
+  EXPECT_TRUE(builder_.Build(&err));
+  ASSERT_EQ("", err);
+  EXPECT_EQ(2u, command_runner_.commands_ran_.size());
+  EXPECT_EQ(2u, builder_.plan_.command_edge_count());
+  BuildLog::LogEntry* log_entry = build_log_.LookupByOutput("out1");
+  ASSERT_TRUE(NULL != log_entry);
+  ASSERT_EQ(2u, log_entry->mtime);
+
+  command_runner_.commands_ran_.clear();
+  state_.Reset();
+  builder_.Cleanup();
+  builder_.plan_.Reset();
+
+  fs_.Tick();
+  fs_.Create("in1", "");
+
+  // Touching a dependency of an order-only dependency of out1 should not cause out1 to
+  // rebuild. If out1 were not a restat rule, then it would rebuild here because its
+  // recorded mtime would have been an earlier mtime than its most recent input's (in2)
+  // mtime
+  EXPECT_TRUE(builder_.AddTarget("out1", &err));
+  ASSERT_EQ("", err);
+  EXPECT_TRUE(!state_.GetNode("out1", 0)->dirty());
+  EXPECT_TRUE(builder_.Build(&err));
+  ASSERT_EQ("", err);
+  EXPECT_EQ(1u, command_runner_.commands_ran_.size());
+  EXPECT_EQ(1u, builder_.plan_.command_edge_count());
+}
+
 TEST_F(BuildWithLogTest, GeneratedPlainDepfileMtime) {
   ASSERT_NO_FATAL_FAILURE(AssertParse(&state_,
 "rule generate-depfile\n"
@@ -1904,10 +2005,11 @@ TEST_F(BuildTest, RspFileSuccess)
   EXPECT_TRUE(builder_.Build(&err));
   ASSERT_EQ(3u, command_runner_.commands_ran_.size());
 
-  // The RSP files were created
-  ASSERT_EQ(files_created + 2, fs_.files_created_.size());
+  // The RSP files and temp file to acquire output mtimes were created
+  ASSERT_EQ(files_created + 3, fs_.files_created_.size());
   ASSERT_EQ(1u, fs_.files_created_.count("out 2.rsp"));
   ASSERT_EQ(1u, fs_.files_created_.count("out 3.rsp"));
+  ASSERT_EQ(1u, fs_.files_created_.count(".ninja_lock"));
 
   // The RSP files were removed
   ASSERT_EQ(files_removed + 2, fs_.files_removed_.size());
@@ -1941,9 +2043,10 @@ TEST_F(BuildTest, RspFileFailure) {
   ASSERT_EQ("subcommand failed", err);
   ASSERT_EQ(1u, command_runner_.commands_ran_.size());
 
-  // The RSP file was created
-  ASSERT_EQ(files_created + 1, fs_.files_created_.size());
+  // The RSP file and temp file to acquire output mtimes were created
+  ASSERT_EQ(files_created + 2, fs_.files_created_.size());
   ASSERT_EQ(1u, fs_.files_created_.count("out.rsp"));
+  ASSERT_EQ(1u, fs_.files_created_.count(".ninja_lock"));
 
   // The RSP file was NOT removed
   ASSERT_EQ(files_removed, fs_.files_removed_.size());
@@ -2522,6 +2625,210 @@ TEST_F(BuildWithDepsLogTest, DepsIgnoredInDryRun) {
   builder.command_runner_.release();
 }
 
+TEST_F(BuildWithDepsLogTest, TestInputMtimeRaceCondition) {
+  string err;
+  const char* manifest =
+      "rule long-cc\n"
+      "  command = long-cc\n"
+      "build out: long-cc in1\n"
+      "  test_dependency = in1\n";
+
+  State state;
+  ASSERT_NO_FATAL_FAILURE(AddCatRule(&state));
+  ASSERT_NO_FATAL_FAILURE(AssertParse(&state, manifest));
+
+  BuildLog build_log;
+  ASSERT_TRUE(build_log.Load("build_log", &err));
+  ASSERT_TRUE(build_log.OpenForWrite("build_log", *this, &err));
+
+  DepsLog deps_log;
+  ASSERT_TRUE(deps_log.Load("ninja_deps", &state, &err));
+  ASSERT_TRUE(deps_log.OpenForWrite("ninja_deps", &err));
+
+  BuildLog::LogEntry* log_entry = NULL;
+  {
+    Builder builder(&state, config_, &build_log, &deps_log, &fs_, &status_, 0);
+    builder.command_runner_.reset(&command_runner_);
+    command_runner_.commands_ran_.clear();
+
+    // Run the build, out gets built, dep file is created
+    EXPECT_TRUE(builder.AddTarget("out", &err));
+    ASSERT_EQ("", err);
+    EXPECT_TRUE(builder.Build(&err));
+    ASSERT_EQ(1u, command_runner_.commands_ran_.size());
+
+    // See that an entry in the logfile is created. the input_mtime is 1 since that was
+    // the mtime of in1 when the command was started
+    log_entry = build_log.LookupByOutput("out");
+    ASSERT_TRUE(NULL != log_entry);
+    ASSERT_EQ(1u, log_entry->mtime);
+
+    builder.command_runner_.release();
+  }
+
+  {
+    Builder builder(&state, config_, &build_log, &deps_log, &fs_, &status_, 0);
+    builder.command_runner_.reset(&command_runner_);
+    command_runner_.commands_ran_.clear();
+
+    // Trigger the build again - "out" should rebuild despite having a newer mtime than
+    // "in1", since "in1" was touched during the build of out (simulated by changing its
+    // mtime in the the test builder's WaitForCommand() which runs before FinishCommand()
+    command_runner_.commands_ran_.clear();
+    state.Reset();
+    EXPECT_TRUE(builder.AddTarget("out", &err));
+    ASSERT_EQ("", err);
+    EXPECT_TRUE(builder.Build(&err));
+    ASSERT_EQ(1u, command_runner_.commands_ran_.size());
+
+    // Check that the logfile entry is still correct
+    log_entry = build_log.LookupByOutput("out");
+    ASSERT_TRUE(NULL != log_entry);
+    ASSERT_TRUE(fs_.files_["in1"].mtime < log_entry->mtime);
+    builder.command_runner_.release();
+  }
+
+  {
+    Builder builder(&state, config_, &build_log, &deps_log, &fs_, &status_, 0);
+    builder.command_runner_.reset(&command_runner_);
+    command_runner_.commands_ran_.clear();
+
+    // And a subsequent run should not have any work to do
+    command_runner_.commands_ran_.clear();
+    state.Reset();
+    EXPECT_TRUE(builder.AddTarget("out", &err));
+    ASSERT_EQ("", err);
+    EXPECT_TRUE(builder.AlreadyUpToDate());
+
+    builder.command_runner_.release();
+  }
+}
+
+TEST_F(BuildWithDepsLogTest, TestInputMtimeRaceConditionWithDepFile) {
+  string err;
+  const char* manifest =
+      "rule long-cc\n"
+      "  command = long-cc\n"
+      "build out: long-cc\n"
+      "  deps = gcc\n"
+      "  depfile = out.d\n"
+      "  test_dependency = header.h\n";
+
+  fs_.Create("header.h", "");
+
+  State state;
+  ASSERT_NO_FATAL_FAILURE(AssertParse(&state, manifest));
+
+  BuildLog build_log;
+  ASSERT_TRUE(build_log.Load("build_log", &err));
+  ASSERT_TRUE(build_log.OpenForWrite("build_log", *this, &err));
+
+  DepsLog deps_log;
+  ASSERT_TRUE(deps_log.Load("ninja_deps", &state, &err));
+  ASSERT_TRUE(deps_log.OpenForWrite("ninja_deps", &err));
+
+  {
+    Builder builder(&state, config_, &build_log, &deps_log, &fs_, &status_, 0);
+    builder.command_runner_.reset(&command_runner_);
+
+    // Run the build, out gets built, dep file is created
+    EXPECT_TRUE(builder.AddTarget("out", &err));
+    ASSERT_EQ("", err);
+    EXPECT_TRUE(builder.Build(&err));
+    ASSERT_EQ(1u, command_runner_.commands_ran_.size());
+
+    // See that an entry in the logfile is created. the mtime is 1 due to the command
+    // starting when the file system's mtime was 1.
+    BuildLog::LogEntry* log_entry = build_log.LookupByOutput("out");
+    ASSERT_TRUE(NULL != log_entry);
+    ASSERT_EQ(1u, log_entry->mtime);
+
+    builder.command_runner_.release();
+  }
+
+  {
+    // Trigger the build again - "out" will rebuild since its newest input mtime (header.h)
+    // is newer than the recorded mtime of out in the build log
+    Builder builder(&state, config_, &build_log, &deps_log, &fs_, &status_, 0);
+    builder.command_runner_.reset(&command_runner_);
+    command_runner_.commands_ran_.clear();
+
+    state.Reset();
+    EXPECT_TRUE(builder.AddTarget("out", &err));
+    ASSERT_EQ("", err);
+    EXPECT_TRUE(builder.Build(&err));
+    ASSERT_EQ(1u, command_runner_.commands_ran_.size());
+
+    builder.command_runner_.release();
+  }
+
+  {
+    // Trigger the build again - "out" won't rebuild since the file wasn't updated during
+    // the previous build
+    Builder builder(&state, config_, &build_log, &deps_log, &fs_, &status_, 0);
+    builder.command_runner_.reset(&command_runner_);
+    command_runner_.commands_ran_.clear();
+
+    state.Reset();
+    EXPECT_TRUE(builder.AddTarget("out", &err));
+    ASSERT_EQ("", err);
+    ASSERT_TRUE(builder.AlreadyUpToDate());
+
+    builder.command_runner_.release();
+  }
+
+  // touch the header to trigger a rebuild
+  fs_.Create("header.h", "");
+  ASSERT_EQ(fs_.now_, 7);
+
+  {
+    // Rebuild. This time, long-cc will cause header.h to be updated while the build is
+    // in progress
+    Builder builder(&state, config_, &build_log, &deps_log, &fs_, &status_, 0);
+    builder.command_runner_.reset(&command_runner_);
+    command_runner_.commands_ran_.clear();
+
+    state.Reset();
+    EXPECT_TRUE(builder.AddTarget("out", &err));
+    ASSERT_EQ("", err);
+    EXPECT_TRUE(builder.Build(&err));
+    ASSERT_EQ(1u, command_runner_.commands_ran_.size());
+
+    builder.command_runner_.release();
+  }
+
+  {
+    // Rebuild. Because header.h is now in the deplog for out, it should be detectable as
+    // a change-while-in-progress and should cause a rebuild of out.
+    Builder builder(&state, config_, &build_log, &deps_log, &fs_, &status_, 0);
+    builder.command_runner_.reset(&command_runner_);
+    command_runner_.commands_ran_.clear();
+
+    state.Reset();
+    EXPECT_TRUE(builder.AddTarget("out", &err));
+    ASSERT_EQ("", err);
+    EXPECT_TRUE(builder.Build(&err));
+    ASSERT_EQ(1u, command_runner_.commands_ran_.size());
+
+    builder.command_runner_.release();
+  }
+
+  {
+    // This time, the header.h file was not updated during the build, so the target should
+    // not be considered dirty.
+    Builder builder(&state, config_, &build_log, &deps_log, &fs_, &status_, 0);
+    builder.command_runner_.reset(&command_runner_);
+    command_runner_.commands_ran_.clear();
+
+    state.Reset();
+    EXPECT_TRUE(builder.AddTarget("out", &err));
+    ASSERT_EQ("", err);
+    EXPECT_TRUE(builder.AlreadyUpToDate());
+
+    builder.command_runner_.release();
+  }
+}
+
 /// Check that a restat rule generating a header cancels compilations correctly.
 TEST_F(BuildTest, RestatDepfileDependency) {
   ASSERT_NO_FATAL_FAILURE(AssertParse(&state_,
@@ -3042,9 +3349,10 @@ TEST_F(BuildTest, DyndepBuild) {
   ASSERT_EQ(2u, fs_.files_read_.size());
   EXPECT_EQ("dd-in", fs_.files_read_[0]);
   EXPECT_EQ("dd", fs_.files_read_[1]);
-  ASSERT_EQ(2u + files_created, fs_.files_created_.size());
+  ASSERT_EQ(3u + files_created, fs_.files_created_.size());
   EXPECT_EQ(1u, fs_.files_created_.count("dd"));
   EXPECT_EQ(1u, fs_.files_created_.count("out"));
+  EXPECT_EQ(1u, fs_.files_created_.count(".ninja_lock"));
 }
 
 TEST_F(BuildTest, DyndepBuildSyntaxError) {