Rocket.Chat
Rocket.Chat copied to clipboard
Published
20 hours ago •
RocketChat
RocketChat
After Upgrade to 5.0.x: Connection to Mongo refused
Description:
Rocket.Chat does not start, because the connection to the MongoDB is refused (see logs below)
Steps to reproduce:
- Install rocket chat 4.8.3 via docker compose
- set the image version to 5.0.x
- Up the compose file
Expected behavior:
Have a working rocket chat instance
Actual behavior:
The server does not start, because it waits for the mongoDB forever
Server Setup Information:
- Version of Rocket.Chat Server: 5.0.2 and 5.0.1
- Operating System: ubuntu server 18.04
- Deployment Method: docker compose
- Number of Running Instances: 1
- DB Replicaset Oplog:
- NodeJS Version:
- MongoDB Version: 4.4
Client Setup Information
- Desktop App or Browser Version: n/a
- Operating System: n/a
Additional context
my compose file:
version: '2'
services:
rocketchat:
image: registry.rocket.chat/rocketchat/rocket.chat:5.0.2
command: >
bash -c
"for (( ; ; )); do
node main.js &&
s=$$? && break || s=$$?;
echo \"Could not start Rocket.Chat. Waiting 5 secs...\";
sleep 5;
done; (exit $$s)"
restart: unless-stopped
volumes:
- ./uploads:/app/uploads
environment:
- PORT=3000
- ROOT_URL=https://chat.domain.com
- MONGO_URL=mongodb://mongo:27017/rocketchat
- MONGO_OPLOG_URL=mongodb://mongo:27017/local
- MAIL_URL=smtp://smtp.email
- TZ=Europe/Berlin
depends_on:
- mongo
# ports:
# - 3000:3000
networks:
- caddy_net
- default
mongo:
image: mongo:4.4
restart: unless-stopped
volumes:
- ./data/db:/data/db
- ./data/dump:/dump
command: >
bash -c
"while [ ! -f /data/db/WiredTiger ]; do
echo \"wiredTiger migration hasn't started yet. Waiting 30 secs...\";
sleep 30;
done;
docker-entrypoint.sh mongod --oplogSize 128 --replSet rs0 --storageEngine=wiredTiger;"
# command: mongod --oplogSize 128 --replSet rs0 --storageEngine=wiredTiger;"
# depends_on:
# - migrator
# migrator:
# build: ./docker/
# volumes:
# - ./data/db:/data/db
mongo-init-replica:
image: mongo:4.4
command: >
bash -c
"for (( ; ; )); do
mongo mongo/rocketchat --eval \"
rs.initiate({
_id: 'rs0',
members: [ { _id: 0, host: 'localhost:27017' } ]})\" &&
s=$$? && break || s=$$?;
echo \"Could not reach MongoDB. Waiting 5 secs ...\";
sleep 5;
done; (exit $$s)"
depends_on:
- mongo
networks:
caddy_net:
external: true
default:
Relevant logs:
$ docker-compose up -d && docker-compose logs -f
Creating network "rocketchat_default" with the default driver
Creating rocketchat_mongo_1 ... done
Creating rocketchat_mongo-init-replica_1 ... done
Creating rocketchat_rocketchat_1 ... done
Attaching to rocketchat_rocketchat_1, rocketchat_mongo-init-replica_1, rocketchat_mongo_1
mongo-init-replica_1 |
mongo-init-replica_1 | WARNING: MongoDB 5.0+ requires a CPU with AVX support, and your current system does not appear to have that!
mongo-init-replica_1 | see https://jira.mongodb.org/browse/SERVER-54407
mongo-init-replica_1 | see also https://www.mongodb.com/community/forums/t/mongodb-5-0-cpu-intel-g4650-compatibility/116610/2
mongo-init-replica_1 | see also https://github.com/docker-library/mongo/issues/485#issuecomment-891991814
mongo-init-replica_1 |
mongo-init-replica_1 | MongoDB shell version v4.4.15
mongo-init-replica_1 | connecting to: mongodb://mongo:27017/rocketchat?compressors=disabled&gssapiServiceName=mongodb
mongo-init-replica_1 | Implicit session: session { "id" : UUID("ae334c5f-ecb1-4abe-8798-7200b1c7d7e9") }
mongo-init-replica_1 | MongoDB server version: 4.4.15
mongo-init-replica_1 | {
mongo-init-replica_1 | "operationTime" : Timestamp(1660036058, 2),
mongo-init-replica_1 | "ok" : 0,
mongo-init-replica_1 | "errmsg" : "already initialized",
mongo-init-replica_1 | "code" : 23,
mongo-init-replica_1 | "codeName" : "AlreadyInitialized",
mongo-init-replica_1 | "$clusterTime" : {
mongo-init-replica_1 | "clusterTime" : Timestamp(1660036058, 2),
mongo-init-replica_1 | "signature" : {
mongo-init-replica_1 | "hash" : BinData(0,"AAAAAAAAAAAAAAAAAAAAAAAAAAA="),
mongo-init-replica_1 | "keyId" : NumberLong(0)
mongo-init-replica_1 | }
mongo-init-replica_1 | }
mongo-init-replica_1 | }
mongo_1 |
mongo_1 | WARNING: MongoDB 5.0+ requires a CPU with AVX support, and your current system does not appear to have that!
mongo_1 | see https://jira.mongodb.org/browse/SERVER-54407
mongo_1 | see also https://www.mongodb.com/community/forums/t/mongodb-5-0-cpu-intel-g4650-compatibility/116610/2
mongo_1 | see also https://github.com/docker-library/mongo/issues/485#issuecomment-891991814
mongo_1 |
mongo_1 |
mongo_1 | WARNING: MongoDB 5.0+ requires a CPU with AVX support, and your current system does not appear to have that!
mongo_1 | see https://jira.mongodb.org/browse/SERVER-54407
mongo_1 | see also https://www.mongodb.com/community/forums/t/mongodb-5-0-cpu-intel-g4650-compatibility/116610/2
mongo_1 | see also https://github.com/docker-library/mongo/issues/485#issuecomment-891991814
mongo_1 |
mongo_1 | {"t":{"$date":"2022-08-09T09:07:36.276+00:00"},"s":"I", "c":"CONTROL", "id":23285, "ctx":"main","msg":"Automatically disabling TLS 1.0, to force-enable TLS 1.0 specify --sslDisabledProtocols 'none'"}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:36.277+00:00"},"s":"W", "c":"ASIO", "id":22601, "ctx":"main","msg":"No TransportLayer configured during NetworkInterface startup"}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:36.278+00:00"},"s":"I", "c":"NETWORK", "id":4648601, "ctx":"main","msg":"Implicit TCP FastOpen unavailable. If TCP FastOpen is required, set tcpFastOpenServer, tcpFastOpenClient, and tcpFastOpenQueueSize."}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:36.278+00:00"},"s":"W", "c":"ASIO", "id":22601, "ctx":"main","msg":"No TransportLayer configured during NetworkInterface startup"}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:36.278+00:00"},"s":"I", "c":"STORAGE", "id":4615611, "ctx":"initandlisten","msg":"MongoDB starting","attr":{"pid":1,"port":27017,"dbPath":"/data/db","architecture":"64-bit","host":"65d7005edb55"}}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:36.278+00:00"},"s":"I", "c":"CONTROL", "id":23403, "ctx":"initandlisten","msg":"Build Info","attr":{"buildInfo":{"version":"4.4.15","gitVersion":"bc17cf2c788c5dda2801a090ea79da5ff7d5fac9","openSSLVersion":"OpenSSL 1.1.1f 31 Mar 2020","modules":[],"allocator":"tcmalloc","environment":{"distmod":"ubuntu2004","distarch":"x86_64","target_arch":"x86_64"}}}}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:36.278+00:00"},"s":"I", "c":"CONTROL", "id":51765, "ctx":"initandlisten","msg":"Operating System","attr":{"os":{"name":"Ubuntu","version":"20.04"}}}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:36.278+00:00"},"s":"I", "c":"CONTROL", "id":21951, "ctx":"initandlisten","msg":"Options set by command line","attr":{"options":{"net":{"bindIp":"*"},"replication":{"oplogSizeMB":128,"replSet":"rs0"},"storage":{"engine":"wiredTiger"}}}}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:36.279+00: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"]}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:36.280+00:00"},"s":"I", "c":"STORAGE", "id":22315, "ctx":"initandlisten","msg":"Opening WiredTiger","attr":{"config":"create,cache_size=27655M,session_max=33000,eviction=(threads_min=4,threads_max=4),config_base=false,statistics=(fast),log=(enabled=true,archive=true,path=journal,compressor=snappy),file_manager=(close_idle_time=100000,close_scan_interval=10,close_handle_minimum=250),statistics_log=(wait=0),verbose=[recovery_progress,checkpoint_progress,compact_progress],"}}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:37.275+00:00"},"s":"I", "c":"STORAGE", "id":22430, "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":"[1660036057:275201][1:0x7f4c39185cc0], txn-recover: [WT_VERB_RECOVERY_PROGRESS] Recovering log 266 through 267"}}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:37.354+00:00"},"s":"I", "c":"STORAGE", "id":22430, "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":"[1660036057:354524][1:0x7f4c39185cc0], txn-recover: [WT_VERB_RECOVERY_PROGRESS] Recovering log 267 through 267"}}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:37.500+00:00"},"s":"I", "c":"STORAGE", "id":22430, "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":"[1660036057:500334][1:0x7f4c39185cc0], txn-recover: [WT_VERB_RECOVERY | WT_VERB_RECOVERY_PROGRESS] Main recovery loop: starting at 266/30080 to 267/256"}}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:37.501+00:00"},"s":"I", "c":"STORAGE", "id":22430, "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":"[1660036057:501007][1:0x7f4c39185cc0], txn-recover: [WT_VERB_RECOVERY_PROGRESS] Recovering log 266 through 267"}}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:37.605+00:00"},"s":"I", "c":"STORAGE", "id":22430, "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":"[1660036057:605525][1:0x7f4c39185cc0], txn-recover: [WT_VERB_RECOVERY_PROGRESS] Recovering log 267 through 267"}}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:37.673+00:00"},"s":"I", "c":"STORAGE", "id":22430, "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":"[1660036057:672986][1:0x7f4c39185cc0], txn-recover: [WT_VERB_RECOVERY | WT_VERB_RECOVERY_PROGRESS] Set global recovery timestamp: (1660035336, 1)"}}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:37.673+00:00"},"s":"I", "c":"STORAGE", "id":22430, "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":"[1660036057:673071][1:0x7f4c39185cc0], txn-recover: [WT_VERB_RECOVERY | WT_VERB_RECOVERY_PROGRESS] Set global oldest timestamp: (1660035331, 1)"}}
rocketchat_mongo-init-replica_1 exited with code 0
mongo_1 | {"t":{"$date":"2022-08-09T09:07:37.759+00:00"},"s":"I", "c":"STORAGE", "id":22430, "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":"[1660036057:759584][1:0x7f4c39185cc0], WT_SESSION.checkpoint: [WT_VERB_CHECKPOINT_PROGRESS] saving checkpoint snapshot min: 14, snapshot max: 14 snapshot count: 0, oldest timestamp: (1660035331, 1) , meta checkpoint timestamp: (1660035336, 1) base write gen: 4225324"}}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:37.963+00:00"},"s":"I", "c":"STORAGE", "id":4795906, "ctx":"initandlisten","msg":"WiredTiger opened","attr":{"durationMillis":1683}}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:37.963+00:00"},"s":"I", "c":"RECOVERY", "id":23987, "ctx":"initandlisten","msg":"WiredTiger recoveryTimestamp","attr":{"recoveryTimestamp":{"$timestamp":{"t":1660035336,"i":1}}}}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:37.966+00:00"},"s":"I", "c":"STORAGE", "id":4366408, "ctx":"initandlisten","msg":"No table logging settings modifications are required for existing WiredTiger tables","attr":{"loggingEnabled":false}}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:37.979+00:00"},"s":"I", "c":"STORAGE", "id":22383, "ctx":"initandlisten","msg":"The size storer reports that the oplog contains","attr":{"numRecords":528490,"dataSize":133020096}}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:37.979+00:00"},"s":"I", "c":"STORAGE", "id":22386, "ctx":"initandlisten","msg":"Sampling the oplog to determine where to place markers for truncation"}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:37.980+00: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":1657379496,"i":1}},"to":{"$timestamp":{"t":1660035336,"i":1}}}}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:37.980+00:00"},"s":"I", "c":"STORAGE", "id":22390, "ctx":"initandlisten","msg":"Taking samples and assuming each oplog section contains","attr":{"numSamples":99,"containsNumRecords":53325,"containsNumBytes":13421818}}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:37.992+00:00"},"s":"I", "c":"STORAGE", "id":22393, "ctx":"initandlisten","msg":"Oplog sampling complete"}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:37.992+00:00"},"s":"I", "c":"STORAGE", "id":22382, "ctx":"initandlisten","msg":"WiredTiger record store oplog processing finished","attr":{"durationMillis":13}}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:37.994+00:00"},"s":"I", "c":"STORAGE", "id":22262, "ctx":"initandlisten","msg":"Timestamp monitor starting"}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:38.019+00: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"]}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:38.022+00:00"},"s":"W", "c":"CONTROL", "id":22167, "ctx":"initandlisten","msg":"You are running on a NUMA machine. We suggest launching mongod like this to avoid performance problems: numactl --interleave=all mongod [other options]","tags":["startupWarnings"]}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:38.113+00:00"},"s":"I", "c":"STORAGE", "id":20536, "ctx":"initandlisten","msg":"Flow Control is enabled on this deployment"}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:38.115+00:00"},"s":"I", "c":"SHARDING", "id":20997, "ctx":"initandlisten","msg":"Refreshed RWC defaults","attr":{"newDefaults":{}}}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:38.118+00:00"},"s":"I", "c":"FTDC", "id":20625, "ctx":"initandlisten","msg":"Initializing full-time diagnostic data capture","attr":{"dataDirectory":"/data/db/diagnostic.data"}}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:38.120+00:00"},"s":"I", "c":"REPL", "id":6015317, "ctx":"initandlisten","msg":"Setting new configuration state","attr":{"newState":"ConfigStartingUp","oldState":"ConfigPreStart"}}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:38.120+00:00"},"s":"I", "c":"REPL", "id":4280500, "ctx":"initandlisten","msg":"Attempting to create internal replication collections"}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:38.124+00:00"},"s":"I", "c":"REPL", "id":4280501, "ctx":"initandlisten","msg":"Attempting to load local voted for document"}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:38.124+00:00"},"s":"I", "c":"REPL", "id":4280502, "ctx":"initandlisten","msg":"Searching for local Rollback ID document"}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:38.126+00:00"},"s":"I", "c":"REPL", "id":21529, "ctx":"initandlisten","msg":"Initializing rollback ID","attr":{"rbid":2}}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:38.126+00:00"},"s":"I", "c":"REPL", "id":4280504, "ctx":"initandlisten","msg":"Cleaning up any partially applied oplog batches & reading last op from oplog"}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:38.128+00:00"},"s":"I", "c":"REPL", "id":21544, "ctx":"initandlisten","msg":"Recovering from stable timestamp","attr":{"stableTimestamp":{"$timestamp":{"t":1660035336,"i":1}},"topOfOplog":{"ts":{"$timestamp":{"t":1660035336,"i":1}},"t":95},"appliedThrough":{"ts":{"$timestamp":{"t":0,"i":0}},"t":-1},"oplogTruncateAfterPoint":{"$timestamp":{"t":0,"i":0}}}}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:38.128+00:00"},"s":"I", "c":"REPL", "id":21545, "ctx":"initandlisten","msg":"Starting recovery oplog application at the stable timestamp","attr":{"stableTimestamp":{"$timestamp":{"t":1660035336,"i":1}}}}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:38.128+00: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"}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:38.128+00:00"},"s":"I", "c":"REPL", "id":4280506, "ctx":"initandlisten","msg":"Reconstructing prepared transactions"}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:38.129+00:00"},"s":"I", "c":"REPL", "id":4280507, "ctx":"initandlisten","msg":"Loaded replica set config, scheduled callback to set local config"}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:38.129+00:00"},"s":"I", "c":"REPL", "id":4280508, "ctx":"ReplCoord-0","msg":"Attempting to set local replica set config; validating config for startup"}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:38.131+00:00"},"s":"I", "c":"REPL", "id":4280509, "ctx":"ReplCoord-0","msg":"Local configuration validated for startup"}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:38.131+00:00"},"s":"I", "c":"REPL", "id":6015317, "ctx":"ReplCoord-0","msg":"Setting new configuration state","attr":{"newState":"ConfigSteady","oldState":"ConfigStartingUp"}}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:38.131+00:00"},"s":"I", "c":"REPL", "id":21392, "ctx":"ReplCoord-0","msg":"New replica set config in use","attr":{"config":{"_id":"rs0","version":2,"term":95,"protocolVersion":1,"writeConcernMajorityJournalDefault":true,"members":[{"_id":0,"host":"localhost:27017","arbiterOnly":false,"buildIndexes":true,"hidden":false,"priority":1.0,"tags":{},"slaveDelay":0,"votes":1}],"settings":{"chainingAllowed":true,"heartbeatIntervalMillis":2000,"heartbeatTimeoutSecs":10,"electionTimeoutMillis":10000,"catchUpTimeoutMillis":-1,"catchUpTakeoverDelayMillis":30000,"getLastErrorModes":{},"getLastErrorDefaults":{"w":1,"wtimeout":0},"replicaSetId":{"$oid":"615ae569b4f1c0850523539d"}}}}}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:38.131+00:00"},"s":"I", "c":"REPL", "id":21393, "ctx":"ReplCoord-0","msg":"Found self in config","attr":{"hostAndPort":"localhost:27017"}}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:38.131+00:00"},"s":"I", "c":"REPL", "id":21358, "ctx":"ReplCoord-0","msg":"Replica set state transition","attr":{"newState":"STARTUP2","oldState":"STARTUP"}}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:38.131+00:00"},"s":"I", "c":"REPL", "id":21320, "ctx":"ReplCoord-0","msg":"Updated term","attr":{"term":95}}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:38.131+00:00"},"s":"I", "c":"REPL", "id":21306, "ctx":"ReplCoord-0","msg":"Starting replication storage threads"}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:38.132+00:00"},"s":"I", "c":"NETWORK", "id":4603701, "ctx":"LogicalSessionCacheRefresh","msg":"Starting Replica Set Monitor","attr":{"protocol":"streamable","uri":"rs0/localhost:27017"}}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:38.132+00:00"},"s":"I", "c":"-", "id":4333223, "ctx":"LogicalSessionCacheRefresh","msg":"RSM now monitoring replica set","attr":{"replicaSet":"rs0","nReplicaSetMembers":1}}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:38.132+00:00"},"s":"I", "c":"-", "id":4333226, "ctx":"LogicalSessionCacheRefresh","msg":"RSM host was added to the topology","attr":{"replicaSet":"rs0","host":"localhost:27017"}}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:38.132+00:00"},"s":"I", "c":"-", "id":4333218, "ctx":"LogicalSessionCacheRefresh","msg":"Rescheduling the next replica set monitoring request","attr":{"replicaSet":"rs0","host":"localhost:27017","delayMillis":0}}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:38.132+00:00"},"s":"I", "c":"REPL", "id":40440, "ctx":"initandlisten","msg":"Starting the TopologyVersionObserver"}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:38.132+00:00"},"s":"I", "c":"REPL", "id":4280512, "ctx":"ReplCoord-0","msg":"No initial sync required. Attempting to begin steady replication"}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:38.132+00:00"},"s":"I", "c":"CONNPOOL", "id":22576, "ctx":"ReplicaSetMonitor-TaskExecutor","msg":"Connecting","attr":{"hostAndPort":"localhost:27017"}}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:38.132+00:00"},"s":"I", "c":"REPL", "id":21358, "ctx":"ReplCoord-0","msg":"Replica set state transition","attr":{"newState":"RECOVERING","oldState":"STARTUP2"}}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:38.132+00:00"},"s":"I", "c":"REPL", "id":40445, "ctx":"TopologyVersionObserver","msg":"Started TopologyVersionObserver"}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:38.133+00:00"},"s":"I", "c":"NETWORK", "id":23015, "ctx":"listener","msg":"Listening on","attr":{"address":"/tmp/mongodb-27017.sock"}}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:38.133+00:00"},"s":"I", "c":"NETWORK", "id":23015, "ctx":"listener","msg":"Listening on","attr":{"address":"0.0.0.0"}}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:38.133+00:00"},"s":"I", "c":"NETWORK", "id":23016, "ctx":"listener","msg":"Waiting for connections","attr":{"port":27017,"ssl":"off"}}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:38.133+00:00"},"s":"I", "c":"NETWORK", "id":22943, "ctx":"listener","msg":"Connection accepted","attr":{"remote":"127.0.0.1:38894","connectionId":2,"connectionCount":1}}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:38.134+00:00"},"s":"I", "c":"NETWORK", "id":51800, "ctx":"conn2","msg":"client metadata","attr":{"remote":"127.0.0.1:38894","client":"conn2","doc":{"driver":{"name":"NetworkInterfaceTL","version":"4.4.15"},"os":{"type":"Linux","name":"Ubuntu","architecture":"x86_64","version":"20.04"}}}}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:38.134+00:00"},"s":"I", "c":"REPL", "id":21299, "ctx":"ReplCoord-0","msg":"Starting replication fetcher thread"}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:38.134+00:00"},"s":"I", "c":"NETWORK", "id":23729, "ctx":"ReplicaSetMonitor-TaskExecutor","msg":"ServerPingMonitor is now monitoring host","attr":{"host":"localhost:27017","replicaSet":"rs0"}}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:38.134+00:00"},"s":"I", "c":"REPL", "id":21300, "ctx":"ReplCoord-0","msg":"Starting replication applier thread"}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:38.134+00:00"},"s":"I", "c":"NETWORK", "id":4333213, "ctx":"ReplicaSetMonitor-TaskExecutor","msg":"RSM Topology Change","attr":{"replicaSet":"rs0","newTopologyDescription":"{ id: \"7bbe0157-b7d4-43e7-9342-5902165814a5\", topologyType: \"ReplicaSetNoPrimary\", servers: { localhost:27017: { address: \"localhost:27017\", topologyVersion: { processId: ObjectId('62f223d81afcb993af3423f1'), counter: 2 }, roundTripTime: 585, lastWriteDate: new Date(1660035336000), opTime: { ts: Timestamp(1660035336, 1), t: 95 }, type: \"RSOther\", minWireVersion: 9, maxWireVersion: 9, me: \"localhost:27017\", setName: \"rs0\", setVersion: 2, lastUpdateTime: new Date(1660036058134), logicalSessionTimeoutMinutes: 30, hosts: { 0: \"localhost:27017\" }, arbiters: {}, passives: {} } }, setName: \"rs0\", compatible: true }","previousTopologyDescription":"{ id: \"cc7862da-8f44-4a11-8463-08da7c3e0e22\", topologyType: \"ReplicaSetNoPrimary\", servers: { localhost:27017: { address: \"localhost:27017\", type: \"Unknown\", minWireVersion: 0, maxWireVersion: 0, lastUpdateTime: new Date(-9223372036854775808), hosts: {}, arbiters: {}, passives: {} } }, setName: \"rs0\", compatible: true }"}}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:38.134+00:00"},"s":"I", "c":"REPL", "id":21301, "ctx":"ReplCoord-0","msg":"Starting replication reporter thread"}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:38.134+00:00"},"s":"I", "c":"REPL", "id":21224, "ctx":"OplogApplier-0","msg":"Starting oplog application"}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:38.134+00:00"},"s":"I", "c":"REPL", "id":21358, "ctx":"OplogApplier-0","msg":"Replica set state transition","attr":{"newState":"SECONDARY","oldState":"RECOVERING"}}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:38.135+00:00"},"s":"I", "c":"NETWORK", "id":22943, "ctx":"listener","msg":"Connection accepted","attr":{"remote":"127.0.0.1:38896","connectionId":3,"connectionCount":2}}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:38.135+00: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}}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:38.135+00: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":95}}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:38.135+00:00"},"s":"I", "c":"ELECTION", "id":21444, "ctx":"ReplCoord-0","msg":"Dry election run succeeded, running for election","attr":{"newTerm":96}}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:38.135+00:00"},"s":"I", "c":"ELECTION", "id":6015300, "ctx":"ReplCoord-0","msg":"Storing last vote document in local storage for my election","attr":{"lastVote":{"term":96,"candidateIndex":0}}}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:38.135+00:00"},"s":"I", "c":"NETWORK", "id":51800, "ctx":"conn3","msg":"client metadata","attr":{"remote":"127.0.0.1:38896","client":"conn3","doc":{"driver":{"name":"NetworkInterfaceTL","version":"4.4.15"},"os":{"type":"Linux","name":"Ubuntu","architecture":"x86_64","version":"20.04"}}}}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:38.136+00:00"},"s":"I", "c":"NETWORK", "id":4333213, "ctx":"ReplicaSetMonitor-TaskExecutor","msg":"RSM Topology Change","attr":{"replicaSet":"rs0","newTopologyDescription":"{ id: \"cb80b4bc-7cd7-4997-84ae-c507281c944c\", topologyType: \"ReplicaSetNoPrimary\", servers: { localhost:27017: { address: \"localhost:27017\", topologyVersion: { processId: ObjectId('62f223d81afcb993af3423f1'), counter: 3 }, roundTripTime: 730, lastWriteDate: new Date(1660035336000), opTime: { ts: Timestamp(1660035336, 1), t: 95 }, type: \"RSSecondary\", minWireVersion: 9, maxWireVersion: 9, me: \"localhost:27017\", setName: \"rs0\", setVersion: 2, lastUpdateTime: new Date(1660036058135), logicalSessionTimeoutMinutes: 30, hosts: { 0: \"localhost:27017\" }, arbiters: {}, passives: {} } }, logicalSessionTimeoutMinutes: 30, setName: \"rs0\", compatible: true }","previousTopologyDescription":"{ id: \"29fb1de5-7bf4-4d52-85d7-88913751ff60\", topologyType: \"ReplicaSetNoPrimary\", servers: { localhost:27017: { address: \"localhost:27017\", topologyVersion: { processId: ObjectId('62f223d81afcb993af3423f1'), counter: 2 }, roundTripTime: 737, lastWriteDate: new Date(1660035336000), opTime: { ts: Timestamp(1660035336, 1), t: 95 }, type: \"RSOther\", minWireVersion: 9, maxWireVersion: 9, me: \"localhost:27017\", setName: \"rs0\", setVersion: 2, lastUpdateTime: new Date(1660036058135), logicalSessionTimeoutMinutes: 30, hosts: { 0: \"localhost:27017\" }, arbiters: {}, passives: {} } }, setName: \"rs0\", compatible: true }"}}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:38.140+00:00"},"s":"I", "c":"ELECTION", "id":21450, "ctx":"ReplCoord-0","msg":"Election succeeded, assuming primary role","attr":{"term":96}}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:38.140+00:00"},"s":"I", "c":"REPL", "id":21358, "ctx":"ReplCoord-0","msg":"Replica set state transition","attr":{"newState":"PRIMARY","oldState":"SECONDARY"}}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:38.140+00:00"},"s":"I", "c":"REPL", "id":21106, "ctx":"ReplCoord-0","msg":"Resetting sync source to empty","attr":{"previousSyncSource":":27017"}}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:38.140+00:00"},"s":"I", "c":"REPL", "id":21359, "ctx":"ReplCoord-0","msg":"Entering primary catch-up mode"}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:38.140+00:00"},"s":"I", "c":"REPL", "id":6015304, "ctx":"ReplCoord-0","msg":"Skipping primary catchup since we are the only node in the replica set."}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:38.140+00:00"},"s":"I", "c":"REPL", "id":21363, "ctx":"ReplCoord-0","msg":"Exited primary catch-up mode"}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:38.140+00:00"},"s":"I", "c":"REPL", "id":21107, "ctx":"ReplCoord-0","msg":"Stopping replication producer"}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:38.140+00:00"},"s":"I", "c":"REPL", "id":21239, "ctx":"ReplBatcher","msg":"Oplog buffer has been drained","attr":{"term":96}}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:38.140+00:00"},"s":"I", "c":"REPL", "id":21239, "ctx":"ReplBatcher","msg":"Oplog buffer has been drained","attr":{"term":96}}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:38.140+00:00"},"s":"I", "c":"NETWORK", "id":4333213, "ctx":"ReplicaSetMonitor-TaskExecutor","msg":"RSM Topology Change","attr":{"replicaSet":"rs0","newTopologyDescription":"{ id: \"61e98353-7971-4383-b4c7-ec55eb98496b\", topologyType: \"ReplicaSetNoPrimary\", servers: { localhost:27017: { address: \"localhost:27017\", topologyVersion: { processId: ObjectId('62f223d81afcb993af3423f1'), counter: 4 }, roundTripTime: 730, lastWriteDate: new Date(1660035336000), opTime: { ts: Timestamp(1660035336, 1), t: 95 }, type: \"RSSecondary\", minWireVersion: 9, maxWireVersion: 9, me: \"localhost:27017\", setName: \"rs0\", setVersion: 2, electionId: ObjectId('7fffffff0000000000000060'), primary: \"localhost:27017\", lastUpdateTime: new Date(1660036058140), logicalSessionTimeoutMinutes: 30, hosts: { 0: \"localhost:27017\" }, arbiters: {}, passives: {} } }, logicalSessionTimeoutMinutes: 30, setName: \"rs0\", compatible: true }","previousTopologyDescription":"{ id: \"52ab6e00-a34e-46fb-b0bd-65aa47625b4e\", topologyType: \"ReplicaSetNoPrimary\", servers: { localhost:27017: { address: \"localhost:27017\", topologyVersion: { processId: ObjectId('62f223d81afcb993af3423f1'), counter: 3 }, roundTripTime: 730, lastWriteDate: new Date(1660035336000), opTime: { ts: Timestamp(1660035336, 1), t: 95 }, type: \"RSSecondary\", minWireVersion: 9, maxWireVersion: 9, me: \"localhost:27017\", setName: \"rs0\", setVersion: 2, lastUpdateTime: new Date(1660036058136), logicalSessionTimeoutMinutes: 30, hosts: { 0: \"localhost:27017\" }, arbiters: {}, passives: {} } }, logicalSessionTimeoutMinutes: 30, setName: \"rs0\", compatible: true }"}}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:38.140+00:00"},"s":"I", "c":"REPL", "id":21343, "ctx":"RstlKillOpThread","msg":"Starting to kill user operations"}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:38.140+00:00"},"s":"I", "c":"REPL", "id":21344, "ctx":"RstlKillOpThread","msg":"Stopped killing user operations"}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:38.141+00:00"},"s":"I", "c":"REPL", "id":21340, "ctx":"RstlKillOpThread","msg":"State transition ops metrics","attr":{"metrics":{"lastStateTransition":"stepUp","userOpsKilled":0,"userOpsRunning":1}}}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:38.141+00:00"},"s":"I", "c":"REPL", "id":4508103, "ctx":"OplogApplier-0","msg":"Increment the config term via reconfig"}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:38.141+00:00"},"s":"I", "c":"REPL", "id":6015313, "ctx":"OplogApplier-0","msg":"Replication config state is Steady, starting reconfig"}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:38.141+00:00"},"s":"I", "c":"REPL", "id":6015317, "ctx":"OplogApplier-0","msg":"Setting new configuration state","attr":{"newState":"ConfigReconfiguring","oldState":"ConfigSteady"}}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:38.141+00:00"},"s":"I", "c":"REPL", "id":21353, "ctx":"OplogApplier-0","msg":"replSetReconfig config object parses ok","attr":{"numMembers":1}}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:38.141+00:00"},"s":"I", "c":"REPL", "id":51814, "ctx":"OplogApplier-0","msg":"Persisting new config to disk"}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:38.145+00:00"},"s":"I", "c":"REPL", "id":6015315, "ctx":"OplogApplier-0","msg":"Persisted new config to disk"}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:38.145+00:00"},"s":"I", "c":"REPL", "id":6015317, "ctx":"OplogApplier-0","msg":"Setting new configuration state","attr":{"newState":"ConfigSteady","oldState":"ConfigReconfiguring"}}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:38.145+00:00"},"s":"I", "c":"REPL", "id":21392, "ctx":"OplogApplier-0","msg":"New replica set config in use","attr":{"config":{"_id":"rs0","version":2,"term":96,"protocolVersion":1,"writeConcernMajorityJournalDefault":true,"members":[{"_id":0,"host":"localhost:27017","arbiterOnly":false,"buildIndexes":true,"hidden":false,"priority":1.0,"tags":{},"slaveDelay":0,"votes":1}],"settings":{"chainingAllowed":true,"heartbeatIntervalMillis":2000,"heartbeatTimeoutSecs":10,"electionTimeoutMillis":10000,"catchUpTimeoutMillis":-1,"catchUpTakeoverDelayMillis":30000,"getLastErrorModes":{},"getLastErrorDefaults":{"w":1,"wtimeout":0},"replicaSetId":{"$oid":"615ae569b4f1c0850523539d"}}}}}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:38.145+00:00"},"s":"I", "c":"REPL", "id":21393, "ctx":"OplogApplier-0","msg":"Found self in config","attr":{"hostAndPort":"localhost:27017"}}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:38.145+00:00"},"s":"I", "c":"REPL", "id":6015310, "ctx":"OplogApplier-0","msg":"Starting to transition to primary."}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:38.145+00:00"},"s":"I", "c":"NETWORK", "id":4333213, "ctx":"ReplicaSetMonitor-TaskExecutor","msg":"RSM Topology Change","attr":{"replicaSet":"rs0","newTopologyDescription":"{ id: \"ccd8ded7-a717-4609-816e-7981f47b3fbe\", topologyType: \"ReplicaSetNoPrimary\", servers: { localhost:27017: { address: \"localhost:27017\", topologyVersion: { processId: ObjectId('62f223d81afcb993af3423f1'), counter: 5 }, roundTripTime: 730, lastWriteDate: new Date(1660035336000), opTime: { ts: Timestamp(1660035336, 1), t: 95 }, type: \"RSSecondary\", minWireVersion: 9, maxWireVersion: 9, me: \"localhost:27017\", setName: \"rs0\", setVersion: 2, electionId: ObjectId('7fffffff0000000000000060'), primary: \"localhost:27017\", lastUpdateTime: new Date(1660036058145), logicalSessionTimeoutMinutes: 30, hosts: { 0: \"localhost:27017\" }, arbiters: {}, passives: {} } }, logicalSessionTimeoutMinutes: 30, setName: \"rs0\", compatible: true }","previousTopologyDescription":"{ id: \"61e98353-7971-4383-b4c7-ec55eb98496b\", topologyType: \"ReplicaSetNoPrimary\", servers: { localhost:27017: { address: \"localhost:27017\", topologyVersion: { processId: ObjectId('62f223d81afcb993af3423f1'), counter: 4 }, roundTripTime: 730, lastWriteDate: new Date(1660035336000), opTime: { ts: Timestamp(1660035336, 1), t: 95 }, type: \"RSSecondary\", minWireVersion: 9, maxWireVersion: 9, me: \"localhost:27017\", setName: \"rs0\", setVersion: 2, electionId: ObjectId('7fffffff0000000000000060'), primary: \"localhost:27017\", lastUpdateTime: new Date(1660036058140), logicalSessionTimeoutMinutes: 30, hosts: { 0: \"localhost:27017\" }, arbiters: {}, passives: {} } }, logicalSessionTimeoutMinutes: 30, setName: \"rs0\", compatible: true }"}}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:38.146+00:00"},"s":"I", "c":"REPL", "id":6015309, "ctx":"OplogApplier-0","msg":"Logging transition to primary to oplog on stepup"}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:38.147+00:00"},"s":"I", "c":"STORAGE", "id":20657, "ctx":"OplogApplier-0","msg":"IndexBuildsCoordinator::onStepUp - this node is stepping up to primary"}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:38.147+00:00"},"s":"I", "c":"REPL", "id":21331, "ctx":"OplogApplier-0","msg":"Transition to primary complete; database writes are now permitted"}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:38.148+00:00"},"s":"I", "c":"REPL", "id":6015306, "ctx":"OplogApplier-0","msg":"Applier already left draining state, exiting."}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:38.148+00:00"},"s":"I", "c":"NETWORK", "id":4333213, "ctx":"ReplicaSetMonitor-TaskExecutor","msg":"RSM Topology Change","attr":{"replicaSet":"rs0","newTopologyDescription":"{ id: \"0e97ac7c-d7e7-42fb-b9e3-0609deb40ca2\", topologyType: \"ReplicaSetWithPrimary\", servers: { localhost:27017: { address: \"localhost:27017\", topologyVersion: { processId: ObjectId('62f223d81afcb993af3423f1'), counter: 6 }, roundTripTime: 730, lastWriteDate: new Date(1660036058000), opTime: { ts: Timestamp(1660036058, 2), t: 96 }, type: \"RSPrimary\", minWireVersion: 9, maxWireVersion: 9, me: \"localhost:27017\", setName: \"rs0\", setVersion: 2, electionId: ObjectId('7fffffff0000000000000060'), primary: \"localhost:27017\", lastUpdateTime: new Date(1660036058148), logicalSessionTimeoutMinutes: 30, hosts: { 0: \"localhost:27017\" }, arbiters: {}, passives: {} } }, logicalSessionTimeoutMinutes: 30, setName: \"rs0\", compatible: true, maxElectionIdSetVersion: { electionId: ObjectId('7fffffff0000000000000060'), setVersion: 2 } }","previousTopologyDescription":"{ id: \"ccd8ded7-a717-4609-816e-7981f47b3fbe\", topologyType: \"ReplicaSetNoPrimary\", servers: { localhost:27017: { address: \"localhost:27017\", topologyVersion: { processId: ObjectId('62f223d81afcb993af3423f1'), counter: 5 }, roundTripTime: 730, lastWriteDate: new Date(1660035336000), opTime: { ts: Timestamp(1660035336, 1), t: 95 }, type: \"RSSecondary\", minWireVersion: 9, maxWireVersion: 9, me: \"localhost:27017\", setName: \"rs0\", setVersion: 2, electionId: ObjectId('7fffffff0000000000000060'), primary: \"localhost:27017\", lastUpdateTime: new Date(1660036058145), logicalSessionTimeoutMinutes: 30, hosts: { 0: \"localhost:27017\" }, arbiters: {}, passives: {} } }, logicalSessionTimeoutMinutes: 30, setName: \"rs0\", compatible: true }"}}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:38.148+00:00"},"s":"I", "c":"NETWORK", "id":22943, "ctx":"listener","msg":"Connection accepted","attr":{"remote":"127.0.0.1:38898","connectionId":6,"connectionCount":3}}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:38.149+00:00"},"s":"I", "c":"NETWORK", "id":22943, "ctx":"listener","msg":"Connection accepted","attr":{"remote":"127.0.0.1:38900","connectionId":8,"connectionCount":4}}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:38.149+00:00"},"s":"I", "c":"NETWORK", "id":51800, "ctx":"conn6","msg":"client metadata","attr":{"remote":"127.0.0.1:38898","client":"conn6","doc":{"driver":{"name":"MongoDB Internal Client","version":"4.4.15"},"os":{"type":"Linux","name":"Ubuntu","architecture":"x86_64","version":"20.04"}}}}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:38.149+00:00"},"s":"I", "c":"NETWORK", "id":20113, "ctx":"LogicalSessionCacheRefresh","msg":"Successfully connected to host","attr":{"connString":"localhost:27017","numOpenConns":1,"socketTimeoutSecs":0.0}}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:38.149+00:00"},"s":"I", "c":"NETWORK", "id":51800, "ctx":"conn8","msg":"client metadata","attr":{"remote":"127.0.0.1:38900","client":"conn8","doc":{"driver":{"name":"MongoDB Internal Client","version":"4.4.15"},"os":{"type":"Linux","name":"Ubuntu","architecture":"x86_64","version":"20.04"}}}}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:38.149+00:00"},"s":"I", "c":"NETWORK", "id":20113, "ctx":"LogicalSessionCacheReap","msg":"Successfully connected to host","attr":{"connString":"localhost:27017","numOpenConns":2,"socketTimeoutSecs":0.0}}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:38.649+00:00"},"s":"I", "c":"NETWORK", "id":22943, "ctx":"listener","msg":"Connection accepted","attr":{"remote":"172.32.4.3:42674","connectionId":9,"connectionCount":5}}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:38.651+00:00"},"s":"I", "c":"NETWORK", "id":51800, "ctx":"conn9","msg":"client metadata","attr":{"remote":"172.32.4.3:42674","client":"conn9","doc":{"application":{"name":"MongoDB Shell"},"driver":{"name":"MongoDB Internal Client","version":"4.4.15"},"os":{"type":"Linux","name":"Ubuntu","architecture":"x86_64","version":"20.04"}}}}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:38.660+00:00"},"s":"I", "c":"REPL", "id":21356, "ctx":"conn9","msg":"replSetInitiate admin command received from client"}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:38.665+00:00"},"s":"I", "c":"NETWORK", "id":22944, "ctx":"conn9","msg":"Connection ended","attr":{"remote":"172.32.4.3:42674","connectionId":9,"connectionCount":4}}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:39.444+00:00"},"s":"I", "c":"NETWORK", "id":22943, "ctx":"listener","msg":"Connection accepted","attr":{"remote":"172.32.4.4:46420","connectionId":10,"connectionCount":5}}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:39.457+00:00"},"s":"I", "c":"NETWORK", "id":51800, "ctx":"conn10","msg":"client metadata","attr":{"remote":"172.32.4.4:46420","client":"conn10","doc":{"driver":{"name":"nodejs","version":"4.3.1"},"os":{"type":"Linux","name":"linux","architecture":"x64","version":"5.15.30-2-pve"},"platform":"Node.js v14.19.3, LE (unified)|Node.js v14.19.3, LE (unified)"}}}
mongo_1 | {"t":{"$date":"2022-08-09T09:07:39.470+00:00"},"s":"I", "c":"NETWORK", "id":22944, "ctx":"conn10","msg":"Connection ended","attr":{"remote":"172.32.4.4:46420","connectionId":10,"connectionCount":4}}
rocketchat_1 | /app/bundle/programs/server/node_modules/fibers/future.js:313
rocketchat_1 | throw(ex);
rocketchat_1 | ^
rocketchat_1 |
rocketchat_1 | MongoServerSelectionError: connect ECONNREFUSED 127.0.0.1:27017
rocketchat_1 | at Timeout._onTimeout (/app/bundle/programs/server/npm/node_modules/meteor/npm-mongo/node_modules/mongodb/lib/sdam/topology.js:312:38)
rocketchat_1 | at listOnTimeout (internal/timers.js:557:17)
rocketchat_1 | at processTimers (internal/timers.js:500:7) {
rocketchat_1 | reason: TopologyDescription {
rocketchat_1 | type: 'ReplicaSetNoPrimary',
rocketchat_1 | servers: Map(1) {
rocketchat_1 | 'localhost:27017' => ServerDescription {
rocketchat_1 | _hostAddress: HostAddress { isIPv6: false, host: 'localhost', port: 27017 },
rocketchat_1 | address: 'localhost:27017',
rocketchat_1 | type: 'Unknown',
rocketchat_1 | hosts: [],
rocketchat_1 | passives: [],
rocketchat_1 | arbiters: [],
rocketchat_1 | tags: {},
rocketchat_1 | minWireVersion: 0,
rocketchat_1 | maxWireVersion: 0,
rocketchat_1 | roundTripTime: -1,
rocketchat_1 | lastUpdateTime: 5597480909,
rocketchat_1 | lastWriteDate: 0,
rocketchat_1 | error: MongoNetworkError: connect ECONNREFUSED 127.0.0.1:27017
rocketchat_1 | at connectionFailureError (/app/bundle/programs/server/npm/node_modules/meteor/npm-mongo/node_modules/mongodb/lib/cmap/connect.js:381:20)
rocketchat_1 | at Socket.<anonymous> (/app/bundle/programs/server/npm/node_modules/meteor/npm-mongo/node_modules/mongodb/lib/cmap/connect.js:301:22)
rocketchat_1 | at Object.onceWrapper (events.js:520:26)
rocketchat_1 | at Socket.emit (events.js:400:28)
rocketchat_1 | at emitErrorNT (internal/streams/destroy.js:106:8)
rocketchat_1 | at emitErrorCloseNT (internal/streams/destroy.js:74:3)
rocketchat_1 | at processTicksAndRejections (internal/process/task_queues.js:82:21)
rocketchat_1 | }
rocketchat_1 | },
rocketchat_1 | stale: false,
rocketchat_1 | compatible: true,
rocketchat_1 | heartbeatFrequencyMS: 10000,
rocketchat_1 | localThresholdMS: 15,
rocketchat_1 | setName: 'rs0',
rocketchat_1 | maxSetVersion: 2,
rocketchat_1 | maxElectionId: ObjectId {
rocketchat_1 | [Symbol(id)]: Buffer(12) [Uint8Array] [
rocketchat_1 | 127, 255, 255, 255, 0,
rocketchat_1 | 0, 0, 0, 0, 0,
rocketchat_1 | 0, 96
rocketchat_1 | ]
rocketchat_1 | },
rocketchat_1 | commonWireVersion: 9,
rocketchat_1 | logicalSessionTimeoutMinutes: undefined
rocketchat_1 | }
rocketchat_1 | }
rocketchat_1 | Could not start Rocket.Chat. Waiting 5 secs...
mongo_1 | {"t":{"$date":"2022-08-09T09:08:16.270+00:00"},"s":"I", "c":"NETWORK", "id":22943, "ctx":"listener","msg":"Connection accepted","attr":{"remote":"172.32.4.4:46422","connectionId":11,"connectionCount":5}}
mongo_1 | {"t":{"$date":"2022-08-09T09:08:16.278+00:00"},"s":"I", "c":"NETWORK", "id":51800, "ctx":"conn11","msg":"client metadata","attr":{"remote":"172.32.4.4:46422","client":"conn11","doc":{"driver":{"name":"nodejs","version":"4.3.1"},"os":{"type":"Linux","name":"linux","architecture":"x64","version":"5.15.30-2-pve"},"platform":"Node.js v14.19.3, LE (unified)|Node.js v14.19.3, LE (unified)"}}}
mongo_1 | {"t":{"$date":"2022-08-09T09:08:16.287+00:00"},"s":"I", "c":"NETWORK", "id":22944, "ctx":"conn11","msg":"Connection ended","attr":{"remote":"172.32.4.4:46422","connectionId":11,"connectionCount":4}}
mongo_1 | {"t":{"$date":"2022-08-09T09:08:37.999+00:00"},"s":"I", "c":"STORAGE", "id":22430, "ctx":"WTCheckpointThread","msg":"WiredTiger message","attr":{"message":"[1660036117:999677][1:0x7f4c31975700], WT_SESSION.checkpoint: [WT_VERB_CHECKPOINT_PROGRESS] saving checkpoint snapshot min: 32, snapshot max: 32 snapshot count: 0, oldest timestamp: (1660036103, 1) , meta checkpoint timestamp: (1660036108, 1) base write gen: 4225324"}}
rocketchat_1 | /app/bundle/programs/server/node_modules/fibers/future.js:313
rocketchat_1 | throw(ex);
rocketchat_1 | ^
rocketchat_1 |
rocketchat_1 | MongoServerSelectionError: connect ECONNREFUSED 127.0.0.1:27017
rocketchat_1 | at Timeout._onTimeout (/app/bundle/programs/server/npm/node_modules/meteor/npm-mongo/node_modules/mongodb/lib/sdam/topology.js:312:38)
rocketchat_1 | at listOnTimeout (internal/timers.js:557:17)
rocketchat_1 | at processTimers (internal/timers.js:500:7) {
rocketchat_1 | reason: TopologyDescription {
rocketchat_1 | type: 'ReplicaSetNoPrimary',
rocketchat_1 | servers: Map(1) {
rocketchat_1 | 'localhost:27017' => ServerDescription {
rocketchat_1 | _hostAddress: HostAddress { isIPv6: false, host: 'localhost', port: 27017 },
rocketchat_1 | address: 'localhost:27017',
rocketchat_1 | type: 'Unknown',
rocketchat_1 | hosts: [],
rocketchat_1 | passives: [],
rocketchat_1 | arbiters: [],
rocketchat_1 | tags: {},
rocketchat_1 | minWireVersion: 0,
rocketchat_1 | maxWireVersion: 0,
rocketchat_1 | roundTripTime: -1,
rocketchat_1 | lastUpdateTime: 5597517710,
rocketchat_1 | lastWriteDate: 0,
rocketchat_1 | error: MongoNetworkError: connect ECONNREFUSED 127.0.0.1:27017
rocketchat_1 | at connectionFailureError (/app/bundle/programs/server/npm/node_modules/meteor/npm-mongo/node_modules/mongodb/lib/cmap/connect.js:381:20)
rocketchat_1 | at Socket.<anonymous> (/app/bundle/programs/server/npm/node_modules/meteor/npm-mongo/node_modules/mongodb/lib/cmap/connect.js:301:22)
rocketchat_1 | at Object.onceWrapper (events.js:520:26)
rocketchat_1 | at Socket.emit (events.js:400:28)
rocketchat_1 | at emitErrorNT (internal/streams/destroy.js:106:8)
rocketchat_1 | at emitErrorCloseNT (internal/streams/destroy.js:74:3)
rocketchat_1 | at processTicksAndRejections (internal/process/task_queues.js:82:21)
rocketchat_1 | }
rocketchat_1 | },
rocketchat_1 | stale: false,
rocketchat_1 | compatible: true,
rocketchat_1 | heartbeatFrequencyMS: 10000,
rocketchat_1 | localThresholdMS: 15,
rocketchat_1 | setName: 'rs0',
rocketchat_1 | maxSetVersion: 2,
rocketchat_1 | maxElectionId: ObjectId {
rocketchat_1 | [Symbol(id)]: Buffer(12) [Uint8Array] [
rocketchat_1 | 127, 255, 255, 255, 0,
rocketchat_1 | 0, 0, 0, 0, 0,
rocketchat_1 | 0, 96
rocketchat_1 | ]
rocketchat_1 | },
rocketchat_1 | commonWireVersion: 9,
rocketchat_1 | logicalSessionTimeoutMinutes: undefined
rocketchat_1 | }
rocketchat_1 | }
rocketchat_1 | Could not start Rocket.Chat. Waiting 5 secs...
mongo_1 | {"t":{"$date":"2022-08-09T09:08:53.056+00:00"},"s":"I", "c":"NETWORK", "id":22943, "ctx":"listener","msg":"Connection accepted","attr":{"remote":"172.32.4.4:46424","connectionId":12,"connectionCount":5}}
mongo_1 | {"t":{"$date":"2022-08-09T09:08:53.064+00:00"},"s":"I", "c":"NETWORK", "id":51800, "ctx":"conn12","msg":"client metadata","attr":{"remote":"172.32.4.4:46424","client":"conn12","doc":{"driver":{"name":"nodejs","version":"4.3.1"},"os":{"type":"Linux","name":"linux","architecture":"x64","version":"5.15.30-2-pve"},"platform":"Node.js v14.19.3, LE (unified)|Node.js v14.19.3, LE (unified)"}}}
mongo_1 | {"t":{"$date":"2022-08-09T09:08:53.074+00:00"},"s":"I", "c":"NETWORK", "id":22944, "ctx":"conn12","msg":"Connection ended","attr":{"remote":"172.32.4.4:46424","connectionId":12,"connectionCount":4}}
rocketchat_1 | /app/bundle/programs/server/node_modules/fibers/future.js:313
rocketchat_1 | throw(ex);
rocketchat_1 | ^
rocketchat_1 |
rocketchat_1 | MongoServerSelectionError: connect ECONNREFUSED 127.0.0.1:27017
rocketchat_1 | at Timeout._onTimeout (/app/bundle/programs/server/npm/node_modules/meteor/npm-mongo/node_modules/mongodb/lib/sdam/topology.js:312:38)
rocketchat_1 | at listOnTimeout (internal/timers.js:557:17)
rocketchat_1 | at processTimers (internal/timers.js:500:7) {
rocketchat_1 | reason: TopologyDescription {
rocketchat_1 | type: 'ReplicaSetNoPrimary',
rocketchat_1 | servers: Map(1) {
rocketchat_1 | 'localhost:27017' => ServerDescription {
rocketchat_1 | _hostAddress: HostAddress { isIPv6: false, host: 'localhost', port: 27017 },
rocketchat_1 | address: 'localhost:27017',
rocketchat_1 | type: 'Unknown',
rocketchat_1 | hosts: [],
rocketchat_1 | passives: [],
rocketchat_1 | arbiters: [],
rocketchat_1 | tags: {},
rocketchat_1 | minWireVersion: 0,
rocketchat_1 | maxWireVersion: 0,
rocketchat_1 | roundTripTime: -1,
rocketchat_1 | lastUpdateTime: 5597554491,
rocketchat_1 | lastWriteDate: 0,
rocketchat_1 | error: MongoNetworkError: connect ECONNREFUSED 127.0.0.1:27017
rocketchat_1 | at connectionFailureError (/app/bundle/programs/server/npm/node_modules/meteor/npm-mongo/node_modules/mongodb/lib/cmap/connect.js:381:20)
rocketchat_1 | at Socket.<anonymous> (/app/bundle/programs/server/npm/node_modules/meteor/npm-mongo/node_modules/mongodb/lib/cmap/connect.js:301:22)
rocketchat_1 | at Object.onceWrapper (events.js:520:26)
rocketchat_1 | at Socket.emit (events.js:400:28)
rocketchat_1 | at emitErrorNT (internal/streams/destroy.js:106:8)
rocketchat_1 | at emitErrorCloseNT (internal/streams/destroy.js:74:3)
rocketchat_1 | at processTicksAndRejections (internal/process/task_queues.js:82:21)
rocketchat_1 | }
rocketchat_1 | },
rocketchat_1 | stale: false,
rocketchat_1 | compatible: true,
rocketchat_1 | heartbeatFrequencyMS: 10000,
rocketchat_1 | localThresholdMS: 15,
rocketchat_1 | setName: 'rs0',
rocketchat_1 | maxSetVersion: 2,
rocketchat_1 | maxElectionId: ObjectId {
rocketchat_1 | [Symbol(id)]: Buffer(12) [Uint8Array] [
rocketchat_1 | 127, 255, 255, 255, 0,
rocketchat_1 | 0, 0, 0, 0, 0,
rocketchat_1 | 0, 96
rocketchat_1 | ]
rocketchat_1 | },
rocketchat_1 | commonWireVersion: 9,
rocketchat_1 | logicalSessionTimeoutMinutes: undefined
rocketchat_1 | }
rocketchat_1 | }
rocketchat_1 | Could not start Rocket.Chat. Waiting 5 secs...
mongo_1 | {"t":{"$date":"2022-08-09T09:09:29.963+00:00"},"s":"I", "c":"NETWORK", "id":22943, "ctx":"listener","msg":"Connection accepted","attr":{"remote":"172.32.4.4:46426","connectionId":13,"connectionCount":5}}
mongo_1 | {"t":{"$date":"2022-08-09T09:09:29.972+00:00"},"s":"I", "c":"NETWORK", "id":51800, "ctx":"conn13","msg":"client metadata","attr":{"remote":"172.32.4.4:46426","client":"conn13","doc":{"driver":{"name":"nodejs","version":"4.3.1"},"os":{"type":"Linux","name":"linux","architecture":"x64","version":"5.15.30-2-pve"},"platform":"Node.js v14.19.3, LE (unified)|Node.js v14.19.3, LE (unified)"}}}
mongo_1 | {"t":{"$date":"2022-08-09T09:09:29.981+00:00"},"s":"I", "c":"NETWORK", "id":22944, "ctx":"conn13","msg":"Connection ended","attr":{"remote":"172.32.4.4:46426","connectionId":13,"connectionCount":4}}
mongo_1 | {"t":{"$date":"2022-08-09T09:09:38.103+00:00"},"s":"I", "c":"STORAGE", "id":22430, "ctx":"WTCheckpointThread","msg":"WiredTiger message","attr":{"message":"[1660036178:103857][1:0x7f4c31975700], WT_SESSION.checkpoint: [WT_VERB_CHECKPOINT_PROGRESS] saving checkpoint snapshot min: 55, snapshot max: 55 snapshot count: 0, oldest timestamp: (1660036163, 1) , meta checkpoint timestamp: (1660036168, 1) base write gen: 4225324"}}
^CERROR: Aborting.
Same config worked at rocket.chat v3.18, but failed at rocket.chat v5.0.2, why ???
MONGO_URL=mongodb://user:passwd@mongo4:27017/rocketchat?&authSource=admin MONGO_OPLOG_URL=mongodb://user:passwd@mongo4:27017/local?&authSource=admin
rocket.chat v3.18 treate mongo4 as a linked docker container, but rocket.chat v5.0.2 make it 127.0.0.1
I tried some ideas. Using this new docker-compose.yml starts the server successfully, but of course with a new empty database
version: '2'
services:
rocketchat:
image: registry.rocket.chat/rocketchat/rocket.chat:latest
restart: unless-stopped
environment:
MONGO_URL: mongodb://mongo:27017/rocketchat?replicaSet=rs0
MONGO_OPLOG_URL: mongodb://mongo:27017/local?replicaSet=rs0
ROOT_URL: https://chat.domain.com
DEPLOY_METHOD: docker
DEPLOY_PLATFORM: linux
depends_on:
- mongo
networks:
- caddy_net
- default
mongo:
image: docker.io/bitnami/mongodb:4.4
restart: unless-stopped
volumes:
- ./mongodb_data:/bitnami/mongodb
environment:
MONGODB_REPLICA_SET_MODE: primary
MONGODB_REPLICA_SET_NAME: rs0
MONGODB_PORT_NUMBER: 27017
MONGODB_INITIAL_PRIMARY_HOST: mongo
MONGODB_INITIAL_PRIMARY_PORT_NUMBER: 27017
MONGODB_ADVERTISED_HOSTNAME: mongo
MONGODB_ENABLE_JOURNAL: "true"
ALLOW_EMPTY_PASSWORD: "yes"
networks:
caddy_net:
external: true
default:
Using image: mongo:4.4 like before does not work. Also copying all those index*.wt files used by the previous mongo image to the one in the new compose file does not work, too.
copy from #26503
There are three solutions,
- Use the new compose file.
- Make sure when you're setting up the replicaset you're using the correct hostname (as in the service name entry of the compose file)
- Using directConnection=true parameter in the MONGO.*_URL variables.
this is worked for me, MONGO_URL=mongodb://user:passwd@mongo4:27017/rocketchat?&authSource=admin&directConnection=true MONGO_OPLOG_URL=mongodb://user:passwd@mongo4:27017/local?&authSource=admin&directConnection=true
Hi! Please check this video about what is happening with on this issue and some fixes. https://www.youtube.com/watch?v=8DeBQsfe2rU
The directConnection approach is a fix and should work. If you have multiple instances, there are more appropriate fixes, as described in the video.
Closing as this is not a Rocket.Chat issue, but a change in node driver with mongo
Just for those not necessarily wanting to watch the full video:
using directConnection=true is actually discouraged in the video and one should rather fix the hostname in the replicaset to something that resolves within the mongodb as well as the rocketchat container to the correct ip.
The fix (assuming the name of the mongodb service is mongo):
# open a mongo shell within the mongo container
docker-compose exec mongo mongo
# Fix the hostname of the replicaset
config = rs.config()
config.members[0].host = 'mongo:27017'
rs.reconfig(config)
