Ninja
build.cc
Go to the documentation of this file.
00001 // Copyright 2011 Google Inc. All Rights Reserved.
00002 //
00003 // Licensed under the Apache License, Version 2.0 (the "License");
00004 // you may not use this file except in compliance with the License.
00005 // You may obtain a copy of the License at
00006 //
00007 //     http://www.apache.org/licenses/LICENSE-2.0
00008 //
00009 // Unless required by applicable law or agreed to in writing, software
00010 // distributed under the License is distributed on an "AS IS" BASIS,
00011 // WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
00012 // See the License for the specific language governing permissions and
00013 // limitations under the License.
00014 
00015 #include "build.h"
00016 
00017 #include <assert.h>
00018 #include <errno.h>
00019 #include <stdio.h>
00020 #include <stdlib.h>
00021 #include <functional>
00022 
00023 #if defined(__SVR4) && defined(__sun)
00024 #include <sys/termios.h>
00025 #endif
00026 
00027 #include "build_log.h"
00028 #include "depfile_parser.h"
00029 #include "deps_log.h"
00030 #include "disk_interface.h"
00031 #include "graph.h"
00032 #include "msvc_helper.h"
00033 #include "state.h"
00034 #include "subprocess.h"
00035 #include "util.h"
00036 
00037 namespace {
00038 
00039 /// A CommandRunner that doesn't actually run the commands.
00040 struct DryRunCommandRunner : public CommandRunner {
00041   virtual ~DryRunCommandRunner() {}
00042 
00043   // Overridden from CommandRunner:
00044   virtual bool CanRunMore();
00045   virtual bool StartCommand(Edge* edge);
00046   virtual bool WaitForCommand(Result* result);
00047 
00048  private:
00049   queue<Edge*> finished_;
00050 };
00051 
00052 bool DryRunCommandRunner::CanRunMore() {
00053   return true;
00054 }
00055 
00056 bool DryRunCommandRunner::StartCommand(Edge* edge) {
00057   finished_.push(edge);
00058   return true;
00059 }
00060 
00061 bool DryRunCommandRunner::WaitForCommand(Result* result) {
00062    if (finished_.empty())
00063      return false;
00064 
00065    result->status = ExitSuccess;
00066    result->edge = finished_.front();
00067    finished_.pop();
00068    return true;
00069 }
00070 
00071 }  // namespace
00072 
00073 BuildStatus::BuildStatus(const BuildConfig& config)
00074     : config_(config),
00075       start_time_millis_(GetTimeMillis()),
00076       started_edges_(0), finished_edges_(0), total_edges_(0),
00077       progress_status_format_(NULL),
00078       overall_rate_(), current_rate_(config.parallelism) {
00079 
00080   // Don't do anything fancy in verbose mode.
00081   if (config_.verbosity != BuildConfig::NORMAL)
00082     printer_.set_smart_terminal(false);
00083 
00084   progress_status_format_ = getenv("NINJA_STATUS");
00085   if (!progress_status_format_)
00086     progress_status_format_ = "[%s/%t] ";
00087 }
00088 
00089 void BuildStatus::PlanHasTotalEdges(int total) {
00090   total_edges_ = total;
00091 }
00092 
00093 void BuildStatus::BuildEdgeStarted(Edge* edge) {
00094   int start_time = (int)(GetTimeMillis() - start_time_millis_);
00095   running_edges_.insert(make_pair(edge, start_time));
00096   ++started_edges_;
00097 
00098   PrintStatus(edge);
00099 }
00100 
00101 void BuildStatus::BuildEdgeFinished(Edge* edge,
00102                                     bool success,
00103                                     const string& output,
00104                                     int* start_time,
00105                                     int* end_time) {
00106   int64_t now = GetTimeMillis();
00107   ++finished_edges_;
00108 
00109   RunningEdgeMap::iterator i = running_edges_.find(edge);
00110   *start_time = i->second;
00111   *end_time = (int)(now - start_time_millis_);
00112   running_edges_.erase(i);
00113 
00114   if (config_.verbosity == BuildConfig::QUIET)
00115     return;
00116 
00117   if (printer_.is_smart_terminal())
00118     PrintStatus(edge);
00119 
00120   // Print the command that is spewing before printing its output.
00121   if (!success)
00122     printer_.PrintOnNewLine("FAILED: " + edge->EvaluateCommand() + "\n");
00123 
00124   if (!output.empty()) {
00125     // ninja sets stdout and stderr of subprocesses to a pipe, to be able to
00126     // check if the output is empty. Some compilers, e.g. clang, check
00127     // isatty(stderr) to decide if they should print colored output.
00128     // To make it possible to use colored output with ninja, subprocesses should
00129     // be run with a flag that forces them to always print color escape codes.
00130     // To make sure these escape codes don't show up in a file if ninja's output
00131     // is piped to a file, ninja strips ansi escape codes again if it's not
00132     // writing to a |smart_terminal_|.
00133     // (Launching subprocesses in pseudo ttys doesn't work because there are
00134     // only a few hundred available on some systems, and ninja can launch
00135     // thousands of parallel compile commands.)
00136     // TODO: There should be a flag to disable escape code stripping.
00137     string final_output;
00138     if (!printer_.is_smart_terminal())
00139       final_output = StripAnsiEscapeCodes(output);
00140     else
00141       final_output = output;
00142     printer_.PrintOnNewLine(final_output);
00143   }
00144 }
00145 
00146 void BuildStatus::BuildFinished() {
00147   printer_.PrintOnNewLine("");
00148 }
00149 
00150 string BuildStatus::FormatProgressStatus(
00151     const char* progress_status_format) const {
00152   string out;
00153   char buf[32];
00154   int percent;
00155   for (const char* s = progress_status_format; *s != '\0'; ++s) {
00156     if (*s == '%') {
00157       ++s;
00158       switch (*s) {
00159       case '%':
00160         out.push_back('%');
00161         break;
00162 
00163         // Started edges.
00164       case 's':
00165         snprintf(buf, sizeof(buf), "%d", started_edges_);
00166         out += buf;
00167         break;
00168 
00169         // Total edges.
00170       case 't':
00171         snprintf(buf, sizeof(buf), "%d", total_edges_);
00172         out += buf;
00173         break;
00174 
00175         // Running edges.
00176       case 'r':
00177         snprintf(buf, sizeof(buf), "%d", started_edges_ - finished_edges_);
00178         out += buf;
00179         break;
00180 
00181         // Unstarted edges.
00182       case 'u':
00183         snprintf(buf, sizeof(buf), "%d", total_edges_ - started_edges_);
00184         out += buf;
00185         break;
00186 
00187         // Finished edges.
00188       case 'f':
00189         snprintf(buf, sizeof(buf), "%d", finished_edges_);
00190         out += buf;
00191         break;
00192 
00193         // Overall finished edges per second.
00194       case 'o':
00195         overall_rate_.UpdateRate(finished_edges_);
00196         snprinfRate(overall_rate_.rate(), buf, "%.1f");
00197         out += buf;
00198         break;
00199 
00200         // Current rate, average over the last '-j' jobs.
00201       case 'c':
00202         current_rate_.UpdateRate(finished_edges_);
00203         snprinfRate(current_rate_.rate(), buf, "%.1f");
00204         out += buf;
00205         break;
00206 
00207         // Percentage
00208       case 'p':
00209         percent = (100 * started_edges_) / total_edges_;
00210         snprintf(buf, sizeof(buf), "%3i%%", percent);
00211         out += buf;
00212         break;
00213 
00214       case 'e': {
00215         double elapsed = overall_rate_.Elapsed();
00216         snprintf(buf, sizeof(buf), "%.3f", elapsed);
00217         out += buf;
00218         break;
00219       }
00220 
00221       default:
00222         Fatal("unknown placeholder '%%%c' in $NINJA_STATUS", *s);
00223         return "";
00224       }
00225     } else {
00226       out.push_back(*s);
00227     }
00228   }
00229 
00230   return out;
00231 }
00232 
00233 void BuildStatus::PrintStatus(Edge* edge) {
00234   if (config_.verbosity == BuildConfig::QUIET)
00235     return;
00236 
00237   bool force_full_command = config_.verbosity == BuildConfig::VERBOSE;
00238 
00239   string to_print = edge->GetBinding("description");
00240   if (to_print.empty() || force_full_command)
00241     to_print = edge->GetBinding("command");
00242 
00243   if (finished_edges_ == 0) {
00244     overall_rate_.Restart();
00245     current_rate_.Restart();
00246   }
00247   to_print = FormatProgressStatus(progress_status_format_) + to_print;
00248 
00249   printer_.Print(to_print,
00250                  force_full_command ? LinePrinter::FULL : LinePrinter::ELIDE);
00251 }
00252 
00253 Plan::Plan() : command_edges_(0), wanted_edges_(0) {}
00254 
00255 bool Plan::AddTarget(Node* node, string* err) {
00256   vector<Node*> stack;
00257   return AddSubTarget(node, &stack, err);
00258 }
00259 
00260 bool Plan::AddSubTarget(Node* node, vector<Node*>* stack, string* err) {
00261   Edge* edge = node->in_edge();
00262   if (!edge) {  // Leaf node.
00263     if (node->dirty()) {
00264       string referenced;
00265       if (!stack->empty())
00266         referenced = ", needed by '" + stack->back()->path() + "',";
00267       *err = "'" + node->path() + "'" + referenced + " missing "
00268              "and no known rule to make it";
00269     }
00270     return false;
00271   }
00272 
00273   if (CheckDependencyCycle(node, stack, err))
00274     return false;
00275 
00276   if (edge->outputs_ready())
00277     return false;  // Don't need to do anything.
00278 
00279   // If an entry in want_ does not already exist for edge, create an entry which
00280   // maps to false, indicating that we do not want to build this entry itself.
00281   pair<map<Edge*, bool>::iterator, bool> want_ins =
00282     want_.insert(make_pair(edge, false));
00283   bool& want = want_ins.first->second;
00284 
00285   // If we do need to build edge and we haven't already marked it as wanted,
00286   // mark it now.
00287   if (node->dirty() && !want) {
00288     want = true;
00289     ++wanted_edges_;
00290     if (edge->AllInputsReady())
00291       ScheduleWork(edge);
00292     if (!edge->is_phony())
00293       ++command_edges_;
00294   }
00295 
00296   if (!want_ins.second)
00297     return true;  // We've already processed the inputs.
00298 
00299   stack->push_back(node);
00300   for (vector<Node*>::iterator i = edge->inputs_.begin();
00301        i != edge->inputs_.end(); ++i) {
00302     if (!AddSubTarget(*i, stack, err) && !err->empty())
00303       return false;
00304   }
00305   assert(stack->back() == node);
00306   stack->pop_back();
00307 
00308   return true;
00309 }
00310 
00311 bool Plan::CheckDependencyCycle(Node* node, vector<Node*>* stack, string* err) {
00312   vector<Node*>::reverse_iterator ri =
00313       find(stack->rbegin(), stack->rend(), node);
00314   if (ri == stack->rend())
00315     return false;
00316 
00317   // Add this node onto the stack to make it clearer where the loop
00318   // is.
00319   stack->push_back(node);
00320 
00321   vector<Node*>::iterator start = find(stack->begin(), stack->end(), node);
00322   *err = "dependency cycle: ";
00323   for (vector<Node*>::iterator i = start; i != stack->end(); ++i) {
00324     if (i != start)
00325       err->append(" -> ");
00326     err->append((*i)->path());
00327   }
00328   return true;
00329 }
00330 
00331 Edge* Plan::FindWork() {
00332   if (ready_.empty())
00333     return NULL;
00334   set<Edge*>::iterator i = ready_.begin();
00335   Edge* edge = *i;
00336   ready_.erase(i);
00337   return edge;
00338 }
00339 
00340 void Plan::ScheduleWork(Edge* edge) {
00341   Pool* pool = edge->pool();
00342   if (pool->ShouldDelayEdge()) {
00343     // The graph is not completely clean. Some Nodes have duplicate Out edges.
00344     // We need to explicitly ignore these here, otherwise their work will get
00345     // scheduled twice (see https://github.com/martine/ninja/pull/519)
00346     if (ready_.count(edge)) {
00347       return;
00348     }
00349     pool->DelayEdge(edge);
00350     pool->RetrieveReadyEdges(&ready_);
00351   } else {
00352     pool->EdgeScheduled(*edge);
00353     ready_.insert(edge);
00354   }
00355 }
00356 
00357 void Plan::ResumeDelayedJobs(Edge* edge) {
00358   edge->pool()->EdgeFinished(*edge);
00359   edge->pool()->RetrieveReadyEdges(&ready_);
00360 }
00361 
00362 void Plan::EdgeFinished(Edge* edge) {
00363   map<Edge*, bool>::iterator i = want_.find(edge);
00364   assert(i != want_.end());
00365   if (i->second)
00366     --wanted_edges_;
00367   want_.erase(i);
00368   edge->outputs_ready_ = true;
00369 
00370   // See if this job frees up any delayed jobs
00371   ResumeDelayedJobs(edge);
00372 
00373   // Check off any nodes we were waiting for with this edge.
00374   for (vector<Node*>::iterator i = edge->outputs_.begin();
00375        i != edge->outputs_.end(); ++i) {
00376     NodeFinished(*i);
00377   }
00378 }
00379 
00380 void Plan::NodeFinished(Node* node) {
00381   // See if we we want any edges from this node.
00382   for (vector<Edge*>::const_iterator i = node->out_edges().begin();
00383        i != node->out_edges().end(); ++i) {
00384     map<Edge*, bool>::iterator want_i = want_.find(*i);
00385     if (want_i == want_.end())
00386       continue;
00387 
00388     // See if the edge is now ready.
00389     if ((*i)->AllInputsReady()) {
00390       if (want_i->second) {
00391         ScheduleWork(*i);
00392       } else {
00393         // We do not need to build this edge, but we might need to build one of
00394         // its dependents.
00395         EdgeFinished(*i);
00396       }
00397     }
00398   }
00399 }
00400 
00401 void Plan::CleanNode(DependencyScan* scan, Node* node) {
00402   node->set_dirty(false);
00403 
00404   for (vector<Edge*>::const_iterator ei = node->out_edges().begin();
00405        ei != node->out_edges().end(); ++ei) {
00406     // Don't process edges that we don't actually want.
00407     map<Edge*, bool>::iterator want_i = want_.find(*ei);
00408     if (want_i == want_.end() || !want_i->second)
00409       continue;
00410 
00411     // If all non-order-only inputs for this edge are now clean,
00412     // we might have changed the dirty state of the outputs.
00413     vector<Node*>::iterator
00414         begin = (*ei)->inputs_.begin(),
00415         end = (*ei)->inputs_.end() - (*ei)->order_only_deps_;
00416     if (find_if(begin, end, mem_fun(&Node::dirty)) == end) {
00417       // Recompute most_recent_input and command.
00418       Node* most_recent_input = NULL;
00419       for (vector<Node*>::iterator ni = begin; ni != end; ++ni) {
00420         if (!most_recent_input || (*ni)->mtime() > most_recent_input->mtime())
00421           most_recent_input = *ni;
00422       }
00423       string command = (*ei)->EvaluateCommand(true);
00424 
00425       // Now, recompute the dirty state of each output.
00426       bool all_outputs_clean = true;
00427       for (vector<Node*>::iterator ni = (*ei)->outputs_.begin();
00428            ni != (*ei)->outputs_.end(); ++ni) {
00429         if (!(*ni)->dirty())
00430           continue;
00431 
00432         if (scan->RecomputeOutputDirty(*ei, most_recent_input, 0,
00433                                        command, *ni)) {
00434           (*ni)->MarkDirty();
00435           all_outputs_clean = false;
00436         } else {
00437           CleanNode(scan, *ni);
00438         }
00439       }
00440 
00441       // If we cleaned all outputs, mark the node as not wanted.
00442       if (all_outputs_clean) {
00443         want_i->second = false;
00444         --wanted_edges_;
00445         if (!(*ei)->is_phony())
00446           --command_edges_;
00447       }
00448     }
00449   }
00450 }
00451 
00452 void Plan::Dump() {
00453   printf("pending: %d\n", (int)want_.size());
00454   for (map<Edge*, bool>::iterator i = want_.begin(); i != want_.end(); ++i) {
00455     if (i->second)
00456       printf("want ");
00457     i->first->Dump();
00458   }
00459   printf("ready: %d\n", (int)ready_.size());
00460 }
00461 
00462 struct RealCommandRunner : public CommandRunner {
00463   explicit RealCommandRunner(const BuildConfig& config) : config_(config) {}
00464   virtual ~RealCommandRunner() {}
00465   virtual bool CanRunMore();
00466   virtual bool StartCommand(Edge* edge);
00467   virtual bool WaitForCommand(Result* result);
00468   virtual vector<Edge*> GetActiveEdges();
00469   virtual void Abort();
00470 
00471   const BuildConfig& config_;
00472   SubprocessSet subprocs_;
00473   map<Subprocess*, Edge*> subproc_to_edge_;
00474 };
00475 
00476 vector<Edge*> RealCommandRunner::GetActiveEdges() {
00477   vector<Edge*> edges;
00478   for (map<Subprocess*, Edge*>::iterator i = subproc_to_edge_.begin();
00479        i != subproc_to_edge_.end(); ++i)
00480     edges.push_back(i->second);
00481   return edges;
00482 }
00483 
00484 void RealCommandRunner::Abort() {
00485   subprocs_.Clear();
00486 }
00487 
00488 bool RealCommandRunner::CanRunMore() {
00489   return ((int)subprocs_.running_.size()) < config_.parallelism
00490     && ((subprocs_.running_.empty() || config_.max_load_average <= 0.0f)
00491         || GetLoadAverage() < config_.max_load_average);
00492 }
00493 
00494 bool RealCommandRunner::StartCommand(Edge* edge) {
00495   string command = edge->EvaluateCommand();
00496   Subprocess* subproc = subprocs_.Add(command);
00497   if (!subproc)
00498     return false;
00499   subproc_to_edge_.insert(make_pair(subproc, edge));
00500 
00501   return true;
00502 }
00503 
00504 bool RealCommandRunner::WaitForCommand(Result* result) {
00505   Subprocess* subproc;
00506   while ((subproc = subprocs_.NextFinished()) == NULL) {
00507     bool interrupted = subprocs_.DoWork();
00508     if (interrupted)
00509       return false;
00510   }
00511 
00512   result->status = subproc->Finish();
00513   result->output = subproc->GetOutput();
00514 
00515   map<Subprocess*, Edge*>::iterator i = subproc_to_edge_.find(subproc);
00516   result->edge = i->second;
00517   subproc_to_edge_.erase(i);
00518 
00519   delete subproc;
00520   return true;
00521 }
00522 
00523 Builder::Builder(State* state, const BuildConfig& config,
00524                  BuildLog* build_log, DepsLog* deps_log,
00525                  DiskInterface* disk_interface)
00526     : state_(state), config_(config), disk_interface_(disk_interface),
00527       scan_(state, build_log, deps_log, disk_interface) {
00528   status_ = new BuildStatus(config);
00529 }
00530 
00531 Builder::~Builder() {
00532   Cleanup();
00533 }
00534 
00535 void Builder::Cleanup() {
00536   if (command_runner_.get()) {
00537     vector<Edge*> active_edges = command_runner_->GetActiveEdges();
00538     command_runner_->Abort();
00539 
00540     for (vector<Edge*>::iterator i = active_edges.begin();
00541          i != active_edges.end(); ++i) {
00542       string depfile = (*i)->GetBinding("depfile");
00543       for (vector<Node*>::iterator ni = (*i)->outputs_.begin();
00544            ni != (*i)->outputs_.end(); ++ni) {
00545         // Only delete this output if it was actually modified.  This is
00546         // important for things like the generator where we don't want to
00547         // delete the manifest file if we can avoid it.  But if the rule
00548         // uses a depfile, always delete.  (Consider the case where we
00549         // need to rebuild an output because of a modified header file
00550         // mentioned in a depfile, and the command touches its depfile
00551         // but is interrupted before it touches its output file.)
00552         if (!depfile.empty() ||
00553             (*ni)->mtime() != disk_interface_->Stat((*ni)->path())) {
00554           disk_interface_->RemoveFile((*ni)->path());
00555         }
00556       }
00557       if (!depfile.empty())
00558         disk_interface_->RemoveFile(depfile);
00559     }
00560   }
00561 }
00562 
00563 Node* Builder::AddTarget(const string& name, string* err) {
00564   Node* node = state_->LookupNode(name);
00565   if (!node) {
00566     *err = "unknown target: '" + name + "'";
00567     return NULL;
00568   }
00569   if (!AddTarget(node, err))
00570     return NULL;
00571   return node;
00572 }
00573 
00574 bool Builder::AddTarget(Node* node, string* err) {
00575   node->StatIfNecessary(disk_interface_);
00576   if (Edge* in_edge = node->in_edge()) {
00577     if (!scan_.RecomputeDirty(in_edge, err))
00578       return false;
00579     if (in_edge->outputs_ready())
00580       return true;  // Nothing to do.
00581   }
00582 
00583   if (!plan_.AddTarget(node, err))
00584     return false;
00585 
00586   return true;
00587 }
00588 
00589 bool Builder::AlreadyUpToDate() const {
00590   return !plan_.more_to_do();
00591 }
00592 
00593 bool Builder::Build(string* err) {
00594   assert(!AlreadyUpToDate());
00595 
00596   status_->PlanHasTotalEdges(plan_.command_edge_count());
00597   int pending_commands = 0;
00598   int failures_allowed = config_.failures_allowed;
00599 
00600   // Set up the command runner if we haven't done so already.
00601   if (!command_runner_.get()) {
00602     if (config_.dry_run)
00603       command_runner_.reset(new DryRunCommandRunner);
00604     else
00605       command_runner_.reset(new RealCommandRunner(config_));
00606   }
00607 
00608   // This main loop runs the entire build process.
00609   // It is structured like this:
00610   // First, we attempt to start as many commands as allowed by the
00611   // command runner.
00612   // Second, we attempt to wait for / reap the next finished command.
00613   while (plan_.more_to_do()) {
00614     // See if we can start any more commands.
00615     if (failures_allowed && command_runner_->CanRunMore()) {
00616       if (Edge* edge = plan_.FindWork()) {
00617         if (!StartEdge(edge, err)) {
00618           status_->BuildFinished();
00619           return false;
00620         }
00621 
00622         if (edge->is_phony()) {
00623           plan_.EdgeFinished(edge);
00624         } else {
00625           ++pending_commands;
00626         }
00627 
00628         // We made some progress; go back to the main loop.
00629         continue;
00630       }
00631     }
00632 
00633     // See if we can reap any finished commands.
00634     if (pending_commands) {
00635       CommandRunner::Result result;
00636       if (!command_runner_->WaitForCommand(&result) ||
00637           result.status == ExitInterrupted) {
00638         status_->BuildFinished();
00639         *err = "interrupted by user";
00640         return false;
00641       }
00642 
00643       --pending_commands;
00644       FinishCommand(&result);
00645 
00646       if (!result.success()) {
00647         if (failures_allowed)
00648           failures_allowed--;
00649       }
00650 
00651       // We made some progress; start the main loop over.
00652       continue;
00653     }
00654 
00655     // If we get here, we cannot make any more progress.
00656     status_->BuildFinished();
00657     if (failures_allowed == 0) {
00658       if (config_.failures_allowed > 1)
00659         *err = "subcommands failed";
00660       else
00661         *err = "subcommand failed";
00662     } else if (failures_allowed < config_.failures_allowed)
00663       *err = "cannot make progress due to previous errors";
00664     else
00665       *err = "stuck [this is a bug]";
00666 
00667     return false;
00668   }
00669 
00670   status_->BuildFinished();
00671   return true;
00672 }
00673 
00674 bool Builder::StartEdge(Edge* edge, string* err) {
00675   METRIC_RECORD("StartEdge");
00676   if (edge->is_phony())
00677     return true;
00678 
00679   status_->BuildEdgeStarted(edge);
00680 
00681   // Create directories necessary for outputs.
00682   // XXX: this will block; do we care?
00683   for (vector<Node*>::iterator i = edge->outputs_.begin();
00684        i != edge->outputs_.end(); ++i) {
00685     if (!disk_interface_->MakeDirs((*i)->path()))
00686       return false;
00687   }
00688 
00689   // Create response file, if needed
00690   // XXX: this may also block; do we care?
00691   string rspfile = edge->GetBinding("rspfile");
00692   if (!rspfile.empty()) {
00693     string content = edge->GetBinding("rspfile_content");
00694     if (!disk_interface_->WriteFile(rspfile, content))
00695       return false;
00696   }
00697 
00698   // start command computing and run it
00699   if (!command_runner_->StartCommand(edge)) {
00700     err->assign("command '" + edge->EvaluateCommand() + "' failed.");
00701     return false;
00702   }
00703 
00704   return true;
00705 }
00706 
00707 void Builder::FinishCommand(CommandRunner::Result* result) {
00708   METRIC_RECORD("FinishCommand");
00709 
00710   Edge* edge = result->edge;
00711 
00712   // First try to extract dependencies from the result, if any.
00713   // This must happen first as it filters the command output (we want
00714   // to filter /showIncludes output, even on compile failure) and
00715   // extraction itself can fail, which makes the command fail from a
00716   // build perspective.
00717   vector<Node*> deps_nodes;
00718   string deps_type = edge->GetBinding("deps");
00719   if (!deps_type.empty()) {
00720     string extract_err;
00721     if (!ExtractDeps(result, deps_type, &deps_nodes, &extract_err) &&
00722         result->success()) {
00723       if (!result->output.empty())
00724         result->output.append("\n");
00725       result->output.append(extract_err);
00726       result->status = ExitFailure;
00727     }
00728   }
00729 
00730   int start_time, end_time;
00731   status_->BuildEdgeFinished(edge, result->success(), result->output,
00732                              &start_time, &end_time);
00733 
00734   // The rest of this function only applies to successful commands.
00735   if (!result->success())
00736     return;
00737 
00738   // Restat the edge outputs, if necessary.
00739   TimeStamp restat_mtime = 0;
00740   if (edge->GetBindingBool("restat") && !config_.dry_run) {
00741     bool node_cleaned = false;
00742 
00743     for (vector<Node*>::iterator i = edge->outputs_.begin();
00744          i != edge->outputs_.end(); ++i) {
00745       TimeStamp new_mtime = disk_interface_->Stat((*i)->path());
00746       if ((*i)->mtime() == new_mtime) {
00747         // The rule command did not change the output.  Propagate the clean
00748         // state through the build graph.
00749         // Note that this also applies to nonexistent outputs (mtime == 0).
00750         plan_.CleanNode(&scan_, *i);
00751         node_cleaned = true;
00752       }
00753     }
00754 
00755     if (node_cleaned) {
00756       // If any output was cleaned, find the most recent mtime of any
00757       // (existing) non-order-only input or the depfile.
00758       for (vector<Node*>::iterator i = edge->inputs_.begin();
00759            i != edge->inputs_.end() - edge->order_only_deps_; ++i) {
00760         TimeStamp input_mtime = disk_interface_->Stat((*i)->path());
00761         if (input_mtime > restat_mtime)
00762           restat_mtime = input_mtime;
00763       }
00764 
00765       string depfile = edge->GetBinding("depfile");
00766       if (restat_mtime != 0 && !depfile.empty()) {
00767         TimeStamp depfile_mtime = disk_interface_->Stat(depfile);
00768         if (depfile_mtime > restat_mtime)
00769           restat_mtime = depfile_mtime;
00770       }
00771 
00772       // The total number of edges in the plan may have changed as a result
00773       // of a restat.
00774       status_->PlanHasTotalEdges(plan_.command_edge_count());
00775     }
00776   }
00777 
00778   plan_.EdgeFinished(edge);
00779 
00780   // Delete any left over response file.
00781   string rspfile = edge->GetBinding("rspfile");
00782   if (!rspfile.empty())
00783     disk_interface_->RemoveFile(rspfile);
00784 
00785   if (scan_.build_log()) {
00786     scan_.build_log()->RecordCommand(edge, start_time, end_time,
00787                                      restat_mtime);
00788   }
00789 
00790   if (!deps_type.empty() && !config_.dry_run) {
00791     assert(edge->outputs_.size() == 1 && "should have been rejected by parser");
00792     Node* out = edge->outputs_[0];
00793     TimeStamp deps_mtime = disk_interface_->Stat(out->path());
00794     scan_.deps_log()->RecordDeps(out, deps_mtime, deps_nodes);
00795   }
00796 
00797 }
00798 
00799 bool Builder::ExtractDeps(CommandRunner::Result* result,
00800                           const string& deps_type,
00801                           vector<Node*>* deps_nodes,
00802                           string* err) {
00803 #ifdef _WIN32
00804   if (deps_type == "msvc") {
00805     CLParser parser;
00806     result->output = parser.Parse(result->output);
00807     for (set<string>::iterator i = parser.includes_.begin();
00808          i != parser.includes_.end(); ++i) {
00809       deps_nodes->push_back(state_->GetNode(*i));
00810     }
00811   } else
00812 #endif
00813   if (deps_type == "gcc") {
00814     string depfile = result->edge->GetBinding("depfile");
00815     if (depfile.empty()) {
00816       *err = string("edge with deps=gcc but no depfile makes no sense");
00817       return false;
00818     }
00819 
00820     string content = disk_interface_->ReadFile(depfile, err);
00821     if (!err->empty())
00822       return false;
00823     if (content.empty())
00824       return true;
00825 
00826     DepfileParser deps;
00827     if (!deps.Parse(&content, err))
00828       return false;
00829 
00830     // XXX check depfile matches expected output.
00831     deps_nodes->reserve(deps.ins_.size());
00832     for (vector<StringPiece>::iterator i = deps.ins_.begin();
00833          i != deps.ins_.end(); ++i) {
00834       if (!CanonicalizePath(const_cast<char*>(i->str_), &i->len_, err))
00835         return false;
00836       deps_nodes->push_back(state_->GetNode(*i));
00837     }
00838 
00839     if (disk_interface_->RemoveFile(depfile) < 0) {
00840       *err = string("deleting depfile: ") + strerror(errno) + string("\n");
00841       return false;
00842     }
00843   } else {
00844     Fatal("unknown deps type '%s'", deps_type.c_str());
00845   }
00846 
00847   return true;
00848 }