inconsistent lock state in shmem_fallocate

16 views
Skip to first unread message

syzbot

unread,
Apr 12, 2019, 8:00:56 PM4/12/19
to syzkaller-a...@googlegroups.com
Hello,

syzbot found the following crash on:

HEAD commit: d08574b6 ANDROID: cuttlefish_defconfig: Enable VIRTIO_INPUT
git tree: android-4.4
console output: https://syzkaller.appspot.com/x/log.txt?x=12b18e80c00000
kernel config: https://syzkaller.appspot.com/x/.config?x=39bc4256ec37590
dashboard link: https://syzkaller.appspot.com/bug?extid=5c9710eb563be3a65db0
compiler: gcc (GCC) 9.0.0 20181231 (experimental)
syz repro: https://syzkaller.appspot.com/x/repro.syz?x=155c57bf400000
C reproducer: https://syzkaller.appspot.com/x/repro.c?x=14b2419f400000

IMPORTANT: if you fix the bug, please add the following tag to the commit:
Reported-by: syzbot+5c9710...@syzkaller.appspotmail.com

=================================
[ INFO: inconsistent lock state ]
4.4.169+ #2 Not tainted
---------------------------------
inconsistent {RECLAIM_FS-ON-W} -> {IN-RECLAIM_FS-W} usage.
kswapd0/28 [HC0[0]:SC0[0]:HE1:SE1] takes:
(&sb->s_type->i_mutex_key#10){+.+.?.}, at: [<ffffffff8140445b>]
shmem_fallocate+0x13b/0x9c0 mm/shmem.c:2078
{RECLAIM_FS-ON-W} state was registered at:
[<ffffffff811fedc1>] mark_held_locks+0xb1/0x100
kernel/locking/lockdep.c:2536
[<ffffffff8120759c>] __lockdep_trace_alloc kernel/locking/lockdep.c:2758
[inline]
[<ffffffff8120759c>] lockdep_trace_alloc+0x18c/0x2b0
kernel/locking/lockdep.c:2773
[<ffffffff813d004a>] __alloc_pages_nodemask+0x13a/0x14b0
mm/page_alloc.c:3266
[<ffffffff81401b33>] __alloc_pages include/linux/gfp.h:415 [inline]
[<ffffffff81401b33>] __alloc_pages_node include/linux/gfp.h:428 [inline]
[<ffffffff81401b33>] alloc_pages_node include/linux/gfp.h:442 [inline]
[<ffffffff81401b33>] shmem_alloc_page mm/shmem.c:953 [inline]
[<ffffffff81401b33>] shmem_getpage_gfp+0x6a3/0x1120 mm/shmem.c:1191
[<ffffffff8140269b>] shmem_getpage mm/shmem.c:130 [inline]
[<ffffffff8140269b>] shmem_write_begin+0xeb/0x190 mm/shmem.c:1509
[<ffffffff813b92a1>] generic_perform_write+0x281/0x540 mm/filemap.c:2591
[<ffffffff813bcec0>] __generic_file_write_iter+0x350/0x540
mm/filemap.c:2716
[<ffffffff813bd45a>] generic_file_write_iter+0x3aa/0x740 mm/filemap.c:2744
[<ffffffff814964b8>] new_sync_write fs/read_write.c:478 [inline]
[<ffffffff814964b8>] __vfs_write+0x2e8/0x3d0 fs/read_write.c:491
[<ffffffff81497fe2>] vfs_write+0x182/0x4e0 fs/read_write.c:538
[<ffffffff8149a61c>] SYSC_write fs/read_write.c:585 [inline]
[<ffffffff8149a61c>] SyS_write+0xdc/0x1c0 fs/read_write.c:577
[<ffffffff827153a1>] entry_SYSCALL_64_fastpath+0x1e/0x9a
irq event stamp: 41
hardirqs last enabled at (41): [<ffffffff827088cd>]
__mutex_trylock_slowpath kernel/locking/mutex.c:885 [inline]
hardirqs last enabled at (41): [<ffffffff827088cd>]
mutex_trylock+0x28d/0x500 kernel/locking/mutex.c:908
hardirqs last disabled at (40): [<ffffffff827086ef>]
__mutex_trylock_slowpath kernel/locking/mutex.c:873 [inline]
hardirqs last disabled at (40): [<ffffffff827086ef>]
mutex_trylock+0xaf/0x500 kernel/locking/mutex.c:908
softirqs last enabled at (0): [<ffffffff810cbe1b>]
copy_process+0x127b/0x68c0 kernel/fork.c:1468
softirqs last disabled at (0): [< (null)>] (null)

other info that might help us debug this:
Possible unsafe locking scenario:

CPU0
----
lock(&sb->s_type->i_mutex_key#10);
<Interrupt>
lock(&sb->s_type->i_mutex_key#10);

*** DEADLOCK ***

2 locks held by kswapd0/28:
#0: (shrinker_rwsem){++++..}, at: [<ffffffff813ee0b2>]
shrink_slab.part.0+0xb2/0xb30 mm/vmscan.c:431
#1: (ashmem_mutex){+.+.+.}, at: [<ffffffff82118166>]
ashmem_shrink_scan+0x56/0x4c0 drivers/staging/android/ashmem.c:442

stack backtrace:
CPU: 1 PID: 28 Comm: kswapd0 Not tainted 4.4.169+ #2
0000000000000000 218b77c28ac0b8db ffff8800bb657290 ffffffff81aab9c1
00000000000000f0 ffff8800001f5f00 ffffffff83abd980 ffffffff84055ac0
ffff8800001f6838 ffff8800bb657308 ffffffff813ad270 0000000000000000
Call Trace:
[<ffffffff81aab9c1>] __dump_stack lib/dump_stack.c:15 [inline]
[<ffffffff81aab9c1>] dump_stack+0xc1/0x120 lib/dump_stack.c:51
[<ffffffff813ad270>] print_usage_bug.cold+0x454/0x592
kernel/locking/lockdep.c:2267
[<ffffffff811fdfcd>] valid_state kernel/locking/lockdep.c:2280 [inline]
[<ffffffff811fdfcd>] mark_lock_irq kernel/locking/lockdep.c:2478 [inline]
[<ffffffff811fdfcd>] mark_lock+0x6fd/0x1440 kernel/locking/lockdep.c:2933
[<ffffffff811ffde7>] mark_irqflags kernel/locking/lockdep.c:2834 [inline]
[<ffffffff811ffde7>] __lock_acquire+0xa27/0x4f50
kernel/locking/lockdep.c:3169
[<ffffffff81205d7e>] lock_acquire+0x15e/0x450 kernel/locking/lockdep.c:3592
[<ffffffff82708c01>] __mutex_lock_common kernel/locking/mutex.c:521
[inline]
[<ffffffff82708c01>] mutex_lock_nested+0xc1/0xb80
kernel/locking/mutex.c:621
[<ffffffff8140445b>] shmem_fallocate+0x13b/0x9c0 mm/shmem.c:2078
[<ffffffff821182d3>] ashmem_shrink_scan
drivers/staging/android/ashmem.c:449 [inline]
[<ffffffff821182d3>] ashmem_shrink_scan+0x1c3/0x4c0
drivers/staging/android/ashmem.c:433
[<ffffffff813ee402>] do_shrink_slab mm/vmscan.c:357 [inline]
[<ffffffff813ee402>] shrink_slab.part.0+0x402/0xb30 mm/vmscan.c:455
[<ffffffff813f6f4c>] shrink_slab mm/vmscan.c:425 [inline]
[<ffffffff813f6f4c>] shrink_zone+0x4bc/0x610 mm/vmscan.c:2448
[<ffffffff813f8daf>] kswapd_shrink_zone mm/vmscan.c:3123 [inline]
[<ffffffff813f8daf>] balance_pgdat mm/vmscan.c:3298 [inline]
[<ffffffff813f8daf>] kswapd+0xaaf/0x1c60 mm/vmscan.c:3506
[<ffffffff811340d3>] kthread+0x273/0x310 kernel/kthread.c:211
[<ffffffff827157c5>] ret_from_fork+0x55/0x80 arch/x86/entry/entry_64.S:537
lowmemorykiller: Killing 'restorecond' (2001) (tgid 2001), adj 0,
to free 4908kB on behalf of 'kswapd0' (28) because
cache 3912kB is below limit 6144kB for oom_score_adj 0
Free memory is -5312kB above reserved
lowmemorykiller: Killing 'dhclient' (1787) (tgid 1787), adj 0,
to free 2292kB on behalf of 'kswapd0' (28) because


---
This bug is generated by a bot. It may contain errors.
See https://goo.gl/tpsmEJ for more information about syzbot.
syzbot engineers can be reached at syzk...@googlegroups.com.

syzbot will keep track of this bug report. See:
https://goo.gl/tpsmEJ#status for how to communicate with syzbot.
syzbot can test patches for this bug, for details see:
https://goo.gl/tpsmEJ#testing-patches

syzbot

unread,
Apr 13, 2019, 8:00:33 PM4/13/19
to syzkaller-a...@googlegroups.com
Hello,

syzbot found the following crash on:

HEAD commit: 8fe42840 Merge 4.9.141 into android-4.9
git tree: android-4.9
console output: https://syzkaller.appspot.com/x/log.txt?x=130ade80c00000
kernel config: https://syzkaller.appspot.com/x/.config?x=22a5ba9f73b6da1d
dashboard link: https://syzkaller.appspot.com/bug?extid=6e5f7ecd43ca27145f88
compiler: gcc (GCC) 8.0.1 20180413 (experimental)
syz repro: https://syzkaller.appspot.com/x/repro.syz?x=137ed5ab400000
C reproducer: https://syzkaller.appspot.com/x/repro.c?x=160dec07400000

IMPORTANT: if you fix the bug, please add the following tag to the commit:
Reported-by: syzbot+6e5f7e...@syzkaller.appspotmail.com

=================================
[ INFO: inconsistent lock state ]
4.9.141+ #1 Not tainted
---------------------------------
inconsistent {RECLAIM_FS-ON-W} -> {IN-RECLAIM_FS-W} usage.
kswapd0/33 [HC0[0]:SC0[0]:HE1:SE1] takes:
(&sb->s_type->i_mutex_key#10){+.+.?.}, at: [<ffffffff81464edc>] inode_lock
include/linux/fs.h:766 [inline]
(&sb->s_type->i_mutex_key#10){+.+.?.}, at: [<ffffffff81464edc>]
shmem_fallocate+0x13c/0xb10 mm/shmem.c:2676
mark_held_locks+0xc7/0x130 kernel/locking/lockdep.c:2660
__lockdep_trace_alloc kernel/locking/lockdep.c:2882 [inline]
lockdep_trace_alloc+0x18e/0x2a0 kernel/locking/lockdep.c:2897
__alloc_pages_nodemask+0x14a/0x1bd0 mm/page_alloc.c:3804
__alloc_pages include/linux/gfp.h:433 [inline]
__alloc_pages_node include/linux/gfp.h:446 [inline]
alloc_pages_node include/linux/gfp.h:460 [inline]
shmem_alloc_page mm/shmem.c:1420 [inline]
shmem_alloc_and_acct_page mm/shmem.c:1450 [inline]
shmem_getpage_gfp+0xc7c/0x18f0 mm/shmem.c:1724
shmem_getpage mm/shmem.c:123 [inline]
shmem_write_begin+0xf4/0x1a0 mm/shmem.c:2205
generic_perform_write+0x28a/0x500 mm/filemap.c:2753
__generic_file_write_iter+0x352/0x540 mm/filemap.c:2878
generic_file_write_iter+0x37a/0x620 mm/filemap.c:2906
new_sync_write fs/read_write.c:496 [inline]
__vfs_write+0x3d7/0x580 fs/read_write.c:509
vfs_write+0x187/0x520 fs/read_write.c:557
SYSC_write fs/read_write.c:604 [inline]
SyS_write+0xd9/0x1c0 fs/read_write.c:596
do_syscall_64+0x19f/0x550 arch/x86/entry/common.c:285
entry_SYSCALL_64_after_swapgs+0x5d/0xdb
irq event stamp: 1055
hardirqs last enabled at (1055): [<ffffffff8280b008>]
__mutex_trylock_slowpath kernel/locking/mutex.c:885 [inline]
hardirqs last enabled at (1055): [<ffffffff8280b008>]
mutex_trylock+0x258/0x3e0 kernel/locking/mutex.c:908
hardirqs last disabled at (1054): [<ffffffff8280ae5f>]
__mutex_trylock_slowpath kernel/locking/mutex.c:873 [inline]
hardirqs last disabled at (1054): [<ffffffff8280ae5f>]
mutex_trylock+0xaf/0x3e0 kernel/locking/mutex.c:908
softirqs last enabled at (1012): [<ffffffff8281cdfd>]
__do_softirq+0x46d/0x964 kernel/softirq.c:314
softirqs last disabled at (1001): [<ffffffff810efdbc>] invoke_softirq
kernel/softirq.c:368 [inline]
softirqs last disabled at (1001): [<ffffffff810efdbc>] irq_exit+0x11c/0x150
kernel/softirq.c:409

other info that might help us debug this:
Possible unsafe locking scenario:

CPU0
----
lock(&sb->s_type->i_mutex_key#10);
<Interrupt>
lock(&sb->s_type->i_mutex_key#10);

*** DEADLOCK ***

2 locks held by kswapd0/33:
#0: (shrinker_rwsem){++++..}, at: [<ffffffff814499b2>]
shrink_slab.part.8+0xb2/0xa00 mm/vmscan.c:471
#1: (ashmem_mutex){+.+.+.}, at: [<ffffffff821ed9f5>]
ashmem_shrink_scan+0x55/0x4c0 drivers/staging/android/ashmem.c:455

stack backtrace:
CPU: 0 PID: 33 Comm: kswapd0 Not tainted 4.9.141+ #1
ffff8801d8417380 ffffffff81b42e79 ffff8801d8408000 ffffffff83cac960
ffff8801d8408900 ffff8801d8408920 ffffffff84244d40 ffff8801d84173f8
ffffffff81400780 0000000000000000 ffffffff00000001 0000000000000001
Call Trace:
[<ffffffff81b42e79>] __dump_stack lib/dump_stack.c:15 [inline]
[<ffffffff81b42e79>] dump_stack+0xc1/0x128 lib/dump_stack.c:51
[<ffffffff81400780>] print_usage_bug.cold.40+0x44e/0x57e
kernel/locking/lockdep.c:2387
[<ffffffff81205d42>] valid_state kernel/locking/lockdep.c:2400 [inline]
[<ffffffff81205d42>] mark_lock_irq kernel/locking/lockdep.c:2602 [inline]
[<ffffffff81205d42>] mark_lock+0x2f2/0x1290 kernel/locking/lockdep.c:3065
[<ffffffff812079e2>] mark_irqflags kernel/locking/lockdep.c:2958 [inline]
[<ffffffff812079e2>] __lock_acquire+0x632/0x4a10
kernel/locking/lockdep.c:3302
[<ffffffff8120c8d0>] lock_acquire+0x130/0x3e0 kernel/locking/lockdep.c:3756
[<ffffffff828116f1>] down_write+0x41/0xa0 kernel/locking/rwsem.c:52
[<ffffffff81464edc>] inode_lock include/linux/fs.h:766 [inline]
[<ffffffff81464edc>] shmem_fallocate+0x13c/0xb10 mm/shmem.c:2676
[<ffffffff821edb59>] ashmem_shrink_scan+0x1b9/0x4c0
drivers/staging/android/ashmem.c:462
[<ffffffff81449cc6>] do_shrink_slab mm/vmscan.c:398 [inline]
[<ffffffff81449cc6>] shrink_slab.part.8+0x3c6/0xa00 mm/vmscan.c:501
[<ffffffff814557fd>] shrink_slab mm/vmscan.c:465 [inline]
[<ffffffff814557fd>] shrink_node+0x1ed/0x740 mm/vmscan.c:2602
[<ffffffff814570b9>] kswapd_shrink_node mm/vmscan.c:3202 [inline]
[<ffffffff814570b9>] balance_pgdat mm/vmscan.c:3319 [inline]
[<ffffffff814570b9>] kswapd+0x7e9/0x13b0 mm/vmscan.c:3512
[<ffffffff81142c3d>] kthread+0x26d/0x300 kernel/kthread.c:211
[<ffffffff82817a5c>] ret_from_fork+0x5c/0x70 arch/x86/entry/entry_64.S:373
Reply all
Reply to author
Forward
0 new messages