scheduler hang on cpu re-hotplug with 2.6.27rc8

scheduler hang on cpu re-hotplug with 2.6.27rc8

[Andi Kleen]

[Rafael, something for the regression list]

While testing cpu hotunplug/hotreplug (first 
setting two CPUs to offline and then to online again) on a 16 thread machine
with 2.6.27rc8 the first 

# echo 1 > ./devices/system/cpu/cpu14/online

after hotunplug deadlocked somewhere in the scheduler:

bash          D 00000000ffffcb5b     0  4683   4671
 ffff8804bc583c68 0000000000000086 ffff8804bc9d8640 0000000000000296
 ffff8804bdd34730 ffff8804be6fc090 ffff8804bdd34978 0000000c805a1e2a
 ffff8804be4fd780 ffffffff802298b4 ffffffff808acd98 ffff88027d0b1168
Call Trace:
 [<ffffffff802298b4>] __dequeue_entity+0x25/0x68
 [<ffffffff805a1b4b>] schedule_timeout+0x1e/0xad
 [<ffffffff8022a11f>] __disable_runtime+0x57/0x155
 [<ffffffff8025cc47>] cpupri_set+0xbe/0xcd
 [<ffffffff805a19b3>] wait_for_common+0xcd/0x131
 [<ffffffff8022c918>] default_wake_function+0x0/0xe
 [<ffffffff80241f3a>] synchronize_rcu+0x30/0x36
 [<ffffffff80241fac>] wakeme_after_rcu+0x0/0xc
 [<ffffffff8022dab6>] partition_sched_domains+0x9b/0x1dd
 [<ffffffff8022dc26>] update_sched_domains+0x2e/0x35
 [<ffffffff805a5297>] notifier_call_chain+0x29/0x4c
 [<ffffffff8059ef76>] _cpu_up+0xd0/0x10a
 [<ffffffff8059f004>] cpu_up+0x54/0x61
 [<ffffffff805837d5>] store_online+0x43/0x67
 [<ffffffff802c51e9>] sysfs_write_file+0xd2/0x110
 [<ffffffff8028656b>] vfs_write+0xad/0x136
 [<ffffffff802869f3>] sys_write+0x45/0x6e
 [<ffffffff8020b22b>] system_call_fastpath+0x16/0x1b

It just hung forever, but the machine was otherwise fully functional.

This was without frame pointers so the backtrace presumably has
some garbage. Haven't looked too closely.

-Andi

-- 
ak@linux.intel.com

Re: RCU hang on cpu re-hotplug with 2.6.27rc8

[Andi Kleen]

[modifying subject]

On Mon, Oct 06, 2008 at 04:12:20PM +0200, Andi Kleen wrote:
> [Rafael, something for the regression list]
> 
> While testing cpu hotunplug/hotreplug (first 
> setting two CPUs to offline and then to online again) on a 16 thread machine
> with 2.6.27rc8 the first 
> 
> # echo 1 > ./devices/system/cpu/cpu14/online
> 
> after hotunplug deadlocked somewhere in the scheduler:

I let it run for longer and I ended up with more and more processes
stuck in synchronize_rcu(). No more backtraces because the system
has no console and is now not able to write to disk anymore.

So it seems like there's something broken with RCU & cpu hotplug
in 2.6.28rc8. cc Paul.

It's probably not the scheduler, sorry for blaming it earlier.

-Andi

> bash          D 00000000ffffcb5b     0  4683   4671
>  ffff8804bc583c68 0000000000000086 ffff8804bc9d8640 0000000000000296
>  ffff8804bdd34730 ffff8804be6fc090 ffff8804bdd34978 0000000c805a1e2a
>  ffff8804be4fd780 ffffffff802298b4 ffffffff808acd98 ffff88027d0b1168
> Call Trace:
>  [<ffffffff802298b4>] __dequeue_entity+0x25/0x68
>  [<ffffffff805a1b4b>] schedule_timeout+0x1e/0xad
>  [<ffffffff8022a11f>] __disable_runtime+0x57/0x155
>  [<ffffffff8025cc47>] cpupri_set+0xbe/0xcd
>  [<ffffffff805a19b3>] wait_for_common+0xcd/0x131
>  [<ffffffff8022c918>] default_wake_function+0x0/0xe
>  [<ffffffff80241f3a>] synchronize_rcu+0x30/0x36
>  [<ffffffff80241fac>] wakeme_after_rcu+0x0/0xc
>  [<ffffffff8022dab6>] partition_sched_domains+0x9b/0x1dd
>  [<ffffffff8022dc26>] update_sched_domains+0x2e/0x35
>  [<ffffffff805a5297>] notifier_call_chain+0x29/0x4c
>  [<ffffffff8059ef76>] _cpu_up+0xd0/0x10a
>  [<ffffffff8059f004>] cpu_up+0x54/0x61
>  [<ffffffff805837d5>] store_online+0x43/0x67
>  [<ffffffff802c51e9>] sysfs_write_file+0xd2/0x110
>  [<ffffffff8028656b>] vfs_write+0xad/0x136
>  [<ffffffff802869f3>] sys_write+0x45/0x6e
>  [<ffffffff8020b22b>] system_call_fastpath+0x16/0x1b
> 
> It just hung forever, but the machine was otherwise fully functional.
> 
> This was without frame pointers so the backtrace presumably has
> some garbage. Haven't looked too closely.
> 
> -Andi
> 
> -- 
> ak@linux.intel.com

-- 
ak@linux.intel.com

Re: RCU hang on cpu re-hotplug with 2.6.27rc8

[Paul E. McKenney]

On Tue, Oct 07, 2008 at 01:28:37AM +0200, Andi Kleen wrote:
> [modifying subject]
> 
> On Mon, Oct 06, 2008 at 04:12:20PM +0200, Andi Kleen wrote:
> > [Rafael, something for the regression list]
> > 
> > While testing cpu hotunplug/hotreplug (first 
> > setting two CPUs to offline and then to online again) on a 16 thread machine
> > with 2.6.27rc8 the first 
> > 
> > # echo 1 > ./devices/system/cpu/cpu14/online
> > 
> > after hotunplug deadlocked somewhere in the scheduler:
> 
> I let it run for longer and I ended up with more and more processes
> stuck in synchronize_rcu(). No more backtraces because the system
> has no console and is now not able to write to disk anymore.
> 
> So it seems like there's something broken with RCU & cpu hotplug
> in 2.6.28rc8. cc Paul.
> 
> It's probably not the scheduler, sorry for blaming it earlier.

Could you please try the patch at the following URL (from Thomas
Gleixner)?

http://www.rdrop.com/users/paulmck/patches/2.6.27-rc7-tglx-timer-1.patch

This fixed some CPU hotplug hangs that I was seeing in 2.6.27-rc7 and
-rc8.  Alternatively, try 2.6.27-rc9, which seems to include Thomas's
patch.

							Thanx, Paul

> -Andi
> 
> > bash          D 00000000ffffcb5b     0  4683   4671
> >  ffff8804bc583c68 0000000000000086 ffff8804bc9d8640 0000000000000296
> >  ffff8804bdd34730 ffff8804be6fc090 ffff8804bdd34978 0000000c805a1e2a
> >  ffff8804be4fd780 ffffffff802298b4 ffffffff808acd98 ffff88027d0b1168
> > Call Trace:
> >  [<ffffffff802298b4>] __dequeue_entity+0x25/0x68
> >  [<ffffffff805a1b4b>] schedule_timeout+0x1e/0xad
> >  [<ffffffff8022a11f>] __disable_runtime+0x57/0x155
> >  [<ffffffff8025cc47>] cpupri_set+0xbe/0xcd
> >  [<ffffffff805a19b3>] wait_for_common+0xcd/0x131
> >  [<ffffffff8022c918>] default_wake_function+0x0/0xe
> >  [<ffffffff80241f3a>] synchronize_rcu+0x30/0x36
> >  [<ffffffff80241fac>] wakeme_after_rcu+0x0/0xc
> >  [<ffffffff8022dab6>] partition_sched_domains+0x9b/0x1dd
> >  [<ffffffff8022dc26>] update_sched_domains+0x2e/0x35
> >  [<ffffffff805a5297>] notifier_call_chain+0x29/0x4c
> >  [<ffffffff8059ef76>] _cpu_up+0xd0/0x10a
> >  [<ffffffff8059f004>] cpu_up+0x54/0x61
> >  [<ffffffff805837d5>] store_online+0x43/0x67
> >  [<ffffffff802c51e9>] sysfs_write_file+0xd2/0x110
> >  [<ffffffff8028656b>] vfs_write+0xad/0x136
> >  [<ffffffff802869f3>] sys_write+0x45/0x6e
> >  [<ffffffff8020b22b>] system_call_fastpath+0x16/0x1b
> > 
> > It just hung forever, but the machine was otherwise fully functional.
> > 
> > This was without frame pointers so the backtrace presumably has
> > some garbage. Haven't looked too closely.
> > 
> > -Andi
> > 
> > -- 
> > ak@linux.intel.com
> 
> -- 
> ak@linux.intel.com

Re: RCU hang on cpu re-hotplug with 2.6.27rc8

[Andi Kleen]

> Could you please try the patch at the following URL (from Thomas
> Gleixner)?
> 
> http://www.rdrop.com/users/paulmck/patches/2.6.27-rc7-tglx-timer-1.patch
> 
> This fixed some CPU hotplug hangs that I was seeing in 2.6.27-rc7 and
> -rc8.  Alternatively, try 2.6.27-rc9, which seems to include Thomas's
> patch.

Still happens with rc9.  This time with frame pointers:

bash          D 00000000ffff975e     0  4770   4757
 ffff8804bcda3bf8 0000000000000082 ffff8804bcda3c18 0000000000000296
 ffff8804bde4e6b0 ffff8804be6fc630 ffff8804bde4e8f8 0000000e00000296
 ffff8804bcda3c18 ffffffff808cfd98 ffff880288064780 ffff88027d18ec98
Call Trace:
 [<ffffffff805c4915>] schedule_timeout+0x22/0xb4
 [<ffffffff8020a009>] ? __switch_to+0x320/0x330
 [<ffffffff802602ed>] ? cpupri_set+0xc5/0xd8
 [<ffffffff805c476f>] wait_for_common+0xcd/0x131
 [<ffffffff8022db87>] ? default_wake_function+0x0/0xf
 [<ffffffff805c485d>] wait_for_completion+0x18/0x1a
 [<ffffffff80243fbf>] synchronize_rcu+0x35/0x3c
 [<ffffffff8024403e>] ? wakeme_after_rcu+0x0/0x12
 [<ffffffff8022ed25>] partition_sched_domains+0x9b/0x1dd
 [<ffffffff8022dbb3>] ? wake_up_process+0x10/0x12
 [<ffffffff8022ee95>] update_sched_domains+0x2e/0x35
 [<ffffffff805c8342>] notifier_call_chain+0x33/0x5b
 [<ffffffff80249291>] __raw_notifier_call_chain+0x9/0xb
 [<ffffffff802492a2>] raw_notifier_call_chain+0xf/0x11
 [<ffffffff805c1c3a>] _cpu_up+0xd3/0x10c
 [<ffffffff805c1cca>] cpu_up+0x57/0x67
 [<ffffffff805a5787>] store_online+0x4d/0x75
 [<ffffffff803e67bb>] sysdev_store+0x1b/0x1d
 [<ffffffff802cce10>] sysfs_write_file+0xe0/0x11c
 [<ffffffff8028b661>] vfs_write+0xae/0x137
 [<ffffffff8028bb0a>] sys_write+0x47/0x6f
 [<ffffffff8020b34b>] system_call_fastpath+0x16/0x1b

BTW it also happens reliably every time. Reproduced it three times
now. I just do

laut:~ # echo 0 > /sys/devices/system/cpu/cpu15/online 
laut:~ # echo 0 > /sys/devices/system/cpu/cpu14/online 
laut:~ # echo 1 > /sys/devices/system/cpu/cpu14/online 
laut:~ # echo 1 > /sys/devices/system/cpu/cpu15/online 
<hang>

-Andi

Re: RCU hang on cpu re-hotplug with 2.6.27rc8

[Paul E. McKenney]

On Tue, Oct 07, 2008 at 09:15:44AM +0200, Andi Kleen wrote:
> > Could you please try the patch at the following URL (from Thomas
> > Gleixner)?
> > 
> > http://www.rdrop.com/users/paulmck/patches/2.6.27-rc7-tglx-timer-1.patch
> > 
> > This fixed some CPU hotplug hangs that I was seeing in 2.6.27-rc7 and
> > -rc8.  Alternatively, try 2.6.27-rc9, which seems to include Thomas's
> > patch.
> 
> Still happens with rc9.  This time with frame pointers:

Hmmm...  I chased out a number of these when doing rcutree.

This with classic RCU or preemptable RCU?

> bash          D 00000000ffff975e     0  4770   4757
>  ffff8804bcda3bf8 0000000000000082 ffff8804bcda3c18 0000000000000296
>  ffff8804bde4e6b0 ffff8804be6fc630 ffff8804bde4e8f8 0000000e00000296
>  ffff8804bcda3c18 ffffffff808cfd98 ffff880288064780 ffff88027d18ec98
> Call Trace:
>  [<ffffffff805c4915>] schedule_timeout+0x22/0xb4
>  [<ffffffff8020a009>] ? __switch_to+0x320/0x330
>  [<ffffffff802602ed>] ? cpupri_set+0xc5/0xd8
>  [<ffffffff805c476f>] wait_for_common+0xcd/0x131
>  [<ffffffff8022db87>] ? default_wake_function+0x0/0xf
>  [<ffffffff805c485d>] wait_for_completion+0x18/0x1a
>  [<ffffffff80243fbf>] synchronize_rcu+0x35/0x3c
>  [<ffffffff8024403e>] ? wakeme_after_rcu+0x0/0x12
>  [<ffffffff8022ed25>] partition_sched_domains+0x9b/0x1dd
>  [<ffffffff8022dbb3>] ? wake_up_process+0x10/0x12
>  [<ffffffff8022ee95>] update_sched_domains+0x2e/0x35
>  [<ffffffff805c8342>] notifier_call_chain+0x33/0x5b
>  [<ffffffff80249291>] __raw_notifier_call_chain+0x9/0xb
>  [<ffffffff802492a2>] raw_notifier_call_chain+0xf/0x11
>  [<ffffffff805c1c3a>] _cpu_up+0xd3/0x10c
>  [<ffffffff805c1cca>] cpu_up+0x57/0x67
>  [<ffffffff805a5787>] store_online+0x4d/0x75
>  [<ffffffff803e67bb>] sysdev_store+0x1b/0x1d
>  [<ffffffff802cce10>] sysfs_write_file+0xe0/0x11c
>  [<ffffffff8028b661>] vfs_write+0xae/0x137
>  [<ffffffff8028bb0a>] sys_write+0x47/0x6f
>  [<ffffffff8020b34b>] system_call_fastpath+0x16/0x1b
> 
> BTW it also happens reliably every time. Reproduced it three times
> now. I just do
> 
> laut:~ # echo 0 > /sys/devices/system/cpu/cpu15/online 
> laut:~ # echo 0 > /sys/devices/system/cpu/cpu14/online 
> laut:~ # echo 1 > /sys/devices/system/cpu/cpu14/online 
> laut:~ # echo 1 > /sys/devices/system/cpu/cpu15/online 
> <hang>

Could you please send me your .config file?

							Thanx, Paul

Re: RCU hang on cpu re-hotplug with 2.6.27rc8

[Andi Kleen]

> Hmmm...  I chased out a number of these when doing rcutree.
> 
> This with classic RCU or preemptable RCU?

classic.

> Could you please send me your .config file?

http://halobates.de/defconfig64

-Andi

-- 
ak@linux.intel.com

Re: RCU hang on cpu re-hotplug with 2.6.27rc8

[Paul E. McKenney]

On Tue, Oct 07, 2008 at 05:49:39PM +0200, Andi Kleen wrote:
> > Hmmm...  I chased out a number of these when doing rcutree.
> > 
> > This with classic RCU or preemptable RCU?
> 
> classic.
> 
> > Could you please send me your .config file?
> 
> http://halobates.de/defconfig64

Thank you!  Hmmm, classic RCU, worked just fine in 2.6.27-rc7 with
Thomas's patch.  I was doing random onlines and offlines in a loop,
with about 3 seconds between each operation continuously for more than
ten hours, both x86 and Power.  So could you please try 2.6.27-rc7 with
Thomas's patch as follows?

http://www.rdrop.com/users/paulmck/patches/2.6.27-rc7-tglx-timer-1.patch

Failing that, I guess my next step would be to create tracing for
classic RCU to help figure out what RCU believes is preventing the
grace period from ending.

						Thanx, Paul

Re: RCU hang on cpu re-hotplug with 2.6.27rc8

[Andi Kleen]

On Tue, Oct 07, 2008 at 09:34:01AM -0700, Paul E. McKenney wrote:
> Thank you!  Hmmm, classic RCU, worked just fine in 2.6.27-rc7 with
> Thomas's patch.  I was doing random onlines and offlines in a loop,
> with about 3 seconds between each operation continuously for more than
> ten hours, both x86 and Power.  So could you please try 2.6.27-rc7 with
> Thomas's patch as follows?
> 
> http://www.rdrop.com/users/paulmck/patches/2.6.27-rc7-tglx-timer-1.patch

Same effect. Hung on the first try

bash          D 00000000ffff25c1     0  4755   4742
 ffff88027b127bf8 0000000000000086 ffff88027b127c18 0000000000000296
 ffff88027c80b330 ffff8804be488b90 ffff88027c80b578 0000000300000296
 ffff88027b127c18 ffffffff808cbd18 ffff88002805d600 ffff88027d182098
Call Trace:
 [<ffffffff805c318d>] schedule_timeout+0x22/0xb4
 [<ffffffff8020a029>] ? __switch_to+0x320/0x330
 [<ffffffff8025fa65>] ? cpupri_set+0xc5/0xd8
 [<ffffffff805c2fe7>] wait_for_common+0xcd/0x131
 [<ffffffff8022d297>] ? default_wake_function+0x0/0xf
 [<ffffffff805c30d5>] wait_for_completion+0x18/0x1a
 [<ffffffff8024374b>] synchronize_rcu+0x35/0x3c
 [<ffffffff802437ca>] ? wakeme_after_rcu+0x0/0x12
 [<ffffffff8022e435>] partition_sched_domains+0x9b/0x1dd
 [<ffffffff8022d2c3>] ? wake_up_process+0x10/0x12
 [<ffffffff8022e5a5>] update_sched_domains+0x2e/0x35
 [<ffffffff805c6bb2>] notifier_call_chain+0x33/0x5b
 [<ffffffff80248a29>] __raw_notifier_call_chain+0x9/0xb
 [<ffffffff80248a3a>] raw_notifier_call_chain+0xf/0x11
 [<ffffffff805c06e6>] _cpu_up+0xd3/0x10c
 [<ffffffff805c0776>] cpu_up+0x57/0x67
 [<ffffffff805a4ab7>] store_online+0x4d/0x75
 [<ffffffff803e5d0b>] sysdev_store+0x1b/0x1d
 [<ffffffff802cc49c>] sysfs_write_file+0xe0/0x11c
 [<ffffffff8028ad1d>] vfs_write+0xae/0x137
 [<ffffffff8028b1c6>] sys_write+0x47/0x6f
 [<ffffffff8020b36b>] system_call_fastpath+0x16/0x1b

-Andi

-- 
ak@linux.intel.com

Re: RCU hang on cpu re-hotplug with 2.6.27rc8

[Paul E. McKenney]

On Tue, Oct 07, 2008 at 11:09:47PM +0200, Andi Kleen wrote:
> On Tue, Oct 07, 2008 at 09:34:01AM -0700, Paul E. McKenney wrote:
> > Thank you!  Hmmm, classic RCU, worked just fine in 2.6.27-rc7 with
> > Thomas's patch.  I was doing random onlines and offlines in a loop,
> > with about 3 seconds between each operation continuously for more than
> > ten hours, both x86 and Power.  So could you please try 2.6.27-rc7 with
> > Thomas's patch as follows?
> > 
> > http://www.rdrop.com/users/paulmck/patches/2.6.27-rc7-tglx-timer-1.patch
> 
> Same effect. Hung on the first try
> 
> bash          D 00000000ffff25c1     0  4755   4742
>  ffff88027b127bf8 0000000000000086 ffff88027b127c18 0000000000000296
>  ffff88027c80b330 ffff8804be488b90 ffff88027c80b578 0000000300000296
>  ffff88027b127c18 ffffffff808cbd18 ffff88002805d600 ffff88027d182098
> Call Trace:
>  [<ffffffff805c318d>] schedule_timeout+0x22/0xb4
>  [<ffffffff8020a029>] ? __switch_to+0x320/0x330
>  [<ffffffff8025fa65>] ? cpupri_set+0xc5/0xd8
>  [<ffffffff805c2fe7>] wait_for_common+0xcd/0x131
>  [<ffffffff8022d297>] ? default_wake_function+0x0/0xf
>  [<ffffffff805c30d5>] wait_for_completion+0x18/0x1a
>  [<ffffffff8024374b>] synchronize_rcu+0x35/0x3c
>  [<ffffffff802437ca>] ? wakeme_after_rcu+0x0/0x12
>  [<ffffffff8022e435>] partition_sched_domains+0x9b/0x1dd
>  [<ffffffff8022d2c3>] ? wake_up_process+0x10/0x12
>  [<ffffffff8022e5a5>] update_sched_domains+0x2e/0x35
>  [<ffffffff805c6bb2>] notifier_call_chain+0x33/0x5b
>  [<ffffffff80248a29>] __raw_notifier_call_chain+0x9/0xb
>  [<ffffffff80248a3a>] raw_notifier_call_chain+0xf/0x11
>  [<ffffffff805c06e6>] _cpu_up+0xd3/0x10c
>  [<ffffffff805c0776>] cpu_up+0x57/0x67
>  [<ffffffff805a4ab7>] store_online+0x4d/0x75
>  [<ffffffff803e5d0b>] sysdev_store+0x1b/0x1d
>  [<ffffffff802cc49c>] sysfs_write_file+0xe0/0x11c
>  [<ffffffff8028ad1d>] vfs_write+0xae/0x137
>  [<ffffffff8028b1c6>] sys_write+0x47/0x6f
>  [<ffffffff8020b36b>] system_call_fastpath+0x16/0x1b

Thus far, as usual, I cannot reproduce, either on x86 or Power.  You are
running on hyperthreaded machines?  If so, what happens if you disable
CONFIG_SCHED_SMT and CONFIG_SCHED_MC?

You are running on a 16-CPU x86-64 box?

							Thanx, Paul

[PATCH] rudimentary tracing for Classic RCU

[Paul E. McKenney]

Hello!

This is a tracing patch for Classic RCU, which creates an "rcu/rcucb"
file in debugfs.  This patch can be handy when you need to work out
why RCU is refusing to end the current grace period.

Reading from the file results in something like the following:

	rcu: cur=1129  completed=1128  np=0  s=0
		0,3,7
	rcu_bh: cur=-287  completed=-287  np=0  s=0

	online: 0-7

The first two lines are for rcu, the second two for rcu_bh.
The cur= is the current grace-period number, and the completed=
is the number of the last completed grace period.  If these two
numbers are equal, the corresponding flavor of RCU is idle.
The np= is a flag indicating that an additional RCU grace period
beyond the current one will be required.  The s=, if non-zero,
indicates that a round of reschedule IPIs has been send to
attempt to expedite the current grace period.

The second and fourth lines are a comma/dash-separated list of
the CPUs that have not yet reported a quiescent state for the
current grace period (CPUs 0, 3, and 7 for "rcu" above).

The last line lists the online CPUs.

Tested on x86 and Power.

Signed-off-by: Paul E. McKenney <paulmck@linux.vnet.ibm.com>
---

 include/linux/rcuclassic.h |    3 +
 kernel/Kconfig.preempt     |    1 
 kernel/Makefile            |    2 
 kernel/rcuclassic.c        |    4 -
 kernel/rcuclassic_trace.c  |  126 +++++++++++++++++++++++++++++++++++++++++++++
 5 files changed, 133 insertions(+), 3 deletions(-)

diff --git a/include/linux/rcuclassic.h b/include/linux/rcuclassic.h
index 4ab8436..061a272 100644
--- a/include/linux/rcuclassic.h
+++ b/include/linux/rcuclassic.h
@@ -54,6 +54,9 @@ struct rcu_ctrlblk {
 				 /* for current batch to proceed.        */
 } ____cacheline_internodealigned_in_smp;
 
