For some time now, I always[0] receive a lockdep warning when there's some disk I/O on the system. But recently the warning looks kinda mangled, I suspect the recent printk change (4bcc595ccd80, "printk: reinstate KERN_CONT for printing continuation lines") to be the reason for that. In previous versions, the warning looked like this:
http://nerdbynature.de/bits/4.6.0-rc7/dmesg.txt Below is the new warning, which is barely readable anymore. Of course, best would be for the warning to vanish (hehe) but maybe the printout could be fixed too? Thanks, Christian. [ 2401.254353] ========================================================= [ 2401.254410] [ INFO: possible irq lock inversion dependency detected ] [ 2401.254469] 4.9.0-rc6 #1 Not tainted [ 2401.254506] --------------------------------------------------------- [ 2401.254560] kswapd0/282 just changed the state of lock: [ 2401.254620] ( [ 2401.254647] &jfs_ip->rdwrlock [ 2401.254685] #2 [ 2401.254698] ){++++-.} [ 2401.254730] , at: [ 2401.254764] [<c01f9c38>] jfs_get_block+0x50/0x370 [ 2401.254812] but this lock took another, RECLAIM_FS-unsafe lock in the past: [ 2401.254868] ( [ 2401.254890] &jfs_ip->commit_mutex [ 2401.254927] ){+.+.+.} [ 2401.254945] and interrupts could create inverse lock ordering between them. [ 2401.255041] other info that might help us debug this: [ 2401.255097] Possible interrupt unsafe locking scenario: [ 2401.255160] CPU0 CPU1 [ 2401.255203] ---- ---- [ 2401.255243] lock( [ 2401.255273] &jfs_ip->commit_mutex [ 2401.255310] ); [ 2401.255334] local_irq_disable(); [ 2401.255381] lock( [ 2401.255420] &jfs_ip->rdwrlock [ 2401.255454] #2 [ 2401.255467] ); [ 2401.255494] lock( [ 2401.255536] &jfs_ip->commit_mutex [ 2401.255573] ); [ 2401.255596] <Interrupt> [ 2401.255623] lock( [ 2401.255648] &jfs_ip->rdwrlock [ 2401.256059] #2 [ 2401.256071] ); [ 2401.256446] *** DEADLOCK *** [ 2401.257522] no locks held by kswapd0/282. [ 2401.257888] the shortest dependencies between 2nd lock and 1st lock: [ 2401.258622] -> [ 2401.258645] ( [ 2401.259014] &jfs_ip->commit_mutex [ 2401.259047] ){+.+.+.} [ 2401.259418] ops: 31698 [ 2401.259435] { [ 2401.259800] HARDIRQ-ON-W [ 2401.259829] at: [ 2401.260192] [ 2401.260236] [<c00633c8>] lock_acquire+0x4c/0x68 [ 2401.260619] [ 2401.260657] [<c0652780>] mutex_lock_nested+0x38/0x2f8 [ 2401.261048] [ 2401.261108] [<c01fafd0>] jfs_create+0x88/0x2c4 [ 2401.261839] [ 2401.261996] [<c00ffe24>] path_openat+0xc1c/0x100c [ 2401.262689] [ 2401.262860] [<c0101224>] do_filp_open+0xb0/0x100 [ 2401.263639] [ 2401.263678] [<c00ee44c>] do_sys_open+0x154/0x21c [ 2401.264368] [ 2401.264411] [<c00107e8>] ret_from_syscall+0x0/0x38 [ 2401.265070] SOFTIRQ-ON-W [ 2401.265099] at: [ 2401.265579] [ 2401.265751] [<c00633c8>] lock_acquire+0x4c/0x68 [ 2401.266268] [ 2401.266437] [<c0652780>] mutex_lock_nested+0x38/0x2f8 [ 2401.266975] [ 2401.267135] [<c01fafd0>] jfs_create+0x88/0x2c4 [ 2401.267679] [ 2401.267837] [<c00ffe24>] path_openat+0xc1c/0x100c [ 2401.268394] [ 2401.268560] [<c0101224>] do_filp_open+0xb0/0x100 [ 2401.269104] [ 2401.269273] [<c00ee44c>] do_sys_open+0x154/0x21c [ 2401.269969] [ 2401.270040] [<c00107e8>] ret_from_syscall+0x0/0x38 [ 2401.270727] RECLAIM_FS-ON-W [ 2401.270761] at: [ 2401.271279] [ 2401.271418] [<c0063960>] lockdep_trace_alloc+0x8c/0xe4 [ 2401.272017] [ 2401.272122] [<c00e7f64>] __kmalloc+0x40/0x14c [ 2401.272706] [ 2401.272839] [<c021b638>] __jfs_set_acl+0xa0/0x1a4 [ 2401.273428] [ 2401.273541] [<c021b898>] jfs_set_acl+0x50/0x9c [ 2401.274135] [ 2401.274267] [<c014bd20>] posix_acl_chmod+0xf0/0x130 [ 2401.274824] [ 2401.274991] [<c0110a48>] notify_change+0x1c4/0x42c [ 2401.275690] [ 2401.275727] [<c00ecb00>] chmod_common+0x74/0x10c [ 2401.276382] [ 2401.276419] [<c00edc60>] SyS_fchmod+0x30/0x64 [ 2401.277090] [ 2401.277129] [<c00107e8>] ret_from_syscall+0x0/0x38 [ 2401.277805] INITIAL USE [ 2401.277834] at: [ 2401.278352] [ 2401.278525] [<c00633c8>] lock_acquire+0x4c/0x68 [ 2401.279054] [ 2401.279224] [<c0652780>] mutex_lock_nested+0x38/0x2f8 [ 2401.279783] [ 2401.279944] [<c01fafd0>] jfs_create+0x88/0x2c4 [ 2401.280528] [ 2401.280645] [<c00ffe24>] path_openat+0xc1c/0x100c [ 2401.281287] [ 2401.281358] [<c0101224>] do_filp_open+0xb0/0x100 [ 2401.282048] [ 2401.282084] [<c00ee44c>] do_sys_open+0x154/0x21c [ 2401.282840] [ 2401.282880] [<c00107e8>] ret_from_syscall+0x0/0x38 [ 2401.283590] } [ 2401.284175] ... key at: [ 2401.284247] [<c105a23c>] __key.33791+0x0/0x8 [ 2401.284978] ... acquired at: [ 2401.285526] [ 2401.285621] [<c0652780>] mutex_lock_nested+0x38/0x2f8 [ 2401.286280] [ 2401.286378] [<c0210f78>] extAlloc+0x4c/0x650 [ 2401.287025] [ 2401.287118] [<c01f9dc0>] jfs_get_block+0x1d8/0x370 [ 2401.287787] [ 2401.287889] [<c012bf1c>] nobh_write_begin+0x174/0x48c [ 2401.288820] [ 2401.288855] [<c01fa6ac>] jfs_write_begin+0x34/0x94 [ 2401.289605] [ 2401.289633] [<c00a6810>] generic_perform_write+0xb0/0x1bc [ 2401.290481] [ 2401.290508] [<c00a8258>] __generic_file_write_iter+0x1a4/0x1f8 [ 2401.291290] [ 2401.291317] [<c00a8398>] generic_file_write_iter+0xec/0x240 [ 2401.292110] [ 2401.292137] [<c00eec78>] __vfs_write+0xd8/0x188 [ 2401.292905] [ 2401.292931] [<c00ef0bc>] vfs_write+0xc4/0x244 [ 2401.293703] [ 2401.293731] [<c00f0f0c>] SyS_write+0x4c/0xc4 [ 2401.294506] [ 2401.294533] [<c00107e8>] ret_from_syscall+0x0/0x38 [ 2401.295992] -> [ 2401.296014] ( [ 2401.296631] &jfs_ip->rdwrlock [ 2401.296745] #2 [ 2401.297340] ){++++-.} [ 2401.297410] ops: 63559 [ 2401.298054] { [ 2401.298663] HARDIRQ-ON-W [ 2401.298786] at: [ 2401.299442] [ 2401.299520] [<c00633c8>] lock_acquire+0x4c/0x68 [ 2401.300438] [ 2401.300578] [<c005d548>] down_write_nested+0x30/0x7c [ 2401.301402] [ 2401.301554] [<c01f9c38>] jfs_get_block+0x50/0x370 [ 2401.302369] [ 2401.302453] [<c012bf1c>] nobh_write_begin+0x174/0x48c [ 2401.303301] [ 2401.303367] [<c01fa6ac>] jfs_write_begin+0x34/0x94 [ 2401.304219] [ 2401.304294] [<c00a6810>] generic_perform_write+0xb0/0x1bc [ 2401.305087] [ 2401.305141] [<c00a8258>] __generic_file_write_iter+0x1a4/0x1f8 [ 2401.305913] [ 2401.305984] [<c00a8398>] generic_file_write_iter+0xec/0x240 [ 2401.306728] [ 2401.306831] [<c00eec78>] __vfs_write+0xd8/0x188 [ 2401.307532] [ 2401.307617] [<c00ef0bc>] vfs_write+0xc4/0x244 [ 2401.308334] [ 2401.308394] [<c00f0f0c>] SyS_write+0x4c/0xc4 [ 2401.309135] [ 2401.309172] [<c00107e8>] ret_from_syscall+0x0/0x38 [ 2401.309924] HARDIRQ-ON-R [ 2401.309953] at: [ 2401.310662] [ 2401.310698] [<c00633c8>] lock_acquire+0x4c/0x68 [ 2401.311456] [ 2401.311491] [<c005d454>] down_read_nested+0x30/0x74 [ 2401.312277] [ 2401.312318] [<c01f9d00>] jfs_get_block+0x118/0x370 [ 2401.313107] [ 2401.313173] [<c0134484>] do_mpage_readpage+0x444/0x814 [ 2401.313959] [ 2401.314007] [<c0134954>] mpage_readpages+0x100/0x190 [ 2401.314827] [ 2401.314975] [<c00b3e50>] __do_page_cache_readahead+0x260/0x32c [ 2401.315716] [ 2401.315853] [<c00a8be0>] generic_file_read_iter+0x638/0x898 [ 2401.316569] [ 2401.316709] [<c00eeaf8>] __vfs_read+0xd8/0x180 [ 2401.317374] [ 2401.317517] [<c00eeecc>] vfs_read+0x98/0x1c4 [ 2401.318144] [ 2401.318266] [<c00f74dc>] prepare_binprm+0xd0/0x158 [ 2401.318964] [ 2401.319081] [<c00f7d4c>] do_execveat_common+0x4d4/0x76c [ 2401.319791] [ 2401.319859] [<c00f8010>] do_execve+0x2c/0x3c [ 2401.320582] [ 2401.320620] [<c0003fa0>] try_to_run_init_process+0x18/0x58 [ 2401.321398] [ 2401.321451] [<c00048b8>] kernel_init+0xc0/0x128 [ 2401.322210] [ 2401.322259] [<c0010924>] ret_from_kernel_thread+0x5c/0x64 [ 2401.323030] SOFTIRQ-ON-W [ 2401.323059] at: [ 2401.323764] [ 2401.323805] [<c00633c8>] lock_acquire+0x4c/0x68 [ 2401.324553] [ 2401.324588] [<c005d548>] down_write_nested+0x30/0x7c [ 2401.325364] [ 2401.325400] [<c01f9c38>] jfs_get_block+0x50/0x370 [ 2401.326149] [ 2401.326187] [<c012bf1c>] nobh_write_begin+0x174/0x48c [ 2401.326945] [ 2401.326981] [<c01fa6ac>] jfs_write_begin+0x34/0x94 [ 2401.327737] [ 2401.327773] [<c00a6810>] generic_perform_write+0xb0/0x1bc [ 2401.328593] [ 2401.328628] [<c00a8258>] __generic_file_write_iter+0x1a4/0x1f8 [ 2401.329415] [ 2401.329451] [<c00a8398>] generic_file_write_iter+0xec/0x240 [ 2401.330214] [ 2401.330276] [<c00eec78>] __vfs_write+0xd8/0x188 [ 2401.331014] [ 2401.331071] [<c00ef0bc>] vfs_write+0xc4/0x244 [ 2401.331805] [ 2401.331847] [<c00f0f0c>] SyS_write+0x4c/0xc4 [ 2401.332602] [ 2401.332639] [<c00107e8>] ret_from_syscall+0x0/0x38 [ 2401.333385] SOFTIRQ-ON-R [ 2401.333414] at: [ 2401.334113] [ 2401.334149] [<c00633c8>] lock_acquire+0x4c/0x68 [ 2401.334899] [ 2401.334934] [<c005d454>] down_read_nested+0x30/0x74 [ 2401.335715] [ 2401.335755] [<c01f9d00>] jfs_get_block+0x118/0x370 [ 2401.336541] [ 2401.336576] [<c0134484>] do_mpage_readpage+0x444/0x814 [ 2401.337370] [ 2401.337405] [<c0134954>] mpage_readpages+0x100/0x190 [ 2401.338181] [ 2401.338302] [<c00b3e50>] __do_page_cache_readahead+0x260/0x32c [ 2401.339068] [ 2401.339192] [<c00a8be0>] generic_file_read_iter+0x638/0x898 [ 2401.339901] [ 2401.340042] [<c00eeaf8>] __vfs_read+0xd8/0x180 [ 2401.340710] [ 2401.340844] [<c00eeecc>] vfs_read+0x98/0x1c4 [ 2401.341513] [ 2401.341612] [<c00f74dc>] prepare_binprm+0xd0/0x158 [ 2401.342326] [ 2401.342421] [<c00f7d4c>] do_execveat_common+0x4d4/0x76c [ 2401.343154] [ 2401.343202] [<c00f8010>] do_execve+0x2c/0x3c [ 2401.343949] [ 2401.344052] [<c0003fa0>] try_to_run_init_process+0x18/0x58 [ 2401.344805] [ 2401.344883] [<c00048b8>] kernel_init+0xc0/0x128 [ 2401.345615] [ 2401.345714] [<c0010924>] ret_from_kernel_thread+0x5c/0x64 [ 2401.346442] IN-RECLAIM_FS-W [ 2401.346524] at: [ 2401.347190] [ 2401.347228] [<c00633c8>] lock_acquire+0x4c/0x68 [ 2401.347984] [ 2401.348024] [<c005d548>] down_write_nested+0x30/0x7c [ 2401.348760] [ 2401.348798] [<c01f9c38>] jfs_get_block+0x50/0x370 [ 2401.349559] [ 2401.349599] [<c012a10c>] __block_write_full_page+0x31c/0x4a0 [ 2401.350372] [ 2401.350410] [<c00b9be4>] shrink_page_list+0x868/0xdc8 [ 2401.351166] [ 2401.351248] [<c00ba920>] shrink_inactive_list+0x22c/0x404 [ 2401.352021] [ 2401.352058] [<c00bb1e8>] shrink_node+0x388/0x67c [ 2401.352812] [ 2401.352851] [<c00bbdf0>] kswapd+0x3c4/0x560 [ 2401.353582] [ 2401.353620] [<c004bd54>] kthread+0xbc/0xd0 [ 2401.354361] [ 2401.354400] [<c0010924>] ret_from_kernel_thread+0x5c/0x64 [ 2401.355140] INITIAL USE [ 2401.355169] at: [ 2401.355858] [ 2401.355898] [<c00633c8>] lock_acquire+0x4c/0x68 [ 2401.356627] [ 2401.356662] [<c005d454>] down_read_nested+0x30/0x74 [ 2401.357414] [ 2401.357456] [<c01f9d00>] jfs_get_block+0x118/0x370 [ 2401.358208] [ 2401.358244] [<c0134484>] do_mpage_readpage+0x444/0x814 [ 2401.359013] [ 2401.359051] [<c0134954>] mpage_readpages+0x100/0x190 [ 2401.359789] [ 2401.359842] [<c00b3e50>] __do_page_cache_readahead+0x260/0x32c [ 2401.360659] [ 2401.360703] [<c00a8be0>] generic_file_read_iter+0x638/0x898 [ 2401.361475] [ 2401.361616] [<c00eeaf8>] __vfs_read+0xd8/0x180 [ 2401.362308] [ 2401.362413] [<c00eeecc>] vfs_read+0x98/0x1c4 [ 2401.363099] [ 2401.363173] [<c00f74dc>] prepare_binprm+0xd0/0x158 [ 2401.363895] [ 2401.363976] [<c00f7d4c>] do_execveat_common+0x4d4/0x76c [ 2401.364704] [ 2401.364744] [<c00f8010>] do_execve+0x2c/0x3c [ 2401.365478] [ 2401.365518] [<c0003fa0>] try_to_run_init_process+0x18/0x58 [ 2401.366253] [ 2401.366289] [<c00048b8>] kernel_init+0xc0/0x128 [ 2401.367046] [ 2401.367083] [<c0010924>] ret_from_kernel_thread+0x5c/0x64 [ 2401.367865] } [ 2401.368531] ... key at: [ 2401.368566] [<c105a234>] __key.33790+0x0/0x8 [ 2401.369316] ... acquired at: [ 2401.370021] [ 2401.370049] [<c0061108>] mark_lock+0x3dc/0x72c [ 2401.370682] [ 2401.370814] [<c0061ba0>] __lock_acquire+0x204/0x16b4 [ 2401.371433] [ 2401.371540] [<c00633c8>] lock_acquire+0x4c/0x68 [ 2401.372155] [ 2401.372249] [<c005d548>] down_write_nested+0x30/0x7c [ 2401.373188] [ 2401.373216] [<c01f9c38>] jfs_get_block+0x50/0x370 [ 2401.373939] [ 2401.374003] [<c012a10c>] __block_write_full_page+0x31c/0x4a0 [ 2401.374869] [ 2401.374901] [<c00b9be4>] shrink_page_list+0x868/0xdc8 [ 2401.375675] [ 2401.375701] [<c00ba920>] shrink_inactive_list+0x22c/0x404 [ 2401.376477] [ 2401.376504] [<c00bb1e8>] shrink_node+0x388/0x67c [ 2401.377262] [ 2401.377288] [<c00bbdf0>] kswapd+0x3c4/0x560 [ 2401.378039] [ 2401.378065] [<c004bd54>] kthread+0xbc/0xd0 [ 2401.378829] [ 2401.378857] [<c0010924>] ret_from_kernel_thread+0x5c/0x64 [ 2401.380201] stack backtrace: [ 2401.381394] CPU: 0 PID: 282 Comm: kswapd0 Not tainted 4.9.0-rc6 #1 [ 2401.382155] Call Trace: [ 2401.382873] [ef281a30] [c0657468] print_irq_inversion_bug.part.21+0x1d4/0x1f0 (unreliable) [ 2401.383704] [ef281a60] [c00603d8] check_usage_forwards+0x150/0x154 [ 2401.384542] [ef281ab0] [c0061108] mark_lock+0x3dc/0x72c [ 2401.385482] [ef281ae0] [c0061ba0] __lock_acquire+0x204/0x16b4 [ 2401.386399] [ef281b80] [c00633c8] lock_acquire+0x4c/0x68 [ 2401.387158] [ef281ba0] [c005d548] down_write_nested+0x30/0x7c [ 2401.388085] [ef281bb0] [c01f9c38] jfs_get_block+0x50/0x370 [ 2401.388747] [ef281c00] [c012a10c] __block_write_full_page+0x31c/0x4a0 [ 2401.389539] [ef281c50] [c00b9be4] shrink_page_list+0x868/0xdc8 [ 2401.390358] [ef281d10] [c00ba920] shrink_inactive_list+0x22c/0x404 [ 2401.391171] [ef281d70] [c00bb1e8] shrink_node+0x388/0x67c [ 2401.391952] [ef281e10] [c00bbdf0] kswapd+0x3c4/0x560 [ 2401.392709] [ef281eb0] [c004bd54] kthread+0xbc/0xd0 [ 2401.393468] [ef281f40] [c0010924] ret_from_kernel_thread+0x5c/0x64 [0] https://sourceforge.net/p/jfs/mailman/message/35093141/ -- BOFH excuse #185: system consumed all the paper for paging ------------------------------------------------------------------------------ _______________________________________________ Jfs-discussion mailing list Jfs-discussion@lists.sourceforge.net https://lists.sourceforge.net/lists/listinfo/jfs-discussion