Backup and restore AKS cluster using velero failing

[Vrushk84]

Maintainer EDI (@ashish-amarnath): Updating markdown formatting

What steps did you take and what happened: Installed velero on existing and new AKS cluster. Took backup of the existing AKS cluster of a particular namespace. New AKS cluster points to the same storage location where backups of existing cluster exists. Tried to restore the backup on the new AKS cluster.

What did you expect to happen: Expected backup to restore on new AKS cluster

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.)

1. velero backup describe

   $ velero backup describe 
   Name:         elysiumanalytics-aks-tenant1-new
   Namespace:    velero
   Labels:       velero.io/storage-location=default
   Annotations:  velero.io/source-cluster-k8s-gitversion=v1.17.9
               velero.io/source-cluster-k8s-major-version=1
               velero.io/source-cluster-k8s-minor-version=17
   
   Phase:  Completed
   
   Errors:    0
   Warnings:  0
   
   Namespaces:
   Included:  tenant1
   Excluded:  <none>
   
   Resources:
   Included:        *
   Excluded:        <none>
   Cluster-scoped:  auto
   
   Label selector:  <none>
   
   Storage Location:  default
   
   Velero-Native Snapshot PVs:  auto
   
   TTL:  720h0m0s
   
   Hooks:  <none>
   
   Backup Format Version:  1
   
   Started:    2020-08-25 19:36:28 +0000 UTC
   Completed:  2020-08-25 19:36:33 +0000 UTC
   
   Expiration:  2020-09-24 19:36:28 +0000 UTC
   
   Total items to be backed up:  4019
   Items backed up:              4019
   
   Velero-Native Snapshots: <none included>

2. backup yaml

   $ kubectl get backup/elysiumanalytics-aks-tenant1-new -n velero -o yaml
   
   apiVersion: velero.io/v1
   kind: Backup
   metadata:
   annotations:
       velero.io/source-cluster-k8s-gitversion: v1.17.9
       velero.io/source-cluster-k8s-major-version: "1"
       velero.io/source-cluster-k8s-minor-version: "17"
   creationTimestamp: "2020-08-25T19:36:28Z"
   generation: 8
   labels:
       velero.io/storage-location: default
   name: elysiumanalytics-aks-tenant1-new
   namespace: velero
   resourceVersion: "54411264"
   selfLink: /apis/velero.io/v1/namespaces/velero/backups/elysiumanalytics-aks-tenant1-new
   uid: 96dc92c6-600c-4074-8c5d-ac46c4b146fc
   spec:
   hooks: {}
   includedNamespaces:
   - tenant1
   storageLocation: default
   ttl: 720h0m0s
   volumeSnapshotLocations:
   - default
   status:
   completionTimestamp: "2020-08-25T19:36:33Z"
   expiration: "2020-09-24T19:36:28Z"
   formatVersion: 1.1.0
   phase: Completed
   progress:
       itemsBackedUp: 4019
       totalItems: 4019
   startTimestamp: "2020-08-25T19:36:28Z"
   version: 1

3. restore yaml

   $ kubectl get restore/tenant1backup -n velero -o yaml
   apiVersion: velero.io/v1
   kind: Restore
   metadata:
   creationTimestamp: "2020-08-25T20:35:58Z"
   generation: 3
   name: tenant1backup
   namespace: velero
   resourceVersion: "16897"
   selfLink: /apis/velero.io/v1/namespaces/velero/restores/tenant1backup
   uid: 90c27e04-336e-4360-9fa8-02ab8f8f56c4
   spec:
   backupName: elysiumanalytics-aks-tenant1-new
   excludedResources:
   - nodes
   - events
   - events.events.k8s.io
   - backups.velero.io
   - restores.velero.io
   - resticrepositories.velero.io
   includedNamespaces:
   - '*'
   status:
   phase: Completed
   warnings: 2

