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 #8173

Merged
merged 3 commits into from
Sep 15, 2022
Merged
Changes from 2 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
51 changes: 51 additions & 0 deletions fdbserver/storageserver.actor.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -1122,6 +1122,12 @@ struct StorageServer {
Counter changeFeedDiskReads;

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 @@ -1159,6 +1165,26 @@ struct StorageServer {
self->thisServerID,
SERVER_KNOBS->LATENCY_METRICS_LOGGING_INTERVAL,
SERVER_KNOBS->LATENCY_SAMPLE_SIZE),
readKeyLatencySample("ReadKeyLatencyMetrics",
sfc-gh-satherton marked this conversation as resolved.
Show resolved Hide resolved
self->thisServerID,
SERVER_KNOBS->LATENCY_METRICS_LOGGING_INTERVAL,
SERVER_KNOBS->LATENCY_SAMPLE_SIZE),
readValueLatencySample("ReadValueLatencyMetrics",
self->thisServerID,
SERVER_KNOBS->LATENCY_METRICS_LOGGING_INTERVAL,
SERVER_KNOBS->LATENCY_SAMPLE_SIZE),
readRangeLatencySample("ReadRangeLatencyMetrics",
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 @@ -1837,6 +1863,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.options.present() && req.options.get().debugID.present())
g_traceBatch.addEvent("GetValueDebug",
req.options.get().debugID.get().first(),
Expand All @@ -1845,6 +1875,8 @@ 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.options.present() && req.options.get().debugID.present())
g_traceBatch.addEvent("GetValueDebug",
req.options.get().debugID.get().first(),
Expand Down Expand Up @@ -1940,6 +1972,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 @@ -3732,13 +3765,18 @@ 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.options.present() && req.options.get().debugID.present())
g_traceBatch.addEvent(
"TransactionDebug", req.options.get().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 @@ -3882,6 +3920,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 @@ -4479,13 +4518,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.options.present() && req.options.get().debugID.present())
g_traceBatch.addEvent(
"TransactionDebug", req.options.get().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 @@ -4899,9 +4943,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);
sfc-gh-satherton marked this conversation as resolved.
Show resolved Hide resolved

state Optional<TenantMapEntry> tenantEntry = data->getTenantEntry(version, req.tenantInfo);
if (tenantEntry.present()) {
Expand Down Expand Up @@ -4971,6 +5020,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