RocketChat / Rocket.Chat

The communications platform that puts data protection first.
https://rocket.chat/
Other
40.59k stars 10.59k forks source link

Rocket Chat does not start after 6.3.5 update (from 6.3.0) #30398

Closed NoLooseEnds closed 1 year ago

NoLooseEnds commented 1 year ago

Description:

I updated my docker install from 6.3.0 directly to 6.3.5 (latest), but that broke the whole thing. Trying to go back to 6.3.0 (or 6.3.1) did not resolve it.

Any tips is hugely appreciated.

(I do have a few days old backup, but would ideally keep the last few days).

Steps to reproduce:

# docker compose pull (from 6.3.0 to 6.3.5)
# docker compose up -d

Expected behavior:

Should upgrade and work as normal.

Actual behavior:

It halts in the startup process, don't see the "running-badge" running. But no super obvious huge error? Usually the "running-badge" shows up right after where it halts.

See logs below

Server Setup Information:

Client Setup Information

Relevant logs:

Testing with curl @ domain:

➜  rocketchat curl -vvvv chat.domain.tld
*   Trying [ipv6address]:80...
* Connected to chat.domain.tld (ipv6address) port 80 (#0)
> GET / HTTP/1.1
> Host: chat.domain.tld
> User-Agent: curl/7.88.1
> Accept: */*
>
< HTTP/1.1 308 Permanent Redirect
< Connection: close
< Location: https://chat.domain.tld/
< Server: Caddy
< Date: Thu, 14 Sep 2023 19:59:21 GMT
< Content-Length: 0
<
* Closing connection 0

Testing with curl @ localhost:

➜  rocketchat curl -vvvv localhost:3000
*   Trying 127.0.0.1:3000...
* Connected to localhost (127.0.0.1) port 3000 (#0)
> GET / HTTP/1.1
> Host: localhost:3000
> User-Agent: curl/7.88.1
> Accept: */*
>
* Recv failure: Connection reset by peer
* Closing connection 0
curl: (56) Recv failure: Connection reset by peer

➜ rocketchat docker logs rocketchat

strict mode: missing type "object" for keyword "additionalProperties" at "#" (strictTypes)
strict mode: missing type "object" for keyword "properties" at "#" (strictTypes)
strict mode: use allowUnionTypes to allow union type keyword at "#/properties/value" (strictTypes)
(node:9) NOTE: We are formalizing our plans to enter AWS SDK for JavaScript (v2) into maintenance mode in 2023.

Please migrate your code to use AWS SDK for JavaScript (v3).
For more information, check the migration guide at https://a.co/7PzMCcy
(Use `node --trace-warnings ...` to show where the warning was created)
MessageType.render is deprecated. Use MessageType.message instead. livechat_webrtc_video_call
{"level":40,"time":"2023-09-14T19:49:51.136Z","pid":9,"hostname":"ecdb202e7feb","name":"VoIPService","msg":"Voip is not enabled. Cant start the service"}
{"level":51,"time":"2023-09-14T19:49:51.789Z","pid":9,"hostname":"ecdb202e7feb","name":"Migrations","msg":"Not migrating, already at version 301"}
[2023-09-14T19:49:51.820Z] INFO  feeb6de5-e94a-4a16-aefb-5def8891fd1e/BROKER: Moleculer v0.14.29 is starting...
[2023-09-14T19:49:51.820Z] INFO  feeb6de5-e94a-4a16-aefb-5def8891fd1e/BROKER: Namespace: <not defined>
[2023-09-14T19:49:51.820Z] INFO  feeb6de5-e94a-4a16-aefb-5def8891fd1e/BROKER: Node ID: feeb6de5-e94a-4a16-aefb-5def8891fd1e
[2023-09-14T19:49:51.821Z] INFO  feeb6de5-e94a-4a16-aefb-5def8891fd1e/REGISTRY: Strategy: RoundRobinStrategy
[2023-09-14T19:49:51.821Z] INFO  feeb6de5-e94a-4a16-aefb-5def8891fd1e/REGISTRY: Discoverer: LocalDiscoverer
[2023-09-14T19:49:51.822Z] INFO  feeb6de5-e94a-4a16-aefb-5def8891fd1e/BROKER: Serializer: JSONSerializer
[2023-09-14T19:49:51.827Z] INFO  feeb6de5-e94a-4a16-aefb-5def8891fd1e/BROKER: Validator: FastestValidator
[2023-09-14T19:49:51.828Z] INFO  feeb6de5-e94a-4a16-aefb-5def8891fd1e/BROKER: Registered 13 middleware(s).
[2023-09-14T19:49:51.829Z] INFO  feeb6de5-e94a-4a16-aefb-5def8891fd1e/BROKER: Transporter: TcpTransporter
{"level":51,"time":"2023-09-14T19:49:51.846Z","pid":9,"hostname":"ecdb202e7feb","name":"DatabaseWatcher","msg":"Using change streams"}
[2023-09-14T19:49:51.923Z] INFO  feeb6de5-e94a-4a16-aefb-5def8891fd1e/TRANSIT: Connecting to the transporter...
[2023-09-14T19:49:51.926Z] INFO  feeb6de5-e94a-4a16-aefb-5def8891fd1e/TRANSPORTER: TCP server is listening on port 43297
[2023-09-14T19:49:51.927Z] INFO  feeb6de5-e94a-4a16-aefb-5def8891fd1e/TRANSPORTER: UDP Discovery is disabled.
[2023-09-14T19:49:51.927Z] INFO  feeb6de5-e94a-4a16-aefb-5def8891fd1e/TRANSPORTER: TCP Transporter started.
ufs: temp directory created at "/tmp/ufs"
(node:9) [MONGODB DRIVER] Warning: cursor.count is deprecated and will be removed in the next major version, please use `collection.estimatedDocumentCount` or `collection.countDocuments` instead
[2023-09-14T19:49:52.436Z] INFO  feeb6de5-e94a-4a16-aefb-5def8891fd1e/REGISTRY: '$node' service is registered.
[2023-09-14T19:49:52.437Z] INFO  feeb6de5-e94a-4a16-aefb-5def8891fd1e/REGISTRY: 'matrix' service is registered.
[2023-09-14T19:49:52.437Z] INFO  feeb6de5-e94a-4a16-aefb-5def8891fd1e/$NODE: Service '$node' started.
[2023-09-14T19:49:52.437Z] INFO  feeb6de5-e94a-4a16-aefb-5def8891fd1e/MATRIX: Service 'matrix' started.
[2023-09-14T19:49:52.438Z] INFO  feeb6de5-e94a-4a16-aefb-5def8891fd1e/BROKER: ✔ ServiceBroker with 2 service(s) started successfully in 597ms.

➜ rocketchat docker logs rocketmongo

{"t":{"$date":"2023-09-14T21:49:42.210+02:00"},"s":"I",  "c":"CONTROL",  "id":23285,   "ctx":"-","msg":"Automatically disabling TLS 1.0, to force-enable TLS 1.0 specify --sslDisabledProtocols 'none'"}
{"t":{"$date":"2023-09-14T21:49:42.211+02:00"},"s":"I",  "c":"NETWORK",  "id":4915701, "ctx":"main","msg":"Initialized wire specification","attr":{"spec":{"incomingExternalClient":{"minWireVersion":0,"maxWireVersion":13},"incomingInternalClient":{"minWireVersion":0,"maxWireVersion":13},"outgoing":{"minWireVersion":0,"maxWireVersion":13},"isInternalClient":true
}}}
{"t":{"$date":"2023-09-14T21:49:42.211+02:00"},"s":"W",  "c":"ASIO",     "id":22601,   "ctx":"main","msg":"No TransportLayer configured during NetworkInterface startup"}
{"t":{"$date":"2023-09-14T21:49:42.211+02:00"},"s":"I",  "c":"NETWORK",  "id":4648601, "ctx":"main","msg":"Implicit TCP FastOpen unavailable. If TCP FastOpen is required, set tcpFastOpenServer, tcpFastOpenClient, and tcpFastOpenQueueSize."}
{"t":{"$date":"2023-09-14T21:49:42.212+02:00"},"s":"W",  "c":"ASIO",     "id":22601,   "ctx":"main","msg":"No TransportLayer configured during NetworkInterface startup"}
{"t":{"$date":"2023-09-14T21:49:42.212+02:00"},"s":"W",  "c":"ASIO",     "id":22601,   "ctx":"main","msg":"No TransportLayer configured during NetworkInterface startup"}
{"t":{"$date":"2023-09-14T21:49:42.212+02:00"},"s":"I",  "c":"REPL",     "id":5123008, "ctx":"main","msg":"Successfully registered PrimaryOnlyService","attr":{"service":"TenantMigrationDonorService","ns":"config.tenantMigrationDonors"}}
{"t":{"$date":"2023-09-14T21:49:42.212+02:00"},"s":"I",  "c":"REPL",     "id":5123008, "ctx":"main","msg":"Successfully registered PrimaryOnlyService","attr":{"service":"TenantMigrationRecipientService","ns":"config.tenantMigrationRecipients"}}
{"t":{"$date":"2023-09-14T21:49:42.212+02:00"},"s":"I",  "c":"CONTROL",  "id":5945603, "ctx":"main","msg":"Multi threading initialized"}
{"t":{"$date":"2023-09-14T21:49:42.213+02:00"},"s":"I",  "c":"CONTROL",  "id":4615611, "ctx":"initandlisten","msg":"MongoDB starting","attr":{"pid":1,"port":27017,"dbPath":"/data/db","architecture":"64-bit","host":"07645e84c819"}}
{"t":{"$date":"2023-09-14T21:49:42.213+02:00"},"s":"I",  "c":"CONTROL",  "id":23403,   "ctx":"initandlisten","msg":"Build Info","attr":{"buildInfo":{"version":"5.0.21","gitVersion":"4fad44a858d8ee2d642566fc8872ef410f6534e4","openSSLVersion":"OpenSSL 1.1.1f  31 Mar 2020","modules":[],"allocator":"tcmalloc","environment":{"distmod":"ubuntu2004","distarch":"x86_6
4","target_arch":"x86_64"}}}}
{"t":{"$date":"2023-09-14T21:49:42.213+02:00"},"s":"I",  "c":"CONTROL",  "id":51765,   "ctx":"initandlisten","msg":"Operating System","attr":{"os":{"name":"Ubuntu","version":"20.04"}}}
{"t":{"$date":"2023-09-14T21:49:42.213+02:00"},"s":"I",  "c":"CONTROL",  "id":21951,   "ctx":"initandlisten","msg":"Options set by command line","attr":{"options":{"net":{"bindIp":"*"},"replication":{"replSet":"rs0"}}}}
{"t":{"$date":"2023-09-14T21:49:42.213+02:00"},"s":"I",  "c":"STORAGE",  "id":22270,   "ctx":"initandlisten","msg":"Storage engine to use detected by data files","attr":{"dbpath":"/data/db","storageEngine":"wiredTiger"}}
{"t":{"$date":"2023-09-14T21:49:42.213+02:00"},"s":"I",  "c":"STORAGE",  "id":22297,   "ctx":"initandlisten","msg":"Using the XFS filesystem is strongly recommended with the WiredTiger storage engine. See http://dochub.mongodb.org/core/prodnotes-filesystem","tags":["startupWarnings"]}
{"t":{"$date":"2023-09-14T21:49:42.213+02:00"},"s":"I",  "c":"STORAGE",  "id":22315,   "ctx":"initandlisten","msg":"Opening WiredTiger","attr":{"config":"create,cache_size=31597M,session_max=33000,eviction=(threads_min=4,threads_max=4),config_base=false,statistics=(fast),log=(enabled=true,archive=true,path=journal,compressor=snappy),builtin_extension_config=(z
std=(compression_level=6)),file_manager=(close_idle_time=600,close_scan_interval=10,close_handle_minimum=250),statistics_log=(wait=0),verbose=[recovery_progress,checkpoint_progress,compact_progress],"}}
{"t":{"$date":"2023-09-14T21:49:42.337+02:00"},"s":"I",  "c":"STORAGE",  "id":22430,   "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":"[1694720982:337212][1:0x7f9197782c80], txn-recover: [WT_VERB_RECOVERY_PROGRESS] Recovering log 87 through 88"}}
{"t":{"$date":"2023-09-14T21:49:42.369+02:00"},"s":"I",  "c":"STORAGE",  "id":22430,   "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":"[1694720982:369366][1:0x7f9197782c80], txn-recover: [WT_VERB_RECOVERY_PROGRESS] Recovering log 88 through 88"}}
{"t":{"$date":"2023-09-14T21:49:42.426+02:00"},"s":"I",  "c":"STORAGE",  "id":22430,   "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":"[1694720982:426612][1:0x7f9197782c80], txn-recover: [WT_VERB_RECOVERY_ALL] Main recovery loop: starting at 87/223616 to 88/256"}}
{"t":{"$date":"2023-09-14T21:49:42.468+02:00"},"s":"I",  "c":"STORAGE",  "id":22430,   "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":"[1694720982:468545][1:0x7f9197782c80], txn-recover: [WT_VERB_RECOVERY_PROGRESS] Recovering log 87 through 88"}}
{"t":{"$date":"2023-09-14T21:49:42.504+02:00"},"s":"I",  "c":"STORAGE",  "id":22430,   "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":"[1694720982:504048][1:0x7f9197782c80], txn-recover: [WT_VERB_RECOVERY_PROGRESS] Recovering log 88 through 88"}}
{"t":{"$date":"2023-09-14T21:49:42.522+02:00"},"s":"I",  "c":"STORAGE",  "id":22430,   "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":"[1694720982:522973][1:0x7f9197782c80], txn-recover: [WT_VERB_RECOVERY_ALL] Set global recovery timestamp: (1694720959, 1)"}}
{"t":{"$date":"2023-09-14T21:49:42.522+02:00"},"s":"I",  "c":"STORAGE",  "id":22430,   "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":"[1694720982:522993][1:0x7f9197782c80], txn-recover: [WT_VERB_RECOVERY_ALL] Set global oldest timestamp: (1694720659, 1)"}}
{"t":{"$date":"2023-09-14T21:49:42.547+02:00"},"s":"I",  "c":"STORAGE",  "id":22430,   "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":"[1694720982:547748][1:0x7f9197782c80], WT_SESSION.checkpoint: [WT_VERB_CHECKPOINT_PROGRESS] saving checkpoint snapshot min: 1, snapshot max: 1 snapshot count: 0, oldest timestamp: (1694720659, 1) , meta chec
kpoint timestamp: (1694720959, 1) base write gen: 14809349"}}
{"t":{"$date":"2023-09-14T21:49:42.581+02:00"},"s":"I",  "c":"STORAGE",  "id":4795906, "ctx":"initandlisten","msg":"WiredTiger opened","attr":{"durationMillis":368}}
{"t":{"$date":"2023-09-14T21:49:42.581+02:00"},"s":"I",  "c":"RECOVERY", "id":23987,   "ctx":"initandlisten","msg":"WiredTiger recoveryTimestamp","attr":{"recoveryTimestamp":{"$timestamp":{"t":1694720959,"i":1}}}}
{"t":{"$date":"2023-09-14T21:49:42.581+02:00"},"s":"I",  "c":"RECOVERY", "id":5380106, "ctx":"initandlisten","msg":"WiredTiger oldestTimestamp","attr":{"oldestTimestamp":{"$timestamp":{"t":1694720659,"i":1}}}}
{"t":{"$date":"2023-09-14T21:49:42.586+02:00"},"s":"I",  "c":"STORAGE",  "id":22383,   "ctx":"initandlisten","msg":"The size storer reports that the oplog contains","attr":{"numRecords":5467713,"dataSize":1492053087}}
{"t":{"$date":"2023-09-14T21:49:42.586+02:00"},"s":"I",  "c":"STORAGE",  "id":22386,   "ctx":"initandlisten","msg":"Sampling the oplog to determine where to place markers for truncation"}
{"t":{"$date":"2023-09-14T21:49:42.586+02:00"},"s":"I",  "c":"STORAGE",  "id":22389,   "ctx":"initandlisten","msg":"Sampling from the oplog to determine where to place markers for truncation","attr":{"from":{"$timestamp":{"t":1666288519,"i":1}},"to":{"$timestamp":{"t":1694720959,"i":1}}}}
{"t":{"$date":"2023-09-14T21:49:42.586+02:00"},"s":"I",  "c":"STORAGE",  "id":22390,   "ctx":"initandlisten","msg":"Taking samples and assuming each oplog section contains","attr":{"numSamples":99,"containsNumRecords":549505,"containsNumBytes":149951292}}
{"t":{"$date":"2023-09-14T21:49:42.608+02:00"},"s":"I",  "c":"STORAGE",  "id":22393,   "ctx":"initandlisten","msg":"Oplog sampling complete"}
{"t":{"$date":"2023-09-14T21:49:42.608+02:00"},"s":"I",  "c":"STORAGE",  "id":22382,   "ctx":"initandlisten","msg":"WiredTiger record store oplog processing finished","attr":{"durationMillis":22}}
{"t":{"$date":"2023-09-14T21:49:42.644+02:00"},"s":"I",  "c":"STORAGE",  "id":22262,   "ctx":"initandlisten","msg":"Timestamp monitor starting"}
{"t":{"$date":"2023-09-14T21:49:42.650+02:00"},"s":"W",  "c":"CONTROL",  "id":22120,   "ctx":"initandlisten","msg":"Access control is not enabled for the database. Read and write access to data and configuration is unrestricted","tags":["startupWarnings"]}
{"t":{"$date":"2023-09-14T21:49:42.650+02:00"},"s":"W",  "c":"CONTROL",  "id":22178,   "ctx":"initandlisten","msg":"/sys/kernel/mm/transparent_hugepage/enabled is 'always'. We suggest setting it to 'never'","tags":["startupWarnings"]}
{"t":{"$date":"2023-09-14T21:49:42.653+02:00"},"s":"I",  "c":"NETWORK",  "id":4915702, "ctx":"initandlisten","msg":"Updated wire specification","attr":{"oldSpec":{"incomingExternalClient":{"minWireVersion":0,"maxWireVersion":13},"incomingInternalClient":{"minWireVersion":0,"maxWireVersion":13},"outgoing":{"minWireVersion":0,"maxWireVersion":13},"isInternalClie
nt":true},"newSpec":{"incomingExternalClient":{"minWireVersion":0,"maxWireVersion":13},"incomingInternalClient":{"minWireVersion":13,"maxWireVersion":13},"outgoing":{"minWireVersion":13,"maxWireVersion":13},"isInternalClient":true}}}
{"t":{"$date":"2023-09-14T21:49:42.654+02:00"},"s":"I",  "c":"STORAGE",  "id":5071100, "ctx":"initandlisten","msg":"Clearing temp directory"}
{"t":{"$date":"2023-09-14T21:49:42.806+02:00"},"s":"I",  "c":"CONTROL",  "id":20536,   "ctx":"initandlisten","msg":"Flow Control is enabled on this deployment"}
{"t":{"$date":"2023-09-14T21:49:42.806+02:00"},"s":"I",  "c":"STORAGE",  "id":5380103, "ctx":"initandlisten","msg":"Unpin oldest timestamp request","attr":{"service":"_wt_startup","requestedTs":{"$timestamp":{"t":1694720659,"i":1}}}}
{"t":{"$date":"2023-09-14T21:49:42.807+02:00"},"s":"I",  "c":"SHARDING", "id":20997,   "ctx":"initandlisten","msg":"Refreshed RWC defaults","attr":{"newDefaults":{}}}
{"t":{"$date":"2023-09-14T21:49:42.807+02:00"},"s":"I",  "c":"FTDC",     "id":20625,   "ctx":"initandlisten","msg":"Initializing full-time diagnostic data capture","attr":{"dataDirectory":"/data/db/diagnostic.data"}}
{"t":{"$date":"2023-09-14T21:49:42.808+02:00"},"s":"I",  "c":"REPL",     "id":6015317, "ctx":"initandlisten","msg":"Setting new configuration state","attr":{"newState":"ConfigStartingUp","oldState":"ConfigPreStart"}}
{"t":{"$date":"2023-09-14T21:49:42.809+02:00"},"s":"I",  "c":"REPL",     "id":4280500, "ctx":"initandlisten","msg":"Attempting to create internal replication collections"}
{"t":{"$date":"2023-09-14T21:49:42.809+02:00"},"s":"I",  "c":"-",        "id":4939300, "ctx":"monitoring-keys-for-HMAC","msg":"Failed to refresh key cache","attr":{"error":"ReadConcernMajorityNotAvailableYet: Read concern majority reads are currently not possible.","nextWakeupMillis":200}}
{"t":{"$date":"2023-09-14T21:49:42.810+02:00"},"s":"I",  "c":"REPL",     "id":4280501, "ctx":"initandlisten","msg":"Attempting to load local voted for document"}
{"t":{"$date":"2023-09-14T21:49:42.810+02:00"},"s":"I",  "c":"REPL",     "id":4280502, "ctx":"initandlisten","msg":"Searching for local Rollback ID document"}
{"t":{"$date":"2023-09-14T21:49:42.811+02:00"},"s":"I",  "c":"REPL",     "id":21529,   "ctx":"initandlisten","msg":"Initializing rollback ID","attr":{"rbid":2}}
{"t":{"$date":"2023-09-14T21:49:42.812+02:00"},"s":"I",  "c":"REPL",     "id":4280504, "ctx":"initandlisten","msg":"Cleaning up any partially applied oplog batches & reading last op from oplog"}
{"t":{"$date":"2023-09-14T21:49:42.812+02:00"},"s":"I",  "c":"REPL",     "id":21544,   "ctx":"initandlisten","msg":"Recovering from stable timestamp","attr":{"stableTimestamp":{"$timestamp":{"t":1694720959,"i":1}},"topOfOplog":{"ts":{"$timestamp":{"t":1694720959,"i":1}},"t":61},"appliedThrough":{"ts":{"$timestamp":{"t":0,"i":0}},"t":-1}}}
{"t":{"$date":"2023-09-14T21:49:42.812+02:00"},"s":"I",  "c":"REPL",     "id":21545,   "ctx":"initandlisten","msg":"Starting recovery oplog application at the stable timestamp","attr":{"stableTimestamp":{"$timestamp":{"t":1694720959,"i":1}}}}
{"t":{"$date":"2023-09-14T21:49:42.812+02:00"},"s":"I",  "c":"REPL",     "id":5466604, "ctx":"initandlisten","msg":"Start point for recovery oplog application exists in oplog. No adjustment necessary","attr":{"startPoint":{"$timestamp":{"t":1694720959,"i":1}}}}
{"t":{"$date":"2023-09-14T21:49:42.812+02:00"},"s":"I",  "c":"REPL",     "id":21549,   "ctx":"initandlisten","msg":"No oplog entries to apply for recovery. Start point is at the top of the oplog"}
{"t":{"$date":"2023-09-14T21:49:42.812+02:00"},"s":"I",  "c":"REPL",     "id":4280505, "ctx":"initandlisten","msg":"Creating any necessary TenantMigrationAccessBlockers for unfinished migrations"}
{"t":{"$date":"2023-09-14T21:49:42.813+02:00"},"s":"I",  "c":"REPL",     "id":4280506, "ctx":"initandlisten","msg":"Reconstructing prepared transactions"}
{"t":{"$date":"2023-09-14T21:49:42.814+02:00"},"s":"I",  "c":"REPL",     "id":4280507, "ctx":"initandlisten","msg":"Loaded replica set config, scheduled callback to set local config"}
{"t":{"$date":"2023-09-14T21:49:42.814+02:00"},"s":"I",  "c":"REPL",     "id":4280508, "ctx":"ReplCoord-0","msg":"Attempting to set local replica set config; validating config for startup"}
{"t":{"$date":"2023-09-14T21:49:42.818+02:00"},"s":"I",  "c":"CONTROL",  "id":20714,   "ctx":"LogicalSessionCacheRefresh","msg":"Failed to refresh session cache, will try again at the next refresh interval","attr":{"error":"NotYetInitialized: Replication has not yet been configured"}}
{"t":{"$date":"2023-09-14T21:49:42.819+02:00"},"s":"I",  "c":"CONTROL",  "id":20711,   "ctx":"LogicalSessionCacheReap","msg":"Failed to reap transaction table","attr":{"error":"NotYetInitialized: Replication has not yet been configured"}}
{"t":{"$date":"2023-09-14T21:49:42.824+02:00"},"s":"I",  "c":"REPL",     "id":40440,   "ctx":"initandlisten","msg":"Starting the TopologyVersionObserver"}
{"t":{"$date":"2023-09-14T21:49:42.826+02:00"},"s":"I",  "c":"REPL",     "id":40445,   "ctx":"TopologyVersionObserver","msg":"Started TopologyVersionObserver"}
{"t":{"$date":"2023-09-14T21:49:42.829+02:00"},"s":"I",  "c":"NETWORK",  "id":23015,   "ctx":"listener","msg":"Listening on","attr":{"address":"/tmp/mongodb-27017.sock"}}
{"t":{"$date":"2023-09-14T21:49:42.829+02:00"},"s":"I",  "c":"NETWORK",  "id":23015,   "ctx":"listener","msg":"Listening on","attr":{"address":"0.0.0.0"}}
{"t":{"$date":"2023-09-14T21:49:42.829+02:00"},"s":"I",  "c":"NETWORK",  "id":23016,   "ctx":"listener","msg":"Waiting for connections","attr":{"port":27017,"ssl":"off"}}
{"t":{"$date":"2023-09-14T21:49:42.842+02:00"},"s":"I",  "c":"REPL",     "id":4280509, "ctx":"ReplCoord-0","msg":"Local configuration validated for startup"}
{"t":{"$date":"2023-09-14T21:49:42.842+02:00"},"s":"I",  "c":"REPL",     "id":6015317, "ctx":"ReplCoord-0","msg":"Setting new configuration state","attr":{"newState":"ConfigSteady","oldState":"ConfigStartingUp"}}
{"t":{"$date":"2023-09-14T21:49:42.842+02:00"},"s":"I",  "c":"REPL",     "id":21392,   "ctx":"ReplCoord-0","msg":"New replica set config in use","attr":{"config":{"_id":"rs0","version":3,"term":61,"members":[{"_id":0,"host":"mongo:27017","arbiterOnly":false,"buildIndexes":true,"hidden":false,"priority":1,"tags":{},"secondaryDelaySecs":0,"votes":1}],"protocolVe
rsion":1,"writeConcernMajorityJournalDefault":true,"settings":{"chainingAllowed":true,"heartbeatIntervalMillis":2000,"heartbeatTimeoutSecs":10,"electionTimeoutMillis":10000,"catchUpTimeoutMillis":-1,"catchUpTakeoverDelayMillis":30000,"getLastErrorModes":{},"getLastErrorDefaults":{"w":1,"wtimeout":0},"replicaSetId":{"$oid":"63518b876718bb89af45350d"}}}}}
{"t":{"$date":"2023-09-14T21:49:42.842+02:00"},"s":"I",  "c":"REPL",     "id":21393,   "ctx":"ReplCoord-0","msg":"Found self in config","attr":{"hostAndPort":"mongo:27017"}}
{"t":{"$date":"2023-09-14T21:49:42.842+02:00"},"s":"I",  "c":"REPL",     "id":21358,   "ctx":"ReplCoord-0","msg":"Replica set state transition","attr":{"newState":"STARTUP2","oldState":"STARTUP"}}
{"t":{"$date":"2023-09-14T21:49:42.842+02:00"},"s":"I",  "c":"REPL",     "id":21320,   "ctx":"ReplCoord-0","msg":"Updated term","attr":{"term":61}}
{"t":{"$date":"2023-09-14T21:49:42.842+02:00"},"s":"I",  "c":"REPL",     "id":21306,   "ctx":"ReplCoord-0","msg":"Starting replication storage threads"}
{"t":{"$date":"2023-09-14T21:49:42.843+02:00"},"s":"I",  "c":"REPL",     "id":4280512, "ctx":"ReplCoord-0","msg":"No initial sync required. Attempting to begin steady replication"}
{"t":{"$date":"2023-09-14T21:49:42.843+02:00"},"s":"I",  "c":"REPL",     "id":21358,   "ctx":"ReplCoord-0","msg":"Replica set state transition","attr":{"newState":"RECOVERING","oldState":"STARTUP2"}}
{"t":{"$date":"2023-09-14T21:49:42.847+02:00"},"s":"I",  "c":"REPL",     "id":21299,   "ctx":"ReplCoord-0","msg":"Starting replication fetcher thread"}
{"t":{"$date":"2023-09-14T21:49:42.849+02:00"},"s":"I",  "c":"REPL",     "id":21300,   "ctx":"ReplCoord-0","msg":"Starting replication applier thread"}
{"t":{"$date":"2023-09-14T21:49:42.849+02:00"},"s":"I",  "c":"REPL",     "id":21224,   "ctx":"OplogApplier-0","msg":"Starting oplog application"}
{"t":{"$date":"2023-09-14T21:49:42.849+02:00"},"s":"I",  "c":"REPL",     "id":21301,   "ctx":"ReplCoord-0","msg":"Starting replication reporter thread"}
{"t":{"$date":"2023-09-14T21:49:42.850+02:00"},"s":"I",  "c":"REPL",     "id":21358,   "ctx":"OplogApplier-0","msg":"Replica set state transition","attr":{"newState":"SECONDARY","oldState":"RECOVERING"}}
{"t":{"$date":"2023-09-14T21:49:42.850+02:00"},"s":"I",  "c":"ELECTION", "id":4615652, "ctx":"OplogApplier-0","msg":"Starting an election, since we've seen no PRIMARY in election timeout period","attr":{"electionTimeoutPeriodMillis":10000}}
{"t":{"$date":"2023-09-14T21:49:42.850+02:00"},"s":"I",  "c":"ELECTION", "id":21438,   "ctx":"OplogApplier-0","msg":"Conducting a dry run election to see if we could be elected","attr":{"currentTerm":61}}
{"t":{"$date":"2023-09-14T21:49:42.850+02:00"},"s":"I",  "c":"ELECTION", "id":21444,   "ctx":"ReplCoord-1","msg":"Dry election run succeeded, running for election","attr":{"newTerm":62}}
{"t":{"$date":"2023-09-14T21:49:42.851+02:00"},"s":"I",  "c":"ELECTION", "id":6015300, "ctx":"ReplCoord-1","msg":"Storing last vote document in local storage for my election","attr":{"lastVote":{"term":62,"candidateIndex":0}}}
{"t":{"$date":"2023-09-14T21:49:42.852+02:00"},"s":"I",  "c":"REPL",     "id":4280511, "ctx":"ReplCoord-0","msg":"Set local replica set config"}
{"t":{"$date":"2023-09-14T21:49:42.858+02:00"},"s":"I",  "c":"ELECTION", "id":21450,   "ctx":"ReplCoord-1","msg":"Election succeeded, assuming primary role","attr":{"term":62}}
{"t":{"$date":"2023-09-14T21:49:42.858+02:00"},"s":"I",  "c":"REPL",     "id":21358,   "ctx":"ReplCoord-1","msg":"Replica set state transition","attr":{"newState":"PRIMARY","oldState":"SECONDARY"}}
{"t":{"$date":"2023-09-14T21:49:42.858+02:00"},"s":"I",  "c":"REPL",     "id":21106,   "ctx":"ReplCoord-1","msg":"Resetting sync source to empty","attr":{"previousSyncSource":":27017"}}
{"t":{"$date":"2023-09-14T21:49:42.858+02:00"},"s":"I",  "c":"REPL",     "id":21359,   "ctx":"ReplCoord-1","msg":"Entering primary catch-up mode"}
{"t":{"$date":"2023-09-14T21:49:42.858+02:00"},"s":"I",  "c":"REPL",     "id":6015304, "ctx":"ReplCoord-1","msg":"Skipping primary catchup since we are the only node in the replica set."}
{"t":{"$date":"2023-09-14T21:49:42.858+02:00"},"s":"I",  "c":"REPL",     "id":21363,   "ctx":"ReplCoord-1","msg":"Exited primary catch-up mode"}
{"t":{"$date":"2023-09-14T21:49:42.858+02:00"},"s":"I",  "c":"REPL",     "id":21107,   "ctx":"ReplCoord-1","msg":"Stopping replication producer"}
{"t":{"$date":"2023-09-14T21:49:42.858+02:00"},"s":"I",  "c":"REPL",     "id":21239,   "ctx":"ReplBatcher","msg":"Oplog buffer has been drained","attr":{"term":62}}
{"t":{"$date":"2023-09-14T21:49:42.858+02:00"},"s":"I",  "c":"REPL",     "id":21343,   "ctx":"RstlKillOpThread","msg":"Starting to kill user operations"}
{"t":{"$date":"2023-09-14T21:49:42.858+02:00"},"s":"I",  "c":"REPL",     "id":21344,   "ctx":"RstlKillOpThread","msg":"Stopped killing user operations"}
{"t":{"$date":"2023-09-14T21:49:42.858+02:00"},"s":"I",  "c":"REPL",     "id":21340,   "ctx":"RstlKillOpThread","msg":"State transition ops metrics","attr":{"metrics":{"lastStateTransition":"stepUp","userOpsKilled":0,"userOpsRunning":0}}}
{"t":{"$date":"2023-09-14T21:49:42.858+02:00"},"s":"I",  "c":"REPL",     "id":4508103, "ctx":"OplogApplier-0","msg":"Increment the config term via reconfig"}
{"t":{"$date":"2023-09-14T21:49:42.858+02:00"},"s":"I",  "c":"REPL",     "id":6015313, "ctx":"OplogApplier-0","msg":"Replication config state is Steady, starting reconfig"}
{"t":{"$date":"2023-09-14T21:49:42.858+02:00"},"s":"I",  "c":"REPL",     "id":6015317, "ctx":"OplogApplier-0","msg":"Setting new configuration state","attr":{"newState":"ConfigReconfiguring","oldState":"ConfigSteady"}}
{"t":{"$date":"2023-09-14T21:49:42.858+02:00"},"s":"I",  "c":"REPL",     "id":21353,   "ctx":"OplogApplier-0","msg":"replSetReconfig config object parses ok","attr":{"numMembers":1}}
{"t":{"$date":"2023-09-14T21:49:42.858+02:00"},"s":"I",  "c":"REPL",     "id":51814,   "ctx":"OplogApplier-0","msg":"Persisting new config to disk"}
{"t":{"$date":"2023-09-14T21:49:42.860+02:00"},"s":"I",  "c":"REPL",     "id":6015315, "ctx":"OplogApplier-0","msg":"Persisted new config to disk"}
{"t":{"$date":"2023-09-14T21:49:42.860+02:00"},"s":"I",  "c":"REPL",     "id":6015317, "ctx":"OplogApplier-0","msg":"Setting new configuration state","attr":{"newState":"ConfigSteady","oldState":"ConfigReconfiguring"}}
{"t":{"$date":"2023-09-14T21:49:42.860+02:00"},"s":"I",  "c":"REPL",     "id":21392,   "ctx":"OplogApplier-0","msg":"New replica set config in use","attr":{"config":{"_id":"rs0","version":3,"term":62,"members":[{"_id":0,"host":"mongo:27017","arbiterOnly":false,"buildIndexes":true,"hidden":false,"priority":1,"tags":{},"secondaryDelaySecs":0,"votes":1}],"protoco
lVersion":1,"writeConcernMajorityJournalDefault":true,"settings":{"chainingAllowed":true,"heartbeatIntervalMillis":2000,"heartbeatTimeoutSecs":10,"electionTimeoutMillis":10000,"catchUpTimeoutMillis":-1,"catchUpTakeoverDelayMillis":30000,"getLastErrorModes":{},"getLastErrorDefaults":{"w":1,"wtimeout":0},"replicaSetId":{"$oid":"63518b876718bb89af45350d"}}}}}
{"t":{"$date":"2023-09-14T21:49:42.860+02:00"},"s":"I",  "c":"REPL",     "id":21393,   "ctx":"OplogApplier-0","msg":"Found self in config","attr":{"hostAndPort":"mongo:27017"}}
{"t":{"$date":"2023-09-14T21:49:42.860+02:00"},"s":"I",  "c":"REPL",     "id":6015310, "ctx":"OplogApplier-0","msg":"Starting to transition to primary."}
{"t":{"$date":"2023-09-14T21:49:42.861+02:00"},"s":"I",  "c":"REPL",     "id":6015309, "ctx":"OplogApplier-0","msg":"Logging transition to primary to oplog on stepup"}
{"t":{"$date":"2023-09-14T21:49:42.861+02:00"},"s":"I",  "c":"STORAGE",  "id":20657,   "ctx":"OplogApplier-0","msg":"IndexBuildsCoordinator::onStepUp - this node is stepping up to primary"}
{"t":{"$date":"2023-09-14T21:49:42.861+02:00"},"s":"I",  "c":"REPL",     "id":21331,   "ctx":"OplogApplier-0","msg":"Transition to primary complete; database writes are now permitted"}
{"t":{"$date":"2023-09-14T21:49:42.861+02:00"},"s":"I",  "c":"-",        "id":4939300, "ctx":"monitoring-keys-for-HMAC","msg":"Failed to refresh key cache","attr":{"error":"ReadConcernMajorityNotAvailableYet: Read concern majority reads are currently not possible.","nextWakeupMillis":400}}
{"t":{"$date":"2023-09-14T21:49:42.863+02:00"},"s":"I",  "c":"REPL",     "id":5123005, "ctx":"TenantMigrationRecipientService-1","msg":"Rebuilding PrimaryOnlyService due to stepUp","attr":{"service":"TenantMigrationRecipientService"}}
{"t":{"$date":"2023-09-14T21:49:42.863+02:00"},"s":"I",  "c":"REPL",     "id":5123005, "ctx":"TenantMigrationDonorService-0","msg":"Rebuilding PrimaryOnlyService due to stepUp","attr":{"service":"TenantMigrationDonorService"}}
{"t":{"$date":"2023-09-14T21:49:43.842+02:00"},"s":"I",  "c":"NETWORK",  "id":22943,   "ctx":"listener","msg":"Connection accepted","attr":{"remote":"172.20.0.4:41696","uuid":"de799c01-8e80-49ec-b705-276399c2e056","connectionId":1,"connectionCount":1}}
{"t":{"$date":"2023-09-14T21:49:43.847+02:00"},"s":"I",  "c":"NETWORK",  "id":51800,   "ctx":"conn1","msg":"client metadata","attr":{"remote":"172.20.0.4:41696","client":"conn1","doc":{"driver":{"name":"nodejs","version":"4.16.0"},"platform":"Node.js v14.21.3, LE","os":{"name":"linux","architecture":"x64","version":"6.1.0-12-amd64","type":"Linux"}}}}
{"t":{"$date":"2023-09-14T21:49:43.852+02:00"},"s":"I",  "c":"NETWORK",  "id":22943,   "ctx":"listener","msg":"Connection accepted","attr":{"remote":"172.20.0.4:41700","uuid":"f579735a-ddd0-4056-b4f0-d9e4ce07cf74","connectionId":2,"connectionCount":2}}
{"t":{"$date":"2023-09-14T21:49:43.852+02:00"},"s":"I",  "c":"NETWORK",  "id":22943,   "ctx":"listener","msg":"Connection accepted","attr":{"remote":"172.20.0.4:41704","uuid":"9622b974-34a9-4145-9a44-0d3a035d89cc","connectionId":3,"connectionCount":3}}
{"t":{"$date":"2023-09-14T21:49:43.852+02:00"},"s":"I",  "c":"NETWORK",  "id":51800,   "ctx":"conn2","msg":"client metadata","attr":{"remote":"172.20.0.4:41700","client":"conn2","doc":{"driver":{"name":"nodejs","version":"4.16.0"},"platform":"Node.js v14.21.3, LE","os":{"name":"linux","architecture":"x64","version":"6.1.0-12-amd64","type":"Linux"}}}}
{"t":{"$date":"2023-09-14T21:49:43.853+02:00"},"s":"I",  "c":"NETWORK",  "id":51800,   "ctx":"conn3","msg":"client metadata","attr":{"remote":"172.20.0.4:41704","client":"conn3","doc":{"driver":{"name":"nodejs","version":"4.16.0"},"platform":"Node.js v14.21.3, LE","os":{"name":"linux","architecture":"x64","version":"6.1.0-12-amd64","type":"Linux"}}}}
{"t":{"$date":"2023-09-14T21:49:44.855+02:00"},"s":"I",  "c":"NETWORK",  "id":22943,   "ctx":"listener","msg":"Connection accepted","attr":{"remote":"172.20.0.4:41720","uuid":"384503aa-3603-4a61-a809-2b0236e1dcb0","connectionId":4,"connectionCount":4}}
{"t":{"$date":"2023-09-14T21:49:44.860+02:00"},"s":"I",  "c":"NETWORK",  "id":22943,   "ctx":"listener","msg":"Connection accepted","attr":{"remote":"172.20.0.4:41722","uuid":"da50aa23-ea63-433b-857e-3f32382cf5d3","connectionId":5,"connectionCount":5}}
{"t":{"$date":"2023-09-14T21:49:44.861+02:00"},"s":"I",  "c":"NETWORK",  "id":51800,   "ctx":"conn4","msg":"client metadata","attr":{"remote":"172.20.0.4:41720","client":"conn4","doc":{"driver":{"name":"nodejs","version":"4.16.0"},"platform":"Node.js v14.21.3, LE","os":{"name":"linux","architecture":"x64","version":"6.1.0-12-amd64","type":"Linux"}}}}
{"t":{"$date":"2023-09-14T21:49:44.862+02:00"},"s":"I",  "c":"NETWORK",  "id":51800,   "ctx":"conn5","msg":"client metadata","attr":{"remote":"172.20.0.4:41722","client":"conn5","doc":{"driver":{"name":"nodejs","version":"4.16.0"},"platform":"Node.js v14.21.3, LE","os":{"name":"linux","architecture":"x64","version":"6.1.0-12-amd64","type":"Linux"}}}}
{"t":{"$date":"2023-09-14T21:49:44.866+02:00"},"s":"I",  "c":"NETWORK",  "id":22943,   "ctx":"listener","msg":"Connection accepted","attr":{"remote":"172.20.0.4:41728","uuid":"88f9e06f-40dc-4aae-b0cb-d5f8950986fd","connectionId":6,"connectionCount":6}}
{"t":{"$date":"2023-09-14T21:49:44.866+02:00"},"s":"I",  "c":"NETWORK",  "id":22943,   "ctx":"listener","msg":"Connection accepted","attr":{"remote":"172.20.0.4:41730","uuid":"4fc43a4c-78bd-48fa-9a68-2314ee14c857","connectionId":7,"connectionCount":7}}
{"t":{"$date":"2023-09-14T21:49:44.867+02:00"},"s":"I",  "c":"NETWORK",  "id":51800,   "ctx":"conn6","msg":"client metadata","attr":{"remote":"172.20.0.4:41728","client":"conn6","doc":{"driver":{"name":"nodejs","version":"4.16.0"},"platform":"Node.js v14.21.3, LE","os":{"name":"linux","architecture":"x64","version":"6.1.0-12-amd64","type":"Linux"}}}}
{"t":{"$date":"2023-09-14T21:49:44.868+02:00"},"s":"I",  "c":"NETWORK",  "id":51800,   "ctx":"conn7","msg":"client metadata","attr":{"remote":"172.20.0.4:41730","client":"conn7","doc":{"driver":{"name":"nodejs","version":"4.16.0"},"platform":"Node.js v14.21.3, LE","os":{"name":"linux","architecture":"x64","version":"6.1.0-12-amd64","type":"Linux"}}}}
{"t":{"$date":"2023-09-14T21:49:44.872+02:00"},"s":"I",  "c":"NETWORK",  "id":22943,   "ctx":"listener","msg":"Connection accepted","attr":{"remote":"172.20.0.4:41742","uuid":"80beada3-4c78-42a8-b3e4-9b6aad0a545d","connectionId":8,"connectionCount":8}}
{"t":{"$date":"2023-09-14T21:49:44.872+02:00"},"s":"I",  "c":"NETWORK",  "id":22943,   "ctx":"listener","msg":"Connection accepted","attr":{"remote":"172.20.0.4:41758","uuid":"98611d96-2943-4fb5-93ae-0901b4297d3c","connectionId":9,"connectionCount":9}}
{"t":{"$date":"2023-09-14T21:49:44.874+02:00"},"s":"I",  "c":"NETWORK",  "id":51800,   "ctx":"conn8","msg":"client metadata","attr":{"remote":"172.20.0.4:41742","client":"conn8","doc":{"driver":{"name":"nodejs","version":"4.16.0"},"platform":"Node.js v14.21.3, LE","os":{"name":"linux","architecture":"x64","version":"6.1.0-12-amd64","type":"Linux"}}}}
{"t":{"$date":"2023-09-14T21:49:44.875+02:00"},"s":"I",  "c":"NETWORK",  "id":51800,   "ctx":"conn9","msg":"client metadata","attr":{"remote":"172.20.0.4:41758","client":"conn9","doc":{"driver":{"name":"nodejs","version":"4.16.0"},"platform":"Node.js v14.21.3, LE","os":{"name":"linux","architecture":"x64","version":"6.1.0-12-amd64","type":"Linux"}}}}
{"t":{"$date":"2023-09-14T21:49:44.881+02:00"},"s":"I",  "c":"NETWORK",  "id":22943,   "ctx":"listener","msg":"Connection accepted","attr":{"remote":"172.20.0.4:41774","uuid":"9e9e304b-27eb-476d-822a-c2a1c0bd0be8","connectionId":10,"connectionCount":10}}
{"t":{"$date":"2023-09-14T21:49:44.882+02:00"},"s":"I",  "c":"NETWORK",  "id":22943,   "ctx":"listener","msg":"Connection accepted","attr":{"remote":"172.20.0.4:41782","uuid":"5be041f2-f207-4dd2-9f9a-acd281f54ae5","connectionId":11,"connectionCount":11}}
{"t":{"$date":"2023-09-14T21:49:44.884+02:00"},"s":"I",  "c":"NETWORK",  "id":51800,   "ctx":"conn10","msg":"client metadata","attr":{"remote":"172.20.0.4:41774","client":"conn10","doc":{"driver":{"name":"nodejs","version":"4.16.0"},"platform":"Node.js v14.21.3, LE","os":{"name":"linux","architecture":"x64","version":"6.1.0-12-amd64","type":"Linux"}}}}
{"t":{"$date":"2023-09-14T21:49:44.884+02:00"},"s":"I",  "c":"NETWORK",  "id":51800,   "ctx":"conn11","msg":"client metadata","attr":{"remote":"172.20.0.4:41782","client":"conn11","doc":{"driver":{"name":"nodejs","version":"4.16.0"},"platform":"Node.js v14.21.3, LE","os":{"name":"linux","architecture":"x64","version":"6.1.0-12-amd64","type":"Linux"}}}}
{"t":{"$date":"2023-09-14T21:49:47.694+02:00"},"s":"I",  "c":"NETWORK",  "id":22943,   "ctx":"listener","msg":"Connection accepted","attr":{"remote":"172.20.0.5:49152","uuid":"472db538-3c8e-42e3-8872-873344c8027f","connectionId":12,"connectionCount":12}}
{"t":{"$date":"2023-09-14T21:49:47.695+02:00"},"s":"I",  "c":"NETWORK",  "id":51800,   "ctx":"conn12","msg":"client metadata","attr":{"remote":"172.20.0.5:49152","client":"conn12","doc":{"application":{"name":"MongoDB Shell"},"driver":{"name":"MongoDB Internal Client","version":"5.0.21"},"os":{"type":"Linux","name":"Ubuntu","architecture":"x86_64","version":"2
0.04"}}}}
{"t":{"$date":"2023-09-14T21:49:47.697+02:00"},"s":"I",  "c":"REPL",     "id":21356,   "ctx":"conn12","msg":"replSetInitiate admin command received from client"}
{"t":{"$date":"2023-09-14T21:49:47.698+02:00"},"s":"I",  "c":"NETWORK",  "id":22944,   "ctx":"conn12","msg":"Connection ended","attr":{"remote":"172.20.0.5:49152","uuid":"472db538-3c8e-42e3-8872-873344c8027f","connectionId":12,"connectionCount":11}}
{"t":{"$date":"2023-09-14T21:49:50.849+02:00"},"s":"I",  "c":"NETWORK",  "id":22943,   "ctx":"listener","msg":"Connection accepted","attr":{"remote":"172.20.0.4:41790","uuid":"e3f17a9d-b574-48ae-8a11-34b29a91dcc7","connectionId":13,"connectionCount":12}}
{"t":{"$date":"2023-09-14T21:49:50.849+02:00"},"s":"I",  "c":"NETWORK",  "id":22943,   "ctx":"listener","msg":"Connection accepted","attr":{"remote":"172.20.0.4:41804","uuid":"ef79b38f-7691-447b-a0c6-5237517d4a9c","connectionId":14,"connectionCount":13}}
{"t":{"$date":"2023-09-14T21:49:50.867+02:00"},"s":"I",  "c":"NETWORK",  "id":51800,   "ctx":"conn13","msg":"client metadata","attr":{"remote":"172.20.0.4:41790","client":"conn13","doc":{"driver":{"name":"nodejs","version":"4.16.0"},"platform":"Node.js v14.21.3, LE","os":{"name":"linux","architecture":"x64","version":"6.1.0-12-amd64","type":"Linux"}}}}
{"t":{"$date":"2023-09-14T21:49:50.868+02:00"},"s":"I",  "c":"NETWORK",  "id":51800,   "ctx":"conn14","msg":"client metadata","attr":{"remote":"172.20.0.4:41804","client":"conn14","doc":{"driver":{"name":"nodejs","version":"4.16.0"},"platform":"Node.js v14.21.3, LE","os":{"name":"linux","architecture":"x64","version":"6.1.0-12-amd64","type":"Linux"}}}}
{"t":{"$date":"2023-09-14T21:49:51.393+02:00"},"s":"I",  "c":"NETWORK",  "id":22943,   "ctx":"listener","msg":"Connection accepted","attr":{"remote":"172.20.0.4:41816","uuid":"91245ecf-1462-46da-92c9-9bb32834611d","connectionId":15,"connectionCount":14}}
{"t":{"$date":"2023-09-14T21:49:51.393+02:00"},"s":"I",  "c":"NETWORK",  "id":22943,   "ctx":"listener","msg":"Connection accepted","attr":{"remote":"172.20.0.4:41818","uuid":"459cffda-a20d-4787-9845-f688a5880177","connectionId":16,"connectionCount":15}}
{"t":{"$date":"2023-09-14T21:49:51.401+02:00"},"s":"I",  "c":"NETWORK",  "id":51800,   "ctx":"conn15","msg":"client metadata","attr":{"remote":"172.20.0.4:41816","client":"conn15","doc":{"driver":{"name":"nodejs","version":"4.16.0"},"platform":"Node.js v14.21.3, LE","os":{"name":"linux","architecture":"x64","version":"6.1.0-12-amd64","type":"Linux"}}}}
{"t":{"$date":"2023-09-14T21:49:51.401+02:00"},"s":"I",  "c":"NETWORK",  "id":51800,   "ctx":"conn16","msg":"client metadata","attr":{"remote":"172.20.0.4:41818","client":"conn16","doc":{"driver":{"name":"nodejs","version":"4.16.0"},"platform":"Node.js v14.21.3, LE","os":{"name":"linux","architecture":"x64","version":"6.1.0-12-amd64","type":"Linux"}}}}
{"t":{"$date":"2023-09-14T21:49:52.082+02:00"},"s":"I",  "c":"NETWORK",  "id":22943,   "ctx":"listener","msg":"Connection accepted","attr":{"remote":"172.20.0.4:40522","uuid":"53da9d95-2e0b-4ea9-b21b-acb4121291cc","connectionId":17,"connectionCount":16}}
{"t":{"$date":"2023-09-14T21:49:52.082+02:00"},"s":"I",  "c":"NETWORK",  "id":51800,   "ctx":"conn17","msg":"client metadata","attr":{"remote":"172.20.0.4:40522","client":"conn17","doc":{"driver":{"name":"nodejs","version":"4.16.0"},"platform":"Node.js v14.21.3, LE","os":{"name":"linux","architecture":"x64","version":"6.1.0-12-amd64","type":"Linux"}}}}
{"t":{"$date":"2023-09-14T21:49:54.862+02:00"},"s":"I",  "c":"NETWORK",  "id":22943,   "ctx":"listener","msg":"Connection accepted","attr":{"remote":"172.20.0.4:40530","uuid":"aaa4c801-a1a9-4f2c-896d-eeca6b0d2760","connectionId":18,"connectionCount":17}}
{"t":{"$date":"2023-09-14T21:49:54.863+02:00"},"s":"I",  "c":"NETWORK",  "id":51800,   "ctx":"conn18","msg":"client metadata","attr":{"remote":"172.20.0.4:40530","client":"conn18","doc":{"driver":{"name":"nodejs","version":"4.16.0"},"platform":"Node.js v14.21.3, LE","os":{"name":"linux","architecture":"x64","version":"6.1.0-12-amd64","type":"Linux"}}}}
{"t":{"$date":"2023-09-14T21:50:42.664+02:00"},"s":"I",  "c":"STORAGE",  "id":22430,   "ctx":"Checkpointer","msg":"WiredTiger message","attr":{"message":"[1694721042:664249][1:0x7f918e76f700], WT_SESSION.checkpoint: [WT_VERB_CHECKPOINT_PROGRESS] saving checkpoint snapshot min: 52, snapshot max: 52 snapshot count: 0, oldest timestamp: (1694720742, 1) , meta che
ckpoint timestamp: (1694721042, 1) base write gen: 14809349"}}
NoLooseEnds commented 1 year ago

I'm really stuck here. As far as I can tell it's outputing the exact same output as a clean install up until the last part, just not coming to the point of showing (which should be next):

+---------------------------------------------------+
|                   SERVER RUNNING                  |
+---------------------------------------------------+
|                                                   |
|  Rocket.Chat Version: 6.3.5                       |
|       NodeJS Version: 14.21.3 - x64               |
|      MongoDB Version: 5.0.21                      |
|       MongoDB Engine: wiredTiger                  |
|             Platform: linux                       |
|         Process Port: 3000                        |
|             Site URL: https://chat.domain.tld     |
|     ReplicaSet OpLog: Enabled                     |
|          Commit Hash: 5c9c3f7864                  |
|        Commit Branch: HEAD                        |
|                                                   |
+---------------------------------------------------+

(Gotton from a clean install)

Tried restoring the backup dump, but unfortunately that also gives the exact same error. Importing it "over" a default install messes up the install since it does not overwrite existing/duplicate keys (and doing that would probably make it go back to how it was).

Any help is much appreciated!

klys commented 1 year ago

The best advice is a preventive one:

The problem could be depending on how complex your configuration is.

Important also to read the change logs to confirm any breaking change that can also be catch on a isolated environment away form the production one.

NoLooseEnds commented 1 year ago

Thanks, I guess, that's the lesson to take. I figured I was pretty safe just dumping the DB regularly.

I ended up migrating away from RocketChat and over to Mattermost (something had been contemplating for a while anyway). And since I was completely stuck with this issue – it was the excuse I needed. I had all the data from the db, so I just needed to format the export a bit to get it over.

To answer your questions (for the record):

Very small instance with only a handfull of users.

Anyhow, closing this since it's not an active issue (for me) at least.

Lesson learned: Use a test environment, even for the smaller updates.