4. velero restore logs tenant1backup

   time="2020-08-25T20:35:58Z" level=info msg="starting restore" logSource="pkg/controller/restore_controller.go:453" restore=velero/tenant1backup
   time="2020-08-25T20:35:58Z" level=info msg="Starting restore of backup velero/elysiumanalytics-aks-tenant1-new" logSource="pkg/restore/restore.go:345" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Restoring cluster level resource 'customresourcedefinitions.apiextensions.k8s.io'" logSource="pkg/restore/restore.go:704" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Getting client for apiextensions.k8s.io/v1beta1, Kind=CustomResourceDefinition" logSource="pkg/restore/restore.go:746" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Executing item action for customresourcedefinitions.apiextensions.k8s.io" logSource="pkg/restore/restore.go:964" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Executing CRDV1PreserveUnknownFieldsAction" cmd=/velero logSource="pkg/restore/crd_v1_preserve_unknown_fields_action.go:49" pluginName=velero restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Attempting to restore CustomResourceDefinition: backups.velero.io" logSource="pkg/restore/restore.go:1070" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Skipping restore of resource because it cannot be resolved via discovery" logSource="pkg/restore/restore.go:383" resource=volumesnapshotclass.snapshot.storage.k8s.io restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Skipping restore of resource because it cannot be resolved via discovery" logSource="pkg/restore/restore.go:383" resource=volumesnapshotcontents.snapshot.storage.k8s.io restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Skipping restore of resource because it cannot be resolved via discovery" logSource="pkg/restore/restore.go:383" resource=volumesnapshots.snapshot.storage.k8s.io restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Restoring cluster level resource 'persistentvolumes'" logSource="pkg/restore/restore.go:704" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Getting client for /v1, Kind=PersistentVolume" logSource="pkg/restore/restore.go:746" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Restoring persistent volume as-is because it doesn't have a snapshot and its reclaim policy is not Delete." logSource="pkg/restore/restore.go:940" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="No snapshot found for persistent volume" logSource="pkg/restore/pv_restorer.go:81" persistentVolume=datadrive restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Executing item action for persistentvolumes" logSource="pkg/restore/restore.go:964" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Executing ChangeStorageClassAction" cmd=/velero logSource="pkg/restore/change_storageclass_action.go:63" pluginName=velero restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Done executing ChangeStorageClassAction" cmd=/velero logSource="pkg/restore/change_storageclass_action.go:74" pluginName=velero restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Attempting to restore PersistentVolume: datadrive" logSource="pkg/restore/restore.go:1070" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Restoring resource 'persistentvolumeclaims' into namespace 'tenant1'" logSource="pkg/restore/restore.go:702" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Getting client for /v1, Kind=PersistentVolumeClaim" logSource="pkg/restore/restore.go:746" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Executing item action for persistentvolumeclaims" logSource="pkg/restore/restore.go:964" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Executing AddPVFromPVCAction" cmd=/velero logSource="pkg/restore/add_pv_from_pvc_action.go:44" pluginName=velero restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Adding PV datadrive as an additional item to restore" cmd=/velero logSource="pkg/restore/add_pv_from_pvc_action.go:66" pluginName=velero restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Skipping persistentvolumes/datadrive because it's already been restored." logSource="pkg/restore/restore.go:844" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Executing item action for persistentvolumeclaims" logSource="pkg/restore/restore.go:964" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Executing ChangePVCNodeSelectorAction" cmd=/velero logSource="pkg/restore/change_pvc_node_selector.go:63" pluginName=velero restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Done executing ChangePVCNodeSelectorAction" cmd=/velero logSource="pkg/restore/change_pvc_node_selector.go:91" pluginName=velero restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Executing item action for persistentvolumeclaims" logSource="pkg/restore/restore.go:964" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Executing ChangeStorageClassAction" cmd=/velero logSource="pkg/restore/change_storageclass_action.go:63" pluginName=velero restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Done executing ChangeStorageClassAction" cmd=/velero logSource="pkg/restore/change_storageclass_action.go:74" pluginName=velero restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Attempting to restore PersistentVolumeClaim: datadrive" logSource="pkg/restore/restore.go:1070" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Restoring resource 'secrets' into namespace 'tenant1'" logSource="pkg/restore/restore.go:702" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Getting client for /v1, Kind=Secret" logSource="pkg/restore/restore.go:746" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Attempting to restore Secret: default-token-kpt49" logSource="pkg/restore/restore.go:1070" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Restoring resource 'serviceaccounts' into namespace 'tenant1'" logSource="pkg/restore/restore.go:702" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Getting client for /v1, Kind=ServiceAccount" logSource="pkg/restore/restore.go:746" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Executing item action for serviceaccounts" logSource="pkg/restore/restore.go:964" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Executing ServiceAccountAction" cmd=/velero logSource="pkg/restore/service_account_action.go:47" pluginName=velero restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Done executing ServiceAccountAction" cmd=/velero logSource="pkg/restore/service_account_action.go:78" pluginName=velero restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Attempting to restore ServiceAccount: default" logSource="pkg/restore/restore.go:1070" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Restoring resource 'pods' into namespace 'tenant1'" logSource="pkg/restore/restore.go:702" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Getting client for /v1, Kind=Pod" logSource="pkg/restore/restore.go:746" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Executing item action for pods" logSource="pkg/restore/restore.go:964" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Executing AddPVCFromPodAction" cmd=/velero logSource="pkg/restore/add_pvc_from_pod_action.go:44" pluginName=velero restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Adding PVC tenant1/datadrive as an additional item to restore" cmd=/velero logSource="pkg/restore/add_pvc_from_pod_action.go:58" pluginName=velero restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Skipping persistentvolumeclaims/tenant1/datadrive because it's already been restored." logSource="pkg/restore/restore.go:844" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Executing item action for pods" logSource="pkg/restore/restore.go:964" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Executing item action for pods" logSource="pkg/restore/restore.go:964" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Executing ResticRestoreAction" cmd=/velero logSource="pkg/restore/restic_restore_action.go:69" pluginName=velero restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Done executing ResticRestoreAction" cmd=/velero logSource="pkg/restore/restic_restore_action.go:92" pluginName=velero restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Attempting to restore Pod: elysuim-logstash-d44894f8f-4vr62" logSource="pkg/restore/restore.go:1070" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Executing item action for pods" logSource="pkg/restore/restore.go:964" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Executing AddPVCFromPodAction" cmd=/velero logSource="pkg/restore/add_pvc_from_pod_action.go:44" pluginName=velero restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Adding PVC tenant1/datadrive as an additional item to restore" cmd=/velero logSource="pkg/restore/add_pvc_from_pod_action.go:58" pluginName=velero restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Skipping persistentvolumeclaims/tenant1/datadrive because it's already been restored." logSource="pkg/restore/restore.go:844" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Executing item action for pods" logSource="pkg/restore/restore.go:964" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Executing item action for pods" logSource="pkg/restore/restore.go:964" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Executing ResticRestoreAction" cmd=/velero logSource="pkg/restore/restic_restore_action.go:69" pluginName=velero restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Done executing ResticRestoreAction" cmd=/velero logSource="pkg/restore/restic_restore_action.go:92" pluginName=velero restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Attempting to restore Pod: elysuim-logstash-d44894f8f-hvzk8" logSource="pkg/restore/restore.go:1070" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Executing item action for pods" logSource="pkg/restore/restore.go:964" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Executing AddPVCFromPodAction" cmd=/velero logSource="pkg/restore/add_pvc_from_pod_action.go:44" pluginName=velero restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Adding PVC tenant1/datadrive as an additional item to restore" cmd=/velero logSource="pkg/restore/add_pvc_from_pod_action.go:58" pluginName=velero restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Skipping persistentvolumeclaims/tenant1/datadrive because it's already been restored." logSource="pkg/restore/restore.go:844" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Executing item action for pods" logSource="pkg/restore/restore.go:964" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Executing item action for pods" logSource="pkg/restore/restore.go:964" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Executing ResticRestoreAction" cmd=/velero logSource="pkg/restore/restic_restore_action.go:69" pluginName=velero restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Done executing ResticRestoreAction" cmd=/velero logSource="pkg/restore/restic_restore_action.go:92" pluginName=velero restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Attempting to restore Pod: elysuim-logstash-d44894f8f-p7rh9" logSource="pkg/restore/restore.go:1070" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Executing item action for pods" logSource="pkg/restore/restore.go:964" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Executing AddPVCFromPodAction" cmd=/velero logSource="pkg/restore/add_pvc_from_pod_action.go:44" pluginName=velero restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Adding PVC tenant1/datadrive as an additional item to restore" cmd=/velero logSource="pkg/restore/add_pvc_from_pod_action.go:58" pluginName=velero restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Skipping persistentvolumeclaims/tenant1/datadrive because it's already been restored." logSource="pkg/restore/restore.go:844" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Executing item action for pods" logSource="pkg/restore/restore.go:964" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Executing item action for pods" logSource="pkg/restore/restore.go:964" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Executing ResticRestoreAction" cmd=/velero logSource="pkg/restore/restic_restore_action.go:69" pluginName=velero restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Done executing ResticRestoreAction" cmd=/velero logSource="pkg/restore/restic_restore_action.go:92" pluginName=velero restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Attempting to restore Pod: elysuim-logstash-d44894f8f-s2jbf" logSource="pkg/restore/restore.go:1070" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="tenant1/source-data-extractor-prune-1598382300-vdlhw is complete - skipping" logSource="pkg/restore/restore.go:831" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="tenant1/source-data-extractor-upload-blob-iis-1598384100-x8nlr is complete - skipping" logSource="pkg/restore/restore.go:831" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Executing item action for pods" logSource="pkg/restore/restore.go:964" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Executing AddPVCFromPodAction" cmd=/velero logSource="pkg/restore/add_pvc_from_pod_action.go:44" pluginName=velero restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Adding PVC tenant1/datadrive as an additional item to restore" cmd=/velero logSource="pkg/restore/add_pvc_from_pod_action.go:58" pluginName=velero restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Skipping persistentvolumeclaims/tenant1/datadrive because it's already been restored." logSource="pkg/restore/restore.go:844" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Executing item action for pods" logSource="pkg/restore/restore.go:964" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Executing item action for pods" logSource="pkg/restore/restore.go:964" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Executing ResticRestoreAction" cmd=/velero logSource="pkg/restore/restic_restore_action.go:69" pluginName=velero restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Done executing ResticRestoreAction" cmd=/velero logSource="pkg/restore/restic_restore_action.go:92" pluginName=velero restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Attempting to restore Pod: source-data-extractor-upload-blob-iis-1598384160-z6jxw" logSource="pkg/restore/restore.go:1070" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="tenant1/source-data-extractor-upload-blob-msagent-1598384100-4cggm is complete - skipping" logSource="pkg/restore/restore.go:831" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Executing item action for pods" logSource="pkg/restore/restore.go:964" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Executing AddPVCFromPodAction" cmd=/velero logSource="pkg/restore/add_pvc_from_pod_action.go:44" pluginName=velero restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Adding PVC tenant1/datadrive as an additional item to restore" cmd=/velero logSource="pkg/restore/add_pvc_from_pod_action.go:58" pluginName=velero restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Skipping persistentvolumeclaims/tenant1/datadrive because it's already been restored." logSource="pkg/restore/restore.go:844" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Executing item action for pods" logSource="pkg/restore/restore.go:964" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Executing item action for pods" logSource="pkg/restore/restore.go:964" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Executing ResticRestoreAction" cmd=/velero logSource="pkg/restore/restic_restore_action.go:69" pluginName=velero restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Done executing ResticRestoreAction" cmd=/velero logSource="pkg/restore/restic_restore_action.go:92" pluginName=velero restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Attempting to restore Pod: source-data-extractor-upload-blob-msagent-1598384160-hrcjz" logSource="pkg/restore/restore.go:1070" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="tenant1/source-data-extractor-upload-blob-msconnectivity-159838410kx42w is complete - skipping" logSource="pkg/restore/restore.go:831" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Executing item action for pods" logSource="pkg/restore/restore.go:964" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Executing AddPVCFromPodAction" cmd=/velero logSource="pkg/restore/add_pvc_from_pod_action.go:44" pluginName=velero restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Adding PVC tenant1/datadrive as an additional item to restore" cmd=/velero logSource="pkg/restore/add_pvc_from_pod_action.go:58" pluginName=velero restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Skipping persistentvolumeclaims/tenant1/datadrive because it's already been restored." logSource="pkg/restore/restore.go:844" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Executing item action for pods" logSource="pkg/restore/restore.go:964" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Executing item action for pods" logSource="pkg/restore/restore.go:964" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Executing ResticRestoreAction" cmd=/velero logSource="pkg/restore/restic_restore_action.go:69" pluginName=velero restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Done executing ResticRestoreAction" cmd=/velero logSource="pkg/restore/restic_restore_action.go:92" pluginName=velero restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Attempting to restore Pod: source-data-extractor-upload-blob-msconnectivity-1598384166jzn4" logSource="pkg/restore/restore.go:1070" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="tenant1/source-data-extractor-upload-blob-msexchange-1598384100-kpmkb is complete - skipping" logSource="pkg/restore/restore.go:831" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Executing item action for pods" logSource="pkg/restore/restore.go:964" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Executing AddPVCFromPodAction" cmd=/velero logSource="pkg/restore/add_pvc_from_pod_action.go:44" pluginName=velero restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Adding PVC tenant1/datadrive as an additional item to restore" cmd=/velero logSource="pkg/restore/add_pvc_from_pod_action.go:58" pluginName=velero restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Skipping persistentvolumeclaims/tenant1/datadrive because it's already been restored." logSource="pkg/restore/restore.go:844" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Executing item action for pods" logSource="pkg/restore/restore.go:964" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Executing item action for pods" logSource="pkg/restore/restore.go:964" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Executing ResticRestoreAction" cmd=/velero logSource="pkg/restore/restic_restore_action.go:69" pluginName=velero restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Done executing ResticRestoreAction" cmd=/velero logSource="pkg/restore/restic_restore_action.go:92" pluginName=velero restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Attempting to restore Pod: source-data-extractor-upload-blob-msexchange-1598384160-l99z6" logSource="pkg/restore/restore.go:1070" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="tenant1/source-data-extractor-upload-blob-netflow-1598384100-g29mf is complete - skipping" logSource="pkg/restore/restore.go:831" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Executing item action for pods" logSource="pkg/restore/restore.go:964" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Executing AddPVCFromPodAction" cmd=/velero logSource="pkg/restore/add_pvc_from_pod_action.go:44" pluginName=velero restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Adding PVC tenant1/datadrive as an additional item to restore" cmd=/velero logSource="pkg/restore/add_pvc_from_pod_action.go:58" pluginName=velero restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Skipping persistentvolumeclaims/tenant1/datadrive because it's already been restored." logSource="pkg/restore/restore.go:844" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Executing item action for pods" logSource="pkg/restore/restore.go:964" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Executing item action for pods" logSource="pkg/restore/restore.go:964" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Executing ResticRestoreAction" cmd=/velero logSource="pkg/restore/restic_restore_action.go:69" pluginName=velero restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Done executing ResticRestoreAction" cmd=/velero logSource="pkg/restore/restic_restore_action.go:92" pluginName=velero restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Attempting to restore Pod: source-data-extractor-upload-blob-netflow-1598384160-pdzdp" logSource="pkg/restore/restore.go:1070" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="tenant1/source-data-extractor-upload-blob-snp-1598384100-wmknr is complete - skipping" logSource="pkg/restore/restore.go:831" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Executing item action for pods" logSource="pkg/restore/restore.go:964" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Executing AddPVCFromPodAction" cmd=/velero logSource="pkg/restore/add_pvc_from_pod_action.go:44" pluginName=velero restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Adding PVC tenant1/datadrive as an additional item to restore" cmd=/velero logSource="pkg/restore/add_pvc_from_pod_action.go:58" pluginName=velero restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Skipping persistentvolumeclaims/tenant1/datadrive because it's already been restored." logSource="pkg/restore/restore.go:844" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Executing item action for pods" logSource="pkg/restore/restore.go:964" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Executing item action for pods" logSource="pkg/restore/restore.go:964" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Executing ResticRestoreAction" cmd=/velero logSource="pkg/restore/restic_restore_action.go:69" pluginName=velero restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Done executing ResticRestoreAction" cmd=/velero logSource="pkg/restore/restic_restore_action.go:92" pluginName=velero restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Attempting to restore Pod: source-data-extractor-upload-blob-snp-1598384160-mmstd" logSource="pkg/restore/restore.go:1070" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="tenant1/source-data-extractor-upload-blob-sysmon-1598384100-xfs5h is complete - skipping" logSource="pkg/restore/restore.go:831" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Executing item action for pods" logSource="pkg/restore/restore.go:964" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Executing AddPVCFromPodAction" cmd=/velero logSource="pkg/restore/add_pvc_from_pod_action.go:44" pluginName=velero restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Adding PVC tenant1/datadrive as an additional item to restore" cmd=/velero logSource="pkg/restore/add_pvc_from_pod_action.go:58" pluginName=velero restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Skipping persistentvolumeclaims/tenant1/datadrive because it's already been restored." logSource="pkg/restore/restore.go:844" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Executing item action for pods" logSource="pkg/restore/restore.go:964" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Executing item action for pods" logSource="pkg/restore/restore.go:964" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Executing ResticRestoreAction" cmd=/velero logSource="pkg/restore/restic_restore_action.go:69" pluginName=velero restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Done executing ResticRestoreAction" cmd=/velero logSource="pkg/restore/restic_restore_action.go:92" pluginName=velero restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Attempting to restore Pod: source-data-extractor-upload-blob-sysmon-1598384160-7k8vg" logSource="pkg/restore/restore.go:1070" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="tenant1/source-data-extractor-upload-blob-wgdhcp-1598384100-72dbp is complete - skipping" logSource="pkg/restore/restore.go:831" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Executing item action for pods" logSource="pkg/restore/restore.go:964" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Executing AddPVCFromPodAction" cmd=/velero logSource="pkg/restore/add_pvc_from_pod_action.go:44" pluginName=velero restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Adding PVC tenant1/datadrive as an additional item to restore" cmd=/velero logSource="pkg/restore/add_pvc_from_pod_action.go:58" pluginName=velero restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Skipping persistentvolumeclaims/tenant1/datadrive because it's already been restored." logSource="pkg/restore/restore.go:844" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Executing item action for pods" logSource="pkg/restore/restore.go:964" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Executing item action for pods" logSource="pkg/restore/restore.go:964" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Executing ResticRestoreAction" cmd=/velero logSource="pkg/restore/restic_restore_action.go:69" pluginName=velero restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Done executing ResticRestoreAction" cmd=/velero logSource="pkg/restore/restic_restore_action.go:92" pluginName=velero restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Attempting to restore Pod: source-data-extractor-upload-blob-wgdhcp-1598384160-fqtmc" logSource="pkg/restore/restore.go:1070" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="tenant1/source-data-extractor-upload-blob-wgevents-1598384100-cftnp is complete - skipping" logSource="pkg/restore/restore.go:831" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Executing item action for pods" logSource="pkg/restore/restore.go:964" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Executing AddPVCFromPodAction" cmd=/velero logSource="pkg/restore/add_pvc_from_pod_action.go:44" pluginName=velero restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Adding PVC tenant1/datadrive as an additional item to restore" cmd=/velero logSource="pkg/restore/add_pvc_from_pod_action.go:58" pluginName=velero restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Skipping persistentvolumeclaims/tenant1/datadrive because it's already been restored." logSource="pkg/restore/restore.go:844" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Executing item action for pods" logSource="pkg/restore/restore.go:964" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Executing item action for pods" logSource="pkg/restore/restore.go:964" restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Executing ResticRestoreAction" cmd=/velero logSource="pkg/restore/restic_restore_action.go:69" pluginName=velero restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Done executing ResticRestoreAction" cmd=/velero logSource="pkg/restore/restic_restore_action.go:92" pluginName=velero restore=velero/tenant1backup
   time="2020-08-25T20:35:59Z" level=info msg="Attempting to restore Pod: source-data-extractor-upload-blob-wgevents-1598384160-cxgc4" logSource="pkg/restore/restore.go:1070" restore=velero/tenant1backup
   time="2020-08-25T20:36:00Z" level=info msg="tenant1/source-data-extractor-upload-blob-wgtraffic-1598384100-spbwn is complete - skipping" logSource="pkg/restore/restore.go:831" restore=velero/tenant1backup
   time="2020-08-25T20:36:00Z" level=info msg="Executing item action for pods" logSource="pkg/restore/restore.go:964" restore=velero/tenant1backup
   time="2020-08-25T20:36:00Z" level=info msg="Executing AddPVCFromPodAction" cmd=/velero logSource="pkg/restore/add_pvc_from_pod_action.go:44" pluginName=velero restore=velero/tenant1backup
   time="2020-08-25T20:36:00Z" level=info msg="Adding PVC tenant1/datadrive as an additional item to restore" cmd=/velero logSource="pkg/restore/add_pvc_from_pod_action.go:58" pluginName=velero restore=velero/tenant1backup
   time="2020-08-25T20:36:00Z" level=info msg="Skipping persistentvolumeclaims/tenant1/datadrive because it's already been restored." logSource="pkg/restore/restore.go:844" restore=velero/tenant1backup
   time="2020-08-25T20:36:00Z" level=info msg="Executing item action for pods" logSource="pkg/restore/restore.go:964" restore=velero/tenant1backup
   time="2020-08-25T20:36:00Z" level=info msg="Executing item action for pods" logSource="pkg/restore/restore.go:964" restore=velero/tenant1backup
   time="2020-08-25T20:36:00Z" level=info msg="Executing ResticRestoreAction" cmd=/velero logSource="pkg/restore/restic_restore_action.go:69" pluginName=velero restore=velero/tenant1backup
   time="2020-08-25T20:36:00Z" level=info msg="Done executing ResticRestoreAction" cmd=/velero logSource="pkg/restore/restic_restore_action.go:92" pluginName=velero restore=velero/tenant1backup
   time="2020-08-25T20:36:00Z" level=info msg="Attempting to restore Pod: source-data-extractor-upload-blob-wgtraffic-1598384160-rd45x" logSource="pkg/restore/restore.go:1070" restore=velero/tenant1backup
   time="2020-08-25T20:36:00Z" level=info msg="tenant1/source-data-extractor-upload-blob-windowsnxlog-1598384100-4h8cp is complete - skipping" logSource="pkg/restore/restore.go:831" restore=velero/tenant1backup
   time="2020-08-25T20:36:00Z" level=info msg="Executing item action for pods" logSource="pkg/restore/restore.go:964" restore=velero/tenant1backup
   time="2020-08-25T20:36:00Z" level=info msg="Executing AddPVCFromPodAction" cmd=/velero logSource="pkg/restore/add_pvc_from_pod_action.go:44" pluginName=velero restore=velero/tenant1backup
   time="2020-08-25T20:36:00Z" level=info msg="Adding PVC tenant1/datadrive as an additional item to restore" cmd=/velero logSource="pkg/restore/add_pvc_from_pod_action.go:58" pluginName=velero restore=velero/tenant1backup
   time="2020-08-25T20:36:00Z" level=info msg="Skipping persistentvolumeclaims/tenant1/datadrive because it's already been restored." logSource="pkg/restore/restore.go:844" restore=velero/tenant1backup
   time="2020-08-25T20:36:00Z" level=info msg="Executing item action for pods" logSource="pkg/restore/restore.go:964" restore=velero/tenant1backup
   time="2020-08-25T20:36:00Z" level=info msg="Executing item action for pods" logSource="pkg/restore/restore.go:964" restore=velero/tenant1backup
   time="2020-08-25T20:36:00Z" level=info msg="Executing ResticRestoreAction" cmd=/velero logSource="pkg/restore/restic_restore_action.go:69" pluginName=velero restore=velero/tenant1backup
   time="2020-08-25T20:36:00Z" level=info msg="Done executing ResticRestoreAction" cmd=/velero logSource="pkg/restore/restic_restore_action.go:92" pluginName=velero restore=velero/tenant1backup
   time="2020-08-25T20:36:00Z" level=info msg="Attempting to restore Pod: source-data-extractor-upload-blob-windowsnxlog-1598384160-scbt4" logSource="pkg/restore/restore.go:1070" restore=velero/tenant1backup
   time="2020-08-25T20:36:00Z" level=info msg="Restoring resource 'replicasets.apps' into namespace 'tenant1'" logSource="pkg/restore/restore.go:702" restore=velero/tenant1backup
   time="2020-08-25T20:36:00Z" level=info msg="Getting client for apps/v1, Kind=ReplicaSet" logSource="pkg/restore/restore.go:746" restore=velero/tenant1backup
   time="2020-08-25T20:36:00Z" level=info msg="Attempting to restore ReplicaSet: elysuim-logstash-d44894f8f" logSource="pkg/restore/restore.go:1070" restore=velero/tenant1backup
   time="2020-08-25T20:36:00Z" level=info msg="Skipping restore of resource because the restore spec excludes it" logSource="pkg/restore/restore.go:398" resource=backups.velero.io restore=velero/tenant1backup
   time="2020-08-25T20:36:00Z" level=info msg="Restoring resource 'cronjobs.batch' into namespace 'tenant1'" logSource="pkg/restore/restore.go:702" restore=velero/tenant1backup
   time="2020-08-25T20:36:00Z" level=info msg="Getting client for batch/v1beta1, Kind=CronJob" logSource="pkg/restore/restore.go:746" restore=velero/tenant1backup
   time="2020-08-25T20:36:00Z" level=info msg="Attempting to restore CronJob: source-data-extractor-monitor-metrics" logSource="pkg/restore/restore.go:1070" restore=velero/tenant1backup
   time="2020-08-25T20:36:00Z" level=info msg="Attempting to restore CronJob: source-data-extractor-monitor-size-metrics" logSource="pkg/restore/restore.go:1070" restore=velero/tenant1backup
   time="2020-08-25T20:36:00Z" level=info msg="Attempting to restore CronJob: source-data-extractor-prune" logSource="pkg/restore/restore.go:1070" restore=velero/tenant1backup
   time="2020-08-25T20:36:00Z" level=info msg="Attempting to restore CronJob: source-data-extractor-upload-blob-iis" logSource="pkg/restore/restore.go:1070" restore=velero/tenant1backup
   time="2020-08-25T20:36:00Z" level=info msg="Attempting to restore CronJob: source-data-extractor-upload-blob-msagent" logSource="pkg/restore/restore.go:1070" restore=velero/tenant1backup
   time="2020-08-25T20:36:00Z" level=info msg="Attempting to restore CronJob: source-data-extractor-upload-blob-msconnectivity" logSource="pkg/restore/restore.go:1070" restore=velero/tenant1backup
   time="2020-08-25T20:36:00Z" level=info msg="Attempting to restore CronJob: source-data-extractor-upload-blob-msexchange" logSource="pkg/restore/restore.go:1070" restore=velero/tenant1backup
   time="2020-08-25T20:36:00Z" level=info msg="Attempting to restore CronJob: source-data-extractor-upload-blob-netflow" logSource="pkg/restore/restore.go:1070" restore=velero/tenant1backup
   time="2020-08-25T20:36:00Z" level=info msg="Attempting to restore CronJob: source-data-extractor-upload-blob-sep" logSource="pkg/restore/restore.go:1070" restore=velero/tenant1backup
   time="2020-08-25T20:36:00Z" level=info msg="Attempting to restore CronJob: source-data-extractor-upload-blob-snp" logSource="pkg/restore/restore.go:1070" restore=velero/tenant1backup
   time="2020-08-25T20:36:00Z" level=info msg="Attempting to restore CronJob: source-data-extractor-upload-blob-sysmon" logSource="pkg/restore/restore.go:1070" restore=velero/tenant1backup
   time="2020-08-25T20:36:00Z" level=info msg="Attempting to restore CronJob: source-data-extractor-upload-blob-wgdhcp" logSource="pkg/restore/restore.go:1070" restore=velero/tenant1backup
   time="2020-08-25T20:36:00Z" level=info msg="Attempting to restore CronJob: source-data-extractor-upload-blob-wgevents" logSource="pkg/restore/restore.go:1070" restore=velero/tenant1backup
   time="2020-08-25T20:36:00Z" level=info msg="Attempting to restore CronJob: source-data-extractor-upload-blob-wgtraffic" logSource="pkg/restore/restore.go:1070" restore=velero/tenant1backup
   time="2020-08-25T20:36:00Z" level=info msg="Attempting to restore CronJob: source-data-extractor-upload-blob-windowsnxlog" logSource="pkg/restore/restore.go:1070" restore=velero/tenant1backup
   time="2020-08-25T20:36:00Z" level=info msg="Restoring resource 'deployments.apps' into namespace 'tenant1'" logSource="pkg/restore/restore.go:702" restore=velero/tenant1backup
   time="2020-08-25T20:36:01Z" level=info msg="Getting client for apps/v1, Kind=Deployment" logSource="pkg/restore/restore.go:746" restore=velero/tenant1backup
   time="2020-08-25T20:36:01Z" level=info msg="Attempting to restore Deployment: elysuim-logstash" logSource="pkg/restore/restore.go:1070" restore=velero/tenant1backup
   time="2020-08-25T20:36:01Z" level=info msg="Restoring resource 'endpoints' into namespace 'tenant1'" logSource="pkg/restore/restore.go:702" restore=velero/tenant1backup
   time="2020-08-25T20:36:01Z" level=info msg="Getting client for /v1, Kind=Endpoints" logSource="pkg/restore/restore.go:746" restore=velero/tenant1backup
   time="2020-08-25T20:36:01Z" level=info msg="Attempting to restore Endpoints: elysuim-logstash" logSource="pkg/restore/restore.go:1070" restore=velero/tenant1backup
   time="2020-08-25T20:36:01Z" level=info msg="Skipping restore of resource because the restore spec excludes it" logSource="pkg/restore/restore.go:398" resource=events restore=velero/tenant1backup
   time="2020-08-25T20:36:01Z" level=info msg="Restoring resource 'horizontalpodautoscalers.autoscaling' into namespace 'tenant1'" logSource="pkg/restore/restore.go:702" restore=velero/tenant1backup
   time="2020-08-25T20:36:01Z" level=info msg="Getting client for autoscaling/v1, Kind=HorizontalPodAutoscaler" logSource="pkg/restore/restore.go:746" restore=velero/tenant1backup
   time="2020-08-25T20:36:01Z" level=info msg="Attempting to restore HorizontalPodAutoscaler: elysuim-logstash" logSource="pkg/restore/restore.go:1070" restore=velero/tenant1backup
   time="2020-08-25T20:36:01Z" level=info msg="Restoring resource 'jobs.batch' into namespace 'tenant1'" logSource="pkg/restore/restore.go:702" restore=velero/tenant1backup
   time="2020-08-25T20:36:01Z" level=info msg="tenant1/source-data-extractor-monitor-metrics-1598333700 is complete - skipping" logSource="pkg/restore/restore.go:831" restore=velero/tenant1backup
   time="2020-08-25T20:36:01Z" level=info msg="Getting client for batch/v1, Kind=Job" logSource="pkg/restore/restore.go:746" restore=velero/tenant1backup
   time="2020-08-25T20:36:01Z" level=info msg="Executing item action for jobs.batch" logSource="pkg/restore/restore.go:964" restore=velero/tenant1backup
   time="2020-08-25T20:36:01Z" level=info msg="Attempting to restore Job: source-data-extractor-monitor-size-metrics-1594445700" logSource="pkg/restore/restore.go:1070" restore=velero/tenant1backup
   time="2020-08-25T20:36:01Z" level=info msg="tenant1/source-data-extractor-monitor-size-metrics-1598333700 is complete - skipping" logSource="pkg/restore/restore.go:831" restore=velero/tenant1backup
   time="2020-08-25T20:36:01Z" level=info msg="tenant1/source-data-extractor-prune-1597172700 is complete - skipping" logSource="pkg/restore/restore.go:831" restore=velero/tenant1backup
   time="2020-08-25T20:36:01Z" level=info msg="tenant1/source-data-extractor-prune-1598382300 is complete - skipping" logSource="pkg/restore/restore.go:831" restore=velero/tenant1backup
   time="2020-08-25T20:36:01Z" level=info msg="tenant1/source-data-extractor-upload-blob-iis-1597173060 is complete - skipping" logSource="pkg/restore/restore.go:831" restore=velero/tenant1backup
   time="2020-08-25T20:36:01Z" level=info msg="tenant1/source-data-extractor-upload-blob-iis-1598384100 is complete - skipping" logSource="pkg/restore/restore.go:831" restore=velero/tenant1backup
   time="2020-08-25T20:36:01Z" level=info msg="Executing item action for jobs.batch" logSource="pkg/restore/restore.go:964" restore=velero/tenant1backup
   time="2020-08-25T20:36:01Z" level=info msg="Attempting to restore Job: source-data-extractor-upload-blob-iis-1598384160" logSource="pkg/restore/restore.go:1070" restore=velero/tenant1backup
   time="2020-08-25T20:36:01Z" level=info msg="Executing item action for jobs.batch" logSource="pkg/restore/restore.go:964" restore=velero/tenant1backup
   time="2020-08-25T20:36:01Z" level=info msg="Attempting to restore Job: source-data-extractor-upload-blob-msagent-1588833600" logSource="pkg/restore/restore.go:1070" restore=velero/tenant1backup
   time="2020-08-25T20:36:01Z" level=info msg="tenant1/source-data-extractor-upload-blob-msagent-1597173060 is complete - skipping" logSource="pkg/restore/restore.go:831" restore=velero/tenant1backup
   time="2020-08-25T20:36:01Z" level=info msg="tenant1/source-data-extractor-upload-blob-msagent-1598384100 is complete - skipping" logSource="pkg/restore/restore.go:831" restore=velero/tenant1backup
   time="2020-08-25T20:36:01Z" level=info msg="Executing item action for jobs.batch" logSource="pkg/restore/restore.go:964" restore=velero/tenant1backup
   time="2020-08-25T20:36:01Z" level=info msg="Attempting to restore Job: source-data-extractor-upload-blob-msagent-1598384160" logSource="pkg/restore/restore.go:1070" restore=velero/tenant1backup
   time="2020-08-25T20:36:01Z" level=info msg="Executing item action for jobs.batch" logSource="pkg/restore/restore.go:964" restore=velero/tenant1backup
   time="2020-08-25T20:36:01Z" level=info msg="Attempting to restore Job: source-data-extractor-upload-blob-msconnectivity-1587557940" logSource="pkg/restore/restore.go:1070" restore=velero/tenant1backup
   time="2020-08-25T20:36:01Z" level=info msg="tenant1/source-data-extractor-upload-blob-msconnectivity-1597173060 is complete - skipping" logSource="pkg/restore/restore.go:831" restore=velero/tenant1backup
   time="2020-08-25T20:36:01Z" level=info msg="tenant1/source-data-extractor-upload-blob-msconnectivity-1598384100 is complete - skipping" logSource="pkg/restore/restore.go:831" restore=velero/tenant1backup
   time="2020-08-25T20:36:01Z" level=info msg="Executing item action for jobs.batch" logSource="pkg/restore/restore.go:964" restore=velero/tenant1backup
   time="2020-08-25T20:36:01Z" level=info msg="Attempting to restore Job: source-data-extractor-upload-blob-msconnectivity-1598384160" logSource="pkg/restore/restore.go:1070" restore=velero/tenant1backup
   time="2020-08-25T20:36:01Z" level=info msg="Executing item action for jobs.batch" logSource="pkg/restore/restore.go:964" restore=velero/tenant1backup
   time="2020-08-25T20:36:01Z" level=info msg="Attempting to restore Job: source-data-extractor-upload-blob-msexchange-1587558060" logSource="pkg/restore/restore.go:1070" restore=velero/tenant1backup
   time="2020-08-25T20:36:02Z" level=info msg="tenant1/source-data-extractor-upload-blob-msexchange-1597173060 is complete - skipping" logSource="pkg/restore/restore.go:831" restore=velero/tenant1backup
   time="2020-08-25T20:36:02Z" level=info msg="tenant1/source-data-extractor-upload-blob-msexchange-1598384100 is complete - skipping" logSource="pkg/restore/restore.go:831" restore=velero/tenant1backup
   time="2020-08-25T20:36:02Z" level=info msg="Executing item action for jobs.batch" logSource="pkg/restore/restore.go:964" restore=velero/tenant1backup
   time="2020-08-25T20:36:02Z" level=info msg="Attempting to restore Job: source-data-extractor-upload-blob-msexchange-1598384160" logSource="pkg/restore/restore.go:1070" restore=velero/tenant1backup
   time="2020-08-25T20:36:02Z" level=info msg="Executing item action for jobs.batch" logSource="pkg/restore/restore.go:964" restore=velero/tenant1backup
   time="2020-08-25T20:36:02Z" level=info msg="Attempting to restore Job: source-data-extractor-upload-blob-netflow-1587559020" logSource="pkg/restore/restore.go:1070" restore=velero/tenant1backup
   time="2020-08-25T20:36:02Z" level=info msg="tenant1/source-data-extractor-upload-blob-netflow-1597173060 is complete - skipping" logSource="pkg/restore/restore.go:831" restore=velero/tenant1backup
   time="2020-08-25T20:36:02Z" level=info msg="tenant1/source-data-extractor-upload-blob-netflow-1598384100 is complete - skipping" logSource="pkg/restore/restore.go:831" restore=velero/tenant1backup
   time="2020-08-25T20:36:02Z" level=info msg="Executing item action for jobs.batch" logSource="pkg/restore/restore.go:964" restore=velero/tenant1backup
   time="2020-08-25T20:36:02Z" level=info msg="Attempting to restore Job: source-data-extractor-upload-blob-netflow-1598384160" logSource="pkg/restore/restore.go:1070" restore=velero/tenant1backup
   time="2020-08-25T20:36:02Z" level=info msg="Executing item action for jobs.batch" logSource="pkg/restore/restore.go:964" restore=velero/tenant1backup
   time="2020-08-25T20:36:02Z" level=info msg="Attempting to restore Job: source-data-extractor-upload-blob-sep-1587557880" logSource="pkg/restore/restore.go:1070" restore=velero/tenant1backup
   time="2020-08-25T20:36:02Z" level=info msg="tenant1/source-data-extractor-upload-blob-sep-1595869200 is complete - skipping" logSource="pkg/restore/restore.go:831" restore=velero/tenant1backup
   time="2020-08-25T20:36:02Z" level=info msg="tenant1/source-data-extractor-upload-blob-snp-1597173060 is complete - skipping" logSource="pkg/restore/restore.go:831" restore=velero/tenant1backup
   time="2020-08-25T20:36:02Z" level=info msg="tenant1/source-data-extractor-upload-blob-snp-1598384100 is complete - skipping" logSource="pkg/restore/restore.go:831" restore=velero/tenant1backup
   time="2020-08-25T20:36:02Z" level=info msg="Executing item action for jobs.batch" logSource="pkg/restore/restore.go:964" restore=velero/tenant1backup
   time="2020-08-25T20:36:02Z" level=info msg="Attempting to restore Job: source-data-extractor-upload-blob-snp-1598384160" logSource="pkg/restore/restore.go:1070" restore=velero/tenant1backup
   time="2020-08-25T20:36:02Z" level=info msg="tenant1/source-data-extractor-upload-blob-sysmon-1597173060 is complete - skipping" logSource="pkg/restore/restore.go:831" restore=velero/tenant1backup
   time="2020-08-25T20:36:02Z" level=info msg="tenant1/source-data-extractor-upload-blob-sysmon-1598384100 is complete - skipping" logSource="pkg/restore/restore.go:831" restore=velero/tenant1backup
   time="2020-08-25T20:36:02Z" level=info msg="Executing item action for jobs.batch" logSource="pkg/restore/restore.go:964" restore=velero/tenant1backup
   time="2020-08-25T20:36:02Z" level=info msg="Attempting to restore Job: source-data-extractor-upload-blob-sysmon-1598384160" logSource="pkg/restore/restore.go:1070" restore=velero/tenant1backup
   time="2020-08-25T20:36:02Z" level=info msg="Executing item action for jobs.batch" logSource="pkg/restore/restore.go:964" restore=velero/tenant1backup
   time="2020-08-25T20:36:02Z" level=info msg="Attempting to restore Job: source-data-extractor-upload-blob-wgdhcp-1587558300" logSource="pkg/restore/restore.go:1070" restore=velero/tenant1backup
   time="2020-08-25T20:36:02Z" level=info msg="tenant1/source-data-extractor-upload-blob-wgdhcp-1597173060 is complete - skipping" logSource="pkg/restore/restore.go:831" restore=velero/tenant1backup
   time="2020-08-25T20:36:02Z" level=info msg="tenant1/source-data-extractor-upload-blob-wgdhcp-1598384100 is complete - skipping" logSource="pkg/restore/restore.go:831" restore=velero/tenant1backup
   time="2020-08-25T20:36:02Z" level=info msg="Executing item action for jobs.batch" logSource="pkg/restore/restore.go:964" restore=velero/tenant1backup
   time="2020-08-25T20:36:02Z" level=info msg="Attempting to restore Job: source-data-extractor-upload-blob-wgdhcp-1598384160" logSource="pkg/restore/restore.go:1070" restore=velero/tenant1backup
   time="2020-08-25T20:36:02Z" level=info msg="Executing item action for jobs.batch" logSource="pkg/restore/restore.go:964" restore=velero/tenant1backup
   time="2020-08-25T20:36:02Z" level=info msg="Attempting to restore Job: source-data-extractor-upload-blob-wgevents-1587558900" logSource="pkg/restore/restore.go:1070" restore=velero/tenant1backup
   time="2020-08-25T20:36:03Z" level=info msg="tenant1/source-data-extractor-upload-blob-wgevents-1597173060 is complete - skipping" logSource="pkg/restore/restore.go:831" restore=velero/tenant1backup
   time="2020-08-25T20:36:03Z" level=info msg="tenant1/source-data-extractor-upload-blob-wgevents-1598384100 is complete - skipping" logSource="pkg/restore/restore.go:831" restore=velero/tenant1backup
   time="2020-08-25T20:36:03Z" level=info msg="Executing item action for jobs.batch" logSource="pkg/restore/restore.go:964" restore=velero/tenant1backup
   time="2020-08-25T20:36:03Z" level=info msg="Attempting to restore Job: source-data-extractor-upload-blob-wgevents-1598384160" logSource="pkg/restore/restore.go:1070" restore=velero/tenant1backup
   time="2020-08-25T20:36:03Z" level=info msg="tenant1/source-data-extractor-upload-blob-wgtraffic-1597173060 is complete - skipping" logSource="pkg/restore/restore.go:831" restore=velero/tenant1backup
   time="2020-08-25T20:36:03Z" level=info msg="tenant1/source-data-extractor-upload-blob-wgtraffic-1598384100 is complete - skipping" logSource="pkg/restore/restore.go:831" restore=velero/tenant1backup
   time="2020-08-25T20:36:03Z" level=info msg="Executing item action for jobs.batch" logSource="pkg/restore/restore.go:964" restore=velero/tenant1backup
   time="2020-08-25T20:36:03Z" level=info msg="Attempting to restore Job: source-data-extractor-upload-blob-wgtraffic-1598384160" logSource="pkg/restore/restore.go:1070" restore=velero/tenant1backup
   time="2020-08-25T20:36:03Z" level=info msg="Executing item action for jobs.batch" logSource="pkg/restore/restore.go:964" restore=velero/tenant1backup
   time="2020-08-25T20:36:03Z" level=info msg="Attempting to restore Job: source-data-extractor-upload-blob-windowsnxlog-1587548760" logSource="pkg/restore/restore.go:1070" restore=velero/tenant1backup
   time="2020-08-25T20:36:03Z" level=info msg="tenant1/source-data-extractor-upload-blob-windowsnxlog-1597173060 is complete - skipping" logSource="pkg/restore/restore.go:831" restore=velero/tenant1backup
   time="2020-08-25T20:36:03Z" level=info msg="tenant1/source-data-extractor-upload-blob-windowsnxlog-1598384100 is complete - skipping" logSource="pkg/restore/restore.go:831" restore=velero/tenant1backup
   time="2020-08-25T20:36:03Z" level=info msg="Executing item action for jobs.batch" logSource="pkg/restore/restore.go:964" restore=velero/tenant1backup
   time="2020-08-25T20:36:03Z" level=info msg="Attempting to restore Job: source-data-extractor-upload-blob-windowsnxlog-1598384160" logSource="pkg/restore/restore.go:1070" restore=velero/tenant1backup
   time="2020-08-25T20:36:03Z" level=info msg="Restoring resource 'services' into namespace 'tenant1'" logSource="pkg/restore/restore.go:702" restore=velero/tenant1backup
   time="2020-08-25T20:36:03Z" level=info msg="Getting client for /v1, Kind=Service" logSource="pkg/restore/restore.go:746" restore=velero/tenant1backup
   time="2020-08-25T20:36:03Z" level=info msg="Executing item action for services" logSource="pkg/restore/restore.go:964" restore=velero/tenant1backup
   time="2020-08-25T20:36:03Z" level=info msg="Attempting to restore Service: elysuim-logstash" logSource="pkg/restore/restore.go:1070" restore=velero/tenant1backup
   time="2020-08-25T20:36:03Z" level=info msg="Waiting for all restic restores to complete" logSource="pkg/restore/restore.go:470" restore=velero/tenant1backup
   time="2020-08-25T20:36:03Z" level=info msg="Done waiting for all restic restores to complete" logSource="pkg/restore/restore.go:486" restore=velero/tenant1backup
   time="2020-08-25T20:36:03Z" level=info msg="restore completed" logSource="pkg/controller/restore_controller.go:468" restore=velero/tenant1backup

