Paul E. McKenney | 64db4cf | 2008-12-18 21:55:32 +0100 | [diff] [blame] | 1 | CONFIG_RCU_TRACE debugfs Files and Formats |
| 2 | |
| 3 | |
Paul E. McKenney | 8e79e1f | 2010-11-04 14:31:19 -0700 | [diff] [blame] | 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. |
Paul E. McKenney | 64db4cf | 2008-12-18 21:55:32 +0100 | [diff] [blame] | 9 | |
| 10 | |
Paul E. McKenney | 8e79e1f | 2010-11-04 14:31:19 -0700 | [diff] [blame] | 11 | CONFIG_TREE_RCU and CONFIG_TREE_PREEMPT_RCU debugfs Files and Formats |
Paul E. McKenney | 64db4cf | 2008-12-18 21:55:32 +0100 | [diff] [blame] | 12 | |
Paul E. McKenney | 8e79e1f | 2010-11-04 14:31:19 -0700 | [diff] [blame] | 13 | These implementations of RCU provides five debugfs files under the |
Paul E. McKenney | 64db4cf | 2008-12-18 21:55:32 +0100 | [diff] [blame] | 14 | top-level directory RCU: rcu/rcudata (which displays fields in struct |
Paul E. McKenney | 8e79e1f | 2010-11-04 14:31:19 -0700 | [diff] [blame] | 15 | rcu_data), rcu/rcudata.csv (which is a .csv spreadsheet version of |
| 16 | rcu/rcudata), rcu/rcugp (which displays grace-period counters), |
| 17 | rcu/rcuhier (which displays the struct rcu_node hierarchy), and |
| 18 | rcu/rcu_pending (which displays counts of the reasons that the |
| 19 | rcu_pending() function decided that there was core RCU work to do). |
Paul E. McKenney | 64db4cf | 2008-12-18 21:55:32 +0100 | [diff] [blame] | 20 | |
| 21 | The output of "cat rcu/rcudata" looks as follows: |
| 22 | |
Paul E. McKenney | d6714c2 | 2009-08-22 13:56:46 -0700 | [diff] [blame] | 23 | rcu_sched: |
Paul E. McKenney | e59fb31 | 2010-09-07 10:38:22 -0700 | [diff] [blame] | 24 | 0 c=17829 g=17829 pq=1 pqc=17829 qp=0 dt=10951/1/0 df=1101 of=0 ri=36 ql=0 b=10 |
| 25 | 1 c=17829 g=17829 pq=1 pqc=17829 qp=0 dt=16117/1/0 df=1015 of=0 ri=0 ql=0 b=10 |
| 26 | 2 c=17829 g=17829 pq=1 pqc=17829 qp=0 dt=1445/1/0 df=1839 of=0 ri=0 ql=0 b=10 |
| 27 | 3 c=17829 g=17829 pq=1 pqc=17829 qp=0 dt=6681/1/0 df=1545 of=0 ri=0 ql=0 b=10 |
| 28 | 4 c=17829 g=17829 pq=1 pqc=17829 qp=0 dt=1003/1/0 df=1992 of=0 ri=0 ql=0 b=10 |
| 29 | 5 c=17829 g=17830 pq=1 pqc=17829 qp=1 dt=3887/1/0 df=3331 of=0 ri=4 ql=2 b=10 |
| 30 | 6 c=17829 g=17829 pq=1 pqc=17829 qp=0 dt=859/1/0 df=3224 of=0 ri=0 ql=0 b=10 |
| 31 | 7 c=17829 g=17830 pq=0 pqc=17829 qp=1 dt=3761/1/0 df=1818 of=0 ri=0 ql=2 b=10 |
Paul E. McKenney | 64db4cf | 2008-12-18 21:55:32 +0100 | [diff] [blame] | 32 | rcu_bh: |
Paul E. McKenney | e59fb31 | 2010-09-07 10:38:22 -0700 | [diff] [blame] | 33 | 0 c=-275 g=-275 pq=1 pqc=-275 qp=0 dt=10951/1/0 df=0 of=0 ri=0 ql=0 b=10 |
| 34 | 1 c=-275 g=-275 pq=1 pqc=-275 qp=0 dt=16117/1/0 df=13 of=0 ri=0 ql=0 b=10 |
| 35 | 2 c=-275 g=-275 pq=1 pqc=-275 qp=0 dt=1445/1/0 df=15 of=0 ri=0 ql=0 b=10 |
| 36 | 3 c=-275 g=-275 pq=1 pqc=-275 qp=0 dt=6681/1/0 df=9 of=0 ri=0 ql=0 b=10 |
| 37 | 4 c=-275 g=-275 pq=1 pqc=-275 qp=0 dt=1003/1/0 df=15 of=0 ri=0 ql=0 b=10 |
| 38 | 5 c=-275 g=-275 pq=1 pqc=-275 qp=0 dt=3887/1/0 df=15 of=0 ri=0 ql=0 b=10 |
| 39 | 6 c=-275 g=-275 pq=1 pqc=-275 qp=0 dt=859/1/0 df=15 of=0 ri=0 ql=0 b=10 |
| 40 | 7 c=-275 g=-275 pq=1 pqc=-275 qp=0 dt=3761/1/0 df=15 of=0 ri=0 ql=0 b=10 |
Paul E. McKenney | 64db4cf | 2008-12-18 21:55:32 +0100 | [diff] [blame] | 41 | |
Paul E. McKenney | bd58b43 | 2009-10-14 10:15:54 -0700 | [diff] [blame] | 42 | 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 |
| 44 | additional section for rcu_preempt. Each section has one line per CPU, |
| 45 | or eight for this 8-CPU system. The fields are as follows: |
Paul E. McKenney | 64db4cf | 2008-12-18 21:55:32 +0100 | [diff] [blame] | 46 | |
| 47 | o The number at the beginning of each line is the CPU number. |
| 48 | CPUs numbers followed by an exclamation mark are offline, |
| 49 | but have been online at least once since boot. There will be |
| 50 | no output for CPUs that have never been online, which can be |
| 51 | a good thing in the surprisingly common case where NR_CPUS is |
| 52 | substantially larger than the number of actual CPUs. |
| 53 | |
| 54 | o "c" is the count of grace periods that this CPU believes have |
| 55 | completed. CPUs in dynticks idle mode may lag quite a ways |
Paul E. McKenney | bd58b43 | 2009-10-14 10:15:54 -0700 | [diff] [blame] | 56 | behind, for example, CPU 4 under "rcu_sched" above, which has |
| 57 | slept through the past 25 RCU grace periods. It is not unusual |
| 58 | to see CPUs lagging by thousands of grace periods. |
Paul E. McKenney | 64db4cf | 2008-12-18 21:55:32 +0100 | [diff] [blame] | 59 | |
| 60 | o "g" is the count of grace periods that this CPU believes have |
| 61 | started. Again, CPUs in dynticks idle mode may lag behind. |
| 62 | If the "c" and "g" values are equal, this CPU has already |
| 63 | reported a quiescent state for the last RCU grace period that |
| 64 | it is aware of, otherwise, the CPU believes that it owes RCU a |
| 65 | quiescent state. |
| 66 | |
| 67 | o "pq" indicates that this CPU has passed through a quiescent state |
| 68 | for the current grace period. It is possible for "pq" to be |
| 69 | "1" and "c" different than "g", which indicates that although |
| 70 | the CPU has passed through a quiescent state, either (1) this |
| 71 | CPU has not yet reported that fact, (2) some other CPU has not |
| 72 | yet reported for this grace period, or (3) both. |
| 73 | |
| 74 | o "pqc" indicates which grace period the last-observed quiescent |
| 75 | state for this CPU corresponds to. This is important for handling |
| 76 | the race between CPU 0 reporting an extended dynticks-idle |
| 77 | quiescent state for CPU 1 and CPU 1 suddenly waking up and |
| 78 | reporting its own quiescent state. If CPU 1 was the last CPU |
| 79 | for the current grace period, then the CPU that loses this race |
| 80 | will attempt to incorrectly mark CPU 1 as having checked in for |
| 81 | the next grace period! |
| 82 | |
| 83 | o "qp" indicates that RCU still expects a quiescent state from |
| 84 | this CPU. |
| 85 | |
Paul E. McKenney | 64db4cf | 2008-12-18 21:55:32 +0100 | [diff] [blame] | 86 | o "dt" is the current value of the dyntick counter that is incremented |
| 87 | when entering or leaving dynticks idle state, either by the |
Paul E. McKenney | e59fb31 | 2010-09-07 10:38:22 -0700 | [diff] [blame] | 88 | scheduler or by irq. The number after the first "/" is the |
| 89 | interrupt nesting depth when in dyntick-idle state, or one |
| 90 | greater than the interrupt-nesting depth otherwise. The number |
| 91 | after the second "/" is the NMI nesting depth. |
Paul E. McKenney | 64db4cf | 2008-12-18 21:55:32 +0100 | [diff] [blame] | 92 | |
| 93 | This field is displayed only for CONFIG_NO_HZ kernels. |
| 94 | |
| 95 | o "df" is the number of times that some other CPU has forced a |
| 96 | quiescent state on behalf of this CPU due to this CPU being in |
| 97 | dynticks-idle state. |
| 98 | |
| 99 | This field is displayed only for CONFIG_NO_HZ kernels. |
| 100 | |
| 101 | o "of" is the number of times that some other CPU has forced a |
| 102 | quiescent state on behalf of this CPU due to this CPU being |
| 103 | offline. In a perfect world, this might neve happen, but it |
| 104 | turns out that offlining and onlining a CPU can take several grace |
| 105 | periods, and so there is likely to be an extended period of time |
| 106 | when RCU believes that the CPU is online when it really is not. |
| 107 | Please note that erring in the other direction (RCU believing a |
| 108 | CPU is offline when it is really alive and kicking) is a fatal |
| 109 | error, so it makes sense to err conservatively. |
| 110 | |
| 111 | o "ri" is the number of times that RCU has seen fit to send a |
| 112 | reschedule IPI to this CPU in order to get it to report a |
| 113 | quiescent state. |
| 114 | |
| 115 | o "ql" is the number of RCU callbacks currently residing on |
| 116 | this CPU. This is the total number of callbacks, regardless |
| 117 | of what state they are in (new, waiting for grace period to |
| 118 | start, waiting for grace period to end, ready to invoke). |
| 119 | |
| 120 | o "b" is the batch limit for this CPU. If more than this number |
| 121 | of RCU callbacks is ready to invoke, then the remainder will |
| 122 | be deferred. |
| 123 | |
Paul E. McKenney | 269dcc1 | 2010-09-07 14:23:09 -0700 | [diff] [blame] | 124 | o "ci" is the number of RCU callbacks that have been invoked for |
| 125 | this CPU. Note that ci+ql is the number of callbacks that have |
| 126 | been registered in absence of CPU-hotplug activity. |
| 127 | |
| 128 | o "co" is the number of RCU callbacks that have been orphaned due to |
Paul E. McKenney | 2d999e0 | 2010-10-20 12:06:18 -0700 | [diff] [blame] | 129 | this CPU going offline. These orphaned callbacks have been moved |
| 130 | to an arbitrarily chosen online CPU. |
Paul E. McKenney | 269dcc1 | 2010-09-07 14:23:09 -0700 | [diff] [blame] | 131 | |
| 132 | o "ca" is the number of RCU callbacks that have been adopted due to |
| 133 | other CPUs going offline. Note that ci+co-ca+ql is the number of |
| 134 | RCU callbacks registered on this CPU. |
| 135 | |
Paul E. McKenney | 6fd9b3a | 2009-04-13 21:31:18 -0700 | [diff] [blame] | 136 | There is also an rcu/rcudata.csv file with the same information in |
| 137 | comma-separated-variable spreadsheet format. |
| 138 | |
Paul E. McKenney | 64db4cf | 2008-12-18 21:55:32 +0100 | [diff] [blame] | 139 | |
| 140 | The output of "cat rcu/rcugp" looks as follows: |
| 141 | |
Paul E. McKenney | d6714c2 | 2009-08-22 13:56:46 -0700 | [diff] [blame] | 142 | rcu_sched: completed=33062 gpnum=33063 |
Paul E. McKenney | 64db4cf | 2008-12-18 21:55:32 +0100 | [diff] [blame] | 143 | rcu_bh: completed=464 gpnum=464 |
| 144 | |
Paul E. McKenney | bd58b43 | 2009-10-14 10:15:54 -0700 | [diff] [blame] | 145 | Again, this output is for both "rcu_sched" and "rcu_bh". Note that |
| 146 | kernels built with CONFIG_TREE_PREEMPT_RCU will have an additional |
| 147 | "rcu_preempt" line. The fields are taken from the rcu_state structure, |
| 148 | and are as follows: |
Paul E. McKenney | 64db4cf | 2008-12-18 21:55:32 +0100 | [diff] [blame] | 149 | |
| 150 | o "completed" is the number of grace periods that have completed. |
| 151 | It is comparable to the "c" field from rcu/rcudata in that a |
| 152 | CPU whose "c" field matches the value of "completed" is aware |
| 153 | that the corresponding RCU grace period has completed. |
| 154 | |
| 155 | o "gpnum" is the number of grace periods that have started. It is |
| 156 | comparable to the "g" field from rcu/rcudata in that a CPU |
| 157 | whose "g" field matches the value of "gpnum" is aware that the |
| 158 | corresponding RCU grace period has started. |
| 159 | |
| 160 | If these two fields are equal (as they are for "rcu_bh" above), |
| 161 | then there is no grace period in progress, in other words, RCU |
| 162 | is idle. On the other hand, if the two fields differ (as they |
Paul E. McKenney | bd58b43 | 2009-10-14 10:15:54 -0700 | [diff] [blame] | 163 | do for "rcu_sched" above), then an RCU grace period is in progress. |
Paul E. McKenney | 64db4cf | 2008-12-18 21:55:32 +0100 | [diff] [blame] | 164 | |
| 165 | |
| 166 | The output of "cat rcu/rcuhier" looks as follows, with very long lines: |
| 167 | |
Paul E. McKenney | 2d999e0 | 2010-10-20 12:06:18 -0700 | [diff] [blame] | 168 | c=6902 g=6903 s=2 jfq=3 j=72c7 nfqs=13142/nfqsng=0(13142) fqlh=6 |
Paul E. McKenney | 12f5f52 | 2010-11-29 21:56:39 -0800 | [diff] [blame^] | 169 | 1/1 ..>. 0:127 ^0 |
| 170 | 3/3 ..>. 0:35 ^0 0/0 ..>. 36:71 ^1 0/0 ..>. 72:107 ^2 0/0 ..>. 108:127 ^3 |
| 171 | 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 |
Paul E. McKenney | 64db4cf | 2008-12-18 21:55:32 +0100 | [diff] [blame] | 172 | rcu_bh: |
Paul E. McKenney | 2d999e0 | 2010-10-20 12:06:18 -0700 | [diff] [blame] | 173 | c=-226 g=-226 s=1 jfq=-5701 j=72c7 nfqs=88/nfqsng=0(88) fqlh=0 |
Paul E. McKenney | 12f5f52 | 2010-11-29 21:56:39 -0800 | [diff] [blame^] | 174 | 0/1 ..>. 0:127 ^0 |
| 175 | 0/3 ..>. 0:35 ^0 0/0 ..>. 36:71 ^1 0/0 ..>. 72:107 ^2 0/0 ..>. 108:127 ^3 |
| 176 | 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 |
Paul E. McKenney | 64db4cf | 2008-12-18 21:55:32 +0100 | [diff] [blame] | 177 | |
Paul E. McKenney | bd58b43 | 2009-10-14 10:15:54 -0700 | [diff] [blame] | 178 | This is once again split into "rcu_sched" and "rcu_bh" portions, |
| 179 | and CONFIG_TREE_PREEMPT_RCU kernels will again have an additional |
| 180 | "rcu_preempt" section. The fields are as follows: |
Paul E. McKenney | 64db4cf | 2008-12-18 21:55:32 +0100 | [diff] [blame] | 181 | |
| 182 | o "c" is exactly the same as "completed" under rcu/rcugp. |
| 183 | |
| 184 | o "g" is exactly the same as "gpnum" under rcu/rcugp. |
| 185 | |
| 186 | o "s" is the "signaled" state that drives force_quiescent_state()'s |
| 187 | state machine. |
| 188 | |
| 189 | o "jfq" is the number of jiffies remaining for this grace period |
| 190 | before force_quiescent_state() is invoked to help push things |
Paul E. McKenney | 269dcc1 | 2010-09-07 14:23:09 -0700 | [diff] [blame] | 191 | along. Note that CPUs in dyntick-idle mode throughout the grace |
Paul E. McKenney | 64db4cf | 2008-12-18 21:55:32 +0100 | [diff] [blame] | 192 | period will not report on their own, but rather must be check by |
| 193 | some other CPU via force_quiescent_state(). |
| 194 | |
| 195 | o "j" is the low-order four hex digits of the jiffies counter. |
| 196 | Yes, Paul did run into a number of problems that turned out to |
| 197 | be due to the jiffies counter no longer counting. Why do you ask? |
| 198 | |
| 199 | o "nfqs" is the number of calls to force_quiescent_state() since |
| 200 | boot. |
| 201 | |
| 202 | o "nfqsng" is the number of useless calls to force_quiescent_state(), |
| 203 | where there wasn't actually a grace period active. This can |
| 204 | happen due to races. The number in parentheses is the difference |
| 205 | between "nfqs" and "nfqsng", or the number of times that |
| 206 | force_quiescent_state() actually did some real work. |
| 207 | |
| 208 | o "fqlh" is the number of calls to force_quiescent_state() that |
| 209 | exited immediately (without even being counted in nfqs above) |
| 210 | due to contention on ->fqslock. |
| 211 | |
| 212 | o Each element of the form "1/1 0:127 ^0" represents one struct |
| 213 | rcu_node. Each line represents one level of the hierarchy, from |
| 214 | root to leaves. It is best to think of the rcu_data structures |
| 215 | as forming yet another level after the leaves. Note that there |
| 216 | might be either one, two, or three levels of rcu_node structures, |
| 217 | depending on the relationship between CONFIG_RCU_FANOUT and |
| 218 | CONFIG_NR_CPUS. |
Paul E. McKenney | 0edf1a6 | 2009-10-14 10:15:59 -0700 | [diff] [blame] | 219 | |
Paul E. McKenney | 64db4cf | 2008-12-18 21:55:32 +0100 | [diff] [blame] | 220 | o The numbers separated by the "/" are the qsmask followed |
| 221 | by the qsmaskinit. The qsmask will have one bit |
| 222 | set for each entity in the next lower level that |
| 223 | has not yet checked in for the current grace period. |
| 224 | The qsmaskinit will have one bit for each entity that is |
| 225 | currently expected to check in during each grace period. |
| 226 | The value of qsmaskinit is assigned to that of qsmask |
| 227 | at the beginning of each grace period. |
| 228 | |
Paul E. McKenney | bd58b43 | 2009-10-14 10:15:54 -0700 | [diff] [blame] | 229 | For example, for "rcu_sched", the qsmask of the first |
| 230 | entry of the lowest level is 0x14, meaning that we |
| 231 | are still waiting for CPUs 2 and 4 to check in for the |
| 232 | current grace period. |
Paul E. McKenney | 64db4cf | 2008-12-18 21:55:32 +0100 | [diff] [blame] | 233 | |
Paul E. McKenney | 0edf1a6 | 2009-10-14 10:15:59 -0700 | [diff] [blame] | 234 | o The characters separated by the ">" indicate the state |
Paul E. McKenney | 12f5f52 | 2010-11-29 21:56:39 -0800 | [diff] [blame^] | 235 | of the blocked-tasks lists. A "G" preceding the ">" |
Paul E. McKenney | 0edf1a6 | 2009-10-14 10:15:59 -0700 | [diff] [blame] | 236 | indicates that at least one task blocked in an RCU |
| 237 | read-side critical section blocks the current grace |
Paul E. McKenney | 12f5f52 | 2010-11-29 21:56:39 -0800 | [diff] [blame^] | 238 | period, while a "E" preceding the ">" indicates that |
| 239 | at least one task blocked in an RCU read-side critical |
| 240 | section blocks the current expedited grace period. |
| 241 | A "T" character following the ">" indicates that at |
| 242 | least one task is blocked within an RCU read-side |
| 243 | critical section, regardless of whether any current |
| 244 | grace period (expedited or normal) is inconvenienced. |
| 245 | A "." character appears if the corresponding condition |
| 246 | does not hold, so that "..>." indicates that no tasks |
| 247 | are blocked. In contrast, "GE>T" indicates maximal |
| 248 | inconvenience from blocked tasks. |
Paul E. McKenney | 0edf1a6 | 2009-10-14 10:15:59 -0700 | [diff] [blame] | 249 | |
Paul E. McKenney | 64db4cf | 2008-12-18 21:55:32 +0100 | [diff] [blame] | 250 | o The numbers separated by the ":" are the range of CPUs |
| 251 | served by this struct rcu_node. This can be helpful |
| 252 | in working out how the hierarchy is wired together. |
| 253 | |
| 254 | For example, the first entry at the lowest level shows |
| 255 | "0:5", indicating that it covers CPUs 0 through 5. |
| 256 | |
| 257 | o The number after the "^" indicates the bit in the |
| 258 | next higher level rcu_node structure that this |
| 259 | rcu_node structure corresponds to. |
| 260 | |
| 261 | For example, the first entry at the lowest level shows |
| 262 | "^0", indicating that it corresponds to bit zero in |
| 263 | the first entry at the middle level. |
Paul E. McKenney | 6fd9b3a | 2009-04-13 21:31:18 -0700 | [diff] [blame] | 264 | |
| 265 | |
| 266 | The output of "cat rcu/rcu_pending" looks as follows: |
| 267 | |
Paul E. McKenney | d6714c2 | 2009-08-22 13:56:46 -0700 | [diff] [blame] | 268 | rcu_sched: |
Paul E. McKenney | d21670a | 2010-04-14 17:39:26 -0700 | [diff] [blame] | 269 | 0 np=255892 qsp=53936 rpq=85 cbr=0 cng=14417 gpc=10033 gps=24320 nf=6445 nn=146741 |
| 270 | 1 np=261224 qsp=54638 rpq=33 cbr=0 cng=25723 gpc=16310 gps=2849 nf=5912 nn=155792 |
| 271 | 2 np=237496 qsp=49664 rpq=23 cbr=0 cng=2762 gpc=45478 gps=1762 nf=1201 nn=136629 |
| 272 | 3 np=236249 qsp=48766 rpq=98 cbr=0 cng=286 gpc=48049 gps=1218 nf=207 nn=137723 |
| 273 | 4 np=221310 qsp=46850 rpq=7 cbr=0 cng=26 gpc=43161 gps=4634 nf=3529 nn=123110 |
| 274 | 5 np=237332 qsp=48449 rpq=9 cbr=0 cng=54 gpc=47920 gps=3252 nf=201 nn=137456 |
| 275 | 6 np=219995 qsp=46718 rpq=12 cbr=0 cng=50 gpc=42098 gps=6093 nf=4202 nn=120834 |
| 276 | 7 np=249893 qsp=49390 rpq=42 cbr=0 cng=72 gpc=38400 gps=17102 nf=41 nn=144888 |
Paul E. McKenney | 6fd9b3a | 2009-04-13 21:31:18 -0700 | [diff] [blame] | 277 | rcu_bh: |
Paul E. McKenney | d21670a | 2010-04-14 17:39:26 -0700 | [diff] [blame] | 278 | 0 np=146741 qsp=1419 rpq=6 cbr=0 cng=6 gpc=0 gps=0 nf=2 nn=145314 |
| 279 | 1 np=155792 qsp=12597 rpq=3 cbr=0 cng=0 gpc=4 gps=8 nf=3 nn=143180 |
| 280 | 2 np=136629 qsp=18680 rpq=1 cbr=0 cng=0 gpc=7 gps=6 nf=0 nn=117936 |
| 281 | 3 np=137723 qsp=2843 rpq=0 cbr=0 cng=0 gpc=10 gps=7 nf=0 nn=134863 |
| 282 | 4 np=123110 qsp=12433 rpq=0 cbr=0 cng=0 gpc=4 gps=2 nf=0 nn=110671 |
| 283 | 5 np=137456 qsp=4210 rpq=1 cbr=0 cng=0 gpc=6 gps=5 nf=0 nn=133235 |
| 284 | 6 np=120834 qsp=9902 rpq=2 cbr=0 cng=0 gpc=6 gps=3 nf=2 nn=110921 |
| 285 | 7 np=144888 qsp=26336 rpq=0 cbr=0 cng=0 gpc=8 gps=2 nf=0 nn=118542 |
Paul E. McKenney | 6fd9b3a | 2009-04-13 21:31:18 -0700 | [diff] [blame] | 286 | |
Paul E. McKenney | bd58b43 | 2009-10-14 10:15:54 -0700 | [diff] [blame] | 287 | As always, this is once again split into "rcu_sched" and "rcu_bh" |
| 288 | portions, with CONFIG_TREE_PREEMPT_RCU kernels having an additional |
| 289 | "rcu_preempt" section. The fields are as follows: |
Paul E. McKenney | 6fd9b3a | 2009-04-13 21:31:18 -0700 | [diff] [blame] | 290 | |
| 291 | o "np" is the number of times that __rcu_pending() has been invoked |
| 292 | for the corresponding flavor of RCU. |
| 293 | |
| 294 | o "qsp" is the number of times that the RCU was waiting for a |
| 295 | quiescent state from this CPU. |
| 296 | |
Paul E. McKenney | d21670a | 2010-04-14 17:39:26 -0700 | [diff] [blame] | 297 | o "rpq" is the number of times that the CPU had passed through |
| 298 | a quiescent state, but not yet reported it to RCU. |
| 299 | |
Paul E. McKenney | 6fd9b3a | 2009-04-13 21:31:18 -0700 | [diff] [blame] | 300 | o "cbr" is the number of times that this CPU had RCU callbacks |
| 301 | that had passed through a grace period, and were thus ready |
| 302 | to be invoked. |
| 303 | |
| 304 | o "cng" is the number of times that this CPU needed another |
| 305 | grace period while RCU was idle. |
| 306 | |
| 307 | o "gpc" is the number of times that an old grace period had |
| 308 | completed, but this CPU was not yet aware of it. |
| 309 | |
| 310 | o "gps" is the number of times that a new grace period had started, |
| 311 | but this CPU was not yet aware of it. |
| 312 | |
| 313 | o "nf" is the number of times that this CPU suspected that the |
| 314 | current grace period had run for too long, and thus needed to |
| 315 | be forced. |
| 316 | |
| 317 | Please note that "forcing" consists of sending resched IPIs |
| 318 | to holdout CPUs. If that CPU really still is in an old RCU |
| 319 | read-side critical section, then we really do have to wait for it. |
| 320 | The assumption behing "forcing" is that the CPU is not still in |
| 321 | an old RCU read-side critical section, but has not yet responded |
| 322 | for some other reason. |
| 323 | |
| 324 | o "nn" is the number of times that this CPU needed nothing. Alert |
| 325 | readers will note that the rcu "nn" number for a given CPU very |
| 326 | closely matches the rcu_bh "np" number for that same CPU. This |
| 327 | is due to short-circuit evaluation in rcu_pending(). |
Paul E. McKenney | 8e79e1f | 2010-11-04 14:31:19 -0700 | [diff] [blame] | 328 | |
| 329 | |
| 330 | CONFIG_TINY_RCU and CONFIG_TINY_PREEMPT_RCU debugfs Files and Formats |
| 331 | |
| 332 | These implementations of RCU provides a single debugfs file under the |
| 333 | top-level directory RCU, namely rcu/rcudata, which displays fields in |
| 334 | rcu_bh_ctrlblk, rcu_sched_ctrlblk and, for CONFIG_TINY_PREEMPT_RCU, |
| 335 | rcu_preempt_ctrlblk. |
| 336 | |
| 337 | The output of "cat rcu/rcudata" is as follows: |
| 338 | |
| 339 | rcu_preempt: qlen=24 gp=1097669 g197/p197/c197 tasks=... |
| 340 | ttb=. btg=no ntb=184 neb=0 nnb=183 j=01f7 bt=0274 |
| 341 | normal balk: nt=1097669 gt=0 bt=371 b=0 ny=25073378 nos=0 |
| 342 | exp balk: bt=0 nos=0 |
| 343 | rcu_sched: qlen: 0 |
| 344 | rcu_bh: qlen: 0 |
| 345 | |
| 346 | This is split into rcu_preempt, rcu_sched, and rcu_bh sections, with the |
| 347 | rcu_preempt section appearing only in CONFIG_TINY_PREEMPT_RCU builds. |
| 348 | The last three lines of the rcu_preempt section appear only in |
| 349 | CONFIG_RCU_BOOST kernel builds. The fields are as follows: |
| 350 | |
| 351 | o "qlen" is the number of RCU callbacks currently waiting either |
| 352 | for an RCU grace period or waiting to be invoked. This is the |
| 353 | only field present for rcu_sched and rcu_bh, due to the |
| 354 | short-circuiting of grace period in those two cases. |
| 355 | |
| 356 | o "gp" is the number of grace periods that have completed. |
| 357 | |
| 358 | o "g197/p197/c197" displays the grace-period state, with the |
| 359 | "g" number being the number of grace periods that have started |
| 360 | (mod 256), the "p" number being the number of grace periods |
| 361 | that the CPU has responded to (also mod 256), and the "c" |
| 362 | number being the number of grace periods that have completed |
| 363 | (once again mode 256). |
| 364 | |
| 365 | Why have both "gp" and "g"? Because the data flowing into |
| 366 | "gp" is only present in a CONFIG_RCU_TRACE kernel. |
| 367 | |
| 368 | o "tasks" is a set of bits. The first bit is "T" if there are |
| 369 | currently tasks that have recently blocked within an RCU |
| 370 | read-side critical section, the second bit is "N" if any of the |
| 371 | aforementioned tasks are blocking the current RCU grace period, |
| 372 | and the third bit is "E" if any of the aforementioned tasks are |
| 373 | blocking the current expedited grace period. Each bit is "." |
| 374 | if the corresponding condition does not hold. |
| 375 | |
| 376 | o "ttb" is a single bit. It is "B" if any of the blocked tasks |
| 377 | need to be priority boosted and "." otherwise. |
| 378 | |
| 379 | o "btg" indicates whether boosting has been carried out during |
| 380 | the current grace period, with "exp" indicating that boosting |
| 381 | is in progress for an expedited grace period, "no" indicating |
| 382 | that boosting has not yet started for a normal grace period, |
| 383 | "begun" indicating that boosting has bebug for a normal grace |
| 384 | period, and "done" indicating that boosting has completed for |
| 385 | a normal grace period. |
| 386 | |
| 387 | o "ntb" is the total number of tasks subjected to RCU priority boosting |
| 388 | periods since boot. |
| 389 | |
| 390 | o "neb" is the number of expedited grace periods that have had |
| 391 | to resort to RCU priority boosting since boot. |
| 392 | |
| 393 | o "nnb" is the number of normal grace periods that have had |
| 394 | to resort to RCU priority boosting since boot. |
| 395 | |
| 396 | o "j" is the low-order 12 bits of the jiffies counter in hexadecimal. |
| 397 | |
| 398 | o "bt" is the low-order 12 bits of the value that the jiffies counter |
| 399 | will have at the next time that boosting is scheduled to begin. |
| 400 | |
| 401 | o In the line beginning with "normal balk", the fields are as follows: |
| 402 | |
| 403 | o "nt" is the number of times that the system balked from |
| 404 | boosting because there were no blocked tasks to boost. |
| 405 | Note that the system will balk from boosting even if the |
| 406 | grace period is overdue when the currently running task |
| 407 | is looping within an RCU read-side critical section. |
| 408 | There is no point in boosting in this case, because |
| 409 | boosting a running task won't make it run any faster. |
| 410 | |
| 411 | o "gt" is the number of times that the system balked |
| 412 | from boosting because, although there were blocked tasks, |
| 413 | none of them were preventing the current grace period |
| 414 | from completing. |
| 415 | |
| 416 | o "bt" is the number of times that the system balked |
| 417 | from boosting because boosting was already in progress. |
| 418 | |
| 419 | o "b" is the number of times that the system balked from |
| 420 | boosting because boosting had already completed for |
| 421 | the grace period in question. |
| 422 | |
| 423 | o "ny" is the number of times that the system balked from |
| 424 | boosting because it was not yet time to start boosting |
| 425 | the grace period in question. |
| 426 | |
| 427 | o "nos" is the number of times that the system balked from |
| 428 | boosting for inexplicable ("not otherwise specified") |
| 429 | reasons. This can actually happen due to races involving |
| 430 | increments of the jiffies counter. |
| 431 | |
| 432 | o In the line beginning with "exp balk", the fields are as follows: |
| 433 | |
| 434 | o "bt" is the number of times that the system balked from |
| 435 | boosting because there were no blocked tasks to boost. |
| 436 | |
| 437 | o "nos" is the number of times that the system balked from |
| 438 | boosting for inexplicable ("not otherwise specified") |
| 439 | reasons. |