linux-kernel.vger.kernel.org archive mirror
 help / color / mirror / Atom feed
* TREE_SRCU slows hotplug by factor ~16
@ 2017-04-24  2:48 Mike Galbraith
  2017-04-24  3:32 ` Paul E. McKenney
  0 siblings, 1 reply; 24+ messages in thread
From: Mike Galbraith @ 2017-04-24  2:48 UTC (permalink / raw)
  To: Paul E. McKenney; +Cc: LKML

Greetings,

Running Steven's hotplug stress script in tip w. CLASSIC_SRCU takes 55s
in my i4790 box, whereas TREE_SRCU takes over 16m.  (Master with the
same config does it in 39s.. but then lockdep isn't enabled in master)

	-Mike

^ permalink raw reply	[flat|nested] 24+ messages in thread

* Re: TREE_SRCU slows hotplug by factor ~16
  2017-04-24  2:48 TREE_SRCU slows hotplug by factor ~16 Mike Galbraith
@ 2017-04-24  3:32 ` Paul E. McKenney
  2017-04-24  5:24   ` Mike Galbraith
  0 siblings, 1 reply; 24+ messages in thread
From: Paul E. McKenney @ 2017-04-24  3:32 UTC (permalink / raw)
  To: Mike Galbraith; +Cc: LKML

On Mon, Apr 24, 2017 at 04:48:09AM +0200, Mike Galbraith wrote:
> Greetings,
> 
> Running Steven's hotplug stress script in tip w. CLASSIC_SRCU takes 55s
> in my i4790 box, whereas TREE_SRCU takes over 16m.  (Master with the
> same config does it in 39s.. but then lockdep isn't enabled in master)

That doesn't sound good...

But exactly which version are you using?  There were some 8x slowdowns
earlier this week that have since been fixed.  Also, how many CPUs are
on your system?

							Thanx, Paul

^ permalink raw reply	[flat|nested] 24+ messages in thread

* Re: TREE_SRCU slows hotplug by factor ~16
  2017-04-24  3:32 ` Paul E. McKenney
@ 2017-04-24  5:24   ` Mike Galbraith
  2017-04-24  6:22     ` Paul E. McKenney
  0 siblings, 1 reply; 24+ messages in thread
From: Mike Galbraith @ 2017-04-24  5:24 UTC (permalink / raw)
  To: paulmck; +Cc: LKML

On Sun, 2017-04-23 at 20:32 -0700, Paul E. McKenney wrote:
> On Mon, Apr 24, 2017 at 04:48:09AM +0200, Mike Galbraith wrote:
> > Greetings,
> > 
> > Running Steven's hotplug stress script in tip w. CLASSIC_SRCU takes 55s
> > in my i4790 box, whereas TREE_SRCU takes over 16m.  (Master with the
> > same config does it in 39s.. but then lockdep isn't enabled in master)
> 
> That doesn't sound good...
> 
> But exactly which version are you using?  There were some 8x slowdowns
> earlier this week that have since been fixed.  Also, how many CPUs are
> on your system?

4 cores+SMT, tip.yesterday_afternoon (precise!) was initial test point,
tip.this_morning (v4.11-rc7-955-g76f8909e1cd8) is still slow.

	-Mike

^ permalink raw reply	[flat|nested] 24+ messages in thread

* Re: TREE_SRCU slows hotplug by factor ~16
  2017-04-24  5:24   ` Mike Galbraith
@ 2017-04-24  6:22     ` Paul E. McKenney
  2017-04-24  7:35       ` Mike Galbraith
  0 siblings, 1 reply; 24+ messages in thread
From: Paul E. McKenney @ 2017-04-24  6:22 UTC (permalink / raw)
  To: Mike Galbraith; +Cc: LKML

On Mon, Apr 24, 2017 at 07:24:44AM +0200, Mike Galbraith wrote:
> On Sun, 2017-04-23 at 20:32 -0700, Paul E. McKenney wrote:
> > On Mon, Apr 24, 2017 at 04:48:09AM +0200, Mike Galbraith wrote:
> > > Greetings,
> > > 
> > > Running Steven's hotplug stress script in tip w. CLASSIC_SRCU takes 55s
> > > in my i4790 box, whereas TREE_SRCU takes over 16m.  (Master with the
> > > same config does it in 39s.. but then lockdep isn't enabled in master)
> > 
> > That doesn't sound good...
> > 
> > But exactly which version are you using?  There were some 8x slowdowns
> > earlier this week that have since been fixed.  Also, how many CPUs are
> > on your system?
> 
> 4 cores+SMT, tip.yesterday_afternoon (precise!) was initial test point,
> tip.this_morning (v4.11-rc7-955-g76f8909e1cd8) is still slow.

OK, that is after the earlier fix!  And modest in size as well.

Assuming 4ms per TREE_SRCU synchronize_srcu(), I end up with the
CLASSIC_SRCU doing a synchronize_srcu() every 200us or so, which
I am having a hard time believing.  But it does matter, because
it controls what approach I take to fixing this.

Could you please collect an ftrace (or whatever) showing the timestamp
sequence of calls to synchronize_srcu(), synchronize_srcu_expedited(),
and call_srcu() during the execution of the stress script?  If it is easy
to do, also the timestamp sequence of returns from synchronize_srcu()
and synchronize_srcu_expedited()?

							Thanx, Paul

^ permalink raw reply	[flat|nested] 24+ messages in thread

* Re: TREE_SRCU slows hotplug by factor ~16
  2017-04-24  6:22     ` Paul E. McKenney
@ 2017-04-24  7:35       ` Mike Galbraith
  2017-04-24  8:43         ` Mike Galbraith
  2017-04-24 16:24         ` Paul E. McKenney
  0 siblings, 2 replies; 24+ messages in thread
From: Mike Galbraith @ 2017-04-24  7:35 UTC (permalink / raw)
  To: paulmck; +Cc: LKML

On Sun, 2017-04-23 at 23:22 -0700, Paul E. McKenney wrote:

> Could you please collect an ftrace (or whatever) showing the timestamp
> sequence of calls to synchronize_srcu(), synchronize_srcu_expedited(),
> and call_srcu() during the execution of the stress script?  If it is easy
> to do, also the timestamp sequence of returns from synchronize_srcu()
> and synchronize_srcu_expedited()?

The first two minutes below config bits, trace_printk([enter/exit]) in
each function.  If you (unlikely, but..) want the whole trace, holler.

# RCU Subsystem
CONFIG_TREE_RCU=y
CONFIG_RCU_EXPERT=y
CONFIG_SRCU=y
# CONFIG_CLASSIC_SRCU is not set
CONFIG_TREE_SRCU=y
# CONFIG_TASKS_RCU is not set
CONFIG_RCU_STALL_COMMON=y
CONFIG_RCU_FANOUT=64
CONFIG_RCU_FANOUT_LEAF=16
# CONFIG_RCU_FAST_NO_HZ is not set
# CONFIG_TREE_RCU_TRACE is not set
CONFIG_RCU_KTHREAD_PRIO=0
CONFIG_RCU_NOCB_CPU=y
CONFIG_RCU_NOCB_CPU_NONE=y
# CONFIG_RCU_NOCB_CPU_ZERO is not set
# CONFIG_RCU_NOCB_CPU_ALL is not set
# RCU Debugging
# CONFIG_PROVE_RCU is not set
# CONFIG_SPARSE_RCU_POINTER is not set
# CONFIG_RCU_PERF_TEST is not set
# CONFIG_RCU_TORTURE_TEST is not set
CONFIG_RCU_CPU_STALL_TIMEOUT=60
# CONFIG_RCU_TRACE is not set
# CONFIG_RCU_EQS_DEBUG is not set


# tracer: nop
#
# entries-in-buffer/entries-written: 229332/229332   #P:8
#
#                              _-----=> irqs-off
#                             / _----=> need-resched
#                            | / _---=> hardirq/softirq
#                            || / _--=> preempt-depth
#                            ||| /     delay
#           TASK-PID   CPU#  ||||    TIMESTAMP  FUNCTION
#              | |       |   ||||       |         |
 stress-cpu-hotp-2443  [004] ....   144.123608: synchronize_srcu: enter
 stress-cpu-hotp-2443  [004] ....   144.123610: call_srcu: enter
 stress-cpu-hotp-2443  [004] ....   144.123612: call_srcu: exit
 stress-cpu-hotp-2443  [005] ....   144.139528: synchronize_srcu: exit
 stress-cpu-hotp-2443  [005] ....   144.139646: synchronize_srcu: enter
 stress-cpu-hotp-2443  [005] ....   144.139646: call_srcu: enter
 stress-cpu-hotp-2443  [005] ....   144.139648: call_srcu: exit
 stress-cpu-hotp-2443  [006] ....   144.155813: synchronize_srcu: exit
 stress-cpu-hotp-2443  [006] ....   144.155981: synchronize_srcu: enter
 stress-cpu-hotp-2443  [006] ....   144.155982: call_srcu: enter
 stress-cpu-hotp-2443  [006] ....   144.155983: call_srcu: exit
 stress-cpu-hotp-2443  [007] ....   144.172078: synchronize_srcu: exit
 stress-cpu-hotp-2443  [007] ....   144.172234: synchronize_srcu: enter
 stress-cpu-hotp-2443  [007] ....   144.172235: call_srcu: enter
 stress-cpu-hotp-2443  [007] ....   144.172237: call_srcu: exit
 stress-cpu-hotp-2443  [000] ....   144.188319: synchronize_srcu: exit
 stress-cpu-hotp-2443  [000] ....   144.188465: synchronize_srcu: enter
 stress-cpu-hotp-2443  [000] ....   144.188466: call_srcu: enter
 stress-cpu-hotp-2443  [000] ....   144.188468: call_srcu: exit
 stress-cpu-hotp-2443  [002] ....   144.202528: synchronize_srcu: exit
 stress-cpu-hotp-2443  [002] ....   144.202650: synchronize_srcu: enter
 stress-cpu-hotp-2443  [002] ....   144.202651: call_srcu: enter
 stress-cpu-hotp-2443  [002] ....   144.202652: call_srcu: exit
 stress-cpu-hotp-2443  [003] ....   144.219081: synchronize_srcu: exit
 stress-cpu-hotp-2443  [003] ....   144.219238: synchronize_srcu: enter
 stress-cpu-hotp-2443  [003] ....   144.219238: call_srcu: enter
 stress-cpu-hotp-2443  [003] ....   144.219240: call_srcu: exit
 stress-cpu-hotp-2443  [004] ....   144.235319: synchronize_srcu: exit
 stress-cpu-hotp-2443  [004] ....   144.235567: synchronize_srcu: enter
 stress-cpu-hotp-2443  [004] ....   144.235568: call_srcu: enter
 stress-cpu-hotp-2443  [004] ....   144.235571: call_srcu: exit
 stress-cpu-hotp-2443  [005] ....   144.251548: synchronize_srcu: exit
 stress-cpu-hotp-2443  [005] ....   144.251706: synchronize_srcu: enter
 stress-cpu-hotp-2443  [005] ....   144.251706: call_srcu: enter
 stress-cpu-hotp-2443  [005] ....   144.251708: call_srcu: exit
 stress-cpu-hotp-2443  [006] ....   144.267865: synchronize_srcu: exit
 stress-cpu-hotp-2443  [006] ....   144.268132: synchronize_srcu: enter
 stress-cpu-hotp-2443  [006] ....   144.268133: call_srcu: enter
 stress-cpu-hotp-2443  [006] ....   144.268136: call_srcu: exit
 stress-cpu-hotp-2443  [007] ....   144.284078: synchronize_srcu: exit
 stress-cpu-hotp-2443  [007] ....   144.284257: synchronize_srcu: enter
 stress-cpu-hotp-2443  [007] ....   144.284258: call_srcu: enter
 stress-cpu-hotp-2443  [007] ....   144.284260: call_srcu: exit
 stress-cpu-hotp-2443  [000] ....   144.300314: synchronize_srcu: exit
 stress-cpu-hotp-2443  [000] ....   144.300462: synchronize_srcu: enter
 stress-cpu-hotp-2443  [000] ....   144.300463: call_srcu: enter
 stress-cpu-hotp-2443  [000] ....   144.300464: call_srcu: exit
 stress-cpu-hotp-2443  [002] ....   144.314533: synchronize_srcu: exit
 stress-cpu-hotp-2443  [002] ....   144.314657: synchronize_srcu: enter
 stress-cpu-hotp-2443  [002] ....   144.314658: call_srcu: enter
 stress-cpu-hotp-2443  [002] ....   144.314659: call_srcu: exit
 stress-cpu-hotp-2443  [003] ....   144.331056: synchronize_srcu: exit
 stress-cpu-hotp-2443  [003] ....   144.331227: synchronize_srcu: enter
 stress-cpu-hotp-2443  [003] ....   144.331227: call_srcu: enter
 stress-cpu-hotp-2443  [003] ....   144.331229: call_srcu: exit
 stress-cpu-hotp-2443  [004] ....   144.347334: synchronize_srcu: exit
 stress-cpu-hotp-2443  [004] ....   144.347517: synchronize_srcu: enter
 stress-cpu-hotp-2443  [004] ....   144.347518: call_srcu: enter
 stress-cpu-hotp-2443  [004] ....   144.347519: call_srcu: exit
 stress-cpu-hotp-2443  [005] ....   144.363567: synchronize_srcu: exit
 stress-cpu-hotp-2443  [005] ....   144.363731: synchronize_srcu: enter
 stress-cpu-hotp-2443  [005] ....   144.363732: call_srcu: enter
 stress-cpu-hotp-2443  [005] ....   144.363733: call_srcu: exit
 stress-cpu-hotp-2443  [006] ....   144.379804: synchronize_srcu: exit
 stress-cpu-hotp-2443  [006] ....   144.379987: synchronize_srcu: enter
 stress-cpu-hotp-2443  [006] ....   144.379988: call_srcu: enter
 stress-cpu-hotp-2443  [006] ....   144.379989: call_srcu: exit
 stress-cpu-hotp-2443  [007] ....   144.396077: synchronize_srcu: exit
 stress-cpu-hotp-2443  [007] ....   144.396259: synchronize_srcu: enter
 stress-cpu-hotp-2443  [007] ....   144.396260: call_srcu: enter
 stress-cpu-hotp-2443  [007] ....   144.396261: call_srcu: exit
 stress-cpu-hotp-2443  [000] ....   144.412385: synchronize_srcu: exit
 stress-cpu-hotp-2443  [000] ....   144.412653: synchronize_srcu: enter
 stress-cpu-hotp-2443  [000] ....   144.412654: call_srcu: enter
 stress-cpu-hotp-2443  [000] ....   144.412657: call_srcu: exit
 stress-cpu-hotp-2443  [002] ....   144.426647: synchronize_srcu: exit
 stress-cpu-hotp-2443  [002] ....   144.426888: synchronize_srcu: enter
 stress-cpu-hotp-2443  [002] ....   144.426889: call_srcu: enter
 stress-cpu-hotp-2443  [002] ....   144.426891: call_srcu: exit
 stress-cpu-hotp-2443  [003] ....   144.443134: synchronize_srcu: exit
 stress-cpu-hotp-2443  [003] ....   144.443325: synchronize_srcu: enter
 stress-cpu-hotp-2443  [003] ....   144.443325: call_srcu: enter
 stress-cpu-hotp-2443  [003] ....   144.443327: call_srcu: exit
 stress-cpu-hotp-2443  [004] ....   144.459327: synchronize_srcu: exit
 stress-cpu-hotp-2443  [004] ....   144.459521: synchronize_srcu: enter
 stress-cpu-hotp-2443  [004] ....   144.459522: call_srcu: enter
 stress-cpu-hotp-2443  [004] ....   144.459524: call_srcu: exit
 stress-cpu-hotp-2443  [005] ....   144.475553: synchronize_srcu: exit
 stress-cpu-hotp-2443  [005] ....   144.475672: synchronize_srcu: enter
 stress-cpu-hotp-2443  [005] ....   144.475673: call_srcu: enter
 stress-cpu-hotp-2443  [005] ....   144.475674: call_srcu: exit
 stress-cpu-hotp-2443  [006] ....   144.491798: synchronize_srcu: exit
 stress-cpu-hotp-2443  [006] ....   144.491919: synchronize_srcu: enter
 stress-cpu-hotp-2443  [006] ....   144.491920: call_srcu: enter
 stress-cpu-hotp-2443  [006] ....   144.491921: call_srcu: exit
 stress-cpu-hotp-2443  [007] ....   144.508035: synchronize_srcu: exit
 stress-cpu-hotp-2443  [007] ....   144.508160: synchronize_srcu: enter
 stress-cpu-hotp-2443  [007] ....   144.508161: call_srcu: enter
 stress-cpu-hotp-2443  [007] ....   144.508162: call_srcu: exit
 stress-cpu-hotp-2443  [000] ....   144.524301: synchronize_srcu: exit
 stress-cpu-hotp-2443  [000] ....   144.524419: synchronize_srcu: enter
 stress-cpu-hotp-2443  [000] ....   144.524419: call_srcu: enter
 stress-cpu-hotp-2443  [000] ....   144.524421: call_srcu: exit
 stress-cpu-hotp-2443  [002] ....   144.538545: synchronize_srcu: exit
 stress-cpu-hotp-2443  [002] ....   144.538665: synchronize_srcu: enter
 stress-cpu-hotp-2443  [002] ....   144.538666: call_srcu: enter
 stress-cpu-hotp-2443  [002] ....   144.538667: call_srcu: exit
 stress-cpu-hotp-2443  [003] ....   144.555051: synchronize_srcu: exit
 stress-cpu-hotp-2443  [003] ....   144.555174: synchronize_srcu: enter
 stress-cpu-hotp-2443  [003] ....   144.555174: call_srcu: enter
 stress-cpu-hotp-2443  [003] ....   144.555175: call_srcu: exit
 stress-cpu-hotp-2443  [004] ....   144.571290: synchronize_srcu: exit
 stress-cpu-hotp-2443  [004] ....   144.571412: synchronize_srcu: enter
 stress-cpu-hotp-2443  [004] ....   144.571412: call_srcu: enter
 stress-cpu-hotp-2443  [004] ....   144.571413: call_srcu: exit
 stress-cpu-hotp-2443  [005] ....   144.587554: synchronize_srcu: exit
 stress-cpu-hotp-2443  [005] ....   144.587672: synchronize_srcu: enter
 stress-cpu-hotp-2443  [005] ....   144.587673: call_srcu: enter
 stress-cpu-hotp-2443  [005] ....   144.587674: call_srcu: exit
 stress-cpu-hotp-2443  [006] ....   144.603843: synchronize_srcu: exit
 stress-cpu-hotp-2443  [006] ....   144.604008: synchronize_srcu: enter
 stress-cpu-hotp-2443  [006] ....   144.604008: call_srcu: enter
 stress-cpu-hotp-2443  [006] ....   144.604010: call_srcu: exit
 stress-cpu-hotp-2443  [007] ....   144.620087: synchronize_srcu: exit
 stress-cpu-hotp-2443  [007] ....   144.620317: synchronize_srcu: enter
 stress-cpu-hotp-2443  [007] ....   144.620318: call_srcu: enter
 stress-cpu-hotp-2443  [007] ....   144.620321: call_srcu: exit
 stress-cpu-hotp-2443  [000] ....   144.636342: synchronize_srcu: exit
 stress-cpu-hotp-2443  [000] ....   144.636520: synchronize_srcu: enter
 stress-cpu-hotp-2443  [000] ....   144.636521: call_srcu: enter
 stress-cpu-hotp-2443  [000] ....   144.636523: call_srcu: exit
 stress-cpu-hotp-2443  [002] ....   144.650579: synchronize_srcu: exit
 stress-cpu-hotp-2443  [002] ....   144.650737: synchronize_srcu: enter
 stress-cpu-hotp-2443  [002] ....   144.650738: call_srcu: enter
 stress-cpu-hotp-2443  [002] ....   144.650739: call_srcu: exit
 stress-cpu-hotp-2443  [003] ....   144.667084: synchronize_srcu: exit
 stress-cpu-hotp-2443  [003] ....   144.667247: synchronize_srcu: enter
 stress-cpu-hotp-2443  [003] ....   144.667247: call_srcu: enter
 stress-cpu-hotp-2443  [003] ....   144.667249: call_srcu: exit
 stress-cpu-hotp-2443  [004] ....   144.683340: synchronize_srcu: exit
 stress-cpu-hotp-2443  [004] ....   144.683513: synchronize_srcu: enter
 stress-cpu-hotp-2443  [004] ....   144.683514: call_srcu: enter
 stress-cpu-hotp-2443  [004] ....   144.683516: call_srcu: exit
 stress-cpu-hotp-2443  [005] ....   144.699556: synchronize_srcu: exit
 stress-cpu-hotp-2443  [005] ....   144.699675: synchronize_srcu: enter
 stress-cpu-hotp-2443  [005] ....   144.699675: call_srcu: enter
 stress-cpu-hotp-2443  [005] ....   144.699676: call_srcu: exit
 stress-cpu-hotp-2443  [006] ....   144.715841: synchronize_srcu: exit
 stress-cpu-hotp-2443  [006] ....   144.716013: synchronize_srcu: enter
 stress-cpu-hotp-2443  [006] ....   144.716014: call_srcu: enter
 stress-cpu-hotp-2443  [006] ....   144.716015: call_srcu: exit
 stress-cpu-hotp-2443  [007] ....   144.732096: synchronize_srcu: exit
 stress-cpu-hotp-2443  [007] ....   144.732269: synchronize_srcu: enter
 stress-cpu-hotp-2443  [007] ....   144.732270: call_srcu: enter
 stress-cpu-hotp-2443  [007] ....   144.732271: call_srcu: exit
 stress-cpu-hotp-2443  [000] ....   144.748393: synchronize_srcu: exit
 stress-cpu-hotp-2443  [000] ....   144.748641: synchronize_srcu: enter
 stress-cpu-hotp-2443  [000] ....   144.748642: call_srcu: enter
 stress-cpu-hotp-2443  [000] ....   144.748645: call_srcu: exit
 stress-cpu-hotp-2443  [002] ....   144.762639: synchronize_srcu: exit
 stress-cpu-hotp-2443  [002] ....   144.762854: synchronize_srcu: enter
 stress-cpu-hotp-2443  [002] ....   144.762855: call_srcu: enter
 stress-cpu-hotp-2443  [002] ....   144.762857: call_srcu: exit
 stress-cpu-hotp-2443  [003] ....   144.779100: synchronize_srcu: exit
 stress-cpu-hotp-2443  [003] ....   144.779278: synchronize_srcu: enter
 stress-cpu-hotp-2443  [003] ....   144.779279: call_srcu: enter
 stress-cpu-hotp-2443  [003] ....   144.779280: call_srcu: exit
 stress-cpu-hotp-2443  [004] ....   144.795348: synchronize_srcu: exit
 stress-cpu-hotp-2443  [004] ....   144.795525: synchronize_srcu: enter
 stress-cpu-hotp-2443  [004] ....   144.795526: call_srcu: enter
 stress-cpu-hotp-2443  [004] ....   144.795527: call_srcu: exit
 stress-cpu-hotp-2443  [005] ....   144.811583: synchronize_srcu: exit
 stress-cpu-hotp-2443  [005] ....   144.811749: synchronize_srcu: enter
 stress-cpu-hotp-2443  [005] ....   144.811750: call_srcu: enter
 stress-cpu-hotp-2443  [005] ....   144.811751: call_srcu: exit
 stress-cpu-hotp-2443  [006] ....   144.827831: synchronize_srcu: exit
 stress-cpu-hotp-2443  [006] ....   144.827997: synchronize_srcu: enter
 stress-cpu-hotp-2443  [006] ....   144.827998: call_srcu: enter
 stress-cpu-hotp-2443  [006] ....   144.827999: call_srcu: exit
 stress-cpu-hotp-2443  [007] ....   144.844104: synchronize_srcu: exit
 stress-cpu-hotp-2443  [007] ....   144.844281: synchronize_srcu: enter
 stress-cpu-hotp-2443  [007] ....   144.844281: call_srcu: enter
 stress-cpu-hotp-2443  [007] ....   144.844283: call_srcu: exit
 stress-cpu-hotp-2443  [000] ....   144.860339: synchronize_srcu: exit
 stress-cpu-hotp-2443  [000] ....   144.860484: synchronize_srcu: enter
 stress-cpu-hotp-2443  [000] ....   144.860485: call_srcu: enter
 stress-cpu-hotp-2443  [000] ....   144.860487: call_srcu: exit
 stress-cpu-hotp-2443  [002] ....   144.874584: synchronize_srcu: exit
 stress-cpu-hotp-2443  [002] ....   144.874737: synchronize_srcu: enter
 stress-cpu-hotp-2443  [002] ....   144.874737: call_srcu: enter
 stress-cpu-hotp-2443  [002] ....   144.874739: call_srcu: exit
 stress-cpu-hotp-2443  [003] ....   144.891117: synchronize_srcu: exit
 stress-cpu-hotp-2443  [003] ....   144.891459: synchronize_srcu: enter
 stress-cpu-hotp-2443  [003] ....   144.891460: call_srcu: enter
 stress-cpu-hotp-2443  [003] ....   144.891463: call_srcu: exit
 stress-cpu-hotp-2443  [004] ....   144.907376: synchronize_srcu: exit
 stress-cpu-hotp-2443  [004] ....   144.907628: synchronize_srcu: enter
 stress-cpu-hotp-2443  [004] ....   144.907629: call_srcu: enter
 stress-cpu-hotp-2443  [004] ....   144.907631: call_srcu: exit
 stress-cpu-hotp-2443  [005] ....   144.923590: synchronize_srcu: exit
 stress-cpu-hotp-2443  [005] ....   144.923756: synchronize_srcu: enter
 stress-cpu-hotp-2443  [005] ....   144.923756: call_srcu: enter
 stress-cpu-hotp-2443  [005] ....   144.923758: call_srcu: exit
 stress-cpu-hotp-2443  [006] ....   144.939837: synchronize_srcu: exit
 stress-cpu-hotp-2443  [006] ....   144.940007: synchronize_srcu: enter
 stress-cpu-hotp-2443  [006] ....   144.940008: call_srcu: enter
 stress-cpu-hotp-2443  [006] ....   144.940009: call_srcu: exit
 stress-cpu-hotp-2443  [007] ....   144.956110: synchronize_srcu: exit
 stress-cpu-hotp-2443  [007] ....   144.956285: synchronize_srcu: enter
 stress-cpu-hotp-2443  [007] ....   144.956286: call_srcu: enter
 stress-cpu-hotp-2443  [007] ....   144.956287: call_srcu: exit
 stress-cpu-hotp-2443  [000] ....   144.972344: synchronize_srcu: exit
 stress-cpu-hotp-2443  [000] ....   144.972492: synchronize_srcu: enter
 stress-cpu-hotp-2443  [000] ....   144.972493: call_srcu: enter
 stress-cpu-hotp-2443  [000] ....   144.972495: call_srcu: exit
 stress-cpu-hotp-2443  [002] ....   144.986566: synchronize_srcu: exit
 stress-cpu-hotp-2443  [002] ....   144.986689: synchronize_srcu: enter
 stress-cpu-hotp-2443  [002] ....   144.986689: call_srcu: enter
 stress-cpu-hotp-2443  [002] ....   144.986690: call_srcu: exit
 stress-cpu-hotp-2443  [003] ....   145.003114: synchronize_srcu: exit
 stress-cpu-hotp-2443  [003] ....   145.003292: synchronize_srcu: enter
 stress-cpu-hotp-2443  [003] ....   145.003293: call_srcu: enter
 stress-cpu-hotp-2443  [003] ....   145.003294: call_srcu: exit
 stress-cpu-hotp-2443  [004] ....   145.019350: synchronize_srcu: exit
 stress-cpu-hotp-2443  [004] ....   145.019528: synchronize_srcu: enter
 stress-cpu-hotp-2443  [004] ....   145.019529: call_srcu: enter
 stress-cpu-hotp-2443  [004] ....   145.019531: call_srcu: exit
 stress-cpu-hotp-2443  [005] ....   145.035659: synchronize_srcu: exit
 stress-cpu-hotp-2443  [005] ....   145.035939: synchronize_srcu: enter
 stress-cpu-hotp-2443  [005] ....   145.035940: call_srcu: enter
 stress-cpu-hotp-2443  [005] ....   145.035943: call_srcu: exit
 stress-cpu-hotp-2443  [006] ....   145.051891: synchronize_srcu: exit
 stress-cpu-hotp-2443  [006] ....   145.052106: synchronize_srcu: enter
 stress-cpu-hotp-2443  [006] ....   145.052107: call_srcu: enter
 stress-cpu-hotp-2443  [006] ....   145.052109: call_srcu: exit
 stress-cpu-hotp-2443  [007] ....   145.068125: synchronize_srcu: exit
 stress-cpu-hotp-2443  [007] ....   145.068279: synchronize_srcu: enter
 stress-cpu-hotp-2443  [007] ....   145.068279: call_srcu: enter
 stress-cpu-hotp-2443  [007] ....   145.068280: call_srcu: exit
 stress-cpu-hotp-2443  [000] ....   145.084332: synchronize_srcu: exit
 stress-cpu-hotp-2443  [000] ....   145.084472: synchronize_srcu: enter
 stress-cpu-hotp-2443  [000] ....   145.084473: call_srcu: enter
 stress-cpu-hotp-2443  [000] ....   145.084474: call_srcu: exit
 stress-cpu-hotp-2443  [002] ....   145.098605: synchronize_srcu: exit
 stress-cpu-hotp-2443  [002] ....   145.098743: synchronize_srcu: enter
 stress-cpu-hotp-2443  [002] ....   145.098744: call_srcu: enter
 stress-cpu-hotp-2443  [002] ....   145.098745: call_srcu: exit
 stress-cpu-hotp-2443  [003] ....   145.114590: synchronize_srcu: exit
 stress-cpu-hotp-2443  [003] ....   145.114728: synchronize_srcu: enter
 stress-cpu-hotp-2443  [003] ....   145.114728: call_srcu: enter
 stress-cpu-hotp-2443  [003] ....   145.114729: call_srcu: exit
 stress-cpu-hotp-2443  [005] ....   145.130591: synchronize_srcu: exit
 stress-cpu-hotp-2443  [005] ....   145.130728: synchronize_srcu: enter
 stress-cpu-hotp-2443  [005] ....   145.130728: call_srcu: enter
 stress-cpu-hotp-2443  [005] ....   145.130730: call_srcu: exit
 stress-cpu-hotp-2443  [006] ....   145.147857: synchronize_srcu: exit
 stress-cpu-hotp-2443  [006] ....   145.228078: synchronize_srcu: enter
 stress-cpu-hotp-2443  [006] ....   145.228079: call_srcu: enter
 stress-cpu-hotp-2443  [006] ....   145.228080: call_srcu: exit
 stress-cpu-hotp-2443  [007] ....   145.244025: synchronize_srcu: exit
 stress-cpu-hotp-2443  [007] ....   145.244106: synchronize_srcu: enter
 stress-cpu-hotp-2443  [007] ....   145.244106: call_srcu: enter
 stress-cpu-hotp-2443  [007] ....   145.244107: call_srcu: exit
 stress-cpu-hotp-2443  [000] ....   145.260286: synchronize_srcu: exit
 stress-cpu-hotp-2443  [000] ....   145.260361: synchronize_srcu: enter
 stress-cpu-hotp-2443  [000] ....   145.260361: call_srcu: enter
 stress-cpu-hotp-2443  [000] ....   145.260362: call_srcu: exit
 stress-cpu-hotp-2443  [003] ....   145.274522: synchronize_srcu: exit
 stress-cpu-hotp-2443  [003] ....   145.274594: synchronize_srcu: enter
 stress-cpu-hotp-2443  [003] ....   145.274594: call_srcu: enter
 stress-cpu-hotp-2443  [003] ....   145.274595: call_srcu: exit
 stress-cpu-hotp-2443  [004] ....   145.291289: synchronize_srcu: exit
 stress-cpu-hotp-2443  [004] ....   145.291358: synchronize_srcu: enter
 stress-cpu-hotp-2443  [004] ....   145.291358: call_srcu: enter
 stress-cpu-hotp-2443  [004] ....   145.291359: call_srcu: exit
 stress-cpu-hotp-2443  [005] ....   145.307529: synchronize_srcu: exit
 stress-cpu-hotp-2443  [005] ....   145.307599: synchronize_srcu: enter
 stress-cpu-hotp-2443  [005] ....   145.307599: call_srcu: enter
 stress-cpu-hotp-2443  [005] ....   145.307600: call_srcu: exit
 stress-cpu-hotp-2443  [006] ....   145.323901: synchronize_srcu: exit
 stress-cpu-hotp-2443  [006] ....   145.324063: synchronize_srcu: enter
 stress-cpu-hotp-2443  [006] ....   145.324063: call_srcu: enter
 stress-cpu-hotp-2443  [006] ....   145.324065: call_srcu: exit
 stress-cpu-hotp-2443  [007] ....   145.340122: synchronize_srcu: exit
 stress-cpu-hotp-2443  [007] ....   145.340288: synchronize_srcu: enter
 stress-cpu-hotp-2443  [007] ....   145.340289: call_srcu: enter
 stress-cpu-hotp-2443  [007] ....   145.340291: call_srcu: exit
 stress-cpu-hotp-2443  [000] ....   145.356378: synchronize_srcu: exit
 stress-cpu-hotp-2443  [000] ....   145.356519: synchronize_srcu: enter
 stress-cpu-hotp-2443  [000] ....   145.356520: call_srcu: enter
 stress-cpu-hotp-2443  [000] ....   145.356521: call_srcu: exit
 stress-cpu-hotp-2443  [003] ....   145.370650: synchronize_srcu: exit
 stress-cpu-hotp-2443  [003] ....   145.370797: synchronize_srcu: enter
 stress-cpu-hotp-2443  [003] ....   145.370798: call_srcu: enter
 stress-cpu-hotp-2443  [003] ....   145.370799: call_srcu: exit
 stress-cpu-hotp-2443  [004] ....   145.387385: synchronize_srcu: exit
 stress-cpu-hotp-2443  [004] ....   145.387547: synchronize_srcu: enter
 stress-cpu-hotp-2443  [004] ....   145.387548: call_srcu: enter
 stress-cpu-hotp-2443  [004] ....   145.387549: call_srcu: exit
 stress-cpu-hotp-2443  [005] ....   145.403636: synchronize_srcu: exit
 stress-cpu-hotp-2443  [005] ....   145.403799: synchronize_srcu: enter
 stress-cpu-hotp-2443  [005] ....   145.403800: call_srcu: enter
 stress-cpu-hotp-2443  [005] ....   145.403802: call_srcu: exit
 stress-cpu-hotp-2443  [006] ....   145.419885: synchronize_srcu: exit
 stress-cpu-hotp-2443  [006] ....   145.420055: synchronize_srcu: enter
 stress-cpu-hotp-2443  [006] ....   145.420056: call_srcu: enter
 stress-cpu-hotp-2443  [006] ....   145.420057: call_srcu: exit
 stress-cpu-hotp-2443  [007] ....   145.436154: synchronize_srcu: exit
 stress-cpu-hotp-2443  [007] ....   145.436372: synchronize_srcu: enter
 stress-cpu-hotp-2443  [007] ....   145.436372: call_srcu: enter
 stress-cpu-hotp-2443  [007] ....   145.436374: call_srcu: exit
 stress-cpu-hotp-2443  [000] ....   145.452413: synchronize_srcu: exit
 stress-cpu-hotp-2443  [000] ....   145.452550: synchronize_srcu: enter
 stress-cpu-hotp-2443  [000] ....   145.452551: call_srcu: enter
 stress-cpu-hotp-2443  [000] ....   145.452552: call_srcu: exit
 stress-cpu-hotp-2443  [003] ....   145.466606: synchronize_srcu: exit
 stress-cpu-hotp-2443  [003] ....   145.466721: synchronize_srcu: enter
 stress-cpu-hotp-2443  [003] ....   145.466721: call_srcu: enter
 stress-cpu-hotp-2443  [003] ....   145.466722: call_srcu: exit
 stress-cpu-hotp-2443  [004] ....   145.483395: synchronize_srcu: exit
 stress-cpu-hotp-2443  [004] ....   145.483555: synchronize_srcu: enter
 stress-cpu-hotp-2443  [004] ....   145.483555: call_srcu: enter
 stress-cpu-hotp-2443  [004] ....   145.483557: call_srcu: exit
 stress-cpu-hotp-2443  [005] ....   145.499628: synchronize_srcu: exit
 stress-cpu-hotp-2443  [005] ....   145.499761: synchronize_srcu: enter
 stress-cpu-hotp-2443  [005] .N..   145.499774: call_srcu: enter
 stress-cpu-hotp-2443  [005] .N..   145.499775: call_srcu: exit
 stress-cpu-hotp-2443  [006] ....   145.515879: synchronize_srcu: exit
 stress-cpu-hotp-2443  [006] ....   145.516009: synchronize_srcu: enter
 stress-cpu-hotp-2443  [006] ....   145.516009: call_srcu: enter
 stress-cpu-hotp-2443  [006] ....   145.516011: call_srcu: exit
 stress-cpu-hotp-2443  [007] ....   145.532164: synchronize_srcu: exit
 stress-cpu-hotp-2443  [007] ....   145.532488: synchronize_srcu: enter
 stress-cpu-hotp-2443  [007] ....   145.532489: call_srcu: enter
 stress-cpu-hotp-2443  [007] ....   145.532492: call_srcu: exit
 stress-cpu-hotp-2443  [000] ....   145.548447: synchronize_srcu: exit
 stress-cpu-hotp-2443  [000] ....   145.548659: synchronize_srcu: enter
 stress-cpu-hotp-2443  [000] ....   145.548660: call_srcu: enter
 stress-cpu-hotp-2443  [000] ....   145.548663: call_srcu: exit
 stress-cpu-hotp-2443  [003] ....   145.562706: synchronize_srcu: exit
 stress-cpu-hotp-2443  [003] ....   145.562897: synchronize_srcu: enter
 stress-cpu-hotp-2443  [003] ....   145.562898: call_srcu: enter
 stress-cpu-hotp-2443  [003] ....   145.562900: call_srcu: exit
 stress-cpu-hotp-2443  [004] ....   145.579403: synchronize_srcu: exit
 stress-cpu-hotp-2443  [004] ....   145.579562: synchronize_srcu: enter
 stress-cpu-hotp-2443  [004] ....   145.579563: call_srcu: enter
 stress-cpu-hotp-2443  [004] ....   145.579564: call_srcu: exit
 stress-cpu-hotp-2443  [005] ....   145.595636: synchronize_srcu: exit
 stress-cpu-hotp-2443  [005] ....   145.595766: synchronize_srcu: enter
 stress-cpu-hotp-2443  [005] ....   145.595766: call_srcu: enter
 stress-cpu-hotp-2443  [005] ....   145.595768: call_srcu: exit
 stress-cpu-hotp-2443  [006] ....   145.611902: synchronize_srcu: exit
 stress-cpu-hotp-2443  [006] ....   145.612059: synchronize_srcu: enter
 stress-cpu-hotp-2443  [006] ....   145.612060: call_srcu: enter
 stress-cpu-hotp-2443  [006] ....   145.612061: call_srcu: exit
 stress-cpu-hotp-2443  [007] ....   145.628136: synchronize_srcu: exit
 stress-cpu-hotp-2443  [007] ....   145.628266: synchronize_srcu: enter
 stress-cpu-hotp-2443  [007] ....   145.628267: call_srcu: enter
 stress-cpu-hotp-2443  [007] ....   145.628268: call_srcu: exit
 stress-cpu-hotp-2443  [000] ....   145.644392: synchronize_srcu: exit
 stress-cpu-hotp-2443  [000] ....   145.644518: synchronize_srcu: enter
 stress-cpu-hotp-2443  [000] ....   145.644519: call_srcu: enter
 stress-cpu-hotp-2443  [000] ....   145.644521: call_srcu: exit
 stress-cpu-hotp-2443  [003] ....   145.658609: synchronize_srcu: exit
 stress-cpu-hotp-2443  [003] ....   145.658698: synchronize_srcu: enter
 stress-cpu-hotp-2443  [003] ....   145.658699: call_srcu: enter
 stress-cpu-hotp-2443  [003] ....   145.658700: call_srcu: exit
 stress-cpu-hotp-2443  [004] ....   145.675410: synchronize_srcu: exit
 stress-cpu-hotp-2443  [004] ....   145.675570: synchronize_srcu: enter
 stress-cpu-hotp-2443  [004] ....   145.675571: call_srcu: enter
 stress-cpu-hotp-2443  [004] ....   145.675572: call_srcu: exit
 stress-cpu-hotp-2443  [005] ....   145.691706: synchronize_srcu: exit
 stress-cpu-hotp-2443  [005] ....   145.691950: synchronize_srcu: enter
 stress-cpu-hotp-2443  [005] ....   145.691951: call_srcu: enter
 stress-cpu-hotp-2443  [005] ....   145.691953: call_srcu: exit
 stress-cpu-hotp-2443  [006] ....   145.707926: synchronize_srcu: exit
 stress-cpu-hotp-2443  [006] ....   145.708096: synchronize_srcu: enter
 stress-cpu-hotp-2443  [006] ....   145.708097: call_srcu: enter
 stress-cpu-hotp-2443  [006] ....   145.708099: call_srcu: exit
 stress-cpu-hotp-2443  [007] ....   145.724154: synchronize_srcu: exit
 stress-cpu-hotp-2443  [007] ....   145.724333: synchronize_srcu: enter
 stress-cpu-hotp-2443  [007] ....   145.724333: call_srcu: enter
 stress-cpu-hotp-2443  [007] ....   145.724335: call_srcu: exit
 stress-cpu-hotp-2443  [000] ....   145.740412: synchronize_srcu: exit
 stress-cpu-hotp-2443  [000] ....   145.740559: synchronize_srcu: enter
 stress-cpu-hotp-2443  [000] ....   145.740559: call_srcu: enter
 stress-cpu-hotp-2443  [000] ....   145.740561: call_srcu: exit
 stress-cpu-hotp-2443  [003] ....   145.754685: synchronize_srcu: exit
 stress-cpu-hotp-2443  [003] ....   145.754835: synchronize_srcu: enter
 stress-cpu-hotp-2443  [003] ....   145.754836: call_srcu: enter
 stress-cpu-hotp-2443  [003] ....   145.754838: call_srcu: exit
 stress-cpu-hotp-2443  [004] ....   145.771415: synchronize_srcu: exit
 stress-cpu-hotp-2443  [004] ....   145.771591: synchronize_srcu: enter
 stress-cpu-hotp-2443  [004] ....   145.771592: call_srcu: enter
 stress-cpu-hotp-2443  [004] ....   145.771594: call_srcu: exit
 stress-cpu-hotp-2443  [005] ....   145.787635: synchronize_srcu: exit
 stress-cpu-hotp-2443  [005] ....   145.787747: synchronize_srcu: enter
 stress-cpu-hotp-2443  [005] ....   145.787748: call_srcu: enter
 stress-cpu-hotp-2443  [005] ....   145.787749: call_srcu: exit
 stress-cpu-hotp-2443  [006] ....   145.803943: synchronize_srcu: exit
 stress-cpu-hotp-2443  [006] ....   145.804168: synchronize_srcu: enter
 stress-cpu-hotp-2443  [006] ....   145.804170: call_srcu: enter
 stress-cpu-hotp-2443  [006] ....   145.804172: call_srcu: exit
 stress-cpu-hotp-2443  [007] ....   145.820168: synchronize_srcu: exit
 stress-cpu-hotp-2443  [007] ....   145.820320: synchronize_srcu: enter
 stress-cpu-hotp-2443  [007] ....   145.820321: call_srcu: enter
 stress-cpu-hotp-2443  [007] ....   145.820322: call_srcu: exit
 stress-cpu-hotp-2443  [000] ....   145.836412: synchronize_srcu: exit
 stress-cpu-hotp-2443  [000] ....   145.836543: synchronize_srcu: enter
 stress-cpu-hotp-2443  [000] ....   145.836544: call_srcu: enter
 stress-cpu-hotp-2443  [000] ....   145.836545: call_srcu: exit
 stress-cpu-hotp-2443  [003] ....   145.850638: synchronize_srcu: exit
 stress-cpu-hotp-2443  [003] ....   145.850757: synchronize_srcu: enter
 stress-cpu-hotp-2443  [003] ....   145.850757: call_srcu: enter
 stress-cpu-hotp-2443  [003] ....   145.850758: call_srcu: exit
 stress-cpu-hotp-2443  [004] ....   145.867433: synchronize_srcu: exit
 stress-cpu-hotp-2443  [004] ....   145.867597: synchronize_srcu: enter
 stress-cpu-hotp-2443  [004] ....   145.867598: call_srcu: enter
 stress-cpu-hotp-2443  [004] ....   145.867599: call_srcu: exit
 stress-cpu-hotp-2443  [005] ....   145.883680: synchronize_srcu: exit
 stress-cpu-hotp-2443  [005] ....   145.883843: synchronize_srcu: enter
 stress-cpu-hotp-2443  [005] ....   145.883843: call_srcu: enter
 stress-cpu-hotp-2443  [005] ....   145.883845: call_srcu: exit
 stress-cpu-hotp-2443  [006] ....   145.899908: synchronize_srcu: exit
 stress-cpu-hotp-2443  [006] ....   145.900073: synchronize_srcu: enter
 stress-cpu-hotp-2443  [006] ....   145.900073: call_srcu: enter
 stress-cpu-hotp-2443  [006] ....   145.900075: call_srcu: exit
 stress-cpu-hotp-2443  [007] ....   145.916213: synchronize_srcu: exit
 stress-cpu-hotp-2443  [007] ....   145.916405: synchronize_srcu: enter
 stress-cpu-hotp-2443  [007] ....   145.916406: call_srcu: enter
 stress-cpu-hotp-2443  [007] ....   145.916408: call_srcu: exit
 stress-cpu-hotp-2443  [000] ....   145.932453: synchronize_srcu: exit
 stress-cpu-hotp-2443  [000] ....   145.932653: synchronize_srcu: enter
 stress-cpu-hotp-2443  [000] ....   145.932653: call_srcu: enter
 stress-cpu-hotp-2443  [000] ....   145.932656: call_srcu: exit
 stress-cpu-hotp-2443  [003] ....   145.946674: synchronize_srcu: exit
 stress-cpu-hotp-2443  [003] ....   145.946818: synchronize_srcu: enter
 stress-cpu-hotp-2443  [003] ....   145.946819: call_srcu: enter
 stress-cpu-hotp-2443  [003] ....   145.946820: call_srcu: exit
 stress-cpu-hotp-2443  [004] ....   145.963402: synchronize_srcu: exit
 stress-cpu-hotp-2443  [004] ....   145.963539: synchronize_srcu: enter
 stress-cpu-hotp-2443  [004] ....   145.963540: call_srcu: enter
 stress-cpu-hotp-2443  [004] ....   145.963542: call_srcu: exit
 stress-cpu-hotp-2443  [005] ....   145.979671: synchronize_srcu: exit
 stress-cpu-hotp-2443  [005] ....   145.979790: synchronize_srcu: enter
 stress-cpu-hotp-2443  [005] ....   145.979790: call_srcu: enter
 stress-cpu-hotp-2443  [005] ....   145.979792: call_srcu: exit
 stress-cpu-hotp-2443  [006] ....   145.995927: synchronize_srcu: exit
 stress-cpu-hotp-2443  [006] ....   145.996046: synchronize_srcu: enter
 stress-cpu-hotp-2443  [006] ....   145.996046: call_srcu: enter
 stress-cpu-hotp-2443  [006] ....   145.996048: call_srcu: exit
 stress-cpu-hotp-2443  [007] ....   146.012167: synchronize_srcu: exit
 stress-cpu-hotp-2443  [007] ....   146.012282: synchronize_srcu: enter
 stress-cpu-hotp-2443  [007] ....   146.012283: call_srcu: enter
 stress-cpu-hotp-2443  [007] ....   146.012284: call_srcu: exit
 stress-cpu-hotp-2443  [000] ....   146.028405: synchronize_srcu: exit
 stress-cpu-hotp-2443  [000] ....   146.028522: synchronize_srcu: enter
 stress-cpu-hotp-2443  [000] ....   146.028522: call_srcu: enter
 stress-cpu-hotp-2443  [000] ....   146.028523: call_srcu: exit
 stress-cpu-hotp-2443  [003] ....   146.042653: synchronize_srcu: exit
 stress-cpu-hotp-2443  [003] ....   146.042774: synchronize_srcu: enter
 stress-cpu-hotp-2443  [003] ....   146.042774: call_srcu: enter
 stress-cpu-hotp-2443  [003] ....   146.042775: call_srcu: exit
 stress-cpu-hotp-2443  [004] ....   146.059407: synchronize_srcu: exit
 stress-cpu-hotp-2443  [004] ....   146.059521: synchronize_srcu: enter
 stress-cpu-hotp-2443  [004] ....   146.059522: call_srcu: enter
 stress-cpu-hotp-2443  [004] ....   146.059523: call_srcu: exit
 stress-cpu-hotp-2443  [005] ....   146.075658: synchronize_srcu: exit
 stress-cpu-hotp-2443  [005] ....   146.075772: synchronize_srcu: enter
 stress-cpu-hotp-2443  [005] ....   146.075773: call_srcu: enter
 stress-cpu-hotp-2443  [005] ....   146.075774: call_srcu: exit
 stress-cpu-hotp-2443  [006] ....   146.091906: synchronize_srcu: exit
 stress-cpu-hotp-2443  [006] ....   146.092021: synchronize_srcu: enter
 stress-cpu-hotp-2443  [006] ....   146.092022: call_srcu: enter
 stress-cpu-hotp-2443  [006] ....   146.092023: call_srcu: exit
 stress-cpu-hotp-2443  [007] ....   146.108187: synchronize_srcu: exit
 stress-cpu-hotp-2443  [007] ....   146.108336: synchronize_srcu: enter
 stress-cpu-hotp-2443  [007] ....   146.108337: call_srcu: enter
 stress-cpu-hotp-2443  [007] ....   146.108338: call_srcu: exit
 stress-cpu-hotp-2443  [000] ....   146.124439: synchronize_srcu: exit
 stress-cpu-hotp-2443  [000] ....   146.124572: synchronize_srcu: enter
 stress-cpu-hotp-2443  [000] ....   146.124572: call_srcu: enter
 stress-cpu-hotp-2443  [000] ....   146.124574: call_srcu: exit
 stress-cpu-hotp-2443  [003] ....   146.138656: synchronize_srcu: exit
 stress-cpu-hotp-2443  [003] ....   146.138773: synchronize_srcu: enter
 stress-cpu-hotp-2443  [003] ....   146.138773: call_srcu: enter
 stress-cpu-hotp-2443  [003] ....   146.138774: call_srcu: exit

^ permalink raw reply	[flat|nested] 24+ messages in thread

* Re: TREE_SRCU slows hotplug by factor ~16
  2017-04-24  7:35       ` Mike Galbraith
@ 2017-04-24  8:43         ` Mike Galbraith
  2017-04-24 16:24         ` Paul E. McKenney
  1 sibling, 0 replies; 24+ messages in thread
From: Mike Galbraith @ 2017-04-24  8:43 UTC (permalink / raw)
  To: paulmck; +Cc: LKML

On Mon, 2017-04-24 at 09:35 +0200, Mike Galbraith wrote:

> # tracer: nop
> #
> # entries-in-buffer/entries-written: 229332/229332   #P:8
> #
> #                              _-----=> irqs-off
> #                             / _----=> need-resched
> #                            | / _---=> hardirq/softirq
> #                            || / _--=> preempt-depth
> #                            ||| /     delay
> #           TASK-PID   CPU#  ||||    TIMESTAMP  FUNCTION
> #              | |       |   ||||       |         |
>  stress-cpu-hotp-2443  [004] ....   144.123608: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [004] ....   144.123610: call_srcu: enter
>  stress-cpu-hotp-2443  [004] ....   144.123612: call_srcu: exit
>  stress-cpu-hotp-2443  [005] ....   144.139528: synchronize_srcu: exit

I probably could have sent a LOT less trace.

classic:

# tracer: nop
#
# entries-in-buffer/entries-written: 114688/114688   #P:8
#
#                              _-----=> irqs-off
#                             / _----=> need-resched
#                            | / _---=> hardirq/softirq
#                            || / _--=> preempt-depth
#                            ||| /     delay
#           TASK-PID   CPU#  ||||    TIMESTAMP  FUNCTION
#              | |       |   ||||       |         |
 stress-cpu-hotp-4337  [007] ....   174.082801: synchronize_srcu: enter
 stress-cpu-hotp-4337  [007] ....   174.082802: synchronize_srcu: exit
 stress-cpu-hotp-4337  [007] ....   174.082896: synchronize_srcu: enter
 stress-cpu-hotp-4337  [007] ....   174.082896: synchronize_srcu: exit
 stress-cpu-hotp-4337  [007] ....   174.082975: synchronize_srcu: enter
 stress-cpu-hotp-4337  [007] ....   174.082975: synchronize_srcu: exit
 stress-cpu-hotp-4337  [007] ....   174.083051: synchronize_srcu: enter
 stress-cpu-hotp-4337  [007] ....   174.083051: synchronize_srcu: exit
....

^ permalink raw reply	[flat|nested] 24+ messages in thread

* Re: TREE_SRCU slows hotplug by factor ~16
  2017-04-24  7:35       ` Mike Galbraith
  2017-04-24  8:43         ` Mike Galbraith
@ 2017-04-24 16:24         ` Paul E. McKenney
  2017-04-25 22:36           ` Paul E. McKenney
  1 sibling, 1 reply; 24+ messages in thread
From: Paul E. McKenney @ 2017-04-24 16:24 UTC (permalink / raw)
  To: Mike Galbraith; +Cc: LKML

On Mon, Apr 24, 2017 at 09:35:03AM +0200, Mike Galbraith wrote:
> On Sun, 2017-04-23 at 23:22 -0700, Paul E. McKenney wrote:
> 
> > Could you please collect an ftrace (or whatever) showing the timestamp
> > sequence of calls to synchronize_srcu(), synchronize_srcu_expedited(),
> > and call_srcu() during the execution of the stress script?  If it is easy
> > to do, also the timestamp sequence of returns from synchronize_srcu()
> > and synchronize_srcu_expedited()?
> 
> The first two minutes below config bits, trace_printk([enter/exit]) in
> each function.  If you (unlikely, but..) want the whole trace, holler.
> 
> # RCU Subsystem
> CONFIG_TREE_RCU=y
> CONFIG_RCU_EXPERT=y
> CONFIG_SRCU=y
> # CONFIG_CLASSIC_SRCU is not set
> CONFIG_TREE_SRCU=y
> # CONFIG_TASKS_RCU is not set
> CONFIG_RCU_STALL_COMMON=y
> CONFIG_RCU_FANOUT=64
> CONFIG_RCU_FANOUT_LEAF=16
> # CONFIG_RCU_FAST_NO_HZ is not set
> # CONFIG_TREE_RCU_TRACE is not set
> CONFIG_RCU_KTHREAD_PRIO=0
> CONFIG_RCU_NOCB_CPU=y
> CONFIG_RCU_NOCB_CPU_NONE=y
> # CONFIG_RCU_NOCB_CPU_ZERO is not set
> # CONFIG_RCU_NOCB_CPU_ALL is not set
> # RCU Debugging
> # CONFIG_PROVE_RCU is not set
> # CONFIG_SPARSE_RCU_POINTER is not set
> # CONFIG_RCU_PERF_TEST is not set
> # CONFIG_RCU_TORTURE_TEST is not set
> CONFIG_RCU_CPU_STALL_TIMEOUT=60
> # CONFIG_RCU_TRACE is not set
> # CONFIG_RCU_EQS_DEBUG is not set

Thank you for the data, extremely helpful!  I now know that I must
immediately fix this the hard way rather than trying several simpler
possibilities that, according to your trace data, would be complete
wastes of time.

My initial calculation was actually optimistic.  There was one
exit-to-enter interval at about 80 milliseconds, but the second
longest is 342 microseconds, and the vast majority are under 200
microseconds.

Back to the drawing board!

This will take some time, but I should have a patch for you in a few days,
hopefully sooner.

							Thanx, Paul

> # tracer: nop
> #
> # entries-in-buffer/entries-written: 229332/229332   #P:8
> #
> #                              _-----=> irqs-off
> #                             / _----=> need-resched
> #                            | / _---=> hardirq/softirq
> #                            || / _--=> preempt-depth
> #                            ||| /     delay
> #           TASK-PID   CPU#  ||||    TIMESTAMP  FUNCTION
> #              | |       |   ||||       |         |
>  stress-cpu-hotp-2443  [004] ....   144.123608: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [004] ....   144.123610: call_srcu: enter
>  stress-cpu-hotp-2443  [004] ....   144.123612: call_srcu: exit
>  stress-cpu-hotp-2443  [005] ....   144.139528: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [005] ....   144.139646: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [005] ....   144.139646: call_srcu: enter
>  stress-cpu-hotp-2443  [005] ....   144.139648: call_srcu: exit
>  stress-cpu-hotp-2443  [006] ....   144.155813: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [006] ....   144.155981: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [006] ....   144.155982: call_srcu: enter
>  stress-cpu-hotp-2443  [006] ....   144.155983: call_srcu: exit
>  stress-cpu-hotp-2443  [007] ....   144.172078: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [007] ....   144.172234: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [007] ....   144.172235: call_srcu: enter
>  stress-cpu-hotp-2443  [007] ....   144.172237: call_srcu: exit
>  stress-cpu-hotp-2443  [000] ....   144.188319: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [000] ....   144.188465: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [000] ....   144.188466: call_srcu: enter
>  stress-cpu-hotp-2443  [000] ....   144.188468: call_srcu: exit
>  stress-cpu-hotp-2443  [002] ....   144.202528: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [002] ....   144.202650: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [002] ....   144.202651: call_srcu: enter
>  stress-cpu-hotp-2443  [002] ....   144.202652: call_srcu: exit
>  stress-cpu-hotp-2443  [003] ....   144.219081: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [003] ....   144.219238: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [003] ....   144.219238: call_srcu: enter
>  stress-cpu-hotp-2443  [003] ....   144.219240: call_srcu: exit
>  stress-cpu-hotp-2443  [004] ....   144.235319: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [004] ....   144.235567: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [004] ....   144.235568: call_srcu: enter
>  stress-cpu-hotp-2443  [004] ....   144.235571: call_srcu: exit
>  stress-cpu-hotp-2443  [005] ....   144.251548: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [005] ....   144.251706: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [005] ....   144.251706: call_srcu: enter
>  stress-cpu-hotp-2443  [005] ....   144.251708: call_srcu: exit
>  stress-cpu-hotp-2443  [006] ....   144.267865: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [006] ....   144.268132: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [006] ....   144.268133: call_srcu: enter
>  stress-cpu-hotp-2443  [006] ....   144.268136: call_srcu: exit
>  stress-cpu-hotp-2443  [007] ....   144.284078: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [007] ....   144.284257: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [007] ....   144.284258: call_srcu: enter
>  stress-cpu-hotp-2443  [007] ....   144.284260: call_srcu: exit
>  stress-cpu-hotp-2443  [000] ....   144.300314: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [000] ....   144.300462: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [000] ....   144.300463: call_srcu: enter
>  stress-cpu-hotp-2443  [000] ....   144.300464: call_srcu: exit
>  stress-cpu-hotp-2443  [002] ....   144.314533: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [002] ....   144.314657: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [002] ....   144.314658: call_srcu: enter
>  stress-cpu-hotp-2443  [002] ....   144.314659: call_srcu: exit
>  stress-cpu-hotp-2443  [003] ....   144.331056: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [003] ....   144.331227: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [003] ....   144.331227: call_srcu: enter
>  stress-cpu-hotp-2443  [003] ....   144.331229: call_srcu: exit
>  stress-cpu-hotp-2443  [004] ....   144.347334: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [004] ....   144.347517: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [004] ....   144.347518: call_srcu: enter
>  stress-cpu-hotp-2443  [004] ....   144.347519: call_srcu: exit
>  stress-cpu-hotp-2443  [005] ....   144.363567: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [005] ....   144.363731: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [005] ....   144.363732: call_srcu: enter
>  stress-cpu-hotp-2443  [005] ....   144.363733: call_srcu: exit
>  stress-cpu-hotp-2443  [006] ....   144.379804: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [006] ....   144.379987: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [006] ....   144.379988: call_srcu: enter
>  stress-cpu-hotp-2443  [006] ....   144.379989: call_srcu: exit
>  stress-cpu-hotp-2443  [007] ....   144.396077: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [007] ....   144.396259: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [007] ....   144.396260: call_srcu: enter
>  stress-cpu-hotp-2443  [007] ....   144.396261: call_srcu: exit
>  stress-cpu-hotp-2443  [000] ....   144.412385: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [000] ....   144.412653: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [000] ....   144.412654: call_srcu: enter
>  stress-cpu-hotp-2443  [000] ....   144.412657: call_srcu: exit
>  stress-cpu-hotp-2443  [002] ....   144.426647: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [002] ....   144.426888: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [002] ....   144.426889: call_srcu: enter
>  stress-cpu-hotp-2443  [002] ....   144.426891: call_srcu: exit
>  stress-cpu-hotp-2443  [003] ....   144.443134: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [003] ....   144.443325: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [003] ....   144.443325: call_srcu: enter
>  stress-cpu-hotp-2443  [003] ....   144.443327: call_srcu: exit
>  stress-cpu-hotp-2443  [004] ....   144.459327: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [004] ....   144.459521: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [004] ....   144.459522: call_srcu: enter
>  stress-cpu-hotp-2443  [004] ....   144.459524: call_srcu: exit
>  stress-cpu-hotp-2443  [005] ....   144.475553: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [005] ....   144.475672: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [005] ....   144.475673: call_srcu: enter
>  stress-cpu-hotp-2443  [005] ....   144.475674: call_srcu: exit
>  stress-cpu-hotp-2443  [006] ....   144.491798: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [006] ....   144.491919: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [006] ....   144.491920: call_srcu: enter
>  stress-cpu-hotp-2443  [006] ....   144.491921: call_srcu: exit
>  stress-cpu-hotp-2443  [007] ....   144.508035: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [007] ....   144.508160: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [007] ....   144.508161: call_srcu: enter
>  stress-cpu-hotp-2443  [007] ....   144.508162: call_srcu: exit
>  stress-cpu-hotp-2443  [000] ....   144.524301: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [000] ....   144.524419: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [000] ....   144.524419: call_srcu: enter
>  stress-cpu-hotp-2443  [000] ....   144.524421: call_srcu: exit
>  stress-cpu-hotp-2443  [002] ....   144.538545: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [002] ....   144.538665: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [002] ....   144.538666: call_srcu: enter
>  stress-cpu-hotp-2443  [002] ....   144.538667: call_srcu: exit
>  stress-cpu-hotp-2443  [003] ....   144.555051: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [003] ....   144.555174: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [003] ....   144.555174: call_srcu: enter
>  stress-cpu-hotp-2443  [003] ....   144.555175: call_srcu: exit
>  stress-cpu-hotp-2443  [004] ....   144.571290: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [004] ....   144.571412: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [004] ....   144.571412: call_srcu: enter
>  stress-cpu-hotp-2443  [004] ....   144.571413: call_srcu: exit
>  stress-cpu-hotp-2443  [005] ....   144.587554: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [005] ....   144.587672: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [005] ....   144.587673: call_srcu: enter
>  stress-cpu-hotp-2443  [005] ....   144.587674: call_srcu: exit
>  stress-cpu-hotp-2443  [006] ....   144.603843: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [006] ....   144.604008: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [006] ....   144.604008: call_srcu: enter
>  stress-cpu-hotp-2443  [006] ....   144.604010: call_srcu: exit
>  stress-cpu-hotp-2443  [007] ....   144.620087: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [007] ....   144.620317: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [007] ....   144.620318: call_srcu: enter
>  stress-cpu-hotp-2443  [007] ....   144.620321: call_srcu: exit
>  stress-cpu-hotp-2443  [000] ....   144.636342: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [000] ....   144.636520: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [000] ....   144.636521: call_srcu: enter
>  stress-cpu-hotp-2443  [000] ....   144.636523: call_srcu: exit
>  stress-cpu-hotp-2443  [002] ....   144.650579: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [002] ....   144.650737: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [002] ....   144.650738: call_srcu: enter
>  stress-cpu-hotp-2443  [002] ....   144.650739: call_srcu: exit
>  stress-cpu-hotp-2443  [003] ....   144.667084: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [003] ....   144.667247: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [003] ....   144.667247: call_srcu: enter
>  stress-cpu-hotp-2443  [003] ....   144.667249: call_srcu: exit
>  stress-cpu-hotp-2443  [004] ....   144.683340: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [004] ....   144.683513: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [004] ....   144.683514: call_srcu: enter
>  stress-cpu-hotp-2443  [004] ....   144.683516: call_srcu: exit
>  stress-cpu-hotp-2443  [005] ....   144.699556: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [005] ....   144.699675: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [005] ....   144.699675: call_srcu: enter
>  stress-cpu-hotp-2443  [005] ....   144.699676: call_srcu: exit
>  stress-cpu-hotp-2443  [006] ....   144.715841: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [006] ....   144.716013: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [006] ....   144.716014: call_srcu: enter
>  stress-cpu-hotp-2443  [006] ....   144.716015: call_srcu: exit
>  stress-cpu-hotp-2443  [007] ....   144.732096: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [007] ....   144.732269: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [007] ....   144.732270: call_srcu: enter
>  stress-cpu-hotp-2443  [007] ....   144.732271: call_srcu: exit
>  stress-cpu-hotp-2443  [000] ....   144.748393: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [000] ....   144.748641: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [000] ....   144.748642: call_srcu: enter
>  stress-cpu-hotp-2443  [000] ....   144.748645: call_srcu: exit
>  stress-cpu-hotp-2443  [002] ....   144.762639: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [002] ....   144.762854: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [002] ....   144.762855: call_srcu: enter
>  stress-cpu-hotp-2443  [002] ....   144.762857: call_srcu: exit
>  stress-cpu-hotp-2443  [003] ....   144.779100: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [003] ....   144.779278: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [003] ....   144.779279: call_srcu: enter
>  stress-cpu-hotp-2443  [003] ....   144.779280: call_srcu: exit
>  stress-cpu-hotp-2443  [004] ....   144.795348: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [004] ....   144.795525: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [004] ....   144.795526: call_srcu: enter
>  stress-cpu-hotp-2443  [004] ....   144.795527: call_srcu: exit
>  stress-cpu-hotp-2443  [005] ....   144.811583: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [005] ....   144.811749: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [005] ....   144.811750: call_srcu: enter
>  stress-cpu-hotp-2443  [005] ....   144.811751: call_srcu: exit
>  stress-cpu-hotp-2443  [006] ....   144.827831: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [006] ....   144.827997: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [006] ....   144.827998: call_srcu: enter
>  stress-cpu-hotp-2443  [006] ....   144.827999: call_srcu: exit
>  stress-cpu-hotp-2443  [007] ....   144.844104: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [007] ....   144.844281: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [007] ....   144.844281: call_srcu: enter
>  stress-cpu-hotp-2443  [007] ....   144.844283: call_srcu: exit
>  stress-cpu-hotp-2443  [000] ....   144.860339: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [000] ....   144.860484: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [000] ....   144.860485: call_srcu: enter
>  stress-cpu-hotp-2443  [000] ....   144.860487: call_srcu: exit
>  stress-cpu-hotp-2443  [002] ....   144.874584: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [002] ....   144.874737: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [002] ....   144.874737: call_srcu: enter
>  stress-cpu-hotp-2443  [002] ....   144.874739: call_srcu: exit
>  stress-cpu-hotp-2443  [003] ....   144.891117: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [003] ....   144.891459: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [003] ....   144.891460: call_srcu: enter
>  stress-cpu-hotp-2443  [003] ....   144.891463: call_srcu: exit
>  stress-cpu-hotp-2443  [004] ....   144.907376: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [004] ....   144.907628: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [004] ....   144.907629: call_srcu: enter
>  stress-cpu-hotp-2443  [004] ....   144.907631: call_srcu: exit
>  stress-cpu-hotp-2443  [005] ....   144.923590: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [005] ....   144.923756: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [005] ....   144.923756: call_srcu: enter
>  stress-cpu-hotp-2443  [005] ....   144.923758: call_srcu: exit
>  stress-cpu-hotp-2443  [006] ....   144.939837: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [006] ....   144.940007: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [006] ....   144.940008: call_srcu: enter
>  stress-cpu-hotp-2443  [006] ....   144.940009: call_srcu: exit
>  stress-cpu-hotp-2443  [007] ....   144.956110: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [007] ....   144.956285: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [007] ....   144.956286: call_srcu: enter
>  stress-cpu-hotp-2443  [007] ....   144.956287: call_srcu: exit
>  stress-cpu-hotp-2443  [000] ....   144.972344: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [000] ....   144.972492: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [000] ....   144.972493: call_srcu: enter
>  stress-cpu-hotp-2443  [000] ....   144.972495: call_srcu: exit
>  stress-cpu-hotp-2443  [002] ....   144.986566: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [002] ....   144.986689: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [002] ....   144.986689: call_srcu: enter
>  stress-cpu-hotp-2443  [002] ....   144.986690: call_srcu: exit
>  stress-cpu-hotp-2443  [003] ....   145.003114: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [003] ....   145.003292: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [003] ....   145.003293: call_srcu: enter
>  stress-cpu-hotp-2443  [003] ....   145.003294: call_srcu: exit
>  stress-cpu-hotp-2443  [004] ....   145.019350: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [004] ....   145.019528: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [004] ....   145.019529: call_srcu: enter
>  stress-cpu-hotp-2443  [004] ....   145.019531: call_srcu: exit
>  stress-cpu-hotp-2443  [005] ....   145.035659: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [005] ....   145.035939: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [005] ....   145.035940: call_srcu: enter
>  stress-cpu-hotp-2443  [005] ....   145.035943: call_srcu: exit
>  stress-cpu-hotp-2443  [006] ....   145.051891: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [006] ....   145.052106: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [006] ....   145.052107: call_srcu: enter
>  stress-cpu-hotp-2443  [006] ....   145.052109: call_srcu: exit
>  stress-cpu-hotp-2443  [007] ....   145.068125: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [007] ....   145.068279: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [007] ....   145.068279: call_srcu: enter
>  stress-cpu-hotp-2443  [007] ....   145.068280: call_srcu: exit
>  stress-cpu-hotp-2443  [000] ....   145.084332: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [000] ....   145.084472: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [000] ....   145.084473: call_srcu: enter
>  stress-cpu-hotp-2443  [000] ....   145.084474: call_srcu: exit
>  stress-cpu-hotp-2443  [002] ....   145.098605: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [002] ....   145.098743: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [002] ....   145.098744: call_srcu: enter
>  stress-cpu-hotp-2443  [002] ....   145.098745: call_srcu: exit
>  stress-cpu-hotp-2443  [003] ....   145.114590: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [003] ....   145.114728: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [003] ....   145.114728: call_srcu: enter
>  stress-cpu-hotp-2443  [003] ....   145.114729: call_srcu: exit
>  stress-cpu-hotp-2443  [005] ....   145.130591: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [005] ....   145.130728: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [005] ....   145.130728: call_srcu: enter
>  stress-cpu-hotp-2443  [005] ....   145.130730: call_srcu: exit
>  stress-cpu-hotp-2443  [006] ....   145.147857: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [006] ....   145.228078: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [006] ....   145.228079: call_srcu: enter
>  stress-cpu-hotp-2443  [006] ....   145.228080: call_srcu: exit
>  stress-cpu-hotp-2443  [007] ....   145.244025: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [007] ....   145.244106: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [007] ....   145.244106: call_srcu: enter
>  stress-cpu-hotp-2443  [007] ....   145.244107: call_srcu: exit
>  stress-cpu-hotp-2443  [000] ....   145.260286: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [000] ....   145.260361: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [000] ....   145.260361: call_srcu: enter
>  stress-cpu-hotp-2443  [000] ....   145.260362: call_srcu: exit
>  stress-cpu-hotp-2443  [003] ....   145.274522: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [003] ....   145.274594: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [003] ....   145.274594: call_srcu: enter
>  stress-cpu-hotp-2443  [003] ....   145.274595: call_srcu: exit
>  stress-cpu-hotp-2443  [004] ....   145.291289: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [004] ....   145.291358: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [004] ....   145.291358: call_srcu: enter
>  stress-cpu-hotp-2443  [004] ....   145.291359: call_srcu: exit
>  stress-cpu-hotp-2443  [005] ....   145.307529: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [005] ....   145.307599: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [005] ....   145.307599: call_srcu: enter
>  stress-cpu-hotp-2443  [005] ....   145.307600: call_srcu: exit
>  stress-cpu-hotp-2443  [006] ....   145.323901: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [006] ....   145.324063: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [006] ....   145.324063: call_srcu: enter
>  stress-cpu-hotp-2443  [006] ....   145.324065: call_srcu: exit
>  stress-cpu-hotp-2443  [007] ....   145.340122: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [007] ....   145.340288: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [007] ....   145.340289: call_srcu: enter
>  stress-cpu-hotp-2443  [007] ....   145.340291: call_srcu: exit
>  stress-cpu-hotp-2443  [000] ....   145.356378: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [000] ....   145.356519: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [000] ....   145.356520: call_srcu: enter
>  stress-cpu-hotp-2443  [000] ....   145.356521: call_srcu: exit
>  stress-cpu-hotp-2443  [003] ....   145.370650: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [003] ....   145.370797: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [003] ....   145.370798: call_srcu: enter
>  stress-cpu-hotp-2443  [003] ....   145.370799: call_srcu: exit
>  stress-cpu-hotp-2443  [004] ....   145.387385: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [004] ....   145.387547: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [004] ....   145.387548: call_srcu: enter
>  stress-cpu-hotp-2443  [004] ....   145.387549: call_srcu: exit
>  stress-cpu-hotp-2443  [005] ....   145.403636: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [005] ....   145.403799: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [005] ....   145.403800: call_srcu: enter
>  stress-cpu-hotp-2443  [005] ....   145.403802: call_srcu: exit
>  stress-cpu-hotp-2443  [006] ....   145.419885: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [006] ....   145.420055: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [006] ....   145.420056: call_srcu: enter
>  stress-cpu-hotp-2443  [006] ....   145.420057: call_srcu: exit
>  stress-cpu-hotp-2443  [007] ....   145.436154: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [007] ....   145.436372: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [007] ....   145.436372: call_srcu: enter
>  stress-cpu-hotp-2443  [007] ....   145.436374: call_srcu: exit
>  stress-cpu-hotp-2443  [000] ....   145.452413: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [000] ....   145.452550: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [000] ....   145.452551: call_srcu: enter
>  stress-cpu-hotp-2443  [000] ....   145.452552: call_srcu: exit
>  stress-cpu-hotp-2443  [003] ....   145.466606: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [003] ....   145.466721: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [003] ....   145.466721: call_srcu: enter
>  stress-cpu-hotp-2443  [003] ....   145.466722: call_srcu: exit
>  stress-cpu-hotp-2443  [004] ....   145.483395: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [004] ....   145.483555: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [004] ....   145.483555: call_srcu: enter
>  stress-cpu-hotp-2443  [004] ....   145.483557: call_srcu: exit
>  stress-cpu-hotp-2443  [005] ....   145.499628: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [005] ....   145.499761: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [005] .N..   145.499774: call_srcu: enter
>  stress-cpu-hotp-2443  [005] .N..   145.499775: call_srcu: exit
>  stress-cpu-hotp-2443  [006] ....   145.515879: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [006] ....   145.516009: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [006] ....   145.516009: call_srcu: enter
>  stress-cpu-hotp-2443  [006] ....   145.516011: call_srcu: exit
>  stress-cpu-hotp-2443  [007] ....   145.532164: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [007] ....   145.532488: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [007] ....   145.532489: call_srcu: enter
>  stress-cpu-hotp-2443  [007] ....   145.532492: call_srcu: exit
>  stress-cpu-hotp-2443  [000] ....   145.548447: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [000] ....   145.548659: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [000] ....   145.548660: call_srcu: enter
>  stress-cpu-hotp-2443  [000] ....   145.548663: call_srcu: exit
>  stress-cpu-hotp-2443  [003] ....   145.562706: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [003] ....   145.562897: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [003] ....   145.562898: call_srcu: enter
>  stress-cpu-hotp-2443  [003] ....   145.562900: call_srcu: exit
>  stress-cpu-hotp-2443  [004] ....   145.579403: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [004] ....   145.579562: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [004] ....   145.579563: call_srcu: enter
>  stress-cpu-hotp-2443  [004] ....   145.579564: call_srcu: exit
>  stress-cpu-hotp-2443  [005] ....   145.595636: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [005] ....   145.595766: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [005] ....   145.595766: call_srcu: enter
>  stress-cpu-hotp-2443  [005] ....   145.595768: call_srcu: exit
>  stress-cpu-hotp-2443  [006] ....   145.611902: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [006] ....   145.612059: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [006] ....   145.612060: call_srcu: enter
>  stress-cpu-hotp-2443  [006] ....   145.612061: call_srcu: exit
>  stress-cpu-hotp-2443  [007] ....   145.628136: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [007] ....   145.628266: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [007] ....   145.628267: call_srcu: enter
>  stress-cpu-hotp-2443  [007] ....   145.628268: call_srcu: exit
>  stress-cpu-hotp-2443  [000] ....   145.644392: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [000] ....   145.644518: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [000] ....   145.644519: call_srcu: enter
>  stress-cpu-hotp-2443  [000] ....   145.644521: call_srcu: exit
>  stress-cpu-hotp-2443  [003] ....   145.658609: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [003] ....   145.658698: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [003] ....   145.658699: call_srcu: enter
>  stress-cpu-hotp-2443  [003] ....   145.658700: call_srcu: exit
>  stress-cpu-hotp-2443  [004] ....   145.675410: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [004] ....   145.675570: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [004] ....   145.675571: call_srcu: enter
>  stress-cpu-hotp-2443  [004] ....   145.675572: call_srcu: exit
>  stress-cpu-hotp-2443  [005] ....   145.691706: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [005] ....   145.691950: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [005] ....   145.691951: call_srcu: enter
>  stress-cpu-hotp-2443  [005] ....   145.691953: call_srcu: exit
>  stress-cpu-hotp-2443  [006] ....   145.707926: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [006] ....   145.708096: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [006] ....   145.708097: call_srcu: enter
>  stress-cpu-hotp-2443  [006] ....   145.708099: call_srcu: exit
>  stress-cpu-hotp-2443  [007] ....   145.724154: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [007] ....   145.724333: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [007] ....   145.724333: call_srcu: enter
>  stress-cpu-hotp-2443  [007] ....   145.724335: call_srcu: exit
>  stress-cpu-hotp-2443  [000] ....   145.740412: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [000] ....   145.740559: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [000] ....   145.740559: call_srcu: enter
>  stress-cpu-hotp-2443  [000] ....   145.740561: call_srcu: exit
>  stress-cpu-hotp-2443  [003] ....   145.754685: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [003] ....   145.754835: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [003] ....   145.754836: call_srcu: enter
>  stress-cpu-hotp-2443  [003] ....   145.754838: call_srcu: exit
>  stress-cpu-hotp-2443  [004] ....   145.771415: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [004] ....   145.771591: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [004] ....   145.771592: call_srcu: enter
>  stress-cpu-hotp-2443  [004] ....   145.771594: call_srcu: exit
>  stress-cpu-hotp-2443  [005] ....   145.787635: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [005] ....   145.787747: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [005] ....   145.787748: call_srcu: enter
>  stress-cpu-hotp-2443  [005] ....   145.787749: call_srcu: exit
>  stress-cpu-hotp-2443  [006] ....   145.803943: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [006] ....   145.804168: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [006] ....   145.804170: call_srcu: enter
>  stress-cpu-hotp-2443  [006] ....   145.804172: call_srcu: exit
>  stress-cpu-hotp-2443  [007] ....   145.820168: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [007] ....   145.820320: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [007] ....   145.820321: call_srcu: enter
>  stress-cpu-hotp-2443  [007] ....   145.820322: call_srcu: exit
>  stress-cpu-hotp-2443  [000] ....   145.836412: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [000] ....   145.836543: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [000] ....   145.836544: call_srcu: enter
>  stress-cpu-hotp-2443  [000] ....   145.836545: call_srcu: exit
>  stress-cpu-hotp-2443  [003] ....   145.850638: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [003] ....   145.850757: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [003] ....   145.850757: call_srcu: enter
>  stress-cpu-hotp-2443  [003] ....   145.850758: call_srcu: exit
>  stress-cpu-hotp-2443  [004] ....   145.867433: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [004] ....   145.867597: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [004] ....   145.867598: call_srcu: enter
>  stress-cpu-hotp-2443  [004] ....   145.867599: call_srcu: exit
>  stress-cpu-hotp-2443  [005] ....   145.883680: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [005] ....   145.883843: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [005] ....   145.883843: call_srcu: enter
>  stress-cpu-hotp-2443  [005] ....   145.883845: call_srcu: exit
>  stress-cpu-hotp-2443  [006] ....   145.899908: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [006] ....   145.900073: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [006] ....   145.900073: call_srcu: enter
>  stress-cpu-hotp-2443  [006] ....   145.900075: call_srcu: exit
>  stress-cpu-hotp-2443  [007] ....   145.916213: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [007] ....   145.916405: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [007] ....   145.916406: call_srcu: enter
>  stress-cpu-hotp-2443  [007] ....   145.916408: call_srcu: exit
>  stress-cpu-hotp-2443  [000] ....   145.932453: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [000] ....   145.932653: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [000] ....   145.932653: call_srcu: enter
>  stress-cpu-hotp-2443  [000] ....   145.932656: call_srcu: exit
>  stress-cpu-hotp-2443  [003] ....   145.946674: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [003] ....   145.946818: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [003] ....   145.946819: call_srcu: enter
>  stress-cpu-hotp-2443  [003] ....   145.946820: call_srcu: exit
>  stress-cpu-hotp-2443  [004] ....   145.963402: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [004] ....   145.963539: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [004] ....   145.963540: call_srcu: enter
>  stress-cpu-hotp-2443  [004] ....   145.963542: call_srcu: exit
>  stress-cpu-hotp-2443  [005] ....   145.979671: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [005] ....   145.979790: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [005] ....   145.979790: call_srcu: enter
>  stress-cpu-hotp-2443  [005] ....   145.979792: call_srcu: exit
>  stress-cpu-hotp-2443  [006] ....   145.995927: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [006] ....   145.996046: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [006] ....   145.996046: call_srcu: enter
>  stress-cpu-hotp-2443  [006] ....   145.996048: call_srcu: exit
>  stress-cpu-hotp-2443  [007] ....   146.012167: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [007] ....   146.012282: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [007] ....   146.012283: call_srcu: enter
>  stress-cpu-hotp-2443  [007] ....   146.012284: call_srcu: exit
>  stress-cpu-hotp-2443  [000] ....   146.028405: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [000] ....   146.028522: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [000] ....   146.028522: call_srcu: enter
>  stress-cpu-hotp-2443  [000] ....   146.028523: call_srcu: exit
>  stress-cpu-hotp-2443  [003] ....   146.042653: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [003] ....   146.042774: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [003] ....   146.042774: call_srcu: enter
>  stress-cpu-hotp-2443  [003] ....   146.042775: call_srcu: exit
>  stress-cpu-hotp-2443  [004] ....   146.059407: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [004] ....   146.059521: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [004] ....   146.059522: call_srcu: enter
>  stress-cpu-hotp-2443  [004] ....   146.059523: call_srcu: exit
>  stress-cpu-hotp-2443  [005] ....   146.075658: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [005] ....   146.075772: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [005] ....   146.075773: call_srcu: enter
>  stress-cpu-hotp-2443  [005] ....   146.075774: call_srcu: exit
>  stress-cpu-hotp-2443  [006] ....   146.091906: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [006] ....   146.092021: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [006] ....   146.092022: call_srcu: enter
>  stress-cpu-hotp-2443  [006] ....   146.092023: call_srcu: exit
>  stress-cpu-hotp-2443  [007] ....   146.108187: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [007] ....   146.108336: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [007] ....   146.108337: call_srcu: enter
>  stress-cpu-hotp-2443  [007] ....   146.108338: call_srcu: exit
>  stress-cpu-hotp-2443  [000] ....   146.124439: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [000] ....   146.124572: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [000] ....   146.124572: call_srcu: enter
>  stress-cpu-hotp-2443  [000] ....   146.124574: call_srcu: exit
>  stress-cpu-hotp-2443  [003] ....   146.138656: synchronize_srcu: exit
>  stress-cpu-hotp-2443  [003] ....   146.138773: synchronize_srcu: enter
>  stress-cpu-hotp-2443  [003] ....   146.138773: call_srcu: enter
>  stress-cpu-hotp-2443  [003] ....   146.138774: call_srcu: exit
> 
> 

^ permalink raw reply	[flat|nested] 24+ messages in thread

* Re: TREE_SRCU slows hotplug by factor ~16
  2017-04-24 16:24         ` Paul E. McKenney
@ 2017-04-25 22:36           ` Paul E. McKenney
  2017-04-26 14:31             ` Paul E. McKenney
  0 siblings, 1 reply; 24+ messages in thread
From: Paul E. McKenney @ 2017-04-25 22:36 UTC (permalink / raw)
  To: Mike Galbraith; +Cc: LKML

On Mon, Apr 24, 2017 at 09:24:42AM -0700, Paul E. McKenney wrote:
> On Mon, Apr 24, 2017 at 09:35:03AM +0200, Mike Galbraith wrote:
> > On Sun, 2017-04-23 at 23:22 -0700, Paul E. McKenney wrote:
> > 
> > > Could you please collect an ftrace (or whatever) showing the timestamp
> > > sequence of calls to synchronize_srcu(), synchronize_srcu_expedited(),
> > > and call_srcu() during the execution of the stress script?  If it is easy
> > > to do, also the timestamp sequence of returns from synchronize_srcu()
> > > and synchronize_srcu_expedited()?
> > 
> > The first two minutes below config bits, trace_printk([enter/exit]) in
> > each function.  If you (unlikely, but..) want the whole trace, holler.
> > 
> > # RCU Subsystem
> > CONFIG_TREE_RCU=y
> > CONFIG_RCU_EXPERT=y
> > CONFIG_SRCU=y
> > # CONFIG_CLASSIC_SRCU is not set
> > CONFIG_TREE_SRCU=y
> > # CONFIG_TASKS_RCU is not set
> > CONFIG_RCU_STALL_COMMON=y
> > CONFIG_RCU_FANOUT=64
> > CONFIG_RCU_FANOUT_LEAF=16
> > # CONFIG_RCU_FAST_NO_HZ is not set
> > # CONFIG_TREE_RCU_TRACE is not set
> > CONFIG_RCU_KTHREAD_PRIO=0
> > CONFIG_RCU_NOCB_CPU=y
> > CONFIG_RCU_NOCB_CPU_NONE=y
> > # CONFIG_RCU_NOCB_CPU_ZERO is not set
> > # CONFIG_RCU_NOCB_CPU_ALL is not set
> > # RCU Debugging
> > # CONFIG_PROVE_RCU is not set
> > # CONFIG_SPARSE_RCU_POINTER is not set
> > # CONFIG_RCU_PERF_TEST is not set
> > # CONFIG_RCU_TORTURE_TEST is not set
> > CONFIG_RCU_CPU_STALL_TIMEOUT=60
> > # CONFIG_RCU_TRACE is not set
> > # CONFIG_RCU_EQS_DEBUG is not set
> 
> Thank you for the data, extremely helpful!  I now know that I must
> immediately fix this the hard way rather than trying several simpler
> possibilities that, according to your trace data, would be complete
> wastes of time.
> 
> My initial calculation was actually optimistic.  There was one
> exit-to-enter interval at about 80 milliseconds, but the second
> longest is 342 microseconds, and the vast majority are under 200
> microseconds.
> 
> Back to the drawing board!
> 
> This will take some time, but I should have a patch for you in a few days,
> hopefully sooner.

Making progress, might have something late tomorrow (Wednesday) Pacific
Time, will definitely have something Thursday Pacific Time.

								Thanx, Paul

^ permalink raw reply	[flat|nested] 24+ messages in thread

* Re: TREE_SRCU slows hotplug by factor ~16
  2017-04-25 22:36           ` Paul E. McKenney
@ 2017-04-26 14:31             ` Paul E. McKenney
  2017-04-26 15:26               ` Mike Galbraith
  0 siblings, 1 reply; 24+ messages in thread
From: Paul E. McKenney @ 2017-04-26 14:31 UTC (permalink / raw)
  To: Mike Galbraith; +Cc: LKML

On Tue, Apr 25, 2017 at 03:36:42PM -0700, Paul E. McKenney wrote:
> On Mon, Apr 24, 2017 at 09:24:42AM -0700, Paul E. McKenney wrote:
> > On Mon, Apr 24, 2017 at 09:35:03AM +0200, Mike Galbraith wrote:
> > > On Sun, 2017-04-23 at 23:22 -0700, Paul E. McKenney wrote:
> > > 
> > > > Could you please collect an ftrace (or whatever) showing the timestamp
> > > > sequence of calls to synchronize_srcu(), synchronize_srcu_expedited(),
> > > > and call_srcu() during the execution of the stress script?  If it is easy
> > > > to do, also the timestamp sequence of returns from synchronize_srcu()
> > > > and synchronize_srcu_expedited()?
> > > 
> > > The first two minutes below config bits, trace_printk([enter/exit]) in
> > > each function.  If you (unlikely, but..) want the whole trace, holler.
> > > 
> > > # RCU Subsystem
> > > CONFIG_TREE_RCU=y
> > > CONFIG_RCU_EXPERT=y
> > > CONFIG_SRCU=y
> > > # CONFIG_CLASSIC_SRCU is not set
> > > CONFIG_TREE_SRCU=y
> > > # CONFIG_TASKS_RCU is not set
> > > CONFIG_RCU_STALL_COMMON=y
> > > CONFIG_RCU_FANOUT=64
> > > CONFIG_RCU_FANOUT_LEAF=16
> > > # CONFIG_RCU_FAST_NO_HZ is not set
> > > # CONFIG_TREE_RCU_TRACE is not set
> > > CONFIG_RCU_KTHREAD_PRIO=0
> > > CONFIG_RCU_NOCB_CPU=y
> > > CONFIG_RCU_NOCB_CPU_NONE=y
> > > # CONFIG_RCU_NOCB_CPU_ZERO is not set
> > > # CONFIG_RCU_NOCB_CPU_ALL is not set
> > > # RCU Debugging
> > > # CONFIG_PROVE_RCU is not set
> > > # CONFIG_SPARSE_RCU_POINTER is not set
> > > # CONFIG_RCU_PERF_TEST is not set
> > > # CONFIG_RCU_TORTURE_TEST is not set
> > > CONFIG_RCU_CPU_STALL_TIMEOUT=60
> > > # CONFIG_RCU_TRACE is not set
> > > # CONFIG_RCU_EQS_DEBUG is not set
> > 
> > Thank you for the data, extremely helpful!  I now know that I must
> > immediately fix this the hard way rather than trying several simpler
> > possibilities that, according to your trace data, would be complete
> > wastes of time.
> > 
> > My initial calculation was actually optimistic.  There was one
> > exit-to-enter interval at about 80 milliseconds, but the second
> > longest is 342 microseconds, and the vast majority are under 200
> > microseconds.
> > 
> > Back to the drawing board!
> > 
> > This will take some time, but I should have a patch for you in a few days,
> > hopefully sooner.
> 
> Making progress, might have something late tomorrow (Wednesday) Pacific
> Time, will definitely have something Thursday Pacific Time.

And a sneak preview, semi-tested.  If you get a chance to run this, please
let me know now it goes.

This should apply on -tip or on -rcu.  Probably on recent -next as well.

							Thanx, Paul

------------------------------------------------------------------------

diff --git a/Documentation/admin-guide/kernel-parameters.txt b/Documentation/admin-guide/kernel-parameters.txt
index facc20a3f962..4a4b9266c4de 100644
--- a/Documentation/admin-guide/kernel-parameters.txt
+++ b/Documentation/admin-guide/kernel-parameters.txt
@@ -3779,6 +3779,14 @@
 	spia_pedr=
 	spia_peddr=
 
+	srcutree.exp_holdoff [KNL]
+			Specifies how many nanoseconds must elapse
+			since the end of the last SRCU grace period for
+			a given srcu_struct until the next normal SRCU
+			grace period will be considered for automatic
+			expediting.  Set to zero to disable automatic
+			expediting.
+
 	stacktrace	[FTRACE]
 			Enabled the stack tracer on boot up.
 
diff --git a/include/linux/srcuclassic.h b/include/linux/srcuclassic.h
index 41cf99930f34..5753f7322262 100644
--- a/include/linux/srcuclassic.h
+++ b/include/linux/srcuclassic.h
@@ -98,4 +98,18 @@ void synchronize_srcu_expedited(struct srcu_struct *sp);
 void srcu_barrier(struct srcu_struct *sp);
 unsigned long srcu_batches_completed(struct srcu_struct *sp);
 
+static inline void srcutorture_get_gp_data(enum rcutorture_type test_type,
+					   struct srcu_struct *sp, int *flags,
+					   unsigned long *gpnum,
+					   unsigned long *completed)
+{
+	if (test_type != SRCU_FLAVOR)
+		return;
+	*flags = 0;
+	*completed = sp->completed;
+	*gpnum = *completed;
+	if (sp->batch_queue.head || sp->batch_check0.head || sp->batch_check0.head)
+		(*gpnum)++;
+}
+
 #endif
diff --git a/include/linux/srcutiny.h b/include/linux/srcutiny.h
index 4f284e4f4d8c..42311ee0334f 100644
--- a/include/linux/srcutiny.h
+++ b/include/linux/srcutiny.h
@@ -78,4 +78,16 @@ static inline unsigned long srcu_batches_completed(struct srcu_struct *sp)
 	return 0;
 }
 
+static inline void srcutorture_get_gp_data(enum rcutorture_type test_type,
+					   struct srcu_struct *sp, int *flags,
+					   unsigned long *gpnum,
+					   unsigned long *completed)
+{
+	if (test_type != SRCU_FLAVOR)
+		return;
+	*flags = 0;
+	*completed = sp->srcu_gp_seq;
+	*gpnum = *completed;
+}
+
 #endif
diff --git a/include/linux/srcutree.h b/include/linux/srcutree.h
index 0400e211aa44..32e86d85fd11 100644
--- a/include/linux/srcutree.h
+++ b/include/linux/srcutree.h
@@ -43,10 +43,13 @@ struct srcu_data {
 	spinlock_t lock ____cacheline_internodealigned_in_smp;
 	struct rcu_segcblist srcu_cblist;	/* List of callbacks.*/
 	unsigned long srcu_gp_seq_needed;	/* Furthest future GP needed. */
+	unsigned long srcu_gp_seq_needed_exp;	/* Furthest future exp GP. */
 	bool srcu_cblist_invoking;		/* Invoking these CBs? */
 	struct delayed_work work;		/* Context for CB invoking. */
 	struct rcu_head srcu_barrier_head;	/* For srcu_barrier() use. */
 	struct srcu_node *mynode;		/* Leaf srcu_node. */
+	unsigned long grpmask;			/* Mask for leaf srcu_node */
+						/*  ->srcu_data_have_cbs[]. */
 	int cpu;
 	struct srcu_struct *sp;
 };
