Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

response.body.children is not iterable TypeError: response.body.children is not iterable #376

Open
djjudas21 opened this issue Mar 21, 2024 · 3 comments
Open

response.body.children is not iterable TypeError: response.body.children is not iterable #376

djjudas21 opened this issue Mar 21, 2024 · 3 comments

Comments

@djjudas21
Copy link

I've started trying to use snapshots in anger for the first time and I'm running into this error:

E0321 21:17:30.634398       1 snapshot_controller.go:124] checkandUpdateContentStatus [snapcontent-f1302406-9689-43ba-9273-fa4962c22221]: error occurred failed to take snapshot of the volume pvc-0ccd4181-398b-4d3c-ad97-bc876159b7c4: "rpc error: code = Internal desc = TypeError: response.body.children is not iterable TypeError: response.body.children is not iterable\n    at FreeNASApiDriver.CreateSnapshot (/home/csi/app/src/driver/freenas/api.js:3993:43)\n    at runMicrotasks (<anonymous>)\n    at processTicksAndRejections (node:internal/process/task_queues:96:5)\n    at async requestHandlerProxy (/home/csi/app/bin/democratic-csi:217:18)"
E0321 21:17:30.634425       1 snapshot_controller_base.go:283] could not sync content "snapcontent-f1302406-9689-43ba-9273-fa4962c22221": failed to take snapshot of the volume pvc-0ccd4181-398b-4d3c-ad97-bc876159b7c4: "rpc error: code = Internal desc = TypeError: response.body.children is not iterable TypeError: response.body.children is not iterable\n    at FreeNASApiDriver.CreateSnapshot (/home/csi/app/src/driver/freenas/api.js:3993:43)\n    at runMicrotasks (<anonymous>)\n    at processTicksAndRejections (node:internal/process/task_queues:96:5)\n    at async requestHandlerProxy (/home/csi/app/bin/democratic-csi:217:18)"
I0321 21:17:30.634477       1 snapshot_controller_base.go:185] Failed to sync content "snapcontent-f1302406-9689-43ba-9273-fa4962c22221", will retry again: failed to take snapshot of the volume pvc-0ccd4181-398b-4d3c-ad97-bc876159b7c4: "rpc error: code = Internal desc = TypeError: response.body.children is not iterable TypeError: response.body.children is not iterable\n    at FreeNASApiDriver.CreateSnapshot (/home/csi/app/src/driver/freenas/api.js:3993:43)\n    at runMicrotasks (<anonymous>)\n    at processTicksAndRejections (node:internal/process/task_queues:96:5)\n    at async requestHandlerProxy (/home/csi/app/bin/democratic-csi:217:18)"
I0321 21:17:30.634561       1 event.go:285] Event(v1.ObjectReference{Kind:"VolumeSnapshotContent", Namespace:"", Name:"snapcontent-f1302406-9689-43ba-9273-fa4962c22221", UID:"9e559b9c-1249-401d-8cde-b80b46787470", APIVersion:"snapshot.storage.k8s.io/v1", ResourceVersion:"159777225", FieldPath:""}): type: 'Warning' reason: 'SnapshotContentCheckandUpdateFailed' Failed to check and update snapshot content: failed to take snapshot of the volume pvc-0ccd4181-398b-4d3c-ad97-bc876159b7c4: "rpc error: code = Internal desc = TypeError: response.body.children is not iterable TypeError: response.body.children is not iterable\n    at FreeNASApiDriver.CreateSnapshot (/home/csi/app/src/driver/freenas/api.js:3993:43)\n    at runMicrotasks (<anonymous>)\n    at processTicksAndRejections (node:internal/process/task_queues:96:5)\n    at async requestHandlerProxy (/home/csi/app/bin/democratic-csi:217:18)"

I'm wondering if this is because I recently upgraded to TrueNAS SCALE 23.10.2 - I'm sure snapshots used to work last time I tried.

I'm deploying chart democratic-csi-0.14.51.0 with the following values (plus a redacted API key)

