aboutsummaryrefslogtreecommitdiffstats
path: root/Documentation/RCU/trace.txt
diff options
context:
space:
mode:
Diffstat (limited to 'Documentation/RCU/trace.txt')
-rw-r--r--Documentation/RCU/trace.txt419
1 files changed, 197 insertions, 222 deletions
diff --git a/Documentation/RCU/trace.txt b/Documentation/RCU/trace.txt
index c776968f446..8173cec473a 100644
--- a/Documentation/RCU/trace.txt
+++ b/Documentation/RCU/trace.txt
@@ -10,63 +10,51 @@ 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 provide several debugfs directories under the 13These implementations of RCU provides several debugfs files under the
14top-level directory "rcu": 14top-level directory "rcu":
15 15
16rcu/rcu_bh 16rcu/rcudata:
17rcu/rcu_preempt
18rcu/rcu_sched
19
20Each directory contains files for the corresponding flavor of RCU.
21Note that rcu/rcu_preempt is only present for CONFIG_TREE_PREEMPT_RCU.
22For CONFIG_TREE_RCU, the RCU flavor maps onto the RCU-sched flavor,
23so that activity for both appears in rcu/rcu_sched.
24
25In addition, the following file appears in the top-level directory:
26rcu/rcutorture. This file displays rcutorture test progress. The output
27of "cat rcu/rcutorture" looks as follows:
28
29rcutorture test sequence: 0 (test in progress)
30rcutorture update version number: 615
31
32The first line shows the number of rcutorture tests that have completed
33since boot. If a test is currently running, the "(test in progress)"
34string will appear as shown above. The second line shows the number of
35update cycles that the current test has started, or zero if there is
36no test in progress.
37
38
39Within each flavor directory (rcu/rcu_bh, rcu/rcu_sched, and possibly
40also rcu/rcu_preempt) the following files will be present:
41
42rcudata:
43 Displays fields in struct rcu_data. 17 Displays fields in struct rcu_data.
44rcuexp: 18rcu/rcudata.csv:
45 Displays statistics for expedited grace periods. 19 Comma-separated values spreadsheet version of rcudata.
46rcugp: 20rcu/rcugp:
47 Displays grace-period counters. 21 Displays grace-period counters.
48rcuhier: 22rcu/rcuhier:
49 Displays the struct rcu_node hierarchy. 23 Displays the struct rcu_node hierarchy.
50rcu_pending: 24rcu/rcu_pending:
51 Displays counts of the reasons rcu_pending() decided that RCU had 25 Displays counts of the reasons rcu_pending() decided that RCU had
52 work to do. 26 work to do.
53rcuboost: 27rcu/rcutorture:
28 Displays rcutorture test progress.
29rcu/rcuboost:
54 Displays RCU boosting statistics. Only present if 30 Displays RCU boosting statistics. Only present if
55 CONFIG_RCU_BOOST=y. 31 CONFIG_RCU_BOOST=y.
56 32
57The output of "cat rcu/rcu_preempt/rcudata" looks as follows: 33The output of "cat rcu/rcudata" looks as follows:
58 34
59 0!c=30455 g=30456 pq=1 qp=1 dt=126535/140000000000000/0 df=2002 of=4 ql=0/0 qs=N... b=10 ci=74572 nci=0 co=1131 ca=716 35rcu_sched:
60 1!c=30719 g=30720 pq=1 qp=0 dt=132007/140000000000000/0 df=1874 of=10 ql=0/0 qs=N... b=10 ci=123209 nci=0 co=685 ca=982 36 0 c=20972 g=20973 pq=1 pqc=20972 qp=0 dt=545/1/0 df=50 of=0 ri=0 ql=163 qs=NRW. kt=0/W/0 ktl=ebc3 b=10 ci=153737 co=0 ca=0
61 2!c=30150 g=30151 pq=1 qp=1 dt=138537/140000000000000/0 df=1707 of=8 ql=0/0 qs=N... b=10 ci=80132 nci=0 co=1328 ca=1458 37 1 c=20972 g=20973 pq=1 pqc=20972 qp=0 dt=967/1/0 df=58 of=0 ri=0 ql=634 qs=NRW. kt=0/W/1 ktl=58c b=10 ci=191037 co=0 ca=0
62 3 c=31249 g=31250 pq=1 qp=0 dt=107255/140000000000000/0 df=1749 of=6 ql=0/450 qs=NRW. b=10 ci=151700 nci=0 co=509 ca=622 38 2 c=20972 g=20973 pq=1 pqc=20972 qp=0 dt=1081/1/0 df=175 of=0 ri=0 ql=74 qs=N.W. kt=0/W/2 ktl=da94 b=10 ci=75991 co=0 ca=0
63 4!c=29502 g=29503 pq=1 qp=1 dt=83647/140000000000000/0 df=965 of=5 ql=0/0 qs=N... b=10 ci=65643 nci=0 co=1373 ca=1521 39 3 c=20942 g=20943 pq=1 pqc=20942 qp=1 dt=1846/0/0 df=404 of=0 ri=0 ql=0 qs=.... kt=0/W/3 ktl=d1cd b=10 ci=72261 co=0 ca=0
64 5 c=31201 g=31202 pq=1 qp=1 dt=70422/0/0 df=535 of=7 ql=0/0 qs=.... b=10 ci=58500 nci=0 co=764 ca=698 40 4 c=20972 g=20973 pq=1 pqc=20972 qp=0 dt=369/1/0 df=83 of=0 ri=0 ql=48 qs=N.W. kt=0/W/4 ktl=e0e7 b=10 ci=128365 co=0 ca=0
65 6!c=30253 g=30254 pq=1 qp=1 dt=95363/140000000000000/0 df=780 of=5 ql=0/0 qs=N... b=10 ci=100607 nci=0 co=1414 ca=1353 41 5 c=20972 g=20973 pq=1 pqc=20972 qp=0 dt=381/1/0 df=64 of=0 ri=0 ql=169 qs=NRW. kt=0/W/5 ktl=fb2f b=10 ci=164360 co=0 ca=0
66 7 c=31178 g=31178 pq=1 qp=0 dt=91536/0/0 df=547 of=4 ql=0/0 qs=.... b=10 ci=109819 nci=0 co=1115 ca=969 42 6 c=20972 g=20973 pq=1 pqc=20972 qp=0 dt=1037/1/0 df=183 of=0 ri=0 ql=62 qs=N.W. kt=0/W/6 ktl=d2ad b=10 ci=65663 co=0 ca=0
67 43 7 c=20897 g=20897 pq=1 pqc=20896 qp=0 dt=1572/0/0 df=382 of=0 ri=0 ql=0 qs=.... kt=0/W/7 ktl=cf15 b=10 ci=75006 co=0 ca=0
68This file has one line per CPU, or eight for this 8-CPU system. 44rcu_bh:
69The fields are as follows: 45 0 c=1480 g=1480 pq=1 pqc=1479 qp=0 dt=545/1/0 df=6 of=0 ri=1 ql=0 qs=.... kt=0/W/0 ktl=ebc3 b=10 ci=0 co=0 ca=0
46 1 c=1480 g=1480 pq=1 pqc=1479 qp=0 dt=967/1/0 df=3 of=0 ri=1 ql=0 qs=.... kt=0/W/1 ktl=58c b=10 ci=151 co=0 ca=0
47 2 c=1480 g=1480 pq=1 pqc=1479 qp=0 dt=1081/1/0 df=6 of=0 ri=1 ql=0 qs=.... kt=0/W/2 ktl=da94 b=10 ci=0 co=0 ca=0
48 3 c=1480 g=1480 pq=1 pqc=1479 qp=0 dt=1846/0/0 df=8 of=0 ri=1 ql=0 qs=.... kt=0/W/3 ktl=d1cd b=10 ci=0 co=0 ca=0
49 4 c=1480 g=1480 pq=1 pqc=1479 qp=0 dt=369/1/0 df=6 of=0 ri=1 ql=0 qs=.... kt=0/W/4 ktl=e0e7 b=10 ci=0 co=0 ca=0
50 5 c=1480 g=1480 pq=1 pqc=1479 qp=0 dt=381/1/0 df=4 of=0 ri=1 ql=0 qs=.... kt=0/W/5 ktl=fb2f b=10 ci=0 co=0 ca=0
51 6 c=1480 g=1480 pq=1 pqc=1479 qp=0 dt=1037/1/0 df=6 of=0 ri=1 ql=0 qs=.... kt=0/W/6 ktl=d2ad b=10 ci=0 co=0 ca=0
52 7 c=1474 g=1474 pq=1 pqc=1473 qp=0 dt=1572/0/0 df=8 of=0 ri=1 ql=0 qs=.... kt=0/W/7 ktl=cf15 b=10 ci=0 co=0 ca=0
53
54The first section lists the rcu_data structures for rcu_sched, the second
55for rcu_bh. Note that CONFIG_TREE_PREEMPT_RCU kernels will have an
56additional section for rcu_preempt. Each section has one line per CPU,
57or eight for this 8-CPU system. The fields are as follows:
70 58
71o The number at the beginning of each line is the CPU number. 59o The number at the beginning of each line is the CPU number.
72 CPUs numbers followed by an exclamation mark are offline, 60 CPUs numbers followed by an exclamation mark are offline,
@@ -76,13 +64,11 @@ o The number at the beginning of each line is the CPU number.
76 substantially larger than the number of actual CPUs. 64 substantially larger than the number of actual CPUs.
77 65
78o "c" is the count of grace periods that this CPU believes have 66o "c" is the count of grace periods that this CPU believes have
79 completed. Offlined CPUs and CPUs in dynticks idle mode may lag 67 completed. Offlined CPUs and CPUs in dynticks idle mode may
80 quite a ways behind, for example, CPU 4 under "rcu_sched" above, 68 lag quite a ways behind, for example, CPU 6 under "rcu_sched"
81 which has been offline through 16 RCU grace periods. It is not 69 above, which has been offline through not quite 40,000 RCU grace
82 unusual to see offline CPUs lagging by thousands of grace periods. 70 periods. It is not unusual to see CPUs lagging by thousands of
83 Note that although the grace-period number is an unsigned long, 71 grace periods.
84 it is printed out as a signed long to allow more human-friendly
85 representation near boot time.
86 72
87o "g" is the count of grace periods that this CPU believes have 73o "g" is the count of grace periods that this CPU believes have
88 started. Again, offlined CPUs and CPUs in dynticks idle mode 74 started. Again, offlined CPUs and CPUs in dynticks idle mode
@@ -98,25 +84,34 @@ o "pq" indicates that this CPU has passed through a quiescent state
98 CPU has not yet reported that fact, (2) some other CPU has not 84 CPU has not yet reported that fact, (2) some other CPU has not
99 yet reported for this grace period, or (3) both. 85 yet reported for this grace period, or (3) both.
100 86
87o "pqc" indicates which grace period the last-observed quiescent
88 state for this CPU corresponds to. This is important for handling
89 the race between CPU 0 reporting an extended dynticks-idle
90 quiescent state for CPU 1 and CPU 1 suddenly waking up and
91 reporting its own quiescent state. If CPU 1 was the last CPU
92 for the current grace period, then the CPU that loses this race
93 will attempt to incorrectly mark CPU 1 as having checked in for
94 the next grace period!
95
101o "qp" indicates that RCU still expects a quiescent state from 96o "qp" indicates that RCU still expects a quiescent state from
102 this CPU. Offlined CPUs and CPUs in dyntick idle mode might 97 this CPU. Offlined CPUs and CPUs in dyntick idle mode might
103 well have qp=1, which is OK: RCU is still ignoring them. 98 well have qp=1, which is OK: RCU is still ignoring them.
104 99
105o "dt" is the current value of the dyntick counter that is incremented 100o "dt" is the current value of the dyntick counter that is incremented
106 when entering or leaving idle, either due to a context switch or 101 when entering or leaving dynticks idle state, either by the
107 due to an interrupt. This number is even if the CPU is in idle 102 scheduler or by irq. This number is even if the CPU is in
108 from RCU's viewpoint and odd otherwise. The number after the 103 dyntick idle mode and odd otherwise. The number after the first
109 first "/" is the interrupt nesting depth when in idle state, 104 "/" is the interrupt nesting depth when in dyntick-idle state,
110 or a large number added to the interrupt-nesting depth when 105 or one greater than the interrupt-nesting depth otherwise.
111 running a non-idle task. Some architectures do not accurately 106 The number after the second "/" is the NMI nesting depth.
112 count interrupt nesting when running in non-idle kernel context, 107
113 which can result in interesting anomalies such as negative 108 This field is displayed only for CONFIG_NO_HZ kernels.
114 interrupt-nesting levels. The number after the second "/"
115 is the NMI nesting depth.
116 109
117o "df" is the number of times that some other CPU has forced a 110o "df" is the number of times that some other CPU has forced a
118 quiescent state on behalf of this CPU due to this CPU being in 111 quiescent state on behalf of this CPU due to this CPU being in
119 idle state. 112 dynticks-idle state.
113
114 This field is displayed only for CONFIG_NO_HZ kernels.
120 115
121o "of" is the number of times that some other CPU has forced a 116o "of" is the number of times that some other CPU has forced a
122 quiescent state on behalf of this CPU due to this CPU being 117 quiescent state on behalf of this CPU due to this CPU being
@@ -128,14 +123,14 @@ o "of" is the number of times that some other CPU has forced a
128 CPU is offline when it is really alive and kicking) is a fatal 123 CPU is offline when it is really alive and kicking) is a fatal
129 error, so it makes sense to err conservatively. 124 error, so it makes sense to err conservatively.
130 125
126o "ri" is the number of times that RCU has seen fit to send a
127 reschedule IPI to this CPU in order to get it to report a
128 quiescent state.
129
131o "ql" is the number of RCU callbacks currently residing on 130o "ql" is the number of RCU callbacks currently residing on
132 this CPU. The first number is the number of "lazy" callbacks 131 this CPU. This is the total number of callbacks, regardless
133 that are known to RCU to only be freeing memory, and the number 132 of what state they are in (new, waiting for grace period to
134 after the "/" is the total number of callbacks, lazy or not. 133 start, waiting for grace period to end, ready to invoke).
135 These counters count callbacks regardless of what phase of
136 grace-period processing that they are in (new, waiting for
137 grace period to start, waiting for grace period to end, ready
138 to invoke).
139 134
140o "qs" gives an indication of the state of the callback queue 135o "qs" gives an indication of the state of the callback queue
141 with four characters: 136 with four characters:
@@ -163,43 +158,6 @@ o "qs" gives an indication of the state of the callback queue
163 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,
164 the corresponding character is replaced by ".". 159 the corresponding character is replaced by ".".
165 160
166o "b" is the batch limit for this CPU. If more than this number
167 of RCU callbacks is ready to invoke, then the remainder will
168 be deferred.
169
170o "ci" is the number of RCU callbacks that have been invoked for
171 this CPU. Note that ci+nci+ql is the number of callbacks that have
172 been registered in absence of CPU-hotplug activity.
173
174o "nci" is the number of RCU callbacks that have been offloaded from
175 this CPU. This will always be zero unless the kernel was built
176 with CONFIG_RCU_NOCB_CPU=y and the "rcu_nocbs=" kernel boot
177 parameter was specified.
178
179o "co" is the number of RCU callbacks that have been orphaned due to
180 this CPU going offline. These orphaned callbacks have been moved
181 to an arbitrarily chosen online CPU.
182
183o "ca" is the number of RCU callbacks that have been adopted by this
184 CPU due to other CPUs going offline. Note that ci+co-ca+ql is
185 the number of RCU callbacks registered on this CPU.
186
187
188Kernels compiled with CONFIG_RCU_BOOST=y display the following from
189/debug/rcu/rcu_preempt/rcudata:
190
191 0!c=12865 g=12866 pq=1 qp=1 dt=83113/140000000000000/0 df=288 of=11 ql=0/0 qs=N... kt=0/O ktl=944 b=10 ci=60709 nci=0 co=748 ca=871
192 1 c=14407 g=14408 pq=1 qp=0 dt=100679/140000000000000/0 df=378 of=7 ql=0/119 qs=NRW. kt=0/W ktl=9b6 b=10 ci=109740 nci=0 co=589 ca=485
193 2 c=14407 g=14408 pq=1 qp=0 dt=105486/0/0 df=90 of=9 ql=0/89 qs=NRW. kt=0/W ktl=c0c b=10 ci=83113 nci=0 co=533 ca=490
194 3 c=14407 g=14408 pq=1 qp=0 dt=107138/0/0 df=142 of=8 ql=0/188 qs=NRW. kt=0/W ktl=b96 b=10 ci=121114 nci=0 co=426 ca=290
195 4 c=14405 g=14406 pq=1 qp=1 dt=50238/0/0 df=706 of=7 ql=0/0 qs=.... kt=0/W ktl=812 b=10 ci=34929 nci=0 co=643 ca=114
196 5!c=14168 g=14169 pq=1 qp=0 dt=45465/140000000000000/0 df=161 of=11 ql=0/0 qs=N... kt=0/O ktl=b4d b=10 ci=47712 nci=0 co=677 ca=722
197 6 c=14404 g=14405 pq=1 qp=0 dt=59454/0/0 df=94 of=6 ql=0/0 qs=.... kt=0/W ktl=e57 b=10 ci=55597 nci=0 co=701 ca=811
198 7 c=14407 g=14408 pq=1 qp=1 dt=68850/0/0 df=31 of=8 ql=0/0 qs=.... kt=0/W ktl=14bd b=10 ci=77475 nci=0 co=508 ca=1042
199
200This is similar to the output discussed above, but contains the following
201additional fields:
202
203o "kt" is the per-CPU kernel-thread state. The digit preceding 161o "kt" is the per-CPU kernel-thread state. The digit preceding
204 the first slash is zero if there is no work pending and 1 162 the first slash is zero if there is no work pending and 1
205 otherwise. The character between the first pair of slashes is 163 otherwise. The character between the first pair of slashes is
@@ -226,59 +184,39 @@ o "kt" is the per-CPU kernel-thread state. The digit preceding
226 The number after the final slash is the CPU that the kthread 184 The number after the final slash is the CPU that the kthread
227 is actually running on. 185 is actually running on.
228 186
229 This field is displayed only for CONFIG_RCU_BOOST kernels.
230
231o "ktl" is the low-order 16 bits (in hexadecimal) of the count of 187o "ktl" is the low-order 16 bits (in hexadecimal) of the count of
232 the number of times that this CPU's per-CPU kthread has gone 188 the number of times that this CPU's per-CPU kthread has gone
233 through its loop servicing invoke_rcu_cpu_kthread() requests. 189 through its loop servicing invoke_rcu_cpu_kthread() requests.
234 190
235 This field is displayed only for CONFIG_RCU_BOOST kernels. 191o "b" is the batch limit for this CPU. If more than this number
236 192 of RCU callbacks is ready to invoke, then the remainder will
237 193 be deferred.
238The output of "cat rcu/rcu_preempt/rcuexp" looks as follows:
239
240s=21872 d=21872 w=0 tf=0 wd1=0 wd2=0 n=0 sc=21872 dt=21872 dl=0 dx=21872
241
242These fields are as follows:
243
244o "s" is the starting sequence number.
245
246o "d" is the ending sequence number. When the starting and ending
247 numbers differ, there is an expedited grace period in progress.
248
249o "w" is the number of times that the sequence numbers have been
250 in danger of wrapping.
251
252o "tf" is the number of times that contention has resulted in a
253 failure to begin an expedited grace period.
254
255o "wd1" and "wd2" are the number of times that an attempt to
256 start an expedited grace period found that someone else had
257 completed an expedited grace period that satisfies the
258 attempted request. "Our work is done."
259
260o "n" is number of times that contention was so great that
261 the request was demoted from an expedited grace period to
262 a normal grace period.
263 194
264o "sc" is the number of times that the attempt to start a 195o "ci" is the number of RCU callbacks that have been invoked for
265 new expedited grace period succeeded. 196 this CPU. Note that ci+ql is the number of callbacks that have
197 been registered in absence of CPU-hotplug activity.
266 198
267o "dt" is the number of times that we attempted to update 199o "co" is the number of RCU callbacks that have been orphaned due to
268 the "d" counter. 200 this CPU going offline. These orphaned callbacks have been moved
201 to an arbitrarily chosen online CPU.
269 202
270o "dl" is the number of times that we failed to update the "d" 203o "ca" is the number of RCU callbacks that have been adopted due to
271 counter. 204 other CPUs going offline. Note that ci+co-ca+ql is the number of
205 RCU callbacks registered on this CPU.
272 206
273o "dx" is the number of times that we succeeded in updating 207There is also an rcu/rcudata.csv file with the same information in
274 the "d" counter. 208comma-separated-variable spreadsheet format.
275 209
276 210
277The output of "cat rcu/rcu_preempt/rcugp" looks as follows: 211The output of "cat rcu/rcugp" looks as follows:
278 212
279completed=31249 gpnum=31250 age=1 max=18 213rcu_sched: completed=33062 gpnum=33063
214rcu_bh: completed=464 gpnum=464
280 215
281These fields are taken from the rcu_state structure, and are as follows: 216Again, this output is for both "rcu_sched" and "rcu_bh". Note that
217kernels built with CONFIG_TREE_PREEMPT_RCU will have an additional
218"rcu_preempt" line. The fields are taken from the rcu_state structure,
219and are as follows:
282 220
283o "completed" is the number of grace periods that have completed. 221o "completed" is the number of grace periods that have completed.
284 It is comparable to the "c" field from rcu/rcudata in that a 222 It is comparable to the "c" field from rcu/rcudata in that a
@@ -286,42 +224,44 @@ o "completed" is the number of grace periods that have completed.
286 that the corresponding RCU grace period has completed. 224 that the corresponding RCU grace period has completed.
287 225
288o "gpnum" is the number of grace periods that have started. It is 226o "gpnum" is the number of grace periods that have started. It is
289 similarly comparable to the "g" field from rcu/rcudata in that 227 comparable to the "g" field from rcu/rcudata in that a CPU
290 a CPU whose "g" field matches the value of "gpnum" is aware that 228 whose "g" field matches the value of "gpnum" is aware that the
291 the corresponding RCU grace period has started. 229 corresponding RCU grace period has started.
292
293 If these two fields are equal, then there is no grace period
294 in progress, in other words, RCU is idle. On the other hand,
295 if the two fields differ (as they are above), then an RCU grace
296 period is in progress.
297 230
298o "age" is the number of jiffies that the current grace period 231 If these two fields are equal (as they are for "rcu_bh" above),
299 has extended for, or zero if there is no grace period currently 232 then there is no grace period in progress, in other words, RCU
300 in effect. 233 is idle. On the other hand, if the two fields differ (as they
234 do for "rcu_sched" above), then an RCU grace period is in progress.
301 235
302o "max" is the age in jiffies of the longest-duration grace period
303 thus far.
304 236
305The output of "cat rcu/rcu_preempt/rcuhier" looks as follows: 237The output of "cat rcu/rcuhier" looks as follows, with very long lines:
306 238
307c=14407 g=14408 s=0 jfq=2 j=c863 nfqs=12040/nfqsng=0(12040) fqlh=1051 oqlen=0/0 239c=6902 g=6903 s=2 jfq=3 j=72c7 nfqs=13142/nfqsng=0(13142) fqlh=6
3083/3 ..>. 0:7 ^0 2401/1 ..>. 0:127 ^0
309e/e ..>. 0:3 ^0 d/d ..>. 4:7 ^1 2413/3 ..>. 0:35 ^0 0/0 ..>. 36:71 ^1 0/0 ..>. 72:107 ^2 0/0 ..>. 108:127 ^3
2423/3f ..>. 0:5 ^0 2/3 ..>. 6:11 ^1 0/0 ..>. 12:17 ^2 0/0 ..>. 18:23 ^3 0/0 ..>. 24:29 ^4 0/0 ..>. 30:35 ^5 0/0 ..>. 36:41 ^0 0/0 ..>. 42:47 ^1 0/0 ..>. 48:53 ^2 0/0 ..>. 54:59 ^3 0/0 ..>. 60:65 ^4 0/0 ..>. 66:71 ^5 0/0 ..>. 72:77 ^0 0/0 ..>. 78:83 ^1 0/0 ..>. 84:89 ^2 0/0 ..>. 90:95 ^3 0/0 ..>. 96:101 ^4 0/0 ..>. 102:107 ^5 0/0 ..>. 108:113 ^0 0/0 ..>. 114:119 ^1 0/0 ..>. 120:125 ^2 0/0 ..>. 126:127 ^3
243rcu_bh:
244c=-226 g=-226 s=1 jfq=-5701 j=72c7 nfqs=88/nfqsng=0(88) fqlh=0
2450/1 ..>. 0:127 ^0
2460/3 ..>. 0:35 ^0 0/0 ..>. 36:71 ^1 0/0 ..>. 72:107 ^2 0/0 ..>. 108:127 ^3
2470/3f ..>. 0:5 ^0 0/3 ..>. 6:11 ^1 0/0 ..>. 12:17 ^2 0/0 ..>. 18:23 ^3 0/0 ..>. 24:29 ^4 0/0 ..>. 30:35 ^5 0/0 ..>. 36:41 ^0 0/0 ..>. 42:47 ^1 0/0 ..>. 48:53 ^2 0/0 ..>. 54:59 ^3 0/0 ..>. 60:65 ^4 0/0 ..>. 66:71 ^5 0/0 ..>. 72:77 ^0 0/0 ..>. 78:83 ^1 0/0 ..>. 84:89 ^2 0/0 ..>. 90:95 ^3 0/0 ..>. 96:101 ^4 0/0 ..>. 102:107 ^5 0/0 ..>. 108:113 ^0 0/0 ..>. 114:119 ^1 0/0 ..>. 120:125 ^2 0/0 ..>. 126:127 ^3
310 248
311The fields are as follows: 249This is once again split into "rcu_sched" and "rcu_bh" portions,
250and CONFIG_TREE_PREEMPT_RCU kernels will again have an additional
251"rcu_preempt" section. The fields are as follows:
312 252
313o "c" is exactly the same as "completed" under rcu/rcu_preempt/rcugp. 253o "c" is exactly the same as "completed" under rcu/rcugp.
314 254
315o "g" is exactly the same as "gpnum" under rcu/rcu_preempt/rcugp. 255o "g" is exactly the same as "gpnum" under rcu/rcugp.
316 256
317o "s" is the current state of the force_quiescent_state() 257o "s" is the "signaled" state that drives force_quiescent_state()'s
318 state machine. 258 state machine.
319 259
320o "jfq" is the number of jiffies remaining for this grace period 260o "jfq" is the number of jiffies remaining for this grace period
321 before force_quiescent_state() is invoked to help push things 261 before force_quiescent_state() is invoked to help push things
322 along. Note that CPUs in idle mode throughout the grace period 262 along. Note that CPUs in dyntick-idle mode throughout the grace
323 will not report on their own, but rather must be check by some 263 period will not report on their own, but rather must be check by
324 other CPU via force_quiescent_state(). 264 some other CPU via force_quiescent_state().
325 265
326o "j" is the low-order four hex digits of the jiffies counter. 266o "j" is the low-order four hex digits of the jiffies counter.
327 Yes, Paul did run into a number of problems that turned out to 267 Yes, Paul did run into a number of problems that turned out to
@@ -332,8 +272,7 @@ o "nfqs" is the number of calls to force_quiescent_state() since
332 272
333o "nfqsng" is the number of useless calls to force_quiescent_state(), 273o "nfqsng" is the number of useless calls to force_quiescent_state(),
334 where there wasn't actually a grace period active. This can 274 where there wasn't actually a grace period active. This can
335 no longer happen due to grace-period processing being pushed 275 happen due to races. The number in parentheses is the difference
336 into a kthread. The number in parentheses is the difference
337 between "nfqs" and "nfqsng", or the number of times that 276 between "nfqs" and "nfqsng", or the number of times that
338 force_quiescent_state() actually did some real work. 277 force_quiescent_state() actually did some real work.
339 278
@@ -341,27 +280,28 @@ o "fqlh" is the number of calls to force_quiescent_state() that
341 exited immediately (without even being counted in nfqs above) 280 exited immediately (without even being counted in nfqs above)
342 due to contention on ->fqslock. 281 due to contention on ->fqslock.
343 282
344o Each element of the form "3/3 ..>. 0:7 ^0" represents one rcu_node 283o Each element of the form "1/1 0:127 ^0" represents one struct
345 structure. Each line represents one level of the hierarchy, 284 rcu_node. Each line represents one level of the hierarchy, from
346 from root to leaves. It is best to think of the rcu_data 285 root to leaves. It is best to think of the rcu_data structures
347 structures as forming yet another level after the leaves. 286 as forming yet another level after the leaves. Note that there
348 Note that there might be either one, two, three, or even four 287 might be either one, two, or three levels of rcu_node structures,
349 levels of rcu_node structures, depending on the relationship 288 depending on the relationship between CONFIG_RCU_FANOUT and
350 between CONFIG_RCU_FANOUT, CONFIG_RCU_FANOUT_LEAF (possibly 289 CONFIG_NR_CPUS.
351 adjusted using the rcu_fanout_leaf kernel boot parameter), and
352 CONFIG_NR_CPUS (possibly adjusted using the nr_cpu_ids count of
353 possible CPUs for the booting hardware).
354 290
355 o The numbers separated by the "/" are the qsmask followed 291 o The numbers separated by the "/" are the qsmask followed
356 by the qsmaskinit. The qsmask will have one bit 292 by the qsmaskinit. The qsmask will have one bit
357 set for each entity in the next lower level that has 293 set for each entity in the next lower level that
358 not yet checked in for the current grace period ("e" 294 has not yet checked in for the current grace period.
359 indicating CPUs 5, 6, and 7 in the example above).
360 The qsmaskinit will have one bit for each entity that is 295 The qsmaskinit will have one bit for each entity that is
361 currently expected to check in during each grace period. 296 currently expected to check in during each grace period.
362 The value of qsmaskinit is assigned to that of qsmask 297 The value of qsmaskinit is assigned to that of qsmask
363 at the beginning of each grace period. 298 at the beginning of each grace period.
364 299
300 For example, for "rcu_sched", the qsmask of the first
301 entry of the lowest level is 0x14, meaning that we
302 are still waiting for CPUs 2 and 4 to check in for the
303 current grace period.
304
365 o The characters separated by the ">" indicate the state 305 o The characters separated by the ">" indicate the state
366 of the blocked-tasks lists. A "G" preceding the ">" 306 of the blocked-tasks lists. A "G" preceding the ">"
367 indicates that at least one task blocked in an RCU 307 indicates that at least one task blocked in an RCU
@@ -376,39 +316,48 @@ o Each element of the form "3/3 ..>. 0:7 ^0" represents one rcu_node
376 A "." character appears if the corresponding condition 316 A "." character appears if the corresponding condition
377 does not hold, so that "..>." indicates that no tasks 317 does not hold, so that "..>." indicates that no tasks
378 are blocked. In contrast, "GE>T" indicates maximal 318 are blocked. In contrast, "GE>T" indicates maximal
379 inconvenience from blocked tasks. CONFIG_TREE_RCU 319 inconvenience from blocked tasks.
380 builds of the kernel will always show "..>.".
381 320
382 o The numbers separated by the ":" are the range of CPUs 321 o The numbers separated by the ":" are the range of CPUs
383 served by this struct rcu_node. This can be helpful 322 served by this struct rcu_node. This can be helpful
384 in working out how the hierarchy is wired together. 323 in working out how the hierarchy is wired together.
385 324
386 For example, the example rcu_node structure shown above 325 For example, the first entry at the lowest level shows
387 has "0:7", indicating that it covers CPUs 0 through 7. 326 "0:5", indicating that it covers CPUs 0 through 5.
388 327
389 o The number after the "^" indicates the bit in the 328 o The number after the "^" indicates the bit in the
390 next higher level rcu_node structure that this rcu_node 329 next higher level rcu_node structure that this
391 structure corresponds to. For example, the "d/d ..>. 4:7 330 rcu_node structure corresponds to.
392 ^1" has a "1" in this position, indicating that it 331
393 corresponds to the "1" bit in the "3" shown in the 332 For example, the first entry at the lowest level shows
394 "3/3 ..>. 0:7 ^0" entry on the next level up. 333 "^0", indicating that it corresponds to bit zero in
395 334 the first entry at the middle level.
396 335
397The output of "cat rcu/rcu_sched/rcu_pending" looks as follows: 336
398 337The output of "cat rcu/rcu_pending" looks as follows:
399 0!np=26111 qsp=29 rpq=5386 cbr=1 cng=570 gpc=3674 gps=577 nn=15903 338
400 1!np=28913 qsp=35 rpq=6097 cbr=1 cng=448 gpc=3700 gps=554 nn=18113 339rcu_sched:
401 2!np=32740 qsp=37 rpq=6202 cbr=0 cng=476 gpc=4627 gps=546 nn=20889 340 0 np=255892 qsp=53936 rpq=85 cbr=0 cng=14417 gpc=10033 gps=24320 nf=6445 nn=146741
402 3 np=23679 qsp=22 rpq=5044 cbr=1 cng=415 gpc=3403 gps=347 nn=14469 341 1 np=261224 qsp=54638 rpq=33 cbr=0 cng=25723 gpc=16310 gps=2849 nf=5912 nn=155792
403 4!np=30714 qsp=4 rpq=5574 cbr=0 cng=528 gpc=3931 gps=639 nn=20042 342 2 np=237496 qsp=49664 rpq=23 cbr=0 cng=2762 gpc=45478 gps=1762 nf=1201 nn=136629
404 5 np=28910 qsp=2 rpq=5246 cbr=0 cng=428 gpc=4105 gps=709 nn=18422 343 3 np=236249 qsp=48766 rpq=98 cbr=0 cng=286 gpc=48049 gps=1218 nf=207 nn=137723
405 6!np=38648 qsp=5 rpq=7076 cbr=0 cng=840 gpc=4072 gps=961 nn=25699 344 4 np=221310 qsp=46850 rpq=7 cbr=0 cng=26 gpc=43161 gps=4634 nf=3529 nn=123110
406 7 np=37275 qsp=2 rpq=6873 cbr=0 cng=868 gpc=3416 gps=971 nn=25147 345 5 np=237332 qsp=48449 rpq=9 cbr=0 cng=54 gpc=47920 gps=3252 nf=201 nn=137456
407 346 6 np=219995 qsp=46718 rpq=12 cbr=0 cng=50 gpc=42098 gps=6093 nf=4202 nn=120834
408The fields are as follows: 347 7 np=249893 qsp=49390 rpq=42 cbr=0 cng=72 gpc=38400 gps=17102 nf=41 nn=144888
409 348rcu_bh:
410o The leading number is the CPU number, with "!" indicating 349 0 np=146741 qsp=1419 rpq=6 cbr=0 cng=6 gpc=0 gps=0 nf=2 nn=145314
411 an offline CPU. 350 1 np=155792 qsp=12597 rpq=3 cbr=0 cng=0 gpc=4 gps=8 nf=3 nn=143180
351 2 np=136629 qsp=18680 rpq=1 cbr=0 cng=0 gpc=7 gps=6 nf=0 nn=117936
352 3 np=137723 qsp=2843 rpq=0 cbr=0 cng=0 gpc=10 gps=7 nf=0 nn=134863
353 4 np=123110 qsp=12433 rpq=0 cbr=0 cng=0 gpc=4 gps=2 nf=0 nn=110671
354 5 np=137456 qsp=4210 rpq=1 cbr=0 cng=0 gpc=6 gps=5 nf=0 nn=133235
355 6 np=120834 qsp=9902 rpq=2 cbr=0 cng=0 gpc=6 gps=3 nf=2 nn=110921
356 7 np=144888 qsp=26336 rpq=0 cbr=0 cng=0 gpc=8 gps=2 nf=0 nn=118542
357
358As always, this is once again split into "rcu_sched" and "rcu_bh"
359portions, with CONFIG_TREE_PREEMPT_RCU kernels having an additional
360"rcu_preempt" section. The fields are as follows:
412 361
413o "np" is the number of times that __rcu_pending() has been invoked 362o "np" is the number of times that __rcu_pending() has been invoked
414 for the corresponding flavor of RCU. 363 for the corresponding flavor of RCU.
@@ -432,23 +381,49 @@ o "gpc" is the number of times that an old grace period had
432o "gps" is the number of times that a new grace period had started, 381o "gps" is the number of times that a new grace period had started,
433 but this CPU was not yet aware of it. 382 but this CPU was not yet aware of it.
434 383
435o "nn" is the number of times that this CPU needed nothing. 384o "nf" is the number of times that this CPU suspected that the
385 current grace period had run for too long, and thus needed to
386 be forced.
387
388 Please note that "forcing" consists of sending resched IPIs
389 to holdout CPUs. If that CPU really still is in an old RCU
390 read-side critical section, then we really do have to wait for it.
391 The assumption behing "forcing" is that the CPU is not still in
392 an old RCU read-side critical section, but has not yet responded
393 for some other reason.
394
395o "nn" is the number of times that this CPU needed nothing. Alert
396 readers will note that the rcu "nn" number for a given CPU very
397 closely matches the rcu_bh "np" number for that same CPU. This
398 is due to short-circuit evaluation in rcu_pending().
399
400
401The output of "cat rcu/rcutorture" looks as follows:
402
403rcutorture test sequence: 0 (test in progress)
404rcutorture update version number: 615
405
406The first line shows the number of rcutorture tests that have completed
407since boot. If a test is currently running, the "(test in progress)"
408string will appear as shown above. The second line shows the number of
409update cycles that the current test has started, or zero if there is
410no test in progress.
436 411
437 412
438The output of "cat rcu/rcuboost" looks as follows: 413The output of "cat rcu/rcuboost" looks as follows:
439 414
4400:3 tasks=.... kt=W ntb=0 neb=0 nnb=0 j=c864 bt=c894 4150:5 tasks=.... kt=W ntb=0 neb=0 nnb=0 j=2f95 bt=300f
441 balk: nt=0 egt=4695 bt=0 nb=0 ny=56 nos=0 416 balk: nt=0 egt=989 bt=0 nb=0 ny=0 nos=16
4424:7 tasks=.... kt=W ntb=0 neb=0 nnb=0 j=c864 bt=c894 4176:7 tasks=.... kt=W ntb=0 neb=0 nnb=0 j=2f95 bt=300f
443 balk: nt=0 egt=6541 bt=0 nb=0 ny=126 nos=0 418 balk: nt=0 egt=225 bt=0 nb=0 ny=0 nos=6
444 419
445This information is output only for rcu_preempt. Each two-line entry 420This information is output only for rcu_preempt. Each two-line entry
446corresponds to a leaf rcu_node strcuture. The fields are as follows: 421corresponds to a leaf rcu_node strcuture. The fields are as follows:
447 422
448o "n:m" is the CPU-number range for the corresponding two-line 423o "n:m" is the CPU-number range for the corresponding two-line
449 entry. In the sample output above, the first entry covers 424 entry. In the sample output above, the first entry covers
450 CPUs zero through three and the second entry covers CPUs four 425 CPUs zero through five and the second entry covers CPUs 6
451 through seven. 426 and 7.
452 427
453o "tasks=TNEB" gives the state of the various segments of the 428o "tasks=TNEB" gives the state of the various segments of the
454 rnp->blocked_tasks list: 429 rnp->blocked_tasks list: