Velero Backup Status still keep `In Processing` #3256

zzbmmbzz · 2020-11-17T03:17:37Z

zzbmmbzz
Nov 17, 2020

I have stuck when backup cluster using velero.
Status In Processing still kept. Please help check it. Thanks

kubectl logs -f deployment/velero -n velero

time="2020-11-17T02:44:12Z" level=info msg="setting log-level to INFO" logSource="pkg/cmd/server/server.go:171"
time="2020-11-17T02:44:12Z" level=info msg="Starting Velero server v1.3.2 (55a9914a3e4719fb1578529c45430a8c11c28145)" logSource="pkg/cmd/server/server.go:173"
time="2020-11-17T02:44:12Z" level=info msg="No feature flags enabled" logSource="pkg/cmd/server/server.go:177"
time="2020-11-17T02:44:12Z" level=info msg="registering plugin" command=/velero kind=BackupItemAction logSource="pkg/plugin/clientmgmt/registry.go:100" name=velero.io/crd-remap-version
time="2020-11-17T02:44:12Z" level=info msg="registering plugin" command=/velero kind=BackupItemAction logSource="pkg/plugin/clientmgmt/registry.go:100" name=velero.io/pod
time="2020-11-17T02:44:12Z" level=info msg="registering plugin" command=/velero kind=BackupItemAction logSource="pkg/plugin/clientmgmt/registry.go:100" name=velero.io/pv
time="2020-11-17T02:44:12Z" level=info msg="registering plugin" command=/velero kind=BackupItemAction logSource="pkg/plugin/clientmgmt/registry.go:100" name=velero.io/service-account
time="2020-11-17T02:44:12Z" level=info msg="registering plugin" command=/velero kind=RestoreItemAction logSource="pkg/plugin/clientmgmt/registry.go:100" name=velero.io/add-pv-from-pvc
time="2020-11-17T02:44:12Z" level=info msg="registering plugin" command=/velero kind=RestoreItemAction logSource="pkg/plugin/clientmgmt/registry.go:100" name=velero.io/add-pvc-from-pod
time="2020-11-17T02:44:12Z" level=info msg="registering plugin" command=/velero kind=RestoreItemAction logSource="pkg/plugin/clientmgmt/registry.go:100" name=velero.io/change-storage-class
time="2020-11-17T02:44:12Z" level=info msg="registering plugin" command=/velero kind=RestoreItemAction logSource="pkg/plugin/clientmgmt/registry.go:100" name=velero.io/cluster-role-bindings
time="2020-11-17T02:44:12Z" level=info msg="registering plugin" command=/velero kind=RestoreItemAction logSource="pkg/plugin/clientmgmt/registry.go:100" name=velero.io/crd-preserve-fields
time="2020-11-17T02:44:12Z" level=info msg="registering plugin" command=/velero kind=RestoreItemAction logSource="pkg/plugin/clientmgmt/registry.go:100" name=velero.io/job
time="2020-11-17T02:44:12Z" level=info msg="registering plugin" command=/velero kind=RestoreItemAction logSource="pkg/plugin/clientmgmt/registry.go:100" name=velero.io/pod
time="2020-11-17T02:44:12Z" level=info msg="registering plugin" command=/velero kind=RestoreItemAction logSource="pkg/plugin/clientmgmt/registry.go:100" name=velero.io/restic
time="2020-11-17T02:44:12Z" level=info msg="registering plugin" command=/velero kind=RestoreItemAction logSource="pkg/plugin/clientmgmt/registry.go:100" name=velero.io/role-bindings
time="2020-11-17T02:44:12Z" level=info msg="registering plugin" command=/velero kind=RestoreItemAction logSource="pkg/plugin/clientmgmt/registry.go:100" name=velero.io/service
time="2020-11-17T02:44:12Z" level=info msg="registering plugin" command=/velero kind=RestoreItemAction logSource="pkg/plugin/clientmgmt/registry.go:100" name=velero.io/service-account
time="2020-11-17T02:44:12Z" level=info msg="registering plugin" command=/plugins/velero-plugin-for-aws kind=VolumeSnapshotter logSource="pkg/plugin/clientmgmt/registry.go:100" name=velero.io/aws
time="2020-11-17T02:44:12Z" level=info msg="registering plugin" command=/plugins/velero-plugin-for-aws kind=ObjectStore logSource="pkg/plugin/clientmgmt/registry.go:100" name=velero.io/aws
time="2020-11-17T02:44:12Z" level=info msg="Checking existence of namespace" logSource="pkg/cmd/server/server.go:337" namespace=velero
time="2020-11-17T02:44:12Z" level=info msg="Namespace exists" logSource="pkg/cmd/server/server.go:343" namespace=velero
time="2020-11-17T02:44:15Z" level=info msg="Checking existence of Velero custom resource definitions" logSource="pkg/cmd/server/server.go:372"
time="2020-11-17T02:44:15Z" level=info msg="All Velero custom resource definitions exist" logSource="pkg/cmd/server/server.go:406"
time="2020-11-17T02:44:15Z" level=info msg="Checking that all backup storage locations are valid" logSource="pkg/cmd/server/server.go:413"
time="2020-11-17T02:44:18Z" level=info msg="Starting controllers" logSource="pkg/cmd/server/server.go:526"
time="2020-11-17T02:44:18Z" level=info msg="Backup sync period is 1m0s" logSource="pkg/controller/backup_sync_controller.go:72"
time="2020-11-17T02:44:18Z" level=info msg="Server started successfully" logSource="pkg/cmd/server/server.go:786"
time="2020-11-17T02:44:18Z" level=info msg="Starting metric server at address [:8085]" logSource="pkg/cmd/server/server.go:534"
time="2020-11-17T02:44:18Z" level=info msg="Starting controller" controller=backup-sync logSource="pkg/controller/generic_controller.go:76"
time="2020-11-17T02:44:18Z" level=info msg="Waiting for caches to sync" controller=backup-sync logSource="pkg/controller/generic_controller.go:79"
time="2020-11-17T02:44:18Z" level=info msg="Starting controller" controller=backup logSource="pkg/controller/generic_controller.go:76"
time="2020-11-17T02:44:18Z" level=info msg="Waiting for caches to sync" controller=backup logSource="pkg/controller/generic_controller.go:79"
time="2020-11-17T02:44:18Z" level=info msg="Starting controller" controller=gc-controller logSource="pkg/controller/generic_controller.go:76"
time="2020-11-17T02:44:18Z" level=info msg="Waiting for caches to sync" controller=gc-controller logSource="pkg/controller/generic_controller.go:79"
time="2020-11-17T02:44:18Z" level=info msg="Starting controller" controller=restic-repository logSource="pkg/controller/generic_controller.go:76"
time="2020-11-17T02:44:18Z" level=info msg="Waiting for caches to sync" controller=restic-repository logSource="pkg/controller/generic_controller.go:79"
time="2020-11-17T02:44:18Z" level=info msg="Starting controller" controller=serverstatusrequest logSource="pkg/controller/generic_controller.go:76"
time="2020-11-17T02:44:18Z" level=info msg="Waiting for caches to sync" controller=serverstatusrequest logSource="pkg/controller/generic_controller.go:79"
time="2020-11-17T02:44:18Z" level=info msg="Starting controller" controller=schedule logSource="pkg/controller/generic_controller.go:76"
time="2020-11-17T02:44:18Z" level=info msg="Waiting for caches to sync" controller=schedule logSource="pkg/controller/generic_controller.go:79"
time="2020-11-17T02:44:18Z" level=info msg="Starting controller" controller=backup-deletion logSource="pkg/controller/generic_controller.go:76"
time="2020-11-17T02:44:18Z" level=info msg="Waiting for caches to sync" controller=backup-deletion logSource="pkg/controller/generic_controller.go:79"
time="2020-11-17T02:44:18Z" level=info msg="Starting controller" controller=restore logSource="pkg/controller/generic_controller.go:76"
time="2020-11-17T02:44:18Z" level=info msg="Waiting for caches to sync" controller=restore logSource="pkg/controller/generic_controller.go:79"
time="2020-11-17T02:44:18Z" level=info msg="Starting controller" controller=downloadrequest logSource="pkg/controller/generic_controller.go:76"
time="2020-11-17T02:44:18Z" level=info msg="Waiting for caches to sync" controller=downloadrequest logSource="pkg/controller/generic_controller.go:79"
time="2020-11-17T02:44:20Z" level=info msg="Caches are synced" controller=schedule logSource="pkg/controller/generic_controller.go:83"
time="2020-11-17T02:44:20Z" level=info msg="Caches are synced" controller=serverstatusrequest logSource="pkg/controller/generic_controller.go:83"
time="2020-11-17T02:44:20Z" level=info msg="Caches are synced" controller=restic-repository logSource="pkg/controller/generic_controller.go:83"
time="2020-11-17T02:44:20Z" level=info msg="Caches are synced" controller=backup-sync logSource="pkg/controller/generic_controller.go:83"
time="2020-11-17T02:44:20Z" level=info msg="Caches are synced" controller=backup logSource="pkg/controller/generic_controller.go:83"
time="2020-11-17T02:44:20Z" level=info msg="Caches are synced" controller=downloadrequest logSource="pkg/controller/generic_controller.go:83"
time="2020-11-17T02:44:20Z" level=info msg="Caches are synced" controller=restore logSource="pkg/controller/generic_controller.go:83"
time="2020-11-17T02:44:20Z" level=info msg="Caches are synced" controller=gc-controller logSource="pkg/controller/generic_controller.go:83"
time="2020-11-17T02:44:20Z" level=info msg="Caches are synced" controller=backup-deletion logSource="pkg/controller/generic_controller.go:83"
time="2020-11-17T02:44:20Z" level=info msg="Checking for expired DeleteBackupRequests" controller=backup-deletion logSource="pkg/controller/backup_deletion_controller.go:456"
time="2020-11-17T02:44:20Z" level=info msg="Done checking for expired DeleteBackupRequests" controller=backup-deletion logSource="pkg/controller/backup_deletion_controller.go:484"

