This service will be undergoing maintenance at 00:00 UTC, 2016-08-01. It is expected to last about 1 hours

Bug 695375

Summary: binfmt_misc rule delays systemd
Product: [Fedora] Fedora Reporter: Zdenek Kabelac <zkabelac>
Component: module-init-toolsAssignee: Jon Masters <jcm>
Status: CLOSED ERRATA QA Contact: Fedora Extras Quality Assurance <extras-qa>
Severity: unspecified Docs Contact:
Priority: unspecified    
Version: rawhideCC: jcm, jonathan, lpoetter, mschmidt
Target Milestone: ---   
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: module-init-tools-3.12-5.fc15 Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2011-04-28 15:24:45 EDT Type: ---
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Bug Depends On:    
Bug Blocks: 695415    
Attachments:
Description Flags
Stack trace when TB mounts binfmt_misc none

Description Zdenek Kabelac 2011-04-11 10:15:55 EDT
Description of problem:

My own kernel is using kernel module for binfmt_misc
(default Fedora kernel has it 'built-in'

file: /etc/modprobe.d/dist.conf

has this rule:
install binfmt_misc /sbin/modprobe --first-time --ignore-install binfmt_misc && { /bin/mount -t binfmt_misc none /proc/sys/fs/binfmt_misc > /dev/null 2>&1 || :; }


However now with systemd - it's causing loop problem:

[  102.797132] systemd[1]: proc-sys-fs-binfmt_misc.automount changed waiting -> running
[  102.805168] systemd[1]: About to execute: /bin/mount binfmt_misc /proc/sys/fs/binfmt_misc -t binfmt_misc
....
[  242.080189] INFO: task mount:1504 blocked for more than 120 seconds.
[  242.086600] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[  242.094607] mount           D 00000000ffff18f7     0  1504      1 0x00000000
[  242.101843]  ffff880112e51a88 0000000000000046 ffff880112f90000 00000000ffff18f7
[  242.109382]  ffff880112e51a48 ffff88013bbd2180 0000000000000000 ffff880112e51fd8
[  242.116963]  ffff880112f90000 fffe06de000001ef ffff880112e51fd8 ffff880112e51fd8
[  242.124560] Call Trace:
[  242.127068]  [<ffffffff81490675>] schedule_timeout+0x2b5/0x480
[  242.132928]  [<ffffffff8148efaa>] ? wait_for_common+0x4a/0x180
[  242.138801]  [<ffffffff81496ce9>] ? sub_preempt_count+0xa9/0xe0
[  242.144813]  [<ffffffff8148f077>] wait_for_common+0x117/0x180
[  242.150648]  [<ffffffff81048d90>] ? try_to_wake_up+0x5e0/0x5e0
[  242.156601]  [<ffffffff8148f1bd>] wait_for_completion+0x1d/0x20
[  242.162548]  [<ffffffff8106cac5>] call_usermodehelper_exec+0x185/0x190
[  242.169113]  [<ffffffff8108b4b3>] ? lockdep_init_map+0xb3/0x560
[  242.175057]  [<ffffffff8108b4b3>] ? lockdep_init_map+0xb3/0x560
[  242.181089]  [<ffffffff8116aaa9>] ? get_fs_type+0x99/0xc0
[  242.186517]  [<ffffffff8106ccce>] __request_module+0x14e/0x2d0
[  242.192380]  [<ffffffff81493645>] ? _raw_read_unlock+0x35/0x60
[  242.198239]  [<ffffffff8116aaa9>] get_fs_type+0x99/0xc0
[  242.203574]  [<ffffffff8116cfba>] do_kern_mount+0x3a/0x110
[  242.209103]  [<ffffffff8116e664>] do_mount+0x1a4/0x840
[  242.214291]  [<ffffffff81115a3b>] ? memdup_user+0x4b/0x90
[  242.219787]  [<ffffffff81115adb>] ? strndup_user+0x5b/0x80
[  242.225305]  [<ffffffff8116f0a0>] sys_mount+0x90/0xe0
[  242.230393]  [<ffffffff8149abeb>] system_call_fastpath+0x16/0x1b
[  242.236440] no locks held by mount/1504.
[  282.805253] systemd[1]: proc-sys-fs-binfmt_misc.mount mounting timed out. Stopping.

just then  binfmt_misc get inserted - and some following mount will succeed.

It's been causing interesting 3 minuted delays with Thunderbird startup.

As a fix I've removed problematic 'install' line from dist.conf - and the problem is gone.


Version-Release number of selected component (if applicable):
module-init-tools-3.12-4.fc15.x86_64

How reproducible:
Having  binfmt_misc compiled as module

Steps to Reproduce:
1.
2.
3.
  
Actual results:


Expected results:
No major delays in binfmt_misc module loading


Additional info:
Comment 1 Zdenek Kabelac 2011-04-11 10:18:06 EDT
It could be triggered by just:

/bin/mount binfmt_misc /proc/sys/fs/binfmt_misc -t binfmt_misc
Comment 2 Michal Schmidt 2011-04-11 12:17:12 EDT
There are two convenience features which work fine if taken independently, but together they lead to Zdeněk's lockup:

 - the rule in /etc/modprobe.d/dist.conf mounts /proc/sys/fs/binfmt_misc
   automatically when someone loads the binfmt_misc kernel module.

 - systemd uses autofs on /proc/sys/fs/binfmt_misc to mount it automatically
   when someone attempts to use it. The kernel will request the binfmt_misc
   module when it needs for the mount.

But even without systemd's autofs involvement (tested by masking the proc-sys-fs-binfmt_misc.automount unit) there is a little bug:

# /bin/mount binfmt_misc /proc/sys/fs/binfmt_misc -t binfmt_misc
mount: binfmt_misc already mounted or /proc/sys/fs/binfmt_misc busy
mount: according to mtab, none is already mounted on /proc/sys/fs/binfmt_misc

In this case the result was just a confusing error message, as the mount did actually succeed.

The rule for binfmt_misc should be removed because:
 - Fedora kernels are built with CONFIG_BINFMT_MISC=y anyway, so the rule has
   no effect there.
 - on custom kernels with CONFIG_BINFMT_MISC=m it leads to the lockup when
   used with systemd's automount.
Comment 3 Lennart Poettering 2011-04-11 12:25:26 EDT
Yes, I agree with Michal, the rule should be removed.
Comment 4 Michal Schmidt 2011-04-11 12:36:41 EDT
Kay Sievers had this to say about our dist.conf on IRC #systemd:

<kay> michich: wow, people run mount(8) from modprobe?
<kay> yikes, that needs to go
<kay> nothing should ever call mount or any other stuff like that in sync calls like modprobe
<kay> http://pkgs.fedoraproject.org/gitweb/?p=module-init-tools.git;a=blob;f=modprobe-dist.conf;h=eadd5c7e9a82b6cdcb4ef9ac7e67c771fbf38a02;hb=refs/heads/f15/master
<kay> there are many really nice things in that file :)
<kay> can someone hit jcm with a cluebat please!
<michich> kay, can I quote you in the bug? :-)
<kay> michich: oh, yeah, please do
<kay> michich: there is almost nothing in that file, that belongs there
<kay> michich: lots of stuff does not exist anymore; static aliases belong into the kernel module, not magically mapped in userspace; /bin/true stuff should be blacklisted; magically named  aliases don't belong into module-init-tools
Comment 5 Lennart Poettering 2011-04-11 12:44:31 EDT
Related to this, I asked the kernel folks to compile binfmt_misc as module by default. If this happens this line really has to go.

