test ubuntu-21.10-64:tests/main/services-install-hook-can-run-svcs:enableflag is flaky

[Ian Johnson]

The test sometimes fails because the snapctl command hangs when the install hook tries to start the service:

+ /home/gopath/src/github.com/snapcore/snapd/tests/lib/tools/snaps-state install-local test-snapd-install-hook-runs-svc
error: cannot perform the following tasks:
- Run install hook of "test-snapd-install-hook-runs-svc" snap if present (run hook "install":
-----
DEBUG: performing operation: (disabled) use debug build to see details
DEBUG: performing operation: (disabled) use debug build to see details
DEBUG: performing operation: (disabled) use debug build to see details
DEBUG: performing operation: (disabled) use debug build to see details
DEBUG: performing operation: (disabled) use debug build to see details
DEBUG: performing operation: (disabled) use debug build to see details
DEBUG: performing operation: (disabled) use debug build to see details
DEBUG: performing operation: (disabled) use debug build to see details
DEBUG: performing operation: (disabled) use debug build to see details
DEBUG: performing operation: (disabled) use debug build to see details
DEBUG: performing operation: (disabled) use debug build to see details
DEBUG: performing operation: (disabled) use debug build to see details
DEBUG: performing operation: (disabled) use debug build to see details
DEBUG: performing operation: (disabled) use debug build to see details
DEBUG: performing operation: (disabled) use debug build to see details
DEBUG: performing operation: (disabled) use debug build to see details
DEBUG: performing operation: (disabled) use debug build to see details
DEBUG: performing operation: (disabled) use debug build to see details
DEBUG: performing operation: (disabled) use debug build to see details
DEBUG: performing operation: (disabled) use debug build to see details
DEBUG: set_effective_identity uid:0 (change: no), gid:0 (change: yes)
DEBUG: set_effective_identity uid:0 (change: no), gid:0 (change: yes)
DEBUG: performing operation: (disabled) use debug build to see details
DEBUG: set_effective_identity uid:0 (change: no), gid:0 (change: yes)
DEBUG: set_effective_identity uid:0 (change: no), gid:0 (change: yes)
DEBUG: performing operation: (disabled) use debug build to see details
DEBUG: performing operation: (disabled) use debug build to see details
DEBUG: performing operation: (disabled) use debug build to see details
DEBUG: performing operation: (disabled) use debug build to see details
DEBUG: performing operation: (disabled) use debug build to see details
DEBUG: performing operation: (disabled) use debug build to see details
DEBUG: performing operation: (disabled) use debug build to see details
DEBUG: performing operation: (disabled) use debug build to see details
DEBUG: performing operation: (disabled) use debug build to see details
DEBUG: performing operation: (disabled) use debug build to see details
DEBUG: performing operation: (disabled) use debug build to see details
DEBUG: performing operation: (disabled) use debug build to see details
DEBUG: set_effective_identity uid:0 (change: no), gid:0 (change: yes)
DEBUG: set_effective_identity uid:0 (change: no), gid:0 (change: yes)
DEBUG: performing operation: (disabled) use debug build to see details
DEBUG: performing operation: (disabled) use debug build to see details
DEBUG: performing operation: pivot_root /tmp/snap.rootfs_tXbtoL /tmp/snap.rootfs_tXbtoL//var/lib/snapd/hostfs
DEBUG: performing operation: (disabled) use debug build to see details
DEBUG: performing operation: rmdir /var/lib/snapd/hostfs//tmp/snap.rootfs_tXbtoL
DEBUG: performing operation: (disabled) use debug build to see details
DEBUG: performing operation: (disabled) use debug build to see details
DEBUG: performing operation: (disabled) use debug build to see details
DEBUG: performing operation: (disabled) use debug build to see details
DEBUG: set_effective_identity uid:0 (change: no), gid:0 (change: yes)
DEBUG: set_effective_identity uid:0 (change: no), gid:0 (change: yes)
DEBUG: performing operation: (disabled) use debug build to see details
DEBUG: performing operation: (disabled) use debug build to see details
DEBUG: performing operation: (disabled) use debug build to see details
DEBUG: performing operation: (disabled) use debug build to see details
DEBUG: set_effective_identity uid:0 (change: no), gid:0 (change: yes)
DEBUG: calling snapd tool snap-update-ns
DEBUG: waiting for snapd tool snap-update-ns to terminate
DEBUG: changing apparmor hat to mount-namespace-capture-helper
DEBUG: helper process waiting for command
DEBUG: sanity timeout initialized and set for 30 seconds
DEBUG: requesting changing of apparmor profile on next exec to snap-update-ns.test-snapd-install-hook-runs-svc
common.go:60: DEBUG: locking mount namespace of snap "test-snapd-install-hook-runs-svc"
common.go:81: DEBUG: freezing processes of snap "test-snapd-install-hook-runs-svc"
freezer.go:197: DEBUG: freeze, skipping own group /sys/fs/cgroup/system.slice/snap.test-snapd-install-hook-runs-svc.hook.install.1f0355c9-1a3a-4927-a60b-db5285ccbd83.scope
common.go:89: DEBUG: unlocking mount namespace of snap "test-snapd-install-hook-runs-svc"
common.go:91: DEBUG: thawing processes of snap "test-snapd-install-hook-runs-svc"
DEBUG: snap-update-ns finished successfully
DEBUG: set_effective_identity uid:0 (change: no), gid:0 (change: yes)
DEBUG: saved mount namespace meta-data to /run/snapd/ns/snap.test-snapd-install-hook-runs-svc.info
DEBUG: sending command 1 to helper process (pid: 145086)
DEBUG: waiting for response from helper
DEBUG: sanity timeout reset and disabled
DEBUG: helper process received command 1
DEBUG: capturing per-snap mount namespace
DEBUG: mount namespace of process 145076 preserved as test-snapd-install-hook-runs-svc.mnt
DEBUG: helper process waiting for command
DEBUG: sanity timeout initialized and set for 30 seconds
DEBUG: releasing lock 8
DEBUG: sending command 0 to helper process (pid: 145086)
DEBUG: waiting for response from helper
DEBUG: sanity timeout reset and disabled
DEBUG: helper process received command 0
DEBUG: helper process exiting
DEBUG: waiting for the helper process to exit
DEBUG: helper process exited normally
DEBUG: resetting PATH to values in sync with core snap
DEBUG: set_effective_identity uid:0 (change: yes), gid:0 (change: yes)
DEBUG: creating user data directory: /root/snap/test-snapd-install-hook-runs-svc/x1
DEBUG: requesting changing of apparmor profile on next exec to snap.test-snapd-install-hook-runs-svc.hook.install
DEBUG: ruid: 0, euid: 0, suid: 0
DEBUG: loading bpf program for security tag snap.test-snapd-install-hook-runs-svc.hook.install
DEBUG: read 6128 bytes from /var/lib/snapd/seccomp/bpf//snap.test-snapd-install-hook-runs-svc.hook.install.bin
DEBUG: read 152 bytes from /var/lib/snapd/seccomp/bpf/global.bin
DEBUG: execv(/usr/lib/snapd/snap-exec, /usr/lib/snapd/snap-exec...)
DEBUG: argv[1] = --hook=install
DEBUG: argv[2] = test-snapd-install-hook-runs-svc
DEBUG: umask restored to 022
DEBUG: working directory re-interpreted to /
error: error running snapctl: start command is taking too long
-----)

Full log at https://pastebin.ubuntu.com/p/nWTKCRxTDZ/