Error appends using ScheduleBackup : ERROR: [050]: unable to acquire lock on file

[fguiet]

Hi,

I try to use the ScheduleBackup (backup every 5 minutes here)

---
apiVersion: postgresql.cnpg.io/v1
kind: ScheduledBackup
metadata:
  name: schedule-backup-example
  namespace: pg-xxx-ns
spec:
  target: primary
  backupOwnerReference: self
  immediate: true
  method: plugin
  pluginConfiguration:
    name: pgbackrest.cnpg.opera.com
    parameters:
      type: full
  schedule: "* */5 * * * *"
  cluster:
    name: pg-test-cluster

But I get the following error in the sidecar container

{"level":"info","ts":"2025-07-27T09:45:59.311951203Z","msg":"Starting backup","logging_pod":"pg-test-cluster-1"}
{"level":"info","ts":"2025-07-27T09:45:59.320322723Z","msg":"pgbackrest creating stanza","logging_pod":"pg-test-cluster-1"}
{"level":"info","ts":"2025-07-27T09:45:59.320370434Z","msg":"Executing pgbackrest stanza-create command","logging_pod":"pg-test-cluster-1","options":["stanza-create","--repo1-type","s3","--repo1-s3-endpoint","xxx","--repo1-storage-verify-tls=n","--repo1-s3-bucket","pg-backup-01-prod","--repo1-path","/k8s-dbaas-test","--repo1-s3-uri-style","path","--pg1-path","/var/lib/postgresql/data/pgdata","--pg1-user","postgres","--pg1-socket-path","/controller/run/","--log-level-stderr","warn","--log-level-console","off","--stanza","pg-test-cluster","--lock-path","/controller/tmp/pgbackrest"]}
{"level":"info","ts":"2025-07-27T09:45:59.334595798Z","logger":"pgbackrest stanza-create","msg":"WARN: unable to open log file '/var/log/pgbackrest/pg-test-cluster-stanza-create.log': No such file or directory","pipe":"stderr","logging_pod":"pg-test-cluster-1"}
{"level":"info","ts":"2025-07-27T09:45:59.335088943Z","logger":"pgbackrest stanza-create","msg":"      NOTE: process will continue without log file.","pipe":"stderr","logging_pod":"pg-test-cluster-1"}
{"level":"info","ts":"2025-07-27T09:45:59.349187122Z","logger":"pgbackrest stanza-create","msg":"ERROR: [050]: unable to acquire lock on file '/controller/tmp/pgbackrest/pg-test-cluster-backup-1.lock': Resource temporarily unavailable","pipe":"stderr","logging_pod":"pg-test-cluster-1"}
{"level":"info","ts":"2025-07-27T09:45:59.349211122Z","logger":"pgbackrest stanza-create","msg":"       HINT: is another pgBackRest process running?","pipe":"stderr","logging_pod":"pg-test-cluster-1"}
{"level":"error","ts":"2025-07-27T09:45:59.350373905Z","msg":"Error invoking pgbackrest stanza-create","logging_pod":"pg-test-cluster-1","options":["stanza-create","--repo1-type","s3","--repo1-s3-endpoint","xxx","--repo1-storage-verify-tls=n","--repo1-s3-bucket","pg-backup-01-prod","--repo1-path","/k8s-dbaas-test","--repo1-s3-uri-style","path","--pg1-path","/var/lib/postgresql/data/pgdata","--pg1-user","postgres","--pg1-socket-path","/controller/run/","--log-level-stderr","warn","--log-level-console","off","--stanza","pg-test-cluster","--lock-path","/controller/tmp/pgbackrest"],"exitCode":-1,"error":"exit status 50","stacktrace":"github.com/cloudnative-pg/machinery/pkg/log.(*logger).Error\n\t/go/pkg/mod/github.com/cloudnative-pg/machinery@v0.0.0-20250124134709-2553c239f2c8/pkg/log/log.go:125\ngithub.com/operasoftware/cnpg-plugin-pgbackrest/internal/pgbackrest/backup.(*Command).CreatePgbackrestStanza\n\t/workspace/internal/pgbackrest/backup/backup.go:308\ngithub.com/operasoftware/cnpg-plugin-pgbackrest/internal/cnpgi/instance.BackupServiceImplementation.Backup\n\t/workspace/internal/cnpgi/instance/backup.go:121\ngithub.com/cloudnative-pg/cnpg-i/pkg/backup._Backup_Backup_Handler.func1\n\t/go/pkg/mod/github.com/cloudnative-pg/cnpg-i@v0.0.0-20250129202149-1b1d818ad283/pkg/backup/backup_grpc.pb.go:127\ngithub.com/grpc-ecosystem/go-grpc-middleware/v2/interceptors/recovery.UnaryServerInterceptor.func1\n\t/go/pkg/mod/github.com/grpc-ecosystem/go-grpc-middleware/v2@v2.2.0/interceptors/recovery/interceptors.go:34\ngoogle.golang.org/grpc.getChainUnaryHandler.func1\n\t/go/pkg/mod/google.golang.org/grpc@v1.70.0/server.go:1212\ngithub.com/cloudnative-pg/cnpg-i-machinery/pkg/pluginhelper/http.(*Server).Start.loggingUnaryServerInterceptor.func3\n\t/go/pkg/mod/github.com/cloudnative-pg/cnpg-i-machinery@v0.0.0-20250124134931-9247f383fe01/pkg/pluginhelper/http/grpc.go:37\ngoogle.golang.org/grpc.getChainUnaryHandler.func1\n\t/go/pkg/mod/google.golang.org/grpc@v1.70.0/server.go:1212\ngithub.com/cloudnative-pg/cnpg-i-machinery/pkg/pluginhelper/http.(*Server).Start.logFailedRequestsUnaryServerInterceptor.func2\n\t/go/pkg/mod/github.com/cloudnative-pg/cnpg-i-machinery@v0.0.0-20250124134931-9247f383fe01/pkg/pluginhelper/http/grpc.go:49\ngoogle.golang.org/grpc.NewServer.chainUnaryServerInterceptors.chainUnaryInterceptors.func1\n\t/go/pkg/mod/google.golang.org/grpc@v1.70.0/server.go:1203\ngithub.com/cloudnative-pg/cnpg-i/pkg/backup._Backup_Backup_Handler\n\t/go/pkg/mod/github.com/cloudnative-pg/cnpg-i@v0.0.0-20250129202149-1b1d818ad283/pkg/backup/backup_grpc.pb.go:129\ngoogle.golang.org/grpc.(*Server).processUnaryRPC\n\t/go/pkg/mod/google.golang.org/grpc@v1.70.0/server.go:1400\ngoogle.golang.org/grpc.(*Server).handleStream\n\t/go/pkg/mod/google.golang.org/grpc@v1.70.0/server.go:1810\ngoogle.golang.org/grpc.(*Server).serveStreams.func2.1\n\t/go/pkg/mod/google.golang.org/grpc@v1.70.0/server.go:1030"}

Strangely a simple backup is seem to work properly like

apiVersion: postgresql.cnpg.io/v1
kind: Backup
metadata:
  name: backup-example
  namespace: pg-xxx-ns
spec:
  method: plugin
  cluster:
    name: pg-test-cluster
  target: primary
  pluginConfiguration:
    name: pgbackrest.cnpg.opera.com
    parameters:
      type: full

frederic

[Agalin]

Every 5 minutes... my guess would be that the previous backup is still in progress to some degree. You can check the lock file under /controller/tmp/pgbackrest, it's a standard pgbackrest lock - a human-readable JSON.

[fguiet]

Hi @Agalin,

The PostgreSQL instance is empty...so 5 minutes should be enough to backup an empty database.

Will try to schedule the backup every 30 minutes, I'll tell you the result in this thread.

Thank helping,
frederic