andrey                                   Fri, 22 Oct 2010 15:46:26 +0000

Revision: http://svn.php.net/viewvc?view=revision&revision=304627

Log:
profiling in trace mode

Changed paths:
    U   php/php-src/branches/PHP_5_3/ext/mysqlnd/mysqlnd.c
    U   php/php-src/branches/PHP_5_3/ext/mysqlnd/mysqlnd_debug.c
    U   php/php-src/branches/PHP_5_3/ext/mysqlnd/mysqlnd_debug.h
    U   php/php-src/branches/PHP_5_3/ext/pdo_mysql/php_pdo_mysql_int.h
    U   php/php-src/trunk/ext/mysqlnd/mysqlnd.c
    U   php/php-src/trunk/ext/mysqlnd/mysqlnd_debug.c
    U   php/php-src/trunk/ext/mysqlnd/mysqlnd_debug.h
    U   php/php-src/trunk/ext/pdo_mysql/php_pdo_mysql_int.h

Modified: php/php-src/branches/PHP_5_3/ext/mysqlnd/mysqlnd.c
===================================================================
--- php/php-src/branches/PHP_5_3/ext/mysqlnd/mysqlnd.c	2010-10-22 14:51:07 UTC (rev 304626)
+++ php/php-src/branches/PHP_5_3/ext/mysqlnd/mysqlnd.c	2010-10-22 15:46:26 UTC (rev 304627)
@@ -2315,10 +2315,11 @@
 PHPAPI MYSQLND * _mysqlnd_init(zend_bool persistent TSRMLS_DC)
 {
 	size_t alloc_size = sizeof(MYSQLND) + mysqlnd_plugin_count() * sizeof(void *);
-	MYSQLND *ret = mnd_pecalloc(1, alloc_size, persistent);
+	MYSQLND *ret;

 	DBG_ENTER("mysqlnd_init");
 	DBG_INF_FMT("persistent=%u", persistent);
+	ret = mnd_pecalloc(1, alloc_size, persistent);
 	if (!ret) {
 		DBG_RETURN(NULL);
 	}

Modified: php/php-src/branches/PHP_5_3/ext/mysqlnd/mysqlnd_debug.c
===================================================================
--- php/php-src/branches/PHP_5_3/ext/mysqlnd/mysqlnd_debug.c	2010-10-22 14:51:07 UTC (rev 304626)
+++ php/php-src/branches/PHP_5_3/ext/mysqlnd/mysqlnd_debug.c	2010-10-22 15:46:26 UTC (rev 304627)
@@ -27,6 +27,7 @@
 #include "mysqlnd_wireprotocol.h"
 #include "mysqlnd_statistics.h"
 #include "zend_builtin_functions.h"
+#include "inttypes.h"

 static const char * const mysqlnd_debug_default_trace_file = "/tmp/mysqlnd.trace";

@@ -287,7 +288,6 @@
 								flags & MYSQLND_DEBUG_DUMP_LEVEL? level_buffer:"",
 								pipe_buffer, type? type:"", buffer);
 	efree(buffer);
-
 	ret = php_stream_write(self->stream, message_line, message_line_len)? PASS:FAIL;
 	efree(message_line); /* allocated by spprintf */

@@ -307,6 +307,7 @@
 										  unsigned int line, const char * const file,
 										  const char * const func_name, unsigned int func_name_len)
 {
+	uint64_t some_time = 0;
 	if ((self->flags & MYSQLND_DEBUG_DUMP_TRACE) == 0 || self->file_name == NULL) {
 		return FALSE;
 	}
@@ -319,6 +320,7 @@
 		while (*p) {
 			if (*p == func_name) {
 				zend_stack_push(&self->call_stack, "", sizeof(""));
+				zend_stack_push(&self->call_time_stack, &some_time, sizeof(some_time));
 				return FALSE;
 			}
 			p++;
@@ -326,6 +328,7 @@
 	}

 	zend_stack_push(&self->call_stack, func_name, func_name_len + 1);
+	zend_stack_push(&self->call_time_stack, &some_time, sizeof(some_time));

 	if (zend_hash_num_elements(&self->not_filtered_functions) &&
 		0 == zend_hash_exists(&self->not_filtered_functions, func_name, strlen(func_name) + 1))
@@ -341,9 +344,12 @@

 /* {{{ mysqlnd_res_meta::func_leave */
 static enum_func_status
-MYSQLND_METHOD(mysqlnd_debug, func_leave)(MYSQLND_DEBUG * self, unsigned int line, const char * const file)
+MYSQLND_METHOD(mysqlnd_debug, func_leave)(MYSQLND_DEBUG * self, unsigned int line, const char * const file, uint64_t call_time)
 {
 	char *func_name;
+	uint64_t * parent_non_own_time_ptr = NULL, * mine_non_own_time_ptr = NULL;
+	uint64_t mine_non_own_time;
+
 	if ((self->flags & MYSQLND_DEBUG_DUMP_TRACE) == 0 || self->file_name == NULL) {
 		return PASS;
 	}
@@ -353,15 +359,34 @@

 	zend_stack_top(&self->call_stack, (void **)&func_name);

+
+	zend_stack_top(&self->call_time_stack, (void **)&mine_non_own_time_ptr);
+	mine_non_own_time = *mine_non_own_time_ptr;
+	zend_stack_del_top(&self->call_time_stack); /* callee - removing ourselves */
+
 	if (func_name[0] == '\0') {
 		; /* don't log that function */
 	} else if (!zend_hash_num_elements(&self->not_filtered_functions) ||
 			   1 == zend_hash_exists(&self->not_filtered_functions, func_name, strlen(func_name) + 1))
 	{
-		self->m->log_va(self, line, file, zend_stack_count(&self->call_stack) - 1, NULL, "<%s", func_name);
+		self->m->log_va(self, line, file, zend_stack_count(&self->call_stack) - 1, NULL, "<%s (total=%u own=%u in_calls=%u)",
+						func_name, (unsigned int) call_time, (unsigned int) (call_time - mine_non_own_time), (unsigned int) mine_non_own_time
+					);
 	}

-	return zend_stack_del_top(&self->call_stack) == SUCCESS? PASS:FAIL;
+	{
+		enum_func_status ret = zend_stack_del_top(&self->call_stack) == SUCCESS? PASS:FAIL;
+		if ((uint) zend_stack_count(&self->call_time_stack)) {
+			uint64_t parent_non_own_time = 0;
+
+			zend_stack_top(&self->call_time_stack, (void **)&parent_non_own_time_ptr);
+			parent_non_own_time = *parent_non_own_time_ptr;
+			parent_non_own_time += call_time;
+			zend_stack_del_top(&self->call_time_stack); /* the caller */
+			zend_stack_push(&self->call_time_stack, &parent_non_own_time, sizeof(parent_non_own_time)); /* add back the caller */
+		}
+		return ret;
+	}
 }
 /* }}} */

@@ -389,6 +414,7 @@
 		self->file_name = NULL;
 	}
 	zend_stack_destroy(&self->call_stack);
+	zend_stack_destroy(&self->call_time_stack);
 	zend_hash_destroy(&self->not_filtered_functions);
 	efree(self);
 	return PASS;
@@ -613,6 +639,7 @@
 	ret->nest_level_limit = 0;
 	ret->pid = getpid();
 	zend_stack_init(&ret->call_stack);
+	zend_stack_init(&ret->call_time_stack);
 	zend_hash_init(&ret->not_filtered_functions, 0, NULL, NULL, 0);

 	ret->m = & mysqlnd_mysqlnd_debug_methods;
@@ -640,6 +667,9 @@
 	while (zend_stack_count(&dbg->call_stack)) {
 		zend_stack_del_top(&dbg->call_stack);
 	}