Anything else you would like to add: [Miscellaneous information that will assist in solving the issue.]

Environment:

• Velero version: Client: Version: v1.4.2 Git commit: 56a08a4d695d893f0863f697c2f926e27d70c0c5 Server: Version: v1.4.2

• Velero features (use velero client config get features): features:

• Kubernetes version (use kubectl version): Client Version: version.Info{Major:"1", Minor:"17", GitVersion:"v1.17.0", GitCommit:"70132b0f130acc0bed193d9ba59dd186f0e634cf", GitTreeState:"clean", BuildDate:"2019-12-07T21:20:10Z", GoVersion:"go1.13.4", Compiler:"gc", Platform:"linux/amd64"} Server Version: version.Info{Major:"1", Minor:"17", GitVersion:"v1.17.9", GitCommit:"e3808385c7b3a3b86db714d67bdd266dc2b6ab62", GitTreeState:"clean", BuildDate:"2020-07-15T20:50:36Z", GoVersion:"go1.13.6", Compiler:"gc", Platform:"linux/amd64"}

• Kubernetes installer & version: Created an Azure VM in the same VNet where Azure AKS cluster resides. Installed az and then used command az aks install-cli to install latest kubectl. Connected to cluster using command: az aks get-credentials --resource-group myResourceGroup --name myAKSCluster

