Mount failure due to iscsiadmin discover error

[gosuri]

Version

v1.15.4-k3s.1

Images

• quay.io/k8scsi/csi-node-driver-registrar:v1.2.0
• docker.io/packethost/csi-packet:1c039e3
• quay.io/k8scsi/csi-provisioner:v1.4.0
• quay.io/k8scsi/csi-attacher:v2.0.0

Snapshot

kubectl get nodes -o json | jq '.items[] | .status.images[]'

{
  "names": [
    "docker.io/packethost/csi-packet@sha256:3a8c01a297f503bf313641ef282e2713523a8bdac4184117cd47ac81fc0bcb63",
    "docker.io/packethost/csi-packet:1c039e3"
  ],
  "sizeBytes": 76884203
}
{
  "names": [
    "gcr.io/kubernetes-helm/tiller@sha256:be79aff05025bd736f027eaf4a1b2716ac1e09b88e0e9493c962642519f19d9c",
    "gcr.io/kubernetes-helm/tiller:v2.14.2"
  ],
  "sizeBytes": 30875059
}
{
  "names": [
    "docker.io/rancher/klipper-helm@sha256:72690de1ae2259a41075e87ff453936a74e0f2dbf2ad1dd96a4f72136a48038d",
    "docker.io/rancher/klipper-helm:v0.1.5"
  ],
  "sizeBytes": 27089525
}
{
  "names": [
    "docker.io/library/traefik@sha256:e1e1b1dadfaab6d64f420f4352356e98e289fc7c8bf9f47387866f221c60e4e6",
    "docker.io/library/traefik:1.7.14"
  ],
  "sizeBytes": 23626773
}
{
  "names": [
    "quay.io/k8scsi/csi-provisioner:v1.4.0"
  ],
  "sizeBytes": 20068761
}
{
  "names": [
    "quay.io/k8scsi/csi-attacher:v2.0.0"
  ],
  "sizeBytes": 17305293
}
{
  "names": [
    "docker.io/coredns/coredns@sha256:cfa7236dab4e3860881fdf755880ff8361e42f6cba2e3775ae48e2d46d22f7ba",
    "docker.io/coredns/coredns:1.6.3"
  ],
  "sizeBytes": 14191001
}
{
  "names": [
    "quay.io/k8scsi/csi-node-driver-registrar:v1.2.0"
  ],
  "sizeBytes": 7676183
}
{
  "names": [
    "docker.io/rancher/klipper-lb@sha256:2cff68f14dd050a5ab16b59a55d5ba34d6edc3f6edfc1ec5bd4e437d4ba47290",
    "docker.io/rancher/klipper-lb:v0.1.1"
  ],
  "sizeBytes": 2708144
}
{
  "names": [
    "k8s.gcr.io/pause@sha256:f78411e19d84a252e53bff71a4407a5686c46983a2c2eeed83929b888179acea",
    "k8s.gcr.io/pause:3.1"
  ],
  "sizeBytes": 317164
}

DaemonSet

apiVersion: extensions/v1beta1
kind: DaemonSet
metadata:
  annotations:
    kubectl.kubernetes.io/last-applied-configuration: |
      {"apiVersion":"apps/v1","kind":"DaemonSet","metadata":{"annotations":{},"name":"csi-node","namespace":"kube-system"},"spec":{"selector":{"matchLabels":{"app":"csi-packet-driver"}},"template":{"metadata":{"labels":{"app":"csi-packet-driver"}},"spec":{"containers":[{"args":["--v=5","--csi-address=$(ADDRESS)","--kubelet-registration-path=/var/lib/rancher/k3s/agent/kubelet/plugins/net.packet.csi/csi.sock"],"env":[{"name":"ADDRESS","value":"/csi/csi.sock"},{"name":"KUBE_NODE_NAME","valueFrom":{"fieldRef":{"fieldPath":"spec.nodeName"}}}],"image":"quay.io/k8scsi/csi-node-driver-registrar:v1.2.0","imagePullPolicy":"IfNotPresent","name":"csi-driver-registrar","volumeMounts":[{"mountPath":"/csi","name":"plugin-dir"},{"mountPath":"/registration","name":"registration-dir"}]},{"args":["--endpoint=$(CSI_ENDPOINT)","--nodeid=$(KUBE_NODE_NAME)"],"env":[{"name":"CSI_ENDPOINT","value":"unix:///csi/csi.sock"},{"name":"KUBE_NODE_NAME","valueFrom":{"fieldRef":{"fieldPath":"spec.nodeName"}}}],"image":"docker.io/packethost/csi-packet:1c039e3","imagePullPolicy":"Always","name":"packet-driver","securityContext":{"privileged":true},"volumeMounts":[{"mountPath":"/var/lib/rancher/k3s/agent/kubelet/pods","mountPropagation":"Bidirectional","name":"kubelet-dir"},{"mountPath":"/sbin/iscsiadm","name":"iscsiadm"},{"mountPath":"/csi","name":"plugin-dir"},{"mountPath":"/sys/devices","name":"sys-devices"},{"mountPath":"/dev","name":"dev"},{"mountPath":"/etc","name":"etc"},{"mountPath":"/run/udev","name":"run-udev"},{"mountPath":"/var/lib/iscsi","name":"var-lib-iscsi"},{"mountPath":"/lib/modules","name":"lib-modules"},{"mountPath":"/usr/share/ca-certificates/","name":"ca-certs-alternative","readOnly":true}]}],"hostNetwork":true,"serviceAccount":"csi-node-sa","volumes":[{"hostPath":{"path":"/var/lib/rancher/k3s/agent/kubelet/plugins_registry","type":"Directory"},"name":"registration-dir"},{"hostPath":{"path":"/var/lib/rancher/k3s/agent/kubelet/pods","type":"Directory"},"name":"kubelet-dir"},{"hostPath":{"path":"/var/lib/rancher/k3s/agent/kubelet/plugins/net.packet.csi/","type":"DirectoryOrCreate"},"name":"plugin-dir"},{"hostPath":{"path":"/sbin/iscsiadm","type":"File"},"name":"iscsiadm"},{"hostPath":{"path":"/dev","type":"Directory"},"name":"dev"},{"hostPath":{"path":"/etc/"},"name":"etc"},{"hostPath":{"path":"/var/lib/iscsi/","type":"DirectoryOrCreate"},"name":"var-lib-iscsi"},{"hostPath":{"path":"/sys/devices","type":"Directory"},"name":"sys-devices"},{"hostPath":{"path":"/run/udev/","type":"Directory"},"name":"run-udev"},{"hostPath":{"path":"/lib/modules","type":"Directory"},"name":"lib-modules"},{"hostPath":{"path":"/usr/share/ca-certificates/","type":"DirectoryOrCreate"},"name":"ca-certs-alternative"}]}}}}
  creationTimestamp: "2019-10-08T09:38:30Z"
  generation: 1
  name: csi-node
  namespace: kube-system
  resourceVersion: "423"
  selfLink: /apis/extensions/v1beta1/namespaces/kube-system/daemonsets/csi-node
  uid: d2c80c36-4369-4861-8f9c-aa9e4481b87d
spec:
  revisionHistoryLimit: 10
  selector:
    matchLabels:
      app: csi-packet-driver
  template:
    metadata:
      creationTimestamp: null
      labels:
        app: csi-packet-driver
    spec:
      containers:
      - args:
        - --v=5
        - --csi-address=$(ADDRESS)
        - --kubelet-registration-path=/var/lib/rancher/k3s/agent/kubelet/plugins/net.packet.csi/csi.sock
        env:
        - name: ADDRESS
          value: /csi/csi.sock
        - name: KUBE_NODE_NAME
          valueFrom:
            fieldRef:
              apiVersion: v1
              fieldPath: spec.nodeName
        image: quay.io/k8scsi/csi-node-driver-registrar:v1.2.0
        imagePullPolicy: IfNotPresent
        name: csi-driver-registrar
        resources: {}
        terminationMessagePath: /dev/termination-log
        terminationMessagePolicy: File
        volumeMounts:
        - mountPath: /csi
          name: plugin-dir
        - mountPath: /registration
          name: registration-dir
      - args:
        - --endpoint=$(CSI_ENDPOINT)
        - --nodeid=$(KUBE_NODE_NAME)
        env:
        - name: CSI_ENDPOINT
          value: unix:///csi/csi.sock
        - name: KUBE_NODE_NAME
          valueFrom:
            fieldRef:
              apiVersion: v1
              fieldPath: spec.nodeName
        image: docker.io/packethost/csi-packet:1c039e3
        imagePullPolicy: Always
        name: packet-driver
        resources: {}
        securityContext:
          privileged: true
        terminationMessagePath: /dev/termination-log
        terminationMessagePolicy: File
        volumeMounts:
        - mountPath: /var/lib/rancher/k3s/agent/kubelet/pods
          mountPropagation: Bidirectional
          name: kubelet-dir
        - mountPath: /sbin/iscsiadm
          name: iscsiadm
        - mountPath: /csi
          name: plugin-dir
        - mountPath: /sys/devices
          name: sys-devices
        - mountPath: /dev
          name: dev
        - mountPath: /etc
          name: etc
        - mountPath: /run/udev
          name: run-udev
        - mountPath: /var/lib/iscsi
          name: var-lib-iscsi
        - mountPath: /lib/modules
          name: lib-modules
        - mountPath: /usr/share/ca-certificates/
          name: ca-certs-alternative
          readOnly: true
      dnsPolicy: ClusterFirst
      hostNetwork: true
      restartPolicy: Always
      schedulerName: default-scheduler
      securityContext: {}
      serviceAccount: csi-node-sa
      serviceAccountName: csi-node-sa
      terminationGracePeriodSeconds: 30
      volumes:
      - hostPath:
          path: /var/lib/rancher/k3s/agent/kubelet/plugins_registry
          type: Directory
        name: registration-dir
      - hostPath:
          path: /var/lib/rancher/k3s/agent/kubelet/pods
          type: Directory
        name: kubelet-dir
      - hostPath:
          path: /var/lib/rancher/k3s/agent/kubelet/plugins/net.packet.csi/
          type: DirectoryOrCreate
        name: plugin-dir
      - hostPath:
          path: /sbin/iscsiadm
          type: File
        name: iscsiadm
      - hostPath:
          path: /dev
          type: Directory
        name: dev
      - hostPath:
          path: /etc/
          type: ""
        name: etc
      - hostPath:
          path: /var/lib/iscsi/
          type: DirectoryOrCreate
        name: var-lib-iscsi
      - hostPath:
          path: /sys/devices
          type: Directory
        name: sys-devices
      - hostPath:
          path: /run/udev/
          type: Directory
        name: run-udev
      - hostPath:
          path: /lib/modules
          type: Directory
        name: lib-modules
      - hostPath:
          path: /usr/share/ca-certificates/
          type: DirectoryOrCreate
        name: ca-certs-alternative
  templateGeneration: 1
  updateStrategy:
    rollingUpdate:
      maxUnavailable: 1
    type: RollingUpdate
status:
  currentNumberScheduled: 1
  desiredNumberScheduled: 1
  numberAvailable: 1
  numberMisscheduled: 0
  numberReady: 1
  observedGeneration: 1
  updatedNumberScheduled: 1

Logs (Pre Provision)

kubelet

Oct 08 09:41:16 k1.ovrclk.net k3s[11703]: E1008 09:41:16.069020   11703 goroutinemap.go:150] Operation for "/var/lib/rancher/k3s/agent/kubelet/plugins/net.packet.csi/csi.sock" failed. No retries permitted until 2019-10-08 09:43:18.068964228 +0000 UTC m=+294.756846874 (durationBeforeRetry 2m2s). Error: "RegisterPlugin error -- failed to get plugin info using RPC GetInfo at socket /var/lib/rancher/k3s/agent/kubelet/plugins/net.packet.csi/csi.sock, err: rpc error: code = Unimplemented desc = unknown service pluginregistration.Registration"

packet-driver

{"level":"info","msg":"started","time":"2019-10-08T09:39:05Z","version":"1c039e3"}
{"endpoint":"unix:///csi/csi.sock","level":"info","msg":"Starting server","node":"k1.ovrclk.net","time":"2019-10-08T09:39:05Z"}
{"address":"//csi/csi.sock","level":"info","msg":"Listening for connections","proto":"unix","time":"2019-10-08T09:39:05Z"}
{"level":"info","msg":"PacketIdentityServer.GetPluginInfo called","time":"2019-10-08T09:39:06Z"}
{"GRPC.call":"/csi.v1.Identity/GetPluginInfo","GRPC.request":"","level":"info","msg":"GRPC response: name:\"net.packet.csi\" vendor_version:\"1c039e3\" ","time":"2019-10-08T09:39:06Z"}
{"endpoint":"unix:///csi/csi.sock","level":"info","msg":"NodeGetInfo called","node":"k1.ovrclk.net","time":"2019-10-08T09:39:07Z"}
{"GRPC.call":"/csi.v1.Node/NodeGetInfo","GRPC.request":"","level":"info","msg":"GRPC response: node_id:\"k1.ovrclk.net\" ","time":"2019-10-08T09:39:07Z"}

csi-driver-registrar

I1008 09:39:00.396246       1 main.go:110] Version: v1.2.0-0-g6ef000ae
I1008 09:39:00.396272       1 main.go:120] Attempting to open a gRPC connection with: "/csi/csi.sock"
I1008 09:39:00.396279       1 connection.go:151] Connecting to unix:///csi/csi.sock
I1008 09:39:06.626105       1 main.go:127] Calling CSI driver to discover driver name
I1008 09:39:06.626127       1 connection.go:180] GRPC call: /csi.v1.Identity/GetPluginInfo
I1008 09:39:06.626134       1 connection.go:181] GRPC request: {}
I1008 09:39:06.627616       1 connection.go:183] GRPC response: {"name":"net.packet.csi","vendor_version":"1c039e3"}
I1008 09:39:06.628109       1 connection.go:184] GRPC error: <nil>
I1008 09:39:06.628117       1 main.go:137] CSI driver name: "net.packet.csi"
I1008 09:39:06.628135       1 node_register.go:58] Starting Registration Server at: /registration/net.packet.csi-reg.sock
I1008 09:39:06.628229       1 node_register.go:67] Registration Server started at: /registration/net.packet.csi-reg.sock
I1008 09:39:07.025889       1 main.go:77] Received GetInfo call: &InfoRequest{}
I1008 09:39:07.034070       1 main.go:87] Received NotifyRegistrationStatus call: &RegistrationStatus{PluginRegistered:true,Error:,}

Logs (Post Provision)

kubelet

Oct 08 09:50:39 k1.ovrclk.net k3s[11703]: I1008 09:50:39.541039   11703 event.go:258] Event(v1.ObjectReference{Kind:"PersistentVolumeClaim", Namespace:"akash-sanity-1570528238", Name:"sanity-pvc", UID:"b71827b4-9e13-43f7-80a8-efbf446bb6bb", APIVersion:"v1", ResourceVersion:"653", FieldPath:""}): type: 'Normal' reason: 'ExternalProvisioning' waiting for a volume to be created, either by external provisioner "net.packet.csi" or manually created by system administrator
Oct 08 09:50:39 k1.ovrclk.net k3s[11703]: I1008 09:50:39.541559   11703 event.go:258] Event(v1.ObjectReference{Kind:"PersistentVolumeClaim", Namespace:"akash-sanity-1570528238", Name:"sanity-pvc", UID:"b71827b4-9e13-43f7-80a8-efbf446bb6bb", APIVersion:"v1", ResourceVersion:"653", FieldPath:""}): type: 'Normal' reason: 'ExternalProvisioning' waiting for a volume to be created, either by external provisioner "net.packet.csi" or manually created by system administrator
Oct 08 09:50:39 k1.ovrclk.net k3s[11703]: E1008 09:50:39.811161   11703 factory.go:678] Error scheduling akash-sanity-1570528238/sanity-pod: pod has unbound immediate PersistentVolumeClaims; retrying
Oct 08 09:50:39 k1.ovrclk.net k3s[11703]: E1008 09:50:39.820339   11703 scheduler.go:485] error selecting node for pod: pod has unbound immediate PersistentVolumeClaims
Oct 08 09:50:45 k1.ovrclk.net k3s[11703]: I1008 09:50:45.226291   11703 event.go:258] Event(v1.ObjectReference{Kind:"PersistentVolumeClaim", Namespace:"akash-sanity-1570528238", Name:"sanity-pvc", UID:"b71827b4-9e13-43f7-80a8-efbf446bb6bb", APIVersion:"v1", ResourceVersion:"653", FieldPath:""}): type: 'Normal' reason: 'ExternalProvisioning' waiting for a volume to be created, either by external provisioner "net.packet.csi" or manually created by system administrator
Oct 08 09:50:45 k1.ovrclk.net k3s[11703]: E1008 09:50:45.417645   11703 factory.go:678] Error scheduling akash-sanity-1570528238/sanity-pod: pod has unbound immediate PersistentVolumeClaims; retrying
Oct 08 09:50:45 k1.ovrclk.net k3s[11703]: E1008 09:50:45.417671   11703 scheduler.go:485] error selecting node for pod: pod has unbound immediate PersistentVolumeClaims
Oct 08 09:50:47 k1.ovrclk.net k3s[11703]: I1008 09:50:47.867470   11703 reconciler.go:288] attacherDetacher.AttachVolume started for volume "pvc-b71827b4-9e13-43f7-80a8-efbf446bb6bb" (UniqueName: "kubernetes.io/csi/net.packet.csi^51e533b3-a38e-4ebf-917f-6f90920c1342") from node "k1.ovrclk.net"
Oct 08 09:50:47 k1.ovrclk.net k3s[11703]: I1008 09:50:47.959856   11703 reconciler.go:203] operationExecutor.VerifyControllerAttachedVolume started for volume "default-token-4mxmd" (UniqueName: "kubernetes.io/secret/92fef253-ca60-48e3-ae8e-ef6826ff6d3b-default-token-4mxmd") pod "sanity-pod" (UID: "92fef253-ca60-48e3-ae8e-ef6826ff6d3b")
Oct 08 09:50:47 k1.ovrclk.net k3s[11703]: I1008 09:50:47.960108   11703 reconciler.go:203] operationExecutor.VerifyControllerAttachedVolume started for volume "pvc-b71827b4-9e13-43f7-80a8-efbf446bb6bb" (UniqueName: "kubernetes.io/csi/net.packet.csi^51e533b3-a38e-4ebf-917f-6f90920c1342") pod "sanity-pod" (UID: "92fef253-ca60-48e3-ae8e-ef6826ff6d3b")
Oct 08 09:50:47 k1.ovrclk.net k3s[11703]: E1008 09:50:47.960329   11703 nestedpendingoperations.go:270] Operation for "\"kubernetes.io/csi/net.packet.csi^51e533b3-a38e-4ebf-917f-6f90920c1342\"" failed. No retries permitted until 2019-10-08 09:50:48.460260533 +0000 UTC m=+745.148143131 (durationBeforeRetry 500ms). Error: "Volume has not been added to the list of VolumesInUse in the node's volume status for volume \"pvc-b71827b4-9e13-43f7-80a8-efbf446bb6bb\" (UniqueName: \"kubernetes.io/csi/net.packet.csi^51e533b3-a38e-4ebf-917f-6f90920c1342\") pod \"sanity-pod\" (UID: \"92fef253-ca60-48e3-ae8e-ef6826ff6d3b\") "
Oct 08 09:50:48 k1.ovrclk.net k3s[11703]: I1008 09:50:48.462104   11703 reconciler.go:203] operationExecutor.VerifyControllerAttachedVolume started for volume "pvc-b71827b4-9e13-43f7-80a8-efbf446bb6bb" (UniqueName: "kubernetes.io/csi/net.packet.csi^51e533b3-a38e-4ebf-917f-6f90920c1342") pod "sanity-pod" (UID: "92fef253-ca60-48e3-ae8e-ef6826ff6d3b")
Oct 08 09:50:48 k1.ovrclk.net k3s[11703]: E1008 09:50:48.462320   11703 nestedpendingoperations.go:270] Operation for "\"kubernetes.io/csi/net.packet.csi^51e533b3-a38e-4ebf-917f-6f90920c1342\"" failed. No retries permitted until 2019-10-08 09:50:49.462243959 +0000 UTC m=+746.150126529 (durationBeforeRetry 1s). Error: "Volume has not been added to the list of VolumesInUse in the node's volume status for volume \"pvc-b71827b4-9e13-43f7-80a8-efbf446bb6bb\" (UniqueName: \"kubernetes.io/csi/net.packet.csi^51e533b3-a38e-4ebf-917f-6f90920c1342\") pod \"sanity-pod\" (UID: \"92fef253-ca60-48e3-ae8e-ef6826ff6d3b\") "
Oct 08 09:50:49 k1.ovrclk.net k3s[11703]: I1008 09:50:49.466599   11703 reconciler.go:203] operationExecutor.VerifyControllerAttachedVolume started for volume "pvc-b71827b4-9e13-43f7-80a8-efbf446bb6bb" (UniqueName: "kubernetes.io/csi/net.packet.csi^51e533b3-a38e-4ebf-917f-6f90920c1342") pod "sanity-pod" (UID: "92fef253-ca60-48e3-ae8e-ef6826ff6d3b")
Oct 08 09:50:49 k1.ovrclk.net k3s[11703]: E1008 09:50:49.466804   11703 nestedpendingoperations.go:270] Operation for "\"kubernetes.io/csi/net.packet.csi^51e533b3-a38e-4ebf-917f-6f90920c1342\"" failed. No retries permitted until 2019-10-08 09:50:51.466741244 +0000 UTC m=+748.154623751 (durationBeforeRetry 2s). Error: "Volume has not been added to the list of VolumesInUse in the node's volume status for volume \"pvc-b71827b4-9e13-43f7-80a8-efbf446bb6bb\" (UniqueName: \"kubernetes.io/csi/net.packet.csi^51e533b3-a38e-4ebf-917f-6f90920c1342\") pod \"sanity-pod\" (UID: \"92fef253-ca60-48e3-ae8e-ef6826ff6d3b\") "
Oct 08 09:50:51 k1.ovrclk.net k3s[11703]: I1008 09:50:51.474987   11703 reconciler.go:203] operationExecutor.VerifyControllerAttachedVolume started for volume "pvc-b71827b4-9e13-43f7-80a8-efbf446bb6bb" (UniqueName: "kubernetes.io/csi/net.packet.csi^51e533b3-a38e-4ebf-917f-6f90920c1342") pod "sanity-pod" (UID: "92fef253-ca60-48e3-ae8e-ef6826ff6d3b")
Oct 08 09:50:51 k1.ovrclk.net k3s[11703]: E1008 09:50:51.479844   11703 nestedpendingoperations.go:270] Operation for "\"kubernetes.io/csi/net.packet.csi^51e533b3-a38e-4ebf-917f-6f90920c1342\"" failed. No retries permitted until 2019-10-08 09:50:55.479781838 +0000 UTC m=+752.167664385 (durationBeforeRetry 4s). Error: "Volume not attached according to node status for volume \"pvc-b71827b4-9e13-43f7-80a8-efbf446bb6bb\" (UniqueName: \"kubernetes.io/csi/net.packet.csi^51e533b3-a38e-4ebf-917f-6f90920c1342\") pod \"sanity-pod\" (UID: \"92fef253-ca60-48e3-ae8e-ef6826ff6d3b\") "
Oct 08 09:50:54 k1.ovrclk.net k3s[11703]: I1008 09:50:54.316597   11703 operation_generator.go:358] AttachVolume.Attach succeeded for volume "pvc-b71827b4-9e13-43f7-80a8-efbf446bb6bb" (UniqueName: "kubernetes.io/csi/net.packet.csi^51e533b3-a38e-4ebf-917f-6f90920c1342") from node "k1.ovrclk.net"
Oct 08 09:50:54 k1.ovrclk.net k3s[11703]: I1008 09:50:54.316780   11703 event.go:258] Event(v1.ObjectReference{Kind:"Pod", Namespace:"akash-sanity-1570528238", Name:"sanity-pod", UID:"92fef253-ca60-48e3-ae8e-ef6826ff6d3b", APIVersion:"v1", ResourceVersion:"668", FieldPath:""}): type: 'Normal' reason: 'SuccessfulAttachVolume' AttachVolume.Attach succeeded for volume "pvc-b71827b4-9e13-43f7-80a8-efbf446bb6bb"
Oct 08 09:50:55 k1.ovrclk.net k3s[11703]: I1008 09:50:55.491309   11703 reconciler.go:203] operationExecutor.VerifyControllerAttachedVolume started for volume "pvc-b71827b4-9e13-43f7-80a8-efbf446bb6bb" (UniqueName: "kubernetes.io/csi/net.packet.csi^51e533b3-a38e-4ebf-917f-6f90920c1342") pod "sanity-pod" (UID: "92fef253-ca60-48e3-ae8e-ef6826ff6d3b")
Oct 08 09:50:55 k1.ovrclk.net k3s[11703]: I1008 09:50:55.496360   11703 operation_generator.go:1437] Controller attach succeeded for volume "pvc-b71827b4-9e13-43f7-80a8-efbf446bb6bb" (UniqueName: "kubernetes.io/csi/net.packet.csi^51e533b3-a38e-4ebf-917f-6f90920c1342") pod "sanity-pod" (UID: "92fef253-ca60-48e3-ae8e-ef6826ff6d3b") device path: ""
Oct 08 09:50:55 k1.ovrclk.net k3s[11703]: I1008 09:50:55.692429   11703 operation_generator.go:629] MountVolume.WaitForAttach entering for volume "pvc-b71827b4-9e13-43f7-80a8-efbf446bb6bb" (UniqueName: "kubernetes.io/csi/net.packet.csi^51e533b3-a38e-4ebf-917f-6f90920c1342") pod "sanity-pod" (UID: "92fef253-ca60-48e3-ae8e-ef6826ff6d3b") DevicePath ""
Oct 08 09:50:55 k1.ovrclk.net k3s[11703]: I1008 09:50:55.696844   11703 operation_generator.go:638] MountVolume.WaitForAttach succeeded for volume "pvc-b71827b4-9e13-43f7-80a8-efbf446bb6bb" (UniqueName: "kubernetes.io/csi/net.packet.csi^51e533b3-a38e-4ebf-917f-6f90920c1342") pod "sanity-pod" (UID: "92fef253-ca60-48e3-ae8e-ef6826ff6d3b") DevicePath "csi-38853ef68f955e2132a9ba0e35976886f648e07c7b847a1aefa3110353411aaa"
Oct 08 09:50:55 k1.ovrclk.net k3s[11703]: E1008 09:50:55.858905   11703 csi_attacher.go:337] kubernetes.io/csi: attacher.MountDevice failed: rpc error: code = Unknown desc = iscsiadmin discover error, exit status 21
Oct 08 09:50:55 k1.ovrclk.net k3s[11703]: E1008 09:50:55.859055   11703 nestedpendingoperations.go:270] Operation for "\"kubernetes.io/csi/net.packet.csi^51e533b3-a38e-4ebf-917f-6f90920c1342\"" failed. No retries permitted until 2019-10-08 09:50:56.359034549 +0000 UTC m=+753.046916974 (durationBeforeRetry 500ms). Error: "MountVolume.MountDevice failed for volume \"pvc-b71827b4-9e13-43f7-80a8-efbf446bb6bb\" (UniqueName: \"kubernetes.io/csi/net.packet.csi^51e533b3-a38e-4ebf-917f-6f90920c1342\") pod \"sanity-pod\" (UID: \"92fef253-ca60-48e3-ae8e-ef6826ff6d3b\") : rpc error: code = Unknown desc = iscsiadmin discover error, exit status 21"
Oct 08 09:50:56 k1.ovrclk.net k3s[11703]: I1008 09:50:56.511701   11703 operation_generator.go:629] MountVolume.WaitForAttach entering for volume "pvc-b71827b4-9e13-43f7-80a8-efbf446bb6bb" (UniqueName: "kubernetes.io/csi/net.packet.csi^51e533b3-a38e-4ebf-917f-6f90920c1342") pod "sanity-pod" (UID: "92fef253-ca60-48e3-ae8e-ef6826ff6d3b") DevicePath ""
Oct 08 09:50:56 k1.ovrclk.net k3s[11703]: I1008 09:50:56.516468   11703 operation_generator.go:638] MountVolume.WaitForAttach succeeded for volume "pvc-b71827b4-9e13-43f7-80a8-efbf446bb6bb" (UniqueName: "kubernetes.io/csi/net.packet.csi^51e533b3-a38e-4ebf-917f-6f90920c1342") pod "sanity-pod" (UID: "92fef253-ca60-48e3-ae8e-ef6826ff6d3b") DevicePath "csi-38853ef68f955e2132a9ba0e35976886f648e07c7b847a1aefa3110353411aaa"
Oct 08 09:50:56 k1.ovrclk.net k3s[11703]: E1008 09:50:56.653324   11703 csi_attacher.go:337] kubernetes.io/csi: attacher.MountDevice failed: rpc error: code = Unknown desc = iscsiadmin discover error, exit status 21
Oct 08 09:50:56 k1.ovrclk.net k3s[11703]: E1008 09:50:56.653824   11703 nestedpendingoperations.go:270] Operation for "\"kubernetes.io/csi/net.packet.csi^51e533b3-a38e-4ebf-917f-6f90920c1342\"" failed. No retries permitted until 2019-10-08 09:50:57.6537525 +0000 UTC m=+754.341635011 (durationBeforeRetry 1s). Error: "MountVolume.MountDevice failed for volume \"pvc-b71827b4-9e13-43f7-80a8-efbf446bb6bb\" (UniqueName: \"kubernetes.io/csi/net.packet.csi^51e533b3-a38e-4ebf-917f-6f90920c1342\") pod \"sanity-pod\" (UID: \"92fef253-ca60-48e3-ae8e-ef6826ff6d3b\") : rpc error: code = Unknown desc = iscsiadmin discover error, exit status 21"
Oct 08 09:50:57 k1.ovrclk.net k3s[11703]: I1008 09:50:57.823552   11703 operation_generator.go:629] MountVolume.WaitForAttach entering for volume "pvc-b71827b4-9e13-43f7-80a8-efbf446bb6bb" (UniqueName: "kubernetes.io/csi/net.packet.csi^51e533b3-a38e-4ebf-917f-6f90920c1342") pod "sanity-pod" (UID: "92fef253-ca60-48e3-ae8e-ef6826ff6d3b") DevicePath ""
Oct 08 09:50:57 k1.ovrclk.net k3s[11703]: I1008 09:50:57.828097   11703 operation_generator.go:638] MountVolume.WaitForAttach succeeded for volume "pvc-b71827b4-9e13-43f7-80a8-efbf446bb6bb" (UniqueName: "kubernetes.io/csi/net.packet.csi^51e533b3-a38e-4ebf-917f-6f90920c1342") pod "sanity-pod" (UID: "92fef253-ca60-48e3-ae8e-ef6826ff6d3b") DevicePath "csi-38853ef68f955e2132a9ba0e35976886f648e07c7b847a1aefa3110353411aaa"
Oct 08 09:50:57 k1.ovrclk.net k3s[11703]: E1008 09:50:57.962424   11703 csi_attacher.go:337] kubernetes.io/csi: attacher.MountDevice failed: rpc error: code = Unknown desc = iscsiadmin discover error, exit status 21
Oct 08 09:50:57 k1.ovrclk.net k3s[11703]: E1008 09:50:57.962903   11703 nestedpendingoperations.go:270] Operation for "\"kubernetes.io/csi/net.packet.csi^51e533b3-a38e-4ebf-917f-6f90920c1342\"" failed. No retries permitted until 2019-10-08 09:50:59.96283464 +0000 UTC m=+756.650717129 (durationBeforeRetry 2s). Error: "MountVolume.MountDevice failed for volume \"pvc-b71827b4-9e13-43f7-80a8-efbf446bb6bb\" (UniqueName: \"kubernetes.io/csi/net.packet.csi^51e533b3-a38e-4ebf-917f-6f90920c1342\") pod \"sanity-pod\" (UID: \"92fef253-ca60-48e3-ae8e-ef6826ff6d3b\") : rpc error: code = Unknown desc = iscsiadmin discover error, exit status 21"
Oct 08 09:51:00 k1.ovrclk.net k3s[11703]: I1008 09:51:00.123748   11703 operation_generator.go:629] MountVolume.WaitForAttach entering for volume "pvc-b71827b4-9e13-43f7-80a8-efbf446bb6bb" (UniqueName: "kubernetes.io/csi/net.packet.csi^51e533b3-a38e-4ebf-917f-6f90920c1342") pod "sanity-pod" (UID: "92fef253-ca60-48e3-ae8e-ef6826ff6d3b") DevicePath ""
Oct 08 09:51:00 k1.ovrclk.net k3s[11703]: I1008 09:51:00.128413   11703 operation_generator.go:638] MountVolume.WaitForAttach succeeded for volume "pvc-b71827b4-9e13-43f7-80a8-efbf446bb6bb" (UniqueName: "kubernetes.io/csi/net.packet.csi^51e533b3-a38e-4ebf-917f-6f90920c1342") pod "sanity-pod" (UID: "92fef253-ca60-48e3-ae8e-ef6826ff6d3b") DevicePath "csi-38853ef68f955e2132a9ba0e35976886f648e07c7b847a1aefa3110353411aaa"
Oct 08 09:51:00 k1.ovrclk.net k3s[11703]: E1008 09:51:00.263783   11703 csi_attacher.go:337] kubernetes.io/csi: attacher.MountDevice failed: rpc error: code = Unknown desc = iscsiadmin discover error, exit status 21
Oct 08 09:51:00 k1.ovrclk.net k3s[11703]: E1008 09:51:00.264341   11703 nestedpendingoperations.go:270] Operation for "\"kubernetes.io/csi/net.packet.csi^51e533b3-a38e-4ebf-917f-6f90920c1342\"" failed. No retries permitted until 2019-10-08 09:51:04.264248989 +0000 UTC m=+760.952131520 (durationBeforeRetry 4s). Error: "MountVolume.MountDevice failed for volume \"pvc-b71827b4-9e13-43f7-80a8-efbf446bb6bb\" (UniqueName: \"kubernetes.io/csi/net.packet.csi^51e533b3-a38e-4ebf-917f-6f90920c1342\") pod \"sanity-pod\" (UID: \"92fef253-ca60-48e3-ae8e-ef6826ff6d3b\") : rpc error: code = Unknown desc = iscsiadmin discover error, exit status 21"
Oct 08 09:51:04 k1.ovrclk.net k3s[11703]: I1008 09:51:04.443450   11703 operation_generator.go:629] MountVolume.WaitForAttach entering for volume "pvc-b71827b4-9e13-43f7-80a8-efbf446bb6bb" (UniqueName: "kubernetes.io/csi/net.packet.csi^51e533b3-a38e-4ebf-917f-6f90920c1342") pod "sanity-pod" (UID: "92fef253-ca60-48e3-ae8e-ef6826ff6d3b") DevicePath ""
Oct 08 09:51:04 k1.ovrclk.net k3s[11703]: I1008 09:51:04.448071   11703 operation_generator.go:638] MountVolume.WaitForAttach succeeded for volume "pvc-b71827b4-9e13-43f7-80a8-efbf446bb6bb" (UniqueName: "kubernetes.io/csi/net.packet.csi^51e533b3-a38e-4ebf-917f-6f90920c1342") pod "sanity-pod" (UID: "92fef253-ca60-48e3-ae8e-ef6826ff6d3b") DevicePath "csi-38853ef68f955e2132a9ba0e35976886f648e07c7b847a1aefa3110353411aaa"
Oct 08 09:51:04 k1.ovrclk.net k3s[11703]: E1008 09:51:04.582853   11703 csi_attacher.go:337] kubernetes.io/csi: attacher.MountDevice failed: rpc error: code = Unknown desc = iscsiadmin discover error, exit status 21
Oct 08 09:51:04 k1.ovrclk.net k3s[11703]: E1008 09:51:04.583395   11703 nestedpendingoperations.go:270] Operation for "\"kubernetes.io/csi/net.packet.csi^51e533b3-a38e-4ebf-917f-6f90920c1342\"" failed. No retries permitted until 2019-10-08 09:51:12.583305321 +0000 UTC m=+769.271187842 (durationBeforeRetry 8s). Error: "MountVolume.MountDevice failed for volume \"pvc-b71827b4-9e13-43f7-80a8-efbf446bb6bb\" (UniqueName: \"kubernetes.io/csi/net.packet.csi^51e533b3-a38e-4ebf-917f-6f90920c1342\") pod \"sanity-pod\" (UID: \"92fef253-ca60-48e3-ae8e-ef6826ff6d3b\") : rpc error: code = Unknown desc = iscsiadmin discover error, exit status 21"
Oct 08 09:51:12 k1.ovrclk.net k3s[11703]: I1008 09:51:12.783655   11703 operation_generator.go:629] MountVolume.WaitForAttach entering for volume "pvc-b71827b4-9e13-43f7-80a8-efbf446bb6bb" (UniqueName: "kubernetes.io/csi/net.packet.csi^51e533b3-a38e-4ebf-917f-6f90920c1342") pod "sanity-pod" (UID: "92fef253-ca60-48e3-ae8e-ef6826ff6d3b") DevicePath ""
Oct 08 09:51:12 k1.ovrclk.net k3s[11703]: I1008 09:51:12.788414   11703 operation_generator.go:638] MountVolume.WaitForAttach succeeded for volume "pvc-b71827b4-9e13-43f7-80a8-efbf446bb6bb" (UniqueName: "kubernetes.io/csi/net.packet.csi^51e533b3-a38e-4ebf-917f-6f90920c1342") pod "sanity-pod" (UID: "92fef253-ca60-48e3-ae8e-ef6826ff6d3b") DevicePath "csi-38853ef68f955e2132a9ba0e35976886f648e07c7b847a1aefa3110353411aaa"
Oct 08 09:51:12 k1.ovrclk.net k3s[11703]: E1008 09:51:12.921761   11703 csi_attacher.go:337] kubernetes.io/csi: attacher.MountDevice failed: rpc error: code = Unknown desc = iscsiadmin discover error, exit status 21
Oct 08 09:51:12 k1.ovrclk.net k3s[11703]: E1008 09:51:12.922290   11703 nestedpendingoperations.go:270] Operation for "\"kubernetes.io/csi/net.packet.csi^51e533b3-a38e-4ebf-917f-6f90920c1342\"" failed. No retries permitted until 2019-10-08 09:51:28.922216873 +0000 UTC m=+785.610099389 (durationBeforeRetry 16s). Error: "MountVolume.MountDevice failed for volume \"pvc-b71827b4-9e13-43f7-80a8-efbf446bb6bb\" (UniqueName: \"kubernetes.io/csi/net.packet.csi^51e533b3-a38e-4ebf-917f-6f90920c1342\") pod \"sanity-pod\" (UID: \"92fef253-ca60-48e3-ae8e-ef6826ff6d3b\") : rpc error: code = Unknown desc = iscsiadmin discover error, exit status 21"
Oct 08 09:51:23 k1.ovrclk.net k3s[11703]: I1008 09:51:23.720492   11703 trace.go:116] Trace[729856802]: "Get /api/v1/namespaces/kube-system/pods/csi-node-srtdr/log" (started: 2019-10-08 09:50:25.340144121 +0000 UTC m=+722.028026617) (total time: 58.380267342s):
Oct 08 09:51:23 k1.ovrclk.net k3s[11703]: Trace[729856802]: [58.380263243s] [58.375847887s] Transformed response object
Oct 08 09:51:23 k1.ovrclk.net k3s[11703]: I1008 09:51:23.726282   11703 log.go:172] http: superfluous response.WriteHeader call from github.com/rancher/k3s/vendor/k8s.io/apiserver/pkg/server/httplog.(*respLogger).WriteHeader (httplog.go:184)
Oct 08 09:51:26 k1.ovrclk.net k3s[11703]: E1008 09:51:26.283895   11703 goroutinemap.go:150] Operation for "/var/lib/rancher/k3s/agent/kubelet/plugins/net.packet.csi/csi.sock" failed. No retries permitted until 2019-10-08 09:53:28.283839312 +0000 UTC m=+904.971721985 (durationBeforeRetry 2m2s). Error: "RegisterPlugin error -- failed to get plugin info using RPC GetInfo at socket /var/lib/rancher/k3s/agent/kubelet/plugins/net.packet.csi/csi.sock, err: rpc error: code = Unimplemented desc = unknown service pluginregistration.Registration"
Oct 08 09:51:29 k1.ovrclk.net k3s[11703]: I1008 09:51:29.055018   11703 operation_generator.go:629] MountVolume.WaitForAttach entering for volume "pvc-b71827b4-9e13-43f7-80a8-efbf446bb6bb" (UniqueName: "kubernetes.io/csi/net.packet.csi^51e533b3-a38e-4ebf-917f-6f90920c1342") pod "sanity-pod" (UID: "92fef253-ca60-48e3-ae8e-ef6826ff6d3b") DevicePath ""
Oct 08 09:51:29 k1.ovrclk.net k3s[11703]: I1008 09:51:29.056883   11703 operation_generator.go:638] MountVolume.WaitForAttach succeeded for volume "pvc-b71827b4-9e13-43f7-80a8-efbf446bb6bb" (UniqueName: "kubernetes.io/csi/net.packet.csi^51e533b3-a38e-4ebf-917f-6f90920c1342") pod "sanity-pod" (UID: "92fef253-ca60-48e3-ae8e-ef6826ff6d3b") DevicePath "csi-38853ef68f955e2132a9ba0e35976886f648e07c7b847a1aefa3110353411aaa"
Oct 08 09:51:29 k1.ovrclk.net k3s[11703]: E1008 09:51:29.190995   11703 csi_attacher.go:337] kubernetes.io/csi: attacher.MountDevice failed: rpc error: code = Unknown desc = iscsiadmin discover error, exit status 21
Oct 08 09:51:29 k1.ovrclk.net k3s[11703]: E1008 09:51:29.191466   11703 nestedpendingoperations.go:270] Operation for "\"kubernetes.io/csi/net.packet.csi^51e533b3-a38e-4ebf-917f-6f90920c1342\"" failed. No retries permitted until 2019-10-08 09:52:01.191394986 +0000 UTC m=+817.879277512 (durationBeforeRetry 32s). Error: "MountVolume.MountDevice failed for volume \"pvc-b71827b4-9e13-43f7-80a8-efbf446bb6bb\" (UniqueName: \"kubernetes.io/csi/net.packet.csi^51e533b3-a38e-4ebf-917f-6f90920c1342\") pod \"sanity-pod\" (UID: \"92fef253-ca60-48e3-ae8e-ef6826ff6d3b\") : rpc error: code = Unknown desc = iscsiadmin discover error, exit status 21"
Oct 08 09:52:01 k1.ovrclk.net k3s[11703]: I1008 09:52:01.391555   11703 operation_generator.go:629] MountVolume.WaitForAttach entering for volume "pvc-b71827b4-9e13-43f7-80a8-efbf446bb6bb" (UniqueName: "kubernetes.io/csi/net.packet.csi^51e533b3-a38e-4ebf-917f-6f90920c1342") pod "sanity-pod" (UID: "92fef253-ca60-48e3-ae8e-ef6826ff6d3b") DevicePath ""
Oct 08 09:52:01 k1.ovrclk.net k3s[11703]: I1008 09:52:01.396287   11703 operation_generator.go:638] MountVolume.WaitForAttach succeeded for volume "pvc-b71827b4-9e13-43f7-80a8-efbf446bb6bb" (UniqueName: "kubernetes.io/csi/net.packet.csi^51e533b3-a38e-4ebf-917f-6f90920c1342") pod "sanity-pod" (UID: "92fef253-ca60-48e3-ae8e-ef6826ff6d3b") DevicePath "csi-38853ef68f955e2132a9ba0e35976886f648e07c7b847a1aefa3110353411aaa"
Oct 08 09:52:01 k1.ovrclk.net k3s[11703]: E1008 09:52:01.531149   11703 csi_attacher.go:337] kubernetes.io/csi: attacher.MountDevice failed: rpc error: code = Unknown desc = iscsiadmin discover error, exit status 21
Oct 08 09:52:01 k1.ovrclk.net k3s[11703]: E1008 09:52:01.531652   11703 nestedpendingoperations.go:270] Operation for "\"kubernetes.io/csi/net.packet.csi^51e533b3-a38e-4ebf-917f-6f90920c1342\"" failed. No retries permitted until 2019-10-08 09:53:05.531554553 +0000 UTC m=+882.219437078 (durationBeforeRetry 1m4s). Error: "MountVolume.MountDevice failed for volume \"pvc-b71827b4-9e13-43f7-80a8-efbf446bb6bb\" (UniqueName: \"kubernetes.io/csi/net.packet.csi^51e533b3-a38e-4ebf-917f-6f90920c1342\") pod \"sanity-pod\" (UID: \"92fef253-ca60-48e3-ae8e-ef6826ff6d3b\") : rpc error: code = Unknown desc = iscsiadmin discover error, exit status 21"
Oct 08 09:52:24 k1.ovrclk.net k3s[11703]: I1008 09:52:24.098998   11703 trace.go:116] Trace[880451703]: "Get /api/v1/namespaces/kube-system/pods/csi-node-srtdr/log" (started: 2019-10-08 09:50:30.740991707 +0000 UTC m=+727.428874233) (total time: 1m53.357925044s):
Oct 08 09:52:24 k1.ovrclk.net k3s[11703]: Trace[880451703]: [1m53.357922502s] [1m53.353923807s] Transformed response object

node / packet-driver

{"endpoint":"unix:///csi/csi.sock","level":"info","msg":"NodeGetCapabilities called","node":"k1.ovrclk.net","time":"2019-10-08T09:50:55Z"}
{"GRPC.call":"/csi.v1.Node/NodeGetCapabilities","GRPC.request":"","level":"info","msg":"GRPC response: capabilities:\u003crpc:\u003ctype:STAGE_UNSTAGE_VOLUME \u003e \u003e ","time":"2019-10-08T09:50:55Z"}
{"endpoint":"unix:///csi/csi.sock","level":"info","msg":"NodeStageVolume called","node":"k1.ovrclk.net","time":"2019-10-08T09:50:55Z"}
{"args":"--mode discovery --portal 10.144.144.135 --type sendtargets --discover","command":"iscsiadm","error":"exit status 21","level":"error","msg":"Error","out":"iscsiadm: No portals found\n","time":"2019-10-08T09:50:55Z"}
{"endpoint":"unix:///csi/csi.sock","fsType":"ext4","level":"info","method":"NodeStageVolume","msg":"iscsiadmin discover error, exit status 21","node":"k1.ovrclk.net","staging_target_path":"/var/lib/rancher/k3s/agent/kubelet/plugins/kubernetes.io/csi/pv/pvc-b71827b4-9e13-43f7-80a8-efbf446bb6bb/globalmount","time":"2019-10-08T09:50:55Z","volume_id":"51e533b3-a38e-4ebf-917f-6f90920c1342","volume_name":"volume-51e533b3"}
{"GRPC.call":"/csi.v1.Node/NodeStageVolume","GRPC.request":"volume_id:\"51e533b3-a38e-4ebf-917f-6f90920c1342\" publish_context:\u003ckey:\"AttachmentId\" value:\"c631ab93-fa62-4bc4-8c22-36d7b102266a\" \u003e publish_context:\u003ckey:\"VolumeId\" value:\"51e533b3-a38e-4ebf-917f-6f90920c1342\" \u003e publish_context:\u003ckey:\"VolumeName\" value:\"volume-51e533b3\" \u003e staging_target_path:\"/var/lib/rancher/k3s/agent/kubelet/plugins/kubernetes.io/csi/pv/pvc-b71827b4-9e13-43f7-80a8-efbf446bb6bb/globalmount\" volume_capability:\u003cmount:\u003cfs_type:\"ext4\" \u003e access_mode:\u003cmode:SINGLE_NODE_WRITER \u003e \u003e volume_context:\u003ckey:\"storage.kubernetes.io/csiProvisionerIdentity\" value:\"1570527546484-8081-net.packet.csi\" \u003e ","level":"error","msg":"GRPC error: rpc error: code = Unknown desc = iscsiadmin discover error, exit status 21","time":"2019-10-08T09:50:55Z"}
{"endpoint":"unix:///csi/csi.sock","level":"info","msg":"NodeGetCapabilities called","node":"k1.ovrclk.net","time":"2019-10-08T09:50:56Z"}
{"GRPC.call":"/csi.v1.Node/NodeGetCapabilities","GRPC.request":"","level":"info","msg":"GRPC response: capabilities:\u003crpc:\u003ctype:STAGE_UNSTAGE_VOLUME \u003e \u003e ","time":"2019-10-08T09:50:56Z"}
{"endpoint":"unix:///csi/csi.sock","level":"info","msg":"NodeStageVolume called","node":"k1.ovrclk.net","time":"2019-10-08T09:50:56Z"}
{"args":"--mode discovery --portal 10.144.144.135 --type sendtargets --discover","command":"iscsiadm","error":"exit status 21","level":"error","msg":"Error","out":"iscsiadm: No portals found\n","time":"2019-10-08T09:50:56Z"}
{"endpoint":"unix:///csi/csi.sock","fsType":"ext4","level":"info","method":"NodeStageVolume","msg":"iscsiadmin discover error, exit status 21","node":"k1.ovrclk.net","staging_target_path":"/var/lib/rancher/k3s/agent/kubelet/plugins/kubernetes.io/csi/pv/pvc-b71827b4-9e13-43f7-80a8-efbf446bb6bb/globalmount","time":"2019-10-08T09:50:56Z","volume_id":"51e533b3-a38e-4ebf-917f-6f90920c1342","volume_name":"volume-51e533b3"}
{"GRPC.call":"/csi.v1.Node/NodeStageVolume","GRPC.request":"volume_id:\"51e533b3-a38e-4ebf-917f-6f90920c1342\" publish_context:\u003ckey:\"AttachmentId\" value:\"c631ab93-fa62-4bc4-8c22-36d7b102266a\" \u003e publish_context:\u003ckey:\"VolumeId\" value:\"51e533b3-a38e-4ebf-917f-6f90920c1342\" \u003e publish_context:\u003ckey:\"VolumeName\" value:\"volume-51e533b3\" \u003e staging_target_path:\"/var/lib/rancher/k3s/agent/kubelet/plugins/kubernetes.io/csi/pv/pvc-b71827b4-9e13-43f7-80a8-efbf446bb6bb/globalmount\" volume_capability:\u003cmount:\u003cfs_type:\"ext4\" \u003e access_mode:\u003cmode:SINGLE_NODE_WRITER \u003e \u003e volume_context:\u003ckey:\"storage.kubernetes.io/csiProvisionerIdentity\" value:\"1570527546484-8081-net.packet.csi\" \u003e ","level":"error","msg":"GRPC error: rpc error: code = Unknown desc = iscsiadmin discover error, exit status 21","time":"2019-10-08T09:50:56Z"}
{"endpoint":"unix:///csi/csi.sock","level":"info","msg":"NodeGetCapabilities called","node":"k1.ovrclk.net","time":"2019-10-08T09:50:57Z"}
{"GRPC.call":"/csi.v1.Node/NodeGetCapabilities","GRPC.request":"","level":"info","msg":"GRPC response: capabilities:\u003crpc:\u003ctype:STAGE_UNSTAGE_VOLUME \u003e \u003e ","time":"2019-10-08T09:50:57Z"}
{"endpoint":"unix:///csi/csi.sock","level":"info","msg":"NodeStageVolume called","node":"k1.ovrclk.net","time":"2019-10-08T09:50:57Z"}
{"args":"--mode discovery --portal 10.144.144.135 --type sendtargets --discover","command":"iscsiadm","error":"exit status 21","level":"error","msg":"Error","out":"iscsiadm: No portals found\n","time":"2019-10-08T09:50:57Z"}
{"endpoint":"unix:///csi/csi.sock","fsType":"ext4","level":"info","method":"NodeStageVolume","msg":"iscsiadmin discover error, exit status 21","node":"k1.ovrclk.net","staging_target_path":"/var/lib/rancher/k3s/agent/kubelet/plugins/kubernetes.io/csi/pv/pvc-b71827b4-9e13-43f7-80a8-efbf446bb6bb/globalmount","time":"2019-10-08T09:50:57Z","volume_id":"51e533b3-a38e-4ebf-917f-6f90920c1342","volume_name":"volume-51e533b3"}
{"GRPC.call":"/csi.v1.Node/NodeStageVolume","GRPC.request":"volume_id:\"51e533b3-a38e-4ebf-917f-6f90920c1342\" publish_context:\u003ckey:\"AttachmentId\" value:\"c631ab93-fa62-4bc4-8c22-36d7b102266a\" \u003e publish_context:\u003ckey:\"VolumeId\" value:\"51e533b3-a38e-4ebf-917f-6f90920c1342\" \u003e publish_context:\u003ckey:\"VolumeName\" value:\"volume-51e533b3\" \u003e staging_target_path:\"/var/lib/rancher/k3s/agent/kubelet/plugins/kubernetes.io/csi/pv/pvc-b71827b4-9e13-43f7-80a8-efbf446bb6bb/globalmount\" volume_capability:\u003cmount:\u003cfs_type:\"ext4\" \u003e access_mode:\u003cmode:SINGLE_NODE_WRITER \u003e \u003e volume_context:\u003ckey:\"storage.kubernetes.io/csiProvisionerIdentity\" value:\"1570527546484-8081-net.packet.csi\" \u003e ","level":"error","msg":"GRPC error: rpc error: code = Unknown desc = iscsiadmin discover error, exit status 21","time":"2019-10-08T09:50:57Z"}
{"endpoint":"unix:///csi/csi.sock","level":"info","msg":"NodeGetCapabilities called","node":"k1.ovrclk.net","time":"2019-10-08T09:51:00Z"}
{"GRPC.call":"/csi.v1.Node/NodeGetCapabilities","GRPC.request":"","level":"info","msg":"GRPC response: capabilities:\u003crpc:\u003ctype:STAGE_UNSTAGE_VOLUME \u003e \u003e ","time":"2019-10-08T09:51:00Z"}
{"endpoint":"unix:///csi/csi.sock","level":"info","msg":"NodeStageVolume called","node":"k1.ovrclk.net","time":"2019-10-08T09:51:00Z"}
{"args":"--mode discovery --portal 10.144.144.135 --type sendtargets --discover","command":"iscsiadm","error":"exit status 21","level":"error","msg":"Error","out":"iscsiadm: No portals found\n","time":"2019-10-08T09:51:00Z"}
{"endpoint":"unix:///csi/csi.sock","fsType":"ext4","level":"info","method":"NodeStageVolume","msg":"iscsiadmin discover error, exit status 21","node":"k1.ovrclk.net","staging_target_path":"/var/lib/rancher/k3s/agent/kubelet/plugins/kubernetes.io/csi/pv/pvc-b71827b4-9e13-43f7-80a8-efbf446bb6bb/globalmount","time":"2019-10-08T09:51:00Z","volume_id":"51e533b3-a38e-4ebf-917f-6f90920c1342","volume_name":"volume-51e533b3"}
{"GRPC.call":"/csi.v1.Node/NodeStageVolume","GRPC.request":"volume_id:\"51e533b3-a38e-4ebf-917f-6f90920c1342\" publish_context:\u003ckey:\"AttachmentId\" value:\"c631ab93-fa62-4bc4-8c22-36d7b102266a\" \u003e publish_context:\u003ckey:\"VolumeId\" value:\"51e533b3-a38e-4ebf-917f-6f90920c1342\" \u003e publish_context:\u003ckey:\"VolumeName\" value:\"volume-51e533b3\" \u003e staging_target_path:\"/var/lib/rancher/k3s/agent/kubelet/plugins/kubernetes.io/csi/pv/pvc-b71827b4-9e13-43f7-80a8-efbf446bb6bb/globalmount\" volume_capability:\u003cmount:\u003cfs_type:\"ext4\" \u003e access_mode:\u003cmode:SINGLE_NODE_WRITER \u003e \u003e volume_context:\u003ckey:\"storage.kubernetes.io/csiProvisionerIdentity\" value:\"1570527546484-8081-net.packet.csi\" \u003e ","level":"error","msg":"GRPC error: rpc error: code = Unknown desc = iscsiadmin discover error, exit status 21","time":"2019-10-08T09:51:00Z"}
{"endpoint":"unix:///csi/csi.sock","level":"info","msg":"NodeGetCapabilities called","node":"k1.ovrclk.net","time":"2019-10-08T09:51:04Z"}
{"GRPC.call":"/csi.v1.Node/NodeGetCapabilities","GRPC.request":"","level":"info","msg":"GRPC response: capabilities:\u003crpc:\u003ctype:STAGE_UNSTAGE_VOLUME \u003e \u003e ","time":"2019-10-08T09:51:04Z"}
{"endpoint":"unix:///csi/csi.sock","level":"info","msg":"NodeStageVolume called","node":"k1.ovrclk.net","time":"2019-10-08T09:51:04Z"}
{"args":"--mode discovery --portal 10.144.144.135 --type sendtargets --discover","command":"iscsiadm","error":"exit status 21","level":"error","msg":"Error","out":"iscsiadm: No portals found\n","time":"2019-10-08T09:51:04Z"}
{"endpoint":"unix:///csi/csi.sock","fsType":"ext4","level":"info","method":"NodeStageVolume","msg":"iscsiadmin discover error, exit status 21","node":"k1.ovrclk.net","staging_target_path":"/var/lib/rancher/k3s/agent/kubelet/plugins/kubernetes.io/csi/pv/pvc-b71827b4-9e13-43f7-80a8-efbf446bb6bb/globalmount","time":"2019-10-08T09:51:04Z","volume_id":"51e533b3-a38e-4ebf-917f-6f90920c1342","volume_name":"volume-51e533b3"}
{"GRPC.call":"/csi.v1.Node/NodeStageVolume","GRPC.request":"volume_id:\"51e533b3-a38e-4ebf-917f-6f90920c1342\" publish_context:\u003ckey:\"AttachmentId\" value:\"c631ab93-fa62-4bc4-8c22-36d7b102266a\" \u003e publish_context:\u003ckey:\"VolumeId\" value:\"51e533b3-a38e-4ebf-917f-6f90920c1342\" \u003e publish_context:\u003ckey:\"VolumeName\" value:\"volume-51e533b3\" \u003e staging_target_path:\"/var/lib/rancher/k3s/agent/kubelet/plugins/kubernetes.io/csi/pv/pvc-b71827b4-9e13-43f7-80a8-efbf446bb6bb/globalmount\" volume_capability:\u003cmount:\u003cfs_type:\"ext4\" \u003e access_mode:\u003cmode:SINGLE_NODE_WRITER \u003e \u003e volume_context:\u003ckey:\"storage.kubernetes.io/csiProvisionerIdentity\" value:\"1570527546484-8081-net.packet.csi\" \u003e ","level":"error","msg":"GRPC error: rpc error: code = Unknown desc = iscsiadmin discover error, exit status 21","time":"2019-10-08T09:51:04Z"}
{"endpoint":"unix:///csi/csi.sock","level":"info","msg":"NodeGetCapabilities called","node":"k1.ovrclk.net","time":"2019-10-08T09:51:12Z"}
{"GRPC.call":"/csi.v1.Node/NodeGetCapabilities","GRPC.request":"","level":"info","msg":"GRPC response: capabilities:\u003crpc:\u003ctype:STAGE_UNSTAGE_VOLUME \u003e \u003e ","time":"2019-10-08T09:51:12Z"}
{"endpoint":"unix:///csi/csi.sock","level":"info","msg":"NodeStageVolume called","node":"k1.ovrclk.net","time":"2019-10-08T09:51:12Z"}
{"args":"--mode discovery --portal 10.144.144.135 --type sendtargets --discover","command":"iscsiadm","error":"exit status 21","level":"error","msg":"Error","out":"iscsiadm: No portals found\n","time":"2019-10-08T09:51:12Z"}
{"endpoint":"unix:///csi/csi.sock","fsType":"ext4","level":"info","method":"NodeStageVolume","msg":"iscsiadmin discover error, exit status 21","node":"k1.ovrclk.net","staging_target_path":"/var/lib/rancher/k3s/agent/kubelet/plugins/kubernetes.io/csi/pv/pvc-b71827b4-9e13-43f7-80a8-efbf446bb6bb/globalmount","time":"2019-10-08T09:51:12Z","volume_id":"51e533b3-a38e-4ebf-917f-6f90920c1342","volume_name":"volume-51e533b3"}
{"GRPC.call":"/csi.v1.Node/NodeStageVolume","GRPC.request":"volume_id:\"51e533b3-a38e-4ebf-917f-6f90920c1342\" publish_context:\u003ckey:\"AttachmentId\" value:\"c631ab93-fa62-4bc4-8c22-36d7b102266a\" \u003e publish_context:\u003ckey:\"VolumeId\" value:\"51e533b3-a38e-4ebf-917f-6f90920c1342\" \u003e publish_context:\u003ckey:\"VolumeName\" value:\"volume-51e533b3\" \u003e staging_target_path:\"/var/lib/rancher/k3s/agent/kubelet/plugins/kubernetes.io/csi/pv/pvc-b71827b4-9e13-43f7-80a8-efbf446bb6bb/globalmount\" volume_capability:\u003cmount:\u003cfs_type:\"ext4\" \u003e access_mode:\u003cmode:SINGLE_NODE_WRITER \u003e \u003e volume_context:\u003ckey:\"storage.kubernetes.io/csiProvisionerIdentity\" value:\"1570527546484-8081-net.packet.csi\" \u003e ","level":"error","msg":"GRPC error: rpc error: code = Unknown desc = iscsiadmin discover error, exit status 21","time":"2019-10-08T09:51:12Z"}
{"endpoint":"unix:///csi/csi.sock","level":"info","msg":"NodeGetCapabilities called","node":"k1.ovrclk.net","time":"2019-10-08T09:51:29Z"}
{"GRPC.call":"/csi.v1.Node/NodeGetCapabilities","GRPC.request":"","level":"info","msg":"GRPC response: capabilities:\u003crpc:\u003ctype:STAGE_UNSTAGE_VOLUME \u003e \u003e ","time":"2019-10-08T09:51:29Z"}
{"endpoint":"unix:///csi/csi.sock","level":"info","msg":"NodeStageVolume called","node":"k1.ovrclk.net","time":"2019-10-08T09:51:29Z"}
{"args":"--mode discovery --portal 10.144.144.135 --type sendtargets --discover","command":"iscsiadm","error":"exit status 21","level":"error","msg":"Error","out":"iscsiadm: No portals found\n","time":"2019-10-08T09:51:29Z"}
{"endpoint":"unix:///csi/csi.sock","fsType":"ext4","level":"info","method":"NodeStageVolume","msg":"iscsiadmin discover error, exit status 21","node":"k1.ovrclk.net","staging_target_path":"/var/lib/rancher/k3s/agent/kubelet/plugins/kubernetes.io/csi/pv/pvc-b71827b4-9e13-43f7-80a8-efbf446bb6bb/globalmount","time":"2019-10-08T09:51:29Z","volume_id":"51e533b3-a38e-4ebf-917f-6f90920c1342","volume_name":"volume-51e533b3"}
{"GRPC.call":"/csi.v1.Node/NodeStageVolume","GRPC.request":"volume_id:\"51e533b3-a38e-4ebf-917f-6f90920c1342\" publish_context:\u003ckey:\"AttachmentId\" value:\"c631ab93-fa62-4bc4-8c22-36d7b102266a\" \u003e publish_context:\u003ckey:\"VolumeId\" value:\"51e533b3-a38e-4ebf-917f-6f90920c1342\" \u003e publish_context:\u003ckey:\"VolumeName\" value:\"volume-51e533b3\" \u003e staging_target_path:\"/var/lib/rancher/k3s/agent/kubelet/plugins/kubernetes.io/csi/pv/pvc-b71827b4-9e13-43f7-80a8-efbf446bb6bb/globalmount\" volume_capability:\u003cmount:\u003cfs_type:\"ext4\" \u003e access_mode:\u003cmode:SINGLE_NODE_WRITER \u003e \u003e volume_context:\u003ckey:\"storage.kubernetes.io/csiProvisionerIdentity\" value:\"1570527546484-8081-net.packet.csi\" \u003e ","level":"error","msg":"GRPC error: rpc error: code = Unknown desc = iscsiadmin discover error, exit status 21","time":"2019-10-08T09:51:29Z"}
{"endpoint":"unix:///csi/csi.sock","level":"info","msg":"NodeGetCapabilities called","node":"k1.ovrclk.net","time":"2019-10-08T09:52:01Z"}
{"GRPC.call":"/csi.v1.Node/NodeGetCapabilities","GRPC.request":"","level":"info","msg":"GRPC response: capabilities:\u003crpc:\u003ctype:STAGE_UNSTAGE_VOLUME \u003e \u003e ","time":"2019-10-08T09:52:01Z"}
{"endpoint":"unix:///csi/csi.sock","level":"info","msg":"NodeStageVolume called","node":"k1.ovrclk.net","time":"2019-10-08T09:52:01Z"}
{"args":"--mode discovery --portal 10.144.144.135 --type sendtargets --discover","command":"iscsiadm","error":"exit status 21","level":"error","msg":"Error","out":"iscsiadm: No portals found\n","time":"2019-10-08T09:52:01Z"}
{"endpoint":"unix:///csi/csi.sock","fsType":"ext4","level":"info","method":"NodeStageVolume","msg":"iscsiadmin discover error, exit status 21","node":"k1.ovrclk.net","staging_target_path":"/var/lib/rancher/k3s/agent/kubelet/plugins/kubernetes.io/csi/pv/pvc-b71827b4-9e13-43f7-80a8-efbf446bb6bb/globalmount","time":"2019-10-08T09:52:01Z","volume_id":"51e533b3-a38e-4ebf-917f-6f90920c1342","volume_name":"volume-51e533b3"}
{"GRPC.call":"/csi.v1.Node/NodeStageVolume","GRPC.request":"volume_id:\"51e533b3-a38e-4ebf-917f-6f90920c1342\" publish_context:\u003ckey:\"AttachmentId\" value:\"c631ab93-fa62-4bc4-8c22-36d7b102266a\" \u003e publish_context:\u003ckey:\"VolumeId\" value:\"51e533b3-a38e-4ebf-917f-6f90920c1342\" \u003e publish_context:\u003ckey:\"VolumeName\" value:\"volume-51e533b3\" \u003e staging_target_path:\"/var/lib/rancher/k3s/agent/kubelet/plugins/kubernetes.io/csi/pv/pvc-b71827b4-9e13-43f7-80a8-efbf446bb6bb/globalmount\" volume_capability:\u003cmount:\u003cfs_type:\"ext4\" \u003e access_mode:\u003cmode:SINGLE_NODE_WRITER \u003e \u003e volume_context:\u003ckey:\"storage.kubernetes.io/csiProvisionerIdentity\" value:\"1570527546484-8081-net.packet.csi\" \u003e ","level":"error","msg":"GRPC error: rpc error: code = Unknown desc = iscsiadmin discover error, exit status 21","time":"2019-10-08T09:52:01Z"}

controller / csi-attacher

I1008 09:39:03.266522       1 main.go:85] Version: v2.0.0-0-g27b83ca
I1008 09:39:03.267608       1 connection.go:151] Connecting to unix:///csi/csi.sock
I1008 09:39:06.210998       1 common.go:111] Probing CSI driver for readiness
I1008 09:39:06.211015       1 connection.go:180] GRPC call: /csi.v1.Identity/Probe
I1008 09:39:06.211020       1 connection.go:181] GRPC request: {}
I1008 09:39:06.212151       1 connection.go:183] GRPC response: {}
I1008 09:39:06.212769       1 connection.go:184] GRPC error: <nil>
I1008 09:39:06.212818       1 connection.go:180] GRPC call: /csi.v1.Identity/GetPluginInfo
I1008 09:39:06.212824       1 connection.go:181] GRPC request: {}
I1008 09:39:06.213491       1 connection.go:183] GRPC response: {"name":"net.packet.csi","vendor_version":"1c039e3"}
I1008 09:39:06.213851       1 connection.go:184] GRPC error: <nil>
I1008 09:39:06.213857       1 main.go:128] CSI driver name: "net.packet.csi"
I1008 09:39:06.213862       1 connection.go:180] GRPC call: /csi.v1.Identity/GetPluginCapabilities
I1008 09:39:06.213865       1 connection.go:181] GRPC request: {}
I1008 09:39:06.214461       1 connection.go:183] GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}}]}
I1008 09:39:06.214921       1 connection.go:184] GRPC error: <nil>
I1008 09:39:06.214925       1 connection.go:180] GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I1008 09:39:06.214928       1 connection.go:181] GRPC request: {}
I1008 09:39:06.215419       1 connection.go:183] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":2}}},{"Type":{"Rpc":{"type":3}}}]}
I1008 09:39:06.216309       1 connection.go:184] GRPC error: <nil>
I1008 09:39:06.216329       1 main.go:152] CSI driver supports ControllerPublishUnpublish, using real CSI handler
I1008 09:39:06.216404       1 controller.go:113] Starting CSI attacher
I1008 09:39:06.216829       1 reflector.go:123] Starting reflector *v1beta1.CSINode (10m0s) from k8s.io/client-go/informers/factory.go:133
I1008 09:39:06.216898       1 reflector.go:161] Listing and watching *v1beta1.CSINode from k8s.io/client-go/informers/factory.go:133
I1008 09:39:06.216829       1 reflector.go:123] Starting reflector *v1.Node (10m0s) from k8s.io/client-go/informers/factory.go:133
I1008 09:39:06.216966       1 reflector.go:161] Listing and watching *v1.Node from k8s.io/client-go/informers/factory.go:133
I1008 09:39:06.216835       1 reflector.go:123] Starting reflector *v1beta1.VolumeAttachment (10m0s) from k8s.io/client-go/informers/factory.go:133
I1008 09:39:06.217006       1 reflector.go:161] Listing and watching *v1beta1.VolumeAttachment from k8s.io/client-go/informers/factory.go:133
I1008 09:39:06.216881       1 reflector.go:123] Starting reflector *v1.PersistentVolume (10m0s) from k8s.io/client-go/informers/factory.go:133
I1008 09:39:06.217140       1 reflector.go:161] Listing and watching *v1.PersistentVolume from k8s.io/client-go/informers/factory.go:133
I1008 09:39:06.316560       1 shared_informer.go:123] caches populated
I1008 09:46:17.229984       1 reflector.go:370] k8s.io/client-go/informers/factory.go:133: Watch close - *v1.PersistentVolume total 0 items received
I1008 09:47:07.227062       1 reflector.go:370] k8s.io/client-go/informers/factory.go:133: Watch close - *v1beta1.CSINode total 2 items received
I1008 09:47:25.229722       1 reflector.go:370] k8s.io/client-go/informers/factory.go:133: Watch close - *v1beta1.VolumeAttachment total 0 items received
I1008 09:48:48.227573       1 reflector.go:370] k8s.io/client-go/informers/factory.go:133: Watch close - *v1.Node total 11 items received
I1008 09:49:06.228962       1 reflector.go:235] k8s.io/client-go/informers/factory.go:133: forcing resync
I1008 09:49:06.229013       1 reflector.go:235] k8s.io/client-go/informers/factory.go:133: forcing resync
I1008 09:50:45.419485       1 controller.go:205] Started PV processing "pvc-b71827b4-9e13-43f7-80a8-efbf446bb6bb"
I1008 09:50:45.419505       1 csi_handler.go:444] CSIHandler: processing PV "pvc-b71827b4-9e13-43f7-80a8-efbf446bb6bb"
I1008 09:50:45.419516       1 csi_handler.go:448] CSIHandler: processing PV "pvc-b71827b4-9e13-43f7-80a8-efbf446bb6bb": no deletion timestamp, ignoring
I1008 09:50:45.420235       1 controller.go:205] Started PV processing "pvc-b71827b4-9e13-43f7-80a8-efbf446bb6bb"
I1008 09:50:45.420258       1 csi_handler.go:444] CSIHandler: processing PV "pvc-b71827b4-9e13-43f7-80a8-efbf446bb6bb"
I1008 09:50:45.420268       1 csi_handler.go:448] CSIHandler: processing PV "pvc-b71827b4-9e13-43f7-80a8-efbf446bb6bb": no deletion timestamp, ignoring
I1008 09:50:47.879324       1 controller.go:175] Started VA processing "csi-38853ef68f955e2132a9ba0e35976886f648e07c7b847a1aefa3110353411aaa"
I1008 09:50:47.879369       1 csi_handler.go:89] CSIHandler: processing VA "csi-38853ef68f955e2132a9ba0e35976886f648e07c7b847a1aefa3110353411aaa"
I1008 09:50:47.879389       1 csi_handler.go:116] Attaching "csi-38853ef68f955e2132a9ba0e35976886f648e07c7b847a1aefa3110353411aaa"
I1008 09:50:47.879408       1 csi_handler.go:249] Starting attach operation for "csi-38853ef68f955e2132a9ba0e35976886f648e07c7b847a1aefa3110353411aaa"
I1008 09:50:47.879570       1 csi_handler.go:215] Adding finalizer to PV "pvc-b71827b4-9e13-43f7-80a8-efbf446bb6bb"
I1008 09:50:47.891041       1 csi_handler.go:224] PV finalizer added to "pvc-b71827b4-9e13-43f7-80a8-efbf446bb6bb"
I1008 09:50:47.891100       1 csi_handler.go:542] Found NodeID k1.ovrclk.net in CSINode k1.ovrclk.net
I1008 09:50:47.891212       1 csi_handler.go:177] VA finalizer added to "csi-38853ef68f955e2132a9ba0e35976886f648e07c7b847a1aefa3110353411aaa"
I1008 09:50:47.891256       1 csi_handler.go:191] NodeID annotation added to "csi-38853ef68f955e2132a9ba0e35976886f648e07c7b847a1aefa3110353411aaa"
I1008 09:50:47.892158       1 controller.go:205] Started PV processing "pvc-b71827b4-9e13-43f7-80a8-efbf446bb6bb"
I1008 09:50:47.892207       1 csi_handler.go:444] CSIHandler: processing PV "pvc-b71827b4-9e13-43f7-80a8-efbf446bb6bb"
I1008 09:50:47.892245       1 csi_handler.go:448] CSIHandler: processing PV "pvc-b71827b4-9e13-43f7-80a8-efbf446bb6bb": no deletion timestamp, ignoring
I1008 09:50:47.902939       1 connection.go:180] GRPC call: /csi.v1.Controller/ControllerPublishVolume
I1008 09:50:47.903001       1 connection.go:181] GRPC request: {"node_id":"k1.ovrclk.net","volume_capability":{"AccessType":{"Mount":{"fs_type":"ext4"}},"access_mode":{"mode":1}},"volume_context":{"storage.kubernetes.io/csiProvisionerIdentity":"1570527546484-8081-net.packet.csi"},"volume_id":"51e533b3-a38e-4ebf-917f-6f90920c1342"}
I1008 09:50:54.308320       1 connection.go:183] GRPC response: {"publish_context":{"AttachmentId":"c631ab93-fa62-4bc4-8c22-36d7b102266a","VolumeId":"51e533b3-a38e-4ebf-917f-6f90920c1342","VolumeName":"volume-51e533b3"}}
I1008 09:50:54.309920       1 connection.go:184] GRPC error: <nil>
I1008 09:50:54.309952       1 csi_handler.go:129] Attached "csi-38853ef68f955e2132a9ba0e35976886f648e07c7b847a1aefa3110353411aaa"
I1008 09:50:54.309974       1 util.go:35] Marking as attached "csi-38853ef68f955e2132a9ba0e35976886f648e07c7b847a1aefa3110353411aaa"
I1008 09:50:54.316013       1 util.go:48] Marked as attached "csi-38853ef68f955e2132a9ba0e35976886f648e07c7b847a1aefa3110353411aaa"
I1008 09:50:54.316062       1 csi_handler.go:135] Fully attached "csi-38853ef68f955e2132a9ba0e35976886f648e07c7b847a1aefa3110353411aaa"
I1008 09:50:54.316098       1 csi_handler.go:105] CSIHandler: finished processing "csi-38853ef68f955e2132a9ba0e35976886f648e07c7b847a1aefa3110353411aaa"
I1008 09:50:54.316178       1 controller.go:175] Started VA processing "csi-38853ef68f955e2132a9ba0e35976886f648e07c7b847a1aefa3110353411aaa"
I1008 09:50:54.316210       1 csi_handler.go:89] CSIHandler: processing VA "csi-38853ef68f955e2132a9ba0e35976886f648e07c7b847a1aefa3110353411aaa"
I1008 09:50:54.316240       1 csi_handler.go:116] Attaching "csi-38853ef68f955e2132a9ba0e35976886f648e07c7b847a1aefa3110353411aaa"
I1008 09:50:54.316267       1 csi_handler.go:249] Starting attach operation for "csi-38853ef68f955e2132a9ba0e35976886f648e07c7b847a1aefa3110353411aaa"
I1008 09:50:54.316492       1 csi_handler.go:209] PV finalizer is already set on "pvc-b71827b4-9e13-43f7-80a8-efbf446bb6bb"
I1008 09:50:54.316541       1 csi_handler.go:542] Found NodeID k1.ovrclk.net in CSINode k1.ovrclk.net
I1008 09:50:54.316597       1 csi_handler.go:169] VA finalizer is already set on "csi-38853ef68f955e2132a9ba0e35976886f648e07c7b847a1aefa3110353411aaa"
I1008 09:50:54.316624       1 csi_handler.go:183] NodeID annotation is already set on "csi-38853ef68f955e2132a9ba0e35976886f648e07c7b847a1aefa3110353411aaa"
I1008 09:50:54.316671       1 connection.go:180] GRPC call: /csi.v1.Controller/ControllerPublishVolume
I1008 09:50:54.316696       1 connection.go:181] GRPC request: {"node_id":"k1.ovrclk.net","volume_capability":{"AccessType":{"Mount":{"fs_type":"ext4"}},"access_mode":{"mode":1}},"volume_context":{"storage.kubernetes.io/csiProvisionerIdentity":"1570527546484-8081-net.packet.csi"},"volume_id":"51e533b3-a38e-4ebf-917f-6f90920c1342"}
I1008 09:50:56.987814       1 connection.go:183] GRPC response: {}
I1008 09:50:56.989194       1 connection.go:184] GRPC error: rpc error: code = Unknown desc = error attempting to attach 51e533b3-a38e-4ebf-917f-6f90920c1342 to 2b764f26-a703-4415-a294-142be3c72e97, POST https://api.packet.net/storage/51e533b3-a38e-4ebf-917f-6f90920c1342/attachments: 422 Instance is already attached to this volume
I1008 09:50:56.989236       1 csi_handler.go:412] Saving attach error to "csi-38853ef68f955e2132a9ba0e35976886f648e07c7b847a1aefa3110353411aaa"
I1008 09:50:56.995384       1 csi_handler.go:423] Saved attach error to "csi-38853ef68f955e2132a9ba0e35976886f648e07c7b847a1aefa3110353411aaa"
I1008 09:50:56.995491       1 csi_handler.go:99] Error processing "csi-38853ef68f955e2132a9ba0e35976886f648e07c7b847a1aefa3110353411aaa": failed to attach: rpc error: code = Unknown desc = error attempting to attach 51e533b3-a38e-4ebf-917f-6f90920c1342 to 2b764f26-a703-4415-a294-142be3c72e97, POST https://api.packet.net/storage/51e533b3-a38e-4ebf-917f-6f90920c1342/attachments: 422 Instance is already attached to this volume
I1008 09:50:56.995651       1 controller.go:175] Started VA processing "csi-38853ef68f955e2132a9ba0e35976886f648e07c7b847a1aefa3110353411aaa"
I1008 09:50:56.995705       1 csi_handler.go:89] CSIHandler: processing VA "csi-38853ef68f955e2132a9ba0e35976886f648e07c7b847a1aefa3110353411aaa"
I1008 09:50:56.995732       1 csi_handler.go:111] "csi-38853ef68f955e2132a9ba0e35976886f648e07c7b847a1aefa3110353411aaa" is already attached
I1008 09:50:56.995764       1 csi_handler.go:105] CSIHandler: finished processing "csi-38853ef68f955e2132a9ba0e35976886f648e07c7b847a1aefa3110353411aaa"
I1008 09:50:56.996198       1 controller.go:141] Ignoring VolumeAttachment "csi-38853ef68f955e2132a9ba0e35976886f648e07c7b847a1aefa3110353411aaa" change
I1008 09:50:57.995826       1 controller.go:175] Started VA processing "csi-38853ef68f955e2132a9ba0e35976886f648e07c7b847a1aefa3110353411aaa"
I1008 09:50:57.995878       1 csi_handler.go:89] CSIHandler: processing VA "csi-38853ef68f955e2132a9ba0e35976886f648e07c7b847a1aefa3110353411aaa"
I1008 09:50:57.995904       1 csi_handler.go:111] "csi-38853ef68f955e2132a9ba0e35976886f648e07c7b847a1aefa3110353411aaa" is already attached
I1008 09:50:57.995927       1 csi_handler.go:105] CSIHandler: finished processing "csi-38853ef68f955e2132a9ba0e35976886f648e07c7b847a1aefa3110353411aaa"

