Hang triggered by udev coldplug, looks like a race

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

 



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-fsdevel" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at  http://vger.kernel.org/majordomo-info.html



[Index of Archives]     [Linux Ext4 Filesystem]     [Union Filesystem]     [Filesystem Testing]     [Ceph Users]     [Ecryptfs]     [AutoFS]     [Kernel Newbies]     [Share Photos]     [Security]     [Netfilter]     [Bugtraq]     [Yosemite News]     [MIPS Linux]     [ARM Linux]     [Linux Security]     [Linux Cachefs]     [Reiser Filesystem]     [Linux RAID]     [Samba]     [Device Mapper]     [CEPH Development]
  Powered by Linux