Bug #28399 DBUG output like mysqldump
Submitted: 13 May 2007 12:38 Modified: 13 Jul 2009 15:57
Reporter: Geoffroy Cogniaux Email Updates:
Status: Won't fix Impact on me:
None 
Category:MySQL Server: Logging Severity:S4 (Feature request)
Version: OS:Any
Assigned to: CPU Architecture:Any
Tags: Contribution, debug

[13 May 2007 12:38] Geoffroy Cogniaux
Description:
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.

How to repeat:
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: ");
....
[13 May 2007 12:39] Geoffroy Cogniaux
The patch

Attachment: dbug.patch (application/octet-stream, text), 15.68 KiB.

[14 May 2007 5: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 2007 9: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.
[17 May 2007 9:28] MySQL Verification Team
Thank you for the bug report feature request and contribution.
[21 May 2007 15:37] Sergei Golubchik
Is it too hard ?
One problem with your code - it doesn't work (produces invalid SQL script) if the program changes output flags during the runtime (e.g. DBUG_PUSH("t")).
We can say that this is a limitation of this feature, it's ok, not a big deal.

But assuming we accept this limitation, one can parse dbug logs with a simple perl script, as below. It expects a command-line parameter with the debug control string, the same that was used to produce the dbug trace. If you think this is too much to ask from the user, we can have dbug to print it as the first line in the trace and discover it automatically.

#!/usr/bin/perl

$_=shift or die;
s/^-#//;
$format=":$_:";

while(<>) {
  if ($format =~ /:i:/) { s/^(\w+): // or die; $pid=$1; }
  if ($format =~ /:N:/) { s/^(\d+): // or die; $linenum=$1; }
  if ($format =~ /:T:/) { s/^(\w+): // or die; $timestamp=$1; }
  .....
[21 May 2007 15:43] Sergei Golubchik
mine perl example parses the trace log very strictly. to allow the program to use DBUG_FILE directly, it should be relaxed by replacing "or die" to "or next"
[22 May 2007 19:24] Geoffroy Cogniaux
I didn't have thought of this way. You're right, it's not so hard to parse one more time the debug args.    
DBUG_PUSH("t") doesn't produce invalid SQL, it doesn't produce SQL any more because, adding my flag SQL_DUMP, I limited it to work only with "d" option because for trace injection, I don't need to have indents which is the only feature of "t" option I believe. This is a limitation but a needed limitation.  
In my opinion, the most important isn't to know if it's well or beautiful, but to know if it works and increases speed for bugs discovering. ( this is the why of a trace ... ).Does it ? I will be glad to have helped you a little bit.
Bye.
[1 Jun 2007 8:49] Geoffroy Cogniaux
I found a bug in the patch.
Please replace
#define DUMP_SQL (cs->stack->flags & SQL_OUTPUT_ON && !TRACING && !PROFILING)

by 

#define DUMP_SQL (cs && cs->stack->flags & SQL_OUTPUT_ON && !TRACING && !PROFILING)
[13 Jul 2009 15:24] liz drachnik
Hello Geoffrey - 

 In order for us to continue the process of reviewing your contribution
 to MySQL - We need you to review and sign the Sun|MySQL contributor
 agreement (the "SCA")

 The process is explained here:
 http://forge.mysql.com/wiki/Sun_Contributor_Agreement

 Getting a signed/approved SCA on file will help us facilitate your
 contribution-- this one, and others in the future.

 Thank you !

 Liz Drachnik  - Program Manager - MySQL
[13 Jul 2009 15:57] Sergei Golubchik
I don't see a need for functionality in the dbug library itself, I think it belongs to a separate log post-processor.