Make backwards modification time check permanent, add another experiment

7 files changed, 163 insertions, 51 deletions

diff --git a/build2/cc/compile-rule.cxx b/build2/cc/compile-rule.cxx
index e361e9d..9326193 100644
--- a/build2/cc/compile-rule.cxx
+++ b/build2/cc/compile-rule.cxx
@@ -4249,7 +4249,8 @@ namespace build2
         return *pr.first;
       }
 
-      // Make sure depdb is no older than any of our prerequisites.
+      // Make sure depdb is no older than any of our prerequisites (see md.mt
+      // logic description above for details).
       //
       touch (md.dd, false, verb_never);
 
@@ -4668,11 +4669,14 @@ namespace build2
         rm.cancel ();
       }
 
+      timestamp now (system_clock::now ());
+      depdb::verify (timestamp_unknown, md.dd, tp, now);
+
       // Should we go to the filesystem and get the new mtime? We know the
       // file has been modified, so instead just use the current clock time.
       // It has the advantage of having the subseconds precision.
       //
-      t.mtime (system_clock::now ());
+      t.mtime (now);
       return target_state::changed;
     }
 
diff --git a/build2/cc/link-rule.cxx b/build2/cc/link-rule.cxx
index 2581d6f..47c058d 100644
--- a/build2/cc/link-rule.cxx
+++ b/build2/cc/link-rule.cxx
@@ -2071,12 +2071,7 @@ namespace build2
       if (dd.writing () || dd.mtime > mt)
         scratch = update = true;
 
-#define BUILD2_MTIME_CHECK
-#ifdef BUILD2_MTIME_CHECK
-      timestamp dd_tt (system_clock::now ());
-#endif
-
-      timestamp dd_cl (dd.close ());
+      dd.close ();
 
       // If nothing changed, then we are done.
       //
@@ -2559,23 +2554,7 @@ namespace build2
       }
 
       rm.cancel ();
-
-#ifdef BUILD2_MTIME_CHECK
-      {
-        timestamp tp_mt (file_mtime (tp));
-        timestamp dd_mt (file_mtime (dd.path));
-        timestamp tp_tt (system_clock::now ());
-
-        if (dd_mt > tp_mt)
-          fail << "backwards modification times:\n"
-               << dd_tt    << " window start\n"
-               << dd_cl    << " write mtime\n"
-               << dd.mtime << " close mtime\n"
-               << dd_mt    << " " << dd.path.string () << '\n'
-               << tp_mt    << " " << tp.string () << '\n'
-               << tp_tt    << " window end";
-      }
-#endif
+      dd.verify (tp);
 
       // Should we go to the filesystem and get the new mtime? We know the
       // file has been modified, so instead just use the current clock time.
diff --git a/build2/cli/rule.cxx b/build2/cli/rule.cxx
index 6c87490..d07af15 100644
--- a/build2/cli/rule.cxx
+++ b/build2/cli/rule.cxx
@@ -234,9 +234,8 @@ namespace build2
       // We use depdb to track changes to the .cli file name, options,
       // compiler, etc.
       //
+      depdb dd (tp + ".d");
       {
-        depdb dd (tp + ".d");
-
         // First should come the rule name/version.
         //
         if (dd.expect ("cli.compile 1") != nullptr)
@@ -259,14 +258,14 @@ namespace build2
         //
         if (dd.expect (s.path ()) != nullptr)
           l4 ([&]{trace << "input file mismatch forcing update of " << t;});
+      }
 
-        // Update if depdb mismatch.
-        //
-        if (dd.writing () || dd.mtime > mt)
-          update = true;
+      // Update if depdb mismatch.
+      //
+      if (dd.writing () || dd.mtime > mt)
+        update = true;
 
-        dd.close ();
-      }
+      dd.close ();
 
       // If nothing changed, then we are done.
       //
@@ -325,6 +324,8 @@ namespace build2
 
       run (cli, args);
 
+      dd.verify (tp);
+
       t.mtime (system_clock::now ());
       return target_state::changed;
     }
diff --git a/build2/depdb.cxx b/build2/depdb.cxx
index 088b355..aec2562 100644
--- a/build2/depdb.cxx
+++ b/build2/depdb.cxx
@@ -205,7 +205,7 @@ namespace build2
       fs_.put ('\n');
   }
 
-  timestamp depdb::
+  void depdb::
   close ()
   {
     // If we are at eof, then it means all lines are good, there is the "end
@@ -265,23 +265,40 @@ namespace build2
     //
 #ifdef _WIN32
     timestamp mt (timestamp_unknown);
+
+    // See libbutl/filesystem.cxx for details.
+    //
+    auto to_timestamp = [] (const FILETIME& t) -> timestamp
+    {
+      uint64_t nsec ((static_cast<uint64_t> (t.dwHighDateTime) << 32) |
+                     t.dwLowDateTime);
+      nsec -= 11644473600ULL * 10000000;
+      nsec *= 100;
+
+      return timestamp (
+        chrono::duration_cast<duration> (chrono::nanoseconds (nsec)));
+    };
 #endif
 
     if (state_ == state::write)
     {
+#ifdef BUILD2_MTIME_CHECK
+      start_ = system_clock::now ();
+#endif
+
 #ifdef _WIN32
+      //
+      // On Windows there are two times, the precise time (which is what we
+      // get with system_clock::now()) and what we will call "filesystem time"
+      // which can lag the precise time by as much as couple of milliseconds.
+      //
       FILETIME ft;
       GetSystemTimeAsFileTime (&ft);
+      mt = to_timestamp (ft);
 
-      // See libbutl/filesystem.cxx for details.
-      //
-      uint64_t nsec ((static_cast<uint64_t> (ft.dwHighDateTime) << 32) |
-                     ft.dwLowDateTime);
-      nsec -= 11644473600ULL * 10000000;
-      nsec *= 100;
-
-      mt = timestamp (
-        chrono::duration_cast<duration> (chrono::nanoseconds (nsec)));
+#ifdef BUILD2_MTIME_CHECK
+      wtime_ = mt; // Save for check below.
+#endif
 #endif
 
       fs_.put ('\0'); // The "end marker".
@@ -292,22 +309,88 @@ namespace build2
 #if defined(_WIN32) || defined(__FreeBSD__)
     if (state_ == state::write)
     {
-      mtime = file_mtime (path); // Save for debugging.
-
 #ifdef _WIN32
+      auto file_mtime_h = [&to_timestamp] (const path_type& p) -> timestamp
+      {
+        HANDLE h (CreateFile (p.string ().c_str (),
+                              FILE_READ_ATTRIBUTES,
+                              FILE_SHARE_READ | FILE_SHARE_WRITE,
+                              NULL,
+                              OPEN_EXISTING,
+                              0,
+                              NULL));
+
+        assert (h != INVALID_HANDLE_VALUE);
+
+        BY_HANDLE_FILE_INFORMATION fi;
+        if (!GetFileInformationByHandle (h, &fi))
+          assert (false);
+
+        timestamp r (to_timestamp (fi.ftLastWriteTime));
+        CloseHandle (h);
+        return r;
+      };
+
+      mtime = file_mtime_h (path); // Save for check below.
+
       if (mtime < mt)
       {
         file_mtime (path, mt);
-        assert (file_mtime (path) == mt);
+        assert (file_mtime_h (path) == mt);
       }
+#else
+      mtime = file_mtime (path); // Save for check below.
 #endif
     }
 #endif
+  }
 
-#ifdef _WIN32
-    return mt;
-#else
-    return timestamp_unknown;
+#ifdef BUILD2_MTIME_CHECK
+  void depdb::
+  verify (const path_type& t, timestamp e)
+  {
+    if (state_ != state::write)
+      return;
+
+    // We could call the static version but then we would have lost additional
+    // information for some platforms.
+    //
+    timestamp t_mt (file_mtime (t));
+    timestamp d_mt (file_mtime (path));
+
+    if (d_mt > t_mt)
+    {
+      if (e == timestamp_unknown)
+        e = system_clock::now ();
+
+      fail << "backwards modification times detected:\n"
+           << start_ << " sequence start\n"
+#if defined(_WIN32)
+           << wtime_ << " write time\n"
+#endif
+#if defined(_WIN32) || defined(__FreeBSD__)
+           << mtime  << " close mtime\n"
 #endif
+           << d_mt   << " " << path.string () << '\n'
+           << t_mt   << " " << t.string () << '\n'
+           << e      << " sequence end";
+    }
+  }
+
+  void depdb::
+  verify (timestamp s, const path_type& d, const path_type& t, timestamp e)
+  {
+    timestamp t_mt (file_mtime (t));
+    timestamp d_mt (file_mtime (d));
+
+    if (d_mt > t_mt)
+    {
+      fail << "backwards modification times detected:\n"
+           << s    << " sequence start\n"
+           << d_mt << " " << d.string () << '\n'
+           << t_mt << " " << t.string () << '\n'
+           << e    << " sequence end";
+    }
   }
+#endif // BUILD2_MTIME_CHECK
 }
