BUG: Bad page map in process init pte:c0ab684c pmd:01182000 (on a PowerMac G4 DP)
Erhard Furtner
erhard_f at mailbox.org
Thu Jun 20 08:42:37 AEST 2024
On Thu, 29 Feb 2024 17:11:28 +0000
Christophe Leroy <christophe.leroy at csgroup.eu> wrote:
> Le 29/02/2024 à 02:09, Erhard Furtner a écrit :
> > On Mon, 12 Dec 2022 14:31:35 +1000
> > "Nicholas Piggin" <npiggin at gmail.com> wrote:
> >
> >> On Thu Dec 1, 2022 at 7:44 AM AEST, Erhard F. wrote:
> >>> Getting this at boot sometimes, but not always (PowerMac G4 DP, kernel 6.0.9):
> >>>
> >>> [...]
> >>> Freeing unused kernel image (initmem) memory: 1328K
> >>> Checked W+X mappings: passed, no W+X pages found
> >>> rodata_test: all tests were successful
> >>> Run /sbin/init as init process
> >>> _swap_info_get: Bad swap file entry 24c0ab68
> >>> BUG: Bad page map in process init pte:c0ab684c pmd:01182000
> >>
> >> Have you run memtest on the system? Are the messages related to a
> >> kernel upgrade? This and your KASAN bugs look possibly like random
> >> corruption.
> >>
> >> Although with that KASAN one it's strange that kernfs_node_cache
> >> was involved both times, it's strange that page tables are pointing
> >> to that same slab memory. It could be a page table page use-after
> >> -free maybe? Maybe with the page table fragment code. I'm sure other
> >> people would have hit that before though, so I don't know what to
> >> suggest.
> >>
> >> Thanks,
> >> Nick
> >
> > Revisited the issue on kernel v6.8-rc6 and I can still reproduce it.
> >
> > Short summary as my last post was over a year ago:
> > (x) I get this memory corruption only when CONFIG_VMAP_STACK=y and CONFIG_SMP=y is enabled.
> > (x) I don't get this memory corruption when only one of the above is enabled. ^^
> > (x) memtester says the 2 GiB RAM in my G4 DP are fine.
> > (x) I don't get this issue on my G5 11,2 or Talos II.
> > (x) "stress -m 2 --vm-bytes 965M" provokes the issue in < 10 secs. (https://salsa.debian.org/debian/stress)
> >
> > For the test I used CONFIG_KASAN_INLINE=y for v6.8-rc6 and debug_pagealloc=on, page_owner=on and got this dmesg:
> >
> > [...]
> > pagealloc: memory corruption
> > f5fcfff0: 00 00 00 00 ....
> > CPU: 1 PID: 1788 Comm: stress Tainted: G B 6.8.0-rc6-PMacG4 #15
> > Hardware name: PowerMac3,6 7455 0x80010303 PowerMac
> > Call Trace:
> > [f3bfbac0] [c162a8e8] dump_stack_lvl+0x60/0x94 (unreliable)
> > [f3bfbae0] [c04edf9c] __kernel_unpoison_pages+0x1e0/0x1f0
> > [f3bfbb30] [c04a8aa0] post_alloc_hook+0xe0/0x174
> > [f3bfbb60] [c04a8b58] prep_new_page+0x24/0xbc
> > [f3bfbb80] [c04abcc4] get_page_from_freelist+0xcd0/0xf10
> > [f3bfbc50] [c04aecd8] __alloc_pages+0x204/0xe2c
> > [f3bfbda0] [c04b07a8] __folio_alloc+0x18/0x88
> > [f3bfbdc0] [c0461a10] vma_alloc_zeroed_movable_folio.isra.0+0x2c/0x6c
> > [f3bfbde0] [c046bb90] handle_mm_fault+0x91c/0x19ac
> > [f3bfbec0] [c0047b8c] ___do_page_fault+0x93c/0xc14
> > [f3bfbf10] [c0048278] do_page_fault+0x28/0x60
> > [f3bfbf30] [c000433c] DataAccess_virt+0x124/0x17c
> > --- interrupt: 300 at 0xbe30d8
> > NIP: 00be30d8 LR: 00be30b4 CTR: 00000000
> > REGS: f3bfbf40 TRAP: 0300 Tainted: G B (6.8.0-rc6-PMacG4)
> > MSR: 0000d032 <EE,PR,ME,IR,DR,RI> CR: 20882464 XER: 00000000
> > DAR: 88c7a010 DSISR: 42000000
> > GPR00: 00be30b4 af8397d0 a78436c0 6b2ee010 3c500000 20224462 fe77f7e1 00b00264
> > GPR08: 1d98d000 1d98c000 00000000 40ae256a 20882262 00bffff4 00000000 00000000
> > GPR16: 00000000 00000002 00000000 0000005a 40802262 80002262 40002262 00c000a4
> > GPR24: ffffffff ffffffff 3c500000 00000000 00000000 6b2ee010 00c07d64 00001000
> > NIP [00be30d8] 0xbe30d8
> > LR [00be30b4] 0xbe30b4
> > --- interrupt: 300
> > page:ef4bd92c refcount:1 mapcount:0 mapping:00000000 index:0x1 pfn:0x310b3
> > flags: 0x80000000(zone=2)
> > page_type: 0xffffffff()
> > raw: 80000000 00000100 00000122 00000000 00000001 00000000 ffffffff 00000001
> > raw: 00000000
> > page dumped because: pagealloc: corrupted page details
> > page_owner info is not present (never set?)
> > swapper/1: page allocation failure: order:0, mode:0x820(GFP_ATOMIC), nodemask=(null),cpuset=/,mems_allowed=0
> > CPU: 1 PID: 0 Comm: swapper/1 Tainted: G B 6.8.0-rc6-PMacG4 #15
> > Hardware name: PowerMac3,6 7455 0x80010303 PowerMac
> > Call Trace:
> > [f101b9d0] [c162a8e8] dump_stack_lvl+0x60/0x94 (unreliable)
> > [f101b9f0] [c04ae948] warn_alloc+0x154/0x2e0
> > [f101bab0] [c04af030] __alloc_pages+0x55c/0xe2c
> > SLUB: Unable to allocate memory on node -1, gfp=0x820(GFP_ATOMIC)
> > cache: skbuff_head_cache, object size: 176, buffer size: 288, default order: 0, min order: 0
> > node 0: slabs: 509, objs: 7126, free: 0
> > SLUB: Unable to allocate memory on node -1, gfp=0x820(GFP_ATOMIC)
> > cache: skbuff_head_cache, object size: 176, buffer size: 288, default order: 0, min order: 0
> > node 0: slabs: 509, objs: 7126, free: 0
> > SLUB: Unable to allocate memory on node -1, gfp=0x820(GFP_ATOMIC)
> > cache: skbuff_head_cache, object size: 176, buffer size: 288, default order: 0, min order: 0
> > node 0: slabs: 509, objs: 7126, free: 0
> > SLUB: Unable to allocate memory on node -1, gfp=0x820(GFP_ATOMIC)
> > cache: skbuff_head_cache, object size: 176, buffer size: 288, default order: 0, min order: 0
> > node 0: slabs: 509, objs: 7126, free: 0
> > SLUB: Unable to allocate memory on node -1, gfp=0x820(GFP_ATOMIC)
> > cache: skbuff_head_cache, object size: 176, buffer size: 288, default order: 0, min order: 0
> > node 0: slabs: 509, objs: 7126, free: 0
> > SLUB: Unable to allocate memory on node -1, gfp=0x820(GFP_ATOMIC)
> > cache: skbuff_head_cache, object size: 176, buffer size: 288, default order: 0, min order: 0
> > node 0: slabs: 509, objs: 7126, free: 0
> > SLUB: Unable to allocate memory on node -1, gfp=0x820(GFP_ATOMIC)
> > cache: skbuff_head_cache, object size: 176, buffer size: 288, default order: 0, min order: 0
> > node 0: slabs: 509, objs: 7126, free: 0
> > SLUB: Unable to allocate memory on node -1, gfp=0x820(GFP_ATOMIC)
> > cache: skbuff_head_cache, object size: 176, buffer size: 288, default order: 0, min order: 0
> > node 0: slabs: 509, objs: 7126, free: 0
> > SLUB: Unable to allocate memory on node -1, gfp=0x820(GFP_ATOMIC)
> > cache: skbuff_head_cache, object size: 176, buffer size: 288, default order: 0, min order: 0
> > node 0: slabs: 509, objs: 7126, free: 0
> > SLUB: Unable to allocate memory on node -1, gfp=0x820(GFP_ATOMIC)
> > cache: skbuff_head_cache, object size: 176, buffer size: 288, default order: 0, min order: 0
> > node 0: slabs: 509, objs: 7126, free: 0
> > [...]
Turned out the "SLUB: Unable to allocate memory on node -1, gfp=0x820(GFP_ATOMIC)" I reported seems a different issue (https://lore.kernel.org/all/20240515224524.1c8befbe@yea/) not related to the page corruption issue I originally reported in this thread.
The "pagealloc: memory corruption" remains however as of kernel v6.10-rc4.
I reduced and simplified the kernel .config (disabled non-essential drivers, PREEMPT_NONE=y, disabled zswap, disabled lru_gen, etc.) to reduce contributing factors as much as possible. And finally I am getting something meaningful out of KCSAN:
[...]
BUG: KCSAN: data-race in __hrtimer_run_queues / hrtimer_active
read to 0xeefc7ad0 of 4 bytes by interrupt on cpu 1:
hrtimer_active+0xb0/0x100
task_tick_fair+0x7c/0x80
sched_tick+0x7c/0xd0
update_process_times+0xc8/0x120
tick_nohz_handler+0x1ac/0x270
__hrtimer_run_queues+0x174/0x1dc
hrtimer_interrupt+0x168/0x350
timer_interrupt+0x108/0x178
Decrementer_virt+0x100/0x104
0xffffffff
kcsan_setup_watchpoint+0x2dc/0x4a8
memchr_inv+0x100/0x188
__kernel_unpoison_pages+0xe0/0x1a8
post_alloc_hook+0xa4/0x10c
prep_new_page+0x24/0x5c
get_page_from_freelist+0x238/0x5e0
__alloc_pages_noprof+0xec/0x7d0
__folio_alloc_noprof+0x14/0x30
vma_alloc_zeroed_movable_folio.isra.0+0x34/0x7c
handle_mm_fault+0x368/0xd00
___do_page_fault+0x3ac/0x504
do_page_fault+0x20/0x38
DataAccess_virt+0x11c/0x174
write to 0xeefc7ad0 of 4 bytes by interrupt on cpu 0:
__hrtimer_run_queues+0x1d0/0x1dc
hrtimer_interrupt+0x168/0x350
timer_interrupt+0x108/0x178
Decrementer_virt+0x100/0x104
0x67e51595
mas_start+0x64/0x1b0
mas_state_walk+0x24/0x78
mt_find+0xa8/0x20c
find_vma+0x44/0x68
lock_mm_and_find_vma+0x44/0x1a8
___do_page_fault+0x33c/0x504
do_page_fault+0x20/0x38
DataAccess_virt+0x11c/0x174
Reported by Kernel Concurrency Sanitizer on:
CPU: 0 PID: 1452 Comm: stress Not tainted 6.10.0-rc4-PMacG4 #28
Hardware name: PowerMac3,6 7455 0x80010303 PowerMac
==================================================================
==================================================================
BUG: KCSAN: data-race in __hrtimer_run_queues / hrtimer_active
read to 0xeefc7ad0 of 4 bytes by interrupt on cpu 1:
hrtimer_active+0xb0/0x100
task_tick_fair+0x7c/0x80
sched_tick+0x7c/0xd0
update_process_times+0xc8/0x120
tick_nohz_handler+0x1ac/0x270
__hrtimer_run_queues+0x174/0x1dc
hrtimer_interrupt+0x168/0x350
timer_interrupt+0x108/0x178
Decrementer_virt+0x100/0x104
0x0
kcsan_setup_watchpoint+0x2dc/0x4a8
memchr_inv+0x100/0x188
__kernel_unpoison_pages+0xe0/0x1a8
post_alloc_hook+0xa4/0x10c
prep_new_page+0x24/0x5c
get_page_from_freelist+0x238/0x5e0
__alloc_pages_noprof+0xec/0x7d0
__folio_alloc_noprof+0x14/0x30
vma_alloc_zeroed_movable_folio.isra.0+0x34/0x7c
handle_mm_fault+0x368/0xd00
___do_page_fault+0x3ac/0x504
do_page_fault+0x20/0x38
DataAccess_virt+0x11c/0x174
write to 0xeefc7ad0 of 4 bytes by interrupt on cpu 0:
__hrtimer_run_queues+0x1d0/0x1dc
hrtimer_interrupt+0x168/0x350
timer_interrupt+0x108/0x178
Decrementer_virt+0x100/0x104
memchr_inv+0x100/0x188
__kernel_unpoison_pages+0xe0/0x1a8
post_alloc_hook+0xa4/0x10c
prep_new_page+0x24/0x5c
get_page_from_freelist+0x238/0x5e0
__alloc_pages_noprof+0xec/0x7d0
__folio_alloc_noprof+0x14/0x30
vma_alloc_zeroed_movable_folio.isra.0+0x34/0x7c
handle_mm_fault+0x368/0xd00
___do_page_fault+0x3ac/0x504
do_page_fault+0x20/0x38
DataAccess_virt+0x11c/0x174
Reported by Kernel Concurrency Sanitizer on:
CPU: 0 PID: 1452 Comm: stress Not tainted 6.10.0-rc4-PMacG4 #28
Hardware name: PowerMac3,6 7455 0x80010303 PowerMac
==================================================================
pagealloc: memory corruption
fffcfff0: 00 00 00 00 ....
CPU: 1 PID: 1453 Comm: stress Not tainted 6.10.0-rc4-PMacG4 #28
Hardware name: PowerMac3,6 7455 0x80010303 PowerMac
Call Trace:
[f2f59c60] [c09ba37c] dump_stack_lvl+0x78/0xac (unreliable)
[f2f59c80] [c09ba3d0] dump_stack+0x20/0x34
[f2f59c90] [c02624a8] __kernel_unpoison_pages+0x198/0x1a8
[f2f59ce0] [c0247168] post_alloc_hook+0xa4/0x10c
[f2f59d00] [c02471f4] prep_new_page+0x24/0x5c
[f2f59d20] [c0247c5c] get_page_from_freelist+0x238/0x5e0
[f2f59da0] [c0249720] __alloc_pages_noprof+0xec/0x7d0
[f2f59e40] [c024a39c] __folio_alloc_noprof+0x14/0x30
[f2f59e50] [c0223104] vma_alloc_zeroed_movable_folio.isra.0+0x34/0x7c
[f2f59e70] [c02288f0] handle_mm_fault+0x368/0xd00
[f2f59ef0] [c0031488] ___do_page_fault+0x3ac/0x504
[f2f59f30] [c00317f8] do_page_fault+0x20/0x38
[f2f59f40] [c0004324] DataAccess_virt+0x11c/0x174
--- interrupt: 300 at 0x8c3008
NIP: 008c3008 LR: 008c2fe8 CTR: a78e4a68
REGS: f2f59f50 TRAP: 0300 Not tainted (6.10.0-rc4-PMacG4)
MSR: 0000d032 <EE,PR,ME,IR,DR,RI> CR: 20882464 XER: 00000000
DAR: 8f860010 DSISR: 42000000
GPR00: 008c2fe8 afd8fa70 a7922780 6c2ce010 3b600000 00000000 00000003 007e01e4
GPR08: 23593000 23592000 00000000 a78e4a68 20882462 008dff68 00000000 40882462
GPR16: ffffffff 00000000 00000002 00000000 00000001 00000000 008e0018 00000001
GPR24: ffffffff ffffffff 3b600000 0000005a 6c2ce010 00000000 008e7cd0 00001000
NIP [008c3008] 0x8c3008
LR [008c2fe8] 0x8c2fe8
--- interrupt: 300
page: refcount:1 mapcount:0 mapping:00000000 index:0x0 pfn:0x3106d
flags: 0x80000000(zone=2)
raw: 80000000 00000100 00000122 00000000 00000000 00000000 ffffffff 00000001
page dumped because: pagealloc: corrupted page details
[...]
'stress' mentioned by KCSAN is the process I use to trigger the page corruption via "stress -m 2 --vm-bytes 950M".
I tried this several times and "BUG: KCSAN: data-race in __hrtimer_run_queues / hrtimer_active" repeatedly shows up in dmesg shortly before the page corruption, though not always. Sometimes I got instead:
[...]
BUG: KCSAN: data-race in alloc_tag_restore / alloc_tag_save
read to 0xc3282278 of 4 bytes by interrupt on cpu 0:
alloc_tag_save+0x2c/0x64
__alloc_skb+0x130/0x208
__netdev_alloc_skb+0x4c/0x2a0
gem_poll+0x12d4/0x16b8
__napi_poll.constprop.0+0x64/0x264
net_rx_action+0x2a4/0x4b8
handle_softirqs+0x280/0x2fc
do_softirq_own_stack+0x70/0x90
do_softirq_own_stack+0x60/0x90
__irq_exit_rcu+0x88/0x118
irq_exit+0x10/0x20
interrupt_async_exit_prepare.isra.0+0x18/0x2c
do_IRQ+0x24/0x2c
HardwareInterrupt_virt+0x100/0x104
folios_put_refs+0xb0/0x1ec
udelay+0x1c/0x2c
kcsan_setup_watchpoint+0x2dc/0x4a8
alloc_tag_restore+0x54/0x78
folio_alloc_noprof.constprop.0+0x68/0x8c
vma_alloc_zeroed_movable_folio.isra.0+0x4c/0xac
handle_mm_fault+0x368/0xd1c
___do_page_fault+0x3ac/0x514
do_page_fault+0x20/0x38
DataAccess_virt+0x11c/0x174
write to 0xc3282278 of 4 bytes by task 1572 on cpu 0:
alloc_tag_restore+0x54/0x78
folio_alloc_noprof.constprop.0+0x68/0x8c
vma_alloc_zeroed_movable_folio.isra.0+0x4c/0xac
handle_mm_fault+0x368/0xd1c
___do_page_fault+0x3ac/0x514
do_page_fault+0x20/0x38
DataAccess_virt+0x11c/0x174
Reported by Kernel Concurrency Sanitizer on:
CPU: 0 PID: 1572 Comm: stress Not tainted 6.10.0-rc4-PMacG4 #23
Hardware name: PowerMac3,6 7455 0x80010303 PowerMac
[...]
Full dmesg and kernel .config attached.
Regards,
Erhard
-------------- next part --------------
A non-text attachment was scrubbed...
Name: config_610-rc4_g4-
Type: application/octet-stream
Size: 83129 bytes
Desc: not available
URL: <http://lists.ozlabs.org/pipermail/linuxppc-dev/attachments/20240620/defe1311/attachment-0002.obj>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: dmesg_610-rc4_g4_03
Type: application/octet-stream
Size: 61380 bytes
Desc: not available
URL: <http://lists.ozlabs.org/pipermail/linuxppc-dev/attachments/20240620/defe1311/attachment-0003.obj>
More information about the Linuxppc-dev
mailing list