SemLock and execution slowness

[Alvaro Uria]

bsrally snap (see [1], copied and updated from fcbtest[2]) fails when the last part (libc-shm-shim) is not included. The way to reproduce it is by running:
"""
bsrally.rally plugin list --platform openstack
"""

The error is pasted in [3] (PermissionDenied due to libpthread-2.27.so, libpthread.so.0 and lib64/ld-linux-x86-64.so.2 not being available).

OTOH, I have run rally+rally-openstack+tempest (same versions) by following the install_rally.sh script, which creates a virtualenvironment, and I have compared it with the snap (when libc-shm-shim part is included), and I notice ~4s lag on the snap. I have tried to trace the issue by running the command in front of strace but I get:
"""
execve("/snap/snapd/4605/usr/lib/snapd/snap-confine", ["/snap/snapd/4605/usr/lib/snapd/s"..., "--base", "core18", "snap.bsrally.rally", "/usr/lib/snapd/snap-exec", "bsrally.rally", "--config-file", "/home/nagiososc/rally.conf", "verify", "list-verifiers"], 0xc4200b5c80 /* 45 vars */) = -1 EACCES (Permission denied)
write(2, "internal error, please report: r"..., 81internal error, please report: running "bsrally.rally" failed: permission denied
) = 81
exit_group(4)
"""

Could you please advice on how to improve the snapcraft.yaml definition (if needed) and how to troubleshoot the slowness at the beginning of the execution?

Thank you.

1. https://github.com/auria/bsrally/blob/master/snapcraft.yaml
2. https://github.com/lolwww/fcbtest/blob/master/snapcraft.yaml
3. https://pastebin.ubuntu.com/p/JrCvbbz4MW/

[Ian Johnson (anonymouse67)]

What is the output of `snap run --trace-exec $SNAP_NAME.$SNAP_APP` ?

Note that using strace directly with `snap run` doesn't work well, but you can use `snap run --strace $SNAP_NAME.$SNAP_APP`

[Alvaro Uria (aluria)]

root@juju-b6ff74-29:~# snap run --trace-exec bsrally.rally
/usr/bin/strace: exec: Permission denied
error: exit status 1

After giving full privilege in sudoers:
"""
nagiososc ALL=(ALL) NOPASSWD:ALL

nagiososc@juju-b6ff74-29:~$ snap run --strace bsrally.rally --config-file /home/nagiososc/rally.conf verify list-verifiers
error: exit status 1
"""

Running time:
"""
nagiososc@juju-b6ff74-29:~$ time bsrally.rally --config-file /home/nagiososc/rally.conf verify list-verifiers
+--------------------------------------+-----------------+---------+-----------+---------------------+---------------------+-----------+-------------+-------------+--------+
| UUID | Name | Type | Platform | Created at | Updated at | Status | Version | System-wide | Active |
+--------------------------------------+-----------------+---------+-----------+---------------------+---------------------+-----------+-------------+-------------+--------+
| 045ffc5e-e915-4f13-a30c-2ca43745ae81 | tempestverifier | tempest | openstack | 2019-09-18T14:41:51 | 2019-09-18T14:41:55 | installed | tags/21.0.0 | True | :-) |
+--------------------------------------+-----------------+---------+-----------+---------------------+---------------------+-----------+-------------+-------------+--------+

real 0m20.989s
user 0m8.801s
sys 0m0.843s
"""

The difference with the virtual environment (no snap) is:
"""
(rally) nagiososc@juju-b6ff74-23:~$ time rally verify list-verifiers
+--------------------------------------+-----------------+---------+-----------+---------------------+---------------------+-----------+---------+-------------+--------+
| UUID | Name | Type | Platform | Created at | Updated at | Status | Version | System-wide | Active |
+--------------------------------------+-----------------+---------+-----------+---------------------+---------------------+-----------+---------+-------------+--------+
| 47cbeeb6-e1e5-4e35-bf34-b8aa883ebadc | tempestverifier | tempest | openstack | 2019-09-17T14:35:46 | 2019-09-17T14:36:22 | installed | 21.0.0 | False | :-) |
+--------------------------------------+-----------------+---------+-----------+---------------------+---------------------+-----------+---------+-------------+--------+

real 0m4.781s
user 0m3.599s
sys 0m0.628s
"""

