Physical restore stuck in "running" forever

[cjesper]

Report

Hi,
We're having issues with PBM physical restores getting stuck in "running". This happens across multiple clusters and with multiple backups per cluster (ie. not isolated to specific backups within the cluster)

More about the problem

The restore starts running - the backup-agent container gets stopped etc - and then we start seeing logs like:
DEBUG	checking if restore is allowed	{"controller": "psmdbrestore-controller", "controllerGroup": "psmdb.percona.com", "controllerKind": "PerconaServerMongoDBRestore", "PerconaServerMongoDBRestore": {"name":"restore-new-entity-candidate-5",
"namespace":"psmdb-new-entity-candidate"}, "namespace": "psmdb-new-entity-candidate", "name": "restore-new-entity-candidate-5", "reconcileID": "f15e7345-ab10-4077-b095-f4841a5f0083", "cluster": "new-entity-candidate", "namespace": "psmdb-new-entity-candidate"}
DEBUG	Check restore status	{"controller": "psmdbrestore-controller", "controllerGroup": "psmdb.percona.com", "controllerKind": "PerconaServerMongoDBRestore", 
"PerconaServerMongoDBRestore": {"name":"restore-new-entity-candidate-5","namespace":"psmdb-new-entity-candidate"}, "namespace": "psmdb-new-entity-candidate", "name": "restore-new-entity-candidate-5", "reconcileID": "f15e7345-ab10-4077-b095-f4841a5f0083", "command": ["/opt/percona/pbm", "describe-restore", "2026-01-13T08:37:06.41089787Z", 
"--config", "/etc/pbm/pbm_config.yaml", "--out", "json"], "pod": "new-entity-candidate-new-entity-candidate-0"}
DEBUG	PBM restore status	{"controller": "psmdbrestore-controller", "controllerGroup": "psmdb.percona.com", "controllerKind": "PerconaServerMongoDBRestore", 
"PerconaServerMongoDBRestore": {"name":"restore-new-entity-candidate-5","namespace":"psmdb-new-entity-candidate"},
 "namespace": "psmdb-new-entity-candidate", "name": "restore-new-entity-candidate-5", "reconcileID": "f15e7345-ab10-4077-b095-f4841a5f0083", "status": {"type":"physical","opid":"","name":"2026-01-13T08:37:06.41089787Z",
"replsets":[{"name":"new-entity-candidate","start_ts":0,"status":"running","size":0,"size_uncompressed":0,"last_transition_ts":1768293448,"first_write_ts":{"T":0,"I":0},"last_write_ts":{"T":0,"I":0},"node":"","conditions":null}],"compression":"","store":{"type":""},"size":0,"size_uncompressed":0,
"mongodb_version":"","fcv":"","start_ts":0,"last_transition_ts":1768293453,"first_write_ts":{"T":0,"I":0},"last_write_ts":{"T":0,"I":0},"hb":{"T":0,"I":0},"status":"running","conditions":null,"n":null,"pbm_version":"","balancer":""}}

It seems like the replica in the set gets stuck in an unhealthy state:

members: [
    {
      _id: 0,
      name: 'new-entity-candidate-new-entity-candidate-0.new-entity-candidate-new-entity-candidate.psmdb-new-entity-candidate.svc.cluster.local:27017',
      health: 1,
      state: 1,
      stateStr: 'PRIMARY',
      uptime: 2543,
      optime: { ts: Timestamp({ t: 1768295948, i: 1 }), t: Long('292') },
      optimeDate: ISODate('2026-01-13T09:19:08.000Z'),
      lastAppliedWallTime: ISODate('2026-01-13T09:19:08.043Z'),
      lastDurableWallTime: ISODate('2026-01-13T09:19:08.043Z'),
      syncSourceHost: '',
      syncSourceId: -1,
      infoMessage: '',
      electionTime: Timestamp({ t: 1768293418, i: 1 }),
      electionDate: ISODate('2026-01-13T08:36:58.000Z'),
      configVersion: 13384721,
      configTerm: -1,
      self: true,
      lastHeartbeatMessage: ''
    },
    {
      _id: 1,
      name: 'new-entity-candidate-new-entity-candidate-1.new-entity-candidate-new-entity-candidate.psmdb-new-entity-candidate.svc.cluster.local:27017',
      health: 0,
      state: 8,
      stateStr: '(not reachable/healthy)',
      uptime: 0,
      optime: { ts: Timestamp({ t: 0, i: 0 }), t: Long('-1') },
      optimeDurable: { ts: Timestamp({ t: 0, i: 0 }), t: Long('-1') },
      optimeDate: ISODate('1970-01-01T00:00:00.000Z'),
      optimeDurableDate: ISODate('1970-01-01T00:00:00.000Z'),
      lastAppliedWallTime: ISODate('2026-01-13T08:37:46.912Z'),
      lastDurableWallTime: ISODate('2026-01-13T08:37:46.912Z'),
      lastHeartbeat: ISODate('2026-01-13T09:19:06.549Z'),
      lastHeartbeatRecv: ISODate('2026-01-13T08:37:51.577Z'),
      pingMs: Long('0'),
      lastHeartbeatMessage: 'Error connecting to new-entity-candidate-new-entity-candidate-1.new-entity-candidate-new-entity-candidate.psmdb-new-entity-candidate.svc.cluster.local:27017 (10.203.64.43:27017) :: caused by :: onInvoke :: caused by :: Connection refused',
      syncSourceHost: '',
      syncSourceId: -1,
      infoMessage: '',
      configVersion: 13384721,
      configTerm: -1
    }
  ],

And the container logs show endless uploading of ".hb"-files:

2026-01-13T08:38:19.000+0000 I [restore/2026-01-13T08:37:06.41089787Z] copy <2026-01-12T21:31:57Z/new-entity-candidate/index-90--4004084906419493573.wt.gz> to </data/db/index-90--4004084906419493573.wt>
2026-01-13T08:38:19.000+0000 I [restore/2026-01-13T08:37:06.41089787Z] copy <2026-01-12T21:31:57Z/new-entity-candidate/sizeStorer.wt.gz> to </data/db/sizeStorer.wt>
2026-01-13T08:38:19.000+0000 I [restore/2026-01-13T08:37:06.41089787Z] copy <2026-01-12T21:31:57Z/new-entity-candidate/WiredTiger.backup.gz> to </data/db/WiredTiger.backup>
2026-01-13T08:38:19.000+0000 I [restore/2026-01-13T08:37:06.41089787Z] copy <2026-01-12T21:31:57Z/new-entity-candidate/WiredTiger.gz> to </data/db/WiredTiger>
2026-01-13T08:38:19.000+0000 I [restore/2026-01-13T08:37:06.41089787Z] copy <2026-01-12T21:31:57Z/new-entity-candidate/storage.bson.gz.0-114> to </data/db/storage.bson>
2026-01-13T08:38:20.000+0000 I [restore/2026-01-13T08:37:06.41089787Z] copy <2026-01-12T21:31:57Z/new-entity-candidate/journal/WiredTigerLog.0000000029.gz> to </data/db/journal/WiredTigerLog.0000000029>
2026-01-13T08:38:20.000+0000 I [restore/2026-01-13T08:37:06.41089787Z] copy <2026-01-12T21:31:57Z/new-entity-candidate/key.db/WiredTigerLog.0000000029.gz> to </data/db/key.db/WiredTigerLog.0000000029>
2026-01-13T08:38:20.000+0000 I [restore/2026-01-13T08:37:06.41089787Z] copy <2026-01-12T21:31:57Z/new-entity-candidate/key.db/WiredTigerLog.0000000028.gz> to </data/db/key.db/WiredTigerLog.0000000028>
2026-01-13T08:38:20.000+0000 I [restore/2026-01-13T08:37:06.41089787Z] preparing data
2026-01-13T08:38:21.000+0000 D [restore/2026-01-13T08:37:06.41089787Z] oplogTruncateAfterPoint: {1768253519 1}
2026-01-13T08:38:23.000+0000 I [restore/2026-01-13T08:37:06.41089787Z] recovering oplog as standalone
2026-01-13T08:38:27.000+0000 I [restore/2026-01-13T08:37:06.41089787Z] clean-up and reset replicaset config
2026-01-13T08:38:29.000+0000 D [restore/2026-01-13T08:37:06.41089787Z] dropping 'admin.pbmAgents'
2026-01-13T08:38:29.000+0000 D [restore/2026-01-13T08:37:06.41089787Z] dropping 'admin.pbmBackups'
2026-01-13T08:38:29.000+0000 D [restore/2026-01-13T08:37:06.41089787Z] dropping 'admin.pbmRestores'
2026-01-13T08:38:29.000+0000 D [restore/2026-01-13T08:37:06.41089787Z] dropping 'admin.pbmCmd'
2026-01-13T08:38:29.000+0000 D [restore/2026-01-13T08:37:06.41089787Z] dropping 'admin.pbmPITRChunks'
2026-01-13T08:38:29.000+0000 D [restore/2026-01-13T08:37:06.41089787Z] dropping 'admin.pbmPITR'
2026-01-13T08:38:29.000+0000 D [restore/2026-01-13T08:37:06.41089787Z] dropping 'admin.pbmOpLog'
2026-01-13T08:38:29.000+0000 D [restore/2026-01-13T08:37:06.41089787Z] dropping 'admin.pbmLog'
2026-01-13T08:38:29.000+0000 D [restore/2026-01-13T08:37:06.41089787Z] dropping 'admin.pbmLock'
2026-01-13T08:38:29.000+0000 D [restore/2026-01-13T08:37:06.41089787Z] dropping 'admin.pbmLock'
2026-01-13T08:38:29.000+0000 D [restore/2026-01-13T08:37:06.41089787Z] dropping 'admin.pbmLockOp'
2026-01-13T08:38:31.000+0000 I [restore/2026-01-13T08:37:06.41089787Z] restore on node succeed
2026-01-13T08:38:31.000+0000 I [restore/2026-01-13T08:37:06.41089787Z] moving to state done
2026-01-13T08:38:31.000+0000 D [restore/2026-01-13T08:37:06.41089787Z] uploading ".pbm.restore/2026-01-13T08:37:06.41089787Z/rs.new-entity-candidate/node.new-entity-candidate-new-entity-candidate-1.new-entity-candidate-new-entity-candidate.psmdb-new-entity-candidate.svc.cluster.local:27017.done" [size hint: 10 (10.00B); part size: 10485760 (10.00MB)]
2026-01-13T08:38:31.000+0000 I [restore/2026-01-13T08:37:06.41089787Z] waiting for `done` status in rs map[.pbm.restore/2026-01-13T08:37:06.41089787Z/rs.new-entity-candidate/node.new-entity-candidate-new-entity-candidate-0.new-entity-candidate-new-entity-candidate.psmdb-new-entity-candidate.svc.cluster.local:27017:{} .pbm.restore/2026-01-13T08:37:06.41089787Z/rs.new-entity-candidate/node.new-entity-candidate-new-entity-candidate-1.new-entity-candidate-new-entity-candidate.psmdb-new-entity-candidate.svc.cluster.local:27017:{}]
2026-01-13T08:39:07.000+0000 D [restore/2026-01-13T08:37:06.41089787Z] uploading ".pbm.restore/2026-01-13T08:37:06.41089787Z/rs.new-entity-candidate/node.new-entity-candidate-new-entity-candidate-1.new-entity-candidate-new-entity-candidate.psmdb-new-entity-candidate.svc.cluster.local:27017.hb" [size hint: 10 (10.00B); part size: 10485760 (10.00MB)]
2026-01-13T08:39:07.000+0000 D [restore/2026-01-13T08:37:06.41089787Z] uploading ".pbm.restore/2026-01-13T08:37:06.41089787Z/rs.new-entity-candidate/rs.hb" [size hint: 10 (10.00B); part size: 10485760 (10.00MB)]
2026-01-13T08:39:07.000+0000 D [restore/2026-01-13T08:37:06.41089787Z] uploading ".pbm.restore/2026-01-13T08:37:06.41089787Z/cluster.hb" [size hint: 10 (10.00B); part size: 10485760 (10.00MB)]

The mongorestore resource in question looks like this:

k describe perconaservermongodbrestores -n psmdb-new-entity-candidate
Name:         restore-new-entity-candidate-5
Namespace:    psmdb-new-entity-candidate
Labels:       <none>
Annotations:  <none>
API Version:  psmdb.percona.com/v1
Kind:         PerconaServerMongoDBRestore
Metadata:
  Creation Timestamp:  2026-01-13T08:34:43Z
  Generation:          1
  Resource Version:    205262868
  UID:                 7490e4af-dab6-4a84-9c3b-dade5136fc06
Spec:
  Backup Name:   cron-new-entity-candi-20260111230100-9pz6g
  Cluster Name:  new-entity-candidate
Status:
  Pbm Name:  2026-01-13T08:37:06.41089787Z
  State:     running
Events:      <none>

And the backups:

NAME                                        CLUSTER           STORAGE      DESTINATION                                                        TYPE       SIZE   STATUS   COMPLETED   AGE
cron-annotation-util-20251227010100-slvmr   annotation-util   s3-us-east   s3://mongodb-backups/annotation-util/2025-12-27T01:01:06Z   physical          ready    17d         17d
cron-annotation-util-20251227030100-bbrtr   annotation-util   s3-us-east   s3://mongodb-backups/annotation-util/2025-12-27T03:14:35Z   physical          ready    17d         17d
cron-annotation-util-20251227050100-h9l8t   annotation-util   s3-us-east   s3://mongodb-backups/annotation-util/2025-12-27T05:05:27Z   physical          ready    17d         17d

Full PSMDB resource spec:

kubectl describe perconaservermongodb -n psmdb-new-entity-candidate
Name:         new-entity-candidate
Namespace:    psmdb-new-entity-candidate
Labels:       app.kubernetes.io/instance=new-entity-candidate-app
              argocd.argoproj.io/instance=new-entity-candidate
Annotations:  argocd.argoproj.io/tracking-id: new-entity-candidate:psmdb.percona.com/PerconaServerMongoDB:psmdb-new-entity-candidate/new-entity-candidate
API Version:  psmdb.percona.com/v1
Kind:         PerconaServerMongoDB
Metadata:
  Creation Timestamp:  2025-12-12T13:37:44Z
  Generation:          6
  Resource Version:    205262527
  UID:                 8626393c-300d-43d5-ba74-451ac38f7c68
Spec:
  Backup:
    Container Security Context:
      Allow Privilege Escalation:  false
      Capabilities:
        Drop:
          ALL
      Privileged:       false
      Run As Non Root:  true
      Run As User:      1001
    Enabled:            true
    Image:              perconalab/percona-server-mongodb-operator:main-backup
    Pitr:
      Enabled:  false
    Storages:
      s3-us-east:
        s3:
          Bucket:              mongodb-backups
          Credentials Secret:  pbm-backup-credentials
          Prefix:              new-entity-candidate
          Region:              us-east-1
        Type:                  s3
    Tasks:
      Compression Level:    6
      Compression Type:     gzip
      Enabled:              true
      Keep:                 3
      Name:                 new-entity-candidate-physical
      Schedule:             0 0 * * *
      Storage Name:         s3-us-east
      Type:                 physical
  Cr Version:               1.20.1
  Enable Volume Expansion:  true
  Image:                    percona/percona-server-mongodb:7.0.18-11
  Init Container Security Context:
    Allow Privilege Escalation:  false
    Capabilities:
      Drop:
        ALL
    Run As Group:     1001
    Run As Non Root:  true
    Run As User:      1001
  Replsets:
    Affinity:
      Advanced:
        Node Affinity:
          Required During Scheduling Ignored During Execution:
            Node Selector Terms:
              Match Expressions:
                Key:      test.io/instance-group
                Operator:  In
                Values:
                  mongo-ebs
                  mongo-ebs-xlarge
                  mongo-ebs-4xlarge
        Pod Anti Affinity:
          Required During Scheduling Ignored During Execution:
            Label Selector:
              Match Expressions:
                Key:       app.kubernetes.io/instance
                Operator:  In
                Values:
                  new-entity-candidate
            Topology Key:  kubernetes.io/hostname
    Annotations:
      k8s.grafana.com/job:                 scrape-percona-server-mongodb
      k8s.grafana.com/metrics.portNumber:  9216
      k8s.grafana.com/scrape:              true
    Configuration:                         replication:
  oplogSizeMB: 1000
security:
  clusterAuthMode: keyFile
  keyFile: /etc/mongodb-secrets/mongodb-key
setParameter:
  enableLocalhostAuthBypass: true

    Container Security Context:
      Allow Privilege Escalation:  false
      Capabilities:
        Drop:
          ALL
      Privileged:       false
      Run As Group:     1001
      Run As Non Root:  true
      Run As User:      1001
    Expose:
      Enabled:  false
    Name:       new-entity-candidate
    Pod Security Context:
      Fs Group:      1001
      Run As Group:  1001
      Run As User:   1001
      Supplemental Groups:
        1001
    Resources:
      Limits:
        Cpu:     1500m
        Memory:  2Gi
      Requests:
        Cpu:     1500m
        Memory:  1Gi
    Sidecars:
      Args:
        --mongodb.uri=mongodb://user:password@127.0.0.1:27017/admin
        --collect-all
      Image:  percona/mongodb_exporter:0.40
      Name:   rs-mongo-exporter-0
      Security Context:
        Allow Privilege Escalation:  false
        Capabilities:
          Drop:
            ALL
        Privileged:       false
        Run As Non Root:  true
        Run As User:      1001
    Size:                 2
    Split Horizons:
      new-entity-candidate-new-entity-candidate-0:
        External:  mon-dt-new-entity-candidate-0.test.io
      new-entity-candidate-new-entity-candidate-1:
        External:  mon-dt-new-entity-candidate-1.test.io
    Tolerations:
      Effect:    NoSchedule
      Key:       test.io/mongo-ebs
      Operator:  Exists
    Volume Spec:
      Persistent Volume Claim:
        Annotations:
          ebs.test.io/iops:  3000
        Resources:
          Requests:
            Storage:  10Gi
  Secrets:
    Key File:  new-entity-candidate-keyfile
    Ssl:       mongodb-ssl
  Sharding:
    Enabled:  false
  Tls:
    Allow Invalid Certificates:  true
    Mode:                        preferTLS
  Unsafe Flags:
    Replset Size:   true
    Tls:            true
  Update Strategy:  SmartUpdate
  Users:
    Db:    admin
    Name:  user
    Password Secret Ref:
      Key:   password
      Name:  mongo-user-password
    Roles:
      Db:    admin
      Name:  clusterAdmin
      Db:    admin
      Name:  userAdminAnyDatabase
      Db:    admin
      Name:  readWriteAnyDatabase