@@ -59,6 +62,9 @@ struct srcu_node {
 	unsigned long srcu_have_cbs[4];		/* GP seq for children */
 						/*  having CBs, but only */
 						/*  is > ->srcu_gq_seq. */
+	unsigned long srcu_data_have_cbs[4];	/* Which srcu_data structs */
+						/*  have CBs for given GP? */
+	unsigned long srcu_gp_seq_needed_exp;	/* Furthest future exp GP. */
 	struct srcu_node *srcu_parent;		/* Next up in tree. */
 	int grplo;				/* Least CPU for node. */
 	int grphi;				/* Biggest CPU for node. */
@@ -77,7 +83,8 @@ struct srcu_struct {
 	unsigned int srcu_idx;			/* Current rdr array element. */
 	unsigned long srcu_gp_seq;		/* Grace-period seq #. */
 	unsigned long srcu_gp_seq_needed;	/* Latest gp_seq needed. */
-	atomic_t srcu_exp_cnt;			/* # ongoing expedited GPs. */
+	unsigned long srcu_gp_seq_needed_exp;	/* Furthest future exp GP. */
+	unsigned long srcu_last_gp_end;		/* Last GP end timestamp (ns) */
 	struct srcu_data __percpu *sda;		/* Per-CPU srcu_data array. */
 	unsigned long srcu_barrier_seq;		/* srcu_barrier seq #. */
 	struct mutex srcu_barrier_mutex;	/* Serialize barrier ops. */
@@ -136,4 +143,8 @@ void synchronize_srcu_expedited(struct srcu_struct *sp);
 void srcu_barrier(struct srcu_struct *sp);
 unsigned long srcu_batches_completed(struct srcu_struct *sp);
 
+void srcutorture_get_gp_data(enum rcutorture_type test_type,
+			     struct srcu_struct *sp, int *flags,
+			     unsigned long *gpnum, unsigned long *completed);
+
 #endif
diff --git a/kernel/rcu/rcutorture.c b/kernel/rcu/rcutorture.c
index e9d4527cdd43..ae6e574d4cf5 100644
--- a/kernel/rcu/rcutorture.c
+++ b/kernel/rcu/rcutorture.c
@@ -1360,12 +1360,14 @@ rcu_torture_stats_print(void)
 		cur_ops->stats();
 	if (rtcv_snap == rcu_torture_current_version &&
 	    rcu_torture_current != NULL) {
-		int __maybe_unused flags;
-		unsigned long __maybe_unused gpnum;
-		unsigned long __maybe_unused completed;
+		int __maybe_unused flags = 0;
+		unsigned long __maybe_unused gpnum = 0;
+		unsigned long __maybe_unused completed = 0;
 
 		rcutorture_get_gp_data(cur_ops->ttype,
 				       &flags, &gpnum, &completed);
+		srcutorture_get_gp_data(cur_ops->ttype, srcu_ctlp,
+					&flags, &gpnum, &completed);
 		wtp = READ_ONCE(writer_task);
 		pr_alert("??? Writer stall state %s(%d) g%lu c%lu f%#x ->state %#lx\n",
 			 rcu_torture_writer_state_getname(),
diff --git a/kernel/rcu/srcutree.c b/kernel/rcu/srcutree.c
index 9ecf0acc18eb..b09221912f48 100644
--- a/kernel/rcu/srcutree.c
+++ b/kernel/rcu/srcutree.c
@@ -34,10 +34,14 @@
 #include <linux/sched.h>
 #include <linux/smp.h>
 #include <linux/delay.h>
+#include <linux/module.h>
 #include <linux/srcu.h>
 
 #include "rcu.h"
 
+ulong exp_holdoff = 50 * 1000; /* Holdoff (ns) for auto-expediting. */
+module_param(exp_holdoff, ulong, 0444);
+
 static void srcu_invoke_callbacks(struct work_struct *work);
 static void srcu_reschedule(struct srcu_struct *sp, unsigned long delay);
 
@@ -66,8 +70,13 @@ static void init_srcu_struct_nodes(struct srcu_struct *sp, bool is_static)
 	/* Each pass through this loop initializes one srcu_node structure. */
 	rcu_for_each_node_breadth_first(sp, snp) {
 		spin_lock_init(&snp->lock);
-		for (i = 0; i < ARRAY_SIZE(snp->srcu_have_cbs); i++)
+		WARN_ON_ONCE(ARRAY_SIZE(snp->srcu_have_cbs) !=
+			     ARRAY_SIZE(snp->srcu_data_have_cbs));
+		for (i = 0; i < ARRAY_SIZE(snp->srcu_have_cbs); i++) {
 			snp->srcu_have_cbs[i] = 0;
+			snp->srcu_data_have_cbs[i] = 0;
+		}
+		snp->srcu_gp_seq_needed_exp = 0;
 		snp->grplo = -1;
 		snp->grphi = -1;
 		if (snp == &sp->node[0]) {
@@ -98,6 +107,7 @@ static void init_srcu_struct_nodes(struct srcu_struct *sp, bool is_static)
 		rcu_segcblist_init(&sdp->srcu_cblist);
 		sdp->srcu_cblist_invoking = false;
 		sdp->srcu_gp_seq_needed = sp->srcu_gp_seq;
+		sdp->srcu_gp_seq_needed_exp = sp->srcu_gp_seq;
 		sdp->mynode = &snp_first[cpu / levelspread[level]];
 		for (snp = sdp->mynode; snp != NULL; snp = snp->srcu_parent) {
 			if (snp->grplo < 0)
@@ -107,6 +117,7 @@ static void init_srcu_struct_nodes(struct srcu_struct *sp, bool is_static)
 		sdp->cpu = cpu;
 		INIT_DELAYED_WORK(&sdp->work, srcu_invoke_callbacks);
 		sdp->sp = sp;
+		sdp->grpmask = 1 << (cpu - sdp->mynode->grplo);
 		if (is_static)
 			continue;
 
@@ -130,7 +141,6 @@ static int init_srcu_struct_fields(struct srcu_struct *sp, bool is_static)
 	mutex_init(&sp->srcu_gp_mutex);
 	sp->srcu_idx = 0;
 	sp->srcu_gp_seq = 0;
-	atomic_set(&sp->srcu_exp_cnt, 0);
 	sp->srcu_barrier_seq = 0;
 	mutex_init(&sp->srcu_barrier_mutex);
 	atomic_set(&sp->srcu_barrier_cpu_cnt, 0);
@@ -138,6 +148,8 @@ static int init_srcu_struct_fields(struct srcu_struct *sp, bool is_static)
 	if (!is_static)
 		sp->sda = alloc_percpu(struct srcu_data);
 	init_srcu_struct_nodes(sp, is_static);
+	sp->srcu_gp_seq_needed_exp = 0;
+	sp->srcu_last_gp_end = ktime_get_mono_fast_ns();
 	smp_store_release(&sp->srcu_gp_seq_needed, 0); /* Init done. */
 	return sp->sda ? 0 : -ENOMEM;
 }
@@ -302,6 +314,18 @@ static bool srcu_readers_active(struct srcu_struct *sp)
 
 #define SRCU_INTERVAL		1
 
+/*
+ * Return grace-period delay, zero if there are expedited grace
+ * periods pending, SRCU_INTERVAL otherwise.
+ */
+static unsigned long srcu_get_delay(struct srcu_struct *sp)
+{
+	if (ULONG_CMP_LT(READ_ONCE(sp->srcu_gp_seq),
+			 READ_ONCE(sp->srcu_gp_seq_needed_exp)))
+		return 0;
+	return SRCU_INTERVAL;
+}
+
 /**
  * cleanup_srcu_struct - deconstruct a sleep-RCU structure
  * @sp: structure to clean up.
@@ -313,7 +337,8 @@ void cleanup_srcu_struct(struct srcu_struct *sp)
 {
 	int cpu;
 
-	WARN_ON_ONCE(atomic_read(&sp->srcu_exp_cnt));
+	if (WARN_ON(!srcu_get_delay(sp)))
+		return; /* Leakage unless caller handles error. */
 	if (WARN_ON(srcu_readers_active(sp)))
 		return; /* Leakage unless caller handles error. */
 	flush_delayed_work(&sp->work);
@@ -382,6 +407,7 @@ static void srcu_gp_start(struct srcu_struct *sp)
 			      rcu_seq_current(&sp->srcu_gp_seq));
 	(void)rcu_segcblist_accelerate(&sdp->srcu_cblist,
 				       rcu_seq_snap(&sp->srcu_gp_seq));
+	smp_mb(); /* Order prior store to ->srcu_gp_seq_needed vs. GP start. */
 	rcu_seq_start(&sp->srcu_gp_seq);
 	state = rcu_seq_state(READ_ONCE(sp->srcu_gp_seq));
 	WARN_ON_ONCE(state != SRCU_STATE_SCAN1);
@@ -434,16 +460,20 @@ static void srcu_schedule_cbs_sdp(struct srcu_data *sdp, unsigned long delay)
 
 /*
  * Schedule callback invocation for all srcu_data structures associated
- * with the specified srcu_node structure, if possible, on the corresponding
- * CPUs.
+ * with the specified srcu_node structure that have callbacks for the
+ * just-completed grace period, the one corresponding to idx.  If possible,
+ * schedule this invocation on the corresponding CPUs.
  */
-static void srcu_schedule_cbs_snp(struct srcu_struct *sp, struct srcu_node *snp)
+static void srcu_schedule_cbs_snp(struct srcu_struct *sp, struct srcu_node *snp,
+				  unsigned long mask, unsigned long delay)
 {
 	int cpu;
 
-	for (cpu = snp->grplo; cpu <= snp->grphi; cpu++)
-		srcu_schedule_cbs_sdp(per_cpu_ptr(sp->sda, cpu),
-				      atomic_read(&sp->srcu_exp_cnt) ? 0 : SRCU_INTERVAL);
+	for (cpu = snp->grplo; cpu <= snp->grphi; cpu++) {
+		if (!(mask & (1 << (cpu - snp->grplo))))
+			continue;
+		srcu_schedule_cbs_sdp(per_cpu_ptr(sp->sda, cpu), delay);
+	}
 }
 
 /*
@@ -457,10 +487,12 @@ static void srcu_schedule_cbs_snp(struct srcu_struct *sp, struct srcu_node *snp)
  */
 static void srcu_gp_end(struct srcu_struct *sp)
 {
+	unsigned long cbdelay;
 	bool cbs;
 	unsigned long gpseq;
 	int idx;
 	int idxnext;
+	unsigned long mask;
 	struct srcu_node *snp;
 
 	/* Prevent more than one additional grace period. */
@@ -470,8 +502,12 @@ static void srcu_gp_end(struct srcu_struct *sp)
 	spin_lock_irq(&sp->gp_lock);
 	idx = rcu_seq_state(sp->srcu_gp_seq);
 	WARN_ON_ONCE(idx != SRCU_STATE_SCAN2);
+	cbdelay = srcu_get_delay(sp);
+	sp->srcu_last_gp_end = ktime_get_mono_fast_ns();
 	rcu_seq_end(&sp->srcu_gp_seq);
 	gpseq = rcu_seq_current(&sp->srcu_gp_seq);
+	if (ULONG_CMP_LT(sp->srcu_gp_seq_needed_exp, gpseq))
+		sp->srcu_gp_seq_needed_exp = gpseq;
 	spin_unlock_irq(&sp->gp_lock);
 	mutex_unlock(&sp->srcu_gp_mutex);
 	/* A new grace period can start at this point.  But only one. */
@@ -486,10 +522,14 @@ static void srcu_gp_end(struct srcu_struct *sp)
 			cbs = snp->srcu_have_cbs[idx] == gpseq;
 		snp->srcu_have_cbs[idx] = gpseq;
 		rcu_seq_set_state(&snp->srcu_have_cbs[idx], 1);
+		if (ULONG_CMP_LT(snp->srcu_gp_seq_needed_exp, gpseq))
+			snp->srcu_gp_seq_needed_exp = gpseq;
+		mask = snp->srcu_data_have_cbs[idx];
+		snp->srcu_data_have_cbs[idx] = 0;
 		spin_unlock_irq(&snp->lock);
 		if (cbs) {
 			smp_mb(); /* GP end before CB invocation. */
-			srcu_schedule_cbs_snp(sp, snp);
+			srcu_schedule_cbs_snp(sp, snp, mask, cbdelay);
 		}
 	}
 
@@ -504,25 +544,52 @@ static void srcu_gp_end(struct srcu_struct *sp)
 		srcu_gp_start(sp);
 		spin_unlock_irq(&sp->gp_lock);
 		/* Throttle expedited grace periods: Should be rare! */
-		srcu_reschedule(sp, atomic_read(&sp->srcu_exp_cnt) &&
-				    rcu_seq_ctr(gpseq) & 0xf
-				    ? 0
-				    : SRCU_INTERVAL);
+		srcu_reschedule(sp, rcu_seq_ctr(gpseq) & 0x3ff
+				    ? 0 : SRCU_INTERVAL);
 	} else {
 		spin_unlock_irq(&sp->gp_lock);
 	}
 }
 
 /*
+ * Funnel-locking scheme to scalably mediate many concurrent expedited
+ * grace-period requests.  This function is invoked for the first known
+ * expedited request for a grace period that has already been requested,
+ * but without expediting.  To start a completely new grace period,
+ * whether expedited or not, use srcu_funnel_gp_start() instead.
+ */
+static void srcu_funnel_exp_start(struct srcu_struct *sp, struct srcu_node *snp,
+				  unsigned long s)
+{
+	unsigned long flags;
+
+	for (; snp != NULL; snp = snp->srcu_parent) {
+		if (rcu_seq_done(&sp->srcu_gp_seq, s) ||
+		    ULONG_CMP_GE(READ_ONCE(snp->srcu_gp_seq_needed_exp), s))
+			return;
+		spin_lock_irqsave(&snp->lock, flags);
+		if (ULONG_CMP_GE(snp->srcu_gp_seq_needed_exp, s)) {
+			spin_unlock_irqrestore(&snp->lock, flags);
+			return;
+		}
+		WRITE_ONCE(snp->srcu_gp_seq_needed_exp, s);
+		spin_unlock_irqrestore(&snp->lock, flags);
+	}
+	spin_lock_irqsave(&sp->gp_lock, flags);
+	if (!ULONG_CMP_LT(sp->srcu_gp_seq_needed_exp, s))
+		sp->srcu_gp_seq_needed_exp = s;
+	spin_unlock_irqrestore(&sp->gp_lock, flags);
+}
+
+/*
  * Funnel-locking scheme to scalably mediate many concurrent grace-period
  * requests.  The winner has to do the work of actually starting grace
  * period s.  Losers must either ensure that their desired grace-period
  * number is recorded on at least their leaf srcu_node structure, or they
  * must take steps to invoke their own callbacks.
  */
-static void srcu_funnel_gp_start(struct srcu_struct *sp,
-				 struct srcu_data *sdp,
-				 unsigned long s)
+static void srcu_funnel_gp_start(struct srcu_struct *sp, struct srcu_data *sdp,
+				 unsigned long s, bool do_norm)
 {
 	unsigned long flags;
 	int idx = rcu_seq_ctr(s) % ARRAY_SIZE(sdp->mynode->srcu_have_cbs);
@@ -536,14 +603,25 @@ static void srcu_funnel_gp_start(struct srcu_struct *sp,
 		spin_lock_irqsave(&snp->lock, flags);
 		if (ULONG_CMP_GE(snp->srcu_have_cbs[idx], s)) {
 			snp_seq = snp->srcu_have_cbs[idx];
+			if (snp == sdp->mynode && snp_seq == s)
+				snp->srcu_data_have_cbs[idx] |= sdp->grpmask;
 			spin_unlock_irqrestore(&snp->lock, flags);
 			if (snp == sdp->mynode && snp_seq != s) {
 				smp_mb(); /* CBs after GP! */
-				srcu_schedule_cbs_sdp(sdp, 0);
+				srcu_schedule_cbs_sdp(sdp, do_norm
+							   ? SRCU_INTERVAL
+							   : 0);
+				return;
 			}
+			if (!do_norm)
+				srcu_funnel_exp_start(sp, snp, s);
 			return;
 		}
 		snp->srcu_have_cbs[idx] = s;
+		if (snp == sdp->mynode)
+			snp->srcu_data_have_cbs[idx] |= sdp->grpmask;
+		if (!do_norm && ULONG_CMP_LT(snp->srcu_gp_seq_needed_exp, s))
+			snp->srcu_gp_seq_needed_exp = s;
 		spin_unlock_irqrestore(&snp->lock, flags);
 	}
 
@@ -556,6 +634,8 @@ static void srcu_funnel_gp_start(struct srcu_struct *sp,
 		 */
 		smp_store_release(&sp->srcu_gp_seq_needed, s); /*^^^*/
 	}
+	if (!do_norm && ULONG_CMP_LT(sp->srcu_gp_seq_needed_exp, s))
+		sp->srcu_gp_seq_needed_exp = s;
 
 	/* If grace period not already done and none in progress, start it. */
 	if (!rcu_seq_done(&sp->srcu_gp_seq, s) &&
@@ -563,9 +643,7 @@ static void srcu_funnel_gp_start(struct srcu_struct *sp,
 		WARN_ON_ONCE(ULONG_CMP_GE(sp->srcu_gp_seq, sp->srcu_gp_seq_needed));
 		srcu_gp_start(sp);
 		queue_delayed_work(system_power_efficient_wq, &sp->work,
-				   atomic_read(&sp->srcu_exp_cnt)
-				   ? 0
-				   : SRCU_INTERVAL);
+				   srcu_get_delay(sp));
 	}
 	spin_unlock_irqrestore(&sp->gp_lock, flags);
 }
@@ -580,7 +658,7 @@ static bool try_check_zero(struct srcu_struct *sp, int idx, int trycount)
 	for (;;) {
 		if (srcu_readers_active_idx_check(sp, idx))
 			return true;
-		if (--trycount + !!atomic_read(&sp->srcu_exp_cnt) <= 0)
+		if (--trycount + !srcu_get_delay(sp) <= 0)
 			return false;
 		udelay(SRCU_RETRY_CHECK_DELAY);
 	}
@@ -606,6 +684,67 @@ static void srcu_flip(struct srcu_struct *sp)
 }
 
 /*
+ * If SRCU is likely idle, return true, otherwise return false.
+ *
+ * Note that it is OK for several current from-idle requests for a new
+ * grace period from idle to specify expediting because they will all end
+ * up requesting the same grace period anyhow.  So no loss.
+ *
+ * Note also that if any CPU (including the current one) is still invoking
+ * callbacks, this function will nevertheless say "idle".  This is not
+ * ideal, but the overhead of checking all CPUs' callback lists is even
+ * less ideal, especially on large systems.  Furthermore, the wakeup
+ * can happen before the callback is fully removed, so we have no choice
+ * but to accept this type of error.
+ *
+ * This function is also subject to counter-wrap errors, but let's face
+ * it, if this function was preempted for enough time for the counters
+ * to wrap, it really doesn't matter whether or not we expedite the grace
+ * period.  The extra overhead of a needlessly expedited grace period is
+ * negligible when amoritized over that time period, and the extra latency
+ * of a needlessly non-expedited grace period is similarly negligible.
+ */
+static bool srcu_might_be_idle(struct srcu_struct *sp)
+{
+	unsigned long curseq;
+	unsigned long flags;
+	struct srcu_data *sdp;
+	unsigned long t;
+
+	/* If the local srcu_data structure has callbacks, not idle.  */
+	local_irq_save(flags);
+	sdp = this_cpu_ptr(sp->sda);
+	if (rcu_segcblist_pend_cbs(&sdp->srcu_cblist)) {
+		local_irq_restore(flags);
+		return false; /* Callbacks already present, so not idle. */
+	}
+	local_irq_restore(flags);
+
+	/*
+	 * No local callbacks, so probabalistically probe global state.
+	 * Exact information would require acquiring locks, which would
+	 * kill scalability, hence the probabalistic nature of the probe.
+	 */
+
+	/* First, see if enough time has passed since the last GP. */
+	t = ktime_get_mono_fast_ns();
+	if (exp_holdoff == 0 ||
+	    time_in_range_open(t, sp->srcu_last_gp_end,
+			       sp->srcu_last_gp_end + exp_holdoff))
+		return false; /* Too soon after last GP. */
+
+	/* Next, check for probable idleness. */
+	curseq = rcu_seq_current(&sp->srcu_gp_seq);
+	smp_mb(); /* Order ->srcu_gp_seq with ->srcu_gp_seq_needed. */
+	if (ULONG_CMP_LT(curseq, READ_ONCE(sp->srcu_gp_seq_needed)))
+		return false; /* Grace period in progress, so not idle. */
+	smp_mb(); /* Order ->srcu_gp_seq with prior access. */
+	if (curseq != rcu_seq_current(&sp->srcu_gp_seq))
+		return false; /* GP # changed, so not idle. */
+	return true; /* With reasonable probability, idle! */
+}
+
+/*
  * Enqueue an SRCU callback on the srcu_data structure associated with
  * the current CPU and the specified srcu_struct structure, initiating
  * grace-period processing if it is not already running.
@@ -633,10 +772,11 @@ static void srcu_flip(struct srcu_struct *sp)
  * srcu_read_lock(), and srcu_read_unlock() that are all passed the same
  * srcu_struct structure.
  */
-void call_srcu(struct srcu_struct *sp, struct rcu_head *rhp,
-	       rcu_callback_t func)
+void __call_srcu(struct srcu_struct *sp, struct rcu_head *rhp,
+		 rcu_callback_t func, bool do_norm)
 {
 	unsigned long flags;
+	bool needexp = false;
 	bool needgp = false;
 	unsigned long s;
 	struct srcu_data *sdp;
@@ -655,16 +795,28 @@ void call_srcu(struct srcu_struct *sp, struct rcu_head *rhp,
 		sdp->srcu_gp_seq_needed = s;
 		needgp = true;
 	}
+	if (ULONG_CMP_LT(sdp->srcu_gp_seq_needed_exp, s)) {
+		sdp->srcu_gp_seq_needed_exp = s;
+		needexp = true;
+	}
 	spin_unlock_irqrestore(&sdp->lock, flags);
 	if (needgp)
-		srcu_funnel_gp_start(sp, sdp, s);
+		srcu_funnel_gp_start(sp, sdp, s, do_norm);
+	else
+		srcu_funnel_exp_start(sp, sdp->mynode, s);
+}
+
+void call_srcu(struct srcu_struct *sp, struct rcu_head *rhp,
+	       rcu_callback_t func)
+{
+	__call_srcu(sp, rhp, func, true);
 }
 EXPORT_SYMBOL_GPL(call_srcu);
 
 /*
  * Helper function for synchronize_srcu() and synchronize_srcu_expedited().
  */
-static void __synchronize_srcu(struct srcu_struct *sp)
+static void __synchronize_srcu(struct srcu_struct *sp, bool do_norm)
 {
 	struct rcu_synchronize rcu;
 
@@ -680,7 +832,7 @@ static void __synchronize_srcu(struct srcu_struct *sp)
 	check_init_srcu_struct(sp);
 	init_completion(&rcu.completion);
 	init_rcu_head_on_stack(&rcu.head);
-	call_srcu(sp, &rcu.head, wakeme_after_rcu);
+	__call_srcu(sp, &rcu.head, wakeme_after_rcu, do_norm);
 	wait_for_completion(&rcu.completion);
 	destroy_rcu_head_on_stack(&rcu.head);
 }
@@ -697,18 +849,7 @@ static void __synchronize_srcu(struct srcu_struct *sp)
  */
 void synchronize_srcu_expedited(struct srcu_struct *sp)
 {
-	bool do_norm = rcu_gp_is_normal();
-
-	check_init_srcu_struct(sp);
-	if (!do_norm) {
-		atomic_inc(&sp->srcu_exp_cnt);
-		smp_mb__after_atomic(); /* increment before GP. */
-	}
-	__synchronize_srcu(sp);
-	if (!do_norm) {
-		smp_mb__before_atomic(); /* GP before decrement. */
-		WARN_ON_ONCE(atomic_dec_return(&sp->srcu_exp_cnt) < 0);
-	}
+	__synchronize_srcu(sp, rcu_gp_is_normal());
 }
 EXPORT_SYMBOL_GPL(synchronize_srcu_expedited);
 
@@ -750,13 +891,18 @@ EXPORT_SYMBOL_GPL(synchronize_srcu_expedited);
  * Of course, these memory-ordering guarantees apply only when
  * synchronize_srcu(), srcu_read_lock(), and srcu_read_unlock() are
  * passed the same srcu_struct structure.
+ *
+ * If SRCU is likely idle, expedite the first request.  This semantic
+ * was provided by Classic SRCU, and is relied upon by its users, so TREE
+ * SRCU must also provide it.  Note that detecting idleness is heuristic
+ * and subject to both false positives and negatives.
  */
 void synchronize_srcu(struct srcu_struct *sp)
 {
-	if (rcu_gp_is_expedited())
+	if (srcu_might_be_idle(sp) || rcu_gp_is_expedited())
 		synchronize_srcu_expedited(sp);
 	else
-		__synchronize_srcu(sp);
+		__synchronize_srcu(sp, true);
 }
 EXPORT_SYMBOL_GPL(synchronize_srcu);
 
@@ -991,6 +1137,18 @@ void process_srcu(struct work_struct *work)
 	sp = container_of(work, struct srcu_struct, work.work);
 
 	srcu_advance_state(sp);
-	srcu_reschedule(sp, atomic_read(&sp->srcu_exp_cnt) ? 0 : SRCU_INTERVAL);
+	srcu_reschedule(sp, srcu_get_delay(sp));
 }
 EXPORT_SYMBOL_GPL(process_srcu);
+
+void srcutorture_get_gp_data(enum rcutorture_type test_type,
+			     struct srcu_struct *sp, int *flags,
+			     unsigned long *gpnum, unsigned long *completed)
+{
+	if (test_type != SRCU_FLAVOR)
+		return;
+	*flags = 0;
+	*completed = rcu_seq_ctr(sp->srcu_gp_seq);
+	*gpnum = rcu_seq_ctr(sp->srcu_gp_seq_needed);
+}
+EXPORT_SYMBOL_GPL(srcutorture_get_gp_data);
diff --git a/kernel/rcu/tree.c b/kernel/rcu/tree.c
index 23aa02587d0f..91fff49d5869 100644
--- a/kernel/rcu/tree.c
+++ b/kernel/rcu/tree.c
@@ -704,15 +704,11 @@ void rcutorture_get_gp_data(enum rcutorture_type test_type, int *flags,
 	default:
 		break;
 	}
-	if (rsp != NULL) {
-		*flags = READ_ONCE(rsp->gp_flags);
-		*gpnum = READ_ONCE(rsp->gpnum);
-		*completed = READ_ONCE(rsp->completed);
+	if (rsp == NULL)
 		return;
-	}
-	*flags = 0;
-	*gpnum = 0;
-	*completed = 0;
+	*flags = READ_ONCE(rsp->gp_flags);
+	*gpnum = READ_ONCE(rsp->gpnum);
+	*completed = READ_ONCE(rsp->completed);
 }
 EXPORT_SYMBOL_GPL(rcutorture_get_gp_data);
 

^ permalink raw reply related	[flat|nested] 24+ messages in thread

* Re: TREE_SRCU slows hotplug by factor ~16
  2017-04-26 14:31             ` Paul E. McKenney
@ 2017-04-26 15:26               ` Mike Galbraith
  2017-04-26 15:44                 ` Paul E. McKenney
  0 siblings, 1 reply; 24+ messages in thread
From: Mike Galbraith @ 2017-04-26 15:26 UTC (permalink / raw)
  To: paulmck; +Cc: LKML

On Wed, 2017-04-26 at 07:31 -0700, Paul E. McKenney wrote:

> And a sneak preview, semi-tested.  If you get a chance to run this, please
> let me know now it goes.

That took 'time stress-cpu-hotplug.sh' down to 48s, close to classic.

	-Mike

^ permalink raw reply	[flat|nested] 24+ messages in thread

* Re: TREE_SRCU slows hotplug by factor ~16
  2017-04-26 15:26               ` Mike Galbraith
@ 2017-04-26 15:44                 ` Paul E. McKenney
  2017-04-26 15:49                   ` Mike Galbraith
  0 siblings, 1 reply; 24+ messages in thread
From: Paul E. McKenney @ 2017-04-26 15:44 UTC (permalink / raw)
  To: Mike Galbraith; +Cc: LKML

