Uploaded image for project: 'OpenShift API for Data Protection'
  1. OpenShift API for Data Protection
  2. OADP-1076

Velero pod going in crashLoopbackoff when restore hooks is specified

    XMLWordPrintable

Details

    • False
    • Hide

      None

      Show
      None
    • False
    • QE - Ack
    • ToDo
    • Yes
    • 0
    • 0
    • Very Likely
    • 0
    • None
    • Unset
    • Unknown

    Description

      Description of problem: 

      Velero pod is going in crashLoopBackOff due to nil pointer deference issue. It happens when restore CR contains hooks specification. 

       

      time="2022-12-09T10:45:18Z" level=info msg="Starting EventSource" controller=deletebackuprequest controllerGroup=velero.io controllerKind=DeleteBackupRequest logSource="/remote-source/velero/deps/gomod/pkg/mod/github.com/bombsimon/logrusr/v3@v3.0.0/logrusr.go:108" source="kind source: *v1.DeleteBackupRequest"
E1209 10:45:18.450965       1 runtime.go:79] Observed a panic: "invalid memory address or nil pointer dereference" (runtime error: invalid memory address or nil pointer dereference)
goroutine 1556 [running]:
k8s.io/apimachinery/pkg/util/runtime.logPanic({0x21f27a0?, 0x3d197d0})
    /remote-source/velero/deps/gomod/pkg/mod/k8s.io/apimachinery@v0.24.2/pkg/util/runtime/runtime.go:75 +0x99
k8s.io/apimachinery/pkg/util/runtime.HandleCrash({0x0, 0x0, 0xc00097c8d0?})
    /remote-source/velero/deps/gomod/pkg/mod/k8s.io/apimachinery@v0.24.2/pkg/util/runtime/runtime.go:49 +0x75
panic({0x21f27a0, 0x3d197d0})
    /usr/lib/golang/src/runtime/panic.go:884 +0x212
github.com/vmware-tanzu/velero/pkg/controller.(*restoreController).validateAndComplete(0xc000a32dd0, 0xc000ecc500, {0x2aba440, 0xc00059a6e0})
    /remote-source/velero/app/pkg/controller/restore_controller.go:345 +0xc5b
github.com/vmware-tanzu/velero/pkg/controller.(*restoreController).processRestore(0xc000a32dd0, 0xc000ecc500)
    /remote-source/velero/app/pkg/controller/restore_controller.go:241 +0x117
github.com/vmware-tanzu/velero/pkg/controller.(*restoreController).processQueueItem(0xc000a32dd0, {0xc000e00a50, 0x42})
    /remote-source/velero/app/pkg/controller/restore_controller.go:224 +0x30c
github.com/vmware-tanzu/velero/pkg/controller.(*genericController).processNextWorkItem(0xc00083e780)
    /remote-source/velero/app/pkg/controller/generic_controller.go:132 +0xeb
github.com/vmware-tanzu/velero/pkg/controller.(*genericController).runWorker(0xc000bd9ea8?)
    /remote-source/velero/app/pkg/controller/generic_controller.go:119 +0x25
k8s.io/apimachinery/pkg/util/wait.BackoffUntil.func1(0x1f05a60?)
    /remote-source/velero/deps/gomod/pkg/mod/k8s.io/apimachinery@v0.24.2/pkg/util/wait/wait.go:155 +0x3e
k8s.io/apimachinery/pkg/util/wait.BackoffUntil(0xc000bd9f58?, {0x2a8ef20, 0xc000d352f0}, 0x1, 0xc000c97080)
    /remote-source/velero/deps/gomod/pkg/mod/k8s.io/apimachinery@v0.24.2/pkg/util/wait/wait.go:156 +0xb6
k8s.io/apimachinery/pkg/util/wait.JitterUntil(0xc00089c3f0?, 0x3b9aca00, 0x0, 0x5?, 0x0?)
    /remote-source/velero/deps/gomod/pkg/mod/k8s.io/apimachinery@v0.24.2/pkg/util/wait/wait.go:133 +0x89
k8s.io/apimachinery/pkg/util/wait.Until(...)
    /remote-source/velero/deps/gomod/pkg/mod/k8s.io/apimachinery@v0.24.2/pkg/util/wait/wait.go:90
github.com/vmware-tanzu/velero/pkg/controller.(*genericController).Run.func2()
    /remote-source/velero/app/pkg/controller/generic_controller.go:92 +0x6e
created by github.com/vmware-tanzu/velero/pkg/controller.(*genericController).Run
    /remote-source/velero/app/pkg/controller/generic_controller.go:91 +0x45a
panic: runtime error: invalid memory address or nil pointer dereference [recovered]
    panic: runtime error: invalid memory address or nil pointer dereference
[signal SIGSEGV: segmentation violation code=0x1 addr=0x8 pc=0x1f0ec1b]
goroutine 1556 [running]:
k8s.io/apimachinery/pkg/util/runtime.HandleCrash({0x0, 0x0, 0xc00097c8d0?})
    /remote-source/velero/deps/gomod/pkg/mod/k8s.io/apimachinery@v0.24.2/pkg/util/runtime/runtime.go:56 +0xd7
panic({0x21f27a0, 0x3d197d0})
    /usr/lib/golang/src/runtime/panic.go:884 +0x212
