public inbox for linux-m68k@lists.linux-m68k.org
 help / color / mirror / Atom feed
From: Michael Schmitz <schmitzmic@gmail.com>
To: Finn Thain <fthain@linux-m68k.org>
Cc: Geert Uytterhoeven <geert@linux-m68k.org>,
	linux-m68k@lists.linux-m68k.org
Subject: Re: Spinlock debug, was Re: [PATCH RFC] m68k: skip kernel premption if interrupts were disabled
Date: Sun, 31 Mar 2024 19:14:20 +1300	[thread overview]
Message-ID: <548cf7b0-1e9d-b6ca-29b8-81dac9c115c1@gmail.com> (raw)
In-Reply-To: <181ac173-38c9-a502-84d5-4cc1d3ed6335@linux-m68k.org>

[-- Attachment #1: Type: text/plain, Size: 747 bytes --]

Hi Finn,

Am 30.03.2024 um 19:23 schrieb Finn Thain:
> On Sat, 30 Mar 2024, Michael Schmitz wrote:
>
>>
>> The MFP timer C is not reentered in 66 boots even though I've seen it
>> appear in the stack trace of 8 recursion warnings.
>>
>
> The spinlock recursion warning gives the address of the spinlock. Did you
> figure out which spinlock it is? Also, did you capture all 8 backtraces?

The lock is that in 'runqueues', the single struct rq in use on a single 
processor system.

That much was clear from the backtrace and looking at the code in 
scheduler_tick() before.

I've attached all eight backtraces - the stack contents only varies in a 
few positions, mostly explainable by differences in the initial stack 
pointer.

Cheers,

	Michael

[-- Attachment #2: spinlockdebug-74-traces.txt --]
[-- Type: text/plain, Size: 13671 bytes --]

BUG: spinlock recursion on CPU#0, swapper/1
 lock: 0x447600, .magic: dead4ead, .owner: swapper/1, .owner_cpu: 0
CPU: 0 PID: 1 Comm: swapper Not tainted 6.8.0-rc7-atari-fpuemu-spinlocktest+ #1775
Stack from 00831e98:
        00831e98 003e766e 003e766e 00000000 0000000d 00335630 003e766e 0003aac6
        00447600 003dc464 00830000 000321a6 00447600 0083c000 00831ee0 000321cc
        00447600 00000000 00831eec 000335be 00814080 0003fdea 00055464 00002604
        00006e16 00000000 00000000 0003fe5e 0000000d 00000000 00000000 00000000
        00443048 0032c472 0047aa4c 0047aaa8 00000000 00000000 0003fef6 0047aa4c
        00000000 0047aa4c 0003ff4e 0047aa4c 0047aaa8 0047aa4c 0047aaa8 0047aa4c
Call Trace: [<00335630>] dump_stack+0xc/0x10
 [<0003aac6>] do_raw_spin_lock+0x34/0x58
 [<000321a6>] raw_spin_rq_lock_nested+0x24/0x38
 [<000321cc>] raw_spin_rq_lock.constprop.135+0x12/0x18
 [<000335be>] scheduler_tick+0x10/0x66
 [<0003fdea>] __irq_wake_thread+0x0/0x40
 [<00055464>] update_process_times+0x5e/0x66
 [<00002604>] ret_from_kernel_thread+0x4/0x14
 [<00006e16>] mfp_timer_c_handler+0x5a/0x70
 [<0003fe5e>] __handle_irq_event_percpu+0x34/0xbc
 [<0032c472>] sprintf+0x0/0x24
 [<0003fef6>] handle_irq_event_percpu+0x10/0x3a
 [<0003ff4e>] handle_irq_event+0x2e/0x54
 [<000424f6>] handle_simple_irq+0x56/0x66
 [<00335976>] kernel_init+0x0/0xf2
 [<0003fa00>] handle_irq_desc+0x1e/0x28
 [<000028c0>] do_IRQ+0x20/0x32
 [<000027f4>] user_irqvec_fixup+0xc/0x14
 [<0032c472>] sprintf+0x0/0x24
 [<00002600>] ret_from_kernel_thread+0x0/0x14

RCU Tasks: Setting shift to 0 and lim to 1 rcu_task_cb_adjust=1.
RCU Tasks Trace: Setting shift to 0 and lim to 1 rcu_task_cb_adjust=1.
--
BUG: spinlock recursion on CPU#0, pool_workqueue_/3
 lock: 0x447600, .magic: dead4ead, .owner: pool_workqueue_/3, .owner_cpu: 0
CPU: 0 PID: 3 Comm: pool_workqueue_ Not tainted 6.8.0-rc7-atari-fpuemu-spinlocktest+ #1775
Stack from 00837e98:
        00837e98 003e766e 003e766e 00000000 0000000d 00335630 003e766e 0003aac6
        00447600 003dc464 00836000 000321a6 00447600 0083cc20 00837ee0 000321cc
        00447600 00000000 00837eec 000335be 00814080 0003fdea 00055464 00002604
        00006e16 00000000 00000000 0003fe5e 0000000d 00000000 00000000 00339ee0
        0033a016 000183f2 0047aa4c 0047aaa8 00000000 00000000 0003fef6 0047aa4c
        00000000 0047aa4c 0003ff4e 0047aa4c 0047aaa8 0047aa4c 0047aaa8 0047aa4c
Call Trace: [<00335630>] dump_stack+0xc/0x10
 [<0003aac6>] do_raw_spin_lock+0x34/0x58
 [<000321a6>] raw_spin_rq_lock_nested+0x24/0x38
 [<000321cc>] raw_spin_rq_lock.constprop.135+0x12/0x18
 [<000335be>] scheduler_tick+0x10/0x66
 [<0003fdea>] __irq_wake_thread+0x0/0x40
 [<00055464>] update_process_times+0x5e/0x66
 [<00002604>] ret_from_kernel_thread+0x4/0x14
 [<00006e16>] mfp_timer_c_handler+0x5a/0x70
 [<0003fe5e>] __handle_irq_event_percpu+0x34/0xbc
 [<00339ee0>] _raw_spin_lock+0x0/0x22
 [<0033a016>] _raw_spin_unlock+0x0/0x32
 [<000183f2>] kernel_thread+0x0/0x6c
 [<0003fef6>] handle_irq_event_percpu+0x10/0x3a
 [<0003ff4e>] handle_irq_event+0x2e/0x54
 [<000424f6>] handle_simple_irq+0x56/0x66
 [<0002de6e>] kthread+0x0/0xd4
 [<0003fa00>] handle_irq_desc+0x1e/0x28
 [<000028c0>] do_IRQ+0x20/0x32
 [<000027f4>] user_irqvec_fixup+0xc/0x14
 [<00339ee0>] _raw_spin_lock+0x0/0x22
 [<0033a016>] _raw_spin_unlock+0x0/0x32
 [<000183f2>] kernel_thread+0x0/0x6c
--
BUG: spinlock recursion on CPU#0, swapper/2
 lock: 0x447600, .magic: dead4ead, .owner: swapper/2, .owner_cpu: 0
CPU: 0 PID: 2 Comm: swapper Not tainted 6.8.0-rc7-atari-fpuemu-spinlocktest+ #1775
Stack from 00835e98:
        00835e98 003e766e 003e766e 00000000 0000000d 00335630 003e766e 0003aac6
        00447600 003dc464 00834000 000321a6 00447600 0083c610 00835ee0 000321cc
        00447600 00000000 00835eec 000335be 00814080 0003fdea 00055464 00002604
        00006e16 00000000 00000000 0003fe5e 0000000d 00000000 00000000 00831f10
        00000102 0032c472 0047aa4c 0047aaa8 00000000 00000000 0003fef6 0047aa4c
        00000000 0047aa4c 0003ff4e 0047aa4c 0047aaa8 0047aa4c 0047aaa8 0047aa4c
Call Trace: [<00335630>] dump_stack+0xc/0x10
 [<0003aac6>] do_raw_spin_lock+0x34/0x58
 [<000321a6>] raw_spin_rq_lock_nested+0x24/0x38
 [<000321cc>] raw_spin_rq_lock.constprop.135+0x12/0x18
 [<000335be>] scheduler_tick+0x10/0x66
 [<0003fdea>] __irq_wake_thread+0x0/0x40
 [<00055464>] update_process_times+0x5e/0x66
 [<00002604>] ret_from_kernel_thread+0x4/0x14
 [<00006e16>] mfp_timer_c_handler+0x5a/0x70
 [<0003fe5e>] __handle_irq_event_percpu+0x34/0xbc
 [<0032c472>] sprintf+0x0/0x24
 [<0003fef6>] handle_irq_event_percpu+0x10/0x3a
 [<0003ff4e>] handle_irq_event+0x2e/0x54
 [<000424f6>] handle_simple_irq+0x56/0x66
 [<0002dfd2>] kthreadd+0x0/0x12a
 [<0003fa00>] handle_irq_desc+0x1e/0x28
 [<000028c0>] do_IRQ+0x20/0x32
 [<000027f4>] user_irqvec_fixup+0xc/0x14
 [<0032c472>] sprintf+0x0/0x24
 [<00002600>] ret_from_kernel_thread+0x0/0x14

RCU Tasks: Setting shift to 0 and lim to 1 rcu_task_cb_adjust=1.
RCU Tasks Trace: Setting shift to 0 and lim to 1 rcu_task_cb_adjust=1.
--
BUG: spinlock recursion on CPU#0, swapper/2
 lock: 0x447600, .magic: dead4ead, .owner: swapper/2, .owner_cpu: 0
CPU: 0 PID: 2 Comm: swapper Not tainted 6.8.0-rc7-atari-fpuemu-spinlocktest+ #1775
Stack from 00835e98:
        00835e98 003e766e 003e766e 00000000 0000000d 00335630 003e766e 0003aac6
        00447600 003dc464 00834000 000321a6 00447600 0083c610 00835ee0 000321cc
        00447600 00000000 00835eec 000335be 00814080 0003fdea 00055464 00002604
        00006e16 00000000 00000000 0003fe5e 0000000d 00000000 00000000 00831f10
        00000102 0032c472 0047aa4c 0047aaa8 00000000 00000000 0003fef6 0047aa4c
        00000000 0047aa4c 0003ff4e 0047aa4c 0047aaa8 0047aa4c 0047aaa8 0047aa4c
Call Trace: [<00335630>] dump_stack+0xc/0x10
 [<0003aac6>] do_raw_spin_lock+0x34/0x58
 [<000321a6>] raw_spin_rq_lock_nested+0x24/0x38
 [<000321cc>] raw_spin_rq_lock.constprop.135+0x12/0x18
 [<000335be>] scheduler_tick+0x10/0x66
 [<0003fdea>] __irq_wake_thread+0x0/0x40
 [<00055464>] update_process_times+0x5e/0x66
 [<00002604>] ret_from_kernel_thread+0x4/0x14
 [<00006e16>] mfp_timer_c_handler+0x5a/0x70
 [<0003fe5e>] __handle_irq_event_percpu+0x34/0xbc
 [<0032c472>] sprintf+0x0/0x24
 [<0003fef6>] handle_irq_event_percpu+0x10/0x3a
 [<0003ff4e>] handle_irq_event+0x2e/0x54
 [<000424f6>] handle_simple_irq+0x56/0x66
 [<0002dfd2>] kthreadd+0x0/0x12a
 [<0003fa00>] handle_irq_desc+0x1e/0x28
 [<000028c0>] do_IRQ+0x20/0x32
 [<000027f4>] user_irqvec_fixup+0xc/0x14
 [<0032c472>] sprintf+0x0/0x24
 [<00002600>] ret_from_kernel_thread+0x0/0x14

RCU Tasks: Setting shift to 0 and lim to 1 rcu_task_cb_adjust=1.
RCU Tasks Trace: Setting shift to 0 and lim to 1 rcu_task_cb_adjust=1.
--
BUG: spinlock recursion on CPU#0, swapper/2
 lock: 0x447600, .magic: dead4ead, .owner: swapper/2, .owner_cpu: 0
CPU: 0 PID: 2 Comm: swapper Not tainted 6.8.0-rc7-atari-fpuemu-spinlocktest+ #1775
Stack from 00835e98:
        00835e98 003e766e 003e766e 00000000 0000000d 00335630 003e766e 0003aac6
        00447600 003dc464 00834000 000321a6 00447600 0083c610 00835ee0 000321cc
        00447600 00000000 00835eec 000335be 00814080 0003fdea 00055464 00002604
        00006e16 00000000 00000000 0003fe5e 0000000d 00000000 00000000 00831f10
        00000102 0032c472 0047aa4c 0047aaa8 00000000 00000000 0003fef6 0047aa4c
        00000000 0047aa4c 0003ff4e 0047aa4c 0047aaa8 0047aa4c 0047aaa8 0047aa4c
Call Trace: [<00335630>] dump_stack+0xc/0x10
 [<0003aac6>] do_raw_spin_lock+0x34/0x58
 [<000321a6>] raw_spin_rq_lock_nested+0x24/0x38
 [<000321cc>] raw_spin_rq_lock.constprop.135+0x12/0x18
 [<000335be>] scheduler_tick+0x10/0x66
 [<0003fdea>] __irq_wake_thread+0x0/0x40
 [<00055464>] update_process_times+0x5e/0x66
 [<00002604>] ret_from_kernel_thread+0x4/0x14
 [<00006e16>] mfp_timer_c_handler+0x5a/0x70
 [<0003fe5e>] __handle_irq_event_percpu+0x34/0xbc
 [<0032c472>] sprintf+0x0/0x24
 [<0003fef6>] handle_irq_event_percpu+0x10/0x3a
 [<0003ff4e>] handle_irq_event+0x2e/0x54
 [<000424f6>] handle_simple_irq+0x56/0x66
 [<0002dfd2>] kthreadd+0x0/0x12a
 [<0003fa00>] handle_irq_desc+0x1e/0x28
 [<000028c0>] do_IRQ+0x20/0x32
 [<000027f4>] user_irqvec_fixup+0xc/0x14
 [<0032c472>] sprintf+0x0/0x24
 [<00002600>] ret_from_kernel_thread+0x0/0x14

RCU Tasks: Setting shift to 0 and lim to 1 rcu_task_cb_adjust=1.
RCU Tasks Trace: Setting shift to 0 and lim to 1 rcu_task_cb_adjust=1.
--
BUG: spinlock recursion on CPU#0, pool_workqueue_/3
 lock: 0x447600, .magic: dead4ead, .owner: pool_workqueue_/3, .owner_cpu: 0
CPU: 0 PID: 3 Comm: pool_workqueue_ Not tainted 6.8.0-rc7-atari-fpuemu-spinlocktest+ #1775
Stack from 00837e78:
        00837e78 003e766e 003e766e 00000000 0000000d 00335630 003e766e 0003aac6
        00447600 003dc464 00836000 000321a6 00447600 0083cc20 00837ec0 000321cc
        00447600 00000000 00837ecc 000335be 00814080 0003fdea 00055464 00002604
        00006e16 00000000 00000000 0003fe5e 0000000d 00000000 00000000 00339ee0
        0033a016 000183f2 0047aa4c 0047aaa8 00000000 00837fb4 0003fef6 0047aa4c
        00000000 0047aa4c 0003ff4e 0047aa4c 0047aaa8 0047aa4c 0047aaa8 0047aa4c
Call Trace: [<00335630>] dump_stack+0xc/0x10
 [<0003aac6>] do_raw_spin_lock+0x34/0x58
 [<000321a6>] raw_spin_rq_lock_nested+0x24/0x38
 [<000321cc>] raw_spin_rq_lock.constprop.135+0x12/0x18
 [<000335be>] scheduler_tick+0x10/0x66
 [<0003fdea>] __irq_wake_thread+0x0/0x40
 [<00055464>] update_process_times+0x5e/0x66
 [<00002604>] ret_from_kernel_thread+0x4/0x14
 [<00006e16>] mfp_timer_c_handler+0x5a/0x70
 [<0003fe5e>] __handle_irq_event_percpu+0x34/0xbc
 [<00339ee0>] _raw_spin_lock+0x0/0x22
 [<0033a016>] _raw_spin_unlock+0x0/0x32
 [<000183f2>] kernel_thread+0x0/0x6c
 [<0003fef6>] handle_irq_event_percpu+0x10/0x3a
 [<0003ff4e>] handle_irq_event+0x2e/0x54
 [<000424f6>] handle_simple_irq+0x56/0x66
 [<0003fa00>] handle_irq_desc+0x1e/0x28
 [<000028c0>] do_IRQ+0x20/0x32
 [<000027f4>] user_irqvec_fixup+0xc/0x14
 [<00339ee0>] _raw_spin_lock+0x0/0x22
 [<0033a016>] _raw_spin_unlock+0x0/0x32
 [<000183f2>] kernel_thread+0x0/0x6c
 [<0002de6e>] kthread+0x0/0xd4
--
BUG: spinlock recursion on CPU#0, swapper/1
 lock: 0x447600, .magic: dead4ead, .owner: swapper/1, .owner_cpu: 0
CPU: 0 PID: 1 Comm: swapper Not tainted 6.8.0-rc7-atari-fpuemu-spinlocktest+ #1775
Stack from 00831e98:
        00831e98 003e766e 003e766e 00000000 0000000d 00335630 003e766e 0003aac6
        00447600 003dc464 00830000 000321a6 00447600 0083c000 00831ee0 000321cc
        00447600 00000000 00831eec 000335be 00814080 0003fdea 00055464 00002604
        00006e16 00000000 00000000 0003fe5e 0000000d 00000000 00000000 00000000
        00443048 0032c472 0047aa4c 0047aaa8 00000000 00000000 0003fef6 0047aa4c
        00000000 0047aa4c 0003ff4e 0047aa4c 0047aaa8 0047aa4c 0047aaa8 0047aa4c
Call Trace: [<00335630>] dump_stack+0xc/0x10
 [<0003aac6>] do_raw_spin_lock+0x34/0x58
 [<000321a6>] raw_spin_rq_lock_nested+0x24/0x38
 [<000321cc>] raw_spin_rq_lock.constprop.135+0x12/0x18
 [<000335be>] scheduler_tick+0x10/0x66
 [<0003fdea>] __irq_wake_thread+0x0/0x40
 [<00055464>] update_process_times+0x5e/0x66
 [<00002604>] ret_from_kernel_thread+0x4/0x14
 [<00006e16>] mfp_timer_c_handler+0x5a/0x70
 [<0003fe5e>] __handle_irq_event_percpu+0x34/0xbc
 [<0032c472>] sprintf+0x0/0x24
 [<0003fef6>] handle_irq_event_percpu+0x10/0x3a
 [<0003ff4e>] handle_irq_event+0x2e/0x54
 [<000424f6>] handle_simple_irq+0x56/0x66
 [<00335976>] kernel_init+0x0/0xf2
 [<0003fa00>] handle_irq_desc+0x1e/0x28
 [<000028c0>] do_IRQ+0x20/0x32
 [<000027f4>] user_irqvec_fixup+0xc/0x14
 [<0032c472>] sprintf+0x0/0x24
 [<00002600>] ret_from_kernel_thread+0x0/0x14

RCU Tasks: Setting shift to 0 and lim to 1 rcu_task_cb_adjust=1.
RCU Tasks Trace: Setting shift to 0 and lim to 1 rcu_task_cb_adjust=1.
--
BUG: spinlock recursion on CPU#0, swapper/2
 lock: 0x447600, .magic: dead4ead, .owner: swapper/2, .owner_cpu: 0
CPU: 0 PID: 2 Comm: swapper Not tainted 6.8.0-rc7-atari-fpuemu-spinlocktest+ #1775
Stack from 00835e98:
        00835e98 003e766e 003e766e 00000000 0000000d 00335630 003e766e 0003aac6
        00447600 003dc464 00834000 000321a6 00447600 0083c610 00835ee0 000321cc
        00447600 00000000 00835eec 000335be 00814080 0003fdea 00055464 00002604
        00006e16 00000000 00000000 0003fe5e 0000000d 00000000 00000000 00831f10
        00000102 0032c472 0047aa4c 0047aaa8 00000000 00000000 0003fef6 0047aa4c
        00000000 0047aa4c 0003ff4e 0047aa4c 0047aaa8 0047aa4c 0047aaa8 0047aa4c
Call Trace: [<00335630>] dump_stack+0xc/0x10
 [<0003aac6>] do_raw_spin_lock+0x34/0x58
 [<000321a6>] raw_spin_rq_lock_nested+0x24/0x38
 [<000321cc>] raw_spin_rq_lock.constprop.135+0x12/0x18
 [<000335be>] scheduler_tick+0x10/0x66
 [<0003fdea>] __irq_wake_thread+0x0/0x40
 [<00055464>] update_process_times+0x5e/0x66
 [<00002604>] ret_from_kernel_thread+0x4/0x14
 [<00006e16>] mfp_timer_c_handler+0x5a/0x70
 [<0003fe5e>] __handle_irq_event_percpu+0x34/0xbc
 [<0032c472>] sprintf+0x0/0x24
 [<0003fef6>] handle_irq_event_percpu+0x10/0x3a
 [<0003ff4e>] handle_irq_event+0x2e/0x54
 [<000424f6>] handle_simple_irq+0x56/0x66
 [<0002dfd2>] kthreadd+0x0/0x12a
 [<0003fa00>] handle_irq_desc+0x1e/0x28
 [<000028c0>] do_IRQ+0x20/0x32
 [<000027f4>] user_irqvec_fixup+0xc/0x14
 [<0032c472>] sprintf+0x0/0x24
 [<00002600>] ret_from_kernel_thread+0x0/0x14

RCU Tasks: Setting shift to 0 and lim to 1 rcu_task_cb_adjust=1.
RCU Tasks Trace: Setting shift to 0 and lim to 1 rcu_task_cb_adjust=1.

  reply	other threads:[~2024-03-31  6:14 UTC|newest]

Thread overview: 21+ messages / expand[flat|nested]  mbox.gz  Atom feed  top
2024-03-22  1:48 [PATCH RFC] m68k: skip kernel premption if interrupts were disabled Michael Schmitz
     [not found] ` <fcabda73-4b16-ee2c-e993-2bfcf392a26a@linux-m68k.org>
     [not found]   ` <e89bf618-2fa8-7cbd-16ed-d021a9a7f740@gmail.com>
     [not found]     ` <948c12e4-e85f-a86c-ae95-a1eb03ca026d@gmail.com>
     [not found]       ` <40928e38-0de7-75a6-d5f7-8c913155da03@linux-m68k.org>
2024-03-23  6:32         ` Michael Schmitz
2024-03-25  6:41           ` Michael Schmitz
2024-03-25 22:28             ` Finn Thain
2024-03-25 22:31               ` Michael Schmitz
2024-03-26  0:41                 ` Finn Thain
2024-03-26  9:58                 ` Finn Thain
2024-03-26 19:59                   ` Michael Schmitz
2024-03-26 22:03                     ` Finn Thain
2024-03-26 22:35                       ` Michael Schmitz
2024-03-27  3:50                         ` Finn Thain
2024-03-27  6:56                           ` Michael Schmitz
2024-03-27 23:29                             ` Spinlock debug, was " Finn Thain
     [not found]                               ` <7aee9fd9-1c0e-4874-bb86-e512a7c0caa6@gmail.com>
2024-03-28  2:48                                 ` Finn Thain
2024-03-28 19:54                                   ` Michael Schmitz
2024-03-30  2:46                                     ` Michael Schmitz
2024-03-30  6:23                                       ` Finn Thain
2024-03-31  6:14                                         ` Michael Schmitz [this message]
2024-03-27  8:38                           ` Finn Thain
2024-03-27 22:59                             ` Michael Schmitz
2024-03-27  8:22                     ` Geert Uytterhoeven

Reply instructions:

You may reply publicly to this message via plain-text email
using any one of the following methods:

* Save the following mbox file, import it into your mail client,
  and reply-to-all from there: mbox

  Avoid top-posting and favor interleaved quoting:
  https://en.wikipedia.org/wiki/Posting_style#Interleaved_style

* Reply using the --to, --cc, and --in-reply-to
  switches of git-send-email(1):

  git send-email \
    --in-reply-to=548cf7b0-1e9d-b6ca-29b8-81dac9c115c1@gmail.com \
    --to=schmitzmic@gmail.com \
    --cc=fthain@linux-m68k.org \
    --cc=geert@linux-m68k.org \
    --cc=linux-m68k@lists.linux-m68k.org \
    /path/to/YOUR_REPLY

  https://kernel.org/pub/software/scm/git/docs/git-send-email.html

* If your mail client supports setting the In-Reply-To header
  via mailto: links, try the mailto: link
Be sure your reply has a Subject: header at the top and a blank line before the message body.
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox