summaryrefslogtreecommitdiffstats
diff options
context:
space:
mode:
Diffstat
-rw-r--r--src/build.cc79
-rw-r--r--src/build.h54
-rw-r--r--src/build_test.cc34
-rw-r--r--src/ninja.cc11
4 files changed, 80 insertions, 98 deletions
diff --git a/src/build.cc b/src/build.cc
index 2007d82..f04e2f2 100644
--- a/src/build.cc
+++ b/src/build.cc
@@ -36,6 +36,7 @@
#include "deps_log.h"
#include "disk_interface.h"
#include "graph.h"
+#include "metrics.h"
#include "state.h"
#include "subprocess.h"
#include "util.h"
@@ -79,8 +80,9 @@ bool DryRunCommandRunner::WaitForCommand(Result* result) {
} // namespace
BuildStatus::BuildStatus(const BuildConfig& config)
- : config_(config), start_time_millis_(GetTimeMillis()), started_edges_(0),
- finished_edges_(0), total_edges_(0), progress_status_format_(NULL),
+ : config_(config),
+ started_edges_(0), finished_edges_(0), total_edges_(0),
+ time_millis_(0), progress_status_format_(NULL),
current_rate_(config.parallelism) {
// Don't do anything fancy in verbose mode.
if (config_.verbosity != BuildConfig::NORMAL)
@@ -95,33 +97,24 @@ void BuildStatus::PlanHasTotalEdges(int total) {
total_edges_ = total;
}
-void BuildStatus::BuildEdgeStarted(const Edge* edge) {
- assert(running_edges_.find(edge) == running_edges_.end());
- int start_time = (int)(GetTimeMillis() - start_time_millis_);
- running_edges_.insert(make_pair(edge, start_time));
+void BuildStatus::BuildEdgeStarted(const Edge* edge,
+ int64_t start_time_millis) {
++started_edges_;
+ time_millis_ = start_time_millis;
if (edge->use_console() || printer_.is_smart_terminal())
- PrintStatus(edge, kEdgeStarted);
+ PrintStatus(edge, start_time_millis, kEdgeStarted);
if (edge->use_console())
printer_.SetConsoleLocked(true);
}
-void BuildStatus::BuildEdgeFinished(Edge* edge,
+void BuildStatus::BuildEdgeFinished(Edge* edge, int64_t end_time_millis,
bool success,
- const string& output,
- int* start_time,
- int* end_time) {
- int64_t now = GetTimeMillis();
-
+ const string& output) {
+ time_millis_ = end_time_millis;
++finished_edges_;
- RunningEdgeMap::iterator i = running_edges_.find(edge);
- *start_time = i->second;
- *end_time = (int)(now - start_time_millis_);
- running_edges_.erase(i);
-
if (edge->use_console())
printer_.SetConsoleLocked(false);
@@ -129,7 +122,7 @@ void BuildStatus::BuildEdgeFinished(Edge* edge,
return;
if (!edge->use_console())
- PrintStatus(edge, kEdgeFinished);
+ PrintStatus(edge, end_time_millis, kEdgeFinished);
// Print the command that is spewing before printing its output.
if (!success) {
@@ -192,8 +185,6 @@ void BuildStatus::BuildLoadDyndeps() {
}
void BuildStatus::BuildStarted() {
- overall_rate_.Restart();
- current_rate_.Restart();
}
void BuildStatus::BuildFinished() {
@@ -202,10 +193,9 @@ void BuildStatus::BuildFinished() {
}
string BuildStatus::FormatProgressStatus(
- const char* progress_status_format, EdgeStatus status) const {
+ const char* progress_status_format, int64_t time, EdgeStatus status) const {
string out;
char buf[32];
- int percent;
for (const char* s = progress_status_format; *s != '\0'; ++s) {
if (*s == '%') {
++s;
@@ -251,28 +241,27 @@ string BuildStatus::FormatProgressStatus(
// Overall finished edges per second.
case 'o':
- overall_rate_.UpdateRate(finished_edges_);
- SnprintfRate(overall_rate_.rate(), buf, "%.1f");
+ SnprintfRate(finished_edges_ / (time_millis_ / 1e3), buf, "%.1f");
out += buf;
break;
// Current rate, average over the last '-j' jobs.
case 'c':
- current_rate_.UpdateRate(finished_edges_);
+ current_rate_.UpdateRate(finished_edges_, time_millis_);
SnprintfRate(current_rate_.rate(), buf, "%.1f");
out += buf;
break;
// Percentage
- case 'p':
- percent = (100 * finished_edges_) / total_edges_;
+ case 'p': {
+ int percent = (100 * finished_edges_) / total_edges_;
snprintf(buf, sizeof(buf), "%3i%%", percent);
out += buf;
break;
+ }
case 'e': {
- double elapsed = overall_rate_.Elapsed();
- snprintf(buf, sizeof(buf), "%.3f", elapsed);
+ snprintf(buf, sizeof(buf), "%.3f", time_millis_ / 1e3);
out += buf;
break;
}
@@ -289,7 +278,7 @@ string BuildStatus::FormatProgressStatus(
return out;
}
-void BuildStatus::PrintStatus(const Edge* edge, EdgeStatus status) {
+void BuildStatus::PrintStatus(const Edge* edge, int64_t time, EdgeStatus status) {
if (config_.verbosity == BuildConfig::QUIET)
return;
@@ -299,7 +288,7 @@ void BuildStatus::PrintStatus(const Edge* edge, EdgeStatus status) {
if (to_print.empty() || force_full_command)
to_print = edge->GetBinding("command");
- to_print = FormatProgressStatus(progress_status_format_, status) + to_print;
+ to_print = FormatProgressStatus(progress_status_format_, time, status) + to_print;
printer_.Print(to_print,
force_full_command ? LinePrinter::FULL : LinePrinter::ELIDE);
@@ -729,9 +718,9 @@ bool RealCommandRunner::WaitForCommand(Result* result) {
Builder::Builder(State* state, const BuildConfig& config,
BuildLog* build_log, DepsLog* deps_log,
- DiskInterface* disk_interface)
- : state_(state), config_(config),
- plan_(this), disk_interface_(disk_interface),
+ DiskInterface* disk_interface, int64_t start_time_millis)
+ : state_(state), config_(config), plan_(this),
+ start_time_millis_(start_time_millis), disk_interface_(disk_interface),
scan_(state, build_log, deps_log, disk_interface,
&config_.depfile_parser_options) {
status_ = new BuildStatus(config);
@@ -904,7 +893,10 @@ bool Builder::StartEdge(Edge* edge, string* err) {
if (edge->is_phony())
return true;
- status_->BuildEdgeStarted(edge);
+ int64_t start_time_millis = GetTimeMillis() - start_time_millis_;
+ running_edges_.insert(make_pair(edge, start_time_millis));
+
+ status_->BuildEdgeStarted(edge, start_time_millis);
// Create directories necessary for outputs.
// XXX: this will block; do we care?
@@ -957,9 +949,14 @@ bool Builder::FinishCommand(CommandRunner::Result* result, string* err) {
}
}
- int start_time, end_time;
- status_->BuildEdgeFinished(edge, result->success(), result->output,
- &start_time, &end_time);
+ int64_t start_time_millis, end_time_millis;
+ RunningEdgeMap::iterator it = running_edges_.find(edge);
+ start_time_millis = it->second;
+ end_time_millis = GetTimeMillis() - start_time_millis_;
+ running_edges_.erase(it);
+
+ status_->BuildEdgeFinished(edge, end_time_millis, result->success(),
+ result->output);
// The rest of this function only applies to successful commands.
if (!result->success()) {
@@ -1028,8 +1025,8 @@ bool Builder::FinishCommand(CommandRunner::Result* result, string* err) {
disk_interface_->RemoveFile(rspfile);
if (scan_.build_log()) {
- if (!scan_.build_log()->RecordCommand(edge, start_time, end_time,
- output_mtime)) {
+ if (!scan_.build_log()->RecordCommand(edge, start_time_millis,
+ end_time_millis, output_mtime)) {
*err = string("Error writing to build log: ") + strerror(errno);
return false;
}
diff --git a/src/build.h b/src/build.h
index 0a68478..6935086 100644
--- a/src/build.h
+++ b/src/build.h
@@ -26,7 +26,6 @@
#include "graph.h" // XXX needed for DependencyScan; should rearrange.
#include "exit_status.h"
#include "line_printer.h"
-#include "metrics.h"
#include "util.h" // int64_t
struct BuildLog;
@@ -179,7 +178,7 @@ struct BuildConfig {
struct Builder {
Builder(State* state, const BuildConfig& config,
BuildLog* build_log, DepsLog* deps_log,
- DiskInterface* disk_interface);
+ DiskInterface* disk_interface, int64_t start_time_millis);
~Builder();
/// Clean up after interrupted commands by deleting output files.
@@ -227,6 +226,13 @@ struct Builder {
const std::string& deps_prefix,
std::vector<Node*>* deps_nodes, std::string* err);
+ /// Map of running edge to time the edge started running.
+ typedef std::map<const Edge*, int> RunningEdgeMap;
+ RunningEdgeMap running_edges_;
+
+ /// Time the build started.
+ int64_t start_time_millis_;
+
DiskInterface* disk_interface_;
DependencyScan scan_;
@@ -239,9 +245,9 @@ struct Builder {
struct BuildStatus {
explicit BuildStatus(const BuildConfig& config);
void PlanHasTotalEdges(int total);
- void BuildEdgeStarted(const Edge* edge);
- void BuildEdgeFinished(Edge* edge, bool success, const std::string& output,
- int* start_time, int* end_time);
+ void BuildEdgeStarted(const Edge* edge, int64_t start_time_millis);
+ void BuildEdgeFinished(Edge* edge, int64_t end_time_millis, bool success,
+ const std::string& output);
void BuildLoadDyndeps();
void BuildStarted();
void BuildFinished();
@@ -257,21 +263,15 @@ struct BuildStatus {
/// @param progress_status_format The format of the progress status.
/// @param status The status of the edge.
std::string FormatProgressStatus(const char* progress_status_format,
- EdgeStatus status) const;
+ int64_t time, EdgeStatus status) const;
private:
- void PrintStatus(const Edge* edge, EdgeStatus status);
+ void PrintStatus(const Edge* edge, int64_t time, EdgeStatus status);
const BuildConfig& config_;
- /// Time the build started.
- int64_t start_time_millis_;
-
int started_edges_, finished_edges_, total_edges_;
-
- /// Map of running edge to time the edge started running.
- typedef std::map<const Edge*, int> RunningEdgeMap;
- RunningEdgeMap running_edges_;
+ int64_t time_millis_;
/// Prints progress output.
LinePrinter printer_;
@@ -287,50 +287,30 @@ struct BuildStatus {
snprintf(buf, S, format, rate);
}
- struct RateInfo {
- RateInfo() : rate_(-1) {}
-
- void Restart() { stopwatch_.Restart(); }
- double Elapsed() const { return stopwatch_.Elapsed(); }
- double rate() { return rate_; }
-
- void UpdateRate(int edges) {
- if (edges && stopwatch_.Elapsed())
- rate_ = edges / stopwatch_.Elapsed();
- }
-
- private:
- double rate_;
- Stopwatch stopwatch_;
- };
-
struct SlidingRateInfo {
SlidingRateInfo(int n) : rate_(-1), N(n), last_update_(-1) {}
- void Restart() { stopwatch_.Restart(); }
double rate() { return rate_; }
- void UpdateRate(int update_hint) {
+ void UpdateRate(int update_hint, int64_t time_millis_) {
if (update_hint == last_update_)
return;
last_update_ = update_hint;
if (times_.size() == N)
times_.pop();
- times_.push(stopwatch_.Elapsed());
+ times_.push(time_millis_);
if (times_.back() != times_.front())
- rate_ = times_.size() / (times_.back() - times_.front());
+ rate_ = times_.size() / ((times_.back() - times_.front()) / 1e3);
}
private:
double rate_;
- Stopwatch stopwatch_;
const size_t N;
std::queue<double> times_;
int last_update_;
};
- mutable RateInfo overall_rate_;
mutable SlidingRateInfo current_rate_;
};
diff --git a/src/build_test.cc b/src/build_test.cc
index 0baabc4..4ccb2c4 100644
--- a/src/build_test.cc
+++ b/src/build_test.cc
@@ -486,13 +486,13 @@ struct FakeCommandRunner : public CommandRunner {
struct BuildTest : public StateTestWithBuiltinRules, public BuildLogUser {
BuildTest() : config_(MakeConfig()), command_runner_(&fs_),
- builder_(&state_, config_, NULL, NULL, &fs_),
+ builder_(&state_, config_, NULL, NULL, &fs_, 0),
status_(config_) {
}
explicit BuildTest(DepsLog* log)
: config_(MakeConfig()), command_runner_(&fs_),
- builder_(&state_, config_, NULL, log, &fs_), status_(config_) {}
+ builder_(&state_, config_, NULL, log, &fs_, 0), status_(config_) {}
virtual void SetUp() {
StateTestWithBuiltinRules::SetUp();
@@ -563,7 +563,7 @@ void BuildTest::RebuildTarget(const string& target, const char* manifest,
pdeps_log = &deps_log;
}
- Builder builder(pstate, config_, pbuild_log, pdeps_log, &fs_);
+ Builder builder(pstate, config_, pbuild_log, pdeps_log, &fs_, 0);
EXPECT_TRUE(builder.AddTarget(target, &err));
command_runner_.commands_ran_.clear();
@@ -1400,7 +1400,7 @@ TEST_F(BuildWithLogTest, RestatTest) {
ASSERT_EQ("", err);
EXPECT_TRUE(builder_.Build(&err));
ASSERT_EQ("", err);
- EXPECT_EQ("[3/3]", builder_.status_->FormatProgressStatus("[%s/%t]",
+ EXPECT_EQ("[3/3]", builder_.status_->FormatProgressStatus("[%s/%t]", 0,
BuildStatus::kEdgeStarted));
command_runner_.commands_ran_.clear();
state_.Reset();
@@ -1843,13 +1843,13 @@ TEST_F(BuildTest, StatusFormatElapsed) {
status_.BuildStarted();
// Before any task is done, the elapsed time must be zero.
EXPECT_EQ("[%/e0.000]",
- status_.FormatProgressStatus("[%%/e%e]",
+ status_.FormatProgressStatus("[%%/e%e]", 0,
BuildStatus::kEdgeStarted));
}
TEST_F(BuildTest, StatusFormatReplacePlaceholder) {
EXPECT_EQ("[%/s0/t0/r0/u0/f0]",
- status_.FormatProgressStatus("[%%/s%s/t%t/r%r/u%u/f%f]",
+ status_.FormatProgressStatus("[%%/s%s/t%t/r%r/u%u/f%f]", 0,
BuildStatus::kEdgeStarted));
}
@@ -2120,7 +2120,7 @@ TEST_F(BuildWithDepsLogTest, Straightforward) {
ASSERT_TRUE(deps_log.OpenForWrite("ninja_deps", &err));
ASSERT_EQ("", err);
- Builder builder(&state, config_, NULL, &deps_log, &fs_);
+ Builder builder(&state, config_, NULL, &deps_log, &fs_, 0);
builder.command_runner_.reset(&command_runner_);
EXPECT_TRUE(builder.AddTarget("out", &err));
ASSERT_EQ("", err);
@@ -2150,7 +2150,7 @@ TEST_F(BuildWithDepsLogTest, Straightforward) {
ASSERT_TRUE(deps_log.Load("ninja_deps", &state, &err));
ASSERT_TRUE(deps_log.OpenForWrite("ninja_deps", &err));
- Builder builder(&state, config_, NULL, &deps_log, &fs_);
+ Builder builder(&state, config_, NULL, &deps_log, &fs_, 0);
builder.command_runner_.reset(&command_runner_);
command_runner_.commands_ran_.clear();
EXPECT_TRUE(builder.AddTarget("out", &err));
@@ -2191,7 +2191,7 @@ TEST_F(BuildWithDepsLogTest, ObsoleteDeps) {
ASSERT_TRUE(deps_log.OpenForWrite("ninja_deps", &err));
ASSERT_EQ("", err);
- Builder builder(&state, config_, NULL, &deps_log, &fs_);
+ Builder builder(&state, config_, NULL, &deps_log, &fs_, 0);
builder.command_runner_.reset(&command_runner_);
EXPECT_TRUE(builder.AddTarget("out", &err));
ASSERT_EQ("", err);
@@ -2220,7 +2220,7 @@ TEST_F(BuildWithDepsLogTest, ObsoleteDeps) {
ASSERT_TRUE(deps_log.Load("ninja_deps", &state, &err));
ASSERT_TRUE(deps_log.OpenForWrite("ninja_deps", &err));
- Builder builder(&state, config_, NULL, &deps_log, &fs_);
+ Builder builder(&state, config_, NULL, &deps_log, &fs_, 0);
builder.command_runner_.reset(&command_runner_);
command_runner_.commands_ran_.clear();
EXPECT_TRUE(builder.AddTarget("out", &err));
@@ -2256,7 +2256,7 @@ TEST_F(BuildWithDepsLogTest, DepsIgnoredInDryRun) {
// The deps log is NULL in dry runs.
config_.dry_run = true;
- Builder builder(&state, config_, NULL, NULL, &fs_);
+ Builder builder(&state, config_, NULL, NULL, &fs_, 0);
builder.command_runner_.reset(&command_runner_);
command_runner_.commands_ran_.clear();
@@ -2314,7 +2314,7 @@ TEST_F(BuildWithDepsLogTest, RestatDepfileDependencyDepsLog) {
ASSERT_TRUE(deps_log.OpenForWrite("ninja_deps", &err));
ASSERT_EQ("", err);
- Builder builder(&state, config_, NULL, &deps_log, &fs_);
+ Builder builder(&state, config_, NULL, &deps_log, &fs_, 0);
builder.command_runner_.reset(&command_runner_);
EXPECT_TRUE(builder.AddTarget("out", &err));
ASSERT_EQ("", err);
@@ -2340,7 +2340,7 @@ TEST_F(BuildWithDepsLogTest, RestatDepfileDependencyDepsLog) {
ASSERT_TRUE(deps_log.Load("ninja_deps", &state, &err));
ASSERT_TRUE(deps_log.OpenForWrite("ninja_deps", &err));
- Builder builder(&state, config_, NULL, &deps_log, &fs_);
+ Builder builder(&state, config_, NULL, &deps_log, &fs_, 0);
builder.command_runner_.reset(&command_runner_);
command_runner_.commands_ran_.clear();
EXPECT_TRUE(builder.AddTarget("out", &err));
@@ -2373,7 +2373,7 @@ TEST_F(BuildWithDepsLogTest, DepFileOKDepsLog) {
ASSERT_TRUE(deps_log.OpenForWrite("ninja_deps", &err));
ASSERT_EQ("", err);
- Builder builder(&state, config_, NULL, &deps_log, &fs_);
+ Builder builder(&state, config_, NULL, &deps_log, &fs_, 0);
builder.command_runner_.reset(&command_runner_);
EXPECT_TRUE(builder.AddTarget("fo o.o", &err));
ASSERT_EQ("", err);
@@ -2394,7 +2394,7 @@ TEST_F(BuildWithDepsLogTest, DepFileOKDepsLog) {
ASSERT_TRUE(deps_log.OpenForWrite("ninja_deps", &err));
ASSERT_EQ("", err);
- Builder builder(&state, config_, NULL, &deps_log, &fs_);
+ Builder builder(&state, config_, NULL, &deps_log, &fs_, 0);
builder.command_runner_.reset(&command_runner_);
Edge* edge = state.edges_.back();
@@ -2435,7 +2435,7 @@ TEST_F(BuildWithDepsLogTest, DepFileDepsLogCanonicalize) {
ASSERT_TRUE(deps_log.OpenForWrite("ninja_deps", &err));
ASSERT_EQ("", err);
- Builder builder(&state, config_, NULL, &deps_log, &fs_);
+ Builder builder(&state, config_, NULL, &deps_log, &fs_, 0);
builder.command_runner_.reset(&command_runner_);
EXPECT_TRUE(builder.AddTarget("a/b/c/d/e/fo o.o", &err));
ASSERT_EQ("", err);
@@ -2458,7 +2458,7 @@ TEST_F(BuildWithDepsLogTest, DepFileDepsLogCanonicalize) {
ASSERT_TRUE(deps_log.OpenForWrite("ninja_deps", &err));
ASSERT_EQ("", err);
- Builder builder(&state, config_, NULL, &deps_log, &fs_);
+ Builder builder(&state, config_, NULL, &deps_log, &fs_, 0);
builder.command_runner_.reset(&command_runner_);
Edge* edge = state.edges_.back();
diff --git a/src/ninja.cc b/src/ninja.cc
index eb97320..57690be 100644
--- a/src/ninja.cc
+++ b/src/ninja.cc
@@ -82,7 +82,8 @@ struct Options {
/// to poke into these, so store them as fields on an object.
struct NinjaMain : public BuildLogUser {
NinjaMain(const char* ninja_command, const BuildConfig& config) :
- ninja_command_(ninja_command), config_(config) {}
+ ninja_command_(ninja_command), config_(config),
+ start_time_millis_(GetTimeMillis()) {}
/// Command line used to run Ninja.
const char* ninja_command_;
@@ -172,6 +173,8 @@ struct NinjaMain : public BuildLogUser {
Error("%s", err.c_str()); // Log and ignore Stat() errors.
return mtime == 0;
}
+
+ int64_t start_time_millis_;
};
/// Subtools, accessible via "-t foo".
@@ -249,7 +252,8 @@ bool NinjaMain::RebuildManifest(const char* input_file, string* err) {
if (!node)
return false;
- Builder builder(&state_, config_, &build_log_, &deps_log_, &disk_interface_);
+ Builder builder(&state_, config_, &build_log_, &deps_log_, &disk_interface_,
+ start_time_millis_);
if (!builder.AddTarget(node, err))
return false;
@@ -1199,7 +1203,8 @@ int NinjaMain::RunBuild(int argc, char** argv) {
disk_interface_.AllowStatCache(g_experimental_statcache);
- Builder builder(&state_, config_, &build_log_, &deps_log_, &disk_interface_);
+ Builder builder(&state_, config_, &build_log_, &deps_log_, &disk_interface_,
+ start_time_millis_);
for (size_t i = 0; i < targets.size(); ++i) {
if (!builder.AddTarget(targets[i], &err)) {
if (!err.empty()) {
generated by cgit v0.12 at 2024-09-17 23:57:41 (GMT)