verbose external-provisioner output when shutting down

[pohly]

When deleting a pod that contains PMEM-CSI and external-provisioner and PMEM-CSI shuts down first, external-provisioner logs a "connection lost" error before shutting down itself

[2021-01-18T12:07:10.563Z] test-deployment-driver-image-node-lj4bz/[email protected]: I0118 12:07:10.189564       1 server.go:56] Server on 'unix:///csi/csi.sock' stopped
[2021-01-18T12:07:10.563Z] test-deployment-driver-image-node-4kvc8/[email protected]: F0118 12:07:10.183283       1 connection.go:87] Lost connection to CSI driver, exiting
[2021-01-18T12:07:10.563Z] test-deployment-driver-image-node-4kvc8/[email protected]: I0118 12:07:10.182345       1 pmem-csi-driver.go:264] Caught signal terminated, terminating.
[2021-01-18T12:07:10.563Z] test-deployment-driver-image-node-4kvc8/[email protected]: I0118 12:07:10.184162       1 server.go:56] Server on 'unix:///csi/csi.sock' stopped
[2021-01-18T12:07:10.563Z] test-deployment-driver-image-node-4kvc8/[email protected]: goroutine 27 [running]:
[2021-01-18T12:07:10.563Z] test-deployment-driver-image-node-4kvc8/[email protected]: k8s.io/klog/v2.stacks(0xc00000e001, 0xc00018e600, 0x57, 0x1e2)
[2021-01-18T12:07:10.564Z] test-deployment-driver-image-node-4kvc8/[email protected]: 	/workspace/vendor/k8s.io/klog/v2/klog.go:1026 +0xb9
[2021-01-18T12:07:10.564Z] test-deployment-driver-image-node-4kvc8/[email protected]: k8s.io/klog/v2.(*loggingT).output(0x2604640, 0xc000000003, 0x0, 0x0, 0xc0000e1810, 0x2553078, 0xd, 0x57, 0x0)
[2021-01-18T12:07:10.564Z] test-deployment-driver-image-node-4kvc8/[email protected]: 	/workspace/vendor/k8s.io/klog/v2/klog.go:975 +0x19b
[2021-01-18T12:07:10.564Z] test-deployment-driver-image-node-4kvc8/[email protected]: k8s.io/klog/v2.(*loggingT).printf(0x2604640, 0x3, 0x0, 0x0, 0x0, 0x0, 0x19a584d, 0x26, 0x0, 0x0, ...)
[2021-01-18T12:07:10.564Z] test-deployment-driver-image-node-4kvc8/[email protected]: 	/workspace/vendor/k8s.io/klog/v2/klog.go:750 +0x191
[2021-01-18T12:07:10.564Z] test-deployment-driver-image-node-4kvc8/[email protected]: k8s.io/klog/v2.Fatalf(...)
[2021-01-18T12:07:10.564Z] test-deployment-driver-image-node-4kvc8/[email protected]: 	/workspace/vendor/k8s.io/klog/v2/klog.go:1502
[2021-01-18T12:07:10.564Z] test-deployment-driver-image-node-4kvc8/[email protected]: github.com/kubernetes-csi/csi-lib-utils/connection.ExitOnConnectionLoss.func1(0x2604640)
[2021-01-18T12:07:10.564Z] test-deployment-driver-image-node-4kvc8/[email protected]: 	/workspace/vendor/github.com/kubernetes-csi/csi-lib-utils/connection/connection.go:87 +0x1d4
[2021-01-18T12:07:10.564Z] test-deployment-driver-image-node-4kvc8/[email protected]: github.com/kubernetes-csi/csi-lib-utils/connection.connect.func1(0xc0001eb010, 0xd, 0x4a81737a6, 0x4a81737a6, 0xc0000e7101, 0x10, 0xc00059c600)
[2021-01-18T12:07:10.564Z] test-deployment-driver-image-node-4kvc8/[email protected]: 	/workspace/vendor/github.com/kubernetes-csi/csi-lib-utils/connection/connection.go:134 +0x2aa
[2021-01-18T12:07:10.564Z] test-deployment-driver-image-node-4kvc8/[email protected]: google.golang.org/grpc.WithDialer.func1(0x1ba4a00, 0xc00030c6c0, 0xc0001eb010, 0xd, 0x10, 0x17d5240, 0xa8281195d4fee022, 0x2635dc0)
[2021-01-18T12:07:10.564Z] test-deployment-driver-image-node-4kvc8/[email protected]: 	/workspace/vendor/google.golang.org/grpc/dialoptions.go:398 +0x8e
[2021-01-18T12:07:10.564Z] test-deployment-driver-image-node-4kvc8/[email protected]: google.golang.org/grpc/internal/transport.dial(0x1ba4a00, 0xc00030c6c0, 0xc00031b250, 0xc0001eb010, 0xd, 0x1980038, 0x9, 0xc0003480b0, 0x0, 0x0, ...)
[2021-01-18T12:07:10.564Z] test-deployment-driver-image-node-4kvc8/[email protected]: 	/workspace/vendor/google.golang.org/grpc/internal/transport/http2_client.go:143 +0x2dd
[2021-01-18T12:07:10.564Z] test-deployment-driver-image-node-4kvc8/[email protected]: google.golang.org/grpc/internal/transport.newHTTP2Client(0x1ba4a00, 0xc00030c6c0, 0x1ba4980, 0xc0005a61c0, 0xc0001eb010, 0xd, 0x1980038, 0x9, 0xc0003480b0, 0x0, ...)
[2021-01-18T12:07:10.564Z] test-deployment-driver-image-node-4kvc8/[email protected]: 	/workspace/vendor/google.golang.org/grpc/internal/transport/http2_client.go:183 +0x15e
....

This is from https://cloudnative-k8sci.southcentralus.cloudapp.azure.com/blue/rest/organizations/jenkins/pipelines/pmem-csi/branches/PR-838/runs/14/nodes/88/steps/105/log/?start=0, i.e. testing of PR #838 , but should also occur on current devel.

That output is very verbose. It would be nice to avoid it.

[pohly]

Solutions:

• Slightly delay the shutdown in PMEM-CSI. Assuming that all containers get killed roughly at the same time (to be checked!), external-provisioner then should shut down first.
• If shutdown order is container-by-container, then we can re-order containers to so that external-provisioner comes first. It wasn't done that way because during startup, PMEM-CSI must be up first before external-provisioner can work. But it will retry to connect without verbose output, so this may be better.
• Silence the error message in external-provisioner (upstream solution).

[pohly]

Silence the error message in external-provisioner (upstream solution).

That was done. Our next regular sidecar update will fix this issue.