controller / packet-driver

{"level":"info","msg":"started","time":"2019-10-08T09:39:05Z","version":"1c039e3"}
{"level":"info","msg":"Creating provider","project_id":"48e3616c-8a10-4aa5-8d39-ec6cb2cd8014","time":"2019-10-08T09:39:05Z"}
{"facility_id":"2b70eb8f-fa18-47c0-aba7-222a842362fd","level":"info","msg":"facility found","project_id":"48e3616c-8a10-4aa5-8d39-ec6cb2cd8014","time":"2019-10-08T09:39:06Z"}
{"endpoint":"unix:///csi/csi.sock","level":"info","msg":"Starting server","node":"k1.ovrclk.net","time":"2019-10-08T09:39:06Z"}
{"address":"//csi/csi.sock","level":"info","msg":"Listening for connections","proto":"unix","time":"2019-10-08T09:39:06Z"}
{"level":"info","msg":"PacketIdentityServer.Probe called with args: \u0026csi.ProbeRequest{XXX_NoUnkeyedLiteral:struct {}{}, XXX_unrecognized:[]uint8(nil), XXX_sizecache:0}","time":"2019-10-08T09:39:06Z"}
{"GRPC.call":"/csi.v1.Identity/Probe","GRPC.request":"","level":"info","msg":"GRPC response: ","time":"2019-10-08T09:39:06Z"}
{"level":"info","msg":"PacketIdentityServer.GetPluginInfo called","time":"2019-10-08T09:39:06Z"}
{"GRPC.call":"/csi.v1.Identity/GetPluginInfo","GRPC.request":"","level":"info","msg":"GRPC response: name:\"net.packet.csi\" vendor_version:\"1c039e3\" ","time":"2019-10-08T09:39:06Z"}
{"level":"info","msg":"PacketIdentityServer.GetPluginCapabilities called","time":"2019-10-08T09:39:06Z"}
{"GRPC.call":"/csi.v1.Identity/GetPluginCapabilities","GRPC.request":"","level":"info","msg":"GRPC response: capabilities:\u003cservice:\u003ctype:CONTROLLER_SERVICE \u003e \u003e ","time":"2019-10-08T09:39:06Z"}
{"GRPC.call":"/csi.v1.Controller/ControllerGetCapabilities","GRPC.request":"","level":"info","msg":"GRPC response: capabilities:\u003crpc:\u003ctype:CREATE_DELETE_VOLUME \u003e \u003e capabilities:\u003crpc:\u003ctype:PUBLISH_UNPUBLISH_VOLUME \u003e \u003e capabilities:\u003crpc:\u003ctype:LIST_VOLUMES \u003e \u003e ","time":"2019-10-08T09:39:06Z"}
{"level":"info","msg":"PacketIdentityServer.Probe called with args: \u0026csi.ProbeRequest{XXX_NoUnkeyedLiteral:struct {}{}, XXX_unrecognized:[]uint8(nil), XXX_sizecache:0}","time":"2019-10-08T09:39:06Z"}
{"GRPC.call":"/csi.v1.Identity/Probe","GRPC.request":"","level":"info","msg":"GRPC response: ","time":"2019-10-08T09:39:06Z"}
{"level":"info","msg":"PacketIdentityServer.GetPluginInfo called","time":"2019-10-08T09:39:06Z"}
{"GRPC.call":"/csi.v1.Identity/GetPluginInfo","GRPC.request":"","level":"info","msg":"GRPC response: name:\"net.packet.csi\" vendor_version:\"1c039e3\" ","time":"2019-10-08T09:39:06Z"}
{"level":"info","msg":"PacketIdentityServer.GetPluginCapabilities called","time":"2019-10-08T09:39:06Z"}
{"GRPC.call":"/csi.v1.Identity/GetPluginCapabilities","GRPC.request":"","level":"info","msg":"GRPC response: capabilities:\u003cservice:\u003ctype:CONTROLLER_SERVICE \u003e \u003e ","time":"2019-10-08T09:39:06Z"}
{"GRPC.call":"/csi.v1.Controller/ControllerGetCapabilities","GRPC.request":"","level":"info","msg":"GRPC response: capabilities:\u003crpc:\u003ctype:CREATE_DELETE_VOLUME \u003e \u003e capabilities:\u003crpc:\u003ctype:PUBLISH_UNPUBLISH_VOLUME \u003e \u003e capabilities:\u003crpc:\u003ctype:LIST_VOLUMES \u003e \u003e ","time":"2019-10-08T09:39:06Z"}
{"level":"info","msg":"CreateVolume called","time":"2019-10-08T09:50:39Z","volume_name":"pvc-b71827b4-9e13-43f7-80a8-efbf446bb6bb"}
{"level":"info","msg":"Volume requested","planID":"87728148-3155-4992-a730-8d1e6aca8a32","sizeRequestGiB":10,"time":"2019-10-08T09:50:39Z","volume_name":"pvc-b71827b4-9e13-43f7-80a8-efbf446bb6bb"}
{"GRPC.call":"/csi.v1.Controller/CreateVolume","GRPC.request":"name:\"pvc-b71827b4-9e13-43f7-80a8-efbf446bb6bb\" capacity_range:\u003crequired_bytes:1073741824 \u003e volume_capabilities:\u003cmount:\u003cfs_type:\"ext4\" \u003e access_mode:\u003cmode:SINGLE_NODE_WRITER \u003e \u003e parameters:\u003ckey:\"plan\" value:\"standard\" \u003e ","level":"info","msg":"GRPC response: volume:\u003ccapacity_bytes:10737418240 volume_id:\"51e533b3-a38e-4ebf-917f-6f90920c1342\" \u003e ","time":"2019-10-08T09:50:45Z"}
{"GRPC.call":"/csi.v1.Controller/ControllerPublishVolume","GRPC.request":"volume_id:\"51e533b3-a38e-4ebf-917f-6f90920c1342\" node_id:\"k1.ovrclk.net\" volume_capability:\u003cmount:\u003cfs_type:\"ext4\" \u003e access_mode:\u003cmode:SINGLE_NODE_WRITER \u003e \u003e volume_context:\u003ckey:\"storage.kubernetes.io/csiProvisionerIdentity\" value:\"1570527546484-8081-net.packet.csi\" \u003e ","level":"info","msg":"GRPC response: publish_context:\u003ckey:\"AttachmentId\" value:\"c631ab93-fa62-4bc4-8c22-36d7b102266a\" \u003e publish_context:\u003ckey:\"VolumeId\" value:\"51e533b3-a38e-4ebf-917f-6f90920c1342\" \u003e publish_context:\u003ckey:\"VolumeName\" value:\"volume-51e533b3\" \u003e ","time":"2019-10-08T09:50:54Z"}
{"GRPC.call":"/csi.v1.Controller/ControllerPublishVolume","GRPC.request":"volume_id:\"51e533b3-a38e-4ebf-917f-6f90920c1342\" node_id:\"k1.ovrclk.net\" volume_capability:\u003cmount:\u003cfs_type:\"ext4\" \u003e access_mode:\u003cmode:SINGLE_NODE_WRITER \u003e \u003e volume_context:\u003ckey:\"storage.kubernetes.io/csiProvisionerIdentity\" value:\"1570527546484-8081-net.packet.csi\" \u003e ","level":"error","msg":"GRPC error: rpc error: code = Unknown desc = error attempting to attach 51e533b3-a38e-4ebf-917f-6f90920c1342 to 2b764f26-a703-4415-a294-142be3c72e97, POST https://api.packet.net/storage/51e533b3-a38e-4ebf-917f-6f90920c1342/attachments: 422 Instance is already attached to this volume ","time":"2019-10-08T09:50:56Z"}

volumes

$ curl -s https://metadata.packet.net/metadata | jq '.volumes'

[
  {
    "ips": [
      "10.144.144.133",
      "10.144.145.138"
    ],
    "name": "volume-40e826a5",
    "capacity": {
      "size": "10",
      "unit": "gb"
    },
    "iqn": "iqn.2013-05.com.daterainc:tc:01:sn:9c791ef25608a08c"
  },
  {
    "ips": [
      "10.144.144.135",
      "10.144.145.210"
    ],
    "name": "volume-51e533b3",
    "capacity": {
      "size": "10",
      "unit": "gb"
    },
    "iqn": "iqn.2013-05.com.daterainc:tc:01:sn:35f488b87b3c6dae"
  }
]

iscsiadm

$ iscsiadm --mode discovery --type sendtargets --portal 10.144.144.135 --discover

iscsiadm: No portals found

initiatorname.iscsi

$ cat /etc/iscsi/initiatorname.iscsi

## DO NOT EDIT OR REMOVE THIS FILE!
## If you remove this file, the iSCSI daemon will not start.
## If you change the InitiatorName, existing access control lists
## may reject this initiator.  The InitiatorName must be unique
## for each iSCSI initiator.  Do NOT duplicate iSCSI InitiatorNames.
InitiatorName=iqn.1993-08.org.debian:01:fbecb99663e2

packet iqn

$ curl -s https://metadata.packet.net/metadata | jq -r '.iqn'
iqn.2019-10.net.packet:device.2b764f26

[deitch]

@gosuri, can you please post the results of cat /etc/iscsi/initiatorname.iscsi?

BTW, you win the prize for most complete debugging information in an issue.

[gosuri]

## DO NOT EDIT OR REMOVE THIS FILE!
## If you remove this file, the iSCSI daemon will not start.
## If you change the InitiatorName, existing access control lists
## may reject this initiator.  The InitiatorName must be unique
## for each iSCSI initiator.  Do NOT duplicate iSCSI InitiatorNames.
InitiatorName=iqn.1993-08.org.debian:01:fbecb99663e2

You're doing the hard work, least i could do is support you as best as can :)

[deitch]

And please

curl -s https://metadata.packet.net/metadata | jq -r '.iqn'

[deitch]

You're doing the hard work, least i could do is support you as best as can :)

And believe me, we appreciate it! :-)

[gosuri]

curl -s https://metadata.packet.net/metadata | jq -r '.iqn'
iqn.2019-10.net.packet:device.2b764f26

[deitch]

Yup. That’s it. Known issue. Fix is in the works. Let’s keep this open until that’s done, likely another week or so.

[deitch]

@gosuri #50 fixes this and will close this issue automatically. Nonetheless, when merged in, please validate it.

You still will have a multipath issue; working on that one.

[gosuri]

Great. I assume this is the multipath issue you're referring to MountVolume.MountDevice failed for volume "pvc-14d8fa66-fe5b-4cd3-9f69-80c7a8e41d25" : rpc error: code = Unknown desc = devicePath error, file not found for pattern /dev/disk/by-path/*10.144.144.216*iqn.2013-05.com.daterainc:tc:01:sn:e7817a47612d37b5*

Image Snapshot

{
  "names": [
    "docker.io/grafana/grafana@sha256:f398faf159712dbfddada80679f1411b1baa6fca3ee08317d785c41a2972124a",
    "docker.io/grafana/grafana:6.3.5"
  ],
  "sizeBytes": 98592267
}
{
  "names": [
    "docker.io/packethost/csi-packet@sha256:407c0d3245a5d8f9d691997290ae2623cbadb7bfac42c32d00fa23a95b46c59d",
    "docker.io/packethost/csi-packet:42377cc"
  ],
  "sizeBytes": 76962916
}
{
  "names": [
    "docker.io/prom/prometheus@sha256:8f34c18cf2ccaf21e361afd18e92da2602d0fa23a8917f759f906219242d8572",
    "docker.io/prom/prometheus:v2.11.1"
  ],
  "sizeBytes": 51075391
}
{
  "names": [
    "gcr.io/kubernetes-helm/tiller@sha256:be79aff05025bd736f027eaf4a1b2716ac1e09b88e0e9493c962642519f19d9c",
    "gcr.io/kubernetes-helm/tiller:v2.14.2"
  ],
  "sizeBytes": 30875059
}
{
  "names": [
    "docker.io/rancher/klipper-helm@sha256:72690de1ae2259a41075e87ff453936a74e0f2dbf2ad1dd96a4f72136a48038d",
    "docker.io/rancher/klipper-helm:v0.1.5"
  ],
  "sizeBytes": 27089525
}
{
  "names": [
    "docker.io/prom/alertmanager@sha256:3d52ab7ef3a2e23e26a73cfd0ce13189e3796fb276b9af3e79664e4f743d8a1d",
    "docker.io/prom/alertmanager:v0.18.0"
  ],
  "sizeBytes": 25080314
}
{
  "names": [
    "docker.io/library/traefik@sha256:e1e1b1dadfaab6d64f420f4352356e98e289fc7c8bf9f47387866f221c60e4e6",
    "docker.io/library/traefik:1.7.14"
  ],
  "sizeBytes": 23626773
}
{
  "names": [
    "gcr.io/k8s-minikube/storage-provisioner@sha256:088daa9fcbccf04c3f415d77d5a6360d2803922190b675cb7fc88a9d2d91985a",
    "gcr.io/k8s-minikube/storage-provisioner:v1.8.1"
  ],
  "sizeBytes": 20680423
}
{
  "names": [
    "quay.io/k8scsi/csi-provisioner:v1.4.0"
  ],
  "sizeBytes": 20068761
}
{
  "names": [
    "quay.io/k8scsi/csi-attacher:v2.0.0"
  ],
  "sizeBytes": 17305293
}
{
  "names": [
    "docker.io/coredns/coredns@sha256:cfa7236dab4e3860881fdf755880ff8361e42f6cba2e3775ae48e2d46d22f7ba",
    "docker.io/coredns/coredns:1.6.3"
  ],
  "sizeBytes": 14191001
}
{
  "names": [
    "quay.io/coreos/kube-state-metrics:v1.6.0"
  ],
  "sizeBytes": 12176142
}
{
  "names": [
    "docker.io/ovrclk/akashd@sha256:88d62f6b4d396ca5dcc81195f22bd5f8dc49e875614c597bffb102e49b47791f",
    "docker.io/ovrclk/akashd:latest"
  ],
  "sizeBytes": 11232268
}
{
  "names": [
    "docker.io/prom/node-exporter@sha256:b2dd31b0d23fda63588674e40fd8d05010d07c5d4ac37163fc596ba9065ce38d",
    "docker.io/prom/node-exporter:v0.18.0"
  ],
  "sizeBytes": 11100284
}
{
  "names": [
    "gcr.io/google_containers/metrics-server-amd64@sha256:edab4c64c4e29f665adaf6c0e11fe00ac9d71bb1fdce61bfa3d9e2a664331f79",
    "gcr.io/google_containers/metrics-server-amd64:v0.3.5"
  ],
  "sizeBytes": 10542677
}
{
  "names": [
    "docker.io/jimmidyson/configmap-reload@sha256:befec9f23d2a9da86a298d448cc9140f56a457362a7d9eecddba192db1ab489e",
    "docker.io/jimmidyson/configmap-reload:v0.2.2"
  ],
  "sizeBytes": 9880745
}
{
  "names": [
    "docker.io/prom/pushgateway@sha256:aeb2b7fe9f1464455dfea93494d8e84438bf5d60888fcc9e3554366191c1aba8",
    "docker.io/prom/pushgateway:v0.8.0"
  ],
  "sizeBytes": 7863620
}
{
  "names": [
    "quay.io/k8scsi/csi-node-driver-registrar:v1.2.0"
  ],
  "sizeBytes": 7676183
}
{
  "names": [
    "docker.io/appropriate/curl@sha256:c8bf5bbec6397465a247c2bb3e589bb77e4f62ff88a027175ecb2d9e4f12c9d7",
    "docker.io/appropriate/curl:latest"
  ],
  "sizeBytes": 2779755
}
{
  "names": [
    "docker.io/rancher/klipper-lb@sha256:2cff68f14dd050a5ab16b59a55d5ba34d6edc3f6edfc1ec5bd4e437d4ba47290",
    "docker.io/rancher/klipper-lb:v0.1.1"
  ],
  "sizeBytes": 2708144
}
{
  "names": [
    "docker.io/library/busybox@sha256:fe301db49df08c384001ed752dff6d52b4305a73a7f608f21528048e8a08b51e",
    "docker.io/library/busybox:latest"
  ],
  "sizeBytes": 764658
}
{
  "names": [
    "k8s.gcr.io/pause@sha256:f78411e19d84a252e53bff71a4407a5686c46983a2c2eeed83929b888179acea",
    "k8s.gcr.io/pause:3.1"
  ],
  "sizeBytes": 317164
}

Full Log