Status:
  Backup Config Hash:  6f43a10d901f6b6dad1513a07aff782eb4df1157602b153ca647178feccc9665
  Backup Image:        perconalab/percona-server-mongodb-operator:main-backup
  Backup Version:      2.12.0
  Conditions:
    Last Transition Time:  2025-12-12T13:38:05Z
    Status:                False
    Type:                  sharding
    Last Transition Time:  2025-12-12T13:38:05Z
    Status:                True
    Type:                  initializing
    Last Transition Time:  2025-12-12T13:39:10Z
    Message:               new-entity-candidate: ready
    Reason:                RSReady
    Status:                True
    Type:                  ready
    Last Transition Time:  2025-12-27T18:42:06Z
    Message:               failed to get mongo client: ping mongo: connection() error occurred during connection handshake: dial tcp: lookup new-entity-candidate-new-entity-candidate-0.new-entity-candidate-new-entity-candidate.psmdb-new-entity-candidate.svc.cluster.local on 100.64.0.10:53: no such host
    Reason:                ErrorReconcile
    Status:                True
    Type:                  error
  Host:                    new-entity-candidate-new-entity-candidate.psmdb-new-entity-candidate.svc.cluster.local
  Mongo Image:             percona/percona-server-mongodb:7.0.18-11
  Mongo Version:           7.0.18-11
  Observed Generation:     6
  Ready:                   2
  Replsets:
    New - Entity - Candidate:
      Initialized:  true
      Ready:        2
      Size:         2
      Status:       ready
  Size:             2
  State:            initializing
Events:             <none>

Steps to reproduce

1. Create a PSMDB mongodb cluster
2. Take a backup
3. Start a mongorestore

Versions

1. Kubernetes - 1.29.6
2. Operator - 1.21.1
3. Database - 7.0.18

Anything else?

No response

[egegunes]

PBM terminates mongod during physical restore, replset being unhealthy is expected.

How long restore stayed in running state? What's the size of the backup?

Unfortunately logs you shared didn't give me any clue. Is it possible for you to share full pbm-agent logs?

P.S.: During a physical restore pbm-agent is running in mongod container and its logs are in /tmp/pbm-agent.log. There might be something useful in /tmp/mongod.log and /data/db/pbm.restore.log.* as well.

[cjesper]

Hi @egegunes , thanks for your assistance

How long restore stayed in running state? What's the size of the backup?

I created a new restore a while ago and so far it's been stuck for 15 minutes:

NAME                                CLUSTER         STATUS    AGE
restore-admin-async-jobs-double-node   admin-async-jobs   running   13m

However, we know from experience that even leaving this running for up to 24 hours makes no difference.

The backup size is 105MB (this is a small, dummy cluster)

cron-admin-async-jobs-20260114000000-ln7qf   admin-async-jobs   s3-us-east   s3://k8s-backups/admin-async-jobs/2026-01-14T09:46:28Z   physical   105.64MB   ready    12m         9h

Is it possible for you to share full pbm-agent logs?