github.com/vmware-tanzu/velero/pkg/controller.(*restoreController).validateAndComplete(0xc000a32dd0, 0xc000ecc500, {0x2aba440, 0xc00059a6e0})
    /remote-source/velero/app/pkg/controller/restore_controller.go:345 +0xc5b
github.com/vmware-tanzu/velero/pkg/controller.(*restoreController).processRestore(0xc000a32dd0, 0xc000ecc500)
    /remote-source/velero/app/pkg/controller/restore_controller.go:241 +0x117
github.com/vmware-tanzu/velero/pkg/controller.(*restoreController).processQueueItem(0xc000a32dd0, {0xc000e00a50, 0x42})
    /remote-source/velero/app/pkg/controller/restore_controller.go:224 +0x30c
github.com/vmware-tanzu/velero/pkg/controller.(*genericController).processNextWorkItem(0xc00083e780)
    /remote-source/velero/app/pkg/controller/generic_controller.go:132 +0xeb
github.com/vmware-tanzu/velero/pkg/controller.(*genericController).runWorker(0xc000bd9ea8?)
    /remote-source/velero/app/pkg/controller/generic_controller.go:119 +0x25
k8s.io/apimachinery/pkg/util/wait.BackoffUntil.func1(0x1f05a60?)
    /remote-source/velero/deps/gomod/pkg/mod/k8s.io/apimachinery@v0.24.2/pkg/util/wait/wait.go:155 +0x3e
k8s.io/apimachinery/pkg/util/wait.BackoffUntil(0xc000bd9f58?, {0x2a8ef20, 0xc000d352f0}, 0x1, 0xc000c97080)
    /remote-source/velero/deps/gomod/pkg/mod/k8s.io/apimachinery@v0.24.2/pkg/util/wait/wait.go:156 +0xb6
k8s.io/apimachinery/pkg/util/wait.JitterUntil(0xc00089c3f0?, 0x3b9aca00, 0x0, 0x5?, 0x0?)
    /remote-source/velero/deps/gomod/pkg/mod/k8s.io/apimachinery@v0.24.2/pkg/util/wait/wait.go:133 +0x89
k8s.io/apimachinery/pkg/util/wait.Until(...)
    /remote-source/velero/deps/gomod/pkg/mod/k8s.io/apimachinery@v0.24.2/pkg/util/wait/wait.go:90
github.com/vmware-tanzu/velero/pkg/controller.(*genericController).Run.func2()
    /remote-source/velero/app/pkg/controller/generic_controller.go:92 +0x6e
created by github.com/vmware-tanzu/velero/pkg/controller.(*genericController).Run
    /remote-source/velero/app/pkg/controller/generic_controller.go:91 +0x45a

      Version-Release number of selected component (if applicable):
      OADP 1.2.0-3

       

      How reproducible:
      Always
      Failing consistently

       

      Steps to Reproduce:
      1. Deploy an application

      2. Create a backup (wait until backup gets completed successfully)

      3. Create a restore CR with hooks.
      Example :- 

      apiVersion: velero.io/v1
kind: Restore
metadata:
   name: mysql-hooks-e2e-614a9540-77ab-11ed-8518-845cf3eff33a
   namespace: openshift-adp
spec:
    backupName: mysql-hooks-e2e-614a9540-77ab-11ed-8518-845cf3eff33a
    hooks:
      resources:
      - includedNamespaces:
        - mysql-persistent
        name: restore-hook-1
        postHooks:
        - exec:
            command:
            - bash
            - -c
            - while ! mysqladmin ping -h localhost --silent; do sleep 1; done
            execTimeout: 2m0s
            onError: Fail
            waitTimeout: 2m0s

      Actual results:

      Velero pod is going in crashloopbackoff due to nil pointer issue.

       

      $ oc logs velero-6b57869f5b-wkx4n --previous

time="2022-12-09T10:50:27Z" level=info msg="setting log-level to INFO" logSource="/remote-source/velero/app/pkg/cmd/server/server.go:189"
time="2022-12-09T10:50:27Z" level=info msg="Starting Velero server v1.9.2-OADP (-)" logSource="/remote-source/velero/app/pkg/cmd/server/server.go:191"
time="2022-12-09T10:50:27Z" level=info msg="No feature flags enabled" logSource="/remote-source/velero/app/pkg/cmd/server/server.go:195"
time="2022-12-09T10:50:27Z" level=info msg="registering plugin" command=/velero kind=BackupItemAction logSource="/remote-source/velero/app/pkg/plugin/clientmgmt/process/registry.go:101" name=velero.io/crd-remap-version
time="2022-12-09T10:50:27Z" level=info msg="registering plugin" command=/velero kind=BackupItemAction logSource="/remote-source/velero/app/pkg/plugin/clientmgmt/process/registry.go:101" name=velero.io/pod
time="2022-12-09T10:50:27Z" level=info msg="registering plugin" command=/velero kind=BackupItemAction logSource="/remote-source/velero/app/pkg/plugin/clientmgmt/process/registry.go:101" name=velero.io/pv
time="2022-12-09T10:50:27Z" level=info msg="registering plugin" command=/velero kind=BackupItemAction logSource="/remote-source/velero/app/pkg/plugin/clientmgmt/process/registry.go:101" name=velero.io/service-account
time="2022-12-09T10:50:27Z" level=info msg="registering plugin" command=/velero kind=RestoreItemAction logSource="/remote-source/velero/app/pkg/plugin/clientmgmt/process/registry.go:101" name=velero.io/add-pv-from-pvc
time="2022-12-09T10:50:27Z" level=info msg="registering plugin" command=/velero kind=RestoreItemAction logSource="/remote-source/velero/app/pkg/plugin/clientmgmt/process/registry.go:101" name=velero.io/add-pvc-from-pod
time="2022-12-09T10:50:27Z" level=info msg="registering plugin" command=/velero kind=RestoreItemAction logSource="/remote-source/velero/app/pkg/plugin/clientmgmt/process/registry.go:101" name=velero.io/admission-webhook-configuration
time="2022-12-09T10:50:27Z" level=info msg="registering plugin" command=/velero kind=RestoreItemAction logSource="/remote-source/velero/app/pkg/plugin/clientmgmt/process/registry.go:101" name=velero.io/apiservice
time="2022-12-09T10:50:27Z" level=info msg="registering plugin" command=/velero kind=RestoreItemAction logSource="/remote-source/velero/app/pkg/plugin/clientmgmt/process/registry.go:101" name=velero.io/change-pvc-node-selector
time="2022-12-09T10:50:27Z" level=info msg="registering plugin" command=/velero kind=RestoreItemAction logSource="/remote-source/velero/app/pkg/plugin/clientmgmt/process/registry.go:101" name=velero.io/change-storage-class
time="2022-12-09T10:50:27Z" level=info msg="registering plugin" command=/velero kind=RestoreItemAction logSource="/remote-source/velero/app/pkg/plugin/clientmgmt/process/registry.go:101" name=velero.io/cluster-role-bindings
time="2022-12-09T10:50:27Z" level=info msg="registering plugin" command=/velero kind=RestoreItemAction logSource="/remote-source/velero/app/pkg/plugin/clientmgmt/process/registry.go:101" name=velero.io/crd-preserve-fields
time="2022-12-09T10:50:27Z" level=info msg="registering plugin" command=/velero kind=RestoreItemAction logSource="/remote-source/velero/app/pkg/plugin/clientmgmt/process/registry.go:101" name=velero.io/init-restore-hook
time="2022-12-09T10:50:27Z" level=info msg="registering plugin" command=/velero kind=RestoreItemAction logSource="/remote-source/velero/app/pkg/plugin/clientmgmt/process/registry.go:101" name=velero.io/job
time="2022-12-09T10:50:27Z" level=info msg="registering plugin" command=/velero kind=RestoreItemAction logSource="/remote-source/velero/app/pkg/plugin/clientmgmt/process/registry.go:101" name=velero.io/pod
time="2022-12-09T10:50:27Z" level=info msg="registering plugin" command=/velero kind=RestoreItemAction logSource="/remote-source/velero/app/pkg/plugin/clientmgmt/process/registry.go:101" name=velero.io/pod-volume-restore
time="2022-12-09T10:50:27Z" level=info msg="registering plugin" command=/velero kind=RestoreItemAction logSource="/remote-source/velero/app/pkg/plugin/clientmgmt/process/registry.go:101" name=velero.io/role-bindings
time="2022-12-09T10:50:27Z" level=info msg="registering plugin" command=/velero kind=RestoreItemAction logSource="/remote-source/velero/app/pkg/plugin/clientmgmt/process/registry.go:101" name=velero.io/service
time="2022-12-09T10:50:27Z" level=info msg="registering plugin" command=/velero kind=RestoreItemAction logSource="/remote-source/velero/app/pkg/plugin/clientmgmt/process/registry.go:101" name=velero.io/service-account
time="2022-12-09T10:50:27Z" level=info msg="registering plugin" command=/plugins/kubevirt-velero-plugin kind=BackupItemAction logSource="/remote-source/velero/app/pkg/plugin/clientmgmt/process/registry.go:101" name=kubevirt-velero-plugin/backup-datavolume-action
time="2022-12-09T10:50:27Z" level=info msg="registering plugin" command=/plugins/kubevirt-velero-plugin kind=BackupItemAction logSource="/remote-source/velero/app/pkg/plugin/clientmgmt/process/registry.go:101" name=kubevirt-velero-plugin/backup-virtualmachine-action
time="2022-12-09T10:50:27Z" level=info msg="registering plugin" command=/plugins/kubevirt-velero-plugin kind=BackupItemAction logSource="/remote-source/velero/app/pkg/plugin/clientmgmt/process/registry.go:101" name=kubevirt-velero-plugin/backup-virtualmachineinstance-action
time="2022-12-09T10:50:27Z" level=info msg="registering plugin" command=/plugins/kubevirt-velero-plugin kind=RestoreItemAction logSource="/remote-source/velero/app/pkg/plugin/clientmgmt/process/registry.go:101" name=kubevirt-velero-plugin/restore-pod-action
time="2022-12-09T10:50:27Z" level=info msg="registering plugin" command=/plugins/kubevirt-velero-plugin kind=RestoreItemAction logSource="/remote-source/velero/app/pkg/plugin/clientmgmt/process/registry.go:101" name=kubevirt-velero-plugin/restore-pvc-action
time="2022-12-09T10:50:27Z" level=info msg="registering plugin" command=/plugins/kubevirt-velero-plugin kind=RestoreItemAction logSource="/remote-source/velero/app/pkg/plugin/clientmgmt/process/registry.go:101" name=kubevirt-velero-plugin/restore-vm-action
time="2022-12-09T10:50:27Z" level=info msg="registering plugin" command=/plugins/kubevirt-velero-plugin kind=RestoreItemAction logSource="/remote-source/velero/app/pkg/plugin/clientmgmt/process/registry.go:101" name=kubevirt-velero-plugin/restore-vmi-action
time="2022-12-09T10:50:27Z" level=info msg="registering plugin" command=/plugins/velero-plugin-for-aws kind=VolumeSnapshotter logSource="/remote-source/velero/app/pkg/plugin/clientmgmt/process/registry.go:101" name=velero.io/aws
time="2022-12-09T10:50:27Z" level=info msg="registering plugin" command=/plugins/velero-plugin-for-aws kind=ObjectStore logSource="/remote-source/velero/app/pkg/plugin/clientmgmt/process/registry.go:101" name=velero.io/aws
time="2022-12-09T10:50:27Z" level=info msg="registering plugin" command=/plugins/velero-plugins kind=BackupItemAction logSource="/remote-source/velero/app/pkg/plugin/clientmgmt/process/registry.go:101" name=openshift.io/01-common-backup-plugin
time="2022-12-09T10:50:27Z" level=info msg="registering plugin" command=/plugins/velero-plugins kind=BackupItemAction logSource="/remote-source/velero/app/pkg/plugin/clientmgmt/process/registry.go:101" name=openshift.io/02-serviceaccount-backup-plugin
time="2022-12-09T10:50:27Z" level=info msg="registering plugin" command=/plugins/velero-plugins kind=BackupItemAction logSource="/remote-source/velero/app/pkg/plugin/clientmgmt/process/registry.go:101" name=openshift.io/03-pv-backup-plugin
time="2022-12-09T10:50:27Z" level=info msg="registering plugin" command=/plugins/velero-plugins kind=BackupItemAction logSource="/remote-source/velero/app/pkg/plugin/clientmgmt/process/registry.go:101" name=openshift.io/04-imagestreamtag-backup-plugin
time="2022-12-09T10:50:27Z" level=info msg="registering plugin" command=/plugins/velero-plugins kind=BackupItemAction logSource="/remote-source/velero/app/pkg/plugin/clientmgmt/process/registry.go:101" name=openshift.io/09-replicationcontroller-backup-plugin
time="2022-12-09T10:50:27Z" level=info msg="registering plugin" command=/plugins/velero-plugins kind=BackupItemAction logSource="/remote-source/velero/app/pkg/plugin/clientmgmt/process/registry.go:101" name=openshift.io/12-replicaset-backup-plugin
time="2022-12-09T10:50:27Z" level=info msg="registering plugin" command=/plugins/velero-plugins kind=BackupItemAction logSource="/remote-source/velero/app/pkg/plugin/clientmgmt/process/registry.go:101" name=openshift.io/19-is-backup-plugin
time="2022-12-09T10:50:27Z" level=info msg="registering plugin" command=/plugins/velero-plugins kind=RestoreItemAction logSource="/remote-source/velero/app/pkg/plugin/clientmgmt/process/registry.go:101" name=openshift.io/01-common-restore-plugin
time="2022-12-09T10:50:27Z" level=info msg="registering plugin" command=/plugins/velero-plugins kind=RestoreItemAction logSource="/remote-source/velero/app/pkg/plugin/clientmgmt/process/registry.go:101" name=openshift.io/02-serviceaccount-restore-plugin
time="2022-12-09T10:50:27Z" level=info msg="registering plugin" command=/plugins/velero-plugins kind=RestoreItemAction logSource="/remote-source/velero/app/pkg/plugin/clientmgmt/process/registry.go:101" name=openshift.io/03-pv-restore-plugin
time="2022-12-09T10:50:27Z" level=info msg="registering plugin" command=/plugins/velero-plugins kind=RestoreItemAction logSource="/remote-source/velero/app/pkg/plugin/clientmgmt/process/registry.go:101" name=openshift.io/04-imagestreamtag-restore-plugin
time="2022-12-09T10:50:27Z" level=info msg="registering plugin" command=/plugins/velero-plugins kind=RestoreItemAction logSource="/remote-source/velero/app/pkg/plugin/clientmgmt/process/registry.go:101" name=openshift.io/04-pvc-restore-plugin
time="2022-12-09T10:50:27Z" level=info msg="registering plugin" command=/plugins/velero-plugins kind=RestoreItemAction logSource="/remote-source/velero/app/pkg/plugin/clientmgmt/process/registry.go:101" name=openshift.io/05-route-restore-plugin
time="2022-12-09T10:50:27Z" level=info msg="registering plugin" command=/plugins/velero-plugins kind=RestoreItemAction logSource="/remote-source/velero/app/pkg/plugin/clientmgmt/process/registry.go:101" name=openshift.io/06-build-restore-plugin
time="2022-12-09T10:50:27Z" level=info msg="registering plugin" command=/plugins/velero-plugins kind=RestoreItemAction logSource="/remote-source/velero/app/pkg/plugin/clientmgmt/process/registry.go:101" name=openshift.io/07-pod-restore-plugin
time="2022-12-09T10:50:27Z" level=info msg="registering plugin" command=/plugins/velero-plugins kind=RestoreItemAction logSource="/remote-source/velero/app/pkg/plugin/clientmgmt/process/registry.go:101" name=openshift.io/08-deploymentconfig-restore-plugin
time="2022-12-09T10:50:27Z" level=info msg="registering plugin" command=/plugins/velero-plugins kind=RestoreItemAction logSource="/remote-source/velero/app/pkg/plugin/clientmgmt/process/registry.go:101" name=openshift.io/09-replicationcontroller-restore-plugin
time="2022-12-09T10:50:27Z" level=info msg="registering plugin" command=/plugins/velero-plugins kind=RestoreItemAction logSource="/remote-source/velero/app/pkg/plugin/clientmgmt/process/registry.go:101" name=openshift.io/10-job-restore-plugin
time="2022-12-09T10:50:27Z" level=info msg="registering plugin" command=/plugins/velero-plugins kind=RestoreItemAction logSource="/remote-source/velero/app/pkg/plugin/clientmgmt/process/registry.go:101" name=openshift.io/11-daemonset-restore-plugin
time="2022-12-09T10:50:27Z" level=info msg="registering plugin" command=/plugins/velero-plugins kind=RestoreItemAction logSource="/remote-source/velero/app/pkg/plugin/clientmgmt/process/registry.go:101" name=openshift.io/12-replicaset-restore-plugin
time="2022-12-09T10:50:27Z" level=info msg="registering plugin" command=/plugins/velero-plugins kind=RestoreItemAction logSource="/remote-source/velero/app/pkg/plugin/clientmgmt/process/registry.go:101" name=openshift.io/13-deployment-restore-plugin
time="2022-12-09T10:50:27Z" level=info msg="registering plugin" command=/plugins/velero-plugins kind=RestoreItemAction logSource="/remote-source/velero/app/pkg/plugin/clientmgmt/process/registry.go:101" name=openshift.io/14-statefulset-restore-plugin
time="2022-12-09T10:50:27Z" level=info msg="registering plugin" command=/plugins/velero-plugins kind=RestoreItemAction logSource="/remote-source/velero/app/pkg/plugin/clientmgmt/process/registry.go:101" name=openshift.io/15-service-restore-plugin
time="2022-12-09T10:50:27Z" level=info msg="registering plugin" command=/plugins/velero-plugins kind=RestoreItemAction logSource="/remote-source/velero/app/pkg/plugin/clientmgmt/process/registry.go:101" name=openshift.io/16-cronjob-restore-plugin
time="2022-12-09T10:50:27Z" level=info msg="registering plugin" command=/plugins/velero-plugins kind=RestoreItemAction logSource="/remote-source/velero/app/pkg/plugin/clientmgmt/process/registry.go:101" name=openshift.io/17-buildconfig-restore-plugin
time="2022-12-09T10:50:27Z" level=info msg="registering plugin" command=/plugins/velero-plugins kind=RestoreItemAction logSource="/remote-source/velero/app/pkg/plugin/clientmgmt/process/registry.go:101" name=openshift.io/18-secret-restore-plugin
time="2022-12-09T10:50:27Z" level=info msg="registering plugin" command=/plugins/velero-plugins kind=RestoreItemAction logSource="/remote-source/velero/app/pkg/plugin/clientmgmt/process/registry.go:101" name=openshift.io/19-is-restore-plugin
time="2022-12-09T10:50:27Z" level=info msg="registering plugin" command=/plugins/velero-plugins kind=RestoreItemAction logSource="/remote-source/velero/app/pkg/plugin/clientmgmt/process/registry.go:101" name=openshift.io/20-SCC-restore-plugin
time="2022-12-09T10:50:27Z" level=info msg="registering plugin" command=/plugins/velero-plugins kind=RestoreItemAction logSource="/remote-source/velero/app/pkg/plugin/clientmgmt/process/registry.go:101" name=openshift.io/21-role-bindings-restore-plugin
time="2022-12-09T10:50:27Z" level=info msg="registering plugin" command=/plugins/velero-plugins kind=RestoreItemAction logSource="/remote-source/velero/app/pkg/plugin/clientmgmt/process/registry.go:101" name=openshift.io/22-cluster-role-bindings-restore-plugin
time="2022-12-09T10:50:27Z" level=info msg="registering plugin" command=/plugins/velero-plugins kind=RestoreItemAction logSource="/remote-source/velero/app/pkg/plugin/clientmgmt/process/registry.go:101" name=openshift.io/23-imagetag-restore-plugin
time="2022-12-09T10:50:27Z" level=info msg="registering plugin" command=/plugins/velero-plugins kind=RestoreItemAction logSource="/remote-source/velero/app/pkg/plugin/clientmgmt/process/registry.go:101" name=openshift.io/24-horizontalpodautoscaler-restore-plugin
I1209 10:50:29.011335       1 request.go:601] Waited for 1.029674915s due to client-side throttling, not priority and fairness, request: GET:https://172.30.0.1:443/apis/console.openshift.io/v1?timeout=32s
time="2022-12-09T10:50:30Z" level=info msg="Metrics server is starting to listen" addr=":8080" logSource="/remote-source/velero/deps/gomod/pkg/mod/github.com/bombsimon/logrusr/v3@v3.0.0/logrusr.go:108" logger=controller-runtime.metrics
time="2022-12-09T10:50:30Z" level=info msg="Checking existence of namespace." logSource="/remote-source/velero/app/pkg/cmd/server/server.go:418" namespace=openshift-adp
time="2022-12-09T10:50:30Z" level=info msg="Namespace exists" logSource="/remote-source/velero/app/pkg/cmd/server/server.go:424" namespace=openshift-adp
time="2022-12-09T10:50:37Z" level=info msg="Checking existence of Velero custom resource definitions" logSource="/remote-source/velero/app/pkg/cmd/server/server.go:453"
time="2022-12-09T10:50:37Z" level=info msg="All Velero custom resource definitions exist" logSource="/remote-source/velero/app/pkg/cmd/server/server.go:487"
time="2022-12-09T10:50:37Z" level=warning msg="Velero node agent not found; pod volume backups/restores will not work until it's created" logSource="/remote-source/velero/app/pkg/cmd/server/server.go:550"
time="2022-12-09T10:50:37Z" level=warning msg="Velero node agent not found; pod volume backups/restores will not work until it's created" logSource="/remote-source/velero/app/pkg/cmd/server/server.go:559"
I1209 10:50:39.020307       1 request.go:601] Waited for 1.045929201s due to client-side throttling, not priority and fairness, request: GET:https://172.30.0.1:443/apis/storage.k8s.io/v1beta1?timeout=32s
time="2022-12-09T10:50:40Z" level=info msg="Starting controllers" logSource="/remote-source/velero/app/pkg/cmd/server/server.go:604"
time="2022-12-09T10:50:40Z" level=info msg="Starting metric server at address [:8085]" logSource="/remote-source/velero/app/pkg/cmd/server/server.go:611"
time="2022-12-09T10:50:40Z" level=info msg="Waiting for informer caches to sync" logSource="/remote-source/velero/app/pkg/cmd/server/server.go:763"
time="2022-12-09T10:50:42Z" level=info msg="Done waiting for informer caches to sync" logSource="/remote-source/velero/app/pkg/cmd/server/server.go:766"
time="2022-12-09T10:50:42Z" level=info msg="Informer cache synced" informer="*v1.BackupRepository" logSource="/remote-source/velero/app/pkg/cmd/server/server.go:777"
time="2022-12-09T10:50:42Z" level=info msg="Informer cache synced" informer="*v1.VolumeSnapshotLocation" logSource="/remote-source/velero/app/pkg/cmd/server/server.go:777"
time="2022-12-09T10:50:42Z" level=info msg="Informer cache synced" informer="*v1.Backup" logSource="/remote-source/velero/app/pkg/cmd/server/server.go:777"
time="2022-12-09T10:50:42Z" level=info msg="Informer cache synced" informer="*v1.Restore" logSource="/remote-source/velero/app/pkg/cmd/server/server.go:777"
time="2022-12-09T10:50:42Z" level=info msg="Server starting..." logSource="/remote-source/velero/app/pkg/cmd/server/server.go:886"
time="2022-12-09T10:50:42Z" level=info msg="Starting server" addr="{\"IP\":\"::\",\"Port\":8080,\"Zone\":\"\"}" kind=metrics logSource="/remote-source/velero/deps/gomod/pkg/mod/github.com/bombsimon/logrusr/v3@v3.0.0/logrusr.go:108" path=/metrics
time="2022-12-09T10:50:42Z" level=info msg="Starting controller" controller=backup logSource="/remote-source/velero/app/pkg/controller/generic_controller.go:76"
time="2022-12-09T10:50:42Z" level=info msg="Starting EventSource" controller=backupstoragelocation controllerGroup=velero.io controllerKind=BackupStorageLocation logSource="/remote-source/velero/deps/gomod/pkg/mod/github.com/bombsimon/logrusr/v3@v3.0.0/logrusr.go:108" source="kind source: *v1.BackupStorageLocation"
time="2022-12-09T10:50:42Z" level=info msg="Starting EventSource" controller=backupstoragelocation controllerGroup=velero.io controllerKind=BackupStorageLocation logSource="/remote-source/velero/deps/gomod/pkg/mod/github.com/bombsimon/logrusr/v3@v3.0.0/logrusr.go:108" source="kind source: *v1.BackupStorageLocationList"
time="2022-12-09T10:50:42Z" level=info msg="Starting Controller" controller=backupstoragelocation controllerGroup=velero.io controllerKind=BackupStorageLocation logSource="/remote-source/velero/deps/gomod/pkg/mod/github.com/bombsimon/logrusr/v3@v3.0.0/logrusr.go:108"
time="2022-12-09T10:50:42Z" level=info msg="Starting EventSource" controller=downloadrequest controllerGroup=velero.io controllerKind=DownloadRequest logSource="/remote-source/velero/deps/gomod/pkg/mod/github.com/bombsimon/logrusr/v3@v3.0.0/logrusr.go:108" source="kind source: *v1.DownloadRequest"
time="2022-12-09T10:50:42Z" level=info msg="Starting controller" controller=restore logSource="/remote-source/velero/app/pkg/controller/generic_controller.go:76"
time="2022-12-09T10:50:42Z" level=info msg="Starting EventSource" controller=schedule controllerGroup=velero.io controllerKind=Schedule logSource="/remote-source/velero/deps/gomod/pkg/mod/github.com/bombsimon/logrusr/v3@v3.0.0/logrusr.go:108" source="kind source: *v1.Schedule"
time="2022-12-09T10:50:42Z" level=info msg="Starting Controller" controller=downloadrequest controllerGroup=velero.io controllerKind=DownloadRequest logSource="/remote-source/velero/deps/gomod/pkg/mod/github.com/bombsimon/logrusr/v3@v3.0.0/logrusr.go:108"
time="2022-12-09T10:50:42Z" level=info msg="Starting EventSource" controller=schedule controllerGroup=velero.io controllerKind=Schedule logSource="/remote-source/velero/deps/gomod/pkg/mod/github.com/bombsimon/logrusr/v3@v3.0.0/logrusr.go:108" source="kind source: *v1.ScheduleList"
time="2022-12-09T10:50:42Z" level=info msg="Starting EventSource" controller=backup controllerGroup=velero.io controllerKind=Backup logSource="/remote-source/velero/deps/gomod/pkg/mod/github.com/bombsimon/logrusr/v3@v3.0.0/logrusr.go:108" source="kind source: *v1.Backup"
time="2022-12-09T10:50:42Z" level=info msg="Starting Controller" controller=schedule controllerGroup=velero.io controllerKind=Schedule logSource="/remote-source/velero/deps/gomod/pkg/mod/github.com/bombsimon/logrusr/v3@v3.0.0/logrusr.go:108"
time="2022-12-09T10:50:42Z" level=info msg="Starting EventSource" controller=backup controllerGroup=velero.io controllerKind=Backup logSource="/remote-source/velero/deps/gomod/pkg/mod/github.com/bombsimon/logrusr/v3@v3.0.0/logrusr.go:108" source="kind source: *v1.BackupList"
time="2022-12-09T10:50:42Z" level=info msg="Starting Controller" controller=backup controllerGroup=velero.io controllerKind=Backup logSource="/remote-source/velero/deps/gomod/pkg/mod/github.com/bombsimon/logrusr/v3@v3.0.0/logrusr.go:108"
time="2022-12-09T10:50:42Z" level=info msg="Starting EventSource" controller=backuprepository controllerGroup=velero.io controllerKind=BackupRepository logSource="/remote-source/velero/deps/gomod/pkg/mod/github.com/bombsimon/logrusr/v3@v3.0.0/logrusr.go:108" source="kind source: *v1.BackupRepository"
time="2022-12-09T10:50:42Z" level=info msg="Starting EventSource" controller=backuprepository controllerGroup=velero.io controllerKind=BackupRepository logSource="/remote-source/velero/deps/gomod/pkg/mod/github.com/bombsimon/logrusr/v3@v3.0.0/logrusr.go:108" source="kind source: *v1.BackupRepositoryList"
time="2022-12-09T10:50:42Z" level=info msg="Starting EventSource" controller=backupstoragelocation controllerGroup=velero.io controllerKind=BackupStorageLocation logSource="/remote-source/velero/deps/gomod/pkg/mod/github.com/bombsimon/logrusr/v3@v3.0.0/logrusr.go:108" source="kind source: *v1.BackupStorageLocation"
time="2022-12-09T10:50:42Z" level=info msg="Starting Controller" controller=backuprepository controllerGroup=velero.io controllerKind=BackupRepository logSource="/remote-source/velero/deps/gomod/pkg/mod/github.com/bombsimon/logrusr/v3@v3.0.0/logrusr.go:108"
E1209 10:50:42.353187       1 runtime.go:79] Observed a panic: "invalid memory address or nil pointer dereference" (runtime error: invalid memory address or nil pointer dereference)
goroutine 1517 [running]:
k8s.io/apimachinery/pkg/util/runtime.logPanic({0x21f27a0?, 0x3d197d0})
    /remote-source/velero/deps/gomod/pkg/mod/k8s.io/apimachinery@v0.24.2/pkg/util/runtime/runtime.go:75 +0x99
k8s.io/apimachinery/pkg/util/runtime.HandleCrash({0x0, 0x0, 0xc000424030?})
    /remote-source/velero/deps/gomod/pkg/mod/k8s.io/apimachinery@v0.24.2/pkg/util/runtime/runtime.go:49 +0x75
panic({0x21f27a0, 0x3d197d0})
    /usr/lib/golang/src/runtime/panic.go:884 +0x212
github.com/vmware-tanzu/velero/pkg/controller.(*restoreController).validateAndComplete(0xc0006f20d0, 0xc0010be780, {0x2aba440, 0xc000596d20})
    /remote-source/velero/app/pkg/controller/restore_controller.go:345 +0xc5b
github.com/vmware-tanzu/velero/pkg/controller.(*restoreController).processRestore(0xc0006f20d0, 0xc0010be780)
    /remote-source/velero/app/pkg/controller/restore_controller.go:241 +0x117
github.com/vmware-tanzu/velero/pkg/controller.(*restoreController).processQueueItem(0xc0006f20d0, {0xc000f6a140, 0x42})
    /remote-source/velero/app/pkg/controller/restore_controller.go:224 +0x30c
github.com/vmware-tanzu/velero/pkg/controller.(*genericController).processNextWorkItem(0xc00036b020)
    /remote-source/velero/app/pkg/controller/generic_controller.go:132 +0xeb
github.com/vmware-tanzu/velero/pkg/controller.(*genericController).runWorker(0xc001135ea8?)
    /remote-source/velero/app/pkg/controller/generic_controller.go:119 +0x25
k8s.io/apimachinery/pkg/util/wait.BackoffUntil.func1(0x1?)
    /remote-source/velero/deps/gomod/pkg/mod/k8s.io/apimachinery@v0.24.2/pkg/util/wait/wait.go:155 +0x3e
k8s.io/apimachinery/pkg/util/wait.BackoffUntil(0xc00007dd00?, {0x2a8ef20, 0xc000d57e00}, 0x1, 0xc0007b0180)
    /remote-source/velero/deps/gomod/pkg/mod/k8s.io/apimachinery@v0.24.2/pkg/util/wait/wait.go:156 +0xb6
k8s.io/apimachinery/pkg/util/wait.JitterUntil(0x99336e?, 0x3b9aca00, 0x0, 0x5?, 0xc000f57680?)
    /remote-source/velero/deps/gomod/pkg/mod/k8s.io/apimachinery@v0.24.2/pkg/util/wait/wait.go:133 +0x89
k8s.io/apimachinery/pkg/util/wait.Until(...)
    /remote-source/velero/deps/gomod/pkg/mod/k8s.io/apimachinery@v0.24.2/pkg/util/wait/wait.go:90
github.com/vmware-tanzu/velero/pkg/controller.(*genericController).Run.func2()
    /remote-source/velero/app/pkg/controller/generic_controller.go:92 +0x6e
created by github.com/vmware-tanzu/velero/pkg/controller.(*genericController).Run
    /remote-source/velero/app/pkg/controller/generic_controller.go:91 +0x45a
panic: runtime error: invalid memory address or nil pointer dereference [recovered]
    panic: runtime error: invalid memory address or nil pointer dereference
[signal SIGSEGV: segmentation violation code=0x1 addr=0x8 pc=0x1f0ec1b]
goroutine 1517 [running]:
k8s.io/apimachinery/pkg/util/runtime.HandleCrash({0x0, 0x0, 0xc000424030?})
    /remote-source/velero/deps/gomod/pkg/mod/k8s.io/apimachinery@v0.24.2/pkg/util/runtime/runtime.go:56 +0xd7
panic({0x21f27a0, 0x3d197d0})
    /usr/lib/golang/src/runtime/panic.go:884 +0x212
github.com/vmware-tanzu/velero/pkg/controller.(*restoreController).validateAndComplete(0xc0006f20d0, 0xc0010be780, {0x2aba440, 0xc000596d20})
    /remote-source/velero/app/pkg/controller/restore_controller.go:345 +0xc5b
github.com/vmware-tanzu/velero/pkg/controller.(*restoreController).processRestore(0xc0006f20d0, 0xc0010be780)
    /remote-source/velero/app/pkg/controller/restore_controller.go:241 +0x117
github.com/vmware-tanzu/velero/pkg/controller.(*restoreController).processQueueItem(0xc0006f20d0, {0xc000f6a140, 0x42})
    /remote-source/velero/app/pkg/controller/restore_controller.go:224 +0x30c
github.com/vmware-tanzu/velero/pkg/controller.(*genericController).processNextWorkItem(0xc00036b020)
    /remote-source/velero/app/pkg/controller/generic_controller.go:132 +0xeb
github.com/vmware-tanzu/velero/pkg/controller.(*genericController).runWorker(0xc001135ea8?)
    /remote-source/velero/app/pkg/controller/generic_controller.go:119 +0x25
k8s.io/apimachinery/pkg/util/wait.BackoffUntil.func1(0x1?)
    /remote-source/velero/deps/gomod/pkg/mod/k8s.io/apimachinery@v0.24.2/pkg/util/wait/wait.go:155 +0x3e
k8s.io/apimachinery/pkg/util/wait.BackoffUntil(0xc00007dd00?, {0x2a8ef20, 0xc000d57e00}, 0x1, 0xc0007b0180)
    /remote-source/velero/deps/gomod/pkg/mod/k8s.io/apimachinery@v0.24.2/pkg/util/wait/wait.go:156 +0xb6
k8s.io/apimachinery/pkg/util/wait.JitterUntil(0x99336e?, 0x3b9aca00, 0x0, 0x5?, 0xc000f57680?)
    /remote-source/velero/deps/gomod/pkg/mod/k8s.io/apimachinery@v0.24.2/pkg/util/wait/wait.go:133 +0x89
k8s.io/apimachinery/pkg/util/wait.Until(...)
    /remote-source/velero/deps/gomod/pkg/mod/k8s.io/apimachinery@v0.24.2/pkg/util/wait/wait.go:90
github.com/vmware-tanzu/velero/pkg/controller.(*genericController).Run.func2()
    /remote-source/velero/app/pkg/controller/generic_controller.go:92 +0x6e
created by github.com/vmware-tanzu/velero/pkg/controller.(*genericController).Run
    /remote-source/velero/app/pkg/controller/generic_controller.go:91 +0x45a

      Expected results:
      Restore should be successful.

      Additional info:

      Backup hook case passed https://reportportal-migration-qe.apps.ocp-c1.prod.psi.redhat.com/ui/#oadp/launches/all/2441/82365/log?item0Params=filter.eq.hasStats%3Dtrue%26filter.eq.hasChildren%3Dfalse%26filter.in.type%3DSTEP%26filter.in.status%3DPASSED

      Attachments

        Activity

          People

            spampatt@redhat.com Shubham Pampattiwar
            rhn-support-prajoshi Prasad Joshi
            Votes:
            0 Vote for this issue
            Watchers:
            7 Start watching this issue

            Dates

              Created:
              Updated:
              Resolved: