diff options
author | Paul E. McKenney <paul.mckenney@linaro.org> | 2011-04-06 18:20:47 -0400 |
---|---|---|
committer | Paul E. McKenney <paulmck@linux.vnet.ibm.com> | 2011-05-06 02:16:56 -0400 |
commit | 90e6ac3657fd3b0446d585082000af3cf46439a7 (patch) | |
tree | 1b7e4beb5f649e8a7c7562d2ef557739ad1a2a1e | |
parent | 4a29865689dbb87a02e3b0fff4a4ae5041273173 (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.txt | 186 |
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 | ||
11 | CONFIG_TREE_RCU and CONFIG_TREE_PREEMPT_RCU debugfs Files and Formats | 11 | CONFIG_TREE_RCU and CONFIG_TREE_PREEMPT_RCU debugfs Files and Formats |
12 | 12 | ||
13 | These implementations of RCU provides five debugfs files under the | 13 | These implementations of RCU provides several debugfs files under the |
14 | top-level directory RCU: rcu/rcudata (which displays fields in struct | 14 | top-level directory "rcu": |
15 | rcu_data), rcu/rcudata.csv (which is a .csv spreadsheet version of | 15 | |
16 | rcu/rcudata), rcu/rcugp (which displays grace-period counters), | 16 | rcu/rcudata: |
17 | rcu/rcuhier (which displays the struct rcu_node hierarchy), and | 17 | Displays fields in struct rcu_data. |
18 | rcu/rcu_pending (which displays counts of the reasons that the | 18 | rcu/rcudata.csv: |
19 | rcu_pending() function decided that there was core RCU work to do). | 19 | Comma-separated values spreadsheet version of rcudata. |
20 | rcu/rcugp: | ||
21 | Displays grace-period counters. | ||
22 | rcu/rcuhier: | ||
23 | Displays the struct rcu_node hierarchy. | ||
24 | rcu/rcu_pending: | ||
25 | Displays counts of the reasons rcu_pending() decided that RCU had | ||
26 | work to do. | ||
27 | rcu/rcutorture: | ||
28 | Displays rcutorture test progress. | ||
29 | rcu/rcuboost: | ||
30 | Displays RCU boosting statistics. Only present if | ||
31 | CONFIG_RCU_BOOST=y. | ||
20 | 32 | ||
21 | The output of "cat rcu/rcudata" looks as follows: | 33 | The output of "cat rcu/rcudata" looks as follows: |
22 | 34 | ||
23 | rcu_sched: | 35 | rcu_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 |
32 | rcu_bh: | 44 | rcu_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 | ||
42 | The first section lists the rcu_data structures for rcu_sched, the second | 54 | The first section lists the rcu_data structures for rcu_sched, the second |
43 | for rcu_bh. Note that CONFIG_TREE_PREEMPT_RCU kernels will have an | 55 | for 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 | ||
161 | o "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 | |||
149 | o "b" is the batch limit for this CPU. If more than this number | 178 | o "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 | ||
388 | The output of "cat rcu/rcutorture" looks as follows: | ||
389 | |||
390 | rcutorture test sequence: 0 (test in progress) | ||
391 | rcutorture update version number: 615 | ||
392 | |||
393 | The first line shows the number of rcutorture tests that have completed | ||
394 | since boot. If a test is currently running, the "(test in progress)" | ||
395 | string will appear as shown above. The second line shows the number of | ||
396 | update cycles that the current test has started, or zero if there is | ||
397 | no test in progress. | ||
398 | |||
399 | |||
400 | The output of "cat rcu/rcuboost" looks as follows: | ||
401 | |||
402 | 0: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 | ||
404 | 6: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 | |||
407 | This information is output only for rcu_preempt. Each two-line entry | ||
408 | corresponds to a leaf rcu_node strcuture. The fields are as follows: | ||
409 | |||
410 | o "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 | |||
415 | o "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 | |||
435 | o "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 | |||
452 | o "ntb" is the number of tasks boosted. | ||
453 | |||
454 | o "neb" is the number of tasks boosted in order to complete an | ||
455 | expedited grace period. | ||
456 | |||
457 | o "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 | |||
462 | o "j" is the low-order 16 bits of the jiffies counter in | ||
463 | hexadecimal. | ||
464 | |||
465 | o "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 | |||
470 | o "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 | |||
476 | o "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 | |||
480 | o "bt" counts the number of times we balked because boosting | ||
481 | had already been initiated for the current grace period. | ||
482 | |||
483 | o "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 | |||
488 | o "ny" counts the number of times we balked because it was | ||
489 | not yet time to start boosting. | ||
490 | |||
491 | o "nos" counts the number of times we balked for other | ||
492 | reasons, e.g., the grace period ended first. | ||
493 | |||
494 | |||
359 | CONFIG_TINY_RCU and CONFIG_TINY_PREEMPT_RCU debugfs Files and Formats | 495 | CONFIG_TINY_RCU and CONFIG_TINY_PREEMPT_RCU debugfs Files and Formats |
360 | 496 | ||
361 | These implementations of RCU provides a single debugfs file under the | 497 | These 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 | |||
422 | o "nnb" is the number of normal grace periods that have had | 558 | o "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 | ||
425 | o "j" is the low-order 12 bits of the jiffies counter in hexadecimal. | 561 | o "j" is the low-order 16 bits of the jiffies counter in hexadecimal. |
426 | 562 | ||
427 | o "bt" is the low-order 12 bits of the value that the jiffies counter | 563 | o "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 | ||
430 | o In the line beginning with "normal balk", the fields are as follows: | 566 | o In the line beginning with "normal balk", the fields are as follows: |