+	while (zend_stack_count(&dbg->call_time_stack)) {
+		zend_stack_del_top(&dbg->call_time_stack);
+	}
 #endif
 }
 /* }}} */

Modified: php/php-src/branches/PHP_5_3/ext/mysqlnd/mysqlnd_debug.h
===================================================================
--- php/php-src/branches/PHP_5_3/ext/mysqlnd/mysqlnd_debug.h	2010-10-22 14:51:07 UTC (rev 304626)
+++ php/php-src/branches/PHP_5_3/ext/mysqlnd/mysqlnd_debug.h	2010-10-22 15:46:26 UTC (rev 304627)
@@ -35,7 +35,7 @@
 							   unsigned int level, const char * type, const char *format, ...);
 	zend_bool (*func_enter)(MYSQLND_DEBUG *self, unsigned int line, const char * const file,
 							const char * const func_name, unsigned int func_name_len);
-	enum_func_status (*func_leave)(MYSQLND_DEBUG *self, unsigned int line, const char * const file);
+	enum_func_status (*func_leave)(MYSQLND_DEBUG *self, unsigned int line, const char * const file, uint64_t call_time);
 	enum_func_status (*close)(MYSQLND_DEBUG *self);
 	enum_func_status (*free_handle)(MYSQLND_DEBUG *self);
 };
@@ -52,6 +52,7 @@
 	int pid;
 	char * file_name;
 	zend_stack call_stack;
+	zend_stack call_time_stack;
 	HashTable not_filtered_functions;
 	struct st_mysqlnd_debug_methods *m;
 	const char ** skip_functions;
@@ -63,16 +64,38 @@

 PHPAPI char *	mysqlnd_get_backtrace(uint max_levels, size_t * length TSRMLS_DC);

-/* Variadic Macros were introduced in VC 2005, which is _MSC_VER 1400 */
-#if defined(__GNUC__) || (defined(_MSC_VER) && _MSC_VER >= 1400)
+#if defined(__GNUC__) || (defined(_MSC_VER) && (_MSC_VER >= 1400))
+#define DBG_PROFILE_TIMEVAL_TO_DOUBLE(tp)	((tp.tv_sec * 1000000LL)+ tp.tv_usec)
+#define DBG_PROFILE_DECLARE_TIMEVARS		struct timeval __tp = {0}; uint64_t __start = 0; /* initialization is needed */
+#define DBG_PROFILE_START_TIME()			gettimeofday(&__tp, NULL); __start = DBG_PROFILE_TIMEVAL_TO_DOUBLE(__tp);
+#define DBG_PROFILE_END_TIME(duration)		gettimeofday(&__tp, NULL); (duration) = (DBG_PROFILE_TIMEVAL_TO_DOUBLE(__tp) - __start);
+
 #define DBG_INF_EX(dbg_obj, msg)		do { if (dbg_skip_trace == FALSE) (dbg_obj)->m->log((dbg_obj), __LINE__, __FILE__, -1, "info : ", (msg)); } while (0)
 #define DBG_ERR_EX(dbg_obj, msg)		do { if (dbg_skip_trace == FALSE) (dbg_obj)->m->log((dbg_obj), __LINE__, __FILE__, -1, "error: ", (msg)); } while (0)
 #define DBG_INF_FMT_EX(dbg_obj, ...)	do { if (dbg_skip_trace == FALSE) (dbg_obj)->m->log_va((dbg_obj), __LINE__, __FILE__, -1, "info : ", __VA_ARGS__); } while (0)
 #define DBG_ERR_FMT_EX(dbg_obj, ...)	do { if (dbg_skip_trace == FALSE) (dbg_obj)->m->log_va((dbg_obj), __LINE__, __FILE__, -1, "error: ", __VA_ARGS__); } while (0)

