Hi,
We are getting the fatal error below in our secondary replica.
{"t":{"$date":"2023-03-30T20:21:21.402+00:00"},"s":"F", "c":"REPL", "id":21128, "ctx":"BackgroundSync","msg":"Rollback failed with unrecoverable error","attr":{"error":{"code":127,"codeName":"UnrecoverableRollbackError","errmsg":"not willing to roll back more than 86400 seconds of data. Have: 238302 seconds."}}}
We then changed the admin parameter rollbackTimeLimitSecs from the primary node, as the secondary won’t stay up due to its unhealthiness.
Result of command db.adminCommand({ getParameter: 1, rollbackTimeLimitSecs:1}) after changing the parameter:
{ "rollbackTimeLimitSecs" : 240000, "ok" : 1 }
But the error kept occurring with the exact same message, as if we haven’t had changed it.
MongoDB version: 4.4.6
We are running on Kubernetes, using the primary-secondary-arbiter architecture.
Complete log:
Advertised Hostname: internal-ae46bb59569474ccd9253fd9f2ee8bbd-784996542.us-east-1.elb.amazonaws.com
Pod name matches initial primary pod name, configuring node as a primary
mongodb 20:21:16.14
mongodb 20:21:16.14 Welcome to the Bitnami mongodb container
mongodb 20:21:16.15 Subscribe to project updates by watching https://github.com/bitnami/bitnami-docker-mongodb
mongodb 20:21:16.15 Submit issues and feature requests at https://github.com/bitnami/bitnami-docker-mongodb/issues
mongodb 20:21:16.16
mongodb 20:21:16.16 INFO ==> ** Starting MongoDB setup **
mongodb 20:21:16.21 INFO ==> Validating settings in MONGODB_* env vars...
mongodb 20:21:16.25 INFO ==> Initializing MongoDB...
mongodb 20:21:16.32 INFO ==> Enabling authentication...
mongodb 20:21:16.34 INFO ==> Deploying MongoDB with persisted data...
mongodb 20:21:16.34 INFO ==> Writing keyfile for replica set authentication...
mongodb 20:21:16.43 INFO ==> ** MongoDB setup finished! **
mongodb 20:21:16.48 INFO ==> ** Starting MongoDB **
{"t":{"$date":"2023-03-30T20:21:16.526+00:00"},"s":"I", "c":"CONTROL", "id":20698, "ctx":"main","msg":"***** SERVER RESTARTED *****"}
{"t":{"$date":"2023-03-30T20:21:16.529+00:00"},"s":"I", "c":"CONTROL", "id":23285, "ctx":"main","msg":"Automatically disabling TLS 1.0, to force-enable TLS 1.0 specify --sslDisabledProtocols 'none'"}
{"t":{"$date":"2023-03-30T20:21:16.531+00:00"},"s":"W", "c":"ASIO", "id":22601, "ctx":"main","msg":"No TransportLayer configured during NetworkInterface startup"}
{"t":{"$date":"2023-03-30T20:21:16.532+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."}
{"t":{"$date":"2023-03-30T20:21:16.532+00:00"},"s":"W", "c":"ASIO", "id":22601, "ctx":"main","msg":"No TransportLayer configured during NetworkInterface startup"}
{"t":{"$date":"2023-03-30T20:21:16.595+00:00"},"s":"I", "c":"STORAGE", "id":4615611, "ctx":"initandlisten","msg":"MongoDB starting","attr":{"pid":1,"port":27017,"dbPath":"/bitnami/mongodb/data/db","architecture":"64-bit","host":"scd-open-banking-apps-mongodb-0"}}
{"t":{"$date":"2023-03-30T20:21:16.595+00:00"},"s":"W", "c":"CONTROL", "id":20720, "ctx":"initandlisten","msg":"Available memory is less than system memory","attr":{"availableMemSizeMB":2048,"systemMemSizeMB":3884}}
{"t":{"$date":"2023-03-30T20:21:16.595+00:00"},"s":"I", "c":"CONTROL", "id":23403, "ctx":"initandlisten","msg":"Build Info","attr":{"buildInfo":{"version":"4.4.6","gitVersion":"72e66213c2c3eab37d9358d5e78ad7f5c1d0d0d7","openSSLVersion":"OpenSSL 1.1.1d 10 Sep 2019","modules":[],"allocator":"tcmalloc","environment":{"distmod":"debian10","distarch":"x86_64","target_arch":"x86_64"}}}}
{"t":{"$date":"2023-03-30T20:21:16.595+00:00"},"s":"I", "c":"CONTROL", "id":51765, "ctx":"initandlisten","msg":"Operating System","attr":{"os":{"name":"PRETTY_NAME=\"Debian GNU/Linux 10 (buster)\"","version":"Kernel 5.4.219-126.411.amzn2.x86_64"}}}
{"t":{"$date":"2023-03-30T20:21:16.595+00:00"},"s":"I", "c":"CONTROL", "id":21951, "ctx":"initandlisten","msg":"Options set by command line","attr":{"options":{"config":"/opt/bitnami/mongodb/conf/mongodb.conf","net":{"bindIp":"*","ipv6":false,"port":27017,"unixDomainSocket":{"enabled":true,"pathPrefix":"/opt/bitnami/mongodb/tmp"}},"processManagement":{"fork":false,"pidFilePath":"/opt/bitnami/mongodb/tmp/mongodb.pid"},"replication":{"enableMajorityReadConcern":true,"replSetName":"rs0"},"security":{"authorization":"enabled","keyFile":"/opt/bitnami/mongodb/conf/keyfile"},"setParameter":{"enableLocalhostAuthBypass":"false"},"storage":{"dbPath":"/bitnami/mongodb/data/db","directoryPerDB":false,"journal":{"enabled":true}},"systemLog":{"destination":"file","logAppend":true,"logRotate":"reopen","path":"/opt/bitnami/mongodb/logs/mongodb.log","quiet":false,"verbosity":0}}}}
{"t":{"$date":"2023-03-30T20:21:16.605+00:00"},"s":"W", "c":"STORAGE", "id":22271, "ctx":"initandlisten","msg":"Detected unclean shutdown - Lock file is not empty","attr":{"lockFile":"/bitnami/mongodb/data/db/mongod.lock"}}
{"t":{"$date":"2023-03-30T20:21:16.607+00:00"},"s":"I", "c":"STORAGE", "id":22270, "ctx":"initandlisten","msg":"Storage engine to use detected by data files","attr":{"dbpath":"/bitnami/mongodb/data/db","storageEngine":"wiredTiger"}}
{"t":{"$date":"2023-03-30T20:21:16.608+00:00"},"s":"W", "c":"STORAGE", "id":22302, "ctx":"initandlisten","msg":"Recovering data from the last clean checkpoint."}
{"t":{"$date":"2023-03-30T20:21:16.611+00:00"},"s":"I", "c":"STORAGE", "id":22315, "ctx":"initandlisten","msg":"Opening WiredTiger","attr":{"config":"create,cache_size=512M,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],"}}
{"t":{"$date":"2023-03-30T20:21:18.430+00:00"},"s":"I", "c":"STORAGE", "id":22430, "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":"[1680207678:430654][1:0x7ffa8ab55140], txn-recover: [WT_VERB_RECOVERY_PROGRESS] Recovering log 922 through 923"}}
{"t":{"$date":"2023-03-30T20:21:18.484+00:00"},"s":"I", "c":"STORAGE", "id":22430, "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":"[1680207678:484759][1:0x7ffa8ab55140], txn-recover: [WT_VERB_RECOVERY_PROGRESS] Recovering log 923 through 923"}}
{"t":{"$date":"2023-03-30T20:21:18.905+00:00"},"s":"I", "c":"STORAGE", "id":22430, "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":"[1680207678:905601][1:0x7ffa8ab55140], txn-recover: [WT_VERB_RECOVERY | WT_VERB_RECOVERY_PROGRESS] Main recovery loop: starting at 922/256 to 923/256"}}
{"t":{"$date":"2023-03-30T20:21:18.913+00:00"},"s":"I", "c":"STORAGE", "id":22430, "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":"[1680207678:913723][1:0x7ffa8ab55140], txn-recover: [WT_VERB_RECOVERY_PROGRESS] Recovering log 922 through 923"}}
{"t":{"$date":"2023-03-30T20:21:19.074+00:00"},"s":"I", "c":"STORAGE", "id":22430, "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":"[1680207679:74512][1:0x7ffa8ab55140], file:collection-9-4797836291474800180.wt, txn-recover: [WT_VERB_RECOVERY_PROGRESS] Recovering log 923 through 923"}}
{"t":{"$date":"2023-03-30T20:21:19.115+00:00"},"s":"I", "c":"STORAGE", "id":22430, "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":"[1680207679:115808][1:0x7ffa8ab55140], file:collection-9-4797836291474800180.wt, txn-recover: [WT_VERB_RECOVERY | WT_VERB_RECOVERY_PROGRESS] Set global recovery timestamp: (1679068524, 1)"}}
{"t":{"$date":"2023-03-30T20:21:19.115+00:00"},"s":"I", "c":"STORAGE", "id":22430, "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":"[1680207679:115959][1:0x7ffa8ab55140], file:collection-9-4797836291474800180.wt, txn-recover: [WT_VERB_RECOVERY | WT_VERB_RECOVERY_PROGRESS] Set global oldest timestamp: (1679068524, 1)"}}
{"t":{"$date":"2023-03-30T20:21:19.142+00:00"},"s":"I", "c":"STORAGE", "id":22430, "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":"[1680207679:142252][1:0x7ffa8ab55140], WT_SESSION.checkpoint: [WT_VERB_CHECKPOINT_PROGRESS] saving checkpoint snapshot min: 5, snapshot max: 5 snapshot count: 0, oldest timestamp: (1679068524, 1) , meta checkpoint timestamp: (1679068524, 1)"}}
{"t":{"$date":"2023-03-30T20:21:19.234+00:00"},"s":"I", "c":"STORAGE", "id":4795906, "ctx":"initandlisten","msg":"WiredTiger opened","attr":{"durationMillis":2623}}
{"t":{"$date":"2023-03-30T20:21:19.234+00:00"},"s":"I", "c":"RECOVERY", "id":23987, "ctx":"initandlisten","msg":"WiredTiger recoveryTimestamp","attr":{"recoveryTimestamp":{"$timestamp":{"t":1679068524,"i":1}}}}
{"t":{"$date":"2023-03-30T20:21:19.246+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}}
{"t":{"$date":"2023-03-30T20:21:19.263+00:00"},"s":"I", "c":"STORAGE", "id":22383, "ctx":"initandlisten","msg":"The size storer reports that the oplog contains","attr":{"numRecords":4318444,"dataSize":611921725}}
{"t":{"$date":"2023-03-30T20:21:19.263+00:00"},"s":"I", "c":"STORAGE", "id":22386, "ctx":"initandlisten","msg":"Sampling the oplog to determine where to place markers for truncation"}
{"t":{"$date":"2023-03-30T20:21:19.292+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":1635945730,"i":1}},"to":{"$timestamp":{"t":1679306827,"i":1}}}}
{"t":{"$date":"2023-03-30T20:21:19.292+00:00"},"s":"I", "c":"STORAGE", "id":22390, "ctx":"initandlisten","msg":"Taking samples and assuming each oplog section contains","attr":{"numSamples":11,"containsNumRecords":3788797,"containsNumBytes":536870964}}
{"t":{"$date":"2023-03-30T20:21:19.689+00:00"},"s":"I", "c":"STORAGE", "id":22393, "ctx":"initandlisten","msg":"Oplog sampling complete"}
{"t":{"$date":"2023-03-30T20:21:19.689+00:00"},"s":"I", "c":"STORAGE", "id":22382, "ctx":"initandlisten","msg":"WiredTiger record store oplog processing finished","attr":{"durationMillis":425}}
{"t":{"$date":"2023-03-30T20:21:19.695+00:00"},"s":"I", "c":"STORAGE", "id":22262, "ctx":"initandlisten","msg":"Timestamp monitor starting"}
{"t":{"$date":"2023-03-30T20:21:19.799+00:00"},"s":"I", "c":"STORAGE", "id":20536, "ctx":"initandlisten","msg":"Flow Control is enabled on this deployment"}
{"t":{"$date":"2023-03-30T20:21:19.819+00:00"},"s":"I", "c":"SHARDING", "id":20997, "ctx":"initandlisten","msg":"Refreshed RWC defaults","attr":{"newDefaults":{}}}
{"t":{"$date":"2023-03-30T20:21:19.819+00:00"},"s":"I", "c":"FTDC", "id":20625, "ctx":"initandlisten","msg":"Initializing full-time diagnostic data capture","attr":{"dataDirectory":"/bitnami/mongodb/data/db/diagnostic.data"}}
{"t":{"$date":"2023-03-30T20:21:20.002+00:00"},"s":"I", "c":"REPL", "id":21529, "ctx":"initandlisten","msg":"Initializing rollback ID","attr":{"rbid":303}}
{"t":{"$date":"2023-03-30T20:21:20.002+00:00"},"s":"I", "c":"REPL", "id":501401, "ctx":"initandlisten","msg":"Incrementing the rollback ID after unclean shutdown"}
{"t":{"$date":"2023-03-30T20:21:20.013+00:00"},"s":"I", "c":"REPL", "id":21532, "ctx":"initandlisten","msg":"Incremented the rollback ID","attr":{"rbid":304}}
{"t":{"$date":"2023-03-30T20:21:20.025+00:00"},"s":"I", "c":"REPL", "id":21544, "ctx":"initandlisten","msg":"Recovering from stable timestamp","attr":{"stableTimestamp":{"$timestamp":{"t":1679068524,"i":1}},"topOfOplog":{"ts":{"$timestamp":{"t":1679306827,"i":1}},"t":1782},"appliedThrough":{"ts":{"$timestamp":{"t":0,"i":0}},"t":-1},"oplogTruncateAfterPoint":{"$timestamp":{"t":0,"i":0}}}}
{"t":{"$date":"2023-03-30T20:21:20.025+00:00"},"s":"I", "c":"REPL", "id":21545, "ctx":"initandlisten","msg":"Starting recovery oplog application at the stable timestamp","attr":{"stableTimestamp":{"$timestamp":{"t":1679068524,"i":1}}}}
{"t":{"$date":"2023-03-30T20:21:20.025+00:00"},"s":"I", "c":"REPL", "id":21550, "ctx":"initandlisten","msg":"Replaying stored operations from startPoint (inclusive) to endPoint (inclusive)","attr":{"startPoint":{"$timestamp":{"t":1679068524,"i":1}},"endPoint":{"$timestamp":{"t":1679306827,"i":1}}}}
{"t":{"$date":"2023-03-30T20:21:20.030+00:00"},"s":"I", "c":"REPL", "id":21536, "ctx":"initandlisten","msg":"Completed oplog application for recovery","attr":{"numOpsApplied":5,"numBatches":1,"applyThroughOpTime":{"ts":{"$timestamp":{"t":1679306827,"i":1}},"t":1782}}}
{"t":{"$date":"2023-03-30T20:21:20.045+00: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-03-30T20:21:20.046+00:00"},"s":"I", "c":"REPL", "id":40440, "ctx":"initandlisten","msg":"Starting the TopologyVersionObserver"}
{"t":{"$date":"2023-03-30T20:21:20.046+00: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-03-30T20:21:20.047+00:00"},"s":"I", "c":"REPL", "id":40445, "ctx":"TopologyVersionObserver","msg":"Started TopologyVersionObserver"}
{"t":{"$date":"2023-03-30T20:21:20.047+00:00"},"s":"I", "c":"NETWORK", "id":23015, "ctx":"listener","msg":"Listening on","attr":{"address":"/opt/bitnami/mongodb/tmp/mongodb-27017.sock"}}
{"t":{"$date":"2023-03-30T20:21:20.047+00:00"},"s":"I", "c":"NETWORK", "id":23015, "ctx":"listener","msg":"Listening on","attr":{"address":"0.0.0.0"}}
{"t":{"$date":"2023-03-30T20:21:20.047+00:00"},"s":"I", "c":"NETWORK", "id":23016, "ctx":"listener","msg":"Waiting for connections","attr":{"port":27017,"ssl":"off"}}
{"t":{"$date":"2023-03-30T20:21:20.115+00:00"},"s":"I", "c":"REPL", "id":21315, "ctx":"ReplCoord-0","msg":"","tags":["startupWarnings"]}
{"t":{"$date":"2023-03-30T20:21:20.116+00:00"},"s":"I", "c":"REPL", "id":21316, "ctx":"ReplCoord-0","msg":"** WARNING: This replica set has a Primary-Secondary-Arbiter architecture, but readConcern:majority is enabled ","tags":["startupWarnings"]}
{"t":{"$date":"2023-03-30T20:21:20.116+00:00"},"s":"I", "c":"REPL", "id":21317, "ctx":"ReplCoord-0","msg":"** for this node. This is not a recommended configuration. Please see ","tags":["startupWarnings"]}
{"t":{"$date":"2023-03-30T20:21:20.116+00:00"},"s":"I", "c":"REPL", "id":21318, "ctx":"ReplCoord-0","msg":"** https://dochub.mongodb.org/core/psa-disable-rc-majority","tags":["startupWarnings"]}
{"t":{"$date":"2023-03-30T20:21:20.116+00:00"},"s":"I", "c":"REPL", "id":21319, "ctx":"ReplCoord-0","msg":"","tags":["startupWarnings"]}
{"t":{"$date":"2023-03-30T20:21:20.116+00:00"},"s":"I", "c":"REPL", "id":21392, "ctx":"ReplCoord-0","msg":"New replica set config in use","attr":{"config":{"_id":"rs0","version":3,"term":2141,"protocolVersion":1,"writeConcernMajorityJournalDefault":true,"members":[{"_id":0,"host":"scd-open-banking-apps-mongodb-0.scd-open-banking-apps-mongodb-headless.opbx.svc.cluster.local:27017","arbiterOnly":false,"buildIndexes":true,"hidden":false,"priority":5.0,"tags":{},"slaveDelay":0,"votes":1},{"_id":1,"host":"scd-open-banking-apps-mongodb-arbiter-0.scd-open-banking-apps-mongodb-arbiter-headless.opbx.svc.cluster.local:27017","arbiterOnly":true,"buildIndexes":true,"hidden":false,"priority":0.0,"tags":{},"slaveDelay":0,"votes":1},{"_id":2,"host":"scd-open-banking-apps-mongodb-1.scd-open-banking-apps-mongodb-headless.opbx.svc.cluster.local: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":"61828d01f5d2776cd79eab3e"}}}}}
{"t":{"$date":"2023-03-30T20:21:20.116+00:00"},"s":"I", "c":"REPL", "id":21393, "ctx":"ReplCoord-0","msg":"Found self in config","attr":{"hostAndPort":"scd-open-banking-apps-mongodb-0.scd-open-banking-apps-mongodb-headless.opbx.svc.cluster.local:27017"}}
{"t":{"$date":"2023-03-30T20:21:20.116+00:00"},"s":"I", "c":"REPL", "id":21358, "ctx":"ReplCoord-0","msg":"Replica set state transition","attr":{"newState":"STARTUP2","oldState":"STARTUP"}}
{"t":{"$date":"2023-03-30T20:21:20.117+00:00"},"s":"I", "c":"REPL", "id":21306, "ctx":"ReplCoord-0","msg":"Starting replication storage threads"}
{"t":{"$date":"2023-03-30T20:21:20.117+00:00"},"s":"I", "c":"CONNPOOL", "id":22576, "ctx":"ReplNetwork","msg":"Connecting","attr":{"hostAndPort":"scd-open-banking-apps-mongodb-arbiter-0.scd-open-banking-apps-mongodb-arbiter-headless.opbx.svc.cluster.local:27017"}}
{"t":{"$date":"2023-03-30T20:21:20.117+00:00"},"s":"I", "c":"CONNPOOL", "id":22576, "ctx":"ReplNetwork","msg":"Connecting","attr":{"hostAndPort":"scd-open-banking-apps-mongodb-1.scd-open-banking-apps-mongodb-headless.opbx.svc.cluster.local:27017"}}
{"t":{"$date":"2023-03-30T20:21:20.120+00:00"},"s":"I", "c":"REPL", "id":21358, "ctx":"ReplCoord-0","msg":"Replica set state transition","attr":{"newState":"RECOVERING","oldState":"STARTUP2"}}
{"t":{"$date":"2023-03-30T20:21:20.148+00:00"},"s":"I", "c":"REPL", "id":21299, "ctx":"ReplCoord-0","msg":"Starting replication fetcher thread"}
{"t":{"$date":"2023-03-30T20:21:20.148+00:00"},"s":"I", "c":"REPL", "id":21300, "ctx":"ReplCoord-0","msg":"Starting replication applier thread"}
{"t":{"$date":"2023-03-30T20:21:20.148+00:00"},"s":"I", "c":"REPL", "id":21301, "ctx":"ReplCoord-0","msg":"Starting replication reporter thread"}
{"t":{"$date":"2023-03-30T20:21:20.148+00:00"},"s":"I", "c":"REPL", "id":21224, "ctx":"OplogApplier-0","msg":"Starting oplog application"}
{"t":{"$date":"2023-03-30T20:21:20.148+00:00"},"s":"I", "c":"REPL", "id":21783, "ctx":"BackgroundSync","msg":"Waiting for pings from other members before syncing","attr":{"pingsNeeded":4}}
{"t":{"$date":"2023-03-30T20:21:20.148+00:00"},"s":"I", "c":"REPL", "id":21358, "ctx":"OplogApplier-0","msg":"Replica set state transition","attr":{"newState":"SECONDARY","oldState":"RECOVERING"}}
{"t":{"$date":"2023-03-30T20:21:20.149+00:00"},"s":"I", "c":"REPL", "id":21106, "ctx":"OplogApplier-0","msg":"Resetting sync source to empty","attr":{"previousSyncSource":":27017"}}
{"t":{"$date":"2023-03-30T20:21:20.192+00:00"},"s":"I", "c":"NETWORK", "id":22943, "ctx":"listener","msg":"Connection accepted","attr":{"remote":"10.116.39.216:36484","connectionId":5,"connectionCount":1}}
{"t":{"$date":"2023-03-30T20:21:20.193+00:00"},"s":"I", "c":"NETWORK", "id":51800, "ctx":"conn5","msg":"client metadata","attr":{"remote":"10.116.39.216:36484","client":"conn5","doc":{"driver":{"name":"NetworkInterfaceTL","version":"4.4.6"},"os":{"type":"Linux","name":"PRETTY_NAME=\"Debian GNU/Linux 10 (buster)\"","architecture":"x86_64","version":"Kernel 5.4.219-126.411.amzn2.x86_64"}}}}
{"t":{"$date":"2023-03-30T20:21:20.218+00:00"},"s":"I", "c":"ACCESS", "id":20250, "ctx":"conn5","msg":"Authentication succeeded","attr":{"mechanism":"SCRAM-SHA-256","speculative":true,"principalName":"__system","authenticationDatabase":"local","remote":"10.116.39.216:36484","extraInfo":{}}}
{"t":{"$date":"2023-03-30T20:21:20.219+00:00"},"s":"I", "c":"REPL", "id":21401, "ctx":"conn5","msg":"Scheduling heartbeat to fetch a newer config","attr":{"configTerm":2142,"configVersion":3,"senderHost":"scd-open-banking-apps-mongodb-1.scd-open-banking-apps-mongodb-headless.opbx.svc.cluster.local:27017"}}
{"t":{"$date":"2023-03-30T20:21:20.300+00:00"},"s":"I", "c":"REPL", "id":21392, "ctx":"ReplCoord-1","msg":"New replica set config in use","attr":{"config":{"_id":"rs0","version":3,"term":2142,"protocolVersion":1,"writeConcernMajorityJournalDefault":true,"members":[{"_id":0,"host":"scd-open-banking-apps-mongodb-0.scd-open-banking-apps-mongodb-headless.opbx.svc.cluster.local:27017","arbiterOnly":false,"buildIndexes":true,"hidden":false,"priority":5.0,"tags":{},"slaveDelay":0,"votes":1},{"_id":1,"host":"scd-open-banking-apps-mongodb-arbiter-0.scd-open-banking-apps-mongodb-arbiter-headless.opbx.svc.cluster.local:27017","arbiterOnly":true,"buildIndexes":true,"hidden":false,"priority":0.0,"tags":{},"slaveDelay":0,"votes":1},{"_id":2,"host":"scd-open-banking-apps-mongodb-1.scd-open-banking-apps-mongodb-headless.opbx.svc.cluster.local: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":"61828d01f5d2776cd79eab3e"}}}}}
{"t":{"$date":"2023-03-30T20:21:20.300+00:00"},"s":"I", "c":"REPL", "id":21393, "ctx":"ReplCoord-1","msg":"Found self in config","attr":{"hostAndPort":"scd-open-banking-apps-mongodb-0.scd-open-banking-apps-mongodb-headless.opbx.svc.cluster.local:27017"}}
{"t":{"$date":"2023-03-30T20:21:20.301+00:00"},"s":"I", "c":"REPL", "id":21215, "ctx":"ReplCoord-5","msg":"Member is in new state","attr":{"hostAndPort":"scd-open-banking-apps-mongodb-1.scd-open-banking-apps-mongodb-headless.opbx.svc.cluster.local:27017","newState":"PRIMARY"}}
{"t":{"$date":"2023-03-30T20:21:20.301+00:00"},"s":"I", "c":"ELECTION", "id":4615601, "ctx":"ReplCoord-5","msg":"Scheduling priority takeover","attr":{"when":{"$date":"2023-03-30T20:21:31.639Z"}}}
{"t":{"$date":"2023-03-30T20:21:20.301+00:00"},"s":"I", "c":"REPL", "id":21215, "ctx":"ReplCoord-3","msg":"Member is in new state","attr":{"hostAndPort":"scd-open-banking-apps-mongodb-arbiter-0.scd-open-banking-apps-mongodb-arbiter-headless.opbx.svc.cluster.local:27017","newState":"ARBITER"}}
{"t":{"$date":"2023-03-30T20:21:20.335+00:00"},"s":"I", "c":"NETWORK", "id":22943, "ctx":"listener","msg":"Connection accepted","attr":{"remote":"10.116.39.216:36498","connectionId":8,"connectionCount":2}}
{"t":{"$date":"2023-03-30T20:21:20.336+00:00"},"s":"I", "c":"NETWORK", "id":51800, "ctx":"conn8","msg":"client metadata","attr":{"remote":"10.116.39.216:36498","client":"conn8","doc":{"driver":{"name":"NetworkInterfaceTL","version":"4.4.6"},"os":{"type":"Linux","name":"PRETTY_NAME=\"Debian GNU/Linux 10 (buster)\"","architecture":"x86_64","version":"Kernel 5.4.219-126.411.amzn2.x86_64"}}}}
{"t":{"$date":"2023-03-30T20:21:20.365+00:00"},"s":"I", "c":"NETWORK", "id":22943, "ctx":"listener","msg":"Connection accepted","attr":{"remote":"10.116.42.115:55010","connectionId":9,"connectionCount":3}}
{"t":{"$date":"2023-03-30T20:21:20.366+00:00"},"s":"I", "c":"NETWORK", "id":51800, "ctx":"conn9","msg":"client metadata","attr":{"remote":"10.116.42.115:55010","client":"conn9","doc":{"driver":{"name":"NetworkInterfaceTL","version":"4.4.6"},"os":{"type":"Linux","name":"PRETTY_NAME=\"Debian GNU/Linux 10 (buster)\"","architecture":"x86_64","version":"Kernel 5.4.219-126.411.amzn2.x86_64"}}}}
{"t":{"$date":"2023-03-30T20:21:20.378+00:00"},"s":"I", "c":"ACCESS", "id":20250, "ctx":"conn8","msg":"Authentication succeeded","attr":{"mechanism":"SCRAM-SHA-256","speculative":true,"principalName":"__system","authenticationDatabase":"local","remote":"10.116.39.216:36498","extraInfo":{}}}
{"t":{"$date":"2023-03-30T20:21:20.402+00:00"},"s":"I", "c":"ACCESS", "id":20250, "ctx":"conn9","msg":"Authentication succeeded","attr":{"mechanism":"SCRAM-SHA-256","speculative":true,"principalName":"__system","authenticationDatabase":"local","remote":"10.116.42.115:55010","extraInfo":{}}}
{"t":{"$date":"2023-03-30T20:21:20.492+00:00"},"s":"I", "c":"NETWORK", "id":22943, "ctx":"listener","msg":"Connection accepted","attr":{"remote":"10.116.42.115:55026","connectionId":10,"connectionCount":4}}
{"t":{"$date":"2023-03-30T20:21:20.493+00:00"},"s":"I", "c":"NETWORK", "id":22944, "ctx":"conn10","msg":"Connection ended","attr":{"remote":"10.116.42.115:55026","connectionId":10,"connectionCount":3}}
{"t":{"$date":"2023-03-30T20:21:20.570+00:00"},"s":"I", "c":"NETWORK", "id":22943, "ctx":"listener","msg":"Connection accepted","attr":{"remote":"10.116.42.115:55032","connectionId":11,"connectionCount":4}}
{"t":{"$date":"2023-03-30T20:21:20.571+00:00"},"s":"I", "c":"NETWORK", "id":51800, "ctx":"conn11","msg":"client metadata","attr":{"remote":"10.116.42.115:55032","client":"conn11","doc":{"application":{"name":"MongoDB Shell"},"driver":{"name":"MongoDB Internal Client","version":"4.4.6"},"os":{"type":"Linux","name":"PRETTY_NAME=\"Debian GNU/Linux 10 (buster)\"","architecture":"x86_64","version":"Kernel 5.4.219-126.411.amzn2.x86_64"}}}}
{"t":{"$date":"2023-03-30T20:21:20.620+00:00"},"s":"I", "c":"ACCESS", "id":20250, "ctx":"conn11","msg":"Authentication succeeded","attr":{"mechanism":"SCRAM-SHA-256","speculative":true,"principalName":"root","authenticationDatabase":"admin","remote":"10.116.42.115:55032","extraInfo":{}}}
{"t":{"$date":"2023-03-30T20:21:20.631+00:00"},"s":"I", "c":"NETWORK", "id":22944, "ctx":"conn11","msg":"Connection ended","attr":{"remote":"10.116.42.115:55032","connectionId":11,"connectionCount":3}}
{"t":{"$date":"2023-03-30T20:21:21.148+00:00"},"s":"I", "c":"REPL", "id":21799, "ctx":"BackgroundSync","msg":"Sync source candidate chosen","attr":{"syncSource":"scd-open-banking-apps-mongodb-1.scd-open-banking-apps-mongodb-headless.opbx.svc.cluster.local:27017"}}
{"t":{"$date":"2023-03-30T20:21:21.149+00:00"},"s":"I", "c":"CONNPOOL", "id":22576, "ctx":"ReplCoordExternNetwork","msg":"Connecting","attr":{"hostAndPort":"scd-open-banking-apps-mongodb-1.scd-open-banking-apps-mongodb-headless.opbx.svc.cluster.local:27017"}}
{"t":{"$date":"2023-03-30T20:21:21.189+00:00"},"s":"I", "c":"REPL", "id":21088, "ctx":"BackgroundSync","msg":"Changed sync source","attr":{"oldSyncSource":"empty","newSyncSource":"scd-open-banking-apps-mongodb-1.scd-open-banking-apps-mongodb-headless.opbx.svc.cluster.local:27017"}}
{"t":{"$date":"2023-03-30T20:21:21.276+00:00"},"s":"I", "c":"REPL", "id":21098, "ctx":"BackgroundSync","msg":"Starting rollback due to fetcher error","attr":{"error":"OplogStartMissing: Our last optime fetched: { ts: Timestamp(1679306827, 1), t: 1782 }. source's GTE: { ts: Timestamp(1679306845, 2), t: 1784 }","lastCommittedOpTime":{"ts":{"$timestamp":{"t":0,"i":0}},"t":-1}}}
{"t":{"$date":"2023-03-30T20:21:21.276+00:00"},"s":"I", "c":"REPL", "id":21102, "ctx":"BackgroundSync","msg":"Rollback using 'recoverToStableTimestamp' method"}
{"t":{"$date":"2023-03-30T20:21:21.277+00:00"},"s":"I", "c":"REPL", "id":21104, "ctx":"BackgroundSync","msg":"Scheduling rollback","attr":{"syncSource":"scd-open-banking-apps-mongodb-1.scd-open-banking-apps-mongodb-headless.opbx.svc.cluster.local:27017"}}
{"t":{"$date":"2023-03-30T20:21:21.277+00:00"},"s":"I", "c":"ROLLBACK", "id":21593, "ctx":"BackgroundSync","msg":"Transition to ROLLBACK"}
{"t":{"$date":"2023-03-30T20:21:21.277+00:00"},"s":"I", "c":"REPL", "id":21340, "ctx":"BackgroundSync","msg":"State transition ops metrics","attr":{"metrics":{"lastStateTransition":"rollback","userOpsKilled":0,"userOpsRunning":4}}}
{"t":{"$date":"2023-03-30T20:21:21.277+00:00"},"s":"I", "c":"REPL", "id":21484, "ctx":"BackgroundSync","msg":"Canceling priority takeover callback"}
{"t":{"$date":"2023-03-30T20:21:21.277+00:00"},"s":"I", "c":"REPL", "id":21358, "ctx":"BackgroundSync","msg":"Replica set state transition","attr":{"newState":"ROLLBACK","oldState":"SECONDARY"}}
{"t":{"$date":"2023-03-30T20:21:21.277+00:00"},"s":"I", "c":"NETWORK", "id":22991, "ctx":"BackgroundSync","msg":"Skip closing connection for connection","attr":{"connectionId":9}}
{"t":{"$date":"2023-03-30T20:21:21.277+00:00"},"s":"I", "c":"NETWORK", "id":22991, "ctx":"BackgroundSync","msg":"Skip closing connection for connection","attr":{"connectionId":8}}
{"t":{"$date":"2023-03-30T20:21:21.277+00:00"},"s":"I", "c":"NETWORK", "id":22991, "ctx":"BackgroundSync","msg":"Skip closing connection for connection","attr":{"connectionId":5}}
{"t":{"$date":"2023-03-30T20:21:21.278+00:00"},"s":"I", "c":"ROLLBACK", "id":21606, "ctx":"BackgroundSync","msg":"Finding common point"}
{"t":{"$date":"2023-03-30T20:21:21.301+00:00"},"s":"I", "c":"ELECTION", "id":4615601, "ctx":"ReplCoord-5","msg":"Scheduling priority takeover","attr":{"when":{"$date":"2023-03-30T20:21:31.368Z"}}}
{"t":{"$date":"2023-03-30T20:21:21.402+00:00"},"s":"I", "c":"ROLLBACK", "id":21607, "ctx":"BackgroundSync","msg":"Rollback common point","attr":{"commonPointOpTime":{"ts":{"$timestamp":{"t":1679068524,"i":1}},"t":1781}}}
{"t":{"$date":"2023-03-30T20:21:21.402+00:00"},"s":"I", "c":"ROLLBACK", "id":21612, "ctx":"BackgroundSync","msg":"Rollback summary","attr":{"startTime":{"$date":"2023-03-30T20:21:21.277Z"},"endTime":{"$date":"2023-03-30T20:21:21.402Z"},"syncSource":"scd-open-banking-apps-mongodb-1.scd-open-banking-apps-mongodb-headless.opbx.svc.cluster.local:27017","lastOptimeRolledBack":{"ts":{"$timestamp":{"t":1679306827,"i":1}},"t":1782},"commonPoint":{"ts":{"$timestamp":{"t":1679068524,"i":1}},"t":1781},"lastWallClockTimeRolledBack":{"$date":"2023-03-20T10:07:07.373Z"},"firstOpWallClockTimeAfterCommonPoint":{"$date":"2023-03-17T15:55:24.609Z"},"wallClockTimeDiff":238302,"shardIdentityRolledBack":false,"configServerConfigVersionRolledBack":false,"affectedSessions":[],"affectedNamespaces":[],"rollbackCommandCounts":{},"totalEntriesRolledBackIncludingNoops":5}}
{"t":{"$date":"2023-03-30T20:21:21.402+00:00"},"s":"I", "c":"ROLLBACK", "id":21611, "ctx":"BackgroundSync","msg":"Transition to SECONDARY"}
{"t":{"$date":"2023-03-30T20:21:21.402+00:00"},"s":"I", "c":"REPL", "id":21358, "ctx":"BackgroundSync","msg":"Replica set state transition","attr":{"newState":"SECONDARY","oldState":"ROLLBACK"}}
{"t":{"$date":"2023-03-30T20:21:21.402+00:00"},"s":"I", "c":"REPL", "id":21106, "ctx":"BackgroundSync","msg":"Resetting sync source to empty","attr":{"previousSyncSource":"scd-open-banking-apps-mongodb-1.scd-open-banking-apps-mongodb-headless.opbx.svc.cluster.local:27017"}}
{"t":{"$date":"2023-03-30T20:21:21.402+00:00"},"s":"F", "c":"REPL", "id":21128, "ctx":"BackgroundSync","msg":"Rollback failed with unrecoverable error","attr":{"error":{"code":127,"codeName":"UnrecoverableRollbackError","errmsg":"not willing to roll back more than 86400 seconds of data. Have: 238302 seconds."}}}
{"t":{"$date":"2023-03-30T20:21:21.402+00:00"},"s":"F", "c":"-", "id":23095, "ctx":"BackgroundSync","msg":"Fatal assertion","attr":{"msgid":50666,"error":"UnrecoverableRollbackError: not willing to roll back more than 86400 seconds of data. Have: 238302 seconds.","file":"src/mongo/db/repl/bgsync.cpp","line":807}}
{"t":{"$date":"2023-03-30T20:21:21.402+00:00"},"s":"F", "c":"-", "id":23096, "ctx":"BackgroundSync","msg":"\n\n***aborting after fassert() failure\n\n"}
