Commit | Line | Data |
---|---|---|
64db4cff PM |
1 | CONFIG_RCU_TRACE debugfs Files and Formats |
2 | ||
3 | ||
8e79e1f9 PM |
4 | The rcutree and rcutiny implementations of RCU provide debugfs trace |
5 | output that summarizes counters and state. This information is useful for | |
6 | debugging RCU itself, and can sometimes also help to debug abuses of RCU. | |
7 | The following sections describe the debugfs files and formats, first | |
8 | for rcutree and next for rcutiny. | |
64db4cff PM |
9 | |
10 | ||
8e79e1f9 | 11 | CONFIG_TREE_RCU and CONFIG_TREE_PREEMPT_RCU debugfs Files and Formats |
64db4cff | 12 | |
90e6ac36 PM |
13 | These implementations of RCU provides several debugfs files under the |
14 | top-level directory "rcu": | |
15 | ||
16 | rcu/rcudata: | |
17 | Displays fields in struct rcu_data. | |
18 | rcu/rcudata.csv: | |
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. | |
64db4cff PM |
32 | |
33 | The output of "cat rcu/rcudata" looks as follows: | |
34 | ||
d6714c22 | 35 | rcu_sched: |
90e6ac36 PM |
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 |
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 | |
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 | |
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 | |
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 | |
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 | |
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 | |
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 | |
64db4cff | 44 | rcu_bh: |
90e6ac36 PM |
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 |
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 | |
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 | |
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 | |
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 | |
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 | |
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 | |
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 | |
64db4cff | 53 | |
bd58b430 PM |
54 | The first section lists the rcu_data structures for rcu_sched, the second |
55 | for rcu_bh. Note that CONFIG_TREE_PREEMPT_RCU kernels will have an | |
56 | additional section for rcu_preempt. Each section has one line per CPU, | |
57 | or eight for this 8-CPU system. The fields are as follows: | |
64db4cff PM |
58 | |
59 | o The number at the beginning of each line is the CPU number. | |
60 | CPUs numbers followed by an exclamation mark are offline, | |
61 | but have been online at least once since boot. There will be | |
62 | no output for CPUs that have never been online, which can be | |
63 | a good thing in the surprisingly common case where NR_CPUS is | |
64 | substantially larger than the number of actual CPUs. | |
65 | ||
66 | o "c" is the count of grace periods that this CPU believes have | |
2fa218d8 PM |
67 | completed. Offlined CPUs and CPUs in dynticks idle mode may |
68 | lag quite a ways behind, for example, CPU 6 under "rcu_sched" | |
69 | above, which has been offline through not quite 40,000 RCU grace | |
70 | periods. It is not unusual to see CPUs lagging by thousands of | |
71 | grace periods. | |
64db4cff PM |
72 | |
73 | o "g" is the count of grace periods that this CPU believes have | |
2fa218d8 PM |
74 | started. Again, offlined CPUs and CPUs in dynticks idle mode |
75 | may lag behind. If the "c" and "g" values are equal, this CPU | |
76 | has already reported a quiescent state for the last RCU grace | |
77 | period that it is aware of, otherwise, the CPU believes that it | |
78 | owes RCU a quiescent state. | |
64db4cff PM |
79 | |
80 | o "pq" indicates that this CPU has passed through a quiescent state | |
81 | for the current grace period. It is possible for "pq" to be | |
82 | "1" and "c" different than "g", which indicates that although | |
83 | the CPU has passed through a quiescent state, either (1) this | |
84 | CPU has not yet reported that fact, (2) some other CPU has not | |
85 | yet reported for this grace period, or (3) both. | |
86 | ||
87 | o "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 | ||
96 | o "qp" indicates that RCU still expects a quiescent state from | |
2fa218d8 PM |
97 | this CPU. Offlined CPUs and CPUs in dyntick idle mode might |
98 | well have qp=1, which is OK: RCU is still ignoring them. | |
64db4cff | 99 | |
64db4cff PM |
100 | o "dt" is the current value of the dyntick counter that is incremented |
101 | when entering or leaving dynticks idle state, either by the | |
2fa218d8 PM |
102 | scheduler or by irq. This number is even if the CPU is in |
103 | dyntick idle mode and odd otherwise. The number after the first | |
104 | "/" is the interrupt nesting depth when in dyntick-idle state, | |
105 | or one greater than the interrupt-nesting depth otherwise. | |
106 | The number after the second "/" is the NMI nesting depth. | |
64db4cff PM |
107 | |
108 | This field is displayed only for CONFIG_NO_HZ kernels. | |
109 | ||
110 | o "df" is the number of times that some other CPU has forced a | |
111 | quiescent state on behalf of this CPU due to this CPU being in | |
112 | dynticks-idle state. | |
113 | ||
114 | This field is displayed only for CONFIG_NO_HZ kernels. | |
115 | ||
116 | o "of" is the number of times that some other CPU has forced a | |
117 | quiescent state on behalf of this CPU due to this CPU being | |
2fa218d8 | 118 | offline. In a perfect world, this might never happen, but it |
64db4cff PM |
119 | turns out that offlining and onlining a CPU can take several grace |
120 | periods, and so there is likely to be an extended period of time | |
121 | when RCU believes that the CPU is online when it really is not. | |
122 | Please note that erring in the other direction (RCU believing a | |
123 | CPU is offline when it is really alive and kicking) is a fatal | |
124 | error, so it makes sense to err conservatively. | |
125 | ||
126 | o "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 | ||
130 | o "ql" is the number of RCU callbacks currently residing on | |
131 | this CPU. This is the total number of callbacks, regardless | |
132 | of what state they are in (new, waiting for grace period to | |
133 | start, waiting for grace period to end, ready to invoke). | |
134 | ||
0ac3d136 PM |
135 | o "qs" gives an indication of the state of the callback queue |
136 | with four characters: | |
137 | ||
138 | "N" Indicates that there are callbacks queued that are not | |
139 | ready to be handled by the next grace period, and thus | |
140 | will be handled by the grace period following the next | |
141 | one. | |
142 | ||
143 | "R" Indicates that there are callbacks queued that are | |
144 | ready to be handled by the next grace period. | |
145 | ||
146 | "W" Indicates that there are callbacks queued that are | |
147 | waiting on the current grace period. | |
148 | ||
149 | "D" Indicates that there are callbacks queued that have | |
150 | already been handled by a prior grace period, and are | |
151 | thus waiting to be invoked. Note that callbacks in | |
152 | the process of being invoked are not counted here. | |
153 | Callbacks in the process of being invoked are those | |
154 | that have been removed from the rcu_data structures | |
155 | queues by rcu_do_batch(), but which have not yet been | |
156 | invoked. | |
157 | ||
158 | If there are no callbacks in a given one of the above states, | |
159 | the corresponding character is replaced by ".". | |
160 | ||
90e6ac36 | 161 | o "kt" is the per-CPU kernel-thread state. The digit preceding |
15ba0ba8 PM |
162 | the first slash is zero if there is no work pending and 1 |
163 | otherwise. The character between the slashes is as follows: | |
90e6ac36 PM |
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 | ||
15ba0ba8 PM |
174 | "O" The kernel thread is waiting because it has been |
175 | forced off of its designated CPU or because its | |
176 | ->cpus_allowed mask permits it to run on other than | |
177 | its designated CPU. | |
178 | ||
90e6ac36 PM |
179 | "Y" The kernel thread is yielding to avoid hogging CPU. |
180 | ||
181 | "?" Unknown value, indicates a bug. | |
182 | ||
15ba0ba8 PM |
183 | The number after the final slash is the CPU that the kthread |
184 | is actually running on. | |
185 | ||
64db4cff PM |
186 | o "b" is the batch limit for this CPU. If more than this number |
187 | of RCU callbacks is ready to invoke, then the remainder will | |
188 | be deferred. | |
189 | ||
269dcc1c PM |
190 | o "ci" is the number of RCU callbacks that have been invoked for |
191 | this CPU. Note that ci+ql is the number of callbacks that have | |
192 | been registered in absence of CPU-hotplug activity. | |
193 | ||
194 | o "co" is the number of RCU callbacks that have been orphaned due to | |
2d999e03 PM |
195 | this CPU going offline. These orphaned callbacks have been moved |
196 | to an arbitrarily chosen online CPU. | |
269dcc1c PM |
197 | |
198 | o "ca" is the number of RCU callbacks that have been adopted due to | |
199 | other CPUs going offline. Note that ci+co-ca+ql is the number of | |
200 | RCU callbacks registered on this CPU. | |
201 | ||
6fd9b3a4 PM |
202 | There is also an rcu/rcudata.csv file with the same information in |
203 | comma-separated-variable spreadsheet format. | |
204 | ||
64db4cff PM |
205 | |
206 | The output of "cat rcu/rcugp" looks as follows: | |
207 | ||
d6714c22 | 208 | rcu_sched: completed=33062 gpnum=33063 |
64db4cff PM |
209 | rcu_bh: completed=464 gpnum=464 |
210 | ||
bd58b430 PM |
211 | Again, this output is for both "rcu_sched" and "rcu_bh". Note that |
212 | kernels built with CONFIG_TREE_PREEMPT_RCU will have an additional | |
213 | "rcu_preempt" line. The fields are taken from the rcu_state structure, | |
214 | and are as follows: | |
64db4cff PM |
215 | |
216 | o "completed" is the number of grace periods that have completed. | |
217 | It is comparable to the "c" field from rcu/rcudata in that a | |
218 | CPU whose "c" field matches the value of "completed" is aware | |
219 | that the corresponding RCU grace period has completed. | |
220 | ||
221 | o "gpnum" is the number of grace periods that have started. It is | |
222 | comparable to the "g" field from rcu/rcudata in that a CPU | |
223 | whose "g" field matches the value of "gpnum" is aware that the | |
224 | corresponding RCU grace period has started. | |
225 | ||
226 | If these two fields are equal (as they are for "rcu_bh" above), | |
227 | then there is no grace period in progress, in other words, RCU | |
228 | is idle. On the other hand, if the two fields differ (as they | |
bd58b430 | 229 | do for "rcu_sched" above), then an RCU grace period is in progress. |
64db4cff PM |
230 | |
231 | ||
232 | The output of "cat rcu/rcuhier" looks as follows, with very long lines: | |
233 | ||
2d999e03 | 234 | c=6902 g=6903 s=2 jfq=3 j=72c7 nfqs=13142/nfqsng=0(13142) fqlh=6 |
12f5f524 PM |
235 | 1/1 ..>. 0:127 ^0 |
236 | 3/3 ..>. 0:35 ^0 0/0 ..>. 36:71 ^1 0/0 ..>. 72:107 ^2 0/0 ..>. 108:127 ^3 | |
237 | 3/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 | |
64db4cff | 238 | rcu_bh: |
2d999e03 | 239 | c=-226 g=-226 s=1 jfq=-5701 j=72c7 nfqs=88/nfqsng=0(88) fqlh=0 |
12f5f524 PM |
240 | 0/1 ..>. 0:127 ^0 |
241 | 0/3 ..>. 0:35 ^0 0/0 ..>. 36:71 ^1 0/0 ..>. 72:107 ^2 0/0 ..>. 108:127 ^3 | |
242 | 0/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 | |
64db4cff | 243 | |
bd58b430 PM |
244 | This is once again split into "rcu_sched" and "rcu_bh" portions, |
245 | and CONFIG_TREE_PREEMPT_RCU kernels will again have an additional | |
246 | "rcu_preempt" section. The fields are as follows: | |
64db4cff PM |
247 | |
248 | o "c" is exactly the same as "completed" under rcu/rcugp. | |
249 | ||
250 | o "g" is exactly the same as "gpnum" under rcu/rcugp. | |
251 | ||
252 | o "s" is the "signaled" state that drives force_quiescent_state()'s | |
253 | state machine. | |
254 | ||
255 | o "jfq" is the number of jiffies remaining for this grace period | |
256 | before force_quiescent_state() is invoked to help push things | |
269dcc1c | 257 | along. Note that CPUs in dyntick-idle mode throughout the grace |
64db4cff PM |
258 | period will not report on their own, but rather must be check by |
259 | some other CPU via force_quiescent_state(). | |
260 | ||
261 | o "j" is the low-order four hex digits of the jiffies counter. | |
262 | Yes, Paul did run into a number of problems that turned out to | |
263 | be due to the jiffies counter no longer counting. Why do you ask? | |
264 | ||
265 | o "nfqs" is the number of calls to force_quiescent_state() since | |
266 | boot. | |
267 | ||
268 | o "nfqsng" is the number of useless calls to force_quiescent_state(), | |
269 | where there wasn't actually a grace period active. This can | |
270 | happen due to races. The number in parentheses is the difference | |
271 | between "nfqs" and "nfqsng", or the number of times that | |
272 | force_quiescent_state() actually did some real work. | |
273 | ||
274 | o "fqlh" is the number of calls to force_quiescent_state() that | |
275 | exited immediately (without even being counted in nfqs above) | |
276 | due to contention on ->fqslock. | |
277 | ||
278 | o Each element of the form "1/1 0:127 ^0" represents one struct | |
279 | rcu_node. Each line represents one level of the hierarchy, from | |
280 | root to leaves. It is best to think of the rcu_data structures | |
281 | as forming yet another level after the leaves. Note that there | |
282 | might be either one, two, or three levels of rcu_node structures, | |
283 | depending on the relationship between CONFIG_RCU_FANOUT and | |
284 | CONFIG_NR_CPUS. | |
0edf1a68 | 285 | |
64db4cff PM |
286 | o The numbers separated by the "/" are the qsmask followed |
287 | by the qsmaskinit. The qsmask will have one bit | |
288 | set for each entity in the next lower level that | |
289 | has not yet checked in for the current grace period. | |
290 | The qsmaskinit will have one bit for each entity that is | |
291 | currently expected to check in during each grace period. | |
292 | The value of qsmaskinit is assigned to that of qsmask | |
293 | at the beginning of each grace period. | |
294 | ||
bd58b430 PM |
295 | For example, for "rcu_sched", the qsmask of the first |
296 | entry of the lowest level is 0x14, meaning that we | |
297 | are still waiting for CPUs 2 and 4 to check in for the | |
298 | current grace period. | |
64db4cff | 299 | |
0edf1a68 | 300 | o The characters separated by the ">" indicate the state |
12f5f524 | 301 | of the blocked-tasks lists. A "G" preceding the ">" |
0edf1a68 PM |
302 | indicates that at least one task blocked in an RCU |
303 | read-side critical section blocks the current grace | |
12f5f524 PM |
304 | period, while a "E" preceding the ">" indicates that |
305 | at least one task blocked in an RCU read-side critical | |
306 | section blocks the current expedited grace period. | |
307 | A "T" character following the ">" indicates that at | |
308 | least one task is blocked within an RCU read-side | |
309 | critical section, regardless of whether any current | |
310 | grace period (expedited or normal) is inconvenienced. | |
311 | A "." character appears if the corresponding condition | |
312 | does not hold, so that "..>." indicates that no tasks | |
313 | are blocked. In contrast, "GE>T" indicates maximal | |
314 | inconvenience from blocked tasks. | |
0edf1a68 | 315 | |
64db4cff PM |
316 | o The numbers separated by the ":" are the range of CPUs |
317 | served by this struct rcu_node. This can be helpful | |
318 | in working out how the hierarchy is wired together. | |
319 | ||
320 | For example, the first entry at the lowest level shows | |
321 | "0:5", indicating that it covers CPUs 0 through 5. | |
322 | ||
323 | o The number after the "^" indicates the bit in the | |
324 | next higher level rcu_node structure that this | |
325 | rcu_node structure corresponds to. | |
326 | ||
327 | For example, the first entry at the lowest level shows | |
328 | "^0", indicating that it corresponds to bit zero in | |
329 | the first entry at the middle level. | |
6fd9b3a4 PM |
330 | |
331 | ||
332 | The output of "cat rcu/rcu_pending" looks as follows: | |
333 | ||
d6714c22 | 334 | rcu_sched: |
d21670ac PM |
335 | 0 np=255892 qsp=53936 rpq=85 cbr=0 cng=14417 gpc=10033 gps=24320 nf=6445 nn=146741 |
336 | 1 np=261224 qsp=54638 rpq=33 cbr=0 cng=25723 gpc=16310 gps=2849 nf=5912 nn=155792 | |
337 | 2 np=237496 qsp=49664 rpq=23 cbr=0 cng=2762 gpc=45478 gps=1762 nf=1201 nn=136629 | |
338 | 3 np=236249 qsp=48766 rpq=98 cbr=0 cng=286 gpc=48049 gps=1218 nf=207 nn=137723 | |
339 | 4 np=221310 qsp=46850 rpq=7 cbr=0 cng=26 gpc=43161 gps=4634 nf=3529 nn=123110 | |
340 | 5 np=237332 qsp=48449 rpq=9 cbr=0 cng=54 gpc=47920 gps=3252 nf=201 nn=137456 | |
341 | 6 np=219995 qsp=46718 rpq=12 cbr=0 cng=50 gpc=42098 gps=6093 nf=4202 nn=120834 | |
342 | 7 np=249893 qsp=49390 rpq=42 cbr=0 cng=72 gpc=38400 gps=17102 nf=41 nn=144888 | |
6fd9b3a4 | 343 | rcu_bh: |
d21670ac PM |
344 | 0 np=146741 qsp=1419 rpq=6 cbr=0 cng=6 gpc=0 gps=0 nf=2 nn=145314 |
345 | 1 np=155792 qsp=12597 rpq=3 cbr=0 cng=0 gpc=4 gps=8 nf=3 nn=143180 | |
346 | 2 np=136629 qsp=18680 rpq=1 cbr=0 cng=0 gpc=7 gps=6 nf=0 nn=117936 | |
347 | 3 np=137723 qsp=2843 rpq=0 cbr=0 cng=0 gpc=10 gps=7 nf=0 nn=134863 | |
348 | 4 np=123110 qsp=12433 rpq=0 cbr=0 cng=0 gpc=4 gps=2 nf=0 nn=110671 | |
349 | 5 np=137456 qsp=4210 rpq=1 cbr=0 cng=0 gpc=6 gps=5 nf=0 nn=133235 | |
350 | 6 np=120834 qsp=9902 rpq=2 cbr=0 cng=0 gpc=6 gps=3 nf=2 nn=110921 | |
351 | 7 np=144888 qsp=26336 rpq=0 cbr=0 cng=0 gpc=8 gps=2 nf=0 nn=118542 | |
6fd9b3a4 | 352 | |
bd58b430 PM |
353 | As always, this is once again split into "rcu_sched" and "rcu_bh" |
354 | portions, with CONFIG_TREE_PREEMPT_RCU kernels having an additional | |
355 | "rcu_preempt" section. The fields are as follows: | |
6fd9b3a4 PM |
356 | |
357 | o "np" is the number of times that __rcu_pending() has been invoked | |
358 | for the corresponding flavor of RCU. | |
359 | ||
360 | o "qsp" is the number of times that the RCU was waiting for a | |
361 | quiescent state from this CPU. | |
362 | ||
d21670ac PM |
363 | o "rpq" is the number of times that the CPU had passed through |
364 | a quiescent state, but not yet reported it to RCU. | |
365 | ||
6fd9b3a4 PM |
366 | o "cbr" is the number of times that this CPU had RCU callbacks |
367 | that had passed through a grace period, and were thus ready | |
368 | to be invoked. | |
369 | ||
370 | o "cng" is the number of times that this CPU needed another | |
371 | grace period while RCU was idle. | |
372 | ||
373 | o "gpc" is the number of times that an old grace period had | |
374 | completed, but this CPU was not yet aware of it. | |
375 | ||
376 | o "gps" is the number of times that a new grace period had started, | |
377 | but this CPU was not yet aware of it. | |
378 | ||
379 | o "nf" is the number of times that this CPU suspected that the | |
380 | current grace period had run for too long, and thus needed to | |
381 | be forced. | |
382 | ||
383 | Please note that "forcing" consists of sending resched IPIs | |
384 | to holdout CPUs. If that CPU really still is in an old RCU | |
385 | read-side critical section, then we really do have to wait for it. | |
386 | The assumption behing "forcing" is that the CPU is not still in | |
387 | an old RCU read-side critical section, but has not yet responded | |
388 | for some other reason. | |
389 | ||
390 | o "nn" is the number of times that this CPU needed nothing. Alert | |
391 | readers will note that the rcu "nn" number for a given CPU very | |
392 | closely matches the rcu_bh "np" number for that same CPU. This | |
393 | is due to short-circuit evaluation in rcu_pending(). | |
8e79e1f9 PM |
394 | |
395 | ||
90e6ac36 PM |
396 | The output of "cat rcu/rcutorture" looks as follows: |
397 | ||
398 | rcutorture test sequence: 0 (test in progress) | |
399 | rcutorture update version number: 615 | |
400 | ||
401 | The first line shows the number of rcutorture tests that have completed | |
402 | since boot. If a test is currently running, the "(test in progress)" | |
403 | string will appear as shown above. The second line shows the number of | |
404 | update cycles that the current test has started, or zero if there is | |
405 | no test in progress. | |
406 | ||
407 | ||
408 | The output of "cat rcu/rcuboost" looks as follows: | |
409 | ||
410 | 0:5 tasks=.... kt=W ntb=0 neb=0 nnb=0 j=2f95 bt=300f | |
411 | balk: nt=0 egt=989 bt=0 nb=0 ny=0 nos=16 | |
412 | 6:7 tasks=.... kt=W ntb=0 neb=0 nnb=0 j=2f95 bt=300f | |
413 | balk: nt=0 egt=225 bt=0 nb=0 ny=0 nos=6 | |
414 | ||
415 | This information is output only for rcu_preempt. Each two-line entry | |
416 | corresponds to a leaf rcu_node strcuture. The fields are as follows: | |
417 | ||
418 | o "n:m" is the CPU-number range for the corresponding two-line | |
419 | entry. In the sample output above, the first entry covers | |
420 | CPUs zero through five and the second entry covers CPUs 6 | |
421 | and 7. | |
422 | ||
423 | o "tasks=TNEB" gives the state of the various segments of the | |
424 | rnp->blocked_tasks list: | |
425 | ||
426 | "T" This indicates that there are some tasks that blocked | |
427 | while running on one of the corresponding CPUs while | |
428 | in an RCU read-side critical section. | |
429 | ||
430 | "N" This indicates that some of the blocked tasks are preventing | |
431 | the current normal (non-expedited) grace period from | |
432 | completing. | |
433 | ||
434 | "E" This indicates that some of the blocked tasks are preventing | |
435 | the current expedited grace period from completing. | |
436 | ||
437 | "B" This indicates that some of the blocked tasks are in | |
438 | need of RCU priority boosting. | |
439 | ||
440 | Each character is replaced with "." if the corresponding | |
441 | condition does not hold. | |
442 | ||
443 | o "kt" is the state of the RCU priority-boosting kernel | |
444 | thread associated with the corresponding rcu_node structure. | |
445 | The state can be one of the following: | |
446 | ||
447 | "S" The kernel thread is stopped, in other words, all | |
448 | CPUs corresponding to this rcu_node structure are | |
449 | offline. | |
450 | ||
451 | "R" The kernel thread is running. | |
452 | ||
453 | "W" The kernel thread is waiting because there is no work | |
454 | for it to do. | |
455 | ||
456 | "Y" The kernel thread is yielding to avoid hogging CPU. | |
457 | ||
458 | "?" Unknown value, indicates a bug. | |
459 | ||
460 | o "ntb" is the number of tasks boosted. | |
461 | ||
462 | o "neb" is the number of tasks boosted in order to complete an | |
463 | expedited grace period. | |
464 | ||
465 | o "nnb" is the number of tasks boosted in order to complete a | |
466 | normal (non-expedited) grace period. When boosting a task | |
467 | that was blocking both an expedited and a normal grace period, | |
468 | it is counted against the expedited total above. | |
469 | ||
470 | o "j" is the low-order 16 bits of the jiffies counter in | |
471 | hexadecimal. | |
472 | ||
473 | o "bt" is the low-order 16 bits of the value that the jiffies | |
474 | counter will have when we next start boosting, assuming that | |
475 | the current grace period does not end beforehand. This is | |
476 | also in hexadecimal. | |
477 | ||
478 | o "balk: nt" counts the number of times we didn't boost (in | |
479 | other words, we balked) even though it was time to boost because | |
480 | there were no blocked tasks to boost. This situation occurs | |
481 | when there is one blocked task on one rcu_node structure and | |
482 | none on some other rcu_node structure. | |
483 | ||
484 | o "egt" counts the number of times we balked because although | |
485 | there were blocked tasks, none of them were blocking the | |
486 | current grace period, whether expedited or otherwise. | |
487 | ||
488 | o "bt" counts the number of times we balked because boosting | |
489 | had already been initiated for the current grace period. | |
490 | ||
491 | o "nb" counts the number of times we balked because there | |
492 | was at least one task blocking the current non-expedited grace | |
493 | period that never had blocked. If it is already running, it | |
494 | just won't help to boost its priority! | |
495 | ||
496 | o "ny" counts the number of times we balked because it was | |
497 | not yet time to start boosting. | |
498 | ||
499 | o "nos" counts the number of times we balked for other | |
500 | reasons, e.g., the grace period ended first. | |
501 | ||
502 | ||
8e79e1f9 PM |
503 | CONFIG_TINY_RCU and CONFIG_TINY_PREEMPT_RCU debugfs Files and Formats |
504 | ||
505 | These implementations of RCU provides a single debugfs file under the | |
506 | top-level directory RCU, namely rcu/rcudata, which displays fields in | |
507 | rcu_bh_ctrlblk, rcu_sched_ctrlblk and, for CONFIG_TINY_PREEMPT_RCU, | |
508 | rcu_preempt_ctrlblk. | |
509 | ||
510 | The output of "cat rcu/rcudata" is as follows: | |
511 | ||
512 | rcu_preempt: qlen=24 gp=1097669 g197/p197/c197 tasks=... | |
513 | ttb=. btg=no ntb=184 neb=0 nnb=183 j=01f7 bt=0274 | |
514 | normal balk: nt=1097669 gt=0 bt=371 b=0 ny=25073378 nos=0 | |
515 | exp balk: bt=0 nos=0 | |
516 | rcu_sched: qlen: 0 | |
517 | rcu_bh: qlen: 0 | |
518 | ||
519 | This is split into rcu_preempt, rcu_sched, and rcu_bh sections, with the | |
520 | rcu_preempt section appearing only in CONFIG_TINY_PREEMPT_RCU builds. | |
521 | The last three lines of the rcu_preempt section appear only in | |
522 | CONFIG_RCU_BOOST kernel builds. The fields are as follows: | |
523 | ||
524 | o "qlen" is the number of RCU callbacks currently waiting either | |
525 | for an RCU grace period or waiting to be invoked. This is the | |
526 | only field present for rcu_sched and rcu_bh, due to the | |
527 | short-circuiting of grace period in those two cases. | |
528 | ||
529 | o "gp" is the number of grace periods that have completed. | |
530 | ||
531 | o "g197/p197/c197" displays the grace-period state, with the | |
532 | "g" number being the number of grace periods that have started | |
533 | (mod 256), the "p" number being the number of grace periods | |
534 | that the CPU has responded to (also mod 256), and the "c" | |
535 | number being the number of grace periods that have completed | |
536 | (once again mode 256). | |
537 | ||
538 | Why have both "gp" and "g"? Because the data flowing into | |
539 | "gp" is only present in a CONFIG_RCU_TRACE kernel. | |
540 | ||
541 | o "tasks" is a set of bits. The first bit is "T" if there are | |
542 | currently tasks that have recently blocked within an RCU | |
543 | read-side critical section, the second bit is "N" if any of the | |
544 | aforementioned tasks are blocking the current RCU grace period, | |
545 | and the third bit is "E" if any of the aforementioned tasks are | |
546 | blocking the current expedited grace period. Each bit is "." | |
547 | if the corresponding condition does not hold. | |
548 | ||
549 | o "ttb" is a single bit. It is "B" if any of the blocked tasks | |
550 | need to be priority boosted and "." otherwise. | |
551 | ||
552 | o "btg" indicates whether boosting has been carried out during | |
553 | the current grace period, with "exp" indicating that boosting | |
554 | is in progress for an expedited grace period, "no" indicating | |
555 | that boosting has not yet started for a normal grace period, | |
556 | "begun" indicating that boosting has bebug for a normal grace | |
557 | period, and "done" indicating that boosting has completed for | |
558 | a normal grace period. | |
559 | ||
560 | o "ntb" is the total number of tasks subjected to RCU priority boosting | |
561 | periods since boot. | |
562 | ||
563 | o "neb" is the number of expedited grace periods that have had | |
564 | to resort to RCU priority boosting since boot. | |
565 | ||
566 | o "nnb" is the number of normal grace periods that have had | |
567 | to resort to RCU priority boosting since boot. | |
568 | ||
90e6ac36 | 569 | o "j" is the low-order 16 bits of the jiffies counter in hexadecimal. |
8e79e1f9 | 570 | |
90e6ac36 | 571 | o "bt" is the low-order 16 bits of the value that the jiffies counter |
8e79e1f9 PM |
572 | will have at the next time that boosting is scheduled to begin. |
573 | ||
574 | o In the line beginning with "normal balk", the fields are as follows: | |
575 | ||
576 | o "nt" is the number of times that the system balked from | |
577 | boosting because there were no blocked tasks to boost. | |
578 | Note that the system will balk from boosting even if the | |
579 | grace period is overdue when the currently running task | |
580 | is looping within an RCU read-side critical section. | |
581 | There is no point in boosting in this case, because | |
582 | boosting a running task won't make it run any faster. | |
583 | ||
584 | o "gt" is the number of times that the system balked | |
585 | from boosting because, although there were blocked tasks, | |
586 | none of them were preventing the current grace period | |
587 | from completing. | |
588 | ||
589 | o "bt" is the number of times that the system balked | |
590 | from boosting because boosting was already in progress. | |
591 | ||
592 | o "b" is the number of times that the system balked from | |
593 | boosting because boosting had already completed for | |
594 | the grace period in question. | |
595 | ||
596 | o "ny" is the number of times that the system balked from | |
597 | boosting because it was not yet time to start boosting | |
598 | the grace period in question. | |
599 | ||
600 | o "nos" is the number of times that the system balked from | |
601 | boosting for inexplicable ("not otherwise specified") | |
602 | reasons. This can actually happen due to races involving | |
603 | increments of the jiffies counter. | |
604 | ||
605 | o In the line beginning with "exp balk", the fields are as follows: | |
606 | ||
607 | o "bt" is the number of times that the system balked from | |
608 | boosting because there were no blocked tasks to boost. | |
609 | ||
610 | o "nos" is the number of times that the system balked from | |
611 | boosting for inexplicable ("not otherwise specified") | |
612 | reasons. |