BUG: Bad page state (8)

BUG: Bad page state (8)
Status: upstream: reported on 2021/02/01 10:07
Reported-by: syzbot+97ef6376738cb5104a71@syzkaller.appspotmail.com
Fix commit: mm-filemap-add-filemap_range_uptodate-fix
Patched on: [ci-upstream-linux-next-kasan-gce-root], missing on: [ci-qemu-upstream ci-qemu-upstream-386 ci-qemu2-arm32 ci-qemu2-arm64 ci-qemu2-arm64-compat ci-qemu2-arm64-mte ci-qemu2-riscv64 ci-upstream-bpf-kasan-gce ci-upstream-bpf-next-kasan-gce ci-upstream-gce-leak ci-upstream-kasan-gce ci-upstream-kasan-gce-386 ci-upstream-kasan-gce-root ci-upstream-kasan-gce-selinux-root ci-upstream-kasan-gce-smack-root ci-upstream-kmsan-gce ci-upstream-kmsan-gce-386 ci-upstream-net-kasan-gce ci-upstream-net-this-kasan-gce ci2-upstream-kcsan-gce ci2-upstream-usb]
First crash: 273d, last: 11d

similar bugs (9):
Kernel	Title	Repro	Count	Last	Reported	Patched	Status
upstream	BUG: Bad page state (3)	C	3	1389d	1396d	4/22	fixed on 2018/02/02 04:39
upstream	BUG: Bad page state (5)	C	171	974d	987d	0/22	closed as invalid on 2019/02/27 20:53
upstream	BUG: Bad page state (7)		3	424d	481d	0/22	auto-closed as invalid on 2020/12/28 02:44
android-49	BUG: Bad page state		3	756d	780d	0/3	auto-closed as invalid on 2020/01/30 18:48
android-54	BUG: Bad page state	C	9	577d	608d	0/1	upstream: reported C repro on 2020/02/28 01:20
upstream	BUG: Bad page state (2)		1	1431d	1427d	0/22	closed as invalid on 2017/12/06 12:57
upstream	BUG: Bad page state (4)		1	1193d	1193d	0/22	closed as invalid on 2018/09/05 12:51
upstream	BUG: Bad page state (6)	C	2	973d	973d	0/22	closed as invalid on 2019/03/01 18:38
upstream	BUG: Bad page state	C	2	1534d	1535d	3/22	fixed on 2017/10/24 06:54

Sample crash report:

BUG: Bad page state in process syz-executor.1  pfn:a4000

======================================================
WARNING: possible circular locking dependency detected
5.15.0-rc5-next-20211015-syzkaller #0 Not tainted
------------------------------------------------------
syz-executor.1/6682 is trying to acquire lock:
ffffffff8ba91f80 (console_owner){-...}-{0:0}, at: console_unlock+0x303/0xb70 kernel/printk/printk.c:2710

but task is already holding lock:
ffff8880b9d355c0 (lock#2){..-.}-{2:2}, at: rmqueue_pcplist mm/page_alloc.c:3642 [inline]
ffff8880b9d355c0 (lock#2){..-.}-{2:2}, at: rmqueue mm/page_alloc.c:3680 [inline]
ffff8880b9d355c0 (lock#2){..-.}-{2:2}, at: get_page_from_freelist+0x486/0x2f50 mm/page_alloc.c:4144

which lock already depends on the new lock.


the existing dependency chain (in reverse order) is:

-> #3 (lock#2){..-.}-{2:2}:
       local_lock_acquire include/linux/local_lock_internal.h:29 [inline]
       rmqueue_pcplist mm/page_alloc.c:3642 [inline]
       rmqueue mm/page_alloc.c:3680 [inline]
       get_page_from_freelist+0x4aa/0x2f50 mm/page_alloc.c:4144
       __alloc_pages+0x1b2/0x500 mm/page_alloc.c:5386
       alloc_pages+0x1a7/0x300 mm/mempolicy.c:2191
       alloc_slab_page mm/slub.c:1770 [inline]
       allocate_slab mm/slub.c:1907 [inline]
       new_slab+0x32d/0x4a0 mm/slub.c:1970
       ___slab_alloc+0x947/0x1040 mm/slub.c:3001
       __slab_alloc.constprop.0+0x4d/0xa0 mm/slub.c:3088
       slab_alloc_node mm/slub.c:3179 [inline]
       slab_alloc mm/slub.c:3220 [inline]
       __kmalloc+0x303/0x320 mm/slub.c:4397
       kmalloc include/linux/slab.h:595 [inline]
       tty_buffer_alloc+0x23f/0x2a0 drivers/tty/tty_buffer.c:177
       __tty_buffer_request_room+0x156/0x2a0 drivers/tty/tty_buffer.c:275
       tty_insert_flip_string_fixed_flag+0x93/0x250 drivers/tty/tty_buffer.c:321
       tty_insert_flip_string include/linux/tty_flip.h:42 [inline]
       pty_write+0x11c/0x1e0 drivers/tty/pty.c:122
       ppp_async_push+0x5cb/0x1660 drivers/net/ppp/ppp_async.c:671
       ppp_async_send+0xde/0x110 drivers/net/ppp/ppp_async.c:639
       __ppp_channel_push+0xe3/0x230 drivers/net/ppp/ppp_generic.c:2142
       ppp_channel_push+0x1c2/0x250 drivers/net/ppp/ppp_generic.c:2169
       ppp_write+0x20d/0x2a0 drivers/net/ppp/ppp_generic.c:517
       do_loop_readv_writev fs/read_write.c:753 [inline]
       do_loop_readv_writev fs/read_write.c:737 [inline]
       do_iter_write+0x4f8/0x710 fs/read_write.c:857
       vfs_writev+0x1aa/0x630 fs/read_write.c:928
       do_pwritev fs/read_write.c:1025 [inline]
       __do_sys_pwritev fs/read_write.c:1072 [inline]
       __se_sys_pwritev fs/read_write.c:1067 [inline]
       __x64_sys_pwritev+0x231/0x310 fs/read_write.c:1067
       do_syscall_x64 arch/x86/entry/common.c:50 [inline]
       do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
       entry_SYSCALL_64_after_hwframe+0x44/0xae

-> #2 (&port->lock){-.-.}-{2:2}:
       __raw_spin_lock_irqsave include/linux/spinlock_api_smp.h:110 [inline]
       _raw_spin_lock_irqsave+0x39/0x50 kernel/locking/spinlock.c:162
       tty_port_tty_get+0x1f/0x100 drivers/tty/tty_port.c:289
       tty_port_default_wakeup+0x11/0x40 drivers/tty/tty_port.c:48
       serial8250_tx_chars+0x4f3/0xad0 drivers/tty/serial/8250/8250_port.c:1845
       serial8250_handle_irq.part.0+0x328/0x3d0 drivers/tty/serial/8250/8250_port.c:1932
       serial8250_handle_irq drivers/tty/serial/8250/8250_port.c:1905 [inline]
       serial8250_default_handle_irq+0xb2/0x220 drivers/tty/serial/8250/8250_port.c:1949
       serial8250_interrupt+0xfd/0x200 drivers/tty/serial/8250/8250_core.c:126
       __handle_irq_event_percpu+0x303/0x8f0 kernel/irq/handle.c:156
       handle_irq_event_percpu kernel/irq/handle.c:196 [inline]
       handle_irq_event+0x102/0x280 kernel/irq/handle.c:213
       handle_edge_irq+0x25f/0xd00 kernel/irq/chip.c:822
       generic_handle_irq_desc include/linux/irqdesc.h:158 [inline]
       handle_irq arch/x86/kernel/irq.c:231 [inline]
       __common_interrupt+0x9d/0x210 arch/x86/kernel/irq.c:250
       common_interrupt+0xa4/0xc0 arch/x86/kernel/irq.c:240
       asm_common_interrupt+0x1e/0x40 arch/x86/include/asm/idtentry.h:629
       __raw_spin_unlock_irqrestore include/linux/spinlock_api_smp.h:161 [inline]
       _raw_spin_unlock_irqrestore+0x38/0x70 kernel/locking/spinlock.c:194
       spin_unlock_irqrestore include/linux/spinlock.h:422 [inline]
       uart_write+0x30d/0x570 drivers/tty/serial/serial_core.c:598
       do_output_char+0x5de/0x850 drivers/tty/n_tty.c:444
       process_output drivers/tty/n_tty.c:511 [inline]
       n_tty_write+0x4c3/0xfd0 drivers/tty/n_tty.c:2300
       do_tty_write drivers/tty/tty_io.c:1038 [inline]
       file_tty_write.constprop.0+0x526/0x910 drivers/tty/tty_io.c:1110
       redirected_tty_write+0xa1/0xc0 drivers/tty/tty_io.c:1131
       call_write_iter include/linux/fs.h:2159 [inline]
       do_iter_readv_writev+0x472/0x750 fs/read_write.c:729
       do_iter_write+0x188/0x710 fs/read_write.c:855
       vfs_writev+0x1aa/0x630 fs/read_write.c:928
       do_writev+0x139/0x300 fs/read_write.c:971
       do_syscall_x64 arch/x86/entry/common.c:50 [inline]
       do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
       entry_SYSCALL_64_after_hwframe+0x44/0xae

-> #1 (&port_lock_key){-.-.}-{2:2}:
       __raw_spin_lock_irqsave include/linux/spinlock_api_smp.h:110 [inline]
       _raw_spin_lock_irqsave+0x39/0x50 kernel/locking/spinlock.c:162
       serial8250_console_write+0x91a/0xb70 drivers/tty/serial/8250/8250_port.c:3345
       call_console_drivers kernel/printk/printk.c:1932 [inline]
       console_unlock+0x7a9/0xb70 kernel/printk/printk.c:2714
       vprintk_emit+0x198/0x4f0 kernel/printk/printk.c:2248
       vprintk+0x80/0x90 kernel/printk/printk_safe.c:50
       _printk+0xba/0xed kernel/printk/printk.c:2269
       register_console kernel/printk/printk.c:3054 [inline]
       register_console+0x55f/0x780 kernel/printk/printk.c:2934
       univ8250_console_init+0x3a/0x46 drivers/tty/serial/8250/8250_core.c:680
       console_init+0x3c1/0x58d kernel/printk/printk.c:3154
       start_kernel+0x30b/0x49b init/main.c:1074
       secondary_startup_64_no_verify+0xb0/0xbb

-> #0 (console_owner){-...}-{0:0}:
       check_prev_add kernel/locking/lockdep.c:3063 [inline]
       check_prevs_add kernel/locking/lockdep.c:3186 [inline]
       validate_chain kernel/locking/lockdep.c:3801 [inline]
       __lock_acquire+0x2a07/0x54a0 kernel/locking/lockdep.c:5027
       lock_acquire kernel/locking/lockdep.c:5637 [inline]
       lock_acquire+0x1ab/0x510 kernel/locking/lockdep.c:5602
       console_lock_spinning_enable kernel/printk/printk.c:1784 [inline]
       console_unlock+0x356/0xb70 kernel/printk/printk.c:2711
       vprintk_emit+0x198/0x4f0 kernel/printk/printk.c:2248
       vprintk+0x80/0x90 kernel/printk/printk_safe.c:50
       _printk+0xba/0xed kernel/printk/printk.c:2269
       bad_page.cold+0x87/0xbd mm/page_alloc.c:647
       check_new_page_bad mm/page_alloc.c:2311 [inline]
       check_new_page mm/page_alloc.c:2324 [inline]
       check_new_pcp mm/page_alloc.c:2344 [inline]
       __rmqueue_pcplist mm/page_alloc.c:3626 [inline]
       rmqueue_pcplist mm/page_alloc.c:3652 [inline]
       rmqueue mm/page_alloc.c:3680 [inline]
       get_page_from_freelist+0x1618/0x2f50 mm/page_alloc.c:4144
       __alloc_pages+0x1b2/0x500 mm/page_alloc.c:5386
       alloc_pages+0x1a7/0x300 mm/mempolicy.c:2191
       __get_free_pages+0x8/0x40 mm/page_alloc.c:5435
       io_allocate_scq_urings fs/io_uring.c:10239 [inline]
       io_uring_create fs/io_uring.c:10375 [inline]
       io_uring_setup.cold+0xe47/0x2454 fs/io_uring.c:10465
       do_syscall_x64 arch/x86/entry/common.c:50 [inline]
       do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
       entry_SYSCALL_64_after_hwframe+0x44/0xae

other info that might help us debug this:

Chain exists of:
  console_owner --> &port->lock --> lock#2

 Possible unsafe locking scenario:

       CPU0                    CPU1
       ----                    ----
  lock(lock#2);
                               lock(&port->lock);
                               lock(lock#2);
  lock(console_owner);

 *** DEADLOCK ***

2 locks held by syz-executor.1/6682:
 #0: ffff8880b9d355c0 (lock#2){..-.}-{2:2}, at: rmqueue_pcplist mm/page_alloc.c:3642 [inline]
 #0: ffff8880b9d355c0 (lock#2){..-.}-{2:2}, at: rmqueue mm/page_alloc.c:3680 [inline]
 #0: ffff8880b9d355c0 (lock#2){..-.}-{2:2}, at: get_page_from_freelist+0x486/0x2f50 mm/page_alloc.c:4144
 #1: ffffffff8bb723c0 (console_lock){+.+.}-{0:0}, at: vprintk+0x80/0x90 kernel/printk/printk_safe.c:50

stack backtrace:
CPU: 1 PID: 6682 Comm: syz-executor.1 Not tainted 5.15.0-rc5-next-20211015-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
Call Trace:
 <TASK>
 __dump_stack lib/dump_stack.c:88 [inline]
 dump_stack_lvl+0xcd/0x134 lib/dump_stack.c:106
 check_noncircular+0x25f/0x2e0 kernel/locking/lockdep.c:2143
 check_prev_add kernel/locking/lockdep.c:3063 [inline]
 check_prevs_add kernel/locking/lockdep.c:3186 [inline]
 validate_chain kernel/locking/lockdep.c:3801 [inline]
 __lock_acquire+0x2a07/0x54a0 kernel/locking/lockdep.c:5027
 lock_acquire kernel/locking/lockdep.c:5637 [inline]
 lock_acquire+0x1ab/0x510 kernel/locking/lockdep.c:5602
 console_lock_spinning_enable kernel/printk/printk.c:1784 [inline]
 console_unlock+0x356/0xb70 kernel/printk/printk.c:2711
 vprintk_emit+0x198/0x4f0 kernel/printk/printk.c:2248
 vprintk+0x80/0x90 kernel/printk/printk_safe.c:50
 _printk+0xba/0xed kernel/printk/printk.c:2269
 bad_page.cold+0x87/0xbd mm/page_alloc.c:647
 check_new_page_bad mm/page_alloc.c:2311 [inline]
 check_new_page mm/page_alloc.c:2324 [inline]
 check_new_pcp mm/page_alloc.c:2344 [inline]
 __rmqueue_pcplist mm/page_alloc.c:3626 [inline]
 rmqueue_pcplist mm/page_alloc.c:3652 [inline]
 rmqueue mm/page_alloc.c:3680 [inline]
 get_page_from_freelist+0x1618/0x2f50 mm/page_alloc.c:4144
 __alloc_pages+0x1b2/0x500 mm/page_alloc.c:5386
 alloc_pages+0x1a7/0x300 mm/mempolicy.c:2191
 __get_free_pages+0x8/0x40 mm/page_alloc.c:5435
 io_allocate_scq_urings fs/io_uring.c:10239 [inline]
 io_uring_create fs/io_uring.c:10375 [inline]
 io_uring_setup.cold+0xe47/0x2454 fs/io_uring.c:10465
 do_syscall_x64 arch/x86/entry/common.c:50 [inline]
 do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
 entry_SYSCALL_64_after_hwframe+0x44/0xae
RIP: 0033:0x7f4941f05a39
Code: ff ff c3 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 40 00 48 89 f8 48 89 f7 48 89 d6 48 89 ca 4d 89 c2 4d 89 c8 4c 8b 4c 24 08 0f 05 <48> 3d 01 f0 ff ff 73 01 c3 48 c7 c1 bc ff ff ff f7 d8 64 89 01 48
RSP: 002b:00007f493f47b108 EFLAGS: 00000202 ORIG_RAX: 00000000000001a9
RAX: ffffffffffffffda RBX: 00007f4942008f60 RCX: 00007f4941f05a39
RDX: 0000000020ffc000 RSI: 0000000020001680 RDI: 00000000000073b5
RBP: 0000000020001680 R08: 0000000020001740 R09: 0000000020001740
R10: 0000000000000000 R11: 0000000000000202 R12: 0000000020001740
R13: 0000000020ffc000 R14: 0000000000000000 R15: 0000000020003000
 </TASK>
page:ffffea0002900000 refcount:0 mapcount:0 mapping:0000000000000000 index:0x0 pfn:0xa4000
flags: 0xfff00000000008(dirty|node=0|zone=1|lastcpupid=0x7ff)
raw: 00fff00000000008 dead000000000100 dead000000000122 0000000000000000
raw: 0000000000000000 0000000000000000 00000000ffffffff 0000000000000000
page dumped because: PAGE_FLAGS_CHECK_AT_PREP flag(s) set
page_owner tracks the page as freed
page last allocated via order 9, migratetype Unmovable, gfp_mask 0x552dc0(GFP_USER|__GFP_NOWARN|__GFP_NORETRY|__GFP_COMP|__GFP_ZERO|__GFP_ACCOUNT), pid 6669, ts 1061742477299, free_ts 1062132387481
 prep_new_page mm/page_alloc.c:2416 [inline]
 get_page_from_freelist+0xa72/0x2f50 mm/page_alloc.c:4147
 __alloc_pages+0x1b2/0x500 mm/page_alloc.c:5386
 alloc_pages+0x1a7/0x300 mm/mempolicy.c:2191
 __get_free_pages+0x8/0x40 mm/page_alloc.c:5435
 io_allocate_scq_urings fs/io_uring.c:10239 [inline]
 io_uring_create fs/io_uring.c:10375 [inline]
 io_uring_setup.cold+0xe47/0x2454 fs/io_uring.c:10465
 do_syscall_x64 arch/x86/entry/common.c:50 [inline]
 do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
 entry_SYSCALL_64_after_hwframe+0x44/0xae
page last free stack trace:
 reset_page_owner include/linux/page_owner.h:24 [inline]
 free_pages_prepare mm/page_alloc.c:1336 [inline]
 free_pcp_prepare+0x373/0x870 mm/page_alloc.c:1387
 free_unref_page_prepare mm/page_alloc.c:3307 [inline]
 free_unref_page+0x19/0x690 mm/page_alloc.c:3386
 io_mem_free.part.0+0xb0/0xb9 fs/io_uring.c:8785
 io_mem_free fs/io_uring.c:8780 [inline]
 io_ring_ctx_free fs/io_uring.c:9326 [inline]
 io_ring_exit_work+0xa24/0xbe8 fs/io_uring.c:9479
 process_one_work+0x9b2/0x1690 kernel/workqueue.c:2297
 worker_thread+0x658/0x11f0 kernel/workqueue.c:2444
 kthread+0x405/0x4f0 kernel/kthread.c:327
 ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:295
Modules linked in:
CPU: 1 PID: 6682 Comm: syz-executor.1 Not tainted 5.15.0-rc5-next-20211015-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
Call Trace:
 <TASK>
 __dump_stack lib/dump_stack.c:88 [inline]
 dump_stack_lvl+0xcd/0x134 lib/dump_stack.c:106
 bad_page.cold+0x9c/0xbd mm/page_alloc.c:652
 check_new_page_bad mm/page_alloc.c:2311 [inline]
 check_new_page mm/page_alloc.c:2324 [inline]
 check_new_pcp mm/page_alloc.c:2344 [inline]
 __rmqueue_pcplist mm/page_alloc.c:3626 [inline]
 rmqueue_pcplist mm/page_alloc.c:3652 [inline]
 rmqueue mm/page_alloc.c:3680 [inline]
 get_page_from_freelist+0x1618/0x2f50 mm/page_alloc.c:4144
 __alloc_pages+0x1b2/0x500 mm/page_alloc.c:5386
 alloc_pages+0x1a7/0x300 mm/mempolicy.c:2191
 __get_free_pages+0x8/0x40 mm/page_alloc.c:5435
 io_allocate_scq_urings fs/io_uring.c:10239 [inline]
 io_uring_create fs/io_uring.c:10375 [inline]
 io_uring_setup.cold+0xe47/0x2454 fs/io_uring.c:10465
 do_syscall_x64 arch/x86/entry/common.c:50 [inline]
 do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
 entry_SYSCALL_64_after_hwframe+0x44/0xae
RIP: 0033:0x7f4941f05a39
Code: ff ff c3 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 40 00 48 89 f8 48 89 f7 48 89 d6 48 89 ca 4d 89 c2 4d 89 c8 4c 8b 4c 24 08 0f 05 <48> 3d 01 f0 ff ff 73 01 c3 48 c7 c1 bc ff ff ff f7 d8 64 89 01 48
RSP: 002b:00007f493f47b108 EFLAGS: 00000202 ORIG_RAX: 00000000000001a9
RAX: ffffffffffffffda RBX: 00007f4942008f60 RCX: 00007f4941f05a39
RDX: 0000000020ffc000 RSI: 0000000020001680 RDI: 00000000000073b5
RBP: 0000000020001680 R08: 0000000020001740 R09: 0000000020001740
R10: 0000000000000000 R11: 0000000000000202 R12: 0000000020001740
R13: 0000000020ffc000 R14: 0000000000000000 R15: 0000000020003000
 </TASK>

Crashes (3):
Manager	Time	Kernel	Commit	Syzkaller	Config	Log	Report	VM info	Title
ci-upstream-linux-next-kasan-gce-root	2021/10/16 15:07	linux-next	7c832d2f9b95	0c5d9412	.config	log	report	info	BUG: Bad page state
ci-upstream-linux-next-kasan-gce-root	2021/02/01 19:05	linux-next	fd821bf0ed9a	e6b95f32	.config	log	report	info	BUG: Bad page state
ci-upstream-linux-next-kasan-gce-root	2021/01/28 10:01	linux-next	d03154e8bb6a	eefc07f2	.config	log	report	info	BUG: Bad page state