Commit 0ac3d136b2e3cdf1161178223bc5da14a06241d0

Authored by Paul E. McKenney
Committed by Paul E. McKenney
1 parent 2fa218d8bb

rcu: add callback-queue information to rcudata output

This commit adds an indication of the state of the callback queue using
a string of four characters following the "ql=" integer queue length.
The first character is "N" if there are callbacks that have been
queued that are not yet ready to be handled by the next grace period, or
"." otherwise.  The second character is "R" if there are callbacks queued
that are ready to be handled by the next grace period, or "." otherwise.
The third character is "W" if there are callbacks waiting for the current
grace period, or "." otherwise.  Finally, the fourth character is "D"
if there are callbacks that have been handled by a prior grace period
and are waiting to be invoked, or ".".

Note that callbacks that are in the process of being invoked are
not shown.  These callbacks would have been removed from the rcu_data
structure's list by rcu_do_batch() prior to being executed.  (These
callbacks are also not reflected in the "ql=" total, FWIW.)

Also, document the new callback-queue trace information.

Signed-off-by: Paul E. McKenney <paul.mckenney@linaro.org>
Signed-off-by: Paul E. McKenney <paulmck@linux.vnet.ibm.com>
Reviewed-by: Josh Triplett <josh@joshtriplett.org>

Showing 2 changed files with 61 additions and 18 deletions Side-by-side Diff

Documentation/RCU/trace.txt
... ... @@ -21,23 +21,23 @@
21 21 The output of "cat rcu/rcudata" looks as follows:
22 22  
23 23 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 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 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 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 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 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 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 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 b=10 ci=4026154 co=1948 ca=135
  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
  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
  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
  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
  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
  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
  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
  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
32 32 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 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 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 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 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 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 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 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 b=10 ci=627 co=0 ca=0
  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
  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
  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
  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
  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
  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
  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
  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
41 41  
42 42 The first section lists the rcu_data structures for rcu_sched, the second
43 43 for rcu_bh. Note that CONFIG_TREE_PREEMPT_RCU kernels will have an
... ... @@ -119,6 +119,32 @@
119 119 this CPU. This is the total number of callbacks, regardless
120 120 of what state they are in (new, waiting for grace period to
121 121 start, waiting for grace period to end, ready to invoke).
  122 +
  123 +o "qs" gives an indication of the state of the callback queue
  124 + with four characters:
  125 +
  126 + "N" Indicates that there are callbacks queued that are not
  127 + ready to be handled by the next grace period, and thus
  128 + will be handled by the grace period following the next
  129 + one.
  130 +
  131 + "R" Indicates that there are callbacks queued that are
  132 + ready to be handled by the next grace period.
  133 +
  134 + "W" Indicates that there are callbacks queued that are
  135 + waiting on the current grace period.
  136 +
  137 + "D" Indicates that there are callbacks queued that have
  138 + already been handled by a prior grace period, and are
  139 + thus waiting to be invoked. Note that callbacks in
  140 + the process of being invoked are not counted here.
  141 + Callbacks in the process of being invoked are those
  142 + that have been removed from the rcu_data structures
  143 + queues by rcu_do_batch(), but which have not yet been
  144 + invoked.
  145 +
  146 + If there are no callbacks in a given one of the above states,
  147 + the corresponding character is replaced by ".".
122 148  
123 149 o "b" is the batch limit for this CPU. If more than this number
124 150 of RCU callbacks is ready to invoke, then the remainder will
kernel/rcutree_trace.c
... ... @@ -64,7 +64,16 @@
64 64 rdp->dynticks_fqs);
65 65 #endif /* #ifdef CONFIG_NO_HZ */
66 66 seq_printf(m, " of=%lu ri=%lu", rdp->offline_fqs, rdp->resched_ipi);
67   - seq_printf(m, " ql=%ld b=%ld", rdp->qlen, rdp->blimit);
  67 + seq_printf(m, " ql=%ld qs=%c%c%c%c b=%ld",
  68 + rdp->qlen,
  69 + ".N"[rdp->nxttail[RCU_NEXT_READY_TAIL] !=
  70 + rdp->nxttail[RCU_NEXT_TAIL]],
  71 + ".R"[rdp->nxttail[RCU_WAIT_TAIL] !=
  72 + rdp->nxttail[RCU_NEXT_READY_TAIL]],
  73 + ".W"[rdp->nxttail[RCU_DONE_TAIL] !=
  74 + rdp->nxttail[RCU_WAIT_TAIL]],
  75 + ".D"[&rdp->nxtlist != rdp->nxttail[RCU_DONE_TAIL]],
  76 + rdp->blimit);
68 77 seq_printf(m, " ci=%lu co=%lu ca=%lu\n",
69 78 rdp->n_cbs_invoked, rdp->n_cbs_orphaned, rdp->n_cbs_adopted);
70 79 }
... ... @@ -121,7 +130,15 @@
121 130 rdp->dynticks_fqs);
122 131 #endif /* #ifdef CONFIG_NO_HZ */
123 132 seq_printf(m, ",%lu,%lu", rdp->offline_fqs, rdp->resched_ipi);
124   - seq_printf(m, ",%ld,%ld", rdp->qlen, rdp->blimit);
  133 + seq_printf(m, ",%ld,\"%c%c%c%c\",%ld", rdp->qlen,
  134 + ".N"[rdp->nxttail[RCU_NEXT_READY_TAIL] !=
  135 + rdp->nxttail[RCU_NEXT_TAIL]],
  136 + ".R"[rdp->nxttail[RCU_WAIT_TAIL] !=
  137 + rdp->nxttail[RCU_NEXT_READY_TAIL]],
  138 + ".W"[rdp->nxttail[RCU_DONE_TAIL] !=
  139 + rdp->nxttail[RCU_WAIT_TAIL]],
  140 + ".D"[&rdp->nxtlist != rdp->nxttail[RCU_DONE_TAIL]],
  141 + rdp->blimit);
125 142 seq_printf(m, ",%lu,%lu,%lu\n",
126 143 rdp->n_cbs_invoked, rdp->n_cbs_orphaned, rdp->n_cbs_adopted);
127 144 }