-#define DBG_ENTER_EX(dbg_obj, func_name) zend_bool dbg_skip_trace = TRUE; if ((dbg_obj)) dbg_skip_trace = !(dbg_obj)->m->func_enter((dbg_obj), __LINE__, __FILE__, func_name, strlen(func_name));
-#define DBG_RETURN_EX(dbg_obj, value)	do { if ((dbg_obj)) (dbg_obj)->m->func_leave((dbg_obj), __LINE__, __FILE__); return (value); } while (0)
-#define DBG_VOID_RETURN_EX(dbg_obj)		do { if ((dbg_obj)) (dbg_obj)->m->func_leave((dbg_obj), __LINE__, __FILE__); return; } while (0)
+#define DBG_ENTER_EX(dbg_obj, func_name) DBG_PROFILE_DECLARE_TIMEVARS; zend_bool dbg_skip_trace = TRUE; \
+					if ((dbg_obj)) dbg_skip_trace = !(dbg_obj)->m->func_enter((dbg_obj), __LINE__, __FILE__, func_name, strlen(func_name)); \
+					do { DBG_PROFILE_START_TIME(); } while (0);
+#define DBG_RETURN_EX(dbg_obj, value)	\
+			do {\
+				if ((dbg_obj)) { \
+					uint64_t this_call_duration = 0; \
+					DBG_PROFILE_END_TIME(this_call_duration); \
+					(dbg_obj)->m->func_leave((dbg_obj), __LINE__, __FILE__, this_call_duration); \
+				} \
+				return (value);\
+			} while (0)
+#define DBG_VOID_RETURN_EX(dbg_obj)	\
+			do {\
+				if ((dbg_obj)) { \
+					uint64_t this_call_duration = 0; \
+					DBG_PROFILE_END_TIME(this_call_duration); \
+					(dbg_obj)->m->func_leave((dbg_obj), __LINE__, __FILE__, this_call_duration); \
+				} \
+				return;\
+			} while (0)

 #else
 static inline void DBG_INF_EX(MYSQLND_DEBUG * dbg_obj, const char * const msg) {}

Modified: php/php-src/branches/PHP_5_3/ext/pdo_mysql/php_pdo_mysql_int.h
===================================================================
--- php/php-src/branches/PHP_5_3/ext/pdo_mysql/php_pdo_mysql_int.h	2010-10-22 14:51:07 UTC (rev 304626)
+++ php/php-src/branches/PHP_5_3/ext/pdo_mysql/php_pdo_mysql_int.h	2010-10-22 15:46:26 UTC (rev 304627)
@@ -41,8 +41,8 @@
 #define PDO_DBG_INF_FMT(...) do { if (dbg_skip_trace == FALSE) PDO_MYSQL_G(dbg)->m->log_va(PDO_MYSQL_G(dbg), __LINE__, __FILE__, -1, "info : ", __VA_ARGS__); } while (0)
 #define PDO_DBG_ERR_FMT(...) do { if (dbg_skip_trace == FALSE) PDO_MYSQL_G(dbg)->m->log_va(PDO_MYSQL_G(dbg), __LINE__, __FILE__, -1, "error: ", __VA_ARGS__); } while (0)
 #define PDO_DBG_ENTER(func_name) zend_bool dbg_skip_trace = TRUE; if (PDO_MYSQL_G(dbg)) dbg_skip_trace = !PDO_MYSQL_G(dbg)->m->func_enter(PDO_MYSQL_G(dbg), __LINE__, __FILE__, func_name, strlen(func_name));
-#define PDO_DBG_RETURN(value)	do { if (PDO_MYSQL_G(dbg)) PDO_MYSQL_G(dbg)->m->func_leave(PDO_MYSQL_G(dbg), __LINE__, __FILE__); return (value); } while (0)
-#define PDO_DBG_VOID_RETURN		do { if (PDO_MYSQL_G(dbg)) PDO_MYSQL_G(dbg)->m->func_leave(PDO_MYSQL_G(dbg), __LINE__, __FILE__); return; } while (0)
+#define PDO_DBG_RETURN(value)	do { if (PDO_MYSQL_G(dbg)) PDO_MYSQL_G(dbg)->m->func_leave(PDO_MYSQL_G(dbg), __LINE__, __FILE__, 0); return (value); } while (0)
+#define PDO_DBG_VOID_RETURN		do { if (PDO_MYSQL_G(dbg)) PDO_MYSQL_G(dbg)->m->func_leave(PDO_MYSQL_G(dbg), __LINE__, __FILE__, 0); return; } while (0)

 #else
 #define PDO_DBG_ENABLED 0

Modified: php/php-src/trunk/ext/mysqlnd/mysqlnd.c
===================================================================
--- php/php-src/trunk/ext/mysqlnd/mysqlnd.c	2010-10-22 14:51:07 UTC (rev 304626)
+++ php/php-src/trunk/ext/mysqlnd/mysqlnd.c	2010-10-22 15:46:26 UTC (rev 304627)
@@ -2338,10 +2338,11 @@
 PHPAPI MYSQLND * _mysqlnd_init(zend_bool persistent TSRMLS_DC)
 {
 	size_t alloc_size = sizeof(MYSQLND) + mysqlnd_plugin_count() * sizeof(void *);
-	MYSQLND *ret = mnd_pecalloc(1, alloc_size, persistent);
+	MYSQLND *ret;

 	DBG_ENTER("mysqlnd_init");
 	DBG_INF_FMT("persistent=%u", persistent);
+	ret = mnd_pecalloc(1, alloc_size, persistent);
 	if (!ret) {
 		DBG_RETURN(NULL);
 	}

Modified: php/php-src/trunk/ext/mysqlnd/mysqlnd_debug.c
===================================================================
--- php/php-src/trunk/ext/mysqlnd/mysqlnd_debug.c	2010-10-22 14:51:07 UTC (rev 304626)
+++ php/php-src/trunk/ext/mysqlnd/mysqlnd_debug.c	2010-10-22 15:46:26 UTC (rev 304627)
@@ -27,6 +27,7 @@
 #include "mysqlnd_wireprotocol.h"
 #include "mysqlnd_statistics.h"
 #include "zend_builtin_functions.h"
+#include "inttypes.h"

 static const char * const mysqlnd_debug_default_trace_file = "/tmp/mysqlnd.trace";

@@ -287,7 +288,6 @@
 								flags & MYSQLND_DEBUG_DUMP_LEVEL? level_buffer:"",
 								pipe_buffer, type? type:"", buffer);
 	efree(buffer);
-
 	ret = php_stream_write(self->stream, message_line, message_line_len)? PASS:FAIL;
 	efree(message_line); /* allocated by spprintf */