• Cloud provider or hardware configuration: Microsoft Azure

• OS (e.g. from /etc/os-release): Linux

Vote on this issue!

This is an invitation to the Velero community to vote on issues, you can see the project's top voted issues listed here.
Use the "reaction smiley face" up to the right of this comment to vote.

• :+1: for "I would like to see this bug fixed as soon as possible"
• :-1: for "There are more important bugs to focus on right now"

[ashish-amarnath]

Can you please tell us how you installed Velero? Also, please confirm if you have created a volumesnapshotlocation and share the output of kubectl -n velero get volumesnapshotlocations -oyaml

[Vrushk84]

@ashish-amarnath - Hello Ashish, Please find below the output

kubectl -n velero get volumesnapshotlocations -o yaml apiVersion: v1 items:

• apiVersion: velero.io/v1 kind: VolumeSnapshotLocation metadata: creationTimestamp: "2020-08-10T17:28:42Z" generation: 1 labels: component: velero name: default namespace: velero resourceVersion: "48105162" selfLink: /apis/velero.io/v1/namespaces/velero/volumesnapshotlocations/default uid: eff5c547-db2e-11ea-8432-368d19950893 spec: config: resourceGroup: Velero_Backups subscriptionId: 0039e655-e9bf-4b31-b99e-bd2a756db787 provider: azure kind: List metadata: resourceVersion: "" selfLink: ""

