"deleting outdated backup job" spam in the operator log on operator 1.20.0

Description:

I’ve setup 2 clusters in the same namespace and faced with issue that opertaor is spamming with messages like:

11daf0d8-15a5-48cc-891c-47c4c938d268", "job": "replicaset-test-cluster-daily-physical-backup"}
2025-05-22T20:27:55.840Z	INFO	deleting outdated backup job	{"controller": "psmdb-controller", "controllerGroup": "psmdb.percona.com", "controllerKind": "PerconaServerMongoDB", "PerconaServerMongoDB": {"name":"replicaset-test-cluster","namespace":"percona-mongodb"}, "namespace": "percona-mongodb", "name": "replicaset-test-cluster", "reconcileID": "1c4ef043-1bc8-486b-aec1-0cc1a30789d8", "job": "replicaset-test2-cluster-daily-physical-backup"}
2025-05-22T20:27:59.908Z	INFO	deleting outdated backup job	{"controller": "psmdb-controller", "controllerGroup": "psmdb.percona.com", "controllerKind": "PerconaServerMongoDB", "PerconaServerMongoDB": {"name":"replicaset-test2-cluster","namespace":"percona-mongodb"}, "namespace": "percona-mongodb", "name": "replicaset-test2-cluster", "reconcileID": "d7f8da95-4a60-42eb-a75b-3ddc7399ff6e", "job": "replicaset-test-cluster-daily-physical-backup"}
2025-05-22T20:28:01.900Z	INFO	deleting outdated backup job	{"controller": "psmdb-controller", "controllerGroup": "psmdb.percona.com", "controllerKind": "PerconaServerMongoDB", "PerconaServerMongoDB": {"name":"replicaset-test-cluster","namespace":"percona-mongodb"}, "namespace": "percona-mongodb", "name": "replicaset-test-cluster", "reconcileID": "7cb4e87f-4f81-431b-a678-32d120700de2", "job": "replicaset-test2-cluster-daily-physical-backup"}
2025-05-22T20:28:06.681Z	INFO	deleting outdated backup job	{"controller": "psmdb-controller", "controllerGroup": "psmdb.percona.com", "controllerKind": "PerconaServerMongoDB", "PerconaServerMongoDB": {"name":"replicaset-test2-cluster","namespace":"percona-mongodb"}, "namespace": "percona-mongodb", "name": "replicaset-test2-cluster", "reconcileID": "a4a36133-fc61-4323-87fb-dca2226ebf94", "job": "replicaset-test-cluster-daily-physical-backup"}

For some reasons it tries to delete outdated backup job for cluster A by task from cluster B and for cluster B by task from cluster A.

Deleting cluster B helps to reduce spamming to only deleting backup jobs for cluster A from cluster B tasks. Operator and cluster recreation doesn’t help

Steps to Reproduce:

Setup cluster A and check logs, should be ok:

apiVersion: psmdb.percona.com/v1
kind: PerconaServerMongoDB
metadata:
  name: replicaset-test-cluster
  namespace: percona-mongodb
  finalizers:
    - percona.com/delete-psmdb-pods-in-order
spec:
  clusterServiceDNSMode: Internal
  crVersion: 1.20.0
  image: percona/percona-server-mongodb:7.0.18-11
  secrets:
    users: replicaset-test-cluster-secrets
    encryptionKey: replicaset-test-cluster-mongodb-encryption-key
  replsets:
    - name: rs0
      size: 3
      configuration: |
        operationProfiling:
          mode: all
          slowOpThresholdMs: 100
          rateLimit: 10
      affinity:
        antiAffinityTopologyKey: "kubernetes.io/hostname"
      expose:
        enabled: true
        type: ClusterIP
      resources:
        limits:
          cpu: "300m"
          memory: "0.5G"
        requests:
          cpu: "300m"
          memory: "0.5G"
      volumeSpec:
        persistentVolumeClaim:
          resources:
            requests:
              storage: 3Gi
  sharding:
    enabled: false

  users:
  - name: app-test-user
    db: admin
    passwordSecretRef:
      name: app-test-user-secret
      key: password
    roles:
      - name: readWrite
        db: test_db
      - name: read
        db: sample_mflix
      - name: read
        db: sample_airbnb

  backup:
    enabled: true
    image: percona/percona-backup-mongodb:2.9.1
    storages:
      s3-us-east:
        type: s3
        s3:
          bucket: k8s-slice-mongodb-qa
          credentialsSecret: replicaset-test-cluster-backup-s3
          region: us-east-1
          prefix: "replicaset-test-cluster"
    tasks:
      - name: replicaset-test-cluster-daily-physical-backup
        enabled: true
        schedule: "0 0 * * *"
        keep: 3
        storageName: s3-us-east
        compressionType: gzip
        compressionLevel: 6
        type: physical
  pmm:
    enabled: false
    image: percona/pmm-client:2.44.1
    serverHost: pmm-qa.slicetest.com
    mongodParams: --environment=QA --cluster=replicaset-test-cluster

