MongoDB Incremental Backup are same size as basebackup | PBM

MongoDB Percona Backup for MongoDB
1

I’m using Percona Backup to backup my self hosted mongodb replica set, I have a cronjob that runs the command

$ pbm backup --type incremental

to create an incremental backup on top of the base of incremental backup. But the size of incremental backups are almost same to that of the base backup. What my concern mainly is currently we don’t have much changing data in our database so it shouldnt be backup up new extra gb each hour, when we dont have that much data in our db.

I’m assuming this is a problem? Let me know how I may fix this? Is it because of bad configuration?

image
image895×613 13.3 KB

2

@baniya.sabinn

Initially we saw the base backup with size [2.04GB] then for 1st increment it was [1012MB] and for 2nd increment [1.72GB] and so on. Looking over the recent logs it went to near ~2GB which is the size of Increment base backup.

By any chance did you observe any recent data activity( Insertion/Deletion) etc on this environment ?

Can you please run the below command for a base and few incremental backup samples for a review ?

pbm describe-backup **2024-01-31T13:10:25Z**

Note:- Please change the backup file accordingly.

Also please gather the below details in order to understand your PBM environment and configurations/logs etc.

shell> pbm logs --event=backup

shell> pbm status
shell> pbm config

shell> pbm version

Moreover, can you please provide a few samples from storage statistics in a span of 1 hour interval ?

Mongo> db.runCommand( {dbStats: 1 } )

Exactly, what version of MongoDB you are using ?

3

Hey @anil.joshi . Thanks for your reply. I have listed the answers to your questions below, please find them.

By any chance did you observe any recent data activity( Insertion/Deletion) etc on this environment ?

No

Can you please run the below command for a base and few incremental backup samples for a review ?
pbm describe-backup **2024-01-31T13:10:25Z**

- The first *incremental base* backup (the one with oldest date)

~$ pbm describe-backup 2024-01-13T11:55:18Z
name: "2024-01-13T11:55:18Z"
opid: 65a27a266c02585734025eba
type: incremental
last_write_time: "2024-01-13T11:55:26Z"
last_transition_time: "2024-01-13T12:03:21Z"
mongodb_version: 6.0.11-8
fcv: "6.0"
pbm_version: 2.3.0
status: done
size_h: 2.0 GiB
replsets:
- name: rs0
  status: done
  node: bcbc0fb81f44******
  last_write_time: "2024-01-13T11:55:26Z"
  last_transition_time: "2024-01-13T12:03:17Z"
  security: {}

- The second *incremental base* backup (the second oldest one)

~$ pbm describe-backup 2024-01-13T12:47:38Z
name: "2024-01-13T12:47:38Z"
opid: 65a2866bec2df04c81e3a341
type: incremental
last_write_time: "2024-01-13T12:47:46Z"
last_transition_time: "2024-01-13T12:57:53Z"
mongodb_version: 6.0.11-8
fcv: "6.0"
pbm_version: 2.3.0
status: done
size_h: 2.0 GiB
replsets:
- name: rs0
  status: done
  node: bcbc0fb81f44******
  last_write_time: "2024-01-13T12:47:46Z"
  last_transition_time: "2024-01-13T12:57:50Z"
  security: {}

- The third *incremental* backup (the third oldest one)

~$ pbm describe-backup 2024-01-13T13:15:16Z
name: "2024-01-13T13:15:16Z"
opid: 65a28ce738f6063b69d69325
type: incremental
last_write_time: "2024-01-13T13:15:28Z"
last_transition_time: "2024-01-13T15:16:31Z"
mongodb_version: 6.0.11-8
fcv: "6.0"
pbm_version: 2.3.0
status: done
size_h: 1012.0 MiB
replsets:
- name: rs0
  status: done
  node: bcbc0fb81f44******
  last_write_time: "2024-01-13T13:15:28Z"
  last_transition_time: "2024-01-13T15:16:27Z"
  security: {}

