Velero: Slow pod backup when pod has subitems (pvc->pv)

[hmcgonig]

What steps did you take and what happened:
I ran a full cluster backup with Velero 0.11 and noticed that the backup was very slow when backing up our pods. Upon further inspection I noticed that every URL in the discovery API is being re-requested for every additionalItem that item_backupper finds: https://github.com/heptio/velero/blob/7913ae1867337e0160ccbcefa34a48ba5a779d5b/pkg/backup/item_backupper.go#L321-L323

What did you expect to happen:
Pod/pvc/pv backups would complete must faster. Discovery information could probably also be pulled from a cache.

Additional debugging info

In the below logs I was backing up a pod called asdf-0-0 which had an associated persistent volume claim, which had an associated persistent volume. I ran Velero with --log-level debug --logtostderr -v6 and can see ~2 second delays, where Velero is pulling every discovery URL.

velero-d84694798-tjxxh velero time="2019-05-02T20:09:35Z" level=info msg="Backing up resource" backup=velero/vt-backup-6 group=v1 groupResource=pods logSource="pkg/backup/item_backupper.go:163" name=asdf-0-0 namespace=vt
velero-d84694798-tjxxh velero time="2019-05-02T20:09:35Z" level=debug msg="Executing pre hooks" backup=velero/vt-backup-6 group=v1 groupResource=pods logSource="pkg/backup/item_backupper.go:165" name=asdf-0-0 namespace=vt
velero-d84694798-tjxxh velero time="2019-05-02T20:09:35Z" level=info msg="Executing custom action" backup=velero/vt-backup-6 group=v1 groupResource=pods logSource="pkg/backup/item_backupper.go:308" name=asdf-0-0 namespace=vt
velero-d84694798-tjxxh velero time="2019-05-02T20:09:35Z" level=info msg="Executing podAction" backup=velero/vt-backup-6 cmd=/velero logSource="pkg/backup/pod_action.go:51" pluginName=velero
velero-d84694798-tjxxh velero time="2019-05-02T20:09:35Z" level=info msg="Adding pvc asdf-0-vtdataroot-0-asdf-0-0 to additionalItems" backup=velero/vt-backup-6 cmd=/velero logSource="pkg/backup/pod_action.go:89" pluginName=velero
velero-d84694798-tjxxh velero time="2019-05-02T20:09:35Z" level=info msg="Done executing podAction" backup=velero/vt-backup-6 cmd=/velero logSource="pkg/backup/pod_action.go:98" pluginName=velero
velero-d84694798-tjxxh velero I0502 20:09:36.003171       8 round_trippers.go:405] GET https://172.19.32.1:443/api?timeout=32s 200 OK in 1 milliseconds
velero-d84694798-tjxxh velero I0502 20:09:36.005116       8 round_trippers.go:405] GET https://172.19.32.1:443/apis?timeout=32s 200 OK in 1 milliseconds
velero-d84694798-tjxxh velero I0502 20:09:36.088613       8 request.go:485] Throttling request took 82.909443ms, request: GET:https://172.19.32.1:443/apis/storage.k8s.io/v1?timeout=32s
velero-d84694798-tjxxh velero I0502 20:09:36.088999       8 round_trippers.go:405] GET https://172.19.32.1:443/apis/apiregistration.k8s.io/v1?timeout=32s 200 OK in 83 milliseconds
velero-d84694798-tjxxh velero I0502 20:09:36.088996       8 round_trippers.go:405] GET https://172.19.32.1:443/apis/authentication.k8s.io/v1?timeout=32s 200 OK in 83 milliseconds
velero-d84694798-tjxxh velero I0502 20:09:36.089166       8 round_trippers.go:405] GET https://172.19.32.1:443/apis/settings.k8s.io/v1alpha1?timeout=32s 200 OK in 83 milliseconds
velero-d84694798-tjxxh velero I0502 20:09:36.089191       8 round_trippers.go:405] GET https://172.19.32.1:443/apis/authentication.k8s.io/v1beta1?timeout=32s 200 OK in 83 milliseconds
velero-d84694798-tjxxh velero I0502 20:09:36.089193       8 round_trippers.go:405] GET https://172.19.32.1:443/api/v1?timeout=32s 200 OK in 83 milliseconds
velero-d84694798-tjxxh velero I0502 20:09:36.089201       8 round_trippers.go:405] GET https://172.19.32.1:443/apis/metrics.k8s.io/v1beta1?timeout=32s 200 OK in 83 milliseconds
velero-d84694798-tjxxh velero I0502 20:09:36.089233       8 round_trippers.go:405] GET https://172.19.32.1:443/apis/autoscaling/v1?timeout=32s 200 OK in 83 milliseconds
velero-d84694798-tjxxh velero I0502 20:09:36.089190       8 round_trippers.go:405] GET https://172.19.32.1:443/apis/batch/v2alpha1?timeout=32s 200 OK in 83 milliseconds
velero-d84694798-tjxxh velero I0502 20:09:36.089227       8 round_trippers.go:405] GET https://172.19.32.1:443/apis/certificates.k8s.io/v1beta1?timeout=32s 200 OK in 83 milliseconds
velero-d84694798-tjxxh velero I0502 20:09:36.089269       8 round_trippers.go:405] GET https://172.19.32.1:443/apis/policy/v1beta1?timeout=32s 200 OK in 83 milliseconds
velero-d84694798-tjxxh velero I0502 20:09:36.089275       8 round_trippers.go:405] GET https://172.19.32.1:443/apis/apps/v1beta2?timeout=32s 200 OK in 83 milliseconds
velero-d84694798-tjxxh velero I0502 20:09:36.089291       8 round_trippers.go:405] GET https://172.19.32.1:443/apis/events.k8s.io/v1beta1?timeout=32s 200 OK in 83 milliseconds
velero-d84694798-tjxxh velero I0502 20:09:36.090858       8 round_trippers.go:405] GET https://172.19.32.1:443/apis/storage.k8s.io/v1?timeout=32s 200 OK in 1 milliseconds
velero-d84694798-tjxxh velero I0502 20:09:36.111370       8 request.go:485] Throttling request took 105.664174ms, request: GET:https://172.19.32.1:443/apis/storage.k8s.io/v1beta1?timeout=32s
velero-d84694798-tjxxh velero I0502 20:09:36.113566       8 round_trippers.go:405] GET https://172.19.32.1:443/apis/storage.k8s.io/v1beta1?timeout=32s 200 OK in 2 milliseconds
velero-d84694798-tjxxh velero I0502 20:09:36.188577       8 request.go:485] Throttling request took 182.869984ms, request: GET:https://172.19.32.1:443/apis/apps/v1beta1?timeout=32s
velero-d84694798-tjxxh velero I0502 20:09:36.190562       8 round_trippers.go:405] GET https://172.19.32.1:443/apis/apps/v1beta1?timeout=32s 200 OK in 1 milliseconds
velero-d84694798-tjxxh velero I0502 20:09:36.202059       8 request.go:485] Throttling request took 196.335826ms, request: GET:https://172.19.32.1:443/apis/autoscaling/v2beta1?timeout=32s
velero-d84694798-tjxxh velero I0502 20:09:36.204177       8 round_trippers.go:405] GET https://172.19.32.1:443/apis/autoscaling/v2beta1?timeout=32s 200 OK in 2 milliseconds
velero-d84694798-tjxxh velero I0502 20:09:36.252066       8 request.go:485] Throttling request took 246.323816ms, request: GET:https://172.19.32.1:443/apis/admissionregistration.k8s.io/v1beta1?timeout=32s
velero-d84694798-tjxxh velero I0502 20:09:36.254122       8 round_trippers.go:405] GET https://172.19.32.1:443/apis/admissionregistration.k8s.io/v1beta1?timeout=32s 200 OK in 1 milliseconds
velero-d84694798-tjxxh velero I0502 20:09:36.302068       8 request.go:485] Throttling request took 296.320937ms, request: GET:https://172.19.32.1:443/apis/apiextensions.k8s.io/v1beta1?timeout=32s
velero-d84694798-tjxxh velero I0502 20:09:36.304039       8 round_trippers.go:405] GET https://172.19.32.1:443/apis/apiextensions.k8s.io/v1beta1?timeout=32s 200 OK in 1 milliseconds
velero-d84694798-tjxxh velero I0502 20:09:36.352056       8 request.go:485] Throttling request took 346.306826ms, request: GET:https://172.19.32.1:443/apis/networking.k8s.io/v1?timeout=32s
velero-d84694798-tjxxh velero I0502 20:09:36.354090       8 round_trippers.go:405] GET https://172.19.32.1:443/apis/networking.k8s.io/v1?timeout=32s 200 OK in 1 milliseconds
velero-d84694798-tjxxh velero I0502 20:09:36.402049       8 request.go:485] Throttling request took 396.282213ms, request: GET:https://172.19.32.1:443/apis/extensions/v1beta1?timeout=32s
velero-d84694798-tjxxh velero I0502 20:09:36.404169       8 round_trippers.go:405] GET https://172.19.32.1:443/apis/extensions/v1beta1?timeout=32s 200 OK in 2 milliseconds
velero-d84694798-tjxxh velero I0502 20:09:36.452065       8 request.go:485] Throttling request took 446.296281ms, request: GET:https://172.19.32.1:443/apis/rbac.authorization.k8s.io/v1?timeout=32s
velero-d84694798-tjxxh velero I0502 20:09:36.455009       8 round_trippers.go:405] GET https://172.19.32.1:443/apis/rbac.authorization.k8s.io/v1?timeout=32s 200 OK in 2 milliseconds
velero-d84694798-tjxxh velero I0502 20:09:36.502060       8 request.go:485] Throttling request took 496.289039ms, request: GET:https://172.19.32.1:443/apis/yarn.hubspot.com/v1?timeout=32s
velero-d84694798-tjxxh velero I0502 20:09:36.504257       8 round_trippers.go:405] GET https://172.19.32.1:443/apis/yarn.hubspot.com/v1?timeout=32s 200 OK in 2 milliseconds
velero-d84694798-tjxxh velero I0502 20:09:36.552066       8 request.go:485] Throttling request took 546.290009ms, request: GET:https://172.19.32.1:443/apis/authorization.k8s.io/v1?timeout=32s
velero-d84694798-tjxxh velero I0502 20:09:36.554985       8 round_trippers.go:405] GET https://172.19.32.1:443/apis/authorization.k8s.io/v1?timeout=32s 200 OK in 2 milliseconds
velero-d84694798-tjxxh velero I0502 20:09:36.602070       8 request.go:485] Throttling request took 596.287129ms, request: GET:https://172.19.32.1:443/apis/authorization.k8s.io/v1beta1?timeout=32s
velero-d84694798-tjxxh velero I0502 20:09:36.604930       8 round_trippers.go:405] GET https://172.19.32.1:443/apis/authorization.k8s.io/v1beta1?timeout=32s 200 OK in 2 milliseconds
velero-d84694798-tjxxh velero I0502 20:09:36.652046       8 request.go:485] Throttling request took 646.033734ms, request: GET:https://172.19.32.1:443/apis/zk.hubspot.com/v1?timeout=32s
velero-d84694798-tjxxh velero I0502 20:09:36.688636       8 round_trippers.go:405] GET https://172.19.32.1:443/apis/zk.hubspot.com/v1?timeout=32s 200 OK in 36 milliseconds
velero-d84694798-tjxxh velero I0502 20:09:36.702056       8 request.go:485] Throttling request took 695.999468ms, request: GET:https://172.19.32.1:443/apis/velero.io/v1?timeout=32s
velero-d84694798-tjxxh velero I0502 20:09:36.705040       8 round_trippers.go:405] GET https://172.19.32.1:443/apis/velero.io/v1?timeout=32s 200 OK in 2 milliseconds
velero-d84694798-tjxxh velero I0502 20:09:36.752066       8 request.go:485] Throttling request took 745.98327ms, request: GET:https://172.19.32.1:443/apis/custom.metrics.k8s.io/v1beta1?timeout=32s
velero-d84694798-tjxxh velero I0502 20:09:36.759054       8 round_trippers.go:405] GET https://172.19.32.1:443/apis/custom.metrics.k8s.io/v1beta1?timeout=32s 200 OK in 6 milliseconds
velero-d84694798-tjxxh velero I0502 20:09:36.802062       8 request.go:485] Throttling request took 795.97355ms, request: GET:https://172.19.32.1:443/apis/hubspot.com/v1?timeout=32s
velero-d84694798-tjxxh velero I0502 20:09:36.804195       8 round_trippers.go:405] GET https://172.19.32.1:443/apis/hubspot.com/v1?timeout=32s 200 OK in 2 milliseconds
velero-d84694798-tjxxh velero I0502 20:09:36.852073       8 request.go:485] Throttling request took 845.976371ms, request: GET:https://172.19.32.1:443/apis/puppet.hubspot.com/v1?timeout=32s
velero-d84694798-tjxxh velero I0502 20:09:36.854194       8 round_trippers.go:405] GET https://172.19.32.1:443/apis/puppet.hubspot.com/v1?timeout=32s 200 OK in 2 milliseconds
velero-d84694798-tjxxh velero I0502 20:09:36.903714       8 request.go:485] Throttling request took 897.607179ms, request: GET:https://172.19.32.1:443/apis/apps/v1?timeout=32s
velero-d84694798-tjxxh velero I0502 20:09:36.905945       8 round_trippers.go:405] GET https://172.19.32.1:443/apis/apps/v1?timeout=32s 200 OK in 2 milliseconds
velero-d84694798-tjxxh velero I0502 20:09:36.952075       8 request.go:485] Throttling request took 945.941789ms, request: GET:https://172.19.32.1:443/apis/monitoring.coreos.com/v1?timeout=32s
velero-d84694798-tjxxh velero I0502 20:09:36.954079       8 round_trippers.go:405] GET https://172.19.32.1:443/apis/monitoring.coreos.com/v1?timeout=32s 200 OK in 1 milliseconds
velero-d84694798-tjxxh velero I0502 20:09:37.002069       8 request.go:485] Throttling request took 996.051227ms, request: GET:https://172.19.32.1:443/apis/redis.hubspot.com/v1?timeout=32s
velero-d84694798-tjxxh velero I0502 20:09:37.003966       8 round_trippers.go:405] GET https://172.19.32.1:443/apis/redis.hubspot.com/v1?timeout=32s 200 OK in 1 milliseconds
velero-d84694798-tjxxh velero I0502 20:09:37.051951       8 request.go:485] Throttling request took 1.045804839s, request: GET:https://172.19.32.1:443/apis/rbac.authorization.k8s.io/v1beta1?timeout=32s
velero-d84694798-tjxxh velero I0502 20:09:37.054053       8 round_trippers.go:405] GET https://172.19.32.1:443/apis/rbac.authorization.k8s.io/v1beta1?timeout=32s 200 OK in 2 milliseconds
velero-d84694798-tjxxh velero I0502 20:09:37.101941       8 request.go:485] Throttling request took 1.095795839s, request: GET:https://172.19.32.1:443/apis/rbac.authorization.k8s.io/v1alpha1?timeout=32s
velero-d84694798-tjxxh velero I0502 20:09:37.103924       8 round_trippers.go:405] GET https://172.19.32.1:443/apis/rbac.authorization.k8s.io/v1alpha1?timeout=32s 200 OK in 1 milliseconds
velero-d84694798-tjxxh velero I0502 20:09:37.151936       8 request.go:485] Throttling request took 1.145759717s, request: GET:https://172.19.32.1:443/apis/scheduling.k8s.io/v1alpha1?timeout=32s
velero-d84694798-tjxxh velero I0502 20:09:37.153798       8 round_trippers.go:405] GET https://172.19.32.1:443/apis/scheduling.k8s.io/v1alpha1?timeout=32s 200 OK in 1 milliseconds
velero-d84694798-tjxxh velero I0502 20:09:37.201950       8 request.go:485] Throttling request took 1.195768901s, request: GET:https://172.19.32.1:443/apis/batch/v1?timeout=32s
velero-d84694798-tjxxh velero I0502 20:09:37.203916       8 round_trippers.go:405] GET https://172.19.32.1:443/apis/batch/v1?timeout=32s 200 OK in 1 milliseconds
velero-d84694798-tjxxh velero I0502 20:09:37.251933       8 request.go:485] Throttling request took 1.245725572s, request: GET:https://172.19.32.1:443/apis/vitess.hubspot.com/v1beta1?timeout=32s
velero-d84694798-tjxxh velero I0502 20:09:37.254254       8 round_trippers.go:405] GET https://172.19.32.1:443/apis/vitess.hubspot.com/v1beta1?timeout=32s 200 OK in 2 milliseconds
velero-d84694798-tjxxh velero I0502 20:09:37.301946       8 request.go:485] Throttling request took 1.295679736s, request: GET:https://172.19.32.1:443/apis/batch/v1beta1?timeout=32s
velero-d84694798-tjxxh velero I0502 20:09:37.303972       8 round_trippers.go:405] GET https://172.19.32.1:443/apis/batch/v1beta1?timeout=32s 200 OK in 1 milliseconds
velero-d84694798-tjxxh velero I0502 20:09:37.351947       8 request.go:485] Throttling request took 1.345637286s, request: GET:https://172.19.32.1:443/apis/apiregistration.k8s.io/v1beta1?timeout=32s
velero-d84694798-tjxxh velero I0502 20:09:37.353847       8 round_trippers.go:405] GET https://172.19.32.1:443/apis/apiregistration.k8s.io/v1beta1?timeout=32s 200 OK in 1 milliseconds
velero-d84694798-tjxxh velero I0502 20:09:37.403178       8 round_trippers.go:405] GET https://172.19.32.1:443/api/v1/namespaces/vt/persistentvolumeclaims/asdf-0-vtdataroot-0-asdf-0-0 200 OK in 5 milliseconds
velero-d84694798-tjxxh velero time="2019-05-02T20:09:37Z" level=info msg="Backing up resource" backup=velero/vt-backup-6 group=v1 groupResource=pods logSource="pkg/backup/item_backupper.go:163" name=asdf-0-vtdataroot-0-asdf-0-0 namespace=vt
velero-d84694798-tjxxh velero time="2019-05-02T20:09:37Z" level=debug msg="Executing pre hooks" backup=velero/vt-backup-6 group=v1 groupResource=pods logSource="pkg/backup/item_backupper.go:165" name=asdf-0-vtdataroot-0-asdf-0-0 namespace=vt
velero-d84694798-tjxxh velero time="2019-05-02T20:09:37Z" level=debug msg="Skipping action because it does not apply to this resource" backup=velero/vt-backup-6 group=v1 groupResource=pods logSource="pkg/backup/item_backupper.go:294" name=asdf-0-vtdataroot-0-asdf-0-0 namespace=vt
velero-d84694798-tjxxh velero time="2019-05-02T20:09:37Z" level=info msg="Executing custom action" backup=velero/vt-backup-6 group=v1 groupResource=pods logSource="pkg/backup/item_backupper.go:308" name=asdf-0-vtdataroot-0-asdf-0-0 namespace=vt
velero-d84694798-tjxxh velero time="2019-05-02T20:09:37Z" level=info msg="Executing backupPVAction" backup=velero/vt-backup-6 cmd=/velero logSource="pkg/backup/backup_pv_action.go:48" pluginName=velero
velero-d84694798-tjxxh velero I0502 20:09:37.448781       8 round_trippers.go:405] GET https://172.19.32.1:443/api?timeout=32s 200 OK in 1 milliseconds
velero-d84694798-tjxxh velero I0502 20:09:37.499617       8 round_trippers.go:405] GET https://172.19.32.1:443/apis?timeout=32s 200 OK in 1 milliseconds
velero-d84694798-tjxxh velero I0502 20:09:37.544094       8 round_trippers.go:405] GET https://172.19.32.1:443/apis/extensions/v1beta1?timeout=32s 200 OK in 1 milliseconds
velero-d84694798-tjxxh velero I0502 20:09:37.601926       8 request.go:485] Throttling request took 59.84668ms, request: GET:https://172.19.32.1:443/apis/authorization.k8s.io/v1?timeout=32s
velero-d84694798-tjxxh velero I0502 20:09:37.603782       8 round_trippers.go:405] GET https://172.19.32.1:443/apis/authorization.k8s.io/v1?timeout=32s 200 OK in 1 milliseconds
velero-d84694798-tjxxh velero I0502 20:09:37.619074       8 round_trippers.go:405] GET https://172.19.32.1:443/apis/metrics.k8s.io/v1beta1?timeout=32s 200 OK in 67 milliseconds
velero-d84694798-tjxxh velero I0502 20:09:37.651947       8 request.go:485] Throttling request took 109.856416ms, request: GET:https://172.19.32.1:443/apis/redis.hubspot.com/v1?timeout=32s
velero-d84694798-tjxxh velero I0502 20:09:37.653913       8 round_trippers.go:405] GET https://172.19.32.1:443/apis/redis.hubspot.com/v1?timeout=32s 200 OK in 1 milliseconds
velero-d84694798-tjxxh velero I0502 20:09:37.701943       8 request.go:485] Throttling request took 159.85471ms, request: GET:https://172.19.32.1:443/apis/apps/v1?timeout=32s
velero-d84694798-tjxxh velero I0502 20:09:37.703830       8 round_trippers.go:405] GET https://172.19.32.1:443/apis/apps/v1?timeout=32s 200 OK in 1 milliseconds
velero-d84694798-tjxxh velero I0502 20:09:37.788547       8 request.go:485] Throttling request took 246.453825ms, request: GET:https://172.19.32.1:443/apis/storage.k8s.io/v1?timeout=32s
velero-d84694798-tjxxh velero I0502 20:09:37.790458       8 round_trippers.go:405] GET https://172.19.32.1:443/apis/storage.k8s.io/v1?timeout=32s 200 OK in 1 milliseconds
velero-d84694798-tjxxh velero I0502 20:09:37.801943       8 request.go:485] Throttling request took 259.847906ms, request: GET:https://172.19.32.1:443/apis/velero.io/v1?timeout=32s
velero-d84694798-tjxxh velero I0502 20:09:37.803905       8 round_trippers.go:405] GET https://172.19.32.1:443/apis/velero.io/v1?timeout=32s 200 OK in 1 milliseconds
velero-d84694798-tjxxh velero I0502 20:09:37.851951       8 request.go:485] Throttling request took 309.854812ms, request: GET:https://172.19.32.1:443/apis/apps/v1beta2?timeout=32s
velero-d84694798-tjxxh velero I0502 20:09:37.854177       8 round_trippers.go:405] GET https://172.19.32.1:443/apis/apps/v1beta2?timeout=32s 200 OK in 2 milliseconds
velero-d84694798-tjxxh velero I0502 20:09:37.901943       8 request.go:485] Throttling request took 359.844155ms, request: GET:https://172.19.32.1:443/apis/yarn.hubspot.com/v1?timeout=32s
velero-d84694798-tjxxh velero I0502 20:09:37.904011       8 round_trippers.go:405] GET https://172.19.32.1:443/apis/yarn.hubspot.com/v1?timeout=32s 200 OK in 2 milliseconds
velero-d84694798-tjxxh velero I0502 20:09:37.951941       8 request.go:485] Throttling request took 409.837278ms, request: GET:https://172.19.32.1:443/apis/zk.hubspot.com/v1?timeout=32s
velero-d84694798-tjxxh velero I0502 20:09:37.953867       8 round_trippers.go:405] GET https://172.19.32.1:443/apis/zk.hubspot.com/v1?timeout=32s 200 OK in 1 milliseconds
velero-d84694798-tjxxh velero I0502 20:09:38.001942       8 request.go:485] Throttling request took 459.837115ms, request: GET:https://172.19.32.1:443/apis/apps/v1beta1?timeout=32s
velero-d84694798-tjxxh velero I0502 20:09:38.003853       8 round_trippers.go:405] GET https://172.19.32.1:443/apis/apps/v1beta1?timeout=32s 200 OK in 1 milliseconds
velero-d84694798-tjxxh velero I0502 20:09:38.051933       8 request.go:485] Throttling request took 509.827635ms, request: GET:https://172.19.32.1:443/apis/puppet.hubspot.com/v1?timeout=32s
velero-d84694798-tjxxh velero I0502 20:09:38.054060       8 round_trippers.go:405] GET https://172.19.32.1:443/apis/puppet.hubspot.com/v1?timeout=32s 200 OK in 2 milliseconds
velero-d84694798-tjxxh velero I0502 20:09:38.101948       8 request.go:485] Throttling request took 559.840207ms, request: GET:https://172.19.32.1:443/apis/authorization.k8s.io/v1beta1?timeout=32s
velero-d84694798-tjxxh velero I0502 20:09:38.103988       8 round_trippers.go:405] GET https://172.19.32.1:443/apis/authorization.k8s.io/v1beta1?timeout=32s 200 OK in 1 milliseconds
velero-d84694798-tjxxh velero I0502 20:09:38.151935       8 request.go:485] Throttling request took 609.824185ms, request: GET:https://172.19.32.1:443/apis/custom.metrics.k8s.io/v1beta1?timeout=32s
velero-d84694798-tjxxh velero I0502 20:09:38.157880       8 round_trippers.go:405] GET https://172.19.32.1:443/apis/custom.metrics.k8s.io/v1beta1?timeout=32s 200 OK in 5 milliseconds
velero-d84694798-tjxxh velero I0502 20:09:38.201932       8 request.go:485] Throttling request took 659.818284ms, request: GET:https://172.19.32.1:443/apis/events.k8s.io/v1beta1?timeout=32s
velero-d84694798-tjxxh velero I0502 20:09:38.203783       8 round_trippers.go:405] GET https://172.19.32.1:443/apis/events.k8s.io/v1beta1?timeout=32s 200 OK in 1 milliseconds
velero-d84694798-tjxxh velero I0502 20:09:38.251945       8 request.go:485] Throttling request took 709.828692ms, request: GET:https://172.19.32.1:443/apis/scheduling.k8s.io/v1alpha1?timeout=32s
velero-d84694798-tjxxh velero I0502 20:09:38.254056       8 round_trippers.go:405] GET https://172.19.32.1:443/apis/scheduling.k8s.io/v1alpha1?timeout=32s 200 OK in 2 milliseconds
velero-d84694798-tjxxh velero I0502 20:09:38.301937       8 request.go:485] Throttling request took 759.818806ms, request: GET:https://172.19.32.1:443/apis/autoscaling/v1?timeout=32s
velero-d84694798-tjxxh velero I0502 20:09:38.304050       8 round_trippers.go:405] GET https://172.19.32.1:443/apis/autoscaling/v1?timeout=32s 200 OK in 2 milliseconds
velero-d84694798-tjxxh velero I0502 20:09:38.351955       8 request.go:485] Throttling request took 809.836037ms, request: GET:https://172.19.32.1:443/apis/storage.k8s.io/v1beta1?timeout=32s
velero-d84694798-tjxxh velero I0502 20:09:38.353770       8 round_trippers.go:405] GET https://172.19.32.1:443/apis/storage.k8s.io/v1beta1?timeout=32s 200 OK in 1 milliseconds
velero-d84694798-tjxxh velero I0502 20:09:38.401938       8 request.go:485] Throttling request took 859.816828ms, request: GET:https://172.19.32.1:443/apis/authentication.k8s.io/v1?timeout=32s
velero-d84694798-tjxxh velero I0502 20:09:38.403813       8 round_trippers.go:405] GET https://172.19.32.1:443/apis/authentication.k8s.io/v1?timeout=32s 200 OK in 1 milliseconds
velero-d84694798-tjxxh velero I0502 20:09:38.451943       8 request.go:485] Throttling request took 909.813714ms, request: GET:https://172.19.32.1:443/apis/hubspot.com/v1?timeout=32s
velero-d84694798-tjxxh velero I0502 20:09:38.453902       8 round_trippers.go:405] GET https://172.19.32.1:443/apis/hubspot.com/v1?timeout=32s 200 OK in 1 milliseconds
velero-d84694798-tjxxh velero I0502 20:09:38.501950       8 request.go:485] Throttling request took 959.821326ms, request: GET:https://172.19.32.1:443/apis/policy/v1beta1?timeout=32s
velero-d84694798-tjxxh velero I0502 20:09:38.503872       8 round_trippers.go:405] GET https://172.19.32.1:443/apis/policy/v1beta1?timeout=32s 200 OK in 1 milliseconds
velero-d84694798-tjxxh velero I0502 20:09:38.551950       8 request.go:485] Throttling request took 1.009820062s, request: GET:https://172.19.32.1:443/apis/vitess.hubspot.com/v1beta1?timeout=32s
velero-d84694798-tjxxh velero I0502 20:09:38.553830       8 round_trippers.go:405] GET https://172.19.32.1:443/apis/vitess.hubspot.com/v1beta1?timeout=32s 200 OK in 1 milliseconds
velero-d84694798-tjxxh velero I0502 20:09:38.601950       8 request.go:485] Throttling request took 1.059817637s, request: GET:https://172.19.32.1:443/apis/apiextensions.k8s.io/v1beta1?timeout=32s
velero-d84694798-tjxxh velero I0502 20:09:38.604167       8 round_trippers.go:405] GET https://172.19.32.1:443/apis/apiextensions.k8s.io/v1beta1?timeout=32s 200 OK in 2 milliseconds
velero-d84694798-tjxxh velero I0502 20:09:38.651952       8 request.go:485] Throttling request took 1.109818175s, request: GET:https://172.19.32.1:443/apis/monitoring.coreos.com/v1?timeout=32s
velero-d84694798-tjxxh velero I0502 20:09:38.654048       8 round_trippers.go:405] GET https://172.19.32.1:443/apis/monitoring.coreos.com/v1?timeout=32s 200 OK in 2 milliseconds
velero-d84694798-tjxxh velero I0502 20:09:38.701963       8 request.go:485] Throttling request took 1.159828602s, request: GET:https://172.19.32.1:443/apis/apiregistration.k8s.io/v1?timeout=32s
velero-d84694798-tjxxh velero I0502 20:09:38.704007       8 round_trippers.go:405] GET https://172.19.32.1:443/apis/apiregistration.k8s.io/v1?timeout=32s 200 OK in 1 milliseconds
velero-d84694798-tjxxh velero I0502 20:09:38.751962       8 request.go:485] Throttling request took 1.209820992s, request: GET:https://172.19.32.1:443/apis/authentication.k8s.io/v1beta1?timeout=32s
velero-d84694798-tjxxh velero I0502 20:09:38.754062       8 round_trippers.go:405] GET https://172.19.32.1:443/apis/authentication.k8s.io/v1beta1?timeout=32s 200 OK in 2 milliseconds
velero-d84694798-tjxxh velero I0502 20:09:38.801964       8 request.go:485] Throttling request took 1.259822616s, request: GET:https://172.19.32.1:443/apis/rbac.authorization.k8s.io/v1?timeout=32s
velero-d84694798-tjxxh velero I0502 20:09:38.804148       8 round_trippers.go:405] GET https://172.19.32.1:443/apis/rbac.authorization.k8s.io/v1?timeout=32s 200 OK in 2 milliseconds
velero-d84694798-tjxxh velero I0502 20:09:38.851942       8 request.go:485] Throttling request took 1.309802571s, request: GET:https://172.19.32.1:443/api/v1?timeout=32s
velero-d84694798-tjxxh velero I0502 20:09:38.888577       8 round_trippers.go:405] GET https://172.19.32.1:443/api/v1?timeout=32s 200 OK in 36 milliseconds
velero-d84694798-tjxxh velero I0502 20:09:38.901948       8 request.go:485] Throttling request took 1.359813263s, request: GET:https://172.19.32.1:443/apis/apiregistration.k8s.io/v1beta1?timeout=32s
velero-d84694798-tjxxh velero I0502 20:09:38.903871       8 round_trippers.go:405] GET https://172.19.32.1:443/apis/apiregistration.k8s.io/v1beta1?timeout=32s 200 OK in 1 milliseconds
velero-d84694798-tjxxh velero I0502 20:09:38.951939       8 request.go:485] Throttling request took 1.4098056s, request: GET:https://172.19.32.1:443/apis/batch/v1beta1?timeout=32s
velero-d84694798-tjxxh velero I0502 20:09:38.953906       8 round_trippers.go:405] GET https://172.19.32.1:443/apis/batch/v1beta1?timeout=32s 200 OK in 1 milliseconds
velero-d84694798-tjxxh velero I0502 20:09:39.001959       8 request.go:485] Throttling request took 1.459819076s, request: GET:https://172.19.32.1:443/apis/networking.k8s.io/v1?timeout=32s
velero-d84694798-tjxxh velero I0502 20:09:39.004228       8 round_trippers.go:405] GET https://172.19.32.1:443/apis/networking.k8s.io/v1?timeout=32s 200 OK in 2 milliseconds
velero-d84694798-tjxxh velero I0502 20:09:39.051940       8 request.go:485] Throttling request took 1.509793107s, request: GET:https://172.19.32.1:443/apis/certificates.k8s.io/v1beta1?timeout=32s
velero-d84694798-tjxxh velero I0502 20:09:39.053929       8 round_trippers.go:405] GET https://172.19.32.1:443/apis/certificates.k8s.io/v1beta1?timeout=32s 200 OK in 1 milliseconds
velero-d84694798-tjxxh velero I0502 20:09:39.101939       8 request.go:485] Throttling request took 1.559796522s, request: GET:https://172.19.32.1:443/apis/batch/v2alpha1?timeout=32s
velero-d84694798-tjxxh velero I0502 20:09:39.103840       8 round_trippers.go:405] GET https://172.19.32.1:443/apis/batch/v2alpha1?timeout=32s 200 OK in 1 milliseconds
velero-d84694798-tjxxh velero I0502 20:09:39.152037       8 request.go:485] Throttling request took 1.609893694s, request: GET:https://172.19.32.1:443/apis/rbac.authorization.k8s.io/v1alpha1?timeout=32s
velero-d84694798-tjxxh velero I0502 20:09:39.154037       8 round_trippers.go:405] GET https://172.19.32.1:443/apis/rbac.authorization.k8s.io/v1alpha1?timeout=32s 200 OK in 1 milliseconds
velero-d84694798-tjxxh velero I0502 20:09:39.201945       8 request.go:485] Throttling request took 1.65979511s, request: GET:https://172.19.32.1:443/apis/settings.k8s.io/v1alpha1?timeout=32s
velero-d84694798-tjxxh velero I0502 20:09:39.203966       8 round_trippers.go:405] GET https://172.19.32.1:443/apis/settings.k8s.io/v1alpha1?timeout=32s 200 OK in 1 milliseconds
velero-d84694798-tjxxh velero I0502 20:09:39.251949       8 request.go:485] Throttling request took 1.70980614s, request: GET:https://172.19.32.1:443/apis/admissionregistration.k8s.io/v1beta1?timeout=32s
velero-d84694798-tjxxh velero I0502 20:09:39.253981       8 round_trippers.go:405] GET https://172.19.32.1:443/apis/admissionregistration.k8s.io/v1beta1?timeout=32s 200 OK in 1 milliseconds
velero-d84694798-tjxxh velero I0502 20:09:39.301948       8 request.go:485] Throttling request took 1.759806784s, request: GET:https://172.19.32.1:443/apis/batch/v1?timeout=32s
velero-d84694798-tjxxh velero I0502 20:09:39.305231       8 round_trippers.go:405] GET https://172.19.32.1:443/apis/batch/v1?timeout=32s 200 OK in 3 milliseconds
velero-d84694798-tjxxh velero I0502 20:09:39.351941       8 request.go:485] Throttling request took 1.809795355s, request: GET:https://172.19.32.1:443/apis/rbac.authorization.k8s.io/v1beta1?timeout=32s
velero-d84694798-tjxxh velero I0502 20:09:39.354029       8 round_trippers.go:405] GET https://172.19.32.1:443/apis/rbac.authorization.k8s.io/v1beta1?timeout=32s 200 OK in 2 milliseconds
velero-d84694798-tjxxh velero I0502 20:09:39.401928       8 request.go:485] Throttling request took 1.859772975s, request: GET:https://172.19.32.1:443/apis/autoscaling/v2beta1?timeout=32s
velero-d84694798-tjxxh velero I0502 20:09:39.534163       8 round_trippers.go:405] GET https://172.19.32.1:443/apis/autoscaling/v2beta1?timeout=32s 200 OK in 132 milliseconds
velero-d84694798-tjxxh velero I0502 20:09:39.540388       8 round_trippers.go:405] GET https://172.19.32.1:443/api/v1/persistentvolumes/pvc-7369dcdf-6ab6-11e9-83bd-0e6cdcf47c10 200 OK in 5 milliseconds
velero-d84694798-tjxxh velero time="2019-05-02T20:09:39Z" level=info msg="Backing up resource" backup=velero/vt-backup-6 group=v1 groupResource=pods logSource="pkg/backup/item_backupper.go:163" name=pvc-7369dcdf-6ab6-11e9-83bd-0e6cdcf47c10 namespace=vt
velero-d84694798-tjxxh velero time="2019-05-02T20:09:39Z" level=debug msg="Executing pre hooks" backup=velero/vt-backup-6 group=v1 groupResource=pods logSource="pkg/backup/item_backupper.go:165" name=pvc-7369dcdf-6ab6-11e9-83bd-0e6cdcf47c10 namespace=vt
velero-d84694798-tjxxh velero time="2019-05-02T20:09:39Z" level=debug msg="Skipping action because it does not apply to this resource" backup=velero/vt-backup-6 group=v1 groupResource=pods logSource="pkg/backup/item_backupper.go:294" name=pvc-7369dcdf-6ab6-11e9-83bd-0e6cdcf47c10 namespace=vt
velero-d84694798-tjxxh velero time="2019-05-02T20:09:39Z" level=debug msg="Skipping action because it does not apply to this resource" backup=velero/vt-backup-6 group=v1 groupResource=pods logSource="pkg/backup/item_backupper.go:294" name=pvc-7369dcdf-6ab6-11e9-83bd-0e6cdcf47c10 namespace=vt
velero-d84694798-tjxxh velero time="2019-05-02T20:09:39Z" level=debug msg="Skipping action because it does not apply to this resource" backup=velero/vt-backup-6 group=v1 groupResource=pods logSource="pkg/backup/item_backupper.go:294" name=pvc-7369dcdf-6ab6-11e9-83bd-0e6cdcf47c10 namespace=vt
velero-d84694798-tjxxh velero time="2019-05-02T20:09:39Z" level=info msg="Executing takePVSnapshot" backup=velero/vt-backup-6 group=v1 groupResource=pods logSource="pkg/backup/item_backupper.go:383" name=pvc-7369dcdf-6ab6-11e9-83bd-0e6cdcf47c10 namespace=vt
velero-d84694798-tjxxh velero time="2019-05-02T20:09:39Z" level=info msg="Backup has volume snapshots disabled; skipping volume snapshot action." backup=velero/vt-backup-6 group=v1 groupResource=pods logSource="pkg/backup/item_backupper.go:386" name=pvc-7369dcdf-6ab6-11e9-83bd-0e6cdcf47c10 namespace=vt
velero-d84694798-tjxxh velero time="2019-05-02T20:09:39Z" level=debug msg="Executing post hooks" backup=velero/vt-backup-6 group=v1 groupResource=pods logSource="pkg/backup/item_backupper.go:230" name=pvc-7369dcdf-6ab6-11e9-83bd-0e6cdcf47c10 namespace=vt
velero-d84694798-tjxxh velero time="2019-05-02T20:09:39Z" level=debug msg="Skipping action because it does not apply to this resource" backup=velero/vt-backup-6 group=v1 groupResource=pods logSource="pkg/backup/item_backupper.go:294" name=asdf-0-vtdataroot-0-asdf-0-0 namespace=vt
velero-d84694798-tjxxh velero time="2019-05-02T20:09:39Z" level=debug msg="Executing post hooks" backup=velero/vt-backup-6 group=v1 groupResource=pods logSource="pkg/backup/item_backupper.go:230" name=asdf-0-vtdataroot-0-asdf-0-0 namespace=vt
velero-d84694798-tjxxh velero time="2019-05-02T20:09:39Z" level=debug msg="Skipping action because it does not apply to this resource" backup=velero/vt-backup-6 group=v1 groupResource=pods logSource="pkg/backup/item_backupper.go:294" name=asdf-0-0 namespace=vt
velero-d84694798-tjxxh velero time="2019-05-02T20:09:39Z" level=debug msg="Skipping action because it does not apply to this resource" backup=velero/vt-backup-6 group=v1 groupResource=pods logSource="pkg/backup/item_backupper.go:294" name=asdf-0-0 namespace=vt
velero-d84694798-tjxxh velero time="2019-05-02T20:09:39Z" level=debug msg="Executing post hooks" backup=velero/vt-backup-6 group=v1 groupResource=pods logSource="pkg/backup/item_backupper.go:230" name=asdf-0-0 namespace=vt

I saw this issue which could potentially be related, assuming this issue affects any item that contains many sub-items. https://github.com/heptio/velero/issues/1414

Environment:

• Velero version (use velero version): 0.11 built with patches for https://github.com/heptio/velero/pull/1293 and https://github.com/heptio/velero/pull/1399
• Kubernetes version (use kubectl version): v1.10.11

[skriss]

Thanks for the report @hmcgonig, I do think it's probably related to #1414 -- I think something changed upstream re: the discovery API in the last few releases. We'll dig into this.

[hmcgonig]

Thanks! Very much appreciated!