Hey everyone.
Once in a while we see a test failure where we ask systemd to mount a squashfs, systemd asks the kernel and the kernel says “yeah, mounted” but the mount point doesn’t show up in the mountinfo table. Systemd cross-checks that and returns a protocol error.
Systemd doing the cross-checking: https://github.com/systemd/systemd/blob/5300857701ff5e87169f3c90c6b570c750379dfb/src/core/mount.c#L1286
Kernel, snapd and systemd messages when this happens:
May 30 08:18:01 arch snapd[10146]: May 30 08:17:12 arch kernel: print_req_error: I/O error, dev loop1, sector 0
May 30 08:18:01 arch snapd[10146]: May 30 08:17:13 arch kernel: print_req_error: I/O error, dev loop2, sector 0
May 30 08:18:01 arch snapd[10146]: May 30 08:17:40 arch kernel: print_req_error: I/O error, dev loop1, sector 0
May 30 08:18:01 arch snapd[10146]: May 30 08:17:59 arch kernel: print_req_error: I/O error, dev loop2, sector 0
May 30 08:18:01 arch snapd[10146]: May 30 08:17:59 arch systemd[1]: var-lib-snapd-snap-test\x2dsnapd\x2dcontent\x2dslot-2.mount: Mount process finished, but there is no mount.
May 30 08:18:01 arch snapd[10146]: May 30 08:17:59 arch systemd[1]: var-lib-snapd-snap-test\x2dsnapd\x2dcontent\x2dslot-2.mount: Failed with result 'protocol'.
May 30 08:18:01 arch snapd[10146]: May 30 08:17:59 arch systemd[1]: Failed to mount Mount unit for test-snapd-content-slot, revision 2.
May 30 08:18:01 arch snapd[10146]: May 30 08:17:59 arch kernel: print_req_error: I/O error, dev loop2, sector 0
This was on a kernel version from Arch: 4.16.12-1-ARCH
What I found interesting in this log is that there are I/O errors from more than one loopback device, loop1 and loop2. In this particular case the snap was downloaded from the store and that results in assertion checks that would detect corrupted downloads. The same snap is downloaded over and over and mounted correctly so perhaps there’s some race in the kernel or perhaps the storage in the VM backing this test was just flaky.
Let’s please use this thread to coordinate and collect facts as this happens again.