search

typegoose / mongodb-memory-server

Manage & spin up mongodb server binaries with zero(or slight) configuration for tests.
https://typegoose.github.io/mongodb-memory-server/
MIT License
2.57k stars 185 forks source link

add some kind of state to `MongoInstance` to indicate that `.stop` is currently being executed #802

Closed hasezoey closed 11 months ago

hasezoey commented 11 months ago

Currently MongoInstance.stop can be called multiple times (because it is async) which can cause some duplicated behavior (but seemingly not a actual problem), this case can happen if somehow a instanceError is triggered while already executing .stop

see https://github.com/nodkz/mongodb-memory-server/issues/801#issuecomment-1741096960

example log (from https://github.com/nodkz/mongodb-memory-server/issues/801#issuecomment-1740889901):

  MongoMS:MongoMemoryServer Mongo[46574]: stop: Stopping MongoDB server on port 46574 with pid 7322 +0ms
  MongoMS:MongoInstance Mongo[46574]: stop +2ms
  MongoMS:utils Mongo[46574] killProcess: mongodProcess: sending "SIGINT" +0ms
  MongoMS:MongoInstance Mongo[46574]: closeHandler: Mongod instance closed with an non-0 (or non 12 on windows) code! +1ms
  MongoMS:MongoInstance Mongo[46574]: constructor: Instance has thrown an Error: Error: Instance closed unexpectedly with code "null" and signal "null" +0ms
  MongoMS:MongoInstance Mongo[46574]: stop +0ms
  MongoMS:utils Mongo[46574] killProcess: mongodProcess: sending "SIGINT" +0ms
  MongoMS:MongoInstance Mongo[46574]: closeHandler: code: "null", signal: "null" +0ms
  MongoMS:MongoInstance Mongo[46574]: stdoutHandler: ""{"t":{"$date":"2023-09-29T09:20:22.464-04:00"},"s":"I",  "c":"CONTROL",  "id":23377,   "ctx":"SignalHandler","msg":"Received signal","attr":{"signal":2,"error":"Interrupt: 2"}}
  MongoMS:MongoInstance {"t":{"$date":"2023-09-29T09:20:22.464-04:00"},"s":"I",  "c":"CONTROL",  "id":23381,   "ctx":"SignalHandler","msg":"will terminate after current cmd ends"}
  MongoMS:MongoInstance {"t":{"$date":"2023-09-29T09:20:22.464-04:00"},"s":"I",  "c":"REPL",     "id":4784900, "ctx":"SignalHandler","msg":"Stepping down the ReplicationCoordinator for shutdown","attr":{"waitTimeMillis":15000}}"" +1ms
  MongoMS:MongoInstance Mongo[46574]: stdoutHandler: ""{"t":{"$date":"2023-09-29T09:20:22.464-04:00"},"s":"I",  "c":"REPL",     "id":4794602, "ctx":"SignalHandler","msg":"Attempting to enter quiesce mode"}
  MongoMS:MongoInstance {"t":{"$date":"2023-09-29T09:20:22.464-04:00"},"s":"I",  "c":"-",        "id":6371601, "ctx":"SignalHandler","msg":"Shutting down the FLE Crud thread pool"}
  MongoMS:MongoInstance {"t":{"$date":"2023-09-29T09:20:22.464-04:00"},"s":"I",  "c":"COMMAND",  "id":4784901, "ctx":"SignalHandler","msg":"Shutting down the MirrorMaestro"}
  MongoMS:MongoInstance {"t":{"$date":"2023-09-29T09:20:22.465-04:00"},"s":"I",  "c":"SHARDING", "id":4784902, "ctx":"SignalHandler","msg":"Shutting down the WaitForMajorityService"}"" +0ms
  MongoMS:MongoInstance Mongo[46574]: stdoutHandler: ""{"t":{"$date":"2023-09-29T09:20:22.465-04:00"},"s":"I",  "c":"CONTROL",  "id":4784903, "ctx":"SignalHandler","msg":"Shutting down the LogicalSessionCache"}"" +0ms
  MongoMS:MongoInstance Mongo[46574]: stdoutHandler: ""{"t":{"$date":"2023-09-29T09:20:22.465-04:00"},"s":"I",  "c":"NETWORK",  "id":20562,   "ctx":"SignalHandler","msg":"Shutdown: going to close listening sockets"}"" +0ms
  MongoMS:MongoInstance Mongo[46574]: stdoutHandler: ""{"t":{"$date":"2023-09-29T09:20:22.465-04:00"},"s":"I",  "c":"NETWORK",  "id":23017,   "ctx":"listener","msg":"removing socket file","attr":{"path":"/tmp/mongodb-46574.sock"}}"" +0ms
  MongoMS:MongoInstance Mongo[46574]: stdoutHandler: ""{"t":{"$date":"2023-09-29T09:20:22.465-04:00"},"s":"I",  "c":"NETWORK",  "id":4784905, "ctx":"SignalHandler","msg":"Shutting down the global connection pool"}"" +0ms
  MongoMS:MongoInstance Mongo[46574]: stdoutHandler: ""{"t":{"$date":"2023-09-29T09:20:22.465-04:00"},"s":"I",  "c":"CONTROL",  "id":4784906, "ctx":"SignalHandler","msg":"Shutting down the FlowControlTicketholder"}
  MongoMS:MongoInstance {"t":{"$date":"2023-09-29T09:20:22.465-04:00"},"s":"I",  "c":"-",        "id":20520,   "ctx":"SignalHandler","msg":"Stopping further Flow Control ticket acquisitions."}
  MongoMS:MongoInstance {"t":{"$date":"2023-09-29T09:20:22.465-04:00"},"s":"I",  "c":"REPL",     "id":4784909, "ctx":"SignalHandler","msg":"Shutting down the ReplicationCoordinator"}
  MongoMS:MongoInstance {"t":{"$date":"2023-09-29T09:20:22.465-04:00"},"s":"I",  "c":"SHARDING", "id":4784910, "ctx":"SignalHandler","msg":"Shutting down the ShardingInitializationMongoD"}
  MongoMS:MongoInstance {"t":{"$date":"2023-09-29T09:20:22.465-04:00"},"s":"I",  "c":"REPL",     "id":4784911, "ctx":"SignalHandler","msg":"Enqueuing the ReplicationStateTransitionLock for shutdown"}
  MongoMS:MongoInstance {"t":{"$date":"2023-09-29T09:20:22.465-04:00"},"s":"I",  "c":"-",        "id":4784912, "ctx":"SignalHandler","msg":"Killing all operations for shutdown"}"" +0ms
  MongoMS:MongoInstance Mongo[46574]: stdoutHandler: ""{"t":{"$date":"2023-09-29T09:20:22.465-04:00"},"s":"I",  "c":"-",        "id":4695300, "ctx":"SignalHandler","msg":"Interrupted all currently running operations","attr":{"opsKilled":2}}"" +1ms
  MongoMS:MongoInstance Mongo[46574]: stdoutHandler: ""{"t":{"$date":"2023-09-29T09:20:22.465-04:00"},"s":"I",  "c":"TENANT_M", "id":5093807, "ctx":"SignalHandler","msg":"Shutting down all TenantMigrationAccessBlockers on global shutdown"}
  MongoMS:MongoInstance {"t":{"$date":"2023-09-29T09:20:22.465-04:00"},"s":"I",  "c":"COMMAND",  "id":4784913, "ctx":"SignalHandler","msg":"Shutting down all open transactions"}"" +0ms
  MongoMS:MongoInstance Mongo[46574]: stdoutHandler: ""{"t":{"$date":"2023-09-29T09:20:22.465-04:00"},"s":"I",  "c":"REPL",     "id":4784914, "ctx":"SignalHandler","msg":"Acquiring the ReplicationStateTransitionLock for shutdown"}
  MongoMS:MongoInstance {"t":{"$date":"2023-09-29T09:20:22.465-04:00"},"s":"I",  "c":"INDEX",    "id":4784915, "ctx":"SignalHandler","msg":"Shutting down the IndexBuildsCoordinator"}
  MongoMS:MongoInstance {"t":{"$date":"2023-09-29T09:20:22.465-04:00"},"s":"I",  "c":"NETWORK",  "id":4784918, "ctx":"SignalHandler","msg":"Shutting down the ReplicaSetMonitor"}
  MongoMS:MongoInstance {"t":{"$date":"2023-09-29T09:20:22.466-04:00"},"s":"I",  "c":"SHARDING", "id":4784921, "ctx":"SignalHandler","msg":"Shutting down the MigrationUtilExecutor"}"" +0ms
  MongoMS:MongoInstance Mongo[46574]: stdoutHandler: ""{"t":{"$date":"2023-09-29T09:20:22.466-04:00"},"s":"I",  "c":"ASIO",     "id":22582,   "ctx":"MigrationUtil-TaskExecutor","msg":"Killing all outstanding egress activity."}"" +0ms
  MongoMS:MongoInstance Mongo[46574]: stdoutHandler: ""{"t":{"$date":"2023-09-29T09:20:22.466-04:00"},"s":"I",  "c":"COMMAND",  "id":4784923, "ctx":"SignalHandler","msg":"Shutting down the ServiceEntryPoint"}
  MongoMS:MongoInstance {"t":{"$date":"2023-09-29T09:20:22.466-04:00"},"s":"I",  "c":"CONTROL",  "id":4784925, "ctx":"SignalHandler","msg":"Shutting down free monitoring"}
  MongoMS:MongoInstance {"t":{"$date":"2023-09-29T09:20:22.466-04:00"},"s":"I",  "c":"CONTROL",  "id":20609,   "ctx":"SignalHandler","msg":"Shutting down free monitoring"}"" +0ms
  MongoMS:MongoInstance Mongo[46574]: stdoutHandler: ""{"t":{"$date":"2023-09-29T09:20:22.466-04:00"},"s":"I",  "c":"CONTROL",  "id":4784927, "ctx":"SignalHandler","msg":"Shutting down the HealthLog"}
  MongoMS:MongoInstance {"t":{"$date":"2023-09-29T09:20:22.466-04:00"},"s":"I",  "c":"CONTROL",  "id":4784928, "ctx":"SignalHandler","msg":"Shutting down the TTL monitor"}"" +0ms
  MongoMS:MongoInstance Mongo[46574]: stdoutHandler: ""{"t":{"$date":"2023-09-29T09:20:22.466-04:00"},"s":"I",  "c":"INDEX",    "id":3684100, "ctx":"SignalHandler","msg":"Shutting down TTL collection monitor thread"}"" +0ms
  MongoMS:MongoInstance Mongo[46574]: stdoutHandler: ""{"t":{"$date":"2023-09-29T09:20:22.466-04:00"},"s":"I",  "c":"INDEX",    "id":3684101, "ctx":"SignalHandler","msg":"Finished shutting down TTL collection monitor thread"}
  MongoMS:MongoInstance {"t":{"$date":"2023-09-29T09:20:22.466-04:00"},"s":"I",  "c":"CONTROL",  "id":6278511, "ctx":"SignalHandler","msg":"Shutting down the Change Stream Expired Pre-images Remover"}
  MongoMS:MongoInstance {"t":{"$date":"2023-09-29T09:20:22.466-04:00"},"s":"I",  "c":"CONTROL",  "id":4784929, "ctx":"SignalHandler","msg":"Acquiring the global lock for shutdown"}
  MongoMS:MongoInstance {"t":{"$date":"2023-09-29T09:20:22.466-04:00"},"s":"I",  "c":"CONTROL",  "id":4784930, "ctx":"SignalHandler","msg":"Shutting down the storage engine"}
  MongoMS:MongoInstance {"t":{"$date":"2023-09-29T09:20:22.466-04:00"},"s":"I",  "c":"STORAGE",  "id":22320,   "ctx":"SignalHandler","msg":"Shutting down journal flusher thread"}"" +0ms
  MongoMS:MongoInstance Mongo[46574]: stdoutHandler: ""{"t":{"$date":"2023-09-29T09:20:22.466-04:00"},"s":"I",  "c":"STORAGE",  "id":22321,   "ctx":"SignalHandler","msg":"Finished shutting down journal flusher thread"}
  MongoMS:MongoInstance {"t":{"$date":"2023-09-29T09:20:22.466-04:00"},"s":"I",  "c":"STORAGE",  "id":20282,   "ctx":"SignalHandler","msg":"Deregistering all the collections"}"" +0ms
  MongoMS:MongoInstance Mongo[46574]: stdoutHandler: ""{"t":{"$date":"2023-09-29T09:20:22.466-04:00"},"s":"I",  "c":"STORAGE",  "id":22261,   "ctx":"SignalHandler","msg":"Timestamp monitor shutting down"}"" +0ms
  MongoMS:MongoInstance Mongo[46574]: stdoutHandler: ""{"t":{"$date":"2023-09-29T09:20:22.466-04:00"},"s":"I",  "c":"STORAGE",  "id":22279,   "ctx":"SignalHandler","msg":"shutdown: removing fs lock..."}"" +0ms
  MongoMS:MongoInstance Mongo[46574]: stdoutHandler: ""{"t":{"$date":"2023-09-29T09:20:22.466-04:00"},"s":"I",  "c":"-",        "id":4784931, "ctx":"SignalHandler","msg":"Dropping the scope cache for shutdown"}"" +0ms
  MongoMS:MongoInstance Mongo[46574]: stdoutHandler: ""{"t":{"$date":"2023-09-29T09:20:22.466-04:00"},"s":"I",  "c":"FTDC",     "id":20626,   "ctx":"SignalHandler","msg":"Shutting down full-time diagnostic data capture"}"" +1ms
  MongoMS:MongoInstance Mongo[46574]: stdoutHandler: ""{"t":{"$date":"2023-09-29T09:20:22.467-04:00"},"s":"I",  "c":"CONTROL",  "id":20565,   "ctx":"SignalHandler","msg":"Now exiting"}"" +0ms
  MongoMS:MongoInstance Mongo[46574]: stdoutHandler: ""{"t":{"$date":"2023-09-29T09:20:22.467-04:00"},"s":"I",  "c":"CONTROL",  "id":23138,   "ctx":"SignalHandler","msg":"Shutting down","attr":{"exitCode":0}}"" +0ms
  MongoMS:utils Mongo[46574] killProcess: mongodProcess: got exit signal, Code: 0, Signal: null +6ms
  MongoMS:utils Mongo[46574] killProcess: mongodProcess: got exit signal, Code: 0, Signal: null +0ms
  MongoMS:utils Mongo[46574] killProcess: killerProcess: sending "SIGINT" +1ms
  MongoMS:utils Mongo[46574] killProcess: killerProcess: sending "SIGINT" +0ms
  MongoMS:utils Mongo[46574] killProcess: killerProcess: got exit signal, Code: 0, Signal: null +2ms
  MongoMS:utils Mongo[46574] killProcess: killerProcess: got exit signal, Code: 0, Signal: null +0ms
  MongoMS:MongoInstance Mongo[46574]: stop: Instance Finished Shutdown +6ms
  MongoMS:MongoInstance Mongo[46574]: stop: Instance Finished Shutdown +0ms
github-actions[bot] commented 11 months ago

:tada: This issue has been resolved in version 9.0.0-beta.3 :tada:

The release is available on:

Your semantic-release bot :package::rocket:

hasezoey commented 11 months ago

:tada: This issue has been resolved in version 9.0.0 :tada:

The release is available on:

Manual message because semantic-release hit the limit