Skip to content

add new commit statistics metrics #13416

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.

Sign up for GitHub

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

Open
MarkSh1 wants to merge 2 commits into
base: main
Choose a base branch
from
+304 −5
Open

add new commit statistics metrics #13416

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
2 commits
Select commit Hold shift + click to select a range
5e1b2d3
Added new commit statistics metrics
MarkSh1 Jul 1, 2026
4b3af74
added new metrics into mr-status-json-schemas.rst.inc
MarkSh1 Jul 1, 2026
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
96 changes: 96 additions & 0 deletions documentation/sphinx/source/mr-status-json-schemas.rst.inc
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -304,6 +304,102 @@
"p99":0.0,
"p99.9":0.0
},
"commit_batch_transactions":{ // Number of transactions in the commit batch
"count":0,
"min":0.0,
"max":0.0,
"median":0.0,
"mean":0.0,
"p25":0.0,
"p90":0.0,
"p95":0.0,
"p99":0.0,
"p99.9":0.0
},
"commit_batch_bytes":{ // Total size of transactions in the commit batch (bytes)
"count":0,
"min":0.0,
"max":0.0,
"median":0.0,
"mean":0.0,
"p25":0.0,
"p90":0.0,
"p95":0.0,
"p99":0.0,
"p99.9":0.0
},
"commit_batching_waiting":{ // Time transactions spent waiting in queue before commit batch processing (seconds)
"count":0,
"min":0.0,
"max":0.0,
"median":0.0,
"mean":0.0,
"p25":0.0,
"p90":0.0,
"p95":0.0,
"p99":0.0,
"p99.9":0.0
},
"commit_preresolution_latency":{ // Latency of the pre-resolution phase (seconds)
"count":0,
"min":0.0,
"max":0.0,
"median":0.0,
"mean":0.0,
"p25":0.0,
"p90":0.0,
"p95":0.0,
"p99":0.0,
"p99.9":0.0
},
"commit_resolution_latency":{ // Latency of the resolution phase (seconds)
"count":0,
"min":0.0,
"max":0.0,
"median":0.0,
"mean":0.0,
"p25":0.0,
"p90":0.0,
"p95":0.0,
"p99":0.0,
"p99.9":0.0
},
"commit_postresolution_latency":{ // Latency of the post-resolution phase (seconds)
"count":0,
"min":0.0,
"max":0.0,
"median":0.0,
"mean":0.0,
"p25":0.0,
"p90":0.0,
"p95":0.0,
"p99":0.0,
"p99.9":0.0
},
"commit_tlog_logging_latency":{ // Latency of the TLog logging phase (seconds)
"count":0,
"min":0.0,
"max":0.0,
"median":0.0,
"mean":0.0,
"p25":0.0,
"p90":0.0,
"p95":0.0,
"p99":0.0,
"p99.9":0.0
},
"commit_reply_latency":{ // Latency of the reply phase (seconds)
"count":0,
"min":0.0,
"max":0.0,
"median":0.0,
"mean":0.0,
"p25":0.0,
"p90":0.0,
"p95":0.0,
"p99":0.0,
"p99.9":0.0
},
"grv_latency_bands":{ // How many GRV requests belong to the latency (in seconds) band (e.g., How many requests belong to [0.01,0.1] latency band). The key is the upper bound of the band and the lower bound is the next smallest band (or 0, if none). Example: {0.01: 27, 0.1: 18, 1: 1, inf: 98,filtered: 10}, we have 18 requests in [0.01, 0.1) band.
"$map_key=upperBoundOfBand": 1
},
Expand Down
96 changes: 96 additions & 0 deletions fdbclient/Schemas.cpp
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -289,6 +289,102 @@ const KeyRef JSONSchemas::statusSchema = R"statusSchema(
"p99":0.0,
"p99.9":0.0
},
"commit_batch_transactions":{
"count":0,
"min":0.0,
"max":0.0,
"median":0.0,
"mean":0.0,
"p25":0.0,
"p90":0.0,
"p95":0.0,
"p99":0.0,
"p99.9":0.0
},
"commit_batch_bytes":{
"count":0,
"min":0.0,
"max":0.0,
"median":0.0,
"mean":0.0,
"p25":0.0,
"p90":0.0,
"p95":0.0,
"p99":0.0,
"p99.9":0.0
},
"commit_batching_waiting":{
"count":0,
"min":0.0,
"max":0.0,
"median":0.0,
"mean":0.0,
"p25":0.0,
"p90":0.0,
"p95":0.0,
"p99":0.0,
"p99.9":0.0
},
"commit_preresolution_latency":{
"count":0,
"min":0.0,
"max":0.0,
"median":0.0,
"mean":0.0,
"p25":0.0,
"p90":0.0,
"p95":0.0,
"p99":0.0,
"p99.9":0.0
},
"commit_resolution_latency":{
"count":0,
"min":0.0,
"max":0.0,
"median":0.0,
"mean":0.0,
"p25":0.0,
"p90":0.0,
"p95":0.0,
"p99":0.0,
"p99.9":0.0
},
"commit_postresolution_latency":{
"count":0,
"min":0.0,
"max":0.0,
"median":0.0,
"mean":0.0,
"p25":0.0,
"p90":0.0,
"p95":0.0,
"p99":0.0,
"p99.9":0.0
},
"commit_tlog_logging_latency":{
"count":0,
"min":0.0,
"max":0.0,
"median":0.0,
"mean":0.0,
"p25":0.0,
"p90":0.0,
"p95":0.0,
"p99":0.0,
"p99.9":0.0
},
"commit_reply_latency":{
"count":0,
"min":0.0,
"max":0.0,
"median":0.0,
"mean":0.0,
"p25":0.0,
"p90":0.0,
"p95":0.0,
"p99":0.0,
"p99.9":0.0
},
"grv_latency_bands":{
"$map": 1
},
Expand Down
47 changes: 46 additions & 1 deletion fdbserver/clustercontroller/Status.cpp
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -670,6 +670,46 @@ struct RolesInfo {
if (commitBatchingWindowSize.size()) {
obj["commit_batching_window_size"] = addLatencyStatistics(commitBatchingWindowSize);
}

TraceEventFields const& commitBatchTransactions = metrics.at("CommitBatchTransactions");
if (commitBatchTransactions.size()) {
obj["commit_batch_transactions"] = addLatencyStatistics(commitBatchTransactions);
}

TraceEventFields const& commitBatchBytes = metrics.at("CommitBatchBytes");
if (commitBatchBytes.size()) {
obj["commit_batch_bytes"] = addLatencyStatistics(commitBatchBytes);
}

TraceEventFields const& commitBatchingWaiting = metrics.at("CommitBatchingWaiting");
if (commitBatchingWaiting.size()) {
obj["commit_batching_waiting"] = addLatencyStatistics(commitBatchingWaiting);
}

TraceEventFields const& commitPreresolutionLatency = metrics.at("CommitPreresolutionLatency");
if (commitPreresolutionLatency.size()) {
obj["commit_preresolution_latency"] = addLatencyStatistics(commitPreresolutionLatency);
}

TraceEventFields const& commitResolutionLatency = metrics.at("CommitResolutionLatency");
if (commitResolutionLatency.size()) {
obj["commit_resolution_latency"] = addLatencyStatistics(commitResolutionLatency);
}

TraceEventFields const& commitPostresolutionLatency = metrics.at("CommitPostresolutionLatency");
if (commitPostresolutionLatency.size()) {
obj["commit_postresolution_latency"] = addLatencyStatistics(commitPostresolutionLatency);
}

TraceEventFields const& commitTLogLoggingLatency = metrics.at("CommitTLogLoggingLatency");
if (commitTLogLoggingLatency.size()) {
obj["commit_tlog_logging_latency"] = addLatencyStatistics(commitTLogLoggingLatency);
}

TraceEventFields const& commitReplyLatency = metrics.at("CommitReplyLatency");
if (commitReplyLatency.size()) {
obj["commit_reply_latency"] = addLatencyStatistics(commitReplyLatency);
}
} catch (Error& e) {
if (e.code() != error_code_attribute_not_found) {
throw e;
Expand Down Expand Up @@ -2028,7 +2068,12 @@ static Future<std::vector<std::pair<TLogInterface, EventMap>>> getTLogsAndMetric
static Future<std::vector<std::pair<CommitProxyInterface, EventMap>>> getCommitProxiesAndMetrics(
Reference<AsyncVar<ServerDBInfo>> db,
std::unordered_map<NetworkAddress, WorkerInterface> address_workers) {
std::vector<std::string> eventNames{ "CommitLatencyMetrics", "CommitLatencyBands", "CommitBatchingWindowSize" };
std::vector<std::string> eventNames{
"CommitLatencyMetrics", "CommitLatencyBands", "CommitBatchingWindowSize",
"CommitBatchTransactions", "CommitBatchBytes", "CommitBatchingWaiting",
"CommitPreresolutionLatency", "CommitResolutionLatency", "CommitPostresolutionLatency",
"CommitTLogLoggingLatency", "CommitReplyLatency"
};
std::vector<std::pair<CommitProxyInterface, EventMap>> results =
co_await getServerMetrics(db->get().client.commitProxies, address_workers, std::move(eventNames));

Expand Down
25 changes: 21 additions & 4 deletions fdbserver/commitproxy/CommitProxyServer.cpp
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -884,6 +884,7 @@ Future<Void> preresolutionProcessing(CommitBatchContext* self) {
r->value().emplace_back(versionReply.resolverChangesVersion, it.dest);
}

pProxyCommitData->stats.commitPreresolutionLatency.addMeasurement(now() - startTime);
//TraceEvent("ProxyGotVer", pProxyContext->dbgid).detail("Commit", commitVersion).detail("Prev", prevVersion);

if (debugID.present()) {
Expand Down Expand Up @@ -973,7 +974,10 @@ Future<Void> getResolution(CommitBatchContext* self) {
self->resolution = std::move(resolutionResp);
}

self->pProxyCommitData->stats.resolutionDist->sampleSeconds(g_network->timer_monotonic() - resolutionStart);
double resolutionDuration = g_network->timer_monotonic() - resolutionStart;

self->pProxyCommitData->stats.commitResolutionLatency.addMeasurement(resolutionDuration);
self->pProxyCommitData->stats.resolutionDist->sampleSeconds(resolutionDuration);
if (self->debugID.present()) {
g_traceBatch.addEvent(
"CommitDebug", self->debugID.get().first(), "CommitProxyServer.commitBatch.AfterResolution");
Expand Down Expand Up @@ -1804,7 +1808,10 @@ Future<Void> postResolution(CommitBatchContext* self) {
}
}

pProxyCommitData->stats.processingMutationDist->sampleSeconds(g_network->timer_monotonic() - postResolutionQueuing);
double postResolutionEnd = g_network->timer_monotonic();

pProxyCommitData->stats.commitPostresolutionLatency.addMeasurement(postResolutionEnd - postResolutionStart);
pProxyCommitData->stats.processingMutationDist->sampleSeconds(postResolutionEnd - postResolutionQueuing);
}

Future<Void> transactionLogging(CommitBatchContext* self) {
Expand Down Expand Up @@ -1844,7 +1851,11 @@ Future<Void> transactionLogging(CommitBatchContext* self) {
pProxyCommitData->txsPopVersions.emplace_back(self->commitVersion, self->msg.popTo);
}
pProxyCommitData->logSystemConsumer->popTxs(self->msg.popTo);
pProxyCommitData->stats.tlogLoggingDist->sampleSeconds(g_network->timer_monotonic() - tLoggingStart);

double tLoggingDuration = g_network->timer_monotonic() - tLoggingStart;

pProxyCommitData->stats.commitTLogLoggingLatency.addMeasurement(tLoggingDuration);
pProxyCommitData->stats.tlogLoggingDist->sampleSeconds(tLoggingDuration);
}

Future<Void> reply(CommitBatchContext* self) {
Expand Down Expand Up @@ -1986,6 +1997,7 @@ Future<Void> reply(CommitBatchContext* self) {
// TODO: filter if pipelined with large commit
const double duration = endTime - tr.requestTime();
pProxyCommitData->stats.commitLatencySample.addMeasurement(duration);
pProxyCommitData->stats.commitBatchingWaiting.addMeasurement(self->startTime - tr.requestTime());
if (pProxyCommitData->latencyBandConfig.present()) {
bool filter = self->maxTransactionBytes >
pProxyCommitData->latencyBandConfig.get().commitConfig.maxCommitBytes.orDefault(
Expand Down Expand Up @@ -2046,7 +2058,10 @@ Future<Void> reply(CommitBatchContext* self) {
pProxyCommitData->commitBatchesMemBytesCount -= self->currentBatchMemBytesCount;
ASSERT_ABORT(pProxyCommitData->commitBatchesMemBytesCount >= 0);
co_await self->releaseFuture;
pProxyCommitData->stats.replyCommitDist->sampleSeconds(g_network->timer_monotonic() - replyStart);
double replyDuration = g_network->timer_monotonic() - replyStart;

pProxyCommitData->stats.commitReplyLatency.addMeasurement(replyDuration);
pProxyCommitData->stats.replyCommitDist->sampleSeconds(replyDuration);
}

// Commit one batch of transactions trs
Expand All @@ -2064,6 +2079,8 @@ Future<Void> commitBatchImpl(CommitBatchContext* pContext) {
pContext->pProxyCommitData->lastVersionTime = pContext->startTime;
++pContext->pProxyCommitData->stats.commitBatchIn;
pContext->setupTraceBatch();
pContext->pProxyCommitData->stats.commitBatchBytes.addMeasurement(pContext->currentBatchMemBytesCount);
pContext->pProxyCommitData->stats.commitBatchTransactions.addMeasurement(pContext->trs.size());

/////// Phase 1: Pre-resolution processing (CPU bound except waiting for a version # which is separately pipelined
/// and *should* be available by now (unless empty commit); ordered; currently atomic but could yield)
Expand Down
45 changes: 45 additions & 0 deletions fdbserver/commitproxy/ProxyCommitData.h
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -79,6 +79,19 @@ struct ProxyStats {

LatencySample commitBatchingWindowSize;

// Number of transactions in the batch
LatencySample commitBatchTransactions;
// Summary length of transactions in the batch
LatencySample commitBatchBytes;
// what time transactions were waiting in the batch before they
// started processing with commitBatch()
LatencySample commitBatchingWaiting;
LatencySample commitPreresolutionLatency;
LatencySample commitResolutionLatency;
LatencySample commitPostresolutionLatency;
LatencySample commitTLogLoggingLatency;
LatencySample commitReplyLatency;

LatencySample computeLatency;

Future<Void> logger;
Expand Down Expand Up @@ -148,6 +161,38 @@ struct ProxyStats {
id,
SERVER_KNOBS->LATENCY_METRICS_LOGGING_INTERVAL,
SERVER_KNOBS->LATENCY_SKETCH_ACCURACY),
commitBatchTransactions("CommitBatchTransactions",
id,
SERVER_KNOBS->LATENCY_METRICS_LOGGING_INTERVAL,
SERVER_KNOBS->LATENCY_SKETCH_ACCURACY),
commitBatchBytes("CommitBatchBytes",
id,
SERVER_KNOBS->LATENCY_METRICS_LOGGING_INTERVAL,
SERVER_KNOBS->LATENCY_SKETCH_ACCURACY),
commitBatchingWaiting("CommitBatchingWaiting",
id,
SERVER_KNOBS->LATENCY_METRICS_LOGGING_INTERVAL,
SERVER_KNOBS->LATENCY_SKETCH_ACCURACY),
commitPreresolutionLatency("CommitPreresolutionLatency",
id,
SERVER_KNOBS->LATENCY_METRICS_LOGGING_INTERVAL,
SERVER_KNOBS->LATENCY_SKETCH_ACCURACY),
commitResolutionLatency("CommitResolutionLatency",
id,
SERVER_KNOBS->LATENCY_METRICS_LOGGING_INTERVAL,
SERVER_KNOBS->LATENCY_SKETCH_ACCURACY),
commitPostresolutionLatency("CommitPostresolutionLatency",
id,
SERVER_KNOBS->LATENCY_METRICS_LOGGING_INTERVAL,
SERVER_KNOBS->LATENCY_SKETCH_ACCURACY),
commitTLogLoggingLatency("CommitTLogLoggingLatency",
id,
SERVER_KNOBS->LATENCY_METRICS_LOGGING_INTERVAL,
SERVER_KNOBS->LATENCY_SKETCH_ACCURACY),
commitReplyLatency("CommitReplyLatency",
id,
SERVER_KNOBS->LATENCY_METRICS_LOGGING_INTERVAL,
SERVER_KNOBS->LATENCY_SKETCH_ACCURACY),
computeLatency("ComputeLatency",
id,
SERVER_KNOBS->LATENCY_METRICS_LOGGING_INTERVAL,
Expand Down
Loading