sh-5.1$ cat /tmp/pbm-agent.log
2026-01-14T09:53:05.000+0000 I
                    %                        _____
                   %%%                      |  __ \
                 ###%%%%%%%%%%%%*           | |__) |__ _ __ ___ ___  _ __   __ _
                ###  ##%%      %%%%         |  ___/ _ \ '__/ __/ _ \| '_ \ / _` |
              ####     ##%       %%%%       | |  |  __/ | | (_| (_) | | | | (_| |
             ###        ####      %%%       |_|   \___|_|  \___\___/|_| |_|\__,_|
           ,((###         ###     %%%         _____                       _
          (((( (###        ####  %%%%        / ____|                     | |
         (((     ((#         ######         | (___   __ _ _   _  __ _  __| |
       ((((       (((#        ####           \___ \ / _` | | | |/ _` |/ _` |
      /((          ,(((        *###          ____) | (_| | |_| | (_| | (_| |
    ////             (((         ####       |_____/ \__, |\__,_|\__,_|\__,_|
   ///                ((((        ####                 | |
 /////////////(((((((((((((((((########                |_|   Join @ squad.percona.com/mongodb

** Join Percona Squad! **
Participate in monthly SWAG raffles, get early access to new product features,
invite-only ”ask me anything” sessions with database performance experts.

Interested? Fill in the form at squad.percona.com/mongodb


2026-01-14T09:53:05.000+0000 I log options: log-path=/dev/stderr, log-level:D, log-json:false
2026-01-14T09:53:05.000+0000 I starting PITR routine
2026-01-14T09:53:05.000+0000 I pbm-agent:
Version:   2.12.0
Platform:  linux/amd64
GitCommit: 2f7100a2a1da2bb7074e15d757693999cac7574e
GitBranch: release-2.12.0
BuildTime: 2025-10-31_09:21_UTC
GoVersion: go1.25.3
2026-01-14T09:53:05.000+0000 I node: admin-async-jobs/admin-async-jobs-admin-async-jobs-1.admin-async-jobs-admin-async-jobs.psmdb-admin-async-jobs.svc.cluster.local:27017
2026-01-14T09:53:05.000+0000 I conn level ReadConcern: majority; WriteConcern: majority
2026-01-14T09:53:05.000+0000 I listening for the commands
2026-01-14T09:53:55.000+0000 E [agentCheckup] set status: write into db: server selection error: server selection timeout, current topology: { Type: ReplicaSetNoPrimary, Servers: [{ Addr: admin-async-jobs-admin-async-jobs-0.admin-async-jobs-admin-async-jobs.psmdb-admin-async-jobs.svc.cluster.local:27017, Type: Unknown, Last error: dial tcp: lookup admin-async-jobs-admin-async-jobs-0.admin-async-jobs-admin-async-jobs.psmdb-admin-async-jobs.svc.cluster.local on 100.64.0.10:53: no such host }, { Addr: admin-async-jobs-admin-async-jobs-1.admin-async-jobs-admin-async-jobs.psmdb-admin-async-jobs.svc.cluster.local:27017, Type: RSSecondary, Tag sets: nodeName=i-0ec73e982a6eb3a75,podName=admin-async-jobs-admin-async-jobs-1,serviceName=admin-async-jobs,region=us-east-1,zone=us-east-1a, Average RTT: 281262 }, ] }
2026-01-14T09:54:05.000+0000 E listening commands: watch the cmd stream: server selection error: server selection timeout, current topology: { Type: ReplicaSetNoPrimary, Servers: [{ Addr: admin-async-jobs-admin-async-jobs-0.admin-async-jobs-admin-async-jobs.psmdb-admin-async-jobs.svc.cluster.local:27017, Type: Unknown, Last error: dial tcp: lookup admin-async-jobs-admin-async-jobs-0.admin-async-jobs-admin-async-jobs.psmdb-admin-async-jobs.svc.cluster.local on 100.64.0.10:53: no such host }, { Addr: admin-async-jobs-admin-async-jobs-1.admin-async-jobs-admin-async-jobs.psmdb-admin-async-jobs.svc.cluster.local:27017, Type: RSSecondary, Tag sets: serviceName=admin-async-jobs,region=us-east-1,zone=us-east-1a,nodeName=i-0ec73e982a6eb3a75,podName=admin-async-jobs-admin-async-jobs-1, Average RTT: 272008 }, ] }
2026-01-14T09:54:05.000+0000 E [pitr] init: get conf: get: (NotPrimaryNoSecondaryOk) not primary and secondaryOk=false
2026-01-14T09:54:08.000+0000 I got command restore [name: 2026-01-14T09:54:07.727531186Z, snapshot: 2026-01-14T09:46:28Z] <ts: 1768384447>, opid: 696767bf04dbee47ad2e4144
2026-01-14T09:54:08.000+0000 I got epoch {1768384448 4}
2026-01-14T09:54:08.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] backup: 2026-01-14T09:46:28Z
2026-01-14T09:54:08.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] recovery started
2026-01-14T09:54:08.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] port: 27035
2026-01-14T09:54:08.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] uploading ".pbm.restore/2026-01-14T09:54:07.727531186Z/rs.admin-async-jobs/node.admin-async-jobs-admin-async-jobs-1.admin-async-jobs-admin-async-jobs.psmdb-admin-async-jobs.svc.cluster.local:27017.hb" [size hint: 10 (10.00B); part size: 10485760 (10.00MB)]
2026-01-14T09:54:08.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] uploading ".pbm.restore/2026-01-14T09:54:07.727531186Z/rs.admin-async-jobs/rs.hb" [size hint: 10 (10.00B); part size: 10485760 (10.00MB)]
2026-01-14T09:54:08.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] uploading ".pbm.restore/2026-01-14T09:54:07.727531186Z/cluster.hb" [size hint: 10 (10.00B); part size: 10485760 (10.00MB)]
2026-01-14T09:54:08.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] download max buf 536870912 (arena 268435456, span 33554432, concurrency 2)
2026-01-14T09:54:08.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] mongod binary: mongod, version: v7.0.18-11
2026-01-14T09:54:08.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] restore opts: fallbackEnabled: false; allowPartlyDone: true
2026-01-14T09:54:08.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] moving to state starting
2026-01-14T09:54:08.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] uploading ".pbm.restore/2026-01-14T09:54:07.727531186Z/rs.admin-async-jobs/node.admin-async-jobs-admin-async-jobs-1.admin-async-jobs-admin-async-jobs.psmdb-admin-async-jobs.svc.cluster.local:27017.starting" [size hint: 10 (10.00B); part size: 10485760 (10.00MB)]
2026-01-14T09:54:08.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] waiting for cluster
2026-01-14T09:54:23.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] converged to state starting
2026-01-14T09:54:23.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] starting
2026-01-14T09:54:23.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] moving to state running
2026-01-14T09:54:23.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] uploading ".pbm.restore/2026-01-14T09:54:07.727531186Z/rs.admin-async-jobs/node.admin-async-jobs-admin-async-jobs-1.admin-async-jobs-admin-async-jobs.psmdb-admin-async-jobs.svc.cluster.local:27017.running" [size hint: 10 (10.00B); part size: 10485760 (10.00MB)]
2026-01-14T09:54:23.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] waiting for cluster
2026-01-14T09:54:38.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] converged to state running
2026-01-14T09:54:38.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] send to stopAgent chan
2026-01-14T09:54:38.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] stop agents heartbeats
2026-01-14T09:54:38.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] stopping mongod and flushing old data
2026-01-14T09:54:38.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] shutting down server
2026-01-14T09:54:51.000+0000 D [pitr] stopping main loop
2026-01-14T09:54:54.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] waiting for the node to shutdown
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/collection-59--4878251615819745306.wt
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/collection-8--4878251615819745306.wt
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/index-80--4878251615819745306.wt
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/index-33--4878251615819745306.wt
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/index-77--4878251615819745306.wt
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/index-66--4878251615819745306.wt
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/index-47--4878251615819745306.wt
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/index-48--4878251615819745306.wt
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/collection-44--4878251615819745306.wt
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/index-9--4878251615819745306.wt
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/index-74--4878251615819745306.wt
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/WiredTiger.lock
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/collection-38--4878251615819745306.wt
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/WiredTiger.wt
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/collection-57--4878251615819745306.wt
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/index-68--4878251615819745306.wt
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/collection-76--4878251615819745306.wt
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/index-28--4878251615819745306.wt
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/index-50--4878251615819745306.wt
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/collection-12--4878251615819745306.wt
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/index-75--4878251615819745306.wt
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/collection-2--4878251615819745306.wt
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/index-51--4878251615819745306.wt
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/collection-32--4878251615819745306.wt
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/index-11--4878251615819745306.wt
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/collection-86--4878251615819745306.wt
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/index-7--4878251615819745306.wt
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/index-63--4878251615819745306.wt
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/index-31--4878251615819745306.wt
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/collection-18--4878251615819745306.wt
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/_mdb_catalog.wt
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/index-87--4878251615819745306.wt
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/collection-10--4878251615819745306.wt
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/mongod.lock
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/index-23--4878251615819745306.wt
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/storage.bson
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/index-35--4878251615819745306.wt
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/collection-64--4878251615819745306.wt
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/index-27--4878251615819745306.wt
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/index-72--4878251615819745306.wt
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/index-55--4878251615819745306.wt
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/index-83--4878251615819745306.wt
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/collection-24--4878251615819745306.wt
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/diagnostic.data
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/collection-84--4878251615819745306.wt
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/index-54--4878251615819745306.wt
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/index-30--4878251615819745306.wt
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/index-45--4878251615819745306.wt
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/collection-21--4878251615819745306.wt
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/index-81--4878251615819745306.wt
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/index-36--4878251615819745306.wt
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/index-69--4878251615819745306.wt
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/collection-46--4878251615819745306.wt
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/collection-19--4878251615819745306.wt
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/index-39--4878251615819745306.wt
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/collection-34--4878251615819745306.wt
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/WiredTiger.turtle
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/collection-73--4878251615819745306.wt
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/index-71--4878251615819745306.wt
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/index-5--4878251615819745306.wt
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/index-43--4878251615819745306.wt
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/collection-70--4878251615819745306.wt
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/index-20--4878251615819745306.wt
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/collection-52--4878251615819745306.wt
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/collection-0--4878251615819745306.wt
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/WiredTigerHS.wt
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/index-58--4878251615819745306.wt
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/index-62--4878251615819745306.wt
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/collection-67--4878251615819745306.wt
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/index-1--4878251615819745306.wt
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/collection-42--4878251615819745306.wt
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/index-15--4878251615819745306.wt
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/collection-4--4878251615819745306.wt
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/lost+found
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/collection-61--4878251615819745306.wt
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/sizeStorer.wt
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/index-41--4878251615819745306.wt
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/index-53--4878251615819745306.wt
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/key.db
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/index-22--4878251615819745306.wt
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/index-37--4878251615819745306.wt
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/index-60--4878251615819745306.wt
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/index-78--4878251615819745306.wt
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/psmdb_telemetry.data
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/collection-82--4878251615819745306.wt
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/collection-6--4878251615819745306.wt
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/journal
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/collection-26--4878251615819745306.wt
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/collection-49--4878251615819745306.wt
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/index-13--4878251615819745306.wt
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/collection-40--4878251615819745306.wt
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/collection-14--4878251615819745306.wt
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/index-65--4878251615819745306.wt
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/index-88--4878251615819745306.wt
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/index-85--4878251615819745306.wt
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/index-25--4878251615819745306.wt
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/index-3--4878251615819745306.wt
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/collection-29--4878251615819745306.wt
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/WiredTiger
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/mongod-data
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/collection-56--4878251615819745306.wt
2026-01-14T09:54:55.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] remove /data/db/collection-79--4878251615819745306.wt
2026-01-14T09:54:55.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copying backup data
2026-01-14T09:54:55.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/key.db/WiredTigerLog.0000003971.gz> to </data/db/key.db/WiredTigerLog.0000003971>
2026-01-14T09:54:55.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/key.db/WiredTigerHS.wt.gz> to </data/db/key.db/WiredTigerHS.wt>
2026-01-14T09:54:55.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/key.db/key.wt.gz> to </data/db/key.db/key.wt>
2026-01-14T09:54:56.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/key.db/parameters.wt.gz> to </data/db/key.db/parameters.wt>
2026-01-14T09:54:56.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/key.db/WiredTiger.backup.gz> to </data/db/key.db/WiredTiger.backup>
2026-01-14T09:54:56.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/key.db/WiredTiger.gz> to </data/db/key.db/WiredTiger>
2026-01-14T09:54:56.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/journal/WiredTigerLog.0000003971.gz> to </data/db/journal/WiredTigerLog.0000003971>
2026-01-14T09:54:57.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/WiredTigerHS.wt.gz> to </data/db/WiredTigerHS.wt>
2026-01-14T09:54:57.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/_mdb_catalog.wt.gz> to </data/db/_mdb_catalog.wt>
2026-01-14T09:54:57.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/collection-0--4878251615819745306.wt.gz> to </data/db/collection-0--4878251615819745306.wt>
2026-01-14T09:54:57.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/collection-10--4878251615819745306.wt.gz> to </data/db/collection-10--4878251615819745306.wt>
2026-01-14T09:54:57.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/collection-12--4878251615819745306.wt.gz> to </data/db/collection-12--4878251615819745306.wt>
2026-01-14T09:54:57.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/collection-14--4878251615819745306.wt.gz> to </data/db/collection-14--4878251615819745306.wt>
2026-01-14T09:54:57.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/collection-18--4878251615819745306.wt.gz> to </data/db/collection-18--4878251615819745306.wt>
2026-01-14T09:54:58.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/collection-19--4878251615819745306.wt.gz> to </data/db/collection-19--4878251615819745306.wt>
2026-01-14T09:54:58.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/collection-2--4878251615819745306.wt.gz> to </data/db/collection-2--4878251615819745306.wt>
2026-01-14T09:54:59.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/collection-21--4878251615819745306.wt.gz> to </data/db/collection-21--4878251615819745306.wt>
2026-01-14T09:54:59.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/collection-24--4878251615819745306.wt.gz> to </data/db/collection-24--4878251615819745306.wt>
2026-01-14T09:54:59.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/collection-26--4878251615819745306.wt.gz> to </data/db/collection-26--4878251615819745306.wt>
2026-01-14T09:54:59.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/collection-29--4878251615819745306.wt.gz> to </data/db/collection-29--4878251615819745306.wt>
2026-01-14T09:54:59.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/collection-32--4878251615819745306.wt.gz> to </data/db/collection-32--4878251615819745306.wt>
2026-01-14T09:54:59.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/collection-34--4878251615819745306.wt.gz> to </data/db/collection-34--4878251615819745306.wt>
2026-01-14T09:54:59.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/collection-38--4878251615819745306.wt.gz> to </data/db/collection-38--4878251615819745306.wt>
2026-01-14T09:54:59.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/collection-4--4878251615819745306.wt.gz> to </data/db/collection-4--4878251615819745306.wt>
2026-01-14T09:54:59.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/collection-40--4878251615819745306.wt.gz> to </data/db/collection-40--4878251615819745306.wt>
2026-01-14T09:54:59.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/collection-42--4878251615819745306.wt.gz> to </data/db/collection-42--4878251615819745306.wt>
2026-01-14T09:54:59.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/collection-44--4878251615819745306.wt.gz> to </data/db/collection-44--4878251615819745306.wt>
2026-01-14T09:55:00.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/collection-46--4878251615819745306.wt.gz> to </data/db/collection-46--4878251615819745306.wt>
2026-01-14T09:55:00.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/collection-49--4878251615819745306.wt.gz> to </data/db/collection-49--4878251615819745306.wt>
2026-01-14T09:55:00.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/collection-52--4878251615819745306.wt.gz> to </data/db/collection-52--4878251615819745306.wt>
2026-01-14T09:55:00.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/collection-56--4878251615819745306.wt.gz> to </data/db/collection-56--4878251615819745306.wt>
2026-01-14T09:55:00.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/collection-57--4878251615819745306.wt.gz> to </data/db/collection-57--4878251615819745306.wt>
2026-01-14T09:55:00.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/collection-59--4878251615819745306.wt.gz> to </data/db/collection-59--4878251615819745306.wt>
2026-01-14T09:55:00.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/collection-6--4878251615819745306.wt.gz> to </data/db/collection-6--4878251615819745306.wt>
2026-01-14T09:55:00.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/collection-61--4878251615819745306.wt.gz> to </data/db/collection-61--4878251615819745306.wt>
2026-01-14T09:55:00.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/collection-64--4878251615819745306.wt.gz> to </data/db/collection-64--4878251615819745306.wt>
2026-01-14T09:55:00.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/collection-67--4878251615819745306.wt.gz> to </data/db/collection-67--4878251615819745306.wt>
2026-01-14T09:55:00.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/collection-70--4878251615819745306.wt.gz> to </data/db/collection-70--4878251615819745306.wt>
2026-01-14T09:55:00.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/collection-73--4878251615819745306.wt.gz> to </data/db/collection-73--4878251615819745306.wt>
2026-01-14T09:55:00.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/collection-76--4878251615819745306.wt.gz> to </data/db/collection-76--4878251615819745306.wt>
2026-01-14T09:55:00.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/collection-79--4878251615819745306.wt.gz> to </data/db/collection-79--4878251615819745306.wt>
2026-01-14T09:55:00.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/collection-8--4878251615819745306.wt.gz> to </data/db/collection-8--4878251615819745306.wt>
2026-01-14T09:55:00.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/collection-82--4878251615819745306.wt.gz> to </data/db/collection-82--4878251615819745306.wt>
2026-01-14T09:55:00.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/collection-84--4878251615819745306.wt.gz> to </data/db/collection-84--4878251615819745306.wt>
2026-01-14T09:55:01.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/collection-86--4878251615819745306.wt.gz> to </data/db/collection-86--4878251615819745306.wt>
2026-01-14T09:55:01.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/index-1--4878251615819745306.wt.gz> to </data/db/index-1--4878251615819745306.wt>
2026-01-14T09:55:01.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/index-11--4878251615819745306.wt.gz> to </data/db/index-11--4878251615819745306.wt>
2026-01-14T09:55:01.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/index-13--4878251615819745306.wt.gz> to </data/db/index-13--4878251615819745306.wt>
2026-01-14T09:55:01.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/index-15--4878251615819745306.wt.gz> to </data/db/index-15--4878251615819745306.wt>
2026-01-14T09:55:01.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/index-20--4878251615819745306.wt.gz> to </data/db/index-20--4878251615819745306.wt>
2026-01-14T09:55:01.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/index-22--4878251615819745306.wt.gz> to </data/db/index-22--4878251615819745306.wt>
2026-01-14T09:55:01.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/index-23--4878251615819745306.wt.gz> to </data/db/index-23--4878251615819745306.wt>
2026-01-14T09:55:01.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/index-25--4878251615819745306.wt.gz> to </data/db/index-25--4878251615819745306.wt>
2026-01-14T09:55:01.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/index-27--4878251615819745306.wt.gz> to </data/db/index-27--4878251615819745306.wt>
2026-01-14T09:55:01.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/index-28--4878251615819745306.wt.gz> to </data/db/index-28--4878251615819745306.wt>
2026-01-14T09:55:01.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/index-3--4878251615819745306.wt.gz> to </data/db/index-3--4878251615819745306.wt>
2026-01-14T09:55:01.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/index-30--4878251615819745306.wt.gz> to </data/db/index-30--4878251615819745306.wt>
2026-01-14T09:55:01.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/index-31--4878251615819745306.wt.gz> to </data/db/index-31--4878251615819745306.wt>
2026-01-14T09:55:02.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/index-33--4878251615819745306.wt.gz> to </data/db/index-33--4878251615819745306.wt>
2026-01-14T09:55:02.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/index-35--4878251615819745306.wt.gz> to </data/db/index-35--4878251615819745306.wt>
2026-01-14T09:55:02.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/index-36--4878251615819745306.wt.gz> to </data/db/index-36--4878251615819745306.wt>
2026-01-14T09:55:02.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/index-37--4878251615819745306.wt.gz> to </data/db/index-37--4878251615819745306.wt>
2026-01-14T09:55:02.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/index-39--4878251615819745306.wt.gz> to </data/db/index-39--4878251615819745306.wt>
2026-01-14T09:55:02.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/index-41--4878251615819745306.wt.gz> to </data/db/index-41--4878251615819745306.wt>
2026-01-14T09:55:02.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/index-43--4878251615819745306.wt.gz> to </data/db/index-43--4878251615819745306.wt>
2026-01-14T09:55:02.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/index-45--4878251615819745306.wt.gz> to </data/db/index-45--4878251615819745306.wt>
2026-01-14T09:55:02.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/index-47--4878251615819745306.wt.gz> to </data/db/index-47--4878251615819745306.wt>
2026-01-14T09:55:02.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/index-48--4878251615819745306.wt.gz> to </data/db/index-48--4878251615819745306.wt>
2026-01-14T09:55:02.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/index-5--4878251615819745306.wt.gz> to </data/db/index-5--4878251615819745306.wt>
2026-01-14T09:55:02.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/index-50--4878251615819745306.wt.gz> to </data/db/index-50--4878251615819745306.wt>
2026-01-14T09:55:02.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/index-51--4878251615819745306.wt.gz> to </data/db/index-51--4878251615819745306.wt>
2026-01-14T09:55:03.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/index-53--4878251615819745306.wt.gz> to </data/db/index-53--4878251615819745306.wt>
2026-01-14T09:55:03.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/index-54--4878251615819745306.wt.gz> to </data/db/index-54--4878251615819745306.wt>
2026-01-14T09:55:03.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/index-55--4878251615819745306.wt.gz> to </data/db/index-55--4878251615819745306.wt>
2026-01-14T09:55:03.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/index-58--4878251615819745306.wt.gz> to </data/db/index-58--4878251615819745306.wt>
2026-01-14T09:55:03.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/index-60--4878251615819745306.wt.gz> to </data/db/index-60--4878251615819745306.wt>
2026-01-14T09:55:03.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/index-62--4878251615819745306.wt.gz> to </data/db/index-62--4878251615819745306.wt>
2026-01-14T09:55:03.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/index-63--4878251615819745306.wt.gz> to </data/db/index-63--4878251615819745306.wt>
2026-01-14T09:55:03.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/index-65--4878251615819745306.wt.gz> to </data/db/index-65--4878251615819745306.wt>
2026-01-14T09:55:03.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/index-66--4878251615819745306.wt.gz> to </data/db/index-66--4878251615819745306.wt>
2026-01-14T09:55:03.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/index-68--4878251615819745306.wt.gz> to </data/db/index-68--4878251615819745306.wt>
2026-01-14T09:55:03.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/index-69--4878251615819745306.wt.gz> to </data/db/index-69--4878251615819745306.wt>
2026-01-14T09:55:03.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/index-7--4878251615819745306.wt.gz> to </data/db/index-7--4878251615819745306.wt>
2026-01-14T09:55:03.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/index-71--4878251615819745306.wt.gz> to </data/db/index-71--4878251615819745306.wt>
2026-01-14T09:55:03.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/index-72--4878251615819745306.wt.gz> to </data/db/index-72--4878251615819745306.wt>
2026-01-14T09:55:04.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/index-74--4878251615819745306.wt.gz> to </data/db/index-74--4878251615819745306.wt>
2026-01-14T09:55:04.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/index-75--4878251615819745306.wt.gz> to </data/db/index-75--4878251615819745306.wt>
2026-01-14T09:55:04.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/index-77--4878251615819745306.wt.gz> to </data/db/index-77--4878251615819745306.wt>
2026-01-14T09:55:04.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/index-78--4878251615819745306.wt.gz> to </data/db/index-78--4878251615819745306.wt>
2026-01-14T09:55:04.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/index-80--4878251615819745306.wt.gz> to </data/db/index-80--4878251615819745306.wt>
2026-01-14T09:55:04.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/index-81--4878251615819745306.wt.gz> to </data/db/index-81--4878251615819745306.wt>
2026-01-14T09:55:04.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/index-83--4878251615819745306.wt.gz> to </data/db/index-83--4878251615819745306.wt>
2026-01-14T09:55:04.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/index-85--4878251615819745306.wt.gz> to </data/db/index-85--4878251615819745306.wt>
2026-01-14T09:55:04.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/index-87--4878251615819745306.wt.gz> to </data/db/index-87--4878251615819745306.wt>
2026-01-14T09:55:04.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/index-88--4878251615819745306.wt.gz> to </data/db/index-88--4878251615819745306.wt>
2026-01-14T09:55:04.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/index-9--4878251615819745306.wt.gz> to </data/db/index-9--4878251615819745306.wt>
2026-01-14T09:55:04.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/sizeStorer.wt.gz> to </data/db/sizeStorer.wt>
2026-01-14T09:55:04.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/WiredTiger.backup.gz> to </data/db/WiredTiger.backup>
2026-01-14T09:55:04.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/WiredTiger.gz> to </data/db/WiredTiger>
2026-01-14T09:55:05.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/storage.bson.gz.0-114> to </data/db/storage.bson>
2026-01-14T09:55:05.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/journal/WiredTigerLog.0000003972.gz> to </data/db/journal/WiredTigerLog.0000003972>
2026-01-14T09:55:05.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/key.db/WiredTigerLog.0000003972.gz> to </data/db/key.db/WiredTigerLog.0000003972>
2026-01-14T09:55:05.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] copy <2026-01-14T09:46:28Z/admin-async-jobs/key.db/WiredTigerLog.0000003971.gz> to </data/db/key.db/WiredTigerLog.0000003971>
2026-01-14T09:55:05.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] preparing data
2026-01-14T09:55:07.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] oplogTruncateAfterPoint: {1768383990 2}
2026-01-14T09:55:09.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] recovering oplog as standalone
2026-01-14T09:55:13.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] clean-up and reset replicaset config
2026-01-14T09:55:14.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] dropping 'admin.pbmAgents'
2026-01-14T09:55:14.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] dropping 'admin.pbmBackups'
2026-01-14T09:55:14.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] dropping 'admin.pbmCmd'
2026-01-14T09:55:14.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] dropping 'admin.pbmPITRChunks'
2026-01-14T09:55:14.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] dropping 'admin.pbmPITR'
2026-01-14T09:55:14.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] dropping 'admin.pbmOpLog'
2026-01-14T09:55:14.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] dropping 'admin.pbmLog'
2026-01-14T09:55:14.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] dropping 'admin.pbmLock'
2026-01-14T09:55:14.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] dropping 'admin.pbmRestores'
2026-01-14T09:55:14.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] dropping 'admin.pbmLock'
2026-01-14T09:55:14.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] dropping 'admin.pbmLockOp'
2026-01-14T09:55:17.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] restore on node succeed
2026-01-14T09:55:17.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] moving to state done
2026-01-14T09:55:17.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] uploading ".pbm.restore/2026-01-14T09:54:07.727531186Z/rs.admin-async-jobs/node.admin-async-jobs-admin-async-jobs-1.admin-async-jobs-admin-async-jobs.psmdb-admin-async-jobs.svc.cluster.local:27017.done" [size hint: 10 (10.00B); part size: 10485760 (10.00MB)]
2026-01-14T09:55:17.000+0000 I [restore/2026-01-14T09:54:07.727531186Z] waiting for `done` status in rs map[.pbm.restore/2026-01-14T09:54:07.727531186Z/rs.admin-async-jobs/node.admin-async-jobs-admin-async-jobs-0.admin-async-jobs-admin-async-jobs.psmdb-admin-async-jobs.svc.cluster.local:27017:{} .pbm.restore/2026-01-14T09:54:07.727531186Z/rs.admin-async-jobs/node.admin-async-jobs-admin-async-jobs-1.admin-async-jobs-admin-async-jobs.psmdb-admin-async-jobs.svc.cluster.local:27017:{}]
2026-01-14T09:56:08.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] uploading ".pbm.restore/2026-01-14T09:54:07.727531186Z/rs.admin-async-jobs/node.admin-async-jobs-admin-async-jobs-1.admin-async-jobs-admin-async-jobs.psmdb-admin-async-jobs.svc.cluster.local:27017.hb" [size hint: 10 (10.00B); part size: 10485760 (10.00MB)]
2026-01-14T09:56:08.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] uploading ".pbm.restore/2026-01-14T09:54:07.727531186Z/rs.admin-async-jobs/rs.hb" [size hint: 10 (10.00B); part size: 10485760 (10.00MB)]
2026-01-14T09:56:08.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] uploading ".pbm.restore/2026-01-14T09:54:07.727531186Z/cluster.hb" [size hint: 10 (10.00B); part size: 10485760 (10.00MB)]
2026-01-14T09:58:08.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] uploading ".pbm.restore/2026-01-14T09:54:07.727531186Z/rs.admin-async-jobs/node.admin-async-jobs-admin-async-jobs-1.admin-async-jobs-admin-async-jobs.psmdb-admin-async-jobs.svc.cluster.local:27017.hb" [size hint: 10 (10.00B); part size: 10485760 (10.00MB)]
2026-01-14T09:58:08.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] uploading ".pbm.restore/2026-01-14T09:54:07.727531186Z/rs.admin-async-jobs/rs.hb" [size hint: 10 (10.00B); part size: 10485760 (10.00MB)]
2026-01-14T09:58:08.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] uploading ".pbm.restore/2026-01-14T09:54:07.727531186Z/cluster.hb" [size hint: 10 (10.00B); part size: 10485760 (10.00MB)]
2026-01-14T10:00:08.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] uploading ".pbm.restore/2026-01-14T09:54:07.727531186Z/rs.admin-async-jobs/node.admin-async-jobs-admin-async-jobs-1.admin-async-jobs-admin-async-jobs.psmdb-admin-async-jobs.svc.cluster.local:27017.hb" [size hint: 10 (10.00B); part size: 10485760 (10.00MB)]
2026-01-14T10:00:08.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] uploading ".pbm.restore/2026-01-14T09:54:07.727531186Z/rs.admin-async-jobs/rs.hb" [size hint: 10 (10.00B); part size: 10485760 (10.00MB)]
2026-01-14T10:00:08.000+0000 D [restore/2026-01-14T09:54:07.727531186Z] uploading ".pbm.restore/2026-01-14T09:54:07.727531186Z/cluster.hb" [size hint: 10 (10.00B); part size: 10485760 (10.00MB)]

There might be something useful in /tmp/mongod.log

sh-5.1$ cat /tmp/mongod.log
+ exec numactl --interleave=all mongod --bind_ip_all --auth --dbpath=/data/db --port=27017 --replSet=admin-async-jobs --storageEngine=wiredTiger --relaxPermChecks --clusterAuthMode=keyFile --keyFile=/etc/mongodb-secrets/mongodb-key --enableEncryption --encryptionKeyFile=/etc/mongodb-encryption/encryption-key --wiredTigerCacheSizeGB=0.25 --wiredTigerIndexPrefixCompression=true --config=/etc/mongodb-config/mongod.conf --quiet --tlsMode preferTLS --sslPEMKeyFile /tmp/tls.pem --tlsAllowInvalidCertificates --tlsCAFile /etc/mongodb-ssl/ca.crt

data/db/pbm.restore.log.

cat /data/db/pbm.restore.log.2026-01-14T09-55-13
{"t":{"$date":"2026-01-14T09:55:09.571+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":"2026-01-14T09:55:09.572+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":"2026-01-14T09:55:09.573+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":"2026-01-14T09:55:09.573+00:00"},"s":"I",  "c":"REPL",     "id":5123008, "ctx":"main","msg":"Successfully registered PrimaryOnlyService","attr":{"service":"TenantMigrationDonorService","namespace":"config.tenantMigrationDonors"}}
{"t":{"$date":"2026-01-14T09:55:09.573+00:00"},"s":"I",  "c":"REPL",     "id":5123008, "ctx":"main","msg":"Successfully registered PrimaryOnlyService","attr":{"service":"TenantMigrationRecipientService","namespace":"config.tenantMigrationRecipients"}}
{"t":{"$date":"2026-01-14T09:55:09.573+00:00"},"s":"I",  "c":"CONTROL",  "id":5945603, "ctx":"main","msg":"Multi threading initialized"}
{"t":{"$date":"2026-01-14T09:55:09.574+00:00"},"s":"I",  "c":"TENANT_M", "id":7091600, "ctx":"main","msg":"Starting TenantMigrationAccessBlockerRegistry"}
{"t":{"$date":"2026-01-14T09:55:09.574+00:00"},"s":"I",  "c":"CONTROL",  "id":4615611, "ctx":"initandlisten","msg":"MongoDB starting","attr":{"pid":1140,"port":27035,"dbPath":"/data/db","architecture":"64-bit","host":"admin-async-jobs-admin-async-jobs-1"}}
{"t":{"$date":"2026-01-14T09:55:09.574+00:00"},"s":"W",  "c":"CONTROL",  "id":20720,   "ctx":"initandlisten","msg":"Memory available to mongo process is less than total system memory","attr":{"availableMemSizeMB":1024,"systemMemSizeMB":126762}}
{"t":{"$date":"2026-01-14T09:55:09.574+00:00"},"s":"I",  "c":"CONTROL",  "id":23403,   "ctx":"initandlisten","msg":"Build Info","attr":{"buildInfo":{"version":"7.0.18-11","gitVersion":"97ceec31da21050a3f6f3b203bac9e5a2685dcd2","openSSLVersion":"OpenSSL 3.2.2 4 Jun 2024","modules":[],"proFeatures":[],"allocator":"tcmalloc","environment":{"distarch":"x86_64","target_arch":"x86_64"}}}}
{"t":{"$date":"2026-01-14T09:55:09.574+00:00"},"s":"I",  "c":"CONTROL",  "id":51765,   "ctx":"initandlisten","msg":"Operating System","attr":{"os":{"name":"Red Hat Enterprise Linux release 9.5 (Plow)","version":"Kernel 6.6.110-flatcar"}}}
{"t":{"$date":"2026-01-14T09:55:09.574+00:00"},"s":"I",  "c":"CONTROL",  "id":21951,   "ctx":"initandlisten","msg":"Options set by command line","attr":{"options":{"config":"/tmp/pbmMongdTmpConf2176643401","net":{"bindIp":"localhost","port":27035},"security":{"enableEncryption":true,"encryptionKeyFile":"/etc/mongodb-encryption/encryption-key","relaxPermChecks":true},"setParameter":{"recoverFromOplogAsStandalone":"true","takeUnstableCheckpointOnShutdown":"true"},"storage":{"dbPath":"/data/db","directoryPerDB":false,"wiredTiger":{"collectionConfig":{"blockCompressor":"snappy"},"engineConfig":{"directoryForIndexes":false,"journalCompressor":"snappy"},"indexConfig":{"prefixCompression":true}}},"systemLog":{"destination":"file","path":"/data/db/pbm.restore.log"}}}}
{"t":{"$date":"2026-01-14T09:55:09.574+00:00"},"s":"I",  "c":"STORAGE",  "id":22270,   "ctx":"initandlisten","msg":"Storage engine to use detected by data files","attr":{"dbpath":"/data/db","storageEngine":"wiredTiger"}}
{"t":{"$date":"2026-01-14T09:55:09.574+00:00"},"s":"I",  "c":"STORAGE",  "id":22297,   "ctx":"initandlisten","msg":"Using the XFS filesystem is strongly recommended with the WiredTiger storage engine. See http://dochub.mongodb.org/core/prodnotes-filesystem","tags":["startupWarnings"]}
{"t":{"$date":"2026-01-14T09:55:09.575+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":"2026-01-14T09:55:09.575+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":"2026-01-14T09:55:10.222+00:00"},"s":"I",  "c":"STORAGE",  "id":29039,   "ctx":"initandlisten","msg":"Encryption keys DB is initialized successfully"}
{"t":{"$date":"2026-01-14T09:55:10.222+00:00"},"s":"I",  "c":"STORAGE",  "id":22315,   "ctx":"initandlisten","msg":"Opening WiredTiger","attr":{"config":"create,cache_size=256M,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],encryption=(name=percona,keyid=\"/default\"),extensions=[local=(entry=percona_encryption_extension_init,early_load=true,config=(cipher=AES256-CBC)),],"}}
{"t":{"$date":"2026-01-14T09:55:10.241+00:00"},"s":"I",  "c":"WTRECOV",  "id":22430,   "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":{"ts_sec":1768384510,"ts_usec":240999,"thread":"1140:0x7faa7a69d2c0","session_name":"txn-recover","category":"WT_VERB_RECOVERY_PROGRESS","category_id":30,"verbose_level":"DEBUG_1","verbose_level_id":1,"msg":"Recovering log 3973 through 3974"}}}
{"t":{"$date":"2026-01-14T09:55:10.282+00:00"},"s":"I",  "c":"WTRECOV",  "id":22430,   "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":{"ts_sec":1768384510,"ts_usec":282921,"thread":"1140:0x7faa7a69d2c0","session_name":"txn-recover","category":"WT_VERB_RECOVERY_PROGRESS","category_id":30,"verbose_level":"DEBUG_1","verbose_level_id":1,"msg":"Recovering log 3974 through 3974"}}}
{"t":{"$date":"2026-01-14T09:55:10.344+00:00"},"s":"I",  "c":"WTRECOV",  "id":22430,   "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":{"ts_sec":1768384510,"ts_usec":344388,"thread":"1140:0x7faa7a69d2c0","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 3973/245376 to 3974/256"}}}
{"t":{"$date":"2026-01-14T09:55:10.427+00:00"},"s":"I",  "c":"WTRECOV",  "id":22430,   "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":{"ts_sec":1768384510,"ts_usec":427021,"thread":"1140:0x7faa7a69d2c0","session_name":"txn-recover","category":"WT_VERB_RECOVERY_PROGRESS","category_id":30,"verbose_level":"DEBUG_1","verbose_level_id":1,"msg":"Recovering log 3973 through 3974"}}}
{"t":{"$date":"2026-01-14T09:55:10.475+00:00"},"s":"I",  "c":"WTRECOV",  "id":22430,   "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":{"ts_sec":1768384510,"ts_usec":475781,"thread":"1140:0x7faa7a69d2c0","session_name":"txn-recover","category":"WT_VERB_RECOVERY_PROGRESS","category_id":30,"verbose_level":"DEBUG_1","verbose_level_id":1,"msg":"Recovering log 3974 through 3974"}}}
{"t":{"$date":"2026-01-14T09:55:10.517+00:00"},"s":"I",  "c":"WTRECOV",  "id":22430,   "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":{"ts_sec":1768384510,"ts_usec":517145,"thread":"1140:0x7faa7a69d2c0","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 276 milliseconds"}}}
{"t":{"$date":"2026-01-14T09:55:10.517+00:00"},"s":"I",  "c":"WTRECOV",  "id":22430,   "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":{"ts_sec":1768384510,"ts_usec":517245,"thread":"1140:0x7faa7a69d2c0","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: (1768383940, 1)"}}}
{"t":{"$date":"2026-01-14T09:55:10.517+00:00"},"s":"I",  "c":"WTRECOV",  "id":22430,   "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":{"ts_sec":1768384510,"ts_usec":517259,"thread":"1140:0x7faa7a69d2c0","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: (1768383640, 1)"}}}
{"t":{"$date":"2026-01-14T09:55:10.518+00:00"},"s":"I",  "c":"WTRECOV",  "id":22430,   "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":{"ts_sec":1768384510,"ts_usec":518667,"thread":"1140:0x7faa7a69d2c0","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":"2026-01-14T09:55:10.522+00:00"},"s":"I",  "c":"WTCHKPT",  "id":22430,   "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":{"ts_sec":1768384510,"ts_usec":522335,"thread":"1140:0x7faa7a69d2c0","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: (1768383640, 1) , meta checkpoint timestamp: (1768383940, 1) base write gen: 814421"}}}
{"t":{"$date":"2026-01-14T09:55:10.531+00:00"},"s":"I",  "c":"WTRECOV",  "id":22430,   "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":{"ts_sec":1768384510,"ts_usec":531463,"thread":"1140:0x7faa7a69d2c0","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 12 milliseconds"}}}
{"t":{"$date":"2026-01-14T09:55:10.531+00:00"},"s":"I",  "c":"WTRECOV",  "id":22430,   "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":{"ts_sec":1768384510,"ts_usec":531516,"thread":"1140:0x7faa7a69d2c0","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 290ms, including 276ms for the log replay, 1ms for the rollback to stable, and 12ms for the checkpoint."}}}
{"t":{"$date":"2026-01-14T09:55:10.533+00:00"},"s":"I",  "c":"STORAGE",  "id":4795906, "ctx":"initandlisten","msg":"WiredTiger opened","attr":{"durationMillis":311}}
{"t":{"$date":"2026-01-14T09:55:10.533+00:00"},"s":"I",  "c":"RECOVERY", "id":23987,   "ctx":"initandlisten","msg":"WiredTiger recoveryTimestamp","attr":{"recoveryTimestamp":{"$timestamp":{"t":1768383940,"i":1}}}}
{"t":{"$date":"2026-01-14T09:55:10.533+00:00"},"s":"I",  "c":"RECOVERY", "id":5380106, "ctx":"initandlisten","msg":"WiredTiger oldestTimestamp","attr":{"oldestTimestamp":{"$timestamp":{"t":1768383640,"i":1}}}}
{"t":{"$date":"2026-01-14T09:55:10.635+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":"2026-01-14T09:55:10.635+00:00"},"s":"W",  "c":"CONTROL",  "id":9068900, "ctx":"initandlisten","msg":"For customers running MongoDB 7.0, we suggest changing the contents of the following sysfsFile","attr":{"sysfsFile":"/sys/kernel/mm/transparent_hugepage","currentValue":"always","desiredValue":"never"},"tags":["startupWarnings"]}
{"t":{"$date":"2026-01-14T09:55:10.635+00:00"},"s":"W",  "c":"CONTROL",  "id":5123300, "ctx":"initandlisten","msg":"vm.max_map_count is too low","attr":{"currentValue":1048576,"recommendedMinimum":1677720,"maxConns":838860},"tags":["startupWarnings"]}
{"t":{"$date":"2026-01-14T09:55:10.635+00:00"},"s":"W",  "c":"CONTROL",  "id":21558,   "ctx":"initandlisten","msg":"Setting mongod to readOnly mode as a result of specifying 'recoverFromOplogAsStandalone'","tags":["startupWarnings"]}
{"t":{"$date":"2026-01-14T09:55:10.716+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":"2026-01-14T09:55:10.716+00:00"},"s":"I",  "c":"REPL",     "id":5853300, "ctx":"initandlisten","msg":"current featureCompatibilityVersion value","attr":{"featureCompatibilityVersion":"7.0","context":"startup"}}
{"t":{"$date":"2026-01-14T09:55:10.717+00:00"},"s":"I",  "c":"STORAGE",  "id":5071100, "ctx":"initandlisten","msg":"Clearing temp directory"}
{"t":{"$date":"2026-01-14T09:55:10.783+00:00"},"s":"I",  "c":"CONTROL",  "id":6608200, "ctx":"initandlisten","msg":"Initializing cluster server parameters from disk"}
{"t":{"$date":"2026-01-14T09:55:10.783+00:00"},"s":"I",  "c":"CONTROL",  "id":20536,   "ctx":"initandlisten","msg":"Flow Control is enabled on this deployment"}
{"t":{"$date":"2026-01-14T09:55:10.783+00:00"},"s":"I",  "c":"STORAGE",  "id":5380103, "ctx":"initandlisten","msg":"Unpin oldest timestamp request","attr":{"service":"_wt_startup","requestedTs":{"$timestamp":{"t":1768383640,"i":1}}}}
{"t":{"$date":"2026-01-14T09:55:10.783+00:00"},"s":"I",  "c":"FTDC",     "id":20625,   "ctx":"initandlisten","msg":"Initializing full-time diagnostic data capture","attr":{"dataDirectory":"/data/db/diagnostic.data"}}
{"t":{"$date":"2026-01-14T09:55:10.791+00:00"},"s":"I",  "c":"REPL",     "id":21557,   "ctx":"initandlisten","msg":"Removing unapplied oplog entries after oplogTruncateAfterPoint","attr":{"oplogTruncateAfterPoint":{"":{"$timestamp":{"t":1768383990,"i":2}}}}}
{"t":{"$date":"2026-01-14T09:55:10.791+00:00"},"s":"I",  "c":"REPL",     "id":21553,   "ctx":"initandlisten","msg":"Truncating oplog from truncateAfterOplogEntryTimestamp (non-inclusive)","attr":{"truncateAfterOplogEntryTimestamp":{"$timestamp":{"t":1768383990,"i":2}},"oplogTruncateAfterPoint":{"$timestamp":{"t":1768383990,"i":2}}}}
{"t":{"$date":"2026-01-14T09:55:10.791+00:00"},"s":"I",  "c":"REPL",     "id":21554,   "ctx":"initandlisten","msg":"Replication recovery oplog truncation finished","attr":{"durationMillis":0}}
{"t":{"$date":"2026-01-14T09:55:10.792+00:00"},"s":"I",  "c":"CONTROL",  "id":6608200, "ctx":"initandlisten","msg":"Initializing cluster server parameters from disk"}
{"t":{"$date":"2026-01-14T09:55:10.793+00:00"},"s":"I",  "c":"REPL",     "id":21544,   "ctx":"initandlisten","msg":"Recovering from stable timestamp","attr":{"stableTimestamp":{"$timestamp":{"t":1768383940,"i":1}},"topOfOplog":{"ts":{"$timestamp":{"t":1768383990,"i":2}},"t":1403},"appliedThrough":{"ts":{"$timestamp":{"t":0,"i":0}},"t":-1}}}
{"t":{"$date":"2026-01-14T09:55:10.793+00:00"},"s":"I",  "c":"REPL",     "id":21545,   "ctx":"initandlisten","msg":"Starting recovery oplog application at the stable timestamp","attr":{"stableTimestamp":{"$timestamp":{"t":1768383940,"i":1}}}}
{"t":{"$date":"2026-01-14T09:55:10.793+00:00"},"s":"I",  "c":"REPL",     "id":5466604, "ctx":"initandlisten","msg":"Start point for recovery oplog application exists in oplog. No adjustment necessary","attr":{"startPoint":{"$timestamp":{"t":1768383940,"i":1}}}}
{"t":{"$date":"2026-01-14T09:55:10.793+00:00"},"s":"I",  "c":"REPL",     "id":21550,   "ctx":"initandlisten","msg":"Replaying stored operations from startPoint (exclusive) to endPoint (inclusive)","attr":{"startPoint":{"$timestamp":{"t":1768383940,"i":1}},"endPoint":{"$timestamp":{"t":1768383990,"i":2}}}}
{"t":{"$date":"2026-01-14T09:55:10.818+00:00"},"s":"I",  "c":"REPL",     "id":21536,   "ctx":"initandlisten","msg":"Completed oplog application for recovery","attr":{"numOpsApplied":39,"numBatches":1,"applyThroughOpTime":{"ts":{"$timestamp":{"t":1768383990,"i":2}},"t":1403}}}
{"t":{"$date":"2026-01-14T09:55:10.819+00:00"},"s":"I",  "c":"REPL",     "id":6015317, "ctx":"initandlisten","msg":"Setting new configuration state","attr":{"newState":"ConfigReplicationDisabled","oldState":"ConfigPreStart"}}
{"t":{"$date":"2026-01-14T09:55:10.819+00:00"},"s":"I",  "c":"STORAGE",  "id":22262,   "ctx":"initandlisten","msg":"Timestamp monitor starting"}
{"t":{"$date":"2026-01-14T09:55:10.819+00:00"},"s":"I",  "c":"NETWORK",  "id":23015,   "ctx":"listener","msg":"Listening on","attr":{"address":"/tmp/mongodb-27035.sock"}}
{"t":{"$date":"2026-01-14T09:55:10.819+00:00"},"s":"I",  "c":"NETWORK",  "id":23015,   "ctx":"listener","msg":"Listening on","attr":{"address":"127.0.0.1"}}
{"t":{"$date":"2026-01-14T09:55:10.819+00:00"},"s":"I",  "c":"NETWORK",  "id":23016,   "ctx":"listener","msg":"Waiting for connections","attr":{"port":27035,"ssl":"off"}}
{"t":{"$date":"2026-01-14T09:55:10.819+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":"1049 ms","Write current PID to file":"10 ms","Initialize FCV before rebuilding indexes":"81 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","Load cluster parameters from disk for a standalone":"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 the replication coordinator":"35 ms","Start transport layer":"0 ms","_initAndListen total elapsed time":"1245 ms"}}}}
{"t":{"$date":"2026-01-14T09:55:11.050+00:00"},"s":"I",  "c":"NETWORK",  "id":22943,   "ctx":"listener","msg":"Connection accepted","attr":{"remote":"127.0.0.1:58336","uuid":{"uuid":{"$uuid":"050b6027-0795-4a8e-9a1d-9f956823a356"}},"connectionId":1,"connectionCount":1}}
{"t":{"$date":"2026-01-14T09:55:11.050+00:00"},"s":"I",  "c":"NETWORK",  "id":51800,   "ctx":"conn1","msg":"client metadata","attr":{"remote":"127.0.0.1:58336","client":"conn1","negotiatedCompressors":[],"doc":{"application":{"name":"pbm-physical-restore"},"driver":{"name":"mongo-go-driver","version":"1.17.4"},"os":{"type":"linux","architecture":"amd64"},"platform":"go1.25.3","env":{"container":{"orchestrator":"kubernetes"}}}}}
{"t":{"$date":"2026-01-14T09:55:11.051+00:00"},"s":"I",  "c":"NETWORK",  "id":22943,   "ctx":"listener","msg":"Connection accepted","attr":{"remote":"127.0.0.1:58344","uuid":{"uuid":{"$uuid":"3907a179-e042-41b1-ba67-8937396c8868"}},"connectionId":2,"connectionCount":2}}
{"t":{"$date":"2026-01-14T09:55:11.051+00:00"},"s":"I",  "c":"NETWORK",  "id":22943,   "ctx":"listener","msg":"Connection accepted","attr":{"remote":"127.0.0.1:58358","uuid":{"uuid":{"$uuid":"4077e610-2ce9-4ad7-b657-21f42c944365"}},"connectionId":3,"connectionCount":3}}
{"t":{"$date":"2026-01-14T09:55:11.051+00:00"},"s":"I",  "c":"NETWORK",  "id":51800,   "ctx":"conn2","msg":"client metadata","attr":{"remote":"127.0.0.1:58344","client":"conn2","negotiatedCompressors":[],"doc":{"application":{"name":"pbm-physical-restore"},"driver":{"name":"mongo-go-driver","version":"1.17.4"},"os":{"type":"linux","architecture":"amd64"},"platform":"go1.25.3","env":{"container":{"orchestrator":"kubernetes"}}}}}
{"t":{"$date":"2026-01-14T09:55:11.051+00:00"},"s":"I",  "c":"NETWORK",  "id":51800,   "ctx":"conn3","msg":"client metadata","attr":{"remote":"127.0.0.1:58358","client":"conn3","negotiatedCompressors":[],"doc":{"application":{"name":"pbm-physical-restore"},"driver":{"name":"mongo-go-driver","version":"1.17.4"},"os":{"type":"linux","architecture":"amd64"},"platform":"go1.25.3","env":{"container":{"orchestrator":"kubernetes"}}}}}
{"t":{"$date":"2026-01-14T09:55:11.051+00:00"},"s":"I",  "c":"NETWORK",  "id":6788700, "ctx":"conn3","msg":"Received first command on ingress connection since session start or auth handshake","attr":{"elapsedMillis":0}}
{"t":{"$date":"2026-01-14T09:55:11.051+00:00"},"s":"I",  "c":"COMMAND",  "id":4695400, "ctx":"conn3","msg":"Terminating via shutdown command","attr":{"force":false,"timeoutMillis":15000}}
{"t":{"$date":"2026-01-14T09:55:11.051+00:00"},"s":"I",  "c":"REPL",     "id":4794602, "ctx":"thread36","msg":"Attempting to enter quiesce mode"}
{"t":{"$date":"2026-01-14T09:55:11.051+00:00"},"s":"I",  "c":"-",        "id":6371601, "ctx":"thread36","msg":"Shutting down the FLE Crud thread pool"}
{"t":{"$date":"2026-01-14T09:55:11.051+00:00"},"s":"I",  "c":"COMMAND",  "id":4784901, "ctx":"thread36","msg":"Shutting down the MirrorMaestro"}
{"t":{"$date":"2026-01-14T09:55:11.051+00:00"},"s":"I",  "c":"SHARDING", "id":4784902, "ctx":"thread36","msg":"Shutting down the WaitForMajorityService"}
{"t":{"$date":"2026-01-14T09:55:11.052+00:00"},"s":"I",  "c":"CONTROL",  "id":4784903, "ctx":"thread36","msg":"Shutting down the LogicalSessionCache"}
{"t":{"$date":"2026-01-14T09:55:11.052+00:00"},"s":"I",  "c":"NETWORK",  "id":20562,   "ctx":"thread36","msg":"Shutdown: going to close listening sockets"}
{"t":{"$date":"2026-01-14T09:55:11.052+00:00"},"s":"I",  "c":"NETWORK",  "id":23017,   "ctx":"listener","msg":"removing socket file","attr":{"path":"/tmp/mongodb-27035.sock"}}
{"t":{"$date":"2026-01-14T09:55:11.052+00:00"},"s":"I",  "c":"NETWORK",  "id":4784905, "ctx":"thread36","msg":"Shutting down the global connection pool"}
{"t":{"$date":"2026-01-14T09:55:11.052+00:00"},"s":"I",  "c":"CONTROL",  "id":4784906, "ctx":"thread36","msg":"Shutting down the FlowControlTicketholder"}
{"t":{"$date":"2026-01-14T09:55:11.052+00:00"},"s":"I",  "c":"-",        "id":20520,   "ctx":"thread36","msg":"Stopping further Flow Control ticket acquisitions."}
{"t":{"$date":"2026-01-14T09:55:11.052+00:00"},"s":"I",  "c":"CONTROL",  "id":4784908, "ctx":"thread36","msg":"Shutting down the PeriodicThreadToAbortExpiredTransactions"}
{"t":{"$date":"2026-01-14T09:55:11.052+00:00"},"s":"I",  "c":"REPL",     "id":4784909, "ctx":"thread36","msg":"Shutting down the ReplicationCoordinator"}
{"t":{"$date":"2026-01-14T09:55:11.052+00:00"},"s":"I",  "c":"SHARDING", "id":4784910, "ctx":"thread36","msg":"Shutting down the ShardingInitializationMongoD"}
{"t":{"$date":"2026-01-14T09:55:11.052+00:00"},"s":"I",  "c":"REPL",     "id":4784911, "ctx":"thread36","msg":"Enqueuing the ReplicationStateTransitionLock for shutdown"}
{"t":{"$date":"2026-01-14T09:55:11.052+00:00"},"s":"I",  "c":"-",        "id":4784912, "ctx":"thread36","msg":"Killing all operations for shutdown"}
{"t":{"$date":"2026-01-14T09:55:11.052+00:00"},"s":"I",  "c":"-",        "id":4695300, "ctx":"thread36","msg":"Interrupted all currently running operations","attr":{"opsKilled":5}}
{"t":{"$date":"2026-01-14T09:55:11.052+00:00"},"s":"I",  "c":"TENANT_M", "id":5093807, "ctx":"thread36","msg":"Shutting down all TenantMigrationAccessBlockers on global shutdown"}
{"t":{"$date":"2026-01-14T09:55:11.052+00:00"},"s":"I",  "c":"ASIO",     "id":22582,   "ctx":"TenantMigrationBlockerNet","msg":"Killing all outstanding egress activity."}
{"t":{"$date":"2026-01-14T09:55:11.052+00:00"},"s":"I",  "c":"ASIO",     "id":6529201, "ctx":"thread36","msg":"Network interface redundant shutdown","attr":{"state":"Stopped"}}
{"t":{"$date":"2026-01-14T09:55:11.052+00:00"},"s":"I",  "c":"ASIO",     "id":22582,   "ctx":"thread36","msg":"Killing all outstanding egress activity."}
{"t":{"$date":"2026-01-14T09:55:11.052+00:00"},"s":"I",  "c":"COMMAND",  "id":4784913, "ctx":"thread36","msg":"Shutting down all open transactions"}
{"t":{"$date":"2026-01-14T09:55:11.052+00:00"},"s":"I",  "c":"REPL",     "id":4784914, "ctx":"thread36","msg":"Acquiring the ReplicationStateTransitionLock for shutdown"}
{"t":{"$date":"2026-01-14T09:55:11.052+00:00"},"s":"I",  "c":"INDEX",    "id":4784915, "ctx":"thread36","msg":"Shutting down the IndexBuildsCoordinator"}
{"t":{"$date":"2026-01-14T09:55:11.052+00:00"},"s":"I",  "c":"NETWORK",  "id":4784918, "ctx":"thread36","msg":"Shutting down the ReplicaSetMonitor"}
{"t":{"$date":"2026-01-14T09:55:11.052+00:00"},"s":"I",  "c":"SHARDING", "id":4784921, "ctx":"thread36","msg":"Shutting down the MigrationUtilExecutor"}
{"t":{"$date":"2026-01-14T09:55:11.052+00:00"},"s":"I",  "c":"ASIO",     "id":22582,   "ctx":"MigrationUtil-TaskExecutor","msg":"Killing all outstanding egress activity."}
{"t":{"$date":"2026-01-14T09:55:11.052+00:00"},"s":"I",  "c":"COMMAND",  "id":4784923, "ctx":"thread36","msg":"Shutting down the ServiceEntryPoint"}
{"t":{"$date":"2026-01-14T09:55:11.052+00:00"},"s":"I",  "c":"CONTROL",  "id":4784927, "ctx":"thread36","msg":"Shutting down the HealthLog"}
{"t":{"$date":"2026-01-14T09:55:11.052+00:00"},"s":"I",  "c":"CONTROL",  "id":4784928, "ctx":"thread36","msg":"Shutting down the TTL monitor"}
{"t":{"$date":"2026-01-14T09:55:11.052+00:00"},"s":"I",  "c":"INDEX",    "id":3684100, "ctx":"thread36","msg":"Shutting down TTL collection monitor thread"}
{"t":{"$date":"2026-01-14T09:55:11.052+00:00"},"s":"I",  "c":"INDEX",    "id":3684101, "ctx":"thread36","msg":"Finished shutting down TTL collection monitor thread"}
{"t":{"$date":"2026-01-14T09:55:11.052+00:00"},"s":"I",  "c":"CONTROL",  "id":6278511, "ctx":"thread36","msg":"Shutting down the Change Stream Expired Pre-images Remover"}
{"t":{"$date":"2026-01-14T09:55:11.052+00:00"},"s":"I",  "c":"CONTROL",  "id":4784929, "ctx":"thread36","msg":"Acquiring the global lock for shutdown"}
{"t":{"$date":"2026-01-14T09:55:11.052+00:00"},"s":"I",  "c":"CONTROL",  "id":4784930, "ctx":"thread36","msg":"Shutting down the storage engine"}
{"t":{"$date":"2026-01-14T09:55:11.052+00:00"},"s":"I",  "c":"STORAGE",  "id":22320,   "ctx":"thread36","msg":"Shutting down journal flusher thread"}
{"t":{"$date":"2026-01-14T09:55:11.052+00:00"},"s":"I",  "c":"STORAGE",  "id":22321,   "ctx":"thread36","msg":"Finished shutting down journal flusher thread"}
{"t":{"$date":"2026-01-14T09:55:11.052+00:00"},"s":"I",  "c":"STORAGE",  "id":22322,   "ctx":"thread36","msg":"Shutting down checkpoint thread"}
{"t":{"$date":"2026-01-14T09:55:11.052+00:00"},"s":"I",  "c":"NETWORK",  "id":22944,   "ctx":"conn1","msg":"Connection ended","attr":{"remote":"127.0.0.1:58336","uuid":{"uuid":{"$uuid":"050b6027-0795-4a8e-9a1d-9f956823a356"}},"connectionId":1,"connectionCount":2}}
{"t":{"$date":"2026-01-14T09:55:11.052+00:00"},"s":"I",  "c":"STORAGE",  "id":22323,   "ctx":"thread36","msg":"Finished shutting down checkpoint thread"}
{"t":{"$date":"2026-01-14T09:55:11.052+00:00"},"s":"I",  "c":"STORAGE",  "id":22261,   "ctx":"thread36","msg":"Timestamp monitor shutting down"}
{"t":{"$date":"2026-01-14T09:55:11.052+00:00"},"s":"I",  "c":"STORAGE",  "id":20282,   "ctx":"thread36","msg":"Deregistering all the collections"}
{"t":{"$date":"2026-01-14T09:55:11.053+00:00"},"s":"I",  "c":"STORAGE",  "id":22372,   "ctx":"OplogVisibilityThread","msg":"Oplog visibility thread shutting down."}
{"t":{"$date":"2026-01-14T09:55:11.053+00:00"},"s":"I",  "c":"STORAGE",  "id":22317,   "ctx":"thread36","msg":"WiredTigerKVEngine shutting down"}
{"t":{"$date":"2026-01-14T09:55:11.053+00:00"},"s":"I",  "c":"STORAGE",  "id":22318,   "ctx":"thread36","msg":"Shutting down session sweeper thread"}
{"t":{"$date":"2026-01-14T09:55:11.053+00:00"},"s":"I",  "c":"STORAGE",  "id":22319,   "ctx":"thread36","msg":"Finished shutting down session sweeper thread"}
{"t":{"$date":"2026-01-14T09:55:11.056+00:00"},"s":"I",  "c":"STORAGE",  "id":4795902, "ctx":"thread36","msg":"Closing WiredTiger","attr":{"closeConfig":"leak_memory=true,use_timestamp=false,"}}
{"t":{"$date":"2026-01-14T09:55:11.062+00:00"},"s":"I",  "c":"WTCHKPT",  "id":22430,   "ctx":"thread36","msg":"WiredTiger message","attr":{"message":{"ts_sec":1768384511,"ts_usec":62428,"thread":"1140:0x7faa62b37640","session_name":"close_ckpt","category":"WT_VERB_CHECKPOINT_PROGRESS","category_id":6,"verbose_level":"DEBUG_1","verbose_level_id":1,"msg":"saving checkpoint snapshot min: 155, snapshot max: 155 snapshot count: 0, oldest timestamp: (1768383640, 1) , meta checkpoint timestamp: (0, 0) base write gen: 814421"}}}
{"t":{"$date":"2026-01-14T09:55:11.121+00:00"},"s":"I",  "c":"WTRECOV",  "id":22430,   "ctx":"thread36","msg":"WiredTiger message","attr":{"message":{"ts_sec":1768384511,"ts_usec":121541,"thread":"1140:0x7faa62b37640","session_name":"WT_CONNECTION.close","category":"WT_VERB_RECOVERY_PROGRESS","category_id":30,"verbose_level":"DEBUG_1","verbose_level_id":1,"msg":"shutdown checkpoint has successfully finished and ran for 64 milliseconds"}}}
{"t":{"$date":"2026-01-14T09:55:11.121+00:00"},"s":"I",  "c":"WTRECOV",  "id":22430,   "ctx":"thread36","msg":"WiredTiger message","attr":{"message":{"ts_sec":1768384511,"ts_usec":121704,"thread":"1140:0x7faa62b37640","session_name":"WT_CONNECTION.close","category":"WT_VERB_RECOVERY_PROGRESS","category_id":30,"verbose_level":"DEBUG_1","verbose_level_id":1,"msg":"shutdown was completed successfully and took 65ms, including 0ms for the rollback to stable, and 64ms for the checkpoint."}}}
{"t":{"$date":"2026-01-14T09:55:11.131+00:00"},"s":"I",  "c":"STORAGE",  "id":4795901, "ctx":"thread36","msg":"WiredTiger closed","attr":{"durationMillis":75}}
{"t":{"$date":"2026-01-14T09:55:11.154+00:00"},"s":"I",  "c":"STORAGE",  "id":22279,   "ctx":"thread36","msg":"shutdown: removing fs lock..."}
{"t":{"$date":"2026-01-14T09:55:11.154+00:00"},"s":"I",  "c":"-",        "id":4784931, "ctx":"thread36","msg":"Dropping the scope cache for shutdown"}
{"t":{"$date":"2026-01-14T09:55:11.154+00:00"},"s":"I",  "c":"FTDC",     "id":20626,   "ctx":"thread36","msg":"Shutting down full-time diagnostic data capture"}
{"t":{"$date":"2026-01-14T09:55:11.157+00:00"},"s":"I",  "c":"CONTROL",  "id":20565,   "ctx":"thread36","msg":"Now exiting"}
{"t":{"$date":"2026-01-14T09:55:11.157+00:00"},"s":"I",  "c":"CONTROL",  "id":8423404, "ctx":"thread36","msg":"mongod shutdown complete","attr":{"Summary of time elapsed":{"Statistics":{"Time spent in quiesce mode":"0 ms","Shut down FLE Crud subsystem":"0 ms","Shut down MirrorMaestro":"0 ms","Shut down WaitForMajorityService":"1 ms","Shut down the logical session cache":"0 ms","Shut down the transport layer":"0 ms","Shut down the global connection pool":"0 ms","Shut down the flow control ticket holder":"0 ms","Kill all operations for shutdown":"0 ms","Shut down all tenant migration access blockers on global shutdown":"0 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 health log":"0 ms","Shut down the TTL monitor":"0 ms","Shut down expired pre-images and documents removers":"0 ms","Shut down the storage engine":"102 ms","Wait for the oplog cap maintainer thread to stop":"0 ms","Shut down full-time data capture":"0 ms","shutdownTask total elapsed time":"106 ms"}}}}
{"t":{"$date":"2026-01-14T09:55:11.157+00:00"},"s":"I",  "c":"CONTROL",  "id":23138,   "ctx":"thread36","msg":"Shutting down","attr":{"exitCode":0}}

This is the only thing that's logged by the backup-agent after the restore starts and before the backup-agent containers are terminated:

Jan 14, 2026 @ 09:53:25.172 | 2026/01/14 09:53:25 [entrypoint] kill `pbm-agent` (65): <nil>
-- | --

  | Jan 14, 2026 @ 09:53:25.172 | 2026/01/14 09:53:25 [entrypoint] got terminated, shutting down

  | Jan 14, 2026 @ 09:52:29.967 | 2026/01/14 09:52:29 [entrypoint] got terminated, shutting down

  | Jan 14, 2026 @ 09:52:29.967 | 2026/01/14 09:52:29 [entrypoint] kill `pbm-agent` (74): <nil>

In the mongodb container of the replica pod (admin-async-jobs-admin-async-jobs-1), we see:

The primary pod (admin-async-jobs-admin-async-jobs-0) has no mention of anything related to the restore

And here are some logs from the operator / backup controller

DEBUG	PBM restore status	{"controller": "psmdbrestore-controller", "controllerGroup": "psmdb.percona.com", "controllerKind": "PerconaServerMongoDBRestore", "PerconaServerMongoDBRestore": {"name":"restore-admin-async-jobs-double-node","namespace":"psmdb-admin-async-jobs"}, "namespace": "psmdb-admin-async-jobs", "name": "restore-admin-async-jobs-double-node", "reconcileID": "91299f44-9a46-4ef9-be32-26244d2e7f62", "status": {"type":"physical","opid":"","name":"2026-01-14T09:54:07.727531186Z","replsets":[{"name":"admin-async-jobs","start_ts":0,"status":"running","size":0,"size_uncompressed":0,"last_transition_ts":1768384469,"first_write_ts":{"T":0,"I":0},"last_write_ts":{"T":0,"I":0},"node":"","conditions":null}],"compression":"","store":{"type":""},"size":0,"size_uncompressed":0,"mongodb_version":"","fcv":"","start_ts":0,"last_transition_ts":1768384474,"first_write_ts":{"T":0,"I":0},"last_write_ts":{"T":0,"I":0},"hb":{"T":0,"I":0},"status":"running","conditions":null,"n":null,"pbm_version":"","balancer":""}}
--

  | Jan 14, 2026 @ 10:00:36.067 | 2026-01-14T10:00:36.066Z	DEBUG	Statefulset is ready for physical restore	{"controller": "psmdbrestore-controller", "controllerGroup": "psmdb.percona.com", "controllerKind": "PerconaServerMongoDBRestore", "PerconaServerMongoDBRestore": {"name":"restore-admin-async-jobs-double-node","namespace":"psmdb-admin-async-jobs"}, "namespace": "psmdb-admin-async-jobs", "name": "restore-admin-async-jobs-double-node", "reconcileID": "91299f44-9a46-4ef9-be32-26244d2e7f62", "sts": "admin-async-jobs-admin-async-jobs", "replset": "admin-async-jobs"}

  | Jan 14, 2026 @ 10:00:36.067 | 2026-01-14T10:00:36.066Z	DEBUG	Pod is ready for physical restore	{"controller": "psmdbrestore-controller", "controllerGroup": "psmdb.percona.com", "controllerKind": "PerconaServerMongoDBRestore", "PerconaServerMongoDBRestore": {"name":"restore-admin-async-jobs-double-node","namespace":"psmdb-admin-async-jobs"}, "namespace": "psmdb-admin-async-jobs", "name": "restore-admin-async-jobs-double-node", "reconcileID": "91299f44-9a46-4ef9-be32-26244d2e7f62", "pod": "admin-async-jobs-admin-async-jobs-1"}

  | Jan 14, 2026 @ 10:00:36.067 | 2026-01-14T10:00:36.066Z	DEBUG	Check restore status	{"controller": "psmdbrestore-controller", "controllerGroup": "psmdb.percona.com", "controllerKind": "PerconaServerMongoDBRestore", "PerconaServerMongoDBRestore": {"name":"restore-admin-async-jobs-double-node","namespace":"psmdb-admin-async-jobs"}, "namespace": "psmdb-admin-async-jobs", "name": "restore-admin-async-jobs-double-node", "reconcileID": "91299f44-9a46-4ef9-be32-26244d2e7f62", "command": ["/opt/percona/pbm", "describe-restore", "2026-01-14T09:54:07.727531186Z", "--config", "/etc/pbm/pbm_config.yaml", "--out", "json"], "pod": "admin-async-jobs-admin-async-jobs-0"}

  | Jan 14, 2026 @ 10:00:36.066 | 2026-01-14T10:00:36.066Z	DEBUG	Pod is ready for physical restore	{"controller": "psmdbrestore-controller", "controllerGroup": "psmdb.percona.com", "controllerKind": "PerconaServerMongoDBRestore", "PerconaServerMongoDBRestore": {"name":"restore-admin-async-jobs-double-node","namespace":"psmdb-admin-async-jobs"}, "namespace": "psmdb-admin-async-jobs", "name": "restore-admin-async-jobs-double-node", "reconcileID": "91299f44-9a46-4ef9-be32-26244d2e7f62", "pod": "admin-async-jobs-admin-async-jobs-0"}

  | Jan 14, 2026 @ 10:00:36.066 | 2026-01-14T10:00:36.066Z	DEBUG	checking if restore is allowed	{"controller": "psmdbrestore-controller", "controllerGroup": "psmdb.percona.com", "controllerKind": "PerconaServerMongoDBRestore", "PerconaServerMongoDBRestore": {"name":"restore-admin-async-jobs-double-node","namespace":"psmdb-admin-async-jobs"}, "namespace": "psmdb-admin-async-jobs", "name": "restore-admin-async-jobs-double-node", "reconcileID": "91299f44-9a46-4ef9-be32-26244d2e7f62", "cluster": "admin-async-jobs", "namespace": "psmdb-admin-async-jobs"}

  | Jan 14, 2026 @ 10:00:31.047 | 2026-01-14T10:00:31.047Z	DEBUG	PBM restore status	{"controller": "psmdbrestore-controller", "controllerGroup": "psmdb.percona.com", "controllerKind": "PerconaServerMongoDBRestore", "PerconaServerMongoDBRestore": {"name":"restore-admin-async-jobs-double-node","namespace":"psmdb-admin-async-jobs"}, "namespace": "psmdb-admin-async-jobs", "name": "restore-admin-async-jobs-double-node", "reconcileID": "1bc3cd5f-80d4-4a67-ab4b-2f32351772df", "status": {"type":"physical","opid":"","name":"2026-01-14T09:54:07.727531186Z","replsets":[{"name":"admin-async-jobs","start_ts":0,"status":"running","size":0,"size_uncompressed":0,"last_transition_ts":1768384469,"first_write_ts":{"T":0,"I":0},"last_write_ts":{"T":0,"I":0},"node":"","conditions":null}],"compression":"","store":{"type":""},"size":0,"size_uncompressed":0,"mongodb_version":"","fcv":"","start_ts":0,"last_transition_ts":1768384474,"first_write_ts":{"T":0,"I":0},"last_write_ts":{"T":0,"I":0},"hb":{"T":0,"I":0},"status":"running","conditions":null,"n":null,"pbm_version":"","balancer":""}}

  | Jan 14, 2026 @ 10:00:29.867 | 2026-01-14T10:00:29.867Z	DEBUG	Check restore status	{"controller": "psmdbrestore-controller", "controllerGroup": "psmdb.percona.com", "controllerKind": "PerconaServerMongoDBRestore", "PerconaServerMongoDBRestore": {"name":"restore-admin-async-jobs-double-node","namespace":"psmdb-admin-async-jobs"}, "namespace": "psmdb-admin-async-jobs", "name": "restore-admin-async-jobs-double-node", "reconcileID": "1bc3cd5f-80d4-4a67-ab4b-2f32351772df", "command": ["/opt/percona/pbm", "describe-restore", "2026-01-14T09:54:07.727531186Z", "--config", "/etc/pbm/pbm_config.yaml", "--out", "json"], "pod": "admin-async-jobs-admin-async-jobs-0"}

  | Jan 14, 2026 @ 10:00:29.867 | 2026-01-14T10:00:29.866Z	DEBUG	Pod is ready for physical restore	{"controller": "psmdbrestore-controller", "controllerGroup": "psmdb.percona.com", "controllerKind": "PerconaServerMongoDBRestore", "PerconaServerMongoDBRestore": {"name":"restore-admin-async-jobs-double-node","namespace":"psmdb-admin-async-jobs"}, "namespace": "psmdb-admin-async-jobs", "name": "restore-admin-async-jobs-double-node", "reconcileID": "1bc3cd5f-80d4-4a67-ab4b-2f32351772df", "pod": "admin-async-jobs-admin-async-jobs-1"}

  | Jan 14, 2026 @ 10:00:29.867 | 2026-01-14T10:00:29.866Z	DEBUG	Statefulset is ready for physical restore	{"controller": "psmdbrestore-controller", "controllerGroup": "psmdb.percona.com", "controllerKind": "PerconaServerMongoDBRestore", "PerconaServerMongoDBRestore": {"name":"restore-admin-async-jobs-double-node","namespace":"psmdb-admin-async-jobs"}, "namespace": "psmdb-admin-async-jobs", "name": "restore-admin-async-jobs-double-node", "reconcileID": "1bc3cd5f-80d4-4a67-ab4b-2f32351772df", "sts": "admin-async-jobs-admin-async-jobs", "replset": "admin-async-jobs"

The above messages just keep looping over and over. In general, it seems like it never progresses with the restore after the first node (the replica) - the only trace of the restore on the primary pod is that the backup-container has been terminated.

[egegunes]

Does /tmp/pbm-agent.log looks the same in each pod?

Is it possible that one of pbm-agents is killed due to OOM? Asking because your case made me think of PBM-1548. If possible try with higher resources in the mongod container.

[cjesper]

I tried increasing memory and CPU substantially (to 4G / 4 CPUs) but the same thing happened.

Does /tmp/pbm-agent.log looks the same in each pod?

No, they don't. The first node (primary) is full of these logs

sh-5.1$ cat /etc/hostname
admin-async-jobs-admin-async-jobs-0
sh-5.1$ tail /tmp/pbm-agent.log -n 50
2026-01-15T09:15:13.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] waiting to become secondary before shutting it down
2026-01-15T09:15:14.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] waiting to become secondary before shutting it down
2026-01-15T09:15:15.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] waiting to become secondary before shutting it down
2026-01-15T09:15:16.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] waiting to become secondary before shutting it down
2026-01-15T09:15:17.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] waiting to become secondary before shutting it down
2026-01-15T09:15:18.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] waiting to become secondary before shutting it down
2026-01-15T09:15:19.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] waiting to become secondary before shutting it down
2026-01-15T09:15:20.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] waiting to become secondary before shutting it down
2026-01-15T09:15:21.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] waiting to become secondary before shutting it down
2026-01-15T09:15:22.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] waiting to become secondary before shutting it down
2026-01-15T09:15:23.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] waiting to become secondary before shutting it down
2026-01-15T09:15:24.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] waiting to become secondary before shutting it down
2026-01-15T09:15:25.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] waiting to become secondary before shutting it down
2026-01-15T09:15:26.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] waiting to become secondary before shutting it down
2026-01-15T09:15:27.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] waiting to become secondary before shutting it down
2026-01-15T09:15:28.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] waiting to become secondary before shutting it down
2026-01-15T09:15:29.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] waiting to become secondary before shutting it down
2026-01-15T09:15:30.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] waiting to become secondary before shutting it down
2026-01-15T09:15:30.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] uploading ".pbm.restore/2026-01-15T08:01:30.50237456Z/rs.admin-async-jobs/node.admin-async-jobs-admin-async-jobs-0.admin-async-jobs-admin-async-jobs.psmdb-admin-async-jobs.svc.cluster.local:27017.hb" [size hint: 10 (10.00B); part size: 10485760 (10.00MB)]
2026-01-15T09:15:31.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] uploading ".pbm.restore/2026-01-15T08:01:30.50237456Z/rs.admin-async-jobs/rs.hb" [size hint: 10 (10.00B); part size: 10485760 (10.00MB)]
2026-01-15T09:15:31.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] uploading ".pbm.restore/2026-01-15T08:01:30.50237456Z/cluster.hb" [size hint: 10 (10.00B); part size: 10485760 (10.00MB)]
2026-01-15T09:15:31.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] waiting to become secondary before shutting it down
2026-01-15T09:15:32.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] waiting to become secondary before shutting it down
2026-01-15T09:15:33.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] waiting to become secondary before shutting it down
2026-01-15T09:15:34.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] waiting to become secondary before shutting it down
2026-01-15T09:15:35.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] waiting to become secondary before shutting it down
2026-01-15T09:15:36.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] waiting to become secondary before shutting it down
2026-01-15T09:15:37.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] waiting to become secondary before shutting it down
2026-01-15T09:15:38.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] waiting to become secondary before shutting it down
2026-01-15T09:15:39.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] waiting to become secondary before shutting it down
2026-01-15T09:15:40.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] waiting to become secondary before shutting it down
2026-01-15T09:15:41.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] waiting to become secondary before shutting it down
2026-01-15T09:15:42.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] waiting to become secondary before shutting it down
2026-01-15T09:15:43.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] waiting to become secondary before shutting it down
2026-01-15T09:15:44.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] waiting to become secondary before shutting it down
2026-01-15T09:15:45.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] waiting to become secondary before shutting it down
2026-01-15T09:15:46.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] waiting to become secondary before shutting it down
2026-01-15T09:15:47.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] waiting to become secondary before shutting it down
2026-01-15T09:15:48.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] waiting to become secondary before shutting it down
2026-01-15T09:15:49.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] waiting to become secondary before shutting it down
2026-01-15T09:15:50.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] waiting to become secondary before shutting it down
2026-01-15T09:15:51.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] waiting to become secondary before shutting it down
2026-01-15T09:15:52.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] waiting to become secondary before shutting it down
2026-01-15T09:15:53.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] waiting to become secondary before shutting it down

And then the first logs, for reference:

h-5.1$ head /tmp/pbm-agent.log -n 50
2026-01-15T08:01:14.000+0000 I
                    %                        _____
                   %%%                      |  __ \
                 ###%%%%%%%%%%%%*           | |__) |__ _ __ ___ ___  _ __   __ _
                ###  ##%%      %%%%         |  ___/ _ \ '__/ __/ _ \| '_ \ / _` |
              ####     ##%       %%%%       | |  |  __/ | | (_| (_) | | | | (_| |
             ###        ####      %%%       |_|   \___|_|  \___\___/|_| |_|\__,_|
           ,((###         ###     %%%         _____                       _
          (((( (###        ####  %%%%        / ____|                     | |
         (((     ((#         ######         | (___   __ _ _   _  __ _  __| |
       ((((       (((#        ####           \___ \ / _` | | | |/ _` |/ _` |
      /((          ,(((        *###          ____) | (_| | |_| | (_| | (_| |
    ////             (((         ####       |_____/ \__, |\__,_|\__,_|\__,_|
   ///                ((((        ####                 | |
 /////////////(((((((((((((((((########                |_|   Join @ squad.percona.com/mongodb

** Join Percona Squad! **
Participate in monthly SWAG raffles, get early access to new product features,
invite-only ”ask me anything” sessions with database performance experts.

Interested? Fill in the form at squad.percona.com/mongodb


2026-01-15T08:01:14.000+0000 I log options: log-path=/dev/stderr, log-level:D, log-json:false
2026-01-15T08:01:14.000+0000 I pbm-agent:
Version:   2.12.0
Platform:  linux/amd64
GitCommit: 2f7100a2a1da2bb7074e15d757693999cac7574e
GitBranch: release-2.12.0
BuildTime: 2025-10-31_09:21_UTC
GoVersion: go1.25.3
2026-01-15T08:01:14.000+0000 I starting PITR routine
2026-01-15T08:01:14.000+0000 I node: admin-async-jobs/admin-async-jobs-admin-async-jobs-0.admin-async-jobs-admin-async-jobs.psmdb-admin-async-jobs.svc.cluster.local:27017
2026-01-15T08:01:14.000+0000 I conn level ReadConcern: majority; WriteConcern: majority
2026-01-15T08:01:14.000+0000 I listening for the commands
2026-01-15T08:01:30.000+0000 I got command restore [name: 2026-01-15T08:01:30.50237456Z, snapshot: 2026-01-14T09:46:28Z] <ts: 1768464090>, opid: 69689eda96ec1179b5171501
2026-01-15T08:01:30.000+0000 I got epoch {1768463903 1}
2026-01-15T08:01:30.000+0000 I [restore/2026-01-15T08:01:30.50237456Z] oplog slicer disabled
2026-01-15T08:01:30.000+0000 I [restore/2026-01-15T08:01:30.50237456Z] backup: 2026-01-14T09:46:28Z
2026-01-15T08:01:30.000+0000 I [restore/2026-01-15T08:01:30.50237456Z] recovery started
2026-01-15T08:01:30.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] port: 27291
2026-01-15T08:01:30.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] uploading ".pbm.restore/2026-01-15T08:01:30.50237456Z/rs.admin-async-jobs/node.admin-async-jobs-admin-async-jobs-0.admin-async-jobs-admin-async-jobs.psmdb-admin-async-jobs.svc.cluster.local:27017.hb" [size hint: 10 (10.00B); part size: 10485760 (10.00MB)]
2026-01-15T08:01:30.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] uploading ".pbm.restore/2026-01-15T08:01:30.50237456Z/rs.admin-async-jobs/rs.hb" [size hint: 10 (10.00B); part size: 10485760 (10.00MB)]
2026-01-15T08:01:30.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] uploading ".pbm.restore/2026-01-15T08:01:30.50237456Z/cluster.hb" [size hint: 10 (10.00B); part size: 10485760 (10.00MB)]
2026-01-15T08:01:30.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] download max buf 1073741824 (arena 268435456, span 33554432, concurrency 4)
2026-01-15T08:01:30.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] mongod binary: mongod, version: v7.0.18-11
2026-01-15T08:01:31.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] restore opts: fallbackEnabled: false; allowPartlyDone: true
2026-01-15T08:01:31.000+0000 I [restore/2026-01-15T08:01:30.50237456Z] moving to state starting
2026-01-15T08:01:31.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] uploading ".pbm.restore/2026-01-15T08:01:30.50237456Z/rs.admin-async-jobs/node.admin-async-jobs-admin-async-jobs-0.admin-async-jobs-admin-async-jobs.psmdb-admin-async-jobs.svc.cluster.local:27017.starting" [size hint: 10 (10.00B); part size: 10485760 (10.00MB)]
2026-01-15T08:01:31.000+0000 I [restore/2026-01-15T08:01:30.50237456Z] waiting for `starting` status in rs map[.pbm.restore/2026-01-15T08:01:30.50237456Z/rs.admin-async-jobs/node.admin-async-jobs-admin-async-jobs-0.admin-async-jobs-admin-async-jobs.psmdb-admin-async-jobs.svc.cluster.local:27017:{} .pbm.restore/2026-01-15T08:01:30.50237456Z/rs.admin-async-jobs/node.admin-async-jobs-admin-async-jobs-1.admin-async-jobs-admin-async-jobs.psmdb-admin-async-jobs.svc.cluster.local:27017:{}]
sh-5.1$ head /tmp/pbm-agent.log -n 50
2026-01-15T08:01:14.000+0000 I
                    %                        _____
                   %%%                      |  __ \
                 ###%%%%%%%%%%%%*           | |__) |__ _ __ ___ ___  _ __   __ _
                ###  ##%%      %%%%         |  ___/ _ \ '__/ __/ _ \| '_ \ / _` |
              ####     ##%       %%%%       | |  |  __/ | | (_| (_) | | | | (_| |
             ###        ####      %%%       |_|   \___|_|  \___\___/|_| |_|\__,_|
           ,((###         ###     %%%         _____                       _
          (((( (###        ####  %%%%        / ____|                     | |
         (((     ((#         ######         | (___   __ _ _   _  __ _  __| |
       ((((       (((#        ####           \___ \ / _` | | | |/ _` |/ _` |
      /((          ,(((        *###          ____) | (_| | |_| | (_| | (_| |
    ////             (((         ####       |_____/ \__, |\__,_|\__,_|\__,_|
   ///                ((((        ####                 | |
 /////////////(((((((((((((((((########                |_|   Join @ squad.percona.com/mongodb

** Join Percona Squad! **
Participate in monthly SWAG raffles, get early access to new product features,
invite-only ”ask me anything” sessions with database performance experts.

Interested? Fill in the form at squad.percona.com/mongodb


2026-01-15T08:01:14.000+0000 I log options: log-path=/dev/stderr, log-level:D, log-json:false
2026-01-15T08:01:14.000+0000 I pbm-agent:
Version:   2.12.0
Platform:  linux/amd64
GitCommit: 2f7100a2a1da2bb7074e15d757693999cac7574e
GitBranch: release-2.12.0
BuildTime: 2025-10-31_09:21_UTC
GoVersion: go1.25.3
2026-01-15T08:01:14.000+0000 I starting PITR routine
2026-01-15T08:01:14.000+0000 I node: admin-async-jobs/admin-async-jobs-admin-async-jobs-0.admin-async-jobs-admin-async-jobs.psmdb-admin-async-jobs.svc.cluster.local:27017
2026-01-15T08:01:14.000+0000 I conn level ReadConcern: majority; WriteConcern: majority
2026-01-15T08:01:14.000+0000 I listening for the commands
2026-01-15T08:01:30.000+0000 I got command restore [name: 2026-01-15T08:01:30.50237456Z, snapshot: 2026-01-14T09:46:28Z] <ts: 1768464090>, opid: 69689eda96ec1179b5171501
2026-01-15T08:01:30.000+0000 I got epoch {1768463903 1}
2026-01-15T08:01:30.000+0000 I [restore/2026-01-15T08:01:30.50237456Z] oplog slicer disabled
2026-01-15T08:01:30.000+0000 I [restore/2026-01-15T08:01:30.50237456Z] backup: 2026-01-14T09:46:28Z
2026-01-15T08:01:30.000+0000 I [restore/2026-01-15T08:01:30.50237456Z] recovery started
2026-01-15T08:01:30.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] port: 27291
2026-01-15T08:01:30.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] uploading ".pbm.restore/2026-01-15T08:01:30.50237456Z/rs.admin-async-jobs/node.admin-async-jobs-admin-async-jobs-0.admin-async-jobs-admin-async-jobs.psmdb-admin-async-jobs.svc.cluster.local:27017.hb" [size hint: 10 (10.00B); part size: 10485760 (10.00MB)]
2026-01-15T08:01:30.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] uploading ".pbm.restore/2026-01-15T08:01:30.50237456Z/rs.admin-async-jobs/rs.hb" [size hint: 10 (10.00B); part size: 10485760 (10.00MB)]
2026-01-15T08:01:30.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] uploading ".pbm.restore/2026-01-15T08:01:30.50237456Z/cluster.hb" [size hint: 10 (10.00B); part size: 10485760 (10.00MB)]
2026-01-15T08:01:30.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] download max buf 1073741824 (arena 268435456, span 33554432, concurrency 4)
2026-01-15T08:01:30.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] mongod binary: mongod, version: v7.0.18-11
2026-01-15T08:01:31.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] restore opts: fallbackEnabled: false; allowPartlyDone: true
2026-01-15T08:01:31.000+0000 I [restore/2026-01-15T08:01:30.50237456Z] moving to state starting
2026-01-15T08:01:31.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] uploading ".pbm.restore/2026-01-15T08:01:30.50237456Z/rs.admin-async-jobs/node.admin-async-jobs-admin-async-jobs-0.admin-async-jobs-admin-async-jobs.psmdb-admin-async-jobs.svc.cluster.local:27017.starting" [size hint: 10 (10.00B); part size: 10485760 (10.00MB)]
2026-01-15T08:01:31.000+0000 I [restore/2026-01-15T08:01:30.50237456Z] waiting for `starting` status in rs map[.pbm.restore/2026-01-15T08:01:30.50237456Z/rs.admin-async-jobs/node.admin-async-jobs-admin-async-jobs-0.admin-async-jobs-admin-async-jobs.psmdb-admin-async-jobs.svc.cluster.local:27017:{} .pbm.restore/2026-01-15T08:01:30.50237456Z/rs.admin-async-jobs/node.admin-async-jobs-admin-async-jobs-1.admin-async-jobs-admin-async-jobs.psmdb-admin-async-jobs.svc.cluster.local:27017:{}]

And on the other node:

cat /etc/hostname
admin-async-jobs-admin-async-jobs-1
sh-5.1$ tail /tmp/pbm-agent.log -n 50
2026-01-15T08:47:31.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] uploading ".pbm.restore/2026-01-15T08:01:30.50237456Z/rs.admin-async-jobs/rs.hb" [size hint: 10 (10.00B); part size: 10485760 (10.00MB)]
2026-01-15T08:47:31.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] uploading ".pbm.restore/2026-01-15T08:01:30.50237456Z/cluster.hb" [size hint: 10 (10.00B); part size: 10485760 (10.00MB)]
2026-01-15T08:49:30.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] uploading ".pbm.restore/2026-01-15T08:01:30.50237456Z/rs.admin-async-jobs/node.admin-async-jobs-admin-async-jobs-1.admin-async-jobs-admin-async-jobs.psmdb-admin-async-jobs.svc.cluster.local:27017.hb" [size hint: 10 (10.00B); part size: 10485760 (10.00MB)]
2026-01-15T08:49:31.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] uploading ".pbm.restore/2026-01-15T08:01:30.50237456Z/rs.admin-async-jobs/rs.hb" [size hint: 10 (10.00B); part size: 10485760 (10.00MB)]
2026-01-15T08:49:31.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] uploading ".pbm.restore/2026-01-15T08:01:30.50237456Z/cluster.hb" [size hint: 10 (10.00B); part size: 10485760 (10.00MB)]
2026-01-15T08:51:30.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] uploading ".pbm.restore/2026-01-15T08:01:30.50237456Z/rs.admin-async-jobs/node.admin-async-jobs-admin-async-jobs-1.admin-async-jobs-admin-async-jobs.psmdb-admin-async-jobs.svc.cluster.local:27017.hb" [size hint: 10 (10.00B); part size: 10485760 (10.00MB)]
2026-01-15T08:51:31.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] uploading ".pbm.restore/2026-01-15T08:01:30.50237456Z/rs.admin-async-jobs/rs.hb" [size hint: 10 (10.00B); part size: 10485760 (10.00MB)]
2026-01-15T08:51:31.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] uploading ".pbm.restore/2026-01-15T08:01:30.50237456Z/cluster.hb" [size hint: 10 (10.00B); part size: 10485760 (10.00MB)]
2026-01-15T08:53:30.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] uploading ".pbm.restore/2026-01-15T08:01:30.50237456Z/rs.admin-async-jobs/node.admin-async-jobs-admin-async-jobs-1.admin-async-jobs-admin-async-jobs.psmdb-admin-async-jobs.svc.cluster.local:27017.hb" [size hint: 10 (10.00B); part size: 10485760 (10.00MB)]
2026-01-15T08:53:31.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] uploading ".pbm.restore/2026-01-15T08:01:30.50237456Z/rs.admin-async-jobs/rs.hb" [size hint: 10 (10.00B); part size: 10485760 (10.00MB)]
2026-01-15T08:53:31.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] uploading ".pbm.restore/2026-01-15T08:01:30.50237456Z/cluster.hb" [size hint: 10 (10.00B); part size: 10485760 (10.00MB)]
2026-01-15T08:55:30.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] uploading ".pbm.restore/2026-01-15T08:01:30.50237456Z/rs.admin-async-jobs/node.admin-async-jobs-admin-async-jobs-1.admin-async-jobs-admin-async-jobs.psmdb-admin-async-jobs.svc.cluster.local:27017.hb" [size hint: 10 (10.00B); part size: 10485760 (10.00MB)]
2026-01-15T08:55:31.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] uploading ".pbm.restore/2026-01-15T08:01:30.50237456Z/rs.admin-async-jobs/rs.hb" [size hint: 10 (10.00B); part size: 10485760 (10.00MB)]
2026-01-15T08:55:31.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] uploading ".pbm.restore/2026-01-15T08:01:30.50237456Z/cluster.hb" [size hint: 10 (10.00B); part size: 10485760 (10.00MB)]
2026-01-15T08:57:30.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] uploading ".pbm.restore/2026-01-15T08:01:30.50237456Z/rs.admin-async-jobs/node.admin-async-jobs-admin-async-jobs-1.admin-async-jobs-admin-async-jobs.psmdb-admin-async-jobs.svc.cluster.local:27017.hb" [size hint: 10 (10.00B); part size: 10485760 (10.00MB)]
2026-01-15T08:57:31.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] uploading ".pbm.restore/2026-01-15T08:01:30.50237456Z/rs.admin-async-jobs/rs.hb" [size hint: 10 (10.00B); part size: 10485760 (10.00MB)]
2026-01-15T08:57:31.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] uploading ".pbm.restore/2026-01-15T08:01:30.50237456Z/cluster.hb" [size hint: 10 (10.00B); part size: 10485760 (10.00MB)]
2026-01-15T08:59:30.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] uploading ".pbm.restore/2026-01-15T08:01:30.50237456Z/rs.admin-async-jobs/node.admin-async-jobs-admin-async-jobs-1.admin-async-jobs-admin-async-jobs.psmdb-admin-async-jobs.svc.cluster.local:27017.hb" [size hint: 10 (10.00B); part size: 10485760 (10.00MB)]
2026-01-15T08:59:31.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] uploading ".pbm.restore/2026-01-15T08:01:30.50237456Z/rs.admin-async-jobs/rs.hb" [size hint: 10 (10.00B); part size: 10485760 (10.00MB)]
2026-01-15T08:59:31.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] uploading ".pbm.restore/2026-01-15T08:01:30.50237456Z/cluster.hb" [size hint: 10 (10.00B); part size: 10485760 (10.00MB)]
2026-01-15T09:01:30.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] uploading ".pbm.restore/2026-01-15T08:01:30.50237456Z/rs.admin-async-jobs/node.admin-async-jobs-admin-async-jobs-1.admin-async-jobs-admin-async-jobs.psmdb-admin-async-jobs.svc.cluster.local:27017.hb" [size hint: 10 (10.00B); part size: 10485760 (10.00MB)]
2026-01-15T09:01:31.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] uploading ".pbm.restore/2026-01-15T08:01:30.50237456Z/rs.admin-async-jobs/rs.hb" [size hint: 10 (10.00B); part size: 10485760 (10.00MB)]
2026-01-15T09:01:31.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] uploading ".pbm.restore/2026-01-15T08:01:30.50237456Z/cluster.hb" [size hint: 10 (10.00B); part size: 10485760 (10.00MB)]
2026-01-15T09:03:30.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] uploading ".pbm.restore/2026-01-15T08:01:30.50237456Z/rs.admin-async-jobs/node.admin-async-jobs-admin-async-jobs-1.admin-async-jobs-admin-async-jobs.psmdb-admin-async-jobs.svc.cluster.local:27017.hb" [size hint: 10 (10.00B); part size: 10485760 (10.00MB)]
2026-01-15T09:03:31.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] uploading ".pbm.restore/2026-01-15T08:01:30.50237456Z/rs.admin-async-jobs/rs.hb" [size hint: 10 (10.00B); part size: 10485760 (10.00MB)]
2026-01-15T09:03:31.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] uploading ".pbm.restore/2026-01-15T08:01:30.50237456Z/cluster.hb" [size hint: 10 (10.00B); part size: 10485760 (10.00MB)]
2026-01-15T09:05:30.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] uploading ".pbm.restore/2026-01-15T08:01:30.50237456Z/rs.admin-async-jobs/node.admin-async-jobs-admin-async-jobs-1.admin-async-jobs-admin-async-jobs.psmdb-admin-async-jobs.svc.cluster.local:27017.hb" [size hint: 10 (10.00B); part size: 10485760 (10.00MB)]
2026-01-15T09:05:31.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] uploading ".pbm.restore/2026-01-15T08:01:30.50237456Z/rs.admin-async-jobs/rs.hb" [size hint: 10 (10.00B); part size: 10485760 (10.00MB)]
2026-01-15T09:05:31.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] uploading ".pbm.restore/2026-01-15T08:01:30.50237456Z/cluster.hb" [size hint: 10 (10.00B); part size: 10485760 (10.00MB)]
2026-01-15T09:07:30.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] uploading ".pbm.restore/2026-01-15T08:01:30.50237456Z/rs.admin-async-jobs/node.admin-async-jobs-admin-async-jobs-1.admin-async-jobs-admin-async-jobs.psmdb-admin-async-jobs.svc.cluster.local:27017.hb" [size hint: 10 (10.00B); part size: 10485760 (10.00MB)]
2026-01-15T09:07:31.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] uploading ".pbm.restore/2026-01-15T08:01:30.50237456Z/rs.admin-async-jobs/rs.hb" [size hint: 10 (10.00B); part size: 10485760 (10.00MB)]
2026-01-15T09:07:31.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] uploading ".pbm.restore/2026-01-15T08:01:30.50237456Z/cluster.hb" [size hint: 10 (10.00B); part size: 10485760 (10.00MB)]
2026-01-15T09:09:30.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] uploading ".pbm.restore/2026-01-15T08:01:30.50237456Z/rs.admin-async-jobs/node.admin-async-jobs-admin-async-jobs-1.admin-async-jobs-admin-async-jobs.psmdb-admin-async-jobs.svc.cluster.local:27017.hb" [size hint: 10 (10.00B); part size: 10485760 (10.00MB)]
2026-01-15T09:09:31.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] uploading ".pbm.restore/2026-01-15T08:01:30.50237456Z/rs.admin-async-jobs/rs.hb" [size hint: 10 (10.00B); part size: 10485760 (10.00MB)]
2026-01-15T09:09:31.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] uploading ".pbm.restore/2026-01-15T08:01:30.50237456Z/cluster.hb" [size hint: 10 (10.00B); part size: 10485760 (10.00MB)]
2026-01-15T09:11:30.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] uploading ".pbm.restore/2026-01-15T08:01:30.50237456Z/rs.admin-async-jobs/node.admin-async-jobs-admin-async-jobs-1.admin-async-jobs-admin-async-jobs.psmdb-admin-async-jobs.svc.cluster.local:27017.hb" [size hint: 10 (10.00B); part size: 10485760 (10.00MB)]
2026-01-15T09:11:31.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] uploading ".pbm.restore/2026-01-15T08:01:30.50237456Z/rs.admin-async-jobs/rs.hb" [size hint: 10 (10.00B); part size: 10485760 (10.00MB)]
2026-01-15T09:11:31.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] uploading ".pbm.restore/2026-01-15T08:01:30.50237456Z/cluster.hb" [size hint: 10 (10.00B); part size: 10485760 (10.00MB)]
2026-01-15T09:13:30.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] uploading ".pbm.restore/2026-01-15T08:01:30.50237456Z/rs.admin-async-jobs/node.admin-async-jobs-admin-async-jobs-1.admin-async-jobs-admin-async-jobs.psmdb-admin-async-jobs.svc.cluster.local:27017.hb" [size hint: 10 (10.00B); part size: 10485760 (10.00MB)]
2026-01-15T09:13:31.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] uploading ".pbm.restore/2026-01-15T08:01:30.50237456Z/rs.admin-async-jobs/rs.hb" [size hint: 10 (10.00B); part size: 10485760 (10.00MB)]
2026-01-15T09:13:31.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] uploading ".pbm.restore/2026-01-15T08:01:30.50237456Z/cluster.hb" [size hint: 10 (10.00B); part size: 10485760 (10.00MB)]
2026-01-15T09:15:30.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] uploading ".pbm.restore/2026-01-15T08:01:30.50237456Z/rs.admin-async-jobs/node.admin-async-jobs-admin-async-jobs-1.admin-async-jobs-admin-async-jobs.psmdb-admin-async-jobs.svc.cluster.local:27017.hb" [size hint: 10 (10.00B); part size: 10485760 (10.00MB)]
2026-01-15T09:15:31.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] uploading ".pbm.restore/2026-01-15T08:01:30.50237456Z/rs.admin-async-jobs/rs.hb" [size hint: 10 (10.00B); part size: 10485760 (10.00MB)]
2026-01-15T09:15:31.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] uploading ".pbm.restore/2026-01-15T08:01:30.50237456Z/cluster.hb" [size hint: 10 (10.00B); part size: 10485760 (10.00MB)]
2026-01-15T09:17:30.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] uploading ".pbm.restore/2026-01-15T08:01:30.50237456Z/rs.admin-async-jobs/node.admin-async-jobs-admin-async-jobs-1.admin-async-jobs-admin-async-jobs.psmdb-admin-async-jobs.svc.cluster.local:27017.hb" [size hint: 10 (10.00B); part size: 10485760 (10.00MB)]
2026-01-15T09:17:31.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] uploading ".pbm.restore/2026-01-15T08:01:30.50237456Z/rs.admin-async-jobs/rs.hb" [size hint: 10 (10.00B); part size: 10485760 (10.00MB)]
2026-01-15T09:17:31.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] uploading ".pbm.restore/2026-01-15T08:01:30.50237456Z/cluster.hb" [size hint: 10 (10.00B); part size: 10485760 (10.00MB)]
2026-01-15T09:19:30.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] uploading ".pbm.restore/2026-01-15T08:01:30.50237456Z/rs.admin-async-jobs/node.admin-async-jobs-admin-async-jobs-1.admin-async-jobs-admin-async-jobs.psmdb-admin-async-jobs.svc.cluster.local:27017.hb" [size hint: 10 (10.00B); part size: 10485760 (10.00MB)]
2026-01-15T09:19:31.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] uploading ".pbm.restore/2026-01-15T08:01:30.50237456Z/rs.admin-async-jobs/rs.hb" [size hint: 10 (10.00B); part size: 10485760 (10.00MB)]
2026-01-15T09:19:31.000+0000 D [restore/2026-01-15T08:01:30.50237456Z] uploading ".pbm.restore/2026-01-15T08:01:30.50237456Z/cluster.hb" [size hint: 10 (10.00B); part size: 10485760 (10.00MB)]

