I have a workload that uses a single-node replicaset and does a create index. It looks like I now must start the single-node with the --keyFile option for create index to work – see SERVER-48344. So my questions are:
- The create index statement hung for days in my test before I noticed it.
- If create index requires this to succeed then the create index command should fail immediately. It doesn't fail fast in rc7.
- Have the docs been updated for this new requirement?
- Is this change OK? I get that implementation artifacts might require this, but a single-node replica shouldn't need a keyfile. Users will be slightly unhappy that their workflow has to be changed for this.
This is new in 4.4.0-rc7 and I assume is from the fix for SERVER-48235.
I will attach files, but below some info has been inlined
From mongo.log
{"t":{"$date":"2020-05-29T16:46:09.004-07:00"},"s":"I", "c":"-", "id":51773, "ctx":"IndexBuildsCoordinatorMongod-0","msg":"progress meter","attr":{"name":"Index Build: scanning collection","done":12592300,"total":13026808,"percent":96}}
{"t":{"$date":"2020-05-29T16:46:10.028-07:00"},"s":"I", "c":"INDEX", "id":20391, "ctx":"IndexBuildsCoordinatorMongod-0","msg":"Index build: collection scan done","attr":{"totalRecords":13026808,"durationMillis":42000}}
{"t":{"$date":"2020-05-29T16:46:13.004-07:00"},"s":"I", "c":"-", "id":51773, "ctx":"IndexBuildsCoordinatorMongod-0","msg":"progress meter","attr":{"name":"Index Build: inserting keys from external sorter into index","done":3528500,"total":13026808,"percent":27}}
{"t":{"$date":"2020-05-29T16:46:16.004-07:00"},"s":"I", "c":"-", "id":51773, "ctx":"IndexBuildsCoordinatorMongod-0","msg":"progress meter","attr":{"name":"Index Build: inserting keys from external sorter into index","done":8745400,"total":13026808,"percent":67}}
{"t":{"$date":"2020-05-29T16:46:18.436-07:00"},"s":"I", "c":"INDEX", "id":20685, "ctx":"IndexBuildsCoordinatorMongod-0","msg":"index build: inserted {bulk_getKeysInserted} keys from external sorter into index in {timer_seconds} seconds","attr":{"bulk_getKeysInserted":13026808,"timer_seconds":8}}
{"t":{"$date":"2020-05-29T16:46:18.595-07:00"},"s":"I", "c":"CONNPOOL", "id":22576, "ctx":"ReplNetwork","msg":"Connecting","attr":{"hostAndPort":"localhost:27017"}}
{"t":{"$date":"2020-05-29T16:46:18.596-07:00"},"s":"I", "c":"NETWORK", "id":22943, "ctx":"listener","msg":"connection accepted","attr":{"remote":"127.0.0.1:46208","sessionId":23,"connectionCount":2}}
{"t":{"$date":"2020-05-29T16:46:18.596-07:00"},"s":"I", "c":"NETWORK", "id":51800, "ctx":"conn23","msg":"client metadata","attr":{"remote":"127.0.0.1:46208","client":"conn23","doc":{"driver":{"name":"NetworkInterfaceTL","version":"4.4.0-rc7"},"os":{"type":"Linux","name":"Ubuntu","architecture":"x86_64","version":"18.04"}}}}
{"t":{"$date":"2020-05-29T16:46:18.597-07:00"},"s":"I", "c":"STORAGE", "id":3856202, "ctx":"IndexBuildsCoordinatorMongod-0","msg":"'voteCommitIndexBuild' command failed.","attr":{"indexBuildUUID":{"uuid":{"$uuid":"92295fe8-4718-4bf6-92d1-9cbcb0ab91ed"}},"responseStatus":{"operationTime":{"$timestamp":{"t":1590795976,"i":1}},"ok":0.0,"errmsg":"command voteCommitIndexBuild requires authentication","code":13,"codeName":"Unauthorized","$clusterTime":{"clusterTime":{"$timestamp":{"t":1590795976,"i":1}},"signature":{"hash":{"$binary":{"base64":"uoSbFqScxXJd3ZBioUf0Nbn1+YE=","subType":"0"}},"keyId":6832415531887230980}}}}}
From currentOp()
{
"type" : "op",
"host" : "nuc82:27017",
"desc" : "conn21",
"connectionId" : 21,
"client" : "127.0.0.1:46206",
"appName" : "MongoDB Shell",
"clientMetadata" : {
"application" : {
"name" : "MongoDB Shell"
},
"driver" : {
"name" : "MongoDB Internal Client",
"version" : "4.4.0-rc7"
},
"os" : {
"type" : "Linux",
"name" : "Ubuntu",
"architecture" : "x86_64",
"version" : "18.04"
}
},
"active" : true,
"currentOpTime" : "2020-05-31T08:45:31.023-07:00",
"effectiveUsers" : [
{
"user" : "root",
"db" : "admin"
}
],
"opid" : 22475,
"lsid" : {
"id" : UUID("395d379b-d8ba-43c0-826e-704005748de5"),
"uid" : BinData(0,"Y5mrDaxi8gv8RmdTsQ+1j7fmkr7JUsabhNmXAheU0fg=")
},
"secs_running" : NumberLong(144003),
"microsecs_running" : NumberLong("144003512238"),
"op" : "command",
"ns" : "linkdb0.linktable",
"command" : {
"createIndexes" : "linktable",
"indexes" : [
{
"key" : {
"id1" : 1,
"link_type" : 1,
"visibility" : 1,
"time" : 1,
"id2" : 1,
"version" : 1,
"data" : 1
},
"name" : "id1_1_link_type_1_visibility_1_time_1_id2_1_version_1_data_1"
}
],
"lsid" : {
"id" : UUID("395d379b-d8ba-43c0-826e-704005748de5")
},
"$clusterTime" : {
"clusterTime" : Timestamp(1590795926, 13072),
"signature" : {
"hash" : BinData(0,"NYvnaGW5IYSRa7wm2vn0cXAByWQ="),
"keyId" : NumberLong("6832415531887230980")
}
},
"$db" : "linkdb0"
},
"numYields" : 0,
"waitingForLatch" : {
"timestamp" : ISODate("2020-05-29T23:45:27.659Z"),
"captureName" : "FutureResolution"
},
"locks" : {
},
"waitingForLock" : false,
"lockStats" : {
"ParallelBatchWriterMode" : {
"acquireCount" : {
"r" : NumberLong(3)
}
},
"ReplicationStateTransition" : {
"acquireCount" : {
"w" : NumberLong(5)
}
},
"Global" : {
"acquireCount" : {
"r" : NumberLong(1),
"w" : NumberLong(4)
}
},
"Database" : {
"acquireCount" : {
"r" : NumberLong(1),
"w" : NumberLong(3)
}
},
"Collection" : {
"acquireCount" : {
"w" : NumberLong(1),
"W" : NumberLong(1)
}
},
"Mutex" : {
"acquireCount" : {
"r" : NumberLong(4)
}
}
},
"waitingForFlowControl" : false,
"flowControlStats" : {
"acquireCount" : NumberLong(3)
}
},
The create index thread stack
1 __GI___nanosleep,mongo::sleepmicros(long,mongo::IndexBuildsCoordinatorMongod::_signalPrimaryForCommitReadiness(mongo::OperationContext*,,mongo::IndexBuildsCoordinator::_buildIndex(mongo::OperationContext*,,mongo::IndexBuildsCoordinator::_runIndexBuildInner(mongo::OperationContext*,,mongo::IndexBuildsCoordinator::_runIndexBuild(mongo::OperationContext*,,??,??,mongo::ThreadPool::_doOneTask(std::unique_lock<mongo::latch_detail::Latch>*),mongo::ThreadPool::_consumeTasks(),mongo::ThreadPool::_workerThreadBody(mongo::ThreadPool*,,??,??,start_thread,clone
- duplicates
-
SERVER-50665 Index creation stuck with "Index Build: draining writes received during build"
-
- Closed
-
- is related to
-
SERVER-48235 The primary node should use the AsyncDBClient to vote for committing the index build to allow the request to be interrupted by the IndexBuildsCoordinator
-
- Closed
-