bzr commit into mysql-5.1-bugteam branch (staale.smedseng:2935) Bug#45387

[Staale Smedseng]

#At file:///export/home/tmp/ss156133/z/45387-51/ based on
revid:pstoev@stripped

 2935 Staale Smedseng	2009-06-11
      Bug #45387 Information about statement id for prepared 
      statements missed from general log
      
      Insufficient separation between timetag and ID in the
      log file causes the ID to become intelligible. Separation
      is added, and a testcase is supplied which logs a few
      statements to file and parses and compares the actual 
      and expected IDs.
     @ mysql-test/t/log_state.test
        A small Perl script is embedded to parse the output to
        the given log file, extracting the ID and comparing to
        the expected value.

    modified:
      mysql-test/r/log_state.result
      mysql-test/t/log_state.test
      sql/log.cc
=== modified file 'mysql-test/r/log_state.result'
--- a/mysql-test/r/log_state.result	2009-01-23 12:22:05 +0000
+++ b/mysql-test/r/log_state.result	2009-06-11 14:08:54 +0000
@@ -308,6 +308,15 @@ SET @@global.general_log = @old_general_
 SET @@global.general_log_file = @old_general_log_file;
 SET @@global.slow_query_log = @old_slow_query_log;
 SET @@global.slow_query_log_file = @old_slow_query_log_file;
+#
+# Bug#45387 Information about statement id for prepared 
+#           statements missed from general log
+#
+SET @@global.general_log = ON;
+SET @@global.general_log_file = 'bug45387_general.log';
+SET @@global.general_log = @old_general_log;
+SET @@global.general_log_file = @old_general_log_file;
+Bug#45387: ID match.
 End of 5.1 tests
 # Close connection con1
 SET global general_log = @old_general_log;

=== modified file 'mysql-test/t/log_state.test'
--- a/mysql-test/t/log_state.test	2009-01-23 12:22:05 +0000
+++ b/mysql-test/t/log_state.test	2009-06-11 14:08:54 +0000
@@ -362,6 +362,53 @@ if(!$fixed_bug38124)
 }
 
 
+--echo #
+--echo # Bug#45387 Information about statement id for prepared 
+--echo #           statements missed from general log
+--echo #
+
+let MYSQLD_DATADIR= `SELECT @@datadir`;
+
+# set logging to our specific bug log to control the entries added
+SET @@global.general_log = ON;
+SET @@global.general_log_file = 'bug45387_general.log';
+
+# wait long enough to get a new timestamp in the next log entry
+--real_sleep 1
+
+let CONN_ID= `SELECT CONNECTION_ID()`;
+
+# reset log settings
+SET @@global.general_log = @old_general_log;
+SET @@global.general_log_file = @old_general_log_file;
+
+perl;
+  # get the relevant info from the surrounding perl invocation
+  $datadir= $ENV{'MYSQLD_DATADIR'};
+  $conn_id= $ENV{'CONN_ID'};
+
+  # loop through the log file looking for the stmt querying for conn id
+  open(FILE, "$datadir/bug45387_general.log") or 
+    die("Unable to read log file $datadir/bug45387_general.log: $!\n");
+  while(<FILE>) {
+    if (/\d{6} \d\d:\d\d:\d\d[ \t]+(\d+)[ \t]+Query[ \t]+SELECT CONNECTION_ID/) {
+      $found= $1;
+      break;
+    }
+  }
+  close(FILE);
+
+  # print the result
+  if ($found == $conn_id) {
+    print "Bug#45387: ID match.\n";
+  } else {
+    print "Bug#45387: Expected ID '$conn_id', found '$found' in log file.\n";
+  }
+EOF
+
+--remove_file $MYSQLD_DATADIR/bug45387_general.log
+
+
 --echo End of 5.1 tests
 
 --enable_ps_protocol

=== modified file 'sql/log.cc'
--- a/sql/log.cc	2009-05-31 09:15:35 +0000
+++ b/sql/log.cc	2009-06-11 14:08:54 +0000
@@ -2073,7 +2073,7 @@ bool MYSQL_QUERY_LOG::write(time_t event
         localtime_r(&event_time, &start);
 
         time_buff_len= my_snprintf(local_time_buff, MAX_TIME_SIZE,
-                                   "%02d%02d%02d %2d:%02d:%02d",
+                                   "%02d%02d%02d %2d:%02d:%02d\t",
                                    start.tm_year % 100, start.tm_mon + 1,
                                    start.tm_mday, start.tm_hour,
                                    start.tm_min, start.tm_sec);


Attachment: [text/bzr-bundle] bzr/[e-mail]