- The fourth *incremental* backup (the fourth oldest one )

~$ pbm describe-backup 2024-01-13T16:15:17Z
name: "2024-01-13T16:15:17Z"
opid: 65a2b71858472658cc7e9a1a
type: incremental
last_write_time: "2024-01-13T16:15:29Z"
last_transition_time: "2024-01-13T16:32:06Z"
mongodb_version: 6.0.11-8
fcv: "6.0"
pbm_version: 2.3.0
status: done
size_h: 1.7 GiB
replsets:
- name: rs0
  status: done
  node: bcbc0fb81f44******
  last_write_time: "2024-01-13T16:15:29Z"
  last_transition_time: "2024-01-13T16:32:02Z"
  security: {}

- The latest *incremental base* backup

~$ pbm describe-backup 2024-01-29T03:21:46Z
name: "2024-01-29T03:21:46Z"
opid: 65b719caab9f24e5ff89e8d3
type: incremental
last_write_time: "2024-01-29T03:21:54Z"
last_transition_time: "2024-01-29T03:29:05Z"
mongodb_version: 6.0.11-8
fcv: "6.0"
pbm_version: 2.3.0
status: done
size_h: 2.1 GiB
replsets:
- name: rs0
  status: done
  node: bcbc0fb81f44******
  last_write_time: "2024-01-29T03:21:54Z"
  last_transition_time: "2024-01-29T03:29:01Z"
  security: {}

- The latest *incremental* backup (the third one with latest date)

~$ pbm describe-backup 2024-01-22T02:30:02Z
name: "2024-01-22T02:30:02Z"
opid: 65add32abe493d5c27ecbd9d
type: incremental
last_write_time: "2024-01-22T02:30:27Z"
last_transition_time: "2024-01-22T02:35:55Z"
mongodb_version: 6.0.11-8
fcv: "6.0"
pbm_version: 2.3.0
status: done
size_h: 2.0 GiB
replsets:
- name: rs0
  status: done
  node: bcbc0fb81f44******
  last_write_time: "2024-01-22T02:30:27Z"
  last_transition_time: "2024-01-22T02:35:51Z"
  security: {}

shell> pbm logs --event=backup

These are the logs of that time when those backups were made, currently Im getting backups failing error. But I think the more related one here will be the date in which backups were made.

2024-01-13T11:35:11Z I [rs0/107f5715fce10a76e7*****] [backup/2024-01-13T11:30:02Z] uploading journals done

2024-01-13T11:35:15Z I [rs0/107f5715fce10a76e7*****] [backup/2024-01-13T11:30:02Z] backup finished

2024-01-13T11:55:23Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-13T11:55:18Z] backup started

2024-01-13T11:55:33Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-13T11:55:18Z] uploading data

2024-01-13T12:03:14Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-13T11:55:18Z] uploading data done

2024-01-13T12:03:14Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-13T11:55:18Z] uploading journals

2024-01-13T12:03:15Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-13T11:55:18Z] uploading journals done

2024-01-13T12:03:25Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-13T11:55:18Z] backup finished

2024-01-13T12:46:43Z I [rs0/107f5715fce10a76e7*****] [backup/2024-01-13T12:30:02Z] backup started

2024-01-13T12:46:44Z I [rs0/107f5715fce10a76e7*****] [backup/2024-01-13T12:30:02Z] mark RS as error `can't find incremental backup history. Previous backup was made on another node. You can make a new base incremental backup to start a new history.`: <nil>

2024-01-13T12:46:45Z I [rs0/107f5715fce10a76e7*****] [backup/2024-01-13T12:30:02Z] mark backup as error `can't find incremental backup history. Previous backup was made on another node. You can make a new base incremental backup to start a new history.`: <nil>

2024-01-13T12:46:45Z E [rs0/107f5715fce10a76e7*****] [backup/2024-01-13T12:30:02Z] backup: can't find incremental backup history. Previous backup was made on another node. You can make a new base incremental backup to start a new history.

2024-01-13T12:47:43Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-13T12:47:38Z] backup started

2024-01-13T12:47:53Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-13T12:47:38Z] uploading data

2024-01-13T12:57:47Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-13T12:47:38Z] uploading data done

2024-01-13T12:57:47Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-13T12:47:38Z] uploading journals

2024-01-13T12:57:48Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-13T12:47:38Z] uploading journals done

2024-01-13T12:57:56Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-13T12:47:38Z] backup finished

2024-01-13T13:15:24Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-13T13:15:16Z] backup started

2024-01-13T13:15:35Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-13T13:15:16Z] uploading data

2024-01-13T15:16:22Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-13T13:15:16Z] uploading data done

2024-01-13T15:16:23Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-13T13:15:16Z] uploading journals

2024-01-13T15:16:26Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-13T13:15:16Z] uploading journals done

2024-01-13T15:16:35Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-13T13:15:16Z] backup finished

2024-01-13T16:15:25Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-13T16:15:17Z] backup started

2024-01-13T16:15:36Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-13T16:15:17Z] uploading data

2024-01-13T16:31:57Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-13T16:15:17Z] uploading data done

2024-01-13T16:31:57Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-13T16:15:17Z] uploading journals

2024-01-13T16:32:00Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-13T16:15:17Z] uploading journals done

2024-01-13T16:32:09Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-13T16:15:17Z] backup finished

2024-01-13T17:15:24Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-13T17:15:17Z] backup started

2024-01-13T17:15:35Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-13T17:15:17Z] uploading data

2024-01-13T17:19:44Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-13T17:15:17Z] uploading data done

2024-01-13T17:19:44Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-13T17:15:17Z] uploading journals

2024-01-13T17:19:47Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-13T17:15:17Z] uploading journals done

2024-01-13T17:19:55Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-13T17:15:17Z] backup finished

2024-01-13T19:30:15Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-13T19:30:02Z] backup started

2024-01-13T19:30:26Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-13T19:30:02Z] uploading data

2024-01-13T19:34:27Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-13T19:30:02Z] uploading data done

2024-01-13T19:34:27Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-13T19:30:02Z] uploading journals

2024-01-13T19:34:30Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-13T19:30:02Z] uploading journals done

2024-01-13T19:34:38Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-13T19:30:02Z] backup finished

2024-01-13T20:30:15Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-13T20:30:02Z] backup started

2024-01-13T20:30:26Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-13T20:30:02Z] uploading data

2024-01-13T20:33:56Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-13T20:30:02Z] uploading data done

2024-01-13T20:33:56Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-13T20:30:02Z] uploading journals

2024-01-13T20:33:59Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-13T20:30:02Z] uploading journals done

2024-01-13T20:34:07Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-13T20:30:02Z] backup finished

2024-01-13T21:30:15Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-13T21:30:02Z] backup started

2024-01-13T21:30:26Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-13T21:30:02Z] uploading data

2024-01-13T21:32:12Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-13T21:30:02Z] mark RS as error `upload file `/var/lib/mongodb/collection-6-3776611771898684903.wt`: upload file: write data: upload to S3: MultipartUpload: upload multipart failed

upload id: 2~0AlrW2AEOUGzy1whk_uYvnVmuXJS2JI

caused by: SignatureDoesNotMatch:

status code: 403, request id: tx000000d720b5cbec7edad-0065a3015b-a2c45-default, host id: .`: <nil>

2024-01-13T21:32:12Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-13T21:30:02Z] mark backup as error `upload file `/var/lib/mongodb/collection-6-3776611771898684903.wt`: upload file: write data: upload to S3: MultipartUpload: upload multipart failed

upload id: 2~0AlrW2AEOUGzy1whk_uYvnVmuXJS2JI

caused by: SignatureDoesNotMatch:

status code: 403, request id: tx000000d720b5cbec7edad-0065a3015b-a2c45-default, host id: .`: <nil>

2024-01-13T21:32:13Z E [rs0/bcbc0fb81f44872576*****] [backup/2024-01-13T21:30:02Z] backup: upload file `/var/lib/mongodb/collection-6-3776611771898684903.wt`: upload file: write data: upload to S3: MultipartUpload: upload multipart failed

upload id: 2~0AlrW2AEOUGzy1whk_uYvnVmuXJS2JI

caused by: SignatureDoesNotMatch:

status code: 403, request id: tx000000d720b5cbec7edad-0065a3015b-a2c45-default, host id: .

2024-01-13T22:30:16Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-13T22:30:03Z] backup started

2024-01-13T22:30:26Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-13T22:30:03Z] uploading data

2024-01-13T22:33:51Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-13T22:30:03Z] uploading data done

2024-01-13T22:33:51Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-13T22:30:03Z] uploading journals

2024-01-13T22:33:54Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-13T22:30:03Z] uploading journals done

2024-01-13T22:34:02Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-13T22:30:03Z] backup finished

2024-01-13T23:30:17Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-13T23:30:02Z] backup started

2024-01-13T23:30:28Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-13T23:30:02Z] uploading data

2024-01-13T23:34:13Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-13T23:30:02Z] uploading data done

2024-01-13T23:34:13Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-13T23:30:02Z] uploading journals

2024-01-13T23:34:16Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-13T23:30:02Z] uploading journals done

2024-01-13T23:34:24Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-13T23:30:02Z] backup finished

2024-01-14T00:30:16Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-14T00:30:02Z] backup started

2024-01-14T00:30:26Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-14T00:30:02Z] uploading data

2024-01-14T00:33:36Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-14T00:30:02Z] uploading data done

2024-01-14T00:33:36Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-14T00:30:02Z] uploading journals

2024-01-14T00:33:39Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-14T00:30:02Z] uploading journals done

2024-01-14T00:33:47Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-14T00:30:02Z] backup finished

2024-01-14T01:30:17Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-14T01:30:02Z] backup started

2024-01-14T01:30:28Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-14T01:30:02Z] uploading data

2024-01-14T01:34:15Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-14T01:30:02Z] uploading data done

2024-01-14T01:34:15Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-14T01:30:02Z] uploading journals

2024-01-14T01:34:18Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-14T01:30:02Z] uploading journals done

2024-01-14T01:34:27Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-14T01:30:02Z] backup finished

2024-01-14T02:30:24Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-14T02:30:02Z] backup started

2024-01-14T02:30:36Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-14T02:30:02Z] uploading data

2024-01-14T02:34:14Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-14T02:30:02Z] uploading data done

2024-01-14T02:34:14Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-14T02:30:02Z] uploading journals

2024-01-14T02:34:17Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-14T02:30:02Z] uploading journals done

2024-01-14T02:34:26Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-14T02:30:02Z] backup finished

2024-01-14T04:30:18Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-14T04:30:02Z] backup started

2024-01-14T04:30:29Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-14T04:30:02Z] uploading data

2024-01-14T04:34:09Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-14T04:30:02Z] uploading data done

2024-01-14T04:34:09Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-14T04:30:02Z] uploading journals

2024-01-14T04:34:12Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-14T04:30:02Z] uploading journals done

2024-01-14T04:34:21Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-14T04:30:02Z] backup finished

2024-01-14T05:30:19Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-14T05:30:02Z] backup started

2024-01-14T05:30:30Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-14T05:30:02Z] uploading data

2024-01-14T05:34:18Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-14T05:30:02Z] uploading data done

2024-01-14T05:34:18Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-14T05:30:02Z] uploading journals

2024-01-14T05:34:20Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-14T05:30:02Z] uploading journals done

2024-01-14T05:34:28Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-14T05:30:02Z] backup finished

2024-01-14T06:30:20Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-14T06:30:02Z] backup started

2024-01-14T06:30:31Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-14T06:30:02Z] uploading data

2024-01-14T06:33:58Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-14T06:30:02Z] uploading data done

2024-01-14T06:33:58Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-14T06:30:02Z] uploading journals

2024-01-14T06:34:00Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-14T06:30:02Z] uploading journals done

2024-01-14T06:34:09Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-14T06:30:02Z] backup finished

2024-01-14T07:30:20Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-14T07:30:02Z] backup started

2024-01-14T07:30:31Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-14T07:30:02Z] uploading data

2024-01-14T07:33:53Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-14T07:30:02Z] uploading data done

2024-01-14T07:33:53Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-14T07:30:02Z] uploading journals

2024-01-14T07:33:56Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-14T07:30:02Z] uploading journals done

2024-01-14T07:34:04Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-14T07:30:02Z] backup finished

2024-01-14T08:30:22Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-14T08:30:02Z] backup started

2024-01-14T08:30:32Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-14T08:30:02Z] uploading data

2024-01-14T08:33:54Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-14T08:30:02Z] uploading data done

2024-01-14T08:33:54Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-14T08:30:02Z] uploading journals

2024-01-14T08:33:57Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-14T08:30:02Z] uploading journals done

2024-01-14T08:34:05Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-14T08:30:02Z] backup finished

2024-01-14T09:30:36Z I [rs0/107f5715fce10a76e7*****] [backup/2024-01-14T09:30:02Z] backup started

2024-01-14T09:30:38Z I [rs0/107f5715fce10a76e7*****] [backup/2024-01-14T09:30:02Z] mark RS as error `can't find incremental backup history. Previous backup was made on another node. You can make a new base incremental backup to start a new history.`: <nil>

2024-01-14T09:30:38Z I [rs0/107f5715fce10a76e7*****] [backup/2024-01-14T09:30:02Z] mark backup as error `can't find incremental backup history. Previous backup was made on another node. You can make a new base incremental backup to start a new history.`: <nil>

2024-01-14T09:30:38Z E [rs0/107f5715fce10a76e7*****] [backup/2024-01-14T09:30:02Z] backup: can't find incremental backup history. Previous backup was made on another node. You can make a new base incremental backup to start a new history.

2024-01-14T10:30:22Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-14T10:30:02Z] backup started

2024-01-14T10:30:32Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-14T10:30:02Z] uploading data

2024-01-14T10:34:13Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-14T10:30:02Z] uploading data done

2024-01-14T10:34:14Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-14T10:30:02Z] uploading journals

2024-01-14T10:34:16Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-14T10:30:02Z] uploading journals done

2024-01-14T10:34:24Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-14T10:30:02Z] backup finished

2024-01-14T11:30:37Z I [rs0/107f5715fce10a76e7*****] [backup/2024-01-14T11:30:02Z] backup started

2024-01-14T11:30:39Z I [rs0/107f5715fce10a76e7*****] [backup/2024-01-14T11:30:02Z] mark RS as error `can't find incremental backup history. Previous backup was made on another node. You can make a new base incremental backup to start a new history.`: <nil>

2024-01-14T11:30:40Z I [rs0/107f5715fce10a76e7*****] [backup/2024-01-14T11:30:02Z] mark backup as error `can't find incremental backup history. Previous backup was made on another node. You can make a new base incremental backup to start a new history.`: <nil>

2024-01-14T11:30:40Z E [rs0/107f5715fce10a76e7*****] [backup/2024-01-14T11:30:02Z] backup: can't find incremental backup history. Previous backup was made on another node. You can make a new base incremental backup to start a new history.

2024-01-14T12:30:23Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-14T12:30:02Z] backup started

2024-01-14T12:30:34Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-14T12:30:02Z] uploading data

2024-01-14T12:34:48Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-14T12:30:02Z] uploading data done

2024-01-14T12:34:48Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-14T12:30:02Z] uploading journals

2024-01-14T12:34:50Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-14T12:30:02Z] uploading journals done

2024-01-14T12:34:58Z I [rs0/bcbc0fb81f44872576*****] [backup/2024-01-14T12:30:02Z] backup finished

2024-01-14T14:30:40Z I [rs0/107f5715fce10a76e7*****] [backup/2024-01-14T14:30:03Z] backup started

2024-01-14T14:30:42Z I [rs0/107f5715fce10a76e7*****] [backup/2024-01-14T14:30:03Z] mark RS as error `can't find incremental backup history. Previous backup was made on another node. You can make a new base incremental backup to start a new history.`: <nil>

2024-01-14T14:30:43Z I [rs0/107f5715fce10a76e7*****] [backup/2024-01-14T14:30:03Z] mark backup as error `can't find incremental backup history. Previous backup was made on another node. You can make a new base incremental backup to start a new history.`: <nil>

2024-01-14T14:30:43Z E [rs0/107f5715fce10a76e7*****] [backup/2024-01-14T14:30:03Z] backup: can't find incremental backup history. Previous backup was made on another node. You can make a new base incremental backup to start a new history.

shell> pbm status

~$ pbm status
Cluster:
========
rs0:
  - rs0/107f5715fce10a76e73e23******** [P]: pbm-agent v2.3.0 OK
  - rs0/bcbc0fb81f4487257602d6******** [S]: pbm-agent v2.3.0 OK
  - rs0/733ce2d8189c7d62b9059e******** [S]: pbm-agent v2.3.0 OK


PITR incremental backup:
========================
Status [OFF]

Currently running:
==================
Snapshot backup "2024-01-31T10:51:29Z", started at 2024-01-31T10:51:30Z. Status: snapshot backup. [op id: 65ba2631c311c1d6ac574d2b]

