SERVER-21543 Lengthen delay before deleting old journal files

2 files changed, 52 insertions, 38 deletions

diff --git a/jstests/noPassthroughWithMongod/dur_remove_old_journals.js b/jstests/noPassthroughWithMongod/dur_remove_old_journals.js
index e309eee7b2d..334d6f5ffae 100644
--- a/jstests/noPassthroughWithMongod/dur_remove_old_journals.js
+++ b/jstests/noPassthroughWithMongod/dur_remove_old_journals.js
@@ -1,52 +1,62 @@
 // this test makes sure that old journal files are removed
 
-// tunables
-STRING_SIZE = 1024*1024;
-NUM_TO_INSERT = 2.5*1024;
-PATH = MongoRunner.dataDir + "/dur_remove_old_journals";
-SYNC_DELAY = 5; // must be a number
-
-conn = startMongodEmpty("--port", 30001, "--dbpath", PATH, "--dur", "--smallfiles", "--syncdelay", ''+SYNC_DELAY);
+var dbpath = MongoRunner.dataDir + "/dur_remove_old_journals";
+var conn = MongoRunner.runMongod({
+    journal: "",
+    smallfiles: "",
+    syncdelay: 5,  // seconds between fsyncs.
+    dbpath: dbpath,
+});
 db = conn.getDB("test");
 
-longString = 'x';
-while (longString.length < STRING_SIZE)
-    longString += longString;
+// Returns true if j._0 exists.
+function firstJournalFileExists() {
+    var files = listFiles(dbpath + "/journal");
+    for (var i = 0; i < files.length; i++) {
+        if (files[i].baseName === "j._0") {
+            return true;
+        }
+    }
+    return false;
+}
+
+// Represents the cummulative total of the number of journal files created.
+function getLatestJournalFileNum() {
+    var files = listFiles(dbpath + "/journal");
+    var latest = 0;
+    files.forEach(function(file) {
+        if (file.baseName !== "lsn") {
+            var fileNum = NumberInt(file.baseName[file.baseName.length - 1]);
+            latest = Math.max(latest, fileNum);
+        }
+    });
+    return latest;
+}
+
+var stringSize = 1024*1024;
+var longString = new Array(stringSize).join("x");
+
+// Insert some data to create the first journal file.
+var numInserted = 0;
+while (numInserted < 100) {
+    db.foo.insert({_id: numInserted++, s: longString});
+}
+assert.soon(firstJournalFileExists, "Should have created a journal file");
 
-numInserted = 0;
-while (numInserted < NUM_TO_INSERT){
-    db.foo.insert({_id: numInserted++, s:longString});
 
+// Do writes until the first journal file is deleted, or we give up waiting.
+var maxJournalFiles = 10;
+while (firstJournalFileExists() && getLatestJournalFileNum() < maxJournalFiles) {
+    db.foo.insert({_id: numInserted++, s: longString});
 
     if (numInserted % 100 == 0){
-        print("numInserted: " + numInserted);
+        jsTestLog("numInserted: " + numInserted);
         db.adminCommand({fsync:1});
         db.foo.remove({});
         db.adminCommand({fsync:1});
     }
 }
 
-sleepSecs = SYNC_DELAY + 15 // long enough for data file flushing and journal keep time
-print("\nWaiting " + sleepSecs + " seconds...\n");
-sleep(sleepSecs*1000);
-
-
-files = listFiles(PATH + "/journal")
-printjson(files);
-
-var nfiles = 0;
-files.forEach(function (file) {
-    assert.eq('string', typeof (file.name));    // sanity checking
-    if (/prealloc/.test(file.name)) {
-        ;
-    }
-    else {
-        nfiles++;
-    }
-})
-
-assert.eq(2, nfiles); // latest journal file and lsn
-
-stopMongod(30001);
-
+assert(!firstJournalFileExists(), "Expected to have deleted the first journal file by now");
+MongoRunner.stopMongod(conn);
 print("*** success ***");
diff --git a/src/mongo/db/dur_journal.cpp b/src/mongo/db/dur_journal.cpp
index bb466139f2e..a19032bc4c0 100644
--- a/src/mongo/db/dur_journal.cpp
+++ b/src/mongo/db/dur_journal.cpp
@@ -669,7 +669,11 @@ namespace mongo {
             while( !_oldJournalFiles.empty() ) {
                 JFile f = _oldJournalFiles.front();
 
-                if( f.lastEventTimeMs < _lastFlushTime + ExtraKeepTimeMs ) {
+                    // 'f.lastEventTimeMs' is the timestamp of the last thing in the journal file.
+                    // '_lastFlushTime' is the start time of the last successful flush of the data
+                    // files to disk. We can't delete this journal file until the last successful
+                    // flush time is at least 10 seconds after 'f.lastEventTimeMs'.
+                    if (f.lastEventTimeMs + ExtraKeepTimeMs < _lastFlushTime) {
                     // eligible for deletion
                     boost::filesystem::path p( f.filename );
                     log() << "old journal file will be removed: " << f.filename << endl;