Ubuntu 12.04 install stalls when doing apt-get upgrade

[Daniel Manrique]

[Impact] Installs of the original 12.04 image with 'apt-get upgrade' in their ubiquity/success_command hang. This blocks hardware certification.
[Test case] As below; or, more simply, put the preseed file somewhere network-accessible and boot the installer in a VM with "url=<whatever>", then run the installer with "ubiquity --automatic". For a valid test, you need to take the original 12.04 image and upgrade just the ubiquity* binary packages before starting the installer.
[Regression potential] It's worth testing that d-i still works when built with the updated debian-installer-utils. Nothing outside the installer is at all likely to be affected.

Ubuntu 12.04 release image, this contains Ubiquity 2.10.16, grub-pc 1.99-21ubuntu3 and initramfs-tools 0.99ubuntu13. The updates install grub-pc 1.99-21ubuntu3.1.

At some point between June 28th and July 3rd, the apt-get upgrade process on Precise installations started stalling. We've noticed it stops when updating the initrds for new kernels:

Jul 4 20:43:22 ubuntu in-target: Setting up unity-2d-spread (5.12.0-0ubuntu1.1) ...
Jul 4 20:43:22 ubuntu in-target: Setting up unity-2d (5.12.0-0ubuntu1.1) ...
Jul 4 20:43:22 ubuntu in-target: Processing triggers for libc-bin ...
Jul 4 20:43:23 ubuntu in-target: ldconfig deferred processing now taking place
Jul 4 20:43:23 ubuntu in-target: Processing triggers for resolvconf ...
Jul 4 20:43:23 ubuntu in-target: debconf (developer): frontend started
Jul 4 20:43:23 ubuntu in-target: debconf: unable to initialize frontend: Passthrough
Jul 4 20:43:23 ubuntu in-target: debconf: (Failed to open fd 3: Bad file descriptor at (eval 24) line 3)
Jul 4 20:43:23 ubuntu in-target: debconf: falling back to frontend: Noninteractive
Jul 4 20:43:23 ubuntu in-target: debconf (developer): frontend running, package name is resolvconf
Jul 4 20:43:23 ubuntu in-target: debconf (developer): starting /var/lib/dpkg/info/resolvconf.config configure resolvconf-enable-updates
Jul 4 20:43:23 ubuntu in-target: debconf (developer): <-- INPUT low resolvconf/linkify-resolvconf
Jul 4 20:43:23 ubuntu in-target: Use of uninitialized value in numeric ge (>=) at /usr/share/perl5/Debconf/Priority.pm line 24, <GEN3> line 1.
Jul 4 20:43:23 ubuntu in-target: debconf (developer): --> 30 question skipped
Jul 4 20:43:23 ubuntu in-target: debconf (developer): <-- GO
Jul 4 20:43:23 ubuntu in-target: debconf (developer): --> 0 ok
Jul 4 20:43:23 ubuntu in-target: debconf (developer): <-- GET resolvconf/linkify-resolvconf
Jul 4 20:43:23 ubuntu in-target: debconf (developer): --> 0 false
Jul 4 20:43:23 ubuntu in-target: debconf (developer): <-- INPUT medium resolvconf/downup-interfaces
Jul 4 20:43:23 ubuntu in-target: Use of uninitialized value in numeric ge (>=) at /usr/share/perl5/Debconf/Priority.pm line 24, <GEN3> line 4.
Jul 4 20:43:23 ubuntu in-target: debconf (developer): --> 30 question skipped
Jul 4 20:43:23 ubuntu in-target: debconf (developer): <-- GO
Jul 4 20:43:23 ubuntu in-target: debconf (developer): --> 0 ok
Jul 4 20:43:23 ubuntu in-target: debconf (developer): starting /var/lib/dpkg/info/resolvconf.postinst triggered resolvconf-enable-updates
Jul 4 20:43:23 ubuntu in-target: debconf (developer): <-- STOP
Jul 4 20:43:23 ubuntu in-target: invoke-rc.d: policy-rc.d denied execution of start.
Jul 4 20:43:23 ubuntu in-target: Processing triggers for initramfs-tools ...
Jul 4 20:43:24 ubuntu in-target: update-initramfs: Generating /boot/initrd.img-3.5.0-3-generic
Jul 4 21:17:01 ubuntu CRON[989]: (root) CMD ( cd / && run-parts --report /etc/cron.hourly)

After the last update-initramfs line it stalls forever (notice the timestamp for that command and the following CRON one).

Steps to reproduce (on any machine, this doesn't seem to be hardware-specific):

- Create a nice Ubuntu 12.04 USB stick using USB disk creator (do NOT simply dd the hybrid image onto the USB stick, as you will need to write files to it later).
- Put the attached preseed in the USB stick's preseeds directory, name it ubuntu.seed (overwriting the existing file there).
- Edit syslinux/txt.cfg, go to the second "append" line containing kernel parameters for the "install ubuntu" menu option (line 9 in the file), and right after "only-ubiquity", add a space and "automatic-ubiquity".
- Boot a test system with this USB stick
- Select the "install ubuntu" option

Expected result:
- System installs ubuntu completely, prompts to reboot and boots into a complete installation

Actual result:
- System will stall forever
- Log shows as seen above.

The main addition to the preseed is the late_command:

ubiquity ubiquity/success_command string \
for i in /dev /dev/pts /dev/shm /sys /sys/kernel/security /proc /cdrom; do mount --bind $i / target/$i; done; \
  sed -i -e "/^GRUB_CMDLINE_LINUX_DEFAULT/s/\"$/ initcall_debug\"/" /target/etc/default/grub; chroot /target update-grub; \
  echo "echo 0 > /sys/module/kernel/parameters/initcall_debug" > /target/etc/initramfs-tools/conf.d/initcall; chroot /target update-initramfs -u; \
  for i in /dev/pts /dev/shm /dev /sys/kernel/security /sys /proc /cdrom; do umount $i; done; \
  in-target apt-get update; \
  in-target apt-get upgrade -y --force-yes; \
  true

Note this late_command basically just apt-get updates and upgrades. The first few lines are apparently needed if some of the later updates include a kernel update; without the mounts, the implicit update-grub in /target will fail.

[Brendan Donegan (brendan-donegan)]

This issue doesn't seem to affect servers. I'm not going to try and infer anything from that, but it's an extra data point just the same.

[Colin Watson (cjwatson)]

Can you get a process tree (ps axf) at the point where it hangs?

[Daniel Manrique (roadmr)]

Hi Colin,

Sure, here you go:

  PID TTY STAT TIME COMMAND
    2 ? S 0:00 [kthreadd]
    3 ? S 0:00 \_ [ksoftirqd/0]
    6 ? S 0:00 \_ [migration/0]
    7 ? S 0:00 \_ [watchdog/0]
    8 ? S 0:00 \_ [migration/1]
   10 ? S 0:00 \_ [ksoftirqd/1]
   12 ? S 0:00 \_ [watchdog/1]
   13 ? S 0:00 \_ [migration/2]
   15 ? S 0:00 \_ [ksoftirqd/2]
   16 ? S 0:00 \_ [watchdog/2]
   17 ? S 0:00 \_ [migration/3]
   19 ? S 0:00 \_ [ksoftirqd/3]
   20 ? S 0:00 \_ [watchdog/3]
   21 ? S< 0:00 \_ [cpuset]
   22 ? S< 0:00 \_ [khelper]
   23 ? S 0:00 \_ [kdevtmpfs]
   24 ? S< 0:00 \_ [netns]
   26 ? S 0:00 \_ [sync_supers]
   27 ? S 0:00 \_ [bdi-default]
   28 ? S< 0:00 \_ [kintegrityd]
   29 ? S< 0:00 \_ [kblockd]
   30 ? S< 0:00 \_ [ata_sff]
   31 ? S 0:00 \_ [khubd]
   32 ? S< 0:00 \_ [md]
   34 ? S 0:00 \_ [khungtaskd]
   35 ? S 0:02 \_ [kswapd0]
   36 ? SN 0:00 \_ [ksmd]
   37 ? SN 0:00 \_ [khugepaged]
   38 ? S 0:00 \_ [fsnotify_mark]
   39 ? S 0:00 \_ [ecryptfs-kthrea]
   40 ? S< 0:00 \_ [crypto]
   48 ? S< 0:00 \_ [kthrotld]
   49 ? S 0:00 \_ [scsi_eh_0]
   50 ? S 0:00 \_ [scsi_eh_1]
   51 ? S 0:00 \_ [scsi_eh_2]
   52 ? S 0:00 \_ [scsi_eh_3]
   53 ? S 0:00 \_ [scsi_eh_4]
   54 ? S 0:00 \_ [scsi_eh_5]
   79 ? S< 0:00 \_ [devfreq_wq]
   84 ? S 0:02 \_ [kworker/3:1]
  169 ? S 0:00 \_ [scsi_eh_6]
  172 ? S 0:02 \_ [usb-storage]
  425 ? S< 0:03 \_ [loop0]
  637 ? S< 0:00 \_ [loop1]
  648 ? S 0:00 \_ [kjournald]
 1861 ? S 0:01 \_ [kworker/1:2]
 3934 ? S< 0:00 \_ [krfcommd]
 3992 ? S 0:00 \_ [irq/43-mei]
 4111 ? S< 0:00 \_ [hci0]
 4136 ? S< 0:00 \_ [kmpathd]
 4145 ? S< 0:00 \_ [kmpath_handlerd]
 4160 ? S< 0:00 \_ [kpsmoused]
 4265 ? S< 0:00 \_ [ktpacpid]
 4301 ? S< 0:00 \_ [hd-audio0]
 7309 ? S 0:00 \_ [jfsIO]
 7310 ? S 0:00 \_ [jfsCommit]
 7311 ? S 0:00 \_ [jfsCommit]
 7312 ? S 0:00 \_ [jfsCommit]
 7313 ? S 0:00 \_ [jfsCommit]
 7314 ? S 0:00 \_ [jfsSync]
 7332 ? S< 0:00 \_ [xfs_mru_cache]
 7333 ? S< 0:00 \_ [xfslogd]
 7334 ? S< 0:00 \_ [xfsdatad]
 7335 ? S< 0:00 \_ [xfsconvertd]
10206 ? S 0:04 \_ [jbd2/sda1-8]
10207 ? S< 0:00 \_ [ext4-dio-unwrit]
10645 ? S 0:01 \_ [kworker/0:1]
15342 ? S< 0:00 \_ [cfg80211]
15346 ? S< 0:00 \_ [iwlwifi]
 7453 ? S 0:02 \_ [kworker/2:1]
12985 ? S 0:00 \_ [kworker/3:0]
13063 ? S 0:00 \_ [kworker/1:3]
19706 ? S 0:01 \_ [k...

[Kate Stewart (kate.stewart)]

marked this explicitly against precise, and milestoned to 12.04.1, so it gets focused on in time.

[Colin Watson (cjwatson)]

I've caught this in the act with strace, but the log is 2GB and will take some time to analyse.

My best guess is that one of the packages upgraded in this run starts a daemon which fails to disconnect itself from the stdout/stderr it's given on startup. That means log-output never exits because the file descriptors it's watching are still open. If this theory is correct, then a fix would be twofold: in quantal, fix the daemon to disconnect properly; in both precise and quantal, extend the no-op SIGCHLD handler hack in log-output to force it to exit as soon as its child process exits, even if --pass-stdout isn't being used.

[Brendan Donegan (brendan-donegan)]

@Colin, quick question - can this bug be fixed by changing the archive, or should we give up hope of this ever working in the 12.04 release image?

[Colin Watson (cjwatson)]

The offending process is /usr/lib/accountsservice/accounts-daemon.

I believe this can be worked around in log-output. However, there are multiple problems with accountsservice.postinst. Here's the fragment in question:

get_pid() {
    [ -n "$1" ] || return 0
    [ -S /var/run/dbus/system_bus_socket ] || return 0

    dbus-send --system --dest=org.freedesktop.DBus --print-reply \
              /org/freedesktop/DBus org.freedesktop.DBus.GetConnectionUnixProcessID \
              string:$1 2>/dev/null | awk '/uint32/ {print $2}'
}

if [ "$1" = "configure" ]; then
   # stop accounts-daemon
   pid=$(get_pid org.freedesktop.Accounts)
   kill $pid 2>/dev/null || true

   # restart daemon if it was running before
   [ -z "$pid" ] || /usr/lib/accountsservice/accounts-daemon & >/dev/null || true # will trigger through D-Bus activation
fi

I can see the following problems with this:

 1) There is no check that the process ID acquired via dbus-send is in the same filesystem root. If it is in a different root, accountsservice.postinst should leave well alone because the running executable is not the one that was just modified by unpacking the new version of accountsservice. The effect of this bug is that upgrading a chroot kills the running accounts-daemon in the host system.

 2) "& >/dev/null" is rather mangled shell syntax. Syntactically, & separates commands, and redirections are part of a command. The way this is written, the redirection is in fact part of a no-op command of its own, and is equivalent to opening and closing /dev/null without writing anything to it. Here's a demonstration of why this doesn't do what the author thought it did:

      $ echo hello & >x
      [1] 11962
      hello
      $
      [1]+ Done echo hello
      $ cat x
      $

    In any case, it should redirect stderr as well as stdout to /dev/null. Correct syntax would be:

      [ -z "$pid" ] || /usr/lib/accountsservice/accounts-daemon >/dev/null 2>&1 & || true # will trigger through D-Bus activation

 3) I'm less sure about this part, but given that it falls back to expecting accounts-daemon to be started by D-Bus activation, is there any reason to bother starting it from the postinst at all? It seems that perhaps you could simplify this by just deleting that code and relying entirely on D-Bus activation.

