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