On Wed, Apr 26, 2017 at 05:26:20PM +0200, Mike Galbraith wrote:
> On Wed, 2017-04-26 at 07:31 -0700, Paul E. McKenney wrote:
> 
> > And a sneak preview, semi-tested.  If you get a chance to run this, please
> > let me know now it goes.
> 
> That took 'time stress-cpu-hotplug.sh' down to 48s, close to classic.

Woo-hoo!!!  ;-)

And thank you for your testing efforts!

Should I be comparing this with the 55s number from your initial email,
or to the 39s number?

Either way, given the unusual nature of Steven's hotplug stress test,
I believe that I am good enough for this merge window.  But if we
are talking 48s for Tree SRCU vs. 39s with Classic SRCU, it would be
good to at least understand where the remaining slowdown is.  Here
are a couple of possible causes:

o	My holdoff is too long.  I set it to 50 microseconds based
	on your trace, which shows a minimum grace-period separation
	of 118 microseconds.  But perhaps the trace was too short to
	show the full variation.  One way to check this is to run with
	srcutree.exp_holdoff=25000 or some such.  (Please note that
	srcutree.exp_holdoff is in nanoseconds, -not- microseconds.)

o	My expedited throttling is too aggressive.  This is controlled
	by the following lines of code in srcu_gp_end() in the file
	kernel/rcu/srcutree.c:

		/* Throttle expedited grace periods: Should be rare! */
		srcu_reschedule(sp, rcu_seq_ctr(gpseq) & 0x3ff
				    ? 0 : SRCU_INTERVAL);

	The "0x3ff" says that one in 1024 grace periods should be
	forced to be at least partially non-expedited, regardless
	of anything else.  If making this be (say) "0xfff" gets
	you three-quarters of the way to the 39s, that indicates
	that this is the controlling factor.

