/etc/init.d/umountroot: 'mount / is busy' due to upstart log file

Bug #1181528 reported by Max on 2013-05-18
50
This bug affects 10 people
Affects Status Importance Assigned to Milestone
ureadahead (Ubuntu)
Undecided
Unassigned

Bug Description

Steve Langasek insisted that this bug must be reported to ureadahead.
I am almost sure that it resides somewhere else, but I run out of ideas.
This is another brunch of the Bug lp: #1073433
'Ext4 corruption associated with shutdown of Ubuntu 12.10'
Anyway inability to clearly remount root filesystem readonly is a serious issue.

During shutdown /etc/init.d/umountroot reports
  mount: / is busy
it leads to filesystem recovery next boot.

It happens due to a file opened by upstart:
init 1 root 12w REG 8,2 344 2886145 /var/log/upstart/ureadahead-other.log
(reported by lsof)

For some reason init (upstart) decides that for the third filesystem
there is a fork of ureadahed.

[ 19.563541] init: ureadahead-other main process (912)
[ 19.566832] init: ureadahead-other main process (912) executable changed
[ 19.619194] init: ureadahead-other main process (912) terminated with status 4
[ 19.621332] init: ureadahead-other goal changed from start to stop
[ 19.623678] init: ureadahead-other state changed from spawned to stopping
[ 19.628290] init: ureadahead-other state changed from stopping to killed
[ 19.630631] init: ureadahead-other state changed from killed to post-stop
[ 19.632954] init: ureadahead-other state changed from post-stop to waiting
[ 21.787397] init: ureadahead-other goal changed from stop to start
[ 21.789750] init: ureadahead-other state changed from waiting to starting
[ 21.794433] init: ureadahead-other state changed from starting to pre-start
[ 21.796985] init: ureadahead-other state changed from pre-start to spawned
[ 21.800622] init: ureadahead-other main process (920)
[ 21.803883] init: ureadahead-other main process (920) became new process (921)
[ 21.805935] init: ureadahead-other state changed from spawned to post-start
[ 21.808597] init: ureadahead-other state changed from post-start to running

later initctl status ureadahead-other reports
the process that is absent in ps output.

I would expect that the second ureadahead-other process
must exit with status 4 since there is no pack file.
/var/log/upstart/ureadahead-other.log:

ureadahead:/var/lib/ureadahead/home.pack: No such file or directory
ureadahead:/var/lib/ureadahead/srv.pack: No such file or directory

The bug also appears if there are pack and home.pack files but no srv.pack.
Init does not hold log file if there pack files for all mounted filesystems.
Perhaps the easiest way is to try mainline kernel that does not support
file tracing required for ureadahead (to avoid creation of pack files
during debug).

I am in doubt if someone can easily reproduce this bug although
I see it each boot under certain conditions.

The bug appears for 3 filesystems in /etc/fstab (/ /home /srv in my case).
I never seen it when just / and /home were mounted.
In my case / is ext4, the others are ext3.

The last time the bug disappeared after I removed /srv/mnt directory
from / filesystem (when /srv was not mounted). Now even srv.pack
is not required, just pack and home.pack is enough. But the first
boot when there were no pack files finished with busy /.

I have tried another partition instead of regularly mounted /srv.
There was no bug if that partition was mounted to /mnt
instead of /srv. The bug likes 'acl' in the mount options.

I do not know why mysterious fork happens during second call
of ureadadead-other, I can not reproduce it lunching ureadahead
from command line under strace.

Versions:
Ubuntu 13.10 Raring, i686
ureadahead: 0.100.0-16
upstart: 1.8-0ubuntu1

Launchpad Janitor (janitor) wrote :

Status changed to 'Confirmed' because the bug affects multiple users.

Changed in ureadahead (Ubuntu):
status: New → Confirmed
Paul F (boxjunk) wrote :

I'm seeing what appears to be an unclean shutdown. It looks like / is marked as dirty: every boot runs fsck:

% dmesg | grep sda2
EXT3-fs (sda2): recovery required on readonly filesystem
EXT3-fs (sda2): write access will be enabled during recovery
EXT3-fs (sda2): recovery complete
EXT3-fs (sda2): mounted filesystem with ordered data mode

sda2 is my root / partition. There is 1 drive (SCSI) with 6 partitions. sda1 (/boot, ext3), sda2 (/, ext3) and sda3 (swap) are all primary partitions. sda5 (/home, ext3) and sda6 (/share, FAT32) are logical. Only / (sda2) is unclean.

The workaround of deselecting "Available to all users" in Network Connections discussed in LP: #1073433 works for me. It would seem that there are multiple bugs causing the same behaviour. See LP: #1073433 #124.

% dpkg-query --show ureadahead
ureadahead 0.100.0-12build1

% dpkg-query --show upstart
upstart 1.5-0ubuntu9

% dpkg-query --show network-manager
network-manager 0.9.6.0-0ubuntu7

Ubuntu 12.10 Quantal
Linux 3.5.0-30-generic #51-Ubuntu SMP Tue May 14 18:49:52 UTC 2013 i686 athlon i686 GNU/Linux

Max (m-gorodok) wrote :

Paul, likely your system is affected by
Bug #1124803 "NetworkManager doesn't respond to SIGTERM in daemon mode"

You can check if this bug is related to your problem
by the following commands
sudo initctl status ureadahead-other
sudo lsof | grep ureadahead

This issue assumes /var/log/upstart/ureadahead-other.log
open for writing.

Max (m-gorodok) wrote :

The problem can be reproduced when ureadahead-other
is disabled during boot (by manual in override file).
Second attempt to start for a mount that has no .pack
file (start ureadahead-other MOUNTPOINT=/srv)
leads to unclosed log file.

I have not managed to reproduce it by running
ureadahead from command line.
strace does not show any forks.

It is an Upstart issue. The pure case with shell command:
Bug lp: #1181789

Paul F (boxjunk) wrote :

Ref #3 above.

% sudo initctl status ureadahead-other
ureadahead-other stop/waiting

% sudo lsof | grep ureadahead
lsof: WARNING: can't stat() fuse.gvfsd-fuse file system /run/user/XXX/gvfs
      Output information may be incomplete.
%

Assuming that lsof did complete despite its warning, it would seem that my unclean shutdown is not caused by ureadahead-other.log. I'm probably the victim of the network-manager bug. Thanks Max for the investigations and copious illuminations.
I had already removed myself from the This Bug Affects... list as this was already my strong suspicion.

Thorsten Goetzke (th-goetzke) wrote :

As long as this in not fixed, what might work as good workaround for ureadahead-other accessing /var/log?
I moved "ureadahead-other.conf" to "ureadahead-other.conf.disabled" and did
update-initramfs -u -k all
and on the second reboot umountroot was finally able to mount / as readonly-> clean shutdown+ startup.
Does someone has a better idea?

John Clark (clarkjc) wrote :

Instead of disabling ureadahead-other as suggested in comment #6, I added the following line to /etc/init/ureadahead-other.conf to disable logging for this particular Upstart job:

console none

This prevents the log file from keeping the file system busy. The only downside is that anything logged by ureadahead-other goes to /dev/null instead.

John Clark (clarkjc) wrote :

P.S. You will have to reboot 2 times after adding "console none" for it to work.

Max (m-gorodok) wrote :

Reading init/job_process.c from upstart sources...
It seems that upstart launches ureadahead within a shell
since the exec line from /etc/init/ureadahead-other.conf
contains variable substitution ($MOUNTPOINT).
Is it possible that extra exec (init->sh->ureadahead)
confuses upstart process tracer?

Steve Dodd (anarchetic) wrote :

Easily reproduced here, by (a) having two or more non-root filesystems mounted, (b) deleting all *pack files from /var/lib/ureadahead. The second reboot will fail to unmount the root.

The patch I've added to bug #1181789 seems to be the correct answer, but the attached patch to the ureadahead upstart job should be an effective workaround with no side effects.

To post a comment you must log in.
This report contains Public information  Edit
Everyone can see this information.

Other bug subscribers