+extern struct rcu_ctrlblk rcu_ctrlblk;
+extern struct rcu_ctrlblk rcu_bh_ctrlblk;
+
 /* Is batch a before batch b ? */
 static inline int rcu_batch_before(long a, long b)
 {
diff --git a/kernel/Kconfig.preempt b/kernel/Kconfig.preempt
index 9fdba03..ba32338 100644
--- a/kernel/Kconfig.preempt
+++ b/kernel/Kconfig.preempt
@@ -68,7 +68,6 @@ config PREEMPT_RCU
 
 config RCU_TRACE
 	bool "Enable tracing for RCU - currently stats in debugfs"
-	depends on PREEMPT_RCU
 	select DEBUG_FS
 	default y
 	help
diff --git a/kernel/Makefile b/kernel/Makefile
index 4e1d7df..e0bfce7 100644
--- a/kernel/Makefile
+++ b/kernel/Makefile
@@ -77,6 +77,8 @@ obj-$(CONFIG_CLASSIC_RCU) += rcuclassic.o
 obj-$(CONFIG_PREEMPT_RCU) += rcupreempt.o
 ifeq ($(CONFIG_PREEMPT_RCU),y)
 obj-$(CONFIG_RCU_TRACE) += rcupreempt_trace.o
+else
+obj-$(CONFIG_RCU_TRACE) += rcuclassic_trace.o
 endif
 obj-$(CONFIG_RELAY) += relay.o
 obj-$(CONFIG_SYSCTL) += utsname_sysctl.o
diff --git a/kernel/rcuclassic.c b/kernel/rcuclassic.c
index aad93cd..517eaa9 100644
--- a/kernel/rcuclassic.c
+++ b/kernel/rcuclassic.c
@@ -57,13 +57,13 @@ EXPORT_SYMBOL_GPL(rcu_lock_map);
 
 
 /* Definition for rcupdate control block. */
-static struct rcu_ctrlblk rcu_ctrlblk = {
+struct rcu_ctrlblk rcu_ctrlblk = {
 	.cur = -300,
 	.completed = -300,
 	.lock = __SPIN_LOCK_UNLOCKED(&rcu_ctrlblk.lock),
 	.cpumask = CPU_MASK_NONE,
 };
-static struct rcu_ctrlblk rcu_bh_ctrlblk = {
+struct rcu_ctrlblk rcu_bh_ctrlblk = {
 	.cur = -300,
 	.completed = -300,
 	.lock = __SPIN_LOCK_UNLOCKED(&rcu_bh_ctrlblk.lock),
diff --git a/kernel/rcuclassic_trace.c b/kernel/rcuclassic_trace.c
new file mode 100644
index 0000000..f8b9313
--- /dev/null
+++ b/kernel/rcuclassic_trace.c
@@ -0,0 +1,126 @@
+/*
+ * Read-Copy Update tracing for classic implementation
+ *
+ * This program is free software; you can redistribute it and/or modify
+ * it under the terms of the GNU General Public License as published by
+ * the Free Software Foundation; either version 2 of the License, or
+ * (at your option) any later version.
+ *
+ * This program is distributed in the hope that it will be useful,
+ * but WITHOUT ANY WARRANTY; without even the implied warranty of
+ * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
+ * GNU General Public License for more details.
+ *
+ * You should have received a copy of the GNU General Public License
+ * along with this program; if not, write to the Free Software
+ * Foundation, Inc., 59 Temple Place - Suite 330, Boston, MA 02111-1307, USA.
+ *
+ * Copyright IBM Corporation, 2008
+ *
+ * Papers:  http://www.rdrop.com/users/paulmck/RCU
+ *
+ * For detailed explanation of Read-Copy Update mechanism see -
+ * 		Documentation/RCU
+ *
+ */
+#include <linux/types.h>
+#include <linux/kernel.h>
+#include <linux/init.h>
+#include <linux/spinlock.h>
+#include <linux/smp.h>
+#include <linux/rcupdate.h>
+#include <linux/interrupt.h>
+#include <linux/sched.h>
+#include <asm/atomic.h>
+#include <linux/bitops.h>
+#include <linux/module.h>
+#include <linux/completion.h>
+#include <linux/moduleparam.h>
+#include <linux/percpu.h>
+#include <linux/notifier.h>
+#include <linux/cpu.h>
+#include <linux/mutex.h>
+#include <linux/debugfs.h>
+
+static DEFINE_MUTEX(rcuclassic_trace_mutex);
+static char *rcuclassic_trace_buf;
+#define RCUCLASSIC_TRACE_BUF_SIZE (20*NR_CPUS + 100)
+
+static int print_one_rcu_ctrlblk(struct rcu_ctrlblk *rcp, char *buf, char *ebuf)
+{
+	int cnt = 0;
+
+	cnt += snprintf(&buf[cnt], ebuf - &buf[cnt], "cur=%ld  completed=%ld  "
+			"np=%d  s=%d\n\t",
+			rcp->cur, rcp->completed,
+			rcp->next_pending, rcp->signaled);
+	cnt += cpulist_scnprintf(&buf[cnt], ebuf - &buf[cnt], rcp->cpumask);
+	cnt += snprintf(&buf[cnt], ebuf - &buf[cnt], "\n");
+	return cnt;
+}
+
+static ssize_t rcucb_read(struct file *filp, char __user *buffer,
+				size_t count, loff_t *ppos)
+{
+	ssize_t bcount;
+	char *buf = rcuclassic_trace_buf;
+	char *ebuf = &rcuclassic_trace_buf[RCUCLASSIC_TRACE_BUF_SIZE];
+
+	mutex_lock(&rcuclassic_trace_mutex);
+	buf += snprintf(buf, ebuf - buf, "rcu: ");
+	buf += print_one_rcu_ctrlblk(&rcu_ctrlblk, buf, ebuf);
+	buf += snprintf(buf, ebuf - buf, "rcu_bh: ");
+	buf += print_one_rcu_ctrlblk(&rcu_bh_ctrlblk, buf, ebuf);
+	buf += snprintf(buf, ebuf - buf, "online: ");
+	buf += cpulist_scnprintf(buf, ebuf - buf, cpu_online_map);
+	buf += snprintf(buf, ebuf - buf, "\n");
+	bcount = simple_read_from_buffer(buffer, count, ppos,
+			rcuclassic_trace_buf, strlen(rcuclassic_trace_buf));
+	mutex_unlock(&rcuclassic_trace_mutex);
+	return bcount;
+}
+
+static struct file_operations rcucb_fops = {
+	.owner = THIS_MODULE,
+	.read = rcucb_read,
+};
+
+static struct dentry *rcudir, *cbdir;
+static int rcuclassic_debugfs_init(void)
+{
+	rcudir = debugfs_create_dir("rcu", NULL);
+	if (!rcudir)
+		goto out;
+	cbdir = debugfs_create_file("rcucb", 0444, rcudir, NULL, &rcucb_fops);
+	if (!cbdir)
+		goto free_out;
+	return 0;
+free_out:
+	debugfs_remove(rcudir);
+out:
+	return 1;
+}
+
+static int __init rcuclassic_trace_init(void)
+{
+	int ret;
+
+	rcuclassic_trace_buf = kmalloc(RCUCLASSIC_TRACE_BUF_SIZE, GFP_KERNEL);
+	if (!rcuclassic_trace_buf)
+		return 1;
+	ret = rcuclassic_debugfs_init();
+	if (ret)
+		kfree(rcuclassic_trace_buf);
+	return ret;
+}
+
+static void __exit rcuclassic_trace_cleanup(void)
+{
+	debugfs_remove(cbdir);
+	debugfs_remove(rcudir);
+	kfree(rcuclassic_trace_buf);
+}
+
+
+module_init(rcuclassic_trace_init);
+module_exit(rcuclassic_trace_cleanup);

Re: [PATCH] rudimentary tracing for Classic RCU

[Lai Jiangshan]

Paul E. McKenney wrote:
> Hello!
> 
> This is a tracing patch for Classic RCU, which creates an "rcu/rcucb"
> file in debugfs.  This patch can be handy when you need to work out
> why RCU is refusing to end the current grace period.
> 
> Reading from the file results in something like the following:
> 
> 	rcu: cur=1129  completed=1128  np=0  s=0
> 		0,3,7
> 	rcu_bh: cur=-287  completed=-287  np=0  s=0
> 
> 	online: 0-7
> 
> The first two lines are for rcu, the second two for rcu_bh.
> The cur= is the current grace-period number, and the completed=
> is the number of the last completed grace period.  If these two
> numbers are equal, the corresponding flavor of RCU is idle.
> The np= is a flag indicating that an additional RCU grace period
> beyond the current one will be required.  The s=, if non-zero,
> indicates that a round of reschedule IPIs has been send to
> attempt to expedite the current grace period.
> 
> The second and fourth lines are a comma/dash-separated list of
> the CPUs that have not yet reported a quiescent state for the
> current grace period (CPUs 0, 3, and 7 for "rcu" above).
> 
> The last line lists the online CPUs.
> 
> Tested on x86 and Power.
> 
> Signed-off-by: Paul E. McKenney <paulmck@linux.vnet.ibm.com>
> ---
> 
>  include/linux/rcuclassic.h |    3 +
>  kernel/Kconfig.preempt     |    1 
>  kernel/Makefile            |    2 
>  kernel/rcuclassic.c        |    4 -
>  kernel/rcuclassic_trace.c  |  126 +++++++++++++++++++++++++++++++++++++++++++++
>  5 files changed, 133 insertions(+), 3 deletions(-)
> 
> diff --git a/include/linux/rcuclassic.h b/include/linux/rcuclassic.h
> index 4ab8436..061a272 100644
> --- a/include/linux/rcuclassic.h
> +++ b/include/linux/rcuclassic.h
> @@ -54,6 +54,9 @@ struct rcu_ctrlblk {
>  				 /* for current batch to proceed.        */
>  } ____cacheline_internodealigned_in_smp;
>  
> +extern struct rcu_ctrlblk rcu_ctrlblk;
> +extern struct rcu_ctrlblk rcu_bh_ctrlblk;
> +
>  /* Is batch a before batch b ? */
>  static inline int rcu_batch_before(long a, long b)
>  {
> diff --git a/kernel/Kconfig.preempt b/kernel/Kconfig.preempt
> index 9fdba03..ba32338 100644
> --- a/kernel/Kconfig.preempt
> +++ b/kernel/Kconfig.preempt
> @@ -68,7 +68,6 @@ config PREEMPT_RCU
>  
>  config RCU_TRACE
>  	bool "Enable tracing for RCU - currently stats in debugfs"
> -	depends on PREEMPT_RCU
>  	select DEBUG_FS
>  	default y
>  	help

I think that we can move it to lib/Kconfig.debug.

> diff --git a/kernel/Makefile b/kernel/Makefile
> index 4e1d7df..e0bfce7 100644
> --- a/kernel/Makefile
> +++ b/kernel/Makefile
> @@ -77,6 +77,8 @@ obj-$(CONFIG_CLASSIC_RCU) += rcuclassic.o
>  obj-$(CONFIG_PREEMPT_RCU) += rcupreempt.o
>  ifeq ($(CONFIG_PREEMPT_RCU),y)
>  obj-$(CONFIG_RCU_TRACE) += rcupreempt_trace.o
> +else
> +obj-$(CONFIG_RCU_TRACE) += rcuclassic_trace.o
>  endif
>  obj-$(CONFIG_RELAY) += relay.o
>  obj-$(CONFIG_SYSCTL) += utsname_sysctl.o
> diff --git a/kernel/rcuclassic.c b/kernel/rcuclassic.c
> index aad93cd..517eaa9 100644
> --- a/kernel/rcuclassic.c
> +++ b/kernel/rcuclassic.c
> @@ -57,13 +57,13 @@ EXPORT_SYMBOL_GPL(rcu_lock_map);
>  
>  
>  /* Definition for rcupdate control block. */
> -static struct rcu_ctrlblk rcu_ctrlblk = {
> +struct rcu_ctrlblk rcu_ctrlblk = {
>  	.cur = -300,
>  	.completed = -300,
>  	.lock = __SPIN_LOCK_UNLOCKED(&rcu_ctrlblk.lock),
>  	.cpumask = CPU_MASK_NONE,
>  };
> -static struct rcu_ctrlblk rcu_bh_ctrlblk = {
> +struct rcu_ctrlblk rcu_bh_ctrlblk = {
>  	.cur = -300,
>  	.completed = -300,
>  	.lock = __SPIN_LOCK_UNLOCKED(&rcu_bh_ctrlblk.lock),
> diff --git a/kernel/rcuclassic_trace.c b/kernel/rcuclassic_trace.c
> new file mode 100644
> index 0000000..f8b9313
> --- /dev/null
> +++ b/kernel/rcuclassic_trace.c
> @@ -0,0 +1,126 @@
> +/*
> + * Read-Copy Update tracing for classic implementation
> + *
> + * This program is free software; you can redistribute it and/or modify
> + * it under the terms of the GNU General Public License as published by
> + * the Free Software Foundation; either version 2 of the License, or
> + * (at your option) any later version.
> + *
> + * This program is distributed in the hope that it will be useful,
> + * but WITHOUT ANY WARRANTY; without even the implied warranty of
> + * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
> + * GNU General Public License for more details.
> + *
> + * You should have received a copy of the GNU General Public License
> + * along with this program; if not, write to the Free Software
> + * Foundation, Inc., 59 Temple Place - Suite 330, Boston, MA 02111-1307, USA.
> + *
> + * Copyright IBM Corporation, 2008
> + *
> + * Papers:  http://www.rdrop.com/users/paulmck/RCU
> + *
> + * For detailed explanation of Read-Copy Update mechanism see -
> + * 		Documentation/RCU
> + *
> + */
> +#include <linux/types.h>
> +#include <linux/kernel.h>
> +#include <linux/init.h>
> +#include <linux/spinlock.h>
> +#include <linux/smp.h>
> +#include <linux/rcupdate.h>
> +#include <linux/interrupt.h>
> +#include <linux/sched.h>
> +#include <asm/atomic.h>
> +#include <linux/bitops.h>
> +#include <linux/module.h>
> +#include <linux/completion.h>
> +#include <linux/moduleparam.h>
> +#include <linux/percpu.h>
> +#include <linux/notifier.h>
> +#include <linux/cpu.h>
> +#include <linux/mutex.h>
> +#include <linux/debugfs.h>
> +
> +static DEFINE_MUTEX(rcuclassic_trace_mutex);
> +static char *rcuclassic_trace_buf;
> +#define RCUCLASSIC_TRACE_BUF_SIZE (20*NR_CPUS + 100)
> +
> +static int print_one_rcu_ctrlblk(struct rcu_ctrlblk *rcp, char *buf, char *ebuf)
> +{
> +	int cnt = 0;
> +
> +	cnt += snprintf(&buf[cnt], ebuf - &buf[cnt], "cur=%ld  completed=%ld  "
> +			"np=%d  s=%d\n\t",
> +			rcp->cur, rcp->completed,
> +			rcp->next_pending, rcp->signaled);
> +	cnt += cpulist_scnprintf(&buf[cnt], ebuf - &buf[cnt], rcp->cpumask);
> +	cnt += snprintf(&buf[cnt], ebuf - &buf[cnt], "\n");
> +	return cnt;
> +}
> +
> +static ssize_t rcucb_read(struct file *filp, char __user *buffer,
> +				size_t count, loff_t *ppos)
> +{
> +	ssize_t bcount;
> +	char *buf = rcuclassic_trace_buf;
> +	char *ebuf = &rcuclassic_trace_buf[RCUCLASSIC_TRACE_BUF_SIZE];
> +
> +	mutex_lock(&rcuclassic_trace_mutex);
> +	buf += snprintf(buf, ebuf - buf, "rcu: ");
> +	buf += print_one_rcu_ctrlblk(&rcu_ctrlblk, buf, ebuf);
> +	buf += snprintf(buf, ebuf - buf, "rcu_bh: ");
> +	buf += print_one_rcu_ctrlblk(&rcu_bh_ctrlblk, buf, ebuf);
> +	buf += snprintf(buf, ebuf - buf, "online: ");
> +	buf += cpulist_scnprintf(buf, ebuf - buf, cpu_online_map);
> +	buf += snprintf(buf, ebuf - buf, "\n");
> +	bcount = simple_read_from_buffer(buffer, count, ppos,
> +			rcuclassic_trace_buf, strlen(rcuclassic_trace_buf));
> +	mutex_unlock(&rcuclassic_trace_mutex);
> +	return bcount;
> +}
> +
> +static struct file_operations rcucb_fops = {
> +	.owner = THIS_MODULE,
> +	.read = rcucb_read,
> +};
> +
> +static struct dentry *rcudir, *cbdir;
> +static int rcuclassic_debugfs_init(void)

add __init:
static int __init rcuclassic_debugfs_init(void)

> +{
> +	rcudir = debugfs_create_dir("rcu", NULL);
> +	if (!rcudir)
> +		goto out;
> +	cbdir = debugfs_create_file("rcucb", 0444, rcudir, NULL, &rcucb_fops);
> +	if (!cbdir)
> +		goto free_out;
> +	return 0;
> +free_out:
> +	debugfs_remove(rcudir);
> +out:
> +	return 1;
> +}
> +
> +static int __init rcuclassic_trace_init(void)
> +{
> +	int ret;
> +
> +	rcuclassic_trace_buf = kmalloc(RCUCLASSIC_TRACE_BUF_SIZE, GFP_KERNEL);

I'm wondering about this.
rcuclassic_trace_buf is kmalloc-ed when init module.

In this case, why not define it as:
static char buf[20*NR_CPUS + 100];

and use it like:
pos += snprintf(buf + cnt, sizeof(buf) - cnt, ...);


> +	if (!rcuclassic_trace_buf)
> +		return 1;
> +	ret = rcuclassic_debugfs_init();
> +	if (ret)
> +		kfree(rcuclassic_trace_buf);
> +	return ret;
> +}
> +
> +static void __exit rcuclassic_trace_cleanup(void)
> +{
> +	debugfs_remove(cbdir);
> +	debugfs_remove(rcudir);
> +	kfree(rcuclassic_trace_buf);
> +}
> +
> +
> +module_init(rcuclassic_trace_init);
> +module_exit(rcuclassic_trace_cleanup);


I think this trace file shows too little vars for classic rcu.

It is better that this trace file shows more data.
such as some data in struct rcu_data(quiescent state handling fields, batch, qlen).

or add new files: rcu/rcu_data<cpu#>


Thanks, Lai

Re: [PATCH] rudimentary tracing for Classic RCU

[Andi Kleen]

> In this case, why not define it as:
> static char buf[20*NR_CPUS + 100];

Actually you should near never use NR_CPUS now but always num_possible_cpus()
(or even num_online_cpus()) Using NR_CPUS can lead to extreme waste
of memory on kernels which are compiled for 4096 CPUs for example.

And with num_possible_cpus() kmalloc is needed.

-Andi

Re: [PATCH] rudimentary tracing for Classic RCU

[Lai Jiangshan]

Andi Kleen wrote:
>> In this case, why not define it as:
>> static char buf[20*NR_CPUS + 100];
> 
> Actually you should near never use NR_CPUS now but always num_possible_cpus()
> (or even num_online_cpus()) Using NR_CPUS can lead to extreme waste
> of memory on kernels which are compiled for 4096 CPUs for example.
> 
> And with num_possible_cpus() kmalloc is needed.
> 
> -Andi
> 
> 
> 

I thought the default value of NR_CPUS is 32.

if NR_CPUS is too large, I think using seq_file is good idea,
and rcuclassic_trace_mutex is not need too.

Lai

Re: [PATCH] rudimentary tracing for Classic RCU

[KOSAKI Motohiro]

Hi Lai-san,

> >> In this case, why not define it as:
> >> static char buf[20*NR_CPUS + 100];
> > 
> > Actually you should near never use NR_CPUS now but always num_possible_cpus()
> > (or even num_online_cpus()) Using NR_CPUS can lead to extreme waste
> > of memory on kernels which are compiled for 4096 CPUs for example.
> > 
> > And with num_possible_cpus() kmalloc is needed.
> 
> I thought the default value of NR_CPUS is 32.

it's pointless.
Almost distribution use _very_ large NR_CPUS (likes 4096).
So, We should concern large NR_CPUS.


> 
> if NR_CPUS is too large, I think using seq_file is good idea,
> and rcuclassic_trace_mutex is not need too.

Re: [PATCH] rudimentary tracing for Classic RCU

[Lai Jiangshan]

KOSAKI Motohiro wrote:
> Hi Lai-san,
> 
>>>> In this case, why not define it as:
>>>> static char buf[20*NR_CPUS + 100];
>>> Actually you should near never use NR_CPUS now but always num_possible_cpus()
>>> (or even num_online_cpus()) Using NR_CPUS can lead to extreme waste
>>> of memory on kernels which are compiled for 4096 CPUs for example.
>>>
>>> And with num_possible_cpus() kmalloc is needed.
>> I thought the default value of NR_CPUS is 32.
> 
> it's pointless.
> Almost distribution use _very_ large NR_CPUS (likes 4096).
> So, We should concern large NR_CPUS.

Thanks.

So my advice is to use seq_file.

> 
> 
>> if NR_CPUS is too large, I think using seq_file is good idea,
>> and rcuclassic_trace_mutex is not need too.
> 
> 
> 
> 
> 

Re: [PATCH] rudimentary tracing for Classic RCU

[Andi Kleen]

On Thu, Oct 09, 2008 at 04:14:26PM +0900, KOSAKI Motohiro wrote:
> Hi Lai-san,
> 
> > >> In this case, why not define it as:
> > >> static char buf[20*NR_CPUS + 100];
> > > 
> > > Actually you should near never use NR_CPUS now but always num_possible_cpus()
> > > (or even num_online_cpus()) Using NR_CPUS can lead to extreme waste
> > > of memory on kernels which are compiled for 4096 CPUs for example.
> > > 
> > > And with num_possible_cpus() kmalloc is needed.
> > 
> > I thought the default value of NR_CPUS is 32.
> 
> it's pointless.
> Almost distribution use _very_ large NR_CPUS (likes 4096).

Right now it's more like 8-128, but at least there is some effort
to make a 4096 CPU distribution possible and Mike Travis has been
 tirelessly working on eradicating all the rogue NR_CPUs all over 
the tree.  So it's better to not add more.

> So, We should concern large NR_CPUS.

Agreed.

-Andi

-- 
ak@linux.intel.com

Re: [PATCH] rudimentary tracing for Classic RCU

[Paul E. McKenney]

On Thu, Oct 09, 2008 at 03:05:57PM +0800, Lai Jiangshan wrote:
> Andi Kleen wrote:
> >> In this case, why not define it as:
> >> static char buf[20*NR_CPUS + 100];
> > 
> > Actually you should near never use NR_CPUS now but always num_possible_cpus()
> > (or even num_online_cpus()) Using NR_CPUS can lead to extreme waste
> > of memory on kernels which are compiled for 4096 CPUs for example.
> > 
> > And with num_possible_cpus() kmalloc is needed.
> > 
> > -Andi
> 
> I thought the default value of NR_CPUS is 32.
> 
> if NR_CPUS is too large, I think using seq_file is good idea,
> and rcuclassic_trace_mutex is not need too.

I never have used seq_file, to be honest.  I would welcome a patch from
you applying it to my rcucb and rcudata patch set.

							Thanx, Paul

Re: [PATCH] rudimentary tracing for Classic RCU

[Paul E. McKenney]

On Thu, Oct 09, 2008 at 08:55:29AM +0200, Andi Kleen wrote:
> > In this case, why not define it as:
> > static char buf[20*NR_CPUS + 100];
> 
> Actually you should near never use NR_CPUS now but always num_possible_cpus()
> (or even num_online_cpus()) Using NR_CPUS can lead to extreme waste
> of memory on kernels which are compiled for 4096 CPUs for example.
> 
> And with num_possible_cpus() kmalloc is needed.

OK, new one on me!  Thank you for the pointer!

							Thanx, Paul

Re: [PATCH] rudimentary tracing for Classic RCU

[Paul E. McKenney]

On Thu, Oct 09, 2008 at 02:20:22PM +0800, Lai Jiangshan wrote:

Thank you for looking this over!

> Paul E. McKenney wrote:

[ . . . ]

> > diff --git a/kernel/Kconfig.preempt b/kernel/Kconfig.preempt
> > index 9fdba03..ba32338 100644
> > --- a/kernel/Kconfig.preempt
> > +++ b/kernel/Kconfig.preempt
> > @@ -68,7 +68,6 @@ config PREEMPT_RCU
> >  
> >  config RCU_TRACE
> >  	bool "Enable tracing for RCU - currently stats in debugfs"
> > -	depends on PREEMPT_RCU
> >  	select DEBUG_FS
> >  	default y
> >  	help
> 
> I think that we can move it to lib/Kconfig.debug.

Makes sense!

[ . . . ]

> > +static int __init rcuclassic_trace_init(void)
> > +{
> > +	int ret;
> > +
> > +	rcuclassic_trace_buf = kmalloc(RCUCLASSIC_TRACE_BUF_SIZE, GFP_KERNEL);
> 
> I'm wondering about this.
> rcuclassic_trace_buf is kmalloc-ed when init module.
> 
> In this case, why not define it as:
> static char buf[20*NR_CPUS + 100];
> 
> and use it like:
> pos += snprintf(buf + cnt, sizeof(buf) - cnt, ...);

I will make Andi's suggested change, both here and in other previously
submitted code.

[ . . . ]

> > +	if (!rcuclassic_trace_buf)
> > +		return 1;
> > +	ret = rcuclassic_debugfs_init();
> > +	if (ret)
> > +		kfree(rcuclassic_trace_buf);
> > +	return ret;
> > +}
> > +
> > +static void __exit rcuclassic_trace_cleanup(void)
> > +{
> > +	debugfs_remove(cbdir);
> > +	debugfs_remove(rcudir);
> > +	kfree(rcuclassic_trace_buf);
> > +}
> > +
> > +
> > +module_init(rcuclassic_trace_init);
> > +module_exit(rcuclassic_trace_cleanup);
> 
> 
> I think this trace file shows too little vars for classic rcu.
> 
> It is better that this trace file shows more data.
> such as some data in struct rcu_data(quiescent state handling fields, batch, qlen).
> 
> or add new files: rcu/rcu_data<cpu#>

Indeed!  I will add the ability to dump the rcu_data structures, though
I was planning to just dump all of them rather than CPU-by-CPU.  (Same
approach as in rcutree_trace.c patches.)

							Thanx, Paul

Re: [PATCH] rudimentary tracing for Classic RCU

[Frédéric Weisbecker]

2008/10/9 Paul E. McKenney <paulmck@linux.vnet.ibm.com>:
> Hello!
>
> This is a tracing patch for Classic RCU, which creates an "rcu/rcucb"
> file in debugfs.  This patch can be handy when you need to work out
> why RCU is refusing to end the current grace period.
>
> Reading from the file results in something like the following:
>
>        rcu: cur=1129  completed=1128  np=0  s=0
>                0,3,7
>        rcu_bh: cur=-287  completed=-287  np=0  s=0
>
>        online: 0-7


Hi Paul,

Why don't you use the ring-buffer tracing engine?
You will really make your life better by putting it as a tracer in
kernel/trace and by using the relevant API.
That will avoid you to manage the debugfs things, the memory
allocation, the buffer managment.....

Re: [PATCH] rudimentary tracing for Classic RCU

[Andi Kleen]

> Why don't you use the ring-buffer tracing engine?

Because he doesn't actually need a ring buffer, it's a snapshot in
time.

> You will really make your life better by putting it as a tracer in
> kernel/trace and by using the relevant API.
> That will avoid you to manage the debugfs things, the memory
> allocation, the buffer managment.....

ftrace-of-bork wants to assimilate everything?

-Andi

-- 
ak@linux.intel.com

Re: [PATCH] rudimentary tracing for Classic RCU

[Frédéric Weisbecker]

2008/10/9 Andi Kleen <andi@firstfloor.org>:
>> Why don't you use the ring-buffer tracing engine?
>
> Because he doesn't actually need a ring buffer, it's a snapshot in
> time.

You have the possibility to implement a read callback to not use the
ring buffer.

> ftrace-of-bork wants to assimilate everything?

I just proposed that to unify the tracers.

Re: [PATCH] rudimentary tracing for Classic RCU

[Paul E. McKenney]

On Thu, Oct 09, 2008 at 12:23:13PM +0200, Frédéric Weisbecker wrote:
> 2008/10/9 Paul E. McKenney <paulmck@linux.vnet.ibm.com>:
> > Hello!
> >
> > This is a tracing patch for Classic RCU, which creates an "rcu/rcucb"
> > file in debugfs.  This patch can be handy when you need to work out
> > why RCU is refusing to end the current grace period.
> >
> > Reading from the file results in something like the following:
> >
> >        rcu: cur=1129  completed=1128  np=0  s=0
> >                0,3,7
> >        rcu_bh: cur=-287  completed=-287  np=0  s=0
> >
> >        online: 0-7
> 
> 
> Hi Paul,
> 
> Why don't you use the ring-buffer tracing engine?
> You will really make your life better by putting it as a tracer in
> kernel/trace and by using the relevant API.
> That will avoid you to manage the debugfs things, the memory
> allocation, the buffer managment.....

Hello, Frédéric,

Well, one reason is that I didn't know about it.  ;-)

Does it allow the user to trigger a one-shot trace?  Right now, what
one does is:

	cat /debug/rcu/rcucb

whenever one wants to see what RCU is up to.  You really don't want to
see every new value, as that would generate hundreds of trace records
per second -- per CPU.  What does the user do with the ring-buffer
tracing enging?

							Thanx, Paul

Re: [PATCH] rudimentary tracing for Classic RCU

[Frédéric Weisbecker]

2008/10/9 Paul E. McKenney <paulmck@linux.vnet.ibm.com>:
> Well, one reason is that I didn't know about it.  ;-)
>
> Does it allow the user to trigger a one-shot trace?  Right now, what
> one does is:
>
>        cat /debug/rcu/rcucb
>
> whenever one wants to see what RCU is up to.  You really don't want to
> see every new value, as that would generate hundreds of trace records
> per second -- per CPU.  What does the user do with the ring-buffer
> tracing enging?
>
>                                                        Thanx, Paul

With a tracer from the unified tracing buffer, you have often one
function, used somewhere in the kernel, which will add periodically
some specific entries. For example mmiotrace receives entries which
contain IO access.
When the user tries to read the entries, he has to read the pipe
/debug/tracing/trace_pipe. During this reading,  the tracing engine
calls a read callback given by the tracer. This read callback is
nothing related to entries on the buffer: if the tracer has to print
something special, this is the ususal function.
Than if the read gave some content, the pipe reading returns. Else,
the tracing engine tells the tracer to format its entries from the
ring buffer. If there is no entries, the pipe reading sleeps and waits
for new entries.

So after some thought, I don't think the current tracing engine is
really adapted for what you want. It is a pipe system and it's not
adapted for your one-shot captures.

Sorry for the noise.

But it only requires few features to add for the unified tracing
engine to support such one-shot tracer.

[PATCH] v2 rudimentary tracing for Classic RCU

[Paul E. McKenney]

Hello!

This is a tracing patch for Classic RCU, which creates an "rcu/rcucb"
file in debugfs.  This patch can be handy when you need to work out
why RCU is refusing to end the current grace period.

Changes since v1:  Adds (crude) tracing for rcu_data structures.

Additional work needed:  Don't print rcu_data for offline CPUs.
			 Documentation update.

Reading from the file results in something like the following:

	rcu: cur=1129  completed=1128  np=0  s=0
		0,3,7
	rcu_bh: cur=-287  completed=-287  np=0  s=0

	online: 0-7

The first two lines are for rcu, the second two for rcu_bh.
The cur= is the current grace-period number, and the completed=
is the number of the last completed grace period.  If these two
numbers are equal, the corresponding flavor of RCU is idle.
The np= is a flag indicating that an additional RCU grace period
beyond the current one will be required.  The s=, if non-zero,
indicates that a round of reschedule IPIs has been send to
attempt to expedite the current grace period.

The second and fourth lines are a comma/dash-separated list of
the CPUs that have not yet reported a quiescent state for the
current grace period (CPUs 0, 3, and 7 for "rcu" above).

The last line lists the online CPUs.

Tested on x86 and Power.

Signed-off-by: Paul E. McKenney <paulmck@linux.vnet.ibm.com>
---

 include/linux/rcuclassic.h |    3 
 kernel/Kconfig.preempt     |    1 
 kernel/Makefile            |    2 
 kernel/rcuclassic.c        |    4 -
 kernel/rcuclassic_trace.c  |  179 +++++++++++++++++++++++++++++++++++++++++++++
 5 files changed, 186 insertions(+), 3 deletions(-)

diff --git a/include/linux/rcuclassic.h b/include/linux/rcuclassic.h
index 4ab8436..061a272 100644
--- a/include/linux/rcuclassic.h
+++ b/include/linux/rcuclassic.h
@@ -54,6 +54,9 @@ struct rcu_ctrlblk {
 				 /* for current batch to proceed.        */
 } ____cacheline_internodealigned_in_smp;
 
+extern struct rcu_ctrlblk rcu_ctrlblk;
+extern struct rcu_ctrlblk rcu_bh_ctrlblk;
+
 /* Is batch a before batch b ? */
 static inline int rcu_batch_before(long a, long b)
 {
diff --git a/kernel/Kconfig.preempt b/kernel/Kconfig.preempt
index 9fdba03..ba32338 100644
--- a/kernel/Kconfig.preempt
+++ b/kernel/Kconfig.preempt
@@ -68,7 +68,6 @@ config PREEMPT_RCU
 
 config RCU_TRACE
 	bool "Enable tracing for RCU - currently stats in debugfs"
-	depends on PREEMPT_RCU
 	select DEBUG_FS
 	default y
 	help
diff --git a/kernel/Makefile b/kernel/Makefile
index 4e1d7df..e0bfce7 100644
--- a/kernel/Makefile
+++ b/kernel/Makefile
@@ -77,6 +77,8 @@ obj-$(CONFIG_CLASSIC_RCU) += rcuclassic.o
 obj-$(CONFIG_PREEMPT_RCU) += rcupreempt.o
 ifeq ($(CONFIG_PREEMPT_RCU),y)
 obj-$(CONFIG_RCU_TRACE) += rcupreempt_trace.o
+else
+obj-$(CONFIG_RCU_TRACE) += rcuclassic_trace.o
 endif
 obj-$(CONFIG_RELAY) += relay.o
 obj-$(CONFIG_SYSCTL) += utsname_sysctl.o
diff --git a/kernel/rcuclassic.c b/kernel/rcuclassic.c
index aad93cd..517eaa9 100644
--- a/kernel/rcuclassic.c
+++ b/kernel/rcuclassic.c
@@ -57,13 +57,13 @@ EXPORT_SYMBOL_GPL(rcu_lock_map);
 
 
 /* Definition for rcupdate control block. */
-static struct rcu_ctrlblk rcu_ctrlblk = {
+struct rcu_ctrlblk rcu_ctrlblk = {
 	.cur = -300,
 	.completed = -300,
 	.lock = __SPIN_LOCK_UNLOCKED(&rcu_ctrlblk.lock),
 	.cpumask = CPU_MASK_NONE,
 };
-static struct rcu_ctrlblk rcu_bh_ctrlblk = {
+struct rcu_ctrlblk rcu_bh_ctrlblk = {
 	.cur = -300,
 	.completed = -300,
 	.lock = __SPIN_LOCK_UNLOCKED(&rcu_bh_ctrlblk.lock),
diff --git a/kernel/rcuclassic_trace.c b/kernel/rcuclassic_trace.c
new file mode 100644
index 0000000..a478256
--- /dev/null
+++ b/kernel/rcuclassic_trace.c
@@ -0,0 +1,179 @@
+/*
+ * Read-Copy Update tracing for classic implementation
+ *
+ * This program is free software; you can redistribute it and/or modify
+ * it under the terms of the GNU General Public License as published by
+ * the Free Software Foundation; either version 2 of the License, or
+ * (at your option) any later version.
+ *
+ * This program is distributed in the hope that it will be useful,
+ * but WITHOUT ANY WARRANTY; without even the implied warranty of
+ * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
+ * GNU General Public License for more details.
+ *
+ * You should have received a copy of the GNU General Public License
+ * along with this program; if not, write to the Free Software
+ * Foundation, Inc., 59 Temple Place - Suite 330, Boston, MA 02111-1307, USA.
+ *
+ * Copyright IBM Corporation, 2008
+ *
+ * Papers:  http://www.rdrop.com/users/paulmck/RCU
+ *
+ * For detailed explanation of Read-Copy Update mechanism see -
+ * 		Documentation/RCU
+ *
+ */
+#include <linux/types.h>
+#include <linux/kernel.h>
+#include <linux/init.h>
+#include <linux/spinlock.h>
+#include <linux/smp.h>
+#include <linux/rcupdate.h>
+#include <linux/interrupt.h>
+#include <linux/sched.h>
+#include <asm/atomic.h>
+#include <linux/bitops.h>
+#include <linux/module.h>
+#include <linux/completion.h>
+#include <linux/moduleparam.h>
+#include <linux/percpu.h>
+#include <linux/notifier.h>
+#include <linux/cpu.h>
+#include <linux/mutex.h>
+#include <linux/debugfs.h>
+
+static DEFINE_MUTEX(rcuclassic_trace_mutex);
+static char *rcuclassic_trace_buf;
+#define RCUCLASSIC_TRACE_BUF_SIZE (128 * num_possible_cpus() + 100)
+
+static int print_one_rcu_data(struct rcu_data *rdp, char *buf, char *ebuf)
+{
+	int cnt = 0;
+
+	if (cpu_is_offline(rdp->cpu))
+		return 0;
+	cnt += snprintf(&buf[cnt], ebuf - &buf[cnt],
+		"%3d%cqb=%ld b=%ld pq=%d qsp=%d ql=%ld bl=%ld\n",
+		rdp->cpu, cpu_is_offline(rdp->cpu) ? '!' : ' ',
+		rdp->quiescbatch, rdp->batch, rdp->passed_quiesc,
+		rdp->qs_pending, rdp->qlen, rdp->blimit);
+	return cnt;
+}
+
+#define PRINT_RCU_DATA(name, buf, ebuf) \
+	do { \
+		int _p_r_d_i; \
+		\
+		for_each_possible_cpu(_p_r_d_i) \
+			(buf) += print_one_rcu_data(&per_cpu(name, _p_r_d_i), \
+						    buf, ebuf); \
+	} while (0)
+
+static ssize_t rcudata_read(struct file *filp, char __user *buffer,
+				size_t count, loff_t *ppos)
+{
+	ssize_t bcount;
+	char *buf = rcuclassic_trace_buf;
+	char *ebuf = &rcuclassic_trace_buf[RCUCLASSIC_TRACE_BUF_SIZE];
+
+	mutex_lock(&rcuclassic_trace_mutex);
+	buf += snprintf(buf, ebuf - buf, "rcu:\n");
+	PRINT_RCU_DATA(rcu_data, buf, ebuf);
+	buf += snprintf(buf, ebuf - buf, "rcu_bh:\n");
+	PRINT_RCU_DATA(rcu_bh_data, buf, ebuf);
+	bcount = simple_read_from_buffer(buffer, count, ppos,
+			rcuclassic_trace_buf, strlen(rcuclassic_trace_buf));
+	mutex_unlock(&rcuclassic_trace_mutex);
+	return bcount;
+}
+
+static int print_one_rcu_ctrlblk(struct rcu_ctrlblk *rcp, char *buf, char *ebuf)
+{
+	int cnt = 0;
+
+	cnt += snprintf(&buf[cnt], ebuf - &buf[cnt], "cur=%ld  completed=%ld  "
+			"np=%d  s=%d\n\t",
+			rcp->cur, rcp->completed,
+			rcp->next_pending, rcp->signaled);
+	cnt += cpulist_scnprintf(&buf[cnt], ebuf - &buf[cnt], rcp->cpumask);
+	cnt += snprintf(&buf[cnt], ebuf - &buf[cnt], "\n");
+	return cnt;
+}
+
+static ssize_t rcucb_read(struct file *filp, char __user *buffer,
+				size_t count, loff_t *ppos)
+{
+	ssize_t bcount;
+	char *buf = rcuclassic_trace_buf;
+	char *ebuf = &rcuclassic_trace_buf[RCUCLASSIC_TRACE_BUF_SIZE];
+
+	mutex_lock(&rcuclassic_trace_mutex);
+	buf += snprintf(buf, ebuf - buf, "rcu: ");
+	buf += print_one_rcu_ctrlblk(&rcu_ctrlblk, buf, ebuf);
+	buf += snprintf(buf, ebuf - buf, "rcu_bh: ");
+	buf += print_one_rcu_ctrlblk(&rcu_bh_ctrlblk, buf, ebuf);
+	buf += snprintf(buf, ebuf - buf, "online: ");
+	buf += cpulist_scnprintf(buf, ebuf - buf, cpu_online_map);
+	buf += snprintf(buf, ebuf - buf, "\n");
+	bcount = simple_read_from_buffer(buffer, count, ppos,
+			rcuclassic_trace_buf, strlen(rcuclassic_trace_buf));
+	mutex_unlock(&rcuclassic_trace_mutex);
+	return bcount;
+}
+
+static struct file_operations rcudata_fops = {
+	.owner = THIS_MODULE,
+	.read = rcudata_read,
+};
+
+static struct file_operations rcucb_fops = {
+	.owner = THIS_MODULE,
+	.read = rcucb_read,
+};
+
+static struct dentry *rcudir, *datadir, *cbdir;
+static int rcuclassic_debugfs_init(void)
+{
+	rcudir = debugfs_create_dir("rcu", NULL);
+	if (!rcudir)
+		goto out;
+	datadir = debugfs_create_file("rcudata", 0444, rcudir,
+				      NULL, &rcudata_fops);
+	if (!datadir)
+		goto free_out;
+	cbdir = debugfs_create_file("rcucb", 0444, rcudir, NULL, &rcucb_fops);
+	if (!cbdir)
+		goto free_out;
+	return 0;
+free_out:
+	if (datadir)
+		debugfs_remove(datadir);
+	debugfs_remove(rcudir);
+out:
+	return 1;
+}
+
+static int __init rcuclassic_trace_init(void)
+{
+	int ret;
+
+	rcuclassic_trace_buf = kmalloc(RCUCLASSIC_TRACE_BUF_SIZE, GFP_KERNEL);
+	if (!rcuclassic_trace_buf)
+		return 1;
+	ret = rcuclassic_debugfs_init();
+	if (ret)
+		kfree(rcuclassic_trace_buf);
+	return ret;
+}
+
+static void __exit rcuclassic_trace_cleanup(void)
+{
+	debugfs_remove(datadir);
+	debugfs_remove(cbdir);
+	debugfs_remove(rcudir);
+	kfree(rcuclassic_trace_buf);
+}
+
+
+module_init(rcuclassic_trace_init);
+module_exit(rcuclassic_trace_cleanup);

[PATCH] v3 rudimentary tracing for Classic RCU

[Paul E. McKenney]

Hello!

This is v3 of a tracing patch for Classic RCU, which creates "rcu/rcucb"
and "rcu/rcudata" files in debugfs.  This patch can be handy when you
need to work out why RCU is refusing to end the current grace period.

Should be ready for inclusion in tip/core/rcu, Ingo, please apply.

Changes since v2:  Add flag to rcu_data to avoid printing rcu_data for
		   CPUs that have never been online.

		   Add documentation (below).

Changes since v1:  Adds (crude) tracing for rcu_data structures.

Reading from the "rcu/rcucb" file results in something like the following:

	rcu: cur=1129  completed=1128  pending=0  s=0
		0,3,7
	rcu_bh: cur=-287  completed=-287  pending=0  s=0

	online: 0-7

The first two lines are for rcu, the second two for rcu_bh.  The cur=
is the current grace-period number, and the completed= is the number
of the last completed grace period.  If these two numbers are equal,
the corresponding flavor of RCU is idle.  The pending= is the furthest
future batch number that is required, if equal to cur=, no additional
grace periods are required.  The s=, if non-zero, indicates that a round
of reschedule IPIs has been send to attempt to expedite the current
grace period.

The second and fourth lines are a comma/dash-separated list of
the CPUs that have not yet reported a quiescent state for the
current grace period (CPUs 0, 3, and 7 for "rcu" above).

The last line lists the online CPUs.


Reading from the "rcu/rcudata" file results in the following:

	rcu:
	  0 qb=885 b=884 pq=1 qsp=0 ql=0 bl=10
	  1 qb=885 b=882 pq=1 qsp=0 ql=2 bl=10
	  2 qb=885 b=854 pq=1 qsp=0 ql=0 bl=10
	  3 qb=885 b=885 pq=1 qsp=0 ql=0 bl=10
	rcu_bh:
	  0 qb=-291 b=-291 pq=1 qsp=0 ql=0 bl=10
	  1 qb=-291 b=0 pq=1 qsp=0 ql=0 bl=10
	  2 qb=-291 b=0 pq=1 qsp=0 ql=0 bl=10
	  3 qb=-291 b=-298 pq=1 qsp=0 ql=0 bl=10

This output is again split into rcu and rcu_bh portions.  Within each
portion, there is one line per CPU, but only for those CPUs that have
been online at least once since boot.  The number at the beginning of
each line is the CPU number, followed by an "!" if the corresponding CPU
is currently offline.  The qb= is the batch number for the RCU core,
the b= is the batch number corresponding to the callbacks waiting for
the current grace period for this CPU, the pq= is a flag indicating that
this CPU has passed through a quiescent state for the current grace
period, the qsp= is a flag indicating that the RCU core has been
informed that this CPU has passed through a quiescent state for the
current grace period, the ql= is the number of RCU callbacks currently
enqueued on this CPU (regardless of their state), and the bl= is the
current limit of the number of callbacks to be invoked at one shot.

Tested on x86 and Power, rebased to -tip.

Signed-off-by: Paul E. McKenney <paulmck@linux.vnet.ibm.com>
---

 include/linux/rcuclassic.h |    4 +
 kernel/Kconfig.preempt     |    1 
 kernel/Makefile            |    2 
 kernel/rcuclassic.c        |    5 -
 kernel/rcuclassic_trace.c  |  179 +++++++++++++++++++++++++++++++++++++++++++++
 5 files changed, 188 insertions(+), 3 deletions(-)

diff --git a/include/linux/rcuclassic.h b/include/linux/rcuclassic.h
index 5f89b62..ce183a8 100644
--- a/include/linux/rcuclassic.h
+++ b/include/linux/rcuclassic.h
@@ -63,6 +63,9 @@ struct rcu_ctrlblk {
 				 /* for current batch to proceed.        */
 } ____cacheline_internodealigned_in_smp;
 
+extern struct rcu_ctrlblk rcu_ctrlblk;
+extern struct rcu_ctrlblk rcu_bh_ctrlblk;
+
 /* Is batch a before batch b ? */
 static inline int rcu_batch_before(long a, long b)
 {
@@ -81,6 +84,7 @@ struct rcu_data {
 	long		quiescbatch;     /* Batch # for grace period */
 	int		passed_quiesc;	 /* User-mode/idle loop etc. */
 	int		qs_pending;	 /* core waits for quiesc state */
+	bool		beenonline;	 /* CPU online at least once */
 
 	/* 2) batch handling */
 	/*
diff --git a/kernel/Kconfig.preempt b/kernel/Kconfig.preempt
index 9fdba03..ba32338 100644
--- a/kernel/Kconfig.preempt
+++ b/kernel/Kconfig.preempt
@@ -68,7 +68,6 @@ config PREEMPT_RCU
 
 config RCU_TRACE
 	bool "Enable tracing for RCU - currently stats in debugfs"
-	depends on PREEMPT_RCU
 	select DEBUG_FS
 	default y
 	help
diff --git a/kernel/Makefile b/kernel/Makefile
index 4e1d7df..e0bfce7 100644
--- a/kernel/Makefile
+++ b/kernel/Makefile
@@ -77,6 +77,8 @@ obj-$(CONFIG_CLASSIC_RCU) += rcuclassic.o
 obj-$(CONFIG_PREEMPT_RCU) += rcupreempt.o
 ifeq ($(CONFIG_PREEMPT_RCU),y)
 obj-$(CONFIG_RCU_TRACE) += rcupreempt_trace.o
+else
+obj-$(CONFIG_RCU_TRACE) += rcuclassic_trace.o
 endif
 obj-$(CONFIG_RELAY) += relay.o
 obj-$(CONFIG_SYSCTL) += utsname_sysctl.o
diff --git a/kernel/rcuclassic.c b/kernel/rcuclassic.c
index 37f72e5..54bd23b 100644
--- a/kernel/rcuclassic.c
+++ b/kernel/rcuclassic.c
@@ -58,14 +58,14 @@ EXPORT_SYMBOL_GPL(rcu_lock_map);
 
 
 /* Definition for rcupdate control block. */
-static struct rcu_ctrlblk rcu_ctrlblk = {
+struct rcu_ctrlblk rcu_ctrlblk = {
 	.cur = -300,
 	.completed = -300,
 	.pending = -300,
 	.lock = __SPIN_LOCK_UNLOCKED(&rcu_ctrlblk.lock),
 	.cpumask = CPU_MASK_NONE,
 };
-static struct rcu_ctrlblk rcu_bh_ctrlblk = {
+struct rcu_ctrlblk rcu_bh_ctrlblk = {
 	.cur = -300,
 	.completed = -300,
 	.pending = -300,
@@ -725,6 +725,7 @@ static void rcu_init_percpu_data(int cpu, struct rcu_ctrlblk *rcp,
 	rdp->donetail = &rdp->donelist;
 	rdp->quiescbatch = rcp->completed;
 	rdp->qs_pending = 0;
+	rdp->beenonline = 1;
 	rdp->cpu = cpu;
 	rdp->blimit = blimit;
 	spin_unlock_irqrestore(&rcp->lock, flags);
diff --git a/kernel/rcuclassic_trace.c b/kernel/rcuclassic_trace.c
new file mode 100644
index 0000000..d19780b
--- /dev/null
+++ b/kernel/rcuclassic_trace.c
@@ -0,0 +1,179 @@
+/*
+ * Read-Copy Update tracing for classic implementation
+ *
+ * This program is free software; you can redistribute it and/or modify
+ * it under the terms of the GNU General Public License as published by
+ * the Free Software Foundation; either version 2 of the License, or
+ * (at your option) any later version.
+ *
+ * This program is distributed in the hope that it will be useful,
+ * but WITHOUT ANY WARRANTY; without even the implied warranty of
+ * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
+ * GNU General Public License for more details.
+ *
+ * You should have received a copy of the GNU General Public License
+ * along with this program; if not, write to the Free Software
+ * Foundation, Inc., 59 Temple Place - Suite 330, Boston, MA 02111-1307, USA.
+ *
+ * Copyright IBM Corporation, 2008
+ *
+ * Papers:  http://www.rdrop.com/users/paulmck/RCU
+ *
+ * For detailed explanation of Read-Copy Update mechanism see -
+ * 		Documentation/RCU
+ *
+ */
+#include <linux/types.h>
+#include <linux/kernel.h>
+#include <linux/init.h>
+#include <linux/spinlock.h>
+#include <linux/smp.h>
+#include <linux/rcupdate.h>
+#include <linux/interrupt.h>
+#include <linux/sched.h>
+#include <asm/atomic.h>
+#include <linux/bitops.h>
+#include <linux/module.h>
+#include <linux/completion.h>
+#include <linux/moduleparam.h>
+#include <linux/percpu.h>
+#include <linux/notifier.h>
+#include <linux/cpu.h>
+#include <linux/mutex.h>
+#include <linux/debugfs.h>
+
+static DEFINE_MUTEX(rcuclassic_trace_mutex);
+static char *rcuclassic_trace_buf;
+#define RCUCLASSIC_TRACE_BUF_SIZE (128 * num_possible_cpus() + 100)
+
+static int print_one_rcu_data(struct rcu_data *rdp, char *buf, char *ebuf)
+{
+	int cnt = 0;
+
+	if (!rdp->beenonline)
+		return 0;
+	cnt += snprintf(&buf[cnt], ebuf - &buf[cnt],
+		"%3d%cqb=%ld b=%ld pq=%d qsp=%d ql=%ld bl=%ld\n",
+		rdp->cpu, cpu_is_offline(rdp->cpu) ? '!' : ' ',
+		rdp->quiescbatch, rdp->batch, rdp->passed_quiesc,
+		rdp->qs_pending, rdp->qlen, rdp->blimit);
+	return cnt;
+}
+
+#define PRINT_RCU_DATA(name, buf, ebuf) \
+	do { \
+		int _p_r_d_i; \
+		\
+		for_each_possible_cpu(_p_r_d_i) \
+			(buf) += print_one_rcu_data(&per_cpu(name, _p_r_d_i), \
+						    buf, ebuf); \
+	} while (0)
+
+static ssize_t rcudata_read(struct file *filp, char __user *buffer,
+				size_t count, loff_t *ppos)
+{
+	ssize_t bcount;
+	char *buf = rcuclassic_trace_buf;
+	char *ebuf = &rcuclassic_trace_buf[RCUCLASSIC_TRACE_BUF_SIZE];
+
+	mutex_lock(&rcuclassic_trace_mutex);
+	buf += snprintf(buf, ebuf - buf, "rcu:\n");
+	PRINT_RCU_DATA(rcu_data, buf, ebuf);
+	buf += snprintf(buf, ebuf - buf, "rcu_bh:\n");
+	PRINT_RCU_DATA(rcu_bh_data, buf, ebuf);
+	bcount = simple_read_from_buffer(buffer, count, ppos,
+			rcuclassic_trace_buf, strlen(rcuclassic_trace_buf));
+	mutex_unlock(&rcuclassic_trace_mutex);
+	return bcount;
+}
+
+static int print_one_rcu_ctrlblk(struct rcu_ctrlblk *rcp, char *buf, char *ebuf)
+{
+	int cnt = 0;
+
+	cnt += snprintf(&buf[cnt], ebuf - &buf[cnt], "cur=%ld  completed=%ld  "
+			"pending=%ld  s=%d\n\t",
+			rcp->cur, rcp->completed,
+			rcp->pending, rcp->signaled);
+	cnt += cpulist_scnprintf(&buf[cnt], ebuf - &buf[cnt], rcp->cpumask);
+	cnt += snprintf(&buf[cnt], ebuf - &buf[cnt], "\n");
+	return cnt;
+}
+
+static ssize_t rcucb_read(struct file *filp, char __user *buffer,
+				size_t count, loff_t *ppos)
+{
+	ssize_t bcount;
+	char *buf = rcuclassic_trace_buf;
+	char *ebuf = &rcuclassic_trace_buf[RCUCLASSIC_TRACE_BUF_SIZE];
+
+	mutex_lock(&rcuclassic_trace_mutex);
+	buf += snprintf(buf, ebuf - buf, "rcu: ");
+	buf += print_one_rcu_ctrlblk(&rcu_ctrlblk, buf, ebuf);
+	buf += snprintf(buf, ebuf - buf, "rcu_bh: ");
+	buf += print_one_rcu_ctrlblk(&rcu_bh_ctrlblk, buf, ebuf);
+	buf += snprintf(buf, ebuf - buf, "online: ");
+	buf += cpulist_scnprintf(buf, ebuf - buf, cpu_online_map);
+	buf += snprintf(buf, ebuf - buf, "\n");
+	bcount = simple_read_from_buffer(buffer, count, ppos,
+			rcuclassic_trace_buf, strlen(rcuclassic_trace_buf));
+	mutex_unlock(&rcuclassic_trace_mutex);
+	return bcount;
+}
+
+static struct file_operations rcudata_fops = {
+	.owner = THIS_MODULE,
+	.read = rcudata_read,
+};
+
+static struct file_operations rcucb_fops = {
+	.owner = THIS_MODULE,
+	.read = rcucb_read,
+};
+
+static struct dentry *rcudir, *datadir, *cbdir;
+static int rcuclassic_debugfs_init(void)
+{
+	rcudir = debugfs_create_dir("rcu", NULL);
+	if (!rcudir)
+		goto out;
+	datadir = debugfs_create_file("rcudata", 0444, rcudir,
+				      NULL, &rcudata_fops);
+	if (!datadir)
+		goto free_out;
+	cbdir = debugfs_create_file("rcucb", 0444, rcudir, NULL, &rcucb_fops);
+	if (!cbdir)
+		goto free_out;
+	return 0;
+free_out:
+	if (datadir)
+		debugfs_remove(datadir);
+	debugfs_remove(rcudir);
+out:
+	return 1;
+}
+
+static int __init rcuclassic_trace_init(void)
+{
+	int ret;
+
+	rcuclassic_trace_buf = kmalloc(RCUCLASSIC_TRACE_BUF_SIZE, GFP_KERNEL);
+	if (!rcuclassic_trace_buf)
+		return 1;
+	ret = rcuclassic_debugfs_init();
+	if (ret)
+		kfree(rcuclassic_trace_buf);
+	return ret;
+}
+
+static void __exit rcuclassic_trace_cleanup(void)
+{
+	debugfs_remove(datadir);
+	debugfs_remove(cbdir);
+	debugfs_remove(rcudir);
+	kfree(rcuclassic_trace_buf);
+}
+
+
+module_init(rcuclassic_trace_init);
+module_exit(rcuclassic_trace_cleanup);

Re: [PATCH] v3 rudimentary tracing for Classic RCU

[Lai Jiangshan]

Paul E. McKenney wrote:
> Hello!
> 
> This is v3 of a tracing patch for Classic RCU, which creates "rcu/rcucb"
> and "rcu/rcudata" files in debugfs.  This patch can be handy when you
> need to work out why RCU is refusing to end the current grace period.
> 
> Should be ready for inclusion in tip/core/rcu, Ingo, please apply.

Hi, Paul,

I'm sorry that I'm a little busy these days, so I have not
ported it to seq_file, and you lost one choice.

I found that seq_cpumask_list() is needed when I tried to ported v2
to seq_file, so I introduced seq_cpumask_list() for seq_file, I'm
waiting procfs hackers apply that patch too.

Lai.

> 
> Changes since v2:  Add flag to rcu_data to avoid printing rcu_data for
> 		   CPUs that have never been online.
> 
> 		   Add documentation (below).
> 
> Changes since v1:  Adds (crude) tracing for rcu_data structures.
> 
> Reading from the "rcu/rcucb" file results in something like the following:
> 
> 	rcu: cur=1129  completed=1128  pending=0  s=0
> 		0,3,7

use "somename: 0,3,7" ? then when mask is empty, I think "somename:" is
better than empty line.

> 	rcu_bh: cur=-287  completed=-287  pending=0  s=0
> 
> 	online: 0-7
> 
> The first two lines are for rcu, the second two for rcu_bh.  The cur=
> is the current grace-period number, and the completed= is the number
> of the last completed grace period.  If these two numbers are equal,
> the corresponding flavor of RCU is idle.  The pending= is the furthest
> future batch number that is required, if equal to cur=, no additional
> grace periods are required.  The s=, if non-zero, indicates that a round
> of reschedule IPIs has been send to attempt to expedite the current
> grace period.
> 
> The second and fourth lines are a comma/dash-separated list of
> the CPUs that have not yet reported a quiescent state for the
> current grace period (CPUs 0, 3, and 7 for "rcu" above).
> 
> The last line lists the online CPUs.
> 
> 
> Reading from the "rcu/rcudata" file results in the following:
> 
> 	rcu:
> 	  0 qb=885 b=884 pq=1 qsp=0 ql=0 bl=10
> 	  1 qb=885 b=882 pq=1 qsp=0 ql=2 bl=10
> 	  2 qb=885 b=854 pq=1 qsp=0 ql=0 bl=10
> 	  3 qb=885 b=885 pq=1 qsp=0 ql=0 bl=10
> 	rcu_bh:
> 	  0 qb=-291 b=-291 pq=1 qsp=0 ql=0 bl=10
> 	  1 qb=-291 b=0 pq=1 qsp=0 ql=0 bl=10
> 	  2 qb=-291 b=0 pq=1 qsp=0 ql=0 bl=10
> 	  3 qb=-291 b=-298 pq=1 qsp=0 ql=0 bl=10
> 
> This output is again split into rcu and rcu_bh portions.  Within each
> portion, there is one line per CPU, but only for those CPUs that have
> been online at least once since boot.  The number at the beginning of
> each line is the CPU number, followed by an "!" if the corresponding CPU
> is currently offline.  The qb= is the batch number for the RCU core,
> the b= is the batch number corresponding to the callbacks waiting for
> the current grace period for this CPU, the pq= is a flag indicating that
> this CPU has passed through a quiescent state for the current grace
> period, the qsp= is a flag indicating that the RCU core has been
> informed that this CPU has passed through a quiescent state for the
> current grace period, the ql= is the number of RCU callbacks currently
> enqueued on this CPU (regardless of their state), and the bl= is the
> current limit of the number of callbacks to be invoked at one shot.
> 
> Tested on x86 and Power, rebased to -tip.
> 
> Signed-off-by: Paul E. McKenney <paulmck@linux.vnet.ibm.com>
> ---
> 
>  include/linux/rcuclassic.h |    4 +
>  kernel/Kconfig.preempt     |    1 
>  kernel/Makefile            |    2 
>  kernel/rcuclassic.c        |    5 -
>  kernel/rcuclassic_trace.c  |  179 +++++++++++++++++++++++++++++++++++++++++++++
>  5 files changed, 188 insertions(+), 3 deletions(-)
> 
> diff --git a/include/linux/rcuclassic.h b/include/linux/rcuclassic.h
> index 5f89b62..ce183a8 100644
> --- a/include/linux/rcuclassic.h
> +++ b/include/linux/rcuclassic.h
> @@ -63,6 +63,9 @@ struct rcu_ctrlblk {
>  				 /* for current batch to proceed.        */
>  } ____cacheline_internodealigned_in_smp;
>  
> +extern struct rcu_ctrlblk rcu_ctrlblk;
> +extern struct rcu_ctrlblk rcu_bh_ctrlblk;
> +
>  /* Is batch a before batch b ? */
>  static inline int rcu_batch_before(long a, long b)
>  {
> @@ -81,6 +84,7 @@ struct rcu_data {
>  	long		quiescbatch;     /* Batch # for grace period */
>  	int		passed_quiesc;	 /* User-mode/idle loop etc. */
>  	int		qs_pending;	 /* core waits for quiesc state */
> +	bool		beenonline;	 /* CPU online at least once */
>  
>  	/* 2) batch handling */
>  	/*
> diff --git a/kernel/Kconfig.preempt b/kernel/Kconfig.preempt
> index 9fdba03..ba32338 100644
> --- a/kernel/Kconfig.preempt
> +++ b/kernel/Kconfig.preempt
> @@ -68,7 +68,6 @@ config PREEMPT_RCU
>  
>  config RCU_TRACE
>  	bool "Enable tracing for RCU - currently stats in debugfs"
> -	depends on PREEMPT_RCU
>  	select DEBUG_FS
>  	default y
>  	help
> diff --git a/kernel/Makefile b/kernel/Makefile
> index 4e1d7df..e0bfce7 100644
> --- a/kernel/Makefile
> +++ b/kernel/Makefile
> @@ -77,6 +77,8 @@ obj-$(CONFIG_CLASSIC_RCU) += rcuclassic.o
>  obj-$(CONFIG_PREEMPT_RCU) += rcupreempt.o
>  ifeq ($(CONFIG_PREEMPT_RCU),y)
>  obj-$(CONFIG_RCU_TRACE) += rcupreempt_trace.o
> +else
> +obj-$(CONFIG_RCU_TRACE) += rcuclassic_trace.o
>  endif
>  obj-$(CONFIG_RELAY) += relay.o
>  obj-$(CONFIG_SYSCTL) += utsname_sysctl.o
> diff --git a/kernel/rcuclassic.c b/kernel/rcuclassic.c
> index 37f72e5..54bd23b 100644
> --- a/kernel/rcuclassic.c
> +++ b/kernel/rcuclassic.c
> @@ -58,14 +58,14 @@ EXPORT_SYMBOL_GPL(rcu_lock_map);
>  
>  
>  /* Definition for rcupdate control block. */
> -static struct rcu_ctrlblk rcu_ctrlblk = {
> +struct rcu_ctrlblk rcu_ctrlblk = {
>  	.cur = -300,
>  	.completed = -300,
>  	.pending = -300,
>  	.lock = __SPIN_LOCK_UNLOCKED(&rcu_ctrlblk.lock),
>  	.cpumask = CPU_MASK_NONE,
>  };
> -static struct rcu_ctrlblk rcu_bh_ctrlblk = {
> +struct rcu_ctrlblk rcu_bh_ctrlblk = {
>  	.cur = -300,
>  	.completed = -300,
>  	.pending = -300,
> @@ -725,6 +725,7 @@ static void rcu_init_percpu_data(int cpu, struct rcu_ctrlblk *rcp,
>  	rdp->donetail = &rdp->donelist;
>  	rdp->quiescbatch = rcp->completed;
>  	rdp->qs_pending = 0;
> +	rdp->beenonline = 1;
>  	rdp->cpu = cpu;
>  	rdp->blimit = blimit;
>  	spin_unlock_irqrestore(&rcp->lock, flags);
> diff --git a/kernel/rcuclassic_trace.c b/kernel/rcuclassic_trace.c
> new file mode 100644
> index 0000000..d19780b
> --- /dev/null
> +++ b/kernel/rcuclassic_trace.c
> @@ -0,0 +1,179 @@
> +/*
> + * Read-Copy Update tracing for classic implementation
> + *
> + * This program is free software; you can redistribute it and/or modify
> + * it under the terms of the GNU General Public License as published by
> + * the Free Software Foundation; either version 2 of the License, or
> + * (at your option) any later version.
> + *
> + * This program is distributed in the hope that it will be useful,
> + * but WITHOUT ANY WARRANTY; without even the implied warranty of
> + * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
> + * GNU General Public License for more details.
> + *
> + * You should have received a copy of the GNU General Public License
> + * along with this program; if not, write to the Free Software
> + * Foundation, Inc., 59 Temple Place - Suite 330, Boston, MA 02111-1307, USA.
> + *
> + * Copyright IBM Corporation, 2008
> + *
> + * Papers:  http://www.rdrop.com/users/paulmck/RCU
> + *
> + * For detailed explanation of Read-Copy Update mechanism see -
> + * 		Documentation/RCU
> + *
> + */
> +#include <linux/types.h>
> +#include <linux/kernel.h>
> +#include <linux/init.h>
> +#include <linux/spinlock.h>
> +#include <linux/smp.h>
> +#include <linux/rcupdate.h>
> +#include <linux/interrupt.h>
> +#include <linux/sched.h>
> +#include <asm/atomic.h>
> +#include <linux/bitops.h>
> +#include <linux/module.h>
> +#include <linux/completion.h>
> +#include <linux/moduleparam.h>
> +#include <linux/percpu.h>
> +#include <linux/notifier.h>
> +#include <linux/cpu.h>
> +#include <linux/mutex.h>
> +#include <linux/debugfs.h>
> +
> +static DEFINE_MUTEX(rcuclassic_trace_mutex);
> +static char *rcuclassic_trace_buf;
> +#define RCUCLASSIC_TRACE_BUF_SIZE (128 * num_possible_cpus() + 100)
> +
> +static int print_one_rcu_data(struct rcu_data *rdp, char *buf, char *ebuf)
> +{
> +	int cnt = 0;
> +
> +	if (!rdp->beenonline)
> +		return 0;
> +	cnt += snprintf(&buf[cnt], ebuf - &buf[cnt],
> +		"%3d%cqb=%ld b=%ld pq=%d qsp=%d ql=%ld bl=%ld\n",
> +		rdp->cpu, cpu_is_offline(rdp->cpu) ? '!' : ' ',
> +		rdp->quiescbatch, rdp->batch, rdp->passed_quiesc,
> +		rdp->qs_pending, rdp->qlen, rdp->blimit);
> +	return cnt;
> +}
> +
> +#define PRINT_RCU_DATA(name, buf, ebuf) \
> +	do { \
> +		int _p_r_d_i; \
> +		\
> +		for_each_possible_cpu(_p_r_d_i) \
> +			(buf) += print_one_rcu_data(&per_cpu(name, _p_r_d_i), \
> +						    buf, ebuf); \
> +	} while (0)
> +
> +static ssize_t rcudata_read(struct file *filp, char __user *buffer,
> +				size_t count, loff_t *ppos)
> +{
> +	ssize_t bcount;
> +	char *buf = rcuclassic_trace_buf;
> +	char *ebuf = &rcuclassic_trace_buf[RCUCLASSIC_TRACE_BUF_SIZE];
> +
> +	mutex_lock(&rcuclassic_trace_mutex);
> +	buf += snprintf(buf, ebuf - buf, "rcu:\n");
> +	PRINT_RCU_DATA(rcu_data, buf, ebuf);
> +	buf += snprintf(buf, ebuf - buf, "rcu_bh:\n");
> +	PRINT_RCU_DATA(rcu_bh_data, buf, ebuf);
> +	bcount = simple_read_from_buffer(buffer, count, ppos,
> +			rcuclassic_trace_buf, strlen(rcuclassic_trace_buf));

Is strlen(rcuclassic_trace_buf) == buf - rcuclassic_trace_buf ?

> +	mutex_unlock(&rcuclassic_trace_mutex);
> +	return bcount;
> +}
> +
> +static int print_one_rcu_ctrlblk(struct rcu_ctrlblk *rcp, char *buf, char *ebuf)
> +{
> +	int cnt = 0;
> +
> +	cnt += snprintf(&buf[cnt], ebuf - &buf[cnt], "cur=%ld  completed=%ld  "
> +			"pending=%ld  s=%d\n\t",
> +			rcp->cur, rcp->completed,
> +			rcp->pending, rcp->signaled);
> +	cnt += cpulist_scnprintf(&buf[cnt], ebuf - &buf[cnt], rcp->cpumask);
> +	cnt += snprintf(&buf[cnt], ebuf - &buf[cnt], "\n");
> +	return cnt;
> +}
> +
> +static ssize_t rcucb_read(struct file *filp, char __user *buffer,
> +				size_t count, loff_t *ppos)
> +{
> +	ssize_t bcount;
> +	char *buf = rcuclassic_trace_buf;
> +	char *ebuf = &rcuclassic_trace_buf[RCUCLASSIC_TRACE_BUF_SIZE];
> +
> +	mutex_lock(&rcuclassic_trace_mutex);
> +	buf += snprintf(buf, ebuf - buf, "rcu: ");
> +	buf += print_one_rcu_ctrlblk(&rcu_ctrlblk, buf, ebuf);
> +	buf += snprintf(buf, ebuf - buf, "rcu_bh: ");
> +	buf += print_one_rcu_ctrlblk(&rcu_bh_ctrlblk, buf, ebuf);
> +	buf += snprintf(buf, ebuf - buf, "online: ");
> +	buf += cpulist_scnprintf(buf, ebuf - buf, cpu_online_map);
> +	buf += snprintf(buf, ebuf - buf, "\n");
> +	bcount = simple_read_from_buffer(buffer, count, ppos,
> +			rcuclassic_trace_buf, strlen(rcuclassic_trace_buf));
> +	mutex_unlock(&rcuclassic_trace_mutex);
> +	return bcount;
> +}
> +
> +static struct file_operations rcudata_fops = {
> +	.owner = THIS_MODULE,
> +	.read = rcudata_read,
> +};
> +
> +static struct file_operations rcucb_fops = {
> +	.owner = THIS_MODULE,
> +	.read = rcucb_read,
> +};
> +
> +static struct dentry *rcudir, *datadir, *cbdir;
> +static int rcuclassic_debugfs_init(void)
> +{
> +	rcudir = debugfs_create_dir("rcu", NULL);
> +	if (!rcudir)
> +		goto out;
> +	datadir = debugfs_create_file("rcudata", 0444, rcudir,
> +				      NULL, &rcudata_fops);
> +	if (!datadir)
> +		goto free_out;
> +	cbdir = debugfs_create_file("rcucb", 0444, rcudir, NULL, &rcucb_fops);
> +	if (!cbdir)
> +		goto free_out;
> +	return 0;
> +free_out:
> +	if (datadir)
> +		debugfs_remove(datadir);
> +	debugfs_remove(rcudir);
> +out:
> +	return 1;
> +}
> +
> +static int __init rcuclassic_trace_init(void)
> +{
> +	int ret;
> +
> +	rcuclassic_trace_buf = kmalloc(RCUCLASSIC_TRACE_BUF_SIZE, GFP_KERNEL);
> +	if (!rcuclassic_trace_buf)
> +		return 1;
> +	ret = rcuclassic_debugfs_init();
> +	if (ret)
> +		kfree(rcuclassic_trace_buf);
> +	return ret;
> +}
> +
> +static void __exit rcuclassic_trace_cleanup(void)
> +{
> +	debugfs_remove(datadir);
> +	debugfs_remove(cbdir);
> +	debugfs_remove(rcudir);
> +	kfree(rcuclassic_trace_buf);
> +}
> +
> +
> +module_init(rcuclassic_trace_init);
> +module_exit(rcuclassic_trace_cleanup);

should have:
MODULE_LICENSE("GPL");

optional but recommend:
MODULE_AUTHOR("Paul E. McKenney");
MODULE_DESCRIPTION("DESCRIPTION");

> --
> To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
> the body of a message to majordomo@vger.kernel.org
> More majordomo info at  http://vger.kernel.org/majordomo-info.html
> Please read the FAQ at  http://www.tux.org/lkml/
> 
> 
> 

Re: [PATCH] v3 rudimentary tracing for Classic RCU

[Paul E. McKenney]

On Tue, Oct 14, 2008 at 11:53:22AM +0800, Lai Jiangshan wrote:
> Paul E. McKenney wrote:
> > Hello!
> > 
> > This is v3 of a tracing patch for Classic RCU, which creates "rcu/rcucb"
> > and "rcu/rcudata" files in debugfs.  This patch can be handy when you
> > need to work out why RCU is refusing to end the current grace period.
> > 
> > Should be ready for inclusion in tip/core/rcu, Ingo, please apply.
> 
> Hi, Paul,
> 
> I'm sorry that I'm a little busy these days, so I have not
> ported it to seq_file, and you lost one choice.
> 
> I found that seq_cpumask_list() is needed when I tried to ported v2
> to seq_file, so I introduced seq_cpumask_list() for seq_file, I'm
> waiting procfs hackers apply that patch too.

No problem, will be happy to see your patch whenever it is available.

							Thanx, Paul

> Lai.
> 
> > 
> > Changes since v2:  Add flag to rcu_data to avoid printing rcu_data for
> > 		   CPUs that have never been online.
> > 
> > 		   Add documentation (below).
> > 
> > Changes since v1:  Adds (crude) tracing for rcu_data structures.
> > 
> > Reading from the "rcu/rcucb" file results in something like the following:
> > 
> > 	rcu: cur=1129  completed=1128  pending=0  s=0
> > 		0,3,7
> 
> use "somename: 0,3,7" ? then when mask is empty, I think "somename:" is
> better than empty line.
> 
> > 	rcu_bh: cur=-287  completed=-287  pending=0  s=0
> > 
> > 	online: 0-7
> > 
> > The first two lines are for rcu, the second two for rcu_bh.  The cur=
> > is the current grace-period number, and the completed= is the number
> > of the last completed grace period.  If these two numbers are equal,
> > the corresponding flavor of RCU is idle.  The pending= is the furthest
> > future batch number that is required, if equal to cur=, no additional
> > grace periods are required.  The s=, if non-zero, indicates that a round
> > of reschedule IPIs has been send to attempt to expedite the current
> > grace period.
> > 
> > The second and fourth lines are a comma/dash-separated list of
> > the CPUs that have not yet reported a quiescent state for the
> > current grace period (CPUs 0, 3, and 7 for "rcu" above).
> > 
> > The last line lists the online CPUs.
> > 
> > 
> > Reading from the "rcu/rcudata" file results in the following:
> > 
> > 	rcu:
> > 	  0 qb=885 b=884 pq=1 qsp=0 ql=0 bl=10
> > 	  1 qb=885 b=882 pq=1 qsp=0 ql=2 bl=10
> > 	  2 qb=885 b=854 pq=1 qsp=0 ql=0 bl=10
> > 	  3 qb=885 b=885 pq=1 qsp=0 ql=0 bl=10
> > 	rcu_bh:
> > 	  0 qb=-291 b=-291 pq=1 qsp=0 ql=0 bl=10
> > 	  1 qb=-291 b=0 pq=1 qsp=0 ql=0 bl=10
> > 	  2 qb=-291 b=0 pq=1 qsp=0 ql=0 bl=10
> > 	  3 qb=-291 b=-298 pq=1 qsp=0 ql=0 bl=10
> > 
> > This output is again split into rcu and rcu_bh portions.  Within each
> > portion, there is one line per CPU, but only for those CPUs that have
> > been online at least once since boot.  The number at the beginning of
> > each line is the CPU number, followed by an "!" if the corresponding CPU
> > is currently offline.  The qb= is the batch number for the RCU core,
> > the b= is the batch number corresponding to the callbacks waiting for
> > the current grace period for this CPU, the pq= is a flag indicating that
> > this CPU has passed through a quiescent state for the current grace
> > period, the qsp= is a flag indicating that the RCU core has been
> > informed that this CPU has passed through a quiescent state for the
> > current grace period, the ql= is the number of RCU callbacks currently
> > enqueued on this CPU (regardless of their state), and the bl= is the
> > current limit of the number of callbacks to be invoked at one shot.
> > 
> > Tested on x86 and Power, rebased to -tip.
> > 
> > Signed-off-by: Paul E. McKenney <paulmck@linux.vnet.ibm.com>
> > ---
> > 
> >  include/linux/rcuclassic.h |    4 +
> >  kernel/Kconfig.preempt     |    1 
> >  kernel/Makefile            |    2 
> >  kernel/rcuclassic.c        |    5 -
> >  kernel/rcuclassic_trace.c  |  179 +++++++++++++++++++++++++++++++++++++++++++++
> >  5 files changed, 188 insertions(+), 3 deletions(-)
> > 
> > diff --git a/include/linux/rcuclassic.h b/include/linux/rcuclassic.h
> > index 5f89b62..ce183a8 100644
> > --- a/include/linux/rcuclassic.h
> > +++ b/include/linux/rcuclassic.h
> > @@ -63,6 +63,9 @@ struct rcu_ctrlblk {
> >  				 /* for current batch to proceed.        */
> >  } ____cacheline_internodealigned_in_smp;
> >  
> > +extern struct rcu_ctrlblk rcu_ctrlblk;
> > +extern struct rcu_ctrlblk rcu_bh_ctrlblk;
> > +
> >  /* Is batch a before batch b ? */
> >  static inline int rcu_batch_before(long a, long b)
> >  {
> > @@ -81,6 +84,7 @@ struct rcu_data {
> >  	long		quiescbatch;     /* Batch # for grace period */
> >  	int		passed_quiesc;	 /* User-mode/idle loop etc. */
> >  	int		qs_pending;	 /* core waits for quiesc state */
> > +	bool		beenonline;	 /* CPU online at least once */
> >  
> >  	/* 2) batch handling */
> >  	/*
> > diff --git a/kernel/Kconfig.preempt b/kernel/Kconfig.preempt
> > index 9fdba03..ba32338 100644
> > --- a/kernel/Kconfig.preempt
> > +++ b/kernel/Kconfig.preempt
> > @@ -68,7 +68,6 @@ config PREEMPT_RCU
> >  
> >  config RCU_TRACE
> >  	bool "Enable tracing for RCU - currently stats in debugfs"
> > -	depends on PREEMPT_RCU
> >  	select DEBUG_FS
> >  	default y
> >  	help
> > diff --git a/kernel/Makefile b/kernel/Makefile
> > index 4e1d7df..e0bfce7 100644
> > --- a/kernel/Makefile
> > +++ b/kernel/Makefile
> > @@ -77,6 +77,8 @@ obj-$(CONFIG_CLASSIC_RCU) += rcuclassic.o
> >  obj-$(CONFIG_PREEMPT_RCU) += rcupreempt.o
> >  ifeq ($(CONFIG_PREEMPT_RCU),y)
> >  obj-$(CONFIG_RCU_TRACE) += rcupreempt_trace.o
> > +else
> > +obj-$(CONFIG_RCU_TRACE) += rcuclassic_trace.o
> >  endif
> >  obj-$(CONFIG_RELAY) += relay.o
> >  obj-$(CONFIG_SYSCTL) += utsname_sysctl.o
> > diff --git a/kernel/rcuclassic.c b/kernel/rcuclassic.c
> > index 37f72e5..54bd23b 100644
> > --- a/kernel/rcuclassic.c
> > +++ b/kernel/rcuclassic.c
> > @@ -58,14 +58,14 @@ EXPORT_SYMBOL_GPL(rcu_lock_map);
> >  
> >  
> >  /* Definition for rcupdate control block. */
> > -static struct rcu_ctrlblk rcu_ctrlblk = {
> > +struct rcu_ctrlblk rcu_ctrlblk = {
> >  	.cur = -300,
> >  	.completed = -300,
> >  	.pending = -300,
> >  	.lock = __SPIN_LOCK_UNLOCKED(&rcu_ctrlblk.lock),
> >  	.cpumask = CPU_MASK_NONE,
> >  };
> > -static struct rcu_ctrlblk rcu_bh_ctrlblk = {
> > +struct rcu_ctrlblk rcu_bh_ctrlblk = {
> >  	.cur = -300,
> >  	.completed = -300,
> >  	.pending = -300,
> > @@ -725,6 +725,7 @@ static void rcu_init_percpu_data(int cpu, struct rcu_ctrlblk *rcp,
> >  	rdp->donetail = &rdp->donelist;
> >  	rdp->quiescbatch = rcp->completed;
> >  	rdp->qs_pending = 0;
> > +	rdp->beenonline = 1;
> >  	rdp->cpu = cpu;
> >  	rdp->blimit = blimit;
> >  	spin_unlock_irqrestore(&rcp->lock, flags);
> > diff --git a/kernel/rcuclassic_trace.c b/kernel/rcuclassic_trace.c
> > new file mode 100644
> > index 0000000..d19780b
> > --- /dev/null
> > +++ b/kernel/rcuclassic_trace.c
> > @@ -0,0 +1,179 @@
> > +/*
> > + * Read-Copy Update tracing for classic implementation
> > + *
> > + * This program is free software; you can redistribute it and/or modify
> > + * it under the terms of the GNU General Public License as published by
> > + * the Free Software Foundation; either version 2 of the License, or
> > + * (at your option) any later version.
> > + *
> > + * This program is distributed in the hope that it will be useful,
> > + * but WITHOUT ANY WARRANTY; without even the implied warranty of
> > + * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
> > + * GNU General Public License for more details.
> > + *
> > + * You should have received a copy of the GNU General Public License
> > + * along with this program; if not, write to the Free Software
> > + * Foundation, Inc., 59 Temple Place - Suite 330, Boston, MA 02111-1307, USA.
> > + *
> > + * Copyright IBM Corporation, 2008
> > + *
> > + * Papers:  http://www.rdrop.com/users/paulmck/RCU
> > + *
> > + * For detailed explanation of Read-Copy Update mechanism see -
> > + * 		Documentation/RCU
> > + *
> > + */
> > +#include <linux/types.h>
> > +#include <linux/kernel.h>
> > +#include <linux/init.h>
> > +#include <linux/spinlock.h>
> > +#include <linux/smp.h>
> > +#include <linux/rcupdate.h>
> > +#include <linux/interrupt.h>
> > +#include <linux/sched.h>
> > +#include <asm/atomic.h>
> > +#include <linux/bitops.h>
> > +#include <linux/module.h>
> > +#include <linux/completion.h>
> > +#include <linux/moduleparam.h>
> > +#include <linux/percpu.h>
> > +#include <linux/notifier.h>
> > +#include <linux/cpu.h>
> > +#include <linux/mutex.h>
> > +#include <linux/debugfs.h>
> > +
> > +static DEFINE_MUTEX(rcuclassic_trace_mutex);
> > +static char *rcuclassic_trace_buf;
> > +#define RCUCLASSIC_TRACE_BUF_SIZE (128 * num_possible_cpus() + 100)
> > +
> > +static int print_one_rcu_data(struct rcu_data *rdp, char *buf, char *ebuf)
> > +{
> > +	int cnt = 0;
> > +
> > +	if (!rdp->beenonline)
> > +		return 0;
> > +	cnt += snprintf(&buf[cnt], ebuf - &buf[cnt],
> > +		"%3d%cqb=%ld b=%ld pq=%d qsp=%d ql=%ld bl=%ld\n",
> > +		rdp->cpu, cpu_is_offline(rdp->cpu) ? '!' : ' ',
> > +		rdp->quiescbatch, rdp->batch, rdp->passed_quiesc,
> > +		rdp->qs_pending, rdp->qlen, rdp->blimit);
> > +	return cnt;
> > +}
> > +
> > +#define PRINT_RCU_DATA(name, buf, ebuf) \
> > +	do { \
> > +		int _p_r_d_i; \
> > +		\
> > +		for_each_possible_cpu(_p_r_d_i) \
> > +			(buf) += print_one_rcu_data(&per_cpu(name, _p_r_d_i), \
> > +						    buf, ebuf); \
> > +	} while (0)
> > +
> > +static ssize_t rcudata_read(struct file *filp, char __user *buffer,
> > +				size_t count, loff_t *ppos)
> > +{
> > +	ssize_t bcount;
> > +	char *buf = rcuclassic_trace_buf;
> > +	char *ebuf = &rcuclassic_trace_buf[RCUCLASSIC_TRACE_BUF_SIZE];
> > +
> > +	mutex_lock(&rcuclassic_trace_mutex);
> > +	buf += snprintf(buf, ebuf - buf, "rcu:\n");
> > +	PRINT_RCU_DATA(rcu_data, buf, ebuf);
> > +	buf += snprintf(buf, ebuf - buf, "rcu_bh:\n");
> > +	PRINT_RCU_DATA(rcu_bh_data, buf, ebuf);
> > +	bcount = simple_read_from_buffer(buffer, count, ppos,
> > +			rcuclassic_trace_buf, strlen(rcuclassic_trace_buf));
> 
> Is strlen(rcuclassic_trace_buf) == buf - rcuclassic_trace_buf ?
> 
> > +	mutex_unlock(&rcuclassic_trace_mutex);
> > +	return bcount;
> > +}
> > +
> > +static int print_one_rcu_ctrlblk(struct rcu_ctrlblk *rcp, char *buf, char *ebuf)
> > +{
> > +	int cnt = 0;
> > +
> > +	cnt += snprintf(&buf[cnt], ebuf - &buf[cnt], "cur=%ld  completed=%ld  "
> > +			"pending=%ld  s=%d\n\t",
> > +			rcp->cur, rcp->completed,
> > +			rcp->pending, rcp->signaled);
> > +	cnt += cpulist_scnprintf(&buf[cnt], ebuf - &buf[cnt], rcp->cpumask);
> > +	cnt += snprintf(&buf[cnt], ebuf - &buf[cnt], "\n");
> > +	return cnt;
> > +}
> > +
> > +static ssize_t rcucb_read(struct file *filp, char __user *buffer,
> > +				size_t count, loff_t *ppos)
> > +{
> > +	ssize_t bcount;
> > +	char *buf = rcuclassic_trace_buf;
> > +	char *ebuf = &rcuclassic_trace_buf[RCUCLASSIC_TRACE_BUF_SIZE];
> > +
> > +	mutex_lock(&rcuclassic_trace_mutex);
> > +	buf += snprintf(buf, ebuf - buf, "rcu: ");
> > +	buf += print_one_rcu_ctrlblk(&rcu_ctrlblk, buf, ebuf);
> > +	buf += snprintf(buf, ebuf - buf, "rcu_bh: ");
> > +	buf += print_one_rcu_ctrlblk(&rcu_bh_ctrlblk, buf, ebuf);
> > +	buf += snprintf(buf, ebuf - buf, "online: ");
> > +	buf += cpulist_scnprintf(buf, ebuf - buf, cpu_online_map);
> > +	buf += snprintf(buf, ebuf - buf, "\n");
> > +	bcount = simple_read_from_buffer(buffer, count, ppos,
> > +			rcuclassic_trace_buf, strlen(rcuclassic_trace_buf));
> > +	mutex_unlock(&rcuclassic_trace_mutex);
> > +	return bcount;
> > +}
> > +
> > +static struct file_operations rcudata_fops = {
> > +	.owner = THIS_MODULE,
> > +	.read = rcudata_read,
> > +};
> > +
> > +static struct file_operations rcucb_fops = {
> > +	.owner = THIS_MODULE,
> > +	.read = rcucb_read,
> > +};
> > +
> > +static struct dentry *rcudir, *datadir, *cbdir;
> > +static int rcuclassic_debugfs_init(void)
> > +{
> > +	rcudir = debugfs_create_dir("rcu", NULL);
> > +	if (!rcudir)
> > +		goto out;
> > +	datadir = debugfs_create_file("rcudata", 0444, rcudir,
> > +				      NULL, &rcudata_fops);
> > +	if (!datadir)
> > +		goto free_out;
> > +	cbdir = debugfs_create_file("rcucb", 0444, rcudir, NULL, &rcucb_fops);
> > +	if (!cbdir)
> > +		goto free_out;
> > +	return 0;
> > +free_out:
> > +	if (datadir)
> > +		debugfs_remove(datadir);
> > +	debugfs_remove(rcudir);
> > +out:
> > +	return 1;
> > +}
> > +
> > +static int __init rcuclassic_trace_init(void)
> > +{
> > +	int ret;
> > +
> > +	rcuclassic_trace_buf = kmalloc(RCUCLASSIC_TRACE_BUF_SIZE, GFP_KERNEL);
> > +	if (!rcuclassic_trace_buf)
> > +		return 1;
> > +	ret = rcuclassic_debugfs_init();
> > +	if (ret)
> > +		kfree(rcuclassic_trace_buf);
> > +	return ret;
> > +}
> > +
> > +static void __exit rcuclassic_trace_cleanup(void)
> > +{
> > +	debugfs_remove(datadir);
> > +	debugfs_remove(cbdir);
> > +	debugfs_remove(rcudir);
> > +	kfree(rcuclassic_trace_buf);
> > +}
> > +
> > +
> > +module_init(rcuclassic_trace_init);
> > +module_exit(rcuclassic_trace_cleanup);
> 
> should have:
> MODULE_LICENSE("GPL");
> 
> optional but recommend:
> MODULE_AUTHOR("Paul E. McKenney");
> MODULE_DESCRIPTION("DESCRIPTION");
> 
> > --
> > To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
> > the body of a message to majordomo@vger.kernel.org
> > More majordomo info at  http://vger.kernel.org/majordomo-info.html
> > Please read the FAQ at  http://www.tux.org/lkml/
> > 
> > 
> > 
> 
> 
> 

Re: [PATCH] v3 rudimentary tracing for Classic RCU

[Lai Jiangshan]

trivial ported it to seq_file.
seq_file are very good for the output buffer.

Signed-off-by: Lai Jiangshan <laijs@cn.fujitsu.com>
---
diff --git a/kernel/rcuclassic_trace.c b/kernel/rcuclassic_trace.c
index d19780b..f19217c
--- a/kernel/rcuclassic_trace.c
+++ b/kernel/rcuclassic_trace.c
@@ -23,157 +23,167 @@
  * 		Documentation/RCU
  *
  */
-#include <linux/types.h>
-#include <linux/kernel.h>
-#include <linux/init.h>
-#include <linux/spinlock.h>
-#include <linux/smp.h>
 #include <linux/rcupdate.h>
-#include <linux/interrupt.h>
-#include <linux/sched.h>
-#include <asm/atomic.h>
-#include <linux/bitops.h>
 #include <linux/module.h>
-#include <linux/completion.h>
-#include <linux/moduleparam.h>
-#include <linux/percpu.h>
-#include <linux/notifier.h>
-#include <linux/cpu.h>
-#include <linux/mutex.h>
 #include <linux/debugfs.h>
+#include <linux/seq_file.h>
 
-static DEFINE_MUTEX(rcuclassic_trace_mutex);
-static char *rcuclassic_trace_buf;
-#define RCUCLASSIC_TRACE_BUF_SIZE (128 * num_possible_cpus() + 100)
+static struct rcu_data *get_rcu_data_bh(int cpu)
+{
+	return &per_cpu(rcu_bh_data, cpu);
+}
 
-static int print_one_rcu_data(struct rcu_data *rdp, char *buf, char *ebuf)
+static struct rcu_data *get_rcu_data(int cpu)
 {
-	int cnt = 0;
+	return &per_cpu(rcu_data, cpu);
+}
 
+static int show_rcu_data(struct seq_file *m, void *v)
+{
+	struct rcu_data *rdp = v;
 	if (!rdp->beenonline)
 		return 0;
-	cnt += snprintf(&buf[cnt], ebuf - &buf[cnt],
-		"%3d%cqb=%ld b=%ld pq=%d qsp=%d ql=%ld bl=%ld\n",
-		rdp->cpu, cpu_is_offline(rdp->cpu) ? '!' : ' ',
-		rdp->quiescbatch, rdp->batch, rdp->passed_quiesc,
-		rdp->qs_pending, rdp->qlen, rdp->blimit);
-	return cnt;
+
+	seq_printf(m, "processor\t: %d", rdp->cpu);
+	if (cpu_is_offline(rdp->cpu))
+		seq_puts(m, "!\n");
+	else
+		seq_puts(m, "\n");
+	seq_printf(m, "quiescbatch\t: %ld\n", rdp->quiescbatch);
+	seq_printf(m, "batch\t: %ld\n", rdp->batch);
+	seq_printf(m, "passed_quiesc\t: %d\n", rdp->passed_quiesc);
+	seq_printf(m, "qs_pending\t: %d\n", rdp->qs_pending);
+	seq_printf(m, "qlen\t: %ld\n", rdp->qlen);
+	seq_printf(m, "blimit\t: %ld\n", rdp->blimit);
+	seq_puts(m, "\n\n");
+	return 0;
 }
 
-#define PRINT_RCU_DATA(name, buf, ebuf) \
-	do { \
-		int _p_r_d_i; \
-		\
-		for_each_possible_cpu(_p_r_d_i) \
-			(buf) += print_one_rcu_data(&per_cpu(name, _p_r_d_i), \
-						    buf, ebuf); \
-	} while (0)
-
-static ssize_t rcudata_read(struct file *filp, char __user *buffer,
-				size_t count, loff_t *ppos)
+static void *c_start(struct seq_file *m, loff_t *pos)
 {
-	ssize_t bcount;
-	char *buf = rcuclassic_trace_buf;
-	char *ebuf = &rcuclassic_trace_buf[RCUCLASSIC_TRACE_BUF_SIZE];
-
-	mutex_lock(&rcuclassic_trace_mutex);
-	buf += snprintf(buf, ebuf - buf, "rcu:\n");
-	PRINT_RCU_DATA(rcu_data, buf, ebuf);
-	buf += snprintf(buf, ebuf - buf, "rcu_bh:\n");
-	PRINT_RCU_DATA(rcu_bh_data, buf, ebuf);
-	bcount = simple_read_from_buffer(buffer, count, ppos,
-			rcuclassic_trace_buf, strlen(rcuclassic_trace_buf));
-	mutex_unlock(&rcuclassic_trace_mutex);
-	return bcount;
+	typedef struct rcu_data *(*get_data_func)(int);
+
+	if (*pos == 0)	/* just in case, cpu 0 is not the first */
+		*pos = first_cpu(cpu_possible_map);
+	else
+		*pos = next_cpu_nr(*pos - 1, cpu_possible_map);
+	if ((*pos) < nr_cpu_ids)
+		return ((get_data_func)m->private)(*pos);
+	return NULL;
 }
 
-static int print_one_rcu_ctrlblk(struct rcu_ctrlblk *rcp, char *buf, char *ebuf)
+static void *c_next(struct seq_file *m, void *v, loff_t *pos)
 {
-	int cnt = 0;
-
-	cnt += snprintf(&buf[cnt], ebuf - &buf[cnt], "cur=%ld  completed=%ld  "
-			"pending=%ld  s=%d\n\t",
-			rcp->cur, rcp->completed,
-			rcp->pending, rcp->signaled);
-	cnt += cpulist_scnprintf(&buf[cnt], ebuf - &buf[cnt], rcp->cpumask);
-	cnt += snprintf(&buf[cnt], ebuf - &buf[cnt], "\n");
-	return cnt;
+	(*pos)++;
+	return c_start(m, pos);
 }
 
-static ssize_t rcucb_read(struct file *filp, char __user *buffer,
-				size_t count, loff_t *ppos)
+static void c_stop(struct seq_file *m, void *v)
 {
-	ssize_t bcount;
-	char *buf = rcuclassic_trace_buf;
-	char *ebuf = &rcuclassic_trace_buf[RCUCLASSIC_TRACE_BUF_SIZE];
-
-	mutex_lock(&rcuclassic_trace_mutex);
-	buf += snprintf(buf, ebuf - buf, "rcu: ");
-	buf += print_one_rcu_ctrlblk(&rcu_ctrlblk, buf, ebuf);
-	buf += snprintf(buf, ebuf - buf, "rcu_bh: ");
-	buf += print_one_rcu_ctrlblk(&rcu_bh_ctrlblk, buf, ebuf);
-	buf += snprintf(buf, ebuf - buf, "online: ");
-	buf += cpulist_scnprintf(buf, ebuf - buf, cpu_online_map);
-	buf += snprintf(buf, ebuf - buf, "\n");
-	bcount = simple_read_from_buffer(buffer, count, ppos,
-			rcuclassic_trace_buf, strlen(rcuclassic_trace_buf));
-	mutex_unlock(&rcuclassic_trace_mutex);
-	return bcount;
 }
 
-static struct file_operations rcudata_fops = {
-	.owner = THIS_MODULE,
-	.read = rcudata_read,
+const struct seq_operations rcu_data_seq_op = {
+	.start	= c_start,
+	.next	= c_next,
+	.stop	= c_stop,
+	.show	= show_rcu_data,
 };
 
+static int rcu_data_open(struct inode *inode, struct file *file)
+{
+	int ret = seq_open(file, &rcu_data_seq_op);
+	if (ret)
+		return ret;
+	((struct seq_file *)file->private_data)->private = inode->i_private;
+	return 0;
+}
+
+static const struct file_operations rcu_data_fops = {
+	.owner		= THIS_MODULE,
+	.open		= rcu_data_open,
+	.read		= seq_read,
+	.llseek		= seq_lseek,
+	.release	= seq_release,
+};
+
+static void print_one_rcu_ctrlblk(struct seq_file *m, struct rcu_ctrlblk *rcp)
+{
+	seq_printf(m, "cur=%ld  completed=%ld   pending=%ld  s=%d\n\t",
+			rcp->cur, rcp->completed, rcp->pending, rcp->signaled);
+	seq_cpumask(m, &rcp->cpumask);
+	seq_puts(m, "\n");
+}
+
+static int show_rcucb(struct seq_file *m, void *unused)
+{
+	seq_puts(m, "rcu: ");
+	print_one_rcu_ctrlblk(m, &rcu_ctrlblk);
+	seq_puts(m, "rcu_bh: ");
+	print_one_rcu_ctrlblk(m, &rcu_bh_ctrlblk);
+	seq_puts(m, "online: ");
+	seq_cpumask(m, &cpu_online_map);
+	seq_puts(m, "\n");
+	return 0;
+}
+
+static int rcucb_open(struct inode *inode, struct file *file)
+{
+	return single_open(file, show_rcucb, NULL);
+}
+
 static struct file_operations rcucb_fops = {
-	.owner = THIS_MODULE,
-	.read = rcucb_read,
+	.owner		= THIS_MODULE,
+	.open		= rcucb_open,
+	.read		= seq_read,
+	.llseek		= seq_lseek,
+	.release	= single_release,
 };
 
-static struct dentry *rcudir, *datadir, *cbdir;
-static int rcuclassic_debugfs_init(void)
+static struct dentry *rcudir, *rcu_bh_data_file, *rcu_data_file, *rcucb_file;
+
+static int __init rcuclassic_trace_init(void)
 {
 	rcudir = debugfs_create_dir("rcu", NULL);
 	if (!rcudir)
 		goto out;
-	datadir = debugfs_create_file("rcudata", 0444, rcudir,
-				      NULL, &rcudata_fops);
-	if (!datadir)
-		goto free_out;
-	cbdir = debugfs_create_file("rcucb", 0444, rcudir, NULL, &rcucb_fops);
-	if (!cbdir)
-		goto free_out;
+
+	rcu_bh_data_file = debugfs_create_file("rcu_bh_data", 0444, rcudir,
+			get_rcu_data_bh, &rcu_data_fops);
+	if (!rcu_bh_data_file)
+		goto out_rcudir;
+
+	rcu_data_file = debugfs_create_file("rcu_data", 0444, rcudir,
+			get_rcu_data, &rcu_data_fops);
+	if (!rcu_data_file)
+		goto out_rcudata_bh_file;
+
+	rcucb_file = debugfs_create_file("rcucb", 0444, rcudir,
+			NULL, &rcucb_fops);
+	if (!rcucb_file)
+		goto out_rcudata_file;
 	return 0;
-free_out:
-	if (datadir)
-		debugfs_remove(datadir);
+
+out_rcudata_file:
+	debugfs_remove(rcu_data_file);
+out_rcudata_bh_file:
+	debugfs_remove(rcu_bh_data_file);
+out_rcudir:
 	debugfs_remove(rcudir);
 out:
 	return 1;
 }
 
-static int __init rcuclassic_trace_init(void)
-{
-	int ret;
-
-	rcuclassic_trace_buf = kmalloc(RCUCLASSIC_TRACE_BUF_SIZE, GFP_KERNEL);
-	if (!rcuclassic_trace_buf)
-		return 1;
-	ret = rcuclassic_debugfs_init();
-	if (ret)
-		kfree(rcuclassic_trace_buf);
-	return ret;
-}
-
 static void __exit rcuclassic_trace_cleanup(void)
 {
-	debugfs_remove(datadir);
-	debugfs_remove(cbdir);
+	debugfs_remove(rcucb_file);
+	debugfs_remove(rcu_data_file);
+	debugfs_remove(rcu_bh_data_file);
 	debugfs_remove(rcudir);
-	kfree(rcuclassic_trace_buf);
 }
 
-
 module_init(rcuclassic_trace_init);
 module_exit(rcuclassic_trace_cleanup);
+
+MODULE_AUTHOR("Paul E. McKenney");
+MODULE_DESCRIPTION("Read-Copy Update tracing for classic implementation");
+MODULE_LICENSE("GPL");

Re: [PATCH] v3 rudimentary tracing for Classic RCU

[Paul E. McKenney]

On Thu, Oct 23, 2008 at 07:12:09PM +0800, Lai Jiangshan wrote:
> 
> trivial ported it to seq_file.
> seq_file are very good for the output buffer.

Thank you for putting this together!!!  Looks good at first glance --
I will test it out.

							Thanx, Paul

> Signed-off-by: Lai Jiangshan <laijs@cn.fujitsu.com>
> ---
> diff --git a/kernel/rcuclassic_trace.c b/kernel/rcuclassic_trace.c
> index d19780b..f19217c
> --- a/kernel/rcuclassic_trace.c
> +++ b/kernel/rcuclassic_trace.c
> @@ -23,157 +23,167 @@
>   * 		Documentation/RCU
>   *
>   */
> -#include <linux/types.h>
> -#include <linux/kernel.h>
> -#include <linux/init.h>
> -#include <linux/spinlock.h>
> -#include <linux/smp.h>
>  #include <linux/rcupdate.h>
> -#include <linux/interrupt.h>
> -#include <linux/sched.h>
> -#include <asm/atomic.h>
> -#include <linux/bitops.h>
>  #include <linux/module.h>
> -#include <linux/completion.h>
> -#include <linux/moduleparam.h>
> -#include <linux/percpu.h>
> -#include <linux/notifier.h>
> -#include <linux/cpu.h>
> -#include <linux/mutex.h>
>  #include <linux/debugfs.h>
> +#include <linux/seq_file.h>
> 
> -static DEFINE_MUTEX(rcuclassic_trace_mutex);
> -static char *rcuclassic_trace_buf;
> -#define RCUCLASSIC_TRACE_BUF_SIZE (128 * num_possible_cpus() + 100)
> +static struct rcu_data *get_rcu_data_bh(int cpu)
> +{
> +	return &per_cpu(rcu_bh_data, cpu);
> +}
> 
> -static int print_one_rcu_data(struct rcu_data *rdp, char *buf, char *ebuf)
> +static struct rcu_data *get_rcu_data(int cpu)
>  {
> -	int cnt = 0;
> +	return &per_cpu(rcu_data, cpu);
> +}
> 
> +static int show_rcu_data(struct seq_file *m, void *v)
> +{
> +	struct rcu_data *rdp = v;
>  	if (!rdp->beenonline)
>  		return 0;
> -	cnt += snprintf(&buf[cnt], ebuf - &buf[cnt],
> -		"%3d%cqb=%ld b=%ld pq=%d qsp=%d ql=%ld bl=%ld\n",
> -		rdp->cpu, cpu_is_offline(rdp->cpu) ? '!' : ' ',
> -		rdp->quiescbatch, rdp->batch, rdp->passed_quiesc,
> -		rdp->qs_pending, rdp->qlen, rdp->blimit);
> -	return cnt;
> +
> +	seq_printf(m, "processor\t: %d", rdp->cpu);
> +	if (cpu_is_offline(rdp->cpu))
> +		seq_puts(m, "!\n");
> +	else
> +		seq_puts(m, "\n");
> +	seq_printf(m, "quiescbatch\t: %ld\n", rdp->quiescbatch);
> +	seq_printf(m, "batch\t: %ld\n", rdp->batch);
> +	seq_printf(m, "passed_quiesc\t: %d\n", rdp->passed_quiesc);
> +	seq_printf(m, "qs_pending\t: %d\n", rdp->qs_pending);
> +	seq_printf(m, "qlen\t: %ld\n", rdp->qlen);
> +	seq_printf(m, "blimit\t: %ld\n", rdp->blimit);
> +	seq_puts(m, "\n\n");
> +	return 0;
>  }
> 
> -#define PRINT_RCU_DATA(name, buf, ebuf) \
> -	do { \
> -		int _p_r_d_i; \
> -		\
> -		for_each_possible_cpu(_p_r_d_i) \
> -			(buf) += print_one_rcu_data(&per_cpu(name, _p_r_d_i), \
> -						    buf, ebuf); \
> -	} while (0)
> -
> -static ssize_t rcudata_read(struct file *filp, char __user *buffer,
> -				size_t count, loff_t *ppos)
> +static void *c_start(struct seq_file *m, loff_t *pos)
>  {
> -	ssize_t bcount;
> -	char *buf = rcuclassic_trace_buf;
> -	char *ebuf = &rcuclassic_trace_buf[RCUCLASSIC_TRACE_BUF_SIZE];
> -
> -	mutex_lock(&rcuclassic_trace_mutex);
> -	buf += snprintf(buf, ebuf - buf, "rcu:\n");
> -	PRINT_RCU_DATA(rcu_data, buf, ebuf);
> -	buf += snprintf(buf, ebuf - buf, "rcu_bh:\n");
> -	PRINT_RCU_DATA(rcu_bh_data, buf, ebuf);
> -	bcount = simple_read_from_buffer(buffer, count, ppos,
> -			rcuclassic_trace_buf, strlen(rcuclassic_trace_buf));
> -	mutex_unlock(&rcuclassic_trace_mutex);
> -	return bcount;
> +	typedef struct rcu_data *(*get_data_func)(int);
> +
> +	if (*pos == 0)	/* just in case, cpu 0 is not the first */
> +		*pos = first_cpu(cpu_possible_map);
> +	else
> +		*pos = next_cpu_nr(*pos - 1, cpu_possible_map);
> +	if ((*pos) < nr_cpu_ids)
> +		return ((get_data_func)m->private)(*pos);
> +	return NULL;
>  }
> 
> -static int print_one_rcu_ctrlblk(struct rcu_ctrlblk *rcp, char *buf, char *ebuf)
> +static void *c_next(struct seq_file *m, void *v, loff_t *pos)
>  {
> -	int cnt = 0;
> -
> -	cnt += snprintf(&buf[cnt], ebuf - &buf[cnt], "cur=%ld  completed=%ld  "
> -			"pending=%ld  s=%d\n\t",
> -			rcp->cur, rcp->completed,
> -			rcp->pending, rcp->signaled);
> -	cnt += cpulist_scnprintf(&buf[cnt], ebuf - &buf[cnt], rcp->cpumask);
> -	cnt += snprintf(&buf[cnt], ebuf - &buf[cnt], "\n");
> -	return cnt;
> +	(*pos)++;
> +	return c_start(m, pos);
>  }
> 
> -static ssize_t rcucb_read(struct file *filp, char __user *buffer,
> -				size_t count, loff_t *ppos)
> +static void c_stop(struct seq_file *m, void *v)
>  {
> -	ssize_t bcount;
> -	char *buf = rcuclassic_trace_buf;
> -	char *ebuf = &rcuclassic_trace_buf[RCUCLASSIC_TRACE_BUF_SIZE];
> -
> -	mutex_lock(&rcuclassic_trace_mutex);
> -	buf += snprintf(buf, ebuf - buf, "rcu: ");
> -	buf += print_one_rcu_ctrlblk(&rcu_ctrlblk, buf, ebuf);
> -	buf += snprintf(buf, ebuf - buf, "rcu_bh: ");
> -	buf += print_one_rcu_ctrlblk(&rcu_bh_ctrlblk, buf, ebuf);
> -	buf += snprintf(buf, ebuf - buf, "online: ");
> -	buf += cpulist_scnprintf(buf, ebuf - buf, cpu_online_map);
> -	buf += snprintf(buf, ebuf - buf, "\n");
> -	bcount = simple_read_from_buffer(buffer, count, ppos,
> -			rcuclassic_trace_buf, strlen(rcuclassic_trace_buf));
> -	mutex_unlock(&rcuclassic_trace_mutex);
> -	return bcount;
>  }
> 
> -static struct file_operations rcudata_fops = {
> -	.owner = THIS_MODULE,
> -	.read = rcudata_read,
> +const struct seq_operations rcu_data_seq_op = {
> +	.start	= c_start,
> +	.next	= c_next,
> +	.stop	= c_stop,
> +	.show	= show_rcu_data,
>  };
> 
> +static int rcu_data_open(struct inode *inode, struct file *file)
> +{
> +	int ret = seq_open(file, &rcu_data_seq_op);
> +	if (ret)
> +		return ret;
> +	((struct seq_file *)file->private_data)->private = inode->i_private;
> +	return 0;
> +}
> +
> +static const struct file_operations rcu_data_fops = {
> +	.owner		= THIS_MODULE,
> +	.open		= rcu_data_open,
> +	.read		= seq_read,
> +	.llseek		= seq_lseek,
> +	.release	= seq_release,
> +};
> +
> +static void print_one_rcu_ctrlblk(struct seq_file *m, struct rcu_ctrlblk *rcp)
> +{
> +	seq_printf(m, "cur=%ld  completed=%ld   pending=%ld  s=%d\n\t",
> +			rcp->cur, rcp->completed, rcp->pending, rcp->signaled);
> +	seq_cpumask(m, &rcp->cpumask);
> +	seq_puts(m, "\n");
> +}
> +
> +static int show_rcucb(struct seq_file *m, void *unused)
> +{
> +	seq_puts(m, "rcu: ");
> +	print_one_rcu_ctrlblk(m, &rcu_ctrlblk);
> +	seq_puts(m, "rcu_bh: ");
> +	print_one_rcu_ctrlblk(m, &rcu_bh_ctrlblk);
> +	seq_puts(m, "online: ");
> +	seq_cpumask(m, &cpu_online_map);
> +	seq_puts(m, "\n");
> +	return 0;
> +}
> +
> +static int rcucb_open(struct inode *inode, struct file *file)
> +{
> +	return single_open(file, show_rcucb, NULL);
> +}
> +
>  static struct file_operations rcucb_fops = {
> -	.owner = THIS_MODULE,
> -	.read = rcucb_read,
> +	.owner		= THIS_MODULE,
> +	.open		= rcucb_open,
> +	.read		= seq_read,
> +	.llseek		= seq_lseek,
> +	.release	= single_release,
>  };
> 
> -static struct dentry *rcudir, *datadir, *cbdir;
> -static int rcuclassic_debugfs_init(void)
> +static struct dentry *rcudir, *rcu_bh_data_file, *rcu_data_file, *rcucb_file;
> +
> +static int __init rcuclassic_trace_init(void)
>  {
>  	rcudir = debugfs_create_dir("rcu", NULL);
>  	if (!rcudir)
>  		goto out;
> -	datadir = debugfs_create_file("rcudata", 0444, rcudir,
> -				      NULL, &rcudata_fops);
> -	if (!datadir)
> -		goto free_out;
> -	cbdir = debugfs_create_file("rcucb", 0444, rcudir, NULL, &rcucb_fops);
> -	if (!cbdir)
> -		goto free_out;
> +
> +	rcu_bh_data_file = debugfs_create_file("rcu_bh_data", 0444, rcudir,
> +			get_rcu_data_bh, &rcu_data_fops);
> +	if (!rcu_bh_data_file)
> +		goto out_rcudir;
> +
> +	rcu_data_file = debugfs_create_file("rcu_data", 0444, rcudir,
> +			get_rcu_data, &rcu_data_fops);
> +	if (!rcu_data_file)
> +		goto out_rcudata_bh_file;
> +
> +	rcucb_file = debugfs_create_file("rcucb", 0444, rcudir,
> +			NULL, &rcucb_fops);
> +	if (!rcucb_file)
> +		goto out_rcudata_file;
>  	return 0;
> -free_out:
> -	if (datadir)
> -		debugfs_remove(datadir);
> +
> +out_rcudata_file:
> +	debugfs_remove(rcu_data_file);
> +out_rcudata_bh_file:
> +	debugfs_remove(rcu_bh_data_file);
> +out_rcudir:
>  	debugfs_remove(rcudir);
>  out:
>  	return 1;
>  }
> 
> -static int __init rcuclassic_trace_init(void)
> -{
> -	int ret;
> -
> -	rcuclassic_trace_buf = kmalloc(RCUCLASSIC_TRACE_BUF_SIZE, GFP_KERNEL);
> -	if (!rcuclassic_trace_buf)
> -		return 1;
> -	ret = rcuclassic_debugfs_init();
> -	if (ret)
> -		kfree(rcuclassic_trace_buf);
> -	return ret;
> -}
> -
>  static void __exit rcuclassic_trace_cleanup(void)
>  {
> -	debugfs_remove(datadir);
> -	debugfs_remove(cbdir);
> +	debugfs_remove(rcucb_file);
> +	debugfs_remove(rcu_data_file);
> +	debugfs_remove(rcu_bh_data_file);
>  	debugfs_remove(rcudir);
> -	kfree(rcuclassic_trace_buf);
>  }
> 
> -
>  module_init(rcuclassic_trace_init);
>  module_exit(rcuclassic_trace_cleanup);
> +
> +MODULE_AUTHOR("Paul E. McKenney");
> +MODULE_DESCRIPTION("Read-Copy Update tracing for classic implementation");
> +MODULE_LICENSE("GPL");
> 

Re: [PATCH] v3 rudimentary tracing for Classic RCU

[Paul E. McKenney]

On Sun, Oct 26, 2008 at 02:59:30PM -0700, Paul E. McKenney wrote:
> On Thu, Oct 23, 2008 at 07:12:09PM +0800, Lai Jiangshan wrote:
> > 
> > trivial ported it to seq_file.
> > seq_file are very good for the output buffer.
> 
> Thank you for putting this together!!!  Looks good at first glance --
> I will test it out.

So it does seem to operate correctly.  I combined it with my patch and
applied against 2.6.27 for ease of testing.

One question -- why the multi-line format?  This would be a bit
awkward on a 128-CPU system, let alone on a 4,096-CPU system.
Or am I missing some trick here?

> 							Thanx, Paul
> 
> > Signed-off-by: Lai Jiangshan <laijs@cn.fujitsu.com>
> > ---
> > diff --git a/kernel/rcuclassic_trace.c b/kernel/rcuclassic_trace.c
> > index d19780b..f19217c
> > --- a/kernel/rcuclassic_trace.c
> > +++ b/kernel/rcuclassic_trace.c
> > @@ -23,157 +23,167 @@
> >   * 		Documentation/RCU
> >   *
> >   */
> > -#include <linux/types.h>
> > -#include <linux/kernel.h>
> > -#include <linux/init.h>
> > -#include <linux/spinlock.h>
> > -#include <linux/smp.h>
> >  #include <linux/rcupdate.h>
> > -#include <linux/interrupt.h>
> > -#include <linux/sched.h>
> > -#include <asm/atomic.h>
> > -#include <linux/bitops.h>
> >  #include <linux/module.h>
> > -#include <linux/completion.h>
> > -#include <linux/moduleparam.h>
> > -#include <linux/percpu.h>
> > -#include <linux/notifier.h>
> > -#include <linux/cpu.h>
> > -#include <linux/mutex.h>
> >  #include <linux/debugfs.h>
> > +#include <linux/seq_file.h>
> > 
> > -static DEFINE_MUTEX(rcuclassic_trace_mutex);
> > -static char *rcuclassic_trace_buf;
> > -#define RCUCLASSIC_TRACE_BUF_SIZE (128 * num_possible_cpus() + 100)
> > +static struct rcu_data *get_rcu_data_bh(int cpu)
> > +{
> > +	return &per_cpu(rcu_bh_data, cpu);
> > +}
> > 
> > -static int print_one_rcu_data(struct rcu_data *rdp, char *buf, char *ebuf)
> > +static struct rcu_data *get_rcu_data(int cpu)
> >  {
> > -	int cnt = 0;
> > +	return &per_cpu(rcu_data, cpu);
> > +}
> > 
> > +static int show_rcu_data(struct seq_file *m, void *v)
> > +{
> > +	struct rcu_data *rdp = v;
> >  	if (!rdp->beenonline)
> >  		return 0;
> > -	cnt += snprintf(&buf[cnt], ebuf - &buf[cnt],
> > -		"%3d%cqb=%ld b=%ld pq=%d qsp=%d ql=%ld bl=%ld\n",
> > -		rdp->cpu, cpu_is_offline(rdp->cpu) ? '!' : ' ',
> > -		rdp->quiescbatch, rdp->batch, rdp->passed_quiesc,
> > -		rdp->qs_pending, rdp->qlen, rdp->blimit);
> > -	return cnt;
> > +
> > +	seq_printf(m, "processor\t: %d", rdp->cpu);
> > +	if (cpu_is_offline(rdp->cpu))
> > +		seq_puts(m, "!\n");
> > +	else
> > +		seq_puts(m, "\n");
> > +	seq_printf(m, "quiescbatch\t: %ld\n", rdp->quiescbatch);
> > +	seq_printf(m, "batch\t: %ld\n", rdp->batch);
> > +	seq_printf(m, "passed_quiesc\t: %d\n", rdp->passed_quiesc);
> > +	seq_printf(m, "qs_pending\t: %d\n", rdp->qs_pending);
> > +	seq_printf(m, "qlen\t: %ld\n", rdp->qlen);
> > +	seq_printf(m, "blimit\t: %ld\n", rdp->blimit);
> > +	seq_puts(m, "\n\n");
> > +	return 0;
> >  }
> > 
> > -#define PRINT_RCU_DATA(name, buf, ebuf) \
> > -	do { \
> > -		int _p_r_d_i; \
> > -		\
> > -		for_each_possible_cpu(_p_r_d_i) \
> > -			(buf) += print_one_rcu_data(&per_cpu(name, _p_r_d_i), \
> > -						    buf, ebuf); \
> > -	} while (0)
> > -
> > -static ssize_t rcudata_read(struct file *filp, char __user *buffer,
> > -				size_t count, loff_t *ppos)
> > +static void *c_start(struct seq_file *m, loff_t *pos)
> >  {
> > -	ssize_t bcount;
> > -	char *buf = rcuclassic_trace_buf;
> > -	char *ebuf = &rcuclassic_trace_buf[RCUCLASSIC_TRACE_BUF_SIZE];
> > -
> > -	mutex_lock(&rcuclassic_trace_mutex);
> > -	buf += snprintf(buf, ebuf - buf, "rcu:\n");
> > -	PRINT_RCU_DATA(rcu_data, buf, ebuf);
> > -	buf += snprintf(buf, ebuf - buf, "rcu_bh:\n");
> > -	PRINT_RCU_DATA(rcu_bh_data, buf, ebuf);
> > -	bcount = simple_read_from_buffer(buffer, count, ppos,
> > -			rcuclassic_trace_buf, strlen(rcuclassic_trace_buf));
> > -	mutex_unlock(&rcuclassic_trace_mutex);
> > -	return bcount;
> > +	typedef struct rcu_data *(*get_data_func)(int);
> > +
> > +	if (*pos == 0)	/* just in case, cpu 0 is not the first */
> > +		*pos = first_cpu(cpu_possible_map);
> > +	else
> > +		*pos = next_cpu_nr(*pos - 1, cpu_possible_map);
> > +	if ((*pos) < nr_cpu_ids)
> > +		return ((get_data_func)m->private)(*pos);
> > +	return NULL;
> >  }
> > 
> > -static int print_one_rcu_ctrlblk(struct rcu_ctrlblk *rcp, char *buf, char *ebuf)
> > +static void *c_next(struct seq_file *m, void *v, loff_t *pos)
> >  {
> > -	int cnt = 0;
> > -
> > -	cnt += snprintf(&buf[cnt], ebuf - &buf[cnt], "cur=%ld  completed=%ld  "
> > -			"pending=%ld  s=%d\n\t",
> > -			rcp->cur, rcp->completed,
> > -			rcp->pending, rcp->signaled);
> > -	cnt += cpulist_scnprintf(&buf[cnt], ebuf - &buf[cnt], rcp->cpumask);
> > -	cnt += snprintf(&buf[cnt], ebuf - &buf[cnt], "\n");
> > -	return cnt;
> > +	(*pos)++;
> > +	return c_start(m, pos);
> >  }
> > 
> > -static ssize_t rcucb_read(struct file *filp, char __user *buffer,
> > -				size_t count, loff_t *ppos)
> > +static void c_stop(struct seq_file *m, void *v)
> >  {
> > -	ssize_t bcount;
> > -	char *buf = rcuclassic_trace_buf;
> > -	char *ebuf = &rcuclassic_trace_buf[RCUCLASSIC_TRACE_BUF_SIZE];
> > -
> > -	mutex_lock(&rcuclassic_trace_mutex);
> > -	buf += snprintf(buf, ebuf - buf, "rcu: ");
> > -	buf += print_one_rcu_ctrlblk(&rcu_ctrlblk, buf, ebuf);
> > -	buf += snprintf(buf, ebuf - buf, "rcu_bh: ");
> > -	buf += print_one_rcu_ctrlblk(&rcu_bh_ctrlblk, buf, ebuf);
> > -	buf += snprintf(buf, ebuf - buf, "online: ");
> > -	buf += cpulist_scnprintf(buf, ebuf - buf, cpu_online_map);
> > -	buf += snprintf(buf, ebuf - buf, "\n");
> > -	bcount = simple_read_from_buffer(buffer, count, ppos,
> > -			rcuclassic_trace_buf, strlen(rcuclassic_trace_buf));
> > -	mutex_unlock(&rcuclassic_trace_mutex);
> > -	return bcount;
> >  }
> > 
> > -static struct file_operations rcudata_fops = {
> > -	.owner = THIS_MODULE,
> > -	.read = rcudata_read,
> > +const struct seq_operations rcu_data_seq_op = {
> > +	.start	= c_start,
> > +	.next	= c_next,
> > +	.stop	= c_stop,
> > +	.show	= show_rcu_data,
> >  };
> > 
> > +static int rcu_data_open(struct inode *inode, struct file *file)
> > +{
> > +	int ret = seq_open(file, &rcu_data_seq_op);
> > +	if (ret)
> > +		return ret;
> > +	((struct seq_file *)file->private_data)->private = inode->i_private;
> > +	return 0;
> > +}
> > +
> > +static const struct file_operations rcu_data_fops = {
> > +	.owner		= THIS_MODULE,
> > +	.open		= rcu_data_open,
> > +	.read		= seq_read,
> > +	.llseek		= seq_lseek,
> > +	.release	= seq_release,
> > +};
> > +
> > +static void print_one_rcu_ctrlblk(struct seq_file *m, struct rcu_ctrlblk *rcp)
> > +{
> > +	seq_printf(m, "cur=%ld  completed=%ld   pending=%ld  s=%d\n\t",
> > +			rcp->cur, rcp->completed, rcp->pending, rcp->signaled);
> > +	seq_cpumask(m, &rcp->cpumask);
> > +	seq_puts(m, "\n");
> > +}
> > +
> > +static int show_rcucb(struct seq_file *m, void *unused)
> > +{
> > +	seq_puts(m, "rcu: ");
> > +	print_one_rcu_ctrlblk(m, &rcu_ctrlblk);
> > +	seq_puts(m, "rcu_bh: ");
> > +	print_one_rcu_ctrlblk(m, &rcu_bh_ctrlblk);
> > +	seq_puts(m, "online: ");
> > +	seq_cpumask(m, &cpu_online_map);
> > +	seq_puts(m, "\n");
> > +	return 0;
> > +}
> > +
> > +static int rcucb_open(struct inode *inode, struct file *file)
> > +{
> > +	return single_open(file, show_rcucb, NULL);
> > +}
> > +
> >  static struct file_operations rcucb_fops = {
> > -	.owner = THIS_MODULE,
> > -	.read = rcucb_read,
> > +	.owner		= THIS_MODULE,
> > +	.open		= rcucb_open,
> > +	.read		= seq_read,
> > +	.llseek		= seq_lseek,
> > +	.release	= single_release,
> >  };
> > 
> > -static struct dentry *rcudir, *datadir, *cbdir;
> > -static int rcuclassic_debugfs_init(void)
> > +static struct dentry *rcudir, *rcu_bh_data_file, *rcu_data_file, *rcucb_file;
> > +
> > +static int __init rcuclassic_trace_init(void)
> >  {
> >  	rcudir = debugfs_create_dir("rcu", NULL);
> >  	if (!rcudir)
> >  		goto out;
> > -	datadir = debugfs_create_file("rcudata", 0444, rcudir,
> > -				      NULL, &rcudata_fops);
> > -	if (!datadir)
> > -		goto free_out;
> > -	cbdir = debugfs_create_file("rcucb", 0444, rcudir, NULL, &rcucb_fops);
> > -	if (!cbdir)
> > -		goto free_out;
> > +
> > +	rcu_bh_data_file = debugfs_create_file("rcu_bh_data", 0444, rcudir,
> > +			get_rcu_data_bh, &rcu_data_fops);
> > +	if (!rcu_bh_data_file)
> > +		goto out_rcudir;
> > +
> > +	rcu_data_file = debugfs_create_file("rcu_data", 0444, rcudir,
> > +			get_rcu_data, &rcu_data_fops);
> > +	if (!rcu_data_file)
> > +		goto out_rcudata_bh_file;
> > +
> > +	rcucb_file = debugfs_create_file("rcucb", 0444, rcudir,
> > +			NULL, &rcucb_fops);
> > +	if (!rcucb_file)
> > +		goto out_rcudata_file;
> >  	return 0;
> > -free_out:
> > -	if (datadir)
> > -		debugfs_remove(datadir);
> > +
> > +out_rcudata_file:
> > +	debugfs_remove(rcu_data_file);
> > +out_rcudata_bh_file:
> > +	debugfs_remove(rcu_bh_data_file);
> > +out_rcudir:
> >  	debugfs_remove(rcudir);
> >  out:
> >  	return 1;
> >  }
> > 
> > -static int __init rcuclassic_trace_init(void)
> > -{
> > -	int ret;
> > -
> > -	rcuclassic_trace_buf = kmalloc(RCUCLASSIC_TRACE_BUF_SIZE, GFP_KERNEL);
> > -	if (!rcuclassic_trace_buf)
> > -		return 1;
> > -	ret = rcuclassic_debugfs_init();
> > -	if (ret)
> > -		kfree(rcuclassic_trace_buf);
> > -	return ret;
> > -}
> > -
> >  static void __exit rcuclassic_trace_cleanup(void)
> >  {
> > -	debugfs_remove(datadir);
> > -	debugfs_remove(cbdir);
> > +	debugfs_remove(rcucb_file);
> > +	debugfs_remove(rcu_data_file);
> > +	debugfs_remove(rcu_bh_data_file);
> >  	debugfs_remove(rcudir);
> > -	kfree(rcuclassic_trace_buf);
> >  }
> > 
> > -
> >  module_init(rcuclassic_trace_init);
> >  module_exit(rcuclassic_trace_cleanup);
> > +
> > +MODULE_AUTHOR("Paul E. McKenney");
> > +MODULE_DESCRIPTION("Read-Copy Update tracing for classic implementation");
> > +MODULE_LICENSE("GPL");
> > 

Re: [PATCH] v3 rudimentary tracing for Classic RCU

[Paul E. McKenney]

On Mon, Oct 27, 2008 at 02:50:29PM -0700, Paul E. McKenney wrote:
> On Sun, Oct 26, 2008 at 02:59:30PM -0700, Paul E. McKenney wrote:
> > On Thu, Oct 23, 2008 at 07:12:09PM +0800, Lai Jiangshan wrote:
> > > 
> > > trivial ported it to seq_file.
> > > seq_file are very good for the output buffer.
> > 
> > Thank you for putting this together!!!  Looks good at first glance --
> > I will test it out.
> 
> So it does seem to operate correctly.  I combined it with my patch and
> applied against 2.6.27 for ease of testing.
> 
> One question -- why the multi-line format?  This would be a bit
> awkward on a 128-CPU system, let alone on a 4,096-CPU system.
> Or am I missing some trick here?

To clarify, by "missing some trick", I am wondering if there is some
command that works in blocks of lines.  After all, /proc/cpuinfo
produces the same sort of output that your patch does.  ;-)

							Thanx, Paul

> > > Signed-off-by: Lai Jiangshan <laijs@cn.fujitsu.com>
> > > ---
> > > diff --git a/kernel/rcuclassic_trace.c b/kernel/rcuclassic_trace.c
> > > index d19780b..f19217c
> > > --- a/kernel/rcuclassic_trace.c
> > > +++ b/kernel/rcuclassic_trace.c
> > > @@ -23,157 +23,167 @@
> > >   * 		Documentation/RCU
> > >   *
> > >   */
> > > -#include <linux/types.h>
> > > -#include <linux/kernel.h>
> > > -#include <linux/init.h>
> > > -#include <linux/spinlock.h>
> > > -#include <linux/smp.h>
> > >  #include <linux/rcupdate.h>
> > > -#include <linux/interrupt.h>
> > > -#include <linux/sched.h>
> > > -#include <asm/atomic.h>
> > > -#include <linux/bitops.h>
> > >  #include <linux/module.h>
> > > -#include <linux/completion.h>
> > > -#include <linux/moduleparam.h>
> > > -#include <linux/percpu.h>
> > > -#include <linux/notifier.h>
> > > -#include <linux/cpu.h>
> > > -#include <linux/mutex.h>
> > >  #include <linux/debugfs.h>
> > > +#include <linux/seq_file.h>
> > > 
> > > -static DEFINE_MUTEX(rcuclassic_trace_mutex);
> > > -static char *rcuclassic_trace_buf;
> > > -#define RCUCLASSIC_TRACE_BUF_SIZE (128 * num_possible_cpus() + 100)
> > > +static struct rcu_data *get_rcu_data_bh(int cpu)
> > > +{
> > > +	return &per_cpu(rcu_bh_data, cpu);
> > > +}
> > > 
> > > -static int print_one_rcu_data(struct rcu_data *rdp, char *buf, char *ebuf)
> > > +static struct rcu_data *get_rcu_data(int cpu)
> > >  {
> > > -	int cnt = 0;
> > > +	return &per_cpu(rcu_data, cpu);
> > > +}
> > > 
> > > +static int show_rcu_data(struct seq_file *m, void *v)
> > > +{
> > > +	struct rcu_data *rdp = v;
> > >  	if (!rdp->beenonline)
> > >  		return 0;
> > > -	cnt += snprintf(&buf[cnt], ebuf - &buf[cnt],
> > > -		"%3d%cqb=%ld b=%ld pq=%d qsp=%d ql=%ld bl=%ld\n",
> > > -		rdp->cpu, cpu_is_offline(rdp->cpu) ? '!' : ' ',
> > > -		rdp->quiescbatch, rdp->batch, rdp->passed_quiesc,
> > > -		rdp->qs_pending, rdp->qlen, rdp->blimit);
> > > -	return cnt;
> > > +
> > > +	seq_printf(m, "processor\t: %d", rdp->cpu);
> > > +	if (cpu_is_offline(rdp->cpu))
> > > +		seq_puts(m, "!\n");
> > > +	else
> > > +		seq_puts(m, "\n");
> > > +	seq_printf(m, "quiescbatch\t: %ld\n", rdp->quiescbatch);
> > > +	seq_printf(m, "batch\t: %ld\n", rdp->batch);
> > > +	seq_printf(m, "passed_quiesc\t: %d\n", rdp->passed_quiesc);
> > > +	seq_printf(m, "qs_pending\t: %d\n", rdp->qs_pending);
> > > +	seq_printf(m, "qlen\t: %ld\n", rdp->qlen);
> > > +	seq_printf(m, "blimit\t: %ld\n", rdp->blimit);
> > > +	seq_puts(m, "\n\n");
> > > +	return 0;
> > >  }
> > > 
> > > -#define PRINT_RCU_DATA(name, buf, ebuf) \
> > > -	do { \
> > > -		int _p_r_d_i; \
> > > -		\
> > > -		for_each_possible_cpu(_p_r_d_i) \
> > > -			(buf) += print_one_rcu_data(&per_cpu(name, _p_r_d_i), \
> > > -						    buf, ebuf); \
> > > -	} while (0)
> > > -
> > > -static ssize_t rcudata_read(struct file *filp, char __user *buffer,
> > > -				size_t count, loff_t *ppos)
> > > +static void *c_start(struct seq_file *m, loff_t *pos)
> > >  {
> > > -	ssize_t bcount;
> > > -	char *buf = rcuclassic_trace_buf;
> > > -	char *ebuf = &rcuclassic_trace_buf[RCUCLASSIC_TRACE_BUF_SIZE];
> > > -
> > > -	mutex_lock(&rcuclassic_trace_mutex);
> > > -	buf += snprintf(buf, ebuf - buf, "rcu:\n");
> > > -	PRINT_RCU_DATA(rcu_data, buf, ebuf);
> > > -	buf += snprintf(buf, ebuf - buf, "rcu_bh:\n");
> > > -	PRINT_RCU_DATA(rcu_bh_data, buf, ebuf);
> > > -	bcount = simple_read_from_buffer(buffer, count, ppos,
> > > -			rcuclassic_trace_buf, strlen(rcuclassic_trace_buf));
> > > -	mutex_unlock(&rcuclassic_trace_mutex);
> > > -	return bcount;
> > > +	typedef struct rcu_data *(*get_data_func)(int);
> > > +
> > > +	if (*pos == 0)	/* just in case, cpu 0 is not the first */
> > > +		*pos = first_cpu(cpu_possible_map);
> > > +	else
> > > +		*pos = next_cpu_nr(*pos - 1, cpu_possible_map);
> > > +	if ((*pos) < nr_cpu_ids)
> > > +		return ((get_data_func)m->private)(*pos);
> > > +	return NULL;
> > >  }
> > > 
> > > -static int print_one_rcu_ctrlblk(struct rcu_ctrlblk *rcp, char *buf, char *ebuf)
> > > +static void *c_next(struct seq_file *m, void *v, loff_t *pos)
> > >  {
> > > -	int cnt = 0;
> > > -
> > > -	cnt += snprintf(&buf[cnt], ebuf - &buf[cnt], "cur=%ld  completed=%ld  "
> > > -			"pending=%ld  s=%d\n\t",
> > > -			rcp->cur, rcp->completed,
> > > -			rcp->pending, rcp->signaled);
> > > -	cnt += cpulist_scnprintf(&buf[cnt], ebuf - &buf[cnt], rcp->cpumask);
> > > -	cnt += snprintf(&buf[cnt], ebuf - &buf[cnt], "\n");
> > > -	return cnt;
> > > +	(*pos)++;
> > > +	return c_start(m, pos);
> > >  }
> > > 
> > > -static ssize_t rcucb_read(struct file *filp, char __user *buffer,
> > > -				size_t count, loff_t *ppos)
> > > +static void c_stop(struct seq_file *m, void *v)
> > >  {
> > > -	ssize_t bcount;
> > > -	char *buf = rcuclassic_trace_buf;
> > > -	char *ebuf = &rcuclassic_trace_buf[RCUCLASSIC_TRACE_BUF_SIZE];
> > > -
> > > -	mutex_lock(&rcuclassic_trace_mutex);
> > > -	buf += snprintf(buf, ebuf - buf, "rcu: ");
> > > -	buf += print_one_rcu_ctrlblk(&rcu_ctrlblk, buf, ebuf);
> > > -	buf += snprintf(buf, ebuf - buf, "rcu_bh: ");
> > > -	buf += print_one_rcu_ctrlblk(&rcu_bh_ctrlblk, buf, ebuf);
> > > -	buf += snprintf(buf, ebuf - buf, "online: ");
> > > -	buf += cpulist_scnprintf(buf, ebuf - buf, cpu_online_map);
> > > -	buf += snprintf(buf, ebuf - buf, "\n");
> > > -	bcount = simple_read_from_buffer(buffer, count, ppos,
> > > -			rcuclassic_trace_buf, strlen(rcuclassic_trace_buf));
> > > -	mutex_unlock(&rcuclassic_trace_mutex);
> > > -	return bcount;
> > >  }
> > > 
> > > -static struct file_operations rcudata_fops = {
> > > -	.owner = THIS_MODULE,
> > > -	.read = rcudata_read,
> > > +const struct seq_operations rcu_data_seq_op = {
> > > +	.start	= c_start,
> > > +	.next	= c_next,
> > > +	.stop	= c_stop,
> > > +	.show	= show_rcu_data,
> > >  };
> > > 
> > > +static int rcu_data_open(struct inode *inode, struct file *file)
> > > +{
> > > +	int ret = seq_open(file, &rcu_data_seq_op);
> > > +	if (ret)
> > > +		return ret;
> > > +	((struct seq_file *)file->private_data)->private = inode->i_private;
> > > +	return 0;
> > > +}
> > > +
> > > +static const struct file_operations rcu_data_fops = {
> > > +	.owner		= THIS_MODULE,
> > > +	.open		= rcu_data_open,
> > > +	.read		= seq_read,
> > > +	.llseek		= seq_lseek,
> > > +	.release	= seq_release,
> > > +};
> > > +
> > > +static void print_one_rcu_ctrlblk(struct seq_file *m, struct rcu_ctrlblk *rcp)
> > > +{
> > > +	seq_printf(m, "cur=%ld  completed=%ld   pending=%ld  s=%d\n\t",
> > > +			rcp->cur, rcp->completed, rcp->pending, rcp->signaled);
> > > +	seq_cpumask(m, &rcp->cpumask);
> > > +	seq_puts(m, "\n");
> > > +}
> > > +
> > > +static int show_rcucb(struct seq_file *m, void *unused)
> > > +{
> > > +	seq_puts(m, "rcu: ");
> > > +	print_one_rcu_ctrlblk(m, &rcu_ctrlblk);
> > > +	seq_puts(m, "rcu_bh: ");
> > > +	print_one_rcu_ctrlblk(m, &rcu_bh_ctrlblk);
> > > +	seq_puts(m, "online: ");
> > > +	seq_cpumask(m, &cpu_online_map);
> > > +	seq_puts(m, "\n");
> > > +	return 0;
> > > +}
> > > +
> > > +static int rcucb_open(struct inode *inode, struct file *file)
> > > +{
> > > +	return single_open(file, show_rcucb, NULL);
> > > +}
> > > +
> > >  static struct file_operations rcucb_fops = {
> > > -	.owner = THIS_MODULE,
> > > -	.read = rcucb_read,
> > > +	.owner		= THIS_MODULE,
> > > +	.open		= rcucb_open,
> > > +	.read		= seq_read,
> > > +	.llseek		= seq_lseek,
> > > +	.release	= single_release,
> > >  };
> > > 
> > > -static struct dentry *rcudir, *datadir, *cbdir;
> > > -static int rcuclassic_debugfs_init(void)
> > > +static struct dentry *rcudir, *rcu_bh_data_file, *rcu_data_file, *rcucb_file;
> > > +
> > > +static int __init rcuclassic_trace_init(void)
> > >  {
> > >  	rcudir = debugfs_create_dir("rcu", NULL);
> > >  	if (!rcudir)
> > >  		goto out;
> > > -	datadir = debugfs_create_file("rcudata", 0444, rcudir,
> > > -				      NULL, &rcudata_fops);
> > > -	if (!datadir)
> > > -		goto free_out;
> > > -	cbdir = debugfs_create_file("rcucb", 0444, rcudir, NULL, &rcucb_fops);
> > > -	if (!cbdir)
> > > -		goto free_out;
> > > +
> > > +	rcu_bh_data_file = debugfs_create_file("rcu_bh_data", 0444, rcudir,
> > > +			get_rcu_data_bh, &rcu_data_fops);
> > > +	if (!rcu_bh_data_file)
> > > +		goto out_rcudir;
> > > +
> > > +	rcu_data_file = debugfs_create_file("rcu_data", 0444, rcudir,
> > > +			get_rcu_data, &rcu_data_fops);
> > > +	if (!rcu_data_file)
> > > +		goto out_rcudata_bh_file;
> > > +
> > > +	rcucb_file = debugfs_create_file("rcucb", 0444, rcudir,
> > > +			NULL, &rcucb_fops);
> > > +	if (!rcucb_file)
> > > +		goto out_rcudata_file;
> > >  	return 0;
> > > -free_out:
> > > -	if (datadir)
> > > -		debugfs_remove(datadir);
> > > +
> > > +out_rcudata_file:
> > > +	debugfs_remove(rcu_data_file);
> > > +out_rcudata_bh_file:
> > > +	debugfs_remove(rcu_bh_data_file);
> > > +out_rcudir:
> > >  	debugfs_remove(rcudir);
> > >  out:
> > >  	return 1;
> > >  }
> > > 
> > > -static int __init rcuclassic_trace_init(void)
> > > -{
> > > -	int ret;
> > > -
> > > -	rcuclassic_trace_buf = kmalloc(RCUCLASSIC_TRACE_BUF_SIZE, GFP_KERNEL);
> > > -	if (!rcuclassic_trace_buf)
> > > -		return 1;
> > > -	ret = rcuclassic_debugfs_init();
> > > -	if (ret)
> > > -		kfree(rcuclassic_trace_buf);
> > > -	return ret;
> > > -}
> > > -
> > >  static void __exit rcuclassic_trace_cleanup(void)
> > >  {
> > > -	debugfs_remove(datadir);
> > > -	debugfs_remove(cbdir);
> > > +	debugfs_remove(rcucb_file);
> > > +	debugfs_remove(rcu_data_file);
> > > +	debugfs_remove(rcu_bh_data_file);
> > >  	debugfs_remove(rcudir);
> > > -	kfree(rcuclassic_trace_buf);
> > >  }
> > > 
> > > -
> > >  module_init(rcuclassic_trace_init);
> > >  module_exit(rcuclassic_trace_cleanup);
> > > +
> > > +MODULE_AUTHOR("Paul E. McKenney");
> > > +MODULE_DESCRIPTION("Read-Copy Update tracing for classic implementation");
> > > +MODULE_LICENSE("GPL");
> > > 

Re: [PATCH] v3 rudimentary tracing for Classic RCU

[Paul E. McKenney]

On Mon, Oct 27, 2008 at 04:57:48PM -0700, Paul E. McKenney wrote:
> On Mon, Oct 27, 2008 at 02:50:29PM -0700, Paul E. McKenney wrote:
> > On Sun, Oct 26, 2008 at 02:59:30PM -0700, Paul E. McKenney wrote:
> > > On Thu, Oct 23, 2008 at 07:12:09PM +0800, Lai Jiangshan wrote:
> > > > 
> > > > trivial ported it to seq_file.
> > > > seq_file are very good for the output buffer.
> > > 
> > > Thank you for putting this together!!!  Looks good at first glance --
> > > I will test it out.
> > 
> > So it does seem to operate correctly.  I combined it with my patch and
> > applied against 2.6.27 for ease of testing.
> > 
> > One question -- why the multi-line format?  This would be a bit
> > awkward on a 128-CPU system, let alone on a 4,096-CPU system.
> > Or am I missing some trick here?
> 
> To clarify, by "missing some trick", I am wondering if there is some
> command that works in blocks of lines.  After all, /proc/cpuinfo
> produces the same sort of output that your patch does.  ;-)

Ported to 2.6.27 to ease testing, and fixed up the formatting a bit.
I remember quickly scanning through one-line-per-CPU data to find
problems with rcutree.c, but the expanded names are quite nice -- I
had to brutally abbreviate to fit each CPU on a single line.
And I agree that seqfile does work nicely for this.

I am strongly tempted to suggest CSV format output with headers to
allow the data to be pulled into gnumeric or oocalc -- this would
make handling large numbers of CPUs much easier.  (Quickly donning
the asbestos suit with titanium pinstripes...)

							Thanx, Paul


Signed-off-by: Paul E. McKenney <paulmck@linux.vnet.ibm.com>
Signed-off-by: Lai Jiangshan <laijs@cn.fujitsu.com>
---

 include/linux/rcuclassic.h |    4 
 kernel/Kconfig.preempt     |    1 
 kernel/Makefile            |    2 
 kernel/rcuclassic.c        |    5 -
 kernel/rcuclassic_trace.c  |  198 +++++++++++++++++++++++++++++++++++++++++++++
 5 files changed, 207 insertions(+), 3 deletions(-)

diff --git a/include/linux/rcuclassic.h b/include/linux/rcuclassic.h
index 4ab8436..735f35a 100644
--- a/include/linux/rcuclassic.h
+++ b/include/linux/rcuclassic.h
@@ -54,6 +54,9 @@ struct rcu_ctrlblk {
 				 /* for current batch to proceed.        */
 } ____cacheline_internodealigned_in_smp;
 
+extern struct rcu_ctrlblk rcu_ctrlblk;
+extern struct rcu_ctrlblk rcu_bh_ctrlblk;
+
 /* Is batch a before batch b ? */
 static inline int rcu_batch_before(long a, long b)
 {
@@ -76,6 +79,7 @@ struct rcu_data {
 	long		quiescbatch;     /* Batch # for grace period */
 	int		passed_quiesc;	 /* User-mode/idle loop etc. */
 	int		qs_pending;	 /* core waits for quiesc state */
+	bool		beenonline;	 /* CPU online at least once */
 
 	/* 2) batch handling */
 	long  	       	batch;           /* Batch # for current RCU batch */
diff --git a/kernel/Kconfig.preempt b/kernel/Kconfig.preempt
index 9fdba03..ba32338 100644
--- a/kernel/Kconfig.preempt
+++ b/kernel/Kconfig.preempt
@@ -68,7 +68,6 @@ config PREEMPT_RCU
 
 config RCU_TRACE
 	bool "Enable tracing for RCU - currently stats in debugfs"
-	depends on PREEMPT_RCU
 	select DEBUG_FS
 	default y
 	help
diff --git a/kernel/Makefile b/kernel/Makefile
index 4e1d7df..e0bfce7 100644
--- a/kernel/Makefile
+++ b/kernel/Makefile
@@ -77,6 +77,8 @@ obj-$(CONFIG_CLASSIC_RCU) += rcuclassic.o
 obj-$(CONFIG_PREEMPT_RCU) += rcupreempt.o
 ifeq ($(CONFIG_PREEMPT_RCU),y)
 obj-$(CONFIG_RCU_TRACE) += rcupreempt_trace.o
+else
+obj-$(CONFIG_RCU_TRACE) += rcuclassic_trace.o
 endif
 obj-$(CONFIG_RELAY) += relay.o
 obj-$(CONFIG_SYSCTL) += utsname_sysctl.o
diff --git a/kernel/rcuclassic.c b/kernel/rcuclassic.c
index aad93cd..06472fc 100644
--- a/kernel/rcuclassic.c
+++ b/kernel/rcuclassic.c
@@ -57,13 +57,13 @@ EXPORT_SYMBOL_GPL(rcu_lock_map);
 
 
 /* Definition for rcupdate control block. */
-static struct rcu_ctrlblk rcu_ctrlblk = {
+struct rcu_ctrlblk rcu_ctrlblk = {
 	.cur = -300,
 	.completed = -300,
 	.lock = __SPIN_LOCK_UNLOCKED(&rcu_ctrlblk.lock),
 	.cpumask = CPU_MASK_NONE,
 };
-static struct rcu_ctrlblk rcu_bh_ctrlblk = {
+struct rcu_ctrlblk rcu_bh_ctrlblk = {
 	.cur = -300,
 	.completed = -300,
 	.lock = __SPIN_LOCK_UNLOCKED(&rcu_bh_ctrlblk.lock),
@@ -564,6 +564,7 @@ static void rcu_init_percpu_data(int cpu, struct rcu_ctrlblk *rcp,
 	rdp->donetail = &rdp->donelist;
 	rdp->quiescbatch = rcp->completed;
 	rdp->qs_pending = 0;
+	rdp->beenonline = 1;
 	rdp->cpu = cpu;
 	rdp->blimit = blimit;
 }
diff --git a/kernel/rcuclassic_trace.c b/kernel/rcuclassic_trace.c
new file mode 100644
index 0000000..b719048
--- /dev/null
+++ b/kernel/rcuclassic_trace.c
@@ -0,0 +1,198 @@
+/*
+ * Read-Copy Update tracing for classic implementation
+ *
+ * This program is free software; you can redistribute it and/or modify
+ * it under the terms of the GNU General Public License as published by
+ * the Free Software Foundation; either version 2 of the License, or
+ * (at your option) any later version.
+ *
+ * This program is distributed in the hope that it will be useful,
+ * but WITHOUT ANY WARRANTY; without even the implied warranty of
+ * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
+ * GNU General Public License for more details.
+ *
+ * You should have received a copy of the GNU General Public License
+ * along with this program; if not, write to the Free Software
+ * Foundation, Inc., 59 Temple Place - Suite 330, Boston, MA 02111-1307, USA.
+ *
+ * Copyright IBM Corporation, 2008
+ *
+ * Updated to use seqfile by Lai Jiangshan.
+ *
+ * Papers:  http://www.rdrop.com/users/paulmck/RCU
+ *
+ * For detailed explanation of Read-Copy Update mechanism see -
+ * 		Documentation/RCU
+ *
+ */
+#include <linux/rcupdate.h>
+#include <linux/module.h>
+#include <linux/debugfs.h>
+#include <linux/seq_file.h>
+
+/* Print out rcu_data structures using seqfile facility. */
+
+static struct rcu_data *get_rcu_data_bh(int cpu)
+{
+	return &per_cpu(rcu_bh_data, cpu);
+}
+
+static struct rcu_data *get_rcu_data(int cpu)
+{
+	return &per_cpu(rcu_data, cpu);
+}
+
+static int show_rcu_data(struct seq_file *m, void *v)
+{
+	struct rcu_data *rdp = v;
+
+	if (!rdp->beenonline)
+		return 0;
+
+	seq_printf(m, "processor\t: %d", rdp->cpu);
+	if (cpu_is_offline(rdp->cpu))
+		seq_puts(m, "!\n");
+	else
+		seq_puts(m, "\n");
+	seq_printf(m, "quiescbatch\t: %ld\n", rdp->quiescbatch);
+	seq_printf(m, "batch\t\t: %ld\n", rdp->batch);
+	seq_printf(m, "passed_quiesc\t: %d\n", rdp->passed_quiesc);
+	seq_printf(m, "qs_pending\t: %d\n", rdp->qs_pending);
+	seq_printf(m, "qlen\t\t: %ld\n", rdp->qlen);
+	seq_printf(m, "blimit\t\t: %ld\n", rdp->blimit);
+	seq_puts(m, "\n");
+	return 0;
+}
+
+static void *c_start(struct seq_file *m, loff_t *pos)
+{
+	typedef struct rcu_data *(*get_data_func)(int);
+
+	if (*pos == 0)  /* just in case, cpu 0 is not the first */
+		*pos = first_cpu(cpu_possible_map);
+	else
+		*pos = next_cpu_nr(*pos - 1, cpu_possible_map);
+	if ((*pos) < nr_cpu_ids)
+		return ((get_data_func)m->private)(*pos);
+	return NULL;
+}
+
+static void *c_next(struct seq_file *m, void *v, loff_t *pos)
+{
+	(*pos)++;
+	return c_start(m, pos);
+}
+
+static void c_stop(struct seq_file *m, void *v)
+{
+}
+
+const struct seq_operations rcu_data_seq_op = {
+	.start	= c_start,
+	.next	= c_next,
+	.stop	= c_stop,
+	.show	= show_rcu_data,
+};
+
+static int rcu_data_open(struct inode *inode, struct file *file)
+{
+	int ret = seq_open(file, &rcu_data_seq_op);
+
+	if (ret)
+		return ret;
+	((struct seq_file *)file->private_data)->private = inode->i_private;
+	return 0;
+}
+
+static const struct file_operations rcu_data_fops = {
+	.owner		= THIS_MODULE,
+	.open		= rcu_data_open,
+	.read		= seq_read,
+	.llseek		= seq_lseek,
+	.release	= seq_release,
+};
+
+/* Print out rcu_ctrlblk structures using seqfile facility. */
+
+static void print_one_rcu_ctrlblk(struct seq_file *m, struct rcu_ctrlblk *rcp)
+{
+	seq_printf(m, "cur=%ld  completed=%ld   next_pending=%d  s=%d\n\t",
+		   rcp->cur, rcp->completed, rcp->next_pending, rcp->signaled);
+	seq_cpumask(m, &rcp->cpumask);
+	seq_puts(m, "\n");
+}
+
+static int show_rcucb(struct seq_file *m, void *unused)
+{
+	seq_puts(m, "rcu: ");
+	print_one_rcu_ctrlblk(m, &rcu_ctrlblk);
+	seq_puts(m, "rcu_bh: ");
+	print_one_rcu_ctrlblk(m, &rcu_bh_ctrlblk);
+	seq_puts(m, "online: ");
+	seq_cpumask(m, &cpu_online_map);
+	seq_puts(m, "\n");
+	return 0;
+}
+
+static int rcucb_open(struct inode *inode, struct file *file)
+{
+	return single_open(file, show_rcucb, NULL);
+}
+
+static struct file_operations rcucb_fops = {
+	.owner		= THIS_MODULE,
+	.open		= rcucb_open,
+	.read		= seq_read,
+	.llseek		= seq_lseek,
+	.release	= single_release,
+};
+
+static struct dentry *rcudir, *rcu_bh_data_file, *rcu_data_file, *rcucb_file;
+
+static int __init rcuclassic_trace_init(void)
+{
+	rcudir = debugfs_create_dir("rcu", NULL);
+	if (!rcudir)
+		goto out;
+
+	rcu_bh_data_file = debugfs_create_file("rcu_bh_data", 0444, rcudir,
+					       get_rcu_data_bh, &rcu_data_fops);
+	if (!rcu_bh_data_file)
+		goto out_rcudir;
+
+	rcu_data_file = debugfs_create_file("rcu_data", 0444, rcudir,
+					    get_rcu_data, &rcu_data_fops);
+	if (!rcu_data_file)
+		goto out_rcudata_bh_file;
+
+	rcucb_file = debugfs_create_file("rcucb", 0444, rcudir,
+					 NULL, &rcucb_fops);
+	if (!rcucb_file)
+		goto out_rcudata_file;
+	return 0;
+
+out_rcudata_file:
+	debugfs_remove(rcu_data_file);
+out_rcudata_bh_file:
+	debugfs_remove(rcu_bh_data_file);
+out_rcudir:
+	debugfs_remove(rcudir);
+out:
+	return 1;
+}
+
+static void __exit rcuclassic_trace_cleanup(void)
+{
+	debugfs_remove(rcucb_file);
+	debugfs_remove(rcu_data_file);
+	debugfs_remove(rcu_bh_data_file);
+	debugfs_remove(rcudir);
+}
+
+module_init(rcuclassic_trace_init);
+module_exit(rcuclassic_trace_cleanup);
+
+MODULE_AUTHOR("Paul E. McKenney");
+MODULE_DESCRIPTION("Read-Copy Update tracing for classic implementation");
+MODULE_LICENSE("GPL");
+

Re: [PATCH] v3 rudimentary tracing for Classic RCU

[Lai Jiangshan]

Paul E. McKenney wrote:

> Ported to 2.6.27 to ease testing, and fixed up the formatting a bit.
> I remember quickly scanning through one-line-per-CPU data to find
> problems with rcutree.c, but the expanded names are quite nice -- I
> had to brutally abbreviate to fit each CPU on a single line.
> And I agree that seqfile does work nicely for this.
> 
> I am strongly tempted to suggest CSV format output with headers to
> allow the data to be pulled into gnumeric or oocalc -- this would
> make handling large numbers of CPUs much easier.  (Quickly donning
> the asbestos suit with titanium pinstripes...)
> 
> 							Thanx, Paul
> 
> 

Hi, Paul,
	My patch is like an example, you do not need keep the
codes that I have wrote. you can rewrite all of it. these files
are only accessed by RCU guys, not users. and some file in /proc
is very simple but easy to be read: /proc/stat, /proc/loadavg.

			Thanx, Lai.

Re: [PATCH] v3 rudimentary tracing for Classic RCU

[Paul E. McKenney]

On Wed, Oct 29, 2008 at 09:31:39AM +0800, Lai Jiangshan wrote:
> Paul E. McKenney wrote:
> 
> > Ported to 2.6.27 to ease testing, and fixed up the formatting a bit.
> > I remember quickly scanning through one-line-per-CPU data to find
> > problems with rcutree.c, but the expanded names are quite nice -- I
> > had to brutally abbreviate to fit each CPU on a single line.
> > And I agree that seqfile does work nicely for this.
> > 
> > I am strongly tempted to suggest CSV format output with headers to
> > allow the data to be pulled into gnumeric or oocalc -- this would
> > make handling large numbers of CPUs much easier.  (Quickly donning
> > the asbestos suit with titanium pinstripes...)
> 
> Hi, Paul,
> 	My patch is like an example, you do not need keep the
> codes that I have wrote. you can rewrite all of it. these files
> are only accessed by RCU guys, not users. and some file in /proc
> is very simple but easy to be read: /proc/stat, /proc/loadavg.

Hello, Jiangshan,

Good point -- I do very much appreciate the seqfile tutorial!!!

						Thanx, Paul

Re: RCU hang on cpu re-hotplug with 2.6.27rc8

[Paul E. McKenney]

On Tue, Oct 07, 2008 at 02:22:15PM -0700, Paul E. McKenney wrote:
> On Tue, Oct 07, 2008 at 11:09:47PM +0200, Andi Kleen wrote:
> > On Tue, Oct 07, 2008 at 09:34:01AM -0700, Paul E. McKenney wrote:
> > > Thank you!  Hmmm, classic RCU, worked just fine in 2.6.27-rc7 with
> > > Thomas's patch.  I was doing random onlines and offlines in a loop,
> > > with about 3 seconds between each operation continuously for more than
> > > ten hours, both x86 and Power.  So could you please try 2.6.27-rc7 with
> > > Thomas's patch as follows?
> > > 
> > > http://www.rdrop.com/users/paulmck/patches/2.6.27-rc7-tglx-timer-1.patch
> > 
> > Same effect. Hung on the first try
> > 
> > bash          D 00000000ffff25c1     0  4755   4742
> >  ffff88027b127bf8 0000000000000086 ffff88027b127c18 0000000000000296
> >  ffff88027c80b330 ffff8804be488b90 ffff88027c80b578 0000000300000296
> >  ffff88027b127c18 ffffffff808cbd18 ffff88002805d600 ffff88027d182098
> > Call Trace:
> >  [<ffffffff805c318d>] schedule_timeout+0x22/0xb4
> >  [<ffffffff8020a029>] ? __switch_to+0x320/0x330
> >  [<ffffffff8025fa65>] ? cpupri_set+0xc5/0xd8
> >  [<ffffffff805c2fe7>] wait_for_common+0xcd/0x131
> >  [<ffffffff8022d297>] ? default_wake_function+0x0/0xf
> >  [<ffffffff805c30d5>] wait_for_completion+0x18/0x1a
> >  [<ffffffff8024374b>] synchronize_rcu+0x35/0x3c
> >  [<ffffffff802437ca>] ? wakeme_after_rcu+0x0/0x12
> >  [<ffffffff8022e435>] partition_sched_domains+0x9b/0x1dd
> >  [<ffffffff8022d2c3>] ? wake_up_process+0x10/0x12
> >  [<ffffffff8022e5a5>] update_sched_domains+0x2e/0x35
> >  [<ffffffff805c6bb2>] notifier_call_chain+0x33/0x5b
> >  [<ffffffff80248a29>] __raw_notifier_call_chain+0x9/0xb
> >  [<ffffffff80248a3a>] raw_notifier_call_chain+0xf/0x11
> >  [<ffffffff805c06e6>] _cpu_up+0xd3/0x10c
> >  [<ffffffff805c0776>] cpu_up+0x57/0x67
> >  [<ffffffff805a4ab7>] store_online+0x4d/0x75
> >  [<ffffffff803e5d0b>] sysdev_store+0x1b/0x1d
> >  [<ffffffff802cc49c>] sysfs_write_file+0xe0/0x11c
> >  [<ffffffff8028ad1d>] vfs_write+0xae/0x137
> >  [<ffffffff8028b1c6>] sys_write+0x47/0x6f
> >  [<ffffffff8020b36b>] system_call_fastpath+0x16/0x1b
> 
> Thus far, as usual, I cannot reproduce, either on x86 or Power.  You are
> running on hyperthreaded machines?  If so, what happens if you disable
> CONFIG_SCHED_SMT and CONFIG_SCHED_MC?
> 
> You are running on a 16-CPU x86-64 box?

The attached patch (similar to one in -tip, but set up for mainline and
tweaked to make stall-checking on by default) should get you a stack
trace of any CPUs holding up RCU grace periods for more than about
three seconds.

On the off-chance that this helps.

							Thanx, Paul

Signed-off-by: Paul E. McKenney <paulmck@linux.vnet.ibm.com>
---

diff --git a/include/linux/rcuclassic.h b/include/linux/rcuclassic.h
index 4ab8436..cab055b 100644
--- a/include/linux/rcuclassic.h
+++ b/include/linux/rcuclassic.h
@@ -40,6 +40,10 @@
 #include <linux/cpumask.h>
 #include <linux/seqlock.h>
 
+#ifdef CONFIG_RCU_CPU_STALL_DETECTOR
+#define RCU_SECONDS_TILL_STALL_CHECK	3 * HZ	/* for rcp->jiffies_stall */
+#define RCU_SECONDS_TILL_STALL_RECHECK	30 * HZ	/* for rcp->jiffies_stall */
+#endif /* #ifdef CONFIG_RCU_CPU_STALL_DETECTOR */
 
 /* Global control variables for rcupdate callback mechanism. */
 struct rcu_ctrlblk {
@@ -52,6 +56,11 @@ struct rcu_ctrlblk {
 	spinlock_t	lock	____cacheline_internodealigned_in_smp;
 	cpumask_t	cpumask; /* CPUs that need to switch in order    */
 				 /* for current batch to proceed.        */
+#ifdef CONFIG_RCU_CPU_STALL_DETECTOR
+	unsigned long gp_start;	 /* Time at which GP started in jiffies. */
+	unsigned long jiffies_stall;
+				 /* Time at which to check for CPU stalls. */
+#endif /* #ifdef CONFIG_RCU_CPU_STALL_DETECTOR */
 } ____cacheline_internodealigned_in_smp;
 
 /* Is batch a before batch b ? */
diff --git a/kernel/rcuclassic.c b/kernel/rcuclassic.c
index aad93cd..a299876 100644
--- a/kernel/rcuclassic.c
+++ b/kernel/rcuclassic.c
@@ -118,6 +118,87 @@ static inline void force_quiescent_state(struct rcu_data *rdp,
 }
 #endif
 
+#ifdef CONFIG_RCU_CPU_STALL_DETECTOR
+
+static void record_gp_stall_check_time(struct rcu_ctrlblk *rcp)
+{
+	rcp->gp_start = jiffies;
+	rcp->jiffies_stall = jiffies + RCU_SECONDS_TILL_STALL_CHECK;
+}
+
+static void print_other_cpu_stall(struct rcu_ctrlblk *rcp)
+{
+	int cpu;
+	long delta;
+	unsigned long flags;
+
+	/* Only let one CPU complain about others per time interval. */
+
+	spin_lock_irqsave(&rcp->lock, flags);
+	delta = jiffies - rcp->jiffies_stall;
+	if (delta < 2 || rcp->cur != rcp->completed) {
+		spin_unlock_irqrestore(&rcp->lock, flags);
+		return;
+	}
+	rcp->jiffies_stall = jiffies + RCU_SECONDS_TILL_STALL_RECHECK;
+	spin_unlock_irqrestore(&rcp->lock, flags);
+
+	/* OK, time to rat on our buddy... */
+
+	printk(KERN_ERR "RCU detected CPU stalls:");
+	for_each_possible_cpu(cpu) {
+		if (cpu_isset(cpu, rcp->cpumask))
+			printk(" %d", cpu);
+	}
+	printk(" (detected by %d, t=%ld jiffies)\n",
+	       smp_processor_id(), (long)(jiffies - rcp->gp_start));
+}
+
+static void print_cpu_stall(struct rcu_ctrlblk *rcp)
+{
+	unsigned long flags;
+
+	printk(KERN_ERR "RCU detected CPU %d stall (t=%lu/%lu jiffies)\n",
+			smp_processor_id(), jiffies,
+			jiffies - rcp->gp_start);
+	dump_stack();
+	spin_lock_irqsave(&rcp->lock, flags);
+	if ((long)(jiffies - rcp->jiffies_stall) >= 0)
+		rcp->jiffies_stall =
+			jiffies + RCU_SECONDS_TILL_STALL_RECHECK;
+	spin_unlock_irqrestore(&rcp->lock, flags);
+	set_need_resched();  /* kick ourselves to get things going. */
+}
+
+static void check_cpu_stall(struct rcu_ctrlblk *rcp)
+{
+	long delta;
+
+	delta = jiffies - rcp->jiffies_stall;
+	if (cpu_isset(smp_processor_id(), rcp->cpumask) && delta >= 0) {
+		
+		/* We haven't checked in, so go dump stack. */
+		print_cpu_stall(rcp);
+
+	} else if (rcp->cur != rcp->completed && delta >= 2) {
+
+		/* They had two seconds to dump stack, so complain. */
+		print_other_cpu_stall(rcp);
+	}
+}
+
+#else /* #ifdef CONFIG_RCU_CPU_STALL_DETECTOR */
+
+static void record_gp_stall_check_time(struct rcu_ctrlblk *rcp)
+{
+}
+
+static void check_cpu_stall(struct rcu_ctrlblk *rcp, struct rcu_data *rdp)
+{
+}
+
+#endif /* #else #ifdef CONFIG_RCU_CPU_STALL_DETECTOR */
+
 /**
  * call_rcu - Queue an RCU callback for invocation after a grace period.
  * @head: structure to be used for queueing the RCU updates.
@@ -285,6 +366,7 @@ static void rcu_start_batch(struct rcu_ctrlblk *rcp)
 		 */
 		smp_wmb();
 		rcp->cur++;
+		record_gp_stall_check_time(rcp);
 
 		/*
 		 * Accessing nohz_cpu_mask before incrementing rcp->cur needs a
@@ -468,6 +550,9 @@ static void rcu_process_callbacks(struct softirq_action *unused)
 
 static int __rcu_pending(struct rcu_ctrlblk *rcp, struct rcu_data *rdp)
 {
+	/* Check for CPU stalls, if enabled. */
+	check_cpu_stall(rcp);
+
 	/* This cpu has pending rcu entries and the grace period
 	 * for them has completed.
 	 */
@@ -558,6 +643,9 @@ void rcu_check_callbacks(int cpu, int user)
 static void rcu_init_percpu_data(int cpu, struct rcu_ctrlblk *rcp,
 						struct rcu_data *rdp)
 {
+#ifdef CONFIG_DEBUG_RCU_STALL
+	printk(KERN_INFO "RCU-based detection of stalled CPUs is enabled.\n");
+#endif /* #ifdef CONFIG_DEBUG_RCU_STALL */
 	memset(rdp, 0, sizeof(*rdp));
 	rdp->curtail = &rdp->curlist;
 	rdp->nxttail = &rdp->nxtlist;
diff --git a/lib/Kconfig.debug b/lib/Kconfig.debug
index 0b50481..9fee969 100644
--- a/lib/Kconfig.debug
+++ b/lib/Kconfig.debug
@@ -597,6 +597,19 @@ config RCU_TORTURE_TEST_RUNNABLE
 	  Say N here if you want the RCU torture tests to start only
 	  after being manually enabled via /proc.
 
+config RCU_CPU_STALL_DETECTOR
+	bool "Check for stalled CPUs delaying RCU grace periods"
+	depends on CLASSIC_RCU
+	default y
+	help
+	  This option causes RCU to printk information on which
+	  CPUs are delaying the current grace period, but only when
+	  the grace period extends for excessive time periods.
+
+	  Say Y if you want RCU to perform such checks.
+
+	  Say N if you are unsure.
+
 config KPROBES_SANITY_TEST
 	bool "Kprobes sanity tests"
 	depends on DEBUG_KERNEL

Re: RCU hang on cpu re-hotplug with 2.6.27rc8

[Andi Kleen]

[fix up Thomas' address to not bounce]

On Wed, Oct 08, 2008 at 06:33:21PM -0700, Paul E. McKenney wrote:
> The attached patch (similar to one in -tip, but set up for mainline and
> tweaked to make stall-checking on by default) should get you a stack
> trace of any CPUs holding up RCU grace periods for more than about
> three seconds.
> 
> On the off-chance that this helps.

It actually does. The stall detector makes the online echo return after three seconds,
although it's not 100% clear to me why.

here's the backtrace

RCU detected CPU 14 stall (t=4295149800/5928 jiffies)
Pid: 0, comm: swapper Not tainted 2.6.27-rc9 #5

Call Trace:
 <IRQ>  [<ffffffff8025d188>] __rcu_pending+0x6e/0x1d9
 [<ffffffff8025d329>] rcu_pending+0x36/0x6e
 [<ffffffff8023b480>] update_process_times+0x37/0x5b
 [<ffffffff8024be72>] tick_periodic+0x68/0x74
 [<ffffffff8024be9f>] tick_handle_periodic+0x21/0x66
 [<ffffffff8021bcd2>] smp_apic_timer_interrupt+0x8a/0xa8
 [<ffffffff8020bfe6>] apic_timer_interrupt+0x66/0x70
 <EOI>  [<ffffffff803adb39>] ? acpi_safe_halt+0x2b/0x3e
 [<ffffffff803adbfa>] ? acpi_idle_enter_c1+0xae/0x102
 [<ffffffff804ffdd6>] ? cpuidle_idle_call+0x70/0xa2
 [<ffffffff8020a097>] ? cpu_idle+0x7e/0x9c
 [<ffffffff805bef4a>] ? start_secondary+0x157/0x15c

Timer issue?


-Andi

Re: RCU hang on cpu re-hotplug with 2.6.27rc8

[Thomas Gleixner]

On Thu, 9 Oct 2008, Andi Kleen wrote:
> It actually does. The stall detector makes the online echo return after three seconds,
> although it's not 100% clear to me why.
> 
> here's the backtrace
> 
> RCU detected CPU 14 stall (t=4295149800/5928 jiffies)
> Pid: 0, comm: swapper Not tainted 2.6.27-rc9 #5
> 
> Call Trace:
>  <IRQ>  [<ffffffff8025d188>] __rcu_pending+0x6e/0x1d9
>  [<ffffffff8025d329>] rcu_pending+0x36/0x6e
>  [<ffffffff8023b480>] update_process_times+0x37/0x5b
>  [<ffffffff8024be72>] tick_periodic+0x68/0x74
>  [<ffffffff8024be9f>] tick_handle_periodic+0x21/0x66
>  [<ffffffff8021bcd2>] smp_apic_timer_interrupt+0x8a/0xa8
>  [<ffffffff8020bfe6>] apic_timer_interrupt+0x66/0x70
>  <EOI>  [<ffffffff803adb39>] ? acpi_safe_halt+0x2b/0x3e
>  [<ffffffff803adbfa>] ? acpi_idle_enter_c1+0xae/0x102
>  [<ffffffff804ffdd6>] ? cpuidle_idle_call+0x70/0xa2
>  [<ffffffff8020a097>] ? cpu_idle+0x7e/0x9c
>  [<ffffffff805bef4a>] ? start_secondary+0x157/0x15c
> 
> Timer issue?

Hmm, this is periodic mode so rather unlikely, but who knows. Does
this happen with nohz and/or highres as well ?

Thanks,

	tglx

Re: RCU hang on cpu re-hotplug with 2.6.27rc8

[Andi Kleen]

On Thu, Oct 09, 2008 at 09:24:51AM +0200, Thomas Gleixner wrote:
> On Thu, 9 Oct 2008, Andi Kleen wrote:
> > It actually does. The stall detector makes the online echo return after three seconds,
> > although it's not 100% clear to me why.
> > 
> > here's the backtrace
> > 
> > RCU detected CPU 14 stall (t=4295149800/5928 jiffies)
> > Pid: 0, comm: swapper Not tainted 2.6.27-rc9 #5
> > 
> > Call Trace:
> >  <IRQ>  [<ffffffff8025d188>] __rcu_pending+0x6e/0x1d9
> >  [<ffffffff8025d329>] rcu_pending+0x36/0x6e
> >  [<ffffffff8023b480>] update_process_times+0x37/0x5b
> >  [<ffffffff8024be72>] tick_periodic+0x68/0x74
> >  [<ffffffff8024be9f>] tick_handle_periodic+0x21/0x66
> >  [<ffffffff8021bcd2>] smp_apic_timer_interrupt+0x8a/0xa8
> >  [<ffffffff8020bfe6>] apic_timer_interrupt+0x66/0x70
> >  <EOI>  [<ffffffff803adb39>] ? acpi_safe_halt+0x2b/0x3e
> >  [<ffffffff803adbfa>] ? acpi_idle_enter_c1+0xae/0x102
> >  [<ffffffff804ffdd6>] ? cpuidle_idle_call+0x70/0xa2
> >  [<ffffffff8020a097>] ? cpu_idle+0x7e/0x9c
> >  [<ffffffff805bef4a>] ? start_secondary+0x157/0x15c
> > 
> > Timer issue?
> 
> Hmm, this is periodic mode so rather unlikely, but who knows. Does
> this happen with nohz and/or highres as well ?

With nohz/highres enabled it takes much longer to trigger. Normally
it happened near always on the first try, now I had to let a loop
run for several minutes to trigger it.

But the strange thing is that the stall detector doesn't detect
the hotplugged CPUs stalling now, but other unrelated ones.
I only hotplug 14/15, but it reports 3 and 4. In periodic 
mode the correct CPUs were reported.

-Andi

Here are the backtraces


Switched to high resolution mode on CPU 14
CPU 15 is now offline
RCU detected CPU 3 stall (t=4294999688/3809 jiffies)
Pid: 0, comm: swapper Not tainted 2.6.27-rc9 #6

Call Trace:
 <IRQ>  [<ffffffff8025f474>] __rcu_pending+0x6e/0x1d9
 [<ffffffff8025f615>] rcu_pending+0x36/0x6e
 [<ffffffff8023bc5d>] update_process_times+0x37/0x5b
 [<ffffffff8024de88>] tick_sched_timer+0x81/0xb5
 [<ffffffff80247538>] __run_hrtimer+0x56/0x96
 [<ffffffff80248002>] hrtimer_interrupt+0xe6/0x14d
 [<ffffffff8021bcd2>] smp_apic_timer_interrupt+0x8a/0xa8
 [<ffffffff8020bff6>] apic_timer_interrupt+0x66/0x70
 <EOI>  [<ffffffff803b0254>] ? acpi_idle_enter_bm+0x2a2/0x312
 [<ffffffff803b024a>] ? acpi_idle_enter_bm+0x298/0x312
 [<ffffffff805020c2>] ? cpuidle_idle_call+0x70/0xa2
 [<ffffffff8020a0a1>] ? cpu_idle+0x88/0xae
 [<ffffffff805c137a>] ? start_secondary+0x157/0x15c

RCU detected CPU 3 stall (t=4295007688/1250 jiffies)
Pid: 0, comm: swapper Not tainted 2.6.27-rc9 #6

Call Trace:
 <IRQ>  [<ffffffff8025f474>] __rcu_pending+0x6e/0x1d9
 [<ffffffff8025f615>] rcu_pending+0x36/0x6e
 [<ffffffff8023bc5d>] update_process_times+0x37/0x5b
 [<ffffffff8024de88>] tick_sched_timer+0x81/0xb5
 [<ffffffff80247538>] __run_hrtimer+0x56/0x96
 [<ffffffff80248002>] hrtimer_interrupt+0xe6/0x14d
 [<ffffffff8021bcd2>] smp_apic_timer_interrupt+0x8a/0xa8
 [<ffffffff8020bff6>] apic_timer_interrupt+0x66/0x70
 <EOI>  [<ffffffff803b0254>] ? acpi_idle_enter_bm+0x2a2/0x312
 [<ffffffff803b024a>] ? acpi_idle_enter_bm+0x298/0x312
 [<ffffffff805020c2>] ? cpuidle_idle_call+0x70/0xa2
 [<ffffffff8020a0a1>] ? cpu_idle+0x88/0xae
 [<ffffffff805c137a>] ? start_secondary+0x157/0x15c

RCU detected CPU 3 stall (t=4295012121/2548 jiffies)
Pid: 0, comm: swapper Not tainted 2.6.27-rc9 #6

Call Trace:
 <IRQ>  [<ffffffff8025f474>] __rcu_pending+0x6e/0x1d9
 [<ffffffff8025f640>] rcu_pending+0x61/0x6e
 [<ffffffff8023bc5d>] update_process_times+0x37/0x5b
 [<ffffffff8024de88>] tick_sched_timer+0x81/0xb5
 [<ffffffff80247538>] __run_hrtimer+0x56/0x96
 [<ffffffff80248002>] hrtimer_interrupt+0xe6/0x14d
 [<ffffffff8021bcd2>] smp_apic_timer_interrupt+0x8a/0xa8
 [<ffffffff8020bff6>] apic_timer_interrupt+0x66/0x70
 <EOI>  [<ffffffff803b0254>] ? acpi_idle_enter_bm+0x2a2/0x312
 [<ffffffff803b024a>] ? acpi_idle_enter_bm+0x298/0x312
 [<ffffffff805020c2>] ? cpuidle_idle_call+0x70/0xa2
 [<ffffffff8020a0a1>] ? cpu_idle+0x88/0xae
 [<ffffffff805c137a>] ? start_secondary+0x157/0x15c

RCU detected CPU 2 stall (t=4295014976/874 jiffies)
Pid: 0, comm: swapper Not tainted 2.6.27-rc9 #6

Call Trace:
 <IRQ> <3>RCU detected CPU 3 stall (t=4295014976/874 jiffies)
 [<ffffffff8025f474>] __rcu_pending+0x6e/0x1d9
 [<ffffffff8025f615>] rcu_pending+0x36/0x6e
 [<ffffffff8023bc5d>] update_process_times+0x37/0x5b
 [<ffffffff8024de88>] tick_sched_timer+0x81/0xb5
 [<ffffffff80247538>] __run_hrtimer+0x56/0x96
 [<ffffffff80248002>] hrtimer_interrupt+0xe6/0x14d
 [<ffffffff8021bcd2>] smp_apic_timer_interrupt+0x8a/0xa8
Pid: 0, comm: swapper Not tainted 2.6.27-rc9 #6

Call Trace:
 <IRQ>  [<ffffffff8020bff6>] apic_timer_interrupt+0x66/0x70
 <EOI>  [<ffffffff8024e1b0>] ? tick_nohz_restart_sched_tick+0x15e/0x165
 [<ffffffff8025f474>] __rcu_pending+0x6e/0x1d9
 [<ffffffff8025f615>] rcu_pending+0x36/0x6e
 [<ffffffff8023bc5d>] update_process_times+0x37/0x5b
 [<ffffffff8024de88>] tick_sched_timer+0x81/0xb5
 [<ffffffff80247538>] __run_hrtimer+0x56/0x96
 [<ffffffff80248002>] hrtimer_interrupt+0xe6/0x14d
 [<ffffffff8021bcd2>] smp_apic_timer_interrupt+0x8a/0xa8
 [<ffffffff8020a0bd>] ? cpu_idle+0xa4/0xae
 [<ffffffff805c137a>] ? start_secondary+0x157/0x15c
 [<ffffffff8020bff6>] apic_timer_interrupt+0x66/0x70

 <EOI>  [<ffffffff803b0254>] ? acpi_idle_enter_bm+0x2a2/0x312
 [<ffffffff803b024a>] ? acpi_idle_enter_bm+0x298/0x312
 [<ffffffff805020c2>] ? cpuidle_idle_call+0x70/0xa2
 [<ffffffff8020a0a1>] ? cpu_idle+0x88/0xae
 [<ffffffff805c137a>] ? start_secondary+0x157/0x15c

RCU detected CPU 4 stall (t=4295019871/4894 jiffies)
Pid: 0, comm: swapper Not tainted 2.6.27-rc9 #6

Call Trace:
 <IRQ>  [<ffffffff8025f474>] __rcu_pending+0x6e/0x1d9
 [<ffffffff8025f615>] rcu_pending+0x36/0x6e
 [<ffffffff8023bc5d>] update_process_times+0x37/0x5b
 [<ffffffff8024de88>] tick_sched_timer+0x81/0xb5
 [<ffffffff80247538>] __run_hrtimer+0x56/0x96
RCU detected CPU 6 stall (t=4295019871/4894 jiffies)
Pid: 0, comm: swapper Not tainted 2.6.27-rc9 #6

Call Trace:
 <IRQ>  [<ffffffff8025f474>] __rcu_pending+0x6e/0x1d9
 [<ffffffff80248002>] hrtimer_interrupt+0xe6/0x14d
 [<ffffffff8021bcd2>] smp_apic_timer_interrupt+0x8a/0xa8
 [<ffffffff8020bff6>] apic_timer_interrupt+0x66/0x70
 <EOI>  [<ffffffff803b0254>] ? acpi_idle_enter_bm+0x2a2/0x312
 [<ffffffff8025f615>] rcu_pending+0x36/0x6e
 [<ffffffff8023bc5d>] update_process_times+0x37/0x5b
 [<ffffffff8024de88>] tick_sched_timer+0x81/0xb5
 [<ffffffff80247538>] __run_hrtimer+0x56/0x96
 [<ffffffff80248002>] hrtimer_interrupt+0xe6/0x14d
 [<ffffffff8021bcd2>] smp_apic_timer_interrupt+0x8a/0xa8
 [<ffffffff8020bff6>] apic_timer_interrupt+0x66/0x70
 <EOI>  [<ffffffff8024e1b0>] ? tick_nohz_restart_sched_tick+0x15e/0x165
 [<ffffffff803b024a>] ? acpi_idle_enter_bm+0x298/0x312
 [<ffffffff805020c2>] ? cpuidle_idle_call+0x70/0xa2
 [<ffffffff8020a0a1>] ? cpu_idle+0x88/0xae
 [<ffffffff805c137a>] ? start_secondary+0x157/0x15c

 [<ffffffff8020a0bd>] ? cpu_idle+0xa4/0xae
 [<ffffffff805c137a>] ? start_secondary+0x157/0x15c


-- 
ak@linux.intel.com

Re: RCU hang on cpu re-hotplug with 2.6.27rc8

[Paul E. McKenney]

On Thu, Oct 09, 2008 at 06:56:46AM +0200, Andi Kleen wrote:
> [fix up Thomas' address to not bounce]
> 
> On Wed, Oct 08, 2008 at 06:33:21PM -0700, Paul E. McKenney wrote:
> > The attached patch (similar to one in -tip, but set up for mainline and
> > tweaked to make stall-checking on by default) should get you a stack
> > trace of any CPUs holding up RCU grace periods for more than about
> > three seconds.
> > 
> > On the off-chance that this helps.
> 
> It actually does. The stall detector makes the online echo return
> after three seconds, although it's not 100% clear to me why.

Interesting.  This behavior would be consistent with the CPU entering
dyntick-idle mode without RCU's being aware of this.  Except that your
earlier .config file says "# CONFIG_NO_HZ is not set".  And that would
mean that the CPU really should be invoking RCU's state machine every
scheduling tick.

I confess confusion.

						Thanx, Paul

> here's the backtrace
> 
> RCU detected CPU 14 stall (t=4295149800/5928 jiffies)
> Pid: 0, comm: swapper Not tainted 2.6.27-rc9 #5
> 
> Call Trace:
>  <IRQ>  [<ffffffff8025d188>] __rcu_pending+0x6e/0x1d9
>  [<ffffffff8025d329>] rcu_pending+0x36/0x6e
>  [<ffffffff8023b480>] update_process_times+0x37/0x5b
>  [<ffffffff8024be72>] tick_periodic+0x68/0x74
>  [<ffffffff8024be9f>] tick_handle_periodic+0x21/0x66
>  [<ffffffff8021bcd2>] smp_apic_timer_interrupt+0x8a/0xa8
>  [<ffffffff8020bfe6>] apic_timer_interrupt+0x66/0x70
>  <EOI>  [<ffffffff803adb39>] ? acpi_safe_halt+0x2b/0x3e
>  [<ffffffff803adbfa>] ? acpi_idle_enter_c1+0xae/0x102
>  [<ffffffff804ffdd6>] ? cpuidle_idle_call+0x70/0xa2
>  [<ffffffff8020a097>] ? cpu_idle+0x7e/0x9c
>  [<ffffffff805bef4a>] ? start_secondary+0x157/0x15c
> 
> Timer issue?
> 
> 
> -Andi