Setup cluster B:

apiVersion: psmdb.percona.com/v1
kind: PerconaServerMongoDB
metadata:
  name: replicaset-test2-cluster
  namespace: percona-mongodb
  finalizers:
    - percona.com/delete-psmdb-pods-in-orderspec:
  clusterServiceDNSMode: Internal
  crVersion: 1.20.0
  image: percona/percona-server-mongodb:7.0.18-11
  secrets:
    users: replicaset-test2-cluster-secrets
    encryptionKey: replicaset-test2-cluster-mongodb-encryption-key
  replsets:
    - name: rs0
      size: 3
      configuration: |
        operationProfiling:
          mode: all
          slowOpThresholdMs: 100
          rateLimit: 10
      affinity:
        antiAffinityTopologyKey: "kubernetes.io/hostname"
      expose:
        enabled: true
        type: ClusterIP
      resources:
        limits:
          cpu: "300m"
          memory: "0.5G"
        requests:
          cpu: "300m"
          memory: "0.5G"
      volumeSpec:
        persistentVolumeClaim:
          resources:
            requests:
              storage: 3Gi
  sharding:
    enabled: false

  users:
  - name: app-test-user
    db: admin
    passwordSecretRef:
      name: app-test-user-secret
      key: password
    roles:
      - name: readWrite
        db: test_db

  backup:
    enabled: true
    image: percona/percona-backup-mongodb:2.9.1
    storages:
      s3-us-east:
        type: s3
        s3:
          bucket: k8s-slice-mongodb-qa
          credentialsSecret: replicaset-test2-cluster-backup-s3
          region: us-east-1
          prefix: "replicaset-test2-cluster"
    tasks:
      - name: replicaset-test2-cluster-daily-physical-backup
        enabled: true
        schedule: "0 0 * * *"
        keep: 3
        storageName: s3-us-east
        compressionType: gzip
        compressionLevel: 6
        type: physical
  pmm:
    enabled: false
    image: percona/pmm-client:2.44.1
    serverHost: pmm-qa.slicetest.com
    mongodParams: --environment=QA --cluster=replicaset-test2-cluster

With setting up cluster B the operator starts spamming immediately.

Version:

Operator: 1.20.0
MongoDB: 7.0.18-11
Backup: 2.9.1

Logs:

Logs includes:

  • creating cluster B
  • dropping cluster B and some errors

Expected Result:

Operator should recognise backup tasks per cluster and do not mixed them.

Actual Result:

Opertor mixing backup tasks.

Hi @Stateros ,

Thanks for spotting and submitting the issue. We have reproduced it and created a Jira task for it: Jira .

1 Like

@eleonora.zinchenko there is one more interesting observation: I left only Cluster A, and the Operator stopped spamming me after the backup tasks were completed for the first time.