dsu-igeek · 2020-11-23T20:20:50Z

dsu-igeek
Nov 23, 2020

We could use some additional logs to diagnose the problem.

The output of the following commands will help us better understand what's going on:
(Pasting long output into a GitHub gist or other pastebin is fine.)

kubectl logs deployment/velero -n velero
velero backup describe <backupname> or kubectl get backup/<backupname> -n velero -o yaml
velero backup logs <backupname>
velero restore describe <restorename> or kubectl get restore/<restorename> -n velero -o yaml
velero restore logs <restorename>

0 replies

zzbmmbzz · 2020-11-24T08:43:16Z

zzbmmbzz
Nov 24, 2020
Author

Hi @dsu-igeek Here is the log for you

kubectl logs deployment/velero -n velero - Logs

velero backup describe rancher-backup - Logs

kubectl get backup/rancher-backup -n velero -o yaml - Logs

velero backup logs rancher-backup

Logs for backup "rancher-backup" are not available until it's finished processing. Please wait until the backup has a phase of Completed or Failed and try again.

Backup still Inprogress so I could not get Restore logs for you

0 replies

makabaka-boom · 2020-12-08T06:57:01Z

makabaka-boom
Dec 8, 2020

I had this problem lately. Maybe your velero container happened to something like OOM when executing backup and then been killed. So it restarted and backup's status kept In Progress.

