diff --git a/fdbserver/storageserver.actor.cpp b/fdbserver/storageserver.actor.cpp index eb542b4980..2c510d7634 100644 --- a/fdbserver/storageserver.actor.cpp +++ b/fdbserver/storageserver.actor.cpp @@ -1122,6 +1122,11 @@ public: Counter changeFeedDiskReads; LatencySample readLatencySample; + LatencySample readValueLatencySample; + LatencySample readRangeLatencySample; + LatencySample readVersionWaitSample; + LatencySample readQueueWaitSample; + LatencyBands readLatencyBands; LatencySample mappedRangeSample; // Samples getMappedRange latency LatencySample mappedRangeRemoteSample; // Samples getMappedRange remote subquery latency @@ -1159,6 +1164,22 @@ public: 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, @@ -1837,6 +1858,10 @@ ACTOR Future 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(), @@ -1845,6 +1870,8 @@ ACTOR Future getValueQ(StorageServer* data, GetValueRequest req) { state Optional 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(), @@ -1940,6 +1967,7 @@ ACTOR Future 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::max()); @@ -3732,6 +3760,10 @@ ACTOR Future 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( @@ -3739,6 +3771,7 @@ ACTOR Future getKeyValuesQ(StorageServer* data, GetKeyValuesRequest req) 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 tenantEntry = data->getTenantEntry(version, req.tenantInfo); state Optional tenantPrefix = tenantEntry.map([](TenantMapEntry e) { return e.prefix; }); @@ -3882,6 +3915,7 @@ ACTOR Future 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::max()); @@ -4479,6 +4513,10 @@ ACTOR Future 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( @@ -4486,6 +4524,7 @@ ACTOR Future getMappedKeyValuesQ(StorageServer* data, GetMappedKeyValuesRe // 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 tenantEntry = data->getTenantEntry(req.version, req.tenantInfo); state Optional tenantPrefix = tenantEntry.map([](TenantMapEntry e) { return e.prefix; }); @@ -4899,9 +4938,14 @@ ACTOR Future 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 tenantEntry = data->getTenantEntry(version, req.tenantInfo); if (tenantEntry.present()) {