democratic-csi / charts

MIT License
20 stars 28 forks source link

Questions about `datasetPermissions*` and `shareMaproot*` fields #43

Closed zulhfreelancer closed 1 year ago

zulhfreelancer commented 1 year ago

I'm running TrueNAS Core 13 and democratic-csi Helm chart v0.13.7 (scroll down to see my Helm chart's values file).

In my TrueNAS, I've a created k8s-nfs group (GID: 1001) with k8s-nfs user (UID: 1007) as group member.

I also have followed the Server Prep section based on the democratic-csi's README, specifically this section:

  • Ensure that user has passwordless sudo privileges:

    csi ALL=(ALL) NOPASSWD:ALL
    
    # if on CORE 12.0-u3+ you should be able to do the following
    # which will ensure it does not get reset during reboots etc
    # at the command prompt
    cli
    
    # after you enter the truenas cli and are at that prompt
    account user query select=id,username,uid,sudo_nopasswd
    
    # find the `id` of the user you want to update (note, this is distinct from the `uid`)
    account user update id=<id> sudo=true
    account user update id=<id> sudo_nopasswd=true
    # optional if you want to disable password
    #account user update id=<id> password_disabled=true
    
    # exit cli by hitting ctrl-d
    
    # confirm sudoers file is appropriate
    cat /usr/local/etc/sudoers

    (note this can get reset by FreeNAS if you alter the user via the GUI later)

FYI, I've replaced the sample user (csi) above with my user (k8s-nfs) when executing the commands.

I noticed that my PVCs failed to provision when I set these fields:

But when I did not set them like below, my PVCs are happy.

csiDriver:
  name: "org.democratic-csi.nfs"

storageClasses:
- name: freenas-nfs-csi
  defaultClass: false
  reclaimPolicy: Delete
  volumeBindingMode: Immediate
  allowVolumeExpansion: true
  parameters:
    fsType: nfs

  mountOptions:
  - noatime
  - nfsvers=4
  secrets:
    provisioner-secret:
    controller-publish-secret:
    node-stage-secret:
    node-publish-secret:
    controller-expand-secret:

driver:
  config:
    driver: freenas-nfs
    instance_id:
    httpConnection:
      protocol: http
      host: <my-truenas-core-ip>
      port: 80
      apiVersion: 2
      apiKey: redacted
      allowInsecure: true
    sshConnection:
      host: <my-truenas-core-ip>
      port: 22
      username: k8s-nfs
      privateKey: |
        -----BEGIN OPENSSH PRIVATE KEY-----
        redacted
        -----END OPENSSH PRIVATE KEY-----
    zfs:
      cli:
        sudoEnabled: true
      datasetParentName: foo/k8s/nfs/vols
      detachedSnapshotsDatasetParentName: foo/k8s/nfs/snaps
      datasetEnableQuotas: true
      datasetEnableReservation: false
      datasetPermissionsMode: "0777"
      # datasetPermissionsUser: 1007 # <------------------- THIS
      # datasetPermissionsGroup: 1001 # <------------------ THIS
    nfs:
      shareHost: <my-truenas-core-ip>
      shareAlldirs: false
      shareAllowedHosts: []
      shareAllowedNetworks: []
      # shareMaprootUser: 1007 # <------------------------- THIS
      # shareMaprootGroup: 1001 # <------------------------ THIS
      shareMapallUser: ""
      shareMapallGroup: ""

Questions

  1. What are the purpose of driver.config.zfs.datasetPermissionsUser, driver.config.zfs.datasetPermissionsGroup, driver.config.nfs.shareMaprootUser and driver.config.nfs.shareMaprootGroup fields?
  2. In what scenario(s) we need to set these fields?
    • Is it a good idea not to set them like above?
    • What are the security risks if we did not set them?
  3. Not related to question 1 and 2 (because I'm curious), do we have a list/table somewhere that shows which operations taken by democratic-csi via HTTP vs SSH? I noticed that both driver.config.httpConnection and driver.config.sshConnection blocks need to co-exist. My PVCs did not get created properly if I didn't specify both blocks.
zulhfreelancer commented 1 year ago

@travisghansen - any chance you could take a look at my question above? Your help would be greatly appreciated! 🙂

travisghansen commented 1 year ago

Welcome! Been super busy and on my phone atm but I’ll do my best right now.

  1. dataset user/group does a chmod on the fs server-side. If you are using proper alignment of configs etc kubelet can set that for you using pod security context. The share map values are standard nfs things so I’m sure others have better explanations on those than I do. I would like to see the error logs for the failures when they were set.

  2. with nfs the usage is almost certainly unnecessary. At the end of the day if you use the security context as mentioned above kubelet will set the right permissions for you. Setting the user/group would generally be counter-productive as the user/group of the pod will almost certainly not match the values you set in the config. In short I would leave them empty unless you otherwise have a need.

  3. this is a good question and easy to answer…all zfs operations are done over ssh (and have shared code paths with all the other zfs/ssh drivers). All share buildup/teardown are done using the api. It’s a very clear line of separation in the code as so much of the logic is shared across drivers.

As an aside, I always recommend nfsv3 unless you have a very specific need to use v4. nfs v4 is a case of newer doesn’t mean better and frankly the things trying to be addressed by v4 are generally a waste in a k8s world.

https://github.com/democratic-csi/democratic-csi/issues/274#issuecomment-1426922600

zulhfreelancer commented 1 year ago

Thank you for the answers, @travisghansen. Much appreciated.

Here is how everything looks when I set 4 fields in question above.

All pods including test pod

All democratic-csi pods are happy

pods

Containers in controller pod

All containers in this democratic-csi controller pod are happy

containers

Test PVC

It's not happy. Thus, my test pod (orang color above) also not happy. See kubectl describe output below.

pvc

Test Pod & PVC manifests

kind: PersistentVolumeClaim
apiVersion: v1
metadata:
  name: test-claim-nfs-pvc
  namespace: democratic-csi
  annotations:
    volume.beta.kubernetes.io/storage-class: "freenas-nfs-csi"
spec:
  storageClassName: freenas-nfs-csi
  accessModes:
    - ReadWriteOnce
  resources:
    requests:
      storage: 1Gi
---
apiVersion: v1
kind: Pod
metadata:
  name: test-claim-nfs-pod
  namespace: democratic-csi
spec:
  volumes:
    - name: task-pv-storage
      persistentVolumeClaim:
        claimName: test-claim-nfs-pvc
  containers:
    - name: task-pv-container
      image: nginx
      ports:
        - containerPort: 80
          name: "http-server"
      volumeMounts:
        - mountPath: "/usr/share/nginx/html"
          name: task-pv-storage

Output of kubectl describe pvc test-claim-nfs-pvc

Name:          test-claim-nfs-pvc
Namespace:     democratic-csi
StorageClass:  freenas-nfs-csi
Status:        Pending
Volume:        
Labels:        <none>
Annotations:   volume.beta.kubernetes.io/storage-class: freenas-nfs-csi
               volume.beta.kubernetes.io/storage-provisioner: org.democratic-csi.nfs
               volume.kubernetes.io/storage-provisioner: org.democratic-csi.nfs
Finalizers:    [kubernetes.io/pvc-protection]
Capacity:      
Access Modes:  
VolumeMode:    Filesystem
Used By:       test-claim-nfs-pod
Events:
  Type     Reason                Age                From                                                                                                            Message
  ----     ------                ----               ----                                                                                                            -------
  Warning  ProvisioningFailed    21s (x5 over 60s)  org.democratic-csi.nfs_zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d_7cfa307e-ea4e-49bd-b781-77e22c87dcf1  failed to provision volume with StorageClass "freenas-nfs-csi": rpc error: code = Unknown desc = received error creating nfs share - code: 422 body: {"sharingnfs_create.maproot_user":[{"message":"User not found","errno":22}],"sharingnfs_create.maproot_group":[{"message":"Group not found","errno":22}]}
  Normal   ExternalProvisioning  9s (x6 over 67s)   persistentvolume-controller                                                                                     waiting for a volume to be created, either by external provisioner "org.democratic-csi.nfs" or manually created by system administrator
  Normal   Provisioning          5s (x6 over 67s)   org.democratic-csi.nfs_zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d_7cfa307e-ea4e-49bd-b781-77e22c87dcf1  External provisioner is provisioning volume for claim "democratic-csi/test-claim-nfs-pvc"
Controller pod logs zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:19:49.886939 1 feature_gate.go:245] feature gates: &{map[]} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter I0721 03:19:50.406501 1 main.go:104] Version: v5.0.0-rc3-webhook zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter I0721 03:19:50.410065 1 connection.go:154] Connecting to unix:///csi-data/csi.sock zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:19:49.887138 1 csi-provisioner.go:139] Version: v3.1.0 zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-resizer I0721 03:19:50.142133 1 main.go:93] Version : v1.4.0 zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:19:49.887161 1 csi-provisioner.go:162] Building kube configs for running in cluster... zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:19:49.889328 1 connection.go:154] Connecting to unix:///csi-data/csi.sock zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-resizer I0721 03:19:50.142314 1 feature_gate.go:245] feature gates: &{map[]} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-resizer I0721 03:19:50.145120 1 connection.go:154] Connecting to unix:///csi-data/csi.sock zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d csi-driver grpc implementation: @grpc/grpc-js zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d csi-proxy 2023/07/21 03:19:53 BIND_TO [unix:///csi-data/csi.sock], PROXY_TO [unix:///csi-data/csi.sock.internal] zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d csi-proxy 2023/07/21 03:19:53 waiting for socket [/csi-data/csi.sock.internal] to appear, 60s remaining zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d csi-proxy 2023/07/21 03:19:54 waiting for socket [/csi-data/csi.sock.internal] to appear, 59s remaining zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d csi-driver {"host":"zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d","level":"info","message":"initializing csi driver: freenas-nfs","service":"democratic-csi","timestamp":"2023-07-21T03:19:54.692Z"} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d csi-proxy 2023/07/21 03:19:55 waiting for socket [/csi-data/csi.sock.internal] to appear, 58s remaining zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d csi-driver {"host":"zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d","level":"info","message":"starting csi server - node version: v16.18.0, package version: 1.8.3, config file: /config/..2023_07_21_03_19_49.4261205884/driver-config-file.yaml, csi-name: org.democratic-csi.nfs, csi-driver: freenas-nfs, csi-mode: controller, csi-version: 1.5.0, address: , socket: unix:///csi-data/csi.sock.internal","service":"democratic-csi","timestamp":"2023-07-21T03:19:56.595Z"} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d csi-proxy 2023/07/21 03:19:56 waiting for socket [/csi-data/csi.sock.internal] to appear, 57s remaining zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d csi-proxy 2023/07/21 03:19:57 PROXY_TO [unix:///csi-data/csi.sock.internal] is ready! zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d csi-proxy 2023/07/21 03:19:57 BIND_TO [unix:///csi-data/csi.sock] is ready! zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:19:58.003739 1 common.go:111] Probing CSI driver for readiness zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:19:58.003794 1 connection.go:183] GRPC call: /csi.v1.Identity/Probe zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d csi-driver {"host":"zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d","level":"info","message":"new request - driver: FreeNASSshDriver method: Probe call: {\"metadata\":{\"x-forwarded-host\":[\"localhost\"],\"user-agent\":[\"grpc-go/1.40.0\"]},\"request\":{},\"cancelled\":false}","service":"democratic-csi","timestamp":"2023-07-21T03:19:58.037Z"} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:19:58.003832 1 connection.go:184] GRPC request: {} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d csi-proxy 2023/07/21 03:19:58 request (://localhost) POST /csi.v1.Identity/Probe HTTP/2.0 zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d csi-proxy 2023/07/21 03:19:58 request headers map[Content-Type:[application/grpc] Grpc-Timeout:[89992955u] Te:[trailers] User-Agent:[grpc-go/1.40.0]] zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d csi-proxy 2023/07/21 03:19:58 Dialing upstream: unix:///csi-data/csi.sock.internal zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d csi-driver {"host":"zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d","level":"info","message":"new request - driver: FreeNASSshDriver method: Probe call: {\"metadata\":{\"x-forwarded-host\":[\"localhost\"],\"user-agent\":[\"grpc-go/1.40.0\"]},\"request\":{},\"cancelled\":false}","service":"democratic-csi","timestamp":"2023-07-21T03:19:58.219Z"} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d csi-driver {"host":"zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d","level":"info","message":"new response - driver: FreeNASSshDriver method: Probe response: {\"ready\":{\"value\":true}}","service":"democratic-csi","timestamp":"2023-07-21T03:19:58.262Z"} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d csi-proxy 2023/07/21 03:19:58 request (://localhost) POST /csi.v1.Identity/Probe HTTP/2.0 zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d csi-proxy 2023/07/21 03:19:58 request headers map[Content-Type:[application/grpc] Grpc-Timeout:[89995486u] Te:[trailers] User-Agent:[grpc-go/1.40.0]] zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d csi-proxy 2023/07/21 03:19:58 request (://localhost) POST /csi.v1.Identity/GetPluginInfo HTTP/2.0 zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d csi-proxy 2023/07/21 03:19:58 request headers map[Content-Type:[application/grpc] Grpc-Timeout:[89998630u] Te:[trailers] User-Agent:[grpc-go/1.40.0]] zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-resizer I0721 03:19:58.200935 1 common.go:111] Probing CSI driver for readiness zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-resizer I0721 03:19:58.200981 1 connection.go:183] GRPC call: /csi.v1.Identity/Probe zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-resizer I0721 03:19:58.200996 1 connection.go:184] GRPC request: {} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-resizer I0721 03:19:58.281747 1 connection.go:186] GRPC response: {"ready":{"value":true}} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-resizer I0721 03:19:58.282247 1 connection.go:187] GRPC error: zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-resizer I0721 03:19:58.282535 1 connection.go:183] GRPC call: /csi.v1.Identity/GetPluginInfo zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-resizer I0721 03:19:58.283133 1 connection.go:184] GRPC request: {} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d csi-driver {"host":"zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d","level":"info","message":"new request - driver: FreeNASSshDriver method: GetPluginInfo call: {\"metadata\":{\"user-agent\":[\"grpc-go/1.40.0\"],\"x-forwarded-host\":[\"localhost\"]},\"request\":{},\"cancelled\":false}","service":"democratic-csi","timestamp":"2023-07-21T03:19:58.295Z"} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d csi-driver {"host":"zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d","level":"info","message":"new response - driver: FreeNASSshDriver method: GetPluginInfo response: {\"name\":\"org.democratic-csi.nfs\",\"vendor_version\":\"1.8.3\"}","service":"democratic-csi","timestamp":"2023-07-21T03:19:58.297Z"} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d csi-driver {"host":"zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d","level":"info","message":"new response - driver: FreeNASSshDriver method: Probe response: {\"ready\":{\"value\":true}}","service":"democratic-csi","timestamp":"2023-07-21T03:19:58.308Z"} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-resizer I0721 03:19:58.313011 1 connection.go:186] GRPC response: {"name":"org.democratic-csi.nfs","vendor_version":"1.8.3"} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-resizer I0721 03:19:58.313391 1 connection.go:187] GRPC error: zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-resizer I0721 03:19:58.313452 1 main.go:141] CSI driver name: "org.democratic-csi.nfs" zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-resizer I0721 03:19:58.313494 1 connection.go:183] GRPC call: /csi.v1.Identity/GetPluginCapabilities zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-resizer I0721 03:19:58.313529 1 connection.go:184] GRPC request: {} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d csi-proxy 2023/07/21 03:19:58 request (://localhost) POST /csi.v1.Identity/GetPluginCapabilities HTTP/2.0 zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d csi-proxy 2023/07/21 03:19:58 request headers map[Content-Type:[application/grpc] Grpc-Timeout:[89998630u] Te:[trailers] User-Agent:[grpc-go/1.40.0]] zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:19:58.319148 1 connection.go:186] GRPC response: {"ready":{"value":true}} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:19:58.319749 1 connection.go:187] GRPC error: zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:19:58.320121 1 connection.go:183] GRPC call: /csi.v1.Identity/GetPluginInfo zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:19:58.320202 1 connection.go:184] GRPC request: {} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d csi-proxy 2023/07/21 03:19:58 request (://localhost) POST /csi.v1.Identity/GetPluginInfo HTTP/2.0 zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d csi-proxy 2023/07/21 03:19:58 request headers map[Content-Type:[application/grpc] Grpc-Timeout:[89999306u] Te:[trailers] User-Agent:[grpc-go/1.40.0]] zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d csi-driver {"host":"zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d","level":"info","message":"new request - driver: FreeNASSshDriver method: GetPluginCapabilities call: {\"metadata\":{\"user-agent\":[\"grpc-go/1.40.0\"],\"x-forwarded-host\":[\"localhost\"]},\"request\":{},\"cancelled\":false}","service":"democratic-csi","timestamp":"2023-07-21T03:19:58.328Z"} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d csi-driver {"host":"zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d","level":"info","message":"new response - driver: FreeNASSshDriver method: GetPluginCapabilities response: {\"capabilities\":[{\"service\":{\"type\":\"CONTROLLER_SERVICE\"}},{\"volume_expansion\":{\"type\":\"ONLINE\"}}]}","service":"democratic-csi","timestamp":"2023-07-21T03:19:58.329Z"} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d csi-driver {"host":"zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d","level":"info","message":"new request - driver: FreeNASSshDriver method: GetPluginInfo call: {\"metadata\":{\"user-agent\":[\"grpc-go/1.40.0\"],\"x-forwarded-host\":[\"localhost\"]},\"request\":{},\"cancelled\":false}","service":"democratic-csi","timestamp":"2023-07-21T03:19:58.340Z"} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d csi-driver {"host":"zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d","level":"info","message":"new response - driver: FreeNASSshDriver method: GetPluginInfo response: {\"name\":\"org.democratic-csi.nfs\",\"vendor_version\":\"1.8.3\"}","service":"democratic-csi","timestamp":"2023-07-21T03:19:58.342Z"} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-resizer I0721 03:19:58.347255 1 connection.go:186] GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}}]} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d csi-proxy 2023/07/21 03:19:58 request (://localhost) POST /csi.v1.Identity/GetPluginCapabilities HTTP/2.0 zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-resizer I0721 03:19:58.347959 1 connection.go:187] GRPC error: zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-resizer I0721 03:19:58.348028 1 connection.go:183] GRPC call: /csi.v1.Controller/ControllerGetCapabilities zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-resizer I0721 03:19:58.348065 1 connection.go:184] GRPC request: {} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d csi-proxy 2023/07/21 03:19:58 request headers map[Content-Type:[application/grpc] Grpc-Timeout:[89999880u] Te:[trailers] User-Agent:[grpc-go/1.40.0]] zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d csi-proxy 2023/07/21 03:19:58 request (://localhost) POST /csi.v1.Controller/ControllerGetCapabilities HTTP/2.0 zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:19:58.347143 1 connection.go:186] GRPC response: {"name":"org.democratic-csi.nfs","vendor_version":"1.8.3"} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:19:58.347400 1 connection.go:187] GRPC error: zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:19:58.347431 1 csi-provisioner.go:206] Detected CSI driver org.democratic-csi.nfs zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:19:58.347464 1 connection.go:183] GRPC call: /csi.v1.Identity/GetPluginCapabilities zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:19:58.347476 1 connection.go:184] GRPC request: {} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d csi-proxy 2023/07/21 03:19:58 request headers map[Content-Type:[application/grpc] Grpc-Timeout:[89999767u] Te:[trailers] User-Agent:[grpc-go/1.40.0]] zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d csi-driver {"host":"zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d","level":"info","message":"new request - driver: FreeNASSshDriver method: GetPluginCapabilities call: {\"metadata\":{\"x-forwarded-host\":[\"localhost\"],\"user-agent\":[\"grpc-go/1.40.0\"]},\"request\":{},\"cancelled\":false}","service":"democratic-csi","timestamp":"2023-07-21T03:19:58.352Z"} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d csi-driver {"host":"zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d","level":"info","message":"new response - driver: FreeNASSshDriver method: GetPluginCapabilities response: {\"capabilities\":[{\"service\":{\"type\":\"CONTROLLER_SERVICE\"}},{\"volume_expansion\":{\"type\":\"ONLINE\"}}]}","service":"democratic-csi","timestamp":"2023-07-21T03:19:58.352Z"} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d csi-driver {"host":"zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d","level":"info","message":"new request - driver: FreeNASSshDriver method: ControllerGetCapabilities call: {\"metadata\":{\"user-agent\":[\"grpc-go/1.40.0\"],\"x-forwarded-host\":[\"localhost\"]},\"request\":{},\"cancelled\":false}","service":"democratic-csi","timestamp":"2023-07-21T03:19:58.361Z"} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d csi-driver {"host":"zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d","level":"info","message":"new response - driver: FreeNASSshDriver method: ControllerGetCapabilities response: {\"capabilities\":[{\"rpc\":{\"type\":\"CREATE_DELETE_VOLUME\"}},{\"rpc\":{\"type\":\"LIST_VOLUMES\"}},{\"rpc\":{\"type\":\"GET_CAPACITY\"}},{\"rpc\":{\"type\":\"CREATE_DELETE_SNAPSHOT\"}},{\"rpc\":{\"type\":\"LIST_SNAPSHOTS\"}},{\"rpc\":{\"type\":\"CLONE_VOLUME\"}},{\"rpc\":{\"type\":\"EXPAND_VOLUME\"}},{\"rpc\":{\"type\":\"GET_VOLUME\"}},{\"rpc\":{\"type\":\"SINGLE_NODE_MULTI_WRITER\"}}]}","service":"democratic-csi","timestamp":"2023-07-21T03:19:58.363Z"} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-resizer I0721 03:19:58.372307 1 connection.go:186] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":3}}},{"Type":{"Rpc":{"type":4}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":6}}},{"Type":{"Rpc":{"type":7}}},{"Type":{"Rpc":{"type":9}}},{"Type":{"Rpc":{"type":12}}},{"Type":{"Rpc":{"type":13}}}]} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:19:58.372048 1 connection.go:186] GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}}]} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:19:58.372513 1 connection.go:187] GRPC error: zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:19:58.372552 1 connection.go:183] GRPC call: /csi.v1.Controller/ControllerGetCapabilities zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-resizer I0721 03:19:58.372715 1 connection.go:187] GRPC error: zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-resizer I0721 03:19:58.372776 1 connection.go:183] GRPC call: /csi.v1.Controller/ControllerGetCapabilities zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:19:58.372567 1 connection.go:184] GRPC request: {} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-resizer I0721 03:19:58.372790 1 connection.go:184] GRPC request: {} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d csi-proxy 2023/07/21 03:19:58 request (://localhost) POST /csi.v1.Controller/ControllerGetCapabilities HTTP/2.0 zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d csi-proxy 2023/07/21 03:19:58 request headers map[Content-Type:[application/grpc] Grpc-Timeout:[89999881u] Te:[trailers] User-Agent:[grpc-go/1.40.0]] zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d csi-proxy 2023/07/21 03:19:58 request (://localhost) POST /csi.v1.Controller/ControllerGetCapabilities HTTP/2.0 zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d csi-proxy 2023/07/21 03:19:58 request headers map[Content-Type:[application/grpc] Grpc-Timeout:[89999867u] Te:[trailers] User-Agent:[grpc-go/1.40.0]] zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d csi-driver {"host":"zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d","level":"info","message":"new request - driver: FreeNASSshDriver method: ControllerGetCapabilities call: {\"metadata\":{\"x-forwarded-host\":[\"localhost\"],\"user-agent\":[\"grpc-go/1.40.0\"]},\"request\":{},\"cancelled\":false}","service":"democratic-csi","timestamp":"2023-07-21T03:19:58.376Z"} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d csi-driver {"host":"zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d","level":"info","message":"new response - driver: FreeNASSshDriver method: ControllerGetCapabilities response: {\"capabilities\":[{\"rpc\":{\"type\":\"CREATE_DELETE_VOLUME\"}},{\"rpc\":{\"type\":\"LIST_VOLUMES\"}},{\"rpc\":{\"type\":\"GET_CAPACITY\"}},{\"rpc\":{\"type\":\"CREATE_DELETE_SNAPSHOT\"}},{\"rpc\":{\"type\":\"LIST_SNAPSHOTS\"}},{\"rpc\":{\"type\":\"CLONE_VOLUME\"}},{\"rpc\":{\"type\":\"EXPAND_VOLUME\"}},{\"rpc\":{\"type\":\"GET_VOLUME\"}},{\"rpc\":{\"type\":\"SINGLE_NODE_MULTI_WRITER\"}}]}","service":"democratic-csi","timestamp":"2023-07-21T03:19:58.377Z"} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d csi-driver {"host":"zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d","level":"info","message":"new request - driver: FreeNASSshDriver method: ControllerGetCapabilities call: {\"metadata\":{\"x-forwarded-host\":[\"localhost\"],\"user-agent\":[\"grpc-go/1.40.0\"]},\"request\":{},\"cancelled\":false}","service":"democratic-csi","timestamp":"2023-07-21T03:19:58.385Z"} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d csi-driver {"host":"zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d","level":"info","message":"new response - driver: FreeNASSshDriver method: ControllerGetCapabilities response: {\"capabilities\":[{\"rpc\":{\"type\":\"CREATE_DELETE_VOLUME\"}},{\"rpc\":{\"type\":\"LIST_VOLUMES\"}},{\"rpc\":{\"type\":\"GET_CAPACITY\"}},{\"rpc\":{\"type\":\"CREATE_DELETE_SNAPSHOT\"}},{\"rpc\":{\"type\":\"LIST_SNAPSHOTS\"}},{\"rpc\":{\"type\":\"CLONE_VOLUME\"}},{\"rpc\":{\"type\":\"EXPAND_VOLUME\"}},{\"rpc\":{\"type\":\"GET_VOLUME\"}},{\"rpc\":{\"type\":\"SINGLE_NODE_MULTI_WRITER\"}}]}","service":"democratic-csi","timestamp":"2023-07-21T03:19:58.386Z"} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-resizer I0721 03:19:58.390155 1 connection.go:186] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":3}}},{"Type":{"Rpc":{"type":4}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":6}}},{"Type":{"Rpc":{"type":7}}},{"Type":{"Rpc":{"type":9}}},{"Type":{"Rpc":{"type":12}}},{"Type":{"Rpc":{"type":13}}}]} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-resizer I0721 03:19:58.390513 1 connection.go:187] GRPC error: zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-resizer I0721 03:19:58.390982 1 controller.go:120] Register Pod informer for resizer org.democratic-csi.nfs zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-resizer I0721 03:19:58.392038 1 leaderelection.go:248] attempting to acquire leader lease democratic-csi/external-resizer-org-democratic-csi-nfs... zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:19:58.394930 1 connection.go:186] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":3}}},{"Type":{"Rpc":{"type":4}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":6}}},{"Type":{"Rpc":{"type":7}}},{"Type":{"Rpc":{"type":9}}},{"Type":{"Rpc":{"type":12}}},{"Type":{"Rpc":{"type":13}}}]} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:19:58.395486 1 connection.go:187] GRPC error: zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:19:58.395836 1 csi-provisioner.go:278] CSI driver does not support PUBLISH_UNPUBLISH_VOLUME, not watching VolumeAttachments zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:19:58.397860 1 controller.go:732] Using saving PVs to API server in background zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:19:58.399374 1 leaderelection.go:248] attempting to acquire leader lease democratic-csi/org-democratic-csi-nfs... zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:19:58.418936 1 leaderelection.go:352] lock is held by zfs-nfs-democratic-csi-controller-6b877f98b-2jxlj and has not yet expired zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:19:58.418999 1 leaderelection.go:253] failed to acquire lease democratic-csi/org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:19:58.419062 1 leader_election.go:212] new leader detected, current leader: zfs-nfs-democratic-csi-controller-6b877f98b-2jxlj zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-resizer I0721 03:19:58.422162 1 leaderelection.go:352] lock is held by zfs-nfs-democratic-csi-controller-6b877f98b-2jxlj and has not yet expired zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-resizer I0721 03:19:58.422242 1 leaderelection.go:253] failed to acquire lease democratic-csi/external-resizer-org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-resizer I0721 03:19:58.422312 1 leader_election.go:212] new leader detected, current leader: zfs-nfs-democratic-csi-controller-6b877f98b-2jxlj zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter I0721 03:19:58.518983 1 connection.go:183] GRPC call: /csi.v1.Identity/GetPluginInfo zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter I0721 03:19:58.519185 1 connection.go:184] GRPC request: {} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d csi-proxy 2023/07/21 03:19:58 request (://localhost) POST /csi.v1.Identity/GetPluginInfo HTTP/2.0 zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d csi-proxy 2023/07/21 03:19:58 request headers map[Content-Type:[application/grpc] Grpc-Timeout:[89995171u] Te:[trailers] User-Agent:[grpc-go/1.40.0]] zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d csi-driver {"host":"zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d","level":"info","message":"new request - driver: FreeNASSshDriver method: GetPluginInfo call: {\"metadata\":{\"x-forwarded-host\":[\"localhost\"],\"user-agent\":[\"grpc-go/1.40.0\"]},\"request\":{},\"cancelled\":false}","service":"democratic-csi","timestamp":"2023-07-21T03:19:58.529Z"} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d csi-driver {"host":"zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d","level":"info","message":"new response - driver: FreeNASSshDriver method: GetPluginInfo response: {\"name\":\"org.democratic-csi.nfs\",\"vendor_version\":\"1.8.3\"}","service":"democratic-csi","timestamp":"2023-07-21T03:19:58.529Z"} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter I0721 03:19:58.535206 1 connection.go:186] GRPC response: {"name":"org.democratic-csi.nfs","vendor_version":"1.8.3"} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d csi-proxy 2023/07/21 03:19:58 request (://localhost) POST /csi.v1.Identity/Probe HTTP/2.0 zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter I0721 03:19:58.535459 1 connection.go:187] GRPC error: zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter I0721 03:19:58.535945 1 main.go:184] CSI driver name: "org.democratic-csi.nfs" zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d csi-proxy 2023/07/21 03:19:58 request headers map[Content-Type:[application/grpc] Grpc-Timeout:[89999715u] Te:[trailers] User-Agent:[grpc-go/1.40.0]] zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter I0721 03:19:58.536057 1 common.go:111] Probing CSI driver for readiness zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter I0721 03:19:58.536094 1 connection.go:183] GRPC call: /csi.v1.Identity/Probe zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter I0721 03:19:58.536109 1 connection.go:184] GRPC request: {} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d csi-driver {"host":"zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d","level":"info","message":"new request - driver: FreeNASSshDriver method: Probe call: {\"metadata\":{\"user-agent\":[\"grpc-go/1.40.0\"],\"x-forwarded-host\":[\"localhost\"]},\"request\":{},\"cancelled\":false}","service":"democratic-csi","timestamp":"2023-07-21T03:19:58.540Z"} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d csi-driver {"host":"zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d","level":"info","message":"new response - driver: FreeNASSshDriver method: Probe response: {\"ready\":{\"value\":true}}","service":"democratic-csi","timestamp":"2023-07-21T03:19:58.559Z"} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter I0721 03:19:58.565830 1 connection.go:186] GRPC response: {"ready":{"value":true}} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter I0721 03:19:58.566457 1 connection.go:187] GRPC error: zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter I0721 03:19:58.566587 1 connection.go:183] GRPC call: /csi.v1.Controller/ControllerGetCapabilities zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter I0721 03:19:58.566665 1 connection.go:184] GRPC request: {} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d csi-proxy 2023/07/21 03:19:58 request (://localhost) POST /csi.v1.Controller/ControllerGetCapabilities HTTP/2.0 zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d csi-proxy 2023/07/21 03:19:58 request headers map[Content-Type:[application/grpc] Grpc-Timeout:[89952011u] Te:[trailers] User-Agent:[grpc-go/1.40.0]] zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d csi-driver {"host":"zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d","level":"info","message":"new request - driver: FreeNASSshDriver method: ControllerGetCapabilities call: {\"metadata\":{\"user-agent\":[\"grpc-go/1.40.0\"],\"x-forwarded-host\":[\"localhost\"]},\"request\":{},\"cancelled\":false}","service":"democratic-csi","timestamp":"2023-07-21T03:19:58.571Z"} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d csi-driver {"host":"zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d","level":"info","message":"new response - driver: FreeNASSshDriver method: ControllerGetCapabilities response: {\"capabilities\":[{\"rpc\":{\"type\":\"CREATE_DELETE_VOLUME\"}},{\"rpc\":{\"type\":\"LIST_VOLUMES\"}},{\"rpc\":{\"type\":\"GET_CAPACITY\"}},{\"rpc\":{\"type\":\"CREATE_DELETE_SNAPSHOT\"}},{\"rpc\":{\"type\":\"LIST_SNAPSHOTS\"}},{\"rpc\":{\"type\":\"CLONE_VOLUME\"}},{\"rpc\":{\"type\":\"EXPAND_VOLUME\"}},{\"rpc\":{\"type\":\"GET_VOLUME\"}},{\"rpc\":{\"type\":\"SINGLE_NODE_MULTI_WRITER\"}}]}","service":"democratic-csi","timestamp":"2023-07-21T03:19:58.571Z"} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter I0721 03:19:58.577356 1 connection.go:186] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":3}}},{"Type":{"Rpc":{"type":4}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":6}}},{"Type":{"Rpc":{"type":7}}},{"Type":{"Rpc":{"type":9}}},{"Type":{"Rpc":{"type":12}}},{"Type":{"Rpc":{"type":13}}}]} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter I0721 03:19:58.577778 1 connection.go:187] GRPC error: zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter I0721 03:19:58.577815 1 main.go:222] Start NewCSISnapshotSideCarController with snapshotter [org.democratic-csi.nfs] kubeconfig [] csiTimeout [1m30s] csiAddress [/csi-data/csi.sock] resyncPeriod [15m0s] snapshotNamePrefix [snapshot] snapshotNameUUIDLength [274878201928] zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter I0721 03:19:58.579543 1 leaderelection.go:248] attempting to acquire leader lease democratic-csi/external-snapshotter-leader-org-democratic-csi-nfs... zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter I0721 03:19:58.595013 1 leaderelection.go:352] lock is held by zfs-nfs-democratic-csi-controller-6b877f98b-2jxlj and has not yet expired zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter I0721 03:19:58.595070 1 leaderelection.go:253] failed to acquire lease democratic-csi/external-snapshotter-leader-org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter I0721 03:19:58.595126 1 leader_election.go:212] new leader detected, current leader: zfs-nfs-democratic-csi-controller-6b877f98b-2jxlj zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-resizer I0721 03:20:07.059801 1 leaderelection.go:352] lock is held by zfs-nfs-democratic-csi-controller-6b877f98b-2jxlj and has not yet expired zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-resizer I0721 03:20:07.059845 1 leaderelection.go:253] failed to acquire lease democratic-csi/external-resizer-org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter I0721 03:20:07.235157 1 leaderelection.go:352] lock is held by zfs-nfs-democratic-csi-controller-6b877f98b-2jxlj and has not yet expired zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter I0721 03:20:07.235198 1 leaderelection.go:253] failed to acquire lease democratic-csi/external-snapshotter-leader-org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:20:09.087369 1 leaderelection.go:352] lock is held by zfs-nfs-democratic-csi-controller-6b877f98b-2jxlj and has not yet expired zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:20:09.087412 1 leaderelection.go:253] failed to acquire lease democratic-csi/org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-resizer I0721 03:20:17.723294 1 leaderelection.go:258] successfully acquired lease democratic-csi/external-resizer-org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-resizer I0721 03:20:17.723356 1 leader_election.go:212] new leader detected, current leader: zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-resizer I0721 03:20:17.723739 1 leader_election.go:205] became leader, starting zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-resizer I0721 03:20:17.724611 1 controller.go:255] Starting external resizer org.democratic-csi.nfs zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-resizer I0721 03:20:17.725349 1 reflector.go:219] Starting reflector *v1.PersistentVolume (10m0s) from k8s.io/client-go/informers/factory.go:134 zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-resizer I0721 03:20:17.727144 1 reflector.go:219] Starting reflector *v1.Pod (10m0s) from k8s.io/client-go/informers/factory.go:134 zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-resizer I0721 03:20:17.727230 1 reflector.go:255] Listing and watching *v1.Pod from k8s.io/client-go/informers/factory.go:134 zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-resizer I0721 03:20:17.727258 1 reflector.go:255] Listing and watching *v1.PersistentVolume from k8s.io/client-go/informers/factory.go:134 zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-resizer I0721 03:20:17.726203 1 reflector.go:219] Starting reflector *v1.PersistentVolumeClaim (10m0s) from k8s.io/client-go/informers/factory.go:134 zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-resizer I0721 03:20:17.727904 1 reflector.go:255] Listing and watching *v1.PersistentVolumeClaim from k8s.io/client-go/informers/factory.go:134 zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-resizer I0721 03:20:17.747400 1 leaderelection.go:278] successfully renewed lease democratic-csi/external-resizer-org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-resizer I0721 03:20:17.827749 1 shared_informer.go:270] caches populated zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-resizer I0721 03:20:17.827890 1 controller.go:295] Started PVC processing "digi-data-usage-dashboard/sqlite-pvc" zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-resizer I0721 03:20:17.827975 1 controller.go:343] No need to resize PVC "digi-data-usage-dashboard/sqlite-pvc" zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter I0721 03:20:17.898840 1 leaderelection.go:258] successfully acquired lease democratic-csi/external-snapshotter-leader-org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter I0721 03:20:17.898897 1 leader_election.go:212] new leader detected, current leader: zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter I0721 03:20:17.900585 1 leader_election.go:205] became leader, starting zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter I0721 03:20:17.901685 1 reflector.go:219] Starting reflector *v1.VolumeSnapshotContent (15m0s) from github.com/kubernetes-csi/external-snapshotter/client/v4/informers/externalversions/factory.go:117 zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter I0721 03:20:17.901926 1 reflector.go:255] Listing and watching *v1.VolumeSnapshotContent from github.com/kubernetes-csi/external-snapshotter/client/v4/informers/externalversions/factory.go:117 zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter I0721 03:20:17.903044 1 reflector.go:219] Starting reflector *v1.VolumeSnapshotClass (15m0s) from github.com/kubernetes-csi/external-snapshotter/client/v4/informers/externalversions/factory.go:117 zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter I0721 03:20:17.903157 1 reflector.go:255] Listing and watching *v1.VolumeSnapshotClass from github.com/kubernetes-csi/external-snapshotter/client/v4/informers/externalversions/factory.go:117 zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter I0721 03:20:17.904173 1 snapshot_controller_base.go:115] Starting CSI snapshotter zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter W0721 03:20:17.915701 1 reflector.go:324] github.com/kubernetes-csi/external-snapshotter/client/v4/informers/externalversions/factory.go:117: failed to list *v1.VolumeSnapshotClass: the server could not find the requested resource (get volumesnapshotclasses.snapshot.storage.k8s.io) zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter E0721 03:20:17.916707 1 reflector.go:138] github.com/kubernetes-csi/external-snapshotter/client/v4/informers/externalversions/factory.go:117: Failed to watch *v1.VolumeSnapshotClass: failed to list *v1.VolumeSnapshotClass: the server could not find the requested resource (get volumesnapshotclasses.snapshot.storage.k8s.io) zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter W0721 03:20:17.916419 1 reflector.go:324] github.com/kubernetes-csi/external-snapshotter/client/v4/informers/externalversions/factory.go:117: failed to list *v1.VolumeSnapshotContent: the server could not find the requested resource (get volumesnapshotcontents.snapshot.storage.k8s.io) zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter E0721 03:20:17.920341 1 reflector.go:138] github.com/kubernetes-csi/external-snapshotter/client/v4/informers/externalversions/factory.go:117: Failed to watch *v1.VolumeSnapshotContent: failed to list *v1.VolumeSnapshotContent: the server could not find the requested resource (get volumesnapshotcontents.snapshot.storage.k8s.io) zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter I0721 03:20:17.924487 1 leaderelection.go:278] successfully renewed lease democratic-csi/external-snapshotter-leader-org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:20:18.096114 1 leader_election.go:212] new leader detected, current leader: zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:20:18.096114 1 leaderelection.go:258] successfully acquired lease democratic-csi/org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:20:18.096463 1 leader_election.go:205] became leader, starting zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:20:18.097765 1 reflector.go:219] Starting reflector *v1.StorageClass (1h0m0s) from k8s.io/client-go/informers/factory.go:134 zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:20:18.097857 1 reflector.go:255] Listing and watching *v1.StorageClass from k8s.io/client-go/informers/factory.go:134 zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:20:18.097765 1 reflector.go:219] Starting reflector *v1.PersistentVolumeClaim (15m0s) from k8s.io/client-go/informers/factory.go:134 zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:20:18.097951 1 reflector.go:255] Listing and watching *v1.PersistentVolumeClaim from k8s.io/client-go/informers/factory.go:134 zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:20:18.117462 1 leaderelection.go:278] successfully renewed lease democratic-csi/org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:20:18.197410 1 shared_informer.go:270] caches populated zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:20:18.197838 1 shared_informer.go:270] caches populated zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:20:18.198040 1 controller.go:811] Starting provisioner controller org.democratic-csi.nfs_zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d_7cfa307e-ea4e-49bd-b781-77e22c87dcf1! zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:20:18.198191 1 clone_controller.go:66] Starting CloningProtection controller zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:20:18.199051 1 clone_controller.go:82] Started CloningProtection controller zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:20:18.199064 1 reflector.go:219] Starting reflector *v1.PersistentVolume (15m0s) from sigs.k8s.io/sig-storage-lib-external-provisioner/v8/controller/controller.go:845 zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:20:18.199127 1 reflector.go:255] Listing and watching *v1.PersistentVolume from sigs.k8s.io/sig-storage-lib-external-provisioner/v8/controller/controller.go:845 zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:20:18.198234 1 volume_store.go:97] Starting save volume queue zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:20:18.200912 1 reflector.go:219] Starting reflector *v1.StorageClass (15m0s) from sigs.k8s.io/sig-storage-lib-external-provisioner/v8/controller/controller.go:848 zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:20:18.200995 1 reflector.go:255] Listing and watching *v1.StorageClass from sigs.k8s.io/sig-storage-lib-external-provisioner/v8/controller/controller.go:848 zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:20:18.300119 1 shared_informer.go:270] caches populated zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:20:18.300800 1 controller.go:860] Started provisioner controller org.democratic-csi.nfs_zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d_7cfa307e-ea4e-49bd-b781-77e22c87dcf1! zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter I0721 03:20:19.061059 1 reflector.go:255] Listing and watching *v1.VolumeSnapshotContent from github.com/kubernetes-csi/external-snapshotter/client/v4/informers/externalversions/factory.go:117 zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter W0721 03:20:19.066179 1 reflector.go:324] github.com/kubernetes-csi/external-snapshotter/client/v4/informers/externalversions/factory.go:117: failed to list *v1.VolumeSnapshotContent: the server could not find the requested resource (get volumesnapshotcontents.snapshot.storage.k8s.io) zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter E0721 03:20:19.066408 1 reflector.go:138] github.com/kubernetes-csi/external-snapshotter/client/v4/informers/externalversions/factory.go:117: Failed to watch *v1.VolumeSnapshotContent: failed to list *v1.VolumeSnapshotContent: the server could not find the requested resource (get volumesnapshotcontents.snapshot.storage.k8s.io) zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter I0721 03:20:19.068075 1 reflector.go:255] Listing and watching *v1.VolumeSnapshotClass from github.com/kubernetes-csi/external-snapshotter/client/v4/informers/externalversions/factory.go:117 zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter W0721 03:20:19.072568 1 reflector.go:324] github.com/kubernetes-csi/external-snapshotter/client/v4/informers/externalversions/factory.go:117: failed to list *v1.VolumeSnapshotClass: the server could not find the requested resource (get volumesnapshotclasses.snapshot.storage.k8s.io) zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter E0721 03:20:19.072701 1 reflector.go:138] github.com/kubernetes-csi/external-snapshotter/client/v4/informers/externalversions/factory.go:117: Failed to watch *v1.VolumeSnapshotClass: failed to list *v1.VolumeSnapshotClass: the server could not find the requested resource (get volumesnapshotclasses.snapshot.storage.k8s.io) zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter I0721 03:20:20.778492 1 reflector.go:255] Listing and watching *v1.VolumeSnapshotClass from github.com/kubernetes-csi/external-snapshotter/client/v4/informers/externalversions/factory.go:117 zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter W0721 03:20:20.786772 1 reflector.go:324] github.com/kubernetes-csi/external-snapshotter/client/v4/informers/externalversions/factory.go:117: failed to list *v1.VolumeSnapshotClass: the server could not find the requested resource (get volumesnapshotclasses.snapshot.storage.k8s.io) zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter E0721 03:20:20.787087 1 reflector.go:138] github.com/kubernetes-csi/external-snapshotter/client/v4/informers/externalversions/factory.go:117: Failed to watch *v1.VolumeSnapshotClass: failed to list *v1.VolumeSnapshotClass: the server could not find the requested resource (get volumesnapshotclasses.snapshot.storage.k8s.io) zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter I0721 03:20:21.765712 1 reflector.go:255] Listing and watching *v1.VolumeSnapshotContent from github.com/kubernetes-csi/external-snapshotter/client/v4/informers/externalversions/factory.go:117 zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter W0721 03:20:21.769371 1 reflector.go:324] github.com/kubernetes-csi/external-snapshotter/client/v4/informers/externalversions/factory.go:117: failed to list *v1.VolumeSnapshotContent: the server could not find the requested resource (get volumesnapshotcontents.snapshot.storage.k8s.io) zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter E0721 03:20:21.769538 1 reflector.go:138] github.com/kubernetes-csi/external-snapshotter/client/v4/informers/externalversions/factory.go:117: Failed to watch *v1.VolumeSnapshotContent: failed to list *v1.VolumeSnapshotContent: the server could not find the requested resource (get volumesnapshotcontents.snapshot.storage.k8s.io) zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-resizer I0721 03:20:22.765033 1 leaderelection.go:278] successfully renewed lease democratic-csi/external-resizer-org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter I0721 03:20:22.940191 1 leaderelection.go:278] successfully renewed lease democratic-csi/external-snapshotter-leader-org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:20:23.132958 1 leaderelection.go:278] successfully renewed lease democratic-csi/org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter I0721 03:20:24.488552 1 reflector.go:255] Listing and watching *v1.VolumeSnapshotClass from github.com/kubernetes-csi/external-snapshotter/client/v4/informers/externalversions/factory.go:117 zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter W0721 03:20:24.491845 1 reflector.go:324] github.com/kubernetes-csi/external-snapshotter/client/v4/informers/externalversions/factory.go:117: failed to list *v1.VolumeSnapshotClass: the server could not find the requested resource (get volumesnapshotclasses.snapshot.storage.k8s.io) zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter E0721 03:20:24.491945 1 reflector.go:138] github.com/kubernetes-csi/external-snapshotter/client/v4/informers/externalversions/factory.go:117: Failed to watch *v1.VolumeSnapshotClass: failed to list *v1.VolumeSnapshotClass: the server could not find the requested resource (get volumesnapshotclasses.snapshot.storage.k8s.io) zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter I0721 03:20:25.280803 1 reflector.go:255] Listing and watching *v1.VolumeSnapshotContent from github.com/kubernetes-csi/external-snapshotter/client/v4/informers/externalversions/factory.go:117 zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter W0721 03:20:25.284970 1 reflector.go:324] github.com/kubernetes-csi/external-snapshotter/client/v4/informers/externalversions/factory.go:117: failed to list *v1.VolumeSnapshotContent: the server could not find the requested resource (get volumesnapshotcontents.snapshot.storage.k8s.io) zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter E0721 03:20:25.285090 1 reflector.go:138] github.com/kubernetes-csi/external-snapshotter/client/v4/informers/externalversions/factory.go:117: Failed to watch *v1.VolumeSnapshotContent: failed to list *v1.VolumeSnapshotContent: the server could not find the requested resource (get volumesnapshotcontents.snapshot.storage.k8s.io) zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-resizer I0721 03:20:27.798348 1 leaderelection.go:278] successfully renewed lease democratic-csi/external-resizer-org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter I0721 03:20:27.968882 1 leaderelection.go:278] successfully renewed lease democratic-csi/external-snapshotter-leader-org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:20:28.163311 1 leaderelection.go:278] successfully renewed lease democratic-csi/org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-resizer I0721 03:20:32.817135 1 leaderelection.go:278] successfully renewed lease democratic-csi/external-resizer-org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter I0721 03:20:32.818561 1 reflector.go:255] Listing and watching *v1.VolumeSnapshotClass from github.com/kubernetes-csi/external-snapshotter/client/v4/informers/externalversions/factory.go:117 zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter W0721 03:20:32.821397 1 reflector.go:324] github.com/kubernetes-csi/external-snapshotter/client/v4/informers/externalversions/factory.go:117: failed to list *v1.VolumeSnapshotClass: the server could not find the requested resource (get volumesnapshotclasses.snapshot.storage.k8s.io) zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter E0721 03:20:32.821455 1 reflector.go:138] github.com/kubernetes-csi/external-snapshotter/client/v4/informers/externalversions/factory.go:117: Failed to watch *v1.VolumeSnapshotClass: failed to list *v1.VolumeSnapshotClass: the server could not find the requested resource (get volumesnapshotclasses.snapshot.storage.k8s.io) zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter I0721 03:20:32.983821 1 leaderelection.go:278] successfully renewed lease democratic-csi/external-snapshotter-leader-org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:20:33.179143 1 leaderelection.go:278] successfully renewed lease democratic-csi/org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter I0721 03:20:34.983106 1 reflector.go:255] Listing and watching *v1.VolumeSnapshotContent from github.com/kubernetes-csi/external-snapshotter/client/v4/informers/externalversions/factory.go:117 zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter W0721 03:20:34.989086 1 reflector.go:324] github.com/kubernetes-csi/external-snapshotter/client/v4/informers/externalversions/factory.go:117: failed to list *v1.VolumeSnapshotContent: the server could not find the requested resource (get volumesnapshotcontents.snapshot.storage.k8s.io) zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter E0721 03:20:34.989197 1 reflector.go:138] github.com/kubernetes-csi/external-snapshotter/client/v4/informers/externalversions/factory.go:117: Failed to watch *v1.VolumeSnapshotContent: failed to list *v1.VolumeSnapshotContent: the server could not find the requested resource (get volumesnapshotcontents.snapshot.storage.k8s.io) zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-resizer I0721 03:20:37.850440 1 leaderelection.go:278] successfully renewed lease democratic-csi/external-resizer-org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter I0721 03:20:38.008756 1 leaderelection.go:278] successfully renewed lease democratic-csi/external-snapshotter-leader-org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:20:38.212922 1 leaderelection.go:278] successfully renewed lease democratic-csi/org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter I0721 03:20:43.038491 1 leaderelection.go:278] successfully renewed lease democratic-csi/external-snapshotter-leader-org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-resizer I0721 03:20:42.883544 1 leaderelection.go:278] successfully renewed lease democratic-csi/external-resizer-org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:20:43.248908 1 leaderelection.go:278] successfully renewed lease democratic-csi/org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-resizer I0721 03:20:47.903561 1 leaderelection.go:278] successfully renewed lease democratic-csi/external-resizer-org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter I0721 03:20:48.058521 1 leaderelection.go:278] successfully renewed lease democratic-csi/external-snapshotter-leader-org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:20:48.265827 1 leaderelection.go:278] successfully renewed lease democratic-csi/org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d csi-driver {"host":"zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d","level":"info","message":"new request - driver: FreeNASSshDriver method: Probe call: {\"metadata\":{\"user-agent\":[\"grpc-node-js/1.8.13\"]},\"request\":{},\"cancelled\":false}","service":"democratic-csi","timestamp":"2023-07-21T03:20:50.382Z"} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d csi-driver {"host":"zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d","level":"info","message":"new response - driver: FreeNASSshDriver method: Probe response: {\"ready\":{\"value\":true}}","service":"democratic-csi","timestamp":"2023-07-21T03:20:50.402Z"} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter I0721 03:20:50.532946 1 reflector.go:255] Listing and watching *v1.VolumeSnapshotContent from github.com/kubernetes-csi/external-snapshotter/client/v4/informers/externalversions/factory.go:117 zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter W0721 03:20:50.536172 1 reflector.go:324] github.com/kubernetes-csi/external-snapshotter/client/v4/informers/externalversions/factory.go:117: failed to list *v1.VolumeSnapshotContent: the server could not find the requested resource (get volumesnapshotcontents.snapshot.storage.k8s.io) zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter E0721 03:20:50.536388 1 reflector.go:138] github.com/kubernetes-csi/external-snapshotter/client/v4/informers/externalversions/factory.go:117: Failed to watch *v1.VolumeSnapshotContent: failed to list *v1.VolumeSnapshotContent: the server could not find the requested resource (get volumesnapshotcontents.snapshot.storage.k8s.io) zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-resizer I0721 03:20:52.921874 1 leaderelection.go:278] successfully renewed lease democratic-csi/external-resizer-org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter I0721 03:20:53.075848 1 leaderelection.go:278] successfully renewed lease democratic-csi/external-snapshotter-leader-org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:20:53.282182 1 leaderelection.go:278] successfully renewed lease democratic-csi/org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-resizer I0721 03:20:55.486814 1 controller.go:295] Started PVC processing "democratic-csi/test-claim-nfs-pvc" zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-resizer I0721 03:20:55.486923 1 controller.go:318] PV bound to PVC "democratic-csi/test-claim-nfs-pvc" is not created yet zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:20:55.506192 1 controller.go:1337] provision "democratic-csi/test-claim-nfs-pvc" class "freenas-nfs-csi": started zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner W0721 03:20:55.507259 1 controller.go:579] "fstype" is deprecated and will be removed in a future release, please use "csi.storage.k8s.io/fstype" instead zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:20:55.508571 1 event.go:285] Event(v1.ObjectReference{Kind:"PersistentVolumeClaim", Namespace:"democratic-csi", Name:"test-claim-nfs-pvc", UID:"43582040-e241-4f8b-bea9-f490a0c62c2a", APIVersion:"v1", ResourceVersion:"13544993", FieldPath:""}): type: 'Normal' reason: 'Provisioning' External provisioner is provisioning volume for claim "democratic-csi/test-claim-nfs-pvc" zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:20:55.527292 1 connection.go:183] GRPC call: /csi.v1.Controller/CreateVolume zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d csi-proxy 2023/07/21 03:20:55 request (://localhost) POST /csi.v1.Controller/CreateVolume HTTP/2.0 zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:20:55.527365 1 connection.go:184] GRPC request: {"capacity_range":{"required_bytes":1073741824},"name":"pvc-43582040-e241-4f8b-bea9-f490a0c62c2a","parameters":{"csi.storage.k8s.io/pv/name":"pvc-43582040-e241-4f8b-bea9-f490a0c62c2a","csi.storage.k8s.io/pvc/name":"test-claim-nfs-pvc","csi.storage.k8s.io/pvc/namespace":"democratic-csi","fsType":"nfs"},"volume_capabilities":[{"AccessType":{"Mount":{"fs_type":"nfs","mount_flags":["noatime","nfsvers=4"]}},"access_mode":{"mode":7}}]} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d csi-proxy 2023/07/21 03:20:55 request headers map[Content-Type:[application/grpc] Grpc-Timeout:[89998398u] Te:[trailers] User-Agent:[grpc-go/1.40.0]] zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d csi-driver {"host":"zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d","level":"info","message":"new request - driver: FreeNASSshDriver method: CreateVolume call: {\"metadata\":{\"user-agent\":[\"grpc-go/1.40.0\"],\"x-forwarded-host\":[\"localhost\"]},\"request\":{\"volume_capabilities\":[{\"access_mode\":{\"mode\":\"SINGLE_NODE_MULTI_WRITER\"},\"mount\":{\"mount_flags\":[\"noatime\",\"nfsvers=4\"],\"fs_type\":\"nfs\",\"volume_mount_group\":\"\"},\"access_type\":\"mount\"}],\"parameters\":{\"csi.storage.k8s.io/pv/name\":\"pvc-43582040-e241-4f8b-bea9-f490a0c62c2a\",\"fsType\":\"nfs\",\"csi.storage.k8s.io/pvc/name\":\"test-claim-nfs-pvc\",\"csi.storage.k8s.io/pvc/namespace\":\"democratic-csi\"},\"secrets\":\"redacted\",\"name\":\"pvc-43582040-e241-4f8b-bea9-f490a0c62c2a\",\"capacity_range\":{\"required_bytes\":\"1073741824\",\"limit_bytes\":\"0\"},\"volume_content_source\":null,\"accessibility_requirements\":null},\"cancelled\":false}","service":"democratic-csi","timestamp":"2023-07-21T03:20:55.577Z"} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter I0721 03:20:56.037081 1 reflector.go:255] Listing and watching *v1.VolumeSnapshotClass from github.com/kubernetes-csi/external-snapshotter/client/v4/informers/externalversions/factory.go:117 zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter W0721 03:20:56.040191 1 reflector.go:324] github.com/kubernetes-csi/external-snapshotter/client/v4/informers/externalversions/factory.go:117: failed to list *v1.VolumeSnapshotClass: the server could not find the requested resource (get volumesnapshotclasses.snapshot.storage.k8s.io) zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter E0721 03:20:56.040610 1 reflector.go:138] github.com/kubernetes-csi/external-snapshotter/client/v4/informers/externalversions/factory.go:117: Failed to watch *v1.VolumeSnapshotClass: failed to list *v1.VolumeSnapshotClass: the server could not find the requested resource (get volumesnapshotclasses.snapshot.storage.k8s.io) zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-resizer I0721 03:20:57.939999 1 leaderelection.go:278] successfully renewed lease democratic-csi/external-resizer-org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter I0721 03:20:58.091626 1 leaderelection.go:278] successfully renewed lease democratic-csi/external-snapshotter-leader-org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:20:58.297960 1 leaderelection.go:278] successfully renewed lease democratic-csi/org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:21:02.739415 1 connection.go:186] GRPC response: {} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:21:02.739676 1 connection.go:187] GRPC error: rpc error: code = Unknown desc = received error creating nfs share - code: 422 body: {"sharingnfs_create.maproot_user":[{"message":"User not found","errno":22}],"sharingnfs_create.maproot_group":[{"message":"Group not found","errno":22}]} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:21:02.739757 1 controller.go:764] CreateVolume failed, supports topology = false, node selected false => may reschedule = false => state = Finished: rpc error: code = Unknown desc = received error creating nfs share - code: 422 body: {"sharingnfs_create.maproot_user":[{"message":"User not found","errno":22}],"sharingnfs_create.maproot_group":[{"message":"Group not found","errno":22}]} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:21:02.739919 1 controller.go:1075] Final error received, removing PVC 43582040-e241-4f8b-bea9-f490a0c62c2a from claims in progress zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner W0721 03:21:02.739958 1 controller.go:934] Retrying syncing claim "43582040-e241-4f8b-bea9-f490a0c62c2a", failure 0 zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner E0721 03:21:02.740064 1 controller.go:957] error syncing claim "43582040-e241-4f8b-bea9-f490a0c62c2a": failed to provision volume with StorageClass "freenas-nfs-csi": rpc error: code = Unknown desc = received error creating nfs share - code: 422 body: {"sharingnfs_create.maproot_user":[{"message":"User not found","errno":22}],"sharingnfs_create.maproot_group":[{"message":"Group not found","errno":22}]} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d csi-driver {"host":"zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d","level":"error","message":"handler error - driver: FreeNASSshDriver method: CreateVolume error: {\"name\":\"GrpcError\",\"code\":2,\"message\":\"received error creating nfs share - code: 422 body: {\\\"sharingnfs_create.maproot_user\\\":[{\\\"message\\\":\\\"User not found\\\",\\\"errno\\\":22}],\\\"sharingnfs_create.maproot_group\\\":[{\\\"message\\\":\\\"Group not found\\\",\\\"errno\\\":22}]}\"}","service":"democratic-csi","timestamp":"2023-07-21T03:21:02.733Z"} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:21:02.740566 1 event.go:285] Event(v1.ObjectReference{Kind:"PersistentVolumeClaim", Namespace:"democratic-csi", Name:"test-claim-nfs-pvc", UID:"43582040-e241-4f8b-bea9-f490a0c62c2a", APIVersion:"v1", ResourceVersion:"13544993", FieldPath:""}): type: 'Warning' reason: 'ProvisioningFailed' failed to provision volume with StorageClass "freenas-nfs-csi": rpc error: code = Unknown desc = received error creating nfs share - code: 422 body: {"sharingnfs_create.maproot_user":[{"message":"User not found","errno":22}],"sharingnfs_create.maproot_group":[{"message":"Group not found","errno":22}]} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-resizer I0721 03:21:02.979665 1 leaderelection.go:278] successfully renewed lease democratic-csi/external-resizer-org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter I0721 03:21:03.117545 1 leaderelection.go:278] successfully renewed lease democratic-csi/external-snapshotter-leader-org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:21:03.334599 1 leaderelection.go:278] successfully renewed lease democratic-csi/org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:21:03.740446 1 controller.go:1337] provision "democratic-csi/test-claim-nfs-pvc" class "freenas-nfs-csi": started zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner W0721 03:21:03.740752 1 controller.go:579] "fstype" is deprecated and will be removed in a future release, please use "csi.storage.k8s.io/fstype" instead zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:21:03.742126 1 event.go:285] Event(v1.ObjectReference{Kind:"PersistentVolumeClaim", Namespace:"democratic-csi", Name:"test-claim-nfs-pvc", UID:"43582040-e241-4f8b-bea9-f490a0c62c2a", APIVersion:"v1", ResourceVersion:"13544993", FieldPath:""}): type: 'Normal' reason: 'Provisioning' External provisioner is provisioning volume for claim "democratic-csi/test-claim-nfs-pvc" zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:21:03.755075 1 connection.go:183] GRPC call: /csi.v1.Controller/CreateVolume zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:21:03.755166 1 connection.go:184] GRPC request: {"capacity_range":{"required_bytes":1073741824},"name":"pvc-43582040-e241-4f8b-bea9-f490a0c62c2a","parameters":{"csi.storage.k8s.io/pv/name":"pvc-43582040-e241-4f8b-bea9-f490a0c62c2a","csi.storage.k8s.io/pvc/name":"test-claim-nfs-pvc","csi.storage.k8s.io/pvc/namespace":"democratic-csi","fsType":"nfs"},"volume_capabilities":[{"AccessType":{"Mount":{"fs_type":"nfs","mount_flags":["noatime","nfsvers=4"]}},"access_mode":{"mode":7}}]} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d csi-proxy 2023/07/21 03:21:03 request (://localhost) POST /csi.v1.Controller/CreateVolume HTTP/2.0 zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d csi-proxy 2023/07/21 03:21:03 request headers map[Content-Type:[application/grpc] Grpc-Timeout:[89998658u] Te:[trailers] User-Agent:[grpc-go/1.40.0]] zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d csi-driver {"host":"zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d","level":"info","message":"new request - driver: FreeNASSshDriver method: CreateVolume call: {\"metadata\":{\"x-forwarded-host\":[\"localhost\"],\"user-agent\":[\"grpc-go/1.40.0\"]},\"request\":{\"volume_capabilities\":[{\"access_mode\":{\"mode\":\"SINGLE_NODE_MULTI_WRITER\"},\"mount\":{\"mount_flags\":[\"noatime\",\"nfsvers=4\"],\"fs_type\":\"nfs\",\"volume_mount_group\":\"\"},\"access_type\":\"mount\"}],\"parameters\":{\"fsType\":\"nfs\",\"csi.storage.k8s.io/pvc/name\":\"test-claim-nfs-pvc\",\"csi.storage.k8s.io/pvc/namespace\":\"democratic-csi\",\"csi.storage.k8s.io/pv/name\":\"pvc-43582040-e241-4f8b-bea9-f490a0c62c2a\"},\"secrets\":\"redacted\",\"name\":\"pvc-43582040-e241-4f8b-bea9-f490a0c62c2a\",\"capacity_range\":{\"required_bytes\":\"1073741824\",\"limit_bytes\":\"0\"},\"volume_content_source\":null,\"accessibility_requirements\":null},\"cancelled\":false}","service":"democratic-csi","timestamp":"2023-07-21T03:21:03.773Z"} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d csi-driver {"host":"zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d","level":"error","message":"handler error - driver: FreeNASSshDriver method: CreateVolume error: {\"name\":\"GrpcError\",\"code\":2,\"message\":\"received error creating nfs share - code: 422 body: {\\\"sharingnfs_create.maproot_user\\\":[{\\\"message\\\":\\\"User not found\\\",\\\"errno\\\":22}],\\\"sharingnfs_create.maproot_group\\\":[{\\\"message\\\":\\\"Group not found\\\",\\\"errno\\\":22}]}\"}","service":"democratic-csi","timestamp":"2023-07-21T03:21:07.326Z"} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:21:07.329306 1 connection.go:186] GRPC response: {} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:21:07.329441 1 connection.go:187] GRPC error: rpc error: code = Unknown desc = received error creating nfs share - code: 422 body: {"sharingnfs_create.maproot_user":[{"message":"User not found","errno":22}],"sharingnfs_create.maproot_group":[{"message":"Group not found","errno":22}]} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:21:07.329544 1 controller.go:764] CreateVolume failed, supports topology = false, node selected false => may reschedule = false => state = Finished: rpc error: code = Unknown desc = received error creating nfs share - code: 422 body: {"sharingnfs_create.maproot_user":[{"message":"User not found","errno":22}],"sharingnfs_create.maproot_group":[{"message":"Group not found","errno":22}]} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:21:07.329642 1 controller.go:1075] Final error received, removing PVC 43582040-e241-4f8b-bea9-f490a0c62c2a from claims in progress zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner W0721 03:21:07.329672 1 controller.go:934] Retrying syncing claim "43582040-e241-4f8b-bea9-f490a0c62c2a", failure 1 zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner E0721 03:21:07.329741 1 controller.go:957] error syncing claim "43582040-e241-4f8b-bea9-f490a0c62c2a": failed to provision volume with StorageClass "freenas-nfs-csi": rpc error: code = Unknown desc = received error creating nfs share - code: 422 body: {"sharingnfs_create.maproot_user":[{"message":"User not found","errno":22}],"sharingnfs_create.maproot_group":[{"message":"Group not found","errno":22}]} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:21:07.329808 1 event.go:285] Event(v1.ObjectReference{Kind:"PersistentVolumeClaim", Namespace:"democratic-csi", Name:"test-claim-nfs-pvc", UID:"43582040-e241-4f8b-bea9-f490a0c62c2a", APIVersion:"v1", ResourceVersion:"13544993", FieldPath:""}): type: 'Warning' reason: 'ProvisioningFailed' failed to provision volume with StorageClass "freenas-nfs-csi": rpc error: code = Unknown desc = received error creating nfs share - code: 422 body: {"sharingnfs_create.maproot_user":[{"message":"User not found","errno":22}],"sharingnfs_create.maproot_group":[{"message":"Group not found","errno":22}]} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-resizer I0721 03:21:08.012390 1 leaderelection.go:278] successfully renewed lease democratic-csi/external-resizer-org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter I0721 03:21:08.139991 1 leaderelection.go:278] successfully renewed lease democratic-csi/external-snapshotter-leader-org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:21:08.366805 1 leaderelection.go:278] successfully renewed lease democratic-csi/org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:21:09.329927 1 controller.go:1337] provision "democratic-csi/test-claim-nfs-pvc" class "freenas-nfs-csi": started zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner W0721 03:21:09.330090 1 controller.go:579] "fstype" is deprecated and will be removed in a future release, please use "csi.storage.k8s.io/fstype" instead zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d csi-driver {"host":"zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d","level":"info","message":"new request - driver: FreeNASSshDriver method: CreateVolume call: {\"metadata\":{\"x-forwarded-host\":[\"localhost\"],\"user-agent\":[\"grpc-go/1.40.0\"]},\"request\":{\"volume_capabilities\":[{\"access_mode\":{\"mode\":\"SINGLE_NODE_MULTI_WRITER\"},\"mount\":{\"mount_flags\":[\"noatime\",\"nfsvers=4\"],\"fs_type\":\"nfs\",\"volume_mount_group\":\"\"},\"access_type\":\"mount\"}],\"parameters\":{\"fsType\":\"nfs\",\"csi.storage.k8s.io/pvc/name\":\"test-claim-nfs-pvc\",\"csi.storage.k8s.io/pvc/namespace\":\"democratic-csi\",\"csi.storage.k8s.io/pv/name\":\"pvc-43582040-e241-4f8b-bea9-f490a0c62c2a\"},\"secrets\":\"redacted\",\"name\":\"pvc-43582040-e241-4f8b-bea9-f490a0c62c2a\",\"capacity_range\":{\"required_bytes\":\"1073741824\",\"limit_bytes\":\"0\"},\"volume_content_source\":null,\"accessibility_requirements\":null},\"cancelled\":false}","service":"democratic-csi","timestamp":"2023-07-21T03:21:09.344Z"} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:21:09.330581 1 event.go:285] Event(v1.ObjectReference{Kind:"PersistentVolumeClaim", Namespace:"democratic-csi", Name:"test-claim-nfs-pvc", UID:"43582040-e241-4f8b-bea9-f490a0c62c2a", APIVersion:"v1", ResourceVersion:"13544993", FieldPath:""}): type: 'Normal' reason: 'Provisioning' External provisioner is provisioning volume for claim "democratic-csi/test-claim-nfs-pvc" zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:21:09.337949 1 connection.go:183] GRPC call: /csi.v1.Controller/CreateVolume zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:21:09.338110 1 connection.go:184] GRPC request: {"capacity_range":{"required_bytes":1073741824},"name":"pvc-43582040-e241-4f8b-bea9-f490a0c62c2a","parameters":{"csi.storage.k8s.io/pv/name":"pvc-43582040-e241-4f8b-bea9-f490a0c62c2a","csi.storage.k8s.io/pvc/name":"test-claim-nfs-pvc","csi.storage.k8s.io/pvc/namespace":"democratic-csi","fsType":"nfs"},"volume_capabilities":[{"AccessType":{"Mount":{"fs_type":"nfs","mount_flags":["noatime","nfsvers=4"]}},"access_mode":{"mode":7}}]} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d csi-proxy 2023/07/21 03:21:09 request (://localhost) POST /csi.v1.Controller/CreateVolume HTTP/2.0 zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d csi-proxy 2023/07/21 03:21:09 request headers map[Content-Type:[application/grpc] Grpc-Timeout:[89998590u] Te:[trailers] User-Agent:[grpc-go/1.40.0]] zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-resizer I0721 03:21:13.046676 1 leaderelection.go:278] successfully renewed lease democratic-csi/external-resizer-org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter I0721 03:21:13.158767 1 leaderelection.go:278] successfully renewed lease democratic-csi/external-snapshotter-leader-org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:21:13.384242 1 leaderelection.go:278] successfully renewed lease democratic-csi/org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:21:15.942242 1 connection.go:186] GRPC response: {} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:21:15.942431 1 connection.go:187] GRPC error: rpc error: code = Unknown desc = received error creating nfs share - code: 422 body: {"sharingnfs_create.maproot_user":[{"message":"User not found","errno":22}],"sharingnfs_create.maproot_group":[{"message":"Group not found","errno":22}]} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:21:15.942553 1 controller.go:764] CreateVolume failed, supports topology = false, node selected false => may reschedule = false => state = Finished: rpc error: code = Unknown desc = received error creating nfs share - code: 422 body: {"sharingnfs_create.maproot_user":[{"message":"User not found","errno":22}],"sharingnfs_create.maproot_group":[{"message":"Group not found","errno":22}]} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:21:15.942659 1 controller.go:1075] Final error received, removing PVC 43582040-e241-4f8b-bea9-f490a0c62c2a from claims in progress zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner W0721 03:21:15.942695 1 controller.go:934] Retrying syncing claim "43582040-e241-4f8b-bea9-f490a0c62c2a", failure 2 zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d csi-driver {"host":"zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d","level":"error","message":"handler error - driver: FreeNASSshDriver method: CreateVolume error: {\"name\":\"GrpcError\",\"code\":2,\"message\":\"received error creating nfs share - code: 422 body: {\\\"sharingnfs_create.maproot_user\\\":[{\\\"message\\\":\\\"User not found\\\",\\\"errno\\\":22}],\\\"sharingnfs_create.maproot_group\\\":[{\\\"message\\\":\\\"Group not found\\\",\\\"errno\\\":22}]}\"}","service":"democratic-csi","timestamp":"2023-07-21T03:21:15.939Z"} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner E0721 03:21:15.942756 1 controller.go:957] error syncing claim "43582040-e241-4f8b-bea9-f490a0c62c2a": failed to provision volume with StorageClass "freenas-nfs-csi": rpc error: code = Unknown desc = received error creating nfs share - code: 422 body: {"sharingnfs_create.maproot_user":[{"message":"User not found","errno":22}],"sharingnfs_create.maproot_group":[{"message":"Group not found","errno":22}]} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:21:15.944430 1 event.go:285] Event(v1.ObjectReference{Kind:"PersistentVolumeClaim", Namespace:"democratic-csi", Name:"test-claim-nfs-pvc", UID:"43582040-e241-4f8b-bea9-f490a0c62c2a", APIVersion:"v1", ResourceVersion:"13544993", FieldPath:""}): type: 'Warning' reason: 'ProvisioningFailed' failed to provision volume with StorageClass "freenas-nfs-csi": rpc error: code = Unknown desc = received error creating nfs share - code: 422 body: {"sharingnfs_create.maproot_user":[{"message":"User not found","errno":22}],"sharingnfs_create.maproot_group":[{"message":"Group not found","errno":22}]} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-resizer I0721 03:21:18.063601 1 leaderelection.go:278] successfully renewed lease democratic-csi/external-resizer-org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter I0721 03:21:18.175690 1 leaderelection.go:278] successfully renewed lease democratic-csi/external-snapshotter-leader-org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:21:18.400971 1 leaderelection.go:278] successfully renewed lease democratic-csi/org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:21:19.943437 1 controller.go:1337] provision "democratic-csi/test-claim-nfs-pvc" class "freenas-nfs-csi": started zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner W0721 03:21:19.943589 1 controller.go:579] "fstype" is deprecated and will be removed in a future release, please use "csi.storage.k8s.io/fstype" instead zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:21:19.943658 1 event.go:285] Event(v1.ObjectReference{Kind:"PersistentVolumeClaim", Namespace:"democratic-csi", Name:"test-claim-nfs-pvc", UID:"43582040-e241-4f8b-bea9-f490a0c62c2a", APIVersion:"v1", ResourceVersion:"13544993", FieldPath:""}): type: 'Normal' reason: 'Provisioning' External provisioner is provisioning volume for claim "democratic-csi/test-claim-nfs-pvc" zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d csi-proxy 2023/07/21 03:21:19 request (://localhost) POST /csi.v1.Controller/CreateVolume HTTP/2.0 zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d csi-driver {"host":"zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d","level":"info","message":"new request - driver: FreeNASSshDriver method: CreateVolume call: {\"metadata\":{\"user-agent\":[\"grpc-go/1.40.0\"],\"x-forwarded-host\":[\"localhost\"]},\"request\":{\"volume_capabilities\":[{\"access_mode\":{\"mode\":\"SINGLE_NODE_MULTI_WRITER\"},\"mount\":{\"mount_flags\":[\"noatime\",\"nfsvers=4\"],\"fs_type\":\"nfs\",\"volume_mount_group\":\"\"},\"access_type\":\"mount\"}],\"parameters\":{\"fsType\":\"nfs\",\"csi.storage.k8s.io/pvc/name\":\"test-claim-nfs-pvc\",\"csi.storage.k8s.io/pvc/namespace\":\"democratic-csi\",\"csi.storage.k8s.io/pv/name\":\"pvc-43582040-e241-4f8b-bea9-f490a0c62c2a\"},\"secrets\":\"redacted\",\"name\":\"pvc-43582040-e241-4f8b-bea9-f490a0c62c2a\",\"capacity_range\":{\"required_bytes\":\"1073741824\",\"limit_bytes\":\"0\"},\"volume_content_source\":null,\"accessibility_requirements\":null},\"cancelled\":false}","service":"democratic-csi","timestamp":"2023-07-21T03:21:19.963Z"} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d csi-proxy 2023/07/21 03:21:19 request headers map[Content-Type:[application/grpc] Grpc-Timeout:[89999638u] Te:[trailers] User-Agent:[grpc-go/1.40.0]] zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:21:19.959307 1 connection.go:183] GRPC call: /csi.v1.Controller/CreateVolume zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:21:19.959349 1 connection.go:184] GRPC request: {"capacity_range":{"required_bytes":1073741824},"name":"pvc-43582040-e241-4f8b-bea9-f490a0c62c2a","parameters":{"csi.storage.k8s.io/pv/name":"pvc-43582040-e241-4f8b-bea9-f490a0c62c2a","csi.storage.k8s.io/pvc/name":"test-claim-nfs-pvc","csi.storage.k8s.io/pvc/namespace":"democratic-csi","fsType":"nfs"},"volume_capabilities":[{"AccessType":{"Mount":{"fs_type":"nfs","mount_flags":["noatime","nfsvers=4"]}},"access_mode":{"mode":7}}]} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-resizer I0721 03:21:23.081288 1 leaderelection.go:278] successfully renewed lease democratic-csi/external-resizer-org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter I0721 03:21:23.190693 1 leaderelection.go:278] successfully renewed lease democratic-csi/external-snapshotter-leader-org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:21:23.416754 1 leaderelection.go:278] successfully renewed lease democratic-csi/org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter I0721 03:21:25.882507 1 reflector.go:255] Listing and watching *v1.VolumeSnapshotContent from github.com/kubernetes-csi/external-snapshotter/client/v4/informers/externalversions/factory.go:117 zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter W0721 03:21:25.887511 1 reflector.go:324] github.com/kubernetes-csi/external-snapshotter/client/v4/informers/externalversions/factory.go:117: failed to list *v1.VolumeSnapshotContent: the server could not find the requested resource (get volumesnapshotcontents.snapshot.storage.k8s.io) zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter E0721 03:21:25.887651 1 reflector.go:138] github.com/kubernetes-csi/external-snapshotter/client/v4/informers/externalversions/factory.go:117: Failed to watch *v1.VolumeSnapshotContent: failed to list *v1.VolumeSnapshotContent: the server could not find the requested resource (get volumesnapshotcontents.snapshot.storage.k8s.io) zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:21:26.527581 1 connection.go:186] GRPC response: {} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:21:26.527905 1 connection.go:187] GRPC error: rpc error: code = Unknown desc = received error creating nfs share - code: 422 body: {"sharingnfs_create.maproot_user":[{"message":"User not found","errno":22}],"sharingnfs_create.maproot_group":[{"message":"Group not found","errno":22}]} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:21:26.528106 1 controller.go:764] CreateVolume failed, supports topology = false, node selected false => may reschedule = false => state = Finished: rpc error: code = Unknown desc = received error creating nfs share - code: 422 body: {"sharingnfs_create.maproot_user":[{"message":"User not found","errno":22}],"sharingnfs_create.maproot_group":[{"message":"Group not found","errno":22}]} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:21:26.528519 1 controller.go:1075] Final error received, removing PVC 43582040-e241-4f8b-bea9-f490a0c62c2a from claims in progress zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d csi-driver {"host":"zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d","level":"error","message":"handler error - driver: FreeNASSshDriver method: CreateVolume error: {\"name\":\"GrpcError\",\"code\":2,\"message\":\"received error creating nfs share - code: 422 body: {\\\"sharingnfs_create.maproot_user\\\":[{\\\"message\\\":\\\"User not found\\\",\\\"errno\\\":22}],\\\"sharingnfs_create.maproot_group\\\":[{\\\"message\\\":\\\"Group not found\\\",\\\"errno\\\":22}]}\"}","service":"democratic-csi","timestamp":"2023-07-21T03:21:26.524Z"} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner W0721 03:21:26.528735 1 controller.go:934] Retrying syncing claim "43582040-e241-4f8b-bea9-f490a0c62c2a", failure 3 zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:21:26.528675 1 event.go:285] Event(v1.ObjectReference{Kind:"PersistentVolumeClaim", Namespace:"democratic-csi", Name:"test-claim-nfs-pvc", UID:"43582040-e241-4f8b-bea9-f490a0c62c2a", APIVersion:"v1", ResourceVersion:"13544993", FieldPath:""}): type: 'Warning' reason: 'ProvisioningFailed' failed to provision volume with StorageClass "freenas-nfs-csi": rpc error: code = Unknown desc = received error creating nfs share - code: 422 body: {"sharingnfs_create.maproot_user":[{"message":"User not found","errno":22}],"sharingnfs_create.maproot_group":[{"message":"Group not found","errno":22}]} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner E0721 03:21:26.529046 1 controller.go:957] error syncing claim "43582040-e241-4f8b-bea9-f490a0c62c2a": failed to provision volume with StorageClass "freenas-nfs-csi": rpc error: code = Unknown desc = received error creating nfs share - code: 422 body: {"sharingnfs_create.maproot_user":[{"message":"User not found","errno":22}],"sharingnfs_create.maproot_group":[{"message":"Group not found","errno":22}]} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-resizer I0721 03:21:28.116011 1 leaderelection.go:278] successfully renewed lease democratic-csi/external-resizer-org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter I0721 03:21:28.220316 1 leaderelection.go:278] successfully renewed lease democratic-csi/external-snapshotter-leader-org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:21:28.447509 1 leaderelection.go:278] successfully renewed lease democratic-csi/org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter I0721 03:21:29.783328 1 reflector.go:255] Listing and watching *v1.VolumeSnapshotClass from github.com/kubernetes-csi/external-snapshotter/client/v4/informers/externalversions/factory.go:117 zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter W0721 03:21:29.790110 1 reflector.go:324] github.com/kubernetes-csi/external-snapshotter/client/v4/informers/externalversions/factory.go:117: failed to list *v1.VolumeSnapshotClass: the server could not find the requested resource (get volumesnapshotclasses.snapshot.storage.k8s.io) zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter E0721 03:21:29.790429 1 reflector.go:138] github.com/kubernetes-csi/external-snapshotter/client/v4/informers/externalversions/factory.go:117: Failed to watch *v1.VolumeSnapshotClass: failed to list *v1.VolumeSnapshotClass: the server could not find the requested resource (get volumesnapshotclasses.snapshot.storage.k8s.io) zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-resizer I0721 03:21:33.151853 1 leaderelection.go:278] successfully renewed lease democratic-csi/external-resizer-org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter I0721 03:21:33.249041 1 leaderelection.go:278] successfully renewed lease democratic-csi/external-snapshotter-leader-org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:21:33.487013 1 leaderelection.go:278] successfully renewed lease democratic-csi/org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d csi-proxy 2023/07/21 03:21:34 request (://localhost) POST /csi.v1.Controller/CreateVolume HTTP/2.0 zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d csi-proxy 2023/07/21 03:21:34 request headers map[Content-Type:[application/grpc] Grpc-Timeout:[89999309u] Te:[trailers] User-Agent:[grpc-go/1.40.0]] zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:21:34.529691 1 controller.go:1337] provision "democratic-csi/test-claim-nfs-pvc" class "freenas-nfs-csi": started zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner W0721 03:21:34.529968 1 controller.go:579] "fstype" is deprecated and will be removed in a future release, please use "csi.storage.k8s.io/fstype" instead zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:21:34.530202 1 event.go:285] Event(v1.ObjectReference{Kind:"PersistentVolumeClaim", Namespace:"democratic-csi", Name:"test-claim-nfs-pvc", UID:"43582040-e241-4f8b-bea9-f490a0c62c2a", APIVersion:"v1", ResourceVersion:"13544993", FieldPath:""}): type: 'Normal' reason: 'Provisioning' External provisioner is provisioning volume for claim "democratic-csi/test-claim-nfs-pvc" zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:21:34.547437 1 connection.go:183] GRPC call: /csi.v1.Controller/CreateVolume zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:21:34.547523 1 connection.go:184] GRPC request: {"capacity_range":{"required_bytes":1073741824},"name":"pvc-43582040-e241-4f8b-bea9-f490a0c62c2a","parameters":{"csi.storage.k8s.io/pv/name":"pvc-43582040-e241-4f8b-bea9-f490a0c62c2a","csi.storage.k8s.io/pvc/name":"test-claim-nfs-pvc","csi.storage.k8s.io/pvc/namespace":"democratic-csi","fsType":"nfs"},"volume_capabilities":[{"AccessType":{"Mount":{"fs_type":"nfs","mount_flags":["noatime","nfsvers=4"]}},"access_mode":{"mode":7}}]} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d csi-driver {"host":"zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d","level":"info","message":"new request - driver: FreeNASSshDriver method: CreateVolume call: {\"metadata\":{\"user-agent\":[\"grpc-go/1.40.0\"],\"x-forwarded-host\":[\"localhost\"]},\"request\":{\"volume_capabilities\":[{\"access_mode\":{\"mode\":\"SINGLE_NODE_MULTI_WRITER\"},\"mount\":{\"mount_flags\":[\"noatime\",\"nfsvers=4\"],\"fs_type\":\"nfs\",\"volume_mount_group\":\"\"},\"access_type\":\"mount\"}],\"parameters\":{\"csi.storage.k8s.io/pvc/namespace\":\"democratic-csi\",\"csi.storage.k8s.io/pv/name\":\"pvc-43582040-e241-4f8b-bea9-f490a0c62c2a\",\"fsType\":\"nfs\",\"csi.storage.k8s.io/pvc/name\":\"test-claim-nfs-pvc\"},\"secrets\":\"redacted\",\"name\":\"pvc-43582040-e241-4f8b-bea9-f490a0c62c2a\",\"capacity_range\":{\"required_bytes\":\"1073741824\",\"limit_bytes\":\"0\"},\"volume_content_source\":null,\"accessibility_requirements\":null},\"cancelled\":false}","service":"democratic-csi","timestamp":"2023-07-21T03:21:34.557Z"} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-resizer I0721 03:21:38.179719 1 leaderelection.go:278] successfully renewed lease democratic-csi/external-resizer-org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter I0721 03:21:38.276420 1 leaderelection.go:278] successfully renewed lease democratic-csi/external-snapshotter-leader-org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:21:38.521794 1 leaderelection.go:278] successfully renewed lease democratic-csi/org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d csi-driver {"host":"zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d","level":"error","message":"handler error - driver: FreeNASSshDriver method: CreateVolume error: {\"name\":\"GrpcError\",\"code\":2,\"message\":\"received error creating nfs share - code: 422 body: {\\\"sharingnfs_create.maproot_user\\\":[{\\\"message\\\":\\\"User not found\\\",\\\"errno\\\":22}],\\\"sharingnfs_create.maproot_group\\\":[{\\\"message\\\":\\\"Group not found\\\",\\\"errno\\\":22}]}\"}","service":"democratic-csi","timestamp":"2023-07-21T03:21:41.152Z"} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:21:41.157748 1 connection.go:186] GRPC response: {} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:21:41.157891 1 connection.go:187] GRPC error: rpc error: code = Unknown desc = received error creating nfs share - code: 422 body: {"sharingnfs_create.maproot_user":[{"message":"User not found","errno":22}],"sharingnfs_create.maproot_group":[{"message":"Group not found","errno":22}]} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:21:41.158475 1 controller.go:764] CreateVolume failed, supports topology = false, node selected false => may reschedule = false => state = Finished: rpc error: code = Unknown desc = received error creating nfs share - code: 422 body: {"sharingnfs_create.maproot_user":[{"message":"User not found","errno":22}],"sharingnfs_create.maproot_group":[{"message":"Group not found","errno":22}]} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:21:41.158949 1 event.go:285] Event(v1.ObjectReference{Kind:"PersistentVolumeClaim", Namespace:"democratic-csi", Name:"test-claim-nfs-pvc", UID:"43582040-e241-4f8b-bea9-f490a0c62c2a", APIVersion:"v1", ResourceVersion:"13544993", FieldPath:""}): type: 'Warning' reason: 'ProvisioningFailed' failed to provision volume with StorageClass "freenas-nfs-csi": rpc error: code = Unknown desc = received error creating nfs share - code: 422 body: {"sharingnfs_create.maproot_user":[{"message":"User not found","errno":22}],"sharingnfs_create.maproot_group":[{"message":"Group not found","errno":22}]} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:21:41.158960 1 controller.go:1075] Final error received, removing PVC 43582040-e241-4f8b-bea9-f490a0c62c2a from claims in progress zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner W0721 03:21:41.159078 1 controller.go:934] Retrying syncing claim "43582040-e241-4f8b-bea9-f490a0c62c2a", failure 4 zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner E0721 03:21:41.159163 1 controller.go:957] error syncing claim "43582040-e241-4f8b-bea9-f490a0c62c2a": failed to provision volume with StorageClass "freenas-nfs-csi": rpc error: code = Unknown desc = received error creating nfs share - code: 422 body: {"sharingnfs_create.maproot_user":[{"message":"User not found","errno":22}],"sharingnfs_create.maproot_group":[{"message":"Group not found","errno":22}]} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-resizer I0721 03:21:43.196784 1 leaderelection.go:278] successfully renewed lease democratic-csi/external-resizer-org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter I0721 03:21:43.293826 1 leaderelection.go:278] successfully renewed lease democratic-csi/external-snapshotter-leader-org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:21:43.540016 1 leaderelection.go:278] successfully renewed lease democratic-csi/org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-resizer I0721 03:21:48.216162 1 leaderelection.go:278] successfully renewed lease democratic-csi/external-resizer-org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter I0721 03:21:48.311908 1 leaderelection.go:278] successfully renewed lease democratic-csi/external-snapshotter-leader-org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:21:48.557570 1 leaderelection.go:278] successfully renewed lease democratic-csi/org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d csi-driver {"host":"zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d","level":"info","message":"new request - driver: FreeNASSshDriver method: Probe call: {\"metadata\":{\"user-agent\":[\"grpc-node-js/1.8.13\"]},\"request\":{},\"cancelled\":false}","service":"democratic-csi","timestamp":"2023-07-21T03:21:50.294Z"} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d csi-driver {"host":"zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d","level":"info","message":"new response - driver: FreeNASSshDriver method: Probe response: {\"ready\":{\"value\":true}}","service":"democratic-csi","timestamp":"2023-07-21T03:21:50.310Z"} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-resizer I0721 03:21:53.249787 1 leaderelection.go:278] successfully renewed lease democratic-csi/external-resizer-org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter I0721 03:21:53.337442 1 leaderelection.go:278] successfully renewed lease democratic-csi/external-snapshotter-leader-org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:21:53.581803 1 leaderelection.go:278] successfully renewed lease democratic-csi/org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:21:57.160270 1 controller.go:1337] provision "democratic-csi/test-claim-nfs-pvc" class "freenas-nfs-csi": started zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:21:57.160683 1 event.go:285] Event(v1.ObjectReference{Kind:"PersistentVolumeClaim", Namespace:"democratic-csi", Name:"test-claim-nfs-pvc", UID:"43582040-e241-4f8b-bea9-f490a0c62c2a", APIVersion:"v1", ResourceVersion:"13544993", FieldPath:""}): type: 'Normal' reason: 'Provisioning' External provisioner is provisioning volume for claim "democratic-csi/test-claim-nfs-pvc" zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner W0721 03:21:57.161479 1 controller.go:579] "fstype" is deprecated and will be removed in a future release, please use "csi.storage.k8s.io/fstype" instead zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:21:57.171836 1 connection.go:183] GRPC call: /csi.v1.Controller/CreateVolume zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d csi-proxy 2023/07/21 03:21:57 request (://localhost) POST /csi.v1.Controller/CreateVolume HTTP/2.0 zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d csi-proxy 2023/07/21 03:21:57 request headers map[Content-Type:[application/grpc] Grpc-Timeout:[89999201u] Te:[trailers] User-Agent:[grpc-go/1.40.0]] zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:21:57.171924 1 connection.go:184] GRPC request: {"capacity_range":{"required_bytes":1073741824},"name":"pvc-43582040-e241-4f8b-bea9-f490a0c62c2a","parameters":{"csi.storage.k8s.io/pv/name":"pvc-43582040-e241-4f8b-bea9-f490a0c62c2a","csi.storage.k8s.io/pvc/name":"test-claim-nfs-pvc","csi.storage.k8s.io/pvc/namespace":"democratic-csi","fsType":"nfs"},"volume_capabilities":[{"AccessType":{"Mount":{"fs_type":"nfs","mount_flags":["noatime","nfsvers=4"]}},"access_mode":{"mode":7}}]} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d csi-driver {"host":"zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d","level":"info","message":"new request - driver: FreeNASSshDriver method: CreateVolume call: {\"metadata\":{\"user-agent\":[\"grpc-go/1.40.0\"],\"x-forwarded-host\":[\"localhost\"]},\"request\":{\"volume_capabilities\":[{\"access_mode\":{\"mode\":\"SINGLE_NODE_MULTI_WRITER\"},\"mount\":{\"mount_flags\":[\"noatime\",\"nfsvers=4\"],\"fs_type\":\"nfs\",\"volume_mount_group\":\"\"},\"access_type\":\"mount\"}],\"parameters\":{\"fsType\":\"nfs\",\"csi.storage.k8s.io/pvc/name\":\"test-claim-nfs-pvc\",\"csi.storage.k8s.io/pvc/namespace\":\"democratic-csi\",\"csi.storage.k8s.io/pv/name\":\"pvc-43582040-e241-4f8b-bea9-f490a0c62c2a\"},\"secrets\":\"redacted\",\"name\":\"pvc-43582040-e241-4f8b-bea9-f490a0c62c2a\",\"capacity_range\":{\"required_bytes\":\"1073741824\",\"limit_bytes\":\"0\"},\"volume_content_source\":null,\"accessibility_requirements\":null},\"cancelled\":false}","service":"democratic-csi","timestamp":"2023-07-21T03:21:57.182Z"} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-resizer I0721 03:21:58.267596 1 leaderelection.go:278] successfully renewed lease democratic-csi/external-resizer-org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter I0721 03:21:58.354444 1 leaderelection.go:278] successfully renewed lease democratic-csi/external-snapshotter-leader-org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:21:58.599964 1 leaderelection.go:278] successfully renewed lease democratic-csi/org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-resizer I0721 03:22:03.300620 1 leaderelection.go:278] successfully renewed lease democratic-csi/external-resizer-org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter I0721 03:22:03.378555 1 leaderelection.go:278] successfully renewed lease democratic-csi/external-snapshotter-leader-org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d csi-driver {"host":"zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d","level":"error","message":"handler error - driver: FreeNASSshDriver method: CreateVolume error: {\"name\":\"GrpcError\",\"code\":2,\"message\":\"received error creating nfs share - code: 422 body: {\\\"sharingnfs_create.maproot_user\\\":[{\\\"message\\\":\\\"User not found\\\",\\\"errno\\\":22}],\\\"sharingnfs_create.maproot_group\\\":[{\\\"message\\\":\\\"Group not found\\\",\\\"errno\\\":22}]}\"}","service":"democratic-csi","timestamp":"2023-07-21T03:22:03.764Z"} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:22:03.748083 1 leaderelection.go:278] successfully renewed lease democratic-csi/org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:22:03.766722 1 connection.go:186] GRPC response: {} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:22:03.766820 1 connection.go:187] GRPC error: rpc error: code = Unknown desc = received error creating nfs share - code: 422 body: {"sharingnfs_create.maproot_user":[{"message":"User not found","errno":22}],"sharingnfs_create.maproot_group":[{"message":"Group not found","errno":22}]} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:22:03.766925 1 controller.go:764] CreateVolume failed, supports topology = false, node selected false => may reschedule = false => state = Finished: rpc error: code = Unknown desc = received error creating nfs share - code: 422 body: {"sharingnfs_create.maproot_user":[{"message":"User not found","errno":22}],"sharingnfs_create.maproot_group":[{"message":"Group not found","errno":22}]} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:22:03.767041 1 controller.go:1075] Final error received, removing PVC 43582040-e241-4f8b-bea9-f490a0c62c2a from claims in progress zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner W0721 03:22:03.767084 1 controller.go:934] Retrying syncing claim "43582040-e241-4f8b-bea9-f490a0c62c2a", failure 5 zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:22:03.767139 1 event.go:285] Event(v1.ObjectReference{Kind:"PersistentVolumeClaim", Namespace:"democratic-csi", Name:"test-claim-nfs-pvc", UID:"43582040-e241-4f8b-bea9-f490a0c62c2a", APIVersion:"v1", ResourceVersion:"13544993", FieldPath:""}): type: 'Warning' reason: 'ProvisioningFailed' failed to provision volume with StorageClass "freenas-nfs-csi": rpc error: code = Unknown desc = received error creating nfs share - code: 422 body: {"sharingnfs_create.maproot_user":[{"message":"User not found","errno":22}],"sharingnfs_create.maproot_group":[{"message":"Group not found","errno":22}]} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner E0721 03:22:03.767344 1 controller.go:957] error syncing claim "43582040-e241-4f8b-bea9-f490a0c62c2a": failed to provision volume with StorageClass "freenas-nfs-csi": rpc error: code = Unknown desc = received error creating nfs share - code: 422 body: {"sharingnfs_create.maproot_user":[{"message":"User not found","errno":22}],"sharingnfs_create.maproot_group":[{"message":"Group not found","errno":22}]} zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-resizer I0721 03:22:08.321572 1 leaderelection.go:278] successfully renewed lease democratic-csi/external-resizer-org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter I0721 03:22:08.282730 1 reflector.go:255] Listing and watching *v1.VolumeSnapshotClass from github.com/kubernetes-csi/external-snapshotter/client/v4/informers/externalversions/factory.go:117 zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter W0721 03:22:08.287311 1 reflector.go:324] github.com/kubernetes-csi/external-snapshotter/client/v4/informers/externalversions/factory.go:117: failed to list *v1.VolumeSnapshotClass: the server could not find the requested resource (get volumesnapshotclasses.snapshot.storage.k8s.io) zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter E0721 03:22:08.287436 1 reflector.go:138] github.com/kubernetes-csi/external-snapshotter/client/v4/informers/externalversions/factory.go:117: Failed to watch *v1.VolumeSnapshotClass: failed to list *v1.VolumeSnapshotClass: the server could not find the requested resource (get volumesnapshotclasses.snapshot.storage.k8s.io) zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter I0721 03:22:08.396239 1 leaderelection.go:278] successfully renewed lease democratic-csi/external-snapshotter-leader-org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:22:08.767488 1 leaderelection.go:278] successfully renewed lease democratic-csi/org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter I0721 03:22:09.954504 1 reflector.go:255] Listing and watching *v1.VolumeSnapshotContent from github.com/kubernetes-csi/external-snapshotter/client/v4/informers/externalversions/factory.go:117 zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter W0721 03:22:09.957468 1 reflector.go:324] github.com/kubernetes-csi/external-snapshotter/client/v4/informers/externalversions/factory.go:117: failed to list *v1.VolumeSnapshotContent: the server could not find the requested resource (get volumesnapshotcontents.snapshot.storage.k8s.io) zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter E0721 03:22:09.957534 1 reflector.go:138] github.com/kubernetes-csi/external-snapshotter/client/v4/informers/externalversions/factory.go:117: Failed to watch *v1.VolumeSnapshotContent: failed to list *v1.VolumeSnapshotContent: the server could not find the requested resource (get volumesnapshotcontents.snapshot.storage.k8s.io) zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-resizer I0721 03:22:13.352010 1 leaderelection.go:278] successfully renewed lease democratic-csi/external-resizer-org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter I0721 03:22:13.418329 1 leaderelection.go:278] successfully renewed lease democratic-csi/external-snapshotter-leader-org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:22:13.797044 1 leaderelection.go:278] successfully renewed lease democratic-csi/org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-resizer I0721 03:22:18.368353 1 leaderelection.go:278] successfully renewed lease democratic-csi/external-resizer-org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-snapshotter I0721 03:22:18.435361 1 leaderelection.go:278] successfully renewed lease democratic-csi/external-snapshotter-leader-org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d external-provisioner I0721 03:22:18.816298 1 leaderelection.go:278] successfully renewed lease democratic-csi/org-democratic-csi-nfs

Any idea how to deal with this? I can confirm the group and user were created in my TrueNAS server. The GID and UID are also matched.

travisghansen commented 1 year ago

For the nfs/share values use the name (of user and group) instead of id.

zulhfreelancer commented 1 year ago

When I set the user and group to strings instead of IDs, I got the following. And the test PVC and pod remain unhappy like in my previous comment.

Name:          test-claim-nfs-pvc
Namespace:     democratic-csi
StorageClass:  freenas-nfs-csi
Status:        Pending
Volume:        
Labels:        <none>
Annotations:   volume.beta.kubernetes.io/storage-class: freenas-nfs-csi
               volume.beta.kubernetes.io/storage-provisioner: org.democratic-csi.nfs
               volume.kubernetes.io/storage-provisioner: org.democratic-csi.nfs
Finalizers:    [kubernetes.io/pvc-protection]
Capacity:      
Access Modes:  
VolumeMode:    Filesystem
Used By:       test-claim-nfs-pod
Events:
  Type     Reason                Age               From                                                                                                            Message
  ----     ------                ----              ----                                                                                                            -------
  Normal   ExternalProvisioning  9s (x3 over 12s)  persistentvolume-controller                                                                                     waiting for a volume to be created, either by external provisioner "org.democratic-csi.nfs" or manually created by system administrator
  Warning  ProvisioningFailed    3s (x2 over 8s)   org.democratic-csi.nfs_zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv_48ee7055-5864-4a38-bf69-c5a768a64f56  failed to provision volume with StorageClass "freenas-nfs-csi": rpc error: code = FailedPrecondition desc = BREAKING CHANGE since v1.5.3! datasetPermissionsUser must be numeric: k8s-nfs is invalid
  Normal   Provisioning          1s (x3 over 12s)  org.democratic-csi.nfs_zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv_48ee7055-5864-4a38-bf69-c5a768a64f56  External provisioner is provisioning volume for claim "democratic-csi/test-claim-nfs-pvc"
