Re: [PATCH tip/core/rcu 3/3] srcu: Make early-boot call_srcu() reuse workqueue lists

Paul E. McKenney
2018-08-30T17:35:19Z

On Thu, Aug 30, 2018 at 12:44:44PM -0400, Steven Rostedt wrote:
> On Wed, 29 Aug 2018 20:23:15 -0700
> "Paul E. McKenney" <paulmck@linux.vnet.ibm.com> wrote:
>
> > > > Glad you like it! Does it actually work for you? ;-)
> > >
> > > Oh, you want me to actually test it too? ;-)
> >
> > ;-) ;-) ;-)
> >
> > > I'll try to add that in my todo list tomorrow.
> >
> > Much appreciated!
>
> I reverted the change that prevents calling call_srcu() early:
>
> I checked out v4.19-rc1 and applied these three patches, then did:
>
> git show f8a79d5c7ef47c62d97a30e16064caf2ef91f648 | patch -p1 -R
>
> But still triggered the following:
>
> WARNING: CPU: 0 PID: 0 at /work/git/linux-trace.git/kernel/rcu/srcutree.c:242 check_init_srcu_struct+0x85/0x90

Gah!!! I needed to have removed that WARN_ON_ONCE(), didn't I?
In fact, I should have removed that once I started using workqueues,
quite some time back.

Thank you even more for testing this!!! Glad I asked. ;-)

Now to figure out why my testing didn't hit this... I do invoke
call_srcu() at rcu_init() time and verify that the callback is
eventually invoked. A printk() placed there really does print...

Thanx, Paul

> Modules linked in:
> CPU: 0 PID: 0 Comm: swapper/0 Not tainted 4.19.0-rc1-test+ #1194
> Hardware name: Hewlett-Packard HP Compaq Pro 6300 SFF/339A, BIOS K01 v03.03 07/14/2016
> RIP: 0010:check_init_srcu_struct+0x85/0x90
> Code: 16 25 00 f6 83 70 06 00 00 03 74 0d be 01 00 00 00 48 89 df e8 6c f6 ff ff 5b 4c 89 ee 4c 89 e7 5d 41 5c 41 5d e9 db 4a d7 00 <0f> 0b eb 9a 0f 1f 80 00 00 00 00 0f 1f 44 00 00 41 57 48 8d 87 90
> RSP: 0000:ffff8800d3c07d90 EFLAGS: 00010246
> RAX: 0000000000000000 RBX: ffffffffb9d4d960 RCX: ffffffffb81dab0a
> RDX: 0000000000000007 RSI: dffffc0000000000 RDI: ffffffffba1cd854
> RBP: ffffffffb827de70 R08: fffffbfff76a9525 R09: fffffbfff76a9524
> R10: ffff8800d3c07db0 R11: fffffbfff76a9525 R12: ffff8800cfacba88
> R13: ffffffffb9d4d960 R14: 000000000000000a R15: ffff8800d3c07eb0
> FS: 0000000000000000(0000) GS:ffff8800d3c00000(0000) knlGS:0000000000000000
> CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> CR2: ffff88011e7ff000 CR3: 00000000a2c14001 CR4: 00000000001606f0
> Call Trace:
> <IRQ>
> ? rcu_free_old_probes+0x20/0x20
> ? for_each_kernel_tracepoint+0x50/0x50
> __call_srcu+0x29/0x570
> ? rcu_process_callbacks+0x403/0xcd0
> ? for_each_kernel_tracepoint+0x50/0x50
> rcu_process_callbacks+0x44f/0xcd0
> ? __bpf_trace_timer_class+0x10/0x10
> ? sched_clock+0x5/0x10
> ? note_gp_changes+0xf0/0xf0
> ? __lock_is_held+0x26/0xf0
> __do_softirq+0x13b/0x561
> irq_exit+0x12c/0x140
> smp_apic_timer_interrupt+0xd4/0x2f0
> apic_timer_interrupt+0xf/0x20
> </IRQ>
> RIP: 0010:mwait_idle+0x83/0x260
> Code: 48 89 d1 48 89 d8 0f 01 c8 48 89 df e8 f6 d5 4d ff 48 8b 03 a8 08 0f 85 c0 01 00 00 e8 f6 dc 35 ff 31 c0 48 89 c1 fb 0f 01 c9 <e8> 68 ee 85 ff 41 89 c4 0f 1f 44 00 00 65 48 8b 04 25 c0 ed 01 00
> RSP: 0000:ffffffffb9c07d28 EFLAGS: 00000246 ORIG_RAX: ffffffffffffff13
> RAX: 0000000000000000 RBX: ffffffffb9c1f9c0 RCX: 0000000000000000
> RDX: 0000000000000007 RSI: dffffc0000000000 RDI: ffffffffb9c2028c
> RBP: 0000000000000000 R08: 0000000000000001 R09: 0000000000000000
> R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000000000
> R13: ffffffffba1cd740 R14: 0000000000000000 R15: 0000000000000000
> ? mwait_idle+0x7a/0x260
> default_idle_call+0x2d/0x50
> do_idle+0x251/0x310
> ? arch_cpu_idle_exit+0x40/0x40
> cpu_startup_entry+0xc2/0xd0
> ? cpu_in_idle+0x20/0x20
> ? preempt_count_sub+0xaa/0x100
> start_kernel+0x640/0x67d
> ? thread_stack_cache_init+0x6/0x6
> ? load_ucode_intel_bsp+0x5f/0xa5
> ? load_ucode_intel_bsp+0x5f/0xa5
> ? init_intel_microcode+0xb0/0xb0
> ? load_ucode_bsp+0xbb/0x156
> secondary_startup_64+0xa4/0xb0
> irq event stamp: 21271
> hardirqs last enabled at (21270): [<ffffffffb81e1e52>] rcu_process_callbacks+0x982/0xcd0
> hardirqs last disabled at (21271): [<ffffffffb800447f>] trace_hardirqs_off_thunk+0x1a/0x1c
> softirqs last enabled at (21252): [<ffffffffb811529c>] irq_enter+0x7c/0x80
> softirqs last disabled at (21253): [<ffffffffb81153cc>] irq_exit+0x12c/0x140
> ---[ end trace 64bab84b86e8ec96 ]---
>
> Attached is my config, and my kernel command line has:
>
> trace_event=sched_switch
>
> -- Steve