AssertionError: Starting restore 2024-11-27T12:09:25.442970079Z to point-in-time 2024-11-27T12:08:11 from '2024-11-27T12:04:32Z'..........................Started physical restore. Waiting to finish..............Error: operation failed with: replay pitr oplog: reply oplog: replay chunk 1732709074.1732709137: apply oplog for chunk: applying an entry: op: {"Timestamp":{"T":1732709108,"I":19},"Term":1,"Hash":null,"Version":2,"Operation":"i","Namespace":"test.test","Object":[{"Key":"_id","Value":"67470af4861f6f64aa33518f"},{"Key":"doc","Value":3}],"Query":null,"UI":{"Subtype":4,"Data":"9x/BSSYiQw6CpWpoVxXYeg=="},"LSID":"SAAAAAVpZAAQAAAABAgBkSs3LESIt41PozoPJlAFdWlkACAAAAAAY5mrDaxi8gv8RmdTsQ+1j7fmkr7JUsabhNmXAheU0fgA","TxnNumber":4,"PrevOpTime":"HAAAABF0cwAAAAAAAAAAABJ0AP//////////AA==","MultiOpType":null} | merr <nil>: applyOps: (NotWritablePrimary) not primary {"t":{"$date":"2024-11-27T12:10:04.250+00: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":"2024-11-27T12:10:04.250+00: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":"2024-11-27T12:10:04.253+00:00"},"s":"W", "c":"ASIO", "id":22601, "ctx":"main","msg":"No TransportLayer configured during NetworkInterface startup"} {"t":{"$date":"2024-11-27T12:10:04.253+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":"2024-11-27T12:10:04.254+00:00"},"s":"W", "c":"ASIO", "id":22601, "ctx":"main","msg":"No TransportLayer configured during NetworkInterface startup"} {"t":{"$date":"2024-11-27T12:10:04.254+00:00"},"s":"W", "c":"ASIO", "id":22601, "ctx":"main","msg":"No TransportLayer configured during NetworkInterface startup"} {"t":{"$date":"2024-11-27T12:10:04.254+00:00"},"s":"I", "c":"REPL", "id":5123008, "ctx":"main","msg":"Successfully registered PrimaryOnlyService","attr":{"service":"TenantMigrationDonorService","ns":"config.tenantMigrationDonors"}} {"t":{"$date":"2024-11-27T12:10:04.254+00:00"},"s":"I", "c":"REPL", "id":5123008, "ctx":"main","msg":"Successfully registered PrimaryOnlyService","attr":{"service":"TenantMigrationRecipientService","ns":"config.tenantMigrationRecipients"}} {"t":{"$date":"2024-11-27T12:10:04.254+00:00"},"s":"I", "c":"CONTROL", "id":5945603, "ctx":"main","msg":"Multi threading initialized"} {"t":{"$date":"2024-11-27T12:10:04.254+00:00"},"s":"I", "c":"CONTROL", "id":4615611, "ctx":"initandlisten","msg":"MongoDB starting","attr":{"pid":513,"port":28002,"dbPath":"/var/lib/mongo","architecture":"64-bit","host":"rs101"}} {"t":{"$date":"2024-11-27T12:10:04.254+00:00"},"s":"I", "c":"CONTROL", "id":23403, "ctx":"initandlisten","msg":"Build Info","attr":{"buildInfo":{"version":"5.0.29-25","gitVersion":"6ed5ea3065f1daafa7661d1c05d20c50b614a96a","openSSLVersion":"OpenSSL 1.1.1k FIPS 25 Mar 2021","modules":[],"allocator":"tcmalloc","environment":{"distarch":"x86_64","target_arch":"x86_64"}}}} {"t":{"$date":"2024-11-27T12:10:04.254+00:00"},"s":"I", "c":"CONTROL", "id":51765, "ctx":"initandlisten","msg":"Operating System","attr":{"os":{"name":"Oracle Linux Server release 8.10","version":"Kernel 6.5.0-1025-azure"}}} {"t":{"$date":"2024-11-27T12:10:04.254+00:00"},"s":"I", "c":"CONTROL", "id":21951, "ctx":"initandlisten","msg":"Options set by command line","attr":{"options":{"config":"/tmp/pbmMongdTmpConf1816357726","net":{"bindIp":"localhost","port":28002},"replication":{"replSet":"rs1"},"setParameter":{"disableLogicalSessionCacheRefresh":"true","takeUnstableCheckpointOnShutdown":"true"},"storage":{"dbPath":"/var/lib/mongo","directoryPerDB":false,"wiredTiger":{"collectionConfig":{"blockCompressor":"snappy"},"engineConfig":{"directoryForIndexes":false,"journalCompressor":"snappy"},"indexConfig":{"prefixCompression":true}}},"systemLog":{"destination":"file","path":"/var/lib/mongo/pbm.restore.log"}}}} {"t":{"$date":"2024-11-27T12:10:04.255+00:00"},"s":"I", "c":"STORAGE", "id":22270, "ctx":"initandlisten","msg":"Storage engine to use detected by data files","attr":{"dbpath":"/var/lib/mongo","storageEngine":"wiredTiger"}} {"t":{"$date":"2024-11-27T12:10:04.255+00:00"},"s":"I", "c":"STORAGE", "id":22315, "ctx":"initandlisten","msg":"Opening WiredTiger","attr":{"config":"create,cache_size=7478M,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=(zstd=(compression_level=6)),file_manager=(close_idle_time=600,close_scan_interval=10,close_handle_minimum=2000),statistics_log=(wait=0),verbose=[recovery_progress,checkpoint_progress,compact_progress],"}} {"t":{"$date":"2024-11-27T12:10:04.456+00:00"},"s":"I", "c":"STORAGE", "id":22430, "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":"[1732709404:456106][513:0x7f3f1e6c7c00], txn-recover: [WT_VERB_RECOVERY_PROGRESS] Recovering log 5 through 6"}} {"t":{"$date":"2024-11-27T12:10:04.485+00:00"},"s":"I", "c":"STORAGE", "id":22430, "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":"[1732709404:484995][513:0x7f3f1e6c7c00], txn-recover: [WT_VERB_RECOVERY_PROGRESS] Recovering log 6 through 6"}} {"t":{"$date":"2024-11-27T12:10:04.545+00:00"},"s":"I", "c":"STORAGE", "id":22430, "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":"[1732709404:545453][513:0x7f3f1e6c7c00], txn-recover: [WT_VERB_RECOVERY_ALL] Main recovery loop: starting at 5/39808 to 6/256"}} {"t":{"$date":"2024-11-27T12:10:04.594+00:00"},"s":"I", "c":"STORAGE", "id":22430, "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":"[1732709404:594602][513:0x7f3f1e6c7c00], txn-recover: [WT_VERB_RECOVERY_PROGRESS] Recovering log 5 through 6"}} {"t":{"$date":"2024-11-27T12:10:04.634+00:00"},"s":"I", "c":"STORAGE", "id":22430, "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":"[1732709404:634345][513:0x7f3f1e6c7c00], txn-recover: [WT_VERB_RECOVERY_PROGRESS] Recovering log 6 through 6"}} {"t":{"$date":"2024-11-27T12:10:04.657+00:00"},"s":"I", "c":"STORAGE", "id":22430, "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":"[1732709404:657173][513:0x7f3f1e6c7c00], txn-recover: [WT_VERB_RECOVERY_PROGRESS] recovery log replay has successfully finished and ran for 201 milliseconds"}} {"t":{"$date":"2024-11-27T12:10:04.657+00:00"},"s":"I", "c":"STORAGE", "id":22430, "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":"[1732709404:657222][513:0x7f3f1e6c7c00], txn-recover: [WT_VERB_RECOVERY_ALL] Set global recovery timestamp: (0, 0)"}} {"t":{"$date":"2024-11-27T12:10:04.657+00:00"},"s":"I", "c":"STORAGE", "id":22430, "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":"[1732709404:657233][513:0x7f3f1e6c7c00], txn-recover: [WT_VERB_RECOVERY_ALL] Set global oldest timestamp: (0, 0)"}} {"t":{"$date":"2024-11-27T12:10:04.658+00:00"},"s":"I", "c":"STORAGE", "id":22430, "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":"[1732709404:658017][513:0x7f3f1e6c7c00], txn-recover: [WT_VERB_RECOVERY_PROGRESS] recovery rollback to stable has successfully finished and ran for 0 milliseconds"}} {"t":{"$date":"2024-11-27T12:10:04.659+00:00"},"s":"I", "c":"STORAGE", "id":22430, "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":"[1732709404:659732][513:0x7f3f1e6c7c00], WT_SESSION.checkpoint: [WT_VERB_CHECKPOINT_PROGRESS] saving checkpoint snapshot min: 1, snapshot max: 1 snapshot count: 0, oldest timestamp: (0, 0) , meta checkpoint timestamp: (0, 0) base write gen: 40"}} {"t":{"$date":"2024-11-27T12:10:04.661+00:00"},"s":"I", "c":"STORAGE", "id":22430, "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":"[1732709404:661530][513:0x7f3f1e6c7c00], txn-recover: [WT_VERB_RECOVERY_PROGRESS] recovery checkpoint has successfully finished and ran for 3 milliseconds"}} {"t":{"$date":"2024-11-27T12:10:04.661+00:00"},"s":"I", "c":"STORAGE", "id":22430, "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":"[1732709404:661564][513:0x7f3f1e6c7c00], txn-recover: [WT_VERB_RECOVERY_PROGRESS] recovery was completed successfully and took 205ms, including 201ms for the log replay, 0ms for the rollback to stable, and 3ms for the checkpoint."}} {"t":{"$date":"2024-11-27T12:10:04.662+00:00"},"s":"I", "c":"STORAGE", "id":4795906, "ctx":"initandlisten","msg":"WiredTiger opened","attr":{"durationMillis":407}} {"t":{"$date":"2024-11-27T12:10:04.662+00:00"},"s":"I", "c":"RECOVERY", "id":23987, "ctx":"initandlisten","msg":"WiredTiger recoveryTimestamp","attr":{"recoveryTimestamp":{"$timestamp":{"t":0,"i":0}}}} {"t":{"$date":"2024-11-27T12:10:04.669+00:00"},"s":"I", "c":"STORAGE", "id":22383, "ctx":"initandlisten","msg":"The size storer reports that the oplog contains","attr":{"numRecords":33,"dataSize":8054}} {"t":{"$date":"2024-11-27T12:10:04.669+00:00"},"s":"I", "c":"STORAGE", "id":22384, "ctx":"initandlisten","msg":"Scanning the oplog to determine where to place markers for truncation"} {"t":{"$date":"2024-11-27T12:10:04.670+00:00"},"s":"I", "c":"STORAGE", "id":22382, "ctx":"initandlisten","msg":"WiredTiger record store oplog processing finished","attr":{"durationMillis":0}} {"t":{"$date":"2024-11-27T12:10:04.679+00:00"},"s":"I", "c":"STORAGE", "id":22262, "ctx":"initandlisten","msg":"Timestamp monitor starting"} {"t":{"$date":"2024-11-27T12:10:04.679+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. You can use percona-server-mongodb-enable-auth.sh to fix it","tags":["startupWarnings"]} {"t":{"$date":"2024-11-27T12:10:04.679+00:00"},"s":"W", "c":"CONTROL", "id":22178, "ctx":"initandlisten","msg":"/sys/kernel/mm/transparent_hugepage/enabled is 'always'. We suggest setting it to 'never' in this binary version","tags":["startupWarnings"]} {"t":{"$date":"2024-11-27T12:10:04.686+00: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},"isInternalClient":true},"newSpec":{"incomingExternalClient":{"minWireVersion":0,"maxWireVersion":13},"incomingInternalClient":{"minWireVersion":13,"maxWireVersion":13},"outgoing":{"minWireVersion":13,"maxWireVersion":13},"isInternalClient":true}}} {"t":{"$date":"2024-11-27T12:10:04.686+00:00"},"s":"I", "c":"STORAGE", "id":5071100, "ctx":"initandlisten","msg":"Clearing temp directory"} {"t":{"$date":"2024-11-27T12:10:04.700+00:00"},"s":"I", "c":"CONTROL", "id":20536, "ctx":"initandlisten","msg":"Flow Control is enabled on this deployment"} {"t":{"$date":"2024-11-27T12:10:04.701+00:00"},"s":"W", "c":"SHARDING", "id":22075, "ctx":"initandlisten","msg":"Not started with --shardsvr, but a shardIdentity document was found on disk","attr":{"namespace":"admin.system.version","shardIdentityDocument":{"_id":"shardIdentity","shardName":"rs1","clusterId":{"$oid":"67470ac0d960682c2cd5dfa9"},"configsvrConnectionString":"rscfg/rscfg01:27017"}}} {"t":{"$date":"2024-11-27T12:10:04.701+00:00"},"s":"I", "c":"FTDC", "id":20625, "ctx":"initandlisten","msg":"Initializing full-time diagnostic data capture","attr":{"dataDirectory":"/var/lib/mongo/diagnostic.data"}} {"t":{"$date":"2024-11-27T12:10:04.703+00: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":"2024-11-27T12:10:04.703+00:00"},"s":"I", "c":"REPL", "id":6015317, "ctx":"initandlisten","msg":"Setting new configuration state","attr":{"newState":"ConfigStartingUp","oldState":"ConfigPreStart"}} {"t":{"$date":"2024-11-27T12:10:04.704+00:00"},"s":"I", "c":"REPL", "id":4280500, "ctx":"initandlisten","msg":"Attempting to create internal replication collections"} {"t":{"$date":"2024-11-27T12:10:04.706+00:00"},"s":"I", "c":"REPL", "id":4280501, "ctx":"initandlisten","msg":"Attempting to load local voted for document"} {"t":{"$date":"2024-11-27T12:10:04.706+00:00"},"s":"I", "c":"REPL", "id":21311, "ctx":"initandlisten","msg":"Did not find local initialized voted for document at startup"} {"t":{"$date":"2024-11-27T12:10:04.706+00:00"},"s":"I", "c":"REPL", "id":4280502, "ctx":"initandlisten","msg":"Searching for local Rollback ID document"} {"t":{"$date":"2024-11-27T12:10:04.707+00:00"},"s":"I", "c":"REPL", "id":21529, "ctx":"initandlisten","msg":"Initializing rollback ID","attr":{"rbid":1}} {"t":{"$date":"2024-11-27T12:10:04.707+00:00"},"s":"I", "c":"REPL", "id":4280504, "ctx":"initandlisten","msg":"Cleaning up any partially applied oplog batches & reading last op from oplog"} {"t":{"$date":"2024-11-27T12:10:04.708+00:00"},"s":"I", "c":"REPL", "id":21546, "ctx":"initandlisten","msg":"Recovering from an unstable checkpoint","attr":{"topOfOplog":{"ts":{"$timestamp":{"t":1732709071,"i":58}},"t":1},"appliedThrough":{"ts":{"$timestamp":{"t":1732709071,"i":58}},"t":1}}} {"t":{"$date":"2024-11-27T12:10:04.708+00:00"},"s":"I", "c":"REPL", "id":21548, "ctx":"initandlisten","msg":"Starting recovery oplog application at the appliedThrough through the top of the oplog","attr":{"appliedThrough":{"ts":{"$timestamp":{"t":1732709071,"i":58}},"t":1},"topOfOplog":{"ts":{"$timestamp":{"t":1732709071,"i":58}},"t":1}}} {"t":{"$date":"2024-11-27T12:10:04.708+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"} {"t":{"$date":"2024-11-27T12:10:04.710+00:00"},"s":"I", "c":"STORAGE", "id":22430, "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":"[1732709404:710020][513:0x7f3f1e6c7c00], WT_SESSION.checkpoint: [WT_VERB_CHECKPOINT_PROGRESS] saving checkpoint snapshot min: 31, snapshot max: 31 snapshot count: 0, oldest timestamp: (1732709071, 58) , meta checkpoint timestamp: (0, 0) base write gen: 40"}} {"t":{"$date":"2024-11-27T12:10:04.713+00:00"},"s":"I", "c":"REPL", "id":4280505, "ctx":"initandlisten","msg":"Creating any necessary TenantMigrationAccessBlockers for unfinished migrations"} {"t":{"$date":"2024-11-27T12:10:04.714+00:00"},"s":"I", "c":"REPL", "id":4280506, "ctx":"initandlisten","msg":"Reconstructing prepared transactions"} {"t":{"$date":"2024-11-27T12:10:04.716+00:00"},"s":"I", "c":"REPL", "id":4280507, "ctx":"initandlisten","msg":"Loaded replica set config, scheduled callback to set local config"} {"t":{"$date":"2024-11-27T12:10:04.716+00:00"},"s":"I", "c":"REPL", "id":4280508, "ctx":"ReplCoord-0","msg":"Attempting to set local replica set config; validating config for startup"} {"t":{"$date":"2024-11-27T12:10:04.717+00:00"},"s":"I", "c":"REPL", "id":40440, "ctx":"initandlisten","msg":"Starting the TopologyVersionObserver"} {"t":{"$date":"2024-11-27T12:10:04.717+00:00"},"s":"I", "c":"REPL", "id":40445, "ctx":"TopologyVersionObserver","msg":"Started TopologyVersionObserver"} {"t":{"$date":"2024-11-27T12:10:04.717+00:00"},"s":"I", "c":"NETWORK", "id":23015, "ctx":"listener","msg":"Listening on","attr":{"address":"/tmp/mongodb-28002.sock"}} {"t":{"$date":"2024-11-27T12:10:04.717+00:00"},"s":"I", "c":"NETWORK", "id":23015, "ctx":"listener","msg":"Listening on","attr":{"address":"127.0.0.1"}} {"t":{"$date":"2024-11-27T12:10:04.717+00:00"},"s":"I", "c":"NETWORK", "id":23016, "ctx":"listener","msg":"Waiting for connections","attr":{"port":28002,"ssl":"off"}} {"t":{"$date":"2024-11-27T12:10:04.739+00:00"},"s":"I", "c":"NETWORK", "id":22943, "ctx":"listener","msg":"Connection accepted","attr":{"remote":"127.0.0.1:52164","uuid":"114b8b38-10df-4dc9-b2c8-f1369d061f46","connectionId":1,"connectionCount":1}} {"t":{"$date":"2024-11-27T12:10:04.740+00:00"},"s":"I", "c":"NETWORK", "id":22943, "ctx":"listener","msg":"Connection accepted","attr":{"remote":"127.0.0.1:52180","uuid":"cf27dabc-b69b-415c-b6a0-4a094480ef60","connectionId":3,"connectionCount":2}} {"t":{"$date":"2024-11-27T12:10:04.740+00:00"},"s":"I", "c":"NETWORK", "id":51800, "ctx":"conn1","msg":"client metadata","attr":{"remote":"127.0.0.1:52164","client":"conn1","negotiatedCompressors":[],"doc":{"application":{"name":"pbm-physical-restore"},"driver":{"name":"mongo-go-driver","version":"1.16.0"},"os":{"type":"linux","architecture":"amd64"},"platform":"go1.23.3","env":{"container":{"runtime":"docker"}}}}} {"t":{"$date":"2024-11-27T12:10:04.740+00:00"},"s":"W", "c":"COMMAND", "id":5578800, "ctx":"conn3","msg":"Deprecated operation requested. The client driver may require an upgrade in order to ensure compatibility with future server versions. For more details see https://dochub.mongodb.org/core/legacy-opcode-compatibility","attr":{"op":"query","clientInfo":{"address":"127.0.0.1:52180"}}} {"t":{"$date":"2024-11-27T12:10:04.740+00:00"},"s":"I", "c":"REPL", "id":4280509, "ctx":"ReplCoord-0","msg":"Local configuration validated for startup"} {"t":{"$date":"2024-11-27T12:10:04.740+00:00"},"s":"I", "c":"REPL", "id":6015317, "ctx":"ReplCoord-0","msg":"Setting new configuration state","attr":{"newState":"ConfigSteady","oldState":"ConfigStartingUp"}} {"t":{"$date":"2024-11-27T12:10:04.740+00:00"},"s":"I", "c":"REPL", "id":21392, "ctx":"ReplCoord-0","msg":"New replica set config in use","attr":{"config":{"_id":"rs1","version":1,"members":[{"_id":0,"host":"localhost:28002","arbiterOnly":false,"buildIndexes":true,"hidden":false,"priority":1,"tags":{},"secondaryDelaySecs":0,"votes":1}],"protocolVersion":1,"writeConcernMajorityJournalDefault":true,"settings":{"chainingAllowed":true,"heartbeatIntervalMillis":2000,"heartbeatTimeoutSecs":10,"electionTimeoutMillis":10000,"catchUpTimeoutMillis":-1,"catchUpTakeoverDelayMillis":30000,"getLastErrorModes":{},"getLastErrorDefaults":{"w":1,"wtimeout":0}}}}} {"t":{"$date":"2024-11-27T12:10:04.740+00:00"},"s":"I", "c":"REPL", "id":21393, "ctx":"ReplCoord-0","msg":"Found self in config","attr":{"hostAndPort":"localhost:28002"}} {"t":{"$date":"2024-11-27T12:10:04.740+00:00"},"s":"I", "c":"REPL", "id":21358, "ctx":"ReplCoord-0","msg":"Replica set state transition","attr":{"newState":"STARTUP2","oldState":"STARTUP"}} {"t":{"$date":"2024-11-27T12:10:04.740+00:00"},"s":"I", "c":"REPL", "id":21320, "ctx":"ReplCoord-0","msg":"Updated term","attr":{"term":1}} {"t":{"$date":"2024-11-27T12:10:04.740+00:00"},"s":"I", "c":"REPL", "id":21306, "ctx":"ReplCoord-0","msg":"Starting replication storage threads"} {"t":{"$date":"2024-11-27T12:10:04.740+00:00"},"s":"I", "c":"NETWORK", "id":22944, "ctx":"conn3","msg":"Connection ended","attr":{"remote":"127.0.0.1:52180","uuid":"cf27dabc-b69b-415c-b6a0-4a094480ef60","connectionId":3,"connectionCount":1}} {"t":{"$date":"2024-11-27T12:10:04.741+00:00"},"s":"I", "c":"NETWORK", "id":22943, "ctx":"listener","msg":"Connection accepted","attr":{"remote":"127.0.0.1:52210","uuid":"89916ae6-a53f-46d4-8cdb-299f01988432","connectionId":4,"connectionCount":2}} {"t":{"$date":"2024-11-27T12:10:04.741+00:00"},"s":"I", "c":"REPL", "id":4280512, "ctx":"ReplCoord-0","msg":"No initial sync required. Attempting to begin steady replication"} {"t":{"$date":"2024-11-27T12:10:04.741+00:00"},"s":"I", "c":"REPL", "id":21358, "ctx":"ReplCoord-0","msg":"Replica set state transition","attr":{"newState":"RECOVERING","oldState":"STARTUP2"}} {"t":{"$date":"2024-11-27T12:10:04.741+00:00"},"s":"I", "c":"STORAGE", "id":20320, "ctx":"ReplCoord-0","msg":"createCollection","attr":{"namespace":"local.replset.initialSyncId","uuidDisposition":"generated","uuid":{"uuid":{"$uuid":"4fd1331d-55c4-4815-b4a4-defcc5ada9d4"}},"options":{}}} {"t":{"$date":"2024-11-27T12:10:04.741+00:00"},"s":"I", "c":"NETWORK", "id":22943, "ctx":"listener","msg":"Connection accepted","attr":{"remote":"127.0.0.1:52196","uuid":"850714ce-558a-4471-85c5-1d77f61fcc22","connectionId":5,"connectionCount":3}} {"t":{"$date":"2024-11-27T12:10:04.741+00:00"},"s":"I", "c":"NETWORK", "id":51800, "ctx":"conn5","msg":"client metadata","attr":{"remote":"127.0.0.1:52196","client":"conn5","negotiatedCompressors":[],"doc":{"application":{"name":"pbm-physical-restore"},"driver":{"name":"mongo-go-driver","version":"1.16.0"},"os":{"type":"linux","architecture":"amd64"},"platform":"go1.23.3","env":{"container":{"runtime":"docker"}}}}} {"t":{"$date":"2024-11-27T12:10:04.741+00:00"},"s":"I", "c":"NETWORK", "id":51800, "ctx":"conn4","msg":"client metadata","attr":{"remote":"127.0.0.1:52210","client":"conn4","negotiatedCompressors":[],"doc":{"application":{"name":"pbm-physical-restore"},"driver":{"name":"mongo-go-driver","version":"1.16.0"},"os":{"type":"linux","architecture":"amd64"},"platform":"go1.23.3","env":{"container":{"runtime":"docker"}}}}} {"t":{"$date":"2024-11-27T12:10:04.748+00:00"},"s":"I", "c":"INDEX", "id":20345, "ctx":"ReplCoord-0","msg":"Index build: done building","attr":{"buildUUID":null,"namespace":"local.replset.initialSyncId","index":"_id_","commitTimestamp":null}} {"t":{"$date":"2024-11-27T12:10:04.748+00:00"},"s":"I", "c":"REPL", "id":21299, "ctx":"ReplCoord-0","msg":"Starting replication fetcher thread"} {"t":{"$date":"2024-11-27T12:10:04.748+00:00"},"s":"I", "c":"REPL", "id":21300, "ctx":"ReplCoord-0","msg":"Starting replication applier thread"} {"t":{"$date":"2024-11-27T12:10:04.748+00:00"},"s":"I", "c":"REPL", "id":21224, "ctx":"OplogApplier-0","msg":"Starting oplog application"} {"t":{"$date":"2024-11-27T12:10:04.749+00:00"},"s":"I", "c":"REPL", "id":21301, "ctx":"ReplCoord-0","msg":"Starting replication reporter thread"} {"t":{"$date":"2024-11-27T12:10:04.749+00:00"},"s":"I", "c":"REPL", "id":4280511, "ctx":"ReplCoord-0","msg":"Set local replica set config"} {"t":{"$date":"2024-11-27T12:10:04.749+00:00"},"s":"I", "c":"REPL", "id":21358, "ctx":"OplogApplier-0","msg":"Replica set state transition","attr":{"newState":"SECONDARY","oldState":"RECOVERING"}} {"t":{"$date":"2024-11-27T12:10:04.749+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}} {"t":{"$date":"2024-11-27T12:10:04.749+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":1}} {"t":{"$date":"2024-11-27T12:10:04.749+00:00"},"s":"I", "c":"ELECTION", "id":21444, "ctx":"ReplCoord-0","msg":"Dry election run succeeded, running for election","attr":{"newTerm":2}} {"t":{"$date":"2024-11-27T12:10:04.749+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":2,"candidateIndex":0}}} {"t":{"$date":"2024-11-27T12:10:04.750+00:00"},"s":"I", "c":"ELECTION", "id":21450, "ctx":"ReplCoord-0","msg":"Election succeeded, assuming primary role","attr":{"term":2}} {"t":{"$date":"2024-11-27T12:10:04.750+00:00"},"s":"I", "c":"REPL", "id":21358, "ctx":"ReplCoord-0","msg":"Replica set state transition","attr":{"newState":"PRIMARY","oldState":"SECONDARY"}} {"t":{"$date":"2024-11-27T12:10:04.750+00:00"},"s":"I", "c":"REPL", "id":21106, "ctx":"ReplCoord-0","msg":"Resetting sync source to empty","attr":{"previousSyncSource":":27017"}} {"t":{"$date":"2024-11-27T12:10:04.750+00:00"},"s":"I", "c":"REPL", "id":21359, "ctx":"ReplCoord-0","msg":"Entering primary catch-up mode"} {"t":{"$date":"2024-11-27T12:10:04.750+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."} {"t":{"$date":"2024-11-27T12:10:04.750+00:00"},"s":"I", "c":"REPL", "id":21363, "ctx":"ReplCoord-0","msg":"Exited primary catch-up mode"} {"t":{"$date":"2024-11-27T12:10:04.750+00:00"},"s":"I", "c":"REPL", "id":21107, "ctx":"ReplCoord-0","msg":"Stopping replication producer"} {"t":{"$date":"2024-11-27T12:10:04.750+00:00"},"s":"I", "c":"REPL", "id":21239, "ctx":"ReplBatcher","msg":"Oplog buffer has been drained","attr":{"term":2}} {"t":{"$date":"2024-11-27T12:10:04.755+00:00"},"s":"I", "c":"REPL", "id":21343, "ctx":"RstlKillOpThread","msg":"Starting to kill user operations"} {"t":{"$date":"2024-11-27T12:10:04.755+00:00"},"s":"I", "c":"REPL", "id":21344, "ctx":"RstlKillOpThread","msg":"Stopped killing user operations"} {"t":{"$date":"2024-11-27T12:10:04.755+00:00"},"s":"I", "c":"REPL", "id":21340, "ctx":"RstlKillOpThread","msg":"State transition ops metrics","attr":{"metrics":{"lastStateTransition":"stepUp","userOpsKilled":0,"userOpsRunning":1}}} {"t":{"$date":"2024-11-27T12:10:04.756+00:00"},"s":"I", "c":"REPL", "id":6015310, "ctx":"OplogApplier-0","msg":"Starting to transition to primary."} {"t":{"$date":"2024-11-27T12:10:04.756+00:00"},"s":"I", "c":"REPL", "id":6015309, "ctx":"OplogApplier-0","msg":"Logging transition to primary to oplog on stepup"} {"t":{"$date":"2024-11-27T12:10:04.756+00:00"},"s":"I", "c":"STORAGE", "id":20657, "ctx":"OplogApplier-0","msg":"IndexBuildsCoordinator::onStepUp - this node is stepping up to primary"} {"t":{"$date":"2024-11-27T12:10:04.757+00:00"},"s":"I", "c":"REPL", "id":21331, "ctx":"OplogApplier-0","msg":"Transition to primary complete; database writes are now permitted"} {"t":{"$date":"2024-11-27T12:10:04.757+00:00"},"s":"I", "c":"STORAGE", "id":20320, "ctx":"monitoring-keys-for-HMAC","msg":"createCollection","attr":{"namespace":"admin.system.keys","uuidDisposition":"generated","uuid":{"uuid":{"$uuid":"adb2fe19-9d25-48be-8896-f1647325394d"}},"options":{}}} {"t":{"$date":"2024-11-27T12:10:04.758+00:00"},"s":"I", "c":"STORAGE", "id":22310, "ctx":"JournalFlusher","msg":"Triggering the first stable checkpoint","attr":{"initialDataTimestamp":{"$timestamp":{"t":1732709071,"i":58}},"prevStableTimestamp":{"$timestamp":{"t":0,"i":0}},"currStableTimestamp":{"$timestamp":{"t":1732709404,"i":2}}}} {"t":{"$date":"2024-11-27T12:10:04.759+00:00"},"s":"I", "c":"STORAGE", "id":20320, "ctx":"TenantMigrationDonorService-0","msg":"createCollection","attr":{"namespace":"config.tenantMigrationDonors","uuidDisposition":"generated","uuid":{"uuid":{"$uuid":"fd62ec85-bc41-437c-a2f3-190198009d94"}},"options":{}}} {"t":{"$date":"2024-11-27T12:10:04.759+00:00"},"s":"I", "c":"STORAGE", "id":20320, "ctx":"TenantMigrationRecipientService-0","msg":"createCollection","attr":{"namespace":"config.tenantMigrationRecipients","uuidDisposition":"generated","uuid":{"uuid":{"$uuid":"19f6d2ea-bf05-4882-8a14-4f515373bb1d"}},"options":{}}} {"t":{"$date":"2024-11-27T12:10:04.763+00:00"},"s":"I", "c":"NETWORK", "id":22944, "ctx":"conn4","msg":"Connection ended","attr":{"remote":"127.0.0.1:52210","uuid":"89916ae6-a53f-46d4-8cdb-299f01988432","connectionId":4,"connectionCount":2}} {"t":{"$date":"2024-11-27T12:10:04.764+00:00"},"s":"I", "c":"-", "id":20883, "ctx":"conn1","msg":"Interrupted operation as its client disconnected","attr":{"opId":39}} {"t":{"$date":"2024-11-27T12:10:04.763+00:00"},"s":"I", "c":"NETWORK", "id":22944, "ctx":"conn5","msg":"Connection ended","attr":{"remote":"127.0.0.1:52196","uuid":"850714ce-558a-4471-85c5-1d77f61fcc22","connectionId":5,"connectionCount":1}} {"t":{"$date":"2024-11-27T12:10:04.764+00:00"},"s":"E", "c":"STORAGE", "id":22435, "ctx":"Checkpointer","msg":"WiredTiger error","attr":{"error":2,"message":"[1732709404:764505][513:0x7f3f065d2700], file:collection-2-3386554847868077762.wt, WT_SESSION.checkpoint: __posix_fs_size, 296: /var/lib/mongo/WiredTigerHS.wt: file-size: stat: No such file or directory"}} {"t":{"$date":"2024-11-27T12:10:04.764+00:00"},"s":"E", "c":"STORAGE", "id":22435, "ctx":"Checkpointer","msg":"WiredTiger error","attr":{"error":2,"message":"[1732709404:764712][513:0x7f3f065d2700], file:collection-2-3386554847868077762.wt, WT_SESSION.checkpoint: __reconcile, 351: reconciliation failed after building the disk image: No such file or directory"}} {"t":{"$date":"2024-11-27T12:10:04.764+00:00"},"s":"E", "c":"STORAGE", "id":22435, "ctx":"Checkpointer","msg":"WiredTiger error","attr":{"error":-31804,"message":"[1732709404:764735][513:0x7f3f065d2700], file:collection-2-3386554847868077762.wt, WT_SESSION.checkpoint: __reconcile, 351: the process must exit and restart: WT_PANIC: WiredTiger library panic"}} {"t":{"$date":"2024-11-27T12:10:04.764+00:00"},"s":"F", "c":"-", "id":23089, "ctx":"Checkpointer","msg":"Fatal assertion","attr":{"msgid":50853,"file":"src/mongo/db/storage/wiredtiger/wiredtiger_util.cpp","line":574}} {"t":{"$date":"2024-11-27T12:10:04.764+00:00"},"s":"F", "c":"-", "id":23090, "ctx":"Checkpointer","msg":"\n\n***aborting after fassert() failure\n\n"} {"t":{"$date":"2024-11-27T12:10:04.764+00:00"},"s":"I", "c":"NETWORK", "id":22989, "ctx":"conn1","msg":"Error sending response to client. Ending connection from remote","attr":{"error":{"code":6,"codeName":"HostUnreachable","errmsg":"Connection reset by peer"},"remote":"127.0.0.1:52164","connectionId":1}} {"t":{"$date":"2024-11-27T12:10:04.764+00:00"},"s":"F", "c":"CONTROL", "id":6384300, "ctx":"Checkpointer","msg":"Writing fatal message","attr":{"message":"Got signal: 6 (Aborted).\n"}} {"t":{"$date":"2024-11-27T12:10:04.764+00:00"},"s":"I", "c":"NETWORK", "id":22944, "ctx":"conn1","msg":"Connection ended","attr":{"remote":"127.0.0.1:52164","uuid":"114b8b38-10df-4dc9-b2c8-f1369d061f46","connectionId":1,"connectionCount":0}} {"t":{"$date":"2024-11-27T12:10:04.773+00:00"},"s":"I", "c":"INDEX", "id":20345, "ctx":"monitoring-keys-for-HMAC","msg":"Index build: done building","attr":{"buildUUID":null,"namespace":"admin.system.keys","index":"_id_","commitTimestamp":{"$timestamp":{"t":1732709404,"i":3}}}} {"t":{"$date":"2024-11-27T12:10:04.780+00:00"},"s":"I", "c":"INDEX", "id":20345, "ctx":"TenantMigrationDonorService-0","msg":"Index build: done building","attr":{"buildUUID":null,"namespace":"config.tenantMigrationDonors","index":"_id_","commitTimestamp":{"$timestamp":{"t":1732709404,"i":7}}}} {"t":{"$date":"2024-11-27T12:10:04.780+00:00"},"s":"I", "c":"INDEX", "id":20345, "ctx":"TenantMigrationDonorService-0","msg":"Index build: done building","attr":{"buildUUID":null,"namespace":"config.tenantMigrationDonors","index":"TenantMigrationDonorTTLIndex","commitTimestamp":{"$timestamp":{"t":1732709404,"i":7}}}} {"t":{"$date":"2024-11-27T12:10:04.780+00:00"},"s":"I", "c":"STORAGE", "id":20320, "ctx":"TenantMigrationDonorService-1","msg":"createCollection","attr":{"namespace":"config.external_validation_keys","uuidDisposition":"generated","uuid":{"uuid":{"$uuid":"92e9b090-8c19-48b9-b3f2-91a40d32aa87"}},"options":{}}} {"t":{"$date":"2024-11-27T12:10:04.782+00:00"},"s":"I", "c":"INDEX", "id":20345, "ctx":"TenantMigrationRecipientService-0","msg":"Index build: done building","attr":{"buildUUID":null,"namespace":"config.tenantMigrationRecipients","index":"_id_","commitTimestamp":{"$timestamp":{"t":1732709404,"i":8}}}} {"t":{"$date":"2024-11-27T12:10:04.782+00:00"},"s":"I", "c":"INDEX", "id":20345, "ctx":"TenantMigrationRecipientService-0","msg":"Index build: done building","attr":{"buildUUID":null,"namespace":"config.tenantMigrationRecipients","index":"TenantMigrationRecipientTTLIndex","commitTimestamp":{"$timestamp":{"t":1732709404,"i":8}}}} {"t":{"$date":"2024-11-27T12:10:04.782+00:00"},"s":"I", "c":"REPL", "id":5123005, "ctx":"TenantMigrationRecipientService-0","msg":"Rebuilding PrimaryOnlyService due to stepUp","attr":{"service":"TenantMigrationRecipientService"}} {"t":{"$date":"2024-11-27T12:10:04.789+00:00"},"s":"I", "c":"INDEX", "id":20345, "ctx":"TenantMigrationDonorService-1","msg":"Index build: done building","attr":{"buildUUID":null,"namespace":"config.external_validation_keys","index":"_id_","commitTimestamp":{"$timestamp":{"t":1732709404,"i":11}}}} {"t":{"$date":"2024-11-27T12:10:04.789+00:00"},"s":"I", "c":"INDEX", "id":20345, "ctx":"TenantMigrationDonorService-1","msg":"Index build: done building","attr":{"buildUUID":null,"namespace":"config.external_validation_keys","index":"ExternalKeysTTLIndex","commitTimestamp":{"$timestamp":{"t":1732709404,"i":11}}}} {"t":{"$date":"2024-11-27T12:10:04.789+00:00"},"s":"I", "c":"REPL", "id":5123005, "ctx":"TenantMigrationDonorService-1","msg":"Rebuilding PrimaryOnlyService due to stepUp","attr":{"service":"TenantMigrationDonorService"}} {"t":{"$date":"2024-11-27T12:10:04.823+00:00"},"s":"I", "c":"CONTROL", "id":31380, "ctx":"Checkpointer","msg":"BACKTRACE","attr":{"bt":{"backtrace":[{"a":"55D4184239C3","b":"55D414206000","o":"421D9C3","s":"_ZN5mongo34StackTraceAddressMetadataGenerator4loadEPv","s+":"FC3"},{"a":"55D418426417","b":"55D414206000","o":"4220417","s":"_ZN5mongo15printStackTraceEv","s+":"37"},{"a":"55D41841E5B6","b":"55D414206000","o":"42185B6","s":"abruptQuit","s+":"66"},{"a":"7F3F1BE45D80","b":"7F3F1BE33000","o":"12D80","s":"funlockfile","s+":"50"},{"a":"7F3F1BAAB5EF","b":"7F3F1BA5D000","o":"4E5EF","s":"gsignal","s+":"10F"},{"a":"7F3F1BA7EE65","b":"7F3F1BA5D000","o":"21E65","s":"abort","s+":"127"},{"a":"55D415784D6D","b":"55D414206000","o":"157ED6D","s":"_ZN5mongo25fassertFailedWithLocationEiPKcj","s+":"F6"},{"a":"55D415240CF4","b":"55D414206000","o":"103ACF4","s":"_ZZN5mongo8RecordIdC4EPKciENKUlvE0_clEv","s+":"30B8"},{"a":"55D415AE99F3","b":"55D414206000","o":"18E39F3","s":"__wt_event_handler_set","s+":"4A3"},{"a":"55D4152533E3","b":"55D414206000","o":"104D3E3","s":"__wt_panic_func","s+":"114"},{"a":"55D41524FA8D","b":"55D414206000","o":"1049A8D","s":"__wt_ext_map_windows_error","s+":"25CA"},{"a":"55D415B7EDFA","b":"55D414206000","o":"1978DFA","s":"__wt_sync_file","s+":"6AA"},{"a":"55D415B0813B","b":"55D414206000","o":"190213B","s":"__wt_checkpoint_tree_reconcile_update","s+":"1CB"},{"a":"55D415B0923F","b":"55D414206000","o":"190323F","s":"__wt_checkpoint_sync","s+":"99F"},{"a":"55D415B0AB76","b":"55D414206000","o":"1904B76","s":"__wt_txn_checkpoint","s+":"246"},{"a":"55D4152526EF","b":"55D414206000","o":"104C6EF","s":"__wt_session_notsup","s+":"FCC"},{"a":"55D4159EF586","b":"55D414206000","o":"17E9586","s":"_ZN5mongo18WiredTigerKVEngine11_checkpointEP12__wt_sessionb","s+":"46"},{"a":"55D4159FC988","b":"55D414206000","o":"17F6988","s":"_ZN5mongo18WiredTigerKVEngine11_checkpointEP12__wt_session","s+":"2B8"},{"a":"55D4159FD050","b":"55D414206000","o":"17F7050","s":"_ZN5mongo18WiredTigerKVEngine10checkpointEv","s+":"40"},{"a":"55D4169A2459","b":"55D414206000","o":"279C459","s":"_ZN5mongo12Checkpointer3runEv","s+":"E59"},{"a":"55D4181DEE32","b":"55D414206000","o":"3FD8E32","s":"_ZN5mongo13BackgroundJob7jobBodyEv","s+":"E2"},{"a":"55D4181DF54C","b":"55D414206000","o":"3FD954C","s":"_ZN5mongo13BackgroundJob7jobBodyEv","s+":"7FC"},{"a":"7F3F1C6B0B23","b":"7F3F1C5EE000","o":"C2B23","s":"_ZNKSt10error_code23default_error_conditionEv","s+":"33"},{"a":"7F3F1BE3B1DA","b":"7F3F1BE33000","o":"81DA","s":"start_thread","s+":"EA"},{"a":"7F3F1BA968D3","b":"7F3F1BA5D000","o":"398D3","s":"clone","s+":"43"}],"processInfo":{"mongodbVersion":"5.0.29-25","gitVersion":"6ed5ea3065f1daafa7661d1c05d20c50b614a96a","compiledModules":[],"uname":{"sysname":"Linux","release":"6.5.0-1025-azure","version":"#26~22.04.1-Ubuntu SMP Thu Jul 11 22:33:04 UTC 2024","machine":"x86_64"},"somap":[{"b":"55D414206000","elfType":3,"buildId":"539E2C825673723B04D19874D3C9DF6EB9A69E4F"},{"b":"7F3F1C5EE000","path":"/lib64/libstdc++.so.6","elfType":3,"buildId":"41809D0B18272BC525772714DA54108BF1C59253"},{"b":"7F3F1BE33000","path":"/lib64/libpthread.so.0","elfType":3,"buildId":"0B813C2AD185DCA27DDB58BA42ACC172679B1526"},{"b":"7F3F1BA5D000","path":"/lib64/libc.so.6","elfType":3,"buildId":"BF4C06A1D77241A2D30436873E56C348FCBB5D22"}]}}}} {"t":{"$date":"2024-11-27T12:10:04.823+00:00"},"s":"I", "c":"CONTROL", "id":31445, "ctx":"Checkpointer","msg":"Frame","attr":{"frame":{"a":"55D4184239C3","b":"55D414206000","o":"421D9C3","s":"_ZN5mongo34StackTraceAddressMetadataGenerator4loadEPv","s+":"FC3"}}} {"t":{"$date":"2024-11-27T12:10:04.823+00:00"},"s":"I", "c":"CONTROL", "id":31445, "ctx":"Checkpointer","msg":"Frame","attr":{"frame":{"a":"55D418426417","b":"55D414206000","o":"4220417","s":"_ZN5mongo15printStackTraceEv","s+":"37"}}} {"t":{"$date":"2024-11-27T12:10:04.823+00:00"},"s":"I", "c":"CONTROL", "id":31445, "ctx":"Checkpointer","msg":"Frame","attr":{"frame":{"a":"55D41841E5B6","b":"55D414206000","o":"42185B6","s":"abruptQuit","s+":"66"}}} {"t":{"$date":"2024-11-27T12:10:04.823+00:00"},"s":"I", "c":"CONTROL", "id":31445, "ctx":"Checkpointer","msg":"Frame","attr":{"frame":{"a":"7F3F1BE45D80","b":"7F3F1BE33000","o":"12D80","s":"funlockfile","s+":"50"}}} {"t":{"$date":"2024-11-27T12:10:04.823+00:00"},"s":"I", "c":"CONTROL", "id":31445, "ctx":"Checkpointer","msg":"Frame","attr":{"frame":{"a":"7F3F1BAAB5EF","b":"7F3F1BA5D000","o":"4E5EF","s":"gsignal","s+":"10F"}}} {"t":{"$date":"2024-11-27T12:10:04.823+00:00"},"s":"I", "c":"CONTROL", "id":31445, "ctx":"Checkpointer","msg":"Frame","attr":{"frame":{"a":"7F3F1BA7EE65","b":"7F3F1BA5D000","o":"21E65","s":"abort","s+":"127"}}} {"t":{"$date":"2024-11-27T12:10:04.823+00:00"},"s":"I", "c":"CONTROL", "id":31445, "ctx":"Checkpointer","msg":"Frame","attr":{"frame":{"a":"55D415784D6D","b":"55D414206000","o":"157ED6D","s":"_ZN5mongo25fassertFailedWithLocationEiPKcj","s+":"F6"}}} {"t":{"$date":"2024-11-27T12:10:04.823+00:00"},"s":"I", "c":"CONTROL", "id":31445, "ctx":"Checkpointer","msg":"Frame","attr":{"frame":{"a":"55D415240CF4","b":"55D414206000","o":"103ACF4","s":"_ZZN5mongo8RecordIdC4EPKciENKUlvE0_clEv","s+":"30B8"}}} {"t":{"$date":"2024-11-27T12:10:04.823+00:00"},"s":"I", "c":"CONTROL", "id":31445, "ctx":"Checkpointer","msg":"Frame","attr":{"frame":{"a":"55D415AE99F3","b":"55D414206000","o":"18E39F3","s":"__wt_event_handler_set","s+":"4A3"}}} {"t":{"$date":"2024-11-27T12:10:04.823+00:00"},"s":"I", "c":"CONTROL", "id":31445, "ctx":"Checkpointer","msg":"Frame","attr":{"frame":{"a":"55D4152533E3","b":"55D414206000","o":"104D3E3","s":"__wt_panic_func","s+":"114"}}} {"t":{"$date":"2024-11-27T12:10:04.823+00:00"},"s":"I", "c":"CONTROL", "id":31445, "ctx":"Checkpointer","msg":"Frame","attr":{"frame":{"a":"55D41524FA8D","b":"55D414206000","o":"1049A8D","s":"__wt_ext_map_windows_error","s+":"25CA"}}} {"t":{"$date":"2024-11-27T12:10:04.823+00:00"},"s":"I", "c":"CONTROL", "id":31445, "ctx":"Checkpointer","msg":"Frame","attr":{"frame":{"a":"55D415B7EDFA","b":"55D414206000","o":"1978DFA","s":"__wt_sync_file","s+":"6AA"}}} {"t":{"$date":"2024-11-27T12:10:04.823+00:00"},"s":"I", "c":"CONTROL", "id":31445, "ctx":"Checkpointer","msg":"Frame","attr":{"frame":{"a":"55D415B0813B","b":"55D414206000","o":"190213B","s":"__wt_checkpoint_tree_reconcile_update","s+":"1CB"}}} {"t":{"$date":"2024-11-27T12:10:04.823+00:00"},"s":"I", "c":"CONTROL", "id":31445, "ctx":"Checkpointer","msg":"Frame","attr":{"frame":{"a":"55D415B0923F","b":"55D414206000","o":"190323F","s":"__wt_checkpoint_sync","s+":"99F"}}} {"t":{"$date":"2024-11-27T12:10:04.823+00:00"},"s":"I", "c":"CONTROL", "id":31445, "ctx":"Checkpointer","msg":"Frame","attr":{"frame":{"a":"55D415B0AB76","b":"55D414206000","o":"1904B76","s":"__wt_txn_checkpoint","s+":"246"}}} {"t":{"$date":"2024-11-27T12:10:04.823+00:00"},"s":"I", "c":"CONTROL", "id":31445, "ctx":"Checkpointer","msg":"Frame","attr":{"frame":{"a":"55D4152526EF","b":"55D414206000","o":"104C6EF","s":"__wt_session_notsup","s+":"FCC"}}} {"t":{"$date":"2024-11-27T12:10:04.823+00:00"},"s":"I", "c":"CONTROL", "id":31445, "ctx":"Checkpointer","msg":"Frame","attr":{"frame":{"a":"55D4159EF586","b":"55D414206000","o":"17E9586","s":"_ZN5mongo18WiredTigerKVEngine11_checkpointEP12__wt_sessionb","s+":"46"}}} {"t":{"$date":"2024-11-27T12:10:04.823+00:00"},"s":"I", "c":"CONTROL", "id":31445, "ctx":"Checkpointer","msg":"Frame","attr":{"frame":{"a":"55D4159FC988","b":"55D414206000","o":"17F6988","s":"_ZN5mongo18WiredTigerKVEngine11_checkpointEP12__wt_session","s+":"2B8"}}} {"t":{"$date":"2024-11-27T12:10:04.823+00:00"},"s":"I", "c":"CONTROL", "id":31445, "ctx":"Checkpointer","msg":"Frame","attr":{"frame":{"a":"55D4159FD050","b":"55D414206000","o":"17F7050","s":"_ZN5mongo18WiredTigerKVEngine10checkpointEv","s+":"40"}}} {"t":{"$date":"2024-11-27T12:10:04.823+00:00"},"s":"I", "c":"CONTROL", "id":31445, "ctx":"Checkpointer","msg":"Frame","attr":{"frame":{"a":"55D4169A2459","b":"55D414206000","o":"279C459","s":"_ZN5mongo12Checkpointer3runEv","s+":"E59"}}} {"t":{"$date":"2024-11-27T12:10:04.823+00:00"},"s":"I", "c":"CONTROL", "id":31445, "ctx":"Checkpointer","msg":"Frame","attr":{"frame":{"a":"55D4181DEE32","b":"55D414206000","o":"3FD8E32","s":"_ZN5mongo13BackgroundJob7jobBodyEv","s+":"E2"}}} {"t":{"$date":"2024-11-27T12:10:04.823+00:00"},"s":"I", "c":"CONTROL", "id":31445, "ctx":"Checkpointer","msg":"Frame","attr":{"frame":{"a":"55D4181DF54C","b":"55D414206000","o":"3FD954C","s":"_ZN5mongo13BackgroundJob7jobBodyEv","s+":"7FC"}}} {"t":{"$date":"2024-11-27T12:10:04.823+00:00"},"s":"I", "c":"CONTROL", "id":31445, "ctx":"Checkpointer","msg":"Frame","attr":{"frame":{"a":"7F3F1C6B0B23","b":"7F3F1C5EE000","o":"C2B23","s":"_ZNKSt10error_code23default_error_conditionEv","s+":"33"}}} {"t":{"$date":"2024-11-27T12:10:04.823+00:00"},"s":"I", "c":"CONTROL", "id":31445, "ctx":"Checkpointer","msg":"Frame","attr":{"frame":{"a":"7F3F1BE3B1DA","b":"7F3F1BE33000","o":"81DA","s":"start_thread","s+":"EA"}}} {"t":{"$date":"2024-11-27T12:10:04.823+00:00"},"s":"I", "c":"CONTROL", "id":31445, "ctx":"Checkpointer","msg":"Frame","attr":{"frame":{"a":"7F3F1BA968D3","b":"7F3F1BA5D000","o":"398D3","s":"clone","s+":"43"}}}

AssertionError: assert 748 == 1500 + where 748 = count_documents({}) + where count_documents = Collection(Database(MongoClient(host=['mongos:27017'], document_class=dict, tz_aware=False, connect=True), 'test'), 'test').count_documents

AssertionError: assert 1051 == 1500 + where 1051 = count_documents({}) + where count_documents = Collection(Database(MongoClient(host=['mongos:27017'], document_class=dict, tz_aware=False, connect=True), 'test'), 'test').count_documents

Process completed with exit code 1.

AssertionError: Starting restore 2024-11-27T12:09:28.836651937Z to point-in-time 2024-11-27T12:08:05 from '2024-11-27T12:04:26Z'..........................Started physical restore. Waiting to finish....................Error: operation failed with: replay pitr oplog: reply oplog: replay chunk 1732709068.1732709132: apply oplog for chunk: applying an entry: op: {"Timestamp":{"T":1732709079,"I":6},"Term":1,"Hash":null,"Version":2,"Operation":"u","Namespace":"config.settings","Object":[{"Key":"$v","Value":2},{"Key":"diff","Value":[{"Key":"u","Value":[{"Key":"mode","Value":"full"},{"Key":"stopped","Value":false}]}]}],"Query":[{"Key":"_id","Value":"balancer"}],"UI":{"Subtype":4,"Data":"EJ/Apfn7Ryefszy31e0GXg=="},"LSID":null,"TxnNumber":null,"PrevOpTime":null,"MultiOpType":null} | merr <nil>: applyOps: (NotWritablePrimary) not primary {"t":{"$date":"2024-11-27T12:10:13.524+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":"2024-11-27T12:10:13.525+00:00"},"s":"I", "c":"CONTROL", "id":5945603, "svc":"-", "ctx":"main","msg":"Multi threading initialized"} {"t":{"$date":"2024-11-27T12:10:13.526+00:00"},"s":"I", "c":"NETWORK", "id":4648601, "svc":"-", "ctx":"main","msg":"Implicit TCP FastOpen unavailable. If TCP FastOpen is required, set at least one of the related parameters","attr":{"relatedParameters":["tcpFastOpenServer","tcpFastOpenClient","tcpFastOpenQueueSize"]}} {"t":{"$date":"2024-11-27T12:10:13.526+00:00"},"s":"I", "c":"NETWORK", "id":4915701, "svc":"-", "ctx":"main","msg":"Initialized wire specification","attr":{"spec":{"incomingExternalClient":{"minWireVersion":0,"maxWireVersion":25},"incomingInternalClient":{"minWireVersion":0,"maxWireVersion":25},"outgoing":{"minWireVersion":6,"maxWireVersion":25},"isInternalClient":true}}} {"t":{"$date":"2024-11-27T12:10:13.527+00:00"},"s":"I", "c":"REPL", "id":5123008, "svc":"-", "ctx":"main","msg":"Successfully registered PrimaryOnlyService","attr":{"service":"ReshardingCoordinatorService","namespace":"config.reshardingOperations"}} {"t":{"$date":"2024-11-27T12:10:13.527+00:00"},"s":"I", "c":"REPL", "id":5123008, "svc":"-", "ctx":"main","msg":"Successfully registered PrimaryOnlyService","attr":{"service":"ConfigsvrCoordinatorService","namespace":"config.sharding_configsvr_coordinators"}} {"t":{"$date":"2024-11-27T12:10:13.527+00:00"},"s":"I", "c":"REPL", "id":5123008, "svc":"-", "ctx":"main","msg":"Successfully registered PrimaryOnlyService","attr":{"service":"RenameCollectionParticipantService","namespace":"config.localRenameParticipants"}} {"t":{"$date":"2024-11-27T12:10:13.527+00:00"},"s":"I", "c":"REPL", "id":5123008, "svc":"-", "ctx":"main","msg":"Successfully registered PrimaryOnlyService","attr":{"service":"ShardingDDLCoordinator","namespace":"config.system.sharding_ddl_coordinators"}} {"t":{"$date":"2024-11-27T12:10:13.527+00:00"},"s":"I", "c":"REPL", "id":5123008, "svc":"-", "ctx":"main","msg":"Successfully registered PrimaryOnlyService","attr":{"service":"ReshardingDonorService","namespace":"config.localReshardingOperations.donor"}} {"t":{"$date":"2024-11-27T12:10:13.527+00:00"},"s":"I", "c":"REPL", "id":5123008, "svc":"-", "ctx":"main","msg":"Successfully registered PrimaryOnlyService","attr":{"service":"ReshardingRecipientService","namespace":"config.localReshardingOperations.recipient"}} {"t":{"$date":"2024-11-27T12:10:13.527+00:00"},"s":"I", "c":"REPL", "id":5123008, "svc":"-", "ctx":"main","msg":"Successfully registered PrimaryOnlyService","attr":{"service":"MultiUpdateCoordinatorService","namespace":"config.localMigrationBlockingOperations.multiUpdateCoordinators"}} {"t":{"$date":"2024-11-27T12:10:13.527+00:00"},"s":"I", "c":"TENANT_M", "id":7091600, "svc":"-", "ctx":"main","msg":"Starting TenantMigrationAccessBlockerRegistry"} {"t":{"$date":"2024-11-27T12:10:13.527+00:00"},"s":"I", "c":"CONTROL", "id":4615611, "svc":"S", "ctx":"initandlisten","msg":"MongoDB starting","attr":{"pid":1968,"port":28073,"dbPath":"/var/lib/mongo","architecture":"64-bit","host":"rscfg01"}} {"t":{"$date":"2024-11-27T12:10:13.527+00:00"},"s":"I", "c":"CONTROL", "id":23403, "svc":"S", "ctx":"initandlisten","msg":"Build Info","attr":{"buildInfo":{"version":"8.0.1-1","gitVersion":"88788b464f844b9120ed4a22ebe72cbfa873626c","openSSLVersion":"OpenSSL 1.1.1k FIPS 25 Mar 2021","modules":[],"proFeatures":[],"allocator":"tcmalloc-google","environment":{"distarch":"x86_64","target_arch":"x86_64"}}}} {"t":{"$date":"2024-11-27T12:10:13.527+00:00"},"s":"I", "c":"CONTROL", "id":51765, "svc":"S", "ctx":"initandlisten","msg":"Operating System","attr":{"os":{"name":"Oracle Linux Server release 8.10","version":"Kernel 6.5.0-1025-azure"}}} {"t":{"$date":"2024-11-27T12:10:13.527+00:00"},"s":"I", "c":"CONTROL", "id":21951, "svc":"S", "ctx":"initandlisten","msg":"Options set by command line","attr":{"options":{"config":"/tmp/pbmMongdTmpConf2991990179","net":{"bindIp":"localhost","port":28073},"replication":{"replSet":"rscfg"},"setParameter":{"disableLogicalSessionCacheRefresh":"true","takeUnstableCheckpointOnShutdown":"true"},"sharding":{"clusterRole":"configsvr"},"storage":{"dbPath":"/var/lib/mongo","directoryPerDB":false,"wiredTiger":{"collectionConfig":{"blockCompressor":"snappy"},"engineConfig":{"directoryForIndexes":false,"journalCompressor":"snappy"},"indexConfig":{"prefixCompression":true}}},"systemLog":{"destination":"file","path":"/var/lib/mongo/pbm.restore.log"}}}} {"t":{"$date":"2024-11-27T12:10:13.528+00:00"},"s":"I", "c":"STORAGE", "id":22270, "svc":"S", "ctx":"initandlisten","msg":"Storage engine to use detected by data files","attr":{"dbpath":"/var/lib/mongo","storageEngine":"wiredTiger"}} {"t":{"$date":"2024-11-27T12:10:13.528+00:00"},"s":"I", "c":"STORAGE", "id":22315, "svc":"S", "ctx":"initandlisten","msg":"Opening WiredTiger","attr":{"config":"create,cache_size=7478M,session_max=33000,eviction=(threads_min=4,threads_max=4),config_base=false,statistics=(fast),log=(enabled=true,remove=true,path=journal,compressor=snappy),builtin_extension_config=(zstd=(compression_level=6)),file_manager=(close_idle_time=600,close_scan_interval=10,close_handle_minimum=2000),statistics_log=(wait=0),json_output=(error,message),verbose=[recovery_progress:1,checkpoint_progress:1,compact_progress:1,backup:0,checkpoint:0,compact:0,evict:0,history_store:0,recovery:0,rts:0,salvage:0,tiered:0,timestamp:0,transaction:0,verify:0,log:0],prefetch=(available=true,default=false),"}} {"t":{"$date":"2024-11-27T12:10:13.673+00:00"},"s":"I", "c":"WTRECOV", "id":22430, "svc":"S", "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":{"ts_sec":1732709413,"ts_usec":673777,"thread":"1968:0x7f20b3eba180","session_name":"txn-recover","category":"WT_VERB_RECOVERY_PROGRESS","category_id":34,"verbose_level":"DEBUG_1","verbose_level_id":1,"msg":"Recovering log 5 through 6"}}} {"t":{"$date":"2024-11-27T12:10:13.701+00:00"},"s":"I", "c":"WTRECOV", "id":22430, "svc":"S", "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":{"ts_sec":1732709413,"ts_usec":701123,"thread":"1968:0x7f20b3eba180","session_name":"txn-recover","category":"WT_VERB_RECOVERY_PROGRESS","category_id":34,"verbose_level":"DEBUG_1","verbose_level_id":1,"msg":"Recovering log 6 through 6"}}} {"t":{"$date":"2024-11-27T12:10:13.754+00:00"},"s":"I", "c":"WTRECOV", "id":22430, "svc":"S", "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":{"ts_sec":1732709413,"ts_usec":754813,"thread":"1968:0x7f20b3eba180","session_name":"txn-recover","category":"WT_VERB_RECOVERY_PROGRESS","category_id":34,"verbose_level":"DEBUG_1","verbose_level_id":1,"msg":"Main recovery loop: starting at 5/176768 to 6/256"}}} {"t":{"$date":"2024-11-27T12:10:13.801+00:00"},"s":"I", "c":"WTRECOV", "id":22430, "svc":"S", "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":{"ts_sec":1732709413,"ts_usec":801128,"thread":"1968:0x7f20b3eba180","session_name":"txn-recover","category":"WT_VERB_RECOVERY_PROGRESS","category_id":34,"verbose_level":"DEBUG_1","verbose_level_id":1,"msg":"Recovering log 5 through 6"}}} {"t":{"$date":"2024-11-27T12:10:13.835+00:00"},"s":"I", "c":"WTRECOV", "id":22430, "svc":"S", "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":{"ts_sec":1732709413,"ts_usec":835191,"thread":"1968:0x7f20b3eba180","session_name":"txn-recover","category":"WT_VERB_RECOVERY_PROGRESS","category_id":34,"verbose_level":"DEBUG_1","verbose_level_id":1,"msg":"Recovering log 6 through 6"}}} {"t":{"$date":"2024-11-27T12:10:13.857+00:00"},"s":"I", "c":"WTRECOV", "id":22430, "svc":"S", "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":{"ts_sec":1732709413,"ts_usec":856985,"thread":"1968:0x7f20b3eba180","session_name":"txn-recover","category":"WT_VERB_RECOVERY_PROGRESS","category_id":34,"verbose_level":"DEBUG_1","verbose_level_id":1,"msg":"recovery log replay has successfully finished and ran for 183 milliseconds"}}} {"t":{"$date":"2024-11-27T12:10:13.857+00:00"},"s":"I", "c":"WTRECOV", "id":22430, "svc":"S", "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":{"ts_sec":1732709413,"ts_usec":857070,"thread":"1968:0x7f20b3eba180","session_name":"txn-recover","category":"WT_VERB_RECOVERY_PROGRESS","category_id":34,"verbose_level":"DEBUG_1","verbose_level_id":1,"msg":"Set global recovery timestamp: (0, 0)"}}} {"t":{"$date":"2024-11-27T12:10:13.857+00:00"},"s":"I", "c":"WTRECOV", "id":22430, "svc":"S", "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":{"ts_sec":1732709413,"ts_usec":857095,"thread":"1968:0x7f20b3eba180","session_name":"txn-recover","category":"WT_VERB_RECOVERY_PROGRESS","category_id":34,"verbose_level":"DEBUG_1","verbose_level_id":1,"msg":"Set global oldest timestamp: (0, 0)"}}} {"t":{"$date":"2024-11-27T12:10:13.859+00:00"},"s":"I", "c":"WTRECOV", "id":22430, "svc":"S", "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":{"ts_sec":1732709413,"ts_usec":859081,"thread":"1968:0x7f20b3eba180","session_name":"txn-recover","category":"WT_VERB_RECOVERY_PROGRESS","category_id":34,"verbose_level":"DEBUG_1","verbose_level_id":1,"msg":"recovery rollback to stable has successfully finished and ran for 1 milliseconds"}}} {"t":{"$date":"2024-11-27T12:10:13.862+00:00"},"s":"I", "c":"WTCHKPT", "id":22430, "svc":"S", "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":{"ts_sec":1732709413,"ts_usec":861985,"thread":"1968:0x7f20b3eba180","session_name":"WT_SESSION.checkpoint","category":"WT_VERB_CHECKPOINT_PROGRESS","category_id":7,"verbose_level":"DEBUG_1","verbose_level_id":1,"msg":"saving checkpoint snapshot min: 1, snapshot max: 1 snapshot count: 0, oldest timestamp: (0, 0) , meta checkpoint timestamp: (0, 0) base write gen: 70"}}} {"t":{"$date":"2024-11-27T12:10:13.864+00:00"},"s":"I", "c":"WTRECOV", "id":22430, "svc":"S", "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":{"ts_sec":1732709413,"ts_usec":864134,"thread":"1968:0x7f20b3eba180","session_name":"txn-recover","category":"WT_VERB_RECOVERY_PROGRESS","category_id":34,"verbose_level":"DEBUG_1","verbose_level_id":1,"msg":"recovery checkpoint has successfully finished and ran for 4 milliseconds"}}} {"t":{"$date":"2024-11-27T12:10:13.864+00:00"},"s":"I", "c":"WTRECOV", "id":22430, "svc":"S", "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":{"ts_sec":1732709413,"ts_usec":864188,"thread":"1968:0x7f20b3eba180","session_name":"txn-recover","category":"WT_VERB_RECOVERY_PROGRESS","category_id":34,"verbose_level":"DEBUG_1","verbose_level_id":1,"msg":"recovery was completed successfully and took 190ms, including 183ms for the log replay, 1ms for the rollback to stable, and 4ms for the checkpoint."}}} {"t":{"$date":"2024-11-27T12:10:13.866+00:00"},"s":"I", "c":"STORAGE", "id":4795906, "svc":"S", "ctx":"initandlisten","msg":"WiredTiger opened","attr":{"durationMillis":338}} {"t":{"$date":"2024-11-27T12:10:13.866+00:00"},"s":"I", "c":"RECOVERY", "id":23987, "svc":"S", "ctx":"initandlisten","msg":"WiredTiger recoveryTimestamp","attr":{"recoveryTimestamp":{"$timestamp":{"t":0,"i":0}}}} {"t":{"$date":"2024-11-27T12:10:13.874+00:00"},"s":"I", "c":"STORAGE", "id":7393203, "svc":"S", "ctx":"initandlisten","msg":"The size storer reports that the collection contains","attr":{"numRecords":223,"dataSize":85571}} {"t":{"$date":"2024-11-27T12:10:13.874+00:00"},"s":"I", "c":"STORAGE", "id":7393212, "svc":"S", "ctx":"initandlisten","msg":"Scanning collection to determine where to place markers for truncation","attr":{"namespace":"local.oplog.rs"}} {"t":{"$date":"2024-11-27T12:10:13.874+00:00"},"s":"I", "c":"STORAGE", "id":22382, "svc":"S", "ctx":"initandlisten","msg":"WiredTiger record store oplog processing finished","attr":{"durationMillis":0}} {"t":{"$date":"2024-11-27T12:10:13.915+00:00"},"s":"W", "c":"CONTROL", "id":22120, "svc":"S", "ctx":"initandlisten","msg":"Access control is not enabled for the database. Read and write access to data and configuration is unrestricted. You can use percona-server-mongodb-enable-auth.sh to fix it","tags":["startupWarnings"]} {"t":{"$date":"2024-11-27T12:10:13.915+00:00"},"s":"W", "c":"CONTROL", "id":9068900, "svc":"S", "ctx":"initandlisten","msg":"For customers running the current memory allocator, we suggest changing the contents of the following sysfsFile","attr":{"allocator":"tcmalloc-google","sysfsFile":"/sys/kernel/mm/transparent_hugepage/defrag","currentValue":"madvise","desiredValue":"defer+madvise"},"tags":["startupWarnings"]} {"t":{"$date":"2024-11-27T12:10:13.915+00:00"},"s":"W", "c":"CONTROL", "id":8640302, "svc":"S", "ctx":"initandlisten","msg":"We suggest setting the contents of sysfsFile to 0.","attr":{"sysfsFile":"/sys/kernel/mm/transparent_hugepage/khugepaged/max_ptes_none","currentValue":511},"tags":["startupWarnings"]} {"t":{"$date":"2024-11-27T12:10:13.915+00:00"},"s":"W", "c":"NETWORK", "id":5123300, "svc":"S", "ctx":"initandlisten","msg":"vm.max_map_count is too low","attr":{"currentValue":262144,"recommendedMinimum":1677720,"maxConns":838860},"tags":["startupWarnings"]} {"t":{"$date":"2024-11-27T12:10:13.916+00:00"},"s":"W", "c":"CONTROL", "id":8386700, "svc":"S", "ctx":"initandlisten","msg":"We suggest setting swappiness to 0 or 1, as swapping can cause performance problems.","attr":{"sysfsFile":"/proc/sys/vm/swappiness","currentValue":60},"tags":["startupWarnings"]} {"t":{"$date":"2024-11-27T12:10:13.939+00:00"},"s":"I", "c":"NETWORK", "id":4915702, "svc":"S", "ctx":"initandlisten","msg":"Updated wire specification","attr":{"oldSpec":{"incomingExternalClient":{"minWireVersion":0,"maxWireVersion":25},"incomingInternalClient":{"minWireVersion":0,"maxWireVersion":25},"outgoing":{"minWireVersion":6,"maxWireVersion":25},"isInternalClient":true},"newSpec":{"incomingExternalClient":{"minWireVersion":0,"maxWireVersion":25},"incomingInternalClient":{"minWireVersion":25,"maxWireVersion":25},"outgoing":{"minWireVersion":25,"maxWireVersion":25},"isInternalClient":true}}} {"t":{"$date":"2024-11-27T12:10:13.939+00:00"},"s":"I", "c":"REPL", "id":5853300, "svc":"S", "ctx":"initandlisten","msg":"current featureCompatibilityVersion value","attr":{"featureCompatibilityVersion":"8.0","context":"startup"}} {"t":{"$date":"2024-11-27T12:10:13.940+00:00"},"s":"I", "c":"STORAGE", "id":5071100, "svc":"S", "ctx":"initandlisten","msg":"Clearing temp directory"} {"t":{"$date":"2024-11-27T12:10:13.944+00:00"},"s":"W", "c":"QUERY", "id":3216000, "svc":"S", "ctx":"initandlisten","msg":"$jsonSchema validator does not allow '_id' field. This validator will reject all documents, consider adding '_id' to the allowed fields."} {"t":{"$date":"2024-11-27T12:10:13.944+00:00"},"s":"W", "c":"QUERY", "id":3216000, "svc":"S", "ctx":"initandlisten","msg":"$jsonSchema validator does not allow '_id' field. This validator will reject all documents, consider adding '_id' to the allowed fields."} {"t":{"$date":"2024-11-27T12:10:13.973+00:00"},"s":"I", "c":"CONTROL", "id":20536, "svc":"S", "ctx":"initandlisten","msg":"Flow Control is enabled on this deployment"} {"t":{"$date":"2024-11-27T12:10:13.973+00:00"},"s":"I", "c":"FTDC", "id":20625, "svc":"S", "ctx":"initandlisten","msg":"Initializing full-time diagnostic data capture","attr":{"dataDirectory":"/var/lib/mongo/diagnostic.data"}} {"t":{"$date":"2024-11-27T12:10:13.976+00:00"},"s":"I", "c":"REPL", "id":40440, "svc":"S", "ctx":"initandlisten","msg":"Starting the TopologyVersionObserver"} {"t":{"$date":"2024-11-27T12:10:13.976+00:00"},"s":"I", "c":"REPL", "id":40445, "svc":"S", "ctx":"TopologyVersionObserver","msg":"Started TopologyVersionObserver"} {"t":{"$date":"2024-11-27T12:10:13.978+00:00"},"s":"I", "c":"-", "id":4939300, "svc":"S", "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":"2024-11-27T12:10:13.978+00:00"},"s":"I", "c":"SHARDING", "id":22727, "svc":"-", "ctx":"ShardRegistryUpdater","msg":"Error running periodic reload of shard registry","attr":{"error":"NotYetInitialized: Config shard has not been set up yet","shardRegistryReloadIntervalSeconds":30}} {"t":{"$date":"2024-11-27T12:10:13.978+00:00"},"s":"W", "c":"SHARDING", "id":7012500, "svc":"S", "ctx":"QueryAnalysisConfigurationsRefresher","msg":"Failed to refresh query analysis configurations, will try again at the next interval","attr":{"error":"NotYetInitialized: Config shard has not been set up yet"}} {"t":{"$date":"2024-11-27T12:10:13.978+00:00"},"s":"I", "c":"SHARDING", "id":22072, "svc":"S", "ctx":"initandlisten","msg":"Initializing sharding state","attr":{"initialShardIdentity":{"shardName":"config","clusterId":{"$oid":"67470ab818fc0b93d49e9e9b"},"configsvrConnectionString":"rscfg/rscfg01:27017"}}} {"t":{"$date":"2024-11-27T12:10:13.978+00:00"},"s":"I", "c":"SHARDING", "id":22071, "svc":"S", "ctx":"initandlisten","msg":"Finished initializing sharding components","attr":{"memberState":"secondary"}} {"t":{"$date":"2024-11-27T12:10:13.978+00:00"},"s":"I", "c":"SHARDING", "id":22081, "svc":"S", "ctx":"initandlisten","msg":"Sharding status of the node recovered successfully","attr":{"role":"67470ab818fc0b93d49e9e9b : ClusterRole{shard|config|router} : rscfg/rscfg01:27017 : config"}} {"t":{"$date":"2024-11-27T12:10:13.978+00:00"},"s":"I", "c":"REPL", "id":6015317, "svc":"S", "ctx":"initandlisten","msg":"Setting new configuration state","attr":{"newState":"ConfigStartingUp","oldState":"ConfigPreStart"}} {"t":{"$date":"2024-11-27T12:10:13.978+00:00"},"s":"I", "c":"REPL", "id":6005300, "svc":"S", "ctx":"initandlisten","msg":"Starting up replica set aware services"} {"t":{"$date":"2024-11-27T12:10:13.980+00:00"},"s":"I", "c":"REPL", "id":4280500, "svc":"S", "ctx":"initandlisten","msg":"Attempting to create internal replication collections"} {"t":{"$date":"2024-11-27T12:10:13.982+00:00"},"s":"I", "c":"REPL", "id":4280501, "svc":"S", "ctx":"initandlisten","msg":"Attempting to load local voted for document"} {"t":{"$date":"2024-11-27T12:10:13.982+00:00"},"s":"I", "c":"REPL", "id":21311, "svc":"S", "ctx":"initandlisten","msg":"Did not find local initialized voted for document at startup"} {"t":{"$date":"2024-11-27T12:10:13.982+00:00"},"s":"I", "c":"REPL", "id":4280502, "svc":"S", "ctx":"initandlisten","msg":"Searching for local Rollback ID document"} {"t":{"$date":"2024-11-27T12:10:13.983+00:00"},"s":"I", "c":"REPL", "id":21529, "svc":"S", "ctx":"initandlisten","msg":"Initializing rollback ID","attr":{"rbid":1}} {"t":{"$date":"2024-11-27T12:10:13.983+00:00"},"s":"I", "c":"REPL", "id":4280504, "svc":"S", "ctx":"initandlisten","msg":"Cleaning up any partially applied oplog batches & reading last op from oplog"} {"t":{"$date":"2024-11-27T12:10:13.984+00:00"},"s":"I", "c":"SHARDING", "id":22072, "svc":"S", "ctx":"initandlisten","msg":"Initializing sharding state","attr":{"initialShardIdentity":{"shardName":"config","clusterId":{"$oid":"67470ab818fc0b93d49e9e9b"},"configsvrConnectionString":"rscfg/rscfg01:27017"}}} {"t":{"$date":"2024-11-27T12:10:13.984+00:00"},"s":"I", "c":"CONTROL", "id":6608200, "svc":"S", "ctx":"initandlisten","msg":"Initializing cluster server parameters from disk"} {"t":{"$date":"2024-11-27T12:10:13.985+00:00"},"s":"I", "c":"REPL", "id":21546, "svc":"S", "ctx":"initandlisten","msg":"Recovering from an unstable checkpoint","attr":{"topOfOplog":{"ts":{"$timestamp":{"t":1732709068,"i":1}},"t":1},"appliedThrough":{"ts":{"$timestamp":{"t":0,"i":0}},"t":-1}}} {"t":{"$date":"2024-11-27T12:10:13.985+00:00"},"s":"I", "c":"REPL", "id":21547, "svc":"S", "ctx":"initandlisten","msg":"No oplog entries to apply for recovery. appliedThrough is null"} {"t":{"$date":"2024-11-27T12:10:13.987+00:00"},"s":"I", "c":"WTCHKPT", "id":22430, "svc":"S", "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":{"ts_sec":1732709413,"ts_usec":987171,"thread":"1968:0x7f20b3eba180","session_name":"WT_SESSION.checkpoint","category":"WT_VERB_CHECKPOINT_PROGRESS","category_id":7,"verbose_level":"DEBUG_1","verbose_level_id":1,"msg":"saving checkpoint snapshot min: 103, snapshot max: 103 snapshot count: 0, oldest timestamp: (0, 0) , meta checkpoint timestamp: (0, 0) base write gen: 70"}}} {"t":{"$date":"2024-11-27T12:10:13.990+00:00"},"s":"I", "c":"REPL", "id":4280505, "svc":"S", "ctx":"initandlisten","msg":"Creating any necessary TenantMigrationAccessBlockers for unfinished migrations"} {"t":{"$date":"2024-11-27T12:10:13.990+00:00"},"s":"I", "c":"TENANT_M", "id":6531504, "svc":"S", "ctx":"initandlisten","msg":"Clearing serverless operation lock registry on shutdown","attr":{"ns":null}} {"t":{"$date":"2024-11-27T12:10:13.990+00:00"},"s":"I", "c":"REPL", "id":4280506, "svc":"S", "ctx":"initandlisten","msg":"Reconstructing prepared transactions"} {"t":{"$date":"2024-11-27T12:10:13.991+00:00"},"s":"I", "c":"REPL", "id":4280507, "svc":"S", "ctx":"initandlisten","msg":"Loaded replica set config, scheduled callback to set local config"} {"t":{"$date":"2024-11-27T12:10:13.991+00:00"},"s":"I", "c":"REPL", "id":4280508, "svc":"S", "ctx":"ReplCoord-0","msg":"Attempting to set local replica set config; validating config for startup"} {"t":{"$date":"2024-11-27T12:10:13.991+00:00"},"s":"I", "c":"STORAGE", "id":22262, "svc":"S", "ctx":"initandlisten","msg":"Timestamp monitor starting"} {"t":{"$date":"2024-11-27T12:10:13.991+00:00"},"s":"I", "c":"STORAGE", "id":7333401, "svc":"S", "ctx":"initandlisten","msg":"Starting the DiskSpaceMonitor"} {"t":{"$date":"2024-11-27T12:10:13.992+00:00"},"s":"I", "c":"QUERY", "id":7080100, "svc":"-", "ctx":"ChangeStreamExpiredPreImagesRemover","msg":"Starting Change Stream Expired Pre-images Remover thread"} {"t":{"$date":"2024-11-27T12:10:13.992+00:00"},"s":"I", "c":"-", "id":7658604, "svc":"S", "ctx":"ChangeStreamExpiredPreImagesRemover","msg":"Decided on initial creation method for pre-images truncate markers initialization","attr":{"initialCreationMethod":"emptyCollection","dataSize":0,"numRecords":0,"preImagesCollectionUUID":{"uuid":{"$uuid":"854a164f-5833-4ca1-81df-762e11101aa8"}},"tenantId":null}} {"t":{"$date":"2024-11-27T12:10:13.992+00:00"},"s":"I", "c":"NETWORK", "id":23015, "svc":"-", "ctx":"listener","msg":"Listening on","attr":{"address":"/tmp/mongodb-28073.sock"}} {"t":{"$date":"2024-11-27T12:10:13.992+00:00"},"s":"I", "c":"NETWORK", "id":23015, "svc":"-", "ctx":"listener","msg":"Listening on","attr":{"address":"127.0.0.1:28073"}} {"t":{"$date":"2024-11-27T12:10:13.992+00:00"},"s":"I", "c":"NETWORK", "id":23016, "svc":"-", "ctx":"listener","msg":"Waiting for connections","attr":{"port":28073,"ssl":"off"}} {"t":{"$date":"2024-11-27T12:10:13.992+00:00"},"s":"I", "c":"CONTROL", "id":8423403, "svc":"S", "ctx":"initandlisten","msg":"mongod startup complete","attr":{"Summary of time elapsed":{"Startup from clean shutdown?":true,"Statistics":{"Set up periodic runner":"0 ms","Set up online certificate status protocol manager":"0 ms","Transport layer setup":"0 ms","Run initial syncer crash recovery":"0 ms","Create storage engine lock file in the data directory":"0 ms","Get metadata describing storage engine":"0 ms","Validate options in metadata against current startup options":"0 ms","Create storage engine":"378 ms","Write current PID to file":"0 ms","Write a new metadata for storage engine":"0 ms","Initialize FCV before rebuilding indexes":"23 ms","Drop abandoned idents and get back indexes that need to be rebuilt or builds that need to be restarted":"0 ms","Rebuild indexes for collections":"0 ms","Build user and roles graph":"0 ms","Verify indexes for admin.system.users collection":"0 ms","Verify indexes for admin.system.roles collection":"0 ms","Set up the background thread pool responsible for waiting for opTimes to be majority committed":"0 ms","Initialize the sharding components for a config server":"2 ms","Initialize information needed to make a mongod instance shard aware":"0 ms","Load global settings from config server":"0 ms","Start up the replication coordinator":"13 ms","Create an oplog view for tenant migrations":"0 ms","Ensure the change stream collections on startup contain consistent data":"0 ms","Write startup options to the audit log":"0 ms","Start transport layer":"0 ms","_initAndListen total elapsed time":"465 ms"}}}} {"t":{"$date":"2024-11-27T12:10:13.992+00:00"},"s":"I", "c":"NETWORK", "id":22943, "svc":"-", "ctx":"listener","msg":"Connection accepted","attr":{"remote":"127.0.0.1:59038","uuid":{"uuid":{"$uuid":"29ec3709-2d05-4461-b9cf-74f0ded253d5"}},"connectionId":2,"connectionCount":1}} {"t":{"$date":"2024-11-27T12:10:13.992+00:00"},"s":"I", "c":"-", "id":9023600, "svc":"S", "ctx":"ChangeStreamExpiredPreImagesRemover","msg":"Completed initialization of pre-image tenant truncate markers","attr":{"preImagesCollectionUUID":{"uuid":{"$uuid":"854a164f-5833-4ca1-81df-762e11101aa8"}},"tenantId":null}} {"t":{"$date":"2024-11-27T12:10:13.992+00:00"},"s":"I", "c":"NETWORK", "id":6788700, "svc":"S", "ctx":"conn2","msg":"Received first command on ingress connection since session start or auth handshake","attr":{"elapsedMillis":0}} {"t":{"$date":"2024-11-27T12:10:13.992+00:00"},"s":"I", "c":"REPL", "id":4280509, "svc":"S", "ctx":"ReplCoord-0","msg":"Local configuration validated for startup"} {"t":{"$date":"2024-11-27T12:10:13.992+00:00"},"s":"I", "c":"REPL", "id":6015317, "svc":"S", "ctx":"ReplCoord-0","msg":"Setting new configuration state","attr":{"newState":"ConfigSteady","oldState":"ConfigStartingUp"}} {"t":{"$date":"2024-11-27T12:10:13.992+00:00"},"s":"I", "c":"SHARDING", "id":7063400, "svc":"S", "ctx":"ReplCoord-0","msg":"Updating implicit default writeConcern majority","attr":{"newImplicitDefaultWCMajority":true}} {"t":{"$date":"2024-11-27T12:10:13.992+00:00"},"s":"I", "c":"REPL", "id":21392, "svc":"S", "ctx":"ReplCoord-0","msg":"New replica set config in use","attr":{"config":{"_id":"rscfg","version":1,"members":[{"_id":0,"host":"localhost:28073","arbiterOnly":false,"buildIndexes":true,"hidden":false,"priority":1,"tags":{},"secondaryDelaySecs":0,"votes":1}],"configsvr":true,"protocolVersion":1,"writeConcernMajorityJournalDefault":true,"settings":{"chainingAllowed":true,"heartbeatIntervalMillis":2000,"heartbeatTimeoutSecs":10,"electionTimeoutMillis":10000,"catchUpTimeoutMillis":-1,"catchUpTakeoverDelayMillis":30000,"getLastErrorModes":{},"getLastErrorDefaults":{"w":1,"wtimeout":0}}}}} {"t":{"$date":"2024-11-27T12:10:13.992+00:00"},"s":"I", "c":"REPL", "id":21393, "svc":"S", "ctx":"ReplCoord-0","msg":"Found self in config","attr":{"hostAndPort":"localhost:28073"}} {"t":{"$date":"2024-11-27T12:10:13.992+00:00"},"s":"I", "c":"REPL", "id":21358, "svc":"S", "ctx":"ReplCoord-0","msg":"Replica set state transition","attr":{"newState":"STARTUP2","oldState":"STARTUP"}} {"t":{"$date":"2024-11-27T12:10:13.993+00:00"},"s":"I", "c":"REPL", "id":21827, "svc":"S", "ctx":"ReplCoord-0","msg":"Updating term","attr":{"oldTerm":0,"newTerm":1}} {"t":{"$date":"2024-11-27T12:10:13.993+00:00"},"s":"I", "c":"REPL", "id":21320, "svc":"S", "ctx":"ReplCoord-0","msg":"Updated term","attr":{"term":1}} {"t":{"$date":"2024-11-27T12:10:13.993+00:00"},"s":"I", "c":"NETWORK", "id":4603701, "svc":"S", "ctx":"ReplCoord-0","msg":"Starting Replica Set Monitor","attr":{"protocol":"streamable","uri":"rscfg/localhost:28073"}} {"t":{"$date":"2024-11-27T12:10:13.993+00:00"},"s":"I", "c":"NETWORK", "id":22944, "svc":"S", "ctx":"conn2","msg":"Connection ended","attr":{"remote":"127.0.0.1:59038","uuid":{"uuid":{"$uuid":"29ec3709-2d05-4461-b9cf-74f0ded253d5"}},"connectionId":2,"connectionCount":0}} {"t":{"$date":"2024-11-27T12:10:13.993+00:00"},"s":"I", "c":"-", "id":4333223, "svc":"S", "ctx":"ReplCoord-0","msg":"RSM now monitoring replica set","attr":{"replicaSet":"rscfg","nReplicaSetMembers":1}} {"t":{"$date":"2024-11-27T12:10:13.993+00:00"},"s":"I", "c":"-", "id":4333226, "svc":"S", "ctx":"ReplCoord-0","msg":"RSM host was added to the topology","attr":{"replicaSet":"rscfg","host":"localhost:28073"}} {"t":{"$date":"2024-11-27T12:10:13.993+00:00"},"s":"I", "c":"REPL", "id":21306, "svc":"S", "ctx":"ReplCoord-0","msg":"Starting replication storage threads"} {"t":{"$date":"2024-11-27T12:10:13.993+00:00"},"s":"I", "c":"CONNPOOL", "id":22576, "svc":"-", "ctx":"ReplicaSetMonitor-TaskExecutor","msg":"Connecting","attr":{"hostAndPort":"localhost:28073"}} {"t":{"$date":"2024-11-27T12:10:13.993+00:00"},"s":"I", "c":"NETWORK", "id":22943, "svc":"-", "ctx":"listener","msg":"Connection accepted","attr":{"remote":"127.0.0.1:59054","uuid":{"uuid":{"$uuid":"26535a77-8ab5-4a7d-964f-1adcd2f9573e"}},"connectionId":4,"connectionCount":1}} {"t":{"$date":"2024-11-27T12:10:13.993+00:00"},"s":"I", "c":"REPL", "id":4280512, "svc":"S", "ctx":"ReplCoord-0","msg":"No initial sync required. Attempting to begin steady replication","attr":{"lastOpTime":{"ts":{"$timestamp":{"t":1732709068,"i":1}},"t":1},"isInitialSyncFlagSet":false}} {"t":{"$date":"2024-11-27T12:10:13.993+00:00"},"s":"I", "c":"REPL", "id":21358, "svc":"S", "ctx":"ReplCoord-0","msg":"Replica set state transition","attr":{"newState":"RECOVERING","oldState":"STARTUP2"}} {"t":{"$date":"2024-11-27T12:10:13.993+00:00"},"s":"I", "c":"STORAGE", "id":20320, "svc":"S", "ctx":"ReplCoord-0","msg":"createCollection","attr":{"namespace":"local.replset.initialSyncId","uuidDisposition":"generated","uuid":{"uuid":{"$uuid":"3a71e56e-a21e-4959-99a1-5751addfb2d3"}},"options":{}}} {"t":{"$date":"2024-11-27T12:10:13.994+00:00"},"s":"I", "c":"NETWORK", "id":51800, "svc":"S", "ctx":"conn4","msg":"client metadata","attr":{"remote":"127.0.0.1:59054","client":"conn4","negotiatedCompressors":["snappy","zstd","zlib"],"doc":{"driver":{"name":"NetworkInterfaceTL-ReplicaSetMonitor-TaskExecutor","version":"8.0.1-1"},"os":{"type":"Linux","name":"Oracle Linux Server release 8.10","architecture":"x86_64","version":"Kernel 6.5.0-1025-azure"}}}} {"t":{"$date":"2024-11-27T12:10:13.994+00:00"},"s":"I", "c":"NETWORK", "id":23729, "svc":"-", "ctx":"ReplicaSetMonitor-TaskExecutor","msg":"ServerPingMonitor is now monitoring host","attr":{"host":"localhost:28073","replicaSet":"rscfg"}} {"t":{"$date":"2024-11-27T12:10:13.994+00:00"},"s":"I", "c":"NETWORK", "id":4333213, "svc":"-", "ctx":"ReplicaSetMonitor-TaskExecutor","msg":"RSM Topology Change","attr":{"replicaSet":"rscfg","newTopologyDescription":{"id":"5995d6cc-88d6-42f3-9e85-f3b3bf2f4728","topologyType":"ReplicaSetNoPrimary","servers":{"localhost:28073":{"address":"localhost:28073","topologyVersion":{"processId":{"$oid":"67470c2597aaaf188c000e38"},"counter":2},"roundTripTime":413,"lastWriteDate":{"$date":"2024-11-27T12:04:28.000Z"},"opTime":{"ts":{"$timestamp":{"t":1732709068,"i":1}},"t":1},"type":"RSOther","minWireVersion":25,"maxWireVersion":25,"me":"localhost:28073","setName":"rscfg","setVersion":1,"lastUpdateTime":{"$date":"2024-11-27T12:10:13.994Z"},"logicalSessionTimeoutMinutes":30,"hosts":{"0":"localhost:28073"},"arbiters":{},"passives":{}}},"setName":"rscfg","compatible":true},"previousTopologyDescription":{"id":"e4d3dcad-a14c-49b9-afbd-03e66e571a71","topologyType":"ReplicaSetNoPrimary","servers":{"localhost:28073":{"address":"localhost:28073","type":"Unknown","minWireVersion":0,"maxWireVersion":0,"lastUpdateTime":{"$date":{"$numberLong":"-9223372036854775808"}},"hosts":{},"arbiters":{},"passives":{}}},"setName":"rscfg","compatible":true}}} {"t":{"$date":"2024-11-27T12:10:13.994+00:00"},"s":"I", "c":"NETWORK", "id":22943, "svc":"-", "ctx":"listener","msg":"Connection accepted","attr":{"remote":"127.0.0.1:59062","uuid":{"uuid":{"$uuid":"41031f8c-9b51-4ab0-bfa6-f5e694a8578d"}},"connectionId":5,"connectionCount":2}} {"t":{"$date":"2024-11-27T12:10:13.995+00:00"},"s":"I", "c":"NETWORK", "id":22943, "svc":"-", "ctx":"listener","msg":"Connection accepted","attr":{"remote":"127.0.0.1:59072","uuid":{"uuid":{"$uuid":"53ed5fb3-2f57-4d02-8c52-5a7122080ea2"}},"connectionId":7,"connectionCount":3}} {"t":{"$date":"2024-11-27T12:10:13.995+00:00"},"s":"I", "c":"NETWORK", "id":6788700, "svc":"S", "ctx":"conn4","msg":"Received first command on ingress connection since session start or auth handshake","attr":{"elapsedMillis":0}} {"t":{"$date":"2024-11-27T12:10:13.995+00:00"},"s":"I", "c":"NETWORK", "id":51800, "svc":"S", "ctx":"conn5","msg":"client metadata","attr":{"remote":"127.0.0.1:59062","client":"conn5","negotiatedCompressors":["snappy","zstd","zlib"],"doc":{"driver":{"name":"NetworkInterfaceTL-ReplicaSetMonitor-TaskExecutor","version":"8.0.1-1"},"os":{"type":"Linux","name":"Oracle Linux Server release 8.10","architecture":"x86_64","version":"Kernel 6.5.0-1025-azure"}}}} {"t":{"$date":"2024-11-27T12:10:13.995+00:00"},"s":"I", "c":"NETWORK", "id":51800, "svc":"S", "ctx":"conn7","msg":"client metadata","attr":{"remote":"127.0.0.1:59072","client":"conn7","negotiatedCompressors":[],"doc":{"application":{"name":"pbm-physical-restore"},"driver":{"name":"mongo-go-driver","version":"1.16.0"},"os":{"type":"linux","architecture":"amd64"},"platform":"go1.23.3","env":{"container":{"runtime":"docker"}}}}} {"t":{"$date":"2024-11-27T12:10:13.996+00:00"},"s":"I", "c":"NETWORK", "id":22943, "svc":"-", "ctx":"listener","msg":"Connection accepted","attr":{"remote":"127.0.0.1:59088","uuid":{"uuid":{"$uuid":"cced067e-3b1d-456b-9fd9-191249d5331c"}},"connectionId":8,"connectionCount":4}} {"t":{"$date":"2024-11-27T12:10:13.996+00:00"},"s":"I", "c":"NETWORK", "id":22943, "svc":"-", "ctx":"listener","msg":"Connection accepted","attr":{"remote":"127.0.0.1:59092","uuid":{"uuid":{"$uuid":"e9767f9f-198a-46bd-b7d8-6f83ab063206"}},"connectionId":9,"connectionCount":5}} {"t":{"$date":"2024-11-27T12:10:13.996+00:00"},"s":"I", "c":"NETWORK", "id":51800, "svc":"S", "ctx":"conn8","msg":"client metadata","attr":{"remote":"127.0.0.1:59088","client":"conn8","negotiatedCompressors":[],"doc":{"application":{"name":"pbm-physical-restore"},"driver":{"name":"mongo-go-driver","version":"1.16.0"},"os":{"type":"linux","architecture":"amd64"},"platform":"go1.23.3","env":{"container":{"runtime":"docker"}}}}} {"t":{"$date":"2024-11-27T12:10:13.996+00:00"},"s":"I", "c":"NETWORK", "id":51800, "svc":"S", "ctx":"conn9","msg":"client metadata","attr":{"remote":"127.0.0.1:59092","client":"conn9","negotiatedCompressors":[],"doc":{"application":{"name":"pbm-physical-restore"},"driver":{"name":"mongo-go-driver","version":"1.16.0"},"os":{"type":"linux","architecture":"amd64"},"platform":"go1.23.3","env":{"container":{"runtime":"docker"}}}}} {"t":{"$date":"2024-11-27T12:10:13.996+00:00"},"s":"I", "c":"NETWORK", "id":6788700, "svc":"S", "ctx":"conn8","msg":"Received first command on ingress connection since session start or auth handshake","attr":{"elapsedMillis":0}} {"t":{"$date":"2024-11-27T12:10:13.999+00:00"},"s":"I", "c":"INDEX", "id":20345, "svc":"S", "ctx":"ReplCoord-0","msg":"Index build: done building","attr":{"buildUUID":null,"collectionUUID":{"uuid":{"$uuid":"3a71e56e-a21e-4959-99a1-5751addfb2d3"}},"namespace":"local.replset.initialSyncId","index":"_id_","ident":"index-1-1344107906148837839","collectionIdent":"collection-0-1344107906148837839","commitTimestamp":null}} {"t":{"$date":"2024-11-27T12:10:13.999+00:00"},"s":"I", "c":"REPL", "id":21299, "svc":"S", "ctx":"ReplCoord-0","msg":"Starting replication fetcher thread"} {"t":{"$date":"2024-11-27T12:10:13.999+00:00"},"s":"I", "c":"REPL", "id":8569800, "svc":"S", "ctx":"ReplCoord-0","msg":"Starting replication writer thread"} {"t":{"$date":"2024-11-27T12:10:13.999+00:00"},"s":"I", "c":"REPL", "id":21300, "svc":"S", "ctx":"ReplCoord-0","msg":"Starting replication applier thread"} {"t":{"$date":"2024-11-27T12:10:13.999+00:00"},"s":"I", "c":"REPL", "id":21301, "svc":"S", "ctx":"ReplCoord-0","msg":"Starting replication reporter thread"} {"t":{"$date":"2024-11-27T12:10:13.999+00:00"},"s":"I", "c":"REPL", "id":8543100, "svc":"S", "ctx":"OplogWriter-0","msg":"Starting oplog write"} {"t":{"$date":"2024-11-27T12:10:13.999+00:00"},"s":"I", "c":"REPL", "id":21358, "svc":"S", "ctx":"ReplCoord-0","msg":"Replica set state transition","attr":{"newState":"SECONDARY","oldState":"RECOVERING"}} {"t":{"$date":"2024-11-27T12:10:13.999+00:00"},"s":"I", "c":"REPL", "id":21224, "svc":"S", "ctx":"OplogApplier-0","msg":"Starting oplog application"} {"t":{"$date":"2024-11-27T12:10:14.017+00:00"},"s":"I", "c":"ELECTION", "id":4615652, "svc":"S", "ctx":"ReplCoord-0","msg":"Starting an election, since we've seen no PRIMARY in election timeout period","attr":{"electionTimeoutPeriodMillis":10000}} {"t":{"$date":"2024-11-27T12:10:14.017+00:00"},"s":"I", "c":"ELECTION", "id":21438, "svc":"S", "ctx":"ReplCoord-0","msg":"Conducting a dry run election to see if we could be elected","attr":{"currentTerm":1}} {"t":{"$date":"2024-11-27T12:10:14.017+00:00"},"s":"I", "c":"REPL", "id":4280511, "svc":"S", "ctx":"ReplCoord-0","msg":"Set local replica set config"} {"t":{"$date":"2024-11-27T12:10:14.017+00:00"},"s":"I", "c":"ELECTION", "id":21444, "svc":"S", "ctx":"ReplCoord-1","msg":"Dry election run succeeded, running for election","attr":{"newTerm":2}} {"t":{"$date":"2024-11-27T12:10:14.017+00:00"},"s":"I", "c":"REPL", "id":21827, "svc":"S", "ctx":"ReplCoord-1","msg":"Updating term","attr":{"oldTerm":1,"newTerm":2}} {"t":{"$date":"2024-11-27T12:10:14.017+00:00"},"s":"I", "c":"ELECTION", "id":6015300, "svc":"S", "ctx":"ReplCoord-0","msg":"Storing last vote document in local storage for my election","attr":{"lastVote":{"term":2,"candidateIndex":0}}} {"t":{"$date":"2024-11-27T12:10:14.021+00:00"},"s":"I", "c":"REPL", "id":8423402, "svc":"S", "ctx":"BackgroundSync","msg":"Failed to select a sync source on the first attempt. Starting second attempt"} {"t":{"$date":"2024-11-27T12:10:14.021+00:00"},"s":"I", "c":"NETWORK", "id":4333213, "svc":"-", "ctx":"ReplicaSetMonitor-TaskExecutor","msg":"RSM Topology Change","attr":{"replicaSet":"rscfg","newTopologyDescription":{"id":"a0228977-0ad3-460a-8175-64d7b2ed4144","topologyType":"ReplicaSetNoPrimary","servers":{"localhost:28073":{"address":"localhost:28073","topologyVersion":{"processId":{"$oid":"67470c2597aaaf188c000e38"},"counter":3},"roundTripTime":458,"lastWriteDate":{"$date":"2024-11-27T12:04:28.000Z"},"opTime":{"ts":{"$timestamp":{"t":1732709068,"i":1}},"t":1},"type":"RSSecondary","minWireVersion":25,"maxWireVersion":25,"me":"localhost:28073","setName":"rscfg","setVersion":1,"lastUpdateTime":{"$date":"2024-11-27T12:10:14.021Z"},"logicalSessionTimeoutMinutes":30,"hosts":{"0":"localhost:28073"},"arbiters":{},"passives":{}}},"logicalSessionTimeoutMinutes":30,"setName":"rscfg","compatible":true},"previousTopologyDescription":{"id":"bb42555b-a75a-48a0-a695-2e8145054969","topologyType":"ReplicaSetNoPrimary","servers":{"localhost:28073":{"address":"localhost:28073","topologyVersion":{"processId":{"$oid":"67470c2597aaaf188c000e38"},"counter":2},"roundTripTime":458,"lastWriteDate":{"$date":"2024-11-27T12:04:28.000Z"},"opTime":{"ts":{"$timestamp":{"t":1732709068,"i":1}},"t":1},"type":"RSOther","minWireVersion":25,"maxWireVersion":25,"me":"localhost:28073","setName":"rscfg","setVersion":1,"lastUpdateTime":{"$date":"2024-11-27T12:10:13.995Z"},"logicalSessionTimeoutMinutes":30,"hosts":{"0":"localhost:28073"},"arbiters":{},"passives":{}}},"setName":"rscfg","compatible":true}}} {"t":{"$date":"2024-11-27T12:10:14.021+00:00"},"s":"I", "c":"ELECTION", "id":21450, "svc":"S", "ctx":"ReplCoord-0","msg":"Election succeeded, assuming primary role","attr":{"term":2}} {"t":{"$date":"2024-11-27T12:10:14.021+00:00"},"s":"I", "c":"REPL", "id":21358, "svc":"S", "ctx":"ReplCoord-0","msg":"Replica set state transition","attr":{"newState":"PRIMARY","oldState":"SECONDARY"}} {"t":{"$date":"2024-11-27T12:10:14.021+00:00"},"s":"I", "c":"REPL", "id":21106, "svc":"S", "ctx":"ReplCoord-0","msg":"Resetting sync source to empty","attr":{"previousSyncSource":":27017"}} {"t":{"$date":"2024-11-27T12:10:14.021+00:00"},"s":"I", "c":"REPL", "id":21359, "svc":"S", "ctx":"ReplCoord-0","msg":"Entering primary catch-up mode"} {"t":{"$date":"2024-11-27T12:10:14.021+00:00"},"s":"I", "c":"REPL", "id":6015304, "svc":"S", "ctx":"ReplCoord-0","msg":"Skipping primary catchup since we are the only node in the replica set."} {"t":{"$date":"2024-11-27T12:10:14.021+00:00"},"s":"I", "c":"REPL", "id":21363, "svc":"S", "ctx":"ReplCoord-0","msg":"Exited primary catch-up mode"} {"t":{"$date":"2024-11-27T12:10:14.021+00:00"},"s":"I", "c":"REPL", "id":21107, "svc":"S", "ctx":"ReplCoord-0","msg":"Stopping replication producer"} {"t":{"$date":"2024-11-27T12:10:14.021+00:00"},"s":"I", "c":"REPL", "id":8938402, "svc":"S", "ctx":"OplogWriter-0","msg":"Oplog writer buffer has been drained","attr":{"term":2}} {"t":{"$date":"2024-11-27T12:10:14.022+00:00"},"s":"I", "c":"NETWORK", "id":4333213, "svc":"-", "ctx":"ReplicaSetMonitor-TaskExecutor","msg":"RSM Topology Change","attr":{"replicaSet":"rscfg","newTopologyDescription":{"id":"0fd72e4e-8943-4349-b563-c33a26baf565","topologyType":"ReplicaSetNoPrimary","servers":{"localhost:28073":{"address":"localhost:28073","topologyVersion":{"processId":{"$oid":"67470c2597aaaf188c000e38"},"counter":4},"roundTripTime":458,"lastWriteDate":{"$date":"2024-11-27T12:04:28.000Z"},"opTime":{"ts":{"$timestamp":{"t":1732709068,"i":1}},"t":1},"type":"RSSecondary","minWireVersion":25,"maxWireVersion":25,"me":"localhost:28073","setName":"rscfg","setVersion":1,"electionId":{"$oid":"7fffffff0000000000000002"},"primary":"localhost:28073","lastUpdateTime":{"$date":"2024-11-27T12:10:14.022Z"},"logicalSessionTimeoutMinutes":30,"hosts":{"0":"localhost:28073"},"arbiters":{},"passives":{}}},"logicalSessionTimeoutMinutes":30,"setName":"rscfg","compatible":true},"previousTopologyDescription":{"id":"a0228977-0ad3-460a-8175-64d7b2ed4144","topologyType":"ReplicaSetNoPrimary","servers":{"localhost:28073":{"address":"localhost:28073","topologyVersion":{"processId":{"$oid":"67470c2597aaaf188c000e38"},"counter":3},"roundTripTime":458,"lastWriteDate":{"$date":"2024-11-27T12:04:28.000Z"},"opTime":{"ts":{"$timestamp":{"t":1732709068,"i":1}},"t":1},"type":"RSSecondary","minWireVersion":25,"maxWireVersion":25,"me":"localhost:28073","setName":"rscfg","setVersion":1,"lastUpdateTime":{"$date":"2024-11-27T12:10:14.021Z"},"logicalSessionTimeoutMinutes":30,"hosts":{"0":"localhost:28073"},"arbiters":{},"passives":{}}},"logicalSessionTimeoutMinutes":30,"setName":"rscfg","compatible":true}}} {"t":{"$date":"2024-11-27T12:10:14.022+00:00"},"s":"I", "c":"REPL", "id":21239, "svc":"S", "ctx":"ReplBatcher","msg":"Oplog applier buffer has been drained","attr":{"term":2}} {"t":{"$date":"2024-11-27T12:10:14.022+00:00"},"s":"I", "c":"NETWORK", "id":22943, "svc":"-", "ctx":"listener","msg":"Connection accepted","attr":{"remote":"127.0.0.1:59104","uuid":{"uuid":{"$uuid":"e3cade14-0737-4804-95bd-cdaca88b97f3"}},"connectionId":11,"connectionCount":6}} {"t":{"$date":"2024-11-27T12:10:14.022+00:00"},"s":"I", "c":"REPL", "id":21343, "svc":"S", "ctx":"RstlKillOpThread","msg":"Starting to kill user operations"} {"t":{"$date":"2024-11-27T12:10:14.022+00:00"},"s":"I", "c":"REPL", "id":21344, "svc":"S", "ctx":"RstlKillOpThread","msg":"Stopped killing user operations"} {"t":{"$date":"2024-11-27T12:10:14.022+00:00"},"s":"I", "c":"REPL", "id":21340, "svc":"S", "ctx":"RstlKillOpThread","msg":"State transition ops metrics","attr":{"metrics":{"lastStateTransition":"stepUp","totalOpsKilled":0,"totalOpsRunning":4}}} {"t":{"$date":"2024-11-27T12:10:14.022+00:00"},"s":"I", "c":"REPL", "id":6015310, "svc":"S", "ctx":"OplogApplier-0","msg":"Starting to transition to primary."} {"t":{"$date":"2024-11-27T12:10:14.023+00:00"},"s":"I", "c":"NETWORK", "id":51800, "svc":"S", "ctx":"conn11","msg":"client metadata","attr":{"remote":"127.0.0.1:59104","client":"conn11","negotiatedCompressors":["snappy","zstd","zlib"],"doc":{"driver":{"name":"NetworkInterfaceTL-ShardRegistry","version":"8.0.1-1"},"os":{"type":"Linux","name":"Oracle Linux Server release 8.10","architecture":"x86_64","version":"Kernel 6.5.0-1025-azure"}}}} {"t":{"$date":"2024-11-27T12:10:14.023+00:00"},"s":"I", "c":"REPL", "id":6015309, "svc":"S", "ctx":"OplogApplier-0","msg":"Logging transition to primary to oplog on stepup"} {"t":{"$date":"2024-11-27T12:10:14.025+00:00"},"s":"W", "c":"QUERY", "id":3216000, "svc":"S", "ctx":"OplogApplier-0","msg":"$jsonSchema validator does not allow '_id' field. This validator will reject all documents, consider adding '_id' to the allowed fields."} {"t":{"$date":"2024-11-27T12:10:14.025+00:00"},"s":"W", "c":"QUERY", "id":3216000, "svc":"S", "ctx":"OplogApplier-0","msg":"$jsonSchema validator does not allow '_id' field. This validator will reject all documents, consider adding '_id' to the allowed fields."} {"t":{"$date":"2024-11-27T12:10:14.025+00:00"},"s":"I", "c":"COMMAND", "id":5324200, "svc":"S", "ctx":"OplogApplier-0","msg":"CMD: collMod","attr":{"cmdObj":{"collMod":"settings","validator":{"$jsonSchema":{"oneOf":[{"properties":{"_id":{"enum":["balancer"]},"mode":{"enum":["full","off"]},"stopped":{"bsonType":"bool"},"activeWindow":{"bsonType":"object","required":["start","stop"]},"_secondaryThrottle":{"oneOf":[{"bsonType":"bool"},{"bsonType":"object"}]},"_waitForDelete":{"bsonType":"bool"},"attemptToBalanceJumboChunks":{"bsonType":"bool"}},"additionalProperties":false},{"properties":{"_id":{"enum":["chunksize"]},"value":{"bsonType":"number","minimum":1,"maximum":1024}},"additionalProperties":false},{"properties":{"_id":{"enum":["automerge","ReadWriteConcernDefaults","audit"]}}}]}},"validationLevel":"strict"}}} {"t":{"$date":"2024-11-27T12:10:14.025+00:00"},"s":"W", "c":"QUERY", "id":3216000, "svc":"S", "ctx":"OplogApplier-0","msg":"$jsonSchema validator does not allow '_id' field. This validator will reject all documents, consider adding '_id' to the allowed fields."} {"t":{"$date":"2024-11-27T12:10:14.025+00:00"},"s":"W", "c":"QUERY", "id":3216000, "svc":"S", "ctx":"OplogApplier-0","msg":"$jsonSchema validator does not allow '_id' field. This validator will reject all documents, consider adding '_id' to the allowed fields."} {"t":{"$date":"2024-11-27T12:10:14.025+00:00"},"s":"I", "c":"REPL", "id":7360104, "svc":"S", "ctx":"OplogApplier-0","msg":"Wrote oplog entry for collMod","attr":{"namespace":"config.$cmd","uuid":{"uuid":{"$uuid":"109fc0a5-f9fb-4727-9fb3-3cb7d5ed065e"}},"opTime":{"ts":{"$timestamp":{"t":1732709414,"i":3}},"t":2},"object":{"collMod":"settings","validator":{"$jsonSchema":{"oneOf":[{"properties":{"_id":{"enum":["balancer"]},"mode":{"enum":["full","off"]},"stopped":{"bsonType":"bool"},"activeWindow":{"bsonType":"object","required":["start","stop"]},"_secondaryThrottle":{"oneOf":[{"bsonType":"bool"},{"bsonType":"object"}]},"_waitForDelete":{"bsonType":"bool"},"attemptToBalanceJumboChunks":{"bsonType":"bool"}},"additionalProperties":false},{"properties":{"_id":{"enum":["chunksize"]},"value":{"bsonType":"number","minimum":1,"maximum":1024}},"additionalProperties":false},{"properties":{"_id":{"enum":["automerge","ReadWriteConcernDefaults","audit"]}}}]}},"validationLevel":"strict"}}} {"t":{"$date":"2024-11-27T12:10:14.026+00:00"},"s":"W", "c":"CONTROL", "id":636300, "svc":"S", "ctx":"ftdc","msg":"Use of deprecated server parameter name","attr":{"deprecatedName":"internalQueryCacheSize","canonicalName":"internalQueryCacheMaxEntriesPerCollection"}} {"t":{"$date":"2024-11-27T12:10:14.026+00:00"},"s":"I", "c":"SHARDING", "id":22049, "svc":"S", "ctx":"PeriodicShardedIndexConsistencyChecker","msg":"Checking consistency of sharded collection indexes across the cluster"} {"t":{"$date":"2024-11-27T12:10:14.026+00:00"},"s":"W", "c":"CONTROL", "id":636300, "svc":"S", "ctx":"ftdc","msg":"Use of deprecated server parameter name","attr":{"deprecatedName":"oplogSamplingLogIntervalSeconds","canonicalName":"collectionSamplingLogIntervalSeconds"}} {"t":{"$date":"2024-11-27T12:10:14.026+00:00"},"s":"W", "c":"NETWORK", "id":23803, "svc":"S", "ctx":"ftdc","msg":"Use of deprecated server parameter 'sslMode', please use 'tlsMode' instead."} {"t":{"$date":"2024-11-27T12:10:14.026+00:00"},"s":"W", "c":"CONTROL", "id":636300, "svc":"S", "ctx":"ftdc","msg":"Use of deprecated server parameter name","attr":{"deprecatedName":"wiredTigerConcurrentReadTransactions","canonicalName":"storageEngineConcurrentReadTransactions"}} {"t":{"$date":"2024-11-27T12:10:14.026+00:00"},"s":"W", "c":"CONTROL", "id":636300, "svc":"S", "ctx":"ftdc","msg":"Use of deprecated server parameter name","attr":{"deprecatedName":"wiredTigerConcurrentWriteTransactions","canonicalName":"storageEngineConcurrentWriteTransactions"}} {"t":{"$date":"2024-11-27T12:10:14.027+00:00"},"s":"I", "c":"STORAGE", "id":20657, "svc":"S", "ctx":"OplogApplier-0","msg":"IndexBuildsCoordinator::onStepUp - this node is stepping up to primary"} {"t":{"$date":"2024-11-27T12:10:14.027+00:00"},"s":"I", "c":"-", "id":4939300, "svc":"S", "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":"2024-11-27T12:10:14.028+00:00"},"s":"I", "c":"-", "id":8025900, "svc":"S", "ctx":"OplogApplier-0","msg":"ReplicaSetAwareServiceRegistry::onStepUpComplete stepping up all services"} {"t":{"$date":"2024-11-27T12:10:14.028+00:00"},"s":"I", "c":"STORAGE", "id":7508300, "svc":"S", "ctx":"IndexBuildsCoordinator-StepUp","msg":"Finished performing asynchronous step-up checks on index builds"} {"t":{"$date":"2024-11-27T12:10:14.029+00:00"},"s":"I", "c":"REPL", "id":21331, "svc":"S", "ctx":"OplogApplier-0","msg":"Transition to primary complete; database writes are now permitted","attr":{"term":2}} {"t":{"$date":"2024-11-27T12:10:14.029+00:00"},"s":"I", "c":"NETWORK", "id":4333213, "svc":"-", "ctx":"ReplicaSetMonitor-TaskExecutor","msg":"RSM Topology Change","attr":{"replicaSet":"rscfg","newTopologyDescription":{"id":"7ff4d56e-df84-4dec-9cd3-a47cb29e62cc","topologyType":"ReplicaSetWithPrimary","servers":{"localhost:28073":{"address":"localhost:28073","topologyVersion":{"processId":{"$oid":"67470c2597aaaf188c000e38"},"counter":5},"roundTripTime":458,"lastWriteDate":{"$date":"2024-11-27T12:10:14.000Z"},"opTime":{"ts":{"$timestamp":{"t":1732709414,"i":4}},"t":2},"type":"RSPrimary","minWireVersion":25,"maxWireVersion":25,"me":"localhost:28073","setName":"rscfg","setVersion":1,"electionId":{"$oid":"7fffffff0000000000000002"},"primary":"localhost:28073","lastUpdateTime":{"$date":"2024-11-27T12:10:14.029Z"},"logicalSessionTimeoutMinutes":30,"hosts":{"0":"localhost:28073"},"arbiters":{},"passives":{}}},"logicalSessionTimeoutMinutes":30,"setName":"rscfg","compatible":true,"maxElectionIdSetVersion":{"electionId":{"$oid":"7fffffff0000000000000002"},"setVersion":1}},"previousTopologyDescription":{"id":"0fd72e4e-8943-4349-b563-c33a26baf565","topologyType":"ReplicaSetNoPrimary","servers":{"localhost:28073":{"address":"localhost:28073","topologyVersion":{"processId":{"$oid":"67470c2597aaaf188c000e38"},"counter":4},"roundTripTime":458,"lastWriteDate":{"$date":"2024-11-27T12:04:28.000Z"},"opTime":{"ts":{"$timestamp":{"t":1732709068,"i":1}},"t":1},"type":"RSSecondary","minWireVersion":25,"maxWireVersion":25,"me":"localhost:28073","setName":"rscfg","setVersion":1,"electionId":{"$oid":"7fffffff0000000000000002"},"primary":"localhost:28073","lastUpdateTime":{"$date":"2024-11-27T12:10:14.022Z"},"logicalSessionTimeoutMinutes":30,"hosts":{"0":"localhost:28073"},"arbiters":{},"passives":{}}},"logicalSessionTimeoutMinutes":30,"setName":"rscfg","compatible":true}}} {"t":{"$date":"2024-11-27T12:10:14.029+00:00"},"s":"I", "c":"SHARDING", "id":471691, "svc":"-", "ctx":"ReplicaSetMonitor-TaskExecutor","msg":"Updating the shard registry with confirmed replica set","attr":{"connectionString":"rscfg/localhost:28073"}} {"t":{"$date":"2024-11-27T12:10:14.029+00:00"},"s":"I", "c":"NETWORK", "id":6006301, "svc":"-", "ctx":"ReplicaSetMonitor-TaskExecutor","msg":"Replica set primary server change detected","attr":{"replicaSet":"rscfg","topologyType":"ReplicaSetWithPrimary","primary":"localhost:28073","durationMillis":36}} {"t":{"$date":"2024-11-27T12:10:14.029+00:00"},"s":"I", "c":"SHARDING", "id":22068, "svc":"-", "ctx":"Sharding-Fixed-3","msg":"Updating shard identity config string with confirmed replica set","attr":{"connectionString":"rscfg/localhost:28073"}} {"t":{"$date":"2024-11-27T12:10:14.030+00:00"},"s":"I", "c":"NETWORK", "id":22943, "svc":"-", "ctx":"listener","msg":"Connection accepted","attr":{"remote":"127.0.0.1:59114","uuid":{"uuid":{"$uuid":"2e0c24a0-c1ae-4943-ac7a-f217f72e84f5"}},"connectionId":13,"connectionCount":7}} {"t":{"$date":"2024-11-27T12:10:14.030+00:00"},"s":"E", "c":"WT", "id":22435, "svc":"S", "ctx":"PlacementHistoryCleanUpJob","msg":"WiredTiger error message","attr":{"error":2,"message":{"ts_sec":1732709414,"ts_usec":30421,"thread":"1968:0x7f204622d700","session_dhandle_name":"file:collection-22-12496978015722617064.wt","session_name":"WT_SESSION.open_cursor","category":"WT_VERB_DEFAULT","category_id":12,"verbose_level":"ERROR","verbose_level_id":-3,"msg":"__posix_open_file:924:/var/lib/mongo/collection-22-12496978015722617064.wt: handle-open: open","error_str":"No such file or directory","error_code":2}}} {"t":{"$date":"2024-11-27T12:10:14.030+00:00"},"s":"F", "c":"STORAGE", "id":50883, "svc":"S", "ctx":"PlacementHistoryCleanUpJob","msg":"Cursor not found","attr":{"error":{"code":43,"codeName":"CursorNotFound","errmsg":"Failed to open a WiredTiger cursor. Reason: UnknownError: 2: No such file or directory, uri: table:collection-22-12496978015722617064, config: "}}} {"t":{"$date":"2024-11-27T12:10:14.030+00:00"},"s":"F", "c":"ASSERT", "id":23091, "svc":"S", "ctx":"PlacementHistoryCleanUpJob","msg":"Fatal assertion","attr":{"msgid":50883,"file":"src/mongo/db/storage/wiredtiger/wiredtiger_cursor.cpp","line":111}} {"t":{"$date":"2024-11-27T12:10:14.030+00:00"},"s":"F", "c":"ASSERT", "id":23092, "svc":"S", "ctx":"PlacementHistoryCleanUpJob","msg":"\n\n***aborting after fassert() failure\n\n"}

AssertionError: Unexpected exit code 1 for CommandResult(backend=<testinfra.backend.docker.DockerBackend object at 0x7f5387714a90>, exit_status=1, command=b'pbm config --force-resync --out json', _stdout=b'{"error":"another operation in progress","operation":{"node":"newrscfg01:27017","opid":"674714e0cc94a43e0098845f","replset":"newrscfg","type":"resync"}}\n', _stderr=b'') assert 1 == 0 + where 1 = CommandResult(backend=<testinfra.backend.docker.DockerBackend object at 0x7f5387714a90>, exit_status=1, command=b'pbm ...n":{"node":"newrscfg01:27017","opid":"674714e0cc94a43e0098845f","replset":"newrscfg","type":"resync"}}\n', _stderr=b'').rc