Received-SPF: pass (google.com: best guess record for domain of linux-kernel-owner@vger.kernel.org designates 209.132.180.67 as permitted sender) client-ip=209.132.180.67;
Date:   Thu, 30 Aug 2018 10:35:09 -0700
From:   "Paul E. McKenney" <paulmck@linux.vnet.ibm.com>
To:     Steven Rostedt <rostedt@goodmis.org>
Cc:     linux-kernel@vger.kernel.org, mingo@kernel.org,
        jiangshanlai@gmail.com, dipankar@in.ibm.com,
        akpm@linux-foundation.org, mathieu.desnoyers@efficios.com,
        josh@joshtriplett.org, tglx@linutronix.de, peterz@infradead.org,
        dhowells@redhat.com, edumazet@google.com, fweisbec@gmail.com,
        oleg@redhat.com, joel@joelfernandes.org, Tejun Heo <tj@kernel.org>
Subject: Re: [PATCH tip/core/rcu 3/3] srcu: Make early-boot call_srcu() reuse
 workqueue lists
Reply-To: paulmck@linux.vnet.ibm.com
References: <20180829212036.GA22033@linux.vnet.ibm.com>
 <20180829212313.22903-3-paulmck@linux.vnet.ibm.com>
 <20180829215616.1c10e476@vmware.local.home>
 <20180830020701.GE4225@linux.vnet.ibm.com>
 <20180829224609.5ffdc9ec@vmware.local.home>
 <20180830032315.GG4225@linux.vnet.ibm.com>
 <20180830124444.6bb9faac@gandalf.local.home>
MIME-Version: 1.0
Content-Type: text/plain; charset=us-ascii
Content-Disposition: inline
In-Reply-To: <20180830124444.6bb9faac@gandalf.local.home>
User-Agent: Mutt/1.5.21 (2010-09-15)
Message-Id: <20180830173509.GL4225@linux.vnet.ibm.com>
Sender: linux-kernel-owner@vger.kernel.org
Precedence: bulk

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