0 replies

zzbmmbzz · 2020-12-09T04:44:38Z

zzbmmbzz
Dec 9, 2020
Author

I had this problem lately. Maybe your velero container happened to something like OOM when executing backup and then been killed. So it restarted and backup's status kept In Progress.

let me try when clusters are free

0 replies

codegold79 · 2021-02-02T22:34:04Z

codegold79
Feb 2, 2021

I have no idea if this is the reason for the problem, but I wonder if this error might help point to a solution:

An error occurred: some backup storage locations are invalid: backup store for location "default" is invalid: Backup store contains invalid top-level directories: [rancher]

I found the error message in the logs you shared for kubectl logs deployment/velero -n velero.

1 reply

dsu-igeek Feb 2, 2021

That will cause problems if you have prefixes in the bucket that Velero does not recognize.

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Velero Backup Status still keep `In Processing` #3256

{{title}}

Replies: 5 comments 1 reply

{{title}}

{{title}}

{{editor}}'s edit

{{editor}}'s edit

{{title}}

{{title}}

{{title}}

{{title}}

Select a reply

Velero Backup Status still keep In Processing #3256

zzbmmbzz Nov 17, 2020

Replies: 5 comments · 1 reply

dsu-igeek Nov 23, 2020

zzbmmbzz Nov 24, 2020 Author

makabaka-boom Dec 8, 2020

zzbmmbzz Dec 9, 2020 Author

codegold79 Feb 2, 2021

dsu-igeek Feb 2, 2021

Velero Backup Status still keep `In Processing` #3256

zzbmmbzz
Nov 17, 2020

Replies: 5 comments 1 reply

dsu-igeek
Nov 23, 2020

zzbmmbzz
Nov 24, 2020
Author

makabaka-boom
Dec 8, 2020

zzbmmbzz
Dec 9, 2020
Author

codegold79
Feb 2, 2021