https://bugzilla.redhat.com/show_bug.cgi?id=695415
Comment 6 Jon Masters 2011-04-11 13:28:51 EDT
Thanks for the ping in #systemd. I'll get crufty stupid synchronous calls to mount and friends ripped out. Looks like this is just a straightforward removal as systemd will mount this now anyway, so I'll just can that rule and any others I see like it that aren't needed (and look at anything else in dist.conf that needs love).

Oh, and the OSS thing...I got the ping on that, too.

Jon.
Comment 7 Zdenek Kabelac 2011-04-12 06:34:39 EDT
Created attachment 491450 [details]
Stack trace when TB mounts binfmt_misc

Well it has 'extra' bonus - which probably deserves new BZ for gnome-vfs.

TB is pushed to use gnome-vfs - and gnome-vfs seems to be read /etc/mtab  (which is on my system symbolic link to  /proc/mounts - is that correct with current version of systemd ?)

Anyway - makes 'stat' on each mountpoint - thus effectively mounts all disks - very funny...

Though I've no idea whether gnome-vfs really needs to do all these 'stats' ?

So any idea ?
Comment 8 Lennart Poettering 2011-04-14 11:47:43 EDT
stat() on autofs mount points is a very bad idea, since it triggers them. lstat() doesn't, so this should be a relatively easy fix. Is this only gnome-vfs or also gvfs?
Comment 9 Jon Masters 2011-04-15 02:38:45 EDT
Lennart: I've removed that particular mount from the update I'm pushing but I could do with some help identifying other calls to mount that we can remove. I'd like to kill all of them, and we will, but let's start by removing calls we don't need to replace with something else. What's the story with NFS on your end now?

Jon.
Comment 10 Jon Masters 2011-04-15 02:39:57 EDT
It's really just SUN RPC and NFS remaining. Also, I removed the unmount since I assume you're taking care of unmounting the filesystem too via autofs.

Jon.
Comment 11 Fedora Update System 2011-04-15 03:00:01 EDT
module-init-tools-3.12-5.fc15 has been submitted as an update for Fedora 15.
https://admin.fedoraproject.org/updates/module-init-tools-3.12-5.fc15
Comment 12 Fedora Update System 2011-04-15 20:12:13 EDT
Package module-init-tools-3.12-5.fc15:
* should fix your issue,
* was pushed to the Fedora 15 testing repository,
* should be available at your local mirror within two days.
Update it with:
# su -c 'yum update --enablerepo=updates-testing module-init-tools-3.12-5.fc15'
as soon as you are able to.
Please go to the following url:
https://admin.fedoraproject.org/updates/module-init-tools-3.12-5.fc15
then log in and leave karma (feedback).
Comment 13 Lennart Poettering 2011-04-18 12:06:58 EDT
Yes, we unmount everything as necessary on shutdown. No need to explicitly unmount everything.

I am not entirely sure about the NFS special dirs and where that should move. A better place its probably the NFS scripts in some way. But I am not sure really. There's so much kludgy shell involved with starting up RPC/NFS, it's a bit of a nightmare...
Comment 14 Fedora Update System 2011-04-28 15:24:39 EDT
module-init-tools-3.12-5.fc15 has been pushed to the Fedora 15 stable repository.  If problems still persist, please make note of it in this bug report.