Bug#1107479: util-linux: blkid hangs forever after inserting a DVD-RAM
Hello Uwe,
> Can you easily tell if this happens for several DVD-RAMs or just a
> single one? (That might affect how good this is reproducible for
> upstream.)
I've tested 3 different DVD-RAMs, thus, 3 traces below.
> Usually only the first one is interesting. After that the state of the
> system is broken and the info from later traces is unreliable.
>
> So yes, please provide (at least) the first trace output.
[ 330.049632] pktcdvd: pktcdvd0: writer mapped to sr0
[ 330.074390] sr0: detected capacity change from 8946816 to 8946812
[ 484.388532] INFO: task blkid:1979 blocked for more than 120 seconds.
[ 484.388562] Tainted: G I 6.1.0-37-amd64 #1 Debian 6.1.140-1
[ 484.388577] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 484.388585] task:blkid state:D stack:0 pid:1979 ppid:1768 flags:0x00004002
[ 484.388610] Call Trace:
[ 484.388618] <TASK>
[ 484.388634] __schedule+0x34d/0x9e0
[ 484.388682] schedule+0x5a/0xd0
[ 484.388706] schedule_preempt_disabled+0x11/0x20
[ 484.388728] __mutex_lock.constprop.0+0x399/0x700
[ 484.388761] pkt_ioctl+0x42/0x120 [pktcdvd]
[ 484.388813] pkt_ioctl+0xcb/0x120 [pktcdvd]
[ 484.388853] ? tomoyo_init_request_info+0x95/0xc0
[ 484.388876] blkdev_ioctl+0x130/0x270
[ 484.388896] __x64_sys_ioctl+0x8d/0xd0
[ 484.388920] do_syscall_64+0x55/0xb0
[ 484.388947] ? mutex_lock+0xe/0x30
[ 484.388969] ? pkt_ioctl+0x74/0x120 [pktcdvd]
[ 484.389013] ? blkdev_ioctl+0x130/0x270
[ 484.389030] ? exit_to_user_mode_prepare+0x40/0x1e0
[ 484.389053] ? syscall_exit_to_user_mode+0x1e/0x40
[ 484.389067] ? do_syscall_64+0x61/0xb0
[ 484.389089] ? handle_mm_fault+0xdb/0x2d0
[ 484.389117] ? do_user_addr_fault+0x1b0/0x550
[ 484.389141] ? exit_to_user_mode_prepare+0x40/0x1e0
[ 484.389161] entry_SYSCALL_64_after_hwframe+0x6e/0xd8
[ 484.389181] RIP: 0033:0x7fce32c8ed1b
[ 484.389196] RSP: 002b:00007ffd2857ee10 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
[ 484.389215] RAX: ffffffffffffffda RBX: 0000557da4646b40 RCX: 00007fce32c8ed1b
[ 484.389226] RDX: 00007ffd2857ee90 RSI: 0000000000005395 RDI: 0000000000000006
[ 484.389235] RBP: 0000000000000006 R08: 0000000000000007 R09: 0000557da4646a50
[ 484.389245] R10: 525ee8f48e4e6f05 R11: 0000000000000246 R12: 0000000000000000
[ 484.389255] R13: 0000000000000000 R14: 0000000000000000 R15: 8000000068541db5
[ 484.389280] </TASK>
[ 287.772621] pktcdvd: pktcdvd0: writer mapped to sr0
[ 287.821877] sr0: detected capacity change from 8946816 to 8946812
[ 484.386374] INFO: task blkid:1846 blocked for more than 120 seconds.
[ 484.386404] Tainted: G I 6.1.0-37-amd64 #1 Debian 6.1.140-1
[ 484.386418] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 484.386426] task:blkid state:D stack:0 pid:1846 ppid:1320 flags:0x00000002
[ 484.386451] Call Trace:
[ 484.386459] <TASK>
[ 484.386475] __schedule+0x34d/0x9e0
[ 484.386522] schedule+0x5a/0xd0
[ 484.386546] schedule_preempt_disabled+0x11/0x20
[ 484.386568] __mutex_lock.constprop.0+0x399/0x700
[ 484.386601] pkt_ioctl+0x42/0x120 [pktcdvd]
[ 484.386654] pkt_ioctl+0xcb/0x120 [pktcdvd]
[ 484.386699] blkdev_ioctl+0x130/0x270
[ 484.386720] __x64_sys_ioctl+0x8d/0xd0
[ 484.386745] do_syscall_64+0x55/0xb0
[ 484.386784] ? mutex_lock+0xe/0x30
[ 484.386807] ? pkt_ioctl+0x74/0x120 [pktcdvd]
[ 484.386851] ? blkdev_ioctl+0x130/0x270
[ 484.386868] ? exit_to_user_mode_prepare+0x40/0x1e0
[ 484.386891] ? syscall_exit_to_user_mode+0x1e/0x40
[ 484.386904] ? do_syscall_64+0x61/0xb0
[ 484.386923] ? exit_to_user_mode_prepare+0x40/0x1e0
[ 484.386942] ? syscall_exit_to_user_mode+0x1e/0x40
[ 484.386953] ? do_syscall_64+0x61/0xb0
[ 484.386986] ? handle_mm_fault+0xdb/0x2d0
[ 484.387013] ? do_user_addr_fault+0x1b0/0x550
[ 484.387038] ? exit_to_user_mode_prepare+0x40/0x1e0
[ 484.387057] entry_SYSCALL_64_after_hwframe+0x6e/0xd8
[ 484.387078] RIP: 0033:0x7f4474200d1b
[ 484.387093] RSP: 002b:00007ffd88c45490 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
[ 484.387112] RAX: ffffffffffffffda RBX: 0000558f91d7bb40 RCX: 00007f4474200d1b
[ 484.387123] RDX: 00007ffd88c45510 RSI: 0000000000005395 RDI: 0000000000000006
[ 484.387133] RBP: 0000000000000006 R08: 0000000000000007 R09: 0000558f91d7ba50
[ 484.387142] R10: 498a16647597596d R11: 0000000000000246 R12: 0000000000000000
[ 484.387152] R13: 0000000000000000 R14: 0000000000000000 R15: 8000000068541fe5
[ 484.387176] </TASK>
[ 55.310426] pktcdvd: pktcdvd0: writer mapped to sr0
[ 55.339455] sr0: detected capacity change from 8946816 to 8946812
[ 242.724737] INFO: task blkid:1743 blocked for more than 120 seconds.
[ 242.724768] Tainted: G I 6.1.0-37-amd64 #1 Debian 6.1.140-1
[ 242.724783] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 242.724792] task:blkid state:D stack:0 pid:1743 ppid:1303 flags:0x00004002
[ 242.724817] Call Trace:
[ 242.724825] <TASK>
[ 242.724841] __schedule+0x34d/0x9e0
[ 242.724890] schedule+0x5a/0xd0
[ 242.724913] schedule_preempt_disabled+0x11/0x20
[ 242.724935] __mutex_lock.constprop.0+0x399/0x700
[ 242.724969] pkt_ioctl+0x42/0x120 [pktcdvd]
[ 242.725022] pkt_ioctl+0xcb/0x120 [pktcdvd]
[ 242.725068] blkdev_ioctl+0x130/0x270
[ 242.725089] __x64_sys_ioctl+0x8d/0xd0
[ 242.725113] do_syscall_64+0x55/0xb0
[ 242.725140] ? blkdev_ioctl+0x130/0x270
[ 242.725157] ? exit_to_user_mode_prepare+0x40/0x1e0
[ 242.725180] ? syscall_exit_to_user_mode+0x1e/0x40
[ 242.725193] ? do_syscall_64+0x61/0xb0
[ 242.725214] ? handle_mm_fault+0xdb/0x2d0
[ 242.725242] ? do_user_addr_fault+0x1b0/0x550
[ 242.725266] ? exit_to_user_mode_prepare+0x40/0x1e0
[ 242.725286] entry_SYSCALL_64_after_hwframe+0x6e/0xd8
[ 242.725306] RIP: 0033:0x7f467d342d1b
[ 242.725321] RSP: 002b:00007ffd681ebd60 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
[ 242.725339] RAX: ffffffffffffffda RBX: 00005586e1b6ab40 RCX: 00007f467d342d1b
[ 242.725350] RDX: 00007ffd681ebde0 RSI: 0000000000005395 RDI: 0000000000000006
[ 242.725360] RBP: 0000000000000006 R08: 0000000000000007 R09: 00005586e1b6aa50
[ 242.725370] R10: 182a48e237c20cf1 R11: 0000000000000246 R12: 0000000000000000
[ 242.725380] R13: 0000000000000000 R14: 0000000000000000 R15: 8000000068542162
[ 242.725405] </TASK>
These traces appear approx. 2,5 min. after executing blkid.
Best regards,
Roland
Reply to: