Log latency metrics for batch GRV requests

documentation/sphinx/source/mr-status-json-schemas.rst.inc

@@ -134,6 +134,20 @@
                          "p99.9":0.0
                      }
                   },
+                  "grv_batch_latency_statistics":{
+                     "default":{
+                         "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
+                     }
+                  },                  
                   "read_latency_statistics":{
                      "count":0,
                      "min":0.0,

fdbclient/Schemas.cpp

@@ -157,6 +157,20 @@ const KeyRef JSONSchemas::statusSchema = LiteralStringRef(R"statusSchema(
                         "p99.9":0.0
                      }
                   },
+                  "grv_batch_latency_statistics":{
+                     "default":{
+                        "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
+                     }
+                  },                  
                   "read_latency_statistics":{
                      "count":0,
                      "min":0.0,

fdbserver/GrvProxyServer.actor.cpp

@@ -47,6 +47,7 @@ struct GrvProxyStats {
 
 	LatencyBands grvLatencyBands;
 	LatencySample grvLatencySample;
+    LatencySample grvBatchLatencySample;
 
 	Future<Void> logger;
 
@@ -101,6 +102,8 @@ struct GrvProxyStats {
 	                     id,
 	                     SERVER_KNOBS->LATENCY_METRICS_LOGGING_INTERVAL,
 	                     SERVER_KNOBS->LATENCY_SAMPLE_SIZE),
+	    grvBatchLatencySample("BatchLatencyMetrics", id, SERVER_KNOBS->LATENCY_METRICS_LOGGING_INTERVAL,
+	                     SERVER_KNOBS->LATENCY_SAMPLE_SIZE),
 	    grvLatencyBands("GRVLatencyMetrics", id, SERVER_KNOBS->STORAGE_LOGGING_DELAY) {
 		// The rate at which the limit(budget) is allowed to grow.
 		specialCounter(cc, "SystemAndDefaultTxnRateAllowed", [this]() { return this->transactionRateAllowed; });
@@ -528,6 +531,9 @@ ACTOR Future<Void> sendGrvReplies(Future<GetReadVersionReply> replyFuture,
 		if (request.priority >= TransactionPriority::DEFAULT) {
 			stats->grvLatencyBands.addMeasurement(duration);
 		}
+		else {
+			stats->grvBatchLatencySample.addMeasurement(duration);
+		}
 
 		if (request.flags & GetReadVersionRequest::FLAG_USE_MIN_KNOWN_COMMITTED_VERSION) {
 			// Only backup worker may infrequently use this flag.

fdbserver/Status.actor.cpp

@@ -499,6 +499,11 @@ struct RolesInfo {
 				    maxTLogVersion - version - SERVER_KNOBS->STORAGE_LOGGING_DELAY * SERVER_KNOBS->VERSIONS_PER_SECOND);
 			}
 
+			TraceEventFields const& batchLatencyMetrics = metrics.at("BatchLatencyMetrics");
+			if(batchLatencyMetrics.size()) {
+				obj["grv_batch_latency_statistics"] = addLatencyStatistics(batchLatencyMetrics);
+			}
+
 			TraceEventFields const& readLatencyMetrics = metrics.at("ReadLatencyMetrics");
 			if (readLatencyMetrics.size()) {
 				obj["read_latency_statistics"] = addLatencyStatistics(readLatencyMetrics);
@@ -641,6 +646,10 @@ struct RolesInfo {
 			if (grvLatencyBands.size()) {
 				obj["grv_latency_bands"] = addLatencyBandInfo(grvLatencyBands);
 			}
+			TraceEventFields const& grvBatchMetrics = metrics.at("BatchLatencyMetrics");
+			if(grvBatchMetrics.size()) {
+				obj["grv_batch_latency_statistics"] = addLatencyStatistics(grvBatchMetrics);
+			}						
 		} catch (Error& e) {
 			if (e.code() != error_code_attribute_not_found) {
 				throw e;
@@ -1812,7 +1821,7 @@ ACTOR static Future<vector<std::pair<StorageServerInterface, EventMap>>> getStor
 	           getServerMetrics(servers,
 	                            address_workers,
 	                            std::vector<std::string>{
-	                                "StorageMetrics", "ReadLatencyMetrics", "ReadLatencyBands", "BusiestReadTag" })) &&
+	                                "StorageMetrics", "ReadLatencyMetrics", "ReadLatencyBands", "BusiestReadTag", "BatchLatencyMetrics" })) &&
 	     store(busiestWriteTags, getServerBusiestWriteTags(servers, address_workers, rkWorker)));
 
 	ASSERT(busiestWriteTags.size() == results.size());
@@ -1850,7 +1859,7 @@ ACTOR static Future<vector<std::pair<GrvProxyInterface, EventMap>>> getGrvProxie
 	vector<std::pair<GrvProxyInterface, EventMap>> results =
 	    wait(getServerMetrics(db->get().client.grvProxies,
 	                          address_workers,
-	                          std::vector<std::string>{ "GRVLatencyMetrics", "GRVLatencyBands" }));
+	                          std::vector<std::string>{ "GRVLatencyMetrics", "GRVLatencyBands", "BatchLatencyMetrics" }));
 	return results;
 }
 

fdbserver/storageserver.actor.cpp

@@ -678,6 +678,7 @@ public:
 
 		LatencySample readLatencySample;
 		LatencyBands readLatencyBands;
+		LatencySample batchLatencySample;
 
 		Counters(StorageServer* self)
 		  : cc("StorageServer", self->thisServerID.toString()), getKeyQueries("GetKeyQueries", cc),
@@ -692,10 +693,15 @@ public:
 		    updateBatches("UpdateBatches", cc), updateVersions("UpdateVersions", cc), loops("Loops", cc),
 		    fetchWaitingMS("FetchWaitingMS", cc), fetchWaitingCount("FetchWaitingCount", cc),
 		    fetchExecutingMS("FetchExecutingMS", cc), fetchExecutingCount("FetchExecutingCount", cc),
-		    readsRejected("ReadsRejected", cc), readLatencySample("ReadLatencyMetrics",
+		    readsRejected("ReadsRejected", cc), 
-		                                                          self->thisServerID,
+			batchLatencySample("BatchLatencyMetrics", 
-		                                                          SERVER_KNOBS->LATENCY_METRICS_LOGGING_INTERVAL,
+				self->thisServerID, 
-		                                                          SERVER_KNOBS->LATENCY_SAMPLE_SIZE),
+				SERVER_KNOBS->LATENCY_METRICS_LOGGING_INTERVAL, 
+				SERVER_KNOBS->LATENCY_SAMPLE_SIZE),
+			readLatencySample("ReadLatencyMetrics",
+				self->thisServerID,
+				SERVER_KNOBS->LATENCY_METRICS_LOGGING_INTERVAL,
+				SERVER_KNOBS->LATENCY_SAMPLE_SIZE),
 		    readLatencyBands("ReadLatencyBands", self->thisServerID, SERVER_KNOBS->STORAGE_LOGGING_DELAY) {
 			specialCounter(cc, "LastTLogVersion", [self]() { return self->lastTLogVersion; });
 			specialCounter(cc, "Version", [self]() { return self->version.get(); });