Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

server.unref is not a function. (In 'server.unref()', 'server.unref' is undefined) #801

Closed
DWboutin opened this issue Sep 28, 2023 · 16 comments
Closed

server.unref is not a function. (In 'server.unref()', 'server.unref' is undefined) #801

DWboutin opened this issue Sep 28, 2023 · 16 comments
Labels
bug engine: bun Issue with JS engine "bun" not a MMS issue This is not an issue for "mongodb-memory-server" released on @beta released Pull Request released | Issue is fixed

Comments

@DWboutin
Copy link

Versions

  • Bun: 1.0.3
  • mongodb-memory-server-*: ^9.0.0-beta.2
  • mongodb(the binary version): ^6.1.0
  • mongodb(the js package): 0.0.0
  • mongoose: 7.5.2
  • system: MacOS

package: mongo-memory-server

What is the Problem?

Looks like a problem with the port, but I didn't specified one.

Code Example

My repo: https://github.com/DWboutin/kiosq-backend

It's the only thing implemented

Debug Output

Debug Output 
src/features/users/__tests__/UserRepository.spec.ts:
  MongoMS:ResolveConfig Debug Mode Enabled, through Environment Variable +0ms
  MongoMS:ResolveConfig findPackageJson: Found package.json at "/Users/mikaelboutin/Desktop/coding/bun-backend/package.json" +1ms
  MongoMS:MongoMemoryServer create: Called .create() method +0ms
  MongoMS:MongoMemoryServer Mongo[unknown]: start: Called .start() method +0ms
  MongoMS:MongoMemoryServer Mongo[unknown]: _startUpInstance: Called MongoMemoryServer._startUpInstance() method +0ms
  MongoMS:MongoMemoryServer Mongo[unknown]: getStartOptions: forceSamePort: false +1ms
  MongoMS:MongoMemoryServer Mongo[unknown]: _startUpInstance threw a Error:  [TypeError: server.unref is not a function. (In 'server.unref()', 'server.unref' is undefined)] +1ms
  MongoMS:MongoMemoryServer Mongo[unknown]: stop: Called .stop() method +0ms
  MongoMS:MongoMemoryServer Mongo[unknown]: stop: "instanceInfo" is not defined (never ran?) +0ms