kube-system/csi-packet-controller-0[csi-attacher]: I1011 03:19:14.432108       1 reflector.go:370] k8s.io/client-go/informers/factory.go:133: Watch close - *v1beta1.CSINode total 0 items received
kube-system/csi-packet-controller-0[csi-attacher]: I1011 03:19:32.434806       1 reflector.go:370] k8s.io/client-go/informers/factory.go:133: Watch close - *v1.PersistentVolume total 0 items received
kube-system/csi-packet-controller-0[csi-external-provisioner]: I1011 03:19:33.080825       1 reflector.go:389] sigs.k8s.io/sig-storage-lib-external-provisioner/controller/controller.go:807: Watch close - *v1.StorageClass total 2 items received
kube-system/csi-packet-controller-0[csi-attacher]: I1011 03:20:55.433626       1 reflector.go:370] k8s.io/client-go/informers/factory.go:133: Watch close - *v1.Node total 10 items received
kube-system/csi-packet-controller-0[csi-external-provisioner]: I1011 03:20:56.078662       1 reflector.go:389] sigs.k8s.io/sig-storage-lib-external-provisioner/controller/controller.go:801: Watch close - *v1.PersistentVolumeClaim total 0 items received
kube-system/csi-packet-controller-0[csi-attacher]: I1011 03:21:13.433952       1 reflector.go:235] k8s.io/client-go/informers/factory.go:133: forcing resync
kube-system/csi-packet-controller-0[csi-attacher]: I1011 03:21:13.434011       1 reflector.go:235] k8s.io/client-go/informers/factory.go:133: forcing resync
kube-system/csi-packet-controller-0[csi-attacher]: I1011 03:24:51.437780       1 reflector.go:370] k8s.io/client-go/informers/factory.go:133: Watch close - *v1.PersistentVolume total 0 items received
kube-system/csi-packet-controller-0[csi-attacher]: I1011 03:25:31.437596       1 reflector.go:370] k8s.io/client-go/informers/factory.go:133: Watch close - *v1beta1.VolumeAttachment total 0 items received
kube-system/csi-packet-controller-0[csi-external-provisioner]: I1011 03:25:32.087350       1 reflector.go:389] sigs.k8s.io/sig-storage-lib-external-provisioner/controller/controller.go:804: Watch close - *v1.PersistentVolume total 0 items received
kube-system/csi-packet-controller-0[csi-external-provisioner]: I1011 03:26:14.077905       1 reflector.go:243] sigs.k8s.io/sig-storage-lib-external-provisioner/controller/controller.go:801: forcing resync
kube-system/csi-packet-controller-0[csi-external-provisioner]: I1011 03:26:14.082815       1 reflector.go:243] sigs.k8s.io/sig-storage-lib-external-provisioner/controller/controller.go:804: forcing resync
kube-system/csi-packet-controller-0[csi-external-provisioner]: I1011 03:26:15.081165       1 reflector.go:389] sigs.k8s.io/sig-storage-lib-external-provisioner/controller/controller.go:801: Watch close - *v1.PersistentVolumeClaim total 0 items received
kube-system/csi-packet-controller-0[csi-attacher]: I1011 03:26:41.436761       1 reflector.go:370] k8s.io/client-go/informers/factory.go:133: Watch close - *v1.Node total 6 items received
kube-system/csi-packet-controller-0[csi-attacher]: I1011 03:27:40.434965       1 reflector.go:370] k8s.io/client-go/informers/factory.go:133: Watch close - *v1beta1.CSINode total 0 items received
kube-system/csi-packet-controller-0[csi-external-provisioner]: I1011 03:27:59.083090       1 reflector.go:389] sigs.k8s.io/sig-storage-lib-external-provisioner/controller/controller.go:807: Watch close - *v1.StorageClass total 0 items received
kube-system/csi-packet-controller-0[csi-attacher]: I1011 03:30:20.440512       1 reflector.go:370] k8s.io/client-go/informers/factory.go:133: Watch close - *v1.PersistentVolume total 0 items received
kube-system/csi-packet-controller-0[csi-external-provisioner]: I1011 03:30:34.631968       1 controller.go:1199] provision "akash-sanity-1570764633/sanity-pvc" class "standard": started
kube-system/csi-packet-controller-0[csi-external-provisioner]: I1011 03:30:34.641516       1 controller.go:494] CreateVolumeRequest {Name:pvc-14d8fa66-fe5b-4cd3-9f69-80c7a8e41d25 CapacityRange:required_bytes:1073741824  VolumeCapabilities:[mount:<fs_type:"ext4" > access_mode:<mode:SINGLE_NODE_WRITER > ] Parameters:map[plan:standard] Secrets:map[] VolumeContentSource:<nil> AccessibilityRequirements:<nil> XXX_NoUnkeyedLiteral:{} XXX_unrecognized:[] XXX_sizecache:0}
kube-system/csi-packet-controller-0[csi-external-provisioner]: I1011 03:30:34.641707       1 event.go:255] Event(v1.ObjectReference{Kind:"PersistentVolumeClaim", Namespace:"akash-sanity-1570764633", Name:"sanity-pvc", UID:"14d8fa66-fe5b-4cd3-9f69-80c7a8e41d25", APIVersion:"v1", ResourceVersion:"15959", FieldPath:""}): type: 'Normal' reason: 'Provisioning' External provisioner is provisioning volume for claim "akash-sanity-1570764633/sanity-pvc"
kube-system/csi-packet-controller-0[csi-external-provisioner]: I1011 03:30:34.641807       1 connection.go:180] GRPC call: /csi.v1.Controller/CreateVolume
kube-system/csi-packet-controller-0[csi-external-provisioner]: I1011 03:30:34.641845       1 connection.go:181] GRPC request: {"capacity_range":{"required_bytes":1073741824},"name":"pvc-14d8fa66-fe5b-4cd3-9f69-80c7a8e41d25","parameters":{"plan":"standard"},"volume_capabilities":[{"AccessType":{"Mount":{"fs_type":"ext4"}},"access_mode":{"mode":1}}]}
kube-system/csi-packet-controller-0[packet-driver]: {"level":"info","msg":"CreateVolume called","time":"2019-10-11T03:30:34Z","volume_name":"pvc-14d8fa66-fe5b-4cd3-9f69-80c7a8e41d25"}
kube-system/csi-packet-controller-0[packet-driver]: {"level":"info","msg":"Volume requested","planID":"87728148-3155-4992-a730-8d1e6aca8a32","sizeRequestGiB":10,"time":"2019-10-11T03:30:34Z","volume_name":"pvc-14d8fa66-fe5b-4cd3-9f69-80c7a8e41d25"}
kube-system/csi-packet-controller-0[packet-driver]: {"GRPC.call":"/csi.v1.Controller/CreateVolume","GRPC.request":"name:\"pvc-14d8fa66-fe5b-4cd3-9f69-80c7a8e41d25\" capacity_range:\u003crequired_bytes:1073741824 \u003e volume_capabilities:\u003cmount:\u003cfs_type:\"ext4\" \u003e access_mode:\u003cmode:SINGLE_NODE_WRITER \u003e \u003e parameters:\u003ckey:\"plan\" value:\"standard\" \u003e ","level":"info","msg":"GRPC response: volume:\u003ccapacity_bytes:10737418240 volume_id:\"c3903862-edf9-4ea4-aec9-8316dafd86ce\" \u003e ","time":"2019-10-11T03:30:42Z"}
kube-system/csi-packet-controller-0[csi-external-provisioner]: I1011 03:30:42.318997       1 connection.go:183] GRPC response: {"volume":{"capacity_bytes":10737418240,"volume_id":"c3903862-edf9-4ea4-aec9-8316dafd86ce"}}
kube-system/csi-packet-controller-0[csi-external-provisioner]: I1011 03:30:42.321816       1 connection.go:184] GRPC error: <nil>
kube-system/csi-packet-controller-0[csi-attacher]: I1011 03:30:42.338610       1 controller.go:205] Started PV processing "pvc-14d8fa66-fe5b-4cd3-9f69-80c7a8e41d25"
kube-system/csi-packet-controller-0[csi-attacher]: I1011 03:30:42.338672       1 csi_handler.go:444] CSIHandler: processing PV "pvc-14d8fa66-fe5b-4cd3-9f69-80c7a8e41d25"
kube-system/csi-packet-controller-0[csi-attacher]: I1011 03:30:42.338713       1 csi_handler.go:448] CSIHandler: processing PV "pvc-14d8fa66-fe5b-4cd3-9f69-80c7a8e41d25": no deletion timestamp, ignoring
kube-system/csi-packet-controller-0[csi-attacher]: I1011 03:30:42.341601       1 controller.go:205] Started PV processing "pvc-14d8fa66-fe5b-4cd3-9f69-80c7a8e41d25"
kube-system/csi-packet-controller-0[csi-attacher]: I1011 03:30:42.341655       1 csi_handler.go:444] CSIHandler: processing PV "pvc-14d8fa66-fe5b-4cd3-9f69-80c7a8e41d25"
kube-system/csi-packet-controller-0[csi-external-provisioner]: I1011 03:30:42.321876       1 controller.go:549] create volume rep: {CapacityBytes:10737418240 VolumeId:c3903862-edf9-4ea4-aec9-8316dafd86ce VolumeContext:map[] ContentSource:<nil> AccessibleTopology:[] XXX_NoUnkeyedLiteral:{} XXX_unrecognized:[] XXX_sizecache:0}
kube-system/csi-packet-controller-0[csi-attacher]: I1011 03:30:42.341682       1 csi_handler.go:448] CSIHandler: processing PV "pvc-14d8fa66-fe5b-4cd3-9f69-80c7a8e41d25": no deletion timestamp, ignoring
kube-system/csi-packet-controller-0[csi-external-provisioner]: I1011 03:30:42.321977       1 controller.go:631] successfully created PV pvc-14d8fa66-fe5b-4cd3-9f69-80c7a8e41d25 for PVC sanity-pvc and csi volume name c3903862-edf9-4ea4-aec9-8316dafd86ce
kube-system/csi-packet-controller-0[csi-external-provisioner]: I1011 03:30:42.322040       1 controller.go:647] successfully created PV {GCEPersistentDisk:nil AWSElasticBlockStore:nil HostPath:nil Glusterfs:nil NFS:nil RBD:nil ISCSI:nil Cinder:nil CephFS:nil FC:nil Flocker:nil FlexVolume:nil AzureFile:nil VsphereVolume:nil Quobyte:nil AzureDisk:nil PhotonPersistentDisk:nil PortworxVolume:nil ScaleIO:nil Local:nil StorageOS:nil CSI:&CSIPersistentVolumeSource{Driver:net.packet.csi,VolumeHandle:c3903862-edf9-4ea4-aec9-8316dafd86ce,ReadOnly:false,FSType:ext4,VolumeAttributes:map[string]string{storage.kubernetes.io/csiProvisionerIdentity: 1570763474066-8081-net.packet.csi,},ControllerPublishSecretRef:nil,NodeStageSecretRef:nil,NodePublishSecretRef:nil,ControllerExpandSecretRef:nil,}}
kube-system/csi-packet-controller-0[csi-external-provisioner]: I1011 03:30:42.322420       1 controller.go:1281] provision "akash-sanity-1570764633/sanity-pvc" class "standard": volume "pvc-14d8fa66-fe5b-4cd3-9f69-80c7a8e41d25" provisioned
kube-system/csi-packet-controller-0[csi-external-provisioner]: I1011 03:30:42.322526       1 controller.go:1298] provision "akash-sanity-1570764633/sanity-pvc" class "standard": succeeded
kube-system/csi-packet-controller-0[csi-external-provisioner]: I1011 03:30:42.322560       1 volume_store.go:154] Saving volume pvc-14d8fa66-fe5b-4cd3-9f69-80c7a8e41d25
kube-system/csi-packet-controller-0[csi-external-provisioner]: I1011 03:30:42.341972       1 volume_store.go:157] Volume pvc-14d8fa66-fe5b-4cd3-9f69-80c7a8e41d25 saved
kube-system/csi-packet-controller-0[csi-external-provisioner]: I1011 03:30:42.342094       1 controller.go:1014] Claim processing succeeded, removing PVC 14d8fa66-fe5b-4cd3-9f69-80c7a8e41d25 from claims in progress
kube-system/csi-packet-controller-0[csi-external-provisioner]: I1011 03:30:42.342861       1 event.go:255] Event(v1.ObjectReference{Kind:"PersistentVolumeClaim", Namespace:"akash-sanity-1570764633", Name:"sanity-pvc", UID:"14d8fa66-fe5b-4cd3-9f69-80c7a8e41d25", APIVersion:"v1", ResourceVersion:"15959", FieldPath:""}): type: 'Normal' reason: 'ProvisioningSucceeded' Successfully provisioned volume pvc-14d8fa66-fe5b-4cd3-9f69-80c7a8e41d25
kube-system/csi-packet-controller-0[csi-attacher]: I1011 03:30:45.281007       1 controller.go:175] Started VA processing "csi-a49bfedcb5147ff1e7011adebce879954a14b6860eb64c3d00b7b73c430a0b7a"
kube-system/csi-packet-controller-0[csi-attacher]: I1011 03:30:45.281044       1 csi_handler.go:89] CSIHandler: processing VA "csi-a49bfedcb5147ff1e7011adebce879954a14b6860eb64c3d00b7b73c430a0b7a"
kube-system/csi-packet-controller-0[csi-attacher]: I1011 03:30:45.281064       1 csi_handler.go:116] Attaching "csi-a49bfedcb5147ff1e7011adebce879954a14b6860eb64c3d00b7b73c430a0b7a"
kube-system/csi-packet-controller-0[csi-attacher]: I1011 03:30:45.281082       1 csi_handler.go:249] Starting attach operation for "csi-a49bfedcb5147ff1e7011adebce879954a14b6860eb64c3d00b7b73c430a0b7a"
kube-system/csi-packet-controller-0[csi-attacher]: I1011 03:30:45.281197       1 csi_handler.go:215] Adding finalizer to PV "pvc-14d8fa66-fe5b-4cd3-9f69-80c7a8e41d25"
kube-system/csi-packet-controller-0[csi-attacher]: I1011 03:30:45.290012       1 csi_handler.go:224] PV finalizer added to "pvc-14d8fa66-fe5b-4cd3-9f69-80c7a8e41d25"
kube-system/csi-packet-controller-0[csi-attacher]: I1011 03:30:45.290060       1 csi_handler.go:542] Found NodeID k1.ovrclk.net in CSINode k1.ovrclk.net
kube-system/csi-packet-controller-0[csi-attacher]: I1011 03:30:45.290779       1 csi_handler.go:177] VA finalizer added to "csi-a49bfedcb5147ff1e7011adebce879954a14b6860eb64c3d00b7b73c430a0b7a"
kube-system/csi-packet-controller-0[csi-attacher]: I1011 03:30:45.290855       1 csi_handler.go:191] NodeID annotation added to "csi-a49bfedcb5147ff1e7011adebce879954a14b6860eb64c3d00b7b73c430a0b7a"
kube-system/csi-packet-controller-0[csi-attacher]: I1011 03:30:45.292232       1 controller.go:205] Started PV processing "pvc-14d8fa66-fe5b-4cd3-9f69-80c7a8e41d25"
kube-system/csi-packet-controller-0[csi-attacher]: I1011 03:30:45.292293       1 csi_handler.go:444] CSIHandler: processing PV "pvc-14d8fa66-fe5b-4cd3-9f69-80c7a8e41d25"
kube-system/csi-packet-controller-0[csi-attacher]: I1011 03:30:45.292322       1 csi_handler.go:448] CSIHandler: processing PV "pvc-14d8fa66-fe5b-4cd3-9f69-80c7a8e41d25": no deletion timestamp, ignoring
kube-system/csi-packet-controller-0[csi-attacher]: I1011 03:30:45.299528       1 connection.go:180] GRPC call: /csi.v1.Controller/ControllerPublishVolume
kube-system/csi-packet-controller-0[csi-attacher]: I1011 03:30:45.299562       1 connection.go:181] GRPC request: {"node_id":"k1.ovrclk.net","volume_capability":{"AccessType":{"Mount":{"fs_type":"ext4"}},"access_mode":{"mode":1}},"volume_context":{"storage.kubernetes.io/csiProvisionerIdentity":"1570763474066-8081-net.packet.csi"},"volume_id":"c3903862-edf9-4ea4-aec9-8316dafd86ce"}
kube-system/csi-packet-controller-0[packet-driver]: {"GRPC.call":"/csi.v1.Controller/ControllerPublishVolume","GRPC.request":"volume_id:\"c3903862-edf9-4ea4-aec9-8316dafd86ce\" node_id:\"k1.ovrclk.net\" volume_capability:\u003cmount:\u003cfs_type:\"ext4\" \u003e access_mode:\u003cmode:SINGLE_NODE_WRITER \u003e \u003e volume_context:\u003ckey:\"storage.kubernetes.io/csiProvisionerIdentity\" value:\"1570763474066-8081-net.packet.csi\" \u003e ","level":"info","msg":"GRPC response: publish_context:\u003ckey:\"AttachmentId\" value:\"5c6b903a-847e-4303-a4d3-519f1eb1a3ee\" \u003e publish_context:\u003ckey:\"VolumeId\" value:\"c3903862-edf9-4ea4-aec9-8316dafd86ce\" \u003e publish_context:\u003ckey:\"VolumeName\" value:\"volume-c3903862\" \u003e ","time":"2019-10-11T03:30:52Z"}
kube-system/csi-packet-controller-0[csi-attacher]: I1011 03:30:52.519087       1 connection.go:183] GRPC response: {"publish_context":{"AttachmentId":"5c6b903a-847e-4303-a4d3-519f1eb1a3ee","VolumeId":"c3903862-edf9-4ea4-aec9-8316dafd86ce","VolumeName":"volume-c3903862"}}
kube-system/csi-packet-controller-0[csi-attacher]: I1011 03:30:52.520636       1 connection.go:184] GRPC error: <nil>
kube-system/csi-packet-controller-0[csi-attacher]: I1011 03:30:52.520672       1 csi_handler.go:129] Attached "csi-a49bfedcb5147ff1e7011adebce879954a14b6860eb64c3d00b7b73c430a0b7a"
kube-system/csi-packet-controller-0[csi-attacher]: I1011 03:30:52.520694       1 util.go:35] Marking as attached "csi-a49bfedcb5147ff1e7011adebce879954a14b6860eb64c3d00b7b73c430a0b7a"
kube-system/csi-packet-controller-0[csi-attacher]: I1011 03:30:52.526276       1 util.go:48] Marked as attached "csi-a49bfedcb5147ff1e7011adebce879954a14b6860eb64c3d00b7b73c430a0b7a"
kube-system/csi-packet-controller-0[csi-attacher]: I1011 03:30:52.526341       1 csi_handler.go:135] Fully attached "csi-a49bfedcb5147ff1e7011adebce879954a14b6860eb64c3d00b7b73c430a0b7a"
kube-system/csi-packet-controller-0[csi-attacher]: I1011 03:30:52.526370       1 csi_handler.go:105] CSIHandler: finished processing "csi-a49bfedcb5147ff1e7011adebce879954a14b6860eb64c3d00b7b73c430a0b7a"
kube-system/csi-packet-controller-0[csi-attacher]: I1011 03:30:52.526470       1 controller.go:175] Started VA processing "csi-a49bfedcb5147ff1e7011adebce879954a14b6860eb64c3d00b7b73c430a0b7a"
kube-system/csi-packet-controller-0[csi-attacher]: I1011 03:30:52.526508       1 csi_handler.go:89] CSIHandler: processing VA "csi-a49bfedcb5147ff1e7011adebce879954a14b6860eb64c3d00b7b73c430a0b7a"
kube-system/csi-packet-controller-0[csi-attacher]: I1011 03:30:52.526535       1 csi_handler.go:116] Attaching "csi-a49bfedcb5147ff1e7011adebce879954a14b6860eb64c3d00b7b73c430a0b7a"
kube-system/csi-packet-controller-0[csi-attacher]: I1011 03:30:52.526563       1 csi_handler.go:249] Starting attach operation for "csi-a49bfedcb5147ff1e7011adebce879954a14b6860eb64c3d00b7b73c430a0b7a"
kube-system/csi-packet-controller-0[csi-attacher]: I1011 03:30:52.526714       1 csi_handler.go:209] PV finalizer is already set on "pvc-14d8fa66-fe5b-4cd3-9f69-80c7a8e41d25"
kube-system/csi-packet-controller-0[csi-attacher]: I1011 03:30:52.526768       1 csi_handler.go:542] Found NodeID k1.ovrclk.net in CSINode k1.ovrclk.net
kube-system/csi-packet-controller-0[csi-attacher]: I1011 03:30:52.526814       1 csi_handler.go:169] VA finalizer is already set on "csi-a49bfedcb5147ff1e7011adebce879954a14b6860eb64c3d00b7b73c430a0b7a"
kube-system/csi-packet-controller-0[csi-attacher]: I1011 03:30:52.526839       1 csi_handler.go:183] NodeID annotation is already set on "csi-a49bfedcb5147ff1e7011adebce879954a14b6860eb64c3d00b7b73c430a0b7a"
kube-system/csi-packet-controller-0[csi-attacher]: I1011 03:30:52.526875       1 connection.go:180] GRPC call: /csi.v1.Controller/ControllerPublishVolume
kube-system/csi-packet-controller-0[csi-attacher]: I1011 03:30:52.526888       1 connection.go:181] GRPC request: {"node_id":"k1.ovrclk.net","volume_capability":{"AccessType":{"Mount":{"fs_type":"ext4"}},"access_mode":{"mode":1}},"volume_context":{"storage.kubernetes.io/csiProvisionerIdentity":"1570763474066-8081-net.packet.csi"},"volume_id":"c3903862-edf9-4ea4-aec9-8316dafd86ce"}
kube-system/csi-node-x845j[packet-driver]: {"endpoint":"unix:///csi/csi.sock","level":"info","msg":"NodeGetCapabilities called","node":"k1.ovrclk.net","time":"2019-10-11T03:30:53Z"}
kube-system/csi-node-x845j[packet-driver]: {"GRPC.call":"/csi.v1.Node/NodeGetCapabilities","GRPC.request":"","level":"info","msg":"GRPC response: capabilities:\u003crpc:\u003ctype:STAGE_UNSTAGE_VOLUME \u003e \u003e ","time":"2019-10-11T03:30:53Z"}
kube-system/csi-node-x845j[packet-driver]: {"endpoint":"unix:///csi/csi.sock","level":"info","msg":"NodeStageVolume called","node":"k1.ovrclk.net","time":"2019-10-11T03:30:53Z"}
kube-system/csi-node-x845j[packet-driver]: {"args":"--mode session","command":"iscsiadm","error":"exit status 21","level":"error","msg":"Error","out":"iscsiadm: No active sessions.\n","time":"2019-10-11T03:30:53Z"}
kube-system/csi-node-x845j[packet-driver]: {"endpoint":"unix:///csi/csi.sock","fsType":"ext4","level":"info","method":"NodeStageVolume","msg":"devicePath error, file not found for pattern /dev/disk/by-path/*10.144.144.216*iqn.2013-05.com.daterainc:tc:01:sn:e7817a47612d37b5*","node":"k1.ovrclk.net","staging_target_path":"/var/lib/rancher/k3s/agent/kubelet/plugins/kubernetes.io/csi/pv/pvc-14d8fa66-fe5b-4cd3-9f69-80c7a8e41d25/globalmount","time":"2019-10-11T03:30:53Z","volume_id":"c3903862-edf9-4ea4-aec9-8316dafd86ce","volume_name":"volume-c3903862"}
kube-system/csi-node-x845j[packet-driver]: {"GRPC.call":"/csi.v1.Node/NodeStageVolume","GRPC.request":"volume_id:\"c3903862-edf9-4ea4-aec9-8316dafd86ce\" publish_context:\u003ckey:\"AttachmentId\" value:\"5c6b903a-847e-4303-a4d3-519f1eb1a3ee\" \u003e publish_context:\u003ckey:\"VolumeId\" value:\"c3903862-edf9-4ea4-aec9-8316dafd86ce\" \u003e publish_context:\u003ckey:\"VolumeName\" value:\"volume-c3903862\" \u003e staging_target_path:\"/var/lib/rancher/k3s/agent/kubelet/plugins/kubernetes.io/csi/pv/pvc-14d8fa66-fe5b-4cd3-9f69-80c7a8e41d25/globalmount\" volume_capability:\u003cmount:\u003cfs_type:\"ext4\" \u003e access_mode:\u003cmode:SINGLE_NODE_WRITER \u003e \u003e volume_context:\u003ckey:\"storage.kubernetes.io/csiProvisionerIdentity\" value:\"1570763474066-8081-net.packet.csi\" \u003e ","level":"error","msg":"GRPC error: rpc error: code = Unknown desc = devicePath error, file not found for pattern /dev/disk/by-path/*10.144.144.216*iqn.2013-05.com.daterainc:tc:01:sn:e7817a47612d37b5*","time":"2019-10-11T03:30:53Z"}
kube-system/csi-node-x845j[packet-driver]: {"endpoint":"unix:///csi/csi.sock","level":"info","msg":"NodeGetCapabilities called","node":"k1.ovrclk.net","time":"2019-10-11T03:30:54Z"}
kube-system/csi-node-x845j[packet-driver]: {"GRPC.call":"/csi.v1.Node/NodeGetCapabilities","GRPC.request":"","level":"info","msg":"GRPC response: capabilities:\u003crpc:\u003ctype:STAGE_UNSTAGE_VOLUME \u003e \u003e ","time":"2019-10-11T03:30:54Z"}
kube-system/csi-node-x845j[packet-driver]: {"endpoint":"unix:///csi/csi.sock","level":"info","msg":"NodeStageVolume called","node":"k1.ovrclk.net","time":"2019-10-11T03:30:54Z"}
kube-system/csi-packet-controller-0[packet-driver]: {"GRPC.call":"/csi.v1.Controller/ControllerPublishVolume","GRPC.request":"volume_id:\"c3903862-edf9-4ea4-aec9-8316dafd86ce\" node_id:\"k1.ovrclk.net\" volume_capability:\u003cmount:\u003cfs_type:\"ext4\" \u003e access_mode:\u003cmode:SINGLE_NODE_WRITER \u003e \u003e volume_context:\u003ckey:\"storage.kubernetes.io/csiProvisionerIdentity\" value:\"1570763474066-8081-net.packet.csi\" \u003e ","level":"error","msg":"GRPC error: rpc error: code = Unknown desc = error attempting to attach c3903862-edf9-4ea4-aec9-8316dafd86ce to bdd3116a-d9ee-4cd7-8076-32fec16976fe, POST https://api.packet.net/storage/c3903862-edf9-4ea4-aec9-8316dafd86ce/attachments: 422 Instance is already attached to this volume ","time":"2019-10-11T03:30:56Z"}
kube-system/csi-packet-controller-0[csi-attacher]: I1011 03:30:56.221205       1 connection.go:183] GRPC response: {}
kube-system/csi-packet-controller-0[csi-attacher]: I1011 03:30:56.222594       1 connection.go:184] GRPC error: rpc error: code = Unknown desc = error attempting to attach c3903862-edf9-4ea4-aec9-8316dafd86ce to bdd3116a-d9ee-4cd7-8076-32fec16976fe, POST https://api.packet.net/storage/c3903862-edf9-4ea4-aec9-8316dafd86ce/attachments: 422 Instance is already attached to this volume
kube-system/csi-packet-controller-0[csi-attacher]: I1011 03:30:56.222646       1 csi_handler.go:412] Saving attach error to "csi-a49bfedcb5147ff1e7011adebce879954a14b6860eb64c3d00b7b73c430a0b7a"
kube-system/csi-packet-controller-0[csi-attacher]: I1011 03:30:56.229083       1 csi_handler.go:423] Saved attach error to "csi-a49bfedcb5147ff1e7011adebce879954a14b6860eb64c3d00b7b73c430a0b7a"
kube-system/csi-packet-controller-0[csi-attacher]: I1011 03:30:56.229194       1 csi_handler.go:99] Error processing "csi-a49bfedcb5147ff1e7011adebce879954a14b6860eb64c3d00b7b73c430a0b7a": failed to attach: rpc error: code = Unknown desc = error attempting to attach c3903862-edf9-4ea4-aec9-8316dafd86ce to bdd3116a-d9ee-4cd7-8076-32fec16976fe, POST https://api.packet.net/storage/c3903862-edf9-4ea4-aec9-8316dafd86ce/attachments: 422 Instance is already attached to this volume
kube-system/csi-packet-controller-0[csi-attacher]: I1011 03:30:56.229306       1 controller.go:175] Started VA processing "csi-a49bfedcb5147ff1e7011adebce879954a14b6860eb64c3d00b7b73c430a0b7a"
kube-system/csi-packet-controller-0[csi-attacher]: I1011 03:30:56.229373       1 csi_handler.go:89] CSIHandler: processing VA "csi-a49bfedcb5147ff1e7011adebce879954a14b6860eb64c3d00b7b73c430a0b7a"
kube-system/csi-packet-controller-0[csi-attacher]: I1011 03:30:56.229400       1 csi_handler.go:111] "csi-a49bfedcb5147ff1e7011adebce879954a14b6860eb64c3d00b7b73c430a0b7a" is already attached
kube-system/csi-packet-controller-0[csi-attacher]: I1011 03:30:56.229442       1 csi_handler.go:105] CSIHandler: finished processing "csi-a49bfedcb5147ff1e7011adebce879954a14b6860eb64c3d00b7b73c430a0b7a"
kube-system/csi-packet-controller-0[csi-attacher]: I1011 03:30:56.229901       1 controller.go:141] Ignoring VolumeAttachment "csi-a49bfedcb5147ff1e7011adebce879954a14b6860eb64c3d00b7b73c430a0b7a" change
kube-system/csi-packet-controller-0[csi-attacher]: I1011 03:30:57.229493       1 controller.go:175] Started VA processing "csi-a49bfedcb5147ff1e7011adebce879954a14b6860eb64c3d00b7b73c430a0b7a"
kube-system/csi-packet-controller-0[csi-attacher]: I1011 03:30:57.229546       1 csi_handler.go:89] CSIHandler: processing VA "csi-a49bfedcb5147ff1e7011adebce879954a14b6860eb64c3d00b7b73c430a0b7a"
kube-system/csi-packet-controller-0[csi-attacher]: I1011 03:30:57.229571       1 csi_handler.go:111] "csi-a49bfedcb5147ff1e7011adebce879954a14b6860eb64c3d00b7b73c430a0b7a" is already attached
kube-system/csi-packet-controller-0[csi-attacher]: I1011 03:30:57.229591       1 csi_handler.go:105] CSIHandler: finished processing "csi-a49bfedcb5147ff1e7011adebce879954a14b6860eb64c3d00b7b73c430a0b7a"
kube-system/csi-node-x845j[packet-driver]: {"args":"-f mpatha","level":"info","msg":"multipath timed out","time":"2019-10-11T03:31:04Z","timeout":10000000000}
kube-system/csi-packet-controller-0[csi-attacher]: I1011 03:31:13.434296       1 reflector.go:235] k8s.io/client-go/informers/factory.go:133: forcing resync
kube-system/csi-packet-controller-0[csi-attacher]: I1011 03:31:13.434310       1 reflector.go:235] k8s.io/client-go/informers/factory.go:133: forcing resync
kube-system/csi-packet-controller-0[csi-attacher]: I1011 03:31:13.434432       1 controller.go:175] Started VA processing "csi-a49bfedcb5147ff1e7011adebce879954a14b6860eb64c3d00b7b73c430a0b7a"
kube-system/csi-packet-controller-0[csi-attacher]: I1011 03:31:13.434472       1 csi_handler.go:89] CSIHandler: processing VA "csi-a49bfedcb5147ff1e7011adebce879954a14b6860eb64c3d00b7b73c430a0b7a"
kube-system/csi-packet-controller-0[csi-attacher]: I1011 03:31:13.434478       1 controller.go:205] Started PV processing "pvc-14d8fa66-fe5b-4cd3-9f69-80c7a8e41d25"
kube-system/csi-packet-controller-0[csi-attacher]: I1011 03:31:13.434489       1 csi_handler.go:111] "csi-a49bfedcb5147ff1e7011adebce879954a14b6860eb64c3d00b7b73c430a0b7a" is already attached
kube-system/csi-packet-controller-0[csi-attacher]: I1011 03:31:13.434515       1 csi_handler.go:105] CSIHandler: finished processing "csi-a49bfedcb5147ff1e7011adebce879954a14b6860eb64c3d00b7b73c430a0b7a"
kube-system/csi-packet-controller-0[csi-attacher]: I1011 03:31:13.434515       1 csi_handler.go:444] CSIHandler: processing PV "pvc-14d8fa66-fe5b-4cd3-9f69-80c7a8e41d25"
kube-system/csi-packet-controller-0[csi-attacher]: I1011 03:31:13.434571       1 csi_handler.go:448] CSIHandler: processing PV "pvc-14d8fa66-fe5b-4cd3-9f69-80c7a8e41d25": no deletion timestamp, ignoring
kube-system/csi-node-x845j[packet-driver]: {"args":"volume-c3903862","level":"info","msg":"multipath timed out","time":"2019-10-11T03:31:14Z","timeout":10000000000}
kube-system/csi-node-x845j[packet-driver]: {"endpoint":"unix:///csi/csi.sock","fsType":"ext4","level":"info","method":"NodeStageVolume","msg":"multipath check for /dev/sdc: volume-c3903862 (3600140536d80fbfbc06490b9a214ef52) dm-0 DATERA,IBLOCK\nsize=10G features='1 queue_if_no_path' hwhandler='1 alua' wp=rw\n`-+- policy='round-robin 0' prio=50 status=active\n  |- 8:0:0:0 sdc 8:32 active ready running\n  `- 9:0:0:0 sdd 8:48 active ready running\n","node":"k1.ovrclk.net","staging_target_path":"/var/lib/rancher/k3s/agent/kubelet/plugins/kubernetes.io/csi/pv/pvc-14d8fa66-fe5b-4cd3-9f69-80c7a8e41d25/globalmount","time":"2019-10-11T03:31:14Z","volume_id":"c3903862-edf9-4ea4-aec9-8316dafd86ce","volume_name":"volume-c3903862"}
kube-system/csi-node-x845j[packet-driver]: {"endpoint":"unix:///csi/csi.sock","fsType":"ext4","level":"info","method":"NodeStageVolume","msg":"mounting mapped device","node":"k1.ovrclk.net","staging_target_path":"/var/lib/rancher/k3s/agent/kubelet/plugins/kubernetes.io/csi/pv/pvc-14d8fa66-fe5b-4cd3-9f69-80c7a8e41d25/globalmount","time":"2019-10-11T03:31:15Z","volume_id":"c3903862-edf9-4ea4-aec9-8316dafd86ce","volume_name":"volume-c3903862"}
kube-system/csi-node-x845j[packet-driver]: {"endpoint":"unix:///csi/csi.sock","fsType":"ext4","level":"info","method":"NodeStageVolume","msg":"NodeStageVolume complete","node":"k1.ovrclk.net","staging_target_path":"/var/lib/rancher/k3s/agent/kubelet/plugins/kubernetes.io/csi/pv/pvc-14d8fa66-fe5b-4cd3-9f69-80c7a8e41d25/globalmount","time":"2019-10-11T03:31:15Z","volume_id":"c3903862-edf9-4ea4-aec9-8316dafd86ce","volume_name":"volume-c3903862"}
kube-system/csi-node-x845j[packet-driver]: {"GRPC.call":"/csi.v1.Node/NodeStageVolume","GRPC.request":"volume_id:\"c3903862-edf9-4ea4-aec9-8316dafd86ce\" publish_context:\u003ckey:\"AttachmentId\" value:\"5c6b903a-847e-4303-a4d3-519f1eb1a3ee\" \u003e publish_context:\u003ckey:\"VolumeId\" value:\"c3903862-edf9-4ea4-aec9-8316dafd86ce\" \u003e publish_context:\u003ckey:\"VolumeName\" value:\"volume-c3903862\" \u003e staging_target_path:\"/var/lib/rancher/k3s/agent/kubelet/plugins/kubernetes.io/csi/pv/pvc-14d8fa66-fe5b-4cd3-9f69-80c7a8e41d25/globalmount\" volume_capability:\u003cmount:\u003cfs_type:\"ext4\" \u003e access_mode:\u003cmode:SINGLE_NODE_WRITER \u003e \u003e volume_context:\u003ckey:\"storage.kubernetes.io/csiProvisionerIdentity\" value:\"1570763474066-8081-net.packet.csi\" \u003e ","level":"info","msg":"GRPC response: ","time":"2019-10-11T03:31:15Z"}
kube-system/csi-node-x845j[packet-driver]: {"endpoint":"unix:///csi/csi.sock","level":"info","msg":"NodeGetCapabilities called","node":"k1.ovrclk.net","time":"2019-10-11T03:31:15Z"}
kube-system/csi-node-x845j[packet-driver]: {"GRPC.call":"/csi.v1.Node/NodeGetCapabilities","GRPC.request":"","level":"info","msg":"GRPC response: capabilities:\u003crpc:\u003ctype:STAGE_UNSTAGE_VOLUME \u003e \u003e ","time":"2019-10-11T03:31:15Z"}
kube-system/csi-node-x845j[packet-driver]: {"endpoint":"unix:///csi/csi.sock","level":"info","msg":"NodePublishVolume called","node":"k1.ovrclk.net","time":"2019-10-11T03:31:15Z"}
kube-system/csi-node-x845j[packet-driver]: {"endpoint":"unix:///csi/csi.sock","level":"info","method":"NodePublishVolume","msg":"bind mount complete","node":"k1.ovrclk.net","staging_target_path":"/var/lib/rancher/k3s/agent/kubelet/plugins/kubernetes.io/csi/pv/pvc-14d8fa66-fe5b-4cd3-9f69-80c7a8e41d25/globalmount","target_path":"/var/lib/rancher/k3s/agent/kubelet/pods/9f78f5be-9318-46d0-af74-7dde874794fc/volumes/kubernetes.io~csi/pvc-14d8fa66-fe5b-4cd3-9f69-80c7a8e41d25/mount","time":"2019-10-11T03:31:15Z","volume_id":"c3903862-edf9-4ea4-aec9-8316dafd86ce"}