driver:
  config:
    driver: freenas-api-nfs
    instance_id: truenas
    httpConnection:
      protocol: http
      host: 192.168.0.2
      port: 80
      allowInsecure: true
    zfs:
      datasetProperties:
        "org.freenas:description": "{{ parameters.[csi.storage.k8s.io/pvc/namespace] }}/{{ parameters.[csi.storage.k8s.io/pvc/name] }}"
      datasetParentName: ssd/k8s/vols
      detachedSnapshotsDatasetParentName: ssd/k8s/snaps
      datasetEnableQuotas: true
      datasetEnableReservation: false
      datasetPermissionsMode: "0777"
      datasetPermissionsUser: 0
      datasetPermissionsGroup: 0
    nfs:
      shareCommentTemplate: "{{ parameters.[csi.storage.k8s.io/pvc/namespace] }}-{{ parameters.[csi.storage.k8s.io/pvc/name] }}"
      shareHost: 192.168.0.2
      shareAlldirs: false
      shareAllowedHosts: []
      shareAllowedNetworks: []
      shareMaprootUser: ''
      shareMaprootGroup: ''
      shareMapallUser: root
      shareMapallGroup: root


# https://kubernetes-csi.github.io/docs/csi-driver-object.html
csiDriver:
  # should be globally unique for a given cluster
  name: "org.democratic-csi.nfs"
  storageCapacity: true

controller:
  enabled: true
  rbac:
    enabled: true
  replicaCount: 1
  hostNetwork: false
  priorityClassName: ""

  # https://github.com/kubernetes-csi/external-health-monitor
  externalHealthMonitorController:
    enabled: false
    resources:

  livenessProbe:
    enabled: true

  # democratic-csi controller
  driver:
    enabled: true
    image: docker.io/democraticcsi/democratic-csi:latest
    # imagePullPolicy: Always
    logLevel: info

    resources:

node:
  rbac:
    enabled: true
  enabled: true
  hostNetwork: true
  kubeletHostPath: /var/snap/microk8s/common/var/lib/kubelet

  priorityClassName: ""

  livenessProbe:
    enabled: true

  # democratic-csi node
  driver:
    enabled: true
    image: docker.io/democraticcsi/democratic-csi:latest
    # imagePullPolicy: Always
    logLevel: info

    resources:
      requests:
        memory: 100Mi
        cpu: 25m

  # https://kubernetes-csi.github.io/docs/node-driver-registrar.html
  driverRegistrar:
    resources:

# add note here about volume expansion requirements
storageClasses:
- name: truenas
  defaultClass: false
  reclaimPolicy: Delete
  volumeBindingMode: Immediate
  allowVolumeExpansion: true
  parameters:
    fsType: nfs
    mountOptions:
    - noatime
    - nfsvers=4

volumeSnapshotClasses:
  - name: truenas
    annotations:
      k10.kasten.io/is-snapshot-class: "true"
    defaultClass: false
    deletionPolicy: Delete
@travisghansen
Copy link
Member

#301

Can you enable debug logging on the controller so I can see the raw http response? This problem has been elusive but if you can send over the response that is leading to the situation it's probably easy to fix.

@djjudas21
Copy link
Author

OK. Assuming the controller debug mode is enabled by setting

controller:
  driver:
    enabled: true
    logLevel: debug

This is what the external-snapshotter container spits out. Annoyingly, no error, and it seems to have created the snapshots properly. I guess restarting the controller to enable debugging has "fixed" the problem temporarily.

