AssertionError: Starting restore 2024-10-22T08:48:08.246069778Z to point-in-time 2024-10-22T08:46:45 from '2024-10-22T08:43:04Z'..........................Started physical restore. Waiting to finish..............Error: operation failed with: replay pitr oplog: reply oplog: replay chunk 1729586587.1729586650: apply oplog for chunk: applying an entry: op: {"Timestamp":{"T":1729586621,"I":4},"Term":1,"Hash":null,"Version":2,"Operation":"i","Namespace":"test.test","Object":[{"Key":"_id","Value":"671765bd8cb7972063aeb2bc"},{"Key":"doc","Value":3}],"Query":[{"Key":"_id","Value":"671765bd8cb7972063aeb2bc"}],"UI":{"Subtype":4,"Data":"/GEyuFTKSuCP47Rr5kEDhw=="},"LSID":"SAAAAAVpZAAQAAAABB+PjpREiUKYi+PbIejt9A4FdWlkACAAAAAAY5mrDaxi8gv8RmdTsQ+1j7fmkr7JUsabhNmXAheU0fgA","TxnNumber":4,"PrevOpTime":"HAAAABF0cwAAAAAAAAAAABJ0AP//////////AA==","MultiOpType":null} | merr <nil>: applyOps: (NotWritablePrimary) not primary {"t":{"$date":"2024-10-22T08:48:47.436+00:00"},"s":"I", "c":"NETWORK", "id":4915701, "ctx":"main","msg":"Initialized wire specification","attr":{"spec":{"incomingExternalClient":{"minWireVersion":0,"maxWireVersion":21},"incomingInternalClient":{"minWireVersion":0,"maxWireVersion":21},"outgoing":{"minWireVersion":6,"maxWireVersion":21},"isInternalClient":true}}} {"t":{"$date":"2024-10-22T08:48:47.439+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-10-22T08:48:47.439+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-10-22T08:48:47.440+00:00"},"s":"I", "c":"REPL", "id":5123008, "ctx":"main","msg":"Successfully registered PrimaryOnlyService","attr":{"service":"TenantMigrationDonorService","namespace":"config.tenantMigrationDonors"}} {"t":{"$date":"2024-10-22T08:48:47.440+00:00"},"s":"I", "c":"REPL", "id":5123008, "ctx":"main","msg":"Successfully registered PrimaryOnlyService","attr":{"service":"TenantMigrationRecipientService","namespace":"config.tenantMigrationRecipients"}} {"t":{"$date":"2024-10-22T08:48:47.440+00:00"},"s":"I", "c":"CONTROL", "id":5945603, "ctx":"main","msg":"Multi threading initialized"} {"t":{"$date":"2024-10-22T08:48:47.440+00:00"},"s":"I", "c":"TENANT_M", "id":7091600, "ctx":"main","msg":"Starting TenantMigrationAccessBlockerRegistry"} {"t":{"$date":"2024-10-22T08:48:47.441+00:00"},"s":"I", "c":"CONTROL", "id":4615611, "ctx":"initandlisten","msg":"MongoDB starting","attr":{"pid":624,"port":27057,"dbPath":"/var/lib/mongo","architecture":"64-bit","host":"rs201"}} {"t":{"$date":"2024-10-22T08:48:47.441+00:00"},"s":"I", "c":"CONTROL", "id":23403, "ctx":"initandlisten","msg":"Build Info","attr":{"buildInfo":{"version":"7.0.14-8","gitVersion":"4479fd75bea6bf98a934c29007352dd36f3e1db5","openSSLVersion":"OpenSSL 1.1.1k FIPS 25 Mar 2021","modules":[],"proFeatures":[],"allocator":"tcmalloc","environment":{"distarch":"x86_64","target_arch":"x86_64"}}}} {"t":{"$date":"2024-10-22T08:48:47.441+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-10-22T08:48:47.441+00:00"},"s":"I", "c":"CONTROL", "id":21951, "ctx":"initandlisten","msg":"Options set by command line","attr":{"options":{"config":"/tmp/pbmMongdTmpConf3761800724","net":{"bindIp":"localhost","port":27057},"replication":{"replSet":"rs2"},"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-10-22T08:48:47.442+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-10-22T08:48:47.442+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,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],"}} {"t":{"$date":"2024-10-22T08:48:47.578+00:00"},"s":"I", "c":"WTRECOV", "id":22430, "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":{"ts_sec":1729586927,"ts_usec":578603,"thread":"624:0x7f92543fdc00","session_name":"txn-recover","category":"WT_VERB_RECOVERY_PROGRESS","category_id":30,"verbose_level":"DEBUG_1","verbose_level_id":1,"msg":"Recovering log 5 through 6"}}} {"t":{"$date":"2024-10-22T08:48:47.605+00:00"},"s":"I", "c":"WTRECOV", "id":22430, "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":{"ts_sec":1729586927,"ts_usec":605515,"thread":"624:0x7f92543fdc00","session_name":"txn-recover","category":"WT_VERB_RECOVERY_PROGRESS","category_id":30,"verbose_level":"DEBUG_1","verbose_level_id":1,"msg":"Recovering log 6 through 6"}}} {"t":{"$date":"2024-10-22T08:48:47.659+00:00"},"s":"I", "c":"WTRECOV", "id":22430, "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":{"ts_sec":1729586927,"ts_usec":659827,"thread":"624:0x7f92543fdc00","session_name":"txn-recover","category":"WT_VERB_RECOVERY_PROGRESS","category_id":30,"verbose_level":"DEBUG_1","verbose_level_id":1,"msg":"Main recovery loop: starting at 5/196608 to 6/256"}}} {"t":{"$date":"2024-10-22T08:48:47.710+00:00"},"s":"I", "c":"WTRECOV", "id":22430, "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":{"ts_sec":1729586927,"ts_usec":710878,"thread":"624:0x7f92543fdc00","session_name":"txn-recover","category":"WT_VERB_RECOVERY_PROGRESS","category_id":30,"verbose_level":"DEBUG_1","verbose_level_id":1,"msg":"Recovering log 5 through 6"}}} {"t":{"$date":"2024-10-22T08:48:47.750+00:00"},"s":"I", "c":"WTRECOV", "id":22430, "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":{"ts_sec":1729586927,"ts_usec":750214,"thread":"624:0x7f92543fdc00","session_name":"txn-recover","category":"WT_VERB_RECOVERY_PROGRESS","category_id":30,"verbose_level":"DEBUG_1","verbose_level_id":1,"msg":"Recovering log 6 through 6"}}} {"t":{"$date":"2024-10-22T08:48:47.774+00:00"},"s":"I", "c":"WTRECOV", "id":22430, "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":{"ts_sec":1729586927,"ts_usec":774502,"thread":"624:0x7f92543fdc00","session_name":"txn-recover","category":"WT_VERB_RECOVERY_PROGRESS","category_id":30,"verbose_level":"DEBUG_1","verbose_level_id":1,"msg":"recovery log replay has successfully finished and ran for 196 milliseconds"}}} {"t":{"$date":"2024-10-22T08:48:47.774+00:00"},"s":"I", "c":"WTRECOV", "id":22430, "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":{"ts_sec":1729586927,"ts_usec":774598,"thread":"624:0x7f92543fdc00","session_name":"txn-recover","category":"WT_VERB_RECOVERY_PROGRESS","category_id":30,"verbose_level":"DEBUG_1","verbose_level_id":1,"msg":"Set global recovery timestamp: (0, 0)"}}} {"t":{"$date":"2024-10-22T08:48:47.774+00:00"},"s":"I", "c":"WTRECOV", "id":22430, "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":{"ts_sec":1729586927,"ts_usec":774618,"thread":"624:0x7f92543fdc00","session_name":"txn-recover","category":"WT_VERB_RECOVERY_PROGRESS","category_id":30,"verbose_level":"DEBUG_1","verbose_level_id":1,"msg":"Set global oldest timestamp: (0, 0)"}}} {"t":{"$date":"2024-10-22T08:48:47.775+00:00"},"s":"I", "c":"WTRECOV", "id":22430, "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":{"ts_sec":1729586927,"ts_usec":775863,"thread":"624:0x7f92543fdc00","session_name":"txn-recover","category":"WT_VERB_RECOVERY_PROGRESS","category_id":30,"verbose_level":"DEBUG_1","verbose_level_id":1,"msg":"recovery rollback to stable has successfully finished and ran for 1 milliseconds"}}} {"t":{"$date":"2024-10-22T08:48:47.778+00:00"},"s":"I", "c":"WTCHKPT", "id":22430, "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":{"ts_sec":1729586927,"ts_usec":778145,"thread":"624:0x7f92543fdc00","session_name":"WT_SESSION.checkpoint","category":"WT_VERB_CHECKPOINT_PROGRESS","category_id":6,"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: 57"}}} {"t":{"$date":"2024-10-22T08:48:47.780+00:00"},"s":"I", "c":"WTRECOV", "id":22430, "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":{"ts_sec":1729586927,"ts_usec":780190,"thread":"624:0x7f92543fdc00","session_name":"txn-recover","category":"WT_VERB_RECOVERY_PROGRESS","category_id":30,"verbose_level":"DEBUG_1","verbose_level_id":1,"msg":"recovery checkpoint has successfully finished and ran for 4 milliseconds"}}} {"t":{"$date":"2024-10-22T08:48:47.780+00:00"},"s":"I", "c":"WTRECOV", "id":22430, "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":{"ts_sec":1729586927,"ts_usec":780241,"thread":"624:0x7f92543fdc00","session_name":"txn-recover","category":"WT_VERB_RECOVERY_PROGRESS","category_id":30,"verbose_level":"DEBUG_1","verbose_level_id":1,"msg":"recovery was completed successfully and took 201ms, including 196ms for the log replay, 1ms for the rollback to stable, and 4ms for the checkpoint."}}} {"t":{"$date":"2024-10-22T08:48:47.781+00:00"},"s":"I", "c":"STORAGE", "id":4795906, "ctx":"initandlisten","msg":"WiredTiger opened","attr":{"durationMillis":339}} {"t":{"$date":"2024-10-22T08:48:47.781+00:00"},"s":"I", "c":"RECOVERY", "id":23987, "ctx":"initandlisten","msg":"WiredTiger recoveryTimestamp","attr":{"recoveryTimestamp":{"$timestamp":{"t":0,"i":0}}}} {"t":{"$date":"2024-10-22T08:48:47.790+00:00"},"s":"I", "c":"STORAGE", "id":7393203, "ctx":"initandlisten","msg":"The size storer reports that the collection contains","attr":{"numRecords":73,"dataSize":20956}} {"t":{"$date":"2024-10-22T08:48:47.790+00:00"},"s":"I", "c":"STORAGE", "id":7393212, "ctx":"initandlisten","msg":"Scanning collection to determine where to place markers for truncation","attr":{"namespace":"local.oplog.rs"}} {"t":{"$date":"2024-10-22T08:48:47.791+00:00"},"s":"I", "c":"STORAGE", "id":22382, "ctx":"initandlisten","msg":"WiredTiger record store oplog processing finished","attr":{"durationMillis":0}} {"t":{"$date":"2024-10-22T08:48:47.821+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-10-22T08:48:47.821+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-10-22T08:48:47.821+00:00"},"s":"W", "c":"CONTROL", "id":5123300, "ctx":"initandlisten","msg":"vm.max_map_count is too low","attr":{"currentValue":262144,"recommendedMinimum":1677720,"maxConns":838860},"tags":["startupWarnings"]} {"t":{"$date":"2024-10-22T08:48:47.830+00:00"},"s":"I", "c":"NETWORK", "id":4915702, "ctx":"initandlisten","msg":"Updated wire specification","attr":{"oldSpec":{"incomingExternalClient":{"minWireVersion":0,"maxWireVersion":21},"incomingInternalClient":{"minWireVersion":0,"maxWireVersion":21},"outgoing":{"minWireVersion":6,"maxWireVersion":21},"isInternalClient":true},"newSpec":{"incomingExternalClient":{"minWireVersion":0,"maxWireVersion":21},"incomingInternalClient":{"minWireVersion":21,"maxWireVersion":21},"outgoing":{"minWireVersion":21,"maxWireVersion":21},"isInternalClient":true}}} {"t":{"$date":"2024-10-22T08:48:47.830+00:00"},"s":"I", "c":"REPL", "id":5853300, "ctx":"initandlisten","msg":"current featureCompatibilityVersion value","attr":{"featureCompatibilityVersion":"7.0","context":"startup"}} {"t":{"$date":"2024-10-22T08:48:47.830+00:00"},"s":"I", "c":"STORAGE", "id":5071100, "ctx":"initandlisten","msg":"Clearing temp directory"} {"t":{"$date":"2024-10-22T08:48:47.877+00:00"},"s":"I", "c":"CONTROL", "id":20536, "ctx":"initandlisten","msg":"Flow Control is enabled on this deployment"} {"t":{"$date":"2024-10-22T08:48:47.877+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-10-22T08:48:47.878+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":"rs2","clusterId":{"$oid":"6717658645598c688415bd2d"},"configsvrConnectionString":"rscfg/rscfg01:27017"}}} {"t":{"$date":"2024-10-22T08:48:47.879+00:00"},"s":"I", "c":"REPL", "id":40440, "ctx":"initandlisten","msg":"Starting the TopologyVersionObserver"} {"t":{"$date":"2024-10-22T08:48:47.879+00:00"},"s":"I", "c":"REPL", "id":40445, "ctx":"TopologyVersionObserver","msg":"Started TopologyVersionObserver"} {"t":{"$date":"2024-10-22T08:48:47.881+00:00"},"s":"I", "c":"REPL", "id":6015317, "ctx":"initandlisten","msg":"Setting new configuration state","attr":{"newState":"ConfigStartingUp","oldState":"ConfigPreStart"}} {"t":{"$date":"2024-10-22T08:48:47.881+00:00"},"s":"I", "c":"REPL", "id":6005300, "ctx":"initandlisten","msg":"Starting up replica set aware services"} {"t":{"$date":"2024-10-22T08:48:47.881+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-10-22T08:48:47.881+00:00"},"s":"I", "c":"REPL", "id":4280500, "ctx":"initandlisten","msg":"Attempting to create internal replication collections"} {"t":{"$date":"2024-10-22T08:48:47.884+00:00"},"s":"I", "c":"REPL", "id":4280501, "ctx":"initandlisten","msg":"Attempting to load local voted for document"} {"t":{"$date":"2024-10-22T08:48:47.884+00:00"},"s":"I", "c":"REPL", "id":21311, "ctx":"initandlisten","msg":"Did not find local initialized voted for document at startup"} {"t":{"$date":"2024-10-22T08:48:47.884+00:00"},"s":"I", "c":"REPL", "id":4280502, "ctx":"initandlisten","msg":"Searching for local Rollback ID document"} {"t":{"$date":"2024-10-22T08:48:47.885+00:00"},"s":"I", "c":"REPL", "id":21529, "ctx":"initandlisten","msg":"Initializing rollback ID","attr":{"rbid":1}} {"t":{"$date":"2024-10-22T08:48:47.885+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-10-22T08:48:47.886+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":"rs2","clusterId":{"$oid":"6717658645598c688415bd2d"},"configsvrConnectionString":"rscfg/rscfg01:27017"}}} {"t":{"$date":"2024-10-22T08:48:47.886+00:00"},"s":"I", "c":"CONTROL", "id":6608200, "ctx":"initandlisten","msg":"Initializing cluster server parameters from disk"} {"t":{"$date":"2024-10-22T08:48:47.886+00:00"},"s":"I", "c":"REPL", "id":21546, "ctx":"initandlisten","msg":"Recovering from an unstable checkpoint","attr":{"topOfOplog":{"ts":{"$timestamp":{"t":1729586584,"i":54}},"t":1},"appliedThrough":{"ts":{"$timestamp":{"t":0,"i":0}},"t":-1}}} {"t":{"$date":"2024-10-22T08:48:47.886+00:00"},"s":"I", "c":"REPL", "id":21547, "ctx":"initandlisten","msg":"No oplog entries to apply for recovery. appliedThrough is null"} {"t":{"$date":"2024-10-22T08:48:47.888+00:00"},"s":"I", "c":"WTCHKPT", "id":22430, "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":{"ts_sec":1729586927,"ts_usec":888832,"thread":"624:0x7f92543fdc00","session_name":"WT_SESSION.checkpoint","category":"WT_VERB_CHECKPOINT_PROGRESS","category_id":6,"verbose_level":"DEBUG_1","verbose_level_id":1,"msg":"saving checkpoint snapshot min: 63, snapshot max: 63 snapshot count: 0, oldest timestamp: (0, 0) , meta checkpoint timestamp: (0, 0) base write gen: 57"}}} {"t":{"$date":"2024-10-22T08:48:47.892+00:00"},"s":"I", "c":"REPL", "id":4280505, "ctx":"initandlisten","msg":"Creating any necessary TenantMigrationAccessBlockers for unfinished migrations"} {"t":{"$date":"2024-10-22T08:48:47.893+00:00"},"s":"I", "c":"TENANT_M", "id":6531504, "ctx":"initandlisten","msg":"Clearing serverless operation lock registry on shutdown","attr":{"ns":null}} {"t":{"$date":"2024-10-22T08:48:47.893+00:00"},"s":"I", "c":"REPL", "id":4280506, "ctx":"initandlisten","msg":"Reconstructing prepared transactions"} {"t":{"$date":"2024-10-22T08:48:47.894+00:00"},"s":"I", "c":"REPL", "id":4280507, "ctx":"initandlisten","msg":"Loaded replica set config, scheduled callback to set local config"} {"t":{"$date":"2024-10-22T08:48:47.894+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-10-22T08:48:47.894+00:00"},"s":"I", "c":"STORAGE", "id":22262, "ctx":"initandlisten","msg":"Timestamp monitor starting"} {"t":{"$date":"2024-10-22T08:48:47.912+00:00"},"s":"I", "c":"QUERY", "id":7080100, "ctx":"ChangeStreamExpiredPreImagesRemover","msg":"Starting Change Stream Expired Pre-images Remover thread"} {"t":{"$date":"2024-10-22T08:48:47.913+00:00"},"s":"I", "c":"SHARDING", "id":7012500, "ctx":"QueryAnalysisConfigurationsRefresher","msg":"Failed to refresh query analysis configurations, will try again at the next interval","attr":{"error":"PrimarySteppedDown: No primary exists currently"}} {"t":{"$date":"2024-10-22T08:48:47.913+00:00"},"s":"I", "c":"NETWORK", "id":23015, "ctx":"listener","msg":"Listening on","attr":{"address":"/tmp/mongodb-27057.sock"}} {"t":{"$date":"2024-10-22T08:48:47.913+00:00"},"s":"I", "c":"NETWORK", "id":23015, "ctx":"listener","msg":"Listening on","attr":{"address":"127.0.0.1"}} {"t":{"$date":"2024-10-22T08:48:47.913+00:00"},"s":"I", "c":"NETWORK", "id":23016, "ctx":"listener","msg":"Waiting for connections","attr":{"port":27057,"ssl":"off"}} {"t":{"$date":"2024-10-22T08:48:47.913+00:00"},"s":"I", "c":"CONTROL", "id":8423403, "ctx":"initandlisten","msg":"mongod startup complete","attr":{"Summary of time elapsed":{"Startup from clean shutdown?":true,"Statistics":{"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":"369 ms","Write current PID to file":"10 ms","Initialize FCV before rebuilding indexes":"9 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 information needed to make a mongod instance shard aware":"0 ms","Start up cluster time keys manager with a local/direct keys client":"0 ms","Start up the replication coordinator":"13 ms","Create an oplog view for tenant migrations":"0 ms","Start transport layer":"0 ms","_initAndListen total elapsed time":"472 ms"}}}} {"t":{"$date":"2024-10-22T08:48:47.913+00:00"},"s":"I", "c":"NETWORK", "id":22943, "ctx":"listener","msg":"Connection accepted","attr":{"remote":"127.0.0.1:60272","uuid":{"uuid":{"$uuid":"43685fd4-5057-4ce5-bf85-b9d6472ca781"}},"connectionId":2,"connectionCount":1}} {"t":{"$date":"2024-10-22T08:48:47.913+00:00"},"s":"I", "c":"NETWORK", "id":6788700, "ctx":"conn2","msg":"Received first command on ingress connection since session start or auth handshake","attr":{"elapsedMillis":0}} {"t":{"$date":"2024-10-22T08:48:47.913+00:00"},"s":"I", "c":"REPL", "id":4280509, "ctx":"ReplCoord-0","msg":"Local configuration validated for startup"} {"t":{"$date":"2024-10-22T08:48:47.914+00:00"},"s":"I", "c":"REPL", "id":6015317, "ctx":"ReplCoord-0","msg":"Setting new configuration state","attr":{"newState":"ConfigSteady","oldState":"ConfigStartingUp"}} {"t":{"$date":"2024-10-22T08:48:47.914+00:00"},"s":"I", "c":"NETWORK", "id":22944, "ctx":"conn2","msg":"Connection ended","attr":{"remote":"127.0.0.1:60272","uuid":{"uuid":{"$uuid":"43685fd4-5057-4ce5-bf85-b9d6472ca781"}},"connectionId":2,"connectionCount":0}} {"t":{"$date":"2024-10-22T08:48:47.914+00:00"},"s":"I", "c":"SHARDING", "id":7063400, "ctx":"ReplCoord-0","msg":"Updating implicit default writeConcern majority","attr":{"newImplicitDefaultWCMajority":true}} {"t":{"$date":"2024-10-22T08:48:47.914+00:00"},"s":"I", "c":"REPL", "id":21392, "ctx":"ReplCoord-0","msg":"New replica set config in use","attr":{"config":{"_id":"rs2","version":1,"members":[{"_id":0,"host":"localhost:27057","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-10-22T08:48:47.914+00:00"},"s":"I", "c":"REPL", "id":21393, "ctx":"ReplCoord-0","msg":"Found self in config","attr":{"hostAndPort":"localhost:27057"}} {"t":{"$date":"2024-10-22T08:48:47.914+00:00"},"s":"I", "c":"REPL", "id":21358, "ctx":"ReplCoord-0","msg":"Replica set state transition","attr":{"newState":"STARTUP2","oldState":"STARTUP"}} {"t":{"$date":"2024-10-22T08:48:47.914+00:00"},"s":"I", "c":"REPL", "id":21827, "ctx":"ReplCoord-0","msg":"Updating term","attr":{"oldTerm":0,"newTerm":1}} {"t":{"$date":"2024-10-22T08:48:47.914+00:00"},"s":"I", "c":"REPL", "id":21320, "ctx":"ReplCoord-0","msg":"Updated term","attr":{"term":1}} {"t":{"$date":"2024-10-22T08:48:47.914+00:00"},"s":"I", "c":"REPL", "id":21306, "ctx":"ReplCoord-0","msg":"Starting replication storage threads"} {"t":{"$date":"2024-10-22T08:48:47.914+00:00"},"s":"I", "c":"REPL", "id":4280512, "ctx":"ReplCoord-0","msg":"No initial sync required. Attempting to begin steady replication"} {"t":{"$date":"2024-10-22T08:48:47.914+00:00"},"s":"I", "c":"REPL", "id":21358, "ctx":"ReplCoord-0","msg":"Replica set state transition","attr":{"newState":"RECOVERING","oldState":"STARTUP2"}} {"t":{"$date":"2024-10-22T08:48:47.914+00:00"},"s":"I", "c":"STORAGE", "id":20320, "ctx":"ReplCoord-0","msg":"createCollection","attr":{"namespace":"local.replset.initialSyncId","uuidDisposition":"generated","uuid":{"uuid":{"$uuid":"8b19698e-e658-4cc5-b214-dd92dcfa0189"}},"options":{}}} {"t":{"$date":"2024-10-22T08:48:47.914+00:00"},"s":"I", "c":"NETWORK", "id":22943, "ctx":"listener","msg":"Connection accepted","attr":{"remote":"127.0.0.1:60286","uuid":{"uuid":{"$uuid":"4fdfce1e-53ab-46f6-88d4-7e8084175462"}},"connectionId":3,"connectionCount":1}} {"t":{"$date":"2024-10-22T08:48:47.914+00:00"},"s":"I", "c":"NETWORK", "id":51800, "ctx":"conn3","msg":"client metadata","attr":{"remote":"127.0.0.1:60286","client":"conn3","negotiatedCompressors":[],"doc":{"application":{"name":"pbm-physical-restore"},"driver":{"name":"mongo-go-driver","version":"1.16.0"},"os":{"type":"linux","architecture":"amd64"},"platform":"go1.23.2","env":{"container":{"runtime":"docker"}}}}} {"t":{"$date":"2024-10-22T08:48:47.915+00:00"},"s":"I", "c":"NETWORK", "id":22943, "ctx":"listener","msg":"Connection accepted","attr":{"remote":"127.0.0.1:60302","uuid":{"uuid":{"$uuid":"9d4479f7-99f1-4dd4-be28-b26affc0d63b"}},"connectionId":4,"connectionCount":2}} {"t":{"$date":"2024-10-22T08:48:47.915+00:00"},"s":"I", "c":"NETWORK", "id":22943, "ctx":"listener","msg":"Connection accepted","attr":{"remote":"127.0.0.1:60298","uuid":{"uuid":{"$uuid":"bc51e87e-fe4a-4cbe-bc48-912affe71858"}},"connectionId":5,"connectionCount":3}} {"t":{"$date":"2024-10-22T08:48:47.915+00:00"},"s":"I", "c":"NETWORK", "id":51800, "ctx":"conn4","msg":"client metadata","attr":{"remote":"127.0.0.1:60302","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.2","env":{"container":{"runtime":"docker"}}}}} {"t":{"$date":"2024-10-22T08:48:47.915+00:00"},"s":"I", "c":"NETWORK", "id":51800, "ctx":"conn5","msg":"client metadata","attr":{"remote":"127.0.0.1:60298","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.2","env":{"container":{"runtime":"docker"}}}}} {"t":{"$date":"2024-10-22T08:48:47.916+00:00"},"s":"I", "c":"NETWORK", "id":6788700, "ctx":"conn4","msg":"Received first command on ingress connection since session start or auth handshake","attr":{"elapsedMillis":0}} {"t":{"$date":"2024-10-22T08:48:47.920+00:00"},"s":"I", "c":"REPL", "id":7360102, "ctx":"ReplCoord-0","msg":"Added oplog entry for create to transaction","attr":{"namespace":"local.$cmd","uuid":{"uuid":{"$uuid":"8b19698e-e658-4cc5-b214-dd92dcfa0189"}},"object":{"create":"replset.initialSyncId","idIndex":{"v":2,"key":{"_id":1},"name":"_id_"}}}} {"t":{"$date":"2024-10-22T08:48:47.920+00:00"},"s":"I", "c":"INDEX", "id":20345, "ctx":"ReplCoord-0","msg":"Index build: done building","attr":{"buildUUID":null,"collectionUUID":{"uuid":{"$uuid":"8b19698e-e658-4cc5-b214-dd92dcfa0189"}},"namespace":"local.replset.initialSyncId","index":"_id_","ident":"index-1--6996890584052868265","collectionIdent":"collection-0--6996890584052868265","commitTimestamp":null}} {"t":{"$date":"2024-10-22T08:48:47.920+00:00"},"s":"I", "c":"REPL", "id":21299, "ctx":"ReplCoord-0","msg":"Starting replication fetcher thread"} {"t":{"$date":"2024-10-22T08:48:47.921+00:00"},"s":"I", "c":"REPL", "id":21300, "ctx":"ReplCoord-0","msg":"Starting replication applier thread"} {"t":{"$date":"2024-10-22T08:48:47.921+00:00"},"s":"I", "c":"REPL", "id":21301, "ctx":"ReplCoord-0","msg":"Starting replication reporter thread"} {"t":{"$date":"2024-10-22T08:48:47.921+00:00"},"s":"I", "c":"REPL", "id":21224, "ctx":"OplogApplier-0","msg":"Starting oplog application"} {"t":{"$date":"2024-10-22T08:48:47.921+00:00"},"s":"I", "c":"REPL", "id":4280511, "ctx":"ReplCoord-0","msg":"Set local replica set config"} {"t":{"$date":"2024-10-22T08:48:47.921+00:00"},"s":"I", "c":"REPL", "id":8423402, "ctx":"BackgroundSync","msg":"Failed to select a sync source on the first attempt. Starting second attempt"} {"t":{"$date":"2024-10-22T08:48:47.921+00:00"},"s":"I", "c":"REPL", "id":21358, "ctx":"OplogApplier-0","msg":"Replica set state transition","attr":{"newState":"SECONDARY","oldState":"RECOVERING"}} {"t":{"$date":"2024-10-22T08:48:47.921+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-10-22T08:48:47.921+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-10-22T08:48:47.921+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-10-22T08:48:47.921+00:00"},"s":"I", "c":"REPL", "id":21827, "ctx":"ReplCoord-0","msg":"Updating term","attr":{"oldTerm":1,"newTerm":2}} {"t":{"$date":"2024-10-22T08:48:47.921+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-10-22T08:48:47.922+00:00"},"s":"I", "c":"ELECTION", "id":21450, "ctx":"ReplCoord-0","msg":"Election succeeded, assuming primary role","attr":{"term":2}} {"t":{"$date":"2024-10-22T08:48:47.922+00:00"},"s":"I", "c":"REPL", "id":21358, "ctx":"ReplCoord-0","msg":"Replica set state transition","attr":{"newState":"PRIMARY","oldState":"SECONDARY"}} {"t":{"$date":"2024-10-22T08:48:47.922+00:00"},"s":"I", "c":"REPL", "id":21106, "ctx":"ReplCoord-0","msg":"Resetting sync source to empty","attr":{"previousSyncSource":":27017"}} {"t":{"$date":"2024-10-22T08:48:47.922+00:00"},"s":"I", "c":"REPL", "id":21359, "ctx":"ReplCoord-0","msg":"Entering primary catch-up mode"} {"t":{"$date":"2024-10-22T08:48:47.922+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-10-22T08:48:47.922+00:00"},"s":"I", "c":"REPL", "id":21363, "ctx":"ReplCoord-0","msg":"Exited primary catch-up mode"} {"t":{"$date":"2024-10-22T08:48:47.922+00:00"},"s":"I", "c":"REPL", "id":21107, "ctx":"ReplCoord-0","msg":"Stopping replication producer"} {"t":{"$date":"2024-10-22T08:48:47.922+00:00"},"s":"I", "c":"REPL", "id":21239, "ctx":"ReplBatcher","msg":"Oplog buffer has been drained","attr":{"term":2}} {"t":{"$date":"2024-10-22T08:48:47.922+00:00"},"s":"I", "c":"REPL", "id":21239, "ctx":"ReplBatcher","msg":"Oplog buffer has been drained","attr":{"term":2}} {"t":{"$date":"2024-10-22T08:48:47.922+00:00"},"s":"I", "c":"REPL", "id":21343, "ctx":"RstlKillOpThread","msg":"Starting to kill user operations"} {"t":{"$date":"2024-10-22T08:48:47.922+00:00"},"s":"I", "c":"REPL", "id":21344, "ctx":"RstlKillOpThread","msg":"Stopped killing user operations"} {"t":{"$date":"2024-10-22T08:48:47.922+00:00"},"s":"I", "c":"REPL", "id":21340, "ctx":"RstlKillOpThread","msg":"State transition ops metrics","attr":{"metrics":{"lastStateTransition":"stepUp","userOpsKilled":0,"userOpsRunning":2}}} {"t":{"$date":"2024-10-22T08:48:47.922+00:00"},"s":"I", "c":"REPL", "id":6015310, "ctx":"OplogApplier-0","msg":"Starting to transition to primary."} {"t":{"$date":"2024-10-22T08:48:47.923+00:00"},"s":"I", "c":"REPL", "id":6015309, "ctx":"OplogApplier-0","msg":"Logging transition to primary to oplog on stepup"} {"t":{"$date":"2024-10-22T08:48:47.923+00:00"},"s":"I", "c":"STORAGE", "id":20657, "ctx":"OplogApplier-0","msg":"IndexBuildsCoordinator::onStepUp - this node is stepping up to primary"} {"t":{"$date":"2024-10-22T08:48:47.923+00:00"},"s":"I", "c":"STORAGE", "id":7508300, "ctx":"IndexBuildsCoordinator-StepUp","msg":"Finished performing asynchronous step-up checks on index builds"} {"t":{"$date":"2024-10-22T08:48:47.924+00:00"},"s":"I", "c":"REPL", "id":21331, "ctx":"OplogApplier-0","msg":"Transition to primary complete; database writes are now permitted","attr":{"term":2}} {"t":{"$date":"2024-10-22T08:48:47.924+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":"60cf8474-f7af-4835-b7c2-4f17d9de4ae7"}},"options":{}}} {"t":{"$date":"2024-10-22T08:48:47.924+00:00"},"s":"I", "c":"REPL", "id":6015306, "ctx":"OplogApplier-0","msg":"Applier already left draining state, exiting."} {"t":{"$date":"2024-10-22T08:48:47.925+00:00"},"s":"I", "c":"REPL", "id":6795400, "ctx":"JournalFlusher","msg":"Advancing committed opTime to a new term","attr":{"newCommittedOpTime":{"ts":{"$timestamp":{"t":1729586927,"i":2}},"t":2},"newCommittedWallime":{"$date":"2024-10-22T08:48:47.923Z"},"oldTerm":-1}} {"t":{"$date":"2024-10-22T08:48:47.925+00:00"},"s":"I", "c":"STORAGE", "id":22310, "ctx":"JournalFlusher","msg":"Triggering the first stable checkpoint","attr":{"initialDataTimestamp":{"$timestamp":{"t":1729586584,"i":54}},"prevStableTimestamp":{"$timestamp":{"t":0,"i":0}},"currStableTimestamp":{"$timestamp":{"t":1729586927,"i":2}}}} {"t":{"$date":"2024-10-22T08:48:47.926+00:00"},"s":"I", "c":"REPL", "id":5123005, "ctx":"TenantMigrationRecipientService-0","msg":"Rebuilding PrimaryOnlyService due to stepUp","attr":{"service":"TenantMigrationRecipientService"}} {"t":{"$date":"2024-10-22T08:48:47.926+00:00"},"s":"I", "c":"REPL", "id":5123005, "ctx":"TenantMigrationDonorService-1","msg":"Rebuilding PrimaryOnlyService due to stepUp","attr":{"service":"TenantMigrationDonorService"}} {"t":{"$date":"2024-10-22T08:48:47.930+00:00"},"s":"I", "c":"WTCHKPT", "id":22430, "ctx":"Checkpointer","msg":"WiredTiger message","attr":{"message":{"ts_sec":1729586927,"ts_usec":930868,"thread":"624:0x7f923bccc700","session_name":"WT_SESSION.checkpoint","category":"WT_VERB_CHECKPOINT_PROGRESS","category_id":6,"verbose_level":"DEBUG_1","verbose_level_id":1,"msg":"saving checkpoint snapshot min: 76, snapshot max: 81 snapshot count: 1, oldest timestamp: (1729586627, 2) , meta checkpoint timestamp: (1729586927, 2) base write gen: 57"}}} {"t":{"$date":"2024-10-22T08:48:47.934+00:00"},"s":"I", "c":"REPL", "id":7360103, "ctx":"monitoring-keys-for-HMAC","msg":"Wrote oplog entry for create","attr":{"namespace":"admin.$cmd","uuid":{"uuid":{"$uuid":"60cf8474-f7af-4835-b7c2-4f17d9de4ae7"}},"opTime":{"ts":{"$timestamp":{"t":1729586927,"i":3}},"t":2},"object":{"create":"system.keys","idIndex":{"v":2,"key":{"_id":1},"name":"_id_"}}}} {"t":{"$date":"2024-10-22T08:48:47.934+00:00"},"s":"I", "c":"INDEX", "id":20345, "ctx":"monitoring-keys-for-HMAC","msg":"Index build: done building","attr":{"buildUUID":null,"collectionUUID":{"uuid":{"$uuid":"60cf8474-f7af-4835-b7c2-4f17d9de4ae7"}},"namespace":"admin.system.keys","index":"_id_","ident":"index-3--6996890584052868265","collectionIdent":"collection-2--6996890584052868265","commitTimestamp":{"$timestamp":{"t":1729586927,"i":3}}}} {"t":{"$date":"2024-10-22T08:48:47.936+00:00"},"s":"E", "c":"WT", "id":22435, "ctx":"Checkpointer","msg":"WiredTiger error message","attr":{"error":2,"message":{"ts_sec":1729586927,"ts_usec":936316,"thread":"624:0x7f923bccc700","session_name":"WT_SESSION.checkpoint","category":"WT_VERB_DEFAULT","category_id":9,"verbose_level":"ERROR","verbose_level_id":-3,"msg":"__posix_fs_size:301:/var/lib/mongo/WiredTigerHS.wt: file-size: stat","error_str":"No such file or directory","error_code":2}}} {"t":{"$date":"2024-10-22T08:48:47.936+00:00"},"s":"E", "c":"WT", "id":22435, "ctx":"Checkpointer","msg":"WiredTiger error message","attr":{"error":22,"message":{"ts_sec":1729586927,"ts_usec":936384,"thread":"624:0x7f923bccc700","session_dhandle_name":"file:WiredTigerHS.wt","session_name":"WT_SESSION.checkpoint","category":"WT_VERB_DEFAULT","category_id":9,"verbose_level":"ERROR","verbose_level_id":-3,"msg":"__wt_block_checkpoint_resolve:990:WiredTigerHS.wt: the checkpoint failed, the system must restart","error_str":"Invalid argument","error_code":22}}} {"t":{"$date":"2024-10-22T08:48:47.936+00:00"},"s":"E", "c":"WT", "id":22435, "ctx":"Checkpointer","msg":"WiredTiger error message","attr":{"error":-31804,"message":{"ts_sec":1729586927,"ts_usec":936420,"thread":"624:0x7f923bccc700","session_dhandle_name":"file:WiredTigerHS.wt","session_name":"WT_SESSION.checkpoint","category":"WT_VERB_DEFAULT","category_id":9,"verbose_level":"ERROR","verbose_level_id":-3,"msg":"__wt_block_checkpoint_resolve:990:the process must exit and restart","error_str":"WT_PANIC: WiredTiger library panic","error_code":-31804}}} {"t":{"$date":"2024-10-22T08:48:47.936+00:00"},"s":"F", "c":"ASSERT", "id":23089, "ctx":"Checkpointer","msg":"Fatal assertion","attr":{"msgid":50853,"file":"src/mongo/db/storage/wiredtiger/wiredtiger_util.cpp","line":741}} {"t":{"$date":"2024-10-22T08:48:47.936+00:00"},"s":"F", "c":"ASSERT", "id":23090, "ctx":"Checkpointer","msg":"\n\n***aborting after fassert() failure\n\n"} {"t":{"$date":"2024-10-22T08:48:47.936+00:00"},"s":"F", "c":"CONTROL", "id":6384300, "ctx":"Checkpointer","msg":"Writing fatal message","attr":{"message":"\n"}} {"t":{"$date":"2024-10-22T08:48:47.936+00:00"},"s":"F", "c":"CONTROL", "id":6384300, "ctx":"Checkpointer","msg":"Writing fatal message","attr":{"message":"Got signal: 6 (Aborted).\n"}} {"t":{"$date":"2024-10-22T08:48:47.946+00:00"},"s":"I", "c":"NETWORK", "id":22944, "ctx":"conn4","msg":"Connection ended","attr":{"remote":"127.0.0.1:60302","uuid":{"uuid":{"$uuid":"9d4479f7-99f1-4dd4-be28-b26affc0d63b"}},"connectionId":4,"connectionCount":2}} {"t":{"$date":"2024-10-22T08:48:47.946+00:00"},"s":"I", "c":"NETWORK", "id":22944, "ctx":"conn5","msg":"Connection ended","attr":{"remote":"127.0.0.1:60298","uuid":{"uuid":{"$uuid":"bc51e87e-fe4a-4cbe-bc48-912affe71858"}},"connectionId":5,"connectionCount":1}} {"t":{"$date":"2024-10-22T08:48:47.946+00:00"},"s":"I", "c":"-", "id":20883, "ctx":"conn3","msg":"Interrupted operation as its client disconnected","attr":{"opId":49}} {"t":{"$date":"2024-10-22T08:48:47.947+00:00"},"s":"I", "c":"NETWORK", "id":22944, "ctx":"conn3","msg":"Connection ended","attr":{"remote":"127.0.0.1:60286","uuid":{"uuid":{"$uuid":"4fdfce1e-53ab-46f6-88d4-7e8084175462"}},"connectionId":3,"connectionCount":0}} {"t":{"$date":"2024-10-22T08:48:47.969+00:00"},"s":"I", "c":"CONTROL", "id":31380, "ctx":"Checkpointer","msg":"BACKTRACE","attr":{"bt":{"backtrace":[{"a":"56421D2B91B8","b":"564215302000","o":"7FB71B8","s":"_ZN5mongo15printStackTraceEv","C":"mongo::printStackTrace()","s+":"38"},{"a":"56421D2B3B37","b":"564215302000","o":"7FB1B37","s":"abruptQuit","s+":"77"},{"a":"7F9252135D80","b":"7F9252123000","o":"12D80","s":"funlockfile","s+":"50"},{"a":"7F9251D9B5EF","b":"7F9251D4D000","o":"4E5EF","s":"gsignal","s+":"10F"},{"a":"7F9251D6EE65","b":"7F9251D4D000","o":"21E65","s":"abort","s+":"127"},{"a":"56421D2A57E7","b":"564215302000","o":"7FA37E7","s":"_ZN5mongo11DBException13traceIfNeededERKS0_","C":"mongo::DBException::traceIfNeeded(mongo::DBException const&)","s+":"207"},{"a":"56421D2A625F","b":"564215302000","o":"7FA425F","s":"_ZN5mongo25fassertFailedWithLocationEiPKcj","C":"mongo::fassertFailedWithLocation(int, char const*, unsigned int)","s+":"15E"},{"a":"56421A619AF5","b":"564215302000","o":"5317AF5","s":"_ZN5mongo36TransactionTooLargeForCacheException41defineOnlyInFinalSubclassToPreventSlicingEv","C":"mongo::TransactionTooLargeForCacheException::defineOnlyInFinalSubclassToPreventSlicing()","s+":"1E45"},{"a":"56421A7DC857","b":"564215302000","o":"54DA857","s":"__wt_encrypt_size","s+":"1757"},{"a":"56421A7DD475","b":"564215302000","o":"54DB475","s":"__wt_panic_func","s+":"156"},{"a":"56421A64392F","b":"564215302000","o":"534192F","s":"__wt_block_checkpoint_resolve","s+":"55F"},{"a":"56421A728CBC","b":"564215302000","o":"5426CBC","s":"__wt_meta_track_off","s+":"5DC"},{"a":"56421A803915","b":"564215302000","o":"5501915","s":"__wt_checkpoint_sync","s+":"A75"},{"a":"56421A804F16","b":"564215302000","o":"5502F16","s":"__wt_txn_checkpoint","s+":"116"},{"a":"56421A7ADC88","b":"564215302000","o":"54ABC88","s":"__wt_session_notsup","s+":"2009"},{"a":"56421A5AED98","b":"564215302000","o":"52ACD98","s":"_ZN5mongo18WiredTigerKVEngine11_checkpointEP12__wt_sessionb","C":"mongo::WiredTigerKVEngine::_checkpoint(__wt_session*, bool)","s+":"48"},{"a":"56421A5B935B","b":"564215302000","o":"52B735B","s":"_ZN5mongo18WiredTigerKVEngine11_checkpointEPNS_16OperationContextEP12__wt_session","C":"mongo::WiredTigerKVEngine::_checkpoint(mongo::OperationContext*, __wt_session*)","s+":"3BB"},{"a":"56421A5BB8D9","b":"564215302000","o":"52B98D9","s":"_ZN5mongo18WiredTigerKVEngine10checkpointEPNS_16OperationContextE","C":"mongo::WiredTigerKVEngine::checkpoint(mongo::OperationContext*)","s+":"49"},{"a":"56421AE95839","b":"564215302000","o":"5B93839","s":"_ZN5mongo12Checkpointer3runEv","C":"mongo::Checkpointer::run()","s+":"529"},{"a":"56421CFA9C1A","b":"564215302000","o":"7CA7C1A","s":"_ZN5mongo13BackgroundJob7jobBodyEv","C":"mongo::BackgroundJob::jobBody()","s+":"31A"},{"a":"56421CFA9FFC","b":"564215302000","o":"7CA7FFC","s":"_ZN5mongo13BackgroundJob7jobBodyEv","C":"mongo::BackgroundJob::jobBody()","s+":"6FC"},{"a":"56421D7FDA34","b":"564215302000","o":"84FBA34","s":"_ZNKSt10error_code23default_error_conditionEv","C":"std::error_code::default_error_condition() const","s+":"84"},{"a":"7F925212B1DA","b":"7F9252123000","o":"81DA","s":"start_thread","s+":"EA"},{"a":"7F9251D868D3","b":"7F9251D4D000","o":"398D3","s":"clone","s+":"43"}],"processInfo":{"mongodbVersion":"7.0.14-8","gitVersion":"4479fd75bea6bf98a934c29007352dd36f3e1db5","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":"564215302000","elfType":3,"buildId":"66937C4A678C7DB1AF31CEF100440614C213F407"},{"b":"7F9252123000","path":"/lib64/libpthread.so.0","elfType":3,"buildId":"0B813C2AD185DCA27DDB58BA42ACC172679B1526"},{"b":"7F9251D4D000","path":"/lib64/libc.so.6","elfType":3,"buildId":"BF4C06A1D77241A2D30436873E56C348FCBB5D22"}]}}},"tags":[]} {"t":{"$date":"2024-10-22T08:48:47.969+00:00"},"s":"I", "c":"CONTROL", "id":31445, "ctx":"Checkpointer","msg":"Frame","attr":{"frame":{"a":"56421D2B91B8","b":"564215302000","o":"7FB71B8","s":"_ZN5mongo15printStackTraceEv","C":"mongo::printStackTrace()","s+":"38"}}} {"t":{"$date":"2024-10-22T08:48:47.969+00:00"},"s":"I", "c":"CONTROL", "id":31445, "ctx":"Checkpointer","msg":"Frame","attr":{"frame":{"a":"56421D2B3B37","b":"564215302000","o":"7FB1B37","s":"abruptQuit","s+":"77"}}} {"t":{"$date":"2024-10-22T08:48:47.969+00:00"},"s":"I", "c":"CONTROL", "id":31445, "ctx":"Checkpointer","msg":"Frame","attr":{"frame":{"a":"7F9252135D80","b":"7F9252123000","o":"12D80","s":"funlockfile","s+":"50"}}} {"t":{"$date":"2024-10-22T08:48:47.969+00:00"},"s":"I", "c":"CONTROL", "id":31445, "ctx":"Checkpointer","msg":"Frame","attr":{"frame":{"a":"7F9251D9B5EF","b":"7F9251D4D000","o":"4E5EF","s":"gsignal","s+":"10F"}}} {"t":{"$date":"2024-10-22T08:48:47.969+00:00"},"s":"I", "c":"CONTROL", "id":31445, "ctx":"Checkpointer","msg":"Frame","attr":{"frame":{"a":"7F9251D6EE65","b":"7F9251D4D000","o":"21E65","s":"abort","s+":"127"}}} {"t":{"$date":"2024-10-22T08:48:47.969+00:00"},"s":"I", "c":"CONTROL", "id":31445, "ctx":"Checkpointer","msg":"Frame","attr":{"frame":{"a":"56421D2A57E7","b":"564215302000","o":"7FA37E7","s":"_ZN5mongo11DBException13traceIfNeededERKS0_","C":"mongo::DBException::traceIfNeeded(mongo::DBException const&)","s+":"207"}}} {"t":{"$date":"2024-10-22T08:48:47.969+00:00"},"s":"I", "c":"CONTROL", "id":31445, "ctx":"Checkpointer","msg":"Frame","attr":{"frame":{"a":"56421D2A625F","b":"564215302000","o":"7FA425F","s":"_ZN5mongo25fassertFailedWithLocationEiPKcj","C":"mongo::fassertFailedWithLocation(int, char const*, unsigned int)","s+":"15E"}}} {"t":{"$date":"2024-10-22T08:48:47.969+00:00"},"s":"I", "c":"CONTROL", "id":31445, "ctx":"Checkpointer","msg":"Frame","attr":{"frame":{"a":"56421A619AF5","b":"564215302000","o":"5317AF5","s":"_ZN5mongo36TransactionTooLargeForCacheException41defineOnlyInFinalSubclassToPreventSlicingEv","C":"mongo::TransactionTooLargeForCacheException::defineOnlyInFinalSubclassToPreventSlicing()","s+":"1E45"}}} {"t":{"$date":"2024-10-22T08:48:47.969+00:00"},"s":"I", "c":"CONTROL", "id":31445, "ctx":"Checkpointer","msg":"Frame","attr":{"frame":{"a":"56421A7DC857","b":"564215302000","o":"54DA857","s":"__wt_encrypt_size","s+":"1757"}}} {"t":{"$date":"2024-10-22T08:48:47.969+00:00"},"s":"I", "c":"CONTROL", "id":31445, "ctx":"Checkpointer","msg":"Frame","attr":{"frame":{"a":"56421A7DD475","b":"564215302000","o":"54DB475","s":"__wt_panic_func","s+":"156"}}} {"t":{"$date":"2024-10-22T08:48:47.969+00:00"},"s":"I", "c":"CONTROL", "id":31445, "ctx":"Checkpointer","msg":"Frame","attr":{"frame":{"a":"56421A64392F","b":"564215302000","o":"534192F","s":"__wt_block_checkpoint_resolve","s+":"55F"}}} {"t":{"$date":"2024-10-22T08:48:47.969+00:00"},"s":"I", "c":"CONTROL", "id":31445, "ctx":"Checkpointer","msg":"Frame","attr":{"frame":{"a":"56421A728CBC","b":"564215302000","o":"5426CBC","s":"__wt_meta_track_off","s+":"5DC"}}} {"t":{"$date":"2024-10-22T08:48:47.969+00:00"},"s":"I", "c":"CONTROL", "id":31445, "ctx":"Checkpointer","msg":"Frame","attr":{"frame":{"a":"56421A803915","b":"564215302000","o":"5501915","s":"__wt_checkpoint_sync","s+":"A75"}}} {"t":{"$date":"2024-10-22T08:48:47.969+00:00"},"s":"I", "c":"CONTROL", "id":31445, "ctx":"Checkpointer","msg":"Frame","attr":{"frame":{"a":"56421A804F16","b":"564215302000","o":"5502F16","s":"__wt_txn_checkpoint","s+":"116"}}} {"t":{"$date":"2024-10-22T08:48:47.969+00:00"},"s":"I", "c":"CONTROL", "id":31445, "ctx":"Checkpointer","msg":"Frame","attr":{"frame":{"a":"56421A7ADC88","b":"564215302000","o":"54ABC88","s":"__wt_session_notsup","s+":"2009"}}} {"t":{"$date":"2024-10-22T08:48:47.969+00:00"},"s":"I", "c":"CONTROL", "id":31445, "ctx":"Checkpointer","msg":"Frame","attr":{"frame":{"a":"56421A5AED98","b":"564215302000","o":"52ACD98","s":"_ZN5mongo18WiredTigerKVEngine11_checkpointEP12__wt_sessionb","C":"mongo::WiredTigerKVEngine::_checkpoint(__wt_session*, bool)","s+":"48"}}} {"t":{"$date":"2024-10-22T08:48:47.969+00:00"},"s":"I", "c":"CONTROL", "id":31445, "ctx":"Checkpointer","msg":"Frame","attr":{"frame":{"a":"56421A5B935B","b":"564215302000","o":"52B735B","s":"_ZN5mongo18WiredTigerKVEngine11_checkpointEPNS_16OperationContextEP12__wt_session","C":"mongo::WiredTigerKVEngine::_checkpoint(mongo::OperationContext*, __wt_session*)","s+":"3BB"}}} {"t":{"$date":"2024-10-22T08:48:47.969+00:00"},"s":"I", "c":"CONTROL", "id":31445, "ctx":"Checkpointer","msg":"Frame","attr":{"frame":{"a":"56421A5BB8D9","b":"564215302000","o":"52B98D9","s":"_ZN5mongo18WiredTigerKVEngine10checkpointEPNS_16OperationContextE","C":"mongo::WiredTigerKVEngine::checkpoint(mongo::OperationContext*)","s+":"49"}}} {"t":{"$date":"2024-10-22T08:48:47.969+00:00"},"s":"I", "c":"CONTROL", "id":31445, "ctx":"Checkpointer","msg":"Frame","attr":{"frame":{"a":"56421AE95839","b":"564215302000","o":"5B93839","s":"_ZN5mongo12Checkpointer3runEv","C":"mongo::Checkpointer::run()","s+":"529"}}} {"t":{"$date":"2024-10-22T08:48:47.969+00:00"},"s":"I", "c":"CONTROL", "id":31445, "ctx":"Checkpointer","msg":"Frame","attr":{"frame":{"a":"56421CFA9C1A","b":"564215302000","o":"7CA7C1A","s":"_ZN5mongo13BackgroundJob7jobBodyEv","C":"mongo::BackgroundJob::jobBody()","s+":"31A"}}} {"t":{"$date":"2024-10-22T08:48:47.969+00:00"},"s":"I", "c":"CONTROL", "id":31445, "ctx":"Checkpointer","msg":"Frame","attr":{"frame":{"a":"56421CFA9FFC","b":"564215302000","o":"7CA7FFC","s":"_ZN5mongo13BackgroundJob7jobBodyEv","C":"mongo::BackgroundJob::jobBody()","s+":"6FC"}}} {"t":{"$date":"2024-10-22T08:48:47.969+00:00"},"s":"I", "c":"CONTROL", "id":31445, "ctx":"Checkpointer","msg":"Frame","attr":{"frame":{"a":"56421D7FDA34","b":"564215302000","o":"84FBA34","s":"_ZNKSt10error_code23default_error_conditionEv","C":"std::error_code::default_error_condition() const","s+":"84"}}} {"t":{"$date":"2024-10-22T08:48:47.969+00:00"},"s":"I", "c":"CONTROL", "id":31445, "ctx":"Checkpointer","msg":"Frame","attr":{"frame":{"a":"7F925212B1DA","b":"7F9252123000","o":"81DA","s":"start_thread","s+":"EA"}}} {"t":{"$date":"2024-10-22T08:48:47.969+00:00"},"s":"I", "c":"CONTROL", "id":31445, "ctx":"Checkpointer","msg":"Frame","attr":{"frame":{"a":"7F9251D868D3","b":"7F9251D4D000","o":"398D3","s":"clone","s+":"43"}}}

Process completed with exit code 1.

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