syzbot


BUG: sleeping function called from invalid context at mm/page-writeback.c:LINE

Status: public: reported C repro on 2019/04/13 00:01
Reported-by: syzbot+643442d782f1c79812ac@syzkaller.appspotmail.com
First crash: 2130d, last: 2083d

Sample crash report:
BUG: sleeping function called from invalid context at mm/page-writeback.c:2120
in_atomic(): 1, irqs_disabled(): 0, pid: 0, name: swapper/1
no locks held by swapper/1/0.
Preemption disabled at:[<ffffffff811ebd25>] cpu_idle_loop kernel/sched/idle.c:279 [inline]
Preemption disabled at:[<ffffffff811ebd25>] cpu_startup_entry+0x755/0x810 kernel/sched/idle.c:301

CPU: 1 PID: 0 Comm: swapper/1 Not tainted 4.4.174+ #4
 0000000000000000 d7ee000cd50c6b37 ffff8801db707520 ffffffff81aad1a1
 ffff8801da6897c0 0000000000000101 ffff8801da6897c0 0000000000000101
 ffff8801da6897c0 ffff8801db707558 ffffffff813a6f33 0000000000000000
Call Trace:
 <IRQ>  [<ffffffff81aad1a1>] __dump_stack lib/dump_stack.c:15 [inline]
 <IRQ>  [<ffffffff81aad1a1>] dump_stack+0xc1/0x120 lib/dump_stack.c:51
 [<ffffffff813a6f33>] ___might_sleep.cold+0x1c6/0x1dc kernel/sched/core.c:7988
 [<ffffffff813d2c60>] tag_pages_for_writeback+0xa0/0x1a0 mm/page-writeback.c:2120
 [<ffffffff81656ac9>] ext4_writepages+0xaf9/0x2c40 fs/ext4/inode.c:2582
 [<ffffffff813dac6c>] do_writepages+0xfc/0x1e0 mm/page-writeback.c:2341
 [<ffffffff813bc53d>] __filemap_fdatawrite_range+0x1ad/0x260 mm/filemap.c:347
 [<ffffffff813bc81c>] filemap_write_and_wait_range mm/filemap.c:533 [inline]
 [<ffffffff813bc81c>] filemap_write_and_wait_range+0x5c/0xb0 mm/filemap.c:527
 [<ffffffff8151357b>] __generic_file_fsync+0x9b/0x1c0 fs/libfs.c:940
 [<ffffffff81513718>] generic_file_fsync+0x78/0x120 fs/libfs.c:977
 [<ffffffff81635822>] ext4_sync_file+0x772/0xf10 fs/ext4/fsync.c:109
 [<ffffffff81538fd1>] vfs_fsync_range+0x111/0x260 fs/sync.c:195
 [<ffffffff815534d6>] generic_write_sync include/linux/fs.h:2517 [inline]
 [<ffffffff815534d6>] dio_complete+0x3e6/0x720 fs/direct-io.c:266
 [<ffffffff81553986>] dio_bio_end_aio+0x176/0x3f0 fs/direct-io.c:312
 [<ffffffff81a22de7>] bio_endio+0x187/0x1e0 block/bio.c:1786
 [<ffffffff81a41d37>] req_bio_endio block/blk-core.c:157 [inline]
 [<ffffffff81a41d37>] blk_update_request+0x267/0xa50 block/blk-core.c:2653
 [<ffffffff81d76bbc>] scsi_end_request+0x9c/0x5d0 drivers/scsi/scsi_lib.c:695
 [<ffffffff81d7f3c5>] scsi_io_completion+0x275/0x1810 drivers/scsi/scsi_lib.c:918
 [<ffffffff81d62b84>] scsi_finish_command+0x3a4/0x520 drivers/scsi/scsi.c:607
 [<ffffffff81d7d919>] scsi_softirq_done+0x259/0x370 drivers/scsi/scsi_lib.c:1654
 [<ffffffff81a5f098>] blk_done_softirq+0x258/0x3a0 block/blk-softirq.c:35
 [<ffffffff8271bb16>] __do_softirq+0x226/0xa3f kernel/softirq.c:273
 [<ffffffff810e1a8a>] invoke_softirq kernel/softirq.c:350 [inline]
 [<ffffffff810e1a8a>] irq_exit+0x10a/0x150 kernel/softirq.c:391
 [<ffffffff8271b111>] exiting_irq arch/x86/include/asm/apic.h:652 [inline]
 [<ffffffff8271b111>] do_IRQ+0x111/0x1d0 arch/x86/kernel/irq.c:251
 [<ffffffff8271971d>] common_interrupt+0x9d/0x9d arch/x86/entry/entry_64.S:623
 <EOI>  [<ffffffff810a1dc2>] ? native_safe_halt+0x2/0x10 arch/x86/include/asm/irqflags.h:52
 [<ffffffff81022d50>] arch_cpu_idle+0x10/0x20 arch/x86/kernel/process.c:423
 [<ffffffff811eb4c8>] default_idle_call+0x48/0x70 kernel/sched/idle.c:93
 [<ffffffff811ebca1>] cpuidle_idle_call kernel/sched/idle.c:157 [inline]
 [<ffffffff811ebca1>] cpu_idle_loop kernel/sched/idle.c:253 [inline]
 [<ffffffff811ebca1>] cpu_startup_entry+0x6d1/0x810 kernel/sched/idle.c:301
 [<ffffffff8108719d>] start_secondary+0x31d/0x410 arch/x86/kernel/smpboot.c:245

=================================
[ INFO: inconsistent lock state ]
4.4.174+ #4 Not tainted
---------------------------------
inconsistent {SOFTIRQ-ON-W} -> {IN-SOFTIRQ-W} usage.
swapper/1/0 [HC0[0]:SC1[1]:HE1:SE0] takes:
 (&sb->s_type->i_mutex_key#9){+.?.+.}, at: [<ffffffff815135af>] __generic_file_fsync+0xcf/0x1c0 fs/libfs.c:944
{SOFTIRQ-ON-W} state was registered at:
  [<ffffffff81200423>] mark_irqflags kernel/locking/lockdep.c:2817 [inline]
  [<ffffffff81200423>] __lock_acquire+0xe73/0x4f50 kernel/locking/lockdep.c:3169
  [<ffffffff81205f6e>] lock_acquire+0x15e/0x450 kernel/locking/lockdep.c:3592
  [<ffffffff8270c191>] __mutex_lock_common kernel/locking/mutex.c:521 [inline]
  [<ffffffff8270c191>] mutex_lock_nested+0xc1/0xb80 kernel/locking/mutex.c:621
  [<ffffffff814ab41f>] bprm_fill_uid fs/exec.c:1357 [inline]
  [<ffffffff814ab41f>] prepare_binprm+0x2bf/0x770 fs/exec.c:1391
  [<ffffffff814ad996>] do_execveat_common.isra.0+0xd86/0x1e90 fs/exec.c:1620
  [<ffffffff814af422>] do_execve fs/exec.c:1683 [inline]
  [<ffffffff814af422>] SYSC_execve fs/exec.c:1764 [inline]
  [<ffffffff814af422>] SyS_execve+0x42/0x50 fs/exec.c:1759
  [<ffffffff82718ef5>] return_from_execve+0x0/0x23
irq event stamp: 145358
hardirqs last  enabled at (145358): [<ffffffff8148535a>] quarantine_put+0xda/0x180 mm/kasan/quarantine.c:209
hardirqs last disabled at (145357): [<ffffffff814852d2>] quarantine_put+0x52/0x180 mm/kasan/quarantine.c:186
softirqs last  enabled at (145298): [<ffffffff810e136c>] _local_bh_enable+0x1c/0x50 kernel/softirq.c:144
softirqs last disabled at (145299): [<ffffffff810e1a8a>] invoke_softirq kernel/softirq.c:350 [inline]
softirqs last disabled at (145299): [<ffffffff810e1a8a>] irq_exit+0x10a/0x150 kernel/softirq.c:391

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

no locks held by swapper/1/0.

stack backtrace:
CPU: 1 PID: 0 Comm: swapper/1 Not tainted 4.4.174+ #4
 0000000000000000 d7ee000cd50c6b37 ffff8801db707610 ffffffff81aad1a1
 0000000000000090 ffff8801da6897c0 ffffffff83abf2c0 ffffffff84057a80
 ffff8801da68a0a8 ffff8801db707688 ffffffff813ad456 0000000000000001
Call Trace:
 <IRQ>  [<ffffffff81aad1a1>] __dump_stack lib/dump_stack.c:15 [inline]
 <IRQ>  [<ffffffff81aad1a1>] dump_stack+0xc1/0x120 lib/dump_stack.c:51
 [<ffffffff813ad456>] print_usage_bug.cold+0x454/0x592 kernel/locking/lockdep.c:2267
 [<ffffffff811fe1bd>] valid_state kernel/locking/lockdep.c:2280 [inline]
 [<ffffffff811fe1bd>] mark_lock_irq kernel/locking/lockdep.c:2478 [inline]
 [<ffffffff811fe1bd>] mark_lock+0x6fd/0x1440 kernel/locking/lockdep.c:2933
 [<ffffffff81200a0e>] mark_irqflags kernel/locking/lockdep.c:2799 [inline]
 [<ffffffff81200a0e>] __lock_acquire+0x145e/0x4f50 kernel/locking/lockdep.c:3169
 [<ffffffff81205f6e>] lock_acquire+0x15e/0x450 kernel/locking/lockdep.c:3592
 [<ffffffff8270c191>] __mutex_lock_common kernel/locking/mutex.c:521 [inline]
 [<ffffffff8270c191>] mutex_lock_nested+0xc1/0xb80 kernel/locking/mutex.c:621
 [<ffffffff815135af>] __generic_file_fsync+0xcf/0x1c0 fs/libfs.c:944
 [<ffffffff81513718>] generic_file_fsync+0x78/0x120 fs/libfs.c:977
 [<ffffffff81635822>] ext4_sync_file+0x772/0xf10 fs/ext4/fsync.c:109
 [<ffffffff81538fd1>] vfs_fsync_range+0x111/0x260 fs/sync.c:195
 [<ffffffff815534d6>] generic_write_sync include/linux/fs.h:2517 [inline]
 [<ffffffff815534d6>] dio_complete+0x3e6/0x720 fs/direct-io.c:266
 [<ffffffff81553986>] dio_bio_end_aio+0x176/0x3f0 fs/direct-io.c:312
 [<ffffffff81a22de7>] bio_endio+0x187/0x1e0 block/bio.c:1786
 [<ffffffff81a41d37>] req_bio_endio block/blk-core.c:157 [inline]
 [<ffffffff81a41d37>] blk_update_request+0x267/0xa50 block/blk-core.c:2653
 [<ffffffff81d76bbc>] scsi_end_request+0x9c/0x5d0 drivers/scsi/scsi_lib.c:695
 [<ffffffff81d7f3c5>] scsi_io_completion+0x275/0x1810 drivers/scsi/scsi_lib.c:918
 [<ffffffff81d62b84>] scsi_finish_command+0x3a4/0x520 drivers/scsi/scsi.c:607
 [<ffffffff81d7d919>] scsi_softirq_done+0x259/0x370 drivers/scsi/scsi_lib.c:1654
 [<ffffffff81a5f098>] blk_done_softirq+0x258/0x3a0 block/blk-softirq.c:35
 [<ffffffff8271bb16>] __do_softirq+0x226/0xa3f kernel/softirq.c:273
 [<ffffffff810e1a8a>] invoke_softirq kernel/softirq.c:350 [inline]
 [<ffffffff810e1a8a>] irq_exit+0x10a/0x150 kernel/softirq.c:391
 [<ffffffff8271b111>] exiting_irq arch/x86/include/asm/apic.h:652 [inline]
 [<ffffffff8271b111>] do_IRQ+0x111/0x1d0 arch/x86/kernel/irq.c:251
 [<ffffffff8271971d>] common_interrupt+0x9d/0x9d arch/x86/entry/entry_64.S:623
 <EOI>  [<ffffffff810a1dc2>] ? native_safe_halt+0x2/0x10 arch/x86/include/asm/irqflags.h:52
 [<ffffffff81022d50>] arch_cpu_idle+0x10/0x20 arch/x86/kernel/process.c:423
 [<ffffffff811eb4c8>] default_idle_call+0x48/0x70 kernel/sched/idle.c:93
 [<ffffffff811ebca1>] cpuidle_idle_call kernel/sched/idle.c:157 [inline]
 [<ffffffff811ebca1>] cpu_idle_loop kernel/sched/idle.c:253 [inline]
 [<ffffffff811ebca1>] cpu_startup_entry+0x6d1/0x810 kernel/sched/idle.c:301
 [<ffffffff8108719d>] start_secondary+0x31d/0x410 arch/x86/kernel/smpboot.c:245
------------[ cut here ]------------
kernel BUG at include/linux/pagemap.h:152!
invalid opcode: 0000 [#1] PREEMPT SMP KASAN
Modules linked in:
CPU: 1 PID: 0 Comm: swapper/1 Not tainted 4.4.174+ #4
task: ffff8801da6897c0 task.stack: ffff8801da698000
RIP: 0010:[<ffffffff813b8d6f>]  [<ffffffff813b8d6f>] page_cache_get_speculative include/linux/pagemap.h:152 [inline]
RIP: 0010:[<ffffffff813b8d6f>]  [<ffffffff813b8d6f>] find_get_pages_range_tag+0x4df/0x6a0 mm/filemap.c:1483
RSP: 0018:ffff8801db7075d8  EFLAGS: 00010206
RAX: ffff8801da6897c0 RBX: 000000000000000e RCX: 1ffffffff05f7178
RDX: 0000000000000100 RSI: ffffffff813b8d6f RDI: ffff8801db707648
RBP: ffff8801db7076d0 R08: 0000000000000000 R09: 0000000000000000
R10: ffffffff82836880 R11: ffffffff831a5078 R12: ffff8801d63a3ba0
R13: ffff8801d601dee8 R14: ffff8801db7076a8 R15: ffffea00074f2980
FS:  0000000000000000(0000) GS:ffff8801db700000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00007f68b6b3c000 CR3: 00000001d49ca000 CR4: 00000000001606b0
Stack:
 ffffffff813b8943 1ffff1003b6e0ec5 ffff8801d63a3ba0 1ffff1003b6e0eeb
 0000000100000101 ffff8801db707758 ffff8801db707788 0000000000000fff
 000000000000000e ffffed003ac03bdd 0000000041b58ab3 ffffffff82c5ac4d
Call Trace:
 <IRQ> 
 [<ffffffff813df690>] pagevec_lookup_range_tag+0x40/0x80 mm/swap.c:1137
 [<ffffffff813b742e>] __filemap_fdatawait_range+0xfe/0x260 mm/filemap.c:400
 [<ffffffff813b75b6>] filemap_fdatawait_range+0x26/0x50 mm/filemap.c:438
 [<ffffffff813b7646>] filemap_fdatawait+0x66/0x90 mm/filemap.c:488
 [<ffffffff81526f5e>] __writeback_single_inode+0x76e/0x1380 fs/fs-writeback.c:1295
 [<ffffffff8152a8e6>] writeback_single_inode+0x256/0x450 fs/fs-writeback.c:1397
 [<ffffffff8152abd3>] sync_inode fs/fs-writeback.c:2391 [inline]
 [<ffffffff8152abd3>] sync_inode_metadata+0xc3/0x100 fs/fs-writeback.c:2411
 [<ffffffff8151362e>] __generic_file_fsync+0x14e/0x1c0 fs/libfs.c:951
 [<ffffffff81513718>] generic_file_fsync+0x78/0x120 fs/libfs.c:977
 [<ffffffff81635822>] ext4_sync_file+0x772/0xf10 fs/ext4/fsync.c:109
 [<ffffffff81538fd1>] vfs_fsync_range+0x111/0x260 fs/sync.c:195
 [<ffffffff815534d6>] generic_write_sync include/linux/fs.h:2517 [inline]
 [<ffffffff815534d6>] dio_complete+0x3e6/0x720 fs/direct-io.c:266
 [<ffffffff81553986>] dio_bio_end_aio+0x176/0x3f0 fs/direct-io.c:312
 [<ffffffff81a22de7>] bio_endio+0x187/0x1e0 block/bio.c:1786
 [<ffffffff81a41d37>] req_bio_endio block/blk-core.c:157 [inline]
 [<ffffffff81a41d37>] blk_update_request+0x267/0xa50 block/blk-core.c:2653
 [<ffffffff81d76bbc>] scsi_end_request+0x9c/0x5d0 drivers/scsi/scsi_lib.c:695
 [<ffffffff81d7f3c5>] scsi_io_completion+0x275/0x1810 drivers/scsi/scsi_lib.c:918
 [<ffffffff81d62b84>] scsi_finish_command+0x3a4/0x520 drivers/scsi/scsi.c:607
 [<ffffffff81d7d919>] scsi_softirq_done+0x259/0x370 drivers/scsi/scsi_lib.c:1654
 [<ffffffff81a5f098>] blk_done_softirq+0x258/0x3a0 block/blk-softirq.c:35
 [<ffffffff8271bb16>] __do_softirq+0x226/0xa3f kernel/softirq.c:273
 [<ffffffff810e1a8a>] invoke_softirq kernel/softirq.c:350 [inline]
 [<ffffffff810e1a8a>] irq_exit+0x10a/0x150 kernel/softirq.c:391
 [<ffffffff8271b111>] exiting_irq arch/x86/include/asm/apic.h:652 [inline]
 [<ffffffff8271b111>] do_IRQ+0x111/0x1d0 arch/x86/kernel/irq.c:251
 [<ffffffff8271971d>] common_interrupt+0x9d/0x9d arch/x86/entry/entry_64.S:623
 <EOI> 
 [<ffffffff81022d50>] arch_cpu_idle+0x10/0x20 arch/x86/kernel/process.c:423
 [<ffffffff811eb4c8>] default_idle_call+0x48/0x70 kernel/sched/idle.c:93
 [<ffffffff811ebca1>] cpuidle_idle_call kernel/sched/idle.c:157 [inline]
 [<ffffffff811ebca1>] cpu_idle_loop kernel/sched/idle.c:253 [inline]
 [<ffffffff811ebca1>] cpu_startup_entry+0x6d1/0x810 kernel/sched/idle.c:301
 [<ffffffff8108719d>] start_secondary+0x31d/0x410 arch/x86/kernel/smpboot.c:245
Code: 82 c6 05 84 08 de 01 01 e8 3f 35 e4 ff e9 30 fc ff ff e8 95 08 f5 ff 41 83 e7 01 0f 84 27 fe ff ff e9 38 fc ff ff e8 81 08 f5 ff <0f> 0b 41 89 c4 e9 4f fd ff ff e8 72 08 f5 ff 48 85 db 0f 84 3a 
RIP  [<ffffffff813b8d6f>] page_cache_get_speculative include/linux/pagemap.h:152 [inline]
RIP  [<ffffffff813b8d6f>] find_get_pages_range_tag+0x4df/0x6a0 mm/filemap.c:1483
 RSP <ffff8801db7075d8>
---[ end trace 999987b560beb0e7 ]---

Crashes (3):
Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Assets (help?) Manager Title
2019/03/12 11:49 https://android.googlesource.com/kernel/common android-4.4 62872f952d6b 12365b99 .config console log report syz C ci-android-44-kasan-gce
2019/03/12 11:17 https://android.googlesource.com/kernel/common android-4.4 62872f952d6b 12365b99 .config console log report ci-android-44-kasan-gce
2019/01/24 12:57 https://android.googlesource.com/kernel/common android-4.4 d0c3914ffbe4 ce1ccf97 .config console log report ci-android-44-kasan-gce
* Struck through repros no longer work on HEAD.