| lists.openwall.net | lists / announce owl-users owl-dev john-users john-dev passwdqc-users yescrypt popa3d-users / oss-security kernel-hardening musl sabotage tlsify passwords / crypt-dev xvendor / Bugtraq Full-Disclosure linux-kernel linux-netdev linux-ext4 linux-hardening linux-cve-announce PHC | |
|
Open Source and information security mailing list archives
| ||
|
Date: Thu, 3 Dec 2015 21:52:46 -0800 From: Andy Lutomirski <luto@...capital.net> To: "linux-kernel@...r.kernel.org" <linux-kernel@...r.kernel.org>, V9FS Developers <v9fs-developer@...ts.sourceforge.net>, Linux FS Devel <linux-fsdevel@...r.kernel.org> Subject: Hang triggered by udev coldplug, looks like a race Sometimes udevadm trigger --action=add hangs the system, and the splat below happens. This seems to be timing dependent, and I haven't been able to trigger it yet with lockdep enabled, sadly. Any ideas? I not, I'll try to instrument it better tomorrow. This is 4.4-rc3 plus some patches that I don't think are related. The rootfs is 9p. --Andy [ 60.048359] INFO: task kworker/u2:1:980 blocked for more than 30 seconds. [ 60.051673] Not tainted 4.3.0-rc4+ #3 [ 60.052149] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [ 60.053013] kworker/u2:1 D ffff880006823bc8 14152 980 14 0x00000000 [ 60.053786] ffff880006823bc8 ffff8800072e4740 ffff8800072e63c0 ffff880006824000 [ 60.054637] ffff88000613cfd0 ffff8800072e63c0 00000000ffffffff 0000000000000246 [ 60.055447] ffff880006823be0 ffffffff818d2bfe ffff88000613cfc8 ffff880006823bf0 [ 60.056250] Call Trace: [ 60.056513] [<ffffffff818d2bfe>] schedule+0x2e/0x70 [ 60.057017] [<ffffffff818d2f29>] schedule_preempt_disabled+0x9/0x10 [ 60.057632] [<ffffffff818d5457>] __mutex_lock_slowpath+0x107/0x2f0 [ 60.058242] [<ffffffff811c9123>] ? lookup_fast+0x133/0x2e0 [ 60.058790] [<ffffffff818d5655>] mutex_lock+0x15/0x30 [ 60.059272] [<ffffffff811cc76f>] path_openat+0x63f/0x1220 [ 60.059805] [<ffffffff811ce339>] do_filp_open+0x79/0xd0 [ 60.060352] [<ffffffff8130a136>] ? selinux_cred_prepare+0x16/0x30 [ 60.060966] [<ffffffff8130449e>] ? security_prepare_creds+0x3e/0x60 [ 60.061805] [<ffffffff811c403f>] do_open_execat+0x5f/0x150 [ 60.062316] [<ffffffff811c5d53>] do_execveat_common.isra.33+0x1a3/0x6c0 [ 60.062916] [<ffffffff811c6297>] do_execve+0x27/0x30 [ 60.063355] [<ffffffff810b8d2b>] call_usermodehelper_exec_async+0xeb/0x140 [ 60.063951] [<ffffffff818d7712>] ret_from_fork+0x22/0x40 [ 60.064416] [<ffffffff810b8c40>] ? umh_complete+0x40/0x40 [ 60.064889] INFO: task kworker/u2:1:981 blocked for more than 30 seconds. [ 60.065473] Not tainted 4.3.0-rc4+ #3 [ 60.065834] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [ 60.066507] kworker/u2:1 D ffff880006827bc8 14152 981 14 0x00000000 [ 60.067135] ffff880006827bc8 ffff880006965580 ffff8800072e0e40 ffff880006828000 [ 60.067810] ffff88000613cfd0 ffff8800072e0e40 00000000ffffffff 0000000000000246 [ 60.068491] ffff880006827be0 ffffffff818d2bfe ffff88000613cfc8 ffff880006827bf0 [ 60.069169] Call Trace: [ 60.069386] [<ffffffff818d2bfe>] schedule+0x2e/0x70 [ 60.069814] [<ffffffff818d2f29>] schedule_preempt_disabled+0x9/0x10 [ 60.070361] [<ffffffff818d5457>] __mutex_lock_slowpath+0x107/0x2f0 [ 60.070898] [<ffffffff811c9123>] ? lookup_fast+0x133/0x2e0 [ 60.071381] [<ffffffff818d5655>] mutex_lock+0x15/0x30 [ 60.071825] [<ffffffff811cc76f>] path_openat+0x63f/0x1220 [ 60.072299] [<ffffffff811ce339>] do_filp_open+0x79/0xd0 [ 60.072756] [<ffffffff8130a136>] ? selinux_cred_prepare+0x16/0x30 [ 60.073289] [<ffffffff8130449e>] ? security_prepare_creds+0x3e/0x60 [ 60.073832] [<ffffffff811c403f>] do_open_execat+0x5f/0x150 [ 60.074316] [<ffffffff811c5d53>] do_execveat_common.isra.33+0x1a3/0x6c0 [ 60.075083] [<ffffffff811c6297>] do_execve+0x27/0x30 [ 60.075736] [<ffffffff810b8d2b>] call_usermodehelper_exec_async+0xeb/0x140 [ 60.076648] [<ffffffff818d7712>] ret_from_fork+0x22/0x40 [ 60.077235] [<ffffffff810b8c40>] ? umh_complete+0x40/0x40 [ 60.077805] INFO: task kworker/u2:1:982 blocked for more than 30 seconds. [ 60.078529] Not tainted 4.3.0-rc4+ #3 [ 60.078969] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [ 60.079891] kworker/u2:1 D ffff88000682bbc8 14584 982 14 0x00000000 [ 60.080658] ffff88000682bbc8 ffff8800064cb900 ffff880006bc0e40 ffff88000682c000 [ 60.081474] ffff88000613cfd0 ffff880006bc0e40 00000000ffffffff 0000000000000246 [ 60.082282] ffff88000682bbe0 ffffffff818d2bfe ffff88000613cfc8 ffff88000682bbf0 [ 60.083095] Call Trace: [ 60.083357] [<ffffffff818d2bfe>] schedule+0x2e/0x70 [ 60.083871] [<ffffffff818d2f29>] schedule_preempt_disabled+0x9/0x10 [ 60.084533] [<ffffffff818d5457>] __mutex_lock_slowpath+0x107/0x2f0 [ 60.085181] [<ffffffff811c9123>] ? lookup_fast+0x133/0x2e0 [ 60.085761] [<ffffffff818d5655>] mutex_lock+0x15/0x30 [ 60.086300] [<ffffffff811cc76f>] path_openat+0x63f/0x1220 [ 60.086869] [<ffffffff811ce339>] do_filp_open+0x79/0xd0 [ 60.087422] [<ffffffff8130a136>] ? selinux_cred_prepare+0x16/0x30 [ 60.088067] [<ffffffff8130449e>] ? security_prepare_creds+0x3e/0x60 [ 60.088722] [<ffffffff811c403f>] do_open_execat+0x5f/0x150 [ 60.089301] [<ffffffff811c5d53>] do_execveat_common.isra.33+0x1a3/0x6c0 [ 60.089991] [<ffffffff811c6297>] do_execve+0x27/0x30 [ 60.090552] [<ffffffff810b8d2b>] call_usermodehelper_exec_async+0xeb/0x140 [ 60.091274] [<ffffffff818d7712>] ret_from_fork+0x22/0x40 [ 60.091832] [<ffffffff810b8c40>] ? umh_complete+0x40/0x40 [ 60.092401] INFO: task kworker/u2:1:983 blocked for more than 30 seconds. [ 60.093138] Not tainted 4.3.0-rc4+ #3 [ 60.093574] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [ 60.094379] kworker/u2:1 D ffff88000682fbc8 14544 983 14 0x00000000 [ 60.095139] ffff88000682fbc8 ffff880006bc0e40 ffff88000644c740 ffff880006830000 [ 60.095973] ffff88000613cfd0 ffff88000644c740 00000000ffffffff 0000000000000246 [ 60.096871] ffff88000682fbe0 ffffffff818d2bfe ffff88000613cfc8 ffff88000682fbf0 [ 60.097686] Call Trace: [ 60.097945] [<ffffffff818d2bfe>] schedule+0x2e/0x70 [ 60.098472] [<ffffffff818d2f29>] schedule_preempt_disabled+0x9/0x10 [ 60.099136] [<ffffffff818d5457>] __mutex_lock_slowpath+0x107/0x2f0 [ 60.099786] [<ffffffff811c9123>] ? lookup_fast+0x133/0x2e0 [ 60.100368] [<ffffffff818d5655>] mutex_lock+0x15/0x30 [ 60.100902] [<ffffffff811cc76f>] path_openat+0x63f/0x1220 [ 60.101478] [<ffffffff811ce339>] do_filp_open+0x79/0xd0 [ 60.102060] [<ffffffff8130a136>] ? selinux_cred_prepare+0x16/0x30 [ 60.102706] [<ffffffff8130449e>] ? security_prepare_creds+0x3e/0x60 [ 60.103366] [<ffffffff811c403f>] do_open_execat+0x5f/0x150 [ 60.103947] [<ffffffff811c5d53>] do_execveat_common.isra.33+0x1a3/0x6c0 [ 60.104647] [<ffffffff811c6297>] do_execve+0x27/0x30 [ 60.105205] [<ffffffff810b8d2b>] call_usermodehelper_exec_async+0xeb/0x140 [ 60.105923] [<ffffffff818d7712>] ret_from_fork+0x22/0x40 [ 60.106494] [<ffffffff810b8c40>] ? umh_complete+0x40/0x40 [ 60.107065] INFO: task kworker/u2:1:984 blocked for more than 30 seconds. [ 60.107795] Not tainted 4.3.0-rc4+ #3 [ 60.108248] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [ 60.109115] kworker/u2:1 D ffff8800068e3bc8 14152 984 14 0x00000000 [ 60.109881] ffff8800068e3bc8 ffff880006a25580 ffff880006b65580 ffff8800068e4000 [ 60.110737] ffff88000613cfd0 ffff880006b65580 00000000ffffffff 0000000000000246 [ 60.111577] ffff8800068e3be0 ffffffff818d2bfe ffff88000613cfc8 ffff8800068e3bf0 [ 60.112533] Call Trace: [ 60.112798] [<ffffffff818d2bfe>] schedule+0x2e/0x70 [ 60.113325] [<ffffffff818d2f29>] schedule_preempt_disabled+0x9/0x10 [ 60.113990] [<ffffffff818d5457>] __mutex_lock_slowpath+0x107/0x2f0 [ 60.114652] [<ffffffff811c9123>] ? lookup_fast+0x133/0x2e0 [ 60.115240] [<ffffffff818d5655>] mutex_lock+0x15/0x30 [ 60.115807] [<ffffffff811cc76f>] path_openat+0x63f/0x1220 [ 60.116385] [<ffffffff811ce339>] do_filp_open+0x79/0xd0 [ 60.116942] [<ffffffff8130a136>] ? selinux_cred_prepare+0x16/0x30 [ 60.117595] [<ffffffff8130449e>] ? security_prepare_creds+0x3e/0x60 [ 60.118261] [<ffffffff811c403f>] do_open_execat+0x5f/0x150 [ 60.118845] [<ffffffff811c5d53>] do_execveat_common.isra.33+0x1a3/0x6c0 [ 60.119548] [<ffffffff811c6297>] do_execve+0x27/0x30 [ 60.120110] [<ffffffff810b8d2b>] call_usermodehelper_exec_async+0xeb/0x140 [ 60.120836] [<ffffffff818d7712>] ret_from_fork+0x22/0x40 [ 60.121406] [<ffffffff810b8c40>] ? umh_complete+0x40/0x40 [ 60.121981] INFO: task kworker/u2:1:985 blocked for more than 30 seconds. [ 60.122732] Not tainted 4.3.0-rc4+ #3 [ 60.123177] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [ 60.123992] kworker/u2:1 D ffff8800068e7bc8 14152 985 14 0x00000000 [ 60.124759] ffff8800068e7bc8 ffff8800073c0000 ffff880006b61c80 ffff8800068e8000 [ 60.125579] ffff88000613cfd0 ffff880006b61c80 00000000ffffffff 0000000000000246 [ 60.126389] ffff8800068e7be0 ffffffff818d2bfe ffff88000613cfc8 ffff8800068e7bf0 [ 60.127258] Call Trace: [ 60.127525] [<ffffffff818d2bfe>] schedule+0x2e/0x70 [ 60.128052] [<ffffffff818d2f29>] schedule_preempt_disabled+0x9/0x10 [ 60.128720] [<ffffffff818d5457>] __mutex_lock_slowpath+0x107/0x2f0 [ 60.129380] [<ffffffff811c9123>] ? lookup_fast+0x133/0x2e0 [ 60.129995] [<ffffffff818d5655>] mutex_lock+0x15/0x30 [ 60.130570] [<ffffffff811cc76f>] path_openat+0x63f/0x1220 [ 60.131150] [<ffffffff811ce339>] do_filp_open+0x79/0xd0 [ 60.131733] [<ffffffff8130a136>] ? selinux_cred_prepare+0x16/0x30 [ 60.132410] [<ffffffff8130449e>] ? security_prepare_creds+0x3e/0x60 [ 60.133106] [<ffffffff811c403f>] do_open_execat+0x5f/0x150 [ 60.133692] [<ffffffff811c5d53>] do_execveat_common.isra.33+0x1a3/0x6c0 [ 60.134393] [<ffffffff811c6297>] do_execve+0x27/0x30 [ 60.134951] [<ffffffff810b8d2b>] call_usermodehelper_exec_async+0xeb/0x140 [ 60.135711] [<ffffffff818d7712>] ret_from_fork+0x22/0x40 [ 60.136280] [<ffffffff810b8c40>] ? umh_complete+0x40/0x40 [ 60.136856] INFO: task kworker/u2:1:986 blocked for more than 30 seconds. [ 60.137600] Not tainted 4.3.0-rc4+ #3 [ 60.138073] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [ 60.138881] kworker/u2:1 D ffff8800068ebbc8 14152 986 14 0x00000000 [ 60.139672] ffff8800068ebbc8 ffff8800066bc740 ffff880006b663c0 ffff8800068ec000 [ 60.140545] ffff88000613cfd0 ffff880006b663c0 00000000ffffffff 0000000000000246 [ 60.141356] ffff8800068ebbe0 ffffffff818d2bfe ffff88000613cfc8 ffff8800068ebbf0 [ 60.142209] Call Trace: [ 60.142487] [<ffffffff818d2bfe>] schedule+0x2e/0x70 [ 60.142998] [<ffffffff818d2f29>] schedule_preempt_disabled+0x9/0x10 [ 60.143657] [<ffffffff818d5457>] __mutex_lock_slowpath+0x107/0x2f0 [ 60.144307] [<ffffffff811c9123>] ? lookup_fast+0x133/0x2e0 [ 60.144895] [<ffffffff818d5655>] mutex_lock+0x15/0x30 [ 60.145455] [<ffffffff811cc76f>] path_openat+0x63f/0x1220 [ 60.146117] [<ffffffff811ce339>] do_filp_open+0x79/0xd0 [ 60.146715] [<ffffffff8130a136>] ? selinux_cred_prepare+0x16/0x30 [ 60.147391] [<ffffffff8130449e>] ? security_prepare_creds+0x3e/0x60 [ 60.148081] [<ffffffff811c403f>] do_open_execat+0x5f/0x150 [ 60.148660] [<ffffffff811c5d53>] do_execveat_common.isra.33+0x1a3/0x6c0 [ 60.149380] [<ffffffff811c6297>] do_execve+0x27/0x30 [ 60.149905] [<ffffffff810b8d2b>] call_usermodehelper_exec_async+0xeb/0x140 [ 60.150629] [<ffffffff818d7712>] ret_from_fork+0x22/0x40 [ 60.151189] [<ffffffff810b8c40>] ? umh_complete+0x40/0x40 [ 60.151787] INFO: task kworker/u2:1:987 blocked for more than 30 seconds. [ 60.152497] Not tainted 4.3.0-rc4+ #3 [ 60.152927] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [ 60.153735] kworker/u2:1 D ffff8800068efbc8 14152 987 14 0x00000000 [ 60.154524] ffff8800068efbc8 ffff880007234740 ffff880006bf9c80 ffff8800068f0000 [ 60.155389] ffff88000613cfd0 ffff880006bf9c80 00000000ffffffff 0000000000000246 [ 60.156227] ffff8800068efbe0 ffffffff818d2bfe ffff88000613cfc8 ffff8800068efbf0 [ 60.157040] Call Trace: [ 60.157299] [<ffffffff818d2bfe>] schedule+0x2e/0x70 [ 60.157813] [<ffffffff818d2f29>] schedule_preempt_disabled+0x9/0x10 [ 60.158478] [<ffffffff818d5457>] __mutex_lock_slowpath+0x107/0x2f0 [ 60.159125] [<ffffffff811c9123>] ? lookup_fast+0x133/0x2e0 [ 60.159731] [<ffffffff818d5655>] mutex_lock+0x15/0x30 [ 60.160294] [<ffffffff811cc76f>] path_openat+0x63f/0x1220 [ 60.160864] [<ffffffff811ce339>] do_filp_open+0x79/0xd0 [ 60.161414] [<ffffffff8130a136>] ? selinux_cred_prepare+0x16/0x30 [ 60.162058] [<ffffffff8130449e>] ? security_prepare_creds+0x3e/0x60 [ 60.162711] [<ffffffff811c403f>] do_open_execat+0x5f/0x150 [ 60.163315] [<ffffffff811c5d53>] do_execveat_common.isra.33+0x1a3/0x6c0 [ 60.164038] [<ffffffff811c6297>] do_execve+0x27/0x30 [ 60.164586] [<ffffffff810b8d2b>] call_usermodehelper_exec_async+0xeb/0x140 [ 60.165305] [<ffffffff818d7712>] ret_from_fork+0x22/0x40 [ 60.165890] [<ffffffff810b8c40>] ? umh_complete+0x40/0x40 [ 60.166490] INFO: task kworker/u2:1:988 blocked for more than 30 seconds. [ 60.167220] Not tainted 4.3.0-rc4+ #3 [ 60.167682] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [ 60.168515] kworker/u2:1 D ffff880006913bc8 14152 988 14 0x00000000 [ 60.169270] ffff880006913bc8 ffff8800001663c0 ffff880006bfc740 ffff880006914000 [ 60.170081] ffff88000613cfd0 ffff880006bfc740 00000000ffffffff 0000000000000246 [ 60.170884] ffff880006913be0 ffffffff818d2bfe ffff88000613cfc8 ffff880006913bf0 [ 60.171742] Call Trace: [ 60.172037] [<ffffffff818d2bfe>] schedule+0x2e/0x70 [ 60.172587] [<ffffffff818d2f29>] schedule_preempt_disabled+0x9/0x10 [ 60.173263] [<ffffffff818d5457>] __mutex_lock_slowpath+0x107/0x2f0 [ 60.173928] [<ffffffff811c9123>] ? lookup_fast+0x133/0x2e0 [ 60.174550] [<ffffffff818d5655>] mutex_lock+0x15/0x30 [ 60.175097] [<ffffffff811cc76f>] path_openat+0x63f/0x1220 [ 60.175703] [<ffffffff811afa1c>] ? alloc_pages_current+0x8c/0x100 [ 60.176354] [<ffffffff811ce339>] do_filp_open+0x79/0xd0 [ 60.176955] [<ffffffff8130a136>] ? selinux_cred_prepare+0x16/0x30 [ 60.177630] [<ffffffff8130449e>] ? security_prepare_creds+0x3e/0x60 [ 60.178303] [<ffffffff811c403f>] do_open_execat+0x5f/0x150 [ 60.178984] [<ffffffff811c5d53>] do_execveat_common.isra.33+0x1a3/0x6c0 [ 60.179701] [<ffffffff811c6297>] do_execve+0x27/0x30 [ 60.180268] [<ffffffff810b8d2b>] call_usermodehelper_exec_async+0xeb/0x140 [ 60.181057] [<ffffffff818d7712>] ret_from_fork+0x22/0x40 [ 60.181625] [<ffffffff810b8c40>] ? umh_complete+0x40/0x40 [ 60.182233] INFO: task kworker/u2:1:989 blocked for more than 30 seconds. [ 60.182972] Not tainted 4.3.0-rc4+ #3 [ 60.183420] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [ 60.184268] kworker/u2:1 D ffff880006917bc8 14152 989 14 0x00000000 [ 60.185063] ffff880006917bc8 ffff880000149c80 ffff880006bf8e40 ffff880006918000 [ 60.185954] ffff88000613cfd0 ffff880006bf8e40 00000000ffffffff 0000000000000246 [ 60.186806] ffff880006917be0 ffffffff818d2bfe ffff88000613cfc8 ffff880006917bf0 [ 60.187672] Call Trace: [ 60.187937] [<ffffffff818d2bfe>] schedule+0x2e/0x70 [ 60.188495] [<ffffffff818d2f29>] schedule_preempt_disabled+0x9/0x10 [ 60.189193] [<ffffffff818d5457>] __mutex_lock_slowpath+0x107/0x2f0 [ 60.189851] [<ffffffff811c9123>] ? lookup_fast+0x133/0x2e0 [ 60.190472] [<ffffffff818d5655>] mutex_lock+0x15/0x30 [ 60.191043] [<ffffffff811cc76f>] path_openat+0x63f/0x1220 [ 60.191649] [<ffffffff811ce339>] do_filp_open+0x79/0xd0 [ 60.192112] [<ffffffff8130a136>] ? selinux_cred_prepare+0x16/0x30 [ 60.192678] [<ffffffff8130449e>] ? security_prepare_creds+0x3e/0x60 [ 60.193248] [<ffffffff811c403f>] do_open_execat+0x5f/0x150 [ 60.193722] [<ffffffff811c5d53>] do_execveat_common.isra.33+0x1a3/0x6c0 [ 60.194291] [<ffffffff811c6297>] do_execve+0x27/0x30 [ 60.194724] [<ffffffff810b8d2b>] call_usermodehelper_exec_async+0xeb/0x140 [ 60.195318] [<ffffffff818d7712>] ret_from_fork+0x22/0x40 [ 60.195781] [<ffffffff810b8c40>] ? umh_complete+0x40/0x40 -- To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to majordomo@...r.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
Powered by blists - more mailing lists