src/build.cc

   1 // Copyright 2011 Google Inc. All Rights Reserved.
   2 //
   3 // Licensed under the Apache License, Version 2.0 (the "License");
   4 // you may not use this file except in compliance with the License.
   5 // You may obtain a copy of the License at
   6 //
   7 //     http://www.apache.org/licenses/LICENSE-2.0
   8 //
   9 // Unless required by applicable law or agreed to in writing, software
  10 // distributed under the License is distributed on an "AS IS" BASIS,
  11 // WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
  12 // See the License for the specific language governing permissions and
  13 // limitations under the License.
  14
  15 #include "build.h"
  16
  17 #include <assert.h>
  18 #include <errno.h>
  19 #include <stdio.h>
  20 #include <stdlib.h>
  21 #include <functional>
  22
  23 #ifdef _WIN32
  24 #include <fcntl.h>
  25 #include <io.h>
  26 #endif
  27
  28 #if defined(__SVR4) && defined(__sun)
  29 #include <sys/termios.h>
  30 #endif
  31
  32 #include "build_log.h"
  33 #include "clparser.h"
  34 #include "debug_flags.h"
  35 #include "depfile_parser.h"
  36 #include "deps_log.h"
  37 #include "disk_interface.h"
  38 #include "graph.h"
  39 #include "state.h"
  40 #include "subprocess.h"
  41 #include "util.h"
  42
  43 namespace {
  44
  45 /// A CommandRunner that doesn't actually run the commands.
  46 struct DryRunCommandRunner : public CommandRunner {
  47   virtual ~DryRunCommandRunner() {}
  48
  49   // Overridden from CommandRunner:
  50   virtual bool CanRunMore() const;
  51   virtual bool StartCommand(Edge* edge);
  52   virtual bool WaitForCommand(Result* result);
  53
  54  private:
  55   queue<Edge*> finished_;
  56 };
  57
  58 bool DryRunCommandRunner::CanRunMore() const {
  59   return true;
  60 }
  61
  62 bool DryRunCommandRunner::StartCommand(Edge* edge) {
  63   finished_.push(edge);
  64   return true;
  65 }
  66
  67 bool DryRunCommandRunner::WaitForCommand(Result* result) {
  68    if (finished_.empty())
  69      return false;
  70
  71    result->status = ExitSuccess;
  72    result->edge = finished_.front();
  73    finished_.pop();
  74    return true;
  75 }
  76
  77 }  // namespace
  78
  79 BuildStatus::BuildStatus(const BuildConfig& config)
  80     : config_(config),
  81       start_time_millis_(GetTimeMillis()),
  82       started_edges_(0), finished_edges_(0), total_edges_(0),
  83       progress_status_format_(NULL),
  84       overall_rate_(), current_rate_(config.parallelism) {
  85
  86   // Don't do anything fancy in verbose mode.
  87   if (config_.verbosity != BuildConfig::NORMAL)
  88     printer_.set_smart_terminal(false);
  89
  90   progress_status_format_ = getenv("NINJA_STATUS");
  91   if (!progress_status_format_)
  92     progress_status_format_ = "[%f/%t] ";
  93 }
  94
  95 void BuildStatus::PlanHasTotalEdges(int total) {
  96   total_edges_ = total;
  97 }
  98
  99 void BuildStatus::BuildEdgeStarted(const Edge* edge) {
 100   assert(running_edges_.find(edge) == running_edges_.end());
 101   int start_time = (int)(GetTimeMillis() - start_time_millis_);
 102   running_edges_.insert(make_pair(edge, start_time));
 103   ++started_edges_;
 104
 105   if (edge->use_console() || printer_.is_smart_terminal())
 106     PrintStatus(edge, kEdgeStarted);
 107
 108   if (edge->use_console())
 109     printer_.SetConsoleLocked(true);
 110 }
 111
 112 void BuildStatus::BuildEdgeFinished(Edge* edge,
 113                                     bool success,
 114                                     const string& output,
 115                                     int* start_time,
 116                                     int* end_time) {
 117   int64_t now = GetTimeMillis();
 118
 119   ++finished_edges_;
 120
 121   RunningEdgeMap::iterator i = running_edges_.find(edge);
 122   *start_time = i->second;
 123   *end_time = (int)(now - start_time_millis_);
 124   running_edges_.erase(i);
 125
 126   if (edge->use_console())
 127     printer_.SetConsoleLocked(false);
 128
 129   if (config_.verbosity == BuildConfig::QUIET)
 130     return;
 131
 132   if (!edge->use_console())
 133     PrintStatus(edge, kEdgeFinished);
 134
 135   // Print the command that is spewing before printing its output.
 136   if (!success) {
 137     string outputs;
 138     for (vector<Node*>::const_iterator o = edge->outputs_.begin();
 139          o != edge->outputs_.end(); ++o)
 140       outputs += (*o)->path() + " ";
 141
 142     if (printer_.supports_color()) {
 143         printer_.PrintOnNewLine("\x1B[31m" "FAILED: " "\x1B[0m" + outputs + "\n");
 144     } else {
 145         printer_.PrintOnNewLine("FAILED: " + outputs + "\n");
 146     }
 147     printer_.PrintOnNewLine(edge->EvaluateCommand() + "\n");
 148   }
 149
 150   if (!output.empty()) {
 151     // ninja sets stdout and stderr of subprocesses to a pipe, to be able to
 152     // check if the output is empty. Some compilers, e.g. clang, check
 153     // isatty(stderr) to decide if they should print colored output.
 154     // To make it possible to use colored output with ninja, subprocesses should
 155     // be run with a flag that forces them to always print color escape codes.
 156     // To make sure these escape codes don't show up in a file if ninja's output
 157     // is piped to a file, ninja strips ansi escape codes again if it's not
 158     // writing to a |smart_terminal_|.
 159     // (Launching subprocesses in pseudo ttys doesn't work because there are
 160     // only a few hundred available on some systems, and ninja can launch
 161     // thousands of parallel compile commands.)
 162     string final_output;
 163     if (!printer_.supports_color())
 164       final_output = StripAnsiEscapeCodes(output);
 165     else
 166       final_output = output;
 167
 168 #ifdef _WIN32
 169     // Fix extra CR being added on Windows, writing out CR CR LF (#773)
 170     _setmode(_fileno(stdout), _O_BINARY);  // Begin Windows extra CR fix
 171 #endif
 172
 173     printer_.PrintOnNewLine(final_output);
 174
 175 #ifdef _WIN32
 176     _setmode(_fileno(stdout), _O_TEXT);  // End Windows extra CR fix
 177 #endif
 178   }
 179 }
 180
 181 void BuildStatus::BuildLoadDyndeps() {
 182   // The DependencyScan calls EXPLAIN() to print lines explaining why
 183   // it considers a portion of the graph to be out of date.  Normally
 184   // this is done before the build starts, but our caller is about to
 185   // load a dyndep file during the build.  Doing so may generate more
 186   // explanation lines (via fprintf directly to stderr), but in an
 187   // interactive console the cursor is currently at the end of a status
 188   // line.  Start a new line so that the first explanation does not
 189   // append to the status line.  After the explanations are done a
 190   // new build status line will appear.
 191   if (g_explaining)
 192     printer_.PrintOnNewLine("");
 193 }
 194
 195 void BuildStatus::BuildStarted() {
 196   overall_rate_.Restart();
 197   current_rate_.Restart();
 198 }
 199
 200 void BuildStatus::BuildFinished() {
 201   printer_.SetConsoleLocked(false);
 202   printer_.PrintOnNewLine("");
 203 }
 204
 205 string BuildStatus::FormatProgressStatus(
 206     const char* progress_status_format, EdgeStatus status) const {
 207   string out;
 208   char buf[32];
 209   int percent;
 210   for (const char* s = progress_status_format; *s != '\0'; ++s) {
 211     if (*s == '%') {
 212       ++s;
 213       switch (*s) {
 214       case '%':
 215         out.push_back('%');
 216         break;
 217
 218         // Started edges.
 219       case 's':
 220         snprintf(buf, sizeof(buf), "%d", started_edges_);
 221         out += buf;
 222         break;
 223
 224         // Total edges.
 225       case 't':
 226         snprintf(buf, sizeof(buf), "%d", total_edges_);
 227         out += buf;
 228         break;
 229
 230         // Running edges.
 231       case 'r': {
 232         int running_edges = started_edges_ - finished_edges_;
 233         // count the edge that just finished as a running edge
 234         if (status == kEdgeFinished)
 235           running_edges++;
 236         snprintf(buf, sizeof(buf), "%d", running_edges);
 237         out += buf;
 238         break;
 239       }
 240
 241         // Unstarted edges.
 242       case 'u':
 243         snprintf(buf, sizeof(buf), "%d", total_edges_ - started_edges_);
 244         out += buf;
 245         break;
 246
 247         // Finished edges.
 248       case 'f':
 249         snprintf(buf, sizeof(buf), "%d", finished_edges_);
 250         out += buf;
 251         break;
 252
 253         // Overall finished edges per second.
 254       case 'o':
 255         overall_rate_.UpdateRate(finished_edges_);
 256         SnprintfRate(overall_rate_.rate(), buf, "%.1f");
 257         out += buf;
 258         break;
 259
 260         // Current rate, average over the last '-j' jobs.
 261       case 'c':
 262         current_rate_.UpdateRate(finished_edges_);
 263         SnprintfRate(current_rate_.rate(), buf, "%.1f");
 264         out += buf;
 265         break;
 266
 267         // Percentage
 268       case 'p':
 269         percent = (100 * finished_edges_) / total_edges_;
 270         snprintf(buf, sizeof(buf), "%3i%%", percent);
 271         out += buf;
 272         break;
 273
 274       case 'e': {
 275         double elapsed = overall_rate_.Elapsed();
 276         snprintf(buf, sizeof(buf), "%.3f", elapsed);
 277         out += buf;
 278         break;
 279       }
 280
 281       default:
 282         Fatal("unknown placeholder '%%%c' in $NINJA_STATUS", *s);
 283         return "";
 284       }
 285     } else {
 286       out.push_back(*s);
 287     }
 288   }
 289
 290   return out;
 291 }
 292
 293 void BuildStatus::PrintStatus(const Edge* edge, EdgeStatus status) {
 294   if (config_.verbosity == BuildConfig::QUIET)
 295     return;
 296
 297   bool force_full_command = config_.verbosity == BuildConfig::VERBOSE;
 298
 299   string to_print = edge->GetBinding("description");
 300   if (to_print.empty() || force_full_command)
 301     to_print = edge->GetBinding("command");
 302
 303   to_print = FormatProgressStatus(progress_status_format_, status) + to_print;
 304
 305   printer_.Print(to_print,
 306                  force_full_command ? LinePrinter::FULL : LinePrinter::ELIDE);
 307 }
 308
 309 Plan::Plan(Builder* builder)
 310   : builder_(builder)
 311   , command_edges_(0)
 312   , wanted_edges_(0)
 313 {}
 314
 315 void Plan::Reset() {
 316   command_edges_ = 0;
 317   wanted_edges_ = 0;
 318   ready_.clear();
 319   want_.clear();
 320 }
 321
 322 bool Plan::AddTarget(const Node* node, string* err) {
 323   return AddSubTarget(node, NULL, err, NULL);
 324 }
 325
 326 bool Plan::AddSubTarget(const Node* node, const Node* dependent, string* err,
 327                         set<Edge*>* dyndep_walk) {
 328   Edge* edge = node->in_edge();
 329   if (!edge) {  // Leaf node.
 330     if (node->dirty()) {
 331       string referenced;
 332       if (dependent)
 333         referenced = ", needed by '" + dependent->path() + "',";
 334       *err = "'" + node->path() + "'" + referenced + " missing "
 335              "and no known rule to make it";
 336     }
 337     return false;
 338   }
 339
 340   if (edge->outputs_ready())
 341     return false;  // Don't need to do anything.
 342
 343   // If an entry in want_ does not already exist for edge, create an entry which
 344   // maps to kWantNothing, indicating that we do not want to build this entry itself.
 345   pair<map<Edge*, Want>::iterator, bool> want_ins =
 346     want_.insert(make_pair(edge, kWantNothing));
 347   Want& want = want_ins.first->second;
 348
 349   if (dyndep_walk && want == kWantToFinish)
 350     return false;  // Don't need to do anything with already-scheduled edge.
 351
 352   // If we do need to build edge and we haven't already marked it as wanted,
 353   // mark it now.
 354   if (node->dirty() && want == kWantNothing) {
 355     want = kWantToStart;
 356     EdgeWanted(edge);
 357     if (!dyndep_walk && edge->AllInputsReady())
 358       ScheduleWork(want_ins.first);
 359   }
 360
 361   if (dyndep_walk)
 362     dyndep_walk->insert(edge);
 363
 364   if (!want_ins.second)
 365     return true;  // We've already processed the inputs.
 366
 367   for (vector<Node*>::iterator i = edge->inputs_.begin();
 368        i != edge->inputs_.end(); ++i) {
 369     if (!AddSubTarget(*i, node, err, dyndep_walk) && !err->empty())
 370       return false;
 371   }
 372
 373   return true;
 374 }
 375
 376 void Plan::EdgeWanted(const Edge* edge) {
 377   ++wanted_edges_;
 378   if (!edge->is_phony())
 379     ++command_edges_;
 380 }
 381
 382 Edge* Plan::FindWork() {
 383   if (ready_.empty())
 384     return NULL;
 385   set<Edge*>::iterator e = ready_.begin();
 386   Edge* edge = *e;
 387   ready_.erase(e);
 388   return edge;
 389 }
 390
 391 void Plan::ScheduleWork(map<Edge*, Want>::iterator want_e) {
 392   if (want_e->second == kWantToFinish) {
 393     // This edge has already been scheduled.  We can get here again if an edge
 394     // and one of its dependencies share an order-only input, or if a node
 395     // duplicates an out edge (see https://github.com/ninja-build/ninja/pull/519).
 396     // Avoid scheduling the work again.
 397     return;
 398   }
 399   assert(want_e->second == kWantToStart);
 400   want_e->second = kWantToFinish;
 401
 402   Edge* edge = want_e->first;
 403   Pool* pool = edge->pool();
 404   if (pool->ShouldDelayEdge()) {
 405     pool->DelayEdge(edge);
 406     pool->RetrieveReadyEdges(&ready_);
 407   } else {
 408     pool->EdgeScheduled(*edge);
 409     ready_.insert(edge);
 410   }
 411 }
 412
 413 bool Plan::EdgeFinished(Edge* edge, EdgeResult result, string* err) {
 414   map<Edge*, Want>::iterator e = want_.find(edge);
 415   assert(e != want_.end());
 416   bool directly_wanted = e->second != kWantNothing;
 417
 418   // See if this job frees up any delayed jobs.
 419   if (directly_wanted)
 420     edge->pool()->EdgeFinished(*edge);
 421   edge->pool()->RetrieveReadyEdges(&ready_);
 422
 423   // The rest of this function only applies to successful commands.
 424   if (result != kEdgeSucceeded)
 425     return true;
 426
 427   if (directly_wanted)
 428     --wanted_edges_;
 429   want_.erase(e);
 430   edge->outputs_ready_ = true;
 431
 432   // Check off any nodes we were waiting for with this edge.
 433   for (vector<Node*>::iterator o = edge->outputs_.begin();
 434        o != edge->outputs_.end(); ++o) {
 435     if (!NodeFinished(*o, err))
 436       return false;
 437   }
 438   return true;
 439 }
 440
 441 bool Plan::NodeFinished(Node* node, string* err) {
 442   // If this node provides dyndep info, load it now.
 443   if (node->dyndep_pending()) {
 444     assert(builder_ && "dyndep requires Plan to have a Builder");
 445     // Load the now-clean dyndep file.  This will also update the
 446     // build plan and schedule any new work that is ready.
 447     return builder_->LoadDyndeps(node, err);
 448   }
 449
 450   // See if we we want any edges from this node.
 451   for (vector<Edge*>::const_iterator oe = node->out_edges().begin();
 452        oe != node->out_edges().end(); ++oe) {
 453     map<Edge*, Want>::iterator want_e = want_.find(*oe);
 454     if (want_e == want_.end())
 455       continue;
 456
 457     // See if the edge is now ready.
 458     if (!EdgeMaybeReady(want_e, err))
 459       return false;
 460   }
 461   return true;
 462 }
 463
 464 bool Plan::EdgeMaybeReady(map<Edge*, Want>::iterator want_e, string* err) {
 465   Edge* edge = want_e->first;
 466   if (edge->AllInputsReady()) {
 467     if (want_e->second != kWantNothing) {
 468       ScheduleWork(want_e);
 469     } else {
 470       // We do not need to build this edge, but we might need to build one of
 471       // its dependents.
 472       if (!EdgeFinished(edge, kEdgeSucceeded, err))
 473         return false;
 474     }
 475   }
 476   return true;
 477 }
 478
 479 bool Plan::CleanNode(DependencyScan* scan, Node* node, string* err) {
 480   node->set_dirty(false);
 481
 482   for (vector<Edge*>::const_iterator oe = node->out_edges().begin();
 483        oe != node->out_edges().end(); ++oe) {
 484     // Don't process edges that we don't actually want.
 485     map<Edge*, Want>::iterator want_e = want_.find(*oe);
 486     if (want_e == want_.end() || want_e->second == kWantNothing)
 487       continue;
 488
 489     // Don't attempt to clean an edge if it failed to load deps.
 490     if ((*oe)->deps_missing_)
 491       continue;
 492
 493     // If all non-order-only inputs for this edge are now clean,
 494     // we might have changed the dirty state of the outputs.
 495     vector<Node*>::iterator
 496         begin = (*oe)->inputs_.begin(),
 497         end = (*oe)->inputs_.end() - (*oe)->order_only_deps_;
 498 #if __cplusplus < 201703L
 499 #define MEM_FN mem_fun
 500 #else
 501 #define MEM_FN mem_fn  // mem_fun was removed in C++17.
 502 #endif
 503     if (find_if(begin, end, MEM_FN(&Node::dirty)) == end) {
 504       // Recompute most_recent_input.
 505       Node* most_recent_input = NULL;
 506       for (vector<Node*>::iterator i = begin; i != end; ++i) {
 507         if (!most_recent_input || (*i)->mtime() > most_recent_input->mtime())
 508           most_recent_input = *i;
 509       }
 510
 511       // Now, this edge is dirty if any of the outputs are dirty.
 512       // If the edge isn't dirty, clean the outputs and mark the edge as not
 513       // wanted.
 514       bool outputs_dirty = false;
 515       if (!scan->RecomputeOutputsDirty(*oe, most_recent_input,
 516                                        &outputs_dirty, err)) {
 517         return false;
 518       }
 519       if (!outputs_dirty) {
 520         for (vector<Node*>::iterator o = (*oe)->outputs_.begin();
 521              o != (*oe)->outputs_.end(); ++o) {
 522           if (!CleanNode(scan, *o, err))
 523             return false;
 524         }
 525
 526         want_e->second = kWantNothing;
 527         --wanted_edges_;
 528         if (!(*oe)->is_phony())
 529           --command_edges_;
 530       }
 531     }
 532   }
 533   return true;
 534 }
 535
 536 bool Plan::DyndepsLoaded(DependencyScan* scan, const Node* node,
 537                          const DyndepFile& ddf, string* err) {
 538   // Recompute the dirty state of all our direct and indirect dependents now
 539   // that our dyndep information has been loaded.
 540   if (!RefreshDyndepDependents(scan, node, err))
 541     return false;
 542
 543   // We loaded dyndep information for those out_edges of the dyndep node that
 544   // specify the node in a dyndep binding, but they may not be in the plan.
 545   // Starting with those already in the plan, walk newly-reachable portion
 546   // of the graph through the dyndep-discovered dependencies.
 547
 548   // Find edges in the the build plan for which we have new dyndep info.
 549   std::vector<DyndepFile::const_iterator> dyndep_roots;
 550   for (DyndepFile::const_iterator oe = ddf.begin(); oe != ddf.end(); ++oe) {
 551     Edge* edge = oe->first;
 552
 553     // If the edge outputs are ready we do not need to consider it here.
 554     if (edge->outputs_ready())
 555       continue;
 556
 557     map<Edge*, Want>::iterator want_e = want_.find(edge);
 558
 559     // If the edge has not been encountered before then nothing already in the
 560     // plan depends on it so we do not need to consider the edge yet either.
 561     if (want_e == want_.end())
 562       continue;
 563
 564     // This edge is already in the plan so queue it for the walk.
 565     dyndep_roots.push_back(oe);
 566   }
 567
 568   // Walk dyndep-discovered portion of the graph to add it to the build plan.
 569   std::set<Edge*> dyndep_walk;
 570   for (std::vector<DyndepFile::const_iterator>::iterator
 571        oei = dyndep_roots.begin(); oei != dyndep_roots.end(); ++oei) {
 572     DyndepFile::const_iterator oe = *oei;
 573     for (vector<Node*>::const_iterator i = oe->second.implicit_inputs_.begin();
 574          i != oe->second.implicit_inputs_.end(); ++i) {
 575       if (!AddSubTarget(*i, oe->first->outputs_[0], err, &dyndep_walk) &&
 576           !err->empty())
 577         return false;
 578     }
 579   }
 580
 581   // Add out edges from this node that are in the plan (just as
 582   // Plan::NodeFinished would have without taking the dyndep code path).
 583   for (vector<Edge*>::const_iterator oe = node->out_edges().begin();
 584        oe != node->out_edges().end(); ++oe) {
 585     map<Edge*, Want>::iterator want_e = want_.find(*oe);
 586     if (want_e == want_.end())
 587       continue;
 588     dyndep_walk.insert(want_e->first);
 589   }
 590
 591   // See if any encountered edges are now ready.
 592   for (set<Edge*>::iterator wi = dyndep_walk.begin();
 593        wi != dyndep_walk.end(); ++wi) {
 594     map<Edge*, Want>::iterator want_e = want_.find(*wi);
 595     if (want_e == want_.end())
 596       continue;
 597     if (!EdgeMaybeReady(want_e, err))
 598       return false;
 599   }
 600
 601   return true;
 602 }
 603
 604 bool Plan::RefreshDyndepDependents(DependencyScan* scan, const Node* node,
 605                                    string* err) {
 606   // Collect the transitive closure of dependents and mark their edges
 607   // as not yet visited by RecomputeDirty.
 608   set<Node*> dependents;
 609   UnmarkDependents(node, &dependents);
 610
 611   // Update the dirty state of all dependents and check if their edges
 612   // have become wanted.
 613   for (set<Node*>::iterator i = dependents.begin();
 614        i != dependents.end(); ++i) {
 615     Node* n = *i;
 616
 617     // Check if this dependent node is now dirty.  Also checks for new cycles.
 618     if (!scan->RecomputeDirty(n, err))
 619       return false;
 620     if (!n->dirty())
 621       continue;
 622
 623     // This edge was encountered before.  However, we may not have wanted to
 624     // build it if the outputs were not known to be dirty.  With dyndep
 625     // information an output is now known to be dirty, so we want the edge.
 626     Edge* edge = n->in_edge();
 627     assert(edge && !edge->outputs_ready());
 628     map<Edge*, Want>::iterator want_e = want_.find(edge);
 629     assert(want_e != want_.end());
 630     if (want_e->second == kWantNothing) {
 631       want_e->second = kWantToStart;
 632       EdgeWanted(edge);
 633     }
 634   }
 635   return true;
 636 }
 637
 638 void Plan::UnmarkDependents(const Node* node, set<Node*>* dependents) {
 639   for (vector<Edge*>::const_iterator oe = node->out_edges().begin();
 640        oe != node->out_edges().end(); ++oe) {
 641     Edge* edge = *oe;
 642
 643     map<Edge*, Want>::iterator want_e = want_.find(edge);
 644     if (want_e == want_.end())
 645       continue;
 646
 647     if (edge->mark_ != Edge::VisitNone) {
 648       edge->mark_ = Edge::VisitNone;
 649       for (vector<Node*>::iterator o = edge->outputs_.begin();
 650            o != edge->outputs_.end(); ++o) {
 651         if (dependents->insert(*o).second)
 652           UnmarkDependents(*o, dependents);
 653       }
 654     }
 655   }
 656 }
 657
 658 void Plan::Dump() const {
 659   printf("pending: %d\n", (int)want_.size());
 660   for (map<Edge*, Want>::const_iterator e = want_.begin(); e != want_.end(); ++e) {
 661     if (e->second != kWantNothing)
 662       printf("want ");
 663     e->first->Dump();
 664   }
 665   printf("ready: %d\n", (int)ready_.size());
 666 }
 667
 668 struct RealCommandRunner : public CommandRunner {
 669   explicit RealCommandRunner(const BuildConfig& config) : config_(config) {}
 670   virtual ~RealCommandRunner() {}
 671   virtual bool CanRunMore() const;
 672   virtual bool StartCommand(Edge* edge);
 673   virtual bool WaitForCommand(Result* result);
 674   virtual vector<Edge*> GetActiveEdges();
 675   virtual void Abort();
 676
 677   const BuildConfig& config_;
 678   SubprocessSet subprocs_;
 679   map<const Subprocess*, Edge*> subproc_to_edge_;
 680 };
 681
 682 vector<Edge*> RealCommandRunner::GetActiveEdges() {
 683   vector<Edge*> edges;
 684   for (map<const Subprocess*, Edge*>::iterator e = subproc_to_edge_.begin();
 685        e != subproc_to_edge_.end(); ++e)
 686     edges.push_back(e->second);
 687   return edges;
 688 }
 689
 690 void RealCommandRunner::Abort() {
 691   subprocs_.Clear();
 692 }
 693
 694 bool RealCommandRunner::CanRunMore() const {
 695   size_t subproc_number =
 696       subprocs_.running_.size() + subprocs_.finished_.size();
 697   return (int)subproc_number < config_.parallelism
 698     && ((subprocs_.running_.empty() || config_.max_load_average <= 0.0f)
 699         || GetLoadAverage() < config_.max_load_average);
 700 }
 701
 702 bool RealCommandRunner::StartCommand(Edge* edge) {
 703   string command = edge->EvaluateCommand();
 704   Subprocess* subproc = subprocs_.Add(command, edge->use_console());
 705   if (!subproc)
 706     return false;
 707   subproc_to_edge_.insert(make_pair(subproc, edge));
 708
 709   return true;
 710 }
 711
 712 bool RealCommandRunner::WaitForCommand(Result* result) {
 713   Subprocess* subproc;
 714   while ((subproc = subprocs_.NextFinished()) == NULL) {
 715     bool interrupted = subprocs_.DoWork();
 716     if (interrupted)
 717       return false;
 718   }
 719
 720   result->status = subproc->Finish();
 721   result->output = subproc->GetOutput();
 722
 723   map<const Subprocess*, Edge*>::iterator e = subproc_to_edge_.find(subproc);
 724   result->edge = e->second;
 725   subproc_to_edge_.erase(e);
 726
 727   delete subproc;
 728   return true;
 729 }
 730
 731 Builder::Builder(State* state, const BuildConfig& config,
 732                  BuildLog* build_log, DepsLog* deps_log,
 733                  DiskInterface* disk_interface)
 734     : state_(state), config_(config),
 735       plan_(this), disk_interface_(disk_interface),
 736       scan_(state, build_log, deps_log, disk_interface,
 737             &config_.depfile_parser_options) {
 738   status_ = new BuildStatus(config);
 739 }
 740
 741 Builder::~Builder() {
 742   Cleanup();
 743 }
 744
 745 void Builder::Cleanup() {
 746   if (command_runner_.get()) {
 747     vector<Edge*> active_edges = command_runner_->GetActiveEdges();
 748     command_runner_->Abort();
 749
 750     for (vector<Edge*>::iterator e = active_edges.begin();
 751          e != active_edges.end(); ++e) {
 752       string depfile = (*e)->GetUnescapedDepfile();
 753       for (vector<Node*>::iterator o = (*e)->outputs_.begin();
 754            o != (*e)->outputs_.end(); ++o) {
 755         // Only delete this output if it was actually modified.  This is
 756         // important for things like the generator where we don't want to
 757         // delete the manifest file if we can avoid it.  But if the rule
 758         // uses a depfile, always delete.  (Consider the case where we
 759         // need to rebuild an output because of a modified header file
 760         // mentioned in a depfile, and the command touches its depfile
 761         // but is interrupted before it touches its output file.)
 762         string err;
 763         TimeStamp new_mtime = disk_interface_->Stat((*o)->path(), &err);
 764         if (new_mtime == -1)  // Log and ignore Stat() errors.
 765           Error("%s", err.c_str());
 766         if (!depfile.empty() || (*o)->mtime() != new_mtime)
 767           disk_interface_->RemoveFile((*o)->path());
 768       }
 769       if (!depfile.empty())
 770         disk_interface_->RemoveFile(depfile);
 771     }
 772   }
 773 }
 774
 775 Node* Builder::AddTarget(const string& name, string* err) {
 776   Node* node = state_->LookupNode(name);
 777   if (!node) {
 778     *err = "unknown target: '" + name + "'";
 779     return NULL;
 780   }
 781   if (!AddTarget(node, err))
 782     return NULL;
 783   return node;
 784 }
 785
 786 bool Builder::AddTarget(Node* node, string* err) {
 787   if (!scan_.RecomputeDirty(node, err))
 788     return false;
 789
 790   if (Edge* in_edge = node->in_edge()) {
 791     if (in_edge->outputs_ready())
 792       return true;  // Nothing to do.
 793   }
 794
 795   if (!plan_.AddTarget(node, err))
 796     return false;
 797
 798   return true;
 799 }
 800
 801 bool Builder::AlreadyUpToDate() const {
 802   return !plan_.more_to_do();
 803 }
 804
 805 bool Builder::Build(string* err) {
 806   assert(!AlreadyUpToDate());
 807
 808   status_->PlanHasTotalEdges(plan_.command_edge_count());
 809   int pending_commands = 0;
 810   int failures_allowed = config_.failures_allowed;
 811
 812   // Set up the command runner if we haven't done so already.
 813   if (!command_runner_.get()) {
 814     if (config_.dry_run)
 815       command_runner_.reset(new DryRunCommandRunner);
 816     else
 817       command_runner_.reset(new RealCommandRunner(config_));
 818   }
 819
 820   // We are about to start the build process.
 821   status_->BuildStarted();
 822
 823   // This main loop runs the entire build process.
 824   // It is structured like this:
 825   // First, we attempt to start as many commands as allowed by the
 826   // command runner.
 827   // Second, we attempt to wait for / reap the next finished command.
 828   while (plan_.more_to_do()) {
 829     // See if we can start any more commands.
 830     if (failures_allowed && command_runner_->CanRunMore()) {
 831       if (Edge* edge = plan_.FindWork()) {
 832         if (!StartEdge(edge, err)) {
 833           Cleanup();
 834           status_->BuildFinished();
 835           return false;
 836         }
 837
 838         if (edge->is_phony()) {
 839           if (!plan_.EdgeFinished(edge, Plan::kEdgeSucceeded, err)) {
 840             Cleanup();
 841             status_->BuildFinished();
 842             return false;
 843           }
 844         } else {
 845           ++pending_commands;
 846         }
 847
 848         // We made some progress; go back to the main loop.
 849         continue;
 850       }
 851     }
 852
 853     // See if we can reap any finished commands.
 854     if (pending_commands) {
 855       CommandRunner::Result result;
 856       if (!command_runner_->WaitForCommand(&result) ||
 857           result.status == ExitInterrupted) {
 858         Cleanup();
 859         status_->BuildFinished();
 860         *err = "interrupted by user";
 861         return false;
 862       }
 863
 864       --pending_commands;
 865       if (!FinishCommand(&result, err)) {
 866         Cleanup();
 867         status_->BuildFinished();
 868         return false;
 869       }
 870
 871       if (!result.success()) {
 872         if (failures_allowed)
 873           failures_allowed--;
 874       }
 875
 876       // We made some progress; start the main loop over.
 877       continue;
 878     }
 879
 880     // If we get here, we cannot make any more progress.
 881     status_->BuildFinished();
 882     if (failures_allowed == 0) {
 883       if (config_.failures_allowed > 1)
 884         *err = "subcommands failed";
 885       else
 886         *err = "subcommand failed";
 887     } else if (failures_allowed < config_.failures_allowed)
 888       *err = "cannot make progress due to previous errors";
 889     else
 890       *err = "stuck [this is a bug]";
 891
 892     return false;
 893   }
 894
 895   status_->BuildFinished();
 896   return true;
 897 }
 898
 899 bool Builder::StartEdge(Edge* edge, string* err) {
 900   METRIC_RECORD("StartEdge");
 901   if (edge->is_phony())
 902     return true;
 903
 904   status_->BuildEdgeStarted(edge);
 905
 906   // Create directories necessary for outputs.
 907   // XXX: this will block; do we care?
 908   for (vector<Node*>::iterator o = edge->outputs_.begin();
 909        o != edge->outputs_.end(); ++o) {
 910     if (!disk_interface_->MakeDirs((*o)->path()))
 911       return false;
 912   }
 913
 914   // Create response file, if needed
 915   // XXX: this may also block; do we care?
 916   string rspfile = edge->GetUnescapedRspfile();
 917   if (!rspfile.empty()) {
 918     string content = edge->GetBinding("rspfile_content");
 919     if (!disk_interface_->WriteFile(rspfile, content))
 920       return false;
 921   }
 922
 923   // start command computing and run it
 924   if (!command_runner_->StartCommand(edge)) {
 925     err->assign("command '" + edge->EvaluateCommand() + "' failed.");
 926     return false;
 927   }
 928
 929   return true;
 930 }
 931
 932 bool Builder::FinishCommand(CommandRunner::Result* result, string* err) {
 933   METRIC_RECORD("FinishCommand");
 934
 935   Edge* edge = result->edge;
 936
 937   // First try to extract dependencies from the result, if any.
 938   // This must happen first as it filters the command output (we want
 939   // to filter /showIncludes output, even on compile failure) and
 940   // extraction itself can fail, which makes the command fail from a
 941   // build perspective.
 942   vector<Node*> deps_nodes;
 943   string deps_type = edge->GetBinding("deps");
 944   const string deps_prefix = edge->GetBinding("msvc_deps_prefix");
 945   if (!deps_type.empty()) {
 946     string extract_err;
 947     if (!ExtractDeps(result, deps_type, deps_prefix, &deps_nodes,
 948                      &extract_err) &&
 949         result->success()) {
 950       if (!result->output.empty())
 951         result->output.append("\n");
 952       result->output.append(extract_err);
 953       result->status = ExitFailure;
 954     }
 955   }
 956
 957   int start_time, end_time;
 958   status_->BuildEdgeFinished(edge, result->success(), result->output,
 959                              &start_time, &end_time);
 960
 961   // The rest of this function only applies to successful commands.
 962   if (!result->success()) {
 963     return plan_.EdgeFinished(edge, Plan::kEdgeFailed, err);
 964   }
 965
 966   // Restat the edge outputs
 967   TimeStamp output_mtime = 0;
 968   bool restat = edge->GetBindingBool("restat");
 969   if (!config_.dry_run) {
 970     bool node_cleaned = false;
 971
 972     for (vector<Node*>::iterator o = edge->outputs_.begin();
 973          o != edge->outputs_.end(); ++o) {
 974       TimeStamp new_mtime = disk_interface_->Stat((*o)->path(), err);
 975       if (new_mtime == -1)
 976         return false;
 977       if (new_mtime > output_mtime)
 978         output_mtime = new_mtime;
 979       if ((*o)->mtime() == new_mtime && restat) {
 980         // The rule command did not change the output.  Propagate the clean
 981         // state through the build graph.
 982         // Note that this also applies to nonexistent outputs (mtime == 0).
 983         if (!plan_.CleanNode(&scan_, *o, err))
 984           return false;
 985         node_cleaned = true;
 986       }
 987     }
 988
 989     if (node_cleaned) {
 990       TimeStamp restat_mtime = 0;
 991       // If any output was cleaned, find the most recent mtime of any
 992       // (existing) non-order-only input or the depfile.
 993       for (vector<Node*>::iterator i = edge->inputs_.begin();
 994            i != edge->inputs_.end() - edge->order_only_deps_; ++i) {
 995         TimeStamp input_mtime = disk_interface_->Stat((*i)->path(), err);
 996         if (input_mtime == -1)
 997           return false;
 998         if (input_mtime > restat_mtime)
 999           restat_mtime = input_mtime;
1000       }
1001
1002       string depfile = edge->GetUnescapedDepfile();
1003       if (restat_mtime != 0 && deps_type.empty() && !depfile.empty()) {
1004         TimeStamp depfile_mtime = disk_interface_->Stat(depfile, err);
1005         if (depfile_mtime == -1)
1006           return false;
1007         if (depfile_mtime > restat_mtime)
1008           restat_mtime = depfile_mtime;
1009       }
1010
1011       // The total number of edges in the plan may have changed as a result
1012       // of a restat.
1013       status_->PlanHasTotalEdges(plan_.command_edge_count());
1014
1015       output_mtime = restat_mtime;
1016     }
1017   }
1018
1019   if (!plan_.EdgeFinished(edge, Plan::kEdgeSucceeded, err))
1020     return false;
1021
1022   // Delete any left over response file.
1023   string rspfile = edge->GetUnescapedRspfile();
1024   if (!rspfile.empty() && !g_keep_rsp)
1025     disk_interface_->RemoveFile(rspfile);
1026
1027   if (scan_.build_log()) {
1028     if (!scan_.build_log()->RecordCommand(edge, start_time, end_time,
1029                                           output_mtime)) {
1030       *err = string("Error writing to build log: ") + strerror(errno);
1031       return false;
1032     }
1033   }
1034
1035   if (!deps_type.empty() && !config_.dry_run) {
1036     assert(!edge->outputs_.empty() && "should have been rejected by parser");
1037     for (std::vector<Node*>::const_iterator o = edge->outputs_.begin();
1038          o != edge->outputs_.end(); ++o) {
1039       TimeStamp deps_mtime = disk_interface_->Stat((*o)->path(), err);
1040       if (deps_mtime == -1)
1041         return false;
1042       if (!scan_.deps_log()->RecordDeps(*o, deps_mtime, deps_nodes)) {
1043         *err = std::string("Error writing to deps log: ") + strerror(errno);
1044         return false;
1045       }
1046     }
1047   }
1048   return true;
1049 }
1050
1051 bool Builder::ExtractDeps(CommandRunner::Result* result,
1052                           const string& deps_type,
1053                           const string& deps_prefix,
1054                           vector<Node*>* deps_nodes,
1055                           string* err) {
1056   if (deps_type == "msvc") {
1057     CLParser parser;
1058     string output;
1059     if (!parser.Parse(result->output, deps_prefix, &output, err))
1060       return false;
1061     result->output = output;
1062     for (set<string>::iterator i = parser.includes_.begin();
1063          i != parser.includes_.end(); ++i) {
1064       // ~0 is assuming that with MSVC-parsed headers, it's ok to always make
1065       // all backslashes (as some of the slashes will certainly be backslashes
1066       // anyway). This could be fixed if necessary with some additional
1067       // complexity in IncludesNormalize::Relativize.
1068       deps_nodes->push_back(state_->GetNode(*i, ~0u));
1069     }
1070   } else
1071   if (deps_type == "gcc") {
1072     string depfile = result->edge->GetUnescapedDepfile();
1073     if (depfile.empty()) {
1074       *err = string("edge with deps=gcc but no depfile makes no sense");
1075       return false;
1076     }
1077
1078     // Read depfile content.  Treat a missing depfile as empty.
1079     string content;
1080     switch (disk_interface_->ReadFile(depfile, &content, err)) {
1081     case DiskInterface::Okay:
1082       break;
1083     case DiskInterface::NotFound:
1084       err->clear();
1085       break;
1086     case DiskInterface::OtherError:
1087       return false;
1088     }
1089     if (content.empty())
1090       return true;
1091
1092     DepfileParser deps(config_.depfile_parser_options);
1093     if (!deps.Parse(&content, err))
1094       return false;
1095
1096     // XXX check depfile matches expected output.
1097     deps_nodes->reserve(deps.ins_.size());
1098     for (vector<StringPiece>::iterator i = deps.ins_.begin();
1099          i != deps.ins_.end(); ++i) {
1100       uint64_t slash_bits;
1101       if (!CanonicalizePath(const_cast<char*>(i->str_), &i->len_, &slash_bits,
1102                             err))
1103         return false;
1104       deps_nodes->push_back(state_->GetNode(*i, slash_bits));
1105     }
1106
1107     if (!g_keep_depfile) {
1108       if (disk_interface_->RemoveFile(depfile) < 0) {
1109         *err = string("deleting depfile: ") + strerror(errno) + string("\n");
1110         return false;
1111       }
1112     }
1113   } else {
1114     Fatal("unknown deps type '%s'", deps_type.c_str());
1115   }
1116
1117   return true;
1118 }
1119
1120 bool Builder::LoadDyndeps(Node* node, string* err) {
1121   status_->BuildLoadDyndeps();
1122
1123   // Load the dyndep information provided by this node.
1124   DyndepFile ddf;
1125   if (!scan_.LoadDyndeps(node, &ddf, err))
1126     return false;
1127
1128   // Update the build plan to account for dyndep modifications to the graph.
1129   if (!plan_.DyndepsLoaded(&scan_, node, ddf, err))
1130     return false;
1131
1132   // New command edges may have been added to the plan.
1133   status_->PlanHasTotalEdges(plan_.command_edge_count());
1134
1135   return true;
1136 }