mongo icon indicating copy to clipboard operation
mongo copied to clipboard

Wait for shutdown of mongod used for database init

Open das7pad opened this issue 5 months ago • 0 comments

Closes #730

This PR is waiting for the shutdown of the init database to exit before starting up the main database.

Tested with wrapper entrypoint script against an upstream image:

sed -i 's/--shutdown/--shutdown \&\& while ps "$(< "$pidfile")"; do sleep 1; done/' /usr/local/bin/docker-entrypoint.sh
exec /usr/local/bin/docker-entrypoint.sh "$@"

Before: "MongoDB init process complete; ready for start up." printed before "mongod shutdown complete"

...
17:17:11  mongo-1  | {"t":{"$date":"2025-08-11T16:17:08.804+00:00"},"s":"I",  "c":"STORAGE",  "id":22279,   "ctx":"SignalHandler","msg":"shutdown: removing fs lock..."}
17:17:11  mongo-1  | {"t":{"$date":"2025-08-11T16:17:08.804+00:00"},"s":"I",  "c":"STORAGE",  "id":7474902, "ctx":"SignalHandler","msg":"Shutting down oplog cap maintainer thread"}
17:17:11  mongo-1  | {"t":{"$date":"2025-08-11T16:17:09.000+00:00"},"s":"W",  "c":"REPL",     "id":6100702, "ctx":"ftdc","msg":"Failed to get last stable recovery timestamp due to lock acquire timeout. Note this is expected if shutdown is in progress."}
17:17:11  mongo-1  | {"t":{"$date":"2025-08-11T16:17:09.002+00:00"},"s":"I",  "c":"STORAGE",  "id":7474901, "ctx":"SignalHandler","msg":"Finished shutting down oplog cap maintainer thread"}
17:17:11  mongo-1  | {"t":{"$date":"2025-08-11T16:17:09.002+00:00"},"s":"I",  "c":"-",        "id":4784931, "ctx":"SignalHandler","msg":"Dropping the scope cache for shutdown"}
17:17:11  mongo-1  | {"t":{"$date":"2025-08-11T16:17:09.002+00:00"},"s":"I",  "c":"FTDC",     "id":20626,   "ctx":"SignalHandler","msg":"Shutting down full-time diagnostic data capture"}
17:17:11  mongo-1  | 
17:17:11  mongo-1  | MongoDB init process complete; ready for start up.
17:17:11  mongo-1  | 
17:17:11  mongo-1  | {"t":{"$date":"2025-08-11T16:17:09.776+00:00"},"s":"I",  "c":"CONTROL",  "id":23285,   "ctx":"main","msg":"Automatically disabling TLS 1.0, to force-enable TLS 1.0 specify --sslDisabledProtocols 'none'"}
17:17:11  mongo-1  | {"t":{"$date":"2025-08-11T16:17:09.776+00:00"},"s":"I",  "c":"CONTROL",  "id":5945603, "ctx":"main","msg":"Multi threading initialized"}
17:17:11  mongo-1  | {"t":{"$date":"2025-08-11T16:17:09.776+00:00"},"s":"I",  "c":"NETWORK",  "id":4648601, "ctx":"main","msg":"Implicit TCP FastOpen unavailable. If TCP FastOpen is required, set at least one of the related parameters","attr":{"relatedParameters":["tcpFastOpenServer","tcpFastOpenClient","tcpFastOpenQueueSize"]}}
17:17:11  mongo-1  | {"t":{"$date":"2025-08-11T16:17:09.777+00:00"},"s":"I",  "c":"NETWORK",  "id":4915701, "ctx":"main","msg":"Initialized wire specification","attr":{"spec":{"incomingExternalClient":{"minWireVersion":0,"maxWireVersion":25},"incomingInternalClient":{"minWireVersion":0,"maxWireVersion":25},"outgoing":{"minWireVersion":6,"maxWireVersion":25},"isInternalClient":true}}}
17:17:11  mongo-1  | {"t":{"$date":"2025-08-11T16:17:09.777+00:00"},"s":"I",  "c":"TENANT_M", "id":7091600, "ctx":"main","msg":"Starting TenantMigrationAccessBlockerRegistry"}
17:17:11  mongo-1  | {"t":{"$date":"2025-08-11T16:17:09.777+00:00"},"s":"I",  "c":"CONTROL",  "id":4615611, "ctx":"initandlisten","msg":"MongoDB starting","attr":{"pid":1,"port":27017,"dbPath":"/data/db","architecture":"64-bit","host":"886f613caec4"}}
17:17:11  mongo-1  | {"t":{"$date":"2025-08-11T16:17:09.777+00:00"},"s":"I",  "c":"CONTROL",  "id":23403,   "ctx":"initandlisten","msg":"Build Info","attr":{"buildInfo":{"version":"8.0.11","gitVersion":"bed99f699da6cb2b74262aa6d473446c41476643","openSSLVersion":"OpenSSL 3.0.13 30 Jan 2024","modules":[],"allocator":"tcmalloc-google","environment":{"distmod":"ubuntu2404","distarch":"x86_64","target_arch":"x86_64"}}}}
17:17:11  mongo-1  | {"t":{"$date":"2025-08-11T16:17:09.777+00:00"},"s":"I",  "c":"CONTROL",  "id":51765,   "ctx":"initandlisten","msg":"Operating System","attr":{"os":{"name":"Ubuntu","version":"24.04"}}}
17:17:11  mongo-1  | {"t":{"$date":"2025-08-11T16:17:09.777+00:00"},"s":"I",  "c":"CONTROL",  "id":21951,   "ctx":"initandlisten","msg":"Options set by command line","attr":{"options":{"net":{"bindIp":"*"},"replication":{"replSet":"overleaf"}}}}
17:17:11  mongo-1  | {"t":{"$date":"2025-08-11T16:17:09.778+00:00"},"s":"E",  "c":"CONTROL",  "id":20568,   "ctx":"initandlisten","msg":"Error setting up listener","attr":{"error":{"code":9001,"codeName":"SocketException","errmsg":"0.0.0.0:27017 :: caused by :: setup bind :: caused by :: Address already in use"}}}

