The test runs this aggregate command:
[js_test:safe_secondary_reads_single_migration_waitForDelete] [jsTest] ----
[js_test:safe_secondary_reads_single_migration_waitForDelete] [jsTest] testing command {
[js_test:safe_secondary_reads_single_migration_waitForDelete] [jsTest] "mapReduce" : "foo",
[js_test:safe_secondary_reads_single_migration_waitForDelete] [jsTest] "map" : function() {
[js_test:safe_secondary_reads_single_migration_waitForDelete] [jsTest] emit(this.x, 1);
[js_test:safe_secondary_reads_single_migration_waitForDelete] [jsTest] },
[js_test:safe_secondary_reads_single_migration_waitForDelete] [jsTest] "reduce" : function(key, values) {
[js_test:safe_secondary_reads_single_migration_waitForDelete] [jsTest] return Array.sum(values);
[js_test:safe_secondary_reads_single_migration_waitForDelete] [jsTest] },
[js_test:safe_secondary_reads_single_migration_waitForDelete] [jsTest] "out" : {
[js_test:safe_secondary_reads_single_migration_waitForDelete] [jsTest] "inline" : 1
[js_test:safe_secondary_reads_single_migration_waitForDelete] [jsTest] }
[js_test:safe_secondary_reads_single_migration_waitForDelete] [jsTest] }
[js_test:safe_secondary_reads_single_migration_waitForDelete] [jsTest] ----
We expect that there's exactly one operation in the profiler matching this query:
{
"command.shardVersion" : {
"$exists" : true
},
"command.shardVersion.0" : {
"$ne" : Timestamp(0, 0)
},
"command.shardVersion.1" : {
"$ne" : ObjectId("00000000ffffffffffffffff")
},
"command.$readPreference" : {
"mode" : "secondary"
},
"command.readConcern" : {
"level" : "local"
},
"errCode" : {
"$ne" : 13388
},
"command.aggregate" : "foo"
}
However, the profiler has two matching aggregate commands out of four entries total (two aggregates, a getMore, and the find itself on system.profile).
Here's the first aggregate for the mapreduce command:
{
"op" : "command",
"ns" : "test.foo",
"command" : {
"aggregate" : "foo",
"pipeline" : [
{
"$project" : {
"emits" : {
"$_internalJsEmit" : {
"eval" : "function() {\n emit(this.x, 1);\n }",
"this" : "$$ROOT"
}
},
"_id" : false
}
},
{
"$unwind" : {
"path" : "$emits"
}
},
{
"$group" : {
"_id" : "$emits.k",
"value" : {
"$_internalJsReduce" : {
"data" : "$emits",
"eval" : "function(key, values) {\n return Array.sum(values);\n }"
}
}
}
}
],
"cursor" : {
"batchSize" : 0
},
"allowDiskUse" : true,
"fromMongos" : true,
"let" : {
"IS_MR" : true,
"NOW" : ISODate("2021-04-12T22:19:31.033Z"),
"CLUSTER_TIME" : Timestamp(1618265970, 87)
},
"isMapReduceCommand" : true,
"$queryOptions" : {
"$readPreference" : {
"mode" : "secondary"
}
},
"readConcern" : {
"level" : "local"
},
"needsMerge" : true,
// etc...
The other aggregate command is a $mergeCursors:
"op" : "command",
"ns" : "test.foo",
"command" : {
"aggregate" : "foo",
"pipeline" : [
{
"$mergeCursors" : {
"lsid" : {
"id" : UUID("16770975-1dd1-4392-b907-948771436821"),
"uid" : BinData(0,"47DEQpj8HBSa+/TImW+5JCeuQeRkm5NMpJWZG3hSuFU=")
},
"compareWholeSortKey" : false,
"remotes" : [
{
"shardId" : "safe_secondary_reads_single_migration_waitForDelete-rs0",
"hostAndPort" : "ip-10-122-47-239.ec2.internal:21521",
"cursorResponse" : {
"cursor" : {
"id" : NumberLong("2479107308808163874"),
"ns" : "test.foo",
"firstBatch" : [ ]
},
"ok" : 1
}
},
{
"shardId" : "safe_secondary_reads_single_migration_waitForDelete-rs1",
"hostAndPort" : "ip-10-122-47-239.ec2.internal:21523",
"cursorResponse" : {
"cursor" : {
"id" : NumberLong("497587830264602086"),
"ns" : "test.foo",
"firstBatch" : [ ]
},
"ok" : 1
}
}
],
"tailableMode" : "normal",
"nss" : "test.foo",
"allowPartialResults" : false,
"recordRemoteOpWaitTime" : true
}
},
{
"$group" : {
"_id" : "$$ROOT._id",
"value" : {
"$_internalJsReduce" : {
"data" : "$$ROOT.value",
"eval" : "function(key, values) {\n return Array.sum(values);\n }"
}
},
"$doingMerge" : true
}
}
],
The full output is very large so full logs are attached to the ticket in their entirety.