Mount snap "snapcraft" (1591) ([start snap-snapcraft-1591.mount] failed with exit status 1:

Bug #1772016 reported by Alan Pope 🍺🐧🐱 🦄 on 2018-05-18
14
This bug affects 4 people
Affects Status Importance Assigned to Milestone
snapd
High
Unassigned

Bug Description

I just issued a snap refresh on my laptop and got this when updating snapcraft. Other snaps updated okay. Seems like a horribly technical error message.

alan@hal:~$ snap refresh
error: cannot perform the following tasks:
- Mount snap "snapcraft" (1591) ([start snap-snapcraft-1591.mount] failed with exit status 1: Job for snap-snapcraft-1591.mount failed.
See "systemctl status snap-snapcraft-1591.mount" and "journalctl -xe" for details.
)

I have no idea what's going on.

130 alan@hal:~$ systemctl status snap-snapcraft-1591.mount
● snap-snapcraft-1591.mount
   Loaded: not-found (Reason: No such file or directory)
   Active: failed (Result: protocol) since Fri 2018-05-18 12:39:17 BST; 1min 49s ago

May 18 12:39:17 hal systemd[1]: Mounting Mount unit for snapcraft...
May 18 12:39:17 hal systemd[1]: snap-snapcraft-1591.mount: Mount process finished, but there is no mount.
May 18 12:39:17 hal systemd[1]: snap-snapcraft-1591.mount: Failed with result 'protocol'.
May 18 12:39:17 hal systemd[1]: Failed to mount Mount unit for snapcraft.

Here's the recent snap changes..

Status Spawn Ready Summary
Done 2018-05-18T11:39:12Z 2018-05-18T11:39:12Z Ensure prerequisites for "goxel" are available
Done 2018-05-18T11:39:12Z 2018-05-18T11:39:30Z Download snap "goxel" (531) from channel "edge"
Done 2018-05-18T11:39:12Z 2018-05-18T11:39:30Z Fetch and check assertions for snap "goxel" (531)
Done 2018-05-18T11:39:12Z 2018-05-18T11:39:32Z Mount snap "goxel" (531)
Done 2018-05-18T11:39:12Z 2018-05-18T11:39:32Z Run pre-refresh hook of "goxel" snap if present
Done 2018-05-18T11:39:12Z 2018-05-18T11:39:32Z Stop snap "goxel" services
Done 2018-05-18T11:39:12Z 2018-05-18T11:39:32Z Remove aliases for snap "goxel"
Done 2018-05-18T11:39:12Z 2018-05-18T11:39:32Z Make current revision for snap "goxel" unavailable
Done 2018-05-18T11:39:12Z 2018-05-18T11:39:32Z Copy snap "goxel" data
Done 2018-05-18T11:39:12Z 2018-05-18T11:39:33Z Setup snap "goxel" (531) security profiles
Done 2018-05-18T11:39:12Z 2018-05-18T11:39:33Z Make snap "goxel" (531) available to the system
Done 2018-05-18T11:39:12Z 2018-05-18T11:39:33Z Automatically connect eligible plugs and slots of snap "goxel"
Done 2018-05-18T11:39:12Z 2018-05-18T11:39:33Z Set automatic aliases for snap "goxel"
Done 2018-05-18T11:39:12Z 2018-05-18T11:39:33Z Setup snap "goxel" aliases
Done 2018-05-18T11:39:12Z 2018-05-18T11:39:33Z Run post-refresh hook of "goxel" snap if present
Done 2018-05-18T11:39:12Z 2018-05-18T11:39:33Z Start snap "goxel" (531) services
Done 2018-05-18T11:39:12Z 2018-05-18T11:39:33Z Remove data for snap "goxel" (509)
Done 2018-05-18T11:39:12Z 2018-05-18T11:39:34Z Remove snap "goxel" (509) from the system
Done 2018-05-18T11:39:12Z 2018-05-18T11:39:34Z Clean up "goxel" (531) install
Done 2018-05-18T11:39:12Z 2018-05-18T11:39:35Z Run configure hook of "goxel" snap if present
Done 2018-05-18T11:39:12Z 2018-05-18T11:39:23Z Ensure prerequisites for "snapcraft" are available
Undone 2018-05-18T11:39:12Z 2018-05-18T11:39:23Z Download snap "snapcraft" (1591) from channel "edge"
Done 2018-05-18T11:39:12Z 2018-05-18T11:39:19Z Fetch and check assertions for snap "snapcraft" (1591)
Error 2018-05-18T11:39:12Z 2018-05-18T11:39:18Z Mount snap "snapcraft" (1591)
Hold 2018-05-18T11:39:12Z 2018-05-18T11:39:18Z Run pre-refresh hook of "snapcraft" snap if present
Hold 2018-05-18T11:39:12Z 2018-05-18T11:39:18Z Stop snap "snapcraft" services
Hold 2018-05-18T11:39:12Z 2018-05-18T11:39:18Z Remove aliases for snap "snapcraft"
Hold 2018-05-18T11:39:12Z 2018-05-18T11:39:18Z Make current revision for snap "snapcraft" unavailable
Hold 2018-05-18T11:39:12Z 2018-05-18T11:39:18Z Copy snap "snapcraft" data
Hold 2018-05-18T11:39:12Z 2018-05-18T11:39:18Z Setup snap "snapcraft" (1591) security profiles
Hold 2018-05-18T11:39:12Z 2018-05-18T11:39:18Z Make snap "snapcraft" (1591) available to the system
Hold 2018-05-18T11:39:12Z 2018-05-18T11:39:18Z Automatically connect eligible plugs and slots of snap "snapcraft"
Hold 2018-05-18T11:39:12Z 2018-05-18T11:39:18Z Set automatic aliases for snap "snapcraft"
Hold 2018-05-18T11:39:12Z 2018-05-18T11:39:18Z Setup snap "snapcraft" aliases
Hold 2018-05-18T11:39:12Z 2018-05-18T11:39:18Z Run post-refresh hook of "snapcraft" snap if present
Hold 2018-05-18T11:39:12Z 2018-05-18T11:39:18Z Start snap "snapcraft" (1591) services
Hold 2018-05-18T11:39:12Z 2018-05-18T11:39:18Z Remove data for snap "snapcraft" (1574)
Hold 2018-05-18T11:39:12Z 2018-05-18T11:39:18Z Remove snap "snapcraft" (1574) from the system
Hold 2018-05-18T11:39:12Z 2018-05-18T11:39:18Z Clean up "snapcraft" (1591) install
Hold 2018-05-18T11:39:12Z 2018-05-18T11:39:18Z Run configure hook of "snapcraft" snap if present
Done 2018-05-18T11:39:12Z 2018-05-18T11:39:12Z Ensure prerequisites for "mattermost-desktop" are available
Done 2018-05-18T11:39:12Z 2018-05-18T11:39:14Z Download snap "mattermost-desktop" (60) from channel "edge"
Done 2018-05-18T11:39:12Z 2018-05-18T11:39:16Z Fetch and check assertions for snap "mattermost-desktop" (60)
Done 2018-05-18T11:39:12Z 2018-05-18T11:39:18Z Mount snap "mattermost-desktop" (60)
Done 2018-05-18T11:39:12Z 2018-05-18T11:39:18Z Run pre-refresh hook of "mattermost-desktop" snap if present
Done 2018-05-18T11:39:12Z 2018-05-18T11:39:19Z Stop snap "mattermost-desktop" services
Done 2018-05-18T11:39:12Z 2018-05-18T11:39:19Z Remove aliases for snap "mattermost-desktop"
Done 2018-05-18T11:39:12Z 2018-05-18T11:39:19Z Make current revision for snap "mattermost-desktop" unavailable
Done 2018-05-18T11:39:12Z 2018-05-18T11:39:21Z Copy snap "mattermost-desktop" data
Done 2018-05-18T11:39:12Z 2018-05-18T11:39:23Z Setup snap "mattermost-desktop" (60) security profiles
Done 2018-05-18T11:39:12Z 2018-05-18T11:39:23Z Make snap "mattermost-desktop" (60) available to the system
Done 2018-05-18T11:39:12Z 2018-05-18T11:39:23Z Automatically connect eligible plugs and slots of snap "mattermost-desktop"
Done 2018-05-18T11:39:12Z 2018-05-18T11:39:24Z Set automatic aliases for snap "mattermost-desktop"
Done 2018-05-18T11:39:12Z 2018-05-18T11:39:24Z Setup snap "mattermost-desktop" aliases
Done 2018-05-18T11:39:12Z 2018-05-18T11:39:24Z Run post-refresh hook of "mattermost-desktop" snap if present
Done 2018-05-18T11:39:12Z 2018-05-18T11:39:24Z Start snap "mattermost-desktop" (60) services
Done 2018-05-18T11:39:12Z 2018-05-18T11:39:24Z Clean up "mattermost-desktop" (60) install
Done 2018-05-18T11:39:12Z 2018-05-18T11:39:24Z Run configure hook of "mattermost-desktop" snap if present
Done 2018-05-18T11:39:12Z 2018-05-18T11:39:12Z Ensure prerequisites for "qownnotes" are available
Done 2018-05-18T11:39:12Z 2018-05-18T11:39:15Z Download snap "qownnotes" (966) from channel "stable"
Done 2018-05-18T11:39:12Z 2018-05-18T11:39:16Z Fetch and check assertions for snap "qownnotes" (966)
Done 2018-05-18T11:39:12Z 2018-05-18T11:39:18Z Mount snap "qownnotes" (966)
Done 2018-05-18T11:39:12Z 2018-05-18T11:39:18Z Run pre-refresh hook of "qownnotes" snap if present
Done 2018-05-18T11:39:12Z 2018-05-18T11:39:18Z Stop snap "qownnotes" services
Done 2018-05-18T11:39:12Z 2018-05-18T11:39:18Z Remove aliases for snap "qownnotes"
Done 2018-05-18T11:39:12Z 2018-05-18T11:39:19Z Make current revision for snap "qownnotes" unavailable
Done 2018-05-18T11:39:12Z 2018-05-18T11:39:21Z Copy snap "qownnotes" data
Done 2018-05-18T11:39:12Z 2018-05-18T11:39:21Z Setup snap "qownnotes" (966) security profiles
Done 2018-05-18T11:39:12Z 2018-05-18T11:39:21Z Make snap "qownnotes" (966) available to the system
Done 2018-05-18T11:39:12Z 2018-05-18T11:39:21Z Automatically connect eligible plugs and slots of snap "qownnotes"
Done 2018-05-18T11:39:12Z 2018-05-18T11:39:22Z Set automatic aliases for snap "qownnotes"
Done 2018-05-18T11:39:12Z 2018-05-18T11:39:22Z Setup snap "qownnotes" aliases
Done 2018-05-18T11:39:12Z 2018-05-18T11:39:22Z Run post-refresh hook of "qownnotes" snap if present
Done 2018-05-18T11:39:12Z 2018-05-18T11:39:22Z Start snap "qownnotes" (966) services
Done 2018-05-18T11:39:12Z 2018-05-18T11:39:22Z Remove data for snap "qownnotes" (954)
Done 2018-05-18T11:39:12Z 2018-05-18T11:39:23Z Remove snap "qownnotes" (954) from the system
Done 2018-05-18T11:39:12Z 2018-05-18T11:39:23Z Clean up "qownnotes" (966) install
Done 2018-05-18T11:39:12Z 2018-05-18T11:39:23Z Run configure hook of "qownnotes" snap if present

......................................................................
Mount snap "snapcraft" (1591)

2018-05-18T12:39:18+01:00 ERROR [start snap-snapcraft-1591.mount] failed with exit status 1: Job for snap-snapcraft-1591.mount failed.
See "systemctl status snap-snapcraft-1591.mount" and "journalctl -xe" for details.

Paweł Stołowski (stolowski) wrote :

This is an upstream issue around mount (a race likely) that we see from time to time in spread tests (and afair it was reproduced with a simple script, with no snapd involved). I don't think we can show any better error here. Zyga might know more.

Changed in snapd:
status: New → Triaged
importance: Undecided → High
Zygmunt Krynicki (zyga) wrote :

This is a bug in libmount. I'm tasked with fixing it this cycle. I will likely start working on it next week as it is getting more exposure with recent systemd update.

Changed in snapd:
assignee: nobody → Zygmunt Krynicki (zyga)

The problem can be reliably reproduced on Ubuntu 18.10, Fedora 28/29 and Arch using this script: https://gist.github.com/bboozzoo/d4b142229b1915ef7cc0cf8593599ad9

The basic variant, in parallel, creates mount units on the fly, calls systemd-reload, followed by start and stop. On my machine it takes one loop to fail with:

   systemd[1]: tmp-mounttest-mount-15.mount: Mount process finished, but there is no mount.
   systemd[1]: tmp-mounttest-mount-15.mount: Failed with result 'protocol'.
   systemd[1]: Failed to mount mount unit for test 15.

Note there are some variants in the script too. A variant where units are preloaded before was not seen to fail. Similarly, the variant using mount/umount directly. The variant using systemd-mount was flaky and is clearly missing some synchronization of the state information between systemd and systemd-mount.

Zygmunt Krynicki (zyga) on 2018-11-29
Changed in snapd:
assignee: Zygmunt Krynicki (zyga) → nobody
Michael Vogt (mvo) wrote :

The current PR that should workaround this bug in systemd is here: https://github.com/snapcore/snapd/pull/6331

Changed in snapd:
status: Triaged → In Progress
To post a comment you must log in.
This report contains Public information  Edit
Everyone can see this information.

Duplicates of this bug

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.