On Thu, 29 Feb 2024 17:11:28 +0000 Christophe Leroy <christophe.leroy@xxxxxxxxxx> wrote: > Le 29/02/2024 à 02:09, Erhard Furtner a écrit : > > On Mon, 12 Dec 2022 14:31:35 +1000 > > "Nicholas Piggin" <npiggin@xxxxxxxxx> 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
Attachment:
config_610-rc4_g4-
Description: Binary data
Attachment:
dmesg_610-rc4_g4_03
Description: Binary data
