bk commit into 5.1 tree (malff:1.2619) BUG#27858

[marc.alff]

Below is the list of changes that have just been committed into a local
5.1 repository of marcsql. When marcsql does a push these changes will
be propagated to the main repository and, within 24 hours after the
push, to the public repository.
For information on how to access the public repository
see http://dev.mysql.com/doc/mysql/en/installing-source-tree.html

ChangeSet@stripped, 2007-10-05 19:20:02-06:00, malff@weblab.(none) +3 -0
  Bug#27858 (Failing to log to a log table doesn't log anything to error log)
  
  Before this patch, failures to write to the log tables (mysql.slow_log
  and mysql.general_log) were improperly printed (the time was printed twice),
  or not printed at all.
  
  With this patch, failures to write to the log tables is reported in the
  error log, for all cases of failures.

  mysql-test/r/log_tables.result@stripped, 2007-10-05 19:19:57-06:00, malff@weblab.(none) +4 -0
    Bug#27858 (Failing to log to a log table doesn't log anything to error log)

  mysql-test/t/log_tables.test@stripped, 2007-10-05 19:19:57-06:00, malff@weblab.(none) +56 -0
    Bug#27858 (Failing to log to a log table doesn't log anything to error log)

  sql/log.cc@stripped, 2007-10-05 19:19:57-06:00, malff@weblab.(none) +34 -22
    Bug#27858 (Failing to log to a log table doesn't log anything to error log)

diff -Nrup a/mysql-test/r/log_tables.result b/mysql-test/r/log_tables.result
--- a/mysql-test/r/log_tables.result	2007-08-01 06:48:08 -06:00
+++ b/mysql-test/r/log_tables.result	2007-10-05 19:19:57 -06:00
@@ -270,6 +270,10 @@ use mysql;
 lock tables general_log read local, help_category read local;
 ERROR HY000: You can't use locks with log tables.
 unlock tables;
+drop table if exists mysql.renamed_general_log;
+drop table if exists mysql.renamed_slow_log;
+drop table if exists mysql.general_log_new;
+drop table if exists mysql.slow_log_new;
 use mysql;
 RENAME TABLE general_log TO renamed_general_log;
 ERROR HY000: Cannot rename 'general_log'. When logging enabled, rename to/from log table must rename two tables: the log table to an archive table and another table back to 'general_log'
diff -Nrup a/mysql-test/t/log_tables.test b/mysql-test/t/log_tables.test
--- a/mysql-test/t/log_tables.test	2007-08-01 06:48:09 -06:00
+++ b/mysql-test/t/log_tables.test	2007-10-05 19:19:57 -06:00
@@ -295,6 +295,13 @@ unlock tables;
 # Bug #21785 Server crashes after rename of the log table
 #
 
+--disable_warnings
+drop table if exists mysql.renamed_general_log;
+drop table if exists mysql.renamed_slow_log;
+drop table if exists mysql.general_log_new;
+drop table if exists mysql.slow_log_new;
+--enable_warnings
+
 use mysql;
 # Should result in error
 --error ER_CANT_RENAME_LOG_TABLE
@@ -357,6 +364,55 @@ flush logs;
 flush logs;
 drop table renamed_general_log, renamed_slow_log;
 use test;
+
+#
+# Bug#27858 (Failing to log to a log table doesn't log anything to error log)
+#
+# This test works as expected, it's a negative test.
+# The message "[ERROR] Failed to write to mysql.general_log"
+# is printed to master.err when writing to the table mysql.general_log
+# failed.
+# However, this message is picked up by mysql-test-run.pl,
+# and reported as a test failure, which is a false negative.
+# There is no current way to *selectively* filter out these expected error conditions
+# (see mysql-test/lib/mtr_report.pl, mtr_report_stats()).
+# Instead of filtering all occurences of "Failed to write to
+# mysql.general_log", which could hide bugs when the error is not expected,
+# this test case is commented instead.
+# TODO: improve filtering of expected errors in master.err in
+# mysql-test-run.pl (based on the test name ?), and uncomment this test.
+
+# --disable_warnings
+# drop table if exists mysql.bad_general_log;
+# drop table if exists mysql.bad_slow_log;
+# drop table if exists mysql.general_log_hide;
+# drop table if exists mysql.slow_log_hide;
+# --enable_warnings
+# 
+# create table mysql.bad_general_log (a int) engine= CSV;
+# create table mysql.bad_slow_log (a int) engine= CSV;
+# 
+# # Rename does not perform checks on the table structure,
+# # exploiting this to force a failure to log
+# rename table mysql.general_log to mysql.general_log_hide, mysql.bad_general_log TO mysql.general_log;
+# rename table mysql.slow_log to mysql.slow_log_hide, mysql.bad_slow_log TO mysql.slow_log;
+# 
+# # The following message should be printed in master.log:
+# # [ERROR] Failed to write to mysql.general_log
+# # TODO: See how verifying this could be automated
+# 
+# flush tables;
+# select "logging this should fail";
+# 
+# # Restore the log tables
+# 
+# rename table mysql.general_log to mysql.bad_general_log, mysql.general_log_hide TO mysql.general_log;
+# rename table mysql.slow_log to mysql.bad_slow_log, mysql.slow_log_hide TO mysql.slow_log;
+# 
+# flush tables;
+# 
+# drop table mysql.bad_general_log;
+# drop table mysql.bad_slow_log;
 
 #
 # Bug #21966 Strange warnings on repair of the log tables
diff -Nrup a/sql/log.cc b/sql/log.cc
--- a/sql/log.cc	2007-08-31 16:04:31 -06:00
+++ b/sql/log.cc	2007-10-05 19:19:57 -06:00
@@ -45,6 +45,8 @@ LOGGER logger;
 MYSQL_BIN_LOG mysql_bin_log;
 ulong sync_binlog_counter= 0;
 
+static LEX_STRING unprintable= { C_STRING_WITH_LEN("**UNPRINTABLE**") };
+
 static Muted_query_log_event invisible_commit;
 
 static bool test_if_number(const char *str,
@@ -387,10 +389,24 @@ bool Log_to_csv_event_handler::
   if (table->field[1]->store(user_host, user_host_len, client_cs) ||
       table->field[2]->store((longlong) thread_id, TRUE) ||
       table->field[3]->store((longlong) server_id, TRUE) ||
-      table->field[4]->store(command_type, command_type_len, client_cs) ||
-      table->field[5]->store(sql_text, sql_text_len, client_cs))
+      table->field[4]->store(command_type, command_type_len, client_cs))
     goto err;
 
+  if (table->field[5]->store(sql_text, sql_text_len, client_cs))
+  {
+    /*
+      The sql_text is the text of the query, that is provided by the client.
+      It could contain illegal characters, that cause the error
+      ER_TRUNCATED_WRONG_VALUE_FOR_FIELD when writing to this field.
+      Printing a degraded entry to the log,
+      instead of no entry at all and an error in the error log.
+      TODO: Consider printing with escape sequences ?
+    */
+    if (table->field[5]->store(unprintable.str,
+                               unprintable.length,
+                               & my_charset_utf8_bin))
+      goto err;
+  }
 
   /* mark all fields as not null */
   table->field[1]->set_notnull();
@@ -407,19 +423,14 @@ bool Log_to_csv_event_handler::
 
   /* log table entries are not replicated */
   if (table->file->ha_write_row(table->record[0]))
-  {
-    struct tm start;
-    localtime_r(&event_time, &start);
-
-    sql_print_error("%02d%02d%02d %2d:%02d:%02d - Failed to write to mysql.general_log",
-                    start.tm_year % 100, start.tm_mon + 1,
-                    start.tm_mday, start.tm_hour,
-                    start.tm_min, start.tm_sec);
-  }
+    goto err;
 
   result= FALSE;
 
 err:
+  if (result)
+    sql_print_error("Failed to write to mysql.general_log");
+
   if (need_rnd_end)
   {
     table->file->ha_rnd_end();
@@ -596,24 +607,25 @@ bool Log_to_csv_event_handler::
   table->field[9]->set_notnull();
 
   /* sql_text */
-  if (table->field[10]->store(sql_text,sql_text_len, client_cs))
-    goto err;
+  if (table->field[10]->store(sql_text, sql_text_len, client_cs))
+  {
+    /* See ::log_general() */
+    if (table->field[10]->store(unprintable.str,
+                                unprintable.length,
+                                & my_charset_utf8_bin))
+      goto err;
+  }
 
   /* log table entries are not replicated */
   if (table->file->ha_write_row(table->record[0]))
-  {
-    struct tm start;
-    localtime_r(&current_time, &start);
-
-    sql_print_error("%02d%02d%02d %2d:%02d:%02d - Failed to write to mysql.slow_log",
-                    start.tm_year % 100, start.tm_mon + 1,
-                    start.tm_mday, start.tm_hour,
-                    start.tm_min, start.tm_sec);
-  }
+    goto err;
 
   result= FALSE;
 
 err:
+  if (result)
+    sql_print_error("Failed to write to mysql.slow_log");
+
   if (need_rnd_end)
   {
     table->file->ha_rnd_end();