summaryrefslogtreecommitdiff
diff options
context:
space:
mode:
authorJohn Drouhard <john@jmdtech.org>2021-03-26 12:07:21 -0500
committerJohn Drouhard <john@jmdtech.org>2022-06-10 08:45:47 -0500
commita2b5e6deff1545f5ca1947930fa59fa3ff236db7 (patch)
treee40719247e439840d00b9bc4228aa1c19c442ab7
parent55f54511d35716c43637dee2bcb5fbc7839f967b (diff)
downloadninja-a2b5e6deff1545f5ca1947930fa59fa3ff236db7.tar.gz
Introduce mechanism to provide resiliency for inputs changing while the build runs
When an edge starts to run, create a temporary lock file in the build directory, stat it, and cache its mtime. When the command finishes, use the temporary lock file's mtime from when the edge started running as the mtime that is recorded in the build log for each of the edge's output(s). Subsequent runs will use that as the mtime for the output(s). This provides robustness against inputs changing while the command itself is running. If an input is changed, the subsequent run will detect the output as dirty since its recorded mtime reflects when the build command began, not when the output was actually written to disk. Generator and restat rules are exempt from this and will continue to record their actual mtime on disk at the time the command finished in the build log (unless the restat rule cleans the output). This avoids potential infinite loops when the generator rule touches input dependencies of the output(s) or a restat rule intentionally changes implicit dependencies of its output.
-rw-r--r--src/build.cc88
-rw-r--r--src/build.h1
-rw-r--r--src/build_log.cc10
-rw-r--r--src/build_log.h2
-rw-r--r--src/build_test.cc320
-rw-r--r--src/disk_interface_test.cc2
-rw-r--r--src/graph.cc49
-rw-r--r--src/graph.h4
8 files changed, 396 insertions, 80 deletions
diff --git a/src/build.cc b/src/build.cc
index 6f11ed7..76ff93a 100644
--- a/src/build.cc
+++ b/src/build.cc
@@ -518,6 +518,10 @@ Builder::Builder(State* state, const BuildConfig& config,
start_time_millis_(start_time_millis), disk_interface_(disk_interface),
scan_(state, build_log, deps_log, disk_interface,
&config_.depfile_parser_options) {
+ lock_file_path_ = ".ninja_lock";
+ string build_dir = state_->bindings_.LookupVariable("builddir");
+ if (!build_dir.empty())
+ lock_file_path_ = build_dir + "/" + lock_file_path_;
}
Builder::~Builder() {
@@ -552,6 +556,10 @@ void Builder::Cleanup() {
disk_interface_->RemoveFile(depfile);
}
}
+
+ string err;
+ if (disk_interface_->Stat(lock_file_path_, &err) > 0)
+ disk_interface_->RemoveFile(lock_file_path_);
}
Node* Builder::AddTarget(const string& name, string* err) {
@@ -704,14 +712,25 @@ bool Builder::StartEdge(Edge* edge, string* err) {
status_->BuildEdgeStarted(edge, start_time_millis);
- // Create directories necessary for outputs.
+ TimeStamp build_start = -1;
+
+ // Create directories necessary for outputs and remember the current
+ // filesystem mtime to record later
// XXX: this will block; do we care?
for (vector<Node*>::iterator o = edge->outputs_.begin();
o != edge->outputs_.end(); ++o) {
if (!disk_interface_->MakeDirs((*o)->path()))
return false;
+ if (build_start == -1) {
+ disk_interface_->WriteFile(lock_file_path_, "");
+ build_start = disk_interface_->Stat(lock_file_path_, err);
+ if (build_start == -1)
+ build_start = 0;
+ }
}
+ edge->command_start_time_ = build_start;
+
// Create response file, if needed
// XXX: this may also block; do we care?
string rspfile = edge->GetUnescapedRspfile();
@@ -770,55 +789,42 @@ bool Builder::FinishCommand(CommandRunner::Result* result, string* err) {
}
// Restat the edge outputs
- TimeStamp output_mtime = 0;
- bool restat = edge->GetBindingBool("restat");
+ TimeStamp record_mtime = 0;
if (!config_.dry_run) {
+ const bool restat = edge->GetBindingBool("restat");
+ const bool generator = edge->GetBindingBool("generator");
bool node_cleaned = false;
-
- for (vector<Node*>::iterator o = edge->outputs_.begin();
- o != edge->outputs_.end(); ++o) {
- TimeStamp new_mtime = disk_interface_->Stat((*o)->path(), err);
- if (new_mtime == -1)
- return false;
- if (new_mtime > output_mtime)
- output_mtime = new_mtime;
- if ((*o)->mtime() == new_mtime && restat) {
- // The rule command did not change the output. Propagate the clean
- // state through the build graph.
- // Note that this also applies to nonexistent outputs (mtime == 0).
- if (!plan_.CleanNode(&scan_, *o, err))
+ record_mtime = edge->command_start_time_;
+
+ // restat and generator rules must restat the outputs after the build
+ // has finished. if record_mtime == 0, then there was an error while
+ // attempting to touch/stat the temp file when the edge started and
+ // we should fall back to recording the outputs' current mtime in the
+ // log.
+ if (record_mtime == 0 || restat || generator) {
+ for (vector<Node*>::iterator o = edge->outputs_.begin();
+ o != edge->outputs_.end(); ++o) {
+ TimeStamp new_mtime = disk_interface_->Stat((*o)->path(), err);
+ if (new_mtime == -1)
return false;
- node_cleaned = true;
+ if (new_mtime > record_mtime)
+ record_mtime = new_mtime;
+ if ((*o)->mtime() == new_mtime && restat) {
+ // The rule command did not change the output. Propagate the clean
+ // state through the build graph.
+ // Note that this also applies to nonexistent outputs (mtime == 0).
+ if (!plan_.CleanNode(&scan_, *o, err))
+ return false;
+ node_cleaned = true;
+ }
}
}
-
if (node_cleaned) {
- TimeStamp restat_mtime = 0;
- // If any output was cleaned, find the most recent mtime of any
- // (existing) non-order-only input or the depfile.
- for (vector<Node*>::iterator i = edge->inputs_.begin();
- i != edge->inputs_.end() - edge->order_only_deps_; ++i) {
- TimeStamp input_mtime = disk_interface_->Stat((*i)->path(), err);
- if (input_mtime == -1)
- return false;
- if (input_mtime > restat_mtime)
- restat_mtime = input_mtime;
- }
-
- string depfile = edge->GetUnescapedDepfile();
- if (restat_mtime != 0 && deps_type.empty() && !depfile.empty()) {
- TimeStamp depfile_mtime = disk_interface_->Stat(depfile, err);
- if (depfile_mtime == -1)
- return false;
- if (depfile_mtime > restat_mtime)
- restat_mtime = depfile_mtime;
- }
+ record_mtime = edge->command_start_time_;
// The total number of edges in the plan may have changed as a result
// of a restat.
status_->PlanHasTotalEdges(plan_.command_edge_count());
-
- output_mtime = restat_mtime;
}
}
@@ -832,7 +838,7 @@ bool Builder::FinishCommand(CommandRunner::Result* result, string* err) {
if (scan_.build_log()) {
if (!scan_.build_log()->RecordCommand(edge, start_time_millis,
- end_time_millis, output_mtime)) {
+ end_time_millis, record_mtime)) {
*err = string("Error writing to build log: ") + strerror(errno);
return false;
}
diff --git a/src/build.h b/src/build.h
index d697dfb..d727a8a 100644
--- a/src/build.h
+++ b/src/build.h
@@ -234,6 +234,7 @@ struct Builder {
/// Time the build started.
int64_t start_time_millis_;
+ std::string lock_file_path_;
DiskInterface* disk_interface_;
DependencyScan scan_;
diff --git a/src/build_log.cc b/src/build_log.cc
index 4dcd6ce..b35279d 100644
--- a/src/build_log.cc
+++ b/src/build_log.cc
@@ -116,9 +116,9 @@ BuildLog::LogEntry::LogEntry(const string& output)
: output(output) {}
BuildLog::LogEntry::LogEntry(const string& output, uint64_t command_hash,
- int start_time, int end_time, TimeStamp restat_mtime)
+ int start_time, int end_time, TimeStamp mtime)
: output(output), command_hash(command_hash),
- start_time(start_time), end_time(end_time), mtime(restat_mtime)
+ start_time(start_time), end_time(end_time), mtime(mtime)
{}
BuildLog::BuildLog()
@@ -303,7 +303,7 @@ LoadStatus BuildLog::Load(const string& path, string* err) {
*end = 0;
int start_time = 0, end_time = 0;
- TimeStamp restat_mtime = 0;
+ TimeStamp mtime = 0;
start_time = atoi(start);
start = end + 1;
@@ -319,7 +319,7 @@ LoadStatus BuildLog::Load(const string& path, string* err) {
if (!end)
continue;
*end = 0;
- restat_mtime = strtoll(start, NULL, 10);
+ mtime = strtoll(start, NULL, 10);
start = end + 1;
end = (char*)memchr(start, kFieldSeparator, line_end - start);
@@ -343,7 +343,7 @@ LoadStatus BuildLog::Load(const string& path, string* err) {
entry->start_time = start_time;
entry->end_time = end_time;
- entry->mtime = restat_mtime;
+ entry->mtime = mtime;
if (log_version >= 5) {
char c = *end; *end = '\0';
entry->command_hash = (uint64_t)strtoull(start, NULL, 16);
diff --git a/src/build_log.h b/src/build_log.h
index 88551e3..dd72c4c 100644
--- a/src/build_log.h
+++ b/src/build_log.h
@@ -73,7 +73,7 @@ struct BuildLog {
explicit LogEntry(const std::string& output);
LogEntry(const std::string& output, uint64_t command_hash,
- int start_time, int end_time, TimeStamp restat_mtime);
+ int start_time, int end_time, TimeStamp mtime);
};
/// Lookup a previously-run command by its output path.
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) {
diff --git a/src/disk_interface_test.cc b/src/disk_interface_test.cc
index 5e952ed..7041d98 100644
--- a/src/disk_interface_test.cc
+++ b/src/disk_interface_test.cc
@@ -198,7 +198,7 @@ TEST_F(DiskInterfaceTest, MakeDirs) {
EXPECT_EQ(0, fclose(f));
#ifdef _WIN32
string path2 = "another\\with\\back\\\\slashes\\";
- EXPECT_TRUE(disk_.MakeDirs(path2.c_str()));
+ EXPECT_TRUE(disk_.MakeDirs(path2));
FILE* f2 = fopen((path2 + "a_file").c_str(), "w");
EXPECT_TRUE(f2);
EXPECT_EQ(0, fclose(f2));
diff --git a/src/graph.cc b/src/graph.cc
index 43ba45a..041199a 100644
--- a/src/graph.cc
+++ b/src/graph.cc
@@ -298,37 +298,34 @@ bool DependencyScan::RecomputeOutputDirty(const Edge* edge,
return false;
}
- BuildLog::LogEntry* entry = 0;
-
// Dirty if we're missing the output.
if (!output->exists()) {
EXPLAIN("output %s doesn't exist", output->path().c_str());
return true;
}
- // Dirty if the output is older than the input.
- if (most_recent_input && output->mtime() < most_recent_input->mtime()) {
- TimeStamp output_mtime = output->mtime();
-
- // If this is a restat rule, we may have cleaned the output with a restat
- // rule in a previous run and stored the most recent input mtime in the
- // build log. Use that mtime instead, so that the file will only be
- // considered dirty if an input was modified since the previous run.
- bool used_restat = false;
- if (edge->GetBindingBool("restat") && build_log() &&
- (entry = build_log()->LookupByOutput(output->path()))) {
- output_mtime = entry->mtime;
- used_restat = true;
- }
+ BuildLog::LogEntry* entry = 0;
- if (output_mtime < most_recent_input->mtime()) {
- EXPLAIN("%soutput %s older than most recent input %s "
- "(%" PRId64 " vs %" PRId64 ")",
- used_restat ? "restat of " : "", output->path().c_str(),
- most_recent_input->path().c_str(),
- output_mtime, most_recent_input->mtime());
- return true;
- }
+ // If this is a restat rule, we may have cleaned the output in a
+ // previous run and stored the command start time in the build log.
+ // We don't want to consider a restat rule's outputs as dirty unless
+ // an input changed since the last run, so we'll skip checking the
+ // output file's actual mtime and simply check the recorded mtime from
+ // the log against the most recent input's mtime (see below)
+ bool used_restat = false;
+ if (edge->GetBindingBool("restat") && build_log() &&
+ (entry = build_log()->LookupByOutput(output->path()))) {
+ used_restat = true;
+ }
+
+ // Dirty if the output is older than the input.
+ if (!used_restat && most_recent_input && output->mtime() < most_recent_input->mtime()) {
+ EXPLAIN("output %s older than most recent input %s "
+ "(%" PRId64 " vs %" PRId64 ")",
+ output->path().c_str(),
+ most_recent_input->path().c_str(),
+ output->mtime(), most_recent_input->mtime());
+ return true;
}
if (build_log()) {
@@ -346,7 +343,9 @@ bool DependencyScan::RecomputeOutputDirty(const Edge* edge,
// May also be dirty due to the mtime in the log being older than the
// mtime of the most recent input. This can occur even when the mtime
// on disk is newer if a previous run wrote to the output file but
- // exited with an error or was interrupted.
+ // exited with an error or was interrupted. If this was a restat rule,
+ // then we only check the recorded mtime against the most recent input
+ // mtime and ignore the actual output's mtime above.
EXPLAIN("recorded mtime of %s older than most recent input %s (%" PRId64 " vs %" PRId64 ")",
output->path().c_str(), most_recent_input->path().c_str(),
entry->mtime, most_recent_input->mtime());
diff --git a/src/graph.h b/src/graph.h
index 9de67d2..d07a9b7 100644
--- a/src/graph.h
+++ b/src/graph.h
@@ -172,7 +172,8 @@ struct Edge {
: rule_(NULL), pool_(NULL), dyndep_(NULL), env_(NULL), mark_(VisitNone),
id_(0), outputs_ready_(false), deps_loaded_(false),
deps_missing_(false), generated_by_dep_loader_(false),
- implicit_deps_(0), order_only_deps_(0), implicit_outs_(0) {}
+ command_start_time_(0), implicit_deps_(0), order_only_deps_(0),
+ implicit_outs_(0) {}
/// Return true if all inputs' in-edges are ready.
bool AllInputsReady() const;
@@ -211,6 +212,7 @@ struct Edge {
bool deps_loaded_;
bool deps_missing_;
bool generated_by_dep_loader_;
+ TimeStamp command_start_time_;
const Rule& rule() const { return *rule_; }
Pool* pool() const { return pool_; }