Snapd 2.26.9 and conjure-up no longer work

adam.stokes · July 17, 2017, 5:51pm

I’m not entirely sure whats happening as I have the snap deb package installed at version 2.25 but running snap version shows it at 2.26.9

This is on a fresh xenial server installation and the only command that was run is

sudo snap install conjure-up --classic --edge

Once that happened thats when my snapd version was updated to 2.26.9 and conjure-up fails to start at all.

Get cloud support with Ubuntu Advantage Cloud Guest:
    http://www.ubuntu.com/business/services/cloud

0 packages can be updated.                                                                                                                                                 0 updates are security updates.                                                                                                                                            

                                                                                                                                                                           The programs included with the Ubuntu system are free software;
the exact distribution terms for each program are described in the
individual files in /usr/share/doc/*/copyright.                                                                                                                                                                                                                                                                                                       Ubuntu comes with ABSOLUTELY NO WARRANTY, to the extent permitted by                                                                                                       applicable law.
                                                                                                                                                                           To run a command as administrator (user "root"), use "sudo <command>".                                                                                                     See "man sudo_root" for details.

ubuntu@bobbybooshay:~$ snap info                                                                                                                                           error: the required argument `<snap> (at least 1 argument)` was not provided
ubuntu@bobbybooshay:~$ snap version
snap    2.25
snapd   2.25
series  16
ubuntu  16.04
kernel  4.4.0-83-generic
ubuntu@bobbybooshay:~$ sudo snap install conjure-up --classic --edge
2017-07-17T17:41:05Z INFO cannot auto connect core:core-support-plug to core:core-support: (slot auto-connection), existing connection state "core:core-support-plug core:core-support" in the way
conjure-up (edge) 2.3-alpha1-20170713.0307 from 'canonical' installed
ubuntu@bobbybooshay:~$ snap version
snap    2.26.9
snapd   2.26.9
series  16
ubuntu  16.04
kernel  4.4.0-83-generic
ubuntu@bobbybooshay:~$ conjure-up
Traceback (most recent call last):
  File "/snap/conjure-up/557/bin/conjure-up", line 11, in <module>
    load_entry_point('conjure-up==2.3a1', 'console_scripts', 'conjure-up')()
  File "/snap/conjure-up/557/lib/python3.6/site-packages/conjureup/app.py", line 257, in main
    utils.lxd_version(),
  File "/snap/conjure-up/557/lib/python3.6/site-packages/conjureup/utils.py", line 269, in lxd_version
    raise Exception("Could not determine LXD version.")
Exception: Could not determine LXD version.
ubuntu@bobbybooshay:~$ dpkg -l |grep snap
ii  snapd                              2.25                                       amd64        Tool to interact with Ubuntu Core Snappy.
ii  ubuntu-core-launcher               2.25                                       amd64        Transitional package for snapd
ubuntu@bobbybooshay:~$

Any ideas?

zyga-snapd · July 17, 2017, 5:58pm

Where is the source code of that fragment? Ideally we would look at what is being tested there

adam.stokes · July 17, 2017, 6:00pm

Code is here:

github.com

conjure-up/conjure-up/blob/master/conjureup/utils.py#L276


    cmd = run_script('{} version'.format(app.juju.bin_path))
    if cmd.returncode == 0:
        return parse_version(cmd.stdout.decode().strip())
    else:
        raise Exception("Could not determine Juju version.")
def snap_version():
    """ Get snap version
    """
    cmd = run_script('snap version')
    if cmd.returncode == 0:
        name_version_str = cmd.stdout.decode().splitlines()[0]
        try:
            name, version = name_version_str.split()
            if '~' in version:
                version, series = version.split('~')
            return parse_version(version)
        except:
            raise Exception("Could not determine Snap version.")

and you can see the wrapper in snap/wrappers/lxd

When calling conjure-up.lxd --version directly it reports the version just fine

adam.stokes · July 17, 2017, 6:16pm

update with help from @kyrofa I’ve found this error

ubuntu@bobbybooshay:~$ snap run --shell conjure-up.lxd
ubuntu@bobbybooshay:~$ conjure-up.lxd --version
Can not open /var/lib/snapd/seccomp/profiles//snap.conjure-up.lxd (No such file or directory)
aborting: No such file or directory

zyga-snapd · July 17, 2017, 6:29pm

This is much more interesting!

Conjure up is a classic snap. I suspect there is a bug in the new snap-seccomp and classic confinement (which doesn’t enforce seccomp on the started process). CC @mvo

zyga-snapd · July 17, 2017, 6:37pm

I just reproduced this

zyga-snapd · July 17, 2017, 6:56pm

So I think this is going on:

zyga@fyke:~/go/src/github.com/snapcore/snapd/client$ snap --version
snap    2.26.9
snapd   2.26.9
series  16
ubuntu  16.04
kernel  4.8.0-58-generic

Now let’s run a shell of a snap with classic confinement:

zyga@fyke:~/go/src/github.com/snapcore/snapd/client$ snap run --shell conjure-up.lxd
zyga@fyke:~/go/src/github.com/snapcore/snapd/client$ snap --version
snap    2.25
snapd   2.26.9
series  16
ubuntu  16.04
kernel  4.8.0-58-generic

What just happened? We are still in the main mount namespace so /usr/bin/snap is the distro version. We have however set SNAP_DID_REEXEC=1 and SNAP_REEXEC= so subsequent invocations of snap will just run from the distro package and never attempt to re-exec into the core snap.

This means that classic confinement snaps will use the wrong snap, the wrong snap-confine and won’t understand snap-seccomp.

zyga-snapd · July 17, 2017, 9:06pm

A fix has been made and is currently being tested. We are expecting to release 2.6.10 (or .11) first thing tomorrow CET. The PR is https://github.com/snapcore/snapd/pull/3598 the bug report is https://bugs.launchpad.net/snapd/+bug/1704860

zyga-snapd · July 18, 2017, 8:26pm

We believe this issue is now fixed in the beta channel of the core snap. Could you please try it out and give us your confirmation.

adam.stokes · July 18, 2017, 8:43pm

The beta version has restored conjure-up! Thank you !

vbijumon · July 19, 2017, 5:22am

Am also facing the same issue. can you share the steps to install beta version

zyga-snapd · July 19, 2017, 6:08am

Sue, just snap refresh core --beta

Aathi · July 19, 2017, 12:33pm

Thanks .its working as expected:slight_smile:

adam.stokes · July 19, 2017, 1:40pm

There still seems to be a few users that are running into this problem after installing the beta snap:

Can not open /var/lib/snapd/seccomp/profiles//snap.conjure-up.conjure-up (No such file or directory)
aborting: No such file or directory

snap version && snap list
snap    2.26.13
snapd   2.26.13
series  16
ubuntu  16.04
kernel  4.4.0-83-generic
Name        Version     Rev   Developer  Notes
conjure-up  2.2.2       549   canonical  classic
core        16-2.26.13  2445  canonical  -

zyga-snapd · July 19, 2017, 1:44pm

Aha, can you give us logs from the device? (journalctl -f, run the thing, save what was printed and add it here)

ramur · July 19, 2017, 1:52pm

journalctl -f
-- Logs begin at Wed 2017-07-19 06:28:34 PDT. --
Jul 19 06:34:09 ubudoc3 kernel: audit: type=1400 audit(1500471249.642:55): apparmor="DENIED" operation="file_inherit" profile="/usr/lib/snapd/snap-confine" name="/dev/tty" pid=2873 comm="snap-confine" requested_mask="wr" denied_mask="wr" fsuid=0 ouid=0
Jul 19 06:38:43 ubudoc3 anacron[1282]: Job `cron.weekly' started
Jul 19 06:38:43 ubudoc3 anacron[3187]: Updated timestamp for job `cron.weekly' to 2017-07-19
Jul 19 06:38:46 ubudoc3 anacron[1282]: Job `cron.weekly' terminated
Jul 19 06:43:38 ubudoc3 systemd[1]: Starting Cleanup of Temporary Directories...
Jul 19 06:43:38 ubudoc3 systemd-tmpfiles[3279]: [/usr/lib/tmpfiles.d/var.conf:14] Duplicate line for path "/var/log", ignoring.
Jul 19 06:43:38 ubudoc3 systemd[1]: Started Cleanup of Temporary Directories.
Jul 19 06:43:43 ubudoc3 anacron[1282]: Job `cron.monthly' started
Jul 19 06:43:43 ubudoc3 anacron[1282]: Job `cron.monthly' terminated
Jul 19 06:43:43 ubudoc3 anacron[1282]: Normal exit (2 jobs run)

zyga-snapd · July 19, 2017, 1:53pm

This doesn’t seem to contain the moment when you run a snap command. Typically we’d see a message like this one lip 19 15:52:58 fyke snap[12619]: cmd.go:118: DEBUG: restarting into "/snap/core/current/usr/bin/snap"

adam.stokes · July 19, 2017, 1:59pm

Maybe like journal -xe?

ramur · July 19, 2017, 2:03pm

journalctl -f
-- Logs begin at Wed 2017-07-19 07:01:39 PDT. --
Jul 19 07:03:07 ubudoc3 ureadahead[440]: ureadahead:mask: Ignored relative path
Jul 19 07:03:07 ubudoc3 ureadahead[440]: ureadahead:network: Ignored relative path
Jul 19 07:03:07 ubudoc3 ureadahead[440]: ureadahead:.: Ignored relative path
Jul 19 07:03:07 ubudoc3 ureadahead[440]: ureadahead:af_unix: Ignored relative path
Jul 19 07:03:07 ubudoc3 ureadahead[440]: Counted 8 CPUs
Jul 19 07:03:07 ubudoc3 systemd[1]: Stopped Read required files in advance.
Jul 19 07:03:09 ubudoc3 conjure-up[2982]: cmd.go:105: DEBUG: restarting into "/snap/core/current/usr/bin/snap"
Jul 19 07:03:09 ubudoc3 conjure-up[2982]: cmd.go:149: DEBUG: re-exec disabled by user
Jul 19 07:03:11 ubudoc3 audit[3003]: AVC apparmor="DENIED" operation="file_inherit" profile="/usr/lib/snapd/snap-confine" name="/dev/tty" pid=3003 comm="snap-confine" requested_mask="wr" denied_mask="wr" fsuid=1000 ouid=0
Jul 19 07:03:11 ubudoc3 kernel: audit: type=1400 audit(1500472991.464:55): apparmor="DENIED" operation="file_inherit" profile="/usr/lib/snapd/snap-confine" name="/dev/tty" pid=3003 comm="snap-confine" requested_mask="wr" denied_mask="wr" fsuid=1000 ouid=0
Jul 19 07:03:27 ubudoc3 kernel: usb 3-8: new low-speed USB device number 3 using xhci_hcd
Jul 19 07:03:27 ubudoc3 kernel: usb 3-8: New USB device found, idVendor=046d, idProduct=c05a
Jul 19 07:03:27 ubudoc3 kernel: usb 3-8: New USB device strings: Mfr=1, Product=2, SerialNumber=0
Jul 19 07:03:27 ubudoc3 kernel: usb 3-8: Product: USB Optical Mouse
Jul 19 07:03:27 ubudoc3 kernel: usb 3-8: Manufacturer: Logitech
Jul 19 07:03:27 ubudoc3 kernel: usb 3-8: ep 0x81 - rounding interval to 64 microframes, ep desc says 80 microframes
Jul 19 07:03:27 ubudoc3 kernel: input: Logitech USB Optical Mouse as /devices/pci0000:00/0000:00:14.0/usb3/3-8/3-8:1.0/0003:046D:C05A.0002/input/input14
Jul 19 07:03:27 ubudoc3 kernel: hid-generic 0003:046D:C05A.0002: input,hidraw1: USB HID v1.11 Mouse [Logitech USB Optical Mouse] on usb-0000:00:14.0-8/input0
Jul 19 07:03:27 ubudoc3 mtp-probe[3024]: checking bus 3, device 3: "/sys/devices/pci0000:00/0000:00:14.0/usb3/3-8"
Jul 19 07:03:27 ubudoc3 mtp-probe[3024]: bus: 3, device: 3 was not an MTP device

mvo · July 19, 2017, 2:17pm

Thanks for this log! What is the output of:
apt list snapd
on a terminal? That would help us to reproduce the issue!