diff options
| -rw-r--r-- | mysql-test/r/log_tables_debug.result | 23 | ||||
| -rw-r--r-- | mysql-test/t/log_tables_debug.test | 88 | ||||
| -rw-r--r-- | sql/log.cc | 5 |
3 files changed, 115 insertions, 1 deletions
diff --git a/mysql-test/r/log_tables_debug.result b/mysql-test/r/log_tables_debug.result new file mode 100644 index 00000000000..7255c0d38a3 --- /dev/null +++ b/mysql-test/r/log_tables_debug.result @@ -0,0 +1,23 @@ +SET @old_general_log= @@global.general_log; +SET @old_general_log_file= @@global.general_log_file; +SET @old_slow_query_log= @@global.slow_query_log; +SET @old_slow_query_log_file= @@global.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 SESSION debug='+d,reset_log_last_time'; +SET @@global.general_log = @old_general_log; +SET @@global.general_log_file = @old_general_log_file; +SET SESSION debug=''; +Bug#45387: ID match. +End of 5.1 tests +# +# Cleanup +# +SET global general_log = @old_general_log; +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; diff --git a/mysql-test/t/log_tables_debug.test b/mysql-test/t/log_tables_debug.test new file mode 100644 index 00000000000..86af7322505 --- /dev/null +++ b/mysql-test/t/log_tables_debug.test @@ -0,0 +1,88 @@ +### t/log_tables_debug.test +# +# Log-related tests requiring a debug-build server. +# + +# extra clean-up required due to Bug#38124, set to 1 when behavior has +# changed (see explanation in log_state.test) +let $fixed_bug38124 = 0; + +--source include/have_debug.inc + +# Several subtests modify global variables. Save the initial values only here, +# but reset to the initial values per subtest. +SET @old_general_log= @@global.general_log; +SET @old_general_log_file= @@global.general_log_file; +SET @old_slow_query_log= @@global.slow_query_log; +SET @old_slow_query_log_file= @@global.slow_query_log_file; + + +--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'; + +# turn on output of timestamps on all log file entries, +SET SESSION debug='+d,reset_log_last_time'; + +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; +SET SESSION debug=''; + +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 + + +--echo # +--echo # Cleanup +--echo # + +# Reset global system variables to initial values if forgotten somewhere above. +SET global general_log = @old_general_log; +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; +if(!$fixed_bug38124) +{ + --disable_query_log + let $my_var = `SELECT @old_general_log_file`; + eval SET @@global.general_log_file = '$my_var'; + let $my_var = `SELECT @old_slow_query_log_file`; + eval SET @@global.slow_query_log_file = '$my_var'; + --enable_query_log +} + diff --git a/sql/log.cc b/sql/log.cc index b6b92bf1950..ee7ee48b42c 100644 --- a/sql/log.cc +++ b/sql/log.cc @@ -2065,6 +2065,9 @@ bool MYSQL_QUERY_LOG::write(time_t event_time, const char *user_host, /* Test if someone closed between the is_open test and lock */ if (is_open()) { + /* for testing output of timestamp and thread id */ + DBUG_EXECUTE_IF("reset_log_last_time", last_time= 0;); + /* Note that my_b_write() assumes it knows the length for this */ if (event_time != last_time) { @@ -2073,7 +2076,7 @@ bool MYSQL_QUERY_LOG::write(time_t event_time, const char *user_host, 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); |