Comment 12 for bug 1599799

Federico Gimenez [2016-07-14 13:03 -0000]:
> * Where do you get this "basic.snap" from?
>
> It is built from the source files, from the root of the project
> something like:
>
> integration-tests/bin/snapbuild integration-tests/data/snaps/basic .

integration-tests/bin/ does not exist, and tests/lib/snapbuild is a
directory with just "main.go" in it. This is true for both the
original source dir and the copy in
$AUTOPKGTEST_ARTIFACTS/build/src/github.com/snapcore/snapd
that the test creates.

> To run a single test:
> SNAP_REEXEC=0 ./tests.test -check.vv -check.f <name_of_test>

OK, just running snapOpSuite.TestRemoveBusyRetries succeeds on xenial
and fails on yakkety.

In yakkety there is a failed service after the test failure:

| ● umount-blocker.service - /snap/bin/basic-binaries.block
| Loaded: loaded (/run/systemd/transient/umount-blocker.service; transient; vendor preset: enabled)
| Transient: yes
| Active: failed (Result: exit-code) since Thu 2016-07-14 16:07:16 CEST; 7min ago
| Main PID: 12533 (code=exited, status=1/FAILURE)
|
| Jul 14 16:07:16 autopkgtest systemd[1]: Started /snap/bin/basic-binaries.block.
| Jul 14 16:07:16 autopkgtest basic-binaries.block[12533]: unable to bind /snap/ubuntu-core/current//bin to /bin. errmsg: Permission denied
| Jul 14 16:07:16 autopkgtest systemd[1]: umount-blocker.service: Main process exited, code=exited, status=1/FAILURE

Is that permission error expected? I. e. is umount-blocker.service
supposed to fail for that test, or is that part of the bug?

In Xenial, after the test succeeds, umount-blocker.service succeeded:

| ● umount-blocker.service
| Loaded: not-found (Reason: No such file or directory)
| Active: inactive (dead)
|
| Jul 14 16:19:59 autopkgtest systemd[1]: Started /snap/bin/basic-binaries.block.
| Jul 14 16:19:59 autopkgtest basic-binaries.block[9982]: + cd /snap/basic-binaries/x1
| Jul 14 16:19:59 autopkgtest basic-binaries.block[9982]: + pwd
| Jul 14 16:19:59 autopkgtest basic-binaries.block[9982]: + echo blocking dir /snap/basic-binaries/x1
| Jul 14 16:19:59 autopkgtest basic-binaries.block[9982]: blocking dir /snap/basic-binaries/x1
| Jul 14 16:19:59 autopkgtest basic-binaries.block[9982]: + echo waiting, press ctrl-c to stop
| Jul 14 16:19:59 autopkgtest basic-binaries.block[9982]: waiting, press ctrl-c to stop
| Jul 14 16:19:59 autopkgtest basic-binaries.block[9982]: + sleep 999999
| Jul 14 16:19:59 autopkgtest systemd[1]: Stopping /snap/bin/basic-binaries.block...
| Jul 14 16:19:59 autopkgtest systemd[1]: Stopped /snap/bin/basic-binaries.block.

So I suppose its failure in yakkety is a bug. Instead, a different unit fails:

| ● snap-basic\x2dbinaries-x1.mount
| Loaded: not-found (Reason: No such file or directory)
| Active: failed (Result: exit-code) since Thu 2016-07-14 16:19:59 CEST; 1min 3s ago
|
| Jul 14 16:19:58 autopkgtest systemd[1]: Mounted Mount unit for basic-binaries.
| Jul 14 16:19:59 autopkgtest systemd[1]: Unmounting Mount unit for basic-binaries...
| Jul 14 16:19:59 autopkgtest umount[10002]: umount: /snap/basic-binaries/x1: target is busy
| Jul 14 16:19:59 autopkgtest umount[10002]: (In some cases useful info about processes that
| Jul 14 16:19:59 autopkgtest umount[10002]: use the device is found by lsof(8) or fuser(1).)
| Jul 14 16:19:59 autopkgtest systemd[1]: snap-basic\x2dbinaries-x1.mount: Mount process exited, code=exited status=32
| Jul 14 16:19:59 autopkgtest systemd[1]: Failed unmounting Mount unit for basic-binaries.
| Jul 14 16:19:59 autopkgtest systemd[1]: Unmounting Mount unit for basic-binaries...
| Jul 14 16:19:59 autopkgtest systemd[1]: Unmounted Mount unit for basic-binaries.
| Jul 14 16:19:59 autopkgtest systemd[1]: snap-basic\x2dbinaries-x1.mount: Unit entered failed state.

Maybe that "busy" is due to the successful umount-blocker.service and
this is part of the test?

Any snapd developer who actually has a clue how this works: Please
drill this down into a small reproducer of observable commands, then
we can investigate/bisect where in the stack this happened.