[egegunes]

OK, definitely something strange going on. Could you please share the yaml of the cluster? I want to try to reproduce with your configuration.

[cjesper]

@egegunes Sure:

kubectl describe perconaservermongodb -n psmdb-admin-async-jobs
Name:         admin-async-jobs
Namespace:    psmdb-admin-async-jobs
Labels:       app.kubernetes.io/instance=admin-async-jobs-app
              argocd.argoproj.io/instance=admin-async-jobs
Annotations:  argocd.argoproj.io/tracking-id: admin-async-jobs:psmdb.percona.com/PerconaServerMongoDB:psmdb-admin-async-jobs/admin-async-jobs
API Version:  psmdb.percona.com/v1
Kind:         PerconaServerMongoDB
Metadata:
  Creation Timestamp:  2025-12-12T11:16:59Z
  Generation:          7
  Resource Version:    207612651
  UID:                 83a856a1-5c6d-44f8-a1e8-120d0aa370dd
Spec:
  Backup:
    Container Security Context:
      Allow Privilege Escalation:  false
      Capabilities:
        Drop:
          ALL
      Privileged:       false
      Run As Non Root:  true
      Run As User:      1001
    Enabled:            true
    Image:              perconalab/percona-server-mongodb-operator:main-backup
    Pitr:
      Enabled:  false
    Storages:
      s3-us-east:
        s3:
          Bucket:              mongodb-k8s-backups
          Credentials Secret:  pbm-backup-credentials
          Prefix:              admin-async-jobs
          Region:              us-east-1
        Type:                  s3
    Tasks:
      Compression Level:    6
      Compression Type:     gzip
      Enabled:              true
      Keep:                 3
      Name:                 admin-async-jobs-physical
      Schedule:             0 0 * * *
      Storage Name:         s3-us-east
      Type:                 physical
  Cr Version:               1.20.1
  Enable Volume Expansion:  true
  Image:                    percona/percona-server-mongodb:7.0.18-11
  Init Container Security Context:
    Allow Privilege Escalation:  false
    Capabilities:
      Drop:
        ALL
    Run As Group:     1001
    Run As Non Root:  true
    Run As User:      1001
  Replsets:
    Affinity:
      Advanced:
        Node Affinity:
          Required During Scheduling Ignored During Execution:
            Node Selector Terms:
              Match Expressions:
                Key:       test.io/instance-group
                Operator:  In
                Values:
                  mongo-ebs
                  mongo-ebs-xlarge
                  mongo-ebs-4xlarge
        Pod Anti Affinity:
          Required During Scheduling Ignored During Execution:
            Label Selector:
              Match Expressions:
                Key:       app.kubernetes.io/instance
                Operator:  In
                Values:
                  admin-async-jobs
            Topology Key:  kubernetes.io/hostname
    Annotations:
      k8s.grafana.com/job:                 scrape-percona-server-mongodb
      k8s.grafana.com/metrics.portNumber:  9216
      k8s.grafana.com/scrape:              true
    Configuration:                         replication:
  oplogSizeMB: 1000
