wbtiger
/
foundationdb
mirror of https://github.com/apple/foundationdb.git
1
0
Fork 0
Code Issues Packages Projects Releases Wiki Activity

FastRestore:Suppress or mute spammy trace events

This commit is contained in:
Meng Xu 2020-06-24 22:10:54 -07:00
parent c13ba7aeb4
commit 5860a5b4db
6 changed files with 27 additions and 23 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

17
fdbserver/RestoreApplier.actor.cpp
View File

@ -114,8 +114,7 @@ ACTOR static Future<Void> handleSendMutationVectorRequest(RestoreSendVersionedMu
// Note: Insert new items into processedFileState will not invalidate the reference.
state NotifiedVersion& curMsgIndex = batchData->processedFileState[req.asset];
TraceEvent(SevInfo, "FastRestoreApplierPhaseReceiveMutations", self->id())
.suppressFor(1.0)
TraceEvent(SevFRDebugInfo, "FastRestoreApplierPhaseReceiveMutations", self->id())
.detail("BatchIndex", req.batchIndex)
.detail("RestoreAsset", req.asset.toString())
.detail("RestoreAssetMesssageIndex", curMsgIndex.get())
@ -134,7 +133,7 @@ ACTOR static Future<Void> handleSendMutationVectorRequest(RestoreSendVersionedMu
for (int mIndex = 0; mIndex < req.versionedMutations.size(); mIndex++) {
const VersionedMutation& versionedMutation = req.versionedMutations[mIndex];
TraceEvent(SevFRMutationInfo, "FastRestoreApplierPhaseReceiveMutations", self->id())
TraceEvent(SevFRDebugInfo, "FastRestoreApplierPhaseReceiveMutations", self->id())
.detail("RestoreAsset", req.asset.toString())
.detail("Version", versionedMutation.version.toString())
.detail("Index", mIndex)
@ -160,8 +159,7 @@ ACTOR static Future<Void> handleSendMutationVectorRequest(RestoreSendVersionedMu
}
req.reply.send(RestoreCommonReply(self->id(), isDuplicated));
TraceEvent(SevInfo, "FastRestoreApplierPhaseReceiveMutationsDone", self->id())
.suppressFor(1.0)
TraceEvent(SevFRDebugInfo, "FastRestoreApplierPhaseReceiveMutationsDone", self->id())
.detail("BatchIndex", req.batchIndex)
.detail("RestoreAsset", req.asset.toString())
.detail("ProcessedMessageIndex", curMsgIndex.get())
@ -190,8 +188,8 @@ ACTOR static Future<Void> applyClearRangeMutations(Standalone<VectorRef<KeyRange
tr->clear(range);
++numOps;
if (numOps >= SERVER_KNOBS->FASTRESTORE_TXN_CLEAR_MAX) {
TraceEvent(SevWarnAlways, "FastRestoreApplierClearRangeMutationsTooManyClearsInTxn")
.suppressFor(1.0)
TraceEvent(SevWarn, "FastRestoreApplierClearRangeMutationsTooManyClearsInTxn")
.suppressFor(5.0)
.detail("Clears", numOps)
.detail("Ranges", ranges.size())
.detail("Range", range.toString());
@ -257,6 +255,7 @@ ACTOR static Future<Void> getAndComputeStagingKeys(
if (!fValues[i].get().present()) { // Key not exist in DB
// if condition: fValues[i].Valid() && fValues[i].isReady() && !fValues[i].isError() &&
TraceEvent(SevWarn, "FastRestoreApplierGetAndComputeStagingKeysNoBaseValueInDB", applierID)
.suppressFor(5.0)
.detail("BatchIndex", batchIndex)
.detail("Key", key.first)
.detail("IsReady", fValues[i].isReady())
@ -408,7 +407,7 @@ ACTOR static Future<Void> applyStagingKeysBatch(std::map<Key, StagingKey>::itera
state int sets = 0;
state int clears = 0;
state Key endKey = begin->second.key;
TraceEvent("FastRestoreApplierPhaseApplyStagingKeysBatch", applierID).detail("Begin", begin->first);
TraceEvent(SevFRDebugInfo, "FastRestoreApplierPhaseApplyStagingKeysBatch", applierID).detail("Begin", begin->first);
loop {
try {
tr->setOption(FDBTransactionOptions::ACCESS_SYSTEM_KEYS);
@ -444,7 +443,7 @@ ACTOR static Future<Void> applyStagingKeysBatch(std::map<Key, StagingKey>::itera
.detail("Clears", clears);
}
}
TraceEvent("FastRestoreApplierPhaseApplyStagingKeysBatchPrecommit", applierID)
TraceEvent(SevFRDebugInfo, "FastRestoreApplierPhaseApplyStagingKeysBatchPrecommit", applierID)
.detail("Begin", begin->first)
.detail("End", endKey)
.detail("Sets", sets)

10
fdbserver/RestoreLoader.actor.cpp
View File

@ -352,7 +352,7 @@ ACTOR Future<Void> handleLoadFileRequest(RestoreLoadFileRequest req, Reference<R
bool paramExist = batchData->processedFileParams.find(req.param) != batchData->processedFileParams.end();
bool isReady = paramExist ? batchData->processedFileParams[req.param].isReady() : false;
TraceEvent("FastRestoreLoaderPhaseLoadFile", self->id())
TraceEvent(SevFRDebugInfo, "FastRestoreLoaderPhaseLoadFile", self->id())
.detail("BatchIndex", req.batchIndex)
.detail("ProcessLoadParam", req.param.toString())
.detail("NotProcessed", !paramExist)
@ -364,7 +364,7 @@ ACTOR Future<Void> handleLoadFileRequest(RestoreLoadFileRequest req, Reference<R
wait(isSchedulable(self, req.batchIndex, __FUNCTION__));
if (batchData->processedFileParams.find(req.param) == batchData->processedFileParams.end()) {
TraceEvent("FastRestoreLoadFile", self->id())
TraceEvent(SevFRDebugInfo, "FastRestoreLoadFile", self->id())
.detail("BatchIndex", req.batchIndex)
.detail("ProcessLoadParam", req.param.toString());
ASSERT(batchData->sampleMutations.find(req.param) == batchData->sampleMutations.end());
@ -372,7 +372,7 @@ ACTOR Future<Void> handleLoadFileRequest(RestoreLoadFileRequest req, Reference<R
_processLoadingParam(&self->rangeVersions, req.param, batchData, self->id(), self->bc);
isDuplicated = false;
} else {
TraceEvent("FastRestoreLoadFile", self->id())
TraceEvent(SevFRDebugInfo, "FastRestoreLoadFile", self->id())
.detail("BatchIndex", req.batchIndex)
.detail("WaitOnProcessLoadParam", req.param.toString());
}
@ -381,7 +381,7 @@ ACTOR Future<Void> handleLoadFileRequest(RestoreLoadFileRequest req, Reference<R
wait(it->second); // wait on the processing of the req.param.
req.reply.send(RestoreLoadFileReply(req.param, batchData->sampleMutations[req.param], isDuplicated));
TraceEvent("FastRestoreLoaderPhaseLoadFileDone", self->id())
TraceEvent(SevFRDebugInfo, "FastRestoreLoaderPhaseLoadFileDone", self->id())
.detail("BatchIndex", req.batchIndex)
.detail("ProcessLoadParam", req.param.toString());
// TODO: clear self->sampleMutations[req.param] memory to save memory on loader
@ -855,7 +855,7 @@ ACTOR static Future<Void> _parseRangeFileToMutationsOnLoader(
state VersionedMutationsMap& kvOps = kvOpsIter->second;
state MutationsVec& sampleMutations = samplesIter->second;
TraceEvent("FastRestoreDecodedRangeFile")
TraceEvent(SevFRDebugInfo, "FastRestoreDecodedRangeFile")
.detail("Filename", asset.filename)
.detail("Version", version)
.detail("BeginVersion", asset.beginVersion)

8
fdbserver/RestoreMaster.actor.cpp
View File

@ -714,22 +714,22 @@ ACTOR static Future<Version> collectBackupFiles(Reference<IBackupContainer> bc,
std::set<RestoreFileFR> uniqueLogFiles;
*minRangeVersion = MAX_VERSION;
for (const RangeFile& f : restorable.get().ranges) {
TraceEvent("FastRestoreMasterPhaseCollectBackupFiles").detail("RangeFile", f.toString());
TraceEvent(SevFRDebugInfo, "FastRestoreMasterPhaseCollectBackupFiles").detail("RangeFile", f.toString());
if (f.fileSize <= 0) {
continue;
}
RestoreFileFR file(f);
TraceEvent("FastRestoreMasterPhaseCollectBackupFiles").detail("RangeFileFR", file.toString());
TraceEvent(SevFRDebugInfo, "FastRestoreMasterPhaseCollectBackupFiles").detail("RangeFileFR", file.toString());
uniqueRangeFiles.insert(file);
*minRangeVersion = std::min(*minRangeVersion, file.version);
}
for (const LogFile& f : restorable.get().logs) {
TraceEvent("FastRestoreMasterPhaseCollectBackupFiles").detail("LogFile", f.toString());
TraceEvent(SevFRDebugInfo, "FastRestoreMasterPhaseCollectBackupFiles").detail("LogFile", f.toString());
if (f.fileSize <= 0) {
continue;
}
RestoreFileFR file(f);
TraceEvent("FastRestoreMasterPhaseCollectBackupFiles").detail("LogFileFR", file.toString());
TraceEvent(SevFRDebugInfo, "FastRestoreMasterPhaseCollectBackupFiles").detail("LogFileFR", file.toString());
logFiles->push_back(file);
uniqueLogFiles.insert(file);
}

10
fdbserver/RestoreMaster.actor.h
View File

@ -214,7 +214,7 @@ struct RestoreMasterData : RestoreRoleData, public ReferenceCounted<RestoreMaste
int rangeIdx,
const std::vector<RestoreFileFR>& logFiles) {
double size = 0;
TraceEvent("FastRestoreGetVersionSize")
TraceEvent(SevDebug, "FastRestoreGetVersionSize")
.detail("PreviousVersion", prevVersion)
.detail("NextVersion", nextVersion)
.detail("RangeFiles", rangeFiles.size())
@ -281,7 +281,7 @@ struct RestoreMasterData : RestoreRoleData, public ReferenceCounted<RestoreMaste
if (logIdx < logFiles.size()) {
nextVersion = logFiles[logIdx].endVersion;
} else {
TraceEvent("FastRestoreBuildVersionBatch")
TraceEvent(SevFRDebugInfo, "FastRestoreBuildVersionBatch")
.detail("FinishAllLogFiles", logIdx)
.detail("CurBatchIndex", vb.batchIndex)
.detail("CurBatchSize", vb.size);
@ -309,7 +309,7 @@ struct RestoreMasterData : RestoreRoleData, public ReferenceCounted<RestoreMaste
std::tie(nextVersionSize, nextRangeIdx, curLogFiles) =
getVersionSize(prevEndVersion, nextVersion, rangeFiles, rangeIdx, logFiles);
TraceEvent("FastRestoreBuildVersionBatch")
TraceEvent(SevFRDebugInfo, "FastRestoreBuildVersionBatch")
.detail("BatchIndex", vb.batchIndex)
.detail("VersionBatchBeginVersion", vb.beginVersion)
.detail("PreviousEndVersion", prevEndVersion)
@ -378,13 +378,13 @@ struct RestoreMasterData : RestoreRoleData, public ReferenceCounted<RestoreMaste
ASSERT(prevEndVersion < nextVersion); // Ensure progress
nextVersion = (prevEndVersion + nextVersion) / 2;
rewriteNextVersion = true;
TraceEvent("FastRestoreBuildVersionBatch")
TraceEvent(SevFRDebugInfo, "FastRestoreBuildVersionBatch")
.detail("NextVersionIntervalSize", nextVersionSize); // Duplicate Trace
continue;
}
// Finalize the current version batch
versionBatches->emplace(vb.beginVersion, vb); // copy vb to versionBatch
TraceEvent("FastRestoreBuildVersionBatch")
TraceEvent(SevFRDebugInfo, "FastRestoreBuildVersionBatch")
.detail("FinishBatchIndex", vb.batchIndex)
.detail("VersionBatchBeginVersion", vb.beginVersion)
.detail("VersionBatchEndVersion", vb.endVersion)

2
fdbserver/RestoreRoleCommon.actor.cpp
View File

@ -114,6 +114,7 @@ ACTOR Future<Void> isSchedulable(Reference<RestoreRoleData> self, int actorBatch
if (memory < memoryThresholdBytes || self->finishedBatch.get() + 1 == actorBatchIndex) {
if (memory >= memoryThresholdBytes) {
TraceEvent(SevWarn, "FastRestoreMemoryUsageAboveThreshold", self->id())
.suppressFor(5.0)
.detail("Role", getRoleStr(self->role))
.detail("BatchIndex", actorBatchIndex)
.detail("FinishedBatch", self->finishedBatch.get())
@ -124,6 +125,7 @@ ACTOR Future<Void> isSchedulable(Reference<RestoreRoleData> self, int actorBatch
break;
} else {
TraceEvent(SevInfo, "FastRestoreMemoryUsageAboveThresholdWait", self->id())
.suppressFor(5.0)
.detail("Role", getRoleStr(self->role))
.detail("BatchIndex", actorBatchIndex)
.detail("Actor", name)

3
fdbserver/RestoreUtil.h
View File

@ -39,6 +39,9 @@
#define SevFRMutationInfo SevVerbose
//#define SevFRMutationInfo SevInfo
#define SevFRDebugInfo SevVerbose
//#define SevFRDebugInfo SevInfo
struct VersionedMutation {
MutationRef mutation;
LogMessageVersion version;