Controller pod logs zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-resizer I0722 06:13:22.637497 1 main.go:93] Version : v1.4.0 zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-resizer I0722 06:13:22.644353 1 feature_gate.go:245] feature gates: &{map[]} zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-resizer I0722 06:13:22.647194 1 connection.go:154] Connecting to unix:///csi-data/csi.sock zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv csi-proxy 2023/07/22 06:13:26 BIND_TO [unix:///csi-data/csi.sock], PROXY_TO [unix:///csi-data/csi.sock.internal] zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv csi-proxy 2023/07/22 06:13:26 waiting for socket [/csi-data/csi.sock.internal] to appear, 60s remaining zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-snapshotter I0722 06:13:22.901530 1 main.go:104] Version: v5.0.0-rc3-webhook zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-snapshotter I0722 06:13:22.905382 1 connection.go:154] Connecting to unix:///csi-data/csi.sock zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv csi-driver grpc implementation: @grpc/grpc-js zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner I0722 06:13:22.400957 1 feature_gate.go:245] feature gates: &{map[]} zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner I0722 06:13:22.401201 1 csi-provisioner.go:139] Version: v3.1.0 zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner I0722 06:13:22.401228 1 csi-provisioner.go:162] Building kube configs for running in cluster... zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner I0722 06:13:22.403063 1 connection.go:154] Connecting to unix:///csi-data/csi.sock zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv csi-proxy 2023/07/22 06:13:27 waiting for socket [/csi-data/csi.sock.internal] to appear, 59s remaining zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv csi-driver {"host":"zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv","level":"info","message":"initializing csi driver: freenas-nfs","service":"democratic-csi","timestamp":"2023-07-22T06:13:27.389Z"} zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv csi-proxy 2023/07/22 06:13:28 waiting for socket [/csi-data/csi.sock.internal] to appear, 58s remaining zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv csi-proxy 2023/07/22 06:13:29 waiting for socket [/csi-data/csi.sock.internal] to appear, 57s remaining zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv csi-driver {"host":"zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv","level":"info","message":"starting csi server - node version: v16.18.0, package version: 1.8.3, config file: /config/..2023_07_22_06_13_21.161020458/driver-config-file.yaml, csi-name: org.democratic-csi.nfs, csi-driver: freenas-nfs, csi-mode: controller, csi-version: 1.5.0, address: , socket: unix:///csi-data/csi.sock.internal","service":"democratic-csi","timestamp":"2023-07-22T06:13:29.310Z"} zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv csi-proxy 2023/07/22 06:13:30 PROXY_TO [unix:///csi-data/csi.sock.internal] is ready! zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv csi-proxy 2023/07/22 06:13:30 BIND_TO [unix:///csi-data/csi.sock] is ready! zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-snapshotter I0722 06:13:30.676874 1 connection.go:183] GRPC call: /csi.v1.Identity/GetPluginInfo zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-resizer I0722 06:13:30.702250 1 common.go:111] Probing CSI driver for readiness zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-resizer I0722 06:13:30.702335 1 connection.go:183] GRPC call: /csi.v1.Identity/Probe zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-resizer I0722 06:13:30.702350 1 connection.go:184] GRPC request: {} zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-snapshotter I0722 06:13:30.677009 1 connection.go:184] GRPC request: {} zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv csi-proxy 2023/07/22 06:13:30 request (://localhost) POST /csi.v1.Identity/GetPluginInfo HTTP/2.0 zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv csi-proxy 2023/07/22 06:13:30 request headers map[Content-Type:[application/grpc] Grpc-Timeout:[89994498u] Te:[trailers] User-Agent:[grpc-go/1.40.0]] zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv csi-proxy 2023/07/22 06:13:30 Dialing upstream: unix:///csi-data/csi.sock.internal zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv csi-driver {"host":"zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv","level":"info","message":"new request - driver: FreeNASSshDriver method: GetPluginInfo call: {\"metadata\":{\"user-agent\":[\"grpc-go/1.40.0\"],\"x-forwarded-host\":[\"localhost\"]},\"request\":{},\"cancelled\":false}","service":"democratic-csi","timestamp":"2023-07-22T06:13:30.716Z"} zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv csi-proxy 2023/07/22 06:13:30 request (://localhost) POST /csi.v1.Identity/Probe HTTP/2.0 zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv csi-proxy 2023/07/22 06:13:30 request headers map[Content-Type:[application/grpc] Grpc-Timeout:[89987684u] Te:[trailers] User-Agent:[grpc-go/1.40.0]] zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv csi-driver {"host":"zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv","level":"info","message":"new response - driver: FreeNASSshDriver method: GetPluginInfo response: {\"name\":\"org.democratic-csi.nfs\",\"vendor_version\":\"1.8.3\"}","service":"democratic-csi","timestamp":"2023-07-22T06:13:30.719Z"} zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv csi-driver {"host":"zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv","level":"info","message":"new request - driver: FreeNASSshDriver method: Probe call: {\"metadata\":{\"x-forwarded-host\":[\"localhost\"],\"user-agent\":[\"grpc-go/1.40.0\"]},\"request\":{},\"cancelled\":false}","service":"democratic-csi","timestamp":"2023-07-22T06:13:30.739Z"} zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-snapshotter I0722 06:13:30.762417 1 connection.go:186] GRPC response: {"name":"org.democratic-csi.nfs","vendor_version":"1.8.3"} zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-snapshotter I0722 06:13:30.762620 1 connection.go:187] GRPC error: zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-snapshotter I0722 06:13:30.762684 1 main.go:184] CSI driver name: "org.democratic-csi.nfs" zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-snapshotter I0722 06:13:30.762733 1 common.go:111] Probing CSI driver for readiness zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-snapshotter I0722 06:13:30.762803 1 connection.go:183] GRPC call: /csi.v1.Identity/Probe zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-snapshotter I0722 06:13:30.762821 1 connection.go:184] GRPC request: {} zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv csi-proxy 2023/07/22 06:13:30 request (://localhost) POST /csi.v1.Identity/Probe HTTP/2.0 zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv csi-proxy 2023/07/22 06:13:30 request headers map[Content-Type:[application/grpc] Grpc-Timeout:[89999623u] Te:[trailers] User-Agent:[grpc-go/1.40.0]] zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv csi-driver {"host":"zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv","level":"info","message":"new request - driver: FreeNASSshDriver method: Probe call: {\"metadata\":{\"user-agent\":[\"grpc-go/1.40.0\"],\"x-forwarded-host\":[\"localhost\"]},\"request\":{},\"cancelled\":false}","service":"democratic-csi","timestamp":"2023-07-22T06:13:30.771Z"} zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner I0722 06:13:31.043817 1 common.go:111] Probing CSI driver for readiness zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner I0722 06:13:31.043859 1 connection.go:183] GRPC call: /csi.v1.Identity/Probe zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv csi-driver {"host":"zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv","level":"info","message":"new request - driver: FreeNASSshDriver method: Probe call: {\"metadata\":{\"user-agent\":[\"grpc-go/1.40.0\"],\"x-forwarded-host\":[\"localhost\"]},\"request\":{},\"cancelled\":false}","service":"democratic-csi","timestamp":"2023-07-22T06:13:31.061Z"} zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner I0722 06:13:31.043873 1 connection.go:184] GRPC request: {} zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv csi-proxy 2023/07/22 06:13:31 request (://localhost) POST /csi.v1.Identity/Probe HTTP/2.0 zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv csi-proxy 2023/07/22 06:13:31 request headers map[Content-Type:[application/grpc] Grpc-Timeout:[89990788u] Te:[trailers] User-Agent:[grpc-go/1.40.0]] zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv csi-driver {"host":"zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv","level":"info","message":"new response - driver: FreeNASSshDriver method: Probe response: {\"ready\":{\"value\":true}}","service":"democratic-csi","timestamp":"2023-07-22T06:13:31.191Z"} zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv csi-proxy 2023/07/22 06:13:31 request (://localhost) POST /csi.v1.Identity/GetPluginInfo HTTP/2.0 zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner I0722 06:13:31.198578 1 connection.go:186] GRPC response: {"ready":{"value":true}} zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner I0722 06:13:31.198983 1 connection.go:187] GRPC error: zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv csi-proxy 2023/07/22 06:13:31 request headers map[Content-Type:[application/grpc] Grpc-Timeout:[89999878u] Te:[trailers] User-Agent:[grpc-go/1.40.0]] zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner I0722 06:13:31.199017 1 connection.go:183] GRPC call: /csi.v1.Identity/GetPluginInfo zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner I0722 06:13:31.199031 1 connection.go:184] GRPC request: {} zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv csi-driver {"host":"zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv","level":"info","message":"new request - driver: FreeNASSshDriver method: GetPluginInfo call: {\"metadata\":{\"x-forwarded-host\":[\"localhost\"],\"user-agent\":[\"grpc-go/1.40.0\"]},\"request\":{},\"cancelled\":false}","service":"democratic-csi","timestamp":"2023-07-22T06:13:31.205Z"} zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv csi-driver {"host":"zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv","level":"info","message":"new response - driver: FreeNASSshDriver method: GetPluginInfo response: {\"name\":\"org.democratic-csi.nfs\",\"vendor_version\":\"1.8.3\"}","service":"democratic-csi","timestamp":"2023-07-22T06:13:31.207Z"} zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv csi-proxy 2023/07/22 06:13:31 request (://localhost) POST /csi.v1.Identity/GetPluginCapabilities HTTP/2.0 zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner I0722 06:13:31.212724 1 connection.go:186] GRPC response: {"name":"org.democratic-csi.nfs","vendor_version":"1.8.3"} zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner I0722 06:13:31.212969 1 connection.go:187] GRPC error: zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner I0722 06:13:31.212997 1 csi-provisioner.go:206] Detected CSI driver org.democratic-csi.nfs zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner I0722 06:13:31.213027 1 connection.go:183] GRPC call: /csi.v1.Identity/GetPluginCapabilities zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner I0722 06:13:31.213040 1 connection.go:184] GRPC request: {} zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv csi-proxy 2023/07/22 06:13:31 request headers map[Content-Type:[application/grpc] Grpc-Timeout:[89999880u] Te:[trailers] User-Agent:[grpc-go/1.40.0]] zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv csi-driver {"host":"zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv","level":"info","message":"new request - driver: FreeNASSshDriver method: GetPluginCapabilities call: {\"metadata\":{\"user-agent\":[\"grpc-go/1.40.0\"],\"x-forwarded-host\":[\"localhost\"]},\"request\":{},\"cancelled\":false}","service":"democratic-csi","timestamp":"2023-07-22T06:13:31.220Z"} zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv csi-driver {"host":"zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv","level":"info","message":"new response - driver: FreeNASSshDriver method: GetPluginCapabilities response: {\"capabilities\":[{\"service\":{\"type\":\"CONTROLLER_SERVICE\"}},{\"volume_expansion\":{\"type\":\"ONLINE\"}}]}","service":"democratic-csi","timestamp":"2023-07-22T06:13:31.221Z"} zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner I0722 06:13:31.231700 1 connection.go:186] GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}}]} zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner I0722 06:13:31.232223 1 connection.go:187] GRPC error: zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner I0722 06:13:31.232270 1 connection.go:183] GRPC call: /csi.v1.Controller/ControllerGetCapabilities zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner I0722 06:13:31.232282 1 connection.go:184] GRPC request: {} zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv csi-proxy 2023/07/22 06:13:31 request (://localhost) POST /csi.v1.Controller/ControllerGetCapabilities HTTP/2.0 zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv csi-proxy 2023/07/22 06:13:31 request headers map[Content-Type:[application/grpc] Grpc-Timeout:[89999871u] Te:[trailers] User-Agent:[grpc-go/1.40.0]] zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv csi-driver {"host":"zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv","level":"info","message":"new request - driver: FreeNASSshDriver method: ControllerGetCapabilities call: {\"metadata\":{\"x-forwarded-host\":[\"localhost\"],\"user-agent\":[\"grpc-go/1.40.0\"]},\"request\":{},\"cancelled\":false}","service":"democratic-csi","timestamp":"2023-07-22T06:13:31.238Z"} zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv csi-driver {"host":"zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv","level":"info","message":"new response - driver: FreeNASSshDriver method: ControllerGetCapabilities response: {\"capabilities\":[{\"rpc\":{\"type\":\"CREATE_DELETE_VOLUME\"}},{\"rpc\":{\"type\":\"LIST_VOLUMES\"}},{\"rpc\":{\"type\":\"GET_CAPACITY\"}},{\"rpc\":{\"type\":\"CREATE_DELETE_SNAPSHOT\"}},{\"rpc\":{\"type\":\"LIST_SNAPSHOTS\"}},{\"rpc\":{\"type\":\"CLONE_VOLUME\"}},{\"rpc\":{\"type\":\"EXPAND_VOLUME\"}},{\"rpc\":{\"type\":\"GET_VOLUME\"}},{\"rpc\":{\"type\":\"SINGLE_NODE_MULTI_WRITER\"}}]}","service":"democratic-csi","timestamp":"2023-07-22T06:13:31.240Z"} zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner I0722 06:13:31.249809 1 connection.go:186] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":3}}},{"Type":{"Rpc":{"type":4}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":6}}},{"Type":{"Rpc":{"type":7}}},{"Type":{"Rpc":{"type":9}}},{"Type":{"Rpc":{"type":12}}},{"Type":{"Rpc":{"type":13}}}]} zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner I0722 06:13:31.250547 1 connection.go:187] GRPC error: zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner I0722 06:13:31.251526 1 csi-provisioner.go:278] CSI driver does not support PUBLISH_UNPUBLISH_VOLUME, not watching VolumeAttachments zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner I0722 06:13:31.255764 1 controller.go:732] Using saving PVs to API server in background zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner I0722 06:13:31.256906 1 leaderelection.go:248] attempting to acquire leader lease democratic-csi/org-democratic-csi-nfs... zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner I0722 06:13:31.282907 1 leaderelection.go:352] lock is held by zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d and has not yet expired zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner I0722 06:13:31.283366 1 leader_election.go:212] new leader detected, current leader: zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner I0722 06:13:31.283693 1 leaderelection.go:253] failed to acquire lease democratic-csi/org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-snapshotter I0722 06:13:31.992655 1 connection.go:186] GRPC response: {"ready":{"value":true}} zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-resizer I0722 06:13:31.991941 1 connection.go:186] GRPC response: {"ready":{"value":true}} zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-resizer I0722 06:13:31.992816 1 connection.go:187] GRPC error: zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-resizer I0722 06:13:31.993864 1 connection.go:183] GRPC call: /csi.v1.Identity/GetPluginInfo zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-resizer I0722 06:13:31.994139 1 connection.go:184] GRPC request: {} zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv csi-driver {"host":"zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv","level":"info","message":"new response - driver: FreeNASSshDriver method: Probe response: {\"ready\":{\"value\":true}}","service":"democratic-csi","timestamp":"2023-07-22T06:13:31.983Z"} zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv csi-driver {"host":"zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv","level":"info","message":"new response - driver: FreeNASSshDriver method: Probe response: {\"ready\":{\"value\":true}}","service":"democratic-csi","timestamp":"2023-07-22T06:13:31.988Z"} zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv csi-driver {"host":"zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv","level":"info","message":"new request - driver: FreeNASSshDriver method: GetPluginInfo call: {\"metadata\":{\"x-forwarded-host\":[\"localhost\"],\"user-agent\":[\"grpc-go/1.40.0\"]},\"request\":{},\"cancelled\":false}","service":"democratic-csi","timestamp":"2023-07-22T06:13:32.000Z"} zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-resizer I0722 06:13:32.007313 1 connection.go:186] GRPC response: {"name":"org.democratic-csi.nfs","vendor_version":"1.8.3"} zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv csi-proxy 2023/07/22 06:13:31 request (://localhost) POST /csi.v1.Identity/GetPluginInfo HTTP/2.0 zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-resizer I0722 06:13:32.007678 1 connection.go:187] GRPC error: zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv csi-proxy 2023/07/22 06:13:31 request headers map[Content-Type:[application/grpc] Grpc-Timeout:[89997993u] Te:[trailers] User-Agent:[grpc-go/1.40.0]] zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv csi-proxy 2023/07/22 06:13:32 request (://localhost) POST /csi.v1.Controller/ControllerGetCapabilities HTTP/2.0 zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv csi-proxy 2023/07/22 06:13:32 request headers map[Content-Type:[application/grpc] Grpc-Timeout:[88676761u] Te:[trailers] User-Agent:[grpc-go/1.40.0]] zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv csi-proxy 2023/07/22 06:13:32 request (://localhost) POST /csi.v1.Identity/GetPluginCapabilities HTTP/2.0 zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv csi-driver {"host":"zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv","level":"info","message":"new response - driver: FreeNASSshDriver method: GetPluginInfo response: {\"name\":\"org.democratic-csi.nfs\",\"vendor_version\":\"1.8.3\"}","service":"democratic-csi","timestamp":"2023-07-22T06:13:32.001Z"} zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv csi-proxy 2023/07/22 06:13:32 request headers map[Content-Type:[application/grpc] Grpc-Timeout:[89999783u] Te:[trailers] User-Agent:[grpc-go/1.40.0]] zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-resizer I0722 06:13:32.007715 1 main.go:141] CSI driver name: "org.democratic-csi.nfs" zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-resizer I0722 06:13:32.008086 1 connection.go:183] GRPC call: /csi.v1.Identity/GetPluginCapabilities zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-resizer I0722 06:13:32.008108 1 connection.go:184] GRPC request: {} zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-snapshotter I0722 06:13:31.998216 1 connection.go:187] GRPC error: zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-snapshotter I0722 06:13:31.998470 1 connection.go:183] GRPC call: /csi.v1.Controller/ControllerGetCapabilities zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-snapshotter I0722 06:13:31.998643 1 connection.go:184] GRPC request: {} zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv csi-driver {"host":"zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv","level":"info","message":"new request - driver: FreeNASSshDriver method: ControllerGetCapabilities call: {\"metadata\":{\"x-forwarded-host\":[\"localhost\"],\"user-agent\":[\"grpc-go/1.40.0\"]},\"request\":{},\"cancelled\":false}","service":"democratic-csi","timestamp":"2023-07-22T06:13:32.014Z"} zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv csi-driver {"host":"zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv","level":"info","message":"new response - driver: FreeNASSshDriver method: ControllerGetCapabilities response: {\"capabilities\":[{\"rpc\":{\"type\":\"CREATE_DELETE_VOLUME\"}},{\"rpc\":{\"type\":\"LIST_VOLUMES\"}},{\"rpc\":{\"type\":\"GET_CAPACITY\"}},{\"rpc\":{\"type\":\"CREATE_DELETE_SNAPSHOT\"}},{\"rpc\":{\"type\":\"LIST_SNAPSHOTS\"}},{\"rpc\":{\"type\":\"CLONE_VOLUME\"}},{\"rpc\":{\"type\":\"EXPAND_VOLUME\"}},{\"rpc\":{\"type\":\"GET_VOLUME\"}},{\"rpc\":{\"type\":\"SINGLE_NODE_MULTI_WRITER\"}}]}","service":"democratic-csi","timestamp":"2023-07-22T06:13:32.014Z"} zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv csi-driver {"host":"zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv","level":"info","message":"new request - driver: FreeNASSshDriver method: GetPluginCapabilities call: {\"metadata\":{\"user-agent\":[\"grpc-go/1.40.0\"],\"x-forwarded-host\":[\"localhost\"]},\"request\":{},\"cancelled\":false}","service":"democratic-csi","timestamp":"2023-07-22T06:13:32.021Z"} zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv csi-driver {"host":"zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv","level":"info","message":"new response - driver: FreeNASSshDriver method: GetPluginCapabilities response: {\"capabilities\":[{\"service\":{\"type\":\"CONTROLLER_SERVICE\"}},{\"volume_expansion\":{\"type\":\"ONLINE\"}}]}","service":"democratic-csi","timestamp":"2023-07-22T06:13:32.022Z"} zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv csi-driver {"host":"zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv","level":"info","message":"new request - driver: FreeNASSshDriver method: ControllerGetCapabilities call: {\"metadata\":{\"user-agent\":[\"grpc-go/1.40.0\"],\"x-forwarded-host\":[\"localhost\"]},\"request\":{},\"cancelled\":false}","service":"democratic-csi","timestamp":"2023-07-22T06:13:32.036Z"} zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-resizer I0722 06:13:32.027455 1 connection.go:186] GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}}]} zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-resizer I0722 06:13:32.027950 1 connection.go:187] GRPC error: zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-resizer I0722 06:13:32.028006 1 connection.go:183] GRPC call: /csi.v1.Controller/ControllerGetCapabilities zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-resizer I0722 06:13:32.028019 1 connection.go:184] GRPC request: {} zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv csi-proxy 2023/07/22 06:13:32 request (://localhost) POST /csi.v1.Controller/ControllerGetCapabilities HTTP/2.0 zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv csi-proxy 2023/07/22 06:13:32 request headers map[Content-Type:[application/grpc] Grpc-Timeout:[89999836u] Te:[trailers] User-Agent:[grpc-go/1.40.0]] zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-resizer I0722 06:13:32.045983 1 connection.go:186] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":3}}},{"Type":{"Rpc":{"type":4}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":6}}},{"Type":{"Rpc":{"type":7}}},{"Type":{"Rpc":{"type":9}}},{"Type":{"Rpc":{"type":12}}},{"Type":{"Rpc":{"type":13}}}]} zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-resizer I0722 06:13:32.046588 1 connection.go:187] GRPC error: zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv csi-driver {"host":"zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv","level":"info","message":"new response - driver: FreeNASSshDriver method: ControllerGetCapabilities response: {\"capabilities\":[{\"rpc\":{\"type\":\"CREATE_DELETE_VOLUME\"}},{\"rpc\":{\"type\":\"LIST_VOLUMES\"}},{\"rpc\":{\"type\":\"GET_CAPACITY\"}},{\"rpc\":{\"type\":\"CREATE_DELETE_SNAPSHOT\"}},{\"rpc\":{\"type\":\"LIST_SNAPSHOTS\"}},{\"rpc\":{\"type\":\"CLONE_VOLUME\"}},{\"rpc\":{\"type\":\"EXPAND_VOLUME\"}},{\"rpc\":{\"type\":\"GET_VOLUME\"}},{\"rpc\":{\"type\":\"SINGLE_NODE_MULTI_WRITER\"}}]}","service":"democratic-csi","timestamp":"2023-07-22T06:13:32.037Z"} zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv csi-driver {"host":"zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv","level":"info","message":"new request - driver: FreeNASSshDriver method: ControllerGetCapabilities call: {\"metadata\":{\"user-agent\":[\"grpc-go/1.40.0\"],\"x-forwarded-host\":[\"localhost\"]},\"request\":{},\"cancelled\":false}","service":"democratic-csi","timestamp":"2023-07-22T06:13:32.049Z"} zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-snapshotter I0722 06:13:32.026866 1 connection.go:186] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":3}}},{"Type":{"Rpc":{"type":4}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":6}}},{"Type":{"Rpc":{"type":7}}},{"Type":{"Rpc":{"type":9}}},{"Type":{"Rpc":{"type":12}}},{"Type":{"Rpc":{"type":13}}}]} zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-snapshotter I0722 06:13:32.027452 1 connection.go:187] GRPC error: zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-snapshotter I0722 06:13:32.027543 1 main.go:222] Start NewCSISnapshotSideCarController with snapshotter [org.democratic-csi.nfs] kubeconfig [] csiTimeout [1m30s] csiAddress [/csi-data/csi.sock] resyncPeriod [15m0s] snapshotNamePrefix [snapshot] snapshotNameUUIDLength [274878202104] zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-snapshotter I0722 06:13:32.029610 1 leaderelection.go:248] attempting to acquire leader lease democratic-csi/external-snapshotter-leader-org-democratic-csi-nfs... zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-snapshotter I0722 06:13:32.048588 1 leaderelection.go:352] lock is held by zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d and has not yet expired zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-snapshotter I0722 06:13:32.048654 1 leaderelection.go:253] failed to acquire lease democratic-csi/external-snapshotter-leader-org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-snapshotter I0722 06:13:32.048711 1 leader_election.go:212] new leader detected, current leader: zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-resizer I0722 06:13:32.046628 1 connection.go:183] GRPC call: /csi.v1.Controller/ControllerGetCapabilities zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-resizer I0722 06:13:32.046661 1 connection.go:184] GRPC request: {} zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv csi-proxy 2023/07/22 06:13:32 request (://localhost) POST /csi.v1.Controller/ControllerGetCapabilities HTTP/2.0 zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv csi-proxy 2023/07/22 06:13:32 request headers map[Content-Type:[application/grpc] Grpc-Timeout:[89999860u] Te:[trailers] User-Agent:[grpc-go/1.40.0]] zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv csi-driver {"host":"zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv","level":"info","message":"new response - driver: FreeNASSshDriver method: ControllerGetCapabilities response: {\"capabilities\":[{\"rpc\":{\"type\":\"CREATE_DELETE_VOLUME\"}},{\"rpc\":{\"type\":\"LIST_VOLUMES\"}},{\"rpc\":{\"type\":\"GET_CAPACITY\"}},{\"rpc\":{\"type\":\"CREATE_DELETE_SNAPSHOT\"}},{\"rpc\":{\"type\":\"LIST_SNAPSHOTS\"}},{\"rpc\":{\"type\":\"CLONE_VOLUME\"}},{\"rpc\":{\"type\":\"EXPAND_VOLUME\"}},{\"rpc\":{\"type\":\"GET_VOLUME\"}},{\"rpc\":{\"type\":\"SINGLE_NODE_MULTI_WRITER\"}}]}","service":"democratic-csi","timestamp":"2023-07-22T06:13:32.050Z"} zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-resizer I0722 06:13:32.055274 1 connection.go:186] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":3}}},{"Type":{"Rpc":{"type":4}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":6}}},{"Type":{"Rpc":{"type":7}}},{"Type":{"Rpc":{"type":9}}},{"Type":{"Rpc":{"type":12}}},{"Type":{"Rpc":{"type":13}}}]} zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-resizer I0722 06:13:32.055652 1 connection.go:187] GRPC error: zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-resizer I0722 06:13:32.056243 1 controller.go:120] Register Pod informer for resizer org.democratic-csi.nfs zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-resizer I0722 06:13:32.057349 1 leaderelection.go:248] attempting to acquire leader lease democratic-csi/external-resizer-org-democratic-csi-nfs... zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-resizer I0722 06:13:32.071687 1 leaderelection.go:352] lock is held by zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d and has not yet expired zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-resizer I0722 06:13:32.071750 1 leaderelection.go:253] failed to acquire lease democratic-csi/external-resizer-org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-resizer I0722 06:13:32.071808 1 leader_election.go:212] new leader detected, current leader: zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-snapshotter I0722 06:13:40.691903 1 leaderelection.go:352] lock is held by zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d and has not yet expired zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-snapshotter I0722 06:13:40.691987 1 leaderelection.go:253] failed to acquire lease democratic-csi/external-snapshotter-leader-org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-resizer I0722 06:13:40.713238 1 leaderelection.go:352] lock is held by zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d and has not yet expired zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-resizer I0722 06:13:40.713333 1 leaderelection.go:253] failed to acquire lease democratic-csi/external-resizer-org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner I0722 06:13:41.935015 1 leaderelection.go:352] lock is held by zfs-nfs-democratic-csi-controller-8657f8468f-nfr6d and has not yet expired zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner I0722 06:13:41.935063 1 leaderelection.go:253] failed to acquire lease democratic-csi/org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner I0722 06:13:50.940764 1 leaderelection.go:258] successfully acquired lease democratic-csi/org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner I0722 06:13:50.940789 1 leader_election.go:212] new leader detected, current leader: zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner I0722 06:13:50.945863 1 leader_election.go:205] became leader, starting zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner I0722 06:13:50.947047 1 reflector.go:219] Starting reflector *v1.PersistentVolumeClaim (15m0s) from k8s.io/client-go/informers/factory.go:134 zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner I0722 06:13:50.947137 1 reflector.go:255] Listing and watching *v1.PersistentVolumeClaim from k8s.io/client-go/informers/factory.go:134 zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner I0722 06:13:50.948297 1 reflector.go:219] Starting reflector *v1.StorageClass (1h0m0s) from k8s.io/client-go/informers/factory.go:134 zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner I0722 06:13:50.948382 1 reflector.go:255] Listing and watching *v1.StorageClass from k8s.io/client-go/informers/factory.go:134 zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner I0722 06:13:50.965637 1 leaderelection.go:278] successfully renewed lease democratic-csi/org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner I0722 06:13:51.046257 1 shared_informer.go:270] caches populated zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner I0722 06:13:51.046607 1 shared_informer.go:270] caches populated zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner I0722 06:13:51.046666 1 controller.go:811] Starting provisioner controller org.democratic-csi.nfs_zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv_48ee7055-5864-4a38-bf69-c5a768a64f56! zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner I0722 06:13:51.046820 1 volume_store.go:97] Starting save volume queue zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner I0722 06:13:51.047563 1 reflector.go:219] Starting reflector *v1.PersistentVolume (15m0s) from sigs.k8s.io/sig-storage-lib-external-provisioner/v8/controller/controller.go:845 zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner I0722 06:13:51.047635 1 reflector.go:255] Listing and watching *v1.PersistentVolume from sigs.k8s.io/sig-storage-lib-external-provisioner/v8/controller/controller.go:845 zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner I0722 06:13:51.047653 1 reflector.go:219] Starting reflector *v1.StorageClass (15m0s) from sigs.k8s.io/sig-storage-lib-external-provisioner/v8/controller/controller.go:848 zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner I0722 06:13:51.047685 1 reflector.go:255] Listing and watching *v1.StorageClass from sigs.k8s.io/sig-storage-lib-external-provisioner/v8/controller/controller.go:848 zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner I0722 06:13:51.049130 1 clone_controller.go:66] Starting CloningProtection controller zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner I0722 06:13:51.050011 1 clone_controller.go:82] Started CloningProtection controller zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner I0722 06:13:51.150585 1 shared_informer.go:270] caches populated zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner I0722 06:13:51.152319 1 controller.go:860] Started provisioner controller org.democratic-csi.nfs_zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv_48ee7055-5864-4a38-bf69-c5a768a64f56! zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-snapshotter I0722 06:13:51.355810 1 leader_election.go:212] new leader detected, current leader: zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-snapshotter I0722 06:13:51.357287 1 leaderelection.go:258] successfully acquired lease democratic-csi/external-snapshotter-leader-org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-snapshotter I0722 06:13:51.358999 1 leader_election.go:205] became leader, starting zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-snapshotter I0722 06:13:51.360982 1 reflector.go:219] Starting reflector *v1.VolumeSnapshotClass (15m0s) from github.com/kubernetes-csi/external-snapshotter/client/v4/informers/externalversions/factory.go:117 zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-snapshotter I0722 06:13:51.361072 1 reflector.go:255] Listing and watching *v1.VolumeSnapshotClass from github.com/kubernetes-csi/external-snapshotter/client/v4/informers/externalversions/factory.go:117 zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-snapshotter I0722 06:13:51.361439 1 snapshot_controller_base.go:115] Starting CSI snapshotter zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-snapshotter I0722 06:13:51.362281 1 reflector.go:219] Starting reflector *v1.VolumeSnapshotContent (15m0s) from github.com/kubernetes-csi/external-snapshotter/client/v4/informers/externalversions/factory.go:117 zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-snapshotter I0722 06:13:51.362438 1 reflector.go:255] Listing and watching *v1.VolumeSnapshotContent from github.com/kubernetes-csi/external-snapshotter/client/v4/informers/externalversions/factory.go:117 zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-snapshotter W0722 06:13:51.377028 1 reflector.go:324] github.com/kubernetes-csi/external-snapshotter/client/v4/informers/externalversions/factory.go:117: failed to list *v1.VolumeSnapshotContent: the server could not find the requested resource (get volumesnapshotcontents.snapshot.storage.k8s.io) zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-snapshotter E0722 06:13:51.377356 1 reflector.go:138] github.com/kubernetes-csi/external-snapshotter/client/v4/informers/externalversions/factory.go:117: Failed to watch *v1.VolumeSnapshotContent: failed to list *v1.VolumeSnapshotContent: the server could not find the requested resource (get volumesnapshotcontents.snapshot.storage.k8s.io) zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-snapshotter W0722 06:13:51.377742 1 reflector.go:324] github.com/kubernetes-csi/external-snapshotter/client/v4/informers/externalversions/factory.go:117: failed to list *v1.VolumeSnapshotClass: the server could not find the requested resource (get volumesnapshotclasses.snapshot.storage.k8s.io) zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-snapshotter E0722 06:13:51.377822 1 reflector.go:138] github.com/kubernetes-csi/external-snapshotter/client/v4/informers/externalversions/factory.go:117: Failed to watch *v1.VolumeSnapshotClass: failed to list *v1.VolumeSnapshotClass: the server could not find the requested resource (get volumesnapshotclasses.snapshot.storage.k8s.io) zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-snapshotter I0722 06:13:51.391435 1 leaderelection.go:278] successfully renewed lease democratic-csi/external-snapshotter-leader-org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-resizer I0722 06:13:51.393066 1 leader_election.go:212] new leader detected, current leader: zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-resizer I0722 06:13:51.393157 1 leaderelection.go:258] successfully acquired lease democratic-csi/external-resizer-org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-resizer I0722 06:13:51.393999 1 leader_election.go:205] became leader, starting zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-resizer I0722 06:13:51.396953 1 reflector.go:219] Starting reflector *v1.PersistentVolume (10m0s) from k8s.io/client-go/informers/factory.go:134 zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-resizer I0722 06:13:51.397056 1 reflector.go:255] Listing and watching *v1.PersistentVolume from k8s.io/client-go/informers/factory.go:134 zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-resizer I0722 06:13:51.408742 1 controller.go:255] Starting external resizer org.democratic-csi.nfs zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-resizer I0722 06:13:51.419921 1 reflector.go:219] Starting reflector *v1.PersistentVolumeClaim (10m0s) from k8s.io/client-go/informers/factory.go:134 zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-resizer I0722 06:13:51.420044 1 reflector.go:255] Listing and watching *v1.PersistentVolumeClaim from k8s.io/client-go/informers/factory.go:134 zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-resizer I0722 06:13:51.431092 1 reflector.go:219] Starting reflector *v1.Pod (10m0s) from k8s.io/client-go/informers/factory.go:134 zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-resizer I0722 06:13:51.431184 1 reflector.go:255] Listing and watching *v1.Pod from k8s.io/client-go/informers/factory.go:134 zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-resizer I0722 06:13:51.431938 1 leaderelection.go:278] successfully renewed lease democratic-csi/external-resizer-org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-resizer I0722 06:13:51.509423 1 shared_informer.go:270] caches populated zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-resizer I0722 06:13:51.509552 1 controller.go:295] Started PVC processing "digi-data-usage-dashboard/sqlite-pvc" zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-resizer I0722 06:13:51.509596 1 controller.go:343] No need to resize PVC "digi-data-usage-dashboard/sqlite-pvc" zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-snapshotter I0722 06:13:52.520677 1 reflector.go:255] Listing and watching *v1.VolumeSnapshotClass from github.com/kubernetes-csi/external-snapshotter/client/v4/informers/externalversions/factory.go:117 zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-snapshotter W0722 06:13:52.525416 1 reflector.go:324] github.com/kubernetes-csi/external-snapshotter/client/v4/informers/externalversions/factory.go:117: failed to list *v1.VolumeSnapshotClass: the server could not find the requested resource (get volumesnapshotclasses.snapshot.storage.k8s.io) zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-snapshotter E0722 06:13:52.525476 1 reflector.go:138] github.com/kubernetes-csi/external-snapshotter/client/v4/informers/externalversions/factory.go:117: Failed to watch *v1.VolumeSnapshotClass: failed to list *v1.VolumeSnapshotClass: the server could not find the requested resource (get volumesnapshotclasses.snapshot.storage.k8s.io) zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-snapshotter I0722 06:13:52.528470 1 reflector.go:255] Listing and watching *v1.VolumeSnapshotContent from github.com/kubernetes-csi/external-snapshotter/client/v4/informers/externalversions/factory.go:117 zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-snapshotter W0722 06:13:52.531299 1 reflector.go:324] github.com/kubernetes-csi/external-snapshotter/client/v4/informers/externalversions/factory.go:117: failed to list *v1.VolumeSnapshotContent: the server could not find the requested resource (get volumesnapshotcontents.snapshot.storage.k8s.io) zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-snapshotter E0722 06:13:52.531439 1 reflector.go:138] github.com/kubernetes-csi/external-snapshotter/client/v4/informers/externalversions/factory.go:117: Failed to watch *v1.VolumeSnapshotContent: failed to list *v1.VolumeSnapshotContent: the server could not find the requested resource (get volumesnapshotcontents.snapshot.storage.k8s.io) zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-snapshotter I0722 06:13:54.237000 1 reflector.go:255] Listing and watching *v1.VolumeSnapshotContent from github.com/kubernetes-csi/external-snapshotter/client/v4/informers/externalversions/factory.go:117 zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-snapshotter W0722 06:13:54.241581 1 reflector.go:324] github.com/kubernetes-csi/external-snapshotter/client/v4/informers/externalversions/factory.go:117: failed to list *v1.VolumeSnapshotContent: the server could not find the requested resource (get volumesnapshotcontents.snapshot.storage.k8s.io) zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-snapshotter E0722 06:13:54.241738 1 reflector.go:138] github.com/kubernetes-csi/external-snapshotter/client/v4/informers/externalversions/factory.go:117: Failed to watch *v1.VolumeSnapshotContent: failed to list *v1.VolumeSnapshotContent: the server could not find the requested resource (get volumesnapshotcontents.snapshot.storage.k8s.io) zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-snapshotter I0722 06:13:55.225016 1 reflector.go:255] Listing and watching *v1.VolumeSnapshotClass from github.com/kubernetes-csi/external-snapshotter/client/v4/informers/externalversions/factory.go:117 zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-snapshotter W0722 06:13:55.229203 1 reflector.go:324] github.com/kubernetes-csi/external-snapshotter/client/v4/informers/externalversions/factory.go:117: failed to list *v1.VolumeSnapshotClass: the server could not find the requested resource (get volumesnapshotclasses.snapshot.storage.k8s.io) zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-snapshotter E0722 06:13:55.229257 1 reflector.go:138] github.com/kubernetes-csi/external-snapshotter/client/v4/informers/externalversions/factory.go:117: Failed to watch *v1.VolumeSnapshotClass: failed to list *v1.VolumeSnapshotClass: the server could not find the requested resource (get volumesnapshotclasses.snapshot.storage.k8s.io) zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner I0722 06:13:55.992720 1 leaderelection.go:278] successfully renewed lease democratic-csi/org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-resizer I0722 06:13:56.456272 1 leaderelection.go:278] successfully renewed lease democratic-csi/external-resizer-org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-snapshotter I0722 06:13:56.417611 1 leaderelection.go:278] successfully renewed lease democratic-csi/external-snapshotter-leader-org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-snapshotter I0722 06:13:57.943660 1 reflector.go:255] Listing and watching *v1.VolumeSnapshotContent from github.com/kubernetes-csi/external-snapshotter/client/v4/informers/externalversions/factory.go:117 zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-snapshotter W0722 06:13:57.950257 1 reflector.go:324] github.com/kubernetes-csi/external-snapshotter/client/v4/informers/externalversions/factory.go:117: failed to list *v1.VolumeSnapshotContent: the server could not find the requested resource (get volumesnapshotcontents.snapshot.storage.k8s.io) zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-snapshotter E0722 06:13:57.951527 1 reflector.go:138] github.com/kubernetes-csi/external-snapshotter/client/v4/informers/externalversions/factory.go:117: Failed to watch *v1.VolumeSnapshotContent: failed to list *v1.VolumeSnapshotContent: the server could not find the requested resource (get volumesnapshotcontents.snapshot.storage.k8s.io) zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-snapshotter I0722 06:13:58.740221 1 reflector.go:255] Listing and watching *v1.VolumeSnapshotClass from github.com/kubernetes-csi/external-snapshotter/client/v4/informers/externalversions/factory.go:117 zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-snapshotter W0722 06:13:58.747066 1 reflector.go:324] github.com/kubernetes-csi/external-snapshotter/client/v4/informers/externalversions/factory.go:117: failed to list *v1.VolumeSnapshotClass: the server could not find the requested resource (get volumesnapshotclasses.snapshot.storage.k8s.io) zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-snapshotter E0722 06:13:58.747172 1 reflector.go:138] github.com/kubernetes-csi/external-snapshotter/client/v4/informers/externalversions/factory.go:117: Failed to watch *v1.VolumeSnapshotClass: failed to list *v1.VolumeSnapshotClass: the server could not find the requested resource (get volumesnapshotclasses.snapshot.storage.k8s.io) zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner I0722 06:14:01.023170 1 leaderelection.go:278] successfully renewed lease democratic-csi/org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-resizer I0722 06:14:01.486603 1 leaderelection.go:278] successfully renewed lease democratic-csi/external-resizer-org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-snapshotter I0722 06:14:01.454141 1 leaderelection.go:278] successfully renewed lease democratic-csi/external-snapshotter-leader-org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner I0722 06:14:06.041887 1 leaderelection.go:278] successfully renewed lease democratic-csi/org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-snapshotter I0722 06:14:06.281765 1 reflector.go:255] Listing and watching *v1.VolumeSnapshotContent from github.com/kubernetes-csi/external-snapshotter/client/v4/informers/externalversions/factory.go:117 zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-snapshotter W0722 06:14:06.286265 1 reflector.go:324] github.com/kubernetes-csi/external-snapshotter/client/v4/informers/externalversions/factory.go:117: failed to list *v1.VolumeSnapshotContent: the server could not find the requested resource (get volumesnapshotcontents.snapshot.storage.k8s.io) zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-snapshotter E0722 06:14:06.286439 1 reflector.go:138] github.com/kubernetes-csi/external-snapshotter/client/v4/informers/externalversions/factory.go:117: Failed to watch *v1.VolumeSnapshotContent: failed to list *v1.VolumeSnapshotContent: the server could not find the requested resource (get volumesnapshotcontents.snapshot.storage.k8s.io) zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-snapshotter I0722 06:14:06.471655 1 leaderelection.go:278] successfully renewed lease democratic-csi/external-snapshotter-leader-org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-resizer I0722 06:14:06.508085 1 leaderelection.go:278] successfully renewed lease democratic-csi/external-resizer-org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-snapshotter I0722 06:14:08.445715 1 reflector.go:255] Listing and watching *v1.VolumeSnapshotClass from github.com/kubernetes-csi/external-snapshotter/client/v4/informers/externalversions/factory.go:117 zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-snapshotter W0722 06:14:08.471368 1 reflector.go:324] github.com/kubernetes-csi/external-snapshotter/client/v4/informers/externalversions/factory.go:117: failed to list *v1.VolumeSnapshotClass: the server could not find the requested resource (get volumesnapshotclasses.snapshot.storage.k8s.io) zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-snapshotter E0722 06:14:08.471509 1 reflector.go:138] github.com/kubernetes-csi/external-snapshotter/client/v4/informers/externalversions/factory.go:117: Failed to watch *v1.VolumeSnapshotClass: failed to list *v1.VolumeSnapshotClass: the server could not find the requested resource (get volumesnapshotclasses.snapshot.storage.k8s.io) zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner I0722 06:14:11.060841 1 leaderelection.go:278] successfully renewed lease democratic-csi/org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-resizer I0722 06:14:11.531004 1 leaderelection.go:278] successfully renewed lease democratic-csi/external-resizer-org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-snapshotter I0722 06:14:11.491622 1 leaderelection.go:278] successfully renewed lease democratic-csi/external-snapshotter-leader-org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner I0722 06:14:16.093669 1 leaderelection.go:278] successfully renewed lease democratic-csi/org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-snapshotter I0722 06:14:16.519740 1 leaderelection.go:278] successfully renewed lease democratic-csi/external-snapshotter-leader-org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-resizer I0722 06:14:16.554267 1 leaderelection.go:278] successfully renewed lease democratic-csi/external-resizer-org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner I0722 06:14:21.125713 1 leaderelection.go:278] successfully renewed lease democratic-csi/org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-resizer I0722 06:14:21.612644 1 leaderelection.go:278] successfully renewed lease democratic-csi/external-resizer-org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-snapshotter I0722 06:14:21.613620 1 leaderelection.go:278] successfully renewed lease democratic-csi/external-snapshotter-leader-org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv csi-driver {"host":"zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv","level":"info","message":"new request - driver: FreeNASSshDriver method: Probe call: {\"metadata\":{\"user-agent\":[\"grpc-node-js/1.8.13\"]},\"request\":{},\"cancelled\":false}","service":"democratic-csi","timestamp":"2023-07-22T06:14:22.777Z"} zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv csi-driver {"host":"zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv","level":"info","message":"new response - driver: FreeNASSshDriver method: Probe response: {\"ready\":{\"value\":true}}","service":"democratic-csi","timestamp":"2023-07-22T06:14:22.800Z"} zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-snapshotter I0722 06:14:24.014992 1 reflector.go:255] Listing and watching *v1.VolumeSnapshotClass from github.com/kubernetes-csi/external-snapshotter/client/v4/informers/externalversions/factory.go:117 zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-snapshotter W0722 06:14:24.018647 1 reflector.go:324] github.com/kubernetes-csi/external-snapshotter/client/v4/informers/externalversions/factory.go:117: failed to list *v1.VolumeSnapshotClass: the server could not find the requested resource (get volumesnapshotclasses.snapshot.storage.k8s.io) zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-snapshotter E0722 06:14:24.018753 1 reflector.go:138] github.com/kubernetes-csi/external-snapshotter/client/v4/informers/externalversions/factory.go:117: Failed to watch *v1.VolumeSnapshotClass: failed to list *v1.VolumeSnapshotClass: the server could not find the requested resource (get volumesnapshotclasses.snapshot.storage.k8s.io) zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-resizer I0722 06:14:24.619156 1 controller.go:295] Started PVC processing "democratic-csi/test-claim-nfs-pvc" zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-resizer I0722 06:14:24.619226 1 controller.go:318] PV bound to PVC "democratic-csi/test-claim-nfs-pvc" is not created yet zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner I0722 06:14:24.630225 1 controller.go:1337] provision "democratic-csi/test-claim-nfs-pvc" class "freenas-nfs-csi": started zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner W0722 06:14:24.630514 1 controller.go:579] "fstype" is deprecated and will be removed in a future release, please use "csi.storage.k8s.io/fstype" instead zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner I0722 06:14:24.630635 1 event.go:285] Event(v1.ObjectReference{Kind:"PersistentVolumeClaim", Namespace:"democratic-csi", Name:"test-claim-nfs-pvc", UID:"3fe6d842-c9d3-40f7-9729-264d85372302", APIVersion:"v1", ResourceVersion:"13604394", FieldPath:""}): type: 'Normal' reason: 'Provisioning' External provisioner is provisioning volume for claim "democratic-csi/test-claim-nfs-pvc" zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner I0722 06:14:24.643615 1 connection.go:183] GRPC call: /csi.v1.Controller/CreateVolume zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner I0722 06:14:24.643814 1 connection.go:184] GRPC request: {"capacity_range":{"required_bytes":1073741824},"name":"pvc-3fe6d842-c9d3-40f7-9729-264d85372302","parameters":{"csi.storage.k8s.io/pv/name":"pvc-3fe6d842-c9d3-40f7-9729-264d85372302","csi.storage.k8s.io/pvc/name":"test-claim-nfs-pvc","csi.storage.k8s.io/pvc/namespace":"democratic-csi","fsType":"nfs"},"volume_capabilities":[{"AccessType":{"Mount":{"fs_type":"nfs","mount_flags":["noatime","nfsvers=4"]}},"access_mode":{"mode":7}}]} zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv csi-proxy 2023/07/22 06:14:24 request (://localhost) POST /csi.v1.Controller/CreateVolume HTTP/2.0 zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv csi-proxy 2023/07/22 06:14:24 request headers map[Content-Type:[application/grpc] Grpc-Timeout:[89998268u] Te:[trailers] User-Agent:[grpc-go/1.40.0]] zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv csi-driver {"host":"zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv","level":"info","message":"new request - driver: FreeNASSshDriver method: CreateVolume call: {\"metadata\":{\"user-agent\":[\"grpc-go/1.40.0\"],\"x-forwarded-host\":[\"localhost\"]},\"request\":{\"volume_capabilities\":[{\"access_mode\":{\"mode\":\"SINGLE_NODE_MULTI_WRITER\"},\"mount\":{\"mount_flags\":[\"noatime\",\"nfsvers=4\"],\"fs_type\":\"nfs\",\"volume_mount_group\":\"\"},\"access_type\":\"mount\"}],\"parameters\":{\"fsType\":\"nfs\",\"csi.storage.k8s.io/pvc/name\":\"test-claim-nfs-pvc\",\"csi.storage.k8s.io/pvc/namespace\":\"democratic-csi\",\"csi.storage.k8s.io/pv/name\":\"pvc-3fe6d842-c9d3-40f7-9729-264d85372302\"},\"secrets\":\"redacted\",\"name\":\"pvc-3fe6d842-c9d3-40f7-9729-264d85372302\",\"capacity_range\":{\"required_bytes\":\"1073741824\",\"limit_bytes\":\"0\"},\"volume_content_source\":null,\"accessibility_requirements\":null},\"cancelled\":false}","service":"democratic-csi","timestamp":"2023-07-22T06:14:24.671Z"} zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner I0722 06:14:26.142236 1 leaderelection.go:278] successfully renewed lease democratic-csi/org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-snapshotter I0722 06:14:26.639651 1 leaderelection.go:278] successfully renewed lease democratic-csi/external-snapshotter-leader-org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-resizer I0722 06:14:26.643163 1 leaderelection.go:278] successfully renewed lease democratic-csi/external-resizer-org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv csi-driver {"host":"zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv","level":"error","message":"handler error - driver: FreeNASSshDriver method: CreateVolume error: {\"name\":\"GrpcError\",\"code\":9,\"message\":\"BREAKING CHANGE since v1.5.3! datasetPermissionsUser must be numeric: k8s-nfs is invalid\"}","service":"democratic-csi","timestamp":"2023-07-22T06:14:28.573Z"} zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner I0722 06:14:28.580851 1 connection.go:186] GRPC response: {} zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner I0722 06:14:28.581355 1 connection.go:187] GRPC error: rpc error: code = FailedPrecondition desc = BREAKING CHANGE since v1.5.3! datasetPermissionsUser must be numeric: k8s-nfs is invalid zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner I0722 06:14:28.581488 1 controller.go:764] CreateVolume failed, supports topology = false, node selected false => may reschedule = false => state = Finished: rpc error: code = FailedPrecondition desc = BREAKING CHANGE since v1.5.3! datasetPermissionsUser must be numeric: k8s-nfs is invalid zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner I0722 06:14:28.581793 1 controller.go:1075] Final error received, removing PVC 3fe6d842-c9d3-40f7-9729-264d85372302 from claims in progress zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner W0722 06:14:28.581910 1 controller.go:934] Retrying syncing claim "3fe6d842-c9d3-40f7-9729-264d85372302", failure 0 zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner E0722 06:14:28.582048 1 controller.go:957] error syncing claim "3fe6d842-c9d3-40f7-9729-264d85372302": failed to provision volume with StorageClass "freenas-nfs-csi": rpc error: code = FailedPrecondition desc = BREAKING CHANGE since v1.5.3! datasetPermissionsUser must be numeric: k8s-nfs is invalid zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner I0722 06:14:28.582015 1 event.go:285] Event(v1.ObjectReference{Kind:"PersistentVolumeClaim", Namespace:"democratic-csi", Name:"test-claim-nfs-pvc", UID:"3fe6d842-c9d3-40f7-9729-264d85372302", APIVersion:"v1", ResourceVersion:"13604394", FieldPath:""}): type: 'Warning' reason: 'ProvisioningFailed' failed to provision volume with StorageClass "freenas-nfs-csi": rpc error: code = FailedPrecondition desc = BREAKING CHANGE since v1.5.3! datasetPermissionsUser must be numeric: k8s-nfs is invalid zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-snapshotter I0722 06:14:29.502228 1 reflector.go:255] Listing and watching *v1.VolumeSnapshotContent from github.com/kubernetes-csi/external-snapshotter/client/v4/informers/externalversions/factory.go:117 zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv csi-proxy 2023/07/22 06:14:29 request (://localhost) POST /csi.v1.Controller/CreateVolume HTTP/2.0 zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner I0722 06:14:29.582971 1 controller.go:1337] provision "democratic-csi/test-claim-nfs-pvc" class "freenas-nfs-csi": started zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner W0722 06:14:29.583270 1 controller.go:579] "fstype" is deprecated and will be removed in a future release, please use "csi.storage.k8s.io/fstype" instead zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner I0722 06:14:29.583750 1 event.go:285] Event(v1.ObjectReference{Kind:"PersistentVolumeClaim", Namespace:"democratic-csi", Name:"test-claim-nfs-pvc", UID:"3fe6d842-c9d3-40f7-9729-264d85372302", APIVersion:"v1", ResourceVersion:"13604394", FieldPath:""}): type: 'Normal' reason: 'Provisioning' External provisioner is provisioning volume for claim "democratic-csi/test-claim-nfs-pvc" zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner I0722 06:14:29.590790 1 connection.go:183] GRPC call: /csi.v1.Controller/CreateVolume zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-snapshotter W0722 06:14:29.506994 1 reflector.go:324] github.com/kubernetes-csi/external-snapshotter/client/v4/informers/externalversions/factory.go:117: failed to list *v1.VolumeSnapshotContent: the server could not find the requested resource (get volumesnapshotcontents.snapshot.storage.k8s.io) zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner I0722 06:14:29.590855 1 connection.go:184] GRPC request: {"capacity_range":{"required_bytes":1073741824},"name":"pvc-3fe6d842-c9d3-40f7-9729-264d85372302","parameters":{"csi.storage.k8s.io/pv/name":"pvc-3fe6d842-c9d3-40f7-9729-264d85372302","csi.storage.k8s.io/pvc/name":"test-claim-nfs-pvc","csi.storage.k8s.io/pvc/namespace":"democratic-csi","fsType":"nfs"},"volume_capabilities":[{"AccessType":{"Mount":{"fs_type":"nfs","mount_flags":["noatime","nfsvers=4"]}},"access_mode":{"mode":7}}]} zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-snapshotter E0722 06:14:29.507155 1 reflector.go:138] github.com/kubernetes-csi/external-snapshotter/client/v4/informers/externalversions/factory.go:117: Failed to watch *v1.VolumeSnapshotContent: failed to list *v1.VolumeSnapshotContent: the server could not find the requested resource (get volumesnapshotcontents.snapshot.storage.k8s.io) zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv csi-proxy 2023/07/22 06:14:29 request headers map[Content-Type:[application/grpc] Grpc-Timeout:[89999368u] Te:[trailers] User-Agent:[grpc-go/1.40.0]] zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv csi-driver {"host":"zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv","level":"info","message":"new request - driver: FreeNASSshDriver method: CreateVolume call: {\"metadata\":{\"user-agent\":[\"grpc-go/1.40.0\"],\"x-forwarded-host\":[\"localhost\"]},\"request\":{\"volume_capabilities\":[{\"access_mode\":{\"mode\":\"SINGLE_NODE_MULTI_WRITER\"},\"mount\":{\"mount_flags\":[\"noatime\",\"nfsvers=4\"],\"fs_type\":\"nfs\",\"volume_mount_group\":\"\"},\"access_type\":\"mount\"}],\"parameters\":{\"csi.storage.k8s.io/pvc/name\":\"test-claim-nfs-pvc\",\"csi.storage.k8s.io/pvc/namespace\":\"democratic-csi\",\"csi.storage.k8s.io/pv/name\":\"pvc-3fe6d842-c9d3-40f7-9729-264d85372302\",\"fsType\":\"nfs\"},\"secrets\":\"redacted\",\"name\":\"pvc-3fe6d842-c9d3-40f7-9729-264d85372302\",\"capacity_range\":{\"required_bytes\":\"1073741824\",\"limit_bytes\":\"0\"},\"volume_content_source\":null,\"accessibility_requirements\":null},\"cancelled\":false}","service":"democratic-csi","timestamp":"2023-07-22T06:14:29.604Z"} zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner I0722 06:14:31.160005 1 leaderelection.go:278] successfully renewed lease democratic-csi/org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-resizer I0722 06:14:31.665761 1 leaderelection.go:278] successfully renewed lease democratic-csi/external-resizer-org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-snapshotter I0722 06:14:31.657485 1 leaderelection.go:278] successfully renewed lease democratic-csi/external-snapshotter-leader-org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv csi-driver {"host":"zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv","level":"error","message":"handler error - driver: FreeNASSshDriver method: CreateVolume error: {\"name\":\"GrpcError\",\"code\":9,\"message\":\"BREAKING CHANGE since v1.5.3! datasetPermissionsUser must be numeric: k8s-nfs is invalid\"}","service":"democratic-csi","timestamp":"2023-07-22T06:14:33.005Z"} zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner I0722 06:14:33.007769 1 connection.go:186] GRPC response: {} zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner I0722 06:14:33.007923 1 connection.go:187] GRPC error: rpc error: code = FailedPrecondition desc = BREAKING CHANGE since v1.5.3! datasetPermissionsUser must be numeric: k8s-nfs is invalid zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner I0722 06:14:33.007989 1 controller.go:764] CreateVolume failed, supports topology = false, node selected false => may reschedule = false => state = Finished: rpc error: code = FailedPrecondition desc = BREAKING CHANGE since v1.5.3! datasetPermissionsUser must be numeric: k8s-nfs is invalid zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner I0722 06:14:33.008084 1 controller.go:1075] Final error received, removing PVC 3fe6d842-c9d3-40f7-9729-264d85372302 from claims in progress zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner W0722 06:14:33.008115 1 controller.go:934] Retrying syncing claim "3fe6d842-c9d3-40f7-9729-264d85372302", failure 1 zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner E0722 06:14:33.008169 1 controller.go:957] error syncing claim "3fe6d842-c9d3-40f7-9729-264d85372302": failed to provision volume with StorageClass "freenas-nfs-csi": rpc error: code = FailedPrecondition desc = BREAKING CHANGE since v1.5.3! datasetPermissionsUser must be numeric: k8s-nfs is invalid zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner I0722 06:14:33.008257 1 event.go:285] Event(v1.ObjectReference{Kind:"PersistentVolumeClaim", Namespace:"democratic-csi", Name:"test-claim-nfs-pvc", UID:"3fe6d842-c9d3-40f7-9729-264d85372302", APIVersion:"v1", ResourceVersion:"13604394", FieldPath:""}): type: 'Warning' reason: 'ProvisioningFailed' failed to provision volume with StorageClass "freenas-nfs-csi": rpc error: code = FailedPrecondition desc = BREAKING CHANGE since v1.5.3! datasetPermissionsUser must be numeric: k8s-nfs is invalid zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner I0722 06:14:35.009326 1 controller.go:1337] provision "democratic-csi/test-claim-nfs-pvc" class "freenas-nfs-csi": started zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner W0722 06:14:35.009531 1 controller.go:579] "fstype" is deprecated and will be removed in a future release, please use "csi.storage.k8s.io/fstype" instead zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner I0722 06:14:35.009603 1 event.go:285] Event(v1.ObjectReference{Kind:"PersistentVolumeClaim", Namespace:"democratic-csi", Name:"test-claim-nfs-pvc", UID:"3fe6d842-c9d3-40f7-9729-264d85372302", APIVersion:"v1", ResourceVersion:"13604394", FieldPath:""}): type: 'Normal' reason: 'Provisioning' External provisioner is provisioning volume for claim "democratic-csi/test-claim-nfs-pvc" zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv csi-proxy 2023/07/22 06:14:35 request (://localhost) POST /csi.v1.Controller/CreateVolume HTTP/2.0 zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv csi-proxy 2023/07/22 06:14:35 request headers map[Content-Type:[application/grpc] Grpc-Timeout:[89999687u] Te:[trailers] User-Agent:[grpc-go/1.40.0]] zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner I0722 06:14:35.024425 1 connection.go:183] GRPC call: /csi.v1.Controller/CreateVolume zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner I0722 06:14:35.024474 1 connection.go:184] GRPC request: {"capacity_range":{"required_bytes":1073741824},"name":"pvc-3fe6d842-c9d3-40f7-9729-264d85372302","parameters":{"csi.storage.k8s.io/pv/name":"pvc-3fe6d842-c9d3-40f7-9729-264d85372302","csi.storage.k8s.io/pvc/name":"test-claim-nfs-pvc","csi.storage.k8s.io/pvc/namespace":"democratic-csi","fsType":"nfs"},"volume_capabilities":[{"AccessType":{"Mount":{"fs_type":"nfs","mount_flags":["noatime","nfsvers=4"]}},"access_mode":{"mode":7}}]} zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv csi-driver {"host":"zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv","level":"info","message":"new request - driver: FreeNASSshDriver method: CreateVolume call: {\"metadata\":{\"x-forwarded-host\":[\"localhost\"],\"user-agent\":[\"grpc-go/1.40.0\"]},\"request\":{\"volume_capabilities\":[{\"access_mode\":{\"mode\":\"SINGLE_NODE_MULTI_WRITER\"},\"mount\":{\"mount_flags\":[\"noatime\",\"nfsvers=4\"],\"fs_type\":\"nfs\",\"volume_mount_group\":\"\"},\"access_type\":\"mount\"}],\"parameters\":{\"fsType\":\"nfs\",\"csi.storage.k8s.io/pvc/name\":\"test-claim-nfs-pvc\",\"csi.storage.k8s.io/pvc/namespace\":\"democratic-csi\",\"csi.storage.k8s.io/pv/name\":\"pvc-3fe6d842-c9d3-40f7-9729-264d85372302\"},\"secrets\":\"redacted\",\"name\":\"pvc-3fe6d842-c9d3-40f7-9729-264d85372302\",\"capacity_range\":{\"required_bytes\":\"1073741824\",\"limit_bytes\":\"0\"},\"volume_content_source\":null,\"accessibility_requirements\":null},\"cancelled\":false}","service":"democratic-csi","timestamp":"2023-07-22T06:14:35.029Z"} zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner I0722 06:14:36.191790 1 leaderelection.go:278] successfully renewed lease democratic-csi/org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-snapshotter I0722 06:14:36.685157 1 leaderelection.go:278] successfully renewed lease democratic-csi/external-snapshotter-leader-org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-resizer I0722 06:14:36.695704 1 leaderelection.go:278] successfully renewed lease democratic-csi/external-resizer-org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner I0722 06:14:38.408609 1 connection.go:186] GRPC response: {} zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner I0722 06:14:38.408787 1 connection.go:187] GRPC error: rpc error: code = FailedPrecondition desc = BREAKING CHANGE since v1.5.3! datasetPermissionsUser must be numeric: k8s-nfs is invalid zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner I0722 06:14:38.408854 1 controller.go:764] CreateVolume failed, supports topology = false, node selected false => may reschedule = false => state = Finished: rpc error: code = FailedPrecondition desc = BREAKING CHANGE since v1.5.3! datasetPermissionsUser must be numeric: k8s-nfs is invalid zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner I0722 06:14:38.409004 1 controller.go:1075] Final error received, removing PVC 3fe6d842-c9d3-40f7-9729-264d85372302 from claims in progress zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner W0722 06:14:38.409058 1 controller.go:934] Retrying syncing claim "3fe6d842-c9d3-40f7-9729-264d85372302", failure 2 zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv csi-driver {"host":"zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv","level":"error","message":"handler error - driver: FreeNASSshDriver method: CreateVolume error: {\"name\":\"GrpcError\",\"code\":9,\"message\":\"BREAKING CHANGE since v1.5.3! datasetPermissionsUser must be numeric: k8s-nfs is invalid\"}","service":"democratic-csi","timestamp":"2023-07-22T06:14:38.403Z"} zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner E0722 06:14:38.409152 1 controller.go:957] error syncing claim "3fe6d842-c9d3-40f7-9729-264d85372302": failed to provision volume with StorageClass "freenas-nfs-csi": rpc error: code = FailedPrecondition desc = BREAKING CHANGE since v1.5.3! datasetPermissionsUser must be numeric: k8s-nfs is invalid zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner I0722 06:14:38.409410 1 event.go:285] Event(v1.ObjectReference{Kind:"PersistentVolumeClaim", Namespace:"democratic-csi", Name:"test-claim-nfs-pvc", UID:"3fe6d842-c9d3-40f7-9729-264d85372302", APIVersion:"v1", ResourceVersion:"13604394", FieldPath:""}): type: 'Warning' reason: 'ProvisioningFailed' failed to provision volume with StorageClass "freenas-nfs-csi": rpc error: code = FailedPrecondition desc = BREAKING CHANGE since v1.5.3! datasetPermissionsUser must be numeric: k8s-nfs is invalid zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner I0722 06:14:41.208318 1 leaderelection.go:278] successfully renewed lease democratic-csi/org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-snapshotter I0722 06:14:41.708100 1 leaderelection.go:278] successfully renewed lease democratic-csi/external-snapshotter-leader-org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-resizer I0722 06:14:41.719533 1 leaderelection.go:278] successfully renewed lease democratic-csi/external-resizer-org-democratic-csi-nfs zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner I0722 06:14:42.409404 1 controller.go:1337] provision "democratic-csi/test-claim-nfs-pvc" class "freenas-nfs-csi": started zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner W0722 06:14:42.409552 1 controller.go:579] "fstype" is deprecated and will be removed in a future release, please use "csi.storage.k8s.io/fstype" instead zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner I0722 06:14:42.409916 1 event.go:285] Event(v1.ObjectReference{Kind:"PersistentVolumeClaim", Namespace:"democratic-csi", Name:"test-claim-nfs-pvc", UID:"3fe6d842-c9d3-40f7-9729-264d85372302", APIVersion:"v1", ResourceVersion:"13604394", FieldPath:""}): type: 'Normal' reason: 'Provisioning' External provisioner is provisioning volume for claim "democratic-csi/test-claim-nfs-pvc" zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv csi-proxy 2023/07/22 06:14:42 request (://localhost) POST /csi.v1.Controller/CreateVolume HTTP/2.0 zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner I0722 06:14:42.419102 1 connection.go:183] GRPC call: /csi.v1.Controller/CreateVolume zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner I0722 06:14:42.419155 1 connection.go:184] GRPC request: {"capacity_range":{"required_bytes":1073741824},"name":"pvc-3fe6d842-c9d3-40f7-9729-264d85372302","parameters":{"csi.storage.k8s.io/pv/name":"pvc-3fe6d842-c9d3-40f7-9729-264d85372302","csi.storage.k8s.io/pvc/name":"test-claim-nfs-pvc","csi.storage.k8s.io/pvc/namespace":"democratic-csi","fsType":"nfs"},"volume_capabilities":[{"AccessType":{"Mount":{"fs_type":"nfs","mount_flags":["noatime","nfsvers=4"]}},"access_mode":{"mode":7}}]} zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv csi-proxy 2023/07/22 06:14:42 request headers map[Content-Type:[application/grpc] Grpc-Timeout:[89999533u] Te:[trailers] User-Agent:[grpc-go/1.40.0]] zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv csi-driver {"host":"zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv","level":"info","message":"new request - driver: FreeNASSshDriver method: CreateVolume call: {\"metadata\":{\"user-agent\":[\"grpc-go/1.40.0\"],\"x-forwarded-host\":[\"localhost\"]},\"request\":{\"volume_capabilities\":[{\"access_mode\":{\"mode\":\"SINGLE_NODE_MULTI_WRITER\"},\"mount\":{\"mount_flags\":[\"noatime\",\"nfsvers=4\"],\"fs_type\":\"nfs\",\"volume_mount_group\":\"\"},\"access_type\":\"mount\"}],\"parameters\":{\"csi.storage.k8s.io/pvc/name\":\"test-claim-nfs-pvc\",\"csi.storage.k8s.io/pvc/namespace\":\"democratic-csi\",\"csi.storage.k8s.io/pv/name\":\"pvc-3fe6d842-c9d3-40f7-9729-264d85372302\",\"fsType\":\"nfs\"},\"secrets\":\"redacted\",\"name\":\"pvc-3fe6d842-c9d3-40f7-9729-264d85372302\",\"capacity_range\":{\"required_bytes\":\"1073741824\",\"limit_bytes\":\"0\"},\"volume_content_source\":null,\"accessibility_requirements\":null},\"cancelled\":false}","service":"democratic-csi","timestamp":"2023-07-22T06:14:42.423Z"} zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv csi-driver {"host":"zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv","level":"error","message":"handler error - driver: FreeNASSshDriver method: CreateVolume error: {\"name\":\"GrpcError\",\"code\":9,\"message\":\"BREAKING CHANGE since v1.5.3! datasetPermissionsUser must be numeric: k8s-nfs is invalid\"}","service":"democratic-csi","timestamp":"2023-07-22T06:14:45.793Z"} zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner I0722 06:14:45.796013 1 connection.go:186] GRPC response: {} zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner I0722 06:14:45.796119 1 connection.go:187] GRPC error: rpc error: code = FailedPrecondition desc = BREAKING CHANGE since v1.5.3! datasetPermissionsUser must be numeric: k8s-nfs is invalid zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner I0722 06:14:45.796154 1 controller.go:764] CreateVolume failed, supports topology = false, node selected false => may reschedule = false => state = Finished: rpc error: code = FailedPrecondition desc = BREAKING CHANGE since v1.5.3! datasetPermissionsUser must be numeric: k8s-nfs is invalid zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner I0722 06:14:45.796270 1 controller.go:1075] Final error received, removing PVC 3fe6d842-c9d3-40f7-9729-264d85372302 from claims in progress zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner I0722 06:14:45.796344 1 event.go:285] Event(v1.ObjectReference{Kind:"PersistentVolumeClaim", Namespace:"democratic-csi", Name:"test-claim-nfs-pvc", UID:"3fe6d842-c9d3-40f7-9729-264d85372302", APIVersion:"v1", ResourceVersion:"13604394", FieldPath:""}): type: 'Warning' reason: 'ProvisioningFailed' failed to provision volume with StorageClass "freenas-nfs-csi": rpc error: code = FailedPrecondition desc = BREAKING CHANGE since v1.5.3! datasetPermissionsUser must be numeric: k8s-nfs is invalid zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner W0722 06:14:45.796876 1 controller.go:934] Retrying syncing claim "3fe6d842-c9d3-40f7-9729-264d85372302", failure 3 zfs-nfs-democratic-csi-controller-578fc6f4bd-bg9cv external-provisioner E0722 06:14:45.796970 1 controller.go:957] error syncing claim "3fe6d842-c9d3-40f7-9729-264d85372302": failed to provision volume with StorageClass "freenas-nfs-csi": rpc error: code = FailedPrecondition desc = BREAKING CHANGE since v1.5.3! datasetPermissionsUser must be numeric: k8s-nfs is invalid
travisghansen commented 1 year ago