o	Of course, another question is how much variation there is
	in the timing of that stress test.

If further reduction is needed, and none of these help, could you
please send me a trace of the full run of the same form as the last
one you sent me, covering calls to and returns from call_srcu(),
synchronize_srcu(), and synchronize_srcu_expedited()?

							Thanx, paul

^ permalink raw reply	[flat|nested] 24+ messages in thread

* Re: TREE_SRCU slows hotplug by factor ~16
  2017-04-26 15:44                 ` Paul E. McKenney
@ 2017-04-26 15:49                   ` Mike Galbraith
  2017-04-26 16:00                     ` Paul E. McKenney
  2017-04-26 17:45                     ` Mike Galbraith
  0 siblings, 2 replies; 24+ messages in thread
From: Mike Galbraith @ 2017-04-26 15:49 UTC (permalink / raw)
  To: paulmck; +Cc: LKML

On Wed, 2017-04-26 at 08:44 -0700, Paul E. McKenney wrote:
> On Wed, Apr 26, 2017 at 05:26:20PM +0200, Mike Galbraith wrote:
> > On Wed, 2017-04-26 at 07:31 -0700, Paul E. McKenney wrote:
> > 
> > > And a sneak preview, semi-tested.  If you get a chance to run this, please
> > > let me know now it goes.
> > 
> > That took 'time stress-cpu-hotplug.sh' down to 48s, close to classic.
> 
> Woo-hoo!!!  ;-)
> 
> And thank you for your testing efforts!
> 
> Should I be comparing this with the 55s number from your initial email,
> or to the 39s number?

