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
  3. OADP-1091

[IBM QE-P] Verify Bug OADP-1076 - Velero pod going in crashLoopbackoff when restore hooks is specified

XMLWordPrintable

    • Icon: Sub-task Sub-task
    • Resolution: Done
    • Icon: Undefined Undefined
    • None
    • None
    • None
    • None
    • 4
    • False
    • Hide

      None

      Show
      None
    • False
    • ToDo
    • 0
    • 0.000
    • Very Likely
    • 0
    • None
    • Unset
    • Unknown

      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

        1. 1076.txt
          58 kB
          Sonia Garudi

              sgarudi Sonia Garudi
              mperetz@redhat.com Maya Peretz
              Votes:
              0 Vote for this issue
              Watchers:
              2 Start watching this issue

                Created:
                Updated:
                Resolved: