1 | #ifndef MYSQL_SERVICE_DEBUG_SYNC_INCLUDED |
2 | /* Copyright (c) 2009, 2010, Oracle and/or its affiliates. |
3 | Copyright (c) 2012, Monty Program Ab |
4 | |
5 | This program is free software; you can redistribute it and/or modify |
6 | it under the terms of the GNU General Public License as published by |
7 | the Free Software Foundation; version 2 of the License. |
8 | |
9 | This program is distributed in the hope that it will be useful, |
10 | but WITHOUT ANY WARRANTY; without even the implied warranty of |
11 | MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the |
12 | GNU General Public License for more details. |
13 | |
14 | You should have received a copy of the GNU General Public License |
15 | along with this program; if not, write to the Free Software |
16 | Foundation, Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA */ |
17 | |
18 | /** |
19 | @file |
20 | == Debug Sync Facility == |
21 | |
22 | The Debug Sync Facility allows placement of synchronization points in |
23 | the server code by using the DEBUG_SYNC macro: |
24 | |
25 | open_tables(...) |
26 | |
27 | DEBUG_SYNC(thd, "after_open_tables"); |
28 | |
29 | lock_tables(...) |
30 | |
31 | When activated, a sync point can |
32 | |
33 | - Emit a signal and/or |
34 | - Wait for a signal |
35 | |
36 | Nomenclature: |
37 | |
38 | - signal: A value of a global variable that persists |
39 | until overwritten by a new signal. The global |
40 | variable can also be seen as a "signal post" |
41 | or "flag mast". Then the signal is what is |
42 | attached to the "signal post" or "flag mast". |
43 | |
44 | - emit a signal: Assign the value (the signal) to the global |
45 | variable ("set a flag") and broadcast a |
46 | global condition to wake those waiting for |
47 | a signal. |
48 | |
49 | - wait for a signal: Loop over waiting for the global condition until |
50 | the global value matches the wait-for signal. |
51 | |
52 | By default, all sync points are inactive. They do nothing (except to |
53 | burn a couple of CPU cycles for checking if they are active). |
54 | |
55 | A sync point becomes active when an action is requested for it. |
56 | To do so, put a line like this in the test case file: |
57 | |
58 | SET DEBUG_SYNC= 'after_open_tables SIGNAL opened WAIT_FOR flushed'; |
59 | |
60 | This activates the sync point 'after_open_tables'. It requests it to |
61 | emit the signal 'opened' and wait for another thread to emit the signal |
62 | 'flushed' when the thread's execution runs through the sync point. |
63 | |
64 | For every sync point there can be one action per thread only. Every |
65 | thread can request multiple actions, but only one per sync point. In |
66 | other words, a thread can activate multiple sync points. |
67 | |
68 | Here is an example how to activate and use the sync points: |
69 | |
70 | --connection conn1 |
71 | SET DEBUG_SYNC= 'after_open_tables SIGNAL opened WAIT_FOR flushed'; |
72 | send INSERT INTO t1 VALUES(1); |
73 | --connection conn2 |
74 | SET DEBUG_SYNC= 'now WAIT_FOR opened'; |
75 | SET DEBUG_SYNC= 'after_abort_locks SIGNAL flushed'; |
76 | FLUSH TABLE t1; |
77 | |
78 | When conn1 runs through the INSERT statement, it hits the sync point |
79 | 'after_open_tables'. It notices that it is active and executes its |
80 | action. It emits the signal 'opened' and waits for another thread to |
81 | emit the signal 'flushed'. |
82 | |
83 | conn2 waits immediately at the special sync point 'now' for another |
84 | thread to emit the 'opened' signal. |
85 | |
86 | A signal remains in effect until it is overwritten. If conn1 signals |
87 | 'opened' before conn2 reaches 'now', conn2 will still find the 'opened' |
88 | signal. It does not wait in this case. |
89 | |
90 | When conn2 reaches 'after_abort_locks', it signals 'flushed', which lets |
91 | conn1 awake. |
92 | |
93 | Normally the activation of a sync point is cleared when it has been |
94 | executed. Sometimes it is necessary to keep the sync point active for |
95 | another execution. You can add an execute count to the action: |
96 | |
97 | SET DEBUG_SYNC= 'name SIGNAL sig EXECUTE 3'; |
98 | |
99 | This sets the signal point's activation counter to 3. Each execution |
100 | decrements the counter. After the third execution the sync point |
101 | becomes inactive. |
102 | |
103 | One of the primary goals of this facility is to eliminate sleeps from |
104 | the test suite. In most cases it should be possible to rewrite test |
105 | cases so that they do not need to sleep. (But this facility cannot |
106 | synchronize multiple processes.) However, to support test development, |
107 | and as a last resort, sync point waiting times out. There is a default |
108 | timeout, but it can be overridden: |
109 | |
110 | SET DEBUG_SYNC= 'name WAIT_FOR sig TIMEOUT 10 EXECUTE 2'; |
111 | |
112 | TIMEOUT 0 is special: If the signal is not present, the wait times out |
113 | immediately. |
114 | |
115 | When a wait timed out (even on TIMEOUT 0), a warning is generated so |
116 | that it shows up in the test result. |
117 | |
118 | You can throw an error message and kill the query when a synchronization |
119 | point is hit a certain number of times: |
120 | |
121 | SET DEBUG_SYNC= 'name HIT_LIMIT 3'; |
122 | |
123 | Or combine it with signal and/or wait: |
124 | |
125 | SET DEBUG_SYNC= 'name SIGNAL sig EXECUTE 2 HIT_LIMIT 3'; |
126 | |
127 | Here the first two hits emit the signal, the third hit returns the error |
128 | message and kills the query. |
129 | |
130 | For cases where you are not sure that an action is taken and thus |
131 | cleared in any case, you can force to clear (deactivate) a sync point: |
132 | |
133 | SET DEBUG_SYNC= 'name CLEAR'; |
134 | |
135 | If you want to clear all actions and clear the global signal, use: |
136 | |
137 | SET DEBUG_SYNC= 'RESET'; |
138 | |
139 | This is the only way to reset the global signal to an empty string. |
140 | |
141 | For testing of the facility itself you can execute a sync point just |
142 | as if it had been hit: |
143 | |
144 | SET DEBUG_SYNC= 'name TEST'; |
145 | |
146 | |
147 | === Formal Syntax === |
148 | |
149 | The string to "assign" to the DEBUG_SYNC variable can contain: |
150 | |
151 | {RESET | |
152 | <sync point name> TEST | |
153 | <sync point name> CLEAR | |
154 | <sync point name> {{SIGNAL <signal name> | |
155 | WAIT_FOR <signal name> [TIMEOUT <seconds>]} |
156 | [EXECUTE <count>] &| HIT_LIMIT <count>} |
157 | |
158 | Here '&|' means 'and/or'. This means that one of the sections |
159 | separated by '&|' must be present or both of them. |
160 | |
161 | |
162 | === Activation/Deactivation === |
163 | |
164 | The facility is an optional part of the MySQL server. |
165 | It is enabled in a debug server by default. |
166 | |
167 | ./configure --enable-debug-sync |
168 | |
169 | The Debug Sync Facility, when compiled in, is disabled by default. It |
170 | can be enabled by a mysqld command line option: |
171 | |
172 | --debug-sync-timeout[=default_wait_timeout_value_in_seconds] |
173 | |
174 | 'default_wait_timeout_value_in_seconds' is the default timeout for the |
175 | WAIT_FOR action. If set to zero, the facility stays disabled. |
176 | |
177 | The facility is enabled by default in the test suite, but can be |
178 | disabled with: |
179 | |
180 | mysql-test-run.pl ... --debug-sync-timeout=0 ... |
181 | |
182 | Likewise the default wait timeout can be set: |
183 | |
184 | mysql-test-run.pl ... --debug-sync-timeout=10 ... |
185 | |
186 | The command line option influences the readable value of the system |
187 | variable 'debug_sync'. |
188 | |
189 | * If the facility is not compiled in, the system variable does not exist. |
190 | |
191 | * If --debug-sync-timeout=0 the value of the variable reads as "OFF". |
192 | |
193 | * Otherwise the value reads as "ON - current signal: " followed by the |
194 | current signal string, which can be empty. |
195 | |
196 | The readable variable value is the same, regardless if read as global |
197 | or session value. |
198 | |
199 | Setting the 'debug-sync' system variable requires 'SUPER' privilege. |
200 | You can never read back the string that you assigned to the variable, |
201 | unless you assign the value that the variable does already have. But |
202 | that would give a parse error. A syntactically correct string is |
203 | parsed into a debug sync action and stored apart from the variable value. |
204 | |
205 | |
206 | === Implementation === |
207 | |
208 | Pseudo code for a sync point: |
209 | |
210 | #define DEBUG_SYNC(thd, sync_point_name) |
211 | if (unlikely(opt_debug_sync_timeout)) |
212 | debug_sync(thd, STRING_WITH_LEN(sync_point_name)) |
213 | |
214 | The sync point performs a binary search in a sorted array of actions |
215 | for this thread. |
216 | |
217 | The SET DEBUG_SYNC statement adds a requested action to the array or |
218 | overwrites an existing action for the same sync point. When it adds a |
219 | new action, the array is sorted again. |
220 | |
221 | |
222 | === A typical synchronization pattern === |
223 | |
224 | There are quite a few places in MySQL, where we use a synchronization |
225 | pattern like this: |
226 | |
227 | mysql_mutex_lock(&mutex); |
228 | thd->enter_cond(&condition_variable, &mutex, new_message); |
229 | #if defined(ENABLE_DEBUG_SYNC) |
230 | if (!thd->killed && !end_of_wait_condition) |
231 | DEBUG_SYNC(thd, "sync_point_name"); |
232 | #endif |
233 | while (!thd->killed && !end_of_wait_condition) |
234 | mysql_cond_wait(&condition_variable, &mutex); |
235 | thd->exit_cond(old_message); |
236 | |
237 | Here some explanations: |
238 | |
239 | thd->enter_cond() is used to register the condition variable and the |
240 | mutex in thd->mysys_var. This is done to allow the thread to be |
241 | interrupted (killed) from its sleep. Another thread can find the |
242 | condition variable to signal and mutex to use for synchronization in |
243 | this thread's THD::mysys_var. |
244 | |
245 | thd->enter_cond() requires the mutex to be acquired in advance. |
246 | |
247 | thd->exit_cond() unregisters the condition variable and mutex and |
248 | releases the mutex. |
249 | |
250 | If you want to have a Debug Sync point with the wait, please place it |
251 | behind enter_cond(). Only then you can safely decide, if the wait will |
252 | be taken. Also you will have THD::proc_info correct when the sync |
253 | point emits a signal. DEBUG_SYNC sets its own proc_info, but restores |
254 | the previous one before releasing its internal mutex. As soon as |
255 | another thread sees the signal, it does also see the proc_info from |
256 | before entering the sync point. In this case it will be "new_message", |
257 | which is associated with the wait that is to be synchronized. |
258 | |
259 | In the example above, the wait condition is repeated before the sync |
260 | point. This is done to skip the sync point, if no wait takes place. |
261 | The sync point is before the loop (not inside the loop) to have it hit |
262 | once only. It is possible that the condition variable is signaled |
263 | multiple times without the wait condition to be true. |
264 | |
265 | A bit off-topic: At some places, the loop is taken around the whole |
266 | synchronization pattern: |
267 | |
268 | while (!thd->killed && !end_of_wait_condition) |
269 | { |
270 | mysql_mutex_lock(&mutex); |
271 | thd->enter_cond(&condition_variable, &mutex, new_message); |
272 | if (!thd->killed [&& !end_of_wait_condition]) |
273 | { |
274 | [DEBUG_SYNC(thd, "sync_point_name");] |
275 | mysql_cond_wait(&condition_variable, &mutex); |
276 | } |
277 | thd->exit_cond(old_message); |
278 | } |
279 | |
280 | Note that it is important to repeat the test for thd->killed after |
281 | enter_cond(). Otherwise the killing thread may kill this thread after |
282 | it tested thd->killed in the loop condition and before it registered |
283 | the condition variable and mutex in enter_cond(). In this case, the |
284 | killing thread does not know that this thread is going to wait on a |
285 | condition variable. It would just set THD::killed. But if we would not |
286 | test it again, we would go asleep though we are killed. If the killing |
287 | thread would kill us when we are after the second test, but still |
288 | before sleeping, we hold the mutex, which is registered in mysys_var. |
289 | The killing thread would try to acquire the mutex before signaling |
290 | the condition variable. Since the mutex is only released implicitly in |
291 | mysql_cond_wait(), the signaling happens at the right place. We |
292 | have a safe synchronization. |
293 | |
294 | === Co-work with the DBUG facility === |
295 | |
296 | When running the MySQL test suite with the --debug-dbug command line |
297 | option, the Debug Sync Facility writes trace messages to the DBUG |
298 | trace. The following shell commands proved very useful in extracting |
299 | relevant information: |
300 | |
301 | egrep 'query:|debug_sync_exec:' mysql-test/var/log/mysqld.1.trace |
302 | |
303 | It shows all executed SQL statements and all actions executed by |
304 | synchronization points. |
305 | |
306 | Sometimes it is also useful to see, which synchronization points have |
307 | been run through (hit) with or without executing actions. Then add |
308 | "|debug_sync_point:" to the egrep pattern. |
309 | |
310 | === Further reading === |
311 | |
312 | For a discussion of other methods to synchronize threads see |
313 | http://forge.mysql.com/wiki/MySQL_Internals_Test_Synchronization |
314 | |
315 | For complete syntax tests, functional tests, and examples see the test |
316 | case debug_sync.test. |
317 | |
318 | See also http://forge.mysql.com/worklog/task.php?id=4259 |
319 | */ |
320 | |
321 | #ifndef MYSQL_ABI_CHECK |
322 | #include <stdlib.h> |
323 | #endif |
324 | |
325 | #ifdef __cplusplus |
326 | extern "C" { |
327 | #endif |
328 | |
329 | #ifdef MYSQL_DYNAMIC_PLUGIN |
330 | extern void (*debug_sync_service)(MYSQL_THD, const char *, size_t); |
331 | #else |
332 | #define debug_sync_service debug_sync_C_callback_ptr |
333 | extern void (*debug_sync_C_callback_ptr)(MYSQL_THD, const char *, size_t); |
334 | #endif |
335 | |
336 | #ifdef ENABLED_DEBUG_SYNC |
337 | #define DEBUG_SYNC(thd, name) \ |
338 | do { \ |
339 | if (debug_sync_service) \ |
340 | debug_sync_service(thd, STRING_WITH_LEN(name)); \ |
341 | } while(0) |
342 | |
343 | #define DEBUG_SYNC_C_IF_THD(thd, name) \ |
344 | do { \ |
345 | if (debug_sync_service && thd) \ |
346 | debug_sync_service((MYSQL_THD) thd, STRING_WITH_LEN(name)); \ |
347 | } while(0) |
348 | #else |
349 | #define DEBUG_SYNC(thd,name) do { } while(0) |
350 | #define DEBUG_SYNC_C_IF_THD(thd, _sync_point_name_) do { } while(0) |
351 | #endif /* defined(ENABLED_DEBUG_SYNC) */ |
352 | |
353 | /* compatibility macro */ |
354 | #define DEBUG_SYNC_C(name) DEBUG_SYNC(NULL, name) |
355 | |
356 | #ifdef __cplusplus |
357 | } |
358 | #endif |
359 | |
360 | #define MYSQL_SERVICE_DEBUG_SYNC_INCLUDED |
361 | #endif |
362 | |