On Mon, 16 May 2016, Christian Kujau wrote:
> This just happend on a PowerPC (32 bit) box running Debian/stable and a
> vanilla 4.6.0-rc7 kernel:
>
> =========================================================
> [ INFO: possible irq lock inversion dependency detected ]
> 4.6.0-rc7 #2 Not tainted
> ---------------------------------------------------------
> kswapd0/272 just changed the state of lock:
> (&jfs_ip->rdwrlock#2){++++-.}, at: [<c01f0840>] jfs_get_block+0x50/0x370
> but this lock took another, RECLAIM_FS-unsafe lock in the past:
> (&jfs_ip->commit_mutex){+.+.+.}
This just happened again, while the machine was kinda busy with disk I/O,
this time with 4.7-rc1. I take it this is just a warning and nothing to
worry about?
Thanks,
Christian.
=========================================================
[ INFO: possible irq lock inversion dependency detected ]
4.7.0-rc1 #2 Not tainted
---------------------------------------------------------
snmpd/1903 just changed the state of lock:
(&(imap->im_aglock[index])){+.+.-.}, at: [<c01fb150>] diFree+0x74/0x9f4
but this lock took another, RECLAIM_FS-unsafe lock in the past:
(&jfs_ip->commit_mutex){+.+.+.}
and interrupts could create inverse lock ordering between them.
other info that might help us debug this:
Possible interrupt unsafe locking scenario:
CPU0 CPU1
---- ----
lock(&jfs_ip->commit_mutex);
local_irq_disable();
lock(&(imap->im_aglock[index]));
lock(&jfs_ip->commit_mutex);
<Interrupt>
lock(&(imap->im_aglock[index]));
*** DEADLOCK ***
3 locks held by snmpd/1903:
#0: (rtnl_mutex){+.+.+.}, at: [<c054503c>] netlink_dump+0x20/0x2e4
#1: (shrinker_rwsem){++++..}, at: [<c00b3b70>]
shrink_slab.part.54.constprop.66+0x3c/0x28c
#2: (&type->s_umount_key#23){+++++.}, at: [<c00ec860>] trylock_super+0x20/0x88
the shortest dependencies between 2nd lock and 1st lock:
-> (&jfs_ip->commit_mutex){+.+.+.} ops: 1167483 {
HARDIRQ-ON-W at:
[<c0060da8>] lock_acquire+0x4c/0x68
[<c06298b0>] mutex_lock_nested+0x38/0x2e8
[<c01f1864>] jfs_create+0x88/0x300
[<c00f8aec>] path_openat+0xce4/0x1234
[<c00fa6bc>] do_filp_open+0xac/0xfc
[<c00e81dc>] do_sys_open+0x160/0x22c
[<c001063c>] ret_from_syscall+0x0/0x38
SOFTIRQ-ON-W at:
[<c0060da8>] lock_acquire+0x4c/0x68
[<c06298b0>] mutex_lock_nested+0x38/0x2e8
[<c01f1864>] jfs_create+0x88/0x300
[<c00f8aec>] path_openat+0xce4/0x1234
[<c00fa6bc>] do_filp_open+0xac/0xfc
[<c00e81dc>] do_sys_open+0x160/0x22c
[<c001063c>] ret_from_syscall+0x0/0x38
RECLAIM_FS-ON-W at:
[<c005e5ec>] lockdep_trace_alloc+0x8c/0xe4
[<c00e2388>] __kmalloc+0x40/0x150
[<c0213074>] __jfs_set_acl+0xe4/0x1a8
[<c0213294>] jfs_set_acl+0x50/0x9c
[<c01442e0>] posix_acl_chmod+0xdc/0x11c
[<c010a0b0>] notify_change+0x158/0x3a0
[<c00e684c>] chmod_common+0x74/0x10c
[<c00e78ec>] SyS_fchmod+0x30/0x64
[<c001063c>] ret_from_syscall+0x0/0x38
INITIAL USE at:
[<c0060da8>] lock_acquire+0x4c/0x68
[<c06298b0>] mutex_lock_nested+0x38/0x2e8
[<c01f1864>] jfs_create+0x88/0x300
[<c00f8aec>] path_openat+0xce4/0x1234
[<c00fa6bc>] do_filp_open+0xac/0xfc
[<c00e81dc>] do_sys_open+0x160/0x22c
[<c001063c>] ret_from_syscall+0x0/0x38
}
... key at: [<c0fdf178>] __key.33051+0x0/0x8
... acquired at:
[<c06298b0>] mutex_lock_nested+0x38/0x2e8
[<c01fb704>] diFree+0x628/0x9f4
[<c01f0b90>] jfs_evict_inode+0x7c/0x80
[<c0108a00>] evict+0xbc/0x194
[<c020f0e8>] txUpdateMap+0x22c/0x2c4
[<c02107e4>] jfs_lazycommit+0x164/0x214
[<c0049b64>] kthread+0xbc/0xd0
[<c0010778>] ret_from_kernel_thread+0x5c/0x64
-> (&(imap->im_aglock[index])){+.+.-.} ops: 177579 {
HARDIRQ-ON-W at:
[<c0060da8>] lock_acquire+0x4c/0x68
[<c06298b0>] mutex_lock_nested+0x38/0x2e8
[<c01fbdb4>] diAlloc+0x2e4/0x6e0
[<c0207fcc>] ialloc+0x4c/0x1d0
[<c01f182c>] jfs_create+0x50/0x300
[<c00f8aec>] path_openat+0xce4/0x1234
[<c00fa6bc>] do_filp_open+0xac/0xfc
[<c00e81dc>] do_sys_open+0x160/0x22c
[<c001063c>] ret_from_syscall+0x0/0x38
SOFTIRQ-ON-W at:
[<c0060da8>] lock_acquire+0x4c/0x68
[<c06298b0>] mutex_lock_nested+0x38/0x2e8
[<c01fbdb4>] diAlloc+0x2e4/0x6e0
[<c0207fcc>] ialloc+0x4c/0x1d0
[<c01f182c>] jfs_create+0x50/0x300
[<c00f8aec>] path_openat+0xce4/0x1234
[<c00fa6bc>] do_filp_open+0xac/0xfc
[<c00e81dc>] do_sys_open+0x160/0x22c
[<c001063c>] ret_from_syscall+0x0/0x38
IN-RECLAIM_FS-W at:
[<c0060da8>] lock_acquire+0x4c/0x68
[<c06298b0>] mutex_lock_nested+0x38/0x2e8
[<c01fb150>] diFree+0x74/0x9f4
[<c01f0b90>] jfs_evict_inode+0x7c/0x80
[<c0108a00>] evict+0xbc/0x194
[<c0103374>] __dentry_kill+0x1cc/0x234
[<c0103c00>] shrink_dentry_list+0x134/0x4c8
[<c0104b74>] prune_dcache_sb+0x4c/0x64
[<c00ec9c8>] super_cache_scan+0x100/0x17c
[<c00b3ce0>] shrink_slab.part.54.constprop.66+0x1ac/0x28c
[<c00b689c>] shrink_zone+0x5b8/0x600
[<c00b6b4c>] try_to_free_pages+0x268/0x560
[<c00aa534>] __alloc_pages_nodemask+0x3e8/0x924
[<c00c1690>] kmalloc_order+0x18/0x40
[<c0506220>] __kmalloc_reserve.isra.49+0x30/0x90
[<c05062f4>] __alloc_skb+0x74/0x1d0
[<c0545188>] netlink_dump+0x16c/0x2e4
[<c054556c>] netlink_recvmsg+0x26c/0x398
[<c04fe094>] SyS_recvfrom+0xa8/0x134
[<c04feb98>] SyS_socketcall+0x1e8/0x228
[<c001063c>] ret_from_syscall+0x0/0x38
INITIAL USE at:
[<c0060da8>] lock_acquire+0x4c/0x68
[<c06298b0>] mutex_lock_nested+0x38/0x2e8
[<c01fbdb4>] diAlloc+0x2e4/0x6e0
[<c0207fcc>] ialloc+0x4c/0x1d0
[<c01f182c>] jfs_create+0x50/0x300
[<c00f8aec>] path_openat+0xce4/0x1234
[<c00fa6bc>] do_filp_open+0xac/0xfc
[<c00e81dc>] do_sys_open+0x160/0x22c
[<c001063c>] ret_from_syscall+0x0/0x38
}
... key at: [<c0fdf1a4>] __key.28661+0x0/0x8
... acquired at:
[<c005db88>] mark_lock+0x3dc/0x724
[<c005f428>] __lock_acquire+0x250/0x1870
[<c0060da8>] lock_acquire+0x4c/0x68
[<c06298b0>] mutex_lock_nested+0x38/0x2e8
[<c01fb150>] diFree+0x74/0x9f4
[<c01f0b90>] jfs_evict_inode+0x7c/0x80
[<c0108a00>] evict+0xbc/0x194
[<c0103374>] __dentry_kill+0x1cc/0x234
[<c0103c00>] shrink_dentry_list+0x134/0x4c8
[<c0104b74>] prune_dcache_sb+0x4c/0x64
[<c00ec9c8>] super_cache_scan+0x100/0x17c
[<c00b3ce0>] shrink_slab.part.54.constprop.66+0x1ac/0x28c
[<c00b689c>] shrink_zone+0x5b8/0x600
[<c00b6b4c>] try_to_free_pages+0x268/0x560
[<c00aa534>] __alloc_pages_nodemask+0x3e8/0x924
[<c00c1690>] kmalloc_order+0x18/0x40
[<c0506220>] __kmalloc_reserve.isra.49+0x30/0x90
[<c05062f4>] __alloc_skb+0x74/0x1d0
[<c0545188>] netlink_dump+0x16c/0x2e4
[<c054556c>] netlink_recvmsg+0x26c/0x398
[<c04fe094>] SyS_recvfrom+0xa8/0x134
[<c04feb98>] SyS_socketcall+0x1e8/0x228
[<c001063c>] ret_from_syscall+0x0/0x38
stack backtrace:
CPU: 0 PID: 1903 Comm: snmpd Not tainted 4.7.0-rc1 #2
Call Trace:
[ee1617c0] [c062e798] print_irq_inversion_bug.part.32+0x1d8/0x1f4 (unreliable)
[ee1617f0] [c005cf18] check_usage_forwards+0x15c/0x160
[ee161850] [c005db88] mark_lock+0x3dc/0x724
[ee161880] [c005f428] __lock_acquire+0x250/0x1870
[ee161930] [c0060da8] lock_acquire+0x4c/0x68
[ee161950] [c06298b0] mutex_lock_nested+0x38/0x2e8
[ee1619b0] [c01fb150] diFree+0x74/0x9f4
[ee161a30] [c01f0b90] jfs_evict_inode+0x7c/0x80
[ee161a40] [c0108a00] evict+0xbc/0x194
[ee161a60] [c0103374] __dentry_kill+0x1cc/0x234
[ee161a80] [c0103c00] shrink_dentry_list+0x134/0x4c8
[ee161ac0] [c0104b74] prune_dcache_sb+0x4c/0x64
[ee161ae0] [c00ec9c8] super_cache_scan+0x100/0x17c
[ee161b10] [c00b3ce0] shrink_slab.part.54.constprop.66+0x1ac/0x28c
[ee161b80] [c00b689c] shrink_zone+0x5b8/0x600
[ee161c20] [c00b6b4c] try_to_free_pages+0x268/0x560
[ee161cb0] [c00aa534] __alloc_pages_nodemask+0x3e8/0x924
[ee161d40] [c00c1690] kmalloc_order+0x18/0x40
[ee161d50] [c0506220] __kmalloc_reserve.isra.49+0x30/0x90
[ee161d70] [c05062f4] __alloc_skb+0x74/0x1d0
[ee161da0] [c0545188] netlink_dump+0x16c/0x2e4
[ee161dc0] [c054556c] netlink_recvmsg+0x26c/0x398
[ee161e20] [c04fe094] SyS_recvfrom+0xa8/0x134
[ee161f10] [c04feb98] SyS_socketcall+0x1e8/0x228
[ee161f40] [c001063c] ret_from_syscall+0x0/0x38
--- interrupt: c01 at 0xfa8f410
LR = 0xfe06de8
--
BOFH excuse #420:
Feature was not beta tested
------------------------------------------------------------------------------
What NetFlow Analyzer can do for you? Monitors network bandwidth and traffic
patterns at an interface-level. Reveals which users, apps, and protocols are
consuming the most bandwidth. Provides multi-vendor support for NetFlow,
J-Flow, sFlow and other flows. Make informed decisions using capacity
planning reports. https://ad.doubleclick.net/ddm/clk/305295220;132659582;e
_______________________________________________
Jfs-discussion mailing list
Jfs-discussion@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/jfs-discussion
