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
 
Hash Suite: Windows password security audit tool. GUI, reports in PDF.
[<prev] [next>] [<thread-prev] [day] [month] [year] [list]
Message-ID: <aa62bce3-0a06-eec0-8c12-badb308370fa@oracle.com>
Date:   Mon, 5 Dec 2016 16:44:48 -0600
From:   Dave Kleikamp <dave.kleikamp@...cle.com>
To:     Christian Kujau <lists@...dbynature.de>,
        jfs-discussion@...ts.sourceforge.net
Cc:     linux-kernel@...r.kernel.org, Dmitry Vyukov <dvyukov@...gle.com>
Subject: Re: [Jfs-discussion] jfs: mangled lockdep splat

On 11/22/2016 06:05 PM, Christian Kujau wrote:
> 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?

Dmitry Vyukov has a fix for the lockdep formatting. I haven't tested it,
but none of this output is specific to jfs.

Maybe I should figure out how to get rid of the warning altogether.

Thanks for reporting this.

Shaggy

> 
> 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/
> 

Powered by blists - more mailing lists

Powered by Openwall GNU/*/Linux Powered by OpenVZ