Also, I followed steps from the below link to install velero: https://medium.com/egen/backing-up-aks-cluster-with-velero-b1cec289438f

Referred below link "Migrate to new cluster" section to test restoring on new AKS cluster: https://pumpingco.de/blog/backup-and-restore-a-kubernetes-cluster-with-state-using-velero/

[ashish-amarnath]

The error reported in this issue is that the volume is restored as-is without creating a volume from a snapshot.

Restoring persistent volume as-is because it doesn't have a snapshot and its reclaim policy is not Delete

[ashish-amarnath]

@Vrushk84 Thanks for providing that info and apologies for the avoidable round-trip.

Looking at these lines

time="2020-08-25T20:35:59Z" level=info msg="Restoring persistent volume as-is because it doesn't have a snapshot and its reclaim policy is not Delete." logSource="pkg/restore/restore.go:940" restore=velero/tenant1backup
time="2020-08-25T20:35:59Z" level=info msg="No snapshot found for persistent volume" logSource="pkg/restore/pv_restorer.go:81" persistentVolume=datadrive restore=velero/tenant1backup

The volumes are restored as-is because there are no volumesnapshots in the backup being restored. This is also confirmed by the fact that the output of the velero backup describe command does not include any volume snapshots.

Velero-Native Snapshots: <none included>

Here are a couple of things that you might want to inspect:

1. Was volume snapshotting enabled for this backup? This may be disabled on a per-backup basis using the --snapshot-volumes flag to velero backup create command.
2. Was volume snapshotting disabled when velero was installed? This may be done by setting the --use-volume-snapshots to velero install command to false.
3. Was the volumesnapshotter plugins installed? This can be verified by running the velero plugin get command.

Can you also please share the logs from the backup? You can use velero backup logs elysiumanalytics-aks-tenant1-new

[carlisia]

Since it's been a while, I'm closing this issue. @Vrushk84 feel free to reopen this issue if you are still having problems, and with the information asked above.