Am 28.04.19 um 18:00 schrieb Brad Barnett: > > Package: udev > Version: 232-25+deb9u11 > > After today's upgrade to debian 9.9, I attempted to create a disk image. > > I have a script, it does the following: > > ### > dd if=/dev/zero of=/tmp/ff1.raw bs=1G seek=8 count=0 > sync > sleep 1 > parted /tmp/ff1.raw mklabel msdos > parted -s /tmp/ff1.raw mkpart primary linux-swap 1 100 > parted -s -- /tmp/ff1.raw mkpart primary ext2 101 -1 > parted -s -- /tmp/ff1.raw set 2 boot on > sleep 5 > losetup -Pf /tmp/ff1.raw --show > ### > > The above has been run several times per month, for years. > > After today's upgrade I rebooted, ran the above, and it locked on losetup. > > I see this: > > # ps auxwwf > > root 346 0.0 0.1 45656 3420 ? Ss 11:30 0:00 > /lib/systemd/systemd-udevd --daemon > root 2596 0.0 0.0 45564 2120 ? S 11:31 0:00 \_ > /lib/systemd/systemd-udevd --daemon > root 2597 0.0 0.0 45564 2184 ? D 11:31 0:00 \_ > /lib/systemd/systemd-udevd --daemon > root 2599 0.0 0.1 45644 3096 ? S 11:31 0:00 \_ > /lib/systemd/systemd-udevd --daemon > root 2602 0.0 0.0 45564 2120 ? D 11:31 0:00 \_ > /lib/systemd/systemd-udevd --daemon > root 2603 0.0 0.0 45656 1936 ? D 11:31 0:00 \_ > /lib/systemd/systemd-udevd --daemon > root 2607 0.0 0.0 45656 1936 ? D 11:31 0:00 \_ > /lib/systemd/systemd-udevd --daemon > root 2609 0.0 0.0 45564 2120 ? D 11:31 0:00 \_ > /lib/systemd/systemd-udevd --daemon > root 2610 0.0 0.0 45656 1936 ? D 11:31 0:00 \_ > /lib/systemd/systemd-udevd --daemon > root 2612 0.0 0.0 45656 1936 ? D 11:31 0:00 \_ > /lib/systemd/systemd-udevd --daemon > > And > > root 2591 0.0 0.0 8064 780 pts/2 D 11:31 0:00 > /sbin/losetup -Pf /tmp/ff1.raw --show > > I also see this (last 3 'blocks' pasted): > > Apr 28 11:34:17 buildvm kernel: [ 242.831744] INFO: task systemd-udevd:2612 > blocked for more than 120 seconds. > Apr 28 11:34:17 buildvm kernel: [ 242.831807] Not tainted > 4.9.0-9-amd64 #1 Debian 4.9.168-1 > Apr 28 11:34:17 buildvm kernel: [ 242.831859] "echo 0 > > /proc/sys/kernel/hung_task_timeout_secs" disables this message. > Apr 28 11:34:17 buildvm kernel: [ 242.831927] systemd-udevd D 0 2612 > 346 0x00000004 > Apr 28 11:34:17 buildvm kernel: [ 242.831932] ffff8a2dbb10c400 > 0000000000000000 ffff8a2dbacc5240 ffff8a2dbfa18980 > Apr 28 11:34:17 buildvm kernel: [ 242.831939] ffffffffaf411500 > ffffaf84409e7b58 ffffffffaee15a99 1e580f2a959617cf > Apr 28 11:34:17 buildvm kernel: [ 242.831946] 00000000000402c0 > ffff8a2dbfa18980 0000000000000000 ffff8a2dbacc5240 > > Apr 28 11:34:17 buildvm kernel: [ 242.831952] Call Trace: > Apr 28 11:34:17 buildvm kernel: [ 242.831960] [<ffffffffaee15a99>] ? > __schedule+0x239/0x6f0 > Apr 28 11:34:17 buildvm kernel: [ 242.831967] [<ffffffffaee15f82>] ? > schedule+0x32/0x80 > Apr 28 11:34:17 buildvm kernel: [ 242.831973] [<ffffffffaee1623a>] ? > schedule_preempt_disabled+0xa/0x10 > Apr 28 11:34:17 buildvm kernel: [ 242.831977] [<ffffffffaee17c94>] ? > __mutex_lock_slowpath+0xb4/0x130 > Apr 28 11:34:17 buildvm kernel: [ 242.831982] [<ffffffffaee17d2b>] ? > mutex_lock+0x1b/0x30 > Apr 28 11:34:17 buildvm kernel: [ 242.831988] [<ffffffffc03e11c5>] ? > lo_open+0x15/0x50 [loop] > Apr 28 11:34:17 buildvm kernel: [ 242.831994] [<ffffffffaea48ce3>] ? > __blkdev_get+0xd3/0x470 > Apr 28 11:34:17 buildvm kernel: [ 242.832001] [<ffffffffaea492e6>] ? > blkdev_get+0x126/0x330 > Apr 28 11:34:17 buildvm kernel: [ 242.832008] [<ffffffffaea27e04>] ? > unlock_new_inode+0x44/0x70 > Apr 28 11:34:17 buildvm kernel: [ 242.832014] [<ffffffffaea47e3a>] ? > bdget+0xfa/0x110 > Apr 28 11:34:17 buildvm kernel: [ 242.832020] [<ffffffffaea49530>] ? > blkdev_get_by_dev+0x40/0x40 > Apr 28 11:34:17 buildvm kernel: [ 242.832026] [<ffffffffaea08e74>] ? > do_dentry_open+0x234/0x340 > Apr 28 11:34:17 buildvm kernel: [ 242.832030] [<ffffffffaea1ada7>] ? > path_openat+0x777/0x15b0 > Apr 28 11:34:17 buildvm kernel: [ 242.832037] [<ffffffffae9c8211>] ? > page_add_file_rmap+0x11/0x110 > Apr 28 11:34:17 buildvm kernel: [ 242.832042] [<ffffffffaea1cea1>] ? > do_filp_open+0x91/0x100 > Apr 28 11:34:17 buildvm kernel: [ 242.832047] [<ffffffffae9bb263>] ? > handle_mm_fault+0xcc3/0x1350 > Apr 28 11:34:17 buildvm kernel: [ 242.832052] [<ffffffffaea07b3a>] ? > __check_object_size+0xfa/0x1d8 > Apr 28 11:34:17 buildvm kernel: [ 242.832058] [<ffffffffaea0a3ae>] ? > do_sys_open+0x12e/0x210 > Apr 28 11:34:17 buildvm kernel: [ 242.832064] [<ffffffffae803b7d>] ? > do_syscall_64+0x8d/0xf0 > Apr 28 11:34:17 buildvm kernel: [ 242.832069] [<ffffffffaee1a84e>] ? > entry_SYSCALL_64_after_swapgs+0x58/0xc6 > Apr 28 11:36:18 buildvm kernel: [ 363.661408] INFO: task losetup:2591 > blocked for more than 120 seconds. > Apr 28 11:36:18 buildvm kernel: [ 363.661487] Not tainted > 4.9.0-9-amd64 #1 Debian 4.9.168-1 > Apr 28 11:36:18 buildvm kernel: [ 363.661541] "echo 0 > > /proc/sys/kernel/hung_task_timeout_secs" disables this message. > Apr 28 11:36:18 buildvm kernel: [ 363.661610] losetup D 0 2591 > 1 0x00000004 > Apr 28 11:36:18 buildvm kernel: [ 363.661620] ffff8a2db7926c00 > 0000000000000000 ffff8a2db7956ec0 ffff8a2dbfa18980 > Apr 28 11:36:18 buildvm kernel: [ 363.661628] ffffffffaf411500 > ffffaf8440a7fbd8 ffffffffaee15a99 ffffffffaee1a964 > Apr 28 11:36:18 buildvm kernel: [ 363.661635] 00ff8a2db7957a00 > ffff8a2dbfa18980 ffff8a2dbacc5240 ffff8a2db7956ec0 > Apr 28 11:36:18 buildvm kernel: [ 363.661642] Call Trace: > Apr 28 11:36:18 buildvm kernel: [ 363.661656] [<ffffffffaee15a99>] ? > __schedule+0x239/0x6f0 > Apr 28 11:36:18 buildvm kernel: [ 363.661663] [<ffffffffaee1a964>] ? > __switch_to_asm+0x34/0x70 > Apr 28 11:36:18 buildvm kernel: [ 363.661670] [<ffffffffaee15f82>] ? > schedule+0x32/0x80 > Apr 28 11:36:18 buildvm kernel: [ 363.661677] [<ffffffffaee1623a>] ? > schedule_preempt_disabled+0xa/0x10 > Apr 28 11:36:18 buildvm kernel: [ 363.661682] [<ffffffffaee17c94>] ? > __mutex_lock_slowpath+0xb4/0x130 > Apr 28 11:36:18 buildvm kernel: [ 363.661689] [<ffffffffaee17d2b>] ? > mutex_lock+0x1b/0x30 > Apr 28 11:36:18 buildvm kernel: [ 363.661697] [<ffffffffaeb15e46>] ? > blkdev_reread_part+0x16/0x30 > Apr 28 11:36:18 buildvm kernel: [ 363.661705] [<ffffffffc03e1803>] ? > loop_reread_partitions+0x23/0x50 [loop] > Apr 28 11:36:18 buildvm kernel: [ 363.661712] [<ffffffffc03e1b3b>] ? > loop_set_status+0x30b/0x3a0 [loop] > Apr 28 11:36:18 buildvm kernel: [ 363.661719] [<ffffffffc03e1e88>] ? > loop_set_status64+0x48/0x70 [loop] > Apr 28 11:36:18 buildvm kernel: [ 363.661726] [<ffffffffc03e3138>] ? > lo_ioctl+0xe8/0x6f0 [loop] > Apr 28 11:36:18 buildvm kernel: [ 363.661734] [<ffffffffaeb16645>] ? > blkdev_ioctl+0x265/0x970 > Apr 28 11:36:18 buildvm kernel: [ 363.661740] [<ffffffffae9bb37f>] ? > handle_mm_fault+0xddf/0x1350 > Apr 28 11:36:18 buildvm kernel: [ 363.661748] [<ffffffffaea481a9>] ? > block_ioctl+0x39/0x40 > Apr 28 11:36:18 buildvm kernel: [ 363.661753] [<ffffffffaea201b2>] ? > do_vfs_ioctl+0xa2/0x620 > Apr 28 11:36:18 buildvm kernel: [ 363.661759] [<ffffffffaea207a4>] ? > SyS_ioctl+0x74/0x80 > Apr 28 11:36:18 buildvm kernel: [ 363.661765] [<ffffffffae803b7d>] ? > do_syscall_64+0x8d/0xf0 > Apr 28 11:36:18 buildvm kernel: [ 363.661771] [<ffffffffaee1a84e>] ? > entry_SYSCALL_64_after_swapgs+0x58/0xc6 > Apr 28 11:36:18 buildvm kernel: [ 363.661776] INFO: task systemd-udevd:2597 > blocked for more than 120 seconds. > Apr 28 11:36:18 buildvm kernel: [ 363.661841] Not tainted > 4.9.0-9-amd64 #1 Debian 4.9.168-1 > Apr 28 11:36:18 buildvm kernel: [ 363.661894] "echo 0 > > /proc/sys/kernel/hung_task_timeout_secs" disables this message. > Apr 28 11:36:18 buildvm kernel: [ 363.661962] systemd-udevd D 0 2597 > 346 0x00000004 > Apr 28 11:36:18 buildvm kernel: [ 363.661969] ffff8a2db7924400 > 0000000000000000 ffff8a2db79ff180 ffff8a2dbfb18980 > Apr 28 11:36:18 buildvm kernel: [ 363.661976] ffff8a2dbb91cec0 > ffffaf844086bd88 ffffffffaee15a99 3959c0b6fb0308ab > Apr 28 11:36:18 buildvm kernel: [ 363.661983] 00ffaf844086bd70 > ffff8a2dbfb18980 ffff8a2dbb219498 ffff8a2db79ff180 > Apr 28 11:36:18 buildvm kernel: [ 363.661990] Call Trace: > Apr 28 11:36:18 buildvm kernel: [ 363.661998] [<ffffffffaee15a99>] ? > __schedule+0x239/0x6f0 > Apr 28 11:36:18 buildvm kernel: [ 363.662006] [<ffffffffaee15f82>] ? > schedule+0x32/0x80 > Apr 28 11:36:18 buildvm kernel: [ 363.662013] [<ffffffffaee1623a>] ? > schedule_preempt_disabled+0xa/0x10 > Apr 28 11:36:18 buildvm kernel: [ 363.662017] [<ffffffffaee17c94>] ? > __mutex_lock_slowpath+0xb4/0x130 > Apr 28 11:36:18 buildvm kernel: [ 363.662022] [<ffffffffaee17d2b>] ? > mutex_lock+0x1b/0x30 > Apr 28 11:36:18 buildvm kernel: [ 363.662029] [<ffffffffc03e2ff4>] ? > lo_release+0x44/0xa0 [loop] > Apr 28 11:36:18 buildvm kernel: [ 363.662036] [<ffffffffaea48b2d>] ? > __blkdev_put+0x1ed/0x2d0 > Apr 28 11:36:18 buildvm kernel: [ 363.662043] [<ffffffffaea491b1>] ? > blkdev_close+0x21/0x30 > Apr 28 11:36:18 buildvm kernel: [ 363.662048] [<ffffffffaea0dc48>] ? > __fput+0xd8/0x220 > Apr 28 11:36:18 buildvm kernel: [ 363.662055] [<ffffffffae898d5f>] ? > task_work_run+0x7f/0xa0 > Apr 28 11:36:18 buildvm kernel: [ 363.662061] [<ffffffffae803754>] ? > exit_to_usermode_loop+0xa4/0xb0 > Apr 28 11:36:18 buildvm kernel: [ 363.662067] [<ffffffffae803bcd>] ? > do_syscall_64+0xdd/0xf0 > Apr 28 11:36:18 buildvm kernel: [ 363.662073] [<ffffffffaee1a84e>] ? > entry_SYSCALL_64_after_swapgs+0x58/0xc6 > > The above repeats for all D systemd-udev tasks, and losetup, EG: > > Apr 28 11:34:17 buildvm kernel: [ 242.829350] INFO: task losetup:2591 > blocked for more than 120 seconds. > Apr 28 11:34:17 buildvm kernel: [ 242.829715] INFO: task systemd-udevd:2597 > blocked for more than 120 seconds. > Apr 28 11:34:17 buildvm kernel: [ 242.830018] INFO: task systemd-udevd:2602 > blocked for more than 120 seconds. > Apr 28 11:34:17 buildvm kernel: [ 242.830342] INFO: task systemd-udevd:2603 > blocked for more than 120 seconds. > Apr 28 11:34:17 buildvm kernel: [ 242.830679] INFO: task systemd-udevd:2607 > blocked for more than 120 seconds. > Apr 28 11:34:17 buildvm kernel: [ 242.831086] INFO: task systemd-udevd:2609 > blocked for more than 120 seconds. > Apr 28 11:34:17 buildvm kernel: [ 242.831413] INFO: task systemd-udevd:2610 > blocked for more than 120 seconds. > Apr 28 11:34:17 buildvm kernel: [ 242.831744] INFO: task systemd-udevd:2612 > blocked for more than 120 seconds. > Apr 28 11:36:18 buildvm kernel: [ 363.661408] INFO: task losetup:2591 > blocked for more than 120 seconds. > Apr 28 11:36:18 buildvm kernel: [ 363.661776] INFO: task systemd-udevd:2597 > blocked for more than 120 seconds. > > I tried to strace this, but if I do? It works fine. Further, once I've > done an strace, further losetups work fine -- without blocking. > > Not really sure what's causing this, but without strace and losetup D > forever, it's annoying to debug. Suggestions welcome. > > Note that after the above INFO/hangs, the above systemd-udev and losetup > tasks sit D forever. It's been 20+ minutes, no activity in kern.log, > just dead. >
This looks like a kernel regression. Do you use a Debian kernel? From which version did you upgrade? If you downgrade to the previous kernel version, does the problem go away. -- Why is it that all of the instruments seeking intelligent life in the universe are pointed away from Earth?
signature.asc
Description: OpenPGP digital signature