From 6f1c3d50bb2060d821533b1751b57bcd86dcb5c1 Mon Sep 17 00:00:00 2001 From: Jon Fu Date: Tue, 15 Feb 2022 15:08:53 -0500 Subject: [PATCH] add debug traces for testing --- fdbclient/NativeAPI.actor.cpp | 2 ++ fdbserver/GrvProxyServer.actor.cpp | 4 ++++ 2 files changed, 6 insertions(+) diff --git a/fdbclient/NativeAPI.actor.cpp b/fdbclient/NativeAPI.actor.cpp index 8070c23a66..5fe063616b 100644 --- a/fdbclient/NativeAPI.actor.cpp +++ b/fdbclient/NativeAPI.actor.cpp @@ -5968,9 +5968,11 @@ ACTOR Future extractReadVersion(Reference trState, trState->cx->lastProxyRequestTime = trState->startTime; trState->cx->updateCachedReadVersion(trState->startTime, rep.version); if (rep.rkBatchThrottled) { + TraceEvent("DebugGrvLastRkBatchThrottled").detail("ReplyTime", replyTime); trState->cx->lastRkBatchThrottleTime = replyTime; } if (rep.rkDefaultThrottled) { + TraceEvent("DebugGrvLastRkDefaultThrottled").detail("ReplyTime", replyTime); trState->cx->lastRkDefaultThrottleTime = replyTime; } trState->cx->GRVLatencies.addSample(latency); diff --git a/fdbserver/GrvProxyServer.actor.cpp b/fdbserver/GrvProxyServer.actor.cpp index 6fe559d02d..4aae181e57 100644 --- a/fdbserver/GrvProxyServer.actor.cpp +++ b/fdbserver/GrvProxyServer.actor.cpp @@ -659,6 +659,7 @@ ACTOR Future sendGrvReplies(Future replyFuture, if (stats->lastBatchQueueThrottled) { // Check if this throttling has been sustained for a certain amount of time to avoid false positives if (now() - stats->batchThrottleStartTime > CLIENT_KNOBS->GRV_SUSTAINED_THROTTLING_THRESHOLD) { + TraceEvent("DebugGrvProxyBatchThrottled").detail("StartTime", stats->batchThrottleStartTime); reply.rkBatchThrottled = true; } } @@ -668,6 +669,7 @@ ACTOR Future sendGrvReplies(Future replyFuture, // Consider the batch queue throttled if the default is throttled // to deal with a potential lull in activity for that priority. // Avoids mistakenly thinking batch is unthrottled while default is still throttled. + TraceEvent("DebugGrvProxyDefaultThrottled").detail("StartTime", stats->defaultThrottleStartTime); reply.rkBatchThrottled = true; reply.rkDefaultThrottled = true; } @@ -869,12 +871,14 @@ ACTOR static Future transactionStarter(GrvProxyInterface proxy, requestsToStart++; } if (!batchQueue.empty()) { + TraceEvent("DebugGrvProxyBatchQueueEmpty").detail("Size", batchQueue.size()); grvProxyData->stats.lastBatchQueueThrottled = true; grvProxyData->stats.batchThrottleStartTime = now(); } else { grvProxyData->stats.lastBatchQueueThrottled = false; } if (!defaultQueue.empty()) { + TraceEvent("DebugGrvProxyDefaultQueueEmpty").detail("Size", defaultQueue.size()); grvProxyData->stats.lastDefaultQueueThrottled = true; grvProxyData->stats.defaultThrottleStartTime = now(); } else {