System fails to reboot from live session or ubiquity-dm - squashfs_read_data failed to read block

Diff between the manifests of 20190715 and 20190716.

There are 2 suspects from this list:
casper 1.413 (from 1.4.11)
linux-image 5.2.0-8.9 (from 5.0.0-20.21

This bug is missing log files that will aid in diagnosing the problem. While running an Ubuntu kernel (not a mainline or third-party kernel) please enter the following command in a terminal window:

apport-collect 1840122

and then change the status of the bug to 'Confirmed'.

If, due to the nature of the issue you have encountered, you are unable to run this command, please add a comment stating that fact and change the bug status to 'Confirmed'.

This change has been made by an automated script, maintained by the Ubuntu Kernel Team.

apport information

apport information

apport information

apport information

apport information

apport information

apport information

apport information

apport information

apport information

apport information

apport information

apport information

apport information

apport information

apport information

apport information

I had a look at this and got pretty confused! Feels more like a kernel problem than a casper one, somehow.

I tested it with the current iso (2019-09-17).

1. Booted into live session
2. Waited for 30 minutes
3. Restarted via System menu
4. Restart of the system was successful without any error

Can anybody test it and verify it if it works for them too?

Thanks

Booted daily Ubuntu x86_64 19.10 (2019-09-17) on
hp 8200 elite sff (i5-2400, 8gb, nvidia quadro 600)

Booted live, waited 5 mins
Suspend system, waited 2 mins (was looking at wrong test-steps screen, noting here as 2 mins had passed before I noticed my mistake)
resumed system, waited 2 mins
Clicked restart top-right of display

No issue, system restarted.

I did it again, shorter (untimed) wait times without suspending on same box (it was much much slower to restart this time, but did restart)

I'm having this problem when installing in QEMU/KVM vms. If I disconnect the ISO as per install instructions, the system hangs, with the errors shown in the OP if I choose another tty. Leaving the ISO attached allows the system to reboot but it boots into the ISO.

While recreating this with an image from today I noticed that before seeing the squashfs errors, after pressing an error key in the plymouth screen, there were messages regarding "Failed unmounting /cdrom". I've attached a screenshot showing the messages.

subiquity image has similar, but it manages to reboot fine (attaching subiquity screenshots)

squashfs errors are still bad though.

This bug was fixed in the package casper - 1.421

---------------
casper (1.421) eoan; urgency=medium

  * Drop empty directory (doesn't track well in git)
  * Use debian/casper.dirs to install conf.d

casper (1.420) eoan; urgency=medium

  * Add dependency on finalrd for reliable live-session shutdown. Casper
    setup live systems do have layering violations (/ actually depends on
    /cdrom) and it appears that (although masked) the system manages to
    rip it out, resulting in filesystem errors preventing completing the
    shutdown. That's where pivot to finalrd comes in, to save the day and
    blast the running system into oblivion and complete the shutdown. LP:
    #1840122

 -- Dimitri John Ledkov <email address hidden> Tue, 01 Oct 2019 13:05:51 +0100

Install into QEMU/KVM vm with Ubuntu desktop 20191001.2 completed successfully.

Hello Jean-Baptiste, or anyone else affected,

Accepted casper into bionic-proposed. The package will build now and be available at https://launchpad.net/ubuntu/+source/casper/1.394.3 in a few hours, and then in the -proposed repository.

Please help us by testing this new package. To properly test it you will need to obtain and boot a daily build of a Live CD for bionic. Your feedback will aid us getting this update out to other Ubuntu users.

If this package fixes the bug for you, please add a comment to this bug, mentioning the version of the package you tested and change the tag from verification-needed-bionic to verification-done-bionic. If it does not fix the bug for you, please add a comment stating that, and change the tag to verification-failed-bionic. In either case, without details of your testing we will not be able to proceed.

Further information regarding the verification process can be found at https://wiki.ubuntu.com/QATeam/PerformingSRUVerification . Thank you in advance for helping!

N.B. The updated package will be released to -updates after the bug(s) fixed by this package have been verified and the package has been in -proposed for a minimum of 7 days.

I verified on Ubuntu Desktop 20200128, that casper from proposed pulls finalrd and that it successfully fixes the issue on both a VM and baremetal.

Marking as verification-done.

This bug was fixed in the package casper - 1.394.3

---------------
casper (1.394.3) bionic; urgency=medium

  * Cherrypick from eoan: Add dependency on finalrd for reliable
    live-session shutdown. Casper setup live systems do have layering
    violations (/ actually depends on /cdrom) and it appears that
    (although masked) the system manages to rip it out, resulting in
    filesystem errors preventing completing the shutdown. That's where
    pivot to finalrd comes in, to save the day and blast the running
    system into oblivion and complete the shutdown. LP: #1840122

 -- Dimitri John Ledkov <email address hidden> Tue, 28 Jan 2020 11:09:52 +0000

The verification of the Stable Release Update for casper has completed successfully and the package is now being released to -updates. Subsequently, the Ubuntu Stable Release Updates Team is being unsubscribed and will not receive messages about this bug report. In the event that you encounter a regression using the package from -updates please report a new bug using ubuntu-bug and tag the bug report regression-update so we can easily find any regressions.

The Eoan Ermine has reached end of life, so this bug will not be fixed for that release

I am occasionally seeing this again with the Impish live-server (subiquity) daily ISO images. I saw this happening only on ppc64el and on arm64, and only on preseeded installs (via answers.yaml).

This doesn't prevent the installation from succeeding: what fails is just the post-install reboot. Hard-rebooting the system results in the installed system booting correctly.

This is not easy to reproduce, I went with something on these lines:

for i in {1..100}; do
    echo "Round $i"
    virt-install --os-variant ubuntu18.04 --name paride-impish-preseed --memory 2048 --disk image.qcow2 --disk answers.img --cdrom impish-live-server-ppc64el.iso --noautoconsole --wait -1 || break;
    sleep 5;
    virsh destroy paride-impish-preseed || break;
    virsh undefine paride-impish-preseed || break;
done

When the problem happens virt-install will never exit as the installer system gets caught in the "SQUASHFS error: Failed to read block" error loop. I'm attaching the answers.yaml baked in answers.img (see LP: #1946398 on how to create the answers image file).

Note: that answers.yaml preseeds the installation of a snap. I have the impression that it increases the probability of hitting the failure.

=== kernel log excerpt on failure ===

[ 78.374287] EXT4-fs (vda2): mounted filesystem with ordered data mode. Opts: (null). Quota mode: none.
[ 79.296032] overlayfs: "xino" feature enabled using 32 upper inode bits.
[ 134.464075] overlayfs: "xino" feature enabled using 2 upper inode bits.
[ 355.493023] SGI XFS with ACLs, security attributes, realtime, quota, no debug enabled
[ 355.513889] JFS: nTxBlock = 459, nTxLock = 3673
[ 355.536975] ntfs: driver 2.1.32 [Flags: R/O MODULE].
[ 355.564466] QNX4 filesystem 0.2.3 registered.
[ 355.648190] Btrfs loaded, crc32c=crc32c-vpmsum, zoned=yes
[ 372.037306] VFS: busy inodes on changed media sr0
[ 372.039566] sr 0:0:0:2: [sr0] tag#19 FAILED Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE cmd_age=0s
[ 372.039572] sr 0:0:0:2: [sr0] tag#19 Sense Key : Not Ready [current]
[ 372.039575] sr 0:0:0:2: [sr0] tag#19 Add. Sense: Medium not present
[ 372.039578] sr 0:0:0:2: [sr0] tag#19 CDB: Read(10) 28 00 00 00 a6 35 00 00 20 00
[ 372.039580] blk_update_request: I/O error, dev sr0, sector 170196 op 0x0:(READ) flags 0x80700 phys_seg 1 prio class 0
[ 372.039633] sr 0:0:0:2: [sr0] tag#20 FAILED Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE cmd_age=0s
[ 372.039636] sr 0:0:0:2: [sr0] tag#20 Sense Key : Not Ready [current]
[ 372.039638] sr 0:0:0:2: [sr0] tag#20 Add. Sense: Medium not present
[ 372.039641] sr 0:0:0:2: [sr0] tag#20 CDB: Read(10) 28 00 00 00 a6 35 00 00 20 00
[ 372.039642] blk_update_request: I/O error, dev sr0, sector 170196 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 0
[ 372.039651] blk_update_request: I/O error, dev loop0, sector 36870 op 0x0:(READ) flags 0x800 phys_seg 1 prio class 0
[ 372.051333] SQUASHFS error: Failed to read block 0x1200dd0: -5
[ 372.051337] SQUASHFS error: Unable to read data cache entry [1200dd0]
[ 372.051339] SQUASHFS error: Unable to read page, block 1200dd0, size 8380
[ 372.051461] sr 0:0:0:2: [sr0] tag#21 FAILED Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE c...

Attachment: full dmesg.

I have more evidence that the issue is indeed the same.

The original bug was fixed by making casper depend on finalrd, see the explanatory casper 1.420 d/changelog entry reported in comment 33. However it appears that the fix is racey: sometimes finalrd is not triggered in time at shutdown/reboot, and the system gets stuck with the errors that pivoting to /run/initramfs would prevent.

I verified this by jumping in a shell during a subiquity install and running

# systemctl stop finalrd

and logging out. After doing this the reboot doesn't fail anymore. (Note that finalrd.service has

ExecStart=/bin/true
ExecStop=/usr/bin/finalrd

so it actually does its /run/initramfs overlay mount at *stop* (= at shutdown), and not at start.) Apparently this doesn't happen early or fast enough to save the day when rebooting the live session.

I guess we need to enforce some ordering in the shutdown targets execution.

we should check ordering of services for stop in a booted live session (desktop / server / next-installer) and then figure out if we can add additional dependencies to finalr.service (after) such that its stop is ordered before everything else is stopped.

Our installer could stop finalrd before issuing shutdown too, as a workaround.

Added a subiquity task as this could be worked around there, while I think the kernel tasks could be set to Invalid or Wontfix...

I wonder if we need before= or after= umount.target

From [1]:

> if a unit is configured with After= on another unit,
> the former is stopped before the latter if both are
> shut down.

so maybe we need After=umount.target in finalrd.service.

[1] https://www.freedesktop.org/software/systemd/man/systemd.unit.html

Hmm but umount.target is special (as in systemd.special(7)), so that's not so obvious...

As we have a Conflicts=umount.target, then

> It doesn't matter which of the two ordering dependencies is
> used, because stop jobs are always ordered before start jobs

literally as xnox said. I'm preparing a finalrd with Before=umount.target in a PPA [1].

[1] https://launchpad.net/~paride/+archive/ubuntu/lp1840122-finalrd-race

@brian-murray prepared a test Jammy arm64 ISO with finalrd from the PPA above (serial: 20211208.1). I chose arm64 as it's the architecture most heavily affected by this issue (at least in our test environment).

I performed several ISO test runs on the image and the success rate went from <50% to a solid 100%. I think it's enough to say that the fix works. I'll prepare an upload for Jammy, then we'll have to SRU the fix.

Actually there may be an even better solution:

   Before=shutdown.target

which lintian has been nagging us about:

  https://lintian.debian.org/tags/systemd-service-file-shutdown-problems

"There is race condition between stopping units and systemd getting a request to exit the main loop, so it may proceed with shutdown before all pending stop jobs have been processed."

I've uploaded this for Paride in the interest of getting it into the archive quickly (I assume he's in bed).

 $ dput finalrd_9_source.changes
Trying to upload package to ubuntu
Checking signature on .changes
gpg: /home/bdmurray/source-trees/finalrd/finalrd_9_source.changes: Valid signature from 1E918B66765B3E31
Checking signature on .dsc
gpg: /home/bdmurray/source-trees/finalrd/finalrd_9.dsc: Valid signature from 1E918B66765B3E31
Uploading to ubuntu (via ftp to upload.ubuntu.com):
  Uploading finalrd_9.dsc: done.
  Uploading finalrd_9.tar.xz: done.
  Uploading finalrd_9_source.buildinfo: done.
  Uploading finalrd_9_source.changes: done.
Successfully uploaded packages.

This bug was fixed in the package finalrd - 9

---------------
finalrd (9) jammy; urgency=medium

  * finalrd.service: set Before=shutdown.target.
    Eliminate race between finalrd and shutdown.target.
    See also: lintian's systemd-service-file-shutdown-problems.
    Thanks to Dimitri John Ledkov (LP: #1840122)
  * d/control: bump dh compat level to 11 (via debhelper-compat)
    Compat level 11 ensures compatibility with Bionic.
    Changes:
     - d/rules: switch to dh_installsystemd
  * d/control: set Rules-Requires-Root: no
  * d/control: bump Standards-Version to 4.6.0 (no changes needed)

 -- Paride Legovini <email address hidden> Thu, 09 Dec 2021 11:55:29 +0100

I can confirm the Jammy arm64 images are rebooting fine.

What is the status of this for 20.04.4? Is this just a matter of backporting the finalrd change from 9 to impish and focal? Is there anything blocking this? Since I assume this is reproducible on focal as well, right?

Hi, interestingly this is _not_ reproducible on Focal. I started seeing the failures in Impish. On paper the issue should be present on Focal, but due to its racey nature it's difficult tell exactly why it is not showing up.

I can quickly prepare a SRU upload with only the minimal Before= change, leaving out the packaging changes, but there won't be a real failure case to test against, since the failure is not reproducible on Focal. So I'm unsure on what's best here.

Thank you for the explanation. I think it's good to have this in mind for the future (when someone notices this being broken there as well), but in this case I'm taking it off from the .4 milestone.

Ubuntu 21.10 (Impish Indri) has reached end of life, so this bug will not be fixed for that specific release.