xref: /php-src/ext/mysqlnd/mysqlnd_debug.c (revision 90b7bde6)
1 /*
2   +----------------------------------------------------------------------+
3   | Copyright (c) The PHP Group                                          |
4   +----------------------------------------------------------------------+
5   | This source file is subject to version 3.01 of the PHP license,      |
6   | that is bundled with this package in the file LICENSE, and is        |
7   | available through the world-wide-web at the following url:           |
8   | https://www.php.net/license/3_01.txt                                 |
9   | If you did not receive a copy of the PHP license and are unable to   |
10   | obtain it through the world-wide-web, please send a note to          |
11   | license@php.net so we can mail you a copy immediately.               |
12   +----------------------------------------------------------------------+
13   | Authors: Andrey Hristov <andrey@php.net>                             |
14   |          Ulf Wendel <uw@php.net>                                     |
15   +----------------------------------------------------------------------+
16 */
17 
18 #include "php.h"
19 #include "mysqlnd.h"
20 #include "mysqlnd_priv.h"
21 #include "mysqlnd_debug.h"
22 
23 static const char * const mysqlnd_debug_default_trace_file = "/tmp/mysqlnd.trace";
24 static const char * const mysqlnd_debug_empty_string = "";
25 
26 
27 /* {{{ mysqlnd_debug::open */
28 static enum_func_status
MYSQLND_METHOD(mysqlnd_debug,open)29 MYSQLND_METHOD(mysqlnd_debug, open)(MYSQLND_DEBUG * self, bool reopen)
30 {
31 	if (!self->file_name) {
32 		return FAIL;
33 	}
34 
35 	self->stream = php_stream_open_wrapper(self->file_name,
36 										   reopen == TRUE || self->flags & MYSQLND_DEBUG_APPEND? "ab":"wb",
37 										   REPORT_ERRORS, NULL);
38 	return self->stream? PASS:FAIL;
39 }
40 /* }}} */
41 
42 
43 /* {{{ mysqlnd_debug::log */
44 static enum_func_status
MYSQLND_METHOD(mysqlnd_debug,log)45 MYSQLND_METHOD(mysqlnd_debug, log)(MYSQLND_DEBUG * self,
46 								   unsigned int line, const char * const file,
47 								   unsigned int level, const char * type, const char * message)
48 {
49 	char pipe_buffer[512];
50 	enum_func_status ret;
51 	int i;
52 	char * message_line;
53 	unsigned int message_line_len;
54 	unsigned int flags = self->flags;
55 	char pid_buffer[10], time_buffer[30], file_buffer[200],
56 		 line_buffer[6], level_buffer[7];
57 
58 	if (!self->stream && FAIL == self->m->open(self, FALSE)) {
59 		return FAIL;
60 	}
61 
62 	if (level == -1) {
63 		level = zend_stack_count(&self->call_stack);
64 	}
65 	i = MIN(level, sizeof(pipe_buffer) / 2  - 1);
66 	pipe_buffer[i*2] = '\0';
67 	for (;i > 0;i--) {
68 		pipe_buffer[i*2 - 1] = ' ';
69 		pipe_buffer[i*2 - 2] = '|';
70 	}
71 
72 
73 	if (flags & MYSQLND_DEBUG_DUMP_PID) {
74 		snprintf(pid_buffer, sizeof(pid_buffer) - 1, "%5u: ", self->pid);
75 		pid_buffer[sizeof(pid_buffer) - 1 ] = '\0';
76 	}
77 	if (flags & MYSQLND_DEBUG_DUMP_TIME) {
78 		/* The following from FF's DBUG library, which is in the public domain */
79 #ifdef PHP_WIN32
80 		/* FIXME This doesn't give microseconds as in Unix case, and the resolution is
81 		in system ticks, 10 ms intervals. See my_getsystime.c for high res */
82 		SYSTEMTIME loc_t;
83 		GetLocalTime(&loc_t);
84 		snprintf(time_buffer, sizeof(time_buffer) - 1,
85 				 /* "%04d-%02d-%02d " */
86 				 "%02d:%02d:%02d.%06d ",
87 				 /*tm_p->tm_year + 1900, tm_p->tm_mon + 1, tm_p->tm_mday,*/
88 				 loc_t.wHour, loc_t.wMinute, loc_t.wSecond, loc_t.wMilliseconds);
89 		time_buffer[sizeof(time_buffer) - 1 ] = '\0';
90 #else
91 		struct timeval tv;
92 		struct tm *tm_p;
93 		if (gettimeofday(&tv, NULL) != -1) {
94 			if ((tm_p= localtime((const time_t *)&tv.tv_sec))) {
95 				snprintf(time_buffer, sizeof(time_buffer) - 1,
96 						 /* "%04d-%02d-%02d " */
97 						 "%02d:%02d:%02d.%06d ",
98 						 /*tm_p->tm_year + 1900, tm_p->tm_mon + 1, tm_p->tm_mday,*/
99 						 tm_p->tm_hour, tm_p->tm_min, tm_p->tm_sec,
100 						 (int) (tv.tv_usec));
101 				time_buffer[sizeof(time_buffer) - 1 ] = '\0';
102 			}
103 		}
104 #endif
105 	}
106 	if (flags & MYSQLND_DEBUG_DUMP_FILE) {
107 		snprintf(file_buffer, sizeof(file_buffer) - 1, "%14s: ", file);
108 		file_buffer[sizeof(file_buffer) - 1 ] = '\0';
109 	}
110 	if (flags & MYSQLND_DEBUG_DUMP_LINE) {
111 		snprintf(line_buffer, sizeof(line_buffer) - 1, "%5u: ", line);
112 		line_buffer[sizeof(line_buffer) - 1 ] = '\0';
113 	}
114 	if (flags & MYSQLND_DEBUG_DUMP_LEVEL) {
115 		snprintf(level_buffer, sizeof(level_buffer) - 1, "%4u: ", level);
116 		level_buffer[sizeof(level_buffer) - 1 ] = '\0';
117 	}
118 
119 	message_line_len = mnd_sprintf(&message_line, 0, "%s%s%s%s%s%s%s%s\n",
120 								flags & MYSQLND_DEBUG_DUMP_PID? pid_buffer:"",
121 								flags & MYSQLND_DEBUG_DUMP_TIME? time_buffer:"",
122 								flags & MYSQLND_DEBUG_DUMP_FILE? file_buffer:"",
123 								flags & MYSQLND_DEBUG_DUMP_LINE? line_buffer:"",
124 								flags & MYSQLND_DEBUG_DUMP_LEVEL? level_buffer:"",
125 								pipe_buffer, type? type:"", message);
126 
127 	ret = php_stream_write(self->stream, message_line, message_line_len)? PASS:FAIL;
128 	mnd_sprintf_free(message_line);
129 	if (flags & MYSQLND_DEBUG_FLUSH) {
130 		self->m->close(self);
131 		self->m->open(self, TRUE);
132 	}
133 	return ret;
134 }
135 /* }}} */
136 
137 
138 /* {{{ mysqlnd_debug::log_va */
139 static enum_func_status
MYSQLND_METHOD(mysqlnd_debug,log_va)140 MYSQLND_METHOD(mysqlnd_debug, log_va)(MYSQLND_DEBUG *self,
141 									  unsigned int line, const char * const file,
142 									  unsigned int level, const char * type,
143 									  const char *format, ...)
144 {
145 	char pipe_buffer[512];
146 	int i;
147 	enum_func_status ret;
148 	char * message_line, *buffer;
149 	unsigned int message_line_len;
150 	va_list args;
151 	unsigned int flags = self->flags;
152 	char pid_buffer[10], time_buffer[30], file_buffer[200],
153 		 line_buffer[6], level_buffer[7];
154 
155 	if (!self->stream && FAIL == self->m->open(self, FALSE)) {
156 		return FAIL;
157 	}
158 
159 	if (level == -1) {
160 		level = zend_stack_count(&self->call_stack);
161 	}
162 	i = MIN(level, sizeof(pipe_buffer) / 2  - 1);
163 	pipe_buffer[i*2] = '\0';
164 	for (;i > 0;i--) {
165 		pipe_buffer[i*2 - 1] = ' ';
166 		pipe_buffer[i*2 - 2] = '|';
167 	}
168 
169 
170 	if (flags & MYSQLND_DEBUG_DUMP_PID) {
171 		snprintf(pid_buffer, sizeof(pid_buffer) - 1, "%5u: ", self->pid);
172 		pid_buffer[sizeof(pid_buffer) - 1 ] = '\0';
173 	}
174 	if (flags & MYSQLND_DEBUG_DUMP_TIME) {
175 		/* The following from FF's DBUG library, which is in the public domain */
176 #ifdef PHP_WIN32
177 		/* FIXME This doesn't give microseconds as in Unix case, and the resolution is
178 		in system ticks, 10 ms intervals. See my_getsystime.c for high res */
179 		SYSTEMTIME loc_t;
180 		GetLocalTime(&loc_t);
181 		snprintf(time_buffer, sizeof(time_buffer) - 1,
182 				 /* "%04d-%02d-%02d " */
183 				 "%02d:%02d:%02d.%06d ",
184 				 /*tm_p->tm_year + 1900, tm_p->tm_mon + 1, tm_p->tm_mday,*/
185 				 loc_t.wHour, loc_t.wMinute, loc_t.wSecond, loc_t.wMilliseconds);
186 		time_buffer[sizeof(time_buffer) - 1 ] = '\0';
187 #else
188 		struct timeval tv;
189 		struct tm *tm_p;
190 		if (gettimeofday(&tv, NULL) != -1) {
191 			if ((tm_p= localtime((const time_t *)&tv.tv_sec))) {
192 				snprintf(time_buffer, sizeof(time_buffer) - 1,
193 						 /* "%04d-%02d-%02d " */
194 						 "%02d:%02d:%02d.%06d ",
195 						 /*tm_p->tm_year + 1900, tm_p->tm_mon + 1, tm_p->tm_mday,*/
196 						 tm_p->tm_hour, tm_p->tm_min, tm_p->tm_sec,
197 						 (int) (tv.tv_usec));
198 				time_buffer[sizeof(time_buffer) - 1 ] = '\0';
199 			}
200 		}
201 #endif
202 	}
203 	if (flags & MYSQLND_DEBUG_DUMP_FILE) {
204 		snprintf(file_buffer, sizeof(file_buffer) - 1, "%14s: ", file);
205 		file_buffer[sizeof(file_buffer) - 1 ] = '\0';
206 	}
207 	if (flags & MYSQLND_DEBUG_DUMP_LINE) {
208 		snprintf(line_buffer, sizeof(line_buffer) - 1, "%5u: ", line);
209 		line_buffer[sizeof(line_buffer) - 1 ] = '\0';
210 	}
211 	if (flags & MYSQLND_DEBUG_DUMP_LEVEL) {
212 		snprintf(level_buffer, sizeof(level_buffer) - 1, "%4u: ", level);
213 		level_buffer[sizeof(level_buffer) - 1 ] = '\0';
214 	}
215 
216 	va_start(args, format);
217 	mnd_vsprintf(&buffer, 0, format, args);
218 	va_end(args);
219 
220 	message_line_len = mnd_sprintf(&message_line, 0, "%s%s%s%s%s%s%s%s\n",
221 								flags & MYSQLND_DEBUG_DUMP_PID? pid_buffer:"",
222 								flags & MYSQLND_DEBUG_DUMP_TIME? time_buffer:"",
223 								flags & MYSQLND_DEBUG_DUMP_FILE? file_buffer:"",
224 								flags & MYSQLND_DEBUG_DUMP_LINE? line_buffer:"",
225 								flags & MYSQLND_DEBUG_DUMP_LEVEL? level_buffer:"",
226 								pipe_buffer, type? type:"", buffer);
227 	mnd_sprintf_free(buffer);
228 	ret = php_stream_write(self->stream, message_line, message_line_len)? PASS:FAIL;
229 	mnd_sprintf_free(message_line);
230 
231 	if (flags & MYSQLND_DEBUG_FLUSH) {
232 		self->m->close(self);
233 		self->m->open(self, TRUE);
234 	}
235 	return ret;
236 }
237 /* }}} */
238 
239 
240 /* FALSE - The DBG_ calls won't be traced, TRUE - will be traced */
241 /* {{{ mysqlnd_debug::func_enter */
242 static bool
MYSQLND_METHOD(mysqlnd_debug,func_enter)243 MYSQLND_METHOD(mysqlnd_debug, func_enter)(MYSQLND_DEBUG * self,
244 										  unsigned int line, const char * const file,
245 										  const char * const func_name, unsigned int func_name_len)
246 {
247 	if ((self->flags & MYSQLND_DEBUG_DUMP_TRACE) == 0 || self->file_name == NULL) {
248 		return FALSE;
249 	}
250 	if ((uint32_t) zend_stack_count(&self->call_stack) >= self->nest_level_limit) {
251 		return FALSE;
252 	}
253 
254 	if ((self->flags & MYSQLND_DEBUG_TRACE_MEMORY_CALLS) == 0 && self->skip_functions) {
255 		const char ** p = self->skip_functions;
256 		while (*p) {
257 			if (*p == func_name) {
258 				zend_stack_push(&self->call_stack, &mysqlnd_debug_empty_string);
259 #ifndef MYSQLND_PROFILING_DISABLED
260 				if (self->flags & MYSQLND_DEBUG_PROFILE_CALLS) {
261 					uint64_t some_time = 0;
262 					zend_stack_push(&self->call_time_stack, &some_time);
263 				}
264 #endif
265 				return FALSE;
266 			}
267 			p++;
268 		}
269 	}
270 
271 	zend_stack_push(&self->call_stack, &func_name);
272 #ifndef MYSQLND_PROFILING_DISABLED
273 	if (self->flags & MYSQLND_DEBUG_PROFILE_CALLS) {
274 		uint64_t some_time = 0;
275 		zend_stack_push(&self->call_time_stack, &some_time);
276 	}
277 #endif
278 
279 	if (zend_hash_num_elements(&self->not_filtered_functions) &&
280 		0 == zend_hash_str_exists(&self->not_filtered_functions, func_name, strlen(func_name)))
281 	{
282 		return FALSE;
283 	}
284 
285 	self->m->log_va(self, line, file, zend_stack_count(&self->call_stack) - 1, NULL, ">%s", func_name);
286 	return TRUE;
287 }
288 /* }}} */
289 
290 #ifndef MYSQLND_PROFILING_DISABLED
291 struct st_mysqlnd_dbg_function_profile {
292 	uint64_t calls;
293 	uint64_t min_own;
294 	uint64_t max_own;
295 	uint64_t avg_own;
296 	uint64_t own_underporm_calls;
297 	uint64_t min_in_calls;
298 	uint64_t max_in_calls;
299 	uint64_t avg_in_calls;
300 	uint64_t in_calls_underporm_calls;
301 	uint64_t min_total;
302 	uint64_t max_total;
303 	uint64_t avg_total;
304 	uint64_t total_underporm_calls;
305 };
306 #define PROFILE_UNDERPERFORM_THRESHOLD 10
307 #endif
308 
309 /* {{{ mysqlnd_debug::func_leave */
310 static enum_func_status
MYSQLND_METHOD(mysqlnd_debug,func_leave)311 MYSQLND_METHOD(mysqlnd_debug, func_leave)(MYSQLND_DEBUG * self, unsigned int line, const char * const file, uint64_t call_time)
312 {
313 	char **func_name;
314 	uint64_t * parent_non_own_time_ptr = NULL, * mine_non_own_time_ptr = NULL;
315 	uint64_t mine_non_own_time = 0;
316 	bool profile_calls = self->flags & MYSQLND_DEBUG_PROFILE_CALLS? TRUE:FALSE;
317 
318 	if ((self->flags & MYSQLND_DEBUG_DUMP_TRACE) == 0 || self->file_name == NULL) {
319 		return PASS;
320 	}
321 	if ((uint32_t) zend_stack_count(&self->call_stack) >= self->nest_level_limit) {
322 		return PASS;
323 	}
324 
325 	func_name = zend_stack_top(&self->call_stack);
326 
327 #ifndef MYSQLND_PROFILING_DISABLED
328 	if (profile_calls) {
329 		mine_non_own_time_ptr = zend_stack_top(&self->call_time_stack);
330 		mine_non_own_time = *mine_non_own_time_ptr;
331 		zend_stack_del_top(&self->call_time_stack); /* callee - removing ourselves */
332 	}
333 #endif
334 
335 	if ((*func_name)[0] == '\0') {
336 		; /* don't log that function */
337 	} else if (!zend_hash_num_elements(&self->not_filtered_functions) ||
338 			   1 == zend_hash_str_exists(&self->not_filtered_functions, (*func_name), strlen((*func_name))))
339 	{
340 #ifndef MYSQLND_PROFILING_DISABLED
341 		if (FALSE == profile_calls) {
342 #endif
343 			self->m->log_va(self, line, file, zend_stack_count(&self->call_stack) - 1, NULL, "<%s", *func_name);
344 
345 #ifndef MYSQLND_PROFILING_DISABLED
346 		} else {
347 			struct st_mysqlnd_dbg_function_profile f_profile_stack = {0};
348 			struct st_mysqlnd_dbg_function_profile * f_profile = NULL;
349 			uint64_t own_time = call_time - mine_non_own_time;
350 			uint32_t func_name_len = strlen(*func_name);
351 
352 			self->m->log_va(self, line, file, zend_stack_count(&self->call_stack) - 1, NULL, "<%s (total=%u own=%u in_calls=%u)",
353 						*func_name, (unsigned int) call_time, (unsigned int) own_time, (unsigned int) mine_non_own_time
354 					);
355 
356 			if ((f_profile = zend_hash_str_find_ptr(&self->function_profiles, *func_name, func_name_len)) != NULL) {
357 				/* found */
358 					if (f_profile) {
359 					if (mine_non_own_time < f_profile->min_in_calls) {
360 						f_profile->min_in_calls = mine_non_own_time;
361 					} else if (mine_non_own_time > f_profile->max_in_calls) {
362 						f_profile->max_in_calls = mine_non_own_time;
363 					}
364 					f_profile->avg_in_calls = (f_profile->avg_in_calls * f_profile->calls + mine_non_own_time) / (f_profile->calls + 1);
365 
366 					if (own_time < f_profile->min_own) {
367 						f_profile->min_own = own_time;
368 					} else if (own_time > f_profile->max_own) {
369 						f_profile->max_own = own_time;
370 					}
371 					f_profile->avg_own = (f_profile->avg_own * f_profile->calls + own_time) / (f_profile->calls + 1);
372 
373 					if (call_time < f_profile->min_total) {
374 						f_profile->min_total = call_time;
375 					} else if (call_time > f_profile->max_total) {
376 						f_profile->max_total = call_time;
377 					}
378 					f_profile->avg_total = (f_profile->avg_total * f_profile->calls + call_time) / (f_profile->calls + 1);
379 
380 					++f_profile->calls;
381 					if (f_profile->calls > PROFILE_UNDERPERFORM_THRESHOLD) {
382 						if (f_profile->avg_in_calls < mine_non_own_time) {
383 							f_profile->in_calls_underporm_calls++;
384 						}
385 						if (f_profile->avg_own < own_time) {
386 							f_profile->own_underporm_calls++;
387 						}
388 						if (f_profile->avg_total < call_time) {
389 							f_profile->total_underporm_calls++;
390 						}
391 					}
392 				}
393 			} else {
394 				/* add */
395 				f_profile = &f_profile_stack;
396 				f_profile->min_in_calls = f_profile->max_in_calls = f_profile->avg_in_calls = mine_non_own_time;
397 				f_profile->min_total = f_profile->max_total = f_profile->avg_total = call_time;
398 				f_profile->min_own = f_profile->max_own = f_profile->avg_own = own_time;
399 				f_profile->calls = 1;
400 				zend_hash_str_add_mem(&self->function_profiles, *func_name, func_name_len, f_profile, sizeof(struct st_mysqlnd_dbg_function_profile));
401 			}
402 			if ((uint32_t) zend_stack_count(&self->call_time_stack)) {
403 				uint64_t parent_non_own_time = 0;
404 
405 				parent_non_own_time_ptr = zend_stack_top(&self->call_time_stack);
406 				parent_non_own_time = *parent_non_own_time_ptr;
407 				parent_non_own_time += call_time;
408 				zend_stack_del_top(&self->call_time_stack); /* the caller */
409 				zend_stack_push(&self->call_time_stack, &parent_non_own_time); /* add back the caller */
410 			}
411 		}
412 #endif
413 	}
414 
415 	zend_stack_del_top(&self->call_stack);
416 	return PASS;
417 }
418 /* }}} */
419 
420 
421 /* {{{ mysqlnd_debug::close */
422 static enum_func_status
MYSQLND_METHOD(mysqlnd_debug,close)423 MYSQLND_METHOD(mysqlnd_debug, close)(MYSQLND_DEBUG * self)
424 {
425 	if (self->stream) {
426 #ifndef MYSQLND_PROFILING_DISABLED
427 		if (!(self->flags & MYSQLND_DEBUG_FLUSH) && (self->flags & MYSQLND_DEBUG_PROFILE_CALLS)) {
428 			struct st_mysqlnd_dbg_function_profile * f_profile;
429 			zend_string	*string_key = NULL;
430 
431 			self->m->log_va(self, __LINE__, __FILE__, 0, "info : ",
432 					"number of functions: %d", zend_hash_num_elements(&self->function_profiles));
433 			ZEND_HASH_MAP_FOREACH_STR_KEY_PTR(&self->function_profiles, string_key, f_profile) {
434 				self->m->log_va(self, __LINE__, __FILE__, -1, "info : ",
435 						"%-40s\tcalls=%5" PRIu64
436 						"  own_slow=%5" PRIu64
437 						"  in_calls_slow=%5" PRIu64
438 						"  total_slow=%5" PRIu64
439 						"   min_own=%5" PRIu64
440 						"  max_own=%7" PRIu64
441 						"  avg_own=%7" PRIu64
442 						"      min_in_calls=%5" PRIu64
443 						"  max_in_calls=%7" PRIu64
444 						"  avg_in_calls=%7" PRIu64
445 						"   min_total=%5" PRIu64
446 						"  max_total=%7" PRIu64
447 						"  avg_total=%7" PRIu64
448 						,ZSTR_VAL(string_key)
449 						,(uint64_t) f_profile->calls
450 						,(uint64_t) f_profile->own_underporm_calls
451 						,(uint64_t) f_profile->in_calls_underporm_calls
452 						,(uint64_t) f_profile->total_underporm_calls
453 
454 						,(uint64_t) f_profile->min_own
455 						,(uint64_t) f_profile->max_own
456 						,(uint64_t) f_profile->avg_own
457 						,(uint64_t) f_profile->min_in_calls
458 						,(uint64_t) f_profile->max_in_calls
459 						,(uint64_t) f_profile->avg_in_calls
460 						,(uint64_t) f_profile->min_total
461 						,(uint64_t) f_profile->max_total
462 						,(uint64_t) f_profile->avg_total
463 						);
464 			} ZEND_HASH_FOREACH_END();
465 		}
466 #endif
467 
468 		php_stream_close(self->stream);
469 		self->stream = NULL;
470 	}
471 	/* no DBG_RETURN please */
472 	return PASS;
473 }
474 /* }}} */
475 
476 
477 /* {{{ mysqlnd_res_meta::free */
478 static enum_func_status
MYSQLND_METHOD(mysqlnd_debug,free)479 MYSQLND_METHOD(mysqlnd_debug, free)(MYSQLND_DEBUG * self)
480 {
481 	if (self->file_name && self->file_name != mysqlnd_debug_default_trace_file) {
482 		efree(self->file_name);
483 		self->file_name = NULL;
484 	}
485 	zend_stack_destroy(&self->call_stack);
486 	zend_stack_destroy(&self->call_time_stack);
487 	zend_hash_destroy(&self->not_filtered_functions);
488 	zend_hash_destroy(&self->function_profiles);
489 	free(self);
490 	return PASS;
491 }
492 /* }}} */
493 
494 enum mysqlnd_debug_parser_state
495 {
496 	PARSER_WAIT_MODIFIER,
497 	PARSER_WAIT_COLON,
498 	PARSER_WAIT_VALUE
499 };
500 
501 
502 /* {{{ mysqlnd_res_meta::set_mode */
503 static void
MYSQLND_METHOD(mysqlnd_debug,set_mode)504 MYSQLND_METHOD(mysqlnd_debug, set_mode)(MYSQLND_DEBUG * self, const char * const mode)
505 {
506 	unsigned int mode_len, i;
507 	enum mysqlnd_debug_parser_state state = PARSER_WAIT_MODIFIER;
508 
509 	mode_len = mode? strlen(mode) : 0;
510 
511 	self->flags = 0;
512 	self->nest_level_limit = 0;
513 	if (self->file_name && self->file_name != mysqlnd_debug_default_trace_file) {
514 		efree(self->file_name);
515 		self->file_name = NULL;
516 	}
517 	if (zend_hash_num_elements(&self->not_filtered_functions)) {
518 		zend_hash_destroy(&self->not_filtered_functions);
519 		zend_hash_init(&self->not_filtered_functions, 0, NULL, NULL, 0);
520 	}
521 
522 	for (i = 0; i < mode_len; i++) {
523 		switch (mode[i]) {
524 			case 'O':
525 			case 'A':
526 				self->flags |= MYSQLND_DEBUG_FLUSH;
527 				ZEND_FALLTHROUGH;
528 			case 'a':
529 			case 'o':
530 				if (mode[i] == 'a' || mode[i] == 'A') {
531 					self->flags |= MYSQLND_DEBUG_APPEND;
532 				}
533 				if (i + 1 < mode_len && mode[i+1] == ',') {
534 					unsigned int j = i + 2;
535 #ifdef PHP_WIN32
536 					if (i+4 < mode_len && mode[i+3] == ':' && (mode[i+4] == '\\' || mode[i+4] == '/')) {
537 						j = i + 5;
538 					}
539 #endif
540 					while (j < mode_len) {
541 						if (mode[j] == ':') {
542 							break;
543 						}
544 						j++;
545 					}
546 					if (j > i + 2) {
547 						self->file_name = estrndup(mode + i + 2, j - i - 2);
548 					}
549 					i = j;
550 				} else {
551 					if (!self->file_name)
552 						self->file_name = (char *) mysqlnd_debug_default_trace_file;
553 				}
554 				state = PARSER_WAIT_COLON;
555 				break;
556 			case ':':
557 				if (state != PARSER_WAIT_COLON) {
558 					php_error_docref(NULL, E_WARNING, "Consecutive semicolons at position %u", i);
559 				}
560 				state = PARSER_WAIT_MODIFIER;
561 				break;
562 			case 'f': /* limit output to these functions */
563 				if (i + 1 < mode_len && mode[i+1] == ',') {
564 					unsigned int j = i + 2;
565 					i++;
566 					while (j < mode_len) {
567 						if (mode[j] == ':') {
568 							/* function names with :: */
569 							if ((j + 1 < mode_len) && mode[j+1] == ':') {
570 								j += 2;
571 								continue;
572 							}
573 						}
574 						if (mode[j] == ',' || mode[j] == ':') {
575 							if (j > i + 2) {
576 								char func_name[1024];
577 								unsigned int func_name_len = MIN(sizeof(func_name) - 1, j - i - 1);
578 								memcpy(func_name, mode + i + 1, func_name_len);
579 								func_name[func_name_len] = '\0';
580 
581 								zend_hash_str_add_empty_element(&self->not_filtered_functions,
582 															func_name, func_name_len);
583 								i = j;
584 							}
585 							if (mode[j] == ':') {
586 								break;
587 							}
588 						}
589 						j++;
590 					}
591 					i = j;
592 				} else {
593 					php_error_docref(NULL, E_WARNING,
594 									 "Expected list of functions for '%c' found none", mode[i]);
595 				}
596 				state = PARSER_WAIT_COLON;
597 				break;
598 			case 'D':
599 			case 'd':
600 			case 'g':
601 			case 'p':
602 				/* unsupported */
603 				if ((i + 1) < mode_len && mode[i+1] == ',') {
604 					i+= 2;
605 					while (i < mode_len) {
606 						if (mode[i] == ':') {
607 							break;
608 						}
609 						i++;
610 					}
611 				}
612 				state = PARSER_WAIT_COLON;
613 				break;
614 			case 'F':
615 				self->flags |= MYSQLND_DEBUG_DUMP_FILE;
616 				state = PARSER_WAIT_COLON;
617 				break;
618 			case 'i':
619 				self->flags |= MYSQLND_DEBUG_DUMP_PID;
620 				state = PARSER_WAIT_COLON;
621 				break;
622 			case 'L':
623 				self->flags |= MYSQLND_DEBUG_DUMP_LINE;
624 				state = PARSER_WAIT_COLON;
625 				break;
626 			case 'n':
627 				self->flags |= MYSQLND_DEBUG_DUMP_LEVEL;
628 				state = PARSER_WAIT_COLON;
629 				break;
630 			case 't':
631 				if (mode[i+1] == ',') {
632 					unsigned int j = i + 2;
633 					while (j < mode_len) {
634 						if (mode[j] == ':') {
635 							break;
636 						}
637 						j++;
638 					}
639 					if (j > i + 2) {
640 						char *value_str = estrndup(mode + i + 2, j - i - 2);
641 						self->nest_level_limit = atoi(value_str);
642 						efree(value_str);
643 					}
644 					i = j;
645 				} else {
646 					self->nest_level_limit = 200; /* default value for FF DBUG */
647 				}
648 				self->flags |= MYSQLND_DEBUG_DUMP_TRACE;
649 				state = PARSER_WAIT_COLON;
650 				break;
651 			case 'T':
652 				self->flags |= MYSQLND_DEBUG_DUMP_TIME;
653 				state = PARSER_WAIT_COLON;
654 				break;
655 			case 'N':
656 			case 'P':
657 			case 'r':
658 			case 'S':
659 				state = PARSER_WAIT_COLON;
660 				break;
661 			case 'm': /* mysqlnd extension - trace memory functions */
662 				self->flags |= MYSQLND_DEBUG_TRACE_MEMORY_CALLS;
663 				state = PARSER_WAIT_COLON;
664 				break;
665 			case 'x': /* mysqlnd extension - profile calls */
666 				self->flags |= MYSQLND_DEBUG_PROFILE_CALLS;
667 				state = PARSER_WAIT_COLON;
668 				break;
669 			default:
670 				if (state == PARSER_WAIT_MODIFIER) {
671 					php_error_docref(NULL, E_WARNING, "Unrecognized format '%c'", mode[i]);
672 					if (i+1 < mode_len && mode[i+1] == ',') {
673 						i+= 2;
674 						while (i < mode_len) {
675 							if (mode[i] == ':') {
676 								break;
677 							}
678 							i++;
679 						}
680 					}
681 					state = PARSER_WAIT_COLON;
682 				} else if (state == PARSER_WAIT_COLON) {
683 					php_error_docref(NULL, E_WARNING, "Colon expected, '%c' found", mode[i]);
684 				}
685 				break;
686 		}
687 	}
688 }
689 /* }}} */
690 
691 MYSQLND_CLASS_METHODS_START(mysqlnd_debug)
692 	MYSQLND_METHOD(mysqlnd_debug, open),
693 	MYSQLND_METHOD(mysqlnd_debug, set_mode),
694 	MYSQLND_METHOD(mysqlnd_debug, log),
695 	MYSQLND_METHOD(mysqlnd_debug, log_va),
696 	MYSQLND_METHOD(mysqlnd_debug, func_enter),
697 	MYSQLND_METHOD(mysqlnd_debug, func_leave),
698 	MYSQLND_METHOD(mysqlnd_debug, close),
699 	MYSQLND_METHOD(mysqlnd_debug, free),
700 MYSQLND_CLASS_METHODS_END;
701 
702 
free_ptr(zval * zv)703 static void free_ptr(zval *zv) {
704 	efree(Z_PTR_P(zv));
705 }
706 
707 /* {{{ mysqlnd_debug_init */
708 PHPAPI MYSQLND_DEBUG *
mysqlnd_debug_init(const char * skip_functions[])709 mysqlnd_debug_init(const char * skip_functions[])
710 {
711 	MYSQLND_DEBUG *ret = calloc(1, sizeof(MYSQLND_DEBUG));
712 
713 	ret->nest_level_limit = 0;
714 	ret->pid = getpid();
715 	zend_stack_init(&ret->call_stack, sizeof(char *));
716 	zend_stack_init(&ret->call_time_stack, sizeof(uint64_t));
717 	zend_hash_init(&ret->not_filtered_functions, 0, NULL, NULL, 0);
718 	zend_hash_init(&ret->function_profiles, 0, NULL, free_ptr, 0);
719 
720 	ret->m = & mysqlnd_mysqlnd_debug_methods;
721 	ret->skip_functions = skip_functions;
722 
723 	return ret;
724 }
725 /* }}} */
726 
727 
728 /* {{{ mysqlnd_debug */
mysqlnd_debug(const char * mode)729 PHPAPI void mysqlnd_debug(const char * mode)
730 {
731 #if PHP_DEBUG
732 	MYSQLND_DEBUG * dbg = MYSQLND_G(dbg);
733 	if (!dbg) {
734 		struct st_mysqlnd_plugin_trace_log * trace_log_plugin = mysqlnd_plugin_find("debug_trace");
735 		if (trace_log_plugin) {
736 			dbg = trace_log_plugin->methods.trace_instance_init(mysqlnd_debug_std_no_trace_funcs);
737 			if (!dbg) {
738 				return;
739 			}
740 			MYSQLND_G(dbg) = dbg;
741 		}
742 	}
743 	if (dbg) {
744 		dbg->m->close(dbg);
745 		dbg->m->set_mode(dbg, mode);
746 		while (zend_stack_count(&dbg->call_stack)) {
747 			zend_stack_del_top(&dbg->call_stack);
748 		}
749 		while (zend_stack_count(&dbg->call_time_stack)) {
750 			zend_stack_del_top(&dbg->call_time_stack);
751 		}
752 	}
753 #endif
754 }
755 /* }}} */
756 
757 
758 static struct st_mysqlnd_plugin_trace_log mysqlnd_plugin_trace_log_plugin =
759 {
760 	{
761 		MYSQLND_PLUGIN_API_VERSION,
762 		"debug_trace",
763 		MYSQLND_VERSION_ID,
764 		PHP_MYSQLND_VERSION,
765 		"PHP License 3.01",
766 		"Andrey Hristov <andrey@php.net>,  Ulf Wendel <uw@php.net>, Georg Richter <georg@php.net>",
767 		{
768 			NULL, /* no statistics , will be filled later if there are some */
769 			NULL, /* no statistics */
770 		},
771 		{
772 			NULL /* plugin shutdown */
773 		}
774 	},
775 	{/* methods */
776 		mysqlnd_debug_init,
777 	}
778 };
779 
780 
781 /* {{{ mysqlnd_debug_trace_plugin_register */
782 void
mysqlnd_debug_trace_plugin_register(void)783 mysqlnd_debug_trace_plugin_register(void)
784 {
785 	mysqlnd_plugin_register_ex((struct st_mysqlnd_plugin_header *) &mysqlnd_plugin_trace_log_plugin);
786 }
787 /* }}} */
788