security:
  clusterAuthMode: keyFile
  keyFile: /etc/mongodb-secrets/mongodb-key

    Container Security Context:
      Allow Privilege Escalation:  false
      Capabilities:
        Drop:
          ALL
      Privileged:       false
      Run As Group:     1001
      Run As Non Root:  true
      Run As User:      1001
    Expose:
      Enabled:  false
    Name:       admin-async-jobs
    Pod Security Context:
      Fs Group:      1001
      Run As Group:  1001
      Run As User:   1001
      Supplemental Groups:
        1001
    Resources:
      Limits:
        Cpu:     4
        Memory:  4Gi
      Requests:
        Cpu:     4
        Memory:  4Gi
    Sidecars:
      Args:
        --mongodb.uri=mongodb://admin:password@127.0.0.1:27017/admin
        --collect-all
      Image:  percona/mongodb_exporter:0.40
      Name:   rs-mongo-exporter-0
      Security Context:
        Allow Privilege Escalation:  false
        Capabilities:
          Drop:
            ALL
        Privileged:       false
        Run As Non Root:  true
        Run As User:      1001
    Size:                 2
    Split Horizons:
      admin-async-jobs-admin-async-jobs-0:
        External:  mon-dt-admin-async-jobs-0.test.io
      admin-async-jobs-admin-async-jobs-1:
        External:  mon-dt-admin-async-jobs-1.test.io
    Tolerations:
      Effect:    NoSchedule
      Key:       test.io/mongo-ebs
      Operator:  Exists
    Volume Spec:
      Persistent Volume Claim:
        Annotations:
          ebs.test.io/iops:  3200
        Resources:
          Requests:
            Storage:  5Gi
  Secrets:
    Key File:  admin-async-jobs-keyfile
    Ssl:       mongodb-ssl
  Sharding:
    Enabled:  false
  Tls:
    Allow Invalid Certificates:  true
    Mode:                        preferTLS
  Unsafe Flags:
    Replset Size:   true
    Tls:            true
  Update Strategy:  SmartUpdate
  Users:
    Db:    admin
    Name:  admin
    Password Secret Ref:
      Key:   password
      Name:  mongo-admin-password
    Roles:
      Db:    admin
      Name:  clusterAdmin
      Db:    admin
      Name:  userAdminAnyDatabase
      Db:    admin
      Name:  readWriteAnyDatabase
Status:
  Backup Config Hash:  c59ad9730b5fd92403f9222419fbacbdbdf9c38ac882e220de4cd47b962c6ee0
  Backup Image:        perconalab/percona-server-mongodb-operator:main-backup
  Backup Version:      2.12.0
  Conditions:
    Last Transition Time:  2025-12-12T11:17:12Z
    Status:                False
    Type:                  sharding
    Last Transition Time:  2025-12-12T11:17:12Z
    Status:                True
    Type:                  initializing
    Last Transition Time:  2025-12-12T11:18:45Z
    Message:               admin-async-jobs: ready
    Reason:                RSReady
    Status:                True
    Type:                  ready
    Last Transition Time:  2025-12-17T12:58:25Z
    Message:               dial: ping mongo: connection() error occurred during connection handshake: dial tcp: lookup admin-async-jobs-admin-async-jobs-0.admin-async-jobs-admin-async-jobs.psmdb-admin-async-jobs.svc.cluster.local on 100.64.0.10:53: no such host
    Reason:                ErrorReconcile
    Status:                True
    Type:                  error
  Host:                    admin-async-jobs-admin-async-jobs.psmdb-admin-async-jobs.svc.cluster.local
  Mongo Image:             percona/percona-server-mongodb:7.0.18-11
  Mongo Version:           7.0.18-11
  Observed Generation:     7
  Ready:                   2
  Replsets:
    Admin - Async - Jobs:
      Initialized:  true
      Ready:        2
      Size:         2
      Status:       ready
  Size:             2
  State:            initializing

[egegunes]

@cjesper could you please give me the output of kubectl get psmdb admin-async-jobs -n psmdb-admin-async-jobs -o yaml?

[cjesper]

kubectl get psmdb admin-async-jobs -n psmdb-admin-async-jobs -o yaml
apiVersion: psmdb.percona.com/v1
kind: PerconaServerMongoDB
metadata:
  annotations:
    argocd.argoproj.io/tracking-id: admin-async-jobs:psmdb.percona.com/PerconaServerMongoDB:psmdb-admin-async-jobs/admin-async-jobs
  creationTimestamp: "2025-12-12T11:16:59Z"
  generation: 7
  labels:
    app.kubernetes.io/instance: admin-async-jobs-app
    argocd.argoproj.io/instance: admin-async-jobs
  name: admin-async-jobs
  namespace: psmdb-admin-async-jobs
  resourceVersion: "207612651"
  uid: 83a856a1-5c6d-44f8-a1e8-120d0aa370dd
spec:
  backup:
    containerSecurityContext:
      allowPrivilegeEscalation: false
      capabilities:
        drop:
        - ALL
      privileged: false
      runAsNonRoot: true
      runAsUser: 1001
    enabled: true
    image: perconalab/percona-server-mongodb-operator:main-backup
    pitr:
      enabled: false
    storages:
      s3-us-east:
        s3:
          bucket: mongodb-k8s-backups
          credentialsSecret: pbm-backup-credentials
          prefix: admin-async-jobs
          region: us-east-1
        type: s3
    tasks:
    - compressionLevel: 6
      compressionType: gzip
      enabled: true
      keep: 3
      name: admin-async-jobs-physical
      schedule: 0 0 * * *
      storageName: s3-us-east
      type: physical
  crVersion: 1.20.1
  enableVolumeExpansion: true
  image: percona/percona-server-mongodb:7.0.18-11
  initContainerSecurityContext:
    allowPrivilegeEscalation: false
    capabilities:
      drop:
      - ALL
    runAsGroup: 1001
    runAsNonRoot: true
    runAsUser: 1001
  replsets:
  - affinity:
      advanced:
        nodeAffinity:
          requiredDuringSchedulingIgnoredDuringExecution:
            nodeSelectorTerms:
            - matchExpressions:
              - key: test.io/instance-group
                operator: In
                values:
                - mongo-ebs
                - mongo-ebs-xlarge
                - mongo-ebs-4xlarge
        podAntiAffinity:
          requiredDuringSchedulingIgnoredDuringExecution:
          - labelSelector:
              matchExpressions:
              - key: app.kubernetes.io/instance
                operator: In
                values:
                - admin-async-jobs
            topologyKey: kubernetes.io/hostname
    annotations:
      k8s.grafana.com/job: scrape-percona-server-mongodb
      k8s.grafana.com/metrics.portNumber: "9216"
      k8s.grafana.com/scrape: "true"
    configuration: |
      replication:
        oplogSizeMB: 1000
      security:
        clusterAuthMode: keyFile
        keyFile: /etc/mongodb-secrets/mongodb-key
    containerSecurityContext:
      allowPrivilegeEscalation: false
      capabilities:
        drop:
        - ALL
      privileged: false
      runAsGroup: 1001
      runAsNonRoot: true
      runAsUser: 1001
    expose:
      enabled: false
    name: admin-async-jobs
    podSecurityContext:
      fsGroup: 1001
      runAsGroup: 1001
      runAsUser: 1001
      supplementalGroups:
      - 1001
    resources:
      limits:
        cpu: 4
        memory: 4Gi
      requests:
        cpu: 4
        memory: 4Gi
    sidecars:
    - args:
      - --mongodb.uri=mongodb://admin:password@127.0.0.1:27017/admin
      - --collect-all
      image: percona/mongodb_exporter:0.40
      name: rs-mongo-exporter-0
      securityContext:
        allowPrivilegeEscalation: false
        capabilities:
          drop:
          - ALL
        privileged: false
        runAsNonRoot: true
        runAsUser: 1001
    size: 2
    splitHorizons:
      admin-async-jobs-admin-async-jobs-0:
        external: mon-dt-admin-async-jobs-0.test.io
      admin-async-jobs-admin-async-jobs-1:
        external: mon-dt-admin-async-jobs-1.test.io
    tolerations:
    - effect: NoSchedule
      key: test.io/mongo-ebs
      operator: Exists
    volumeSpec:
      persistentVolumeClaim:
        annotations:
          ebs.test.io/iops: "3200"
        resources:
          requests:
            storage: 5Gi
  secrets:
    keyFile: admin-async-jobs-keyfile
    ssl: mongodb-ssl
  sharding:
    enabled: false
  tls:
    allowInvalidCertificates: true
    mode: preferTLS
  unsafeFlags:
    replsetSize: true
    tls: true
  updateStrategy: SmartUpdate
  users:
  - db: admin
    name: admin
    passwordSecretRef:
      key: password
      name: mongo-admin-password
    roles:
    - db: admin
      name: clusterAdmin
    - db: admin
      name: userAdminAnyDatabase
    - db: admin
      name: readWriteAnyDatabase
status:
  backupConfigHash: c59ad9730b5fd92403f9222419fbacbdbdf9c38ac882e220de4cd47b962c6ee0
  backupImage: perconalab/percona-server-mongodb-operator:main-backup
  backupVersion: 2.12.0
  conditions:
  - lastTransitionTime: "2025-12-12T11:17:12Z"
    status: "False"
    type: sharding
  - lastTransitionTime: "2025-12-12T11:17:12Z"
    status: "True"
    type: initializing
  - lastTransitionTime: "2025-12-12T11:18:45Z"
    message: 'admin-async-jobs: ready'
    reason: RSReady
    status: "True"
    type: ready
  - lastTransitionTime: "2025-12-17T12:58:25Z"
    message: 'dial: ping mongo: connection() error occurred during connection handshake:
      dial tcp: lookup admin-async-jobs-admin-async-jobs-0.admin-async-jobs-admin-async-jobs.psmdb-admin-async-jobs.svc.cluster.local
      on 100.64.0.10:53: no such host'
    reason: ErrorReconcile
    status: "True"
    type: error
  host: admin-async-jobs-admin-async-jobs.psmdb-admin-async-jobs.svc.cluster.local
  mongoImage: percona/percona-server-mongodb:7.0.18-11
  mongoVersion: 7.0.18-11
  observedGeneration: 7
  ready: 2
  replsets:
    admin-async-jobs:
      initialized: true
      ready: 2
      size: 2
      status: ready
  size: 2
  state: initializing

[egegunes]

@cjesper I reproduced your issue, yes restore is stuck.

I suspected it's because replset has only 2 pods. Tried with 3 and restore finished successfully. Are you able to try with 3 replicas?

Not sure if we (or PBM) should count this as a bug tbh, since running only 2 replicas is an unsafe configuration.

[cjesper]

@egegunes - Ah, understood. We've been running a bunch of 2 node clusters to do some testing. I will scale up a cluster to 3 later today and try again. Will report back with status.

[cjesper]

@egegunes Just a follow up / fyi - we've enabled sharding in a few clusters and I seem to be able to reproduce the same behaviour by running <3 config servers ie. if I have a cluster set with
3 mongos
3 mongod
2 configServers
Then the backup becomes stuck in the same way.

Is that also to be expected?

[egegunes]

@cjesper yes, same thing applies to config server replset as well