Skip to content

Commit

Permalink
pkg/report: improve Bad page state parsing
Browse files Browse the repository at this point in the history
Take a frame from the stack trace that is included in the bug report.
  • Loading branch information
a-nogikh committed Oct 22, 2024
1 parent cd6fc0a commit 3cb3e3e
Show file tree
Hide file tree
Showing 6 changed files with 336 additions and 3 deletions.
19 changes: 17 additions & 2 deletions pkg/report/linux.go
Original file line number Diff line number Diff line change
Expand Up @@ -1330,6 +1330,7 @@ var linuxStackParams = &stackParams{
"__fortify_report",
"cleanup_srcu_struct",
"rhashtable_lookup",
"extract_(user|iter)_to_sg",
},
corruptedLines: []*regexp.Regexp{
// Fault injection stacks are frequently intermixed with crash reports.
Expand Down Expand Up @@ -1634,8 +1635,22 @@ var linuxOopses = append([]*oops{
alt: []string{"BUG: Dentry still in use [%[1]v of %[2]v]"},
},
{
title: compile("BUG: Bad page state"),
fmt: "BUG: Bad page state",
title: compile("BUG: Bad page (state|cache)"),
fmt: "BUG: Bad page %[1]v in %[2]v",
stack: &stackFmt{
parts: []*regexp.Regexp{
compile(`page last allocated`),
parseStackTrace,
},
parts2: []*regexp.Regexp{
linuxCallTrace,
parseStackTrace,
},
skip: []string{"post_alloc_hook", "bad_page",
"(free|put|get|update|release)_page",
"free_unref", "^_*folio", "truncate_inode_pages",
"page_frag_free", "free_pcp_prepare"},
},
},
{
title: compile("BUG: Bad page map"),
Expand Down
91 changes: 91 additions & 0 deletions pkg/report/testdata/linux/report/725
Original file line number Diff line number Diff line change
@@ -0,0 +1,91 @@
TITLE: BUG: Bad page state in __get_metapage

[ 65.499023][ T5098] BUG: Bad page state in process syz-executor209 pfn:7deea
[ 65.506426][ T5098] page: refcount:0 mapcount:0 mapping:0000000000000000 index:0x2e pfn:0x7deea
[ 65.515426][ T5098] flags: 0xfff0000000400c(referenced|uptodate|private|node=0|zone=1|lastcpupid=0x7ff)
[ 65.525041][ T5098] raw: 00fff0000000400c dead000000000100 dead000000000122 0000000000000000
[ 65.534267][ T5098] raw: 000000000000002e ffff88807a2723e0 00000000ffffffff 0000000000000000
[ 65.544378][ T5098] page dumped because: PAGE_FLAGS_CHECK_AT_FREE flag(s) set
[ 65.552063][ T5098] page_owner tracks the page as allocated
[ 65.557890][ T5098] page last allocated via order 0, migratetype Unmovable, gfp_mask 0x40c40(GFP_NOFS|__GFP_COMP), pid 5096, tgid 5096 (syz-executor209), ts 64771645974, free_ts 55604629154
[ 65.575967][ T5098] post_alloc_hook+0x1f3/0x230
[ 65.581043][ T5098] get_page_from_freelist+0x2e4c/0x2f10
[ 65.586581][ T5098] __alloc_pages_noprof+0x256/0x6c0
[ 65.591814][ T5098] alloc_pages_mpol_noprof+0x3e8/0x680
[ 65.597377][ T5098] folio_alloc_noprof+0x128/0x180
[ 65.602555][ T5098] filemap_alloc_folio_noprof+0xdf/0x500
[ 65.608226][ T5098] __filemap_get_folio+0x44e/0xc10
[ 65.613415][ T5098] pagecache_get_page+0x2c/0x200
[ 65.618395][ T5098] __get_metapage+0x2b4/0x1050
[ 65.623241][ T5098] diNewExt+0xacf/0x37e0
[ 65.627506][ T5098] diAllocAG+0xbec/0x1e50
[ 65.631904][ T5098] diAlloc+0x1d3/0x1760
[ 65.636073][ T5098] ialloc+0x8f/0x900
[ 65.640305][ T5098] jfs_mkdir+0x1c5/0xba0
[ 65.644572][ T5098] vfs_mkdir+0x2f9/0x4f0
[ 65.649859][ T5098] do_mkdirat+0x264/0x3a0
[ 65.654284][ T5098] page last free pid 5083 tgid 5083 stack trace:
[ 65.660639][ T5098] free_unref_page+0xd19/0xea0
[ 65.665445][ T5098] __folio_put+0x3b9/0x620
[ 65.669903][ T5098] pipe_read+0x6f2/0x13e0
[ 65.674239][ T5098] vfs_read+0x9bd/0xbc0
[ 65.678383][ T5098] ksys_read+0x1a0/0x2c0
[ 65.682755][ T5098] do_syscall_64+0xf3/0x230
[ 65.687248][ T5098] entry_SYSCALL_64_after_hwframe+0x77/0x7f
[ 65.693191][ T5098] Modules linked in:
[ 65.697091][ T5098] CPU: 1 PID: 5098 Comm: syz-executor209 Tainted: G B 6.10.0-syzkaller-11185-g2c9b3512402e #0
[ 65.708700][ T5098] Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 06/27/2024
[ 65.718739][ T5098] Call Trace:
[ 65.722087][ T5098] <TASK>
[ 65.725017][ T5098] dump_stack_lvl+0x241/0x360
[ 65.729680][ T5098] ? __pfx_dump_stack_lvl+0x10/0x10
[ 65.734999][ T5098] ? __pfx_print_modules+0x10/0x10
[ 65.740186][ T5098] bad_page+0x14c/0x170
[ 65.744419][ T5098] free_unref_folios+0x1121/0x19c0
[ 65.749552][ T5098] folios_put_refs+0x93a/0xa60
[ 65.754346][ T5098] ? __pfx_folios_put_refs+0x10/0x10
[ 65.759645][ T5098] ? _raw_spin_unlock_irqrestore+0xdd/0x140
[ 65.765650][ T5098] ? __pfx__raw_spin_unlock_irqrestore+0x10/0x10
[ 65.772192][ T5098] ? rcu_is_watching+0x15/0xb0
[ 65.776979][ T5098] ? lru_add_fn+0xbb6/0x1a20
[ 65.781579][ T5098] folio_batch_move_lru+0x5d7/0x690
[ 65.786782][ T5098] ? __pfx_lru_add_fn+0x10/0x10
[ 65.791629][ T5098] ? __pfx_folio_batch_move_lru+0x10/0x10
[ 65.797339][ T5098] ? folio_batch_add_and_move+0x98/0x2b0
[ 65.802960][ T5098] ? __pfx_lru_add_fn+0x10/0x10
[ 65.807805][ T5098] folio_add_lru+0x39c/0x9e0
[ 65.812384][ T5098] ? folio_add_lru+0x27b/0x9e0
[ 65.817222][ T5098] shmem_alloc_and_add_folio+0xa49/0xdb0
[ 65.822859][ T5098] ? __pfx_shmem_alloc_and_add_folio+0x10/0x10
[ 65.829010][ T5098] shmem_get_folio_gfp+0x82d/0x1f50
[ 65.834508][ T5098] ? __pfx_shmem_get_folio_gfp+0x10/0x10
[ 65.840231][ T5098] ? __pfx_reacquire_held_locks+0x10/0x10
[ 65.846142][ T5098] ? fault_in_readable+0x1a6/0x2b0
[ 65.851451][ T5098] shmem_write_begin+0x170/0x4d0
[ 65.856709][ T5098] ? __pfx_shmem_write_begin+0x10/0x10
[ 65.862359][ T5098] ? fault_in_iov_iter_readable+0x229/0x280
[ 65.868247][ T5098] generic_perform_write+0x399/0x840
[ 65.873536][ T5098] ? __pfx_generic_perform_write+0x10/0x10
[ 65.879333][ T5098] ? preempt_count_add+0x93/0x190
[ 65.884345][ T5098] ? mnt_put_write_access_file+0xbb/0x100
[ 65.890052][ T5098] ? file_update_time+0x3b8/0x430
[ 65.895067][ T5098] shmem_file_write_iter+0xfc/0x120
[ 65.900278][ T5098] vfs_write+0xa72/0xc90
[ 65.904612][ T5098] ? __pfx_shmem_file_write_iter+0x10/0x10
[ 65.910413][ T5098] ? __pfx_vfs_write+0x10/0x10
[ 65.915167][ T5098] ? lockdep_hardirqs_on+0x99/0x150
[ 65.920365][ T5098] ksys_write+0x1a0/0x2c0
[ 65.924692][ T5098] ? __pfx_ksys_write+0x10/0x10
[ 65.929622][ T5098] ? exc_page_fault+0x590/0x8c0
[ 65.934489][ T5098] do_syscall_64+0xf3/0x230
[ 65.939067][ T5098] ? clear_bhb_loop+0x35/0x90
[ 65.943734][ T5098] entry_SYSCALL_64_after_hwframe+0x77/0x7f
[ 65.949988][ T5098] RIP: 0033:0x7f7b5710bee0
[ 65.954598][ T5098] Code: 40 00 48 c7 c2 b8 ff ff ff f7 d8 64 89 02 48 c7 c0 ff ff ff ff eb b7 0f 1f 00 80 3d c1 f1 07 00 00 74 17 b8 01 00 00 00 0f 05 <48> 3d 00 f0 ff ff 77 58 c3 0f 1f 80 00 00 00 00 48 83 ec 28 48 89
[ 65.974381][ T5098] RSP: 002b:00007fffc1930558 EFLAGS: 00000202 ORIG_RAX: 0000000000000001
[ 65.982795][ T5098] RAX: ffffffffffffffda RBX: 00007fffc1930570 RCX: 00007f7b5710bee0
[ 65.990759][ T5098] RDX: 0000000001000000 RSI: 00007f7b4ec00000 RDI: 0000000000000003
[ 65.998722][ T5098] RBP: 00007f7b4ec00000 R08: 0000000000005dd3 R09: 0000000000005dcf
[ 66.006680][ T5098] R10: 0000000000000774 R11: 0000000000000202 R12: 00007fffc1930710
[ 66.014645][ T5098] R13: 00007fffc19305b0 R14: 0000000000000003 R15: 0000000001000000
[ 66.022611][ T5098] </TASK>
102 changes: 102 additions & 0 deletions pkg/report/testdata/linux/report/726
Original file line number Diff line number Diff line change
@@ -0,0 +1,102 @@
TITLE: BUG: Bad page state in bpf_test_run_xdp_live
EXECUTOR: proc=3, id=584

[ 360.589544][ T8978] BUG: Bad page state in process syz.3.584 pfn:7071f
[ 360.597807][ T8978] page: refcount:0 mapcount:0 mapping:0000000000000000 index:0x7f467f1e8 pfn:0x7071f
[ 360.607825][ T8978] flags: 0xfff00000000000(node=0|zone=1|lastcpupid=0x7ff)
[ 360.615503][ T8978] raw: 00fff00000000000 dead000000000040 ffff888062a17000 0000000000000000
[ 360.624597][ T8978] raw: 00000007f467f1e8 0000000000000001 00000000ffffffff 0000000000000000
[ 360.633711][ T8978] page dumped because: page_pool leak
[ 360.639671][ T8978] page_owner tracks the page as allocated
[ 360.646064][ T8978] page last allocated via order 0, migratetype Unmovable, gfp_mask 0x102820(GFP_ATOMIC|__GFP_NOWARN|__GFP_HARDWALL), pid 8978, tgid 8974 (syz.3.584), ts 360393802361, free_ts 357078876492
[ 360.665078][ T8978] post_alloc_hook+0x1f3/0x230
[ 360.670446][ T8978] get_page_from_freelist+0x2e4c/0x2f10
SYZFAIL: failed to recv rpc
fd=3 want=4 recv=0 n=0 (errno 9: Bad file descriptor)
[ 360.676464][ T8978] __alloc_pages_noprof+0x256/0x6c0
[ 360.682165][ T8978] alloc_pages_bulk_noprof+0x729/0xd40
[ 360.687981][ T8978] __page_pool_alloc_pages_slow+0x138/0x690
[ 360.694427][ T8978] page_pool_alloc_pages+0xcb/0x150
[ 360.700249][ T8978] bpf_test_run_xdp_live+0x939/0x2110
[ 360.706140][ T8978] bpf_prog_test_run_xdp+0x80e/0x11b0
[ 360.711890][ T8978] bpf_prog_test_run+0x33a/0x3b0
[ 360.717211][ T8978] __sys_bpf+0x48d/0x810
[ 360.721880][ T8978] __x64_sys_bpf+0x7c/0x90
[ 360.726896][ T8978] do_syscall_64+0xf3/0x230
[ 360.731978][ T8978] entry_SYSCALL_64_after_hwframe+0x77/0x7f
[ 360.738203][ T8978] page last free pid 8932 tgid 8930 stack trace:
[ 360.744932][ T8978] free_unref_page+0xd22/0xea0
[ 360.750056][ T8978] vfree+0x186/0x2e0
[ 360.754447][ T8978] bpf_check+0x7daa/0x19630
[ 360.759581][ T8978] bpf_prog_load+0x1667/0x20f0
[ 360.764781][ T8978] __sys_bpf+0x4ee/0x810
[ 360.769481][ T8978] __x64_sys_bpf+0x7c/0x90
[ 360.774349][ T8978] do_syscall_64+0xf3/0x230
[ 360.779190][ T8978] entry_SYSCALL_64_after_hwframe+0x77/0x7f
[ 360.785680][ T8978] Modules linked in:
[ 360.790303][ T8978] CPU: 1 UID: 0 PID: 8978 Comm: syz.3.584 Not tainted 6.11.0-rc6-syzkaller-00183-gb831f83e40a2 #0
[ 360.800948][ T8978] Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 08/06/2024
[ 360.811056][ T8978] Call Trace:
[ 360.814367][ T8978] <TASK>
[ 360.817327][ T8978] dump_stack_lvl+0x241/0x360
[ 360.822051][ T8978] ? __pfx_dump_stack_lvl+0x10/0x10
[ 360.827292][ T8978] ? __pfx_print_modules+0x10/0x10
[ 360.832477][ T8978] bad_page+0x18e/0x200
[ 360.836687][ T8978] free_unref_page+0xe47/0xea0
[ 360.841504][ T8978] ? compound_order+0x1a/0x60
[ 360.846238][ T8978] skb_release_data+0x6b2/0x880
[ 360.851155][ T8978] sk_skb_reason_drop+0x1a5/0x3d0
[ 360.856235][ T8978] __netif_receive_skb_core+0x3edd/0x4570
[ 360.862030][ T8978] ? trace_call_bpf+0x613/0x8a0
[ 360.866928][ T8978] ? trace_call_bpf+0x613/0x8a0
[ 360.871832][ T8978] ? __pfx___netif_receive_skb_core+0x10/0x10
[ 360.877954][ T8978] ? __pfx_trace_call_bpf+0x10/0x10
[ 360.883200][ T8978] ? __pfx_trace_call_bpf+0x10/0x10
[ 360.888548][ T8978] ? mark_lock+0x9a/0x350
[ 360.892935][ T8978] ? perf_trace_run_bpf_submit+0x10b/0x180
[ 360.898792][ T8978] ? perf_trace_preemptirq_template+0x2d2/0x3f0
[ 360.905089][ T8978] ? irqentry_enter+0x39/0x60
[ 360.909829][ T8978] __netif_receive_skb_list_core+0x2b7/0x980
[ 360.916050][ T8978] ? lockdep_hardirqs_on+0x99/0x150
[ 360.921285][ T8978] ? __pfx___netif_receive_skb_list_core+0x10/0x10
[ 360.927908][ T8978] ? netif_receive_skb_list_internal+0x970/0xe30
[ 360.934260][ T8978] ? netif_receive_skb_list_internal+0x4e8/0xe30
[ 360.940714][ T8978] netif_receive_skb_list_internal+0xa51/0xe30
[ 360.946925][ T8978] ? netif_receive_skb_list_internal+0x4e8/0xe30
[ 360.953322][ T8978] ? __pfx_netif_receive_skb_list_internal+0x10/0x10
[ 360.960049][ T8978] ? __pfx_eth_type_trans+0x10/0x10
[ 360.965352][ T8978] ? __phys_addr+0xba/0x170
[ 360.969866][ T8978] ? build_skb_around+0x111/0x260
[ 360.974911][ T8978] ? __xdp_build_skb_from_frame+0x338/0x650
[ 360.980856][ T8978] netif_receive_skb_list+0x55/0x4b0
[ 360.986167][ T8978] bpf_test_run_xdp_live+0x1af6/0x2110
[ 360.991638][ T8978] ? bpf_dispatcher_change_prog+0xd8b/0xf10
[ 360.997569][ T8978] ? bpf_test_run_xdp_live+0x5bf/0x2110
[ 361.003126][ T8978] ? __pfx_bpf_test_run_xdp_live+0x10/0x10
[ 361.008944][ T8978] ? synchronize_rcu+0x11b/0x360
[ 361.013919][ T8978] ? __pfx_synchronize_rcu+0x10/0x10
[ 361.019246][ T8978] ? __pfx_bpf_dispatcher_change_prog+0x10/0x10
[ 361.025607][ T8978] ? __pfx_xdp_test_run_init_page+0x10/0x10
[ 361.031528][ T8978] ? bpf_prog_test_run_xdp+0x746/0x11b0
[ 361.037260][ T8978] ? bpf_prog_change_xdp+0x12/0x30
[ 361.042399][ T8978] bpf_prog_test_run_xdp+0x80e/0x11b0
[ 361.047821][ T8978] ? __pfx_bpf_prog_test_run_xdp+0x10/0x10
[ 361.053692][ T8978] ? __pfx_bpf_prog_test_run_xdp+0x10/0x10
[ 361.059702][ T8978] bpf_prog_test_run+0x33a/0x3b0
[ 361.064663][ T8978] __sys_bpf+0x48d/0x810
[ 361.068922][ T8978] ? __pfx___sys_bpf+0x10/0x10
[ 361.073696][ T8978] ? lockdep_hardirqs_on_prepare+0x43d/0x780
[ 361.079816][ T8978] __x64_sys_bpf+0x7c/0x90
[ 361.084250][ T8978] do_syscall_64+0xf3/0x230
[ 361.088855][ T8978] ? clear_bhb_loop+0x35/0x90
[ 361.093554][ T8978] entry_SYSCALL_64_after_hwframe+0x77/0x7f
[ 361.099477][ T8978] RIP: 0033:0x7f90d937def9
[ 361.103911][ T8978] 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 a8 ff ff ff f7 d8 64 89 01 48
[ 361.123535][ T8978] RSP: 002b:00007f90da180038 EFLAGS: 00000246 ORIG_RAX: 0000000000000141
[ 361.132052][ T8978] RAX: ffffffffffffffda RBX: 00007f90d9536058 RCX: 00007f90d937def9
[ 361.140056][ T8978] RDX: 0000000000000048 RSI: 0000000020000600 RDI: 000000000000000a
[ 361.148036][ T8978] RBP: 00007f90d93f0b76 R08: 0000000000000000 R09: 0000000000000000
[ 361.156015][ T8978] R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000000
[ 361.164079][ T8978] R13: 0000000000000000 R14: 00007f90d9536058 R15: 00007fff89b68ce8
[ 361.172081][ T8978] </TASK>
[ 361.175540][ T8978] Disabling lock debugging due to kernel taint
35 changes: 35 additions & 0 deletions pkg/report/testdata/linux/report/727
Original file line number Diff line number Diff line change
@@ -0,0 +1,35 @@
TITLE: BUG: Bad page state in hash_sendmsg

[ 35.932064][ T5991] wlan1: Creating new IBSS network, BSSID 50:50:50:50:50:50
[ 35.995178][ T6018] BUG: Bad page state in process syz-executor.0 pfn:1b317b
[ 35.997385][ T6018] page:00000000b430fc6f refcount:0 mapcount:0 mapping:0000000000000000 index:0x0 pfn:0x1b317b
[ 36.000175][ T6018] flags: 0x5ffc00000001000(reserved|node=0|zone=2|lastcpupid=0x7ff)
[ 36.002273][ T6018] page_type: 0xffffffff()
[ 36.003460][ T6018] raw: 05ffc00000001000 fffffc0005cc5ec8 fffffc0005cc5ec8 0000000000000000
[ 36.007695][ T6018] raw: 0000000000000000 0000000000000000 00000000ffffffff 0000000000000000
[ 36.010002][ T6018] page dumped because: PAGE_FLAGS_CHECK_AT_FREE flag(s) set
[ 36.011953][ T6018] Modules linked in:
[ 36.012969][ T6018] CPU: 0 PID: 6018 Comm: syz-executor.0 Not tainted 6.5.0-rc5-syzkaller-g6f09e57d8cf6 #0
[ 36.015567][ T6018] Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 07/12/2023
[ 36.018153][ T6018] Call trace:
[ 36.018992][ T6018] dump_backtrace+0x1b8/0x1e4
[ 36.020256][ T6018] show_stack+0x2c/0x44
[ 36.021336][ T6018] dump_stack_lvl+0xd0/0x124
[ 36.022575][ T6018] dump_stack+0x1c/0x28
[ 36.023621][ T6018] bad_page+0x1a4/0x1c4
[ 36.024713][ T6018] free_page_is_bad_report+0xf4/0x16c
[ 36.026129][ T6018] free_unref_page_prepare+0x988/0xadc
[ 36.027548][ T6018] free_unref_page+0x80/0x3dc
[ 36.028762][ T6018] __folio_put+0xd0/0x12c
[ 36.029926][ T6018] extract_iter_to_sg+0xb94/0x1c08
[ 36.031259][ T6018] hash_sendmsg+0x480/0xe84
[ 36.032439][ T6018] ____sys_sendmsg+0x56c/0x840
[ 36.033674][ T6018] __sys_sendmmsg+0x318/0x7d8
[ 36.034854][ T6018] __arm64_sys_sendmmsg+0xa0/0xbc
[ 36.036158][ T6018] invoke_syscall+0x98/0x2b8
[ 36.037379][ T6018] el0_svc_common+0x130/0x23c
[ 36.038638][ T6018] do_el0_svc+0x48/0x58
[ 36.039718][ T6018] el0_svc+0x58/0x16c
[ 36.040787][ T6018] el0t_64_sync_handler+0x84/0xfc
[ 36.042086][ T6018] el0t_64_sync+0x190/0x194
[ 36.045588][ T6018] Disabling lock debugging due to kernel taint
Loading

0 comments on commit 3cb3e3e

Please sign in to comment.