diff --git a/build2/depdb.hxx b/build2/depdb.hxx
index ffb3b89..7319461 100644
--- a/build2/depdb.hxx
+++ b/build2/depdb.hxx
@@ -11,6 +11,8 @@
 #include <build2/types.hxx>
 #include <build2/utility.hxx>
 
+#define BUILD2_MTIME_CHECK
+
 namespace build2
 {
   // Auxiliary dependency database (those .d files). Uses io_error and
@@ -90,9 +92,23 @@ namespace build2
     // may be left in the old/currupt state. Note that in the read mode this
     // function will "chop off" lines that haven't been read.
     //
-    timestamp
+    // Make sure to call verify() after updating the target for modification
+    // times sanity check after.
+    //
+    void
     close ();
 
+    // Perform target/db modification times sanity check.
+    //
+    void
+    verify (const path_type& target, timestamp end = timestamp_unknown);
+
+    static void
+    verify (timestamp start,
+            const path_type& db,
+            const path_type& target,
+            timestamp end);
+
     // Read the next line. If the result is not NULL, then it is a pointer to
     // the next line in the database (which you are free to move from). If you
     // then call write(), this line will be overwritten.
@@ -213,7 +229,16 @@ namespace build2
     std::fstream           fs_;
     std::fstream::pos_type pos_;  // Start of the last returned line.
     string                 line_; // Current line.
+
+#ifdef BUILD2_MTIME_CHECK
+    timestamp start_;
+#ifdef _WIN32
+    timestamp wtime_;
+#endif
+#endif
   };
 }
 
+#include <build2/depdb.ixx>
+
 #endif // BUILD2_DEPDB_HXX
diff --git a/build2/depdb.ixx b/build2/depdb.ixx
new file mode 100644
index 0000000..c8b187d
--- /dev/null
+++ b/build2/depdb.ixx
@@ -0,0 +1,18 @@
+// file      : build2/depdb.ixx -*- C++ -*-
+// copyright : Copyright (c) 2014-2018 Code Synthesis Ltd
+// license   : MIT; see accompanying LICENSE file
+
+namespace build2
+{
+#ifndef BUILD2_MTIME_CHECK
+  inline void depdb::
+  verify (const path_type&, timestamp)
+  {
+  }
+
+  inline void depdb::
+  verify (timestamp, const path_type&, const path_type&, timestamp)
+  {
+  }
+#endif
+}
diff --git a/build2/in/rule.cxx b/build2/in/rule.cxx
index 86b8ffa..545ded5 100644
--- a/build2/in/rule.cxx
+++ b/build2/in/rule.cxx
@@ -398,6 +398,8 @@ namespace build2
         fail << "unable to " << what << ' ' << *whom << ": " << e;
       }
 
+      dd.verify (tp);
+
       t.mtime (system_clock::now ());
       return target_state::changed;
     }