Hello!
We have problem restoring physical mongodb created with pbm.
MongoDB version - percona-server-mongodb-server/stable,now 6.0.9-7.jammy
PBM version - percona-backup-mongodb/unknown,now 2.7.0-1.jammy
When we restore the backup to the test server with the remapped replica set name, it hangs after some time without any additional logs. We can see that network traffic drops and nothing happens on the server. We could get this error only on incremental physical backups. If we restore only base of incremental physical backups, everything works fine.
We also get this error when we use different servers for restores and different storages for backups. The storages used are OVH object storage and Hetzner object storage.
describe-restore seems to show incorrect information about start time and last_transition_time
~$ pbm describe-restore 2025-02-11T15:55:41.424113159Z -c /home/ubuntu/.config/pbm/pbm-config.s3_hetzner.yml
name: "2025-02-11T15:55:41.424113159Z"
opid: ""
backup: ""
type: physical
status: running
start: "1970-01-01T00:00:00Z"
last_transition_time: "2025-02-11T15:56:08Z"
replsets:
- name: rs-for-restore
status: down
last_transition_time: "2025-02-11T15:56:16Z"
nodes:
- name: 37.27.225.21:27017
status: running
last_transition_time: "2025-02-11T15:55:58Z"
Also, it seems that when the process hangs (and traffic drops), pbm-cli stops waiting, even though we set a fairly large wait time. We get these errors on another restore, so I will send examples in another message so that different timestamps do not bother you. Let me know if it’s important for the discussion.
Also let me know if we could attach any additional info about restores.
I cant attach full log file from start to finish of backup so attaching only main lines about start and some lines from the end
feb 11 15:49:02 backups-3-hel pbm-agent[24213]: 2025-02-11t15:49:02.000+0000 i got command resync <ts: 1739288941>, opid: 67ab716de9c6005697719baa
feb 11 15:49:02 backups-3-hel pbm-agent[24213]: 2025-02-11t15:49:02.000+0000 i got epoch {1739288939 1}
feb 11 15:49:02 backups-3-hel pbm-agent[24213]: 2025-02-11t15:49:02.000+0000 i [resync] started
feb 11 15:49:02 backups-3-hel pbm-agent[24213]: 2025-02-11t15:49:02.000+0000 d [resync] uploading ".pbm.init" [size hint: 5 (5.00b); part size: 10485760 (10.00mb)]
feb 11 15:53:01 backups-3-hel pbm-agent[24213]: 2025-02-11t15:53:01.000+0000 d [resync] got backups list: 12
feb 11 15:53:01 backups-3-hel pbm-agent[24213]: 2025-02-11t15:53:01.000+0000 d [resync] bcp: 2025-01-28t08:56:50z
feb 11 15:53:01 backups-3-hel pbm-agent[24213]: 2025-02-11t15:53:01.000+0000 d [resync] bcp: 2025-01-30t08:00:02z
feb 11 15:53:01 backups-3-hel pbm-agent[24213]: 2025-02-11t15:53:01.000+0000 d [resync] bcp: 2025-02-08t06:00:05z
feb 11 15:53:01 backups-3-hel pbm-agent[24213]: 2025-02-11t15:53:01.000+0000 d [resync] bcp: 2025-01-31t08:56:50z
feb 11 15:53:01 backups-3-hel pbm-agent[24213]: 2025-02-11t15:53:01.000+0000 d [resync] bcp: 2025-02-10t06:00:05z
feb 11 15:53:01 backups-3-hel pbm-agent[24213]: 2025-02-11t15:53:01.000+0000 d [resync] bcp: 2025-02-04t06:00:05z
feb 11 15:53:01 backups-3-hel pbm-agent[24213]: 2025-02-11t15:53:01.000+0000 d [resync] bcp: 2025-02-07t06:00:02z
feb 11 15:53:01 backups-3-hel pbm-agent[24213]: 2025-02-11t15:53:01.000+0000 d [resync] bcp: 2025-02-06t06:00:06z
feb 11 15:53:01 backups-3-hel pbm-agent[24213]: 2025-02-11t15:53:01.000+0000 d [resync] bcp: 2025-01-29t08:00:05z
feb 11 15:53:01 backups-3-hel pbm-agent[24213]: 2025-02-11t15:53:01.000+0000 d [resync] bcp: 2025-02-05t06:00:06z
feb 11 15:53:01 backups-3-hel pbm-agent[24213]: 2025-02-11t15:53:01.000+0000 d [resync] bcp: 2025-02-09t06:00:06z
feb 11 15:53:01 backups-3-hel pbm-agent[24213]: 2025-02-11t15:53:01.000+0000 d [resync] bcp: 2025-02-03t06:00:05z
feb 11 15:53:01 backups-3-hel pbm-agent[24213]: 2025-02-11t15:53:01.000+0000 d [resync] got physical restores list: 0
feb 11 15:53:01 backups-3-hel pbm-agent[24213]: 2025-02-11t15:53:01.000+0000 d [resync] epoch set to {1739289181 26}
feb 11 15:53:01 backups-3-hel pbm-agent[24213]: 2025-02-11t15:53:01.000+0000 i [resync] succeed
feb 11 15:55:41 backups-3-hel pbm-agent[24213]: 2025-02-11t15:55:41.000+0000 i got command restore [name: 2025-02-11t15:55:41.424113159z, snapshot: 2025-02-10t06:00:05z] <ts: 1739289341>, opid: 67ab72fd7fdd739ce90c3ef6
feb 11 15:55:41 backups-3-hel pbm-agent[24213]: 2025-02-11t15:55:41.000+0000 i got epoch {1739289181 26}
feb 11 15:55:41 backups-3-hel pbm-agent[24213]: 2025-02-11t15:55:41.000+0000 i [restore/2025-02-11t15:55:41.424113159z] oplog slicer disabled
feb 11 15:55:41 backups-3-hel pbm-agent[24213]: 2025-02-11t15:55:41.000+0000 i [restore/2025-02-11t15:55:41.424113159z] backup: 2025-02-10t06:00:05z
feb 11 15:55:41 backups-3-hel pbm-agent[24213]: 2025-02-11t15:55:41.000+0000 i [restore/2025-02-11t15:55:41.424113159z] recovery started
feb 11 15:55:41 backups-3-hel pbm-agent[24213]: 2025-02-11t15:55:41.000+0000 d [restore/2025-02-11t15:55:41.424113159z] port: 27640
feb 11 15:55:41 backups-3-hel pbm-agent[24213]: 2025-02-11t15:55:41.000+0000 d [restore/2025-02-11t15:55:41.424113159z] uploading ".pbm.restore/2025-02-11t15:55:41.424113159z/rs.rs-for-restore/node.37.27.225.21:27017.hb" [size hint: 10 (10.00b); part size: 10485760 (10.00mb)]
feb 11 15:55:41 backups-3-hel pbm-agent[24213]: 2025-02-11t15:55:41.000+0000 d [restore/2025-02-11t15:55:41.424113159z] uploading ".pbm.restore/2025-02-11t15:55:41.424113159z/rs.rs-for-restore/rs.hb" [size hint: 10 (10.00b); part size: 10485760 (10.00mb)]
feb 11 15:55:42 backups-3-hel pbm-agent[24213]: 2025-02-11t15:55:42.000+0000 d [restore/2025-02-11t15:55:41.424113159z] uploading ".pbm.restore/2025-02-11t15:55:41.424113159z/cluster.hb" [size hint: 10 (10.00b); part size: 10485760 (10.00mb)]
feb 11 15:55:42 backups-3-hel pbm-agent[24213]: 2025-02-11t15:55:42.000+0000 d [restore/2025-02-11t15:55:41.424113159z] mongod binary: mongod, version: v6.0.9-7
feb 11 15:55:42 backups-3-hel pbm-agent[24213]: 2025-02-11t15:55:42.000+0000 d [restore/2025-02-11t15:55:41.424113159z] get src 2025-02-09t06:00:06z
feb 11 15:55:42 backups-3-hel pbm-agent[24213]: 2025-02-11t15:55:42.000+0000 d [restore/2025-02-11t15:55:41.424113159z] get src 2025-02-08t06:00:05z
feb 11 15:55:42 backups-3-hel pbm-agent[24213]: 2025-02-11t15:55:42.000+0000 d [restore/2025-02-11t15:55:41.424113159z] get src 2025-02-07t06:00:02z
feb 11 15:55:42 backups-3-hel pbm-agent[24213]: 2025-02-11t15:55:42.000+0000 i [restore/2025-02-11t15:55:41.424113159z] moving to state starting
feb 11 15:55:42 backups-3-hel pbm-agent[24213]: 2025-02-11t15:55:42.000+0000 d [restore/2025-02-11t15:55:41.424113159z] uploading ".pbm.restore/2025-02-11t15:55:41.424113159z/rs.rs-for-restore/node.37.27.225.21:27017.starting" [size hint: 10 (10.00b); part size: 10485760 (10.00mb)]
feb 11 15:55:42 backups-3-hel pbm-agent[24213]: 2025-02-11t15:55:42.000+0000 i [restore/2025-02-11t15:55:41.424113159z] waiting for `starting` status in rs map[.pbm.restore/2025-02-11t15:55:41.424113159z/rs.rs-for-restore/node.37.27.225.21:27017:{}]
feb 11 15:55:47 backups-3-hel pbm-agent[24213]: 2025-02-11t15:55:47.000+0000 d [restore/2025-02-11t15:55:41.424113159z] uploading ".pbm.restore/2025-02-11t15:55:41.424113159z/rs.rs-for-restore/rs.starting" [size hint: 10 (10.00b); part size: 10485760 (10.00mb)]
feb 11 15:55:47 backups-3-hel pbm-agent[24213]: 2025-02-11t15:55:47.000+0000 i [restore/2025-02-11t15:55:41.424113159z] waiting for shards map[.pbm.restore/2025-02-11t15:55:41.424113159z/rs.rs-for-restore/rs:{}]
feb 11 15:55:52 backups-3-hel pbm-agent[24213]: 2025-02-11t15:55:52.000+0000 d [restore/2025-02-11t15:55:41.424113159z] uploading ".pbm.restore/2025-02-11t15:55:41.424113159z/cluster.starting" [size hint: 10 (10.00b); part size: 10485760 (10.00mb)]
feb 11 15:55:53 backups-3-hel pbm-agent[24213]: 2025-02-11t15:55:53.000+0000 i [restore/2025-02-11t15:55:41.424113159z] waiting for cluster
feb 11 15:55:58 backups-3-hel pbm-agent[24213]: 2025-02-11t15:55:58.000+0000 d [restore/2025-02-11t15:55:41.424113159z] converged to state starting
feb 11 15:55:58 backups-3-hel pbm-agent[24213]: 2025-02-11t15:55:58.000+0000 d [restore/2025-02-11t15:55:41.424113159z] starting
feb 11 15:55:58 backups-3-hel pbm-agent[24213]: 2025-02-11t15:55:58.000+0000 i [restore/2025-02-11t15:55:41.424113159z] moving to state running
feb 11 15:55:58 backups-3-hel pbm-agent[24213]: 2025-02-11t15:55:58.000+0000 d [restore/2025-02-11t15:55:41.424113159z] uploading ".pbm.restore/2025-02-11t15:55:41.424113159z/rs.rs-for-restore/node.37.27.225.21:27017.running" [size hint: 10 (10.00b); part size: 10485760 (10.00mb)]
feb 11 15:55:58 backups-3-hel pbm-agent[24213]: 2025-02-11t15:55:58.000+0000 i [restore/2025-02-11t15:55:41.424113159z] waiting for `running` status in rs map[.pbm.restore/2025-02-11t15:55:41.424113159z/rs.rs-for-restore/node.37.27.225.21:27017:{}]
feb 11 15:56:03 backups-3-hel pbm-agent[24213]: 2025-02-11t15:56:03.000+0000 d [restore/2025-02-11t15:55:41.424113159z] uploading ".pbm.restore/2025-02-11t15:55:41.424113159z/rs.rs-for-restore/rs.running" [size hint: 10 (10.00b); part size: 10485760 (10.00mb)]
feb 11 15:56:03 backups-3-hel pbm-agent[24213]: 2025-02-11t15:56:03.000+0000 i [restore/2025-02-11t15:55:41.424113159z] waiting for shards map[.pbm.restore/2025-02-11t15:55:41.424113159z/rs.rs-for-restore/rs:{}]
feb 11 15:56:08 backups-3-hel pbm-agent[24213]: 2025-02-11t15:56:08.000+0000 d [restore/2025-02-11t15:55:41.424113159z] uploading ".pbm.restore/2025-02-11t15:55:41.424113159z/cluster.running" [size hint: 10 (10.00b); part size: 10485760 (10.00mb)]
feb 11 15:56:08 backups-3-hel pbm-agent[24213]: 2025-02-11t15:56:08.000+0000 i [restore/2025-02-11t15:55:41.424113159z] waiting for cluster
feb 11 15:56:13 backups-3-hel pbm-agent[24213]: 2025-02-11t15:56:13.000+0000 d [restore/2025-02-11t15:55:41.424113159z] converged to state running
feb 11 15:56:13 backups-3-hel pbm-agent[24213]: 2025-02-11t15:56:13.000+0000 i [restore/2025-02-11t15:55:41.424113159z] send to stopagent chan
feb 11 15:56:14 backups-3-hel pbm-agent[24213]: 2025-02-11t15:56:14.000+0000 d [restore/2025-02-11t15:55:41.424113159z] stop agents heartbeats
feb 11 15:56:14 backups-3-hel pbm-agent[24213]: 2025-02-11t15:56:14.000+0000 i [restore/2025-02-11t15:55:41.424113159z] stopping mongod and flushing old data
feb 11 15:56:14 backups-3-hel pbm-agent[24213]: 2025-02-11t15:56:14.000+0000 d [restore/2025-02-11t15:55:41.424113159z] shutdown server
feb 11 15:56:15 backups-3-hel pbm-agent[24213]: 2025-02-11t15:56:15.000+0000 d [restore/2025-02-11t15:55:41.424113159z] waiting for the node to shutdown
feb 11 15:56:16 backups-3-hel pbm-agent[24213]: 2025-02-11t15:56:16.000+0000 d [restore/2025-02-11t15:55:41.424113159z] uploading ".pbm.restore/2025-02-11t15:55:41.424113159z/rs.rs-for-restore/rs.down" [size hint: 10 (10.00b); part size: 10485760 (10.00mb)]
feb 11 15:56:16 backups-3-hel pbm-agent[24213]: 2025-02-11t15:56:16.000+0000 d [restore/2025-02-11t15:55:41.424113159z] remove old data
....
feb 11 15:56:16 backups-3-hel pbm-agent[24213]: 2025-02-11t15:56:16.000+0000 i [restore/2025-02-11t15:55:41.424113159z] copying backup data
feb 11 15:56:16 backups-3-hel pbm-agent[24213]: 2025-02-11t15:56:16.000+0000 d [restore/2025-02-11t15:55:41.424113159z] download max buf 17179869184 (arena 536870912, span 33554432, concurrency 32)
feb 11 15:56:16 backups-3-hel pbm-agent[24213]: 2025-02-11t15:56:16.000+0000 i [restore/2025-02-11t15:55:41.424113159z] copy <2025-02-07t06:00:02z/fun0/wiredtigerhs.wt.s2.0-2150625280> to </data-mongodb/mongodb/wiredtigerhs.wt>
feb 11 15:56:31 backups-3-hel pbm-agent[24213]: 2025-02-11t15:56:31.000+0000 i [restore/2025-02-11t15:55:41.424113159z] copy <2025-02-07t06:00:02z/fun0/_mdb_catalog.wt.s2.0-106496> to </data-mongodb/mongodb/_mdb_catalog.wt>
.......
feb 11 19:46:52 backups-3-hel pbm-agent[24213]: 2025-02-11t19:46:52.000+0000 i [restore/2025-02-11t15:55:41.424113159z] copy <2025-02-08t06:00:05z/fun0/collection-638--9215508469722123109.wt.s2.1325400064-16777216> to </data-mongodb/mongodb/collection-638--9215508469722123109.wt>
feb 11 19:46:52 backups-3-hel pbm-agent[24213]: 2025-02-11t19:46:52.000+0000 i [restore/2025-02-11t15:55:41.424113159z] copy <2025-02-08t06:00:05z/fun0/collection-65--9215508469722123109.wt.s2.0-4096> to </data-mongodb/mongodb/collection-65--9215508469722123109.wt>
feb 12 10:13:09 backups-3-hel systemd[1]: stopping pbm-agent...
feb 12 10:13:10 backups-3-hel systemd[1]: pbm-agent.service: deactivated successfully.
feb 12 10:13:10 backups-3-hel systemd[1]: stopped pbm-agent.
feb 12 10:13:10 backups-3-hel systemd[1]: pbm-agent.service: consumed 1h 52min 22.806s cpu time.
feb 12 10:15:35 backups-3-hel systemd[1]: started pbm-agent.
cannot attach full file of logs, so sending only main lines to understand assignment
Feb 11 15:55:41 backups-3-hel pbm-agent[24213]: 2025-02-11T15:55:41.000+0000 I got epoch {1739289181 26}
Feb 11 15:55:41 backups-3-hel pbm-agent[24213]: 2025-02-11T15:55:41.000+0000 I [restore/2025-02-11T15:55:41.424113159Z] oplog slicer disabled
Feb 11 15:55:41 backups-3-hel pbm-agent[24213]: 2025-02-11T15:55:41.000+0000 I [restore/2025-02-11T15:55:41.424113159Z] backup: 2025-02-10T06:00:05Z
Feb 11 15:55:41 backups-3-hel pbm-agent[24213]: 2025-02-11T15:55:41.000+0000 I [restore/2025-02-11T15:55:41.424113159Z] recovery started
Feb 11 15:55:41 backups-3-hel pbm-agent[24213]: 2025-02-11T15:55:41.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] port: 27640
Feb 11 15:55:41 backups-3-hel pbm-agent[24213]: 2025-02-11T15:55:41.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] uploading ".pbm.restore/2025-02-11T15:55:41.424113159Z/rs.rs-for-restore/node.37.27.225.21:27017.hb" [size hint: 10 (10.00B); part size: 10485760 (10.00MB)]
Feb 11 15:55:41 backups-3-hel pbm-agent[24213]: 2025-02-11T15:55:41.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] uploading ".pbm.restore/2025-02-11T15:55:41.424113159Z/rs.rs-for-restore/rs.hb" [size hint: 10 (10.00B); part size: 10485760 (10.00MB)]
Feb 11 15:55:42 backups-3-hel pbm-agent[24213]: 2025-02-11T15:55:42.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] uploading ".pbm.restore/2025-02-11T15:55:41.424113159Z/cluster.hb" [size hint: 10 (10.00B); part size: 10485760 (10.00MB)]
Feb 11 15:55:42 backups-3-hel pbm-agent[24213]: 2025-02-11T15:55:42.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] mongod binary: mongod, version: v6.0.9-7
Feb 11 15:55:42 backups-3-hel pbm-agent[24213]: 2025-02-11T15:55:42.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] get src 2025-02-09T06:00:06Z
Feb 11 15:55:42 backups-3-hel pbm-agent[24213]: 2025-02-11T15:55:42.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] get src 2025-02-08T06:00:05Z
Feb 11 15:55:42 backups-3-hel pbm-agent[24213]: 2025-02-11T15:55:42.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] get src 2025-02-07T06:00:02Z
Feb 11 15:55:42 backups-3-hel pbm-agent[24213]: 2025-02-11T15:55:42.000+0000 I [restore/2025-02-11T15:55:41.424113159Z] moving to state starting
Feb 11 15:55:42 backups-3-hel pbm-agent[24213]: 2025-02-11T15:55:42.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] uploading ".pbm.restore/2025-02-11T15:55:41.424113159Z/rs.rs-for-restore/node.37.27.225.21:27017.starting" [size hint: 10 (10.00B); part size: 10485760 (10.00MB)]
Feb 11 15:55:42 backups-3-hel pbm-agent[24213]: 2025-02-11T15:55:42.000+0000 I [restore/2025-02-11T15:55:41.424113159Z] waiting for `starting` status in rs map[.pbm.restore/2025-02-11T15:55:41.424113159Z/rs.rs-for-restore/node.37.27.225.21:27017:{}]
Feb 11 15:55:47 backups-3-hel pbm-agent[24213]: 2025-02-11T15:55:47.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] uploading ".pbm.restore/2025-02-11T15:55:41.424113159Z/rs.rs-for-restore/rs.starting" [size hint: 10 (10.00B); part size: 10485760 (10.00MB)]
Feb 11 15:55:47 backups-3-hel pbm-agent[24213]: 2025-02-11T15:55:47.000+0000 I [restore/2025-02-11T15:55:41.424113159Z] waiting for shards map[.pbm.restore/2025-02-11T15:55:41.424113159Z/rs.rs-for-restore/rs:{}]
Feb 11 15:55:52 backups-3-hel pbm-agent[24213]: 2025-02-11T15:55:52.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] uploading ".pbm.restore/2025-02-11T15:55:41.424113159Z/cluster.starting" [size hint: 10 (10.00B); part size: 10485760 (10.00MB)]
Feb 11 15:55:53 backups-3-hel pbm-agent[24213]: 2025-02-11T15:55:53.000+0000 I [restore/2025-02-11T15:55:41.424113159Z] waiting for cluster
Feb 11 15:55:58 backups-3-hel pbm-agent[24213]: 2025-02-11T15:55:58.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] converged to state starting
Feb 11 15:55:58 backups-3-hel pbm-agent[24213]: 2025-02-11T15:55:58.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] starting
Feb 11 15:55:58 backups-3-hel pbm-agent[24213]: 2025-02-11T15:55:58.000+0000 I [restore/2025-02-11T15:55:41.424113159Z] moving to state running
Feb 11 15:55:58 backups-3-hel pbm-agent[24213]: 2025-02-11T15:55:58.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] uploading ".pbm.restore/2025-02-11T15:55:41.424113159Z/rs.rs-for-restore/node.37.27.225.21:27017.running" [size hint: 10 (10.00B); part size: 10485760 (10.00MB)]
Feb 11 15:55:58 backups-3-hel pbm-agent[24213]: 2025-02-11T15:55:58.000+0000 I [restore/2025-02-11T15:55:41.424113159Z] waiting for `running` status in rs map[.pbm.restore/2025-02-11T15:55:41.424113159Z/rs.rs-for-restore/node.37.27.225.21:27017:{}]
Feb 11 15:56:03 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:03.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] uploading ".pbm.restore/2025-02-11T15:55:41.424113159Z/rs.rs-for-restore/rs.running" [size hint: 10 (10.00B); part size: 10485760 (10.00MB)]
Feb 11 15:56:03 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:03.000+0000 I [restore/2025-02-11T15:55:41.424113159Z] waiting for shards map[.pbm.restore/2025-02-11T15:55:41.424113159Z/rs.rs-for-restore/rs:{}]
Feb 11 15:56:08 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:08.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] uploading ".pbm.restore/2025-02-11T15:55:41.424113159Z/cluster.running" [size hint: 10 (10.00B); part size: 10485760 (10.00MB)]
Feb 11 15:56:08 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:08.000+0000 I [restore/2025-02-11T15:55:41.424113159Z] waiting for cluster
Feb 11 15:56:13 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:13.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] converged to state running
Feb 11 15:56:13 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:13.000+0000 I [restore/2025-02-11T15:55:41.424113159Z] send to stopAgent chan
Feb 11 15:56:14 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:14.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] stop agents heartbeats
Feb 11 15:56:14 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:14.000+0000 I [restore/2025-02-11T15:55:41.424113159Z] stopping mongod and flushing old data
Feb 11 15:56:14 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:14.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] shutdown server
Feb 11 15:56:15 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:15.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] waiting for the node to shutdown
Feb 11 15:56:16 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:16.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] uploading ".pbm.restore/2025-02-11T15:55:41.424113159Z/rs.rs-for-restore/rs.down" [size hint: 10 (10.00B); part size: 10485760 (10.00MB)]
Feb 11 15:56:16 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:16.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] remove old data
Feb 11 15:56:16 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:16.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] remove /data-mongodb/mongodb/mongod.lock
Feb 11 15:56:16 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:16.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] remove /data-mongodb/mongodb/journal
Feb 11 15:56:16 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:16.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] remove /data-mongodb/mongodb/WiredTiger.lock
Feb 11 15:56:16 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:16.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] remove /data-mongodb/mongodb/WiredTiger
Feb 11 15:56:16 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:16.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] remove /data-mongodb/mongodb/WiredTiger.wt
Feb 11 15:56:16 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:16.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] remove /data-mongodb/mongodb/WiredTiger.turtle
Feb 11 15:56:16 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:16.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] remove /data-mongodb/mongodb/WiredTigerHS.wt
Feb 11 15:56:16 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:16.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] remove /data-mongodb/mongodb/sizeStorer.wt
Feb 11 15:56:16 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:16.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] remove /data-mongodb/mongodb/_mdb_catalog.wt
Feb 11 15:56:16 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:16.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] remove /data-mongodb/mongodb/storage.bson
Feb 11 15:56:16 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:16.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] remove /data-mongodb/mongodb/collection-0-1741871530267799973.wt
Feb 11 15:56:16 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:16.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] remove /data-mongodb/mongodb/index-1-1741871530267799973.wt
Feb 11 15:56:16 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:16.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] remove /data-mongodb/mongodb/collection-2-1741871530267799973.wt
Feb 11 15:56:16 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:16.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] remove /data-mongodb/mongodb/index-3-1741871530267799973.wt
Feb 11 15:56:16 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:16.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] remove /data-mongodb/mongodb/collection-4-1741871530267799973.wt
Feb 11 15:56:16 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:16.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] remove /data-mongodb/mongodb/index-5-1741871530267799973.wt
Feb 11 15:56:16 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:16.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] remove /data-mongodb/mongodb/collection-6-1741871530267799973.wt
Feb 11 15:56:16 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:16.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] remove /data-mongodb/mongodb/index-7-1741871530267799973.wt
Feb 11 15:56:16 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:16.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] remove /data-mongodb/mongodb/collection-8-1741871530267799973.wt
Feb 11 15:56:16 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:16.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] remove /data-mongodb/mongodb/index-9-1741871530267799973.wt
Feb 11 15:56:16 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:16.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] remove /data-mongodb/mongodb/collection-10-1741871530267799973.wt
Feb 11 15:56:16 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:16.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] remove /data-mongodb/mongodb/index-11-1741871530267799973.wt
Feb 11 15:56:16 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:16.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] remove /data-mongodb/mongodb/diagnostic.data
Feb 11 15:56:16 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:16.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] remove /data-mongodb/mongodb/collection-0--7608642112471611654.wt
Feb 11 15:56:16 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:16.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] remove /data-mongodb/mongodb/index-1--7608642112471611654.wt
Feb 11 15:56:16 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:16.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] remove /data-mongodb/mongodb/collection-2--7608642112471611654.wt
Feb 11 15:56:16 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:16.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] remove /data-mongodb/mongodb/collection-3--7608642112471611654.wt
Feb 11 15:56:16 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:16.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] remove /data-mongodb/mongodb/index-4--7608642112471611654.wt
Feb 11 15:56:16 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:16.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] remove /data-mongodb/mongodb/collection-5--7608642112471611654.wt
Feb 11 15:56:16 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:16.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] remove /data-mongodb/mongodb/index-6--7608642112471611654.wt
Feb 11 15:56:16 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:16.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] remove /data-mongodb/mongodb/collection-7--7608642112471611654.wt
Feb 11 15:56:16 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:16.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] remove /data-mongodb/mongodb/index-8--7608642112471611654.wt
Feb 11 15:56:16 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:16.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] remove /data-mongodb/mongodb/index-9--7608642112471611654.wt
Feb 11 15:56:16 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:16.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] remove /data-mongodb/mongodb/collection-10--7608642112471611654.wt
Feb 11 15:56:16 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:16.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] remove /data-mongodb/mongodb/index-11--7608642112471611654.wt
Feb 11 15:56:16 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:16.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] remove /data-mongodb/mongodb/collection-12--7608642112471611654.wt
Feb 11 15:56:16 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:16.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] remove /data-mongodb/mongodb/index-13--7608642112471611654.wt
Feb 11 15:56:16 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:16.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] remove /data-mongodb/mongodb/collection-14--7608642112471611654.wt
Feb 11 15:56:16 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:16.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] remove /data-mongodb/mongodb/collection-15--7608642112471611654.wt
Feb 11 15:56:16 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:16.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] remove /data-mongodb/mongodb/index-16--7608642112471611654.wt
Feb 11 15:56:16 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:16.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] remove /data-mongodb/mongodb/collection-17--7608642112471611654.wt
Feb 11 15:56:16 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:16.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] remove /data-mongodb/mongodb/collection-18--7608642112471611654.wt
Feb 11 15:56:16 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:16.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] remove /data-mongodb/mongodb/index-19--7608642112471611654.wt
Feb 11 15:56:16 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:16.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] remove /data-mongodb/mongodb/index-20--7608642112471611654.wt
Feb 11 15:56:16 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:16.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] remove /data-mongodb/mongodb/index-21--7608642112471611654.wt
Feb 11 15:56:16 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:16.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] remove /data-mongodb/mongodb/index-22--7608642112471611654.wt
Feb 11 15:56:16 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:16.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] remove /data-mongodb/mongodb/collection-23--7608642112471611654.wt
Feb 11 15:56:16 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:16.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] remove /data-mongodb/mongodb/index-24--7608642112471611654.wt
Feb 11 15:56:16 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:16.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] remove /data-mongodb/mongodb/index-25--7608642112471611654.wt
Feb 11 15:56:16 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:16.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] remove /data-mongodb/mongodb/collection-26--7608642112471611654.wt
Feb 11 15:56:16 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:16.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] remove /data-mongodb/mongodb/index-27--7608642112471611654.wt
Feb 11 15:56:16 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:16.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] remove /data-mongodb/mongodb/index-28--7608642112471611654.wt
Feb 11 15:56:16 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:16.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] remove /data-mongodb/mongodb/collection-29--7608642112471611654.wt
Feb 11 15:56:16 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:16.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] remove /data-mongodb/mongodb/index-30--7608642112471611654.wt
Feb 11 15:56:16 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:16.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] remove /data-mongodb/mongodb/index-31--7608642112471611654.wt
Feb 11 15:56:16 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:16.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] remove /data-mongodb/mongodb/collection-32--7608642112471611654.wt
Feb 11 15:56:16 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:16.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] remove /data-mongodb/mongodb/index-33--7608642112471611654.wt
Feb 11 15:56:16 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:16.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] remove /data-mongodb/mongodb/collection-34--7608642112471611654.wt
Feb 11 15:56:16 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:16.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] remove /data-mongodb/mongodb/index-35--7608642112471611654.wt
Feb 11 15:56:16 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:16.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] remove /data-mongodb/mongodb/collection-36--7608642112471611654.wt
Feb 11 15:56:16 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:16.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] remove /data-mongodb/mongodb/index-37--7608642112471611654.wt
Feb 11 15:56:16 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:16.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] remove /data-mongodb/mongodb/index-38--7608642112471611654.wt
Feb 11 15:56:16 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:16.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] remove /data-mongodb/mongodb/collection-39--7608642112471611654.wt
Feb 11 15:56:16 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:16.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] remove /data-mongodb/mongodb/index-40--7608642112471611654.wt
Feb 11 15:56:16 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:16.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] remove /data-mongodb/mongodb/index-41--7608642112471611654.wt
Feb 11 15:56:16 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:16.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] remove /data-mongodb/mongodb/collection-42--7608642112471611654.wt
Feb 11 15:56:16 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:16.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] remove /data-mongodb/mongodb/index-43--7608642112471611654.wt
Feb 11 15:56:16 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:16.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] remove /data-mongodb/mongodb/index-44--7608642112471611654.wt
Feb 11 15:56:16 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:16.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] remove /data-mongodb/mongodb/collection-45--7608642112471611654.wt
Feb 11 15:56:16 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:16.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] remove /data-mongodb/mongodb/index-46--7608642112471611654.wt
Feb 11 15:56:16 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:16.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] remove /data-mongodb/mongodb/index-47--7608642112471611654.wt
Feb 11 15:56:16 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:16.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] remove /data-mongodb/mongodb/index-48--7608642112471611654.wt
Feb 11 15:56:16 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:16.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] remove /data-mongodb/mongodb/collection-49--7608642112471611654.wt
Feb 11 15:56:16 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:16.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] remove /data-mongodb/mongodb/index-50--7608642112471611654.wt
Feb 11 15:56:16 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:16.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] remove /data-mongodb/mongodb/collection-51--7608642112471611654.wt
Feb 11 15:56:16 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:16.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] remove /data-mongodb/mongodb/index-52--7608642112471611654.wt
Feb 11 15:56:16 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:16.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] remove /data-mongodb/mongodb/index-53--7608642112471611654.wt
Feb 11 15:56:16 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:16.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] remove /data-mongodb/mongodb/index-54--7608642112471611654.wt
Feb 11 15:56:16 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:16.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] remove /data-mongodb/mongodb/collection-55--7608642112471611654.wt
Feb 11 15:56:16 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:16.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] remove /data-mongodb/mongodb/index-56--7608642112471611654.wt
Feb 11 15:56:16 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:16.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] remove /data-mongodb/mongodb/collection-57--7608642112471611654.wt
Feb 11 15:56:16 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:16.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] remove /data-mongodb/mongodb/index-58--7608642112471611654.wt
Feb 11 15:56:16 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:16.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] remove /data-mongodb/mongodb/index-60--7608642112471611654.wt
Feb 11 15:56:16 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:16.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] remove /data-mongodb/mongodb/collection-59--7608642112471611654.wt
Feb 11 15:56:16 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:16.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] remove /data-mongodb/mongodb/collection-61--7608642112471611654.wt
Feb 11 15:56:16 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:16.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] remove /data-mongodb/mongodb/index-62--7608642112471611654.wt
Feb 11 15:56:16 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:16.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] remove /data-mongodb/mongodb/index-63--7608642112471611654.wt
Feb 11 15:56:16 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:16.000+0000 I [restore/2025-02-11T15:55:41.424113159Z] copying backup data
Feb 11 15:56:16 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:16.000+0000 D [restore/2025-02-11T15:55:41.424113159Z] download max buf 17179869184 (arena 536870912, span 33554432, concurrency 32)
Feb 11 15:56:16 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:16.000+0000 I [restore/2025-02-11T15:55:41.424113159Z] copy <2025-02-07T06:00:02Z/fun0/WiredTigerHS.wt.s2.0-2150625280> to </data-mongodb/mongodb/WiredTigerHS.wt>
Feb 11 15:56:31 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:31.000+0000 I [restore/2025-02-11T15:55:41.424113159Z] copy <2025-02-07T06:00:02Z/fun0/_mdb_catalog.wt.s2.0-106496> to </data-mongodb/mongodb/_mdb_catalog.wt>
Feb 11 15:56:31 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:31.000+0000 I [restore/2025-02-11T15:55:41.424113159Z] copy <2025-02-07T06:00:02Z/fun0/collection-0--4517434000883119559.wt.s2.0-1695744> to </data-mongodb/mongodb/collection-0--4517434000883119559.wt>
Feb 11 15:56:32 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:32.000+0000 I [restore/2025-02-11T15:55:41.424113159Z] copy <2025-02-07T06:00:02Z/fun0/collection-0--7863920685824830437.wt.s2.0-20480> to </data-mongodb/mongodb/collection-0--7863920685824830437.wt>
Feb 11 15:56:33 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:33.000+0000 I [restore/2025-02-11T15:55:41.424113159Z] copy <2025-02-07T06:00:02Z/fun0/collection-0--9215508469722123109.wt.s2.0-45056> to </data-mongodb/mongodb/collection-0--9215508469722123109.wt>
Feb 11 15:56:33 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:33.000+0000 I [restore/2025-02-11T15:55:41.424113159Z] copy <2025-02-07T06:00:02Z/fun0/collection-0-1692246051658870989.wt.s2.0-36864> to </data-mongodb/mongodb/collection-0-1692246051658870989.wt>
Feb 11 15:56:33 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:33.000+0000 I [restore/2025-02-11T15:55:41.424113159Z] copy <2025-02-07T06:00:02Z/fun0/collection-0-8859552334592281951.wt.s2.0-32768> to </data-mongodb/mongodb/collection-0-8859552334592281951.wt>
Feb 11 15:56:33 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:33.000+0000 I [restore/2025-02-11T15:55:41.424113159Z] copy <2025-02-07T06:00:02Z/fun0/collection-10--9215508469722123109.wt.s2.0-32768> to </data-mongodb/mongodb/collection-10--9215508469722123109.wt>
Feb 11 15:56:33 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:33.000+0000 I [restore/2025-02-11T15:55:41.424113159Z] copy <2025-02-07T06:00:02Z/fun0/collection-101--9215508469722123109.wt.s2.0-36864> to </data-mongodb/mongodb/collection-101--9215508469722123109.wt>
Feb 11 15:56:33 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:33.000+0000 I [restore/2025-02-11T15:55:41.424113159Z] copy <2025-02-07T06:00:02Z/fun0/collection-107--9215508469722123109.wt.s2.0-32768> to </data-mongodb/mongodb/collection-107--9215508469722123109.wt>
Feb 11 15:56:33 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:33.000+0000 I [restore/2025-02-11T15:55:41.424113159Z] copy <2025-02-07T06:00:02Z/fun0/collection-112--9215508469722123109.wt.s2.0-36864> to </data-mongodb/mongodb/collection-112--9215508469722123109.wt>
Feb 11 15:56:34 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:34.000+0000 I [restore/2025-02-11T15:55:41.424113159Z] copy <2025-02-07T06:00:02Z/fun0/collection-117--9215508469722123109.wt.s2.0-4096> to </data-mongodb/mongodb/collection-117--9215508469722123109.wt>
Feb 11 15:56:34 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:34.000+0000 I [restore/2025-02-11T15:55:41.424113159Z] copy <2025-02-07T06:00:02Z/fun0/collection-12--9215508469722123109.wt.s2.0-36864> to </data-mongodb/mongodb/collection-12--9215508469722123109.wt>
Feb 11 15:56:34 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:34.000+0000 I [restore/2025-02-11T15:55:41.424113159Z] copy <2025-02-07T06:00:02Z/fun0/collection-123--9215508469722123109.wt.s2.0-4096> to </data-mongodb/mongodb/collection-123--9215508469722123109.wt>
Feb 11 15:56:34 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:34.000+0000 I [restore/2025-02-11T15:55:41.424113159Z] copy <2025-02-07T06:00:02Z/fun0/collection-129--9215508469722123109.wt.s2.0-2592768> to </data-mongodb/mongodb/collection-129--9215508469722123109.wt>
Feb 11 15:56:34 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:34.000+0000 I [restore/2025-02-11T15:55:41.424113159Z] copy <2025-02-07T06:00:02Z/fun0/collection-137--9215508469722123109.wt.s2.0-53248> to </data-mongodb/mongodb/collection-137--9215508469722123109.wt>
Feb 11 15:56:34 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:34.000+0000 I [restore/2025-02-11T15:55:41.424113159Z] copy <2025-02-07T06:00:02Z/fun0/collection-14--7356338056570130922.wt.s2.0-1252773888> to </data-mongodb/mongodb/collection-14--7356338056570130922.wt>
Feb 11 15:56:44 backups-3-hel pbm-agent[24213]: 2025-02-11T15:56:44.000+0000 I [restore/2025-02-11T15:55:41.424113159Z] copy <2025-02-07T06:00:02Z/fun0/collection-145--9215508469722123109.wt.s2.0-4096> to </data-mongodb/mongodb/collection-145--9215508469722123109.wt>
...
Feb 11 19:46:18 backups-3-hel pbm-agent[24213]: 2025-02-11T19:46:18.000+0000 I [restore/2025-02-11T15:55:41.424113159Z] copy <2025-02-08T06:00:05Z/fun0/collection-624--9215508469722123109.wt.s2.778630594560-117440512> to </data-mongodb/mongodb/collection-624--9215508469722123109.wt>
Feb 11 19:46:19 backups-3-hel pbm-agent[24213]: 2025-02-11T19:46:19.000+0000 I [restore/2025-02-11T15:55:41.424113159Z] copy <2025-02-08T06:00:05Z/fun0/collection-624--9215508469722123109.wt.s2.778764812288-117440512> to </data-mongodb/mongodb/collection-624--9215508469722123109.wt>
Feb 11 19:46:20 backups-3-hel pbm-agent[24213]: 2025-02-11T19:46:20.000+0000 I [restore/2025-02-11T15:55:41.424113159Z] copy <2025-02-08T06:00:05Z/fun0/collection-624--9215508469722123109.wt.s2.778899030016-352321536> to </data-mongodb/mongodb/collection-624--9215508469722123109.wt>
Feb 11 19:46:23 backups-3-hel pbm-agent[24213]: 2025-02-11T19:46:23.000+0000 I [restore/2025-02-11T15:55:41.424113159Z] copy <2025-02-08T06:00:05Z/fun0/collection-624--9215508469722123109.wt.s2.779268128768-4211081216> to </data-mongodb/mongodb/collection-624--9215508469722123109.wt>
feb 11 19:46:52 backups-3-hel pbm-agent[24213]: 2025-02-11t19:46:52.000+0000 i [restore/2025-02-11t15:55:41.424113159z] copy <2025-02-08t06:00:05z/fun0/collection-638--9215508469722123109.wt.s2.855638016-33554432> to </data-mongodb/mongodb/collection-638--9215508469722123109.wt>
feb 11 19:46:52 backups-3-hel pbm-agent[24213]: 2025-02-11t19:46:52.000+0000 i [restore/2025-02-11t15:55:41.424113159z] copy <2025-02-08t06:00:05z/fun0/collection-638--9215508469722123109.wt.s2.1325400064-16777216> to </data-mongodb/mongodb/collection-638--9215508469722123109.wt>
feb 11 19:46:52 backups-3-hel pbm-agent[24213]: 2025-02-11t19:46:52.000+0000 i [restore/2025-02-11t15:55:41.424113159z] copy <2025-02-08t06:00:05z/fun0/collection-65--9215508469722123109.wt.s2.0-4096> to </data-mongodb/mongodb/collection-65--9215508469722123109.wt>
feb 12 10:13:09 backups-3-hel systemd[1]: stopping pbm-agent...
feb 12 10:13:10 backups-3-hel systemd[1]: pbm-agent.service: deactivated successfully.
feb 12 10:13:10 backups-3-hel systemd[1]: stopped pbm-agent.
feb 12 10:13:10 backups-3-hel systemd[1]: pbm-agent.service: consumed 1h 52min 22.806s cpu time.
feb 12 10:15:35 backups-3-hel systemd[1]: started pbm-agent.
manual restart in the end to try another restore
Hi, the forum is meant for general questions. Since this looks like it could be a bug please open a ticket at Jira - Percona JIRA
I’m not really good at opening bugs, but Jira.
Maybe we can extract any additional information from internal pbm tables from mongod?
