]>
Commit | Line | Data |
---|---|---|
4c54005c PM |
1 | Using RCU's CPU Stall Detector |
2 | ||
a00e0d71 PM |
3 | The rcu_cpu_stall_suppress module parameter enables RCU's CPU stall |
4 | detector, which detects conditions that unduly delay RCU grace periods. | |
5 | This module parameter enables CPU stall detection by default, but | |
6 | may be overridden via boot-time parameter or at runtime via sysfs. | |
7 | The stall detector's idea of what constitutes "unduly delayed" is | |
8 | controlled by a set of kernel configuration variables and cpp macros: | |
4c54005c | 9 | |
a00e0d71 | 10 | CONFIG_RCU_CPU_STALL_TIMEOUT |
4c54005c | 11 | |
a00e0d71 PM |
12 | This kernel configuration parameter defines the period of time |
13 | that RCU will wait from the beginning of a grace period until it | |
14 | issues an RCU CPU stall warning. This time period is normally | |
24cd7fd0 | 15 | sixty seconds. |
4c54005c | 16 | |
24cd7fd0 PM |
17 | This configuration parameter may be changed at runtime via the |
18 | /sys/module/rcutree/parameters/rcu_cpu_stall_timeout, however | |
19 | this parameter is checked only at the beginning of a cycle. | |
20 | So if you are 30 seconds into a 70-second stall, setting this | |
21 | sysfs parameter to (say) five will shorten the timeout for the | |
22 | -next- stall, or the following warning for the current stall | |
23 | (assuming the stall lasts long enough). It will not affect the | |
24 | timing of the next warning for the current stall. | |
4c54005c | 25 | |
24cd7fd0 PM |
26 | Stall-warning messages may be enabled and disabled completely via |
27 | /sys/module/rcutree/parameters/rcu_cpu_stall_suppress. | |
28 | ||
29 | CONFIG_RCU_CPU_STALL_VERBOSE | |
30 | ||
31 | This kernel configuration parameter causes the stall warning to | |
32 | also dump the stacks of any tasks that are blocking the current | |
33 | RCU-preempt grace period. | |
34 | ||
35 | RCU_CPU_STALL_INFO | |
36 | ||
37 | This kernel configuration parameter causes the stall warning to | |
38 | print out additional per-CPU diagnostic information, including | |
39 | information on scheduling-clock ticks and RCU's idle-CPU tracking. | |
40 | ||
41 | RCU_STALL_DELAY_DELTA | |
42 | ||
43 | Although the lockdep facility is extremely useful, it does add | |
44 | some overhead. Therefore, under CONFIG_PROVE_RCU, the | |
45 | RCU_STALL_DELAY_DELTA macro allows five extra seconds before | |
46 | giving an RCU CPU stall warning message. | |
4c54005c PM |
47 | |
48 | RCU_STALL_RAT_DELAY | |
49 | ||
f1d507be PM |
50 | The CPU stall detector tries to make the offending CPU print its |
51 | own warnings, as this often gives better-quality stack traces. | |
52 | However, if the offending CPU does not detect its own stall in | |
53 | the number of jiffies specified by RCU_STALL_RAT_DELAY, then | |
54 | some other CPU will complain. This delay is normally set to | |
55 | two jiffies. | |
4c54005c | 56 | |
f1d507be PM |
57 | When a CPU detects that it is stalling, it will print a message similar |
58 | to the following: | |
59 | ||
60 | INFO: rcu_sched_state detected stall on CPU 5 (t=2500 jiffies) | |
61 | ||
62 | This message indicates that CPU 5 detected that it was causing a stall, | |
63 | and that the stall was affecting RCU-sched. This message will normally be | |
64 | followed by a stack dump of the offending CPU. On TREE_RCU kernel builds, | |
65 | RCU and RCU-sched are implemented by the same underlying mechanism, | |
66 | while on TREE_PREEMPT_RCU kernel builds, RCU is instead implemented | |
67 | by rcu_preempt_state. | |
68 | ||
69 | On the other hand, if the offending CPU fails to print out a stall-warning | |
70 | message quickly enough, some other CPU will print a message similar to | |
71 | the following: | |
72 | ||
73 | INFO: rcu_bh_state detected stalls on CPUs/tasks: { 3 5 } (detected by 2, 2502 jiffies) | |
74 | ||
75 | This message indicates that CPU 2 detected that CPUs 3 and 5 were both | |
76 | causing stalls, and that the stall was affecting RCU-bh. This message | |
77 | will normally be followed by stack dumps for each CPU. Please note that | |
78 | TREE_PREEMPT_RCU builds can be stalled by tasks as well as by CPUs, | |
79 | and that the tasks will be indicated by PID, for example, "P3421". | |
80 | It is even possible for a rcu_preempt_state stall to be caused by both | |
81 | CPUs -and- tasks, in which case the offending CPUs and tasks will all | |
82 | be called out in the list. | |
83 | ||
84 | Finally, if the grace period ends just as the stall warning starts | |
85 | printing, there will be a spurious stall-warning message: | |
86 | ||
87 | INFO: rcu_bh_state detected stalls on CPUs/tasks: { } (detected by 4, 2502 jiffies) | |
88 | ||
89 | This is rare, but does happen from time to time in real life. | |
90 | ||
24cd7fd0 PM |
91 | If the CONFIG_RCU_CPU_STALL_INFO kernel configuration parameter is set, |
92 | more information is printed with the stall-warning message, for example: | |
93 | ||
94 | INFO: rcu_preempt detected stall on CPU | |
95 | 0: (63959 ticks this GP) idle=241/3fffffffffffffff/0 | |
96 | (t=65000 jiffies) | |
97 | ||
98 | In kernels with CONFIG_RCU_FAST_NO_HZ, even more information is | |
99 | printed: | |
100 | ||
101 | INFO: rcu_preempt detected stall on CPU | |
86f343b5 | 102 | 0: (64628 ticks this GP) idle=dd5/3fffffffffffffff/0 drain=0 . timer not pending |
24cd7fd0 PM |
103 | (t=65000 jiffies) |
104 | ||
105 | The "(64628 ticks this GP)" indicates that this CPU has taken more | |
106 | than 64,000 scheduling-clock interrupts during the current stalled | |
107 | grace period. If the CPU was not yet aware of the current grace | |
108 | period (for example, if it was offline), then this part of the message | |
109 | indicates how many grace periods behind the CPU is. | |
110 | ||
111 | The "idle=" portion of the message prints the dyntick-idle state. | |
112 | The hex number before the first "/" is the low-order 12 bits of the | |
113 | dynticks counter, which will have an even-numbered value if the CPU is | |
114 | in dyntick-idle mode and an odd-numbered value otherwise. The hex | |
115 | number between the two "/"s is the value of the nesting, which will | |
116 | be a small positive number if in the idle loop and a very large positive | |
117 | number (as shown above) otherwise. | |
118 | ||
86f343b5 PM |
119 | For CONFIG_RCU_FAST_NO_HZ kernels, the "drain=0" indicates that the CPU is |
120 | not in the process of trying to force itself into dyntick-idle state, the | |
121 | "." indicates that the CPU has not given up forcing RCU into dyntick-idle | |
122 | mode (it would be "H" otherwise), and the "timer not pending" indicates | |
123 | that the CPU has not recently forced RCU into dyntick-idle mode (it | |
124 | would otherwise indicate the number of microseconds remaining in this | |
125 | forced state). | |
24cd7fd0 PM |
126 | |
127 | ||
128 | Multiple Warnings From One Stall | |
129 | ||
130 | If a stall lasts long enough, multiple stall-warning messages will be | |
131 | printed for it. The second and subsequent messages are printed at | |
132 | longer intervals, so that the time between (say) the first and second | |
133 | message will be about three times the interval between the beginning | |
134 | of the stall and the first message. | |
135 | ||
136 | ||
137 | What Causes RCU CPU Stall Warnings? | |
138 | ||
f1d507be PM |
139 | So your kernel printed an RCU CPU stall warning. The next question is |
140 | "What caused it?" The following problems can result in RCU CPU stall | |
141 | warnings: | |
4c54005c PM |
142 | |
143 | o A CPU looping in an RCU read-side critical section. | |
144 | ||
f1d507be PM |
145 | o A CPU looping with interrupts disabled. This condition can |
146 | result in RCU-sched and RCU-bh stalls. | |
4c54005c | 147 | |
f1d507be PM |
148 | o A CPU looping with preemption disabled. This condition can |
149 | result in RCU-sched stalls and, if ksoftirqd is in use, RCU-bh | |
150 | stalls. | |
151 | ||
152 | o A CPU looping with bottom halves disabled. This condition can | |
153 | result in RCU-sched and RCU-bh stalls. | |
4c54005c PM |
154 | |
155 | o For !CONFIG_PREEMPT kernels, a CPU looping anywhere in the kernel | |
156 | without invoking schedule(). | |
157 | ||
2c96c775 PM |
158 | o A CPU-bound real-time task in a CONFIG_PREEMPT kernel, which might |
159 | happen to preempt a low-priority task in the middle of an RCU | |
160 | read-side critical section. This is especially damaging if | |
161 | that low-priority task is not permitted to run on any other CPU, | |
162 | in which case the next RCU grace period can never complete, which | |
163 | will eventually cause the system to run out of memory and hang. | |
164 | While the system is in the process of running itself out of | |
165 | memory, you might see stall-warning messages. | |
166 | ||
167 | o A CPU-bound real-time task in a CONFIG_PREEMPT_RT kernel that | |
168 | is running at a higher priority than the RCU softirq threads. | |
169 | This will prevent RCU callbacks from ever being invoked, | |
170 | and in a CONFIG_TREE_PREEMPT_RCU kernel will further prevent | |
171 | RCU grace periods from ever completing. Either way, the | |
172 | system will eventually run out of memory and hang. In the | |
173 | CONFIG_TREE_PREEMPT_RCU case, you might see stall-warning | |
174 | messages. | |
175 | ||
2c01531f PM |
176 | o A hardware or software issue shuts off the scheduler-clock |
177 | interrupt on a CPU that is not in dyntick-idle mode. This | |
178 | problem really has happened, and seems to be most likely to | |
179 | result in RCU CPU stall warnings for CONFIG_NO_HZ=n kernels. | |
180 | ||
4c54005c PM |
181 | o A bug in the RCU implementation. |
182 | ||
183 | o A hardware failure. This is quite unlikely, but has occurred | |
f1d507be | 184 | at least once in real life. A CPU failed in a running system, |
4c54005c PM |
185 | becoming unresponsive, but not causing an immediate crash. |
186 | This resulted in a series of RCU CPU stall warnings, eventually | |
187 | leading the realization that the CPU had failed. | |
188 | ||
9ceae0e2 PM |
189 | The RCU, RCU-sched, and RCU-bh implementations have CPU stall warning. |
190 | SRCU does not have its own CPU stall warnings, but its calls to | |
191 | synchronize_sched() will result in RCU-sched detecting RCU-sched-related | |
192 | CPU stalls. Please note that RCU only detects CPU stalls when there is | |
193 | a grace period in progress. No grace period, no CPU stall warnings. | |
f1d507be PM |
194 | |
195 | To diagnose the cause of the stall, inspect the stack traces. | |
196 | The offending function will usually be near the top of the stack. | |
197 | If you have a series of stall warnings from a single extended stall, | |
198 | comparing the stack traces can often help determine where the stall | |
199 | is occurring, which will usually be in the function nearest the top of | |
200 | that portion of the stack which remains the same from trace to trace. | |
201 | If you can reliably trigger the stall, ftrace can be quite helpful. | |
4c54005c | 202 | |
24cd7fd0 PM |
203 | RCU bugs can often be debugged with the help of CONFIG_RCU_TRACE |
204 | and with RCU's event tracing. |