Re: spinlock recursion when running q800 emulation in qemu

[Finn Thain <fthain@linux-m68k.org>]

On Mon, 18 Mar 2024, Michael Schmitz wrote:

> Am 15.03.2024 um 20:24 schrieb Finn Thain:
> >
> > On Fri, 15 Mar 2024, Michael Schmitz wrote:
> >
> >>
> >> No luck with whatever I tried around signals, cache maintenance and 
> >> mm.
> >>
> >> The 'BUG: Bad rss-counter state' message suggests we're freeing the 
> >> same page ranges twice, sometimes in many cases. I cannot quite see 
> >> how preempting the kernel on interupt return would cause this. Signal 
> >> forcing process exit but process exiting before signal is received 
> >> due to preemption? But skipping preemption when a signal is pending 
> >> did not change anything in my tests...
> >>
> >> Running out of ideas here, sorry.
> >>
> >
> > FWIW, I found that the failure mode (with CONFIG_PREEMPT) changed 
> > significantly after I disabled hard irqs in do_IRQ() using the patch I 
> > sent on the 8th. In three stress-ng test runs, I got a soft lockup, a 
> > WARN from set_fc() and some CONFIG_DEBUG_LIST failures...
> 
> Yes, I do see that with your patch, too. I still see the old 'table 
> already free' bug, though.
> 
> As far as I can see, the set_fc warning is from access_error040 and is 
> part of the access error exception that is taken in interrupt context.
> 
> The question is basically - why is __free_one_page() called from 
> interrupt context? Did that also happen before Geert's preemption patch?
> 

I did see that set_fc() warning during the mmap stress testing I did a few 
years ago. The example below comes from 5.18.0-rc7-mac-00006-g210e04ff7681 
but a lot has changed since then and it may not be relevant. I stopped 
doing those tests when Al Viro fixed the bug I was chasing. When I get 
time I shall fire up a Quadra and try again with v6.8.

stress-ng: info:  [116] dispatching hogs: 1 mmap
[ 1673.480000] ------------[ cut here ]------------
[ 1673.480000] WARNING: CPU: 0 PID: 159 at ./arch/m68k/include/asm/processor.h:91 buserr_c+0x59a/0x99a
[ 1673.480000] Modules linked in:
[ 1673.480000] CPU: 0 PID: 159 Comm:  Not tainted 5.18.0-rc7-mac-00006-g210e04ff7681 #2
[ 1673.480000] Stack from 00a13dec:
[ 1673.480000]         00a13dec 0046b224 0046b224 00000000 00a13e08 003d7e16 0046b224 00a13e1c
[ 1673.480000]         0001c1b4 00000000 00a13e94 b6db6eaa 00a13e48 0001c240 00461323 0000005b
[ 1673.480000]         0000678c 00000009 00000000 00000000 00000505 b6db6db6 db6db6db 00a13e88
[ 1673.480000]         0000678c 00461323 0000005b 00000009 00000000 00000000 00989680 00000004
[ 1673.480000]         003d6a82 0000000c 003dbb98 00a1f780 004b0c0c 000496dc 00077359 00a13f0c
[ 1673.480000]         00002bcc 00a13e94 00010000 00000000 00989680 00000004 003d6a82 b6db6db6
[ 1673.480000] Call Trace: [<003d7e16>] dump_stack+0x10/0x16
[ 1673.480000]  [<0001c1b4>] __warn+0xc6/0xe8
[ 1673.480000]  [<0001c240>] warn_slowpath_fmt+0x6a/0x76
[ 1673.480000]  [<0000678c>] buserr_c+0x59a/0x99a
[ 1673.480000]  [<0000678c>] buserr_c+0x59a/0x99a
[ 1673.480000]  [<003d6a82>] _printk+0x0/0x16
[ 1673.480000]  [<003dbb98>] down_read+0x0/0xdc
[ 1673.480000]  [<000496dc>] __irq_wake_thread+0x0/0x44
[ 1673.480000]  [<00077359>] ___bpf_prog_run+0x18b/0x20e4
[ 1673.480000]  [<00002bcc>] buserr+0x20/0x28
[ 1673.480000]  [<00010000>] LP1CONT1+0x4a/0x7c
[ 1673.480000]  [<003d6a82>] _printk+0x0/0x16
[ 1673.480000]  [<00050005>] dma_coherent_ok+0x1d/0xb8
[ 1673.480000]  [<00012704>] tblpre+0x594/0x700
[ 1673.480000]  [<0001c1d6>] warn_slowpath_fmt+0x0/0x76
[ 1673.480000]  [<00040e08>] account_system_time+0x74/0xca
[ 1673.480000]  [<0004113e>] account_process_tick+0x30/0xb0
[ 1673.480000]  [<00010000>] LP1CONT1+0x4a/0x7c
[ 1673.480000]  [<00053a6e>] update_process_times+0x36/0xae
[ 1673.480000]  [<00060bdc>] legacy_timer_tick+0x64/0x6c
[ 1673.480000]  [<00008fa4>] via_timer_handler+0x1e/0x24
[ 1673.480000]  [<00049756>] __handle_irq_event_percpu+0x36/0xd8
[ 1673.480000]  [<00002600>] name_to_dev_t+0x1a4/0x3f8
[ 1673.480000]  [<003d9d40>] yield_to+0x88/0x8c
[ 1673.480000]  [<0004980c>] handle_irq_event_percpu+0x14/0x52
[ 1673.480000]  [<0004986c>] handle_irq_event+0x22/0x36
[ 1673.480000]  [<0004cf1a>] handle_simple_irq+0x4e/0x7c
[ 1673.480000]  [<00048f3e>] generic_handle_irq+0x3c/0x4a
[ 1673.480000]  [<00008e3c>] via1_irq+0x7e/0x96
[ 1673.480000]
[ 1673.480000] ---[ end trace 0000000000000000 ]---