Backups:
========
S3 us-east-1 s3://si*********
  Snapshots:
    2024-01-31T10:51:29Z 0.00B <incremental> [running: running / 2024-01-31T10:51:39Z]
    2024-01-31T10:30:02Z 0.00B <incremental> [ERROR: can't find incremental backup history. Previous backup was made on another node. You can make a new base incremental backup to start a new history.] [2024-01-31T10:30:41Z]
    2024-01-29T03:21:46Z 2.10GB <incremental, base> [restore_to_time: 2024-01-29T03:21:54Z]
    2024-01-26T01:08:15Z 2.02GB <incremental, base> [restore_to_time: 2024-01-26T01:08:22Z]
    2024-01-23T15:40:41Z 2.04GB <incremental, base> [restore_to_time: 2024-01-23T15:40:47Z]
    2024-01-22T02:30:02Z 2.05GB <incremental> [restore_to_time: 2024-01-22T02:30:27Z]
    2024-01-18T03:30:03Z 2.05GB <incremental> [restore_to_time: 2024-01-18T03:30:27Z]
    2024-01-16T03:30:02Z 2.06GB <incremental> [restore_to_time: 2024-01-16T03:30:27Z]
    2024-01-14T12:30:02Z 1.45GB <incremental> [restore_to_time: 2024-01-14T12:30:27Z]
    2024-01-14T10:30:02Z 1.29GB <incremental> [restore_to_time: 2024-01-14T10:30:25Z]
    2024-01-14T08:30:02Z 1.02GB <incremental> [restore_to_time: 2024-01-14T08:30:25Z]
    2024-01-14T07:30:02Z 1.11GB <incremental> [restore_to_time: 2024-01-14T07:30:24Z]
    2024-01-14T06:30:02Z 1.19GB <incremental> [restore_to_time: 2024-01-14T06:30:24Z]
    2024-01-14T05:30:02Z 1.21GB <incremental> [restore_to_time: 2024-01-14T05:30:23Z]
    2024-01-14T04:30:02Z 1.09GB <incremental> [restore_to_time: 2024-01-14T04:30:22Z]
    2024-01-14T02:30:02Z 1.08GB <incremental> [restore_to_time: 2024-01-14T02:30:28Z]
    2024-01-14T01:30:02Z 1.10GB <incremental> [restore_to_time: 2024-01-14T01:30:21Z]
    2024-01-14T00:30:02Z 1.04GB <incremental> [restore_to_time: 2024-01-14T00:30:19Z]
    2024-01-13T23:30:02Z 1.19GB <incremental> [restore_to_time: 2024-01-13T23:30:20Z]
    2024-01-13T22:30:03Z 1.15GB <incremental> [restore_to_time: 2024-01-13T22:30:19Z]
    2024-01-13T20:30:02Z 1.21GB <incremental> [restore_to_time: 2024-01-13T20:30:19Z]
    2024-01-13T19:30:02Z 1.59GB <incremental> [restore_to_time: 2024-01-13T19:30:19Z]
    2024-01-13T17:15:17Z 1.29GB <incremental> [restore_to_time: 2024-01-13T17:15:28Z]
    2024-01-13T16:15:17Z 1.72GB <incremental> [restore_to_time: 2024-01-13T16:15:29Z]
    2024-01-13T13:15:16Z 1012.00MB <incremental> [restore_to_time: 2024-01-13T13:15:28Z]
    2024-01-13T12:47:38Z 2.04GB <incremental, base> [restore_to_time: 2024-01-13T12:47:46Z]
    2024-01-13T11:55:18Z 2.01GB <incremental, base> [restore_to_time: 2024-01-13T11:55:26Z]

shell> pbm config

~$ pbm config
pitr:
  enabled: false
  oplogSpanMin: 0
  compression: s2
storage:
  type: s3
  s3:
    provider: aws
    region: us-east-1
    endpointUrl: s****
    forcePathStyle: true
    bucket: db-backups
    credentials:
      access-key-id: '***'
      secret-access-key: '***'
    maxUploadParts: 10000
    storageClass: STANDARD
    insecureSkipTLSVerify: false
backup:
  compression: s2

shell> pbm version

~$ pbm version
Version:   2.3.0
Platform:  linux/amd64
GitCommit: 3b1c2e263901cf041c6b83547f6f28ac2879911f
GitBranch: release-2.3.0
BuildTime: 2023-09-20_14:44_UTC
GoVersion: go1.19

Mongo> db.runCommand( {dbStats: 1 } )

On admin db
rs0 [direct: primary] admin> db.runCommand( {dbStats: 1 } )
{
  db: 'admin',
  collections: 15,
  views: 0,
  objects: 222630,
  avgObjSize: 252.57645420653103,
  dataSize: 56231096,
  storageSize: 12144640,
  indexes: 23,
  indexSize: 5394432,
  totalSize: 17539072,
  scaleFactor: 1,
  fsUsedSize: 46486044672,
  fsTotalSize: 419491782656,
  ok: 1,
  '$clusterTime': {
    clusterTime: Timestamp({ t: 1706712232, i: 6 }),
    signature: {
      hash: Binary.createFromBase64("AAAAAAAAAAAAAAAAAAAAAAAAAAA=", 0),
      keyId: Long("0")
    }
  },
  operationTime: Timestamp({ t: 1706712232, i: 6 })
}

On production db (Our main db for production)

rs0 [direct: primary] admin> use production
switched to db production
rs0 [direct: primary] production> db.runCommand( {dbStats: 1 } )
{
  db: 'production',
  collections: 26,
  views: 0,
  objects: 629174,
  avgObjSize: 492.8580503962338,
  dataSize: 310093471,
  storageSize: 141238272,
  indexes: 38,
  indexSize: 20508672,
  totalSize: 161746944,
  scaleFactor: 1,
  fsUsedSize: 46486130688,
  fsTotalSize: 419491782656,
  ok: 1,
  '$clusterTime': {
    clusterTime: Timestamp({ t: 1706712285, i: 3 }),
    signature: {
      hash: Binary.createFromBase64("AAAAAAAAAAAAAAAAAAAAAAAAAAA=", 0),
      keyId: Long("0")
    }
  },
  operationTime: Timestamp({ t: 1706712285, i: 3 })
}

Exactly, what version of MongoDB you are using ?

Using MongoDB:          6.0.11-8
4

@anil.joshi mentioning just so it doesn’t get out of sight!

5

@baniya.sabinn

Thanks for sharing the details. The information mostly looks fine and no such suspicious activity.

Although, I see only one sample of db.runCommand( {dbStats: 1 } ). It Could be better to have a few more samples while the backup is ongoing to confirm the changes. Along with that you can also share the mongo error log file [mongod.log ] and the output of db.currentOP() to check for the running processes/queries if any.

s0 [direct: primary] admin> use production
switched to db production
rs0 [direct: primary] production> db.runCommand( {dbStats: 1 } )
{
  db: 'production',
  collections: 26,
  views: 0,
  objects: 629174,
  avgObjSize: 492.8580503962338,
  dataSize: 310093471,
  storageSize: 141238272,
  indexes: 38,
  indexSize: 20508672,
  totalSize: 161746944,
  scaleFactor: 1,
  fsUsedSize: 46486130688

Going forward I have tried to test the behaviour at my environment as well however no such anomalies detected. Please find the below outputs taken for both PBM (2.3.0 OR 2.3.1) versions.

PBM(2.3.0)

Snapshots:
    2024-02-20T10:36:13Z 2.53MB <incremental> [restore_to_time: 2024-02-20T10:36:15Z]
    **2024-02-20T10:35:55Z 5.76MB <incremental, base> [restore_to_time: 2024-02-20T10:35:57Z]**
    2024-02-20T10:35:18Z 2.51MB <incremental> [restore_to_time: 2024-02-20T10:35:19Z]
    2024-02-20T10:34:46Z 70.16KB <incremental> [restore_to_time: 2024-02-20T10:34:48Z]
    2024-02-20T10:34:14Z 2.49MB <incremental> [restore_to_time: 2024-02-20T10:34:17Z]
    **2024-02-20T10:33:48Z 5.77MB <incremental, base> [restore_to_time: 2024-02-20T10:33:50Z]**

PBM(2.3.1)

Snapshots:
    2024-02-20T10:21:04Z 158.00KB <incremental> [running: running / 2024-02-20T10:21:07Z]
    **2024-02-20T10:20:38Z 5.66MB <incremental, base> [running: running / 2024-02-20T10:20:42Z]**
    2024-02-20T10:20:04Z 104.49KB <incremental> [running: running / 2024-02-20T10:20:08Z]
    2024-02-20T10:19:41Z 77.38KB <incremental> [restore_to_time: 2024-02-20T10:19:42Z]
    2024-02-20T10:19:30Z 62.63KB <incremental> [restore_to_time: 2024-02-20T10:19:32Z]
    2024-02-20T10:19:17Z 2.30MB <incremental> [restore_to_time: 2024-02-20T10:19:19Z]
    **2024-02-20T10:18:57Z 5.53MB <incremental, base> [restore_to_time: 2024-02-20T10:18:59Z]**

Did you recently upgraded the PBM version ?

6

@baniya.sabinn

Meanwhile, you are checking the previous details. I want to mention a couple of things which you can try in your environment in order to access the Write changes/behaviour.

Inside MongoDB you can query the oplog collection directly to know about the write operation events.

use local
db.oplog.rs.find()

Also you can enable the PITR in your environment to have oplog slices details about the frequent changes.

pbm config --set pitr.enabled=true

configuration file option:

pitr:
  enabled: <boolean>
  oplogSpanMin: <float64>
  compression: <string>
  compressionLevel: <int>

By default the oplog span is ~10 mins however you can change the the setting[oplogSpanMin] as per your need.

There might be some other overheads (wiredtiger WAL (write-ahead logs)) OR internal ping/heartbeats which contributes to change in Incremental size backup to some extent.

Let us know how this goes!

Regards,
Anil