Velero: error unable to decode disk's description as JSON

[carlisia]

@artooro apologies for moving this issue around. We concluded that this one is best kept as an issue vs. discussion. Please subscribe to this issue to get updates.

Link to original: https://github.com/vmware-tanzu/velero/discussions/3251.

[artooro]

Info requested

kubectl logs deployment/velero -n velero

time="2021-01-28T03:30:57Z" level=info msg="Processing item" backup=velero/daily-schedule-20210128033051 logSource="pkg/backup/backup.go:354" name=gitlab-gitaly-0 namespace=default progress= resource=pods
time="2021-01-28T03:30:57Z" level=info msg="Backing up item" backup=velero/daily-schedule-20210128033051 logSource="pkg/backup/item_backupper.go:121" name=gitlab-gitaly-0 namespace=default resource=pods
time="2021-01-28T03:30:57Z" level=info msg="Executing custom action" backup=velero/daily-schedule-20210128033051 logSource="pkg/backup/item_backupper.go:327" name=gitlab-gitaly-0 namespace=default resource=pods
time="2021-01-28T03:30:57Z" level=info msg="Executing podAction" backup=velero/daily-schedule-20210128033051 cmd=/velero logSource="pkg/backup/pod_action.go:51" pluginName=velero
time="2021-01-28T03:30:57Z" level=info msg="Adding pvc repo-data-gitlab-gitaly-0 to additionalItems" backup=velero/daily-schedule-20210128033051 cmd=/velero logSource="pkg/backup/pod_action.go:67" pluginName=velero
time="2021-01-28T03:30:57Z" level=info msg="Done executing podAction" backup=velero/daily-schedule-20210128033051 cmd=/velero logSource="pkg/backup/pod_action.go:77" pluginName=velero
time="2021-01-28T03:30:57Z" level=info msg="Backing up item" backup=velero/daily-schedule-20210128033051 logSource="pkg/backup/item_backupper.go:121" name=repo-data-gitlab-gitaly-0 namespace=default resource=persistentvolumeclaims
time="2021-01-28T03:30:57Z" level=info msg="Executing custom action" backup=velero/daily-schedule-20210128033051 logSource="pkg/backup/item_backupper.go:327" name=repo-data-gitlab-gitaly-0 namespace=default resource=persistentvolumeclaims
time="2021-01-28T03:30:57Z" level=info msg="Executing PVCAction" backup=velero/daily-schedule-20210128033051 cmd=/velero logSource="pkg/backup/backup_pv_action.go:49" pluginName=velero
time="2021-01-28T03:30:57Z" level=info msg="Backing up item" backup=velero/daily-schedule-20210128033051 logSource="pkg/backup/item_backupper.go:121" name=pv-repo-data-gitlab-gitaly-1 namespace= resource=persistentvolumes
time="2021-01-28T03:30:57Z" level=info msg="Executing takePVSnapshot" backup=velero/daily-schedule-20210128033051 logSource="pkg/backup/item_backupper.go:405" name=pv-repo-data-gitlab-gitaly-1 namespace= resource=persistentvolumes
time="2021-01-28T03:30:57Z" level=info msg="label \"topology.kubernetes.io/zone\" is not present on PersistentVolume, checking deprecated label..." backup=velero/daily-schedule-20210128033051 logSource="pkg/backup/item_backupper.go:432" name=pv-repo-data-gitlab-gitaly-1 namespace= persistentVolume=pv-repo-data-gitlab-gitaly-1 resource=persistentvolumes
time="2021-01-28T03:30:57Z" level=info msg="Got volume ID for persistent volume" backup=velero/daily-schedule-20210128033051 logSource="pkg/backup/item_backupper.go:462" name=pv-repo-data-gitlab-gitaly-1 namespace= persistentVolume=pv-repo-data-gitlab-gitaly-1 resource=persistentvolumes volumeSnapshotLocation=default
time="2021-01-28T03:30:57Z" level=info msg="Getting volume information" backup=velero/daily-schedule-20210128033051 logSource="pkg/backup/item_backupper.go:483" name=pv-repo-data-gitlab-gitaly-1 namespace= persistentVolume=pv-repo-data-gitlab-gitaly-1 resource=persistentvolumes volumeID=gitlab-2
time="2021-01-28T03:30:58Z" level=info msg="Snapshotting persistent volume" backup=velero/daily-schedule-20210128033051 logSource="pkg/backup/item_backupper.go:489" name=pv-repo-data-gitlab-gitaly-1 namespace= persistentVolume=pv-repo-data-gitlab-gitaly-1 resource=persistentvolumes volumeID=gitlab-2
time="2021-01-28T03:30:58Z" level=error msg="unable to decode disk's description as JSON, so only applying Velero-assigned tags to snapshot" backup=velero/daily-schedule-20210128033051 cmd=/plugins/velero-plugin-for-gcp error="unexpected end of JSON input" logSource="/go/src/github.com/vmware-tanzu/velero-plugin-for-gcp/velero-plugin-for-gcp/volume_snapshotter.go:282" pluginName=velero-plugin-for-gcp

