PBM backup never finishing

MongoDB Percona Backup for MongoDB
1

Getting below errors.

$ pbm logs
2022-10-07T19:52:03Z I [sh_34/db31212.or1.omniture.com:27018] [backup/2022-10-07T18:12:39Z] mongodump finished, waiting for the oplog
2022-10-07T19:52:04Z I [sh_34/db31212.or1.omniture.com:27018] [backup/2022-10-07T18:12:39Z] dropping tmp collections
2022-10-07T19:52:04Z I [sh_34/db31212.or1.omniture.com:27018] [backup/2022-10-07T18:12:39Z] mark RS as error `waiting for dump done: backup stuck, last beat ts: 1665166375`: <nil>
2022-10-07T19:52:04Z E [sh_34/db31212.or1.omniture.com:27018] [backup/2022-10-07T18:12:39Z] backup: waiting for dump done: backup stuck, last beat ts: 1665166375
2022-10-07T19:52:18Z I [sh_0/db40619.or1.omniture.com:27018] [backup/2022-10-07T18:12:39Z] mongodump finished, waiting for the oplog
2022-10-07T19:52:19Z I [sh_0/db40619.or1.omniture.com:27018] [backup/2022-10-07T18:12:39Z] dropping tmp collections
2022-10-07T19:52:19Z I [sh_0/db40619.or1.omniture.com:27018] [backup/2022-10-07T18:12:39Z] mark RS as error `waiting for dump done: backup stuck, last beat ts: 1665166375`: <nil>
2022-10-07T19:52:19Z E [sh_0/db40619.or1.omniture.com:27018] [backup/2022-10-07T18:12:39Z] backup: waiting for dump done: backup stuck, last beat ts: 1665166375
2022-10-07T19:53:31Z I [sh_11/db40630.or1.omniture.com:27018] [backup/2022-10-07T18:12:39Z] mongodump finished, waiting for the oplog
2022-10-07T19:53:32Z I [sh_11/db40630.or1.omniture.com:27018] [backup/2022-10-07T18:12:39Z] dropping tmp collections
2022-10-07T19:53:32Z I [sh_11/db40630.or1.omniture.com:27018] [backup/2022-10-07T18:12:39Z] mark RS as error `waiting for dump done: backup stuck, last beat ts: 1665166375`: <nil>
2022-10-07T19:53:32Z E [sh_11/db40630.or1.omniture.com:27018] [backup/2022-10-07T18:12:39Z] backup: waiting for dump done: backup stuck, last beat ts: 1665166375
2022-10-07T19:54:49Z I [sh_28/db31268.or1.omniture.com:27018] [backup/2022-10-07T18:12:39Z] mongodump finished, waiting for the oplog
2022-10-07T19:54:50Z I [sh_28/db31268.or1.omniture.com:27018] [backup/2022-10-07T18:12:39Z] dropping tmp collections
2022-10-07T19:54:50Z I [sh_28/db31268.or1.omniture.com:27018] [backup/2022-10-07T18:12:39Z] mark RS as error `waiting for dump done: backup stuck, last beat ts: 1665166375`: <nil>
2022-10-07T19:54:50Z E [sh_28/db31268.or1.omniture.com:27018] [backup/2022-10-07T18:12:39Z] backup: waiting for dump done: backup stuck, last beat ts: 1665166375
2022-10-07T20:37:17Z I [sh_21/db31258.or1.omniture.com:27018] [backup/2022-10-07T18:12:39Z] mongodump finished, waiting for the oplog
2022-10-07T20:37:18Z I [sh_21/db31258.or1.omniture.com:27018] [backup/2022-10-07T18:12:39Z] dropping tmp collections
2022-10-07T20:37:18Z I [sh_21/db31258.or1.omniture.com:27018] [backup/2022-10-07T18:12:39Z] mark RS as error `waiting for dump done: backup stuck, last beat ts: 1665166375`: <nil>
2022-10-07T20:37:18Z E [sh_21/db31258.or1.omniture.com:27018] [backup/2022-10-07T18:12:39Z] backup: waiting for dump done: backup stuck, last beat ts: 1665166375

Currently running:

Snapshot backup “2022-10-07T18:12:39Z”, started at 2022-10-07T18:12:40Z. Status: error. [op id: 63406c17ba6952b20bb77581]

1 Like
2 
2022-12-08T16:40:29Z D [cfg/mongo-cluster-cfg-1.mongo-cluster-cfg.platform-percona-mongo-cluster.svc.cluster.local:27017] [backup/2022-12-08T16:40:29Z/6392137da296cf278aecab95] init backup meta
2022-12-08T16:40:29Z D [cfg/mongo-cluster-cfg-1.mongo-cluster-cfg.platform-percona-mongo-cluster.svc.cluster.local:27017] [backup/2022-12-08T16:40:29Z/6392137da296cf278aecab95] nomination list for rs0: [[mongo-cluster-rs0-1.mongo-cluster-rs0.platf
orm-percona-mongo-cluster.svc.cluster.local:27017 mongo-cluster-rs0-2.mongo-cluster-rs0.platform-percona-mongo-cluster.svc.cluster.local:27017] [mongo-cluster-rs0-0.mongo-cluster-rs0.platform-percona-mongo-cluster.svc.cluster.local:27017]]
2022-12-08T16:40:29Z D [cfg/mongo-cluster-cfg-1.mongo-cluster-cfg.platform-percona-mongo-cluster.svc.cluster.local:27017] [backup/2022-12-08T16:40:29Z/6392137da296cf278aecab95] nomination list for cfg: [[mongo-cluster-cfg-1.mongo-cluster-cfg.platf
orm-percona-mongo-cluster.svc.cluster.local:27017 mongo-cluster-cfg-0.mongo-cluster-cfg.platform-percona-mongo-cluster.svc.cluster.local:27017 mongo-cluster-cfg-2.mongo-cluster-cfg.platform-percona-mongo-cluster.svc.cluster.local:27017]]
2022-12-08T16:40:29Z D [cfg/mongo-cluster-cfg-1.mongo-cluster-cfg.platform-percona-mongo-cluster.svc.cluster.local:27017] [backup/2022-12-08T16:40:29Z/6392137da296cf278aecab95] nomination list for rs1: [[mongo-cluster-rs1-1.mongo-cluster-rs1.platf
orm-percona-mongo-cluster.svc.cluster.local:27017 mongo-cluster-rs1-0.mongo-cluster-rs1.platform-percona-mongo-cluster.svc.cluster.local:27017] [mongo-cluster-rs1-2.mongo-cluster-rs1.platform-percona-mongo-cluster.svc.cluster.local:27017]]
2022-12-08T16:40:29Z D [cfg/mongo-cluster-cfg-1.mongo-cluster-cfg.platform-percona-mongo-cluster.svc.cluster.local:27017] [backup/2022-12-08T16:40:29Z/6392137da296cf278aecab95] nomination list for rs2: [[mongo-cluster-rs2-1.mongo-cluster-rs2.platf
orm-percona-mongo-cluster.svc.cluster.local:27017 mongo-cluster-rs2-2.mongo-cluster-rs2.platform-percona-mongo-cluster.svc.cluster.local:27017] [mongo-cluster-rs2-0.mongo-cluster-rs2.platform-percona-mongo-cluster.svc.cluster.local:27017]]
2022-12-08T16:40:29Z D [cfg/mongo-cluster-cfg-1.mongo-cluster-cfg.platform-percona-mongo-cluster.svc.cluster.local:27017] [backup/2022-12-08T16:40:29Z/6392137da296cf278aecab95] nomination rs0, set candidates [mongo-cluster-rs0-1.mongo-cluster-rs0.
platform-percona-mongo-cluster.svc.cluster.local:27017 mongo-cluster-rs0-2.mongo-cluster-rs0.platform-percona-mongo-cluster.svc.cluster.local:27017]
2022-12-08T16:40:29Z D [cfg/mongo-cluster-cfg-1.mongo-cluster-cfg.platform-percona-mongo-cluster.svc.cluster.local:27017] [backup/2022-12-08T16:40:29Z/6392137da296cf278aecab95] nomination cfg, set candidates [mongo-cluster-cfg-1.mongo-cluster-cfg.
platform-percona-mongo-cluster.svc.cluster.local:27017 mongo-cluster-cfg-0.mongo-cluster-cfg.platform-percona-mongo-cluster.svc.cluster.local:27017 mongo-cluster-cfg-2.mongo-cluster-cfg.platform-percona-mongo-cluster.svc.cluster.local:27017]
2022-12-08T16:40:29Z D [cfg/mongo-cluster-cfg-1.mongo-cluster-cfg.platform-percona-mongo-cluster.svc.cluster.local:27017] [backup/2022-12-08T16:40:29Z/6392137da296cf278aecab95] nomination rs1, set candidates [mongo-cluster-rs1-1.mongo-cluster-rs1.
platform-percona-mongo-cluster.svc.cluster.local:27017 mongo-cluster-rs1-0.mongo-cluster-rs1.platform-percona-mongo-cluster.svc.cluster.local:27017]
2022-12-08T16:40:29Z D [cfg/mongo-cluster-cfg-1.mongo-cluster-cfg.platform-percona-mongo-cluster.svc.cluster.local:27017] [backup/2022-12-08T16:40:29Z/6392137da296cf278aecab95] nomination rs2, set candidates [mongo-cluster-rs2-1.mongo-cluster-rs2.
platform-percona-mongo-cluster.svc.cluster.local:27017 mongo-cluster-rs2-2.mongo-cluster-rs2.platform-percona-mongo-cluster.svc.cluster.local:27017]
2022-12-08T16:40:30Z I [rs0/mongo-cluster-rs0-2.mongo-cluster-rs0.platform-percona-mongo-cluster.svc.cluster.local:27017] [backup/2022-12-08T16:40:29Z/6392137da296cf278aecab95] backup started
2022-12-08T16:40:30Z I [rs1/mongo-cluster-rs1-0.mongo-cluster-rs1.platform-percona-mongo-cluster.svc.cluster.local:27017] [backup/2022-12-08T16:40:29Z/6392137da296cf278aecab95] backup started
2022-12-08T16:40:30Z I [cfg/mongo-cluster-cfg-2.mongo-cluster-cfg.platform-percona-mongo-cluster.svc.cluster.local:27017] [backup/2022-12-08T16:40:29Z/6392137da296cf278aecab95] backup started
2022-12-08T16:40:30Z D [cfg/mongo-cluster-cfg-2.mongo-cluster-cfg.platform-percona-mongo-cluster.svc.cluster.local:27017] [backup/2022-12-08T16:40:29Z/6392137da296cf278aecab95] waiting for balancer off
2022-12-08T16:40:30Z D [rs1/mongo-cluster-rs1-2.mongo-cluster-rs1.platform-percona-mongo-cluster.svc.cluster.local:27017] [backup/2022-12-08T16:40:29Z/6392137da296cf278aecab95] skip after nomination, probably started by another node
2022-12-08T16:40:30Z D [rs0/mongo-cluster-rs0-0.mongo-cluster-rs0.platform-percona-mongo-cluster.svc.cluster.local:27017] [backup/2022-12-08T16:40:29Z/6392137da296cf278aecab95] skip after nomination, probably started by another node
2022-12-08T16:40:30Z D [cfg/mongo-cluster-cfg-1.mongo-cluster-cfg.platform-percona-mongo-cluster.svc.cluster.local:27017] [backup/2022-12-08T16:40:29Z/6392137da296cf278aecab95] skip after nomination, probably started by another node
2022-12-08T16:40:30Z I [rs2/mongo-cluster-rs2-2.mongo-cluster-rs2.platform-percona-mongo-cluster.svc.cluster.local:27017] [backup/2022-12-08T16:40:29Z/6392137da296cf278aecab95] backup started
2022-12-08T16:40:30Z D [cfg/mongo-cluster-cfg-0.mongo-cluster-cfg.platform-percona-mongo-cluster.svc.cluster.local:27017] [backup/2022-12-08T16:40:29Z/6392137da296cf278aecab95] skip after nomination, probably started by another node
2022-12-08T16:40:30Z D [cfg/mongo-cluster-cfg-2.mongo-cluster-cfg.platform-percona-mongo-cluster.svc.cluster.local:27017] [backup/2022-12-08T16:40:29Z/6392137da296cf278aecab95] balancer status: off
2022-12-08T16:40:30Z D [rs2/mongo-cluster-rs2-1.mongo-cluster-rs2.platform-percona-mongo-cluster.svc.cluster.local:27017] [backup/2022-12-08T16:40:29Z/6392137da296cf278aecab95] skip after nomination, probably started by another node
2022-12-08T16:40:31Z D [rs2/mongo-cluster-rs2-0.mongo-cluster-rs2.platform-percona-mongo-cluster.svc.cluster.local:27017] [backup/2022-12-08T16:40:29Z/6392137da296cf278aecab95] skip after nomination, probably started by another node
2022-12-08T16:40:31Z D [rs1/mongo-cluster-rs1-1.mongo-cluster-rs1.platform-percona-mongo-cluster.svc.cluster.local:27017] [backup/2022-12-08T16:40:29Z/6392137da296cf278aecab95] skip after nomination, probably started by another node
2022-12-08T16:40:31Z D [rs0/mongo-cluster-rs0-1.mongo-cluster-rs0.platform-percona-mongo-cluster.svc.cluster.local:27017] [backup/2022-12-08T16:40:29Z/6392137da296cf278aecab95] skip after nomination, probably started by another node
2022-12-08T16:40:35Z D [cfg/mongo-cluster-cfg-1.mongo-cluster-cfg.platform-percona-mongo-cluster.svc.cluster.local:27017] [backup/2022-12-08T16:40:29Z/6392137da296cf278aecab95] bcp nomination: rs0 won by mongo-cluster-rs0-2.mongo-cluster-rs0.platf
orm-percona-mongo-cluster.svc.cluster.local:27017
2022-12-08T16:40:35Z D [cfg/mongo-cluster-cfg-1.mongo-cluster-cfg.platform-percona-mongo-cluster.svc.cluster.local:27017] [backup/2022-12-08T16:40:29Z/6392137da296cf278aecab95] bcp nomination: rs1 won by mongo-cluster-rs1-0.mongo-cluster-rs1.platf
orm-percona-mongo-cluster.svc.cluster.local:27017
2022-12-08T16:40:35Z D [cfg/mongo-cluster-cfg-1.mongo-cluster-cfg.platform-percona-mongo-cluster.svc.cluster.local:27017] [backup/2022-12-08T16:40:29Z/6392137da296cf278aecab95] bcp nomination: rs2 won by mongo-cluster-rs2-2.mongo-cluster-rs2.platf
orm-percona-mongo-cluster.svc.cluster.local:27017
2022-12-08T16:40:37Z D [rs0/mongo-cluster-rs0-2.mongo-cluster-rs0.platform-percona-mongo-cluster.svc.cluster.local:27017] [backup/2022-12-08T16:40:29Z/6392137da296cf278aecab95] wait for tmp users {1670517637 1677}
2022-12-08T16:40:37Z D [rs2/mongo-cluster-rs2-2.mongo-cluster-rs2.platform-percona-mongo-cluster.svc.cluster.local:27017] [backup/2022-12-08T16:40:29Z/6392137da296cf278aecab95] wait for tmp users {1670517637 3436}
2022-12-08T16:40:37Z D [rs1/mongo-cluster-rs1-0.mongo-cluster-rs1.platform-percona-mongo-cluster.svc.cluster.local:27017] [backup/2022-12-08T16:40:29Z/6392137da296cf278aecab95] wait for tmp users {1670517637 3085}
2022-12-08T16:40:38Z D [cfg/mongo-cluster-cfg-2.mongo-cluster-cfg.platform-percona-mongo-cluster.svc.cluster.local:27017] [backup/2022-12-08T16:40:29Z/6392137da296cf278aecab95] wait for tmp users {1670517638 8}
2022-12-08T16:40:44Z I [cfg/mongo-cluster-cfg-2.mongo-cluster-cfg.platform-percona-mongo-cluster.svc.cluster.local:27017] [backup/2022-12-08T16:40:29Z/6392137da296cf278aecab95] mongodump finished, waiting for the oplog
2022-12-09T00:46:56Z I [rs0/mongo-cluster-rs0-2.mongo-cluster-rs0.platform-percona-mongo-cluster.svc.cluster.local:27017] [backup/2022-12-08T16:40:29Z/6392137da296cf278aecab95] mongodump finished, waiting for the oplog
2022-12-09T00:51:30Z I [rs1/mongo-cluster-rs1-0.mongo-cluster-rs1.platform-percona-mongo-cluster.svc.cluster.local:27017] [backup/2022-12-08T16:40:29Z/6392137da296cf278aecab95] mongodump finished, waiting for the oplog
2022-12-09T01:04:46Z I [rs1/mongo-cluster-rs1-0.mongo-cluster-rs1.platform-percona-mongo-cluster.svc.cluster.local:27017] [backup/2022-12-08T16:40:29Z/6392137da296cf278aecab95] dropping tmp collections
2022-12-09T01:04:46Z I [rs1/mongo-cluster-rs1-0.mongo-cluster-rs1.platform-percona-mongo-cluster.svc.cluster.local:27017] [backup/2022-12-08T16:40:29Z/6392137da296cf278aecab95] mark RS as error `waiting for dump done: backup stuck, last beat ts: 1
670547855`: <nil>
2022-12-09T01:04:46Z D [rs1/mongo-cluster-rs1-0.mongo-cluster-rs1.platform-percona-mongo-cluster.svc.cluster.local:27017] [backup/2022-12-08T16:40:29Z/6392137da296cf278aecab95] set balancer on
2022-12-09T01:04:46Z E [rs1/mongo-cluster-rs1-0.mongo-cluster-rs1.platform-percona-mongo-cluster.svc.cluster.local:27017] [backup/2022-12-08T16:40:29Z/6392137da296cf278aecab95] backup: waiting for dump done: backup stuck, last beat ts: 1670547855
2022-12-09T01:04:46Z D [rs1/mongo-cluster-rs1-0.mongo-cluster-rs1.platform-percona-mongo-cluster.svc.cluster.local:27017] [backup/2022-12-08T16:40:29Z/6392137da296cf278aecab95] releasing lock
2022-12-09T01:04:46Z I [rs0/mongo-cluster-rs0-2.mongo-cluster-rs0.platform-percona-mongo-cluster.svc.cluster.local:27017] [backup/2022-12-08T16:40:29Z/6392137da296cf278aecab95] dropping tmp collections
2022-12-09T01:04:46Z I [rs0/mongo-cluster-rs0-2.mongo-cluster-rs0.platform-percona-mongo-cluster.svc.cluster.local:27017] [backup/2022-12-08T16:40:29Z/6392137da296cf278aecab95] mark RS as error `waiting for dump done: backup stuck, last beat ts: 1
670547855`: <nil>
2022-12-09T01:04:46Z D [rs0/mongo-cluster-rs0-2.mongo-cluster-rs0.platform-percona-mongo-cluster.svc.cluster.local:27017] [backup/2022-12-08T16:40:29Z/6392137da296cf278aecab95] set balancer on
2022-12-09T01:04:46Z E [rs0/mongo-cluster-rs0-2.mongo-cluster-rs0.platform-percona-mongo-cluster.svc.cluster.local:27017] [backup/2022-12-08T16:40:29Z/6392137da296cf278aecab95] backup: waiting for dump done: backup stuck, last beat ts: 1670547855
2022-12-09T01:04:46Z D [rs0/mongo-cluster-rs0-2.mongo-cluster-rs0.platform-percona-mongo-cluster.svc.cluster.local:27017] [backup/2022-12-08T16:40:29Z/6392137da296cf278aecab95] releasing lock

$ get perconaservermongodbbackups.psmdb.percona.com
NAME                                      CLUSTER         STORAGE     DESTINATION            STATUS   COMPLETED   AGE
cron-mongo-cluster-20221208164008-x9bw4   mongo-cluster   s3   2022-12-08T16:40:29Z   error                9h
1 Like