It's a bit confusing, the dataset/fs permissions need to be id, the share need to be name: https://github.com/democratic-csi/democratic-csi/blob/master/src/driver/freenas/ssh.js#L1908-L1927

It's just driven by the TrueNAS API requirements currently. I probably could lookup user based on ID or whatever but currently I just pass the values through to the API.

zulhfreelancer commented 1 year ago

That's fixed it, thank you. For reference, this is the working Helm chart values:

csiDriver:
  name: "org.democratic-csi.nfs"

storageClasses:
- name: freenas-nfs-csi
  defaultClass: false
  reclaimPolicy: Delete
  volumeBindingMode: Immediate
  allowVolumeExpansion: true
  parameters:
    fsType: nfs

  mountOptions:
  - noatime
  - nfsvers=4
  secrets:
    provisioner-secret:
    controller-publish-secret:
    node-stage-secret:
    node-publish-secret:
    controller-expand-secret:

driver:
  config:
    driver: freenas-nfs
    instance_id:
    httpConnection:
      protocol: http
      host: <my-truenas-core-ip>
      port: 80
      apiVersion: 2
      apiKey: redacted
      allowInsecure: true
    sshConnection:
      host: <my-truenas-core-ip>
      port: 22
      username: k8s-nfs
      privateKey: |
        -----BEGIN OPENSSH PRIVATE KEY-----
        redacted
        -----END OPENSSH PRIVATE KEY-----
    zfs:
      cli:
        sudoEnabled: true
      datasetParentName: foo/k8s/nfs/vols
      detachedSnapshotsDatasetParentName: foo/k8s/nfs/snaps
      datasetEnableQuotas: true
      datasetEnableReservation: false
      datasetPermissionsMode: "0777"
      datasetPermissionsUser: 1007 
      datasetPermissionsGroup: 1001 
    nfs:
      shareHost: <my-truenas-core-ip>
      shareAlldirs: false
      shareAllowedHosts: []
      shareAllowedNetworks: []
      shareMaprootUser: k8s-nfs
      shareMaprootGroup: k8s-nfs
      shareMapallUser: ""
      shareMapallGroup: ""
zulhfreelancer commented 1 year ago

Going to close this issue and re-open if needed