[Colin Watson (cjwatson)]

@Brendan: Yes, come to think of it we should clearly fix accountsservice in an SRU so that upgrades from the 12.04 release image (with an unfixed log-output) will work again.

[Launchpad Janitor (janitor)]

This bug was fixed in the package debian-installer-utils - 1.91ubuntu2

---------------
debian-installer-utils (1.91ubuntu2) quantal; urgency=low

  * log-output: Always install a no-op SIGCHLD handler, in case the
    subsidiary process starts a daemon which does not fully disconnect its
    standard file descriptors (LP: #1021293). See also the changelog for
    1.36ubuntu2.
 -- Colin Watson <email address hidden> Fri, 20 Jul 2012 17:12:34 +0100

[Sebastien Bacher (seb128)]

Thanks Colin, I agree with 2) and 3), we can probably drop the restart and let the dbus activation do the job (I will double check it doesn't create issues though), not sure what to do about 1)... is there a standard way it's done in other packages? I'm not sure it's an issue either to restart wrong instances since the service should just respawn and that shouldn't be visible in any way even it's suboptimal

[Colin Watson (cjwatson)]

Right, if you do 3) you don't have to worry very much about 1).

For the record, 1) is easily doable on Linux by comparing
/proc/$pid/root and /proc/self/root, although I don't know whether
Debian would take that since that's non-portable. It would be fine for
Ubuntu though. I suppose a fallback approximation for non-Linux kernels
might be to avoid stopping/restarting the daemon if ischroot exits zero.

[Launchpad Janitor (janitor)]

This bug was fixed in the package accountsservice - 0.6.21-6ubuntu2

---------------
accountsservice (0.6.21-6ubuntu2) quantal; urgency=low

  * debian/accountsservice.postinst:
    - don't try restarting the service from the maintainer script after
      upgrades, it leads to some issues and shouldn't be needed since
      it will be dbus reactivated when needed (lp: #1021293)
 -- Sebastien Bacher <email address hidden> Mon, 23 Jul 2012 19:26:09 +0200

[Adam Conrad (adconrad)]

Hello Daniel, or anyone else affected,

Accepted debian-installer-utils into precise-proposed. The package will build now and be available at http://launchpad.net/ubuntu/+source/debian-installer-utils/1.88ubuntu2.1 in a few hours, and then in the -proposed repository.

Please help us by testing this new package. See https://wiki.ubuntu.com/Testing/EnableProposed for documentation how to enable and use -proposed. Your feedback will aid us getting this update out to other Ubuntu users.

If this package fixes the bug for you, please change the bug tag from verification-needed to verification-done. If it does not, change the tag to verification-failed. In either case, details of your testing will help us make a better decision.

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

[Sebastien Bacher (seb128)]

I've SRUed the accountsservice fix

[Adam Conrad (adconrad)]

Hello Daniel, or anyone else affected,

Accepted ubiquity into precise-proposed. The package will build now and be available at http://launchpad.net/ubuntu/+source/ubiquity/2.10.19 in a few hours, and then in the -proposed repository.

Please help us by testing this new package. See https://wiki.ubuntu.com/Testing/EnableProposed for documentation how to enable and use -proposed. Your feedback will aid us getting this update out to other Ubuntu users.

If this package fixes the bug for you, please change the bug tag from verification-needed to verification-done. If it does not, change the tag to verification-failed. In either case, details of your testing will help us make a better decision.

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

[Stéphane Graber (stgraber)]

Tested with the preseed file attached to the bug, only replacing /dev/sda by /dev/vda before loading it and running ubiquity from precise-proposed in automatic mode.

Installation worked properly, system post-install is up to date except for the kernel and hplip (that require dist-upgrade instead of safe-upgrade).

This was done using the original 12.04 install media (64bit).

[Launchpad Janitor (janitor)]

This bug was fixed in the package ubiquity - 2.10.19

---------------
ubiquity (2.10.19) precise-proposed; urgency=low

  * Automatic update of included source packages: base-installer
    1.122ubuntu7.1, debian-installer-utils 1.88ubuntu2.1, flash-kernel
    2.28ubuntu42.2. (one-time update from precise-proposed) (LP: #1021293)
 -- Stephane Graber <email address hidden> Mon, 30 Jul 2012 10:36:51 -0400

[Launchpad Janitor (janitor)]

This bug was fixed in the package debian-installer-utils - 1.88ubuntu2.1

---------------
debian-installer-utils (1.88ubuntu2.1) precise-proposed; urgency=low

  * log-output: Always install a no-op SIGCHLD handler, in case the
    subsidiary process starts a daemon which does not fully disconnect its
    standard file descriptors (LP: #1021293).
 -- Colin Watson <email address hidden> Fri, 20 Jul 2012 17:18:51 +0100

[Adam Conrad (adconrad)]

Hello Daniel, or anyone else affected,

Accepted accountsservice into precise-proposed. The package will build now and be available at http://launchpad.net/ubuntu/+source/accountsservice/0.6.15-2ubuntu9.3 in a few hours, and then in the -proposed repository.

Please help us by testing this new package. See https://wiki.ubuntu.com/Testing/EnableProposed for documentation how to enable and use -proposed. Your feedback will aid us getting this update out to other Ubuntu users.

If this package fixes the bug for you, please change the bug tag from verification-needed to verification-done. If it does not, change the tag to verification-failed. In either case, details of your testing will help us make a better decision.

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

[Daniel Manrique (roadmr)]

Hi Adam,

I tested the accountsservice update by doing the usual installation process with a preseed file that does dist-upgrade. Note this is starting from a 12.04 release image.

With just -updates enabled, it stalls as described in the original report. The last thing I see in the logfile is " ubuntu in-target: Rebuilding /usr/share/applications/bamf.index..."

With -proposed enabled, the installation goes through as expected, and the accountsservice version that ends up on the system after installation is 0.6.15-2ubuntu9.3.

I'll mark verification-done, though this applies only to the accountsservice update.

[Sebastien Bacher (seb128)]

don't change to fix released before it's copied to -updates,thanks-

[Colin Watson (cjwatson)]

ubiquity/quantal fixed a while back:

ubiquity (2.11.18) quantal; urgency=low

  * Don't bother keeping track of keyboard model names and identifiers, as
    nothing in ubiquity uses them right now.
  * Fix reversed uses of methods mapping between keyboard layout/variant IDs
    and human-readable names, and improve method naming and documentation to
    make this mistake less likely in future (LP: #1027207, #1027620).
  * Automatic update of included source packages: debian-installer-utils
    1.91ubuntu3, flash-kernel 3.0~rc.4ubuntu9, netcfg 1.68ubuntu15.

 -- Colin Watson <email address hidden> Mon, 23 Jul 2012 11:02:13 +0100

[Launchpad Janitor (janitor)]

This bug was fixed in the package accountsservice - 0.6.15-2ubuntu9.3

---------------
accountsservice (0.6.15-2ubuntu9.3) precise-proposed; urgency=low

  * debian/accountsservice.postinst:
    - don't try restarting the service from the maintainer script after
      upgrades, it leads to some issues and shouldn't be needed since
      it will be dbus reactivated when needed (lp: #1021293)
 -- Sebastien Bacher <email address hidden> Mon, 23 Jul 2012 19:26:09 +0200