@@ -307,6 +307,7 @@
 										  unsigned int line, const char * const file,
 										  const char * const func_name, unsigned int func_name_len)
 {
+	uint64_t some_time = 0;
 	if ((self->flags & MYSQLND_DEBUG_DUMP_TRACE) == 0 || self->file_name == NULL) {
 		return FALSE;
 	}
@@ -319,6 +320,7 @@
 		while (*p) {
 			if (*p == func_name) {
 				zend_stack_push(&self->call_stack, "", sizeof(""));
+				zend_stack_push(&self->call_time_stack, &some_time, sizeof(some_time));
 				return FALSE;
 			}
 			p++;
@@ -326,6 +328,7 @@
 	}

 	zend_stack_push(&self->call_stack, func_name, func_name_len + 1);
+	zend_stack_push(&self->call_time_stack, &some_time, sizeof(some_time));

 	if (zend_hash_num_elements(&self->not_filtered_functions) &&
 		0 == zend_hash_exists(&self->not_filtered_functions, func_name, strlen(func_name) + 1))
@@ -341,9 +344,12 @@

 /* {{{ mysqlnd_res_meta::func_leave */
 static enum_func_status
-MYSQLND_METHOD(mysqlnd_debug, func_leave)(MYSQLND_DEBUG * self, unsigned int line, const char * const file)
+MYSQLND_METHOD(mysqlnd_debug, func_leave)(MYSQLND_DEBUG * self, unsigned int line, const char * const file, uint64_t call_time)
 {
 	char *func_name;
+	uint64_t * parent_non_own_time_ptr = NULL, * mine_non_own_time_ptr = NULL;
+	uint64_t mine_non_own_time;
+
 	if ((self->flags & MYSQLND_DEBUG_DUMP_TRACE) == 0 || self->file_name == NULL) {
 		return PASS;
 	}
@@ -353,15 +359,34 @@

 	zend_stack_top(&self->call_stack, (void **)&func_name);

+
+	zend_stack_top(&self->call_time_stack, (void **)&mine_non_own_time_ptr);
+	mine_non_own_time = *mine_non_own_time_ptr;
+	zend_stack_del_top(&self->call_time_stack); /* callee - removing ourselves */
+
 	if (func_name[0] == '\0') {
 		; /* don't log that function */
 	} else if (!zend_hash_num_elements(&self->not_filtered_functions) ||
 			   1 == zend_hash_exists(&self->not_filtered_functions, func_name, strlen(func_name) + 1))
 	{
-		self->m->log_va(self, line, file, zend_stack_count(&self->call_stack) - 1, NULL, "<%s", func_name);
+		self->m->log_va(self, line, file, zend_stack_count(&self->call_stack) - 1, NULL, "<%s (total=%u own=%u in_calls=%u)",
+						func_name, (unsigned int) call_time, (unsigned int) (call_time - mine_non_own_time), (unsigned int) mine_non_own_time
+					);
 	}

-	return zend_stack_del_top(&self->call_stack) == SUCCESS? PASS:FAIL;
+	{
+		enum_func_status ret = zend_stack_del_top(&self->call_stack) == SUCCESS? PASS:FAIL;
+		if ((uint) zend_stack_count(&self->call_time_stack)) {
+			uint64_t parent_non_own_time = 0;
+
+			zend_stack_top(&self->call_time_stack, (void **)&parent_non_own_time_ptr);
+			parent_non_own_time = *parent_non_own_time_ptr;
+			parent_non_own_time += call_time;
+			zend_stack_del_top(&self->call_time_stack); /* the caller */
+			zend_stack_push(&self->call_time_stack, &parent_non_own_time, sizeof(parent_non_own_time)); /* add back the caller */
+		}
+		return ret;
+	}
 }
 /* }}} */

@@ -389,6 +414,7 @@
 		self->file_name = NULL;
 	}
 	zend_stack_destroy(&self->call_stack);
+	zend_stack_destroy(&self->call_time_stack);
 	zend_hash_destroy(&self->not_filtered_functions);
 	efree(self);
 	return PASS;
@@ -613,6 +639,7 @@
 	ret->nest_level_limit = 0;
 	ret->pid = getpid();
 	zend_stack_init(&ret->call_stack);
+	zend_stack_init(&ret->call_time_stack);
 	zend_hash_init(&ret->not_filtered_functions, 0, NULL, NULL, 0);

 	ret->m = & mysqlnd_mysqlnd_debug_methods;
@@ -640,6 +667,9 @@
 	while (zend_stack_count(&dbg->call_stack)) {
 		zend_stack_del_top(&dbg->call_stack);
 	}
+	while (zend_stack_count(&dbg->call_time_stack)) {
+		zend_stack_del_top(&dbg->call_time_stack);
+	}
 #endif
 }
 /* }}} */

Modified: php/php-src/trunk/ext/mysqlnd/mysqlnd_debug.h
===================================================================
--- php/php-src/trunk/ext/mysqlnd/mysqlnd_debug.h	2010-10-22 14:51:07 UTC (rev 304626)
+++ php/php-src/trunk/ext/mysqlnd/mysqlnd_debug.h	2010-10-22 15:46:26 UTC (rev 304627)
@@ -35,7 +35,7 @@
 							   unsigned int level, const char * type, const char *format, ...);
 	zend_bool (*func_enter)(MYSQLND_DEBUG *self, unsigned int line, const char * const file,
 							const char * const func_name, unsigned int func_name_len);
