CSINodeInfo should not be required about external-attacher HOT 8 CLOSED

from external-attacher.

CSINodeInfo is still Alpha in 1.13.

I tried to work around this problem by enabling the feature gates for CSINodeInfo and CSIDriverRegistry and I did follow the example here: https://kubernetes-csi.github.io/docs/Example.html#deployment

I still got the following errors in the external-attacher:

I1121 18:38:19.079423 1 csi_handler.go:91] CSIHandler: processing VA "csi-4800a666312223e9f2c660a5e3a07ba348ac2735a7533db59082418397ee0fff"
I1121 18:38:19.079429 1 csi_handler.go:118] Attaching "csi-4800a666312223e9f2c660a5e3a07ba348ac2735a7533db59082418397ee0fff"
I1121 18:38:19.079438 1 csi_handler.go:257] Starting attach operation for "csi-4800a666312223e9f2c660a5e3a07ba348ac2735a7533db59082418397ee0fff"
I1121 18:38:19.079497 1 csi_handler.go:212] PV finalizer is already set on "pvc-7e549db8-edbc-11e8-8278-000c29e70439"
I1121 18:38:19.083760 1 csi_handler.go:516] Can't get CSINodeInfo 127.0.0.1: csinodeinfos.csi.storage.k8s.io "127.0.0.1" not found
I1121 18:38:19.083782 1 csi_handler.go:380] Saving attach error to "csi-4800a666312223e9f2c660a5e3a07ba348ac2735a7533db59082418397ee0fff"
I1121 18:38:19.086711 1 csi_handler.go:390] Saved attach error to "csi-4800a666312223e9f2c660a5e3a07ba348ac2735a7533db59082418397ee0fff"
I1121 18:38:19.086730 1 csi_handler.go:101] Error processing "csi-4800a666312223e9f2c660a5e3a07ba348ac2735a7533db59082418397ee0fff": failed to attach: node "127.0.0.1" has no NodeID annotation

The "forbidden" error message was gone, but it still couldn't find CSINodeInfo.

There was also this message in kubelet:

I1123 10:17:57.603669 59338 reflector.go:169] Listing and watching *v1alpha1.CSIDriver from k8s.io/csi-api/pkg/client/informers/externalversions/factory.go:117
E1123 10:17:57.605228 59338 reflector.go:134] k8s.io/csi-api/pkg/client/informers/externalversions/factory.go:117: Failed to list *v1alpha1.CSIDriver: the server could not find the requested resource (get csidrivers.csi.storage.k8s.io)
E1123 10:17:57.609073 59338 kubele

from external-attacher.

I have a temporary fix for this problem: #100
With this fix, my CSI plugin works now.

Note that when testing with hostpath CSI plugin, I didn't run into this problem because hostpath didn't implement ControllerPublishVolume and therefore it uses the trivial_handler rather than the csi_handler in external-attacher.

from external-attacher.

I checked today with 1.0-canary images of everything, CSINodeInfo is not required in 1.13 at all.

In attacher logs I still can see an error about CSINodeInfo, but attacher continues without it:

I1126 12:46:11.804570       1 csi_handler.go:118] Attaching "csi-6eec4ae2b83d654c234b32dcfd7e2785508d30da7ccba0b75f101b02c42dceeb"
I1126 12:46:11.804592       1 csi_handler.go:257] Starting attach operation for "csi-6eec4ae2b83d654c234b32dcfd7e2785508d30da7ccba0b75f101b02c42dceeb"
I1126 12:46:11.804694       1 csi_handler.go:218] Adding finalizer to PV "pvc-002a4e5f-f179-11e8-adb4-5254000472e3"
I1126 12:46:11.820575       1 csi_handler.go:226] PV finalizer added to "pvc-002a4e5f-f179-11e8-adb4-5254000472e3"
I1126 12:46:11.820619       1 controller.go:197] Started PV processing "pvc-002a4e5f-f179-11e8-adb4-5254000472e3"
I1126 12:46:11.820642       1 csi_handler.go:410] CSIHandler: processing PV "pvc-002a4e5f-f179-11e8-adb4-5254000472e3"
I1126 12:46:11.820667       1 csi_handler.go:414] CSIHandler: processing PV "pvc-002a4e5f-f179-11e8-adb4-5254000472e3": no deletion timestamp, ignoring
I1126 12:46:11.821583       1 csi_handler.go:516] Can't get CSINodeInfo 127.0.0.1: csinodeinfos.csi.storage.k8s.io "127.0.0.1" is forbidden: User "system:serviceaccount:default:csi-service-account" cannot get resource "csinodeinfos" in API group "csi.storage.k8s.io" at the cluster scope
I1126 12:46:11.821666       1 csi_handler.go:179] VA finalizer added to "csi-6eec4ae2b83d654c234b32dcfd7e2785508d30da7ccba0b75f101b02c42dceeb"
I1126 12:46:11.821689       1 csi_handler.go:193] NodeID annotation added to "csi-6eec4ae2b83d654c234b32dcfd7e2785508d30da7ccba0b75f101b02c42dceeb"
I1126 12:46:11.825572       1 csi_handler.go:203] VolumeAttachment "csi-6eec4ae2b83d654c234b32dcfd7e2785508d30da7ccba0b75f101b02c42dceeb" updated with finalizer and/or NodeID annotation
I1126 12:46:11.825632       1 connection.go:235] GRPC call: /csi.v1.Controller/ControllerPublishVolume
I1126 12:46:11.825645       1 connection.go:236] GRPC request: volume_id:"4" node_id:"io.kubernetes.storage.mock" volume_capability:<mount:<fs_type:"ext4" > access_mode:<mode:SINGLE_NODE_WRITER > > volume_context:<key:"name" value:"pvc-002a4e5f-f179-11e8-adb4-5254000472e3" > volume_context:<key:"storage.kubernetes.io/csiProvisionerIdentity" value:"1543236260925-8081-io.kubernetes.storage.mock" > 
I1126 12:46:11.826582       1 connection.go:238] GRPC response: publish_context:<key:"device" value:"/dev/mock" > publish_context:<key:"readonly" value:"false" > 
I1126 12:46:11.826632       1 connection.go:239] GRPC error: <nil>
I1126 12:46:11.826646       1 csi_handler.go:131] Attached "csi-6eec4ae2b83d654c234b32dcfd7e2785508d30da7ccba0b75f101b02c42dceeb"
I1126 12:46:11.826665       1 util.go:33] Marking as attached "csi-6eec4ae2b83d654c234b32dcfd7e2785508d30da7ccba0b75f101b02c42dceeb"
I1126 12:46:11.829693       1 util.go:43] Marked as attached "csi-6eec4ae2b83d654c234b32dcfd7e2785508d30da7ccba0b75f101b02c42dceeb"
I1126 12:46:11.829717       1 csi_handler.go:137] Fully attached "csi-6eec4ae2b83d654c234b32dcfd7e2785508d30da7ccba0b75f101b02c42dceeb"

