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