-	enum_func_status (*func_leave)(MYSQLND_DEBUG *self, unsigned int line, const char * const file);
+	enum_func_status (*func_leave)(MYSQLND_DEBUG *self, unsigned int line, const char * const file, uint64_t call_time);
 	enum_func_status (*close)(MYSQLND_DEBUG *self);
 	enum_func_status (*free_handle)(MYSQLND_DEBUG *self);
 };
@@ -52,6 +52,7 @@
 	int pid;
 	char * file_name;
 	zend_stack call_stack;
+	zend_stack call_time_stack;
 	HashTable not_filtered_functions;
 	struct st_mysqlnd_debug_methods *m;
 	const char ** skip_functions;
@@ -63,16 +64,38 @@

 PHPAPI char *	mysqlnd_get_backtrace(uint max_levels, size_t * length TSRMLS_DC);

-/* Variadic Macros were introduced in VC 2005, which is _MSC_VER 1400 */
-#if defined(__GNUC__) || (defined(_MSC_VER) && _MSC_VER >= 1400)
+#if defined(__GNUC__) || (defined(_MSC_VER) && (_MSC_VER >= 1400))
+#define DBG_PROFILE_TIMEVAL_TO_DOUBLE(tp)	((tp.tv_sec * 1000000LL)+ tp.tv_usec)
+#define DBG_PROFILE_DECLARE_TIMEVARS		struct timeval __tp = {0}; uint64_t __start = 0; /* initialization is needed */
+#define DBG_PROFILE_START_TIME()			gettimeofday(&__tp, NULL); __start = DBG_PROFILE_TIMEVAL_TO_DOUBLE(__tp);
+#define DBG_PROFILE_END_TIME(duration)		gettimeofday(&__tp, NULL); (duration) = (DBG_PROFILE_TIMEVAL_TO_DOUBLE(__tp) - __start);
+
 #define DBG_INF_EX(dbg_obj, msg)		do { if (dbg_skip_trace == FALSE) (dbg_obj)->m->log((dbg_obj), __LINE__, __FILE__, -1, "info : ", (msg)); } while (0)
 #define DBG_ERR_EX(dbg_obj, msg)		do { if (dbg_skip_trace == FALSE) (dbg_obj)->m->log((dbg_obj), __LINE__, __FILE__, -1, "error: ", (msg)); } while (0)
 #define DBG_INF_FMT_EX(dbg_obj, ...)	do { if (dbg_skip_trace == FALSE) (dbg_obj)->m->log_va((dbg_obj), __LINE__, __FILE__, -1, "info : ", __VA_ARGS__); } while (0)
 #define DBG_ERR_FMT_EX(dbg_obj, ...)	do { if (dbg_skip_trace == FALSE) (dbg_obj)->m->log_va((dbg_obj), __LINE__, __FILE__, -1, "error: ", __VA_ARGS__); } while (0)