After:

...
{"t":{"$date":"2025-08-12T09:29:40.348+00:00"},"s":"I",  "c":"STORAGE",  "id":22279,   "ctx":"SignalHandler","msg":"shutdown: removing fs lock..."}
{"t":{"$date":"2025-08-12T09:29:40.348+00:00"},"s":"I",  "c":"-",        "id":4784931, "ctx":"SignalHandler","msg":"Dropping the scope cache for shutdown"}
{"t":{"$date":"2025-08-12T09:29:40.348+00:00"},"s":"I",  "c":"FTDC",     "id":20626,   "ctx":"SignalHandler","msg":"Shutting down full-time diagnostic data capture"}
{"t":{"$date":"2025-08-12T09:29:40.355+00:00"},"s":"I",  "c":"CONTROL",  "id":20565,   "ctx":"SignalHandler","msg":"Now exiting"}
{"t":{"$date":"2025-08-12T09:29:40.356+00:00"},"s":"I",  "c":"CONTROL",  "id":8423404, "ctx":"SignalHandler","msg":"mongod shutdown complete","attr":{"Summary of time elapsed":{"Statistics":{"Enter terminal shutdown":"0 ms","Step down the replication coordinator for shutdown":"0 ms","Time spent in quiesce mode":"0 ms","Shut down FLE Crud subsystem":"0 ms","Shut down MirrorMaestro":"1 ms","Shut down WaitForMajorityService":"0 ms","Shut down the logical session cache":"0 ms","Shut down the Query Analysis Sampler":"1 ms","Shut down the global connection pool":"0 ms","Shut down the flow control ticket holder":"0 ms","Shut down the replica set node executor":"0 ms","Shut down the thread that aborts expired transactions":"0 ms","Shut down the replica set aware services":"0 ms","Shut down replication":"0 ms","Shut down external state":"125 ms","Shut down replication executor":"0 ms","Join replication executor":"1 ms","Kill all operations for shutdown":"0 ms","Shut down all tenant migration access blockers on global shutdown":"0 ms","Shut down all open transactions":"0 ms","Acquire the RSTL for shutdown":"34 ms","Shut down the IndexBuildsCoordinator and wait for index builds to finish":"0 ms","Shut down the replica set monitor":"0 ms","Shut down the logical time validator":"2 ms","Shut down the migration util executor":"0 ms","Shut down the transport layer":"0 ms","Shut down the health log":"0 ms","Shut down the TTL monitor":"0 ms","Shut down expired pre-images and documents removers":"0 ms","Shut down the storage engine":"154 ms","Wait for the oplog cap maintainer thread to stop":"0 ms","Shut down full-time data capture":"0 ms","Shut down online certificate status protocol manager":"0 ms","shutdownTask total elapsed time":"325 ms"}}}}
{"t":{"$date":"2025-08-12T09:29:40.356+00:00"},"s":"I",  "c":"CONTROL",  "id":23138,   "ctx":"SignalHandler","msg":"Shutting down","attr":{"exitCode":0}}

MongoDB init process complete; ready for start up.

{"t":{"$date":"2025-08-12T09:29:41.074+00:00"},"s":"I",  "c":"CONTROL",  "id":23285,   "ctx":"main","msg":"Automatically disabling TLS 1.0, to force-enable TLS 1.0 specify --sslDisabledProtocols 'none'"}
{"t":{"$date":"2025-08-12T09:29:41.074+00:00"},"s":"I",  "c":"CONTROL",  "id":5945603, "ctx":"main","msg":"Multi threading initialized"}

das7pad avatar Aug 12 '25 09:08 das7pad