Comment 1 for bug 1970477
Revision history for this message
| Maciej Borzecki (maciek-borzecki) wrote | #1 |
© 2004
Canonical Ltd.
•
Terms of use
•
Data privacy
•
Contact Launchpad Support
•
Blog
•
Careers
•
System status
•
0e1f616
(Get the code!)
Thank you for reporting this. I was able to partially reproduce the problem in a VM. I think there are at least 2 issues that interact in a bad way.
First, snapd uses a systemd watchdog to monitor itself. We extend the watchdog wait for startup to complete by some generous estimate, but that estimate proves to be too low for a very slow VM. When inspecting `journalctl -u snapd` you would see a log similar to this:
Apr 27 07:38:10 lubuntu snapd[858]: daemon.go:340: adjusting startup timeout by 1m0s (pessimistic estimate of 30s plus 5s per snap)
Apr 27 07:38:13 lubuntu snapd[858]: backend.go:146: snapd enabled root filesystem on overlay support, additional upperdir permissions granted
Apr 27 07:39:11 lubuntu systemd[1]: snapd.service: start operation timed out. Terminating.
Apr 27 07:40:41 lubuntu systemd[1]: snapd.service: State 'stop-sigterm' timed out. Killing.
Apr 27 07:40:41 lubuntu systemd[1]: snapd.service: Killing process 858 (snapd) with signal SIGKILL.
Apr 27 07:40:41 lubuntu systemd[1]: snapd.service: Main process exited, code=killed, status=9/KILL
Then, firefox is one of the seeded snaps. So it will be installed in the system, but running the firefox's configure hook fails, because it takes way longer than expected to even start it. In this case, the problem appears to be in snap-confine, when it launches a program to adjust the snap's mount namespace according to the layout it requires, there is a 30s timeout, which is hit before the setup is completed:
Apr 27 07:43:01 lubuntu snapd[1156]: taskrunner.go:271: [change 1 "Run configure hook of \"firefox\" snap if present" task] failed: run hook "configure":
Apr 27 07:43:01 lubuntu snapd[1156]: -----
Apr 27 07:43:01 lubuntu snapd[1156]: sanity timeout expired: Interrupted system call
Apr 27 07:43:01 lubuntu snapd[1156]: update.go:85: cannot change mount namespace according to change mount (/var/lib/
Apr 27 07:43:01 lubuntu snapd[1156]: cannot send command 1 to helper process: Broken pipe
Apr 27 07:43:01 lubuntu snapd[1156]: -----
Since the hook failed, the whole process gets undone, and hence firefox is unavailable. Now, snapd has support for preseeding, but I'm not sure if it was used in this scenario, though the timinigs data suggest that plug connections took only couple ms, so I'm guessing pre-generated profiles were used after all.
Some logs I colleted from the VM:
- full log here: https:/
- snap change 1: https:/
- snap debug seeding: https:/
- timinigs of seeding: https:/
The question is whether the problem happens only in a painfully slow VM (TBH I can't even run the 'Try Ubuntu' in such VM), or does it also happen on real, but slow machines?