Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Add new latency samples for GetValue, GetRange, QueueWait, and VersionWait #8215

Merged
merged 3 commits into from Sep 17, 2022
Merged
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Jump to
Jump to file
Failed to load files.
Diff view
Diff view
52 changes: 52 additions & 0 deletions fdbserver/storageserver.actor.cpp
Expand Up @@ -939,6 +939,12 @@ struct StorageServer {
Counter kvCommits;

LatencySample readLatencySample;
LatencySample readKeyLatencySample;
LatencySample readValueLatencySample;
LatencySample readRangeLatencySample;
LatencySample readVersionWaitSample;
LatencySample readQueueWaitSample;

LatencyBands readLatencyBands;
LatencySample mappedRangeSample; // Samples getMappedRange latency
LatencySample mappedRangeRemoteSample; // Samples getMappedRange remote subquery latency
Expand Down Expand Up @@ -974,6 +980,26 @@ struct StorageServer {
self->thisServerID,
SERVER_KNOBS->LATENCY_METRICS_LOGGING_INTERVAL,
SERVER_KNOBS->LATENCY_SAMPLE_SIZE),
readKeyLatencySample("GetKeyMetrics",
self->thisServerID,
SERVER_KNOBS->LATENCY_METRICS_LOGGING_INTERVAL,
SERVER_KNOBS->LATENCY_SAMPLE_SIZE),
readValueLatencySample("GetValueMetrics",
self->thisServerID,
SERVER_KNOBS->LATENCY_METRICS_LOGGING_INTERVAL,
SERVER_KNOBS->LATENCY_SAMPLE_SIZE),
readRangeLatencySample("GetRangeMetrics",
self->thisServerID,
SERVER_KNOBS->LATENCY_METRICS_LOGGING_INTERVAL,
SERVER_KNOBS->LATENCY_SAMPLE_SIZE),
readVersionWaitSample("ReadVersionWaitMetrics",
self->thisServerID,
SERVER_KNOBS->LATENCY_METRICS_LOGGING_INTERVAL,
SERVER_KNOBS->LATENCY_SAMPLE_SIZE),
readQueueWaitSample("ReadQueueWaitMetrics",
self->thisServerID,
SERVER_KNOBS->LATENCY_METRICS_LOGGING_INTERVAL,
SERVER_KNOBS->LATENCY_SAMPLE_SIZE),
readLatencyBands("ReadLatencyBands", self->thisServerID, SERVER_KNOBS->STORAGE_LOGGING_DELAY),
mappedRangeSample("GetMappedRangeMetrics",
self->thisServerID,
Expand Down Expand Up @@ -1562,6 +1588,10 @@ ACTOR Future<Void> getValueQ(StorageServer* data, GetValueRequest req) {
// so we need to downgrade here
wait(data->getQueryDelay());

// Track time from requestTime through now as read queueing wait time
state double queueWaitEnd = g_network->timer();
data->counters.readQueueWaitSample.addMeasurement(queueWaitEnd - req.requestTime());

if (req.debugID.present())
g_traceBatch.addEvent("GetValueDebug",
req.debugID.get().first(),
Expand All @@ -1570,6 +1600,9 @@ ACTOR Future<Void> getValueQ(StorageServer* data, GetValueRequest req) {
state Optional<Value> v;
Version commitVersion = getLatestCommitVersion(req.ssLatestCommitVersions, data->tag);
state Version version = wait(waitForVersion(data, commitVersion, req.version, req.spanContext));

data->counters.readVersionWaitSample.addMeasurement(g_network->timer() - queueWaitEnd);

if (req.debugID.present())
g_traceBatch.addEvent("GetValueDebug",
req.debugID.get().first(),
Expand Down Expand Up @@ -1666,6 +1699,7 @@ ACTOR Future<Void> getValueQ(StorageServer* data, GetValueRequest req) {

double duration = g_network->timer() - req.requestTime();
data->counters.readLatencySample.addMeasurement(duration);
data->counters.readValueLatencySample.addMeasurement(duration);
if (data->latencyBandConfig.present()) {
int maxReadBytes =
data->latencyBandConfig.get().readConfig.maxReadBytes.orDefault(std::numeric_limits<int>::max());
Expand Down Expand Up @@ -3263,12 +3297,17 @@ ACTOR Future<Void> getKeyValuesQ(StorageServer* data, GetKeyValuesRequest req)
wait(data->getQueryDelay());
}

// Track time from requestTime through now as read queueing wait time
state double queueWaitEnd = g_network->timer();
data->counters.readQueueWaitSample.addMeasurement(queueWaitEnd - req.requestTime());

try {
if (req.debugID.present())
g_traceBatch.addEvent("TransactionDebug", req.debugID.get().first(), "storageserver.getKeyValues.Before");

Version commitVersion = getLatestCommitVersion(req.ssLatestCommitVersions, data->tag);
state Version version = wait(waitForVersion(data, commitVersion, req.version, span.context));
data->counters.readVersionWaitSample.addMeasurement(g_network->timer() - queueWaitEnd);

state Optional<TenantMapEntry> tenantEntry = data->getTenantEntry(version, req.tenantInfo);
state Optional<Key> tenantPrefix = tenantEntry.map<Key>([](TenantMapEntry e) { return e.prefix; });
Expand Down Expand Up @@ -3410,6 +3449,7 @@ ACTOR Future<Void> getKeyValuesQ(StorageServer* data, GetKeyValuesRequest req)

double duration = g_network->timer() - req.requestTime();
data->counters.readLatencySample.addMeasurement(duration);
data->counters.readRangeLatencySample.addMeasurement(duration);
if (data->latencyBandConfig.present()) {
int maxReadBytes =
data->latencyBandConfig.get().readConfig.maxReadBytes.orDefault(std::numeric_limits<int>::max());
Expand Down Expand Up @@ -3865,13 +3905,18 @@ ACTOR Future<Void> getMappedKeyValuesQ(StorageServer* data, GetMappedKeyValuesRe
wait(data->getQueryDelay());
}

// Track time from requestTime through now as read queueing wait time
state double queueWaitEnd = g_network->timer();
data->counters.readQueueWaitSample.addMeasurement(queueWaitEnd - req.requestTime());

try {
if (req.debugID.present())
g_traceBatch.addEvent(
"TransactionDebug", req.debugID.get().first(), "storageserver.getMappedKeyValues.Before");
// VERSION_VECTOR change
Version commitVersion = getLatestCommitVersion(req.ssLatestCommitVersions, data->tag);
state Version version = wait(waitForVersion(data, commitVersion, req.version, span.context));
data->counters.readVersionWaitSample.addMeasurement(g_network->timer() - queueWaitEnd);

state Optional<TenantMapEntry> tenantEntry = data->getTenantEntry(req.version, req.tenantInfo);
state Optional<Key> tenantPrefix = tenantEntry.map<Key>([](TenantMapEntry e) { return e.prefix; });
Expand Down Expand Up @@ -4276,9 +4321,14 @@ ACTOR Future<Void> getKeyQ(StorageServer* data, GetKeyRequest req) {
// so we need to downgrade here
wait(data->getQueryDelay());

// Track time from requestTime through now as read queueing wait time
state double queueWaitEnd = g_network->timer();
data->counters.readQueueWaitSample.addMeasurement(queueWaitEnd - req.requestTime());

try {
Version commitVersion = getLatestCommitVersion(req.ssLatestCommitVersions, data->tag);
state Version version = wait(waitForVersion(data, commitVersion, req.version, req.spanContext));
data->counters.readVersionWaitSample.addMeasurement(g_network->timer() - queueWaitEnd);

state Optional<TenantMapEntry> tenantEntry = data->getTenantEntry(version, req.tenantInfo);
if (tenantEntry.present()) {
Expand Down Expand Up @@ -4344,6 +4394,8 @@ ACTOR Future<Void> getKeyQ(StorageServer* data, GetKeyRequest req) {

double duration = g_network->timer() - req.requestTime();
data->counters.readLatencySample.addMeasurement(duration);
data->counters.readKeyLatencySample.addMeasurement(duration);

if (data->latencyBandConfig.present()) {
int maxReadBytes =
data->latencyBandConfig.get().readConfig.maxReadBytes.orDefault(std::numeric_limits<int>::max());
Expand Down