Hi,
Thanks for your feedback.
What could I do now?
[14 May 7:59] Sergei Golubchik
This is a cool idea.
But must it be implemented in the dbug library ? I think such a
functionality belongs to a separate post-processor script that transforms
dbug logs to an SQL. Or any other format of choice - csv, xml, whatever.
[17 May 11:10] Geoffroy Cogniaux
Of course, this is what I tried to do first. But when I saw that it was
being too hard to have always a correct format with all options and that it
needed to deal sometimes with strange output ( direct use of DBUG_FILE for
instance ), I decided to go directly to the source. Else, it's perhaps a
good idea to produce XML instead, because this format is more reusable than
SQL.
-----Message d'origine-----
De : Geoffroy Cogniaux [mailto:geoffroy.cogniaux@stripped]
Envoyé : dimanche 13 mai 2007 14:42
À : internals@stripped
Objet : RE: [PATCH] Proposed patch for a new feature : DBUG output like
mysqldump
I've created corresponding feature request at:
http://bugs.mysql.com/bug.php?id=28399
-----Message d'origine-----
De : Geoffroy Cogniaux [mailto:geoffroy.cogniaux@stripped]
Envoyé : dimanche 13 mai 2007 14:00
À : internals@stripped
Objet : [PATCH] Proposed patch for a new feature : DBUG output like
mysqldump
Hi,
I modified for my own needs (learn code in fact) the file dbug.c of the
dbug library. I added to it the ability to write a sql script file like
mysqldump could do. Thus, I can easily import my trace file into... a mysql
table which is much easier to navigate, compare, search, find or filter than
a flat file.
It has been useful for me, it can be for someone else too, so I join a patch
with my modifications. Let me know if you are interested.
I have tested it under windows and linux (fedora 6).
I added a new option to the --debug mysqld command line option:
Q[,keywords_list], where keywords can be :
- create (if you want to generate the corresponding create table statement)
- drop (if you want to add "drop if exists" statement )
- session (which generates a session number, useful for having more than one
trace in the same table )
- a_table_name (the name table where the trace will have to be inserted)
Note: it checks and works only if "d" option is set.
mysqld --console --debug=d:Q,create,drop,session,mytable:O,/tmp/mysqld.log
Resulting output can look like:
-- SOURCE J:\_devel\_MySQL\mysqld.log;
--
-- generated on Fri Apr 27 10:14:32 2007
CREATE TABLE ` mytable ` (
`ID` INT(11) auto_increment
,`SESSID` INT(11)
,`THREADID` VARCHAR(10)
,`NUMBER` INT(11)
,`STAMP` VARCHAR(15)
,`FILE` VARCHAR(255)
,`LINE` INT(11)
,`DEPTH` INT(11)
,`FUNC` VARCHAR(255)
,`KEYWORD` VARCHAR(255)
,`ARGS` TEXT
,PRIMARY KEY (`ID`)
);
insert into mytable values ( NULL, 1177661672, "T@1", 1,
"10:14:32.000421", "mf_loadpath.c", 33, 1, "my_load_path", "enter",
"path: j:/_devel/_MySQL/src/mysql-5.1-tree/sql/ prefix: ");
insert into mytable values ( NULL, 1177661672, "T@1", 2,
"10:14:32.000421", "mf_loadpath.c", 52, 1, "my_load_path", "exit",
"to: j:/_devel/_MySQL/src/mysql-5.1-tree/sql/");
insert into mytable values ( NULL, 1177661672, "T@1", 3,
"10:14:32.000421", "mf_loadpath.c", 33, 1, "my_load_path", "enter",
"path: j:/_devel/_MySQL/src/mysql-5.1-tree/sql/ prefix: ");
....
-------------
Waiting for your feedback,
Regards,
Geoffroy
Here is the patch :
--- J:\_devel\bk-client2.0\mysql-5.1\dbug\dbug.c 2007-03-17
11:19:17.000000000 +0100
+++ J:\_devel\_MySQL\src\mysql-5.1-tree\dbug\dbug.c 2007-05-13
11:20:48.375000000 +0200
@@ -69,6 +69,9 @@
* DBUG_SET, _db_explain_
* thread-local settings
*
+ * Geoffroy Cogniaux:
+ * SQL_DUMP - To dump with MysqlDump formatted style
+ *
*/
@@ -110,10 +113,13 @@
#define SANITY_CHECK_ON 002000 /* Check safemalloc on DBUG_ENTER */
#define FLUSH_ON_WRITE 004000 /* Flush on every write */
#define OPEN_APPEND 010000 /* Open for append */
+#define SQL_OUTPUT_ON 020000 /* Print out with mysqldump style */
#define TRACING (cs->stack->flags & TRACE_ON)
#define DEBUGGING (cs->stack->flags & DEBUG_ON)
#define PROFILING (cs->stack->flags & PROFILE_ON)
+/* strict mode when SQL_OUTPUT_ON to have nice ouput style */
+#define DUMP_SQL (cs->stack->flags & SQL_OUTPUT_ON && !TRACING
&&
!PROFILING)
/*
* Typedefs to make things more obvious.
@@ -199,6 +205,8 @@
struct link *p_functions; /* List of profiled functions */
struct link *keywords; /* List of debug keywords */
struct link *processes; /* List of process names */
+ struct link *tables; /* List of SQLDUMP style properties */
+ uint sessid; /* Used by SQLDUMP to generate session id*/
struct settings *next; /* Next settings in the list */
};
@@ -261,7 +269,8 @@
static void FreeState (CODE_STATE *cs, struct settings *state, int
free_state);
/* Test for tracing enabled */
static BOOLEAN DoTrace(CODE_STATE *cs);
-
+ /* if SQLDUMP is set, return the name of ouput mysql table */
+static char* GetTableName(CODE_STATE *cs);
/* Test to see if file is writable */
#if !(!defined(HAVE_ACCESS) || defined(MSDOS))
static BOOLEAN Writable(char *pathname);
@@ -469,6 +478,7 @@
stack->p_functions= NULL;
stack->keywords= NULL;
stack->processes= NULL;
+ stack->tables= NULL;
}
else if (!stack->out_file)
{
@@ -486,6 +496,7 @@
stack->p_functions= ListCopy(init_settings.p_functions);
stack->keywords= ListCopy(init_settings.keywords);
stack->processes= ListCopy(init_settings.processes);
+ stack->tables= ListCopy(init_settings.tables);
}
else
{
@@ -493,6 +504,7 @@
stack->p_functions= stack->next->p_functions;
stack->keywords= stack->next->keywords;
stack->processes= stack->next->processes;
+ stack->tables= stack->next->tables;
}
}
@@ -662,12 +674,75 @@
else
stack->flags |= SANITY_CHECK_ON;
break;
+ case 'Q':
+ if (sign < 0 && control == end)
+ {
+ if (!is_shared(stack,tables))
+ FreeList(stack->tables);
+ stack->tables=NULL;
+ break;
+ }
+ if (rel && is_shared(stack,tables))
+ stack->tables= ListCopy(stack->tables);
+ if (sign < 0)
+ stack->tables= ListDel(stack->tables, control, end);
+ else
+ stack->tables= ListAdd(stack->tables, control, end);
+ if (sign < 0)
+ stack->flags &= ~SQL_OUTPUT_ON;
+ else
+ stack->flags |= SQL_OUTPUT_ON;
+ break;
}
if (!*end)
break;
control=end+1;
end= DbugStrTok(control);
}
+ if(DUMP_SQL)//here to be sure that file is open and writable for the 1rst
time
+ {
+ time_t t = time(NULL);
+ cs->stack->sessid = (uint)t;
+ (void) fprintf(cs->stack->out_file,"-- SOURCE %s;\n--
\n",cs->stack->name);
+ (void) fprintf(cs->stack->out_file,"-- generated on %s\n\n",ctime(&t));
+ if(InList(cs->stack->tables,"drop"))//check if we can drop the table
+ {
+ (void) fprintf(cs->stack->out_file,"DROP TABLE IF EXISTS `%s`;\n",
+ GetTableName(cs));
+ }
+ if(InList(cs->stack->tables,"create"))//check if we have to create the
table
+ {
+ (void) fprintf(cs->stack->out_file,"CREATE TABLE `%s` (\n",
+ GetTableName(cs));
+ (void) fprintf(cs->stack->out_file," `ID` INT(11)
auto_increment\n");
+ if(InList(cs->stack->tables,"session"))//check if we want a session
number
+ {
+ (void) fprintf(cs->stack->out_file," ,`SESSID` INT(11)\n");
+ }
+ if (cs->stack->flags & PID_ON)
+#ifdef THREAD
+ (void) fprintf(cs->stack->out_file," ,`THREADID` VARCHAR(10)\n");
+#else
+ (void) fprintf(cs->stack->out_file," ,`PID` INT(11)\n");
+#endif
+ if (cs->stack->flags & NUMBER_ON)
+ (void) fprintf(cs->stack->out_file, " ,`NUMBER` INT(11)\n");
+ if (cs->stack->flags & TIMESTAMP_ON)
+ (void) fprintf(cs->stack->out_file, " ,`STAMP` VARCHAR(15)\n");
+ if (cs->stack->flags & PROCESS_ON)
+ (void) fprintf(cs->stack->out_file, " ,`PROCESS` VARCHAR(255)\n");
+ if (cs->stack->flags & FILE_ON)
+ (void) fprintf(cs->stack->out_file, " ,`FILE` VARCHAR(255)\n");
+ if (cs->stack->flags & LINE_ON)
+ (void) fprintf(cs->stack->out_file, " ,`LINE` INT(11)\n");
+ if (cs->stack->flags & DEPTH_ON)
+ (void) fprintf(cs->stack->out_file, " ,`DEPTH` INT(11)\n");
+ (void) fprintf(cs->stack->out_file, " ,`FUNC` VARCHAR(255)\n");
+ (void) fprintf(cs->stack->out_file, " ,`KEYWORD` VARCHAR(255)\n");
+ (void) fprintf(cs->stack->out_file, " ,`ARGS` TEXT NULL\n");
+ (void) fprintf(cs->stack->out_file,"\n ,PRIMARY KEY (`ID`)
\n);\n\n\n");
+ }
+ }
}
@@ -855,6 +930,9 @@
op_intf_to_buf('t', cs->stack->maxdepth, MAXDEPTH, TRACING);
op_bool_to_buf('T', cs->stack->flags & TIMESTAMP_ON);
op_bool_to_buf('S', cs->stack->flags & SANITY_CHECK_ON);
+ op_bool_to_buf('Q', cs->stack->flags & SQL_OUTPUT_ON);
+ /* Don't know if it's correct */
+ op_list_to_buf('Q', cs->stack->tables, cs->stack->tables);
*buf= '\0';
return 0;
@@ -978,6 +1056,14 @@
(void) fprintf(cs->stack->out_file, ">%s\n", cs->func);
dbug_flush(cs); /* This does a unlock */
}
+ if(DUMP_SQL)
+ {
+ if (!cs->locked)
+ pthread_mutex_lock(&THR_LOCK_dbug);
+ DoPrefix(cs, _line_);
+ (void) fprintf(cs->stack->out_file, "\"%s\",\"enter\",NULL);\n",
cs->func);
+ dbug_flush(cs);
+ }
#ifdef SAFEMALLOC
if (cs->stack->flags & SANITY_CHECK_ON)
if (_sanity(_file_,_line_)) /* Check of safemalloc */
@@ -1020,7 +1106,11 @@
{
if (!cs->locked)
pthread_mutex_lock(&THR_LOCK_dbug);
- (void) fprintf(cs->stack->out_file, ERR_MISSING_RETURN, cs->process,
+ if(DUMP_SQL)
+ (void) fprintf(stderr, ERR_MISSING_RETURN, cs->process,
+ cs->func);
+ else
+ (void) fprintf(cs->stack->out_file, ERR_MISSING_RETURN, cs->process,
cs->func);
dbug_flush(cs);
}
@@ -1046,6 +1136,14 @@
(void) fprintf(cs->stack->out_file, "<%s\n", cs->func);
dbug_flush(cs);
}
+ if(DUMP_SQL)
+ {
+ if (!cs->locked)
+ pthread_mutex_lock(&THR_LOCK_dbug);
+ DoPrefix(cs, _line_);
+ (void) fprintf(cs->stack->out_file, "\"%s\",\"exit\",NULL);\n",
cs->func);
+ dbug_flush(cs);
+ }
}
cs->level= *_slevel_-1;
cs->func= *_sfunc_;
@@ -1131,10 +1229,43 @@
if (TRACING)
Indent(cs, cs->level + 1);
else
- (void) fprintf(cs->stack->out_file, "%s: ", cs->func);
- (void) fprintf(cs->stack->out_file, "%s: ", cs->u_keyword);
- (void) vfprintf(cs->stack->out_file, format, args);
- (void) fputc('\n',cs->stack->out_file);
+ {
+ if(DUMP_SQL)
+ {
+ (void) fprintf(cs->stack->out_file, "\"%s\", ", cs->func);
+ }
+ else
+ (void) fprintf(cs->stack->out_file, "%s: ", cs->func);
+ }
+ if(DUMP_SQL)
+ {
+#if defined ( __WIN__ )
+/* windows shortcut avoiding complex buffer to replace \ by \\ in inserts
*/
+ #define BUFFER_MAX 1024
+ char buffer[BUFFER_MAX];
+ char* ptr;
+ (void) fprintf(cs->stack->out_file, "\"%s\", \"", cs->u_keyword);
+ (void) vsnprintf(buffer,BUFFER_MAX, format, args);
+ ptr = buffer;
+ while(*ptr++)
+ {
+ if(*ptr=='\\')
+ *ptr = '/';
+ }
+ (void) fprintf(cs->stack->out_file,"%s",buffer);
+ (void) fprintf(cs->stack->out_file,"\");\n");
+#else
+ (void) fprintf(cs->stack->out_file, "\"%s\", \"", cs->u_keyword);
+ (void) vfprintf(cs->stack->out_file, format, args);
+ (void) fprintf(cs->stack->out_file,"\");\n");
+#endif
+ }
+ else
+ {
+ (void) fprintf(cs->stack->out_file, "%s: ", cs->u_keyword);
+ (void) vfprintf(cs->stack->out_file, format, args);
+ (void) fputc('\n',cs->stack->out_file);
+ }
dbug_flush(cs);
errno=save_errno;
}
@@ -1168,6 +1299,9 @@
CODE_STATE *cs=0;
get_code_state_or_return;
+ if(DUMP_SQL)
+ return;//NOT IMPLEMENTED YET
+
if (_db_keyword_(cs, (char*) keyword))
{
if (!cs->locked)
@@ -1565,8 +1699,18 @@
FILE *_db_fp_(void)
{
CODE_STATE *cs=0;
- get_code_state_or_return NULL;
- return cs->stack->out_file;
+ if(DUMP_SQL)
+ {
+ /* some functions use DBUG_FILE instead of DBUG_PRINT
+ and doesn't produce well formatted SQL output.
+ */
+ return stderr;
+ }
+ else
+ {
+ get_code_state_or_return NULL;
+ return cs->stack->out_file;
+ }
}
@@ -1723,16 +1867,36 @@
static void DoPrefix(CODE_STATE *cs, uint _line_)
{
cs->lineno++;
+ if(DUMP_SQL)
+ {
+ (void) fprintf(cs->stack->out_file,"insert into %s values ( NULL, ",
+ GetTableName(cs));
+ if(InList(cs->stack->tables,"session"))
+ {
+ (void) fprintf(cs->stack->out_file,"%d, ",cs->stack->sessid);
+ }
+ }
if (cs->stack->flags & PID_ON)
{
#ifdef THREAD
- (void) fprintf(cs->stack->out_file, "%-7s: ", my_thread_name());
+ if(DUMP_SQL)
+ (void) fprintf(cs->stack->out_file, "\"%s\", ", my_thread_name());
+ else
+ (void) fprintf(cs->stack->out_file, "%-7s: ", my_thread_name());
#else
- (void) fprintf(cs->stack->out_file, "%5d: ", (int) getpid());
+ if(DUMP_SQL)
+ (void) fprintf(cs->stack->out_file, "%5d, ", (int) getpid());
+ else
+ (void) fprintf(cs->stack->out_file, "%5d: ", (int) getpid());
#endif
}
if (cs->stack->flags & NUMBER_ON)
- (void) fprintf(cs->stack->out_file, "%5d: ", cs->lineno);
+ {
+ if(DUMP_SQL)
+ (void) fprintf(cs->stack->out_file, "%5d, ", cs->lineno);
+ else
+ (void) fprintf(cs->stack->out_file, "%5d: ", cs->lineno);
+ }
if (cs->stack->flags & TIMESTAMP_ON)
{
#ifdef __WIN__
@@ -1740,7 +1904,14 @@
in system ticks, 10 ms intervals. See my_getsystime.c for high res
*/
SYSTEMTIME loc_t;
GetLocalTime(&loc_t);
- (void) fprintf (cs->stack->out_file,
+ if(DUMP_SQL)
+ (void) fprintf (cs->stack->out_file,
+ /* "%04d-%02d-%02d " */
+ "\"%02d:%02d:%02d.%06d\", ",
+ /*tm_p->tm_year + 1900, tm_p->tm_mon + 1,
tm_p->tm_mday,*/
+ loc_t.wHour, loc_t.wMinute, loc_t.wSecond,
loc_t.wMilliseconds);
+ else
+ (void) fprintf (cs->stack->out_file,
/* "%04d-%02d-%02d " */
"%02d:%02d:%02d.%06d ",
/*tm_p->tm_year + 1900, tm_p->tm_mon + 1,
tm_p->tm_mday,*/
@@ -1752,7 +1923,15 @@
{
if ((tm_p= localtime((const time_t *)&tv.tv_sec)))
{
- (void) fprintf (cs->stack->out_file,
+ if(DUMP_SQL)
+ (void) fprintf (cs->stack->out_file,
+ /* "%04d-%02d-%02d " */
+ "\"%02d:%02d:%02d.%06d\", ",
+ /*tm_p->tm_year + 1900, tm_p->tm_mon + 1,
tm_p->tm_mday,*/
+ tm_p->tm_hour, tm_p->tm_min, tm_p->tm_sec,
+ (int) (tv.tv_usec));
+ else
+ (void) fprintf (cs->stack->out_file,
/* "%04d-%02d-%02d " */
"%02d:%02d:%02d.%06d ",
/*tm_p->tm_year + 1900, tm_p->tm_mon + 1,
tm_p->tm_mday,*/
@@ -1762,14 +1941,28 @@
}
#endif
}
- if (cs->stack->flags & PROCESS_ON)
- (void) fprintf(cs->stack->out_file, "%s: ", cs->process);
- if (cs->stack->flags & FILE_ON)
- (void) fprintf(cs->stack->out_file, "%14s: ", BaseName(cs->file));
- if (cs->stack->flags & LINE_ON)
- (void) fprintf(cs->stack->out_file, "%5d: ", _line_);
- if (cs->stack->flags & DEPTH_ON)
- (void) fprintf(cs->stack->out_file, "%4d: ", cs->level);
+ if(DUMP_SQL)
+ {
+ if (cs->stack->flags & PROCESS_ON)
+ (void) fprintf(cs->stack->out_file, "\"%s\", ", cs->process);
+ if (cs->stack->flags & FILE_ON)
+ (void) fprintf(cs->stack->out_file, "\"%s\", ", BaseName(cs->file));
+ if (cs->stack->flags & LINE_ON)
+ (void) fprintf(cs->stack->out_file, "%5d, ", _line_);
+ if (cs->stack->flags & DEPTH_ON)
+ (void) fprintf(cs->stack->out_file, "%4d, ", cs->level);
+ }
+ else
+ {
+ if (cs->stack->flags & PROCESS_ON)
+ (void) fprintf(cs->stack->out_file, "%s: ", cs->process);
+ if (cs->stack->flags & FILE_ON)
+ (void) fprintf(cs->stack->out_file, "%s: ", BaseName(cs->file));
+ if (cs->stack->flags & LINE_ON)
+ (void) fprintf(cs->stack->out_file, "%5d: ", _line_);
+ if (cs->stack->flags & DEPTH_ON)
+ (void) fprintf(cs->stack->out_file, "%4d: ", cs->level);
+ }
}
@@ -1879,7 +2072,10 @@
fp=0;
if (!Writable(name))
{
- (void) fprintf(cs->stack->out_file, ERR_OPEN, cs->process, name);
+ if(DUMP_SQL)
+ (void) fprintf(stderr, ERR_OPEN, cs->process, name);
+ else
+ (void) fprintf(cs->stack->out_file, ERR_OPEN, cs->process, name);
perror("");
dbug_flush(0);
(void) Delay(cs->stack->delay);
@@ -1889,7 +2085,10 @@
newfile= !EXISTS(name);
if (!(fp= fopen(name, "w")))
{
- (void) fprintf(cs->stack->out_file, ERR_OPEN, cs->process, name);
+ if(DUMP_SQL)
+ (void) fprintf(stderr, ERR_OPEN, cs->process, name);
+ else
+ (void) fprintf(cs->stack->out_file, ERR_OPEN, cs->process, name);
perror("");
dbug_flush(0);
}
@@ -1928,7 +2127,10 @@
if (fp != stderr && fp != stdout && fclose(fp) == EOF)
{
pthread_mutex_lock(&THR_LOCK_dbug);
- (void) fprintf(cs->stack->out_file, ERR_CLOSE, cs->process);
+ if(DUMP_SQL)
+ (void) fprintf(stderr, ERR_CLOSE, cs->process);
+ else
+ (void) fprintf(cs->stack->out_file, ERR_CLOSE, cs->process);
perror("");
dbug_flush(0);
}
@@ -2234,6 +2436,8 @@
#if defined(MSDOS) || defined(__WIN__)
if (cs->stack->out_file != stdout && cs->stack->out_file !=
stderr)
{
+ fflush(cs->stack->out_file);
+ //_commit(fileno(cs->stack->out_file));
if (!(freopen(cs->stack->name,"a",cs->stack->out_file)))
{
(void) fprintf(stderr, ERR_OPEN, cs->process, cs->stack->name);
@@ -2271,6 +2475,61 @@
}
/*
+ * FUNCTION
+ *
+ * GetTableName Get table name for SQLDUMP output style
+ *
+ * SYNOPSIS
+ *
+ * char* GetTableName(CODE_STATE *cs)
+ *
+ * DESCRIPTION
+ *
+ * Search the table name in SQLDUMP keywords list.
+ * In fact, the table name is the word that is different of
+ * others know keywords ( create, drop, or session ).
+ * Default is "trace".
+ *
+ */
+
+char* GetTableName(CODE_STATE *cs)
+{
+ REGISTER struct link *scan;
+ REGISTER char* result;
+
+ if(!DUMP_SQL)
+ return NULL;
+
+ if (cs->stack->tables == NULL)
+ return NULL;
+ else
+ {
+ result= "trace";
+ for (scan= cs->stack->tables; scan != NULL; scan= scan->next_link)
+ {
+ if (!strcmp(scan->str, "create"))
+ {
+ continue;
+ }
+ if (!strcmp(scan->str, "drop"))
+ {
+ continue;
+ }
+ if (!strcmp(scan->str, "session"))
+ {
+ continue;
+ }
+ else
+ {
+ result = scan->str;
+ break;
+ }
+ }
+ }
+ return result;
+}
+
+/*
* Here we need the definitions of the clock routine. Add your
* own for whatever system that you have.
*/
--
MySQL Internals Mailing List
For list archives: http://lists.mysql.com/internals
To unsubscribe:
http://lists.mysql.com/internals?unsub=1
--
MySQL Internals Mailing List
For list archives: http://lists.mysql.com/internals
To unsubscribe:
http://lists.mysql.com/internals?unsub=1
