clean up some more trace lines and leftover code snippets

This commit is contained in:
Jon Fu 2022-02-07 14:50:04 -05:00
parent 6d05ecffc2
commit ec2bbf0343
6 changed files with 8 additions and 33 deletions

View File

@ -123,7 +123,7 @@ void ClientKnobs::initialize(Randomize randomize) {
init( FORCE_GRV_CACHE_OFF, false );
init( GRV_CACHE_RK_COOLDOWN, 60.0 );
init( GRV_THROTTLING_THRESHOLD, 2 );
init( GRV_SUSTAINED_THROTTLING_THRESHOLD, 1.0 );
init( GRV_SUSTAINED_THROTTLING_THRESHOLD, 0.1 );
// TaskBucket
init( TASKBUCKET_LOGGING_DELAY, 5.0 );

View File

@ -1177,6 +1177,7 @@ MultiVersionDatabase::MultiVersionDatabase(MultiVersionApi* api,
: dbState(new DatabaseState(clusterFilePath, versionMonitorDb)) {
dbState->db = db;
dbState->dbVar->set(db);
if (openConnectors) {
if (!api->localClientDisabled) {
dbState->addClient(api->getLocalClient());

View File

@ -108,7 +108,6 @@ struct FdbCApi : public ThreadSafeReferenceCounted<FdbCApi> {
int uidLength,
uint8_t const* snapshotCommmand,
int snapshotCommandLength);
double (*databaseGetMainThreadBusyness)(FDBDatabase* database);
FDBFuture* (*databaseGetServerProtocol)(FDBDatabase* database, uint64_t expectedVersion);

View File

@ -31,7 +31,6 @@
#include "contrib/fmt-8.0.1/include/fmt/format.h"
#include "fdbclient/FDBTypes.h"
#include "fdbclient/Knobs.h"
#include "fdbrpc/FailureMonitor.h"
#include "fdbrpc/MultiInterface.h"
@ -65,14 +64,12 @@
#include "fdbrpc/Net2FileSystem.h"
#include "fdbrpc/simulator.h"
#include "fdbrpc/sim_validation.h"
#include "fdbserver/Knobs.h"
#include "flow/Arena.h"
#include "flow/ActorCollection.h"
#include "flow/DeterministicRandom.h"
#include "flow/Error.h"
#include "flow/FastRef.h"
#include "flow/IRandom.h"
#include "flow/Trace.h"
#include "flow/flow.h"
#include "flow/genericactors.actor.h"
#include "flow/Knobs.h"
@ -1038,20 +1035,13 @@ ACTOR static Future<Void> handleTssMismatches(DatabaseContext* cx) {
ACTOR static Future<Void> backgroundGrvUpdater(DatabaseContext* cx) {
state Transaction tr;
state double grvDelay = 0.001;
TraceEvent("BackgroundGrvUpdaterStart").detail("DBID", cx->dbId).detail("GrvDelay", grvDelay);
TraceEvent("DebugGrvCheckKnobValues")
.detail("MinTraceSeverity", FLOW_KNOBS->MIN_TRACE_SEVERITY)
.detail("GrvSustainedThrottlingThreshold", CLIENT_KNOBS->GRV_SUSTAINED_THROTTLING_THRESHOLD)
.detail("GrvCacheRkCooldown", CLIENT_KNOBS->GRV_CACHE_RK_COOLDOWN)
.detail("MaxVersionCacheLag", CLIENT_KNOBS->MAX_VERSION_CACHE_LAG)
.detail("DebugUseGrvCacheChance", CLIENT_KNOBS->DEBUG_USE_GRV_CACHE_CHANCE);
try {
loop {
wait(refreshTransaction(cx, &tr));
state double curTime = now();
state double lastTime = cx->getLastTimedGRV();
state double lastProxyTime = cx->lastProxyRequest;
TraceEvent("BackgroundGrvUpdaterBefore")
TraceEvent(SevDebug, "BackgroundGrvUpdaterBefore")
.detail("CurTime", curTime)
.detail("LastTime", lastTime)
.detail("GrvDelay", grvDelay)
@ -1066,12 +1056,12 @@ ACTOR static Future<Void> backgroundGrvUpdater(DatabaseContext* cx) {
wait(success(tr.getReadVersion()));
cx->lastProxyRequest = curTime;
grvDelay = (grvDelay + (now() - curTime)) / 2.0;
TraceEvent("BackgroundGrvUpdaterSuccess")
TraceEvent(SevDebug, "BackgroundGrvUpdaterSuccess")
.detail("GrvDelay", grvDelay)
.detail("CachedRv", cx->getCachedRV())
.detail("CachedTime", cx->getLastTimedGRV());
} catch (Error& e) {
TraceEvent("BackgroundGrvUpdaterTxnError").error(e, true);
TraceEvent(SevInfo, "BackgroundGrvUpdaterTxnError").error(e, true);
wait(tr.onError(e));
}
} else {
@ -1079,7 +1069,7 @@ ACTOR static Future<Void> backgroundGrvUpdater(DatabaseContext* cx) {
}
}
} catch (Error& e) {
TraceEvent("BackgroundGrvUpdaterFailed").error(e, true);
TraceEvent(SevInfo, "BackgroundGrvUpdaterFailed").error(e, true);
throw;
}
}
@ -5950,11 +5940,7 @@ ACTOR Future<Version> extractReadVersion(Reference<TransactionState> trState,
double latency = now() - trState->startTime;
trState->cx->lastProxyRequest = trState->startTime;
trState->cx->updateCachedRV(trState->startTime, rep.version);
TraceEvent("DebugGrvQueueIterations").detail("TimeThrottled", rep.queueIterations);
if (rep.rkThrottled && trState->options.priority != TransactionPriority::IMMEDIATE) {
TraceEvent("DebugGrvThrottleObserved")
.detail("TimeThrottled", rep.queueIterations)
.detail("Threshold", CLIENT_KNOBS->GRV_THROTTLING_THRESHOLD);
trState->cx->lastTimedRkThrottle = now();
}
trState->cx->GRVLatencies.addSample(latency);
@ -6017,10 +6003,6 @@ bool rkThrottlingCooledDown(DatabaseContext* cx) {
if (cx->lastTimedRkThrottle == 0.0) {
return true;
}
TraceEvent("DebugGrvRkCd")
.detail("LastTimedRkThrottle", cx->lastTimedRkThrottle)
.detail("TimeElapsed", now() - cx->lastTimedRkThrottle)
.detail("CooldownTime", CLIENT_KNOBS->GRV_CACHE_RK_COOLDOWN);
return (now() - cx->lastTimedRkThrottle > CLIENT_KNOBS->GRV_CACHE_RK_COOLDOWN);
}
@ -6030,7 +6012,6 @@ Future<Version> Transaction::getReadVersion(uint32_t flags) {
(deterministicRandom()->random01() <= CLIENT_KNOBS->DEBUG_USE_GRV_CACHE_CHANCE ||
trState->options.useGrvCache) &&
rkThrottlingCooledDown(getDatabase().getPtr())) {
TraceEvent("DebugGrvEnterCachePath");
// Upon our first request to use cached RVs, start the background updater
if (!trState->cx->grvUpdateHandler.isValid()) {
trState->cx->grvUpdateHandler = backgroundGrvUpdater(getDatabase().getPtr());
@ -6039,7 +6020,6 @@ Future<Version> Transaction::getReadVersion(uint32_t flags) {
double lastTime = trState->cx->getLastTimedGRV();
double requestTime = now();
if (requestTime - lastTime <= CLIENT_KNOBS->MAX_VERSION_CACHE_LAG && rv != Version(0)) {
TraceEvent("DebugGrvUseCache").detail("LastRV", rv).detail("LastTime", format("%.6f", lastTime));
ASSERT(!debug_checkVersionTime(rv, requestTime, "CheckStaleness"));
readVersion = rv;
return readVersion;

View File

@ -654,7 +654,7 @@ ACTOR Future<Void> sendGrvReplies(Future<GetReadVersionReply> replyFuture,
}
reply.queueIterations = request.queueIterations;
TraceEvent("DebugGrvProxyThrottleCheck")
TraceEvent(SevDebug, "DebugGrvProxyThrottleCheck")
.detail("QueueIterations", reply.queueIterations)
.detail("ThrottleThreshold", CLIENT_KNOBS->GRV_THROTTLING_THRESHOLD)
.detail("LastTxnThrottled", stats->lastTxnThrottled)
@ -662,23 +662,18 @@ ACTOR Future<Void> sendGrvReplies(Future<GetReadVersionReply> replyFuture,
.detail("Diff", now() - stats->throttleStartTime)
.detail("SustainedThrottlingThreshold", CLIENT_KNOBS->GRV_SUSTAINED_THROTTLING_THRESHOLD);
if (reply.queueIterations >= CLIENT_KNOBS->GRV_THROTTLING_THRESHOLD) {
TraceEvent("DebugGrvProxyThrottled");
if (stats->lastTxnThrottled) {
TraceEvent("DebugGrvProxyLastTxnThrottled");
// Check if this throttling has been sustained for a certain amount of time to avoid false positives
if (now() - stats->throttleStartTime > CLIENT_KNOBS->GRV_SUSTAINED_THROTTLING_THRESHOLD) {
TraceEvent("DebugGrvProxyRkThrottled");
reply.rkThrottled = true;
}
} else { // !stats->lastTxnThrottled
TraceEvent("DebugGrvProxyLastTxnNotThrottled");
// If not previously throttled, this request/reply is our new starting point
// for judging whether we are being actively throttled by ratekeeper now
stats->lastTxnThrottled = true;
stats->throttleStartTime = now();
}
} else {
TraceEvent("DebugGrvProxyNotThrottled");
stats->lastTxnThrottled = false;
}
request.reply.send(reply);

View File

@ -3,7 +3,7 @@
*
* This source file is part of the FoundationDB open source project
*
* Copyright 2013-2018 Apple Inc. and the FoundationDB project authors
* Copyright 2013-2022 Apple Inc. and the FoundationDB project authors
*
* Licensed under the Apache License, Version 2.0 (the "License");
* you may not use this file except in compliance with the License.