Log the slow query based on how long the query takes to run.

Author: Xin Dong

src/Constants.cpp

@@ -76,5 +76,6 @@ const char* MT_TIME_INSERT_LATENCY_US = "dl_insert_latency_useconds";
 const char* MT_HIST_INSERT_SZ = "dl_insert_size_bytes";
 const char* MT_HIST_TR_PER_REQUEST = "dl_tr_per_request";
 const char* MT_RATE_IDX_REBUILD = "dl_index_rebuild_rate";
+const uint64_t SLOW_QUERY_THRESHOLD_SECONDS = 10;
 
 } // namespace DocLayerConstants

src/Constants.h

@@ -89,6 +89,8 @@ extern const char* MT_TIME_INSERT_LATENCY_US;
 extern const char* MT_HIST_INSERT_SZ;
 extern const char* MT_HIST_TR_PER_REQUEST;
 extern const char* MT_RATE_IDX_REBUILD;
+// TODO: make this part of the knob/options instead of constants?
+extern const uint64_t SLOW_QUERY_THRESHOLD_SECONDS;
 
 } // namespace DocLayerConstants
 

src/ExtMsg.actor.cpp

@@ -514,8 +514,15 @@ ACTOR static Future<Void> doRun(Reference<ExtMsgQuery> query, Reference<ExtConne
 		}
 	}
 
-	DocumentLayer::metricReporter->captureTime(DocLayerConstants::MT_TIME_QUERY_LATENCY_US,
-	                                           (timer_int() - startTime) / 1000);
+	uint64_t queryLatencySeconds = (timer_int() - startTime) / 1000;
+	DocumentLayer::metricReporter->captureTime(DocLayerConstants::MT_TIME_QUERY_LATENCY_US, queryLatencySeconds);
+
+	if (slowQueryLogging && queryLatencySeconds >= DocLayerConstants::SLOW_QUERY_THRESHOLD_SECONDS) {
+		TraceEvent("SlowQuery")
+		    .detail("Threshold", DocLayerConstants::SLOW_QUERY_THRESHOLD_SECONDS)
+		    .detail("Duration", queryLatencySeconds)
+		    .detail("Query", query->toString());
+	}
 
 	return Void();
 }