[deitch]

Yes, multipath is the remaining issue. With iscsi, we were able to override the default config by configuring and passing an iface, which works. Without that, you would need to set the config file and then restart iscsid. Restarting an iscsid which is running outside the container from a process running inside the container is extraordinarily convoluted, if doable at all. The fact that you don't even know what system is controlling it - systemd, rc.init, something else - is more mess.

multipathd, on the other hand, really does care about its config file, but doesn't reload it automatically.

Working on it.

[gosuri]

Great! Thank you

[gosuri]

The latest push is failing with:

MountVolume.MountDevice failed for volume "pvc-f715cd2b-d69d-4f13-962b-4dffc29417a1" : rpc error: code = Unknown desc = devicePath error, file not found for pattern /dev/disk/by-path/*10.144.144.12*iqn.2013-05.com.daterainc:tc:01:sn:40cae22d5ad05998*

Logs

kube-system/tiller-deploy-767d9b9584-gwfjt[tiller]: [tiller] 2019/10/14 09:17:46 preparing install for csi-packet
kube-system/tiller-deploy-767d9b9584-gwfjt[tiller]: [storage] 2019/10/14 09:17:46 getting release history for "csi-packet"
kube-system/tiller-deploy-767d9b9584-gwfjt[tiller]: [tiller] 2019/10/14 09:17:46 rendering csi-packet chart using values
kube-system/tiller-deploy-767d9b9584-gwfjt[tiller]: 2019/10/14 09:17:46 info: manifest "csi-packet/templates/packet-secret.yml" is empty. Skipping.
kube-system/tiller-deploy-767d9b9584-gwfjt[tiller]: [tiller] 2019/10/14 09:17:46 performing install for csi-packet
kube-system/tiller-deploy-767d9b9584-gwfjt[tiller]: [tiller] 2019/10/14 09:17:46 executing 0 crd-install hooks for csi-packet
kube-system/tiller-deploy-767d9b9584-gwfjt[tiller]: [tiller] 2019/10/14 09:17:46 hooks complete for crd-install csi-packet
kube-system/tiller-deploy-767d9b9584-gwfjt[tiller]: [tiller] 2019/10/14 09:17:46 executing 0 pre-install hooks for csi-packet
kube-system/tiller-deploy-767d9b9584-gwfjt[tiller]: [tiller] 2019/10/14 09:17:46 hooks complete for pre-install csi-packet
kube-system/tiller-deploy-767d9b9584-gwfjt[tiller]: [storage] 2019/10/14 09:17:46 getting release history for "csi-packet"
kube-system/tiller-deploy-767d9b9584-gwfjt[tiller]: [storage] 2019/10/14 09:17:46 creating release "csi-packet.v1"
kube-system/tiller-deploy-767d9b9584-gwfjt[tiller]: [kube] 2019/10/14 09:17:46 building resources from manifest
kube-system/tiller-deploy-767d9b9584-gwfjt[tiller]: [kube] 2019/10/14 09:17:46 creating 13 resource(s)
kube-system/tiller-deploy-767d9b9584-gwfjt[tiller]: [tiller] 2019/10/14 09:17:46 executing 0 post-install hooks for csi-packet
kube-system/tiller-deploy-767d9b9584-gwfjt[tiller]: [tiller] 2019/10/14 09:17:46 hooks complete for post-install csi-packet
kube-system/tiller-deploy-767d9b9584-gwfjt[tiller]: [storage] 2019/10/14 09:17:46 updating release "csi-packet.v1"
kube-system/tiller-deploy-767d9b9584-gwfjt[tiller]: [storage] 2019/10/14 09:17:46 getting last revision of "csi-packet"
kube-system/tiller-deploy-767d9b9584-gwfjt[tiller]: [storage] 2019/10/14 09:17:46 getting release history for "csi-packet"
kube-system/tiller-deploy-767d9b9584-gwfjt[tiller]: [kube] 2019/10/14 09:17:46 Doing get for StorageClass: "performance"
kube-system/tiller-deploy-767d9b9584-gwfjt[tiller]: [kube] 2019/10/14 09:17:46 get relation pod of object: /StorageClass/performance
kube-system/tiller-deploy-767d9b9584-gwfjt[tiller]: [kube] 2019/10/14 09:17:46 Doing get for StorageClass: "standard"
kube-system/tiller-deploy-767d9b9584-gwfjt[tiller]: [kube] 2019/10/14 09:17:46 get relation pod of object: /StorageClass/standard
kube-system/tiller-deploy-767d9b9584-gwfjt[tiller]: [kube] 2019/10/14 09:17:46 Doing get for ServiceAccount: "csi-node-sa"
kube-system/tiller-deploy-767d9b9584-gwfjt[tiller]: [kube] 2019/10/14 09:17:46 get relation pod of object: kube-system/ServiceAccount/csi-node-sa
kube-system/tiller-deploy-767d9b9584-gwfjt[tiller]: [kube] 2019/10/14 09:17:46 Doing get for ServiceAccount: "csi-controller-sa"
kube-system/tiller-deploy-767d9b9584-gwfjt[tiller]: [kube] 2019/10/14 09:17:46 get relation pod of object: kube-system/ServiceAccount/csi-controller-sa
kube-system/tiller-deploy-767d9b9584-gwfjt[tiller]: [kube] 2019/10/14 09:17:46 Doing get for ClusterRole: "csi-external-attacher"
kube-system/tiller-deploy-767d9b9584-gwfjt[tiller]: [kube] 2019/10/14 09:17:46 get relation pod of object: /ClusterRole/csi-external-attacher
kube-system/tiller-deploy-767d9b9584-gwfjt[tiller]: [kube] 2019/10/14 09:17:46 Doing get for ClusterRole: "csi-external-provisioner"
kube-system/tiller-deploy-767d9b9584-gwfjt[tiller]: [kube] 2019/10/14 09:17:46 get relation pod of object: /ClusterRole/csi-external-provisioner
kube-system/tiller-deploy-767d9b9584-gwfjt[tiller]: [kube] 2019/10/14 09:17:46 Doing get for ClusterRole: "driver-registrar-role"
kube-system/tiller-deploy-767d9b9584-gwfjt[tiller]: [kube] 2019/10/14 09:17:46 get relation pod of object: /ClusterRole/driver-registrar-role
kube-system/tiller-deploy-767d9b9584-gwfjt[tiller]: [kube] 2019/10/14 09:17:46 Doing get for ClusterRoleBinding: "driver-registrar-binding"
kube-system/tiller-deploy-767d9b9584-gwfjt[tiller]: [kube] 2019/10/14 09:17:46 get relation pod of object: /ClusterRoleBinding/driver-registrar-binding
kube-system/tiller-deploy-767d9b9584-gwfjt[tiller]: [kube] 2019/10/14 09:17:46 Doing get for ClusterRoleBinding: "csi-controller-attacher-binding"
kube-system/tiller-deploy-767d9b9584-gwfjt[tiller]: [kube] 2019/10/14 09:17:46 get relation pod of object: /ClusterRoleBinding/csi-controller-attacher-binding
kube-system/tiller-deploy-767d9b9584-gwfjt[tiller]: [kube] 2019/10/14 09:17:46 Doing get for ClusterRoleBinding: "csi-controller-provisioner-binding"
kube-system/tiller-deploy-767d9b9584-gwfjt[tiller]: [kube] 2019/10/14 09:17:46 get relation pod of object: /ClusterRoleBinding/csi-controller-provisioner-binding
kube-system/tiller-deploy-767d9b9584-gwfjt[tiller]: [kube] 2019/10/14 09:17:46 Doing get for Service: "csi-packet-pd"
kube-system/tiller-deploy-767d9b9584-gwfjt[tiller]: [kube] 2019/10/14 09:17:46 get relation pod of object: default/Service/csi-packet-pd
kube-system/tiller-deploy-767d9b9584-gwfjt[tiller]: [kube] 2019/10/14 09:17:46 Doing get for DaemonSet: "csi-node"
kube-system/tiller-deploy-767d9b9584-gwfjt[tiller]: [kube] 2019/10/14 09:17:46 get relation pod of object: kube-system/DaemonSet/csi-node
kube-system/tiller-deploy-767d9b9584-gwfjt[tiller]: [kube] 2019/10/14 09:17:46 Doing get for StatefulSet: "csi-packet-controller"
kube-system/tiller-deploy-767d9b9584-gwfjt[tiller]: [kube] 2019/10/14 09:17:46 get relation pod of object: kube-system/StatefulSet/csi-packet-controller
kube-system/csi-packet-controller-0[packet-driver]: {"facility_id":"2b70eb8f-fa18-47c0-aba7-222a842362fd","level":"info","msg":"facility found","project_id":"48e3616c-8a10-4aa5-8d39-ec6cb2cd8014","time":"2019-10-14T09:17:53Z"}
kube-system/csi-packet-controller-0[packet-driver]: {"endpoint":"unix:////csi/csi.sock","level":"info","msg":"Starting server","node":"k1.ovrclk.net","time":"2019-10-14T09:17:53Z"}
kube-system/csi-packet-controller-0[packet-driver]: {"address":"///csi/csi.sock","level":"info","msg":"Listening for connections","proto":"unix","time":"2019-10-14T09:17:53Z"}
kube-system/csi-packet-controller-0[csi-attacher]: I1014 09:17:54.104532       1 common.go:111] Probing CSI driver for readiness
kube-system/csi-packet-controller-0[packet-driver]: {"level":"info","msg":"PacketIdentityServer.Probe called with args: \u0026csi.ProbeRequest{XXX_NoUnkeyedLiteral:struct {}{}, XXX_unrecognized:[]uint8(nil), XXX_sizecache:0}","time":"2019-10-14T09:17:54Z"}
kube-system/csi-packet-controller-0[packet-driver]: {"GRPC.call":"/csi.v1.Identity/Probe","GRPC.request":"","level":"info","msg":"GRPC response: ","time":"2019-10-14T09:17:54Z"}
kube-system/csi-packet-controller-0[packet-driver]: {"level":"info","msg":"PacketIdentityServer.GetPluginInfo called","time":"2019-10-14T09:17:54Z"}
kube-system/csi-packet-controller-0[packet-driver]: {"GRPC.call":"/csi.v1.Identity/GetPluginInfo","GRPC.request":"","level":"info","msg":"GRPC response: name:\"net.packet.csi\" vendor_version:\"beb1628\" ","time":"2019-10-14T09:17:54Z"}
kube-system/csi-packet-controller-0[packet-driver]: {"level":"info","msg":"PacketIdentityServer.GetPluginCapabilities called","time":"2019-10-14T09:17:54Z"}
kube-system/csi-packet-controller-0[packet-driver]: {"GRPC.call":"/csi.v1.Identity/GetPluginCapabilities","GRPC.request":"","level":"info","msg":"GRPC response: capabilities:\u003cservice:\u003ctype:CONTROLLER_SERVICE \u003e \u003e ","time":"2019-10-14T09:17:54Z"}
kube-system/csi-packet-controller-0[csi-attacher]: I1014 09:17:54.104596       1 connection.go:180] GRPC call: /csi.v1.Identity/Probe
kube-system/csi-packet-controller-0[csi-attacher]: I1014 09:17:54.104618       1 connection.go:181] GRPC request: {}
kube-system/csi-packet-controller-0[csi-attacher]: I1014 09:17:54.109672       1 connection.go:183] GRPC response: {}
kube-system/csi-node-tx8dw[csi-driver-registrar]: I1014 09:17:53.936613       1 main.go:127] Calling CSI driver to discover driver name
kube-system/csi-node-tx8dw[csi-driver-registrar]: I1014 09:17:53.936710       1 connection.go:180] GRPC call: /csi.v1.Identity/GetPluginInfo
kube-system/csi-node-tx8dw[csi-driver-registrar]: I1014 09:17:53.936737       1 connection.go:181] GRPC request: {}
kube-system/csi-node-tx8dw[csi-driver-registrar]: I1014 09:17:53.941994       1 connection.go:183] GRPC response: {"name":"net.packet.csi","vendor_version":"beb1628"}
kube-system/csi-node-tx8dw[csi-driver-registrar]: I1014 09:17:53.943366       1 connection.go:184] GRPC error: <nil>
kube-system/csi-node-tx8dw[csi-driver-registrar]: I1014 09:17:53.943388       1 main.go:137] CSI driver name: "net.packet.csi"
kube-system/csi-node-tx8dw[csi-driver-registrar]: I1014 09:17:53.943438       1 node_register.go:58] Starting Registration Server at: /registration/net.packet.csi-reg.sock
kube-system/csi-node-tx8dw[csi-driver-registrar]: I1014 09:17:53.943860       1 node_register.go:67] Registration Server started at: /registration/net.packet.csi-reg.sock
kube-system/csi-node-tx8dw[csi-driver-registrar]: I1014 09:17:54.449898       1 main.go:77] Received GetInfo call: &InfoRequest{}
kube-system/csi-packet-controller-0[csi-attacher]: I1014 09:17:54.114004       1 connection.go:184] GRPC error: <nil>
kube-system/csi-node-tx8dw[packet-driver]: {"level":"info","msg":"PacketIdentityServer.GetPluginInfo called","time":"2019-10-14T09:17:53Z"}
kube-system/csi-packet-controller-0[csi-attacher]: I1014 09:17:54.114044       1 connection.go:180] GRPC call: /csi.v1.Identity/GetPluginInfo
kube-system/csi-node-tx8dw[packet-driver]: {"GRPC.call":"/csi.v1.Identity/GetPluginInfo","GRPC.request":"","level":"info","msg":"GRPC response: name:\"net.packet.csi\" vendor_version:\"beb1628\" ","time":"2019-10-14T09:17:53Z"}
kube-system/csi-packet-controller-0[csi-attacher]: I1014 09:17:54.114058       1 connection.go:181] GRPC request: {}
kube-system/csi-packet-controller-0[csi-attacher]: I1014 09:17:54.116312       1 connection.go:183] GRPC response: {"name":"net.packet.csi","vendor_version":"beb1628"}
kube-system/csi-packet-controller-0[csi-attacher]: I1014 09:17:54.117850       1 connection.go:184] GRPC error: <nil>
kube-system/csi-node-tx8dw[packet-driver]: {"endpoint":"unix:///csi/csi.sock","level":"info","msg":"NodeGetInfo called","node":"k1.ovrclk.net","time":"2019-10-14T09:17:54Z"}
kube-system/csi-node-tx8dw[packet-driver]: {"GRPC.call":"/csi.v1.Node/NodeGetInfo","GRPC.request":"","level":"info","msg":"GRPC response: node_id:\"k1.ovrclk.net\" ","time":"2019-10-14T09:17:54Z"}
kube-system/csi-packet-controller-0[csi-attacher]: I1014 09:17:54.117884       1 main.go:128] CSI driver name: "net.packet.csi"
kube-system/csi-packet-controller-0[csi-attacher]: I1014 09:17:54.117912       1 connection.go:180] GRPC call: /csi.v1.Identity/GetPluginCapabilities
kube-system/csi-packet-controller-0[csi-attacher]: I1014 09:17:54.117933       1 connection.go:181] GRPC request: {}
kube-system/csi-packet-controller-0[csi-attacher]: I1014 09:17:54.120083       1 connection.go:183] GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}}]}
kube-system/csi-packet-controller-0[csi-attacher]: I1014 09:17:54.122643       1 connection.go:184] GRPC error: <nil>
kube-system/csi-packet-controller-0[csi-attacher]: I1014 09:17:54.122665       1 connection.go:180] GRPC call: /csi.v1.Controller/ControllerGetCapabilities
kube-system/csi-packet-controller-0[csi-attacher]: I1014 09:17:54.122678       1 connection.go:181] GRPC request: {}
kube-system/csi-packet-controller-0[csi-attacher]: I1014 09:17:54.125032       1 connection.go:183] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":2}}},{"Type":{"Rpc":{"type":3}}}]}
kube-system/csi-packet-controller-0[csi-attacher]: I1014 09:17:54.129789       1 connection.go:184] GRPC error: <nil>
kube-system/csi-packet-controller-0[csi-attacher]: I1014 09:17:54.129870       1 main.go:152] CSI driver supports ControllerPublishUnpublish, using real CSI handler
kube-system/csi-packet-controller-0[csi-attacher]: I1014 09:17:54.130163       1 controller.go:113] Starting CSI attacher
kube-system/csi-node-tx8dw[csi-driver-registrar]: I1014 09:17:54.586648       1 main.go:87] Received NotifyRegistrationStatus call: &RegistrationStatus{PluginRegistered:true,Error:,}
kube-system/csi-packet-controller-0[packet-driver]: {"GRPC.call":"/csi.v1.Controller/ControllerGetCapabilities","GRPC.request":"","level":"info","msg":"GRPC response: capabilities:\u003crpc:\u003ctype:CREATE_DELETE_VOLUME \u003e \u003e capabilities:\u003crpc:\u003ctype:PUBLISH_UNPUBLISH_VOLUME \u003e \u003e capabilities:\u003crpc:\u003ctype:LIST_VOLUMES \u003e \u003e ","time":"2019-10-14T09:17:54Z"}
kube-system/csi-packet-controller-0[csi-attacher]: I1014 09:17:54.131488       1 reflector.go:123] Starting reflector *v1beta1.VolumeAttachment (10m0s) from k8s.io/client-go/informers/factory.go:133
kube-system/csi-packet-controller-0[csi-attacher]: I1014 09:17:54.131558       1 reflector.go:161] Listing and watching *v1beta1.VolumeAttachment from k8s.io/client-go/informers/factory.go:133
kube-system/csi-packet-controller-0[csi-attacher]: I1014 09:17:54.132119       1 reflector.go:123] Starting reflector *v1beta1.CSINode (10m0s) from k8s.io/client-go/informers/factory.go:133
kube-system/csi-packet-controller-0[csi-attacher]: I1014 09:17:54.132177       1 reflector.go:161] Listing and watching *v1beta1.CSINode from k8s.io/client-go/informers/factory.go:133
kube-system/csi-packet-controller-0[csi-attacher]: I1014 09:17:54.132178       1 reflector.go:123] Starting reflector *v1.Node (10m0s) from k8s.io/client-go/informers/factory.go:133
kube-system/csi-packet-controller-0[csi-attacher]: I1014 09:17:54.132296       1 reflector.go:161] Listing and watching *v1.Node from k8s.io/client-go/informers/factory.go:133
kube-system/csi-packet-controller-0[csi-attacher]: I1014 09:17:54.132803       1 reflector.go:123] Starting reflector *v1.PersistentVolume (10m0s) from k8s.io/client-go/informers/factory.go:133
kube-system/csi-packet-controller-0[csi-attacher]: I1014 09:17:54.132862       1 reflector.go:161] Listing and watching *v1.PersistentVolume from k8s.io/client-go/informers/factory.go:133
kube-system/csi-packet-controller-0[csi-attacher]: I1014 09:17:54.230429       1 shared_informer.go:123] caches populated
kube-system/csi-packet-controller-0[csi-external-provisioner]: I1014 09:17:54.802984       1 connection.go:261] Probing CSI driver for readiness
kube-system/csi-packet-controller-0[csi-external-provisioner]: I1014 09:17:54.803061       1 connection.go:180] GRPC call: /csi.v1.Identity/Probe
kube-system/csi-packet-controller-0[csi-external-provisioner]: I1014 09:17:54.803084       1 connection.go:181] GRPC request: {}
kube-system/csi-packet-controller-0[packet-driver]: {"level":"info","msg":"PacketIdentityServer.Probe called with args: \u0026csi.ProbeRequest{XXX_NoUnkeyedLiteral:struct {}{}, XXX_unrecognized:[]uint8(nil), XXX_sizecache:0}","time":"2019-10-14T09:17:54Z"}
kube-system/csi-packet-controller-0[packet-driver]: {"GRPC.call":"/csi.v1.Identity/Probe","GRPC.request":"","level":"info","msg":"GRPC response: ","time":"2019-10-14T09:17:54Z"}
kube-system/csi-packet-controller-0[csi-external-provisioner]: I1014 09:17:54.807720       1 connection.go:183] GRPC response: {}
kube-system/csi-packet-controller-0[csi-external-provisioner]: I1014 09:17:54.809064       1 connection.go:184] GRPC error: <nil>
kube-system/csi-packet-controller-0[csi-external-provisioner]: I1014 09:17:54.809089       1 connection.go:180] GRPC call: /csi.v1.Identity/GetPluginInfo
kube-system/csi-packet-controller-0[packet-driver]: {"level":"info","msg":"PacketIdentityServer.GetPluginInfo called","time":"2019-10-14T09:17:54Z"}
kube-system/csi-packet-controller-0[packet-driver]: {"GRPC.call":"/csi.v1.Identity/GetPluginInfo","GRPC.request":"","level":"info","msg":"GRPC response: name:\"net.packet.csi\" vendor_version:\"beb1628\" ","time":"2019-10-14T09:17:54Z"}
kube-system/csi-packet-controller-0[csi-external-provisioner]: I1014 09:17:54.809102       1 connection.go:181] GRPC request: {}
kube-system/csi-packet-controller-0[csi-external-provisioner]: I1014 09:17:54.811508       1 connection.go:183] GRPC response: {"name":"net.packet.csi","vendor_version":"beb1628"}
kube-system/csi-packet-controller-0[csi-external-provisioner]: I1014 09:17:54.813280       1 connection.go:184] GRPC error: <nil>
kube-system/csi-packet-controller-0[csi-external-provisioner]: I1014 09:17:54.813319       1 csi-provisioner.go:152] Detected CSI driver net.packet.csi
kube-system/csi-packet-controller-0[csi-external-provisioner]: I1014 09:17:54.813411       1 connection.go:180] GRPC call: /csi.v1.Identity/GetPluginCapabilities
kube-system/csi-packet-controller-0[csi-external-provisioner]: I1014 09:17:54.813433       1 connection.go:181] GRPC request: {}
kube-system/csi-packet-controller-0[packet-driver]: {"level":"info","msg":"PacketIdentityServer.GetPluginCapabilities called","time":"2019-10-14T09:17:54Z"}
kube-system/csi-packet-controller-0[packet-driver]: {"GRPC.call":"/csi.v1.Identity/GetPluginCapabilities","GRPC.request":"","level":"info","msg":"GRPC response: capabilities:\u003cservice:\u003ctype:CONTROLLER_SERVICE \u003e \u003e ","time":"2019-10-14T09:17:54Z"}
kube-system/csi-packet-controller-0[csi-external-provisioner]: I1014 09:17:54.817735       1 connection.go:183] GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}}]}
kube-system/csi-packet-controller-0[csi-external-provisioner]: I1014 09:17:54.820200       1 connection.go:184] GRPC error: <nil>
kube-system/csi-packet-controller-0[csi-external-provisioner]: I1014 09:17:54.820239       1 connection.go:180] GRPC call: /csi.v1.Controller/ControllerGetCapabilities
kube-system/csi-packet-controller-0[packet-driver]: {"GRPC.call":"/csi.v1.Controller/ControllerGetCapabilities","GRPC.request":"","level":"info","msg":"GRPC response: capabilities:\u003crpc:\u003ctype:CREATE_DELETE_VOLUME \u003e \u003e capabilities:\u003crpc:\u003ctype:PUBLISH_UNPUBLISH_VOLUME \u003e \u003e capabilities:\u003crpc:\u003ctype:LIST_VOLUMES \u003e \u003e ","time":"2019-10-14T09:17:54Z"}
kube-system/csi-packet-controller-0[csi-external-provisioner]: I1014 09:17:54.820261       1 connection.go:181] GRPC request: {}
kube-system/csi-packet-controller-0[csi-external-provisioner]: I1014 09:17:54.822974       1 connection.go:183] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":2}}},{"Type":{"Rpc":{"type":3}}}]}
kube-system/csi-packet-controller-0[csi-external-provisioner]: I1014 09:17:54.827858       1 connection.go:184] GRPC error: <nil>
kube-system/csi-packet-controller-0[csi-external-provisioner]: I1014 09:17:54.828685       1 controller.go:680] Using saving PVs to API server in background
kube-system/csi-packet-controller-0[csi-external-provisioner]: I1014 09:17:54.828750       1 controller.go:770] Starting provisioner controller net.packet.csi_csi-packet-controller-0_f47c2bd5-5640-4e53-b68c-be928567827d!
kube-system/csi-packet-controller-0[csi-external-provisioner]: I1014 09:17:54.828941       1 volume_store.go:97] Starting save volume queue
kube-system/csi-packet-controller-0[csi-external-provisioner]: I1014 09:17:54.829846       1 reflector.go:122] Starting reflector *v1.PersistentVolume (15m0s) from sigs.k8s.io/sig-storage-lib-external-provisioner/controller/controller.go:804
kube-system/csi-packet-controller-0[csi-external-provisioner]: I1014 09:17:54.829947       1 reflector.go:160] Listing and watching *v1.PersistentVolume from sigs.k8s.io/sig-storage-lib-external-provisioner/controller/controller.go:804
kube-system/csi-packet-controller-0[csi-external-provisioner]: I1014 09:17:54.829777       1 reflector.go:122] Starting reflector *v1.PersistentVolumeClaim (15m0s) from sigs.k8s.io/sig-storage-lib-external-provisioner/controller/controller.go:801
kube-system/csi-packet-controller-0[csi-external-provisioner]: I1014 09:17:54.830260       1 reflector.go:160] Listing and watching *v1.PersistentVolumeClaim from sigs.k8s.io/sig-storage-lib-external-provisioner/controller/controller.go:801
kube-system/csi-packet-controller-0[csi-external-provisioner]: I1014 09:17:54.830054       1 reflector.go:122] Starting reflector *v1.StorageClass (15m0s) from sigs.k8s.io/sig-storage-lib-external-provisioner/controller/controller.go:807
kube-system/csi-packet-controller-0[csi-external-provisioner]: I1014 09:17:54.831381       1 reflector.go:160] Listing and watching *v1.StorageClass from sigs.k8s.io/sig-storage-lib-external-provisioner/controller/controller.go:807
kube-system/csi-packet-controller-0[csi-external-provisioner]: I1014 09:17:54.929039       1 shared_informer.go:177] caches populated
kube-system/csi-packet-controller-0[csi-external-provisioner]: I1014 09:17:54.929692       1 controller.go:819] Started provisioner controller net.packet.csi_csi-packet-controller-0_f47c2bd5-5640-4e53-b68c-be928567827d!
kube-system/csi-packet-controller-0[csi-external-provisioner]: I1014 09:18:59.128801       1 controller.go:1199] provision "akash-sanity-1571044738/sanity-pvc" class "standard": started
kube-system/csi-packet-controller-0[csi-external-provisioner]: I1014 09:18:59.131767       1 controller.go:494] CreateVolumeRequest {Name:pvc-f715cd2b-d69d-4f13-962b-4dffc29417a1 CapacityRange:required_bytes:1073741824  VolumeCapabilities:[mount:<fs_type:"ext4" > access_mode:<mode:SINGLE_NODE_WRITER > ] Parameters:map[plan:standard] Secrets:map[] VolumeContentSource:<nil> AccessibilityRequirements:<nil> XXX_NoUnkeyedLiteral:{} XXX_unrecognized:[] XXX_sizecache:0}
kube-system/csi-packet-controller-0[packet-driver]: {"level":"info","msg":"CreateVolume called","time":"2019-10-14T09:18:59Z","volume_name":"pvc-f715cd2b-d69d-4f13-962b-4dffc29417a1"}
kube-system/csi-packet-controller-0[csi-external-provisioner]: I1014 09:18:59.131862       1 connection.go:180] GRPC call: /csi.v1.Controller/CreateVolume
kube-system/csi-packet-controller-0[packet-driver]: {"level":"info","msg":"Volume requested","planID":"87728148-3155-4992-a730-8d1e6aca8a32","sizeRequestGiB":10,"time":"2019-10-14T09:18:59Z","volume_name":"pvc-f715cd2b-d69d-4f13-962b-4dffc29417a1"}
kube-system/csi-packet-controller-0[csi-external-provisioner]: I1014 09:18:59.131894       1 event.go:255] Event(v1.ObjectReference{Kind:"PersistentVolumeClaim", Namespace:"akash-sanity-1571044738", Name:"sanity-pvc", UID:"f715cd2b-d69d-4f13-962b-4dffc29417a1", APIVersion:"v1", ResourceVersion:"532", FieldPath:""}): type: 'Normal' reason: 'Provisioning' External provisioner is provisioning volume for claim "akash-sanity-1571044738/sanity-pvc"
kube-system/csi-packet-controller-0[csi-external-provisioner]: I1014 09:18:59.131867       1 connection.go:181] GRPC request: {"capacity_range":{"required_bytes":1073741824},"name":"pvc-f715cd2b-d69d-4f13-962b-4dffc29417a1","parameters":{"plan":"standard"},"volume_capabilities":[{"AccessType":{"Mount":{"fs_type":"ext4"}},"access_mode":{"mode":1}}]}
kube-system/csi-packet-controller-0[csi-external-provisioner]: I1014 09:19:04.352001       1 connection.go:183] GRPC response: {"volume":{"capacity_bytes":10737418240,"volume_id":"e990ec13-b34d-4545-aaa3-1f3a52887779"}}
kube-system/csi-packet-controller-0[csi-external-provisioner]: I1014 09:19:04.352612       1 connection.go:184] GRPC error: <nil>
kube-system/csi-packet-controller-0[packet-driver]: {"GRPC.call":"/csi.v1.Controller/CreateVolume","GRPC.request":"name:\"pvc-f715cd2b-d69d-4f13-962b-4dffc29417a1\" capacity_range:\u003crequired_bytes:1073741824 \u003e volume_capabilities:\u003cmount:\u003cfs_type:\"ext4\" \u003e access_mode:\u003cmode:SINGLE_NODE_WRITER \u003e \u003e parameters:\u003ckey:\"plan\" value:\"standard\" \u003e ","level":"info","msg":"GRPC response: volume:\u003ccapacity_bytes:10737418240 volume_id:\"e990ec13-b34d-4545-aaa3-1f3a52887779\" \u003e ","time":"2019-10-14T09:19:04Z"}
kube-system/csi-packet-controller-0[csi-attacher]: I1014 09:19:04.358612       1 controller.go:205] Started PV processing "pvc-f715cd2b-d69d-4f13-962b-4dffc29417a1"
kube-system/csi-packet-controller-0[csi-attacher]: I1014 09:19:04.358633       1 csi_handler.go:444] CSIHandler: processing PV "pvc-f715cd2b-d69d-4f13-962b-4dffc29417a1"
kube-system/csi-packet-controller-0[csi-attacher]: I1014 09:19:04.358645       1 csi_handler.go:448] CSIHandler: processing PV "pvc-f715cd2b-d69d-4f13-962b-4dffc29417a1": no deletion timestamp, ignoring
kube-system/csi-packet-controller-0[csi-attacher]: I1014 09:19:04.359360       1 controller.go:205] Started PV processing "pvc-f715cd2b-d69d-4f13-962b-4dffc29417a1"
kube-system/csi-packet-controller-0[csi-attacher]: I1014 09:19:04.359376       1 csi_handler.go:444] CSIHandler: processing PV "pvc-f715cd2b-d69d-4f13-962b-4dffc29417a1"
kube-system/csi-packet-controller-0[csi-external-provisioner]: I1014 09:19:04.352626       1 controller.go:549] create volume rep: {CapacityBytes:10737418240 VolumeId:e990ec13-b34d-4545-aaa3-1f3a52887779 VolumeContext:map[] ContentSource:<nil> AccessibleTopology:[] XXX_NoUnkeyedLiteral:{} XXX_unrecognized:[] XXX_sizecache:0}
kube-system/csi-packet-controller-0[csi-attacher]: I1014 09:19:04.359386       1 csi_handler.go:448] CSIHandler: processing PV "pvc-f715cd2b-d69d-4f13-962b-4dffc29417a1": no deletion timestamp, ignoring
kube-system/csi-packet-controller-0[csi-external-provisioner]: I1014 09:19:04.352653       1 controller.go:631] successfully created PV pvc-f715cd2b-d69d-4f13-962b-4dffc29417a1 for PVC sanity-pvc and csi volume name e990ec13-b34d-4545-aaa3-1f3a52887779
kube-system/csi-packet-controller-0[csi-external-provisioner]: I1014 09:19:04.352662       1 controller.go:647] successfully created PV {GCEPersistentDisk:nil AWSElasticBlockStore:nil HostPath:nil Glusterfs:nil NFS:nil RBD:nil ISCSI:nil Cinder:nil CephFS:nil FC:nil Flocker:nil FlexVolume:nil AzureFile:nil VsphereVolume:nil Quobyte:nil AzureDisk:nil PhotonPersistentDisk:nil PortworxVolume:nil ScaleIO:nil Local:nil StorageOS:nil CSI:&CSIPersistentVolumeSource{Driver:net.packet.csi,VolumeHandle:e990ec13-b34d-4545-aaa3-1f3a52887779,ReadOnly:false,FSType:ext4,VolumeAttributes:map[string]string{storage.kubernetes.io/csiProvisionerIdentity: 1571044674827-8081-net.packet.csi,},ControllerPublishSecretRef:nil,NodeStageSecretRef:nil,NodePublishSecretRef:nil,ControllerExpandSecretRef:nil,}}
kube-system/csi-packet-controller-0[csi-external-provisioner]: I1014 09:19:04.352752       1 controller.go:1281] provision "akash-sanity-1571044738/sanity-pvc" class "standard": volume "pvc-f715cd2b-d69d-4f13-962b-4dffc29417a1" provisioned
kube-system/csi-packet-controller-0[csi-external-provisioner]: I1014 09:19:04.352799       1 controller.go:1298] provision "akash-sanity-1571044738/sanity-pvc" class "standard": succeeded
kube-system/csi-packet-controller-0[csi-external-provisioner]: I1014 09:19:04.352809       1 volume_store.go:154] Saving volume pvc-f715cd2b-d69d-4f13-962b-4dffc29417a1
kube-system/csi-packet-controller-0[csi-external-provisioner]: I1014 09:19:04.359187       1 volume_store.go:157] Volume pvc-f715cd2b-d69d-4f13-962b-4dffc29417a1 saved
kube-system/csi-packet-controller-0[csi-external-provisioner]: I1014 09:19:04.359238       1 controller.go:1014] Claim processing succeeded, removing PVC f715cd2b-d69d-4f13-962b-4dffc29417a1 from claims in progress
kube-system/csi-packet-controller-0[csi-external-provisioner]: I1014 09:19:04.359474       1 event.go:255] Event(v1.ObjectReference{Kind:"PersistentVolumeClaim", Namespace:"akash-sanity-1571044738", Name:"sanity-pvc", UID:"f715cd2b-d69d-4f13-962b-4dffc29417a1", APIVersion:"v1", ResourceVersion:"532", FieldPath:""}): type: 'Normal' reason: 'ProvisioningSucceeded' Successfully provisioned volume pvc-f715cd2b-d69d-4f13-962b-4dffc29417a1
kube-system/csi-packet-controller-0[csi-attacher]: I1014 09:19:06.994573       1 controller.go:175] Started VA processing "csi-b57ca0db5d22d2ab580d29bee167af73bfb4eec64096c280eadaa0ab17bf589b"
kube-system/csi-packet-controller-0[csi-attacher]: I1014 09:19:06.994619       1 csi_handler.go:89] CSIHandler: processing VA "csi-b57ca0db5d22d2ab580d29bee167af73bfb4eec64096c280eadaa0ab17bf589b"
kube-system/csi-packet-controller-0[csi-attacher]: I1014 09:19:06.994647       1 csi_handler.go:116] Attaching "csi-b57ca0db5d22d2ab580d29bee167af73bfb4eec64096c280eadaa0ab17bf589b"
kube-system/csi-packet-controller-0[csi-attacher]: I1014 09:19:06.994674       1 csi_handler.go:249] Starting attach operation for "csi-b57ca0db5d22d2ab580d29bee167af73bfb4eec64096c280eadaa0ab17bf589b"
kube-system/csi-packet-controller-0[csi-attacher]: I1014 09:19:06.994800       1 csi_handler.go:215] Adding finalizer to PV "pvc-f715cd2b-d69d-4f13-962b-4dffc29417a1"
kube-system/csi-packet-controller-0[csi-attacher]: I1014 09:19:07.008544       1 csi_handler.go:224] PV finalizer added to "pvc-f715cd2b-d69d-4f13-962b-4dffc29417a1"
kube-system/csi-packet-controller-0[csi-attacher]: I1014 09:19:07.008618       1 csi_handler.go:542] Found NodeID k1.ovrclk.net in CSINode k1.ovrclk.net
kube-system/csi-packet-controller-0[csi-attacher]: I1014 09:19:07.008711       1 csi_handler.go:177] VA finalizer added to "csi-b57ca0db5d22d2ab580d29bee167af73bfb4eec64096c280eadaa0ab17bf589b"
kube-system/csi-packet-controller-0[csi-attacher]: I1014 09:19:07.008750       1 csi_handler.go:191] NodeID annotation added to "csi-b57ca0db5d22d2ab580d29bee167af73bfb4eec64096c280eadaa0ab17bf589b"
kube-system/csi-packet-controller-0[csi-attacher]: I1014 09:19:07.009664       1 controller.go:205] Started PV processing "pvc-f715cd2b-d69d-4f13-962b-4dffc29417a1"
kube-system/csi-packet-controller-0[csi-attacher]: I1014 09:19:07.009716       1 csi_handler.go:444] CSIHandler: processing PV "pvc-f715cd2b-d69d-4f13-962b-4dffc29417a1"
kube-system/csi-packet-controller-0[csi-attacher]: I1014 09:19:07.009756       1 csi_handler.go:448] CSIHandler: processing PV "pvc-f715cd2b-d69d-4f13-962b-4dffc29417a1": no deletion timestamp, ignoring
kube-system/csi-packet-controller-0[csi-attacher]: I1014 09:19:07.020143       1 connection.go:180] GRPC call: /csi.v1.Controller/ControllerPublishVolume
kube-system/csi-packet-controller-0[csi-attacher]: I1014 09:19:07.020194       1 connection.go:181] GRPC request: {"node_id":"k1.ovrclk.net","volume_capability":{"AccessType":{"Mount":{"fs_type":"ext4"}},"access_mode":{"mode":1}},"volume_context":{"storage.kubernetes.io/csiProvisionerIdentity":"1571044674827-8081-net.packet.csi"},"volume_id":"e990ec13-b34d-4545-aaa3-1f3a52887779"}
kube-system/csi-packet-controller-0[packet-driver]: {"GRPC.call":"/csi.v1.Controller/ControllerPublishVolume","GRPC.request":"volume_id:\"e990ec13-b34d-4545-aaa3-1f3a52887779\" node_id:\"k1.ovrclk.net\" volume_capability:\u003cmount:\u003cfs_type:\"ext4\" \u003e access_mode:\u003cmode:SINGLE_NODE_WRITER \u003e \u003e volume_context:\u003ckey:\"storage.kubernetes.io/csiProvisionerIdentity\" value:\"1571044674827-8081-net.packet.csi\" \u003e ","level":"info","msg":"GRPC response: publish_context:\u003ckey:\"AttachmentId\" value:\"df4f4d3b-61e5-4792-9a4b-e1d84ece8227\" \u003e publish_context:\u003ckey:\"VolumeId\" value:\"e990ec13-b34d-4545-aaa3-1f3a52887779\" \u003e publish_context:\u003ckey:\"VolumeName\" value:\"volume-e990ec13\" \u003e ","time":"2019-10-14T09:19:12Z"}
kube-system/csi-packet-controller-0[csi-attacher]: I1014 09:19:12.017681       1 connection.go:183] GRPC response: {"publish_context":{"AttachmentId":"df4f4d3b-61e5-4792-9a4b-e1d84ece8227","VolumeId":"e990ec13-b34d-4545-aaa3-1f3a52887779","VolumeName":"volume-e990ec13"}}
kube-system/csi-packet-controller-0[csi-attacher]: I1014 09:19:12.019480       1 connection.go:184] GRPC error: <nil>
kube-system/csi-packet-controller-0[csi-attacher]: I1014 09:19:12.019506       1 csi_handler.go:129] Attached "csi-b57ca0db5d22d2ab580d29bee167af73bfb4eec64096c280eadaa0ab17bf589b"
kube-system/csi-packet-controller-0[csi-attacher]: I1014 09:19:12.019532       1 util.go:35] Marking as attached "csi-b57ca0db5d22d2ab580d29bee167af73bfb4eec64096c280eadaa0ab17bf589b"
kube-system/csi-packet-controller-0[csi-attacher]: I1014 09:19:12.025691       1 util.go:48] Marked as attached "csi-b57ca0db5d22d2ab580d29bee167af73bfb4eec64096c280eadaa0ab17bf589b"
kube-system/csi-packet-controller-0[csi-attacher]: I1014 09:19:12.025753       1 csi_handler.go:135] Fully attached "csi-b57ca0db5d22d2ab580d29bee167af73bfb4eec64096c280eadaa0ab17bf589b"
kube-system/csi-packet-controller-0[csi-attacher]: I1014 09:19:12.025787       1 csi_handler.go:105] CSIHandler: finished processing "csi-b57ca0db5d22d2ab580d29bee167af73bfb4eec64096c280eadaa0ab17bf589b"
kube-system/csi-packet-controller-0[csi-attacher]: I1014 09:19:12.025901       1 controller.go:175] Started VA processing "csi-b57ca0db5d22d2ab580d29bee167af73bfb4eec64096c280eadaa0ab17bf589b"
kube-system/csi-packet-controller-0[csi-attacher]: I1014 09:19:12.025942       1 csi_handler.go:89] CSIHandler: processing VA "csi-b57ca0db5d22d2ab580d29bee167af73bfb4eec64096c280eadaa0ab17bf589b"
kube-system/csi-packet-controller-0[csi-attacher]: I1014 09:19:12.025970       1 csi_handler.go:116] Attaching "csi-b57ca0db5d22d2ab580d29bee167af73bfb4eec64096c280eadaa0ab17bf589b"
kube-system/csi-packet-controller-0[csi-attacher]: I1014 09:19:12.025999       1 csi_handler.go:249] Starting attach operation for "csi-b57ca0db5d22d2ab580d29bee167af73bfb4eec64096c280eadaa0ab17bf589b"
kube-system/csi-packet-controller-0[csi-attacher]: I1014 09:19:12.026217       1 csi_handler.go:209] PV finalizer is already set on "pvc-f715cd2b-d69d-4f13-962b-4dffc29417a1"
kube-system/csi-packet-controller-0[csi-attacher]: I1014 09:19:12.026274       1 csi_handler.go:542] Found NodeID k1.ovrclk.net in CSINode k1.ovrclk.net
kube-system/csi-packet-controller-0[csi-attacher]: I1014 09:19:12.026328       1 csi_handler.go:169] VA finalizer is already set on "csi-b57ca0db5d22d2ab580d29bee167af73bfb4eec64096c280eadaa0ab17bf589b"
kube-system/csi-packet-controller-0[csi-attacher]: I1014 09:19:12.026399       1 csi_handler.go:183] NodeID annotation is already set on "csi-b57ca0db5d22d2ab580d29bee167af73bfb4eec64096c280eadaa0ab17bf589b"
kube-system/csi-packet-controller-0[csi-attacher]: I1014 09:19:12.026449       1 connection.go:180] GRPC call: /csi.v1.Controller/ControllerPublishVolume
kube-system/csi-packet-controller-0[csi-attacher]: I1014 09:19:12.026470       1 connection.go:181] GRPC request: {"node_id":"k1.ovrclk.net","volume_capability":{"AccessType":{"Mount":{"fs_type":"ext4"}},"access_mode":{"mode":1}},"volume_context":{"storage.kubernetes.io/csiProvisionerIdentity":"1571044674827-8081-net.packet.csi"},"volume_id":"e990ec13-b34d-4545-aaa3-1f3a52887779"}
kube-system/csi-packet-controller-0[packet-driver]: {"GRPC.call":"/csi.v1.Controller/ControllerPublishVolume","GRPC.request":"volume_id:\"e990ec13-b34d-4545-aaa3-1f3a52887779\" node_id:\"k1.ovrclk.net\" volume_capability:\u003cmount:\u003cfs_type:\"ext4\" \u003e access_mode:\u003cmode:SINGLE_NODE_WRITER \u003e \u003e volume_context:\u003ckey:\"storage.kubernetes.io/csiProvisionerIdentity\" value:\"1571044674827-8081-net.packet.csi\" \u003e ","level":"error","msg":"GRPC error: rpc error: code = Unknown desc = error attempting to attach e990ec13-b34d-4545-aaa3-1f3a52887779 to 2162b84d-716a-4e7e-83e6-0748ee1d87e4, POST https://api.packet.net/storage/e990ec13-b34d-4545-aaa3-1f3a52887779/attachments: 422 Instance is already attached to this volume ","time":"2019-10-14T09:19:13Z"}
kube-system/csi-packet-controller-0[csi-attacher]: I1014 09:19:13.994415       1 connection.go:183] GRPC response: {}
kube-system/csi-packet-controller-0[csi-attacher]: I1014 09:19:13.995467       1 connection.go:184] GRPC error: rpc error: code = Unknown desc = error attempting to attach e990ec13-b34d-4545-aaa3-1f3a52887779 to 2162b84d-716a-4e7e-83e6-0748ee1d87e4, POST https://api.packet.net/storage/e990ec13-b34d-4545-aaa3-1f3a52887779/attachments: 422 Instance is already attached to this volume
kube-system/csi-packet-controller-0[csi-attacher]: I1014 09:19:13.995515       1 csi_handler.go:412] Saving attach error to "csi-b57ca0db5d22d2ab580d29bee167af73bfb4eec64096c280eadaa0ab17bf589b"
kube-system/csi-packet-controller-0[csi-attacher]: I1014 09:19:14.000965       1 csi_handler.go:423] Saved attach error to "csi-b57ca0db5d22d2ab580d29bee167af73bfb4eec64096c280eadaa0ab17bf589b"
kube-system/csi-packet-controller-0[csi-attacher]: I1014 09:19:14.001051       1 csi_handler.go:99] Error processing "csi-b57ca0db5d22d2ab580d29bee167af73bfb4eec64096c280eadaa0ab17bf589b": failed to attach: rpc error: code = Unknown desc = error attempting to attach e990ec13-b34d-4545-aaa3-1f3a52887779 to 2162b84d-716a-4e7e-83e6-0748ee1d87e4, POST https://api.packet.net/storage/e990ec13-b34d-4545-aaa3-1f3a52887779/attachments: 422 Instance is already attached to this volume
kube-system/csi-packet-controller-0[csi-attacher]: I1014 09:19:14.001165       1 controller.go:175] Started VA processing "csi-b57ca0db5d22d2ab580d29bee167af73bfb4eec64096c280eadaa0ab17bf589b"
kube-system/csi-packet-controller-0[csi-attacher]: I1014 09:19:14.001219       1 csi_handler.go:89] CSIHandler: processing VA "csi-b57ca0db5d22d2ab580d29bee167af73bfb4eec64096c280eadaa0ab17bf589b"
kube-system/csi-packet-controller-0[csi-attacher]: I1014 09:19:14.001246       1 csi_handler.go:111] "csi-b57ca0db5d22d2ab580d29bee167af73bfb4eec64096c280eadaa0ab17bf589b" is already attached
kube-system/csi-packet-controller-0[csi-attacher]: I1014 09:19:14.001275       1 csi_handler.go:105] CSIHandler: finished processing "csi-b57ca0db5d22d2ab580d29bee167af73bfb4eec64096c280eadaa0ab17bf589b"
kube-system/csi-packet-controller-0[csi-attacher]: I1014 09:19:14.001940       1 controller.go:141] Ignoring VolumeAttachment "csi-b57ca0db5d22d2ab580d29bee167af73bfb4eec64096c280eadaa0ab17bf589b" change
kube-system/csi-packet-controller-0[csi-attacher]: I1014 09:19:15.001445       1 controller.go:175] Started VA processing "csi-b57ca0db5d22d2ab580d29bee167af73bfb4eec64096c280eadaa0ab17bf589b"
kube-system/csi-packet-controller-0[csi-attacher]: I1014 09:19:15.001498       1 csi_handler.go:89] CSIHandler: processing VA "csi-b57ca0db5d22d2ab580d29bee167af73bfb4eec64096c280eadaa0ab17bf589b"
kube-system/csi-packet-controller-0[csi-attacher]: I1014 09:19:15.001524       1 csi_handler.go:111] "csi-b57ca0db5d22d2ab580d29bee167af73bfb4eec64096c280eadaa0ab17bf589b" is already attached
kube-system/csi-packet-controller-0[csi-attacher]: I1014 09:19:15.001552       1 csi_handler.go:105] CSIHandler: finished processing "csi-b57ca0db5d22d2ab580d29bee167af73bfb4eec64096c280eadaa0ab17bf589b"
kube-system/csi-node-tx8dw[packet-driver]: {"endpoint":"unix:///csi/csi.sock","level":"info","msg":"NodeGetCapabilities called","node":"k1.ovrclk.net","time":"2019-10-14T09:19:22Z"}
kube-system/csi-node-tx8dw[packet-driver]: {"GRPC.call":"/csi.v1.Node/NodeGetCapabilities","GRPC.request":"","level":"info","msg":"GRPC response: capabilities:\u003crpc:\u003ctype:STAGE_UNSTAGE_VOLUME \u003e \u003e ","time":"2019-10-14T09:19:22Z"}
kube-system/csi-node-tx8dw[packet-driver]: {"endpoint":"unix:///csi/csi.sock","level":"info","msg":"NodeStageVolume called","node":"k1.ovrclk.net","time":"2019-10-14T09:19:23Z"}
kube-system/csi-node-tx8dw[packet-driver]: {"args":"--mode session","command":"iscsiadm","error":"exit status 21","level":"error","msg":"Error","out":"iscsiadm: No active sessions.\n","time":"2019-10-14T09:19:24Z"}
kube-system/csi-node-tx8dw[packet-driver]: {"endpoint":"unix:///csi/csi.sock","fsType":"ext4","level":"info","method":"NodeStageVolume","msg":"devicePath error, file not found for pattern /dev/disk/by-path/*10.144.144.12*iqn.2013-05.com.daterainc:tc:01:sn:40cae22d5ad05998*","node":"k1.ovrclk.net","staging_target_path":"/var/lib/rancher/k3s/agent/kubelet/plugins/kubernetes.io/csi/pv/pvc-f715cd2b-d69d-4f13-962b-4dffc29417a1/globalmount","time":"2019-10-14T09:19:24Z","volume_id":"e990ec13-b34d-4545-aaa3-1f3a52887779","volume_name":"volume-e990ec13"}
kube-system/csi-node-tx8dw[packet-driver]: {"GRPC.call":"/csi.v1.Node/NodeStageVolume","GRPC.request":"volume_id:\"e990ec13-b34d-4545-aaa3-1f3a52887779\" publish_context:\u003ckey:\"AttachmentId\" value:\"df4f4d3b-61e5-4792-9a4b-e1d84ece8227\" \u003e publish_context:\u003ckey:\"VolumeId\" value:\"e990ec13-b34d-4545-aaa3-1f3a52887779\" \u003e publish_context:\u003ckey:\"VolumeName\" value:\"volume-e990ec13\" \u003e staging_target_path:\"/var/lib/rancher/k3s/agent/kubelet/plugins/kubernetes.io/csi/pv/pvc-f715cd2b-d69d-4f13-962b-4dffc29417a1/globalmount\" volume_capability:\u003cmount:\u003cfs_type:\"ext4\" \u003e access_mode:\u003cmode:SINGLE_NODE_WRITER \u003e \u003e volume_context:\u003ckey:\"storage.kubernetes.io/csiProvisionerIdentity\" value:\"1571044674827-8081-net.packet.csi\" \u003e ","level":"error","msg":"GRPC error: rpc error: code = Unknown desc = devicePath error, file not found for pattern /dev/disk/by-path/*10.144.144.12*iqn.2013-05.com.daterainc:tc:01:sn:40cae22d5ad05998*","time":"2019-10-14T09:19:24Z"}
kube-system/csi-node-tx8dw[packet-driver]: {"endpoint":"unix:///csi/csi.sock","level":"info","msg":"NodeGetCapabilities called","node":"k1.ovrclk.net","time":"2019-10-14T09:19:24Z"}
kube-system/csi-node-tx8dw[packet-driver]: {"GRPC.call":"/csi.v1.Node/NodeGetCapabilities","GRPC.request":"","level":"info","msg":"GRPC response: capabilities:\u003crpc:\u003ctype:STAGE_UNSTAGE_VOLUME \u003e \u003e ","time":"2019-10-14T09:19:24Z"}
kube-system/csi-node-tx8dw[packet-driver]: {"endpoint":"unix:///csi/csi.sock","level":"info","msg":"NodeStageVolume called","node":"k1.ovrclk.net","time":"2019-10-14T09:19:24Z"}
kube-system/csi-node-tx8dw[packet-driver]: {"args":"-f mpatha","level":"info","msg":"multipath timed out","time":"2019-10-14T09:19:35Z","timeout":10000000000}
kube-system/csi-node-tx8dw[packet-driver]: {"args":"volume-e990ec13","level":"info","msg":"multipath timed out","time":"2019-10-14T09:19:45Z","timeout":10000000000}
kube-system/csi-node-tx8dw[packet-driver]: {"endpoint":"unix:///csi/csi.sock","fsType":"ext4","level":"info","method":"NodeStageVolume","msg":"multipath check for /dev/sdc: volume-e990ec13 (36001405777fc06c74fc4014829ee42f7) dm-0 DATERA,IBLOCK\nsize=10G features='1 queue_if_no_path' hwhandler='1 alua' wp=rw\n`-+- policy='round-robin 0' prio=50 status=active\n  |- 8:0:0:0 sdc 8:32 active ready running\n  `- 9:0:0:0 sdd 8:48 active ready running\n","node":"k1.ovrclk.net","staging_target_path":"/var/lib/rancher/k3s/agent/kubelet/plugins/kubernetes.io/csi/pv/pvc-f715cd2b-d69d-4f13-962b-4dffc29417a1/globalmount","time":"2019-10-14T09:19:45Z","volume_id":"e990ec13-b34d-4545-aaa3-1f3a52887779","volume_name":"volume-e990ec13"}
kube-system/csi-node-tx8dw[packet-driver]: {"endpoint":"unix:///csi/csi.sock","fsType":"ext4","level":"info","method":"NodeStageVolume","msg":"mounting mapped device","node":"k1.ovrclk.net","staging_target_path":"/var/lib/rancher/k3s/agent/kubelet/plugins/kubernetes.io/csi/pv/pvc-f715cd2b-d69d-4f13-962b-4dffc29417a1/globalmount","time":"2019-10-14T09:19:45Z","volume_id":"e990ec13-b34d-4545-aaa3-1f3a52887779","volume_name":"volume-e990ec13"}
kube-system/csi-node-tx8dw[packet-driver]: {"endpoint":"unix:///csi/csi.sock","fsType":"ext4","level":"info","method":"NodeStageVolume","msg":"NodeStageVolume complete","node":"k1.ovrclk.net","staging_target_path":"/var/lib/rancher/k3s/agent/kubelet/plugins/kubernetes.io/csi/pv/pvc-f715cd2b-d69d-4f13-962b-4dffc29417a1/globalmount","time":"2019-10-14T09:19:45Z","volume_id":"e990ec13-b34d-4545-aaa3-1f3a52887779","volume_name":"volume-e990ec13"}
kube-system/csi-node-tx8dw[packet-driver]: {"GRPC.call":"/csi.v1.Node/NodeStageVolume","GRPC.request":"volume_id:\"e990ec13-b34d-4545-aaa3-1f3a52887779\" publish_context:\u003ckey:\"AttachmentId\" value:\"df4f4d3b-61e5-4792-9a4b-e1d84ece8227\" \u003e publish_context:\u003ckey:\"VolumeId\" value:\"e990ec13-b34d-4545-aaa3-1f3a52887779\" \u003e publish_context:\u003ckey:\"VolumeName\" value:\"volume-e990ec13\" \u003e staging_target_path:\"/var/lib/rancher/k3s/agent/kubelet/plugins/kubernetes.io/csi/pv/pvc-f715cd2b-d69d-4f13-962b-4dffc29417a1/globalmount\" volume_capability:\u003cmount:\u003cfs_type:\"ext4\" \u003e access_mode:\u003cmode:SINGLE_NODE_WRITER \u003e \u003e volume_context:\u003ckey:\"storage.kubernetes.io/csiProvisionerIdentity\" value:\"1571044674827-8081-net.packet.csi\" \u003e ","level":"info","msg":"GRPC response: ","time":"2019-10-14T09:19:45Z"}
kube-system/csi-node-tx8dw[packet-driver]: {"endpoint":"unix:///csi/csi.sock","level":"info","msg":"NodeGetCapabilities called","node":"k1.ovrclk.net","time":"2019-10-14T09:19:45Z"}
kube-system/csi-node-tx8dw[packet-driver]: {"GRPC.call":"/csi.v1.Node/NodeGetCapabilities","GRPC.request":"","level":"info","msg":"GRPC response: capabilities:\u003crpc:\u003ctype:STAGE_UNSTAGE_VOLUME \u003e \u003e ","time":"2019-10-14T09:19:45Z"}
kube-system/csi-node-tx8dw[packet-driver]: {"endpoint":"unix:///csi/csi.sock","level":"info","msg":"NodePublishVolume called","node":"k1.ovrclk.net","time":"2019-10-14T09:19:45Z"}
kube-system/csi-node-tx8dw[packet-driver]: {"endpoint":"unix:///csi/csi.sock","level":"info","method":"NodePublishVolume","msg":"bind mount complete","node":"k1.ovrclk.net","staging_target_path":"/var/lib/rancher/k3s/agent/kubelet/plugins/kubernetes.io/csi/pv/pvc-f715cd2b-d69d-4f13-962b-4dffc29417a1/globalmount","target_path":"/var/lib/rancher/k3s/agent/kubelet/pods/f6b00129-2079-4521-a97f-af69a133722c/volumes/kubernetes.io~csi/pvc-f715cd2b-d69d-4f13-962b-4dffc29417a1/mount","time":"2019-10-14T09:19:45Z","volume_id":"e990ec13-b34d-4545-aaa3-1f3a52887779"}
kube-system/csi-node-tx8dw[packet-driver]: {"GRPC.call":"/csi.v1.Node/NodePublishVolume","GRPC.request":"volume_id:\"e990ec13-b34d-4545-aaa3-1f3a52887779\" publish_context:\u003ckey:\"AttachmentId\" value:\"df4f4d3b-61e5-4792-9a4b-e1d84ece8227\" \u003e publish_context:\u003ckey:\"VolumeId\" value:\"e990ec13-b34d-4545-aaa3-1f3a52887779\" \u003e publish_context:\u003ckey:\"VolumeName\" value:\"volume-e990ec13\" \u003e staging_target_path:\"/var/lib/rancher/k3s/agent/kubelet/plugins/kubernetes.io/csi/pv/pvc-f715cd2b-d69d-4f13-962b-4dffc29417a1/globalmount\" target_path:\"/var/lib/rancher/k3s/agent/kubelet/pods/f6b00129-2079-4521-a97f-af69a133722c/volumes/kubernetes.io~csi/pvc-f715cd2b-d69d-4f13-962b-4dffc29417a1/mount\" volume_capability:\u003cmount:\u003cfs_type:\"ext4\" \u003e access_mode:\u003cmode:SINGLE_NODE_WRITER \u003e \u003e volume_context:\u003ckey:\"storage.kubernetes.io/csiProvisionerIdentity\" value:\"1571044674827-8081-net.packet.csi\" \u003e ","level":"info","msg":"GRPC response: ","time":"2019-10-14T09:19:45Z"}
kube-system/csi-node-tx8dw[packet-driver]: {"endpoint":"unix:///csi/csi.sock","level":"info","msg":"NodeGetCapabilities called","node":"k1.ovrclk.net","time":"2019-10-14T09:19:56Z"}
kube-system/csi-node-tx8dw[packet-driver]: {"GRPC.call":"/csi.v1.Node/NodeGetCapabilities","GRPC.request":"","level":"info","msg":"GRPC response: capabilities:\u003crpc:\u003ctype:STAGE_UNSTAGE_VOLUME \u003e \u003e ","time":"2019-10-14T09:19:56Z"}

images

{
  "names": [
    "docker.io/packethost/csi-packet@sha256:79cde1d31fc6d996069aada9862ef153c00dbcec4f8aa0513e29e10705c4e821",
    "docker.io/packethost/csi-packet:beb1628"
  ],
  "sizeBytes": 76966461
}
{
  "names": [
    "gcr.io/kubernetes-helm/tiller@sha256:be79aff05025bd736f027eaf4a1b2716ac1e09b88e0e9493c962642519f19d9c",
    "gcr.io/kubernetes-helm/tiller:v2.14.2"
  ],
  "sizeBytes": 30875059
}
{
  "names": [
    "docker.io/rancher/klipper-helm@sha256:72690de1ae2259a41075e87ff453936a74e0f2dbf2ad1dd96a4f72136a48038d",
    "docker.io/rancher/klipper-helm:v0.1.5"
  ],
  "sizeBytes": 27089525
}
{
  "names": [
    "docker.io/library/traefik@sha256:e1e1b1dadfaab6d64f420f4352356e98e289fc7c8bf9f47387866f221c60e4e6",
    "docker.io/library/traefik:1.7.14"
  ],
  "sizeBytes": 23626773
}
{
  "names": [
    "quay.io/k8scsi/csi-provisioner:v1.4.0"
  ],
  "sizeBytes": 20068761
}
{
  "names": [
    "quay.io/k8scsi/csi-attacher:v2.0.0"
  ],
  "sizeBytes": 17305293
}
{
  "names": [
    "docker.io/coredns/coredns@sha256:cfa7236dab4e3860881fdf755880ff8361e42f6cba2e3775ae48e2d46d22f7ba",
    "docker.io/coredns/coredns:1.6.3"
  ],
  "sizeBytes": 14191001
}
{
  "names": [
    "quay.io/k8scsi/csi-node-driver-registrar:v1.2.0"
  ],
  "sizeBytes": 7676183
}
{
  "names": [
    "docker.io/rancher/klipper-lb@sha256:2cff68f14dd050a5ab16b59a55d5ba34d6edc3f6edfc1ec5bd4e437d4ba47290",
    "docker.io/rancher/klipper-lb:v0.1.1"
  ],
  "sizeBytes": 2708144
}
{
  "names": [
    "docker.io/library/busybox@sha256:fe301db49df08c384001ed752dff6d52b4305a73a7f608f21528048e8a08b51e",
    "docker.io/library/busybox:latest"
  ],
  "sizeBytes": 764658
}
{
  "names": [
    "k8s.gcr.io/pause@sha256:f78411e19d84a252e53bff71a4407a5686c46983a2c2eeed83929b888179acea",
    "k8s.gcr.io/pause:3.1"
  ],
  "sizeBytes": 317164
}

daemonset

apiVersion: extensions/v1beta1
kind: DaemonSet
metadata:
  creationTimestamp: "2019-10-14T09:17:46Z"
  generation: 1
  name: csi-node
  namespace: kube-system
  resourceVersion: "510"
  selfLink: /apis/extensions/v1beta1/namespaces/kube-system/daemonsets/csi-node
  uid: 5ed52b35-77e2-4ef6-b76a-f33b0bf94135
spec:
  revisionHistoryLimit: 10
  selector:
    matchLabels:
      app: csi-packet-driver
  template:
    metadata:
      creationTimestamp: null
      labels:
        app: csi-packet-driver
    spec:
      containers:
      - args:
        - --v=5
        - --csi-address=$(ADDRESS)
        - --kubelet-registration-path=/var/lib/rancher/k3s/agent/kubelet/plugins/net.packet.csi/csi.sock
        env:
        - name: ADDRESS
          value: /csi/csi.sock
        - name: KUBE_NODE_NAME
          valueFrom:
            fieldRef:
              apiVersion: v1
              fieldPath: spec.nodeName
        image: quay.io/k8scsi/csi-node-driver-registrar:v1.2.0
        imagePullPolicy: IfNotPresent
        name: csi-driver-registrar
        resources: {}
        terminationMessagePath: /dev/termination-log
        terminationMessagePolicy: File
        volumeMounts:
        - mountPath: /csi
          name: plugin-dir
        - mountPath: /registration
          name: registration-dir
      - args:
        - --endpoint=$(CSI_ENDPOINT)
        - --nodeid=$(KUBE_NODE_NAME)
        env:
        - name: CSI_ENDPOINT
          value: unix:///csi/csi.sock
        - name: KUBE_NODE_NAME
          valueFrom:
            fieldRef:
              apiVersion: v1
              fieldPath: spec.nodeName
        image: docker.io/packethost/csi-packet:beb1628
        imagePullPolicy: Always
        name: packet-driver
        resources: {}
        securityContext:
          privileged: true
        terminationMessagePath: /dev/termination-log
        terminationMessagePolicy: File
        volumeMounts:
        - mountPath: /var/lib/rancher/k3s/agent/kubelet/pods
          mountPropagation: Bidirectional
          name: kubelet-dir
        - mountPath: /sbin/iscsiadm
          name: iscsiadm
        - mountPath: /var/lib/rancher/k3s/agent/kubelet/plugins
          name: all-plugin-dir
        - mountPath: /csi
          name: plugin-dir
        - mountPath: /sys/devices
          name: sys-devices
        - mountPath: /dev
          name: dev
        - mountPath: /etc
          name: etc
        - mountPath: /run/udev
          name: run-udev
        - mountPath: /var/lib/iscsi
          name: var-lib-iscsi
        - mountPath: /lib/modules
          name: lib-modules
        - mountPath: /usr/share/ca-certificates/
          name: ca-certs-alternative
          readOnly: true
      dnsPolicy: ClusterFirst
      hostNetwork: true
      restartPolicy: Always
      schedulerName: default-scheduler
      securityContext: {}
      serviceAccount: csi-node-sa
      serviceAccountName: csi-node-sa
      terminationGracePeriodSeconds: 30
      volumes:
      - hostPath:
          path: /var/lib/rancher/k3s/agent/kubelet/plugins_registry
          type: Directory
        name: registration-dir
      - hostPath:
          path: /var/lib/rancher/k3s/agent/kubelet/pods
          type: Directory
        name: kubelet-dir
      - hostPath:
          path: /var/lib/rancher/k3s/agent/kubelet/plugins
          type: DirectoryOrCreate
        name: all-plugin-dir
      - hostPath:
          path: /var/lib/rancher/k3s/agent/kubelet/plugins/net.packet.csi/
          type: DirectoryOrCreate
        name: plugin-dir
      - hostPath:
          path: /sbin/iscsiadm
          type: File
        name: iscsiadm
      - hostPath:
          path: /dev
          type: Directory
        name: dev
      - hostPath:
          path: /etc/
          type: ""
        name: etc
      - hostPath:
          path: /var/lib/iscsi/
          type: DirectoryOrCreate
        name: var-lib-iscsi
      - hostPath:
          path: /sys/devices
          type: Directory
        name: sys-devices
      - hostPath:
          path: /run/udev/
          type: Directory
        name: run-udev
      - hostPath:
          path: /lib/modules
          type: Directory
        name: lib-modules
      - hostPath:
          path: /usr/share/ca-certificates/
          type: DirectoryOrCreate
        name: ca-certs-alternative
  templateGeneration: 1
  updateStrategy:
    rollingUpdate:
      maxUnavailable: 1
    type: RollingUpdate
status:
  currentNumberScheduled: 1
  desiredNumberScheduled: 1
  numberAvailable: 1
  numberMisscheduled: 0
  numberReady: 1
  observedGeneration: 1
  updatedNumberScheduled: 1

curl -s https://metadata.packet.net/metadata | jq '.volumes

[
  {
    "ips": [
      "10.144.144.12",
      "10.144.145.10"
    ],
    "name": "volume-e990ec13",
    "capacity": {
      "size": "10",
      "unit": "gb"
    },
    "iqn": "iqn.2013-05.com.daterainc:tc:01:sn:40cae22d5ad05998"
  }
]

curl -s https://metadata.packet.net/metadata | jq -r '.iqn'

iqn.2019-10.net.packet:device.2162b84d

[deitch]

@gosuri can we close this out now that we know that it is k3s (and sometimes works, sometimes does not), but is consistent with k8s? Once k3s behaves nicely with the path (per the linked issue), we can retest and open a new issue if it is needed.

[scottrobertson]

I am seeing this when running on Platform9, so it's not a k3 specific issue. Running packet-block-storage-attach manually resolved the issue (obviously not a fix, but just worth noting).

This is running the YAML from the deployment demo in the repo.

Here is a screenshot of the attach script, before and after.

[deitch]

The problem appears to be either writing to /etc/multipath/bindings, or running multipath volume-3744dc89 afterwards, where it does not pick it up.

Running the packet script afterwards adds it and runs it, and then everything is fine.

The code that does it is here:

    bindings, discards, err := nodeServer.Driver.Attacher.MultipathReadBindings()
    if err != nil {
        logger.Infof("readBindings error, %+v", err)
        return nil, status.Errorf(codes.Unknown, "readBindings error, %+v", err)
    }
    bindings[volumeName] = scsiID
    err = nodeServer.Driver.Attacher.MultipathWriteBindings(bindings)
    if err != nil {
        logger.Infof("writeBindings error, %+v", err)
        return nil, status.Errorf(codes.Unknown, "writeBindings error, %+v", err)
    }
    for mappingName := range discards {
        multipath("-f", mappingName)
    }
    // for some reason, you have to do it twice for it to work
    multipath(volumeName)
    multipath(volumeName)

Notice that line at the end, // for some reason, you have to do it twice for it to work. If we knew why it had to be run twice, we might know why it isn't working correctly now.

Next steps. @scottrobertson kindly agreed to recreate it, and then check the contents of /etc/multipath/bindings after CSI picks it up and has the errors, but without running the packet attach script.

I would ask that you check it on the host, and inside the csi-node-* pod on the host. Sure, /etc is bind-mounted, but who knows? Can you paste the results here, as well as the results of lsblk, ls -l /dev/mapper?

If the contents look right, and it persists, can you run multipath volume-<id> after the CSI runs if it has the same missing issue in /dev/mapper/? Let's see if a manual run of just that fixes it.

[displague]

Thanks again for the detailed report and analysis @gosuri.

At this time, I am closing this issue as 'Will not fix' - see #103 (Equinix Metal Block Storage from Datera is EOL).