I0322 13:53:25.751035       1 snapshot_controller.go:103] createSnapshot for content [snapcontent-ffd0a256-4e73-461a-a36a-69ae09511c95]: started
I0322 13:53:25.751047       1 snapshot_controller.go:291] createSnapshotWrapper: Creating snapshot for content snapcontent-ffd0a256-4e73-461a-a36a-69ae09511c95 through the plugin ...
I0322 13:53:25.751059       1 snapshot_controller.go:205] getCSISnapshotInput for content [snapcontent-ffd0a256-4e73-461a-a36a-69ae09511c95]
I0322 13:53:25.751069       1 snapshot_controller.go:472] getSnapshotClass: VolumeSnapshotClassName [truenas]
I0322 13:53:25.751082       1 snapshot_controller.go:603] setAnnVolumeSnapshotBeingCreated: set annotation [snapshot.storage.kubernetes.io/volumesnapshot-being-created:yes] on content [snapcontent-ffd0a256-4e73-461a-a36a-69ae09511c95].
I0322 13:53:25.751232       1 snapshot_controller_base.go:162] enqueued "snapcontent-ffd0a256-4e73-461a-a36a-69ae09511c95" for sync
I0322 13:53:25.765396       1 util.go:216] storeObjectUpdate updating content "snapcontent-ffd0a256-4e73-461a-a36a-69ae09511c95" with version 160021205
I0322 13:53:25.765435       1 snapshot_controller.go:628] setAnnVolumeSnapshotBeingCreated: volume snapshot content &{TypeMeta:{Kind: APIVersion:} ObjectMeta:{Name:snapcontent-ffd0a256-4e73-461a-a36a-69ae09511c95 GenerateName: Namespace: SelfLink: UID:41e7b5cd-6dbb-4331-8302-4d0ebdb8d6ec ResourceVersion:160021205 Generation:1 CreationTimestamp:2024-03-22 13:53:25 +0000 UTC DeletionTimestamp:<nil> DeletionGracePeriodSeconds:<nil> Labels:map[] Annotations:map[snapshot.storage.kubernetes.io/volumesnapshot-being-created:yes] OwnerReferences:[] Finalizers:[snapshot.storage.kubernetes.io/volumesnapshotcontent-bound-protection] ManagedFields:[{Manager:csi-snapshotter Operation:Update APIVersion:snapshot.storage.k8s.io/v1 Time:2024-03-22 13:53:25 +0000 UTC FieldsType:FieldsV1 FieldsV1:{"f:metadata":{"f:annotations":{".":{},"f:snapshot.storage.kubernetes.io/volumesnapshot-being-created":{}}}} Subresource:} {Manager:snapshot-controller Operation:Update APIVersion:snapshot.storage.k8s.io/v1 Time:2024-03-22 13:53:25 +0000 UTC FieldsType:FieldsV1 FieldsV1:{"f:metadata":{"f:finalizers":{".":{},"v:\"snapshot.storage.kubernetes.io/volumesnapshotcontent-bound-protection\"":{}}},"f:spec":{".":{},"f:deletionPolicy":{},"f:driver":{},"f:source":{".":{},"f:volumeHandle":{}},"f:volumeSnapshotClassName":{},"f:volumeSnapshotRef":{".":{},"f:apiVersion":{},"f:kind":{},"f:name":{},"f:namespace":{},"f:resourceVersion":{},"f:uid":{}}}} Subresource:}]} Spec:{VolumeSnapshotRef:{Kind:VolumeSnapshot Namespace:immich Name:k10-csi-snap-ldz7h8lsqmmj7m7g UID:ffd0a256-4e73-461a-a36a-69ae09511c95 APIVersion:snapshot.storage.k8s.io/v1 ResourceVersion:160021198 FieldPath:} DeletionPolicy:Delete Driver:org.democratic-csi.nfs VolumeSnapshotClassName:0xc0009109d0 Source:{VolumeHandle:0xc0009109c0 SnapshotHandle:<nil>} SourceVolumeMode:<nil>} Status:<nil>}
I0322 13:53:25.765703       1 snapshotter.go:56] CSI CreateSnapshot: snapshot-ffd0a256-4e73-461a-a36a-69ae09511c95
I0322 13:53:25.765722       1 connection.go:183] GRPC call: /csi.v1.Identity/GetPluginInfo
I0322 13:53:25.765734       1 connection.go:184] GRPC request: {}
I0322 13:53:25.767472       1 snapshot_controller_base.go:162] enqueued "snapcontent-ffd0a256-4e73-461a-a36a-69ae09511c95" for sync
I0322 13:53:25.770597       1 connection.go:186] GRPC response: {"name":"org.democratic-csi.nfs","vendor_version":"1.8.4"}
I0322 13:53:25.770682       1 connection.go:187] GRPC error: <nil>
I0322 13:53:25.770700       1 connection.go:183] GRPC call: /csi.v1.Controller/CreateSnapshot
I0322 13:53:25.770712       1 connection.go:184] GRPC request: {"name":"snapshot-ffd0a256-4e73-461a-a36a-69ae09511c95","source_volume_id":"pvc-57482218-4d41-4580-b559-4d065e3a31d0"}
I0322 13:53:26.801367       1 connection.go:186] GRPC response: {"snapshot":{"creation_time":{"seconds":1711115606},"ready_to_use":true,"size_bytes":4779984896,"snapshot_id":"pvc-57482218-4d41-4580-b559-4d065e3a31d0@snapshot-ffd0a256-4e73-461a-a36a-69ae09511c95","source_volume_id":"pvc-57482218-4d41-4580-b559-4d065e3a31d0"}}
I0322 13:53:26.801580       1 connection.go:187] GRPC error: <nil>
I0322 13:53:26.801593       1 snapshotter.go:76] CSI CreateSnapshot: snapshot-ffd0a256-4e73-461a-a36a-69ae09511c95 driver name [org.democratic-csi.nfs] snapshot ID [pvc-57482218-4d41-4580-b559-4d065e3a31d0@snapshot-ffd0a256-4e73-461a-a36a-69ae09511c95] time stamp [seconds:1711115606] size [4779984896] readyToUse [true]
I0322 13:53:26.801629       1 snapshot_controller.go:336] Created snapshot: driver org.democratic-csi.nfs, snapshotId pvc-57482218-4d41-4580-b559-4d065e3a31d0@snapshot-ffd0a256-4e73-461a-a36a-69ae09511c95, creationTime 2024-03-22 13:53:26 +0000 UTC, size 4779984896, readyToUse true
I0322 13:53:26.801653       1 snapshot_controller.go:417] updateSnapshotContentStatus: updating VolumeSnapshotContent [snapcontent-ffd0a256-4e73-461a-a36a-69ae09511c95], snapshotHandle pvc-57482218-4d41-4580-b559-4d065e3a31d0@snapshot-ffd0a256-4e73-461a-a36a-69ae09511c95, readyToUse true, createdAt 1711115606000000000, size 4779984896
I0322 13:53:26.816737       1 snapshot_controller_base.go:162] enqueued "snapcontent-ffd0a256-4e73-461a-a36a-69ae09511c95" for sync
I0322 13:53:26.827157       1 snapshot_controller.go:648] Removed VolumeSnapshotBeingCreated annotation from volume snapshot content snapcontent-ffd0a256-4e73-461a-a36a-69ae09511c95
I0322 13:53:26.827176       1 util.go:216] storeObjectUpdate updating content "snapcontent-ffd0a256-4e73-461a-a36a-69ae09511c95" with version 160021213
I0322 13:53:26.827184       1 util.go:216] storeObjectUpdate updating content "snapcontent-ffd0a256-4e73-461a-a36a-69ae09511c95" with version 160021213
I0322 13:53:26.827195       1 snapshot_controller_base.go:196] syncContentByKey[snapcontent-ffd0a256-4e73-461a-a36a-69ae09511c95]
I0322 13:53:26.827207       1 util.go:212] storeObjectUpdate: ignoring content "snapcontent-ffd0a256-4e73-461a-a36a-69ae09511c95" version 160021212
I0322 13:53:26.828002       1 snapshot_controller_base.go:162] enqueued "snapcontent-ffd0a256-4e73-461a-a36a-69ae09511c95" for sync
I0322 13:53:26.828028       1 snapshot_controller_base.go:196] syncContentByKey[snapcontent-ffd0a256-4e73-461a-a36a-69ae09511c95]
I0322 13:53:26.828038       1 util.go:216] storeObjectUpdate updating content "snapcontent-ffd0a256-4e73-461a-a36a-69ae09511c95" with version 160021213
I0322 13:53:26.828044       1 snapshot_controller.go:56] synchronizing VolumeSnapshotContent[snapcontent-ffd0a256-4e73-461a-a36a-69ae09511c95]
I0322 13:53:26.828070       1 snapshot_controller.go:564] Check if VolumeSnapshotContent[snapcontent-ffd0a256-4e73-461a-a36a-69ae09511c95] should be deleted.
I0322 13:53:26.998006       1 leaderelection.go:278] successfully renewed lease democratic-csi/external-snapshotter-leader-org-democratic-csi-nfs
I0322 13:53:27.155348       1 snapshot_controller_base.go:162] enqueued "snapcontent-6dc56c8b-8eb6-4ed7-8508-0abf111320a5" for sync
I0322 13:53:27.155401       1 snapshot_controller_base.go:196] syncContentByKey[snapcontent-6dc56c8b-8eb6-4ed7-8508-0abf111320a5]
I0322 13:53:27.500390       1 snapshot_controller_base.go:162] enqueued "snapcontent-77c7a6df-94aa-405d-8924-feb2854540df" for sync
I0322 13:53:27.500554       1 snapshot_controller_base.go:196] syncContentByKey[snapcontent-77c7a6df-94aa-405d-8924-feb2854540df]
I0322 13:53:27.500923       1 snapshot_controller_base.go:162] enqueued "snapcontent-6dc56c8b-8eb6-4ed7-8508-0abf111320a5" for sync
I0322 13:53:27.500938       1 snapshot_controller_base.go:196] syncContentByKey[snapcontent-6dc56c8b-8eb6-4ed7-8508-0abf111320a5]
I0322 13:53:27.501031       1 snapshot_controller_base.go:162] enqueued "snapcontent-77c7a6df-94aa-405d-8924-feb2854540df" for sync
I0322 13:53:27.501043       1 snapshot_controller_base.go:196] syncContentByKey[snapcontent-77c7a6df-94aa-405d-8924-feb2854540df]
I0322 13:53:28.019029       1 snapshot_controller_base.go:162] enqueued "snapcontent-6dc56c8b-8eb6-4ed7-8508-0abf111320a5" for sync
I0322 13:53:28.019080       1 snapshot_controller_base.go:196] syncContentByKey[snapcontent-6dc56c8b-8eb6-4ed7-8508-0abf111320a5]
I0322 13:53:28.336583       1 snapshot_controller_base.go:162] enqueued "snapcontent-1de1d73d-813b-41c1-a187-f2f34150e54b" for sync
I0322 13:53:28.336637       1 snapshot_controller_base.go:196] syncContentByKey[snapcontent-1de1d73d-813b-41c1-a187-f2f34150e54b]
I0322 13:53:28.336661       1 util.go:188] storeObjectUpdate: adding content "snapcontent-1de1d73d-813b-41c1-a187-f2f34150e54b", version 160021230
I0322 13:53:28.336679       1 snapshot_controller.go:56] synchronizing VolumeSnapshotContent[snapcontent-1de1d73d-813b-41c1-a187-f2f34150e54b]
I0322 13:53:28.336722       1 snapshot_controller.go:564] Check if VolumeSnapshotContent[snapcontent-1de1d73d-813b-41c1-a187-f2f34150e54b] should be deleted.
I0322 13:53:28.336735       1 snapshot_controller.go:75] syncContent: Call CreateSnapshot for content snapcontent-1de1d73d-813b-41c1-a187-f2f34150e54b
I0322 13:53:28.336747       1 snapshot_controller.go:103] createSnapshot for content [snapcontent-1de1d73d-813b-41c1-a187-f2f34150e54b]: started
I0322 13:53:28.336760       1 snapshot_controller.go:291] createSnapshotWrapper: Creating snapshot for content snapcontent-1de1d73d-813b-41c1-a187-f2f34150e54b through the plugin ...
I0322 13:53:28.336772       1 snapshot_controller.go:205] getCSISnapshotInput for content [snapcontent-1de1d73d-813b-41c1-a187-f2f34150e54b]
I0322 13:53:28.336784       1 snapshot_controller.go:472] getSnapshotClass: VolumeSnapshotClassName [truenas]
I0322 13:53:28.336797       1 snapshot_controller.go:603] setAnnVolumeSnapshotBeingCreated: set annotation [snapshot.storage.kubernetes.io/volumesnapshot-being-created:yes] on content [snapcontent-1de1d73d-813b-41c1-a187-f2f34150e54b].
I0322 13:53:28.356845       1 util.go:216] storeObjectUpdate updating content "snapcontent-1de1d73d-813b-41c1-a187-f2f34150e54b" with version 160021232
I0322 13:53:28.356895       1 snapshot_controller.go:628] setAnnVolumeSnapshotBeingCreated: volume snapshot content &{TypeMeta:{Kind: APIVersion:} ObjectMeta:{Name:snapcontent-1de1d73d-813b-41c1-a187-f2f34150e54b GenerateName: Namespace: SelfLink: UID:98c0462c-aa2e-4f9a-b48b-b6975ea93af5 ResourceVersion:160021232 Generation:1 CreationTimestamp:2024-03-22 13:53:28 +0000 UTC DeletionTimestamp:<nil> DeletionGracePeriodSeconds:<nil> Labels:map[] Annotations:map[snapshot.storage.kubernetes.io/volumesnapshot-being-created:yes] OwnerReferences:[] Finalizers:[] ManagedFields:[{Manager:csi-snapshotter Operation:Update APIVersion:snapshot.storage.k8s.io/v1 Time:2024-03-22 13:53:28 +0000 UTC FieldsType:FieldsV1 FieldsV1:{"f:metadata":{"f:annotations":{".":{},"f:snapshot.storage.kubernetes.io/volumesnapshot-being-created":{}}}} Subresource:} {Manager:snapshot-controller Operation:Update APIVersion:snapshot.storage.k8s.io/v1 Time:2024-03-22 13:53:28 +0000 UTC FieldsType:FieldsV1 FieldsV1:{"f:spec":{".":{},"f:deletionPolicy":{},"f:driver":{},"f:source":{".":{},"f:volumeHandle":{}},"f:volumeSnapshotClassName":{},"f:volumeSnapshotRef":{".":{},"f:apiVersion":{},"f:kind":{},"f:name":{},"f:namespace":{},"f:resourceVersion":{},"f:uid":{}}}} Subresource:}]} Spec:{VolumeSnapshotRef:{Kind:VolumeSnapshot Namespace:immich Name:k10-csi-snap-xn7g8vfnfdtq7tfh UID:1de1d73d-813b-41c1-a187-f2f34150e54b APIVersion:snapshot.storage.k8s.io/v1 ResourceVersion:160021214 FieldPath:} DeletionPolicy:Delete Driver:org.democratic-csi.nfs VolumeSnapshotClassName:0xc0008880a0 Source:{VolumeHandle:0xc000888090 SnapshotHandle:<nil>} SourceVolumeMode:<nil>} Status:<nil>}
I0322 13:53:28.357113       1 snapshotter.go:56] CSI CreateSnapshot: snapshot-1de1d73d-813b-41c1-a187-f2f34150e54b
I0322 13:53:28.357132       1 connection.go:183] GRPC call: /csi.v1.Identity/GetPluginInfo
I0322 13:53:28.357144       1 connection.go:184] GRPC request: {}
I0322 13:53:28.358696       1 snapshot_controller_base.go:162] enqueued "snapcontent-1de1d73d-813b-41c1-a187-f2f34150e54b" for sync
I0322 13:53:28.361780       1 connection.go:186] GRPC response: {"name":"org.democratic-csi.nfs","vendor_version":"1.8.4"}
I0322 13:53:28.361881       1 connection.go:187] GRPC error: <nil>
I0322 13:53:28.361899       1 connection.go:183] GRPC call: /csi.v1.Controller/CreateSnapshot
I0322 13:53:28.361911       1 connection.go:184] GRPC request: {"name":"snapshot-1de1d73d-813b-41c1-a187-f2f34150e54b","source_volume_id":"pvc-0ccd4181-398b-4d3c-ad97-bc876159b7c4"}
I0322 13:53:29.535327       1 snapshot_controller_base.go:162] enqueued "snapcontent-1de1d73d-813b-41c1-a187-f2f34150e54b" for sync
I0322 13:53:30.133507       1 snapshot_controller_base.go:162] enqueued "snapcontent-7d9f4ade-9825-408a-83c1-1de1454f6955" for sync
I0322 13:53:30.133558       1 snapshot_controller_base.go:196] syncContentByKey[snapcontent-7d9f4ade-9825-408a-83c1-1de1454f6955]
I0322 13:53:30.133583       1 util.go:188] storeObjectUpdate: adding content "snapcontent-7d9f4ade-9825-408a-83c1-1de1454f6955", version 160021250
I0322 13:53:30.133602       1 snapshot_controller.go:56] synchronizing VolumeSnapshotContent[snapcontent-7d9f4ade-9825-408a-83c1-1de1454f6955]
I0322 13:53:30.133644       1 snapshot_controller.go:564] Check if VolumeSnapshotContent[snapcontent-7d9f4ade-9825-408a-83c1-1de1454f6955] should be deleted.
I0322 13:53:30.133656       1 snapshot_controller.go:75] syncContent: Call CreateSnapshot for content snapcontent-7d9f4ade-9825-408a-83c1-1de1454f6955
I0322 13:53:30.133668       1 snapshot_controller.go:103] createSnapshot for content [snapcontent-7d9f4ade-9825-408a-83c1-1de1454f6955]: started
I0322 13:53:30.133680       1 snapshot_controller.go:291] createSnapshotWrapper: Creating snapshot for content snapcontent-7d9f4ade-9825-408a-83c1-1de1454f6955 through the plugin ...
I0322 13:53:30.133692       1 snapshot_controller.go:205] getCSISnapshotInput for content [snapcontent-7d9f4ade-9825-408a-83c1-1de1454f6955]
I0322 13:53:30.133703       1 snapshot_controller.go:472] getSnapshotClass: VolumeSnapshotClassName [truenas]
I0322 13:53:30.133716       1 snapshot_controller.go:603] setAnnVolumeSnapshotBeingCreated: set annotation [snapshot.storage.kubernetes.io/volumesnapshot-being-created:yes] on content [snapcontent-7d9f4ade-9825-408a-83c1-1de1454f6955].
I0322 13:53:30.168017       1 util.go:216] storeObjectUpdate updating content "snapcontent-7d9f4ade-9825-408a-83c1-1de1454f6955" with version 160021252
I0322 13:53:30.168056       1 snapshot_controller.go:628] setAnnVolumeSnapshotBeingCreated: volume snapshot content &{TypeMeta:{Kind: APIVersion:} ObjectMeta:{Name:snapcontent-7d9f4ade-9825-408a-83c1-1de1454f6955 GenerateName: Namespace: SelfLink: UID:1141a1e7-79e5-4967-9c42-8ee5f6cc52be ResourceVersion:160021252 Generation:1 CreationTimestamp:2024-03-22 13:53:30 +0000 UTC DeletionTimestamp:<nil> DeletionGracePeriodSeconds:<nil> Labels:map[] Annotations:map[snapshot.storage.kubernetes.io/volumesnapshot-being-created:yes] OwnerReferences:[] Finalizers:[] ManagedFields:[{Manager:csi-snapshotter Operation:Update APIVersion:snapshot.storage.k8s.io/v1 Time:2024-03-22 13:53:30 +0000 UTC FieldsType:FieldsV1 FieldsV1:{"f:metadata":{"f:annotations":{".":{},"f:snapshot.storage.kubernetes.io/volumesnapshot-being-created":{}}}} Subresource:} {Manager:snapshot-controller Operation:Update APIVersion:snapshot.storage.k8s.io/v1 Time:2024-03-22 13:53:30 +0000 UTC FieldsType:FieldsV1 FieldsV1:{"f:spec":{".":{},"f:deletionPolicy":{},"f:driver":{},"f:source":{".":{},"f:volumeHandle":{}},"f:volumeSnapshotClassName":{},"f:volumeSnapshotRef":{".":{},"f:apiVersion":{},"f:kind":{},"f:name":{},"f:namespace":{},"f:resourceVersion":{},"f:uid":{}}}} Subresource:}]} Spec:{VolumeSnapshotRef:{Kind:VolumeSnapshot Namespace:immich Name:k10-csi-snap-d5gkwmhtl98qtwbh UID:7d9f4ade-9825-408a-83c1-1de1454f6955 APIVersion:snapshot.storage.k8s.io/v1 ResourceVersion:160021226 FieldPath:} DeletionPolicy:Delete Driver:org.democratic-csi.nfs VolumeSnapshotClassName:0xc000910fa0 Source:{VolumeHandle:0xc000910f90 SnapshotHandle:<nil>} SourceVolumeMode:<nil>} Status:<nil>}
I0322 13:53:30.168363       1 snapshotter.go:56] CSI CreateSnapshot: snapshot-7d9f4ade-9825-408a-83c1-1de1454f6955
I0322 13:53:30.168469       1 connection.go:183] GRPC call: /csi.v1.Identity/GetPluginInfo
I0322 13:53:30.168529       1 connection.go:184] GRPC request: {}
I0322 13:53:30.171041       1 snapshot_controller_base.go:162] enqueued "snapcontent-7d9f4ade-9825-408a-83c1-1de1454f6955" for sync
I0322 13:53:30.175521       1 connection.go:186] GRPC response: {"name":"org.democratic-csi.nfs","vendor_version":"1.8.4"}
I0322 13:53:30.175601       1 connection.go:187] GRPC error: <nil>
I0322 13:53:30.175619       1 connection.go:183] GRPC call: /csi.v1.Controller/CreateSnapshot
I0322 13:53:30.175631       1 connection.go:184] GRPC request: {"name":"snapshot-7d9f4ade-9825-408a-83c1-1de1454f6955","source_volume_id":"pvc-6bbbb99f-5236-4f25-a18e-3eb33bfe81b9"}
I0322 13:53:30.560824       1 snapshot_controller_base.go:162] enqueued "snapcontent-6dc56c8b-8eb6-4ed7-8508-0abf111320a5" for sync
I0322 13:53:30.560881       1 snapshot_controller_base.go:196] syncContentByKey[snapcontent-6dc56c8b-8eb6-4ed7-8508-0abf111320a5]
I0322 13:53:30.561123       1 snapshot_controller_base.go:162] enqueued "snapcontent-6dc56c8b-8eb6-4ed7-8508-0abf111320a5" for sync
I0322 13:53:30.561180       1 snapshot_controller_base.go:196] syncContentByKey[snapcontent-6dc56c8b-8eb6-4ed7-8508-0abf111320a5]
I0322 13:53:31.131049       1 snapshot_controller_base.go:162] enqueued "snapcontent-7d9f4ade-9825-408a-83c1-1de1454f6955" for sync
I0322 13:53:32.088029       1 leaderelection.go:278] successfully renewed lease democratic-csi/external-snapshotter-leader-org-democratic-csi-nfs
I0322 13:53:33.322165       1 connection.go:186] GRPC response: {"snapshot":{"creation_time":{"seconds":1711115610},"ready_to_use":true,"size_bytes":1006264320,"snapshot_id":"pvc-0ccd4181-398b-4d3c-ad97-bc876159b7c4@snapshot-1de1d73d-813b-41c1-a187-f2f34150e54b","source_volume_id":"pvc-0ccd4181-398b-4d3c-ad97-bc876159b7c4"}}

@travisghansen
Copy link
Member

Ok, leave that enabled for a bit if you don't mind and send the logs from the csi-driver container instead if it ever pops up again.

Thanks!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@travisghansen @djjudas21