diff --git a/fdbserver/OldTLogServer_6_0.actor.cpp b/fdbserver/OldTLogServer_6_0.actor.cpp index 110c54012a..2ee05ab0a4 100644 --- a/fdbserver/OldTLogServer_6_0.actor.cpp +++ b/fdbserver/OldTLogServer_6_0.actor.cpp @@ -1277,20 +1277,21 @@ ACTOR Future commitQueue( TLogData* self ) { } } -ACTOR Future execProcessingHelper(TLogData* self, - Reference logData, - TLogCommitRequest* req, - Standalone>* execTags, - ExecCmdValueString* execArg, - StringRef* execCmd, - Version* execVersion, - vector>* snapFailKeySetters) +void execProcessingHelper(TLogData* self, + Reference logData, + TLogCommitRequest* req, + Standalone>* execTags, + ExecCmdValueString* execArg, + StringRef* execCmd, + Version* execVersion, + vector>* snapFailKeySetters, + vector>* ignoredPops) { // inspect the messages to find if there is an Exec type and print // it. message are prefixed by the length of the message and each // field is prefixed by the length too uint8_t type = MutationRef::MAX_ATOMIC_OP; - state StringRef param2; + StringRef param2; ArenaReader rd(req->arena, req->messages, Unversioned()); int32_t messageLength, rawLength; uint16_t tagCount; @@ -1327,17 +1328,19 @@ ACTOR Future execProcessingHelper(TLogData* self, rd >> len; param2 = StringRef((uint8_t const*)rd.readBytes(len), len); - TraceEvent(SevDebug, "TLogExecCommandType", self->dbgid).detail("Value", execCmd->toString()); + TraceEvent(SevDebug, "TLogExecCommandType", self->dbgid) + .detail("Value", execCmd->toString()) + .detail("Version", req->version); execArg->setCmdValueString(param2); execArg->dbgPrint(); - state StringRef uidStr = execArg->getBinaryArgValue(LiteralStringRef("uid")); + StringRef uidStr = execArg->getBinaryArgValue(LiteralStringRef("uid")); if (!execCmd->startsWith(LiteralStringRef("\xff"))) { *execVersion = req->version; } if (*execCmd == execSnap) { // validation check specific to snap request - state std::string reason; + std::string reason; if (!self->ignorePopRequest) { *execVersion = invalidVersion; reason = "SnapFailIgnorePopNotSet"; @@ -1350,13 +1353,15 @@ ACTOR Future execProcessingHelper(TLogData* self, TraceEvent(SevWarn, "TLogSnapFailed") .detail("IgnorePopUid", self->ignorePopUid) .detail("IgnorePopRequest", self->ignorePopRequest) - .detail("Reason", reason); + .detail("Reason", reason) + .detail("Version", req->version); TraceEvent("ExecCmdSnapCreate") .detail("Uid", uidStr.toString()) .detail("Status", -1) .detail("Tag", logData->allTags.begin()->toString()) - .detail("Role", "TLog"); + .detail("Role", "TLog") + .detail("Version", req->version); if (g_network->isSimulated()) { // write SnapFailedTLog.$UID Standalone keyStr = snapTestFailStatus.withSuffix(uidStr); @@ -1372,7 +1377,8 @@ ACTOR Future execProcessingHelper(TLogData* self, if (self->ignorePopUid != "") { TraceEvent(SevWarn, "TLogPopDisableonDisable") .detail("IgnorePopUid", self->ignorePopUid) - .detail("UidStr", uidStr.toString()); + .detail("UidStr", uidStr.toString()) + .detail("Version", req->version); } self->ignorePopUid = uidStr.toString(); // ignorePopRequest will be turned off after 30 seconds @@ -1382,19 +1388,20 @@ ACTOR Future execProcessingHelper(TLogData* self, .detail("UidStr", uidStr.toString()) .detail("IgnorePopUid", self->ignorePopUid) .detail("IgnporePopRequest", self->ignorePopRequest) - .detail("IgnporePopDeadline", self->ignorePopDeadline); + .detail("IgnporePopDeadline", self->ignorePopDeadline) + .detail("Version", req->version); } if (*execCmd == execEnableTLogPop) { if (self->ignorePopUid != uidStr.toString()) { TraceEvent(SevWarn, "TLogPopDisableEnableUidMismatch") .detail("IgnorePopUid", self->ignorePopUid) - .detail("UidStr", uidStr.toString()); + .detail("UidStr", uidStr.toString()) + .detail("Version", req->version); } TraceEvent("EnableTLogPlayAllIgnoredPops2"); // use toBePopped and issue all the pops - state std::map::iterator it; - state vector> ignoredPops; + std::map::iterator it; self->ignorePopRequest = false; self->ignorePopDeadline = 0.0; self->ignorePopUid = ""; @@ -1402,19 +1409,18 @@ ACTOR Future execProcessingHelper(TLogData* self, TraceEvent("PlayIgnoredPop") .detail("Tag", it->first.toString()) .detail("Version", it->second); - ignoredPops.push_back(tLogPopCore(self, it->first, it->second, logData)); + ignoredPops->push_back(tLogPopCore(self, it->first, it->second, logData)); } self->toBePopped.clear(); - wait(waitForAll(ignoredPops)); TraceEvent("TLogExecCmdPopEnable") .detail("ExecCmd", execCmd->toString()) .detail("UidStr", uidStr.toString()) .detail("IgnorePopUid", self->ignorePopUid) .detail("IgnporePopRequest", self->ignorePopRequest) - .detail("IgnporePopDeadline", self->ignorePopDeadline); + .detail("IgnporePopDeadline", self->ignorePopDeadline) + .detail("Version", req->version); } } - return Void(); } @@ -1528,6 +1534,7 @@ ACTOR Future tLogCommit( state StringRef execCmd; state Standalone> execTags; state vector> snapFailKeySetters; + state vector> playIgnoredPops; if (logData->version.get() == req.prevVersion) { // Not a duplicate (check relies on no waiting between here and self->version.set() below!) if(req.debugID.present()) @@ -1540,7 +1547,7 @@ ACTOR Future tLogCommit( qe.id = logData->logId; if (req.hasExecOp) { - wait(execProcessingHelper(self, logData, &req, &execTags, &execArg, &execCmd, &execVersion, &snapFailKeySetters)); + execProcessingHelper(self, logData, &req, &execTags, &execArg, &execCmd, &execVersion, &snapFailKeySetters, &playIgnoredPops); if (execVersion != invalidVersion) { TraceEvent(SevDebug, "SettingExecOpCommit") .detail("ExecVersion", execVersion) @@ -1564,7 +1571,7 @@ ACTOR Future tLogCommit( // Notifies the commitQueue actor to commit persistentQueue, and also unblocks tLogPeekMessages actors logData->version.set( req.version ); - + wait(waitForAll(playIgnoredPops)); if(req.debugID.present()) g_traceBatch.addEvent("CommitDebug", tlogDebugID.get().first(), "TLog.tLogCommit.AfterTLogCommit"); diff --git a/fdbserver/TLogServer.actor.cpp b/fdbserver/TLogServer.actor.cpp index b0ec62186c..b6cfe3d21e 100644 --- a/fdbserver/TLogServer.actor.cpp +++ b/fdbserver/TLogServer.actor.cpp @@ -1644,20 +1644,21 @@ ACTOR Future commitQueue( TLogData* self ) { } } -ACTOR Future execProcessingHelper(TLogData* self, - Reference logData, - TLogCommitRequest* req, - Standalone>* execTags, - ExecCmdValueString* execArg, - StringRef* execCmd, - Version* execVersion, - vector>* snapFailKeySetters) +void execProcessingHelper(TLogData* self, + Reference logData, + TLogCommitRequest* req, + Standalone>* execTags, + ExecCmdValueString* execArg, + StringRef* execCmd, + Version* execVersion, + vector>* snapFailKeySetters, + vector>* ignoredPops) { // inspect the messages to find if there is an Exec type and print // it. message are prefixed by the length of the message and each // field is prefixed by the length too uint8_t type = MutationRef::MAX_ATOMIC_OP; - state StringRef param2; + StringRef param2; ArenaReader rd(req->arena, req->messages, Unversioned()); int32_t messageLength, rawLength; uint16_t tagCount; @@ -1694,17 +1695,19 @@ ACTOR Future execProcessingHelper(TLogData* self, rd >> len; param2 = StringRef((uint8_t const*)rd.readBytes(len), len); - TraceEvent(SevDebug, "TLogExecCommandType", self->dbgid).detail("Value", execCmd->toString()); + TraceEvent(SevDebug, "TLogExecCommandType", self->dbgid) + .detail("Value", execCmd->toString()) + .detail("Version", req->version); execArg->setCmdValueString(param2); execArg->dbgPrint(); - state StringRef uidStr = execArg->getBinaryArgValue(LiteralStringRef("uid")); + StringRef uidStr = execArg->getBinaryArgValue(LiteralStringRef("uid")); if (!execCmd->startsWith(LiteralStringRef("\xff"))) { *execVersion = req->version; } if (*execCmd == execSnap) { // validation check specific to snap request - state std::string reason; + std::string reason; if (!self->ignorePopRequest) { *execVersion = invalidVersion; reason = "SnapFailIgnorePopNotSet"; @@ -1717,13 +1720,15 @@ ACTOR Future execProcessingHelper(TLogData* self, TraceEvent(SevWarn, "TLogSnapFailed") .detail("IgnorePopUid", self->ignorePopUid) .detail("IgnorePopRequest", self->ignorePopRequest) - .detail("Reason", reason); + .detail("Reason", reason) + .detail("Version", req->version); TraceEvent("ExecCmdSnapCreate") .detail("Uid", uidStr.toString()) .detail("Status", -1) .detail("Tag", logData->allTags.begin()->toString()) - .detail("Role", "TLog"); + .detail("Role", "TLog") + .detail("Version", req->version); if (g_network->isSimulated()) { // write SnapFailedTLog.$UID @@ -1740,7 +1745,8 @@ ACTOR Future execProcessingHelper(TLogData* self, if (self->ignorePopUid != "") { TraceEvent(SevWarn, "TLogPopDisableonDisable") .detail("IgnorePopUid", self->ignorePopUid) - .detail("UidStr", uidStr.toString()); + .detail("UidStr", uidStr.toString()) + .detail("Version", req->version); } self->ignorePopUid = uidStr.toString(); // ignorePopRequest will be turned off after 30 seconds @@ -1750,19 +1756,20 @@ ACTOR Future execProcessingHelper(TLogData* self, .detail("UidStr", uidStr.toString()) .detail("IgnorePopUid", self->ignorePopUid) .detail("IgnporePopRequest", self->ignorePopRequest) - .detail("IgnporePopDeadline", self->ignorePopDeadline); + .detail("IgnporePopDeadline", self->ignorePopDeadline) + .detail("Version", req->version); } if (*execCmd == execEnableTLogPop) { if (self->ignorePopUid != uidStr.toString()) { TraceEvent(SevWarn, "TLogPopDisableEnableUidMismatch") .detail("IgnorePopUid", self->ignorePopUid) - .detail("UidStr", uidStr.toString()); + .detail("UidStr", uidStr.toString()) + .detail("Version", req->version); } TraceEvent("EnableTLogPlayAllIgnoredPops2"); // use toBePopped and issue all the pops - state std::map::iterator it; - state vector> ignoredPops; + std::map::iterator it; self->ignorePopRequest = false; self->ignorePopDeadline = 0.0; self->ignorePopUid = ""; @@ -1770,19 +1777,18 @@ ACTOR Future execProcessingHelper(TLogData* self, TraceEvent("PlayIgnoredPop") .detail("Tag", it->first.toString()) .detail("Version", it->second); - ignoredPops.push_back(tLogPopCore(self, it->first, it->second, logData)); + ignoredPops->push_back(tLogPopCore(self, it->first, it->second, logData)); } self->toBePopped.clear(); - wait(waitForAll(ignoredPops)); TraceEvent("TLogExecCmdPopEnable") .detail("ExecCmd", execCmd->toString()) .detail("UidStr", uidStr.toString()) .detail("IgnorePopUid", self->ignorePopUid) .detail("IgnporePopRequest", self->ignorePopRequest) - .detail("IgnporePopDeadline", self->ignorePopDeadline); + .detail("IgnporePopDeadline", self->ignorePopDeadline) + .detail("Version", req->version); } } - return Void(); } ACTOR Future tLogSnapHelper(TLogData* self, @@ -1894,6 +1900,7 @@ ACTOR Future tLogCommit( state TLogQueueEntryRef qe; state StringRef execCmd; state Standalone> execTags; + state vector> playIgnoredPops; if (logData->version.get() == req.prevVersion) { // Not a duplicate (check relies on no waiting between here and self->version.set() below!) if(req.debugID.present()) @@ -1907,7 +1914,7 @@ ACTOR Future tLogCommit( state vector> snapFailKeySetters; if (req.hasExecOp) { - wait(execProcessingHelper(self, logData, &req, &execTags, &execArg, &execCmd, &execVersion, &snapFailKeySetters)); + execProcessingHelper(self, logData, &req, &execTags, &execArg, &execCmd, &execVersion, &snapFailKeySetters, &playIgnoredPops); if (execVersion != invalidVersion) { TraceEvent(SevDebug, "SettingExecOpCommit") .detail("ExecVersion", execVersion) @@ -1931,6 +1938,7 @@ ACTOR Future tLogCommit( // Notifies the commitQueue actor to commit persistentQueue, and also unblocks tLogPeekMessages actors logData->version.set( req.version ); + wait(waitForAll(playIgnoredPops)); if(req.debugID.present()) g_traceBatch.addEvent("CommitDebug", tlogDebugID.get().first(), "TLog.tLogCommit.AfterTLogCommit");