velero backup describe daily-schedule-20210128033051

Name:         daily-schedule-20210128033051
Namespace:    velero
Labels:       velero.io/schedule-name=daily-schedule
              velero.io/storage-location=default
Annotations:  velero.io/source-cluster-k8s-gitversion=v1.17.14-gke.1600
              velero.io/source-cluster-k8s-major-version=1
              velero.io/source-cluster-k8s-minor-version=17+

Phase:  PartiallyFailed (run `velero backup logs daily-schedule-20210128033051` for more information)

Errors:    1
Warnings:  0

Namespaces:
  Included:  *
  Excluded:  <none>

Resources:
  Included:        *
  Excluded:        <none>
  Cluster-scoped:  auto

Label selector:  <none>

Storage Location:  default

Velero-Native Snapshot PVs:  auto

TTL:  336h0m0s

Hooks:  <none>

Backup Format Version:  1.1.0

Started:    2021-01-27 22:30:51 -0500 EST
Completed:  2021-01-27 22:31:26 -0500 EST

Expiration:  2021-02-10 22:30:51 -0500 EST

Total items to be backed up:  1611
Items backed up:              1611

Velero-Native Snapshots:  17 of 17 snapshots completed successfully (specify --details for more information)

velero backup logs daily-schedule-20210128033051

time="2021-01-28T03:30:57Z" level=info msg="Processing item" backup=velero/daily-schedule-20210128033051 logSource="pkg/backup/backup.go:354" name=gitlab-gitaly-0 namespace=default progress= resource=pods
time="2021-01-28T03:30:57Z" level=info msg="Backing up item" backup=velero/daily-schedule-20210128033051 logSource="pkg/backup/item_backupper.go:121" name=gitlab-gitaly-0 namespace=default resource=pods
time="2021-01-28T03:30:57Z" level=info msg="Executing custom action" backup=velero/daily-schedule-20210128033051 logSource="pkg/backup/item_backupper.go:327" name=gitlab-gitaly-0 namespace=default resource=pods
time="2021-01-28T03:30:57Z" level=info msg="Executing podAction" backup=velero/daily-schedule-20210128033051 cmd=/velero logSource="pkg/backup/pod_action.go:51" pluginName=velero
time="2021-01-28T03:30:57Z" level=info msg="Adding pvc repo-data-gitlab-gitaly-0 to additionalItems" backup=velero/daily-schedule-20210128033051 cmd=/velero logSource="pkg/backup/pod_action.go:67" pluginName=velero
time="2021-01-28T03:30:57Z" level=info msg="Done executing podAction" backup=velero/daily-schedule-20210128033051 cmd=/velero logSource="pkg/backup/pod_action.go:77" pluginName=velero
time="2021-01-28T03:30:57Z" level=info msg="Backing up item" backup=velero/daily-schedule-20210128033051 logSource="pkg/backup/item_backupper.go:121" name=repo-data-gitlab-gitaly-0 namespace=default resource=persistentvolumeclaims
time="2021-01-28T03:30:57Z" level=info msg="Executing custom action" backup=velero/daily-schedule-20210128033051 logSource="pkg/backup/item_backupper.go:327" name=repo-data-gitlab-gitaly-0 namespace=default resource=persistentvolumeclaims
time="2021-01-28T03:30:57Z" level=info msg="Executing PVCAction" backup=velero/daily-schedule-20210128033051 cmd=/velero logSource="pkg/backup/backup_pv_action.go:49" pluginName=velero
time="2021-01-28T03:30:57Z" level=info msg="Backing up item" backup=velero/daily-schedule-20210128033051 logSource="pkg/backup/item_backupper.go:121" name=pv-repo-data-gitlab-gitaly-1 namespace= resource=persistentvolumes
time="2021-01-28T03:30:57Z" level=info msg="Executing takePVSnapshot" backup=velero/daily-schedule-20210128033051 logSource="pkg/backup/item_backupper.go:405" name=pv-repo-data-gitlab-gitaly-1 namespace= resource=persistentvolumes
time="2021-01-28T03:30:57Z" level=info msg="label \"topology.kubernetes.io/zone\" is not present on PersistentVolume, checking deprecated label..." backup=velero/daily-schedule-20210128033051 logSource="pkg/backup/item_backupper.go:432" name=pv-repo-data-gitlab-gitaly-1 namespace= persistentVolume=pv-repo-data-gitlab-gitaly-1 resource=persistentvolumes
time="2021-01-28T03:30:57Z" level=info msg="Got volume ID for persistent volume" backup=velero/daily-schedule-20210128033051 logSource="pkg/backup/item_backupper.go:462" name=pv-repo-data-gitlab-gitaly-1 namespace= persistentVolume=pv-repo-data-gitlab-gitaly-1 resource=persistentvolumes volumeSnapshotLocation=default
time="2021-01-28T03:30:57Z" level=info msg="Getting volume information" backup=velero/daily-schedule-20210128033051 logSource="pkg/backup/item_backupper.go:483" name=pv-repo-data-gitlab-gitaly-1 namespace= persistentVolume=pv-repo-data-gitlab-gitaly-1 resource=persistentvolumes volumeID=gitlab-2
time="2021-01-28T03:30:58Z" level=info msg="Snapshotting persistent volume" backup=velero/daily-schedule-20210128033051 logSource="pkg/backup/item_backupper.go:489" name=pv-repo-data-gitlab-gitaly-1 namespace= persistentVolume=pv-repo-data-gitlab-gitaly-1 resource=persistentvolumes volumeID=gitlab-2
time="2021-01-28T03:30:58Z" level=error msg="unable to decode disk's description as JSON, so only applying Velero-assigned tags to snapshot" backup=velero/daily-schedule-20210128033051 cmd=/plugins/velero-plugin-for-gcp error="unexpected end of JSON input" logSource="/go/src/github.com/vmware-tanzu/velero-plugin-for-gcp/velero-plugin-for-gcp/volume_snapshotter.go:282" pluginName=velero-plugin-for-gcp

One important thing to note is that this disk was created manually and associated with a persistentVolume in kubernetes by manually provisioning the resource.
If I run the command gcloud compute disks describe --zone us-east1-b gitlab-2 there is no description property as there are in disks created by the clusters automated storage provisioning. It's also not possible to update the disk and manually add such a property.

[dsu-igeek]

That error appears to be advisory. Since there are no tags applied to the disk, it shouldn't be a problem that they aren't being backed up. You could test to make sure that the backup can be restored in a clean cluster.

[artooro]

@dsu-igeek yes, it's just annoying that each backup says that it was not successful, even though technically it was. Perhaps the log level should be changed for that message to a warning instead of error?

[georgettica]

for completion, the line that does it is here https://github.com/vmware-tanzu/velero-plugin-for-gcp/blob/ff26107b1df54ad0c07d5f629ce9e779f199644f/velero-plugin-for-gcp/volume_snapshotter.go#L282
as I didn't dig too deep on this, maybe add a issue on that repo for mitigating this issue?

[cvdsande]

That error appears to be advisory. Since there are no tags applied to the disk, it shouldn't be a problem that they aren't being backed up. You could test to make sure that the backup can be restored in a clean cluster.

Just got this error. It's a bit of an issue for us, because the error causes the script to not exit '0'. As a result our backup automation thinks it's failing. I'm commenting here because the other repo doesn't have issues enabled.