Should be the 39, but I'll get you a new tree vs classic number in this
same tree after I finish bisecting TSC going wonky.

	-Mike

^ permalink raw reply	[flat|nested] 24+ messages in thread

* Re: TREE_SRCU slows hotplug by factor ~16
  2017-04-26 15:49                   ` Mike Galbraith
@ 2017-04-26 16:00                     ` Paul E. McKenney
  2017-04-26 17:45                     ` Mike Galbraith
  1 sibling, 0 replies; 24+ messages in thread
From: Paul E. McKenney @ 2017-04-26 16:00 UTC (permalink / raw)
  To: Mike Galbraith; +Cc: LKML

On Wed, Apr 26, 2017 at 05:49:59PM +0200, Mike Galbraith wrote:
> On Wed, 2017-04-26 at 08:44 -0700, Paul E. McKenney wrote:
> > On Wed, Apr 26, 2017 at 05:26:20PM +0200, Mike Galbraith wrote:
> > > On Wed, 2017-04-26 at 07:31 -0700, Paul E. McKenney wrote:
> > > 
> > > > And a sneak preview, semi-tested.  If you get a chance to run this, please
> > > > let me know now it goes.
> > > 
> > > That took 'time stress-cpu-hotplug.sh' down to 48s, close to classic.
> > 
> > Woo-hoo!!!  ;-)
> > 
> > And thank you for your testing efforts!
> > 
> > Should I be comparing this with the 55s number from your initial email,
> > or to the 39s number?
> 
> Should be the 39, but I'll get you a new tree vs classic number in this
> same tree after I finish bisecting TSC going wonky.

Sounds good!!!

In theory, given 4-millisecond SRCU grace periods and 225,000 of them
per run (estimated based on experience and on numbers you have already
provided me), the 0x3ff should be worth only about one second of delay
over the full test.  On a really good day, I could probably invent some
statistics to estimate the slowdown from the 50-microsecond cutoff, but
today is not quite that good a day.  And besides, the only difference
between theory and practice is that in theory they are both the same.  ;-)

So I look forward to seeing your measurements!  And best of everything
with the wonky TSC!!!

							Thanx, Paul

^ permalink raw reply	[flat|nested] 24+ messages in thread

* Re: TREE_SRCU slows hotplug by factor ~16
  2017-04-26 15:49                   ` Mike Galbraith
  2017-04-26 16:00                     ` Paul E. McKenney
@ 2017-04-26 17:45                     ` Mike Galbraith
  2017-04-26 17:55                       ` Paul E. McKenney
  1 sibling, 1 reply; 24+ messages in thread
From: Mike Galbraith @ 2017-04-26 17:45 UTC (permalink / raw)
  To: paulmck; +Cc: LKML

On Wed, 2017-04-26 at 17:49 +0200, Mike Galbraith wrote:
> On Wed, 2017-04-26 at 08:44 -0700, Paul E. McKenney wrote:

> > Should I be comparing this with the 55s number from your initial email,
> > or to the 39s number?
> 
> Should be the 39...

And 39 it is.

	-Mike

^ permalink raw reply	[flat|nested] 24+ messages in thread

* Re: TREE_SRCU slows hotplug by factor ~16
  2017-04-26 17:45                     ` Mike Galbraith
@ 2017-04-26 17:55                       ` Paul E. McKenney
  2017-04-26 17:56                         ` Paul E. McKenney
  0 siblings, 1 reply; 24+ messages in thread
From: Paul E. McKenney @ 2017-04-26 17:55 UTC (permalink / raw)
  To: Mike Galbraith; +Cc: LKML

On Wed, Apr 26, 2017 at 07:45:57PM +0200, Mike Galbraith wrote:
> On Wed, 2017-04-26 at 17:49 +0200, Mike Galbraith wrote:
> > On Wed, 2017-04-26 at 08:44 -0700, Paul E. McKenney wrote:
> 
> > > Should I be comparing this with the 55s number from your initial email,
> > > or to the 39s number?
> > 
> > Should be the 39...
> 
> And 39 it is.

Thank you again for your testing efforts!

OK, I do need to do more work.  My current guess is that I should have
set the default for srcutree.exp_holdoff to 25*1000 instead of 50*1000.
But I am sure that further data will show me the error of my ways.  ;-)

							Thanx, Paul

^ permalink raw reply	[flat|nested] 24+ messages in thread

* Re: TREE_SRCU slows hotplug by factor ~16
  2017-04-26 17:55                       ` Paul E. McKenney
@ 2017-04-26 17:56                         ` Paul E. McKenney
  2017-04-26 18:12                           ` Mike Galbraith
  0 siblings, 1 reply; 24+ messages in thread
From: Paul E. McKenney @ 2017-04-26 17:56 UTC (permalink / raw)
  To: Mike Galbraith; +Cc: LKML

On Wed, Apr 26, 2017 at 10:55:44AM -0700, Paul E. McKenney wrote:
> On Wed, Apr 26, 2017 at 07:45:57PM +0200, Mike Galbraith wrote:
> > On Wed, 2017-04-26 at 17:49 +0200, Mike Galbraith wrote:
> > > On Wed, 2017-04-26 at 08:44 -0700, Paul E. McKenney wrote:
> > 
> > > > Should I be comparing this with the 55s number from your initial email,
> > > > or to the 39s number?
> > > 
> > > Should be the 39...
> > 
> > And 39 it is.
> 
> Thank you again for your testing efforts!
> 
> OK, I do need to do more work.  My current guess is that I should have
> set the default for srcutree.exp_holdoff to 25*1000 instead of 50*1000.
> But I am sure that further data will show me the error of my ways.  ;-)

Oh, and my I add your Tested-by?

							Thanx, Paul

^ permalink raw reply	[flat|nested] 24+ messages in thread

* Re: TREE_SRCU slows hotplug by factor ~16
  2017-04-26 17:56                         ` Paul E. McKenney
@ 2017-04-26 18:12                           ` Mike Galbraith
  2017-04-26 18:25                             ` Paul E. McKenney
  2017-04-27  3:43                             ` Mike Galbraith
  0 siblings, 2 replies; 24+ messages in thread
From: Mike Galbraith @ 2017-04-26 18:12 UTC (permalink / raw)
  To: paulmck; +Cc: LKML

On Wed, 2017-04-26 at 10:56 -0700, Paul E. McKenney wrote:

> > OK, I do need to do more work.  My current guess is that I should have
> > set the default for srcutree.exp_holdoff to 25*1000 instead of 50*1000.
> > But I am sure that further data will show me the error of my ways.  ;-)

I can give that a go tomorrow (too crispy now).

> Oh, and my I add your Tested-by?

Sure.

	-Mike

^ permalink raw reply	[flat|nested] 24+ messages in thread

* Re: TREE_SRCU slows hotplug by factor ~16
  2017-04-26 18:12                           ` Mike Galbraith
@ 2017-04-26 18:25                             ` Paul E. McKenney
  2017-04-27  3:43                             ` Mike Galbraith
  1 sibling, 0 replies; 24+ messages in thread
From: Paul E. McKenney @ 2017-04-26 18:25 UTC (permalink / raw)
  To: Mike Galbraith; +Cc: LKML

On Wed, Apr 26, 2017 at 08:12:10PM +0200, Mike Galbraith wrote:
> On Wed, 2017-04-26 at 10:56 -0700, Paul E. McKenney wrote:
> 
> > > OK, I do need to do more work.  My current guess is that I should have
> > > set the default for srcutree.exp_holdoff to 25*1000 instead of 50*1000.
> > > But I am sure that further data will show me the error of my ways.  ;-)
> 
> I can give that a go tomorrow (too crispy now).

Sounds good!  I think that validating a 75x reduction is good for 
today.  Get some rest!

> > Oh, and my I add your Tested-by?
> 
> Sure.

Done, thank you!

							Thanx, Paul

^ permalink raw reply	[flat|nested] 24+ messages in thread

* Re: TREE_SRCU slows hotplug by factor ~16
  2017-04-26 18:12                           ` Mike Galbraith
  2017-04-26 18:25                             ` Paul E. McKenney
@ 2017-04-27  3:43                             ` Mike Galbraith
  2017-04-27  4:11                               ` Paul E. McKenney
  1 sibling, 1 reply; 24+ messages in thread
From: Mike Galbraith @ 2017-04-27  3:43 UTC (permalink / raw)
  To: paulmck; +Cc: LKML

On Wed, 2017-04-26 at 20:12 +0200, Mike Galbraith wrote:
> On Wed, 2017-04-26 at 10:56 -0700, Paul E. McKenney wrote:
> 
> > > OK, I do need to do more work.  My current guess is that I should have
> > > set the default for srcutree.exp_holdoff to 25*1000 instead of 50*1000.
> > > But I am sure that further data will show me the error of my ways.  ;-)
> 
> I can give that a go tomorrow (too crispy now).

real    0m39.177s
user    0m0.225s
sys     0m5.344s

tadaaa  (tricorder noises... it's dead Jim)

^ permalink raw reply	[flat|nested] 24+ messages in thread

* Re: TREE_SRCU slows hotplug by factor ~16
  2017-04-27  3:43                             ` Mike Galbraith
@ 2017-04-27  4:11                               ` Paul E. McKenney
  2017-04-27  4:15                                 ` Mike Galbraith
  0 siblings, 1 reply; 24+ messages in thread
From: Paul E. McKenney @ 2017-04-27  4:11 UTC (permalink / raw)
  To: Mike Galbraith; +Cc: LKML

On Thu, Apr 27, 2017 at 05:43:59AM +0200, Mike Galbraith wrote:
> On Wed, 2017-04-26 at 20:12 +0200, Mike Galbraith wrote:
> > On Wed, 2017-04-26 at 10:56 -0700, Paul E. McKenney wrote:
> > 
> > > > OK, I do need to do more work.  My current guess is that I should have
> > > > set the default for srcutree.exp_holdoff to 25*1000 instead of 50*1000.
> > > > But I am sure that further data will show me the error of my ways.  ;-)
> > 
> > I can give that a go tomorrow (too crispy now).
> 
> real    0m39.177s
> user    0m0.225s
> sys     0m5.344s
> 
> tadaaa  (tricorder noises... it's dead Jim)

This is with srcutree.exp_holdoff set to 25*1000?  If so, great news!
Really easy to adjust the default.  ;-)

							Thanx, Paul

^ permalink raw reply	[flat|nested] 24+ messages in thread

* Re: TREE_SRCU slows hotplug by factor ~16
  2017-04-27  4:11                               ` Paul E. McKenney
@ 2017-04-27  4:15                                 ` Mike Galbraith
  2017-04-27  5:32                                   ` Paul E. McKenney
  0 siblings, 1 reply; 24+ messages in thread
From: Mike Galbraith @ 2017-04-27  4:15 UTC (permalink / raw)
  To: paulmck; +Cc: LKML

On Wed, 2017-04-26 at 21:11 -0700, Paul E. McKenney wrote:

> This is with srcutree.exp_holdoff set to 25*1000?

Yup.

^ permalink raw reply	[flat|nested] 24+ messages in thread

* Re: TREE_SRCU slows hotplug by factor ~16
  2017-04-27  4:15                                 ` Mike Galbraith
@ 2017-04-27  5:32                                   ` Paul E. McKenney
  2017-04-27  5:44                                     ` Mike Galbraith
  0 siblings, 1 reply; 24+ messages in thread
From: Paul E. McKenney @ 2017-04-27  5:32 UTC (permalink / raw)
  To: Mike Galbraith; +Cc: LKML

On Thu, Apr 27, 2017 at 06:15:56AM +0200, Mike Galbraith wrote:
> On Wed, 2017-04-26 at 21:11 -0700, Paul E. McKenney wrote:
> 
> > This is with srcutree.exp_holdoff set to 25*1000?
> 
> Yup.

And please see below for the trivial patch, just for confirmation.
May I add your Tested-by?

							Thanx, Paul

------------------------------------------------------------------------

diff --git a/kernel/rcu/srcutree.c b/kernel/rcu/srcutree.c
index ccbe1fb84165..65f03bca5b32 100644
--- a/kernel/rcu/srcutree.c
+++ b/kernel/rcu/srcutree.c
@@ -39,7 +39,7 @@
 
 #include "rcu.h"
 
-ulong exp_holdoff = 50 * 1000; /* Holdoff (ns) for auto-expediting. */
+ulong exp_holdoff = 25 * 1000; /* Holdoff (ns) for auto-expediting. */
 module_param(exp_holdoff, ulong, 0444);
 
 static void srcu_invoke_callbacks(struct work_struct *work);

^ permalink raw reply related	[flat|nested] 24+ messages in thread

* Re: TREE_SRCU slows hotplug by factor ~16
  2017-04-27  5:32                                   ` Paul E. McKenney
@ 2017-04-27  5:44                                     ` Mike Galbraith
  2017-04-27 12:37                                       ` Paul E. McKenney
  0 siblings, 1 reply; 24+ messages in thread
From: Mike Galbraith @ 2017-04-27  5:44 UTC (permalink / raw)
  To: paulmck; +Cc: LKML

On Wed, 2017-04-26 at 22:32 -0700, Paul E. McKenney wrote:
> On Thu, Apr 27, 2017 at 06:15:56AM +0200, Mike Galbraith wrote:
> > On Wed, 2017-04-26 at 21:11 -0700, Paul E. McKenney wrote:
> > 
> > > This is with srcutree.exp_holdoff set to 25*1000?
> > 
> > Yup.
> 
> And please see below for the trivial patch, just for confirmation.
> May I add your Tested-by?

Sure.

> diff --git a/kernel/rcu/srcutree.c b/kernel/rcu/srcutree.c
> index ccbe1fb84165..65f03bca5b32 100644
> --- a/kernel/rcu/srcutree.c
> +++ b/kernel/rcu/srcutree.c
> @@ -39,7 +39,7 @@
>  
>  #include "rcu.h"
>  
> -ulong exp_holdoff = 50 * 1000; /* Holdoff (ns) for auto-expediting. */
> +ulong exp_holdoff = 25 * 1000; /* Holdoff (ns) for auto-expediting. */

Yup, exactly what I did.

^ permalink raw reply	[flat|nested] 24+ messages in thread

* Re: TREE_SRCU slows hotplug by factor ~16
  2017-04-27  5:44                                     ` Mike Galbraith
@ 2017-04-27 12:37                                       ` Paul E. McKenney
  0 siblings, 0 replies; 24+ messages in thread
From: Paul E. McKenney @ 2017-04-27 12:37 UTC (permalink / raw)
  To: Mike Galbraith; +Cc: LKML

On Thu, Apr 27, 2017 at 07:44:00AM +0200, Mike Galbraith wrote:
> On Wed, 2017-04-26 at 22:32 -0700, Paul E. McKenney wrote:
> > On Thu, Apr 27, 2017 at 06:15:56AM +0200, Mike Galbraith wrote:
> > > On Wed, 2017-04-26 at 21:11 -0700, Paul E. McKenney wrote:
> > > 
> > > > This is with srcutree.exp_holdoff set to 25*1000?
> > > 
> > > Yup.
> > 
> > And please see below for the trivial patch, just for confirmation.
> > May I add your Tested-by?
> 
> Sure.
> 
> > diff --git a/kernel/rcu/srcutree.c b/kernel/rcu/srcutree.c
> > index ccbe1fb84165..65f03bca5b32 100644
> > --- a/kernel/rcu/srcutree.c
> > +++ b/kernel/rcu/srcutree.c
> > @@ -39,7 +39,7 @@
> >  
> >  #include "rcu.h"
> >  
> > -ulong exp_holdoff = 50 * 1000; /* Holdoff (ns) for auto-expediting. */
> > +ulong exp_holdoff = 25 * 1000; /* Holdoff (ns) for auto-expediting. */
> 
> Yup, exactly what I did.

Woo-hoo!!!

I will beat up on this a bit and send a pull request to Ingo.

And thank you very much for finding this, gathering the trace data
(which was critically important to my figuring out what was going
on), and for testing the patches!

							Thanx, Paul

^ permalink raw reply	[flat|nested] 24+ messages in thread

end of thread, other threads:[~2017-04-27 12:37 UTC | newest]

Thread overview: 24+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2017-04-24  2:48 TREE_SRCU slows hotplug by factor ~16 Mike Galbraith
2017-04-24  3:32 ` Paul E. McKenney
2017-04-24  5:24   ` Mike Galbraith
2017-04-24  6:22     ` Paul E. McKenney
2017-04-24  7:35       ` Mike Galbraith
2017-04-24  8:43         ` Mike Galbraith
2017-04-24 16:24         ` Paul E. McKenney
2017-04-25 22:36           ` Paul E. McKenney
2017-04-26 14:31             ` Paul E. McKenney
2017-04-26 15:26               ` Mike Galbraith
2017-04-26 15:44                 ` Paul E. McKenney
2017-04-26 15:49                   ` Mike Galbraith
2017-04-26 16:00                     ` Paul E. McKenney
2017-04-26 17:45                     ` Mike Galbraith
2017-04-26 17:55                       ` Paul E. McKenney
2017-04-26 17:56                         ` Paul E. McKenney
2017-04-26 18:12                           ` Mike Galbraith
2017-04-26 18:25                             ` Paul E. McKenney
2017-04-27  3:43                             ` Mike Galbraith
2017-04-27  4:11                               ` Paul E. McKenney
2017-04-27  4:15                                 ` Mike Galbraith
2017-04-27  5:32                                   ` Paul E. McKenney
2017-04-27  5:44                                     ` Mike Galbraith
2017-04-27 12:37                                       ` Paul E. McKenney

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).