80 | function tryPort(port) {
81 |     return new Promise((res, rej) => {
82 |         const server = http.createServer();
83 |         server.unref(); // dont keep this server from exiting the application
84 |         server.on('error', (err) => {
85 |             if (err?.code !== 'EADDRINUSE') {
                        ^
TypeError: server.unref is not a function. (In 'server.unref()', 'server.unref' is undefined)
at /Users/mikaelboutin/Desktop/coding/bun-backend/node_modules/mongodb-memory-server-core/lib/util/getport/index.js:85:21

Do you know why it happenes?

no
@DWboutin DWboutin added the bug label Sep 28, 2023
@hasezoey
Copy link
Member

Looks like a problem with the port, but I didn't specified one.

a port is always required, if you dont specify one, one will be generated

server.unref is not a function

this is a problem with bun, seems like it does not implement net:server:unref, see bun documentation:

🟡 Missing net.{get|set}DefaultAutoSelectFamily net.SocketAddress net.BlockList net.Server.ref() net.Server.unref() net.Socket.ref() net.Socket.unref().

source

Not a problem with MMS and bun is also not officially supported by MMS, please open a issue with bun instead (deno somewhat recently had added this)

@hasezoey hasezoey added the not a MMS issue This is not an issue for "mongodb-memory-server" label Sep 28, 2023
@DWboutin
Copy link
Author

Thanks!

@hasezoey
Copy link
Member

btw, does MMS work if you comment out that line (server.unref())? if yes, then i could add a check to see if the function exists and only call it then (but bun will still not be officially supported)

@DWboutin
Copy link
Author

It goes further but does this

src/features/users/__tests__/UserRepository.spec.ts:
  MongoMS:ResolveConfig Debug Mode Enabled, through Environment Variable +0ms
  MongoMS:ResolveConfig findPackageJson: Found package.json at "/Users/mikaelboutin/Desktop/coding/bun-backend/package.json" +2ms
  MongoMS:MongoMemoryServer create: Called .create() method +0ms
  MongoMS:MongoMemoryServer Mongo[unknown]: start: Called .start() method +0ms
  MongoMS:MongoMemoryServer Mongo[unknown]: _startUpInstance: Called MongoMemoryServer._startUpInstance() method +0ms
  MongoMS:MongoMemoryServer Mongo[unknown]: getStartOptions: forceSamePort: false +1ms
  MongoMS:DryMongoBinary generateOptions +0ms
  MongoMS:DryMongoBinary generateDownloadPath: Generating Download Path, preferGlobal: "true" +0ms
  MongoMS:DryMongoBinary generatePaths { version: '6.0.9',
  downloadDir: '',
  os: { os: 'darwin' },
  platform: 'darwin',
  arch: 'x64',
  systemBinary: '' } +1ms
  MongoMS:DryMongoBinary getBinaryName +1ms
  MongoMS:DryMongoBinary combineBinaryName +1ms
  MongoMS:DryMongoBinary combineBinaryName +0ms
  MongoMS:DryMongoBinary combineBinaryName +0ms
  MongoMS:DryMongoBinary generateDownloadPath: Paths: { homeCache: '/Users/mikaelboutin/.cache/mongodb-binaries/mongod-x64-darwin-6.0.9',
  modulesCache: '/Users/mikaelboutin/Desktop/coding/bun-backend/node_modules/.cache/mongodb-memory-server/mongod-x64-darwin-6.0.9',
  relative: '/Users/mikaelboutin/Desktop/coding/bun-backend/mongodb-binaries/mongod-x64-darwin-6.0.9',
  resolveConfig: '' }  +0ms
  MongoMS:DryMongoBinary generateDownloadPath: no existing binary for version "6.0.9" was found +0ms
  MongoMS:DryMongoBinary generateDownloadPath: using global (preferGlobal) "/Users/mikaelboutin/.cache/mongodb-binaries/mongod-x64-darwin-6.0.9" +0ms
  MongoMS:MongoMemoryServer Mongo[unknown]: _startUpInstance: Creating new MongoDB instance with options: { instance: 
   { port: 46574,
     dbName: '',
     ip: '127.0.0.1',
     storageEngine: 'ephemeralForTest',
     replSet: undefined,
     dbPath: '/var/folders/96/n4xpb48143qfrn85rm3l7j240000gn/T/mongo-mem-1SqFbP',
     tmpDir: '/var/folders/96/n4xpb48143qfrn85rm3l7j240000gn/T/mongo-mem-1SqFbP',
     keyfileLocation: undefined,
     launchTimeout: undefined,
     args: undefined,
     auth: false },
  binary: undefined,
  spawn: undefined } +13ms
  MongoMS:MongoInstance create: Called .create() method +0ms
  MongoMS:MongoInstance Mongo[46574]: start +1ms
  MongoMS:MongoBinary getPath +0ms
  MongoMS:DryMongoBinary generateOptions +2ms
  MongoMS:DryMongoBinary generateDownloadPath: Generating Download Path, preferGlobal: "true" +0ms
  MongoMS:DryMongoBinary generatePaths { version: '6.0.9',
  downloadDir: '',
  os: { os: 'darwin' },
  platform: 'darwin',
  arch: 'x64',
  systemBinary: '' } +0ms
  MongoMS:DryMongoBinary getBinaryName +0ms
  MongoMS:DryMongoBinary combineBinaryName +0ms
  MongoMS:DryMongoBinary combineBinaryName +0ms
  MongoMS:DryMongoBinary combineBinaryName +1ms
  MongoMS:DryMongoBinary generateDownloadPath: Paths: { homeCache: '/Users/mikaelboutin/.cache/mongodb-binaries/mongod-x64-darwin-6.0.9',
  modulesCache: '/Users/mikaelboutin/Desktop/coding/bun-backend/node_modules/.cache/mongodb-memory-server/mongod-x64-darwin-6.0.9',
  relative: '/Users/mikaelboutin/Desktop/coding/bun-backend/mongodb-binaries/mongod-x64-darwin-6.0.9',
  resolveConfig: '' }  +0ms
  MongoMS:DryMongoBinary generateDownloadPath: no existing binary for version "6.0.9" was found +0ms
  MongoMS:DryMongoBinary generateDownloadPath: using global (preferGlobal) "/Users/mikaelboutin/.cache/mongodb-binaries/mongod-x64-darwin-6.0.9" +0ms
  MongoMS:MongoBinary getPath: MongoBinary options: {
  "version": "6.0.9",
  "downloadDir": "/Users/mikaelboutin/.cache/mongodb-binaries",
  "os": {
    "os": "darwin"
  },
  "platform": "darwin",
  "arch": "x64",
  "systemBinary": "",
  "checkMD5": true
} +1ms
  MongoMS:DryMongoBinary locateBinary: Trying to locate Binary for version "6.0.9" +0ms
  MongoMS:DryMongoBinary generateOptions +0ms
  MongoMS:DryMongoBinary generateDownloadPath: Generating Download Path, preferGlobal: "true" +0ms
  MongoMS:DryMongoBinary generatePaths { version: '6.0.9',
  downloadDir: '/Users/mikaelboutin/.cache/mongodb-binaries',
  os: { os: 'darwin' },
  platform: 'darwin',
  arch: 'x64',
  systemBinary: '' } +1ms
  MongoMS:DryMongoBinary getBinaryName +0ms
  MongoMS:DryMongoBinary combineBinaryName +0ms
  MongoMS:DryMongoBinary combineBinaryName +0ms
  MongoMS:DryMongoBinary generatePaths: resolveConfigValue is not empty +0ms
  MongoMS:DryMongoBinary combineBinaryName +0ms
  MongoMS:DryMongoBinary combineBinaryName +0ms
  MongoMS:DryMongoBinary generateDownloadPath: Paths: { homeCache: '/Users/mikaelboutin/.cache/mongodb-binaries/mongod-x64-darwin-6.0.9',
  modulesCache: '/Users/mikaelboutin/Desktop/coding/bun-backend/node_modules/.cache/mongodb-memory-server/mongod-x64-darwin-6.0.9',
  relative: '/Users/mikaelboutin/Desktop/coding/bun-backend/mongodb-binaries/mongod-x64-darwin-6.0.9',
  resolveConfig: '/Users/mikaelboutin/.cache/mongodb-binaries/mongod-x64-darwin-6.0.9' }  +0ms
  MongoMS:DryMongoBinary generateDownloadPath: no existing binary for version "6.0.9" was found +1ms
  MongoMS:DryMongoBinary generateDownloadPath: using resolveConfig (DOWNLOAD_DIR) "/Users/mikaelboutin/.cache/mongodb-binaries/mongod-x64-darwin-6.0.9" +0ms
  MongoMS:DryMongoBinary locateBinary: running generateDownloadPath +0ms
  MongoMS:DryMongoBinary generateDownloadPath: Generating Download Path, preferGlobal: "true" +0ms
  MongoMS:DryMongoBinary generatePaths { version: '6.0.9',
  downloadDir: '/Users/mikaelboutin/.cache/mongodb-binaries',
  os: { os: 'darwin' },
  platform: 'darwin',
  arch: 'x64',
  systemBinary: '' } +0ms
  MongoMS:DryMongoBinary getBinaryName +0ms
  MongoMS:DryMongoBinary combineBinaryName +0ms
  MongoMS:DryMongoBinary combineBinaryName +0ms
  MongoMS:DryMongoBinary generatePaths: resolveConfigValue is not empty +0ms
  MongoMS:DryMongoBinary combineBinaryName +0ms
  MongoMS:DryMongoBinary combineBinaryName +0ms
  MongoMS:DryMongoBinary generateDownloadPath: Paths: { homeCache: '/Users/mikaelboutin/.cache/mongodb-binaries/mongod-x64-darwin-6.0.9',
  modulesCache: '/Users/mikaelboutin/Desktop/coding/bun-backend/node_modules/.cache/mongodb-memory-server/mongod-x64-darwin-6.0.9',
  relative: '/Users/mikaelboutin/Desktop/coding/bun-backend/mongodb-binaries/mongod-x64-darwin-6.0.9',
  resolveConfig: '/Users/mikaelboutin/.cache/mongodb-binaries/mongod-x64-darwin-6.0.9' }  +0ms
  MongoMS:DryMongoBinary generateDownloadPath: no existing binary for version "6.0.9" was found +0ms
  MongoMS:DryMongoBinary generateDownloadPath: using resolveConfig (DOWNLOAD_DIR) "/Users/mikaelboutin/.cache/mongodb-binaries/mongod-x64-darwin-6.0.9" +0ms
  MongoMS:DryMongoBinary locateBinary: could not find a existing binary +0ms
  MongoMS:MongoBinary getPath: "RUNTIME_DOWNLOAD" is "true", trying to download +3ms
  MongoMS:MongoBinary download +0ms
  MongoMS:MongoBinary download: Waiting to acquire Download lock for file "/Users/mikaelboutin/.cache/mongodb-binaries/6.0.9.lock" +0ms
  MongoMS:LockFile lock: Locking file "/Users/mikaelboutin/.cache/mongodb-binaries/6.0.9.lock" +0ms
  MongoMS:LockFile checkLock: for file "/Users/mikaelboutin/.cache/mongodb-binaries/6.0.9.lock" with uuid: "undefined" +1ms
  MongoMS:LockFile createLock: trying to create a lock file for "/Users/mikaelboutin/.cache/mongodb-binaries/6.0.9.lock" +0ms
  MongoMS:LockFile createLock: Lock File Created for file "/Users/mikaelboutin/.cache/mongodb-binaries/6.0.9.lock" +4ms
  MongoMS:MongoBinary download: Download lock acquired +5ms
  MongoMS:MongoBinary download: Adding version 6.0.9 to cache +0ms
  MongoMS:MongoBinaryDownload getMongodPath +0ms
  MongoMS:DryMongoBinary generateOptions +6ms
  MongoMS:DryMongoBinary generateDownloadPath: Generating Download Path, preferGlobal: "true" +0ms
  MongoMS:DryMongoBinary generatePaths { version: '6.0.9',
  downloadDir: '/Users/mikaelboutin/.cache/mongodb-binaries',
  os: { os: 'darwin' },
  platform: 'darwin',
  arch: 'x64',
  systemBinary: '' } +0ms
  MongoMS:DryMongoBinary getBinaryName +1ms
  MongoMS:DryMongoBinary combineBinaryName +0ms
  MongoMS:DryMongoBinary combineBinaryName +0ms
  MongoMS:DryMongoBinary generatePaths: resolveConfigValue is not empty +0ms
  MongoMS:DryMongoBinary combineBinaryName +0ms
  MongoMS:DryMongoBinary combineBinaryName +0ms
  MongoMS:DryMongoBinary generateDownloadPath: Paths: { homeCache: '/Users/mikaelboutin/.cache/mongodb-binaries/mongod-x64-darwin-6.0.9',
  modulesCache: '/Users/mikaelboutin/Desktop/coding/bun-backend/node_modules/.cache/mongodb-memory-server/mongod-x64-darwin-6.0.9',
  relative: '/Users/mikaelboutin/Desktop/coding/bun-backend/mongodb-binaries/mongod-x64-darwin-6.0.9',
  resolveConfig: '/Users/mikaelboutin/.cache/mongodb-binaries/mongod-x64-darwin-6.0.9' }  +0ms
  MongoMS:DryMongoBinary generateDownloadPath: no existing binary for version "6.0.9" was found +0ms
  MongoMS:DryMongoBinary generateDownloadPath: using resolveConfig (DOWNLOAD_DIR) "/Users/mikaelboutin/.cache/mongodb-binaries/mongod-x64-darwin-6.0.9" +0ms
  MongoMS:DryMongoBinary getBinaryName +0ms
  MongoMS:DryMongoBinary combineBinaryName +0ms
  MongoMS:MongoBinaryDownload startDownload +2ms
  MongoMS:MongoBinaryDownloadUrl Using "mongodb-macos-x86_64-6.0.9.tgz" as the Archive String +0ms
  MongoMS:MongoBinaryDownloadUrl Using "https://fastdl.mongodb.org" as the mirror +0ms
  MongoMS:MongoBinaryDownload download +1ms
  MongoMS:MongoBinaryDownload download: Downloading: "https://fastdl.mongodb.org/osx/mongodb-macos-x86_64-6.0.9.tgz" +0ms
  MongoMS:MongoBinaryDownload httpDownload +0ms
  MongoMS:MongoBinaryDownload httpDownload: trying to download "https://fastdl.mongodb.org/osx/mongodb-macos-x86_64-6.0.9.tgz" +1ms
  MongoMS:MongoBinaryDownload httpDownload: moved "/Users/mikaelboutin/.cache/mongodb-binaries/mongodb-macos-x86_64-6.0.9.tgz.downloading" to "/Users/mikaelboutin/.cache/mongodb-binaries/mongodb-macos-x86_64-6.0.9.tgz" +3s
  MongoMS:MongoBinaryDownload makeMD5check: Checking MD5 of downloaded binary... +0ms
  MongoMS:MongoBinaryDownload download +0ms
  MongoMS:MongoBinaryDownload download: Downloading: "https://fastdl.mongodb.org/osx/mongodb-macos-x86_64-6.0.9.tgz.md5" +1ms
  MongoMS:MongoBinaryDownload httpDownload +0ms
  MongoMS:MongoBinaryDownload httpDownload: trying to download "https://fastdl.mongodb.org/osx/mongodb-macos-x86_64-6.0.9.tgz.md5" +0ms
  MongoMS:MongoBinaryDownload httpDownload: moved "/Users/mikaelboutin/.cache/mongodb-binaries/mongodb-macos-x86_64-6.0.9.tgz.md5.downloading" to "/Users/mikaelboutin/.cache/mongodb-binaries/mongodb-macos-x86_64-6.0.9.tgz.md5" +80ms
  MongoMS:MongoBinaryDownload makeMD5check: Local MD5: 167645310ec7c425f3faf39b20080201, Remote MD5: 167645310ec7c425f3faf39b20080201 +132ms
  MongoMS:MongoBinaryDownload extract +1ms
  MongoMS:DryMongoBinary generateOptions +4s
  MongoMS:DryMongoBinary generateDownloadPath: Generating Download Path, preferGlobal: "true" +0ms
  MongoMS:DryMongoBinary generatePaths { version: '6.0.9',
  downloadDir: '/Users/mikaelboutin/.cache/mongodb-binaries',
  os: { os: 'darwin' },
  platform: 'darwin',
  arch: 'x64',
  systemBinary: '' } +0ms
  MongoMS:DryMongoBinary getBinaryName +0ms
  MongoMS:DryMongoBinary combineBinaryName +0ms
  MongoMS:DryMongoBinary combineBinaryName +0ms
  MongoMS:DryMongoBinary generatePaths: resolveConfigValue is not empty +0ms
  MongoMS:DryMongoBinary combineBinaryName +0ms
  MongoMS:DryMongoBinary combineBinaryName +0ms
  MongoMS:DryMongoBinary generateDownloadPath: Paths: { homeCache: '/Users/mikaelboutin/.cache/mongodb-binaries/mongod-x64-darwin-6.0.9',
  modulesCache: '/Users/mikaelboutin/Desktop/coding/bun-backend/node_modules/.cache/mongodb-memory-server/mongod-x64-darwin-6.0.9',
  relative: '/Users/mikaelboutin/Desktop/coding/bun-backend/mongodb-binaries/mongod-x64-darwin-6.0.9',
  resolveConfig: '/Users/mikaelboutin/.cache/mongodb-binaries/mongod-x64-darwin-6.0.9' }  +0ms
  MongoMS:DryMongoBinary generateDownloadPath: no existing binary for version "6.0.9" was found +1ms
  MongoMS:DryMongoBinary generateDownloadPath: using resolveConfig (DOWNLOAD_DIR) "/Users/mikaelboutin/.cache/mongodb-binaries/mongod-x64-darwin-6.0.9" +0ms
  MongoMS:DryMongoBinary getBinaryName +0ms
  MongoMS:DryMongoBinary combineBinaryName +0ms
  MongoMS:MongoBinaryDownload extract: archive: "/Users/mikaelboutin/.cache/mongodb-binaries/mongodb-macos-x86_64-6.0.9.tgz" final: "/Users/mikaelboutin/.cache/mongodb-binaries/mongod-x64-darwin-6.0.9" +1ms
  MongoMS:MongoBinaryDownload extractTarGz +0ms
  MongoMS:MongoBinary download: Removing Download lock +6s
  MongoMS:LockFile unlock: Unlocking file "/Users/mikaelboutin/.cache/mongodb-binaries/6.0.9.lock" +6s
  MongoMS:LockFile checkLock: for file "/Users/mikaelboutin/.cache/mongodb-binaries/6.0.9.lock" with uuid: "271a3565-1c45-4a26-9dde-eccc098b965b" +0ms
  MongoMS:LockFile checkLock: Lock File Already exists, and is for *this* process, with uuid: "271a3565-1c45-4a26-9dde-eccc098b965b" +1ms
  MongoMS:LockFile unlock: Lock Status was "availableInstance" for file "/Users/mikaelboutin/.cache/mongodb-binaries/6.0.9.lock" +0ms
  MongoMS:LockFile unlockCleanup: for file "/Users/mikaelboutin/.cache/mongodb-binaries/6.0.9.lock" +0ms
  MongoMS:MongoBinary download: Download lock removed +8ms
  MongoMS:MongoBinary getPath: Mongod binary path: "/Users/mikaelboutin/.cache/mongodb-binaries/mongod-x64-darwin-6.0.9" +0ms
  MongoMS:MongoInstance Mongo[46574]: start: Starting Processes +6s
  MongoMS:MongoInstance Mongo[46574]: _launchMongod: Launching Mongod Process +0ms
  MongoMS:MongoInstance Mongo[46574]: prepareCommandArgs +0ms
  MongoMS:MongoInstance Mongo[46574]: prepareCommandArgs: final argument array:["--port","46574","--dbpath","/var/folders/96/n4xpb48143qfrn85rm3l7j240000gn/T/mongo-mem-1SqFbP","--storageEngine","ephemeralForTest","--bind_ip","127.0.0.1","--noauth"] +1ms
  MongoMS:MongoInstance Mongo[46574]: _launchKiller: Launching Killer Process (parent: 7317, child: 7322) +42ms
  MongoMS:MongoInstance Mongo[46574]: stdoutHandler: ""{"t":{"$date":"2023-09-29T13:20:22.171Z"},"s":"I",  "c":"CONTROL",  "id":5324701, "ctx":"-","msg":"Test storage engine does not support enableMajorityReadConcern=true, forcibly setting to false","attr":{"storageEngine":"ephemeralForTest"}}"" +1s
  MongoMS:MongoInstance Mongo[46574]: stdoutHandler: ""{"t":{"$date":"2023-09-29T13:20:22.172Z"},"s":"W",  "c":"CONTROL",  "id":4788401, "ctx":"-","msg":"Lock-free reads is not compatible with enableMajorityReadConcern=false: disabling lock-free reads."}"" +1ms
  MongoMS:MongoInstance Mongo[46574]: stdoutHandler: ""{"t":{"$date":"2023-09-29T09:20:22.178-04:00"},"s":"I",  "c":"NETWORK",  "id":4915701, "ctx":"thread1","msg":"Initialized wire specification","attr":{"spec":{"incomingExternalClient":{"minWireVersion":0,"maxWireVersion":17},"incomingInternalClient":{"minWireVersion":0,"maxWireVersion":17},"outgoing":{"minWireVersion":6,"maxWireVersion":17},"isInternalClient":true}}}"" +4ms
  MongoMS:MongoInstance Mongo[46574]: stdoutHandler: ""{"t":{"$date":"2023-09-29T09:20:22.193-04:00"},"s":"I",  "c":"CONTROL",  "id":23285,   "ctx":"thread1","msg":"Automatically disabling TLS 1.0, to force-enable TLS 1.0 specify --sslDisabledProtocols 'none'"}"" +14ms
  MongoMS:MongoInstance Mongo[46574]: stdoutHandler: ""{"t":{"$date":"2023-09-29T09:20:22.193-04:00"},"s":"I",  "c":"NETWORK",  "id":4648602, "ctx":"thread1","msg":"Implicit TCP FastOpen in use."}"" +0ms
  MongoMS:MongoInstance Mongo[46574]: stdoutHandler: ""{"t":{"$date":"2023-09-29T09:20:22.197-04:00"},"s":"I",  "c":"REPL",     "id":5123008, "ctx":"thread1","msg":"Successfully registered PrimaryOnlyService","attr":{"service":"TenantMigrationDonorService","namespace":"config.tenantMigrationDonors"}}
  MongoMS:MongoInstance {"t":{"$date":"2023-09-29T09:20:22.197-04:00"},"s":"I",  "c":"REPL",     "id":5123008, "ctx":"thread1","msg":"Successfully registered PrimaryOnlyService","attr":{"service":"TenantMigrationRecipientService","namespace":"config.tenantMigrationRecipients"}}
  MongoMS:MongoInstance {"t":{"$date":"2023-09-29T09:20:22.197-04:00"},"s":"I",  "c":"REPL",     "id":5123008, "ctx":"thread1","msg":"Successfully registered PrimaryOnlyService","attr":{"service":"ShardSplitDonorService","namespace":"config.tenantSplitDonors"}}"" +5ms
  MongoMS:MongoInstance Mongo[46574]: stdoutHandler: ""{"t":{"$date":"2023-09-29T09:20:22.197-04:00"},"s":"I",  "c":"CONTROL",  "id":5945603, "ctx":"thread1","msg":"Multi threading initialized"}
  MongoMS:MongoInstance {"t":{"$date":"2023-09-29T09:20:22.197-04:00"},"s":"I",  "c":"CONTROL",  "id":4615611, "ctx":"initandlisten","msg":"MongoDB starting","attr":{"pid":7322,"port":46574,"dbPath":"/var/folders/96/n4xpb48143qfrn85rm3l7j240000gn/T/mongo-mem-1SqFbP","architecture":"64-bit","host":"Mikaels-MacBook-Pro.local"}}
  MongoMS:MongoInstance {"t":{"$date":"2023-09-29T09:20:22.197-04:00"},"s":"I",  "c":"CONTROL",  "id":23403,   "ctx":"initandlisten","msg":"Build Info","attr":{"buildInfo":{"version":"6.0.9","gitVersion":"90c65f9cc8fc4e6664a5848230abaa9b3f3b02f7","modules":[],"allocator":"system","environment":{"distarch":"x86_64","target_arch":"x86_64"}}}}
  MongoMS:MongoInstance {"t":{"$date":"2023-09-29T09:20:22.197-04:00"},"s":"I",  "c":"CONTROL",  "id":51765,   "ctx":"initandlisten","msg":"Operating System","attr":{"os":{"name":"Mac OS X","version":"22.6.0"}}}
  MongoMS:MongoInstance {"t":{"$date":"2023-09-29T09:20:22.197-04:00"},"s":"I",  "c":"CONTROL",  "id":21951,   "ctx":"initandlisten","msg":"Options set by command line","attr":{"options":{"net":{"bindIp":"127.0.0.1","port":46574},"security":{"authorization":"disabled"},"storage":{"dbPath":"/var/folders/96/n4xpb48143qfrn85rm3l7j240000gn/T/mongo-mem-1SqFbP","engine":"ephemeralForTest"}}}}"" +1ms
  MongoMS:MongoInstance Mongo[46574]: stdoutHandler: ""{"t":{"$date":"2023-09-29T09:20:22.199-04:00"},"s":"I",  "c":"NETWORK",  "id":5693100, "ctx":"initandlisten","msg":"Asio socket.set_option failed with std::system_error","attr":{"note":"acceptor TCP fast open","option":{"level":6,"name":261,"data":"00 04 00 00"},"error":{"what":"set_option: Invalid argument","message":"Invalid argument","category":"asio.system","value":22}}}"" +1ms
  MongoMS:MongoInstance Mongo[46574]: stdoutHandler: ""{"t":{"$date":"2023-09-29T09:20:22.202-04:00"},"s":"I",  "c":"CONTROL",  "id":22197,   "ctx":"initandlisten","msg":"The ephemeralForTest storage engine is for testing only. Do not use in production","tags":["startupWarnings"]}"" +2ms
  MongoMS:MongoInstance Mongo[46574]: stdoutHandler: ""{"t":{"$date":"2023-09-29T09:20:22.203-04:00"},"s":"I",  "c":"STORAGE",  "id":20320,   "ctx":"initandlisten","msg":"createCollection","attr":{"namespace":"admin.system.version","uuidDisposition":"provided","uuid":{"uuid":{"$uuid":"9dd55c11-d159-49d5-acde-a7e71f2576aa"}},"options":{"uuid":{"$uuid":"9dd55c11-d159-49d5-acde-a7e71f2576aa"}}}}"" +1ms
  MongoMS:MongoInstance Mongo[46574]: stdoutHandler: ""{"t":{"$date":"2023-09-29T09:20:22.205-04:00"},"s":"I",  "c":"INDEX",    "id":20345,   "ctx":"initandlisten","msg":"Index build: done building","attr":{"buildUUID":null,"collectionUUID":{"uuid":{"$uuid":"9dd55c11-d159-49d5-acde-a7e71f2576aa"}},"namespace":"admin.system.version","index":"_id_","ident":"index-1-7460808345534661616","collectionIdent":"collection-0-7460808345534661616","commitTimestamp":null}}"" +3ms
  MongoMS:MongoInstance Mongo[46574]: stdoutHandler: ""{"t":{"$date":"2023-09-29T09:20:22.207-04:00"},"s":"I",  "c":"REPL",     "id":20459,   "ctx":"initandlisten","msg":"Setting featureCompatibilityVersion","attr":{"newVersion":"6.0"}}"" +1ms
  MongoMS:MongoInstance Mongo[46574]: stdoutHandler: ""{"t":{"$date":"2023-09-29T09:20:22.207-04:00"},"s":"I",  "c":"REPL",     "id":5853300, "ctx":"initandlisten","msg":"current featureCompatibilityVersion value","attr":{"featureCompatibilityVersion":"6.0","context":"setFCV"}}
  MongoMS:MongoInstance {"t":{"$date":"2023-09-29T09:20:22.207-04:00"},"s":"I",  "c":"NETWORK",  "id":4915702, "ctx":"initandlisten","msg":"Updated wire specification","attr":{"oldSpec":{"incomingExternalClient":{"minWireVersion":0,"maxWireVersion":17},"incomingInternalClient":{"minWireVersion":0,"maxWireVersion":17},"outgoing":{"minWireVersion":6,"maxWireVersion":17},"isInternalClient":true},"newSpec":{"incomingExternalClient":{"minWireVersion":0,"maxWireVersion":17},"incomingInternalClient":{"minWireVersion":17,"maxWireVersion":17},"outgoing":{"minWireVersion":17,"maxWireVersion":17},"isInternalClient":true}}}"" +0ms
  MongoMS:MongoInstance Mongo[46574]: stdoutHandler: ""{"t":{"$date":"2023-09-29T09:20:22.208-04:00"},"s":"I",  "c":"NETWORK",  "id":4915702, "ctx":"initandlisten","msg":"Updated wire specification","attr":{"oldSpec":{"incomingExternalClient":{"minWireVersion":0,"maxWireVersion":17},"incomingInternalClient":{"minWireVersion":17,"maxWireVersion":17},"outgoing":{"minWireVersion":17,"maxWireVersion":17},"isInternalClient":true},"newSpec":{"incomingExternalClient":{"minWireVersion":0,"maxWireVersion":17},"incomingInternalClient":{"minWireVersion":17,"maxWireVersion":17},"outgoing":{"minWireVersion":17,"maxWireVersion":17},"isInternalClient":true}}}
  MongoMS:MongoInstance {"t":{"$date":"2023-09-29T09:20:22.208-04:00"},"s":"I",  "c":"REPL",     "id":5853300, "ctx":"initandlisten","msg":"current featureCompatibilityVersion value","attr":{"featureCompatibilityVersion":"6.0","context":"startup"}}"" +1ms
  MongoMS:MongoInstance Mongo[46574]: stdoutHandler: ""{"t":{"$date":"2023-09-29T09:20:22.208-04:00"},"s":"I",  "c":"STORAGE",  "id":5071100, "ctx":"initandlisten","msg":"Clearing temp directory"}"" +0ms
  MongoMS:MongoInstance Mongo[46574]: stdoutHandler: ""{"t":{"$date":"2023-09-29T09:20:22.208-04:00"},"s":"I",  "c":"CONTROL",  "id":20536,   "ctx":"initandlisten","msg":"Flow Control is enabled on this deployment"}"" +0ms
  MongoMS:MongoInstance Mongo[46574]: stdoutHandler: ""{"t":{"$date":"2023-09-29T09:20:22.208-04:00"},"s":"I",  "c":"FTDC",     "id":20625,   "ctx":"initandlisten","msg":"Initializing full-time diagnostic data capture","attr":{"dataDirectory":"/var/folders/96/n4xpb48143qfrn85rm3l7j240000gn/T/mongo-mem-1SqFbP/diagnostic.data"}}"" +0ms
  MongoMS:MongoInstance Mongo[46574]: stdoutHandler: ""{"t":{"$date":"2023-09-29T09:20:22.211-04:00"},"s":"I",  "c":"STORAGE",  "id":20320,   "ctx":"initandlisten","msg":"createCollection","attr":{"namespace":"local.startup_log","uuidDisposition":"generated","uuid":{"uuid":{"$uuid":"a1cb7836-ff76-46ed-b92b-6d7b5d0754c7"}},"options":{"capped":true,"size":10485760}}}"" +3ms
  MongoMS:MongoInstance Mongo[46574]: stdoutHandler: ""{"t":{"$date":"2023-09-29T09:20:22.211-04:00"},"s":"I",  "c":"INDEX",    "id":20345,   "ctx":"initandlisten","msg":"Index build: done building","attr":{"buildUUID":null,"collectionUUID":{"uuid":{"$uuid":"a1cb7836-ff76-46ed-b92b-6d7b5d0754c7"}},"namespace":"local.startup_log","index":"_id_","ident":"index-3-7460808345534661616","collectionIdent":"collection-2-7460808345534661616","commitTimestamp":null}}"" +0ms
  MongoMS:MongoInstance Mongo[46574]: stdoutHandler: ""{"t":{"$date":"2023-09-29T09:20:22.211-04:00"},"s":"I",  "c":"REPL",     "id":6015317, "ctx":"initandlisten","msg":"Setting new configuration state","attr":{"newState":"ConfigReplicationDisabled","oldState":"ConfigPreStart"}}"" +0ms
  MongoMS:MongoInstance Mongo[46574]: stdoutHandler: ""{"t":{"$date":"2023-09-29T09:20:22.211-04:00"},"s":"I",  "c":"STORAGE",  "id":22262,   "ctx":"initandlisten","msg":"Timestamp monitor starting"}"" +1ms
  MongoMS:MongoInstance Mongo[46574]: stdoutHandler: ""{"t":{"$date":"2023-09-29T09:20:22.213-04:00"},"s":"I",  "c":"NETWORK",  "id":23015,   "ctx":"listener","msg":"Listening on","attr":{"address":"/tmp/mongodb-46574.sock"}}"" +1ms
  MongoMS:MongoInstance Mongo[46574]: stdoutHandler: ""{"t":{"$date":"2023-09-29T09:20:22.213-04:00"},"s":"I",  "c":"NETWORK",  "id":23015,   "ctx":"listener","msg":"Listening on","attr":{"address":"127.0.0.1"}}
  MongoMS:MongoInstance {"t":{"$date":"2023-09-29T09:20:22.213-04:00"},"s":"I",  "c":"NETWORK",  "id":23016,   "ctx":"listener","msg":"Waiting for connections","attr":{"port":46574,"ssl":"off"}}"" +0ms
  MongoMS:MongoInstance Mongo[46574]: constructor: Instance is ready! +0ms
  MongoMS:MongoInstance Mongo[46574]: start: Processes Started +1ms
  MongoMS:MongoMemoryServer Mongo[unknown]: _startUpInstance: Instance Started, createAuth: "false" +7s
  MongoMS:MongoMemoryServer Mongo[46574]: start: Instance fully Started +0ms
  MongoMS:MongoMemoryServer Mongo[46574]: getUri: running undefined undefined +0ms
  MongoMS:MongoInstance Mongo[46574]: stdoutHandler: ""{"t":{"$date":"2023-09-29T09:20:22.215-04:00"},"s":"I",  "c":"CONTROL",  "id":20712,   "ctx":"LogicalSessionCacheReap","msg":"Sessions collection is not set up; waiting until next sessions reap interval","attr":{"error":"NamespaceNotFound: config.system.sessions does not exist"}}
  MongoMS:MongoInstance {"t":{"$date":"2023-09-29T09:20:22.216-04:00"},"s":"I",  "c":"STORAGE",  "id":20320,   "ctx":"LogicalSessionCacheRefresh","msg":"createCollection","attr":{"namespace":"config.system.sessions","uuidDisposition":"generated","uuid":{"uuid":{"$uuid":"5f3bd48d-eb0a-420d-980a-7b05338d1369"}},"options":{}}}
  MongoMS:MongoInstance {"t":{"$date":"2023-09-29T09:20:22.216-04:00"},"s":"I",  "c":"INDEX",    "id":20345,   "ctx":"LogicalSessionCacheRefresh","msg":"Index build: done building","attr":{"buildUUID":null,"collectionUUID":{"uuid":{"$uuid":"5f3bd48d-eb0a-420d-980a-7b05338d1369"}},"namespace":"config.system.sessions","index":"_id_","ident":"index-5-7460808345534661616","collectionIdent":"collection-4-7460808345534661616","commitTimestamp":null}}
  MongoMS:MongoInstance {"t":{"$date":"2023-09-29T09:20:22.216-04:00"},"s":"I",  "c":"INDEX",    "id":20345,   "ctx":"LogicalSessionCacheRefresh","msg":"Index build: done building","attr":{"buildUUID":null,"collectionUUID":{"uuid":{"$uuid":"5f3bd48d-eb0a-420d-980a-7b05338d1369"}},"namespace":"config.system.sessions","index":"lsidTTLIndex","ident":"index-6-7460808345534661616","collectionIdent":"collection-4-7460808345534661616","commitTimestamp":null}}
  MongoMS:MongoInstance {"t":{"$date":"2023-09-29T09:20:22.233-04:00"},"s":"I",  "c":"NETWORK",  "id":22943,   "ctx":"listener","msg":"Connection accepted","attr":{"remote":"127.0.0.1:50156","uuid":"80be4310-2b90-48dc-af89-cf1792892d7d","connectionId":1,"connectionCount":1}}"" +28ms
  MongoMS:MongoInstance Mongo[46574]: stdoutHandler: ""{"t":{"$date":"2023-09-29T09:20:22.252-04:00"},"s":"I",  "c":"NETWORK",  "id":51800,   "ctx":"conn1","msg":"client metadata","attr":{"remote":"127.0.0.1:50156","client":"conn1","doc":{"driver":{"name":"nodejs|Mongoose","version":"5.8.1|7.5.2"},"platform":"Bun v1.0.3, LE","os":{"name":"darwin","architecture":"x64","version":"22.6.0","type":"Darwin"}}}}"" +10ms
MongoDB connected
  MongoMS:MongoInstance Mongo[46574]: stdoutHandler: ""{"t":{"$date":"2023-09-29T09:20:22.265-04:00"},"s":"I",  "c":"NETWORK",  "id":22943,   "ctx":"listener","msg":"Connection accepted","attr":{"remote":"127.0.0.1:50157","uuid":"fa4f3011-716d-41f6-9f9f-2ade3c8bab1a","connectionId":2,"connectionCount":2}}"" +16ms
  MongoMS:MongoInstance Mongo[46574]: stdoutHandler: ""{"t":{"$date":"2023-09-29T09:20:22.268-04:00"},"s":"I",  "c":"NETWORK",  "id":51800,   "ctx":"conn2","msg":"client metadata","attr":{"remote":"127.0.0.1:50157","client":"conn2","doc":{"driver":{"name":"nodejs|Mongoose","version":"5.8.1|7.5.2"},"platform":"Bun v1.0.3, LE","os":{"name":"darwin","architecture":"x64","version":"22.6.0","type":"Darwin"}}}}"" +0ms
  MongoMS:MongoInstance Mongo[46574]: stdoutHandler: ""{"t":{"$date":"2023-09-29T09:20:22.272-04:00"},"s":"I",  "c":"STORAGE",  "id":20320,   "ctx":"conn2","msg":"createCollection","attr":{"namespace":"kiosq.users","uuidDisposition":"generated","uuid":{"uuid":{"$uuid":"ed52b3b0-23c6-4fd1-aa42-04a8627ab314"}},"options":{}}}"" +4ms
  MongoMS:MongoInstance Mongo[46574]: stdoutHandler: ""{"t":{"$date":"2023-09-29T09:20:22.272-04:00"},"s":"I",  "c":"INDEX",    "id":20345,   "ctx":"conn2","msg":"Index build: done building","attr":{"buildUUID":null,"collectionUUID":{"uuid":{"$uuid":"ed52b3b0-23c6-4fd1-aa42-04a8627ab314"}},"namespace":"kiosq.users","index":"_id_","ident":"index-8-7460808345534661616","collectionIdent":"collection-7-7460808345534661616","commitTimestamp":null}}"" +0ms
  MongoMS:MongoInstance Mongo[46574]: stdoutHandler: ""{"t":{"$date":"2023-09-29T09:20:22.281-04:00"},"s":"I",  "c":"INDEX",    "id":20438,   "ctx":"conn2","msg":"Index build: registering","attr":{"buildUUID":{"uuid":{"$uuid":"a5520c80-cda3-4b1f-847d-9b282f6ecfa6"}},"namespace":"kiosq.users","collectionUUID":{"uuid":{"$uuid":"ed52b3b0-23c6-4fd1-aa42-04a8627ab314"}},"indexes":1,"firstIndex":{"name":"email_1"},"command":{"createIndexes":"users","v":2,"indexes":[{"unique":true,"background":true,"name":"email_1","key":{"email":1}}],"ignoreUnknownIndexOptions":false}}}"" +9ms
  MongoMS:MongoInstance Mongo[46574]: stdoutHandler: ""{"t":{"$date":"2023-09-29T09:20:22.281-04:00"},"s":"I",  "c":"INDEX",    "id":20345,   "ctx":"conn2","msg":"Index build: done building","attr":{"buildUUID":null,"collectionUUID":{"uuid":{"$uuid":"ed52b3b0-23c6-4fd1-aa42-04a8627ab314"}},"namespace":"kiosq.users","index":"email_1","ident":"index-9-7460808345534661616","collectionIdent":"collection-7-7460808345534661616","commitTimestamp":null}}"" +0ms
  MongoMS:MongoInstance Mongo[46574]: stdoutHandler: ""{"t":{"$date":"2023-09-29T09:20:22.281-04:00"},"s":"I",  "c":"INDEX",    "id":20440,   "ctx":"conn2","msg":"Index build: waiting for index build to complete","attr":{"buildUUID":{"uuid":{"$uuid":"a5520c80-cda3-4b1f-847d-9b282f6ecfa6"}},"deadline":{"$date":{"$numberLong":"9223372036854775807"}}}}
  MongoMS:MongoInstance {"t":{"$date":"2023-09-29T09:20:22.281-04:00"},"s":"I",  "c":"INDEX",    "id":20447,   "ctx":"conn2","msg":"Index build: completed","attr":{"buildUUID":{"uuid":{"$uuid":"a5520c80-cda3-4b1f-847d-9b282f6ecfa6"}}}}"" +0ms
  MongoMS:MongoInstance Mongo[46574]: stdoutHandler: ""{"t":{"$date":"2023-09-29T09:20:22.284-04:00"},"s":"I",  "c":"INDEX",    "id":20438,   "ctx":"conn2","msg":"Index build: registering","attr":{"buildUUID":{"uuid":{"$uuid":"d4598ea1-ead8-474d-9901-bd149fb5148a"}},"namespace":"kiosq.users","collectionUUID":{"uuid":{"$uuid":"ed52b3b0-23c6-4fd1-aa42-04a8627ab314"}},"indexes":1,"firstIndex":{"name":"username_1"},"command":{"createIndexes":"users","v":2,"indexes":[{"unique":true,"background":true,"name":"username_1","key":{"username":1}}],"ignoreUnknownIndexOptions":false}}}"" +7ms
  MongoMS:MongoInstance Mongo[46574]: stdoutHandler: ""{"t":{"$date":"2023-09-29T09:20:22.284-04:00"},"s":"I",  "c":"INDEX",    "id":20345,   "ctx":"conn2","msg":"Index build: done building","attr":{"buildUUID":null,"collectionUUID":{"uuid":{"$uuid":"ed52b3b0-23c6-4fd1-aa42-04a8627ab314"}},"namespace":"kiosq.users","index":"username_1","ident":"index-10-7460808345534661616","collectionIdent":"collection-7-7460808345534661616","commitTimestamp":null}}
  MongoMS:MongoInstance {"t":{"$date":"2023-09-29T09:20:22.284-04:00"},"s":"I",  "c":"INDEX",    "id":20440,   "ctx":"conn2","msg":"Index build: waiting for index build to complete","attr":{"buildUUID":{"uuid":{"$uuid":"d4598ea1-ead8-474d-9901-bd149fb5148a"}},"deadline":{"$date":{"$numberLong":"9223372036854775807"}}}}
  MongoMS:MongoInstance {"t":{"$date":"2023-09-29T09:20:22.284-04:00"},"s":"I",  "c":"INDEX",    "id":20447,   "ctx":"conn2","msg":"Index build: completed","attr":{"buildUUID":{"uuid":{"$uuid":"d4598ea1-ead8-474d-9901-bd149fb5148a"}}}}"" +1ms
  MongoMS:MongoInstance Mongo[46574]: stdoutHandler: ""{"t":{"$date":"2023-09-29T09:20:22.461-04:00"},"s":"I",  "c":"NETWORK",  "id":22944,   "ctx":"conn2","msg":"Connection ended","attr":{"remote":"127.0.0.1:50157","uuid":"fa4f3011-716d-41f6-9f9f-2ade3c8bab1a","connectionId":2,"connectionCount":1}}
  MongoMS:MongoInstance {"t":{"$date":"2023-09-29T09:20:22.461-04:00"},"s":"I",  "c":"NETWORK",  "id":22944,   "ctx":"conn1","msg":"Connection ended","attr":{"remote":"127.0.0.1:50156","uuid":"80be4310-2b90-48dc-af89-cf1792892d7d","connectionId":1,"connectionCount":0}}"" +172ms
✓ UserRepository > should create a new user [248.20ms]
  MongoMS:MongoMemoryServer Mongo[46574]: stop: Called .stop() method +249ms
  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
  MongoMS:MongoMemoryServer Mongo[46574]: cleanup: { doCleanup: true, force: false } +10ms
  MongoMS:MongoMemoryServer Mongo[46574]: cleanup: removing tmpDir at /var/folders/96/n4xpb48143qfrn85rm3l7j240000gn/T/mongo-mem-1SqFbP +1ms
2 | Object.defineProperty(exports, "__esModule", { value: true });
3 | exports.GenericMMSError = exports.UnknownLinuxDistro = exports.DownloadError = exports.UnknownVersionError = exports.UnexpectedCloseError = exports.StdoutInstanceError = exports.KnownVersionIncompatibilityError = exports.NoRegexMatchError = exports.ParseArchiveRegexError = exports.ReplsetCountLowError = exports.AssertionFallbackError = exports.BinaryNotFoundError = exports.InsufficientPermissionsError = exports.AuthNotObjectError = exports.KeyFileMissingError = exports.InstanceInfoError = exports.StartBinaryFailedError = exports.Md5CheckFailedError = exports.WaitForPrimaryTimeoutError = exports.UnknownArchitectureError = exports.UnknownPlatformError = exports.UnableToUnlockLockfileError = exports.UnknownLockfileStatusError = exports.StateError = void 0;
4 | const utils_1 = require("./utils");
5 | class StateError extends Error {
6 |     constructor(wantedStates, gotState) {
7 |         super(`Incorrect State for operation: "${gotState}", allowed States: "[${wantedStates.join(',')}]"\n` +
            ^
error: Incorrect State for operation: "new", allowed States: "[stopped]"
This may be because of using a v6.x way of calling functions, look at the following guide if anything applies:
https://nodkz.github.io/mongodb-memory-server/docs/guides/migration/migrate7#no-function-other-than-start-create-ensureinstance-will-be-starting-anything
      at new StateError (/Users/mikaelboutin/Desktop/coding/bun-backend/node_modules/mongodb-memory-server-core/lib/util/errors.js:7:8)
      at assertionIsMMSState (/Users/mikaelboutin/Desktop/coding/bun-backend/node_modules/mongodb-memory-server-core/lib/MongoMemoryServer.js:514:57)
      at /Users/mikaelboutin/Desktop/coding/bun-backend/node_modules/mongodb-memory-server-core/lib/MongoMemoryServer.js:297:8
      at cleanup (/Users/mikaelboutin/Desktop/coding/bun-backend/node_modules/mongodb-memory-server-core/lib/MongoMemoryServer.js:296:18)
      at /Users/mikaelboutin/Desktop/coding/bun-backend/src/features/users/__tests__/UserRepository.spec.ts:19:4
      at processTicksAndRejections (:55:76)
      at processTicksAndRejections (:55:76)

@DWboutin
Copy link
Author

@hasezoey is it a problem about how I use it? Incorrect State for operation: "new", allowed States: "[stopped]" bugs me, I do use .create and not new.

Thanks for your support btw and your work on this lib, really appreciated!

@hasezoey
Copy link
Member

hasezoey commented Sep 29, 2023 •
edited
Loading

is it a problem about how I use it? Incorrect State for operation: "new", allowed States: "[stopped]" bugs me, I do use .create and not new.

it seems like cleanup is called multiple times, what is the code you are calling MMS with? (cleanup is only allowed on stopped states, not on new states, stopped is basically ".stop, but without cleanup, restartable" and "new" is "a newly created instance, nothing cached")

aside from that, there are some lines which look kinda off to me:

 MongoMS:MongoMemoryServer Mongo[46574]: stop: Called .stop() method +249ms
 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"}}

somehow the process seems to exit immediately with neither a code nor a signal (both are null) and .stop is somehow called twice (even though there seems to only be one server?) and as can be seen right after those lines is that the mongod process is not actually closed yet.
this seems like a bun issue which somehow calls the close handler before the process actually exists

@DWboutin
Copy link
Author

The only place I use MMS is in this file and I clean up only in the afterAll

https://github.com/DWboutin/kiosq-backend/blob/main/src/features/users/__tests__/UserRepository.spec.ts

@DWboutin
Copy link
Author

Tell me if you want me to create an issue in Bun repo and I'll attache the issue here

@hasezoey
Copy link
Member

The only place I use MMS is in this file and I clean up only in the afterAll

await mongod.stop()
mongod.cleanup()

firstly, .stop automatically calls .cleanup, with options { doCleanup: true, force: false } (ie clean temporary data, if not user specified), second is that .cleanup is a async function, so it would be awaited

you can fix this with either:

  • remove the .cleanup call, or
  • change to use .stop({ doCleanup: false })

as for why stop is seemingly called twice, i now know why after looking at the log again:
.stop is always called if there is a instanceError event

i will likely need to add some kind of tracker to not accidentally call .stop twice

@DWboutin
Copy link
Author

Thanks a lot for the info!

@hasezoey hasezoey mentioned this issue Sep 29, 2023
Closed
@hasezoey
Copy link
Member

i have made #802, which tracks this "state" addition, but ultimately this does not really affect how the cleanup (and so the cleanup error) came to be and seems to be harmless aside from duplicate execution (at least for this case)

@hasezoey
Copy link
Member

Tell me if you want me to create an issue in Bun repo and I'll attache the issue here

yes, it would probably be good to make a issue about that the child_process.on("close") handler is called before the process is actually exited

@hasezoey
Copy link
Member

i will re-open this issue to keep some tracker for the .unref check (and maybe extend until the childprocess issue is resolved)

@hasezoey hasezoey reopened this Sep 29, 2023
@hasezoey hasezoey added the engine: bun Issue with JS engine "bun" label Sep 29, 2023
@DWboutin DWboutin mentioned this issue Sep 29, 2023
Closed
@hasezoey
Copy link
Member

hasezoey commented Oct 5, 2023

with 73c0c2e i have added a check to only run (net)server.unref if it is a function. for confirmation, (child_process)child_process.unref() works?

https://github.com/nodkz/mongodb-memory-server/blob/8d649f777e277646d79a72a911380a5194cc26e4/packages/mongodb-memory-server-core/src/util/MongoInstance.ts#L494

@github-actions
Copy link

github-actions bot commented Oct 5, 2023

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

The release is available on:

Your semantic-release bot 📦🚀

@hasezoey
Copy link
Member

hasezoey commented Oct 6, 2023

🎉 This issue has been resolved in version 9.0.0 🎉

The release is available on:

Manual message because semantic-release hit the limit

@hasezoey hasezoey added the released Pull Request released | Issue is fixed label Oct 6, 2023
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
bug engine: bun Issue with JS engine "bun" not a MMS issue This is not an issue for "mongodb-memory-server" released on @beta released Pull Request released | Issue is fixed
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@DWboutin @hasezoey