Merge pull request #170 from dongxinEric/misc/49/time-based-slow-query-logging

Author: dongxinEric

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 queryLatencyMicroSeconds = (timer_int() - startTime) / 1000;
+	DocumentLayer::metricReporter->captureTime(DocLayerConstants::MT_TIME_QUERY_LATENCY_US, queryLatencyMicroSeconds);
+
+	if (slowQueryLogging && queryLatencyMicroSeconds >= DOCLAYER_KNOBS->SLOW_QUERY_THRESHOLD_MICRO_SECONDS) {
+		TraceEvent(SevWarn, "SlowQuery")
+		    .detail("ThresholdMicroSeconds", DOCLAYER_KNOBS->SLOW_QUERY_THRESHOLD_MICRO_SECONDS)
+		    .detail("DurationMicroSeconds", queryLatencyMicroSeconds)
+		    .detail("Query", query->toString());
+	}
 
 	return Void();
 }

src/Knobs.cpp

@@ -44,6 +44,7 @@ DocLayerKnobs::DocLayerKnobs(bool enable) {
 	init(MAX_RETURNABLE_DATA_SIZE, (1 << 20) * 16);
 	init(CURSOR_EXPIRY, 60 * 10); /* seconds */
 	init(DEFAULT_RETURNABLE_DATA_SIZE, (1 << 20) * 4);
+	init(SLOW_QUERY_THRESHOLD_MICRO_SECONDS, 10 * 1000 * 1000);
 }
 
 bson::BSONObj DocLayerKnobs::dumpKnobs() const {

src/Knobs.h

@@ -37,6 +37,7 @@ class DocLayerKnobs : public Knobs {
 	int MAX_RETURNABLE_DATA_SIZE;
 	int CURSOR_EXPIRY;
 	int DEFAULT_RETURNABLE_DATA_SIZE;
+	int SLOW_QUERY_THRESHOLD_MICRO_SECONDS;
 
 	explicit DocLayerKnobs(bool randomize = false);