/tmp/csi-mount is sometimes not cleaned up after "Node Service"."should work" test which fails further tests

[alexanderKhaustov]

Here's csi-sanity output:

Node Service
should work
/home/akhaustov/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/node.go:625
STEP: reusing connection to CSI driver at unix:///tmp/csi.sock
STEP: reusing connection to CSI driver controller at unix:///tmp/csi.sock
STEP: creating mount and staging directories
STEP: creating a single node writer volume
STEP: getting a node id
STEP: controller publishing volume
STEP: node staging volume
STEP: publishing the volume on a node
STEP: cleaning up calling nodeunpublish
STEP: cleaning up calling nodeunstage
STEP: cleaning up calling controllerunpublishing
STEP: cleaning up deleting the volume
cleanup: deleting sanity-node-full-35BAA099-984D9C20 = ef3gu6pu151v67thndsc
cleanup: warning: NodeUnpublishVolume: rpc error: code = Internal desc = Could not unmount "/tmp/csi-mount": Unmount failed: exit status 32
Unmounting arguments: /tmp/csi-mount
Output: umount: /tmp/csi-mount: not mounted

cleanup: warning: ControllerUnpublishVolume: rpc error: code = InvalidArgument desc = Disk unpublish operation failed

• [SLOW TEST:16.717 seconds]
Node Service
/home/akhaustov/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/tests.go:44
should work
/home/akhaustov/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/node.go:625

ListSnapshots [Controller Server]
should return appropriate values (no optional values added)
/home/akhaustov/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:1579
STEP: reusing connection to CSI driver at unix:///tmp/csi.sock
STEP: reusing connection to CSI driver controller at unix:///tmp/csi.sock
STEP: creating mount and staging directories

• Failure in Spec Setup (BeforeEach) [0.001 seconds]
ListSnapshots [Controller Server]
/home/akhaustov/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/tests.go:44
should return appropriate values (no optional values added) [BeforeEach]
/home/akhaustov/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:1579

failed to create target directory
Unexpected error:
<*os.PathError | 0xc0003db170>: {
Op: "mkdir",
Path: "/tmp/csi-mount",
Err: 0x11,
}
mkdir /tmp/csi-mount: file exists
occurred

/home/akhaustov/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/sanity.go:222

Here's the call order from the driver:

I0426 15:01:54.622765 214412 node.go:73] StageVolume: volume="ef3gu6pu151v67thndsc" operation finished
I0426 15:01:54.625078 214412 node.go:185] PublishVolume(volume_id:"ef3gu6pu151v67thndsc" staging_target_path:"/tmp/csi-staging" target_path:"/tmp/csi-mount/target" volume_capability:<mount:<> access_mode:<mode:SINGLE_NODE_WRITER > > )
I0426 15:01:54.625350 214412 node.go:361] PublishVolume: creating dir /tmp/csi-mount/target
I0426 15:01:54.625459 214412 node.go:366] PublishVolume: mounting /tmp/csi-staging at /tmp/csi-mount/target
I0426 15:01:54.625498 214412 mount_linux.go:138] Mounting cmd (systemd-run) with arguments ([--description=Kubernetes transient mount for /tmp/csi-mount/target --scope -- mount -o bind /tmp/csi-staging /tmp/csi-mount/target])
I0426 15:01:54.636746 214412 mount_linux.go:138] Mounting cmd (systemd-run) with arguments ([--description=Kubernetes transient mount for /tmp/csi-mount/target --scope -- mount -o bind,remount /tmp/csi-staging /tmp/csi-mount/target])
I0426 15:01:54.665978 214412 node.go:236] UnpublishVolume(volume_id:"ef3gu6pu151v67thndsc" target_path:"/tmp/csi-mount/target" )
I0426 15:01:54.666051 214412 node.go:249] UnpublishVolume: unmounting /tmp/csi-mount/target
I0426 15:01:54.666076 214412 mount_linux.go:203] Unmounting /tmp/csi-mount/target
I0426 15:01:54.694340 214412 node.go:139] UnstageVolume(volume_id:"ef3gu6pu151v67thndsc" staging_target_path:"/tmp/csi-staging" )
I0426 15:01:54.695213 214412 node.go:174] UnstageVolume: unmounting /tmp/csi-staging
I0426 15:01:54.695229 214412 mount_linux.go:203] Unmounting /tmp/csi-staging
I0426 15:01:54.716692 214412 controller.go:198] ControllerUnpublishVolume(volume_id:"ef3gu6pu151v67thndsc" node_id:"ef3rphg9mh60js6h4tpt" )
I0426 15:02:00.075137 214412 controller.go:223] ControllerUnpublishVolume: volume ef3gu6pu151v67thndsc detached from node ef3rphg9mh60js6h4tpt
I0426 15:02:00.075743 214412 controller.go:80] DeleteVolume(VolumeId=ef3gu6pu151v67thndsc)
I0426 15:02:03.614579 214412 node.go:236] UnpublishVolume(volume_id:"ef3gu6pu151v67thndsc" target_path:"/tmp/csi-mount" )
I0426 15:02:03.614705 214412 node.go:249] UnpublishVolume: unmounting /tmp/csi-mount
I0426 15:02:03.614753 214412 mount_linux.go:203] Unmounting /tmp/csi-mount
E0426 15:02:03.616796 214412 node.go:252] Could not unmount "/tmp/csi-mount": Unmount failed: exit status 32
Unmounting arguments: /tmp/csi-mount
Output: umount: /tmp/csi-mount: not mounted

I0426 15:02:03.617488 214412 node.go:139] UnstageVolume(volume_id:"ef3gu6pu151v67thndsc" staging_target_path:"/tmp/csi-staging" )
I0426 15:02:03.618271 214412 node.go:166] UnstageVolume: /tmp/csi-staging target not mounted
I0426 15:02:03.618700 214412 controller.go:198] ControllerUnpublishVolume(volume_id:"ef3gu6pu151v67thndsc" node_id:"ef3rphg9mh60js6h4tpt" )
E0426 15:02:03.814387 214412 controller.go:215] Disk unpublish operation failed: request-id = 05f937e6-6e5d-453e-ad2a-e1a49724a569 rpc error: code = InvalidArgument desc = Request validation error: Cannot find disk in instance by specified disk ID.
I0426 15:02:03.815061 214412 controller.go:80] DeleteVolume(VolumeId=ef3gu6pu151v67thndsc)

Note that the failing NodeUnpublishVolume is in fact the second one after the successfull previous one

[pohly]

The underlying problem is that once a test has failed, csi-sanity won't always be able to clean up. For example, if the driver leaves a mounted volume behind, then the usual os.RemoveAll will fail. So the latest code doesn't even try anything more than os.Remove and if that fails, any following os.Mkdir will fail.

IMHO the right solution is to run each test with its own mount and staging directory. Do you agree? This is already possible when using the Go API (just provide your own create/delete functions which dynamically allocate temp directories), but not when using the csi-sanity command.

Are you using the command? Which version?

[alexanderKhaustov]

The underlying problem is that once a test has failed, csi-sanity won't always be able to clean up. For example, if the driver leaves a mounted volume behind, then the usual os.RemoveAll will fail. So the latest code doesn't even try anything more than os.Remove and if that fails, any following os.Mkdir will fail.

Seems like the problem above is that if unmount fails (which happens because it is the second unmount attempt and the folder is already unmounted) then the directory is not deleted. And the test itself is not failing. I'd suggest attempting to remove the folder even if unmounting fails.

Are you using the command? Which version?
I've removed the test setup but it was a recent master version, the day of the post or the previous one

[pohly]

alexanderKhaustov <[email protected]> writes:

> The underlying problem is that once a test has failed, csi-sanity won't always be able to clean up. For example, if the driver leaves a mounted volume behind, then the usual `os.RemoveAll` will fail. So the latest code doesn't even try anything more than `os.Remove` and if that fails, any following `os.Mkdir` will fail. Seems like the problem above is that if unmount fails (which happens because it is the second unmount attempt and the folder is already unmounted) then the directory is not deleted. And the test itself is not failing. I'd suggest attempting to remove the folder even if unmounting fails.

Sorry, I don't follow. If unmounting succeeded, why does removing the folder fail? `os.Remove` is called. Also, you are saying that "unmount fails because it is the second unmount attempt and the folder is already unmounted". This sounds like the driver isn't idempotent? It's not an error to call NodeUnpublishVolume twice.

> Are you using the command? Which version? I've removed the test setup but it was a recent master version, the day of the post or the previous one

Were you using the csi-sanity command?

[alexanderKhaustov]

Sorry, I don't follow. If unmounting succeeded, why does removing the folder fail? os.Remove is called. Also, you are saying that "unmount fails because it is the second unmount attempt and the folder is already unmounted". This sounds like the driver isn't idempotent? It's not an error to call NodeUnpublishVolume twice.

It seemed that remove hasn't been called until after the second unmount attempt and maybe not at all. Still, your objection that driver seems to perform non-idempotently sounds reasonable. I'll look into it once more. Thanks!

Were you using the csi-sanity command?

Yes, I've been running the tests via the command

[fejta-bot]

Issues go stale after 90d of inactivity.
Mark the issue as fresh with /remove-lifecycle stale.
Stale issues rot after an additional 30d of inactivity and eventually close.

If this issue is safe to close now please do so with /close.

Send feedback to sig-testing, kubernetes/test-infra and/or fejta.
/lifecycle stale

[fejta-bot]

Stale issues rot after 30d of inactivity.
Mark the issue as fresh with /remove-lifecycle rotten.
Rotten issues close after an additional 30d of inactivity.

If this issue is safe to close now please do so with /close.

Send feedback to sig-testing, kubernetes/test-infra and/or fejta.
/lifecycle rotten

[fejta-bot]

Rotten issues close after 30d of inactivity.
Reopen the issue with /reopen.
Mark the issue as fresh with /remove-lifecycle rotten.

Send feedback to sig-testing, kubernetes/test-infra and/or fejta.
/close

[k8s-ci-robot]

@fejta-bot: Closing this issue.

In response to this:

Rotten issues close after 30d of inactivity.
Reopen the issue with /reopen.
Mark the issue as fresh with /remove-lifecycle rotten.

Send feedback to sig-testing, kubernetes/test-infra and/or fejta.
/close

Instructions for interacting with me using PR comments are available here. If you have questions or suggestions related to my behavior, please file an issue against the kubernetes/test-infra repository.