2025-05-22T23:59:52.397Z	INFO	deleting outdated backup job	{"controller": "psmdb-controller", "controllerGroup": "psmdb.percona.com", "controllerKind": "PerconaServerMongoDB", "PerconaServerMongoDB": {"name":"replicaset-test-cluster","namespace":"percona-mongodb"}, "namespace": "percona-mongodb", "name": "replicaset-test-cluster", "reconcileID": "a200eb57-e2bd-4ffa-bf4d-5a5d0399adcb", "job": "replicaset-test2-cluster-daily-physical-backup"}
2025-05-22T23:59:58.425Z	INFO	deleting outdated backup job	{"controller": "psmdb-controller", "controllerGroup": "psmdb.percona.com", "controllerKind": "PerconaServerMongoDB", "PerconaServerMongoDB": {"name":"replicaset-test-cluster","namespace":"percona-mongodb"}, "namespace": "percona-mongodb", "name": "replicaset-test-cluster", "reconcileID": "4099e4fa-6a35-40e6-b200-a26bbd36c870", "job": "replicaset-test2-cluster-daily-physical-backup"}
2025-05-23T00:00:00.041Z	INFO	cluster is not found, deleting the job	{"controller": "psmdb-controller", "controllerGroup": "psmdb.percona.com", "controllerKind": "PerconaServerMongoDB", "PerconaServerMongoDB": {"name":"replicaset-test2-cluster","namespace":"percona-mongodb"}, "namespace": "percona-mongodb", "name": "replicaset-test2-cluster", "reconcileID": "a0342d13-9bc6-4a04-a4a4-6349a740aba6", "job": "replicaset-test2-cluster-daily-physical-backup"}
2025-05-23T00:00:00.550Z	INFO	Acquiring the backup lock	{"controller": "psmdbbackup-controller", "controllerGroup": "psmdb.percona.com", "controllerKind": "PerconaServerMongoDBBackup", "PerconaServerMongoDBBackup": {"name":"cron-replicaset-test--20250523000000-lbvj6","namespace":"percona-mongodb"}, "namespace": "percona-mongodb", "name": "cron-replicaset-test--20250523000000-lbvj6", "reconcileID": "435c727e-fc08-402a-8a79-097fdcfad2d0"}
2025-05-23T00:00:00.683Z	INFO	Starting backup	{"controller": "psmdbbackup-controller", "controllerGroup": "psmdb.percona.com", "controllerKind": "PerconaServerMongoDBBackup", "PerconaServerMongoDBBackup": {"name":"cron-replicaset-test--20250523000000-lbvj6","namespace":"percona-mongodb"}, "namespace": "percona-mongodb", "name": "cron-replicaset-test--20250523000000-lbvj6", "reconcileID": "435c727e-fc08-402a-8a79-097fdcfad2d0", "backup": "cron-replicaset-test--20250523000000-lbvj6", "storage": "s3-us-east"}
2025-05-23T00:00:00.683Z	INFO	Sending backup command	{"controller": "psmdbbackup-controller", "controllerGroup": "psmdb.percona.com", "controllerKind": "PerconaServerMongoDBBackup", "PerconaServerMongoDBBackup": {"name":"cron-replicaset-test--20250523000000-lbvj6","namespace":"percona-mongodb"}, "namespace": "percona-mongodb", "name": "cron-replicaset-test--20250523000000-lbvj6", "reconcileID": "435c727e-fc08-402a-8a79-097fdcfad2d0", "backup": "cron-replicaset-test--20250523000000-lbvj6", "storage": "s3-us-east", "backupCmd": "backup [name: 2025-05-23T00:00:00Z, compression: gzip (level: 6)] <ts: 0>", "profile": ""}
2025-05-23T00:00:00.701Z	INFO	Backup state changed	{"controller": "psmdbbackup-controller", "controllerGroup": "psmdb.percona.com", "controllerKind": "PerconaServerMongoDBBackup", "PerconaServerMongoDBBackup": {"name":"cron-replicaset-test--20250523000000-lbvj6","namespace":"percona-mongodb"}, "namespace": "percona-mongodb", "name": "cron-replicaset-test--20250523000000-lbvj6", "reconcileID": "435c727e-fc08-402a-8a79-097fdcfad2d0", "previous": "", "current": "requested"}
2025-05-23T00:00:00.812Z	INFO	Acquiring the backup lock	{"controller": "psmdbbackup-controller", "controllerGroup": "psmdb.percona.com", "controllerKind": "PerconaServerMongoDBBackup", "PerconaServerMongoDBBackup": {"name":"cron-replicaset-test--20250523000000-lbvj6","namespace":"percona-mongodb"}, "namespace": "percona-mongodb", "name": "cron-replicaset-test--20250523000000-lbvj6", "reconcileID": "885e3074-f603-4cf1-a762-f4c8dc38272b"}
2025-05-23T00:00:00.815Z	INFO	Waiting for backup metadata	{"controller": "psmdbbackup-controller", "controllerGroup": "psmdb.percona.com", "controllerKind": "PerconaServerMongoDBBackup", "PerconaServerMongoDBBackup": {"name":"cron-replicaset-test--20250523000000-lbvj6","namespace":"percona-mongodb"}, "namespace": "percona-mongodb", "name": "cron-replicaset-test--20250523000000-lbvj6", "reconcileID": "885e3074-f603-4cf1-a762-f4c8dc38272b", "pbmName": "2025-05-23T00:00:00Z", "backup": "cron-replicaset-test--20250523000000-lbvj6"}
2025-05-23T00:00:05.799Z	INFO	Acquiring the backup lock	{"controller": "psmdbbackup-controller", "controllerGroup": "psmdb.percona.com", "controllerKind": "PerconaServerMongoDBBackup", "PerconaServerMongoDBBackup": {"name":"cron-replicaset-test--20250523000000-lbvj6","namespace":"percona-mongodb"}, "namespace": "percona-mongodb", "name": "cron-replicaset-test--20250523000000-lbvj6", "reconcileID": "116fa544-1933-4fa2-9f20-c07643f8e921"}
2025-05-23T00:00:05.803Z	INFO	Backup state changed	{"controller": "psmdbbackup-controller", "controllerGroup": "psmdb.percona.com", "controllerKind": "PerconaServerMongoDBBackup", "PerconaServerMongoDBBackup": {"name":"cron-replicaset-test--20250523000000-lbvj6","namespace":"percona-mongodb"}, "namespace": "percona-mongodb", "name": "cron-replicaset-test--20250523000000-lbvj6", "reconcileID": "116fa544-1933-4fa2-9f20-c07643f8e921", "previous": "requested", "current": "running"}
2025-05-23T00:00:05.919Z	INFO	Acquiring the backup lock	{"controller": "psmdbbackup-controller", "controllerGroup": "psmdb.percona.com", "controllerKind": "PerconaServerMongoDBBackup", "PerconaServerMongoDBBackup": {"name":"cron-replicaset-test--20250523000000-lbvj6","namespace":"percona-mongodb"}, "namespace": "percona-mongodb", "name": "cron-replicaset-test--20250523000000-lbvj6", "reconcileID": "6ec5e6ce-86bb-4226-9bae-ca3af8264d7f"}
2025-05-23T00:00:10.906Z	INFO	Acquiring the backup lock	{"controller": "psmdbbackup-controller", "controllerGroup": "psmdb.percona.com", "controllerKind": "PerconaServerMongoDBBackup", "PerconaServerMongoDBBackup": {"name":"cron-replicaset-test--20250523000000-lbvj6","namespace":"percona-mongodb"}, "namespace": "percona-mongodb", "name": "cron-replicaset-test--20250523000000-lbvj6", "reconcileID": "30410636-0266-44d6-998e-5bb1bffb2b41"}
2025-05-23T00:00:15.967Z	INFO	Acquiring the backup lock	{"controller": "psmdbbackup-controller", "controllerGroup": "psmdb.percona.com", "controllerKind": "PerconaServerMongoDBBackup", "PerconaServerMongoDBBackup": {"name":"cron-replicaset-test--20250523000000-lbvj6","namespace":"percona-mongodb"}, "namespace": "percona-mongodb", "name": "cron-replicaset-test--20250523000000-lbvj6", "reconcileID": "59433d36-6197-4d02-a61c-3c4da2c4b83c"}
2025-05-23T00:00:21.030Z	INFO	Acquiring the backup lock	{"controller": "psmdbbackup-controller", "controllerGroup": "psmdb.percona.com", "controllerKind": "PerconaServerMongoDBBackup", "PerconaServerMongoDBBackup": {"name":"cron-replicaset-test--20250523000000-lbvj6","namespace":"percona-mongodb"}, "namespace": "percona-mongodb", "name": "cron-replicaset-test--20250523000000-lbvj6", "reconcileID": "c03c89c4-9f19-4360-9d08-0ee5307a4db9"}
2025-05-23T00:00:21.034Z	INFO	Backup state changed	{"controller": "psmdbbackup-controller", "controllerGroup": "psmdb.percona.com", "controllerKind": "PerconaServerMongoDBBackup", "PerconaServerMongoDBBackup": {"name":"cron-replicaset-test--20250523000000-lbvj6","namespace":"percona-mongodb"}, "namespace": "percona-mongodb", "name": "cron-replicaset-test--20250523000000-lbvj6", "reconcileID": "c03c89c4-9f19-4360-9d08-0ee5307a4db9", "previous": "running", "current": "ready"}
2025-05-23T00:00:21.043Z	INFO	Releasing backup lock	{"controller": "psmdbbackup-controller", "controllerGroup": "psmdb.percona.com", "controllerKind": "PerconaServerMongoDBBackup", "PerconaServerMongoDBBackup": {"name":"cron-replicaset-test--20250523000000-lbvj6","namespace":"percona-mongodb"}, "namespace": "percona-mongodb", "name": "cron-replicaset-test--20250523000000-lbvj6", "reconcileID": "c03c89c4-9f19-4360-9d08-0ee5307a4db9", "lease": "psmdb-replicaset-test-cluster-backup-lock"}