-#define DBG_ENTER_EX(dbg_obj, func_name) zend_bool dbg_skip_trace = TRUE; if ((dbg_obj)) dbg_skip_trace = !(dbg_obj)->m->func_enter((dbg_obj), __LINE__, __FILE__, func_name, strlen(func_name));
-#define DBG_RETURN_EX(dbg_obj, value)	do { if ((dbg_obj)) (dbg_obj)->m->func_leave((dbg_obj), __LINE__, __FILE__); return (value); } while (0)
-#define DBG_VOID_RETURN_EX(dbg_obj)		do { if ((dbg_obj)) (dbg_obj)->m->func_leave((dbg_obj), __LINE__, __FILE__); return; } while (0)
+#define DBG_ENTER_EX(dbg_obj, func_name) DBG_PROFILE_DECLARE_TIMEVARS; zend_bool dbg_skip_trace = TRUE; \
+					if ((dbg_obj)) dbg_skip_trace = !(dbg_obj)->m->func_enter((dbg_obj), __LINE__, __FILE__, func_name, strlen(func_name)); \
+					do { DBG_PROFILE_START_TIME(); } while (0);
+#define DBG_RETURN_EX(dbg_obj, value)	\
+			do {\
+				if ((dbg_obj)) { \
+					uint64_t this_call_duration = 0; \
+					DBG_PROFILE_END_TIME(this_call_duration); \
+					(dbg_obj)->m->func_leave((dbg_obj), __LINE__, __FILE__, this_call_duration); \
+				} \
+				return (value);\
+			} while (0)
+#define DBG_VOID_RETURN_EX(dbg_obj)	\
+			do {\
+				if ((dbg_obj)) { \
+					uint64_t this_call_duration = 0; \
+					DBG_PROFILE_END_TIME(this_call_duration); \
+					(dbg_obj)->m->func_leave((dbg_obj), __LINE__, __FILE__, this_call_duration); \
+				} \
+				return;\
+			} while (0)

 #else
 static inline void DBG_INF_EX(MYSQLND_DEBUG * dbg_obj, const char * const msg) {}

Modified: php/php-src/trunk/ext/pdo_mysql/php_pdo_mysql_int.h
===================================================================
--- php/php-src/trunk/ext/pdo_mysql/php_pdo_mysql_int.h	2010-10-22 14:51:07 UTC (rev 304626)
+++ php/php-src/trunk/ext/pdo_mysql/php_pdo_mysql_int.h	2010-10-22 15:46:26 UTC (rev 304627)
@@ -41,8 +41,8 @@
 #define PDO_DBG_INF_FMT(...) do { if (dbg_skip_trace == FALSE) PDO_MYSQL_G(dbg)->m->log_va(PDO_MYSQL_G(dbg), __LINE__, __FILE__, -1, "info : ", __VA_ARGS__); } while (0)
 #define PDO_DBG_ERR_FMT(...) do { if (dbg_skip_trace == FALSE) PDO_MYSQL_G(dbg)->m->log_va(PDO_MYSQL_G(dbg), __LINE__, __FILE__, -1, "error: ", __VA_ARGS__); } while (0)
 #define PDO_DBG_ENTER(func_name) zend_bool dbg_skip_trace = TRUE; if (PDO_MYSQL_G(dbg)) dbg_skip_trace = !PDO_MYSQL_G(dbg)->m->func_enter(PDO_MYSQL_G(dbg), __LINE__, __FILE__, func_name, strlen(func_name));
-#define PDO_DBG_RETURN(value)	do { if (PDO_MYSQL_G(dbg)) PDO_MYSQL_G(dbg)->m->func_leave(PDO_MYSQL_G(dbg), __LINE__, __FILE__); return (value); } while (0)
-#define PDO_DBG_VOID_RETURN		do { if (PDO_MYSQL_G(dbg)) PDO_MYSQL_G(dbg)->m->func_leave(PDO_MYSQL_G(dbg), __LINE__, __FILE__); return; } while (0)
+#define PDO_DBG_RETURN(value)	do { if (PDO_MYSQL_G(dbg)) PDO_MYSQL_G(dbg)->m->func_leave(PDO_MYSQL_G(dbg), __LINE__, __FILE__, 0); return (value); } while (0)
+#define PDO_DBG_VOID_RETURN		do { if (PDO_MYSQL_G(dbg)) PDO_MYSQL_G(dbg)->m->func_leave(PDO_MYSQL_G(dbg), __LINE__, __FILE__, 0); return; } while (0)

 #else
 #define PDO_DBG_ENABLED 0
-- 
PHP CVS Mailing List (http://www.php.net/)
To unsubscribe, visit: http://www.php.net/unsub.php

Reply via email to