In your case, the root cause is node "127.0.0.1" has no NodeID annotation. Many things changed in 1.0, in my case I had to change yaml of my driver to use /var/lib/kubelet/plugins_registry/ instead of /var/lib/kubelet/plugins for driver registrar socket directory, something like this:

kubernetes-sigs/gcp-compute-persistent-disk-csi-driver@762870b

But there may be more reasons why the node does not have annotation. Check driver-registrar and kubelet logs.

from external-attacher.

Thanks @jsafrane ! I'll re-test with the new driver registrar path. I remember there is a change but couldn't find the relevant PR about it.

from external-attacher.

I modified the driver registrar socket directory and tested without CSINodeInfo (using external-attacher v1.0.0 image and driver-registrar v1.0-canary), but I got the same errors in the attacher. Here are errors in kube-controller-manager.log:

E1126 07:42:05.000173 2970 csi_attacher.go:228] kubernetes.io/csi: attachment for 26b93b42-d7ad-4d04-a217-e0ff38f4b348 failed: node "127.0.0.1" has no NodeID annotation
E1126 07:42:05.000243 2970 nestedpendingoperations.go:267] Operation for ""kubernetes.io/csi/csi-opensdsplugin^26b93b42-d7ad-4d04-a217-e0ff38f4b348"" failed. No retries permitted until 2018-11-26 07:42:05.500224109 -0800 PST m=+709.906687860 (durationBeforeRetry 500ms). Error: "AttachVolume.Attach failed for volume "pvc-c82060d8-f191-11e8-8ce4-000c29e70439" (UniqueName: "kubernetes.io/csi/csi-opensdsplugin^26b93b42-d7ad-4d04-a217-e0ff38f4b348") from node "127.0.0.1" : node "127.0.0.1" has no NodeID annotation"

Driver registrar logs look fine:

kubectl logs csi-nodeplugin-opensdsplugin-xcf9z driver-registrar

I1126 15:39:16.423783 1 main.go:138] Version: v1.0.1-0-g78b5c12e
I1126 15:39:16.423841 1 main.go:145] Attempting to open a gRPC connection with: "/csi/csi.sock"
I1126 15:39:16.423854 1 connection.go:68] Connecting to /csi/csi.sock
I1126 15:39:16.423982 1 connection.go:95] Still trying, connection is CONNECTING
I1126 15:39:16.424090 1 connection.go:95] Still trying, connection is TRANSIENT_FAILURE
I1126 15:39:17.424620 1 connection.go:92] Connected
I1126 15:39:17.424637 1 main.go:153] Calling CSI driver to discover driver name.
I1126 15:39:17.424645 1 connection.go:136] GRPC call: /csi.v1.Identity/GetPluginInfo
I1126 15:39:17.424649 1 connection.go:137] GRPC request:
I1126 15:39:17.425406 1 connection.go:139] GRPC response: name:"csi-opensdsplugin"
I1126 15:39:17.425453 1 connection.go:140] GRPC error:
I1126 15:39:17.425459 1 main.go:161] CSI driver name: "csi-opensdsplugin"
I1126 15:39:17.425464 1 main.go:165] Loading kubeconfig.
I1126 15:39:17.425711 1 node_register.go:55] Calling CSI driver to discover node ID.
I1126 15:39:17.426025 1 connection.go:136] GRPC call: /csi.v1.Node/NodeGetInfo
I1126 15:39:17.426050 1 connection.go:137] GRPC request:
I1126 15:39:17.430834 1 connection.go:139] GRPC response: node_id:"ubuntu,iqn:iqn.1993-08.org.debian:01:c6961059376e"
I1126 15:39:17.430961 1 connection.go:140] GRPC error:
I1126 15:39:17.430972 1 node_register.go:63] CSI driver node ID: "ubuntu,iqn:iqn.1993-08.org.debian:01:c6961059376e"
I1126 15:39:17.431251 1 node_register.go:86] Starting Registration Server at: /registration/csi-opensdsplugin-reg.sock
I1126 15:39:17.432065 1 node_register.go:93] Registration Server started at: /registration/csi-opensdsplugin-reg.sock

from external-attacher.

Verified PR #101 fixed this issue. Thanks @jsafrane !

from external-attacher.

if CSINodeInfo is not required, please remove it from docs

from external-attacher.