OTOH, for reference on libc-shm-shim, please check:
https://forum.snapcraft.io/t/request-for-18-track-for-libc-shm-shim-snap/8885

[Alvaro Uria (aluria)]

The snap is running on a LXD container. I have now enabled security.privileged and security.nesting but it still fails.

newfstatat(AT_FDCWD, "/usr/bin/strace", {st_mode=S_IFREG|0755, st_size=1378552, ...}, 0) = 0
pipe2([7, 8], O_CLOEXEC) = 0
getpid() = 935
rt_sigprocmask(SIG_SETMASK, NULL, [], 8) = 0
rt_sigprocmask(SIG_SETMASK, ~[], NULL, 8) = 0
clone(child_stack=NULL, flags=CLONE_VM|CLONE_VFORK|SIGCHLD) = 958
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
close(8) = 0
read(7, "", 8) = 0
close(7) = 0
waitid(P_PID, 958, /usr/bin/strace: exec: Permission denied
{si_signo=SIGCHLD, si_code=CLD_EXITED, si_pid=958, si_uid=0, si_status=1, si_utime=0, si_stime=0}, WEXITED|WNOWAIT, NULL) = 0
--- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_EXITED, si_pid=958, si_uid=0, si_status=1, si_utime=0, si_stime=0} ---
rt_sigreturn({mask=[]}) = 0
wait4(958, [{WIFEXITED(s) && WEXITSTATUS(s) == 1}], 0, {ru_utime={tv_sec=0, tv_usec=4493}, ru_stime={tv_sec=0, tv_usec=9807}, ...}) = 958
epoll_ctl(4, EPOLL_CTL_DEL, 5, 0xc4202593d4) = 0
close(5) = 0
futex(0x5640ce3e9d28, FUTEX_WAIT, 0, NULL) = 0
epoll_pwait(4, [], 128, 0, NULL, 0) = 0
epoll_pwait(4, error: exit status 1
 <unfinished ...>) = ?
+++ exited with 1 +++

[Alvaro Uria (aluria)]

Another snippet:
"""
$ sudo snap run --strace=--raw bsrally.rally --config-file /home/nagiososc/rally.conf verify list-verifiers
execve("/snap/snapd/4605/usr/lib/snapd/snap-confine", ["/snap/snapd/4605/usr/lib/snapd/s"..., "--base", "core18", "snap.bsrally.rally", "/usr/lib/snapd/snap-exec", "bsrally.rally", "--config-file", "/home/nagiososc/rally.conf", "verify", "list-verifiers"], 0x7ffff897ce00 /* 38 vars */) = -1 EACCES (Permission denied)
fstat(2, {st_mode=S_IFIFO|0600, st_size=0, ...}) = 0
write(2, "/usr/bin/strace: exec: Permissio"..., 41/usr/bin/strace: exec: Permission denied
) = 41
getpid() = 2574
exit_group(1) = ?
+++ exited with 1 +++
error: exit status 1
"""

If apparmor is torn down, snap-confine won't run.

Snapd version is 2.40+18.04, and the snap uses core18. Could there be a bug on core18?

[Zygmunt Krynicki (zyga)]

I'm marking this as invalid because this is a support request. At the same time I would like to encourage you to keep discussing this. If the outcome is that there is a bug in snapd then please feel free to reopen this.

[Alvaro Uria (aluria)]

Thank you. I'll follow the conversation at https://forum.snapcraft.io/t/snap-performance-and-troubleshooting-issues/13324