SERVER-17250 Verify logOp listeners are rollback-safe

4 files changed, 58 insertions, 3 deletions

diff --git a/jstests/noPassthroughWithMongod/logop_rollback.js b/jstests/noPassthroughWithMongod/logop_rollback.js
new file mode 100644
index 00000000000..cc585c59a8e
--- /dev/null
+++ b/jstests/noPassthroughWithMongod/logop_rollback.js
@@ -0,0 +1,46 @@
+//
+// Test that we neither rollback logOp nor crash when a WriteUnitOfWork attempts to rollback
+//
+(function() {
+    'use strict';
+
+    function checkForLogOpRollback(coll) {
+        var res = coll.runCommand({ getLog: 'global' });
+        assert.commandWorked(res);
+
+        for (var i = res.log.length - 1; i >= 0; i--) {
+            if (/custom rollback.*logop/i.test(res.log[i])) {
+                return true;
+            }
+        }
+        return false;
+    }
+
+    var coll = db.getSiblingDB('admin').system.roles;
+
+    //
+    // SERVER-17250 -- logOp rollback after triggering a
+    // "key too large to index" exception
+    //
+    var prevVerbosityLevel = db.getLogComponents().verbosity;
+    var prevWriteMode = db.getMongo().writeMode();
+    try {
+        // we need a verbosity level of at least 2 to see rollbacks in the logs
+        db.setLogLevel(2);
+
+        // must be in 'legacy' or 'compatibility' mode
+        db.getMongo().forceWriteMode('compatibility');
+        var res = coll.insert({ _id: new Array(1025).join('x') });
+
+        assert(res.hasWriteError());
+        // ErrorCodes::KeyTooLong == 17280
+        assert.eq(17280, res.getWriteError().code);
+
+        assert(checkForLogOpRollback(coll));
+    }
+    finally {
+        db.getMongo().forceWriteMode(prevWriteMode);
+        db.setLogLevel(prevVerbosityLevel);
+    }
+
+})();
diff --git a/src/mongo/db/storage/in_memory/in_memory_recovery_unit.cpp b/src/mongo/db/storage/in_memory/in_memory_recovery_unit.cpp
index 35b079b2d8e..79715f592e7 100644
--- a/src/mongo/db/storage/in_memory/in_memory_recovery_unit.cpp
+++ b/src/mongo/db/storage/in_memory/in_memory_recovery_unit.cpp
@@ -28,9 +28,12 @@
 *    it in the license file.
 */
 
+#define MONGO_LOG_DEFAULT_COMPONENT ::mongo::logger::LogComponent::kStorage
+
 #include "mongo/db/storage/in_memory/in_memory_recovery_unit.h"
 
 #include "mongo/db/storage/sorted_data_interface.h"
+#include "mongo/util/log.h"
 
 namespace mongo {
     InMemoryRecoveryUnit::~InMemoryRecoveryUnit() {
@@ -64,7 +67,9 @@ namespace mongo {
          try {
              for (Changes::reverse_iterator it = _changes.rbegin(), end = _changes.rend();
                      it != end; ++it) {
-                 (*it)->rollback();
+                 ChangePtr change = *it;
+                 LOG(2) << "CUSTOM ROLLBACK " << demangleName(typeid(*change));
+                 change->rollback();
              }
              _changes.clear();
         }
diff --git a/src/mongo/db/storage/rocks/rocks_recovery_unit.cpp b/src/mongo/db/storage/rocks/rocks_recovery_unit.cpp
index 252d18548dc..7db1de08d49 100644
--- a/src/mongo/db/storage/rocks/rocks_recovery_unit.cpp
+++ b/src/mongo/db/storage/rocks/rocks_recovery_unit.cpp
@@ -225,7 +225,9 @@ namespace mongo {
         try {
             for (Changes::const_reverse_iterator it = _changes.rbegin(), end = _changes.rend();
                     it != end; ++it) {
-                (*it)->rollback();
+                Change* change = *it;
+                LOG(2) << "CUSTOM ROLLBACK " << demangleName(typeid(*change));
+                change->rollback();
             }
             _changes.clear();
         }
diff --git a/src/mongo/db/storage/wiredtiger/wiredtiger_recovery_unit.cpp b/src/mongo/db/storage/wiredtiger/wiredtiger_recovery_unit.cpp
index 971a5829b06..bdd01a5194b 100644
--- a/src/mongo/db/storage/wiredtiger/wiredtiger_recovery_unit.cpp
+++ b/src/mongo/db/storage/wiredtiger/wiredtiger_recovery_unit.cpp
@@ -137,7 +137,9 @@ namespace mongo {
 
             for (Changes::const_reverse_iterator it = _changes.rbegin(), end = _changes.rend();
                     it != end; ++it) {
-                (*it)->rollback();
+                Change* change = *it;
+                LOG(2) << "CUSTOM ROLLBACK " << demangleName(typeid(*change));
+                change->rollback();
             }
             _changes.clear();