BUG: sleeping function called from invalid context in __generic_file_fsync

9 views
Skip to first unread message

syzbot

unread,
Nov 11, 2019, 9:07:10 AM11/11/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=133f9c3ce00000
kernel config: https://syzkaller.appspot.com/x/.config?x=22a5ba9f73b6da1d
dashboard link: https://syzkaller.appspot.com/bug?extid=8753c198c1554c72bfd9
compiler: gcc (GCC) 8.0.1 20180413 (experimental)

Unfortunately, I don't have any reproducer for this crash yet.

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

netlink: 8 bytes leftover after parsing attributes in process
`syz-executor.5'.
BUG: sleeping function called from invalid context at
kernel/locking/rwsem.c:51
in_atomic(): 1, irqs_disabled(): 0, pid: 2640, name: syz-executor.2
1 lock held by syz-executor.2/2640:
#0: (rtnl_mutex){+.+.+.}, at: [<ffffffff823412d7>] rtnl_lock+0x17/0x20
net/core/rtnetlink.c:70
Preemption disabled at:[ 889.819015] [<ffffffff8281ca6d>]
__do_softirq+0xdd/0x964 kernel/softirq.c:265
CPU: 0 PID: 2640 Comm: syz-executor.2 Not tainted 4.9.141+ #1
ffff8801db607a20 ffffffff81b42e79 ffffffff8281ca6d 0000000000000000
0000000000000100 ffff8801c4f997c0 ffff8801c4f997c0 ffff8801db607a58
ffffffff813f9ecf ffff8801c4f997c0 ffffffff82a4fa80 0000000000000033
Call Trace:
<IRQ> [ 889.860451] [<ffffffff81b42e79>] __dump_stack
lib/dump_stack.c:15 [inline]
<IRQ> [ 889.860451] [<ffffffff81b42e79>] dump_stack+0xc1/0x128
lib/dump_stack.c:51
[<ffffffff813f9ecf>] ___might_sleep.cold.31+0x18a/0x1fc
kernel/sched/core.c:7988
[<ffffffff81167c85>] __might_sleep+0x95/0x1a0 kernel/sched/core.c:7945
[<ffffffff828116d1>] down_write+0x21/0xa0 kernel/locking/rwsem.c:51
[<ffffffff8158b831>] inode_lock include/linux/fs.h:766 [inline]
[<ffffffff8158b831>] __generic_file_fsync+0xc1/0x1a0 fs/libfs.c:978
[<ffffffff816b5209>] ext4_sync_file+0x659/0x10a0 fs/ext4/fsync.c:116
[<ffffffff815b195c>] vfs_fsync_range+0x10c/0x260 fs/sync.c:195
[<ffffffff815cd622>] generic_write_sync include/linux/fs.h:2607 [inline]
[<ffffffff815cd622>] dio_complete+0x512/0x6c0 fs/direct-io.c:282
[<ffffffff815cd8ec>] dio_bio_end_aio+0x11c/0x370 fs/direct-io.c:323
[<ffffffff81ab5f75>] bio_endio+0x1a5/0x1f0 block/bio.c:1781
[<ffffffff81ad65d8>] req_bio_endio block/blk-core.c:157 [inline]
[<ffffffff81ad65d8>] blk_update_request+0x248/0x9b0 block/blk-core.c:2628
[<ffffffff81e1c7ed>] scsi_end_request+0x9d/0x5c0
drivers/scsi/scsi_lib.c:606
[<ffffffff81e257f3>] scsi_io_completion+0x273/0x17a0
drivers/scsi/scsi_lib.c:829
[<ffffffff81e0871a>] scsi_finish_command+0x3ba/0x530
drivers/scsi/scsi.c:607
[<ffffffff81e23d20>] scsi_softirq_done+0x250/0x360
drivers/scsi/scsi_lib.c:1567
[<ffffffff81af449d>] blk_done_softirq+0x27d/0x3e0 block/blk-softirq.c:35
[<ffffffff8281cb9e>] __do_softirq+0x20e/0x964 kernel/softirq.c:288
[<ffffffff810efdbc>] invoke_softirq kernel/softirq.c:368 [inline]
[<ffffffff810efdbc>] irq_exit+0x11c/0x150 kernel/softirq.c:409
[<ffffffff82819b9d>] exiting_irq arch/x86/include/asm/apic.h:669 [inline]
[<ffffffff82819b9d>] do_IRQ+0x10d/0x1c0 arch/x86/kernel/irq.c:252
[<ffffffff8281819d>] common_interrupt+0x9d/0x9d
arch/x86/entry/entry_64.S:461
<EOI> [ 890.069779] [<ffffffff823fbaa8>] ? get_next_corpse
net/netfilter/nf_conntrack_core.c:1550 [inline]
<EOI> [ 890.069779] [<ffffffff823fbaa8>] ?
nf_ct_iterate_cleanup+0x238/0x480 net/netfilter/nf_conntrack_core.c:1621
[<ffffffff823fbacf>] local_bh_enable include/linux/bottom_half.h:31
[inline]
[<ffffffff823fbacf>] get_next_corpse
net/netfilter/nf_conntrack_core.c:1565 [inline]
[<ffffffff823fbacf>] nf_ct_iterate_cleanup+0x25f/0x480
net/netfilter/nf_conntrack_core.c:1621
[<ffffffff8260a028>] masq_device_event+0xa8/0xd0
net/ipv4/netfilter/nf_nat_masquerade_ipv4.c:100
[<ffffffff811478d4>] notifier_call_chain+0xb4/0x1d0 kernel/notifier.c:93
[<ffffffff81147a5d>] __raw_notifier_call_chain kernel/notifier.c:394
[inline]
[<ffffffff81147a5d>] raw_notifier_call_chain+0x2d/0x40
kernel/notifier.c:401
[<ffffffff822f4a45>] call_netdevice_notifiers_info+0x55/0x70
net/core/dev.c:1647
[<ffffffff82317fdd>] call_netdevice_notifiers net/core/dev.c:1663 [inline]
[<ffffffff82317fdd>] __dev_notify_flags+0x19d/0x270 net/core/dev.c:6541
[<ffffffff82319123>] dev_change_flags+0xf3/0x140 net/core/dev.c:6572
[<ffffffff8258e871>] devinet_ioctl+0x9d1/0x15d0 net/ipv4/devinet.c:1052
[<ffffffff82596cbe>] inet_ioctl+0x11e/0x1d0 net/ipv4/af_inet.c:908
[<ffffffff8229c00a>] sock_do_ioctl+0x6a/0xb0 net/socket.c:905
[<ffffffff8229cabd>] sock_ioctl+0x32d/0x3c0 net/socket.c:991
[<ffffffff81546dec>] vfs_ioctl fs/ioctl.c:43 [inline]
[<ffffffff81546dec>] file_ioctl fs/ioctl.c:493 [inline]
[<ffffffff81546dec>] do_vfs_ioctl+0x1ac/0x11a0 fs/ioctl.c:677
[<ffffffff81547e6f>] SYSC_ioctl fs/ioctl.c:694 [inline]
[<ffffffff81547e6f>] SyS_ioctl+0x8f/0xc0 fs/ioctl.c:685
[<ffffffff810056ef>] do_syscall_64+0x19f/0x550 arch/x86/entry/common.c:285
[<ffffffff82817893>] entry_SYSCALL_64_after_swapgs+0x5d/0xdb

=================================
[ INFO: inconsistent lock state ]
4.9.141+ #1 Tainted: G W
---------------------------------
inconsistent {SOFTIRQ-ON-W} -> {IN-SOFTIRQ-W} usage.
syz-executor.2/2640 [HC0[0]:SC1[1]:HE1:SE0] takes:
(&sb->s_type->i_mutex_key#9){++?+++}, at: [<ffffffff8158b831>] inode_lock
include/linux/fs.h:766 [inline]
(&sb->s_type->i_mutex_key#9){++?+++}, at: [<ffffffff8158b831>]
__generic_file_fsync+0xc1/0x1a0 fs/libfs.c:978
mark_irqflags kernel/locking/lockdep.c:2941 [inline]
__lock_acquire+0xbdd/0x4a10 kernel/locking/lockdep.c:3302
lock_acquire+0x130/0x3e0 kernel/locking/lockdep.c:3756
down_write+0x41/0xa0 kernel/locking/rwsem.c:52
inode_lock include/linux/fs.h:766 [inline]
bprm_fill_uid fs/exec.c:1506 [inline]
prepare_binprm+0x2b7/0x750 fs/exec.c:1540
do_execveat_common.isra.14+0xe9f/0x1ed0 fs/exec.c:1766
do_execve fs/exec.c:1829 [inline]
SYSC_execve fs/exec.c:1910 [inline]
SyS_execve+0x42/0x50 fs/exec.c:1905
do_syscall_64+0x19f/0x550 arch/x86/entry/common.c:285
entry_SYSCALL_64_after_swapgs+0x5d/0xdb
irq event stamp: 94020
hardirqs last enabled at (94020): [<ffffffff82818226>]
restore_regs_and_iret+0x0/0x1d
hardirqs last disabled at (94019): [<ffffffff82819028>]
apic_timer_interrupt+0x98/0xb0 arch/x86/entry/entry_64.S:648
softirqs last enabled at (93974): [<ffffffff823fbaa8>] get_next_corpse
net/netfilter/nf_conntrack_core.c:1550 [inline]
softirqs last enabled at (93974): [<ffffffff823fbaa8>]
nf_ct_iterate_cleanup+0x238/0x480 net/netfilter/nf_conntrack_core.c:1621
softirqs last disabled at (93977): [<ffffffff810efdbc>] invoke_softirq
kernel/softirq.c:368 [inline]
softirqs last disabled at (93977): [<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#9);
<Interrupt>
lock(&sb->s_type->i_mutex_key#9);

*** DEADLOCK ***

1 lock held by syz-executor.2/2640:
#0: (rtnl_mutex){+.+.+.}, at: [<ffffffff823412d7>] rtnl_lock+0x17/0x20
net/core/rtnetlink.c:70

stack backtrace:
CPU: 0 PID: 2640 Comm: syz-executor.2 Tainted: G W 4.9.141+ #1
ffff8801db607790 ffffffff81b42e79 ffff8801c4f997c0 ffffffff83cac0f0
ffff8801c4f9a098 ffff8801c4f9a0b8 ffffffff84244d40 ffff8801db607808
ffffffff81400780 0000000000000001 ffffffff00000001 0000000000000000
Call Trace:
<IRQ> [ 890.495553] [<ffffffff81b42e79>] __dump_stack
lib/dump_stack.c:15 [inline]
<IRQ> [ 890.495553] [<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
[<ffffffff81208434>] mark_irqflags kernel/locking/lockdep.c:2923 [inline]
[<ffffffff81208434>] __lock_acquire+0x1084/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
[<ffffffff8158b831>] inode_lock include/linux/fs.h:766 [inline]
[<ffffffff8158b831>] __generic_file_fsync+0xc1/0x1a0 fs/libfs.c:978
[<ffffffff816b5209>] ext4_sync_file+0x659/0x10a0 fs/ext4/fsync.c:116
[<ffffffff815b195c>] vfs_fsync_range+0x10c/0x260 fs/sync.c:195
[<ffffffff815cd622>] generic_write_sync include/linux/fs.h:2607 [inline]
[<ffffffff815cd622>] dio_complete+0x512/0x6c0 fs/direct-io.c:282
[<ffffffff815cd8ec>] dio_bio_end_aio+0x11c/0x370 fs/direct-io.c:323
[<ffffffff81ab5f75>] bio_endio+0x1a5/0x1f0 block/bio.c:1781
[<ffffffff81ad65d8>] req_bio_endio block/blk-core.c:157 [inline]
[<ffffffff81ad65d8>] blk_update_request+0x248/0x9b0 block/blk-core.c:2628
[<ffffffff81e1c7ed>] scsi_end_request+0x9d/0x5c0
drivers/scsi/scsi_lib.c:606
[<ffffffff81e257f3>] scsi_io_completion+0x273/0x17a0
drivers/scsi/scsi_lib.c:829
[<ffffffff81e0871a>] scsi_finish_command+0x3ba/0x530
drivers/scsi/scsi.c:607
[<ffffffff81e23d20>] scsi_softirq_done+0x250/0x360
drivers/scsi/scsi_lib.c:1567
[<ffffffff81af449d>] blk_done_softirq+0x27d/0x3e0 block/blk-softirq.c:35
[<ffffffff8281cb9e>] __do_softirq+0x20e/0x964 kernel/softirq.c:288
[<ffffffff810efdbc>] invoke_softirq kernel/softirq.c:368 [inline]
[<ffffffff810efdbc>] irq_exit+0x11c/0x150 kernel/softirq.c:409
[<ffffffff82819b9d>] exiting_irq arch/x86/include/asm/apic.h:669 [inline]
[<ffffffff82819b9d>] do_IRQ+0x10d/0x1c0 arch/x86/kernel/irq.c:252
[<ffffffff8281819d>] common_interrupt+0x9d/0x9d
arch/x86/entry/entry_64.S:461
<EOI> [ 890.773868] [<ffffffff823fbaa8>] ? get_next_corpse
net/netfilter/nf_conntrack_core.c:1550 [inline]
<EOI> [ 890.773868] [<ffffffff823fbaa8>] ?
nf_ct_iterate_cleanup+0x238/0x480 net/netfilter/nf_conntrack_core.c:1621
[<ffffffff823fbacf>] local_bh_enable include/linux/bottom_half.h:31
[inline]
[<ffffffff823fbacf>] get_next_corpse
net/netfilter/nf_conntrack_core.c:1565 [inline]
[<ffffffff823fbacf>] nf_ct_iterate_cleanup+0x25f/0x480
net/netfilter/nf_conntrack_core.c:1621
[<ffffffff8260a028>] masq_device_event+0xa8/0xd0
net/ipv4/netfilter/nf_nat_masquerade_ipv4.c:100
[<ffffffff811478d4>] notifier_call_chain+0xb4/0x1d0 kernel/notifier.c:93
[<ffffffff81147a5d>] __raw_notifier_call_chain kernel/notifier.c:394
[inline]
[<ffffffff81147a5d>] raw_notifier_call_chain+0x2d/0x40
kernel/notifier.c:401
[<ffffffff822f4a45>] call_netdevice_notifiers_info+0x55/0x70
net/core/dev.c:1647
[<ffffffff82317fdd>] call_netdevice_notifiers net/core/dev.c:1663 [inline]
[<ffffffff82317fdd>] __dev_notify_flags+0x19d/0x270 net/core/dev.c:6541
[<ffffffff82319123>] dev_change_flags+0xf3/0x140 net/core/dev.c:6572
[<ffffffff8258e871>] devinet_ioctl+0x9d1/0x15d0 net/ipv4/devinet.c:1052
[<ffffffff82596cbe>] inet_ioctl+0x11e/0x1d0 net/ipv4/af_inet.c:908
[<ffffffff8229c00a>] sock_do_ioctl+0x6a/0xb0 net/socket.c:905
[<ffffffff8229cabd>] sock_ioctl+0x32d/0x3c0 net/socket.c:991
[<ffffffff81546dec>] vfs_ioctl fs/ioctl.c:43 [inline]
[<ffffffff81546dec>] file_ioctl fs/ioctl.c:493 [inline]
[<ffffffff81546dec>] do_vfs_ioctl+0x1ac/0x11a0 fs/ioctl.c:677
[<ffffffff81547e6f>] SYSC_ioctl fs/ioctl.c:694 [inline]
[<ffffffff81547e6f>] SyS_ioctl+0x8f/0xc0 fs/ioctl.c:685
[<ffffffff810056ef>] do_syscall_64+0x19f/0x550 arch/x86/entry/common.c:285
[<ffffffff82817893>] entry_SYSCALL_64_after_swapgs+0x5d/0xdb
BUG: scheduling while atomic: syz-executor.2/2640/0x00000101
INFO: lockdep is turned off.
Modules linked in:
Preemption disabled at:[ 891.005947] [<ffffffff8281ca6d>]
__do_softirq+0xdd/0x964 kernel/softirq.c:265


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

unread,
Mar 10, 2020, 9:07:12 AM3/10/20
to syzkaller-a...@googlegroups.com
Auto-closing this bug as obsolete.
Crashes did not happen for a while, no reproducer and no activity.
Reply all
Reply to author
Forward
0 new messages