Bug 757368

Hi,thank you for your report.could you please help to provide y2logs according to the following URL?Thank you:)
http://en.opensuse.org/openSUSE:Bugreport_YaST.

Created attachment 494294 [details]
YaST logs

I had a similar problem when installing current Factory. In my case there
is no floppy drive but logs are flooded with /dev/fd0 read errors anyway.

Moreover, attempt to install grub2 bootloader leads to probe hanging in
uninterruptible sleep which can be prevented by blacklisting "floppy"
module. Unfortunately I couldn't find more because kernel debuginfo is
missing (Bug 763923).

yast2-storage should not do anything with floppy drive.
Sound like either hwinfo or grub2 setup is doing this.
Reassigning...

What logs are flooded? And you describe more exactly _when_ that happens?

Created attachment 496259 [details]
strace output for grub2-mkconfig (strace -r -f)

I did one more attempt with grub2-mkconfig on current Factory. The grub2-probe
command doesn't actually hang up when reading from /dev/fd0, it just repeats
open() and read() many times and as each syscall takes 12 seconds (sometimes
24 seconds for read()), total time was almost two hours (112 minutes).

Syscall open() spends most time waiting in __floppy_read_block_0():

> PID: 2733   TASK: ffff880127d2e100  CPU: 1   COMMAND: "grub2-probe"
>  #0 [ffff880127ee3948] schedule at fffffff81589f4d
>  #1 [ffff880127ee39c0] schedule_timeout at ffffffff81588a12
>  #2 [ffff880127ee3a60] wait_for_common at ffffffff81589a7f
>  #3 [ffff880127ee3ae0] __floppy_read_block_0 at ffffffffa02237e3 [floppy]
>  #4 [ffff880127ee3ba0] floppy_revalidate at ffffffffa02262bc [floppy]
>  #5 [ffff880127ee3bc0] check_disk_change at ffffffff81191ee3
>  #6 [ffff880127ee3be0] floppy_open at ffffffffa0223c7c [floppy]
>  #7 [ffff880127ee3c30] __blkdev_get at ffffffff81192df3
>  #8 [ffff880127ee3ca0] blkdev_get at ffffffff81193346
>  #9 [ffff880127ee3d20] __dentry_open at ffffffff8115b491
> #10 [ffff880127ee3d70] do_last at ffffffff8116be70
> #11 [ffff880127ee3dd0] path_openat at ffffffff8116c409
> #12 [ffff880127ee3e60] do_filp_open at ffffffff8116c824
> #13 [ffff880127ee3f30] do_sys_open at ffffffff8115c57d
> #14 [ffff880127ee3f80] system_call_fastpath at ffffffff8159247d
>     RIP: 00007feb18503fa0  RSP: 00007fff518e7048  RFLAGS: 00010202
>     RAX: 0000000000000002  RBX: ffffffff8159247d  RCX: 0000000000000000
>     RDX: 0000000000101000  RSI: 0000000000101000  RDI: 00007fff518e60c0
>     RBP: 0000000000000000   R8: 00007fff518e60c0   R9: ffffffffffffff00
>     R10: 00007fff518e5e40  R11: 0000000000000246  R12: 0000000000000000
>     R13: 00007fff518e7590  R14: 0000000000402340  R15: 00007fff518e70e0
>     ORIG_RAX: 0000000000000002  CS: 0033  SS: 002b

Syscall read() spends most time waiting for a page lock in generic_file_aio_read()
waiting for a page lock:

> PID: 2733   TASK: ffff880127d2e100  CPU: 0   COMMAND: "grub2-probe"
>  #0 [ffff880127ee3bd8] schedule at ffffffff81589f4d
>  #1 [ffff880127ee3c50] io_schedule at ffffffff8158a58a
>  #2 [ffff880127ee3c70] sleep_on_page_killable at ffffffff810fe629
>  #3 [ffff880127ee3c80] __wait_on_bit_lock at ffffffff81588b4f
>  #4 [ffff880127ee3cc0] __lock_page_killable at ffffffff810fe592
>  #5 [ffff880127ee3d10] generic_file_aio_read at ffffffff81100958
>  #6 [ffff880127ee3e00] do_sync_read at ffffffff8115c966
>  #7 [ffff880127ee3f10] vfs_read at ffffffff8115d2a4
>  #8 [ffff880127ee3f40] sys_read at ffffffff8115d3c7
>  #9 [ffff880127ee3f80] system_call_fastpath at ffffffff8159247d
>     RIP: 00007feb18504190  RSP: 00007fff518e5f18  RFLAGS: 00010206
>     RAX: 0000000000000000  RBX: ffffffff8159247d  RCX: 0000000000000030
>     RDX: 0000000000000200  RSI: 00000000006e3a80  RDI: 0000000000000003
>     RBP: 0000000000402340   R8: 000000000000000a   R9: 0101010101010101
>     R10: 0000000000000000  R11: 0000000000000246  R12: 00007fff518e6f90
>     R13: 00007fff518e73e0  R14: 0000000000000000  R15: 0000000000000000
>     ORIG_RAX: 0000000000000000  CS: 0033  SS: 002b

I also noticed that at this moment, the radix tree for mapping associated
with /dev/fd0 file has height = 0 but non-null rnode. Moreover the rnode
pointer doesn't refer to a valid struct radix_tree_root, it looks more like
a struct page.


As there is no floppy drive in the computer, loading floppy module should have
failed and even if it didn't for some reason, open() shouldn't succeed. IMHO
we have three different problems here:

1. floppy module loads even if there is no floppy drive
2. after the 12 second timeout (trying to read first sector),
   open("/dev/fd0") returns successfully
3. grub2-probe calls open() and read() too many times so that the total time
   is enormous

Running through strace it seems that grub2-probe is excessively querying
the block size (27 times open(), ioctl(, BLKGETSIZE64), close() if I counted
correctly). While that's probably something that could need improvement the
real issue seems to be the long delays accessing fd0 even though there's no
floppy.

Assigning to kernel team and adding grub2 maintainer for grub2-probe issue.

Floppies are legacy hardware and will not perform well ever. grub2-probe just shouldn't be accessing it if it's not going to get used. Kernel team views this as WONTFIX.

I vaguely remember upstream refuse to fix floppy issue due to some legacy reasons .. will try to make certain they are relevant to this problem.

FWIW two (maybe) relevant mailing list thread.

http://lists.gnu.org/archive/html/grub-devel/2012-06/msg00056.html
http://lists.gnu.org/archive/html/grub-devel/2011-07/msg00030.html

Jeff, there is no reason not to support floppy drives - they are well-understood hardware. And I *do* still use mine regularly. Fortunately, the issue appears to be fixed in 12.2 Beta 2.