From b549d18748a82d2a0e0efccb5ac6d9e3714f5234 Mon Sep 17 00:00:00 2001
From: Evan Martin <martine@danga.com>
Date: Sat, 27 Apr 2013 13:39:04 -0700
Subject: deps log: recover on truncated entry

If a read fails while reading an entry, truncate the log to the last
successfully read entry.  This prevents corruption when a subsequent
run appends another entry.
---
 src/deps_log.cc      | 41 +++++++++++++++++++++++++-----
 src/deps_log_test.cc | 71 +++++++++++++++++++++++++++++++++++++++++++++++++---
 2 files changed, 103 insertions(+), 9 deletions(-)

diff --git a/src/deps_log.cc b/src/deps_log.cc
index ceb75ce..5e5bba9 100644
--- a/src/deps_log.cc
+++ b/src/deps_log.cc
@@ -152,15 +152,23 @@ bool DepsLog::Load(const string& path, State* state, string* err) {
     return true;
   }
 
+  long offset;
+  bool read_failed = false;
   for (;;) {
+    offset = ftell(f);
+
     uint16_t size;
-    if (fread(&size, 2, 1, f) < 1)
+    if (fread(&size, 2, 1, f) < 1) {
+      read_failed = true;
       break;
+    }
     bool is_deps = (size >> 15) != 0;
     size = size & 0x7FFF;
 
-    if (fread(buf, size, 1, f) < 1)
+    if (fread(buf, size, 1, f) < 1) {
+      read_failed = true;
       break;
+    }
 
     if (is_deps) {
       assert(size % 4 == 0);
@@ -195,16 +203,37 @@ bool DepsLog::Load(const string& path, State* state, string* err) {
       nodes_.push_back(node);
     }
   }
-  if (ferror(f)) {
-    *err = strerror(ferror(f));
-    return false;
+
+  if (read_failed) {
+    // An error occurred while loading; try to recover by truncating the
+    // file to the last fully-read record.
+    if (ferror(f)) {
+      *err = strerror(ferror(f));
+    } else {
+      *err = "premature end of file";
+    }
+    fclose(f);
+
+    if (truncate(path.c_str(), offset) < 0) {
+      *err = strerror(errno);
+      return false;
+    }
+
+    // The truncate succeeded; we'll just report the load error as a
+    // warning because the build can proceed.
+    *err += "; recovering";
+    return true;
   }
+
   fclose(f);
+
   return true;
 }
 
 DepsLog::Deps* DepsLog::GetDeps(Node* node) {
-  if (node->id() < 0)
+  // Abort if the node has no id (never referenced in the deps) or if
+  // there's no deps recorded for the node.
+  if (node->id() < 0 || node->id() >= deps_.size())
     return NULL;
   return deps_[node->id()];
 }
diff --git a/src/deps_log_test.cc b/src/deps_log_test.cc
index 40539a7..9623d17 100644
--- a/src/deps_log_test.cc
+++ b/src/deps_log_test.cc
@@ -218,8 +218,7 @@ TEST_F(DepsLogTest, InvalidHeader) {
   }
 }
 
-// Simulate what happens if a write gets interrupted and the resulting
-// file is truncated.
+// Simulate what happens when loading a truncated log file.
 TEST_F(DepsLogTest, Truncated) {
   // Create a file with some entries.
   {
@@ -263,7 +262,7 @@ TEST_F(DepsLogTest, Truncated) {
       break;
     }
 
-    ASSERT_GE(node_count, log.nodes().size());
+    ASSERT_GE(node_count, (int)log.nodes().size());
     node_count = log.nodes().size();
 
     // Count how many non-NULL deps entries there are.
@@ -278,4 +277,70 @@ TEST_F(DepsLogTest, Truncated) {
   }
 }
 
+// Run the truncation-recovery logic.
+TEST_F(DepsLogTest, TruncatedRecovery) {
+  // Create a file with some entries.
+  {
+    State state;
+    DepsLog log;
+    string err;
+    EXPECT_TRUE(log.OpenForWrite(kTestFilename, &err));
+    ASSERT_EQ("", err);
+
+    vector<Node*> deps;
+    deps.push_back(state.GetNode("foo.h"));
+    deps.push_back(state.GetNode("bar.h"));
+    log.RecordDeps(state.GetNode("out.o"), 1, deps);
+
+    deps.clear();
+    deps.push_back(state.GetNode("foo.h"));
+    deps.push_back(state.GetNode("bar2.h"));
+    log.RecordDeps(state.GetNode("out2.o"), 2, deps);
+
+    log.Close();
+  }
+
+  // Shorten the file, corrupting the last record.
+  struct stat st;
+  ASSERT_EQ(0, stat(kTestFilename, &st));
+  ASSERT_EQ(0, truncate(kTestFilename, st.st_size - 2));
+
+  // Load the file again, add an entry.
+  {
+    State state;
+    DepsLog log;
+    string err;
+    EXPECT_TRUE(log.Load(kTestFilename, &state, &err));
+    ASSERT_EQ("premature end of file; recovering", err);
+    err.clear();
+
+    // The truncated entry should've been discarded.
+    EXPECT_EQ(NULL, log.GetDeps(state.GetNode("out2.o")));
+
+    EXPECT_TRUE(log.OpenForWrite(kTestFilename, &err));
+    ASSERT_EQ("", err);
+
+    // Add a new entry.
+    vector<Node*> deps;
+    deps.push_back(state.GetNode("foo.h"));
+    deps.push_back(state.GetNode("bar2.h"));
+    log.RecordDeps(state.GetNode("out2.o"), 3, deps);
+
+    log.Close();
+  }
+
+  // Load the file a third time to verify appending after a mangled
+  // entry doesn't break things.
+  {
+    State state;
+    DepsLog log;
+    string err;
+    EXPECT_TRUE(log.Load(kTestFilename, &state, &err));
+
+    // The truncated entry should exist.
+    DepsLog::Deps* deps = log.GetDeps(state.GetNode("out2.o"));
+    ASSERT_TRUE(deps);
+  }
+}
+
 }  // anonymous namespace
-- 
cgit v0.12