Upgrading to new operator i got this error when backup agent is spinend up:
│ Warning Failed 5m39s (x3 over 5m43s) kubelet Error: couldn’t find key MONGODB_BACKUP_USER_ESCAPED in Secret vcluster–accel-webapp-dev/internal-elog-plus-cluster-users-x-elog-plus-x-vclus-d │
│ d954fa438
Hi @Claudio_Bisegni, how can we reproduce it? Did you perform update from 1.18.0? We need to have STR. Thank you.
hi @Slava_Sarzhan what is a STR? yes i started from a working 1.18.0 setup and upgraded at the beginning the crd, then upgraded the cr, operator and rback resources
STR (steps to reproduce). Please check our documentation Upgrade MongoDB and the Operator - Percona Operator for MongoDB
As you can see you the order should be the following:
- CRD
- RBAC
- operator update
- bump CR version
Could you please recheck this way?
i tryed now the backup is started bu the databse stop in this way:
{"t":{"$date":"2025-01-22T19:54:50.713Z"},"s":"W", "c":"CONTROL", "id":23321, "ctx":"main","msg":"Option: This name is deprecated. Please use the preferred name instead.","attr":{"deprecatedName":"sslPEMKeyFile","preferredName":"tlsCertificateKeyFile"}}
{"t":{"$date":"2025-01-22T19:54:50.723+00:00"},"s":"I", "c":"NETWORK", "id":4913010, "ctx":"main","msg":"Certificate information","attr":{"subject":"CN=elog-plus-cluster,O=PSMDB","issuer":"CN=elog-plus-cluster-ca","thumbprint":"7ED05F081F4EAE162BF15802DC547F6302995639","notValidBefore":{"$date":"2025-01-02T19:19:59.000Z"},"notValidAfter":{"$date":"2025-04-02T19:19:59.000Z"},"keyFile":"/tmp/tls.pem","type":"Server"}}
{"t":{"$date":"2025-01-22T19:54:50.723+00:00"},"s":"I", "c":"NETWORK", "id":4913011, "ctx":"main","msg":"Certificate information","attr":{"subject":"CN=elog-plus-cluster,O=PSMDB","issuer":"CN=elog-plus-cluster-ca","thumbprint":"6DEACA48FF80729D43CB39104F42DE99EF2D9D52","notValidBefore":{"$date":"2025-01-02T19:20:00.000Z"},"notValidAfter":{"$date":"2025-04-02T19:20:00.000Z"},"keyFile":"/tmp/tls-internal.pem","type":"Cluster"}}
{"t":{"$date":"2025-01-22T19:54:50.725+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":"2025-01-22T19:54:50.725+00:00"},"s":"I", "c":"CONTROL", "id":5945603, "ctx":"main","msg":"Multi threading initialized"}
{"t":{"$date":"2025-01-22T19:54:50.725+00:00"},"s":"I", "c":"NETWORK", "id":4648601, "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":"2025-01-22T19:54:50.727+00:00"},"s":"I", "c":"NETWORK", "id":4915701, "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":"2025-01-22T19:54:50.728+00:00"},"s":"I", "c":"TENANT_M", "id":7091600, "ctx":"main","msg":"Starting TenantMigrationAccessBlockerRegistry"}
{"t":{"$date":"2025-01-22T19:54:50.728+00:00"},"s":"I", "c":"CONTROL", "id":4615611, "ctx":"initandlisten","msg":"MongoDB starting","attr":{"pid":1,"port":27017,"dbPath":"/data/db","architecture":"64-bit","host":"elog-plus-cluster-rs0-1"}}
{"t":{"$date":"2025-01-22T19:54:50.728+00:00"},"s":"W", "c":"CONTROL", "id":20720, "ctx":"initandlisten","msg":"Memory available to mongo process is less than total system memory","attr":{"availableMemSizeMB":3814,"systemMemSizeMB":257433}}
{"t":{"$date":"2025-01-22T19:54:50.728+00:00"},"s":"I", "c":"CONTROL", "id":23403, "ctx":"initandlisten","msg":"Build Info","attr":{"buildInfo":{"version":"8.0.4-1","gitVersion":"157769d6f2e4e9748360353504ac7720132b5863","openSSLVersion":"OpenSSL 1.1.1k FIPS 25 Mar 2021","modules":],"proFeatures":],"allocator":"tcmalloc-google","environment":{"distarch":"x86_64","target_arch":"x86_64"}}}}
{"t":{"$date":"2025-01-22T19:54:50.728+00:00"},"s":"I", "c":"CONTROL", "id":51765, "ctx":"initandlisten","msg":"Operating System","attr":{"os":{"name":"Oracle Linux Server release 8.10","version":"Kernel 4.18.0-372.32.1.el8_6.x86_64"}}}
{"t":{"$date":"2025-01-22T19:54:50.728+00:00"},"s":"I", "c":"CONTROL", "id":21951, "ctx":"initandlisten","msg":"Options set by command line","attr":{"options":{"net":{"bindIp":"*","port":27017,"tls":{"CAFile":"/etc/mongodb-ssl/ca.crt","allowInvalidCertificates":true,"certificateKeyFile":"/tmp/tls.pem","clusterCAFile":"/etc/mongodb-ssl-internal/ca.crt","clusterFile":"/tmp/tls-internal.pem","mode":"preferTLS"}},"replication":{"replSet":"rs0"},"security":{"authorization":"enabled","clusterAuthMode":"x509","enableEncryption":true,"encryptionKeyFile":"/etc/mongodb-encryption/encryption-key","relaxPermChecks":true},"storage":{"dbPath":"/data/db","engine":"wiredTiger","wiredTiger":{"engineConfig":{"cacheSizeGB":1.36},"indexConfig":{"prefixCompression":true}}},"systemLog":{"quiet":true}}}}
{"t":{"$date":"2025-01-22T19:54:50.746+00:00"},"s":"I", "c":"STORAGE", "id":29115, "ctx":"initandlisten","msg":"Master encryption key has been read from the key management facility.","attr":{"keyManagementFacilityType":"encryption key file","keyIdentifier":{"encryptionKeyFilePath":"/etc/mongodb-encryption/encryption-key"}}}
{"t":{"$date":"2025-01-22T19:54:50.746+00:00"},"s":"I", "c":"STORAGE", "id":29037, "ctx":"initandlisten","msg":"Initializing KeyDB with wiredtiger_open config: {cfg}","attr":{"cfg":"create,config_base=false,extensions=[local=(entry=percona_encryption_extension_init,early_load=true,config=(cipher=AES256-CBC,rotation=false))],encryption=(name=percona,keyid=\"\"),log=(enabled,file_max=5MB),transaction_sync=(enabled=true,method=fsync),"}}
{"t":{"$date":"2025-01-22T19:54:50.923+00:00"},"s":"I", "c":"STORAGE", "id":29039, "ctx":"initandlisten","msg":"Encryption keys DB is initialized successfully"}
{"t":{"$date":"2025-01-22T19:54:50.923+00:00"},"s":"I", "c":"STORAGE", "id":22315, "ctx":"initandlisten","msg":"Opening WiredTiger","attr":{"config":"create,cache_size=1392M,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),encryption=(name=percona,keyid=\"/default\"),extensions=[local=(entry=percona_encryption_extension_init,early_load=true,config=(cipher=AES256-CBC)),],"}}
{"t":{"$date":"2025-01-22T19:54:50.940+00:00"},"s":"I", "c":"WTRECOV", "id":22430, "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":{"ts_sec":1737575690,"ts_usec":940693,"thread":"1:0x7fc9acb68180","session_name":"txn-recover","category":"WT_VERB_RECOVERY_PROGRESS","category_id":34,"verbose_level":"DEBUG_1","verbose_level_id":1,"msg":"Recovering log 389 through 390"}}}
{"t":{"$date":"2025-01-22T19:54:50.964+00:00"},"s":"I", "c":"WTRECOV", "id":22430, "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":{"ts_sec":1737575690,"ts_usec":964794,"thread":"1:0x7fc9acb68180","session_name":"txn-recover","category":"WT_VERB_RECOVERY_PROGRESS","category_id":34,"verbose_level":"DEBUG_1","verbose_level_id":1,"msg":"Recovering log 390 through 390"}}}
{"t":{"$date":"2025-01-22T19:54:51.054+00:00"},"s":"I", "c":"WTRECOV", "id":22430, "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":{"ts_sec":1737575691,"ts_usec":54746,"thread":"1:0x7fc9acb68180","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 389/2432 to 390/256"}}}
{"t":{"$date":"2025-01-22T19:54:51.111+00:00"},"s":"I", "c":"WTRECOV", "id":22430, "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":{"ts_sec":1737575691,"ts_usec":111686,"thread":"1:0x7fc9acb68180","session_name":"txn-recover","category":"WT_VERB_RECOVERY_PROGRESS","category_id":34,"verbose_level":"DEBUG_1","verbose_level_id":1,"msg":"Recovering log 389 through 390"}}}
{"t":{"$date":"2025-01-22T19:54:51.149+00:00"},"s":"I", "c":"WTRECOV", "id":22430, "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":{"ts_sec":1737575691,"ts_usec":149264,"thread":"1:0x7fc9acb68180","session_name":"txn-recover","category":"WT_VERB_RECOVERY_PROGRESS","category_id":34,"verbose_level":"DEBUG_1","verbose_level_id":1,"msg":"Recovering log 390 through 390"}}}
{"t":{"$date":"2025-01-22T19:54:51.176+00:00"},"s":"I", "c":"WTRECOV", "id":22430, "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":{"ts_sec":1737575691,"ts_usec":176009,"thread":"1:0x7fc9acb68180","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 235 milliseconds"}}}
{"t":{"$date":"2025-01-22T19:54:51.176+00:00"},"s":"I", "c":"WTRECOV", "id":22430, "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":{"ts_sec":1737575691,"ts_usec":176103,"thread":"1:0x7fc9acb68180","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: (1737575652, 1)"}}}
{"t":{"$date":"2025-01-22T19:54:51.176+00:00"},"s":"I", "c":"WTRECOV", "id":22430, "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":{"ts_sec":1737575691,"ts_usec":176121,"thread":"1:0x7fc9acb68180","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: (1737575352, 1)"}}}
{"t":{"$date":"2025-01-22T19:54:51.178+00:00"},"s":"I", "c":"WTRECOV", "id":22430, "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":{"ts_sec":1737575691,"ts_usec":178727,"thread":"1:0x7fc9acb68180","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 2 milliseconds"}}}
{"t":{"$date":"2025-01-22T19:54:51.182+00:00"},"s":"I", "c":"WTCHKPT", "id":22430, "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":{"ts_sec":1737575691,"ts_usec":182284,"thread":"1:0x7fc9acb68180","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: (1737575352, 1) , meta checkpoint timestamp: (1737575652, 1) base write gen: 35188739"}}}
{"t":{"$date":"2025-01-22T19:54:51.184+00:00"},"s":"I", "c":"WTRECOV", "id":22430, "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":{"ts_sec":1737575691,"ts_usec":184909,"thread":"1:0x7fc9acb68180","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 6 milliseconds"}}}
{"t":{"$date":"2025-01-22T19:54:51.185+00:00"},"s":"I", "c":"WTRECOV", "id":22430, "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":{"ts_sec":1737575691,"ts_usec":185125,"thread":"1:0x7fc9acb68180","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 244ms, including 235ms for the log replay, 2ms for the rollback to stable, and 6ms for the checkpoint."}}}
{"t":{"$date":"2025-01-22T19:54:51.186+00:00"},"s":"I", "c":"STORAGE", "id":4795906, "ctx":"initandlisten","msg":"WiredTiger opened","attr":{"durationMillis":263}}
{"t":{"$date":"2025-01-22T19:54:51.186+00:00"},"s":"I", "c":"RECOVERY", "id":23987, "ctx":"initandlisten","msg":"WiredTiger recoveryTimestamp","attr":{"recoveryTimestamp":{"$timestamp":{"t":1737575652,"i":1}}}}
{"t":{"$date":"2025-01-22T19:54:51.186+00:00"},"s":"I", "c":"RECOVERY", "id":5380106, "ctx":"initandlisten","msg":"WiredTiger oldestTimestamp","attr":{"oldestTimestamp":{"$timestamp":{"t":1737575352,"i":1}}}}
{"t":{"$date":"2025-01-22T19:54:51.206+00:00"},"s":"I", "c":"STORAGE", "id":7393203, "ctx":"initandlisten","msg":"The size storer reports that the collection contains","attr":{"numRecords":9581761,"dataSize":5333363105}}
{"t":{"$date":"2025-01-22T19:54:51.206+00:00"},"s":"I", "c":"STORAGE", "id":7393210, "ctx":"initandlisten","msg":"Sampling the collection to determine where to place markers for truncation","attr":{"namespace":"local.oplog.rs"}}
{"t":{"$date":"2025-01-22T19:54:51.207+00:00"},"s":"I", "c":"STORAGE", "id":7393207, "ctx":"initandlisten","msg":"Sampling from the collection to determine where to place markers for truncation","attr":{"namespace":"local.oplog.rs","from":"7363647851907252225","to":"7462830599665876993"}}
{"t":{"$date":"2025-01-22T19:54:51.207+00:00"},"s":"I", "c":"STORAGE", "id":7393216, "ctx":"initandlisten","msg":"Taking samples and assuming each collection section contains equal amounts","attr":{"namespace":"local.oplog.rs","numSamples":993,"containsNumRecords":96453,"containsNumBytes":53687299}}
{"t":{"$date":"2025-01-22T19:54:51.649+00:00"},"s":"I", "c":"STORAGE", "id":7393205, "ctx":"initandlisten","msg":"Collection sampling complete","attr":{"namespace":"local.oplog.rs"}}
{"t":{"$date":"2025-01-22T19:54:51.649+00:00"},"s":"I", "c":"STORAGE", "id":22382, "ctx":"initandlisten","msg":"WiredTiger record store oplog processing finished","attr":{"durationMillis":442}}
{"t":{"$date":"2025-01-22T19:54:51.662+00:00"},"s":"W", "c":"CONTROL", "id":22124, "ctx":"initandlisten","msg":"While invalid X509 certificates may be used to connect to this server, they will not be considered permissible for authentication","tags":["startupWarnings"]}
{"t":{"$date":"2025-01-22T19:54:51.662+00:00"},"s":"W", "c":"CONTROL", "id":9068900, "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":"2025-01-22T19:54:51.662+00:00"},"s":"W", "c":"CONTROL", "id":8640302, "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":"2025-01-22T19:54:51.662+00:00"},"s":"W", "c":"NETWORK", "id":5123300, "ctx":"initandlisten","msg":"vm.max_map_count is too low","attr":{"currentValue":65530,"recommendedMinimum":1677720,"maxConns":838860},"tags":["startupWarnings"]}
{"t":{"$date":"2025-01-22T19:54:51.673+00:00"},"s":"F", "c":"CONTROL", "id":20573, "ctx":"initandlisten","msg":"Wrong mongod version","attr":{"error":"UPGRADE PROBLEM: Found an invalid featureCompatibilityVersion document (ERROR: Location4926900: Invalid featureCompatibilityVersion document in admin.system.version: { _id: \"featureCompatibilityVersion\", version: \"6.0\" }. See https://docs.mongodb.com/master/release-notes/7.0-compatibility/#feature-compatibility. :: caused by :: Invalid feature compatibility version value '6.0'; expected '7.0' or '7.3' or '8.0'. See https://docs.mongodb.com/master/release-notes/7.0-compatibility/#feature-compatibility.). If the current featureCompatibilityVersion is below 7.0, see the documentation on upgrading at https://docs.mongodb.com/master/release-notes/7.0/#upgrade-procedures."}}
{"t":{"$date":"2025-01-22T19:54:51.673+00:00"},"s":"I", "c":"REPL", "id":4784900, "ctx":"initandlisten","msg":"Stepping down the ReplicationCoordinator for shutdown","attr":{"waitTimeMillis":15000}}
{"t":{"$date":"2025-01-22T19:54:51.673+00:00"},"s":"I", "c":"REPL", "id":4794602, "ctx":"initandlisten","msg":"Attempting to enter quiesce mode"}
{"t":{"$date":"2025-01-22T19:54:51.673+00:00"},"s":"I", "c":"-", "id":6371601, "ctx":"initandlisten","msg":"Shutting down the FLE Crud thread pool"}
{"t":{"$date":"2025-01-22T19:54:51.673+00:00"},"s":"I", "c":"COMMAND", "id":4784901, "ctx":"initandlisten","msg":"Shutting down the MirrorMaestro"}
{"t":{"$date":"2025-01-22T19:54:51.673+00:00"},"s":"I", "c":"SHARDING", "id":4784902, "ctx":"initandlisten","msg":"Shutting down the WaitForMajorityService"}
{"t":{"$date":"2025-01-22T19:54:51.673+00:00"},"s":"I", "c":"-", "id":7350601, "ctx":"initandlisten","msg":"Shutting down the QueryAnalysisSampler"}
{"t":{"$date":"2025-01-22T19:54:51.673+00:00"},"s":"I", "c":"NETWORK", "id":8314100, "ctx":"initandlisten","msg":"Shutdown: Closing listener sockets"}
{"t":{"$date":"2025-01-22T19:54:51.673+00:00"},"s":"I", "c":"NETWORK", "id":4784905, "ctx":"initandlisten","msg":"Shutting down the global connection pool"}
{"t":{"$date":"2025-01-22T19:54:51.673+00:00"},"s":"I", "c":"CONTROL", "id":4784906, "ctx":"initandlisten","msg":"Shutting down the FlowControlTicketholder"}
{"t":{"$date":"2025-01-22T19:54:51.673+00:00"},"s":"I", "c":"-", "id":20520, "ctx":"initandlisten","msg":"Stopping further Flow Control ticket acquisitions."}
{"t":{"$date":"2025-01-22T19:54:51.673+00:00"},"s":"I", "c":"REPL", "id":4784907, "ctx":"initandlisten","msg":"Shutting down the replica set node executor"}
{"t":{"$date":"2025-01-22T19:54:51.673+00:00"},"s":"I", "c":"CONTROL", "id":4784908, "ctx":"initandlisten","msg":"Shutting down the PeriodicThreadToAbortExpiredTransactions"}
{"t":{"$date":"2025-01-22T19:54:51.673+00:00"},"s":"I", "c":"REPL", "id":4784909, "ctx":"initandlisten","msg":"Shutting down the ReplicationCoordinator"}
{"t":{"$date":"2025-01-22T19:54:51.673+00:00"},"s":"I", "c":"REPL", "id":5074000, "ctx":"initandlisten","msg":"Shutting down the replica set aware services."}
{"t":{"$date":"2025-01-22T19:54:51.673+00:00"},"s":"I", "c":"REPL", "id":21328, "ctx":"initandlisten","msg":"Shutting down replication subsystems"}
{"t":{"$date":"2025-01-22T19:54:51.673+00:00"},"s":"W", "c":"REPL", "id":21409, "ctx":"initandlisten","msg":"ReplicationCoordinatorImpl::shutdown() called before startup() finished. Shutting down without cleaning up the replication system"}
{"t":{"$date":"2025-01-22T19:54:51.673+00:00"},"s":"I", "c":"SHARDING", "id":4784910, "ctx":"initandlisten","msg":"Shutting down the ShardingInitializationMongoD"}
{"t":{"$date":"2025-01-22T19:54:51.673+00:00"},"s":"I", "c":"REPL", "id":4784911, "ctx":"initandlisten","msg":"Enqueuing the ReplicationStateTransitionLock for shutdown"}
{"t":{"$date":"2025-01-22T19:54:51.673+00:00"},"s":"I", "c":"-", "id":4784912, "ctx":"initandlisten","msg":"Killing all operations for shutdown"}
{"t":{"$date":"2025-01-22T19:54:51.673+00:00"},"s":"I", "c":"-", "id":4695300, "ctx":"initandlisten","msg":"Interrupted all currently running operations","attr":{"opsKilled":4}}
{"t":{"$date":"2025-01-22T19:54:51.673+00:00"},"s":"I", "c":"TENANT_M", "id":5093807, "ctx":"initandlisten","msg":"Shutting down all TenantMigrationAccessBlockers on global shutdown"}
{"t":{"$date":"2025-01-22T19:54:51.673+00:00"},"s":"I", "c":"ASIO", "id":22582, "ctx":"TenantMigrationBlockerNet","msg":"Killing all outstanding egress activity."}
{"t":{"$date":"2025-01-22T19:54:51.674+00:00"},"s":"I", "c":"ASIO", "id":6529201, "ctx":"initandlisten","msg":"Network interface redundant shutdown","attr":{"state":"Stopped"}}
{"t":{"$date":"2025-01-22T19:54:51.674+00:00"},"s":"I", "c":"ASIO", "id":22582, "ctx":"initandlisten","msg":"Killing all outstanding egress activity."}
{"t":{"$date":"2025-01-22T19:54:51.674+00:00"},"s":"I", "c":"COMMAND", "id":4784913, "ctx":"initandlisten","msg":"Shutting down all open transactions"}
{"t":{"$date":"2025-01-22T19:54:51.674+00:00"},"s":"I", "c":"REPL", "id":4784914, "ctx":"initandlisten","msg":"Acquiring the ReplicationStateTransitionLock for shutdown"}
{"t":{"$date":"2025-01-22T19:54:51.674+00:00"},"s":"I", "c":"INDEX", "id":4784915, "ctx":"initandlisten","msg":"Shutting down the IndexBuildsCoordinator"}
{"t":{"$date":"2025-01-22T19:54:51.674+00:00"},"s":"I", "c":"NETWORK", "id":4784918, "ctx":"initandlisten","msg":"Shutting down the ReplicaSetMonitor"}
{"t":{"$date":"2025-01-22T19:54:51.674+00:00"},"s":"I", "c":"SHARDING", "id":4784921, "ctx":"initandlisten","msg":"Shutting down the MigrationUtilExecutor"}
{"t":{"$date":"2025-01-22T19:54:51.674+00:00"},"s":"I", "c":"ASIO", "id":22582, "ctx":"MigrationUtil-TaskExecutor","msg":"Killing all outstanding egress activity."}
{"t":{"$date":"2025-01-22T19:54:51.674+00:00"},"s":"I", "c":"NETWORK", "id":20562, "ctx":"initandlisten","msg":"Shutdown: Closing open transport sessions"}
{"t":{"$date":"2025-01-22T19:54:51.674+00:00"},"s":"I", "c":"NETWORK", "id":4784923, "ctx":"initandlisten","msg":"Shutting down the ASIO transport SessionManager"}
{"t":{"$date":"2025-01-22T19:54:51.674+00:00"},"s":"I", "c":"CONTROL", "id":4784928, "ctx":"initandlisten","msg":"Shutting down the TTL monitor"}
{"t":{"$date":"2025-01-22T19:54:51.674+00:00"},"s":"I", "c":"CONTROL", "id":6278511, "ctx":"initandlisten","msg":"Shutting down the Change Stream Expired Pre-images Remover"}
{"t":{"$date":"2025-01-22T19:54:51.674+00:00"},"s":"I", "c":"CONTROL", "id":4784929, "ctx":"initandlisten","msg":"Acquiring the global lock for shutdown"}
{"t":{"$date":"2025-01-22T19:54:51.674+00:00"},"s":"I", "c":"CONTROL", "id":4784930, "ctx":"initandlisten","msg":"Shutting down the storage engine"}
{"t":{"$date":"2025-01-22T19:54:51.674+00:00"},"s":"I", "c":"STORAGE", "id":22320, "ctx":"initandlisten","msg":"Shutting down journal flusher thread"}
{"t":{"$date":"2025-01-22T19:54:51.674+00:00"},"s":"I", "c":"STORAGE", "id":22321, "ctx":"initandlisten","msg":"Finished shutting down journal flusher thread"}
{"t":{"$date":"2025-01-22T19:54:51.674+00:00"},"s":"I", "c":"STORAGE", "id":22322, "ctx":"initandlisten","msg":"Shutting down checkpoint thread"}
{"t":{"$date":"2025-01-22T19:54:51.674+00:00"},"s":"I", "c":"STORAGE", "id":22323, "ctx":"initandlisten","msg":"Finished shutting down checkpoint thread"}
{"t":{"$date":"2025-01-22T19:54:51.674+00:00"},"s":"I", "c":"STORAGE", "id":20282, "ctx":"initandlisten","msg":"Deregistering all the collections"}
{"t":{"$date":"2025-01-22T19:54:51.674+00:00"},"s":"I", "c":"STORAGE", "id":22372, "ctx":"OplogVisibilityThread","msg":"Oplog visibility thread shutting down."}
{"t":{"$date":"2025-01-22T19:54:51.674+00:00"},"s":"I", "c":"STORAGE", "id":22317, "ctx":"initandlisten","msg":"WiredTigerKVEngine shutting down"}
{"t":{"$date":"2025-01-22T19:54:51.674+00:00"},"s":"I", "c":"STORAGE", "id":22318, "ctx":"initandlisten","msg":"Shutting down session sweeper thread"}
{"t":{"$date":"2025-01-22T19:54:51.674+00:00"},"s":"I", "c":"STORAGE", "id":22319, "ctx":"initandlisten","msg":"Finished shutting down session sweeper thread"}
{"t":{"$date":"2025-01-22T19:54:51.674+00:00"},"s":"I", "c":"STORAGE", "id":4795902, "ctx":"initandlisten","msg":"Closing WiredTiger","attr":{"closeConfig":"leak_memory=true,"}}
{"t":{"$date":"2025-01-22T19:54:51.677+00:00"},"s":"I", "c":"WTRECOV", "id":22430, "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":{"ts_sec":1737575691,"ts_usec":677312,"thread":"1:0x7fc9acb68180","session_name":"WT_CONNECTION.close","category":"WT_VERB_RECOVERY_PROGRESS","category_id":34,"verbose_level":"DEBUG_1","verbose_level_id":1,"msg":"shutdown rollback to stable has successfully finished and ran for 2 milliseconds"}}}
{"t":{"$date":"2025-01-22T19:54:51.677+00:00"},"s":"I", "c":"WTCHKPT", "id":22430, "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":{"ts_sec":1737575691,"ts_usec":677977,"thread":"1:0x7fc9acb68180","session_name":"close_ckpt","category":"WT_VERB_CHECKPOINT_PROGRESS","category_id":7,"verbose_level":"DEBUG_1","verbose_level_id":1,"msg":"saving checkpoint snapshot min: 2, snapshot max: 2 snapshot count: 0, oldest timestamp: (1737575352, 1) , meta checkpoint timestamp: (1737575652, 1) base write gen: 35188739"}}}
{"t":{"$date":"2025-01-22T19:54:51.680+00:00"},"s":"I", "c":"WTRECOV", "id":22430, "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":{"ts_sec":1737575691,"ts_usec":680417,"thread":"1:0x7fc9acb68180","session_name":"WT_CONNECTION.close","category":"WT_VERB_RECOVERY_PROGRESS","category_id":34,"verbose_level":"DEBUG_1","verbose_level_id":1,"msg":"shutdown checkpoint has successfully finished and ran for 3 milliseconds"}}}
{"t":{"$date":"2025-01-22T19:54:51.680+00:00"},"s":"I", "c":"WTRECOV", "id":22430, "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":{"ts_sec":1737575691,"ts_usec":680502,"thread":"1:0x7fc9acb68180","session_name":"WT_CONNECTION.close","category":"WT_VERB_RECOVERY_PROGRESS","category_id":34,"verbose_level":"DEBUG_1","verbose_level_id":1,"msg":"shutdown was completed successfully and took 5ms, including 2ms for the rollback to stable, and 3ms for the checkpoint."}}}
{"t":{"$date":"2025-01-22T19:54:51.695+00:00"},"s":"I", "c":"STORAGE", "id":4795901, "ctx":"initandlisten","msg":"WiredTiger closed","attr":{"durationMillis":21}}
{"t":{"$date":"2025-01-22T19:54:51.702+00:00"},"s":"I", "c":"STORAGE", "id":22279, "ctx":"initandlisten","msg":"shutdown: removing fs lock..."}
{"t":{"$date":"2025-01-22T19:54:51.702+00:00"},"s":"I", "c":"-", "id":4784931, "ctx":"initandlisten","msg":"Dropping the scope cache for shutdown"}
{"t":{"$date":"2025-01-22T19:54:51.702+00:00"},"s":"I", "c":"CONTROL", "id":20565, "ctx":"initandlisten","msg":"Now exiting"}
{"t":{"$date":"2025-01-22T19:54:51.702+00:00"},"s":"I", "c":"CONTROL", "id":8423404, "ctx":"initandlisten","msg":"mongod shutdown complete","attr":{"Summary of time elapsed":{"Statistics":{"Enter terminal shutdown":"0 ms","Step down the replication coordinator for shutdown":"0 ms","Time spent in quiesce mode":"0 ms","Shut down FLE Crud subsystem":"0 ms","Shut down MirrorMaestro":"0 ms","Shut down WaitForMajorityService":"0 ms","Shut down the Query Analysis Sampler":"0 ms","Shut down the global connection pool":"0 ms","Shut down the flow control ticket holder":"0 ms","Shut down the replica set node executor":"0 ms","Shut down the thread that aborts expired transactions":"0 ms","Shut down the replica set aware services":"0 ms","Kill all operations for shutdown":"0 ms","Shut down all tenant migration access blockers on global shutdown":"1 ms","Shut down all open transactions":"0 ms","Acquire the RSTL for shutdown":"0 ms","Shut down the IndexBuildsCoordinator and wait for index builds to finish":"0 ms","Shut down the replica set monitor":"0 ms","Shut down the migration util executor":"0 ms","Shut down the transport layer":"0 ms","Shut down the TTL monitor":"0 ms","Shut down expired pre-images and documents removers":"0 ms","Shut down the storage engine":"28 ms","Wait for the oplog cap maintainer thread to stop":"0 ms","Shut down full-time data capture":"0 ms","Shut down online certificate status protocol manager":"0 ms","shutdownTask total elapsed time":"29 ms"}}}}
{"t":{"$date":"2025-01-22T19:54:51.702+00:00"},"s":"I", "c":"CONTROL", "id":23138, "ctx":"initandlisten","msg":"Shutting down","attr":{"exitCode":62}}
stream closed EOF for elog-plus/elog-plus-cluster-rs0-1 (mongod)
this below is the state of the pod:
I1 mongo-init ● percona/percona-server-mongodb-operator:1.19.0 true Completed 0 off:off:off 300:4000 476:3814 2m46
M1 mongod ● percona/percona-server-mongodb:8.0.4-1-multi false CrashLoopBackOff 4 on:on:off 300:4000 476:3814 mongodb:27017 2m46
M2 mongodb-exporter ● percona/mongodb_exporter:2.37.0 true Running 0 off:off:off 0:0 0:0 2m46
M3 backup-agent ● percona/percona-backup-mongodb:2.8.0-multi true Running 0 off:off:off 300:1000 476:3814 2m46
i think the porblme is the : featureCompatibilityVersion issue
i tried to set up the upgrade option but it didn’t’ worked:
upgradeOptions:
versionServiceEndpoint: https://check.percona.com
apply: Disabled
schedule: "0 2 * * *"
setFCV: true
usualy i want to make the update by hand so i let it disable, but in this case i should enable it, let the db upgrade the feature, and then disable it again?
@Claudio_Bisegni Did you update PSMDB version as well?
do you mean this?:
apiVersion: psmdb.percona.com/v1
kind: PerconaServerMongoDB
metadata:
name: elog-plus-cluster
finalizers:
- percona.com/delete-psmdb-pods-in-order
spec:
crVersion: 1.19.0
image: percona/percona-server-mongodb:8.0.4-1-multi
imagePullPolicy: Always
allowUnsafeConfigurations: false
updateStrategy: SmartUpdate
upgradeOptions:
versionServiceEndpoint: https://check.percona.com
apply: Disabled
schedule: "0 2 * * *"
setFCV: true
...
yes, I am about images for all components like
percona/percona-server-mongodb:8.0.4-1-multi
and
percona/percona-backup-mongodb:2.8.0-multi
If yes, try to split operator update and PSMDB and PBM version update.
We recommend the following way:
- Perform operator update
- Bump crVersion to 1.19.0 (wait and check that all works)
- set new PBM and new PSMDB image but a major version of PSMDB should be the same
- Start major update of PSMDB if needed (e.g. from 7 to 8)
Thank you @Slava_Sarzhan, ok i made this and work but using all new except the mongodb
7.0.15-9-multi
the problem is the update of the mongodb to version 8.0 cause my featureVersion that is still at 6.0.
my question now is, how can upgrdae the featureVersion without enable the upgradeOptions
, i want to do the upgrade by hand so coudl i use that flow below?:
- upgrade
spec.image
→percona/percona-server-mongodb:8.0.4-1-multi
- upgrade
spec.upgradeOptions.apply
→ true - apply wiat for all and then
- upgrade
spec.upgradeOptions.apply
→ false
or there is a better way?
The setFCV flag is independend and you should not enable auto (spec.upgradeOptions.apply) update to use it.
ok i will upgrade the mondodb version along with that flag like below:
spec:
crVersion: 1.19.0
image: percona/percona-server-mongodb:8.0.4-1-multi
imagePullPolicy: Always
allowUnsafeConfigurations: false
updateStrategy: RollingUpdate
upgradeOptions:
versionServiceEndpoint: https://check.percona.com
apply: Disabled
schedule: "0 2 * * *"
setFCV: true
i’ll try and i’ll keep you posted
great worked, so at the end the problem was only that i omitted the setFCV: true
, this behaviour of the setFCV
along with the apply
is not simple to understand.
@Claudio_Bisegni Thanks for feedback we will think how we can describe it more clear in our documentation. Have a good day and I hope you have only positive impressions about our operator
absolutely it is a very good piece of software!