From d91d8ef3fbb1cb6bd164c5da97d2651318d36041 Mon Sep 17 00:00:00 2001 From: Brian DeLeonardis Date: Wed, 4 Nov 2020 21:12:00 +0000 Subject: SERVER-51724 Collect the number of cursor seeks per operation --- .../db/stats/resource_consumption_metrics.cpp | 7 +++++ src/mongo/db/stats/resource_consumption_metrics.h | 11 +++++++ .../db/stats/resource_consumption_metrics_test.cpp | 35 ++++++++++++++++++++++ 3 files changed, 53 insertions(+) (limited to 'src/mongo/db/stats') diff --git a/src/mongo/db/stats/resource_consumption_metrics.cpp b/src/mongo/db/stats/resource_consumption_metrics.cpp index 90d278ea072..072488d593d 100644 --- a/src/mongo/db/stats/resource_consumption_metrics.cpp +++ b/src/mongo/db/stats/resource_consumption_metrics.cpp @@ -58,6 +58,7 @@ static const char kDocUnitsWritten[] = "docUnitsWritten"; static const char kIdxEntryBytesWritten[] = "idxEntryBytesWritten"; static const char kIdxEntryUnitsWritten[] = "idxEntryUnitsWritten"; static const char kDocUnitsReturned[] = "docUnitsReturned"; +static const char kCursorSeeks[] = "cursorSeeks"; inline void appendNonZeroMetric(BSONObjBuilder* builder, const char* name, long long value) { if (value != 0) { @@ -121,6 +122,7 @@ void ResourceConsumption::ReadMetrics::toBson(BSONObjBuilder* builder) const { builder->appendNumber(kIdxEntryUnitsRead, idxEntryUnitsRead); builder->appendNumber(kKeysSorted, keysSorted); builder->appendNumber(kDocUnitsReturned, docUnitsReturned); + builder->appendNumber(kCursorSeeks, cursorSeeks); } void ResourceConsumption::WriteMetrics::toBson(BSONObjBuilder* builder) const { @@ -162,6 +164,7 @@ void ResourceConsumption::OperationMetrics::toBsonNonZeroFields(BSONObjBuilder* appendNonZeroMetric(builder, kIdxEntryUnitsRead, readMetrics.idxEntryUnitsRead); appendNonZeroMetric(builder, kKeysSorted, readMetrics.keysSorted); appendNonZeroMetric(builder, kDocUnitsReturned, readMetrics.docUnitsReturned); + appendNonZeroMetric(builder, kCursorSeeks, readMetrics.cursorSeeks); if (cpuTimer) { appendNonZeroMetric(builder, kCpuNanos, durationCount(cpuTimer->getElapsed())); @@ -247,6 +250,10 @@ bool ResourceConsumption::MetricsCollector::endScopedCollecting() { return wasCollecting; } +void ResourceConsumption::MetricsCollector::incrementOneCursorSeek() { + _doIfCollecting([&] { _metrics.readMetrics.cursorSeeks++; }); +} + ResourceConsumption::ScopedMetricsCollector::ScopedMetricsCollector(OperationContext* opCtx, const std::string& dbName, bool commandCollectsMetrics) diff --git a/src/mongo/db/stats/resource_consumption_metrics.h b/src/mongo/db/stats/resource_consumption_metrics.h index 5e49b6f5f9a..9ca51be3fa8 100644 --- a/src/mongo/db/stats/resource_consumption_metrics.h +++ b/src/mongo/db/stats/resource_consumption_metrics.h @@ -60,6 +60,7 @@ public: idxEntryUnitsRead += other.idxEntryUnitsRead; keysSorted += other.keysSorted; docUnitsReturned += other.docUnitsReturned; + cursorSeeks += other.cursorSeeks; } ReadMetrics& operator+=(const ReadMetrics& other) { @@ -84,6 +85,8 @@ public: long long keysSorted = 0; // Number of document units returned by a query long long docUnitsReturned = 0; + // Number of cursor seeks + long long cursorSeeks = 0; }; /* WriteMetrics maintains metrics for write operations. */ @@ -277,6 +280,14 @@ public: */ void incrementOneIdxEntryWritten(size_t idxEntryBytesWritten); + /** + * This should be called once every time the storage engine successfully does a cursor seek. + * Note that if it takes multiple attempts to do a successful seek, this function should + * only be called once. If the seek does not find anything, this function should not be + * called. + */ + void incrementOneCursorSeek(); + private: /** * Helper function that calls the Func when this collector is currently collecting metrics. diff --git a/src/mongo/db/stats/resource_consumption_metrics_test.cpp b/src/mongo/db/stats/resource_consumption_metrics_test.cpp index fea3bb0a456..b53e754b032 100644 --- a/src/mongo/db/stats/resource_consumption_metrics_test.cpp +++ b/src/mongo/db/stats/resource_consumption_metrics_test.cpp @@ -225,6 +225,7 @@ TEST_F(ResourceConsumptionMetricsTest, IncrementReadMetrics) { operationMetrics.incrementOneIdxEntryRead(_opCtx.get(), 8); operationMetrics.incrementKeysSorted(_opCtx.get(), 16); operationMetrics.incrementDocUnitsReturned(_opCtx.get(), 32); + operationMetrics.incrementOneCursorSeek(); } ASSERT(operationMetrics.hasCollectedMetrics()); @@ -236,6 +237,7 @@ TEST_F(ResourceConsumptionMetricsTest, IncrementReadMetrics) { ASSERT_EQ(metricsCopy["db1"].primaryReadMetrics.idxEntryUnitsRead, 1); ASSERT_EQ(metricsCopy["db1"].primaryReadMetrics.keysSorted, 16); ASSERT_EQ(metricsCopy["db1"].primaryReadMetrics.docUnitsReturned, 32); + ASSERT_EQ(metricsCopy["db1"].primaryReadMetrics.cursorSeeks, 1); // Clear metrics so we do not double-count. operationMetrics.reset(); @@ -247,6 +249,7 @@ TEST_F(ResourceConsumptionMetricsTest, IncrementReadMetrics) { operationMetrics.incrementOneIdxEntryRead(_opCtx.get(), 128); operationMetrics.incrementKeysSorted(_opCtx.get(), 256); operationMetrics.incrementDocUnitsReturned(_opCtx.get(), 512); + operationMetrics.incrementOneCursorSeek(); } metricsCopy = globalResourceConsumption.getDbMetrics(); @@ -256,6 +259,7 @@ TEST_F(ResourceConsumptionMetricsTest, IncrementReadMetrics) { ASSERT_EQ(metricsCopy["db1"].primaryReadMetrics.idxEntryUnitsRead, 1 + 8); ASSERT_EQ(metricsCopy["db1"].primaryReadMetrics.keysSorted, 16 + 256); ASSERT_EQ(metricsCopy["db1"].primaryReadMetrics.docUnitsReturned, 32 + 512); + ASSERT_EQ(metricsCopy["db1"].primaryReadMetrics.cursorSeeks, 1 + 1); } TEST_F(ResourceConsumptionMetricsTest, IncrementReadMetricsSecondary) { @@ -272,6 +276,7 @@ TEST_F(ResourceConsumptionMetricsTest, IncrementReadMetricsSecondary) { operationMetrics.incrementOneIdxEntryRead(_opCtx.get(), 8); operationMetrics.incrementKeysSorted(_opCtx.get(), 16); operationMetrics.incrementDocUnitsReturned(_opCtx.get(), 32); + operationMetrics.incrementOneCursorSeek(); } auto metricsCopy = globalResourceConsumption.getDbMetrics(); @@ -281,6 +286,7 @@ TEST_F(ResourceConsumptionMetricsTest, IncrementReadMetricsSecondary) { ASSERT_EQ(metricsCopy["db1"].secondaryReadMetrics.idxEntryUnitsRead, 1); ASSERT_EQ(metricsCopy["db1"].secondaryReadMetrics.keysSorted, 16); ASSERT_EQ(metricsCopy["db1"].secondaryReadMetrics.docUnitsReturned, 32); + ASSERT_EQ(metricsCopy["db1"].secondaryReadMetrics.cursorSeeks, 1); // Clear metrics so we do not double-count. operationMetrics.reset(); @@ -292,6 +298,7 @@ TEST_F(ResourceConsumptionMetricsTest, IncrementReadMetricsSecondary) { operationMetrics.incrementOneIdxEntryRead(_opCtx.get(), 128); operationMetrics.incrementKeysSorted(_opCtx.get(), 256); operationMetrics.incrementDocUnitsReturned(_opCtx.get(), 512); + operationMetrics.incrementOneCursorSeek(); } metricsCopy = globalResourceConsumption.getDbMetrics(); @@ -301,6 +308,7 @@ TEST_F(ResourceConsumptionMetricsTest, IncrementReadMetricsSecondary) { ASSERT_EQ(metricsCopy["db1"].secondaryReadMetrics.idxEntryUnitsRead, 1 + 8); ASSERT_EQ(metricsCopy["db1"].secondaryReadMetrics.keysSorted, 16 + 256); ASSERT_EQ(metricsCopy["db1"].secondaryReadMetrics.docUnitsReturned, 32 + 512); + ASSERT_EQ(metricsCopy["db1"].secondaryReadMetrics.cursorSeeks, 1 + 1); } TEST_F(ResourceConsumptionMetricsTest, IncrementReadMetricsAcrossStates) { @@ -316,6 +324,7 @@ TEST_F(ResourceConsumptionMetricsTest, IncrementReadMetricsAcrossStates) { operationMetrics.incrementOneIdxEntryRead(_opCtx.get(), 8); operationMetrics.incrementKeysSorted(_opCtx.get(), 16); operationMetrics.incrementDocUnitsReturned(_opCtx.get(), 32); + operationMetrics.incrementOneCursorSeek(); ASSERT_OK(repl::ReplicationCoordinator::get(_opCtx.get()) ->setFollowerMode(repl::MemberState::RS_SECONDARY)); @@ -324,6 +333,7 @@ TEST_F(ResourceConsumptionMetricsTest, IncrementReadMetricsAcrossStates) { operationMetrics.incrementOneIdxEntryRead(_opCtx.get(), 128); operationMetrics.incrementKeysSorted(_opCtx.get(), 256); operationMetrics.incrementDocUnitsReturned(_opCtx.get(), 512); + operationMetrics.incrementOneCursorSeek(); } auto metricsCopy = globalResourceConsumption.getAndClearDbMetrics(); @@ -333,12 +343,14 @@ TEST_F(ResourceConsumptionMetricsTest, IncrementReadMetricsAcrossStates) { ASSERT_EQ(metricsCopy["db1"].primaryReadMetrics.idxEntryUnitsRead, 0); ASSERT_EQ(metricsCopy["db1"].primaryReadMetrics.keysSorted, 0); ASSERT_EQ(metricsCopy["db1"].primaryReadMetrics.docUnitsReturned, 0); + ASSERT_EQ(metricsCopy["db1"].primaryReadMetrics.cursorSeeks, 0); ASSERT_EQ(metricsCopy["db1"].secondaryReadMetrics.docBytesRead, 2 + 32); ASSERT_EQ(metricsCopy["db1"].secondaryReadMetrics.docUnitsRead, 2); ASSERT_EQ(metricsCopy["db1"].secondaryReadMetrics.idxEntryBytesRead, 8 + 128); ASSERT_EQ(metricsCopy["db1"].secondaryReadMetrics.idxEntryUnitsRead, 1 + 8); ASSERT_EQ(metricsCopy["db1"].secondaryReadMetrics.keysSorted, 16 + 256); ASSERT_EQ(metricsCopy["db1"].secondaryReadMetrics.docUnitsReturned, 32 + 512); + ASSERT_EQ(metricsCopy["db1"].secondaryReadMetrics.cursorSeeks, 1 + 1); operationMetrics.reset(); @@ -351,6 +363,7 @@ TEST_F(ResourceConsumptionMetricsTest, IncrementReadMetricsAcrossStates) { operationMetrics.incrementOneIdxEntryRead(_opCtx.get(), 8); operationMetrics.incrementKeysSorted(_opCtx.get(), 16); operationMetrics.incrementDocUnitsReturned(_opCtx.get(), 32); + operationMetrics.incrementOneCursorSeek(); ASSERT_OK(repl::ReplicationCoordinator::get(_opCtx.get()) ->setFollowerMode(repl::MemberState::RS_PRIMARY)); @@ -359,6 +372,7 @@ TEST_F(ResourceConsumptionMetricsTest, IncrementReadMetricsAcrossStates) { operationMetrics.incrementOneIdxEntryRead(_opCtx.get(), 128); operationMetrics.incrementKeysSorted(_opCtx.get(), 256); operationMetrics.incrementDocUnitsReturned(_opCtx.get(), 512); + operationMetrics.incrementOneCursorSeek(); } metricsCopy = globalResourceConsumption.getAndClearDbMetrics(); @@ -368,12 +382,14 @@ TEST_F(ResourceConsumptionMetricsTest, IncrementReadMetricsAcrossStates) { ASSERT_EQ(metricsCopy["db1"].primaryReadMetrics.idxEntryUnitsRead, 1 + 8); ASSERT_EQ(metricsCopy["db1"].primaryReadMetrics.keysSorted, 16 + 256); ASSERT_EQ(metricsCopy["db1"].primaryReadMetrics.docUnitsReturned, 32 + 512); + ASSERT_EQ(metricsCopy["db1"].primaryReadMetrics.cursorSeeks, 1 + 1); ASSERT_EQ(metricsCopy["db1"].secondaryReadMetrics.docBytesRead, 0); ASSERT_EQ(metricsCopy["db1"].secondaryReadMetrics.docUnitsRead, 0); ASSERT_EQ(metricsCopy["db1"].secondaryReadMetrics.idxEntryBytesRead, 0); ASSERT_EQ(metricsCopy["db1"].secondaryReadMetrics.idxEntryUnitsRead, 0); ASSERT_EQ(metricsCopy["db1"].secondaryReadMetrics.keysSorted, 0); ASSERT_EQ(metricsCopy["db1"].secondaryReadMetrics.docUnitsReturned, 0); + ASSERT_EQ(metricsCopy["db1"].secondaryReadMetrics.cursorSeeks, 0); } TEST_F(ResourceConsumptionMetricsTest, DocumentUnitsRead) { @@ -596,4 +612,23 @@ TEST_F(ResourceConsumptionMetricsTest, CpuNanos) { globalCpuTime = globalResourceConsumption.getCpuTime(); ASSERT_EQ(Nanoseconds(0), globalCpuTime); } + +TEST_F(ResourceConsumptionMetricsTest, CursorSeeks) { + auto& globalResourceConsumption = ResourceConsumption::get(getServiceContext()); + auto& operationMetrics = ResourceConsumption::MetricsCollector::get(_opCtx.get()); + + int expectedSeeks = 0; + + { + ResourceConsumption::ScopedMetricsCollector scope(_opCtx.get(), "db1"); + operationMetrics.incrementOneCursorSeek(); + operationMetrics.incrementOneCursorSeek(); + operationMetrics.incrementOneCursorSeek(); + + expectedSeeks += 3; + } + + auto metricsCopy = globalResourceConsumption.getDbMetrics(); + ASSERT_EQ(metricsCopy["db1"].primaryReadMetrics.cursorSeeks, expectedSeeks); +} } // namespace mongo -- cgit v1.2.1