aboutsummaryrefslogtreecommitdiffstats
diff options
context:
space:
mode:
authorPaul E. McKenney <paul.mckenney@linaro.org>2011-04-06 18:20:47 -0400
committerPaul E. McKenney <paulmck@linux.vnet.ibm.com>2011-05-06 02:16:56 -0400
commit90e6ac3657fd3b0446d585082000af3cf46439a7 (patch)
tree1b7e4beb5f649e8a7c7562d2ef557739ad1a2a1e
parent4a29865689dbb87a02e3b0fff4a4ae5041273173 (diff)
rcu: update tracing documentation for new rcutorture and rcuboost
This commit documents the new debugfs rcu/rcutorture and rcu/rcuboost trace files. The description has been updated as suggested by Josh Triplett. Signed-off-by: Paul E. McKenney <paul.mckenney@linaro.org> Signed-off-by: Paul E. McKenney <paulmck@linux.vnet.ibm.com>
-rw-r--r--Documentation/RCU/trace.txt186
1 files changed, 161 insertions, 25 deletions
diff --git a/Documentation/RCU/trace.txt b/Documentation/RCU/trace.txt
index 5aefd5fa7af5..40b530dd0fc7 100644
--- a/Documentation/RCU/trace.txt
+++ b/Documentation/RCU/trace.txt
@@ -10,34 +10,46 @@ for rcutree and next for rcutiny.
10 10
11CONFIG_TREE_RCU and CONFIG_TREE_PREEMPT_RCU debugfs Files and Formats 11CONFIG_TREE_RCU and CONFIG_TREE_PREEMPT_RCU debugfs Files and Formats
12 12
13These implementations of RCU provides five debugfs files under the 13These implementations of RCU provides several debugfs files under the
14top-level directory RCU: rcu/rcudata (which displays fields in struct 14top-level directory "rcu":
15rcu_data), rcu/rcudata.csv (which is a .csv spreadsheet version of 15
16rcu/rcudata), rcu/rcugp (which displays grace-period counters), 16rcu/rcudata:
17rcu/rcuhier (which displays the struct rcu_node hierarchy), and 17 Displays fields in struct rcu_data.
18rcu/rcu_pending (which displays counts of the reasons that the 18rcu/rcudata.csv:
19rcu_pending() function decided that there was core RCU work to do). 19 Comma-separated values spreadsheet version of rcudata.
20rcu/rcugp:
21 Displays grace-period counters.
22rcu/rcuhier:
23 Displays the struct rcu_node hierarchy.
24rcu/rcu_pending:
25 Displays counts of the reasons rcu_pending() decided that RCU had
26 work to do.
27rcu/rcutorture:
28 Displays rcutorture test progress.
29rcu/rcuboost:
30 Displays RCU boosting statistics. Only present if
31 CONFIG_RCU_BOOST=y.
20 32
21The output of "cat rcu/rcudata" looks as follows: 33The output of "cat rcu/rcudata" looks as follows:
22 34
23rcu_sched: 35rcu_sched:
24 0!c=423090 g=423091 pq=1 pqc=423090 qp=1 dt=86475/1/0 df=16319 of=163 ri=1519 ql=0 qs=.... b=10 ci=1460693 co=1648 ca=6448 36 0!c=423090 g=423091 pq=1 pqc=423090 qp=1 dt=86475/1/0 df=16319 of=163 ri=1519 ql=0 qs=.... kt=0/W b=10 ci=1460693 co=1648 ca=6448
25 1!c=423329 g=423330 pq=1 pqc=423329 qp=1 dt=90875/1/0 df=16231 of=157 ri=1249 ql=0 qs=.... b=10 ci=1459002 co=1614 ca=3310 37 1!c=423329 g=423330 pq=1 pqc=423329 qp=1 dt=90875/1/0 df=16231 of=157 ri=1249 ql=0 qs=.... kt=0/W b=10 ci=1459002 co=1614 ca=3310
26 2!c=423370 g=423371 pq=1 pqc=423370 qp=1 dt=69661/1/0 df=16125 of=163 ri=1469 ql=0 qs=.... b=10 ci=1610701 co=2015 ca=2378 38 2!c=423370 g=423371 pq=1 pqc=423370 qp=1 dt=69661/1/0 df=16125 of=163 ri=1469 ql=0 qs=.... kt=0/W b=10 ci=1610701 co=2015 ca=2378
27 3!c=422967 g=422968 pq=1 pqc=422967 qp=1 dt=70349/1/0 df=12528 of=163 ri=1450 ql=0 qs=.... b=10 ci=1427543 co=1430 ca=897 39 3!c=422967 g=422968 pq=1 pqc=422967 qp=1 dt=70349/1/0 df=12528 of=163 ri=1450 ql=0 qs=.... kt=0/W b=10 ci=1427543 co=1430 ca=897
28 4!c=423196 g=423197 pq=1 pqc=423196 qp=0 dt=38935/1/0 df=10959 of=177 ri=1657 ql=0 qs=.... b=10 ci=1562249 co=1896 ca=533 40 4!c=423196 g=423197 pq=1 pqc=423196 qp=0 dt=38935/1/0 df=10959 of=177 ri=1657 ql=0 qs=.... kt=0/W b=10 ci=1562249 co=1896 ca=533
29 5!c=422950 g=422951 pq=1 pqc=422950 qp=0 dt=25127/1/0 df=5895 of=167 ri=1549 ql=0 qs=.... b=10 ci=1777260 co=2137 ca=274 41 5!c=422950 g=422951 pq=1 pqc=422950 qp=0 dt=25127/1/0 df=5895 of=167 ri=1549 ql=0 qs=.... kt=0/W b=10 ci=1777260 co=2137 ca=274
30 6!c=423396 g=423397 pq=1 pqc=423396 qp=1 dt=22639/1/0 df=4590 of=149 ri=1572 ql=0 qs=.... b=10 ci=1471186 co=1530 ca=243 42 6!c=423396 g=423397 pq=1 pqc=423396 qp=1 dt=22639/1/0 df=4590 of=149 ri=1572 ql=0 qs=.... kt=0/W b=10 ci=1471186 co=1530 ca=243
31 7 c=460203 g=460203 pq=1 pqc=460202 qp=0 dt=937087/1/0 df=3298 of=149 ri=1584 ql=6 qs=N.W. b=10 ci=4026154 co=1948 ca=135 43 7 c=460203 g=460203 pq=1 pqc=460202 qp=0 dt=937087/1/0 df=3298 of=149 ri=1584 ql=6 qs=N.W. kt=0/W b=10 ci=4026154 co=1948 ca=135
32rcu_bh: 44rcu_bh:
33 0!c=18446744073709551494 g=18446744073709551494 pq=0 pqc=18446744073709551493 qp=1 dt=86475/1/0 df=11 of=0 ri=0 ql=0 qs=.... b=10 ci=112 co=0 ca=0 45 0!c=18446744073709551494 g=18446744073709551494 pq=0 pqc=18446744073709551493 qp=1 dt=86475/1/0 df=11 of=0 ri=0 ql=0 qs=.... kt=0/W b=10 ci=112 co=0 ca=0
34 1!c=18446744073709551496 g=18446744073709551496 pq=1 pqc=18446744073709551495 qp=0 dt=90875/1/0 df=15 of=0 ri=0 ql=0 qs=.... b=10 ci=143 co=0 ca=0 46 1!c=18446744073709551496 g=18446744073709551496 pq=1 pqc=18446744073709551495 qp=0 dt=90875/1/0 df=15 of=0 ri=0 ql=0 qs=.... kt=0/W b=10 ci=143 co=0 ca=0
35 2!c=18446744073709551496 g=18446744073709551496 pq=1 pqc=18446744073709551495 qp=0 dt=69661/1/0 df=21 of=0 ri=1 ql=0 qs=.... b=10 ci=88 co=0 ca=0 47 2!c=18446744073709551496 g=18446744073709551496 pq=1 pqc=18446744073709551495 qp=0 dt=69661/1/0 df=21 of=0 ri=1 ql=0 qs=.... kt=0/W b=10 ci=88 co=0 ca=0
36 3!c=18446744073709551494 g=18446744073709551494 pq=1 pqc=18446744073709551493 qp=0 dt=70349/1/0 df=13 of=0 ri=0 ql=0 qs=.... b=10 ci=100 co=0 ca=0 48 3!c=18446744073709551494 g=18446744073709551494 pq=1 pqc=18446744073709551493 qp=0 dt=70349/1/0 df=13 of=0 ri=0 ql=0 qs=.... kt=0/W b=10 ci=100 co=0 ca=0
37 4!c=18446744073709551494 g=18446744073709551494 pq=0 pqc=18446744073709551493 qp=1 dt=38935/1/0 df=17 of=0 ri=0 ql=0 qs=.... b=10 ci=36 co=0 ca=0 49 4!c=18446744073709551494 g=18446744073709551494 pq=0 pqc=18446744073709551493 qp=1 dt=38935/1/0 df=17 of=0 ri=0 ql=0 qs=.... kt=0/W b=10 ci=36 co=0 ca=0
38 5!c=18446744073709551494 g=18446744073709551494 pq=0 pqc=18446744073709551493 qp=1 dt=25127/1/0 df=7 of=0 ri=0 ql=0 qs=.... b=10 ci=32 co=0 ca=0 50 5!c=18446744073709551494 g=18446744073709551494 pq=0 pqc=18446744073709551493 qp=1 dt=25127/1/0 df=7 of=0 ri=0 ql=0 qs=.... kt=0/W b=10 ci=32 co=0 ca=0
39 6!c=18446744073709551496 g=18446744073709551496 pq=1 pqc=18446744073709551495 qp=0 dt=22639/1/0 df=9 of=0 ri=0 ql=0 qs=.... b=10 ci=44 co=0 ca=0 51 6!c=18446744073709551496 g=18446744073709551496 pq=1 pqc=18446744073709551495 qp=0 dt=22639/1/0 df=9 of=0 ri=0 ql=0 qs=.... kt=0/W b=10 ci=44 co=0 ca=0
40 7 c=182 g=182 pq=1 pqc=181 qp=0 dt=937087/1/0 df=14 of=0 ri=1 ql=0 qs=.... b=10 ci=627 co=0 ca=0 52 7 c=182 g=182 pq=1 pqc=181 qp=0 dt=937087/1/0 df=14 of=0 ri=1 ql=0 qs=.... kt=0/W b=10 ci=627 co=0 ca=0
41 53
42The first section lists the rcu_data structures for rcu_sched, the second 54The first section lists the rcu_data structures for rcu_sched, the second
43for rcu_bh. Note that CONFIG_TREE_PREEMPT_RCU kernels will have an 55for rcu_bh. Note that CONFIG_TREE_PREEMPT_RCU kernels will have an
@@ -146,6 +158,23 @@ o "qs" gives an indication of the state of the callback queue
146 If there are no callbacks in a given one of the above states, 158 If there are no callbacks in a given one of the above states,
147 the corresponding character is replaced by ".". 159 the corresponding character is replaced by ".".
148 160
161o "kt" is the per-CPU kernel-thread state. The digit preceding
162 the slash is zero if there is no work pending and 1 otherwise.
163 The character after the slash is as follows:
164
165 "S" The kernel thread is stopped, in other words, all
166 CPUs corresponding to this rcu_node structure are
167 offline.
168
169 "R" The kernel thread is running.
170
171 "W" The kernel thread is waiting because there is no work
172 for it to do.
173
174 "Y" The kernel thread is yielding to avoid hogging CPU.
175
176 "?" Unknown value, indicates a bug.
177
149o "b" is the batch limit for this CPU. If more than this number 178o "b" is the batch limit for this CPU. If more than this number
150 of RCU callbacks is ready to invoke, then the remainder will 179 of RCU callbacks is ready to invoke, then the remainder will
151 be deferred. 180 be deferred.
@@ -356,6 +385,113 @@ o "nn" is the number of times that this CPU needed nothing. Alert
356 is due to short-circuit evaluation in rcu_pending(). 385 is due to short-circuit evaluation in rcu_pending().
357 386
358 387
388The output of "cat rcu/rcutorture" looks as follows:
389
390rcutorture test sequence: 0 (test in progress)
391rcutorture update version number: 615
392
393The first line shows the number of rcutorture tests that have completed
394since boot. If a test is currently running, the "(test in progress)"
395string will appear as shown above. The second line shows the number of
396update cycles that the current test has started, or zero if there is
397no test in progress.
398
399
400The output of "cat rcu/rcuboost" looks as follows:
401
4020:5 tasks=.... kt=W ntb=0 neb=0 nnb=0 j=2f95 bt=300f
403 balk: nt=0 egt=989 bt=0 nb=0 ny=0 nos=16
4046:7 tasks=.... kt=W ntb=0 neb=0 nnb=0 j=2f95 bt=300f
405 balk: nt=0 egt=225 bt=0 nb=0 ny=0 nos=6
406
407This information is output only for rcu_preempt. Each two-line entry
408corresponds to a leaf rcu_node strcuture. The fields are as follows:
409
410o "n:m" is the CPU-number range for the corresponding two-line
411 entry. In the sample output above, the first entry covers
412 CPUs zero through five and the second entry covers CPUs 6
413 and 7.
414
415o "tasks=TNEB" gives the state of the various segments of the
416 rnp->blocked_tasks list:
417
418 "T" This indicates that there are some tasks that blocked
419 while running on one of the corresponding CPUs while
420 in an RCU read-side critical section.
421
422 "N" This indicates that some of the blocked tasks are preventing
423 the current normal (non-expedited) grace period from
424 completing.
425
426 "E" This indicates that some of the blocked tasks are preventing
427 the current expedited grace period from completing.
428
429 "B" This indicates that some of the blocked tasks are in
430 need of RCU priority boosting.
431
432 Each character is replaced with "." if the corresponding
433 condition does not hold.
434
435o "kt" is the state of the RCU priority-boosting kernel
436 thread associated with the corresponding rcu_node structure.
437 The state can be one of the following:
438
439 "S" The kernel thread is stopped, in other words, all
440 CPUs corresponding to this rcu_node structure are
441 offline.
442
443 "R" The kernel thread is running.
444
445 "W" The kernel thread is waiting because there is no work
446 for it to do.
447
448 "Y" The kernel thread is yielding to avoid hogging CPU.
449
450 "?" Unknown value, indicates a bug.
451
452o "ntb" is the number of tasks boosted.
453
454o "neb" is the number of tasks boosted in order to complete an
455 expedited grace period.
456
457o "nnb" is the number of tasks boosted in order to complete a
458 normal (non-expedited) grace period. When boosting a task
459 that was blocking both an expedited and a normal grace period,
460 it is counted against the expedited total above.
461
462o "j" is the low-order 16 bits of the jiffies counter in
463 hexadecimal.
464
465o "bt" is the low-order 16 bits of the value that the jiffies
466 counter will have when we next start boosting, assuming that
467 the current grace period does not end beforehand. This is
468 also in hexadecimal.
469
470o "balk: nt" counts the number of times we didn't boost (in
471 other words, we balked) even though it was time to boost because
472 there were no blocked tasks to boost. This situation occurs
473 when there is one blocked task on one rcu_node structure and
474 none on some other rcu_node structure.
475
476o "egt" counts the number of times we balked because although
477 there were blocked tasks, none of them were blocking the
478 current grace period, whether expedited or otherwise.
479
480o "bt" counts the number of times we balked because boosting
481 had already been initiated for the current grace period.
482
483o "nb" counts the number of times we balked because there
484 was at least one task blocking the current non-expedited grace
485 period that never had blocked. If it is already running, it
486 just won't help to boost its priority!
487
488o "ny" counts the number of times we balked because it was
489 not yet time to start boosting.
490
491o "nos" counts the number of times we balked for other
492 reasons, e.g., the grace period ended first.
493
494
359CONFIG_TINY_RCU and CONFIG_TINY_PREEMPT_RCU debugfs Files and Formats 495CONFIG_TINY_RCU and CONFIG_TINY_PREEMPT_RCU debugfs Files and Formats
360 496
361These implementations of RCU provides a single debugfs file under the 497These implementations of RCU provides a single debugfs file under the
@@ -422,9 +558,9 @@ o "neb" is the number of expedited grace periods that have had
422o "nnb" is the number of normal grace periods that have had 558o "nnb" is the number of normal grace periods that have had
423 to resort to RCU priority boosting since boot. 559 to resort to RCU priority boosting since boot.
424 560
425o "j" is the low-order 12 bits of the jiffies counter in hexadecimal. 561o "j" is the low-order 16 bits of the jiffies counter in hexadecimal.
426 562
427o "bt" is the low-order 12 bits of the value that the jiffies counter 563o "bt" is the low-order 16 bits of the value that the jiffies counter
428 will have at the next time that boosting is scheduled to begin. 564 will have at the next time that boosting is scheduled to begin.
429 565
430o In the line beginning with "normal balk", the fields are as follows: 566o In the line beginning with "normal balk", the fields are as follows: