diff --git a/mysql-test/main/slowlog_integrity.result b/mysql-test/main/slowlog_integrity.result new file mode 100644 index 00000000000..f65fbf49c03 --- /dev/null +++ b/mysql-test/main/slowlog_integrity.result @@ -0,0 +1,108 @@ +# +# MDEV-20281 "[ERROR] Failed to write to mysql.slow_log:" without +# error reason +# +call mtr.add_suppression("Failed to write to mysql.slow_log:"); +SET @old_slow_query_log= @@global.slow_query_log; +SET @old_log_output= @@global.log_output; +SET @old_long_query_time= @@long_query_time; +SET GLOBAL log_output= "TABLE"; +SET GLOBAL slow_query_log= ON; +SET SESSION long_query_time= 0; +select 1 from dual; +1 +1 +show create table mysql.slow_log; +Table Create Table +slow_log CREATE TABLE `slow_log` ( + `start_time` timestamp(6) NOT NULL DEFAULT current_timestamp(6) ON UPDATE current_timestamp(6), + `user_host` mediumtext NOT NULL, + `query_time` time(6) NOT NULL, + `lock_time` time(6) NOT NULL, + `rows_sent` bigint(20) unsigned NOT NULL, + `rows_examined` bigint(20) unsigned NOT NULL, + `db` varchar(512) NOT NULL, + `last_insert_id` int(11) NOT NULL, + `insert_id` int(11) NOT NULL, + `server_id` int(10) unsigned NOT NULL, + `sql_text` mediumtext NOT NULL, + `thread_id` bigint(21) unsigned NOT NULL, + `rows_affected` bigint(20) unsigned NOT NULL +) ENGINE=CSV DEFAULT CHARSET=utf8 COLLATE=utf8_general_ci COMMENT='Slow log' +SET @@long_query_time= @old_long_query_time; +SET @@global.log_output= "FILE"; +SET GLOBAL slow_query_log= OFF; +drop table mysql.slow_log; +# one field missing +CREATE TABLE mysql.slow_log ( +`start_time` timestamp(6) NOT NULL DEFAULT current_timestamp(6) ON UPDATE current_timestamp(6), +`user_host` mediumtext NOT NULL, +`query_time` time(6) NOT NULL, +`lock_time` time(6) NOT NULL, +`rows_sent` bigint(20) unsigned NOT NULL, +`rows_examined` bigint(20) unsigned NOT NULL, +`db` varchar(512) NOT NULL, +`last_insert_id` int(11) NOT NULL, +`insert_id` int(11) NOT NULL, +`server_id` int(10) unsigned NOT NULL, +`sql_text` mediumtext NOT NULL, +`thread_id` bigint(21) unsigned NOT NULL +) ENGINE=CSV DEFAULT CHARSET=utf8 COLLATE=utf8_general_ci COMMENT='Slow log'; +SET GLOBAL log_output= "TABLE"; +SET GLOBAL slow_query_log= ON; +SET SESSION long_query_time= 0; +select 1 from dual; +1 +1 +SET @@long_query_time= @old_long_query_time; +SET @@global.log_output= "FILE"; +SET GLOBAL slow_query_log= OFF; +drop table mysql.slow_log; +# crazy types +CREATE TABLE mysql.slow_log ( +`start_time` timestamp(6) NOT NULL DEFAULT current_timestamp(6) ON UPDATE current_timestamp(6), +`user_host` ENUM('apple','orange','pear') NOT NULL, +`query_time` ENUM('apple','orange','pear') NOT NULL, +`lock_time` ENUM('apple','orange','pear') NOT NULL, +`rows_sent` ENUM('apple','orange','pear') NOT NULL, +`rows_examined` ENUM('apple','orange','pear') NOT NULL, +`db` ENUM('apple','orange','pear') NOT NULL, +`last_insert_id` ENUM('apple','orange','pear') NOT NULL, +`insert_id` ENUM('apple','orange','pear') NOT NULL, +`server_id` ENUM('apple','orange','pear') NOT NULL, +`sql_text` ENUM('apple','orange','pear') NOT NULL, +`thread_id` ENUM('apple','orange','pear') NOT NULL, +`rows_affected` ENUM('apple','orange','pear') NOT NULL +) ENGINE=CSV DEFAULT CHARSET=utf8 COLLATE=utf8_general_ci COMMENT='Slow log'; +SET GLOBAL log_output= "TABLE"; +SET GLOBAL slow_query_log= ON; +SET SESSION long_query_time= 0; +select 1 from dual; +1 +1 +SET @@long_query_time= @old_long_query_time; +SET @@global.log_output= "FILE"; +SET GLOBAL slow_query_log= OFF; +drop table mysql.slow_log; +# restore normal slow log table +CREATE TABLE mysql.slow_log ( +`start_time` timestamp(6) NOT NULL DEFAULT current_timestamp(6) ON UPDATE current_timestamp(6), +`user_host` mediumtext NOT NULL, +`query_time` time(6) NOT NULL, +`lock_time` time(6) NOT NULL, +`rows_sent` bigint(20) unsigned NOT NULL, +`rows_examined` bigint(20) unsigned NOT NULL, +`db` varchar(512) NOT NULL, +`last_insert_id` int(11) NOT NULL, +`insert_id` int(11) NOT NULL, +`server_id` int(10) unsigned NOT NULL, +`sql_text` mediumtext NOT NULL, +`thread_id` bigint(21) unsigned NOT NULL, +`rows_affected` bigint(20) unsigned NOT NULL +) ENGINE=CSV DEFAULT CHARSET=utf8 COLLATE=utf8_general_ci COMMENT='Slow log'; +SET @@long_query_time= @old_long_query_time; +SET @@global.log_output= @old_log_output; +SET @@global.slow_query_log= @old_slow_query_log; +FOUND 2 /incorrect number of fields in the log table/ in mysqld.1.err +FOUND 2 /Can't write data \(possible incorrect log table structure\)/ in mysqld.1.err +# End of 10.5 tests diff --git a/mysql-test/main/slowlog_integrity.test b/mysql-test/main/slowlog_integrity.test new file mode 100644 index 00000000000..8db3a5ee881 --- /dev/null +++ b/mysql-test/main/slowlog_integrity.test @@ -0,0 +1,113 @@ +source include/not_embedded.inc; + +--echo # +--echo # MDEV-20281 "[ERROR] Failed to write to mysql.slow_log:" without +--echo # error reason +--echo # + + +call mtr.add_suppression("Failed to write to mysql.slow_log:"); + +--disable_ps_protocol +SET @old_slow_query_log= @@global.slow_query_log; +SET @old_log_output= @@global.log_output; +SET @old_long_query_time= @@long_query_time; +SET GLOBAL log_output= "TABLE"; +SET GLOBAL slow_query_log= ON; +SET SESSION long_query_time= 0; + +select 1 from dual; + +show create table mysql.slow_log; + +SET @@long_query_time= @old_long_query_time; +SET @@global.log_output= "FILE"; +SET GLOBAL slow_query_log= OFF; + +drop table mysql.slow_log; + +--echo # one field missing +CREATE TABLE mysql.slow_log ( + `start_time` timestamp(6) NOT NULL DEFAULT current_timestamp(6) ON UPDATE current_timestamp(6), + `user_host` mediumtext NOT NULL, + `query_time` time(6) NOT NULL, + `lock_time` time(6) NOT NULL, + `rows_sent` bigint(20) unsigned NOT NULL, + `rows_examined` bigint(20) unsigned NOT NULL, + `db` varchar(512) NOT NULL, + `last_insert_id` int(11) NOT NULL, + `insert_id` int(11) NOT NULL, + `server_id` int(10) unsigned NOT NULL, + `sql_text` mediumtext NOT NULL, + `thread_id` bigint(21) unsigned NOT NULL +) ENGINE=CSV DEFAULT CHARSET=utf8 COLLATE=utf8_general_ci COMMENT='Slow log'; + +SET GLOBAL log_output= "TABLE"; +SET GLOBAL slow_query_log= ON; +SET SESSION long_query_time= 0; + +select 1 from dual; + +SET @@long_query_time= @old_long_query_time; +SET @@global.log_output= "FILE"; +SET GLOBAL slow_query_log= OFF; + +drop table mysql.slow_log; + +--echo # crazy types +CREATE TABLE mysql.slow_log ( + `start_time` timestamp(6) NOT NULL DEFAULT current_timestamp(6) ON UPDATE current_timestamp(6), + `user_host` ENUM('apple','orange','pear') NOT NULL, + `query_time` ENUM('apple','orange','pear') NOT NULL, + `lock_time` ENUM('apple','orange','pear') NOT NULL, + `rows_sent` ENUM('apple','orange','pear') NOT NULL, + `rows_examined` ENUM('apple','orange','pear') NOT NULL, + `db` ENUM('apple','orange','pear') NOT NULL, + `last_insert_id` ENUM('apple','orange','pear') NOT NULL, + `insert_id` ENUM('apple','orange','pear') NOT NULL, + `server_id` ENUM('apple','orange','pear') NOT NULL, + `sql_text` ENUM('apple','orange','pear') NOT NULL, + `thread_id` ENUM('apple','orange','pear') NOT NULL, + `rows_affected` ENUM('apple','orange','pear') NOT NULL +) ENGINE=CSV DEFAULT CHARSET=utf8 COLLATE=utf8_general_ci COMMENT='Slow log'; + +SET GLOBAL log_output= "TABLE"; +SET GLOBAL slow_query_log= ON; +SET SESSION long_query_time= 0; + +select 1 from dual; + +SET @@long_query_time= @old_long_query_time; +SET @@global.log_output= "FILE"; +SET GLOBAL slow_query_log= OFF; + +drop table mysql.slow_log; + +--echo # restore normal slow log table +CREATE TABLE mysql.slow_log ( + `start_time` timestamp(6) NOT NULL DEFAULT current_timestamp(6) ON UPDATE current_timestamp(6), + `user_host` mediumtext NOT NULL, + `query_time` time(6) NOT NULL, + `lock_time` time(6) NOT NULL, + `rows_sent` bigint(20) unsigned NOT NULL, + `rows_examined` bigint(20) unsigned NOT NULL, + `db` varchar(512) NOT NULL, + `last_insert_id` int(11) NOT NULL, + `insert_id` int(11) NOT NULL, + `server_id` int(10) unsigned NOT NULL, + `sql_text` mediumtext NOT NULL, + `thread_id` bigint(21) unsigned NOT NULL, + `rows_affected` bigint(20) unsigned NOT NULL +) ENGINE=CSV DEFAULT CHARSET=utf8 COLLATE=utf8_general_ci COMMENT='Slow log'; +SET @@long_query_time= @old_long_query_time; +SET @@global.log_output= @old_log_output; +SET @@global.slow_query_log= @old_slow_query_log; +--enable_ps_protocol + +--let SEARCH_FILE=$MYSQLTEST_VARDIR/log/mysqld.1.err +--let SEARCH_PATTERN=incorrect number of fields in the log table +--source include/search_pattern_in_file.inc +--let SEARCH_PATTERN=Can't write data \(possible incorrect log table structure\) +--source include/search_pattern_in_file.inc + +--echo # End of 10.5 tests diff --git a/sql/log.cc b/sql/log.cc index 32a1436f9a6..e459e3a5b52 100644 --- a/sql/log.cc +++ b/sql/log.cc @@ -694,6 +694,7 @@ bool Log_to_csv_event_handler:: { TABLE_LIST table_list; TABLE *table; + const char *cause= 0; bool result= TRUE; bool need_close= FALSE; bool need_pop= FALSE; @@ -728,13 +729,19 @@ bool Log_to_csv_event_handler:: need_pop= TRUE; if (!(table= open_log_table(thd, &table_list, &open_tables_backup))) + { + cause= "can't open file"; goto err; + } need_close= TRUE; if (table->file->extra(HA_EXTRA_MARK_AS_LOG_TABLE) || table->file->ha_rnd_init_with_error(0)) + { + cause= "can't initialize table handler"; goto err; + } need_rnd_end= TRUE; @@ -753,12 +760,20 @@ bool Log_to_csv_event_handler:: /* check that all columns exist */ if (table->s->fields < 6) + { + cause= "incorrect number of fields in the log table"; goto err; + } DBUG_ASSERT(table->field[0]->type() == MYSQL_TYPE_TIMESTAMP); - table->field[0]->store_timestamp( - hrtime_to_my_time(event_time), hrtime_sec_part(event_time)); + if (table->field[0]->store_timestamp(hrtime_to_my_time(event_time), + hrtime_sec_part(event_time))) + { + cause= "Can't write data (possible incorrect log table structure)"; + goto err; + } + /* do a write */ if (table->field[1]->store(user_host, user_host_len, client_cs) || @@ -766,7 +781,10 @@ bool Log_to_csv_event_handler:: table->field[3]->store((longlong) global_system_variables.server_id, TRUE) || table->field[4]->store(command_type, command_type_len, client_cs)) + { + cause= "Can't write data (possible incorrect log table structure)"; goto err; + } /* A positive return value in store() means truncation. @@ -774,7 +792,10 @@ bool Log_to_csv_event_handler:: */ table->field[5]->flags|= FIELDFLAG_HEX_ESCAPE; if (table->field[5]->store(sql_text, sql_text_len, client_cs) < 0) + { + cause= "Can't write data (possible incorrect log table structure)"; goto err; + } /* mark all fields as not null */ table->field[1]->set_notnull(); @@ -790,14 +811,22 @@ bool Log_to_csv_event_handler:: } if (table->file->ha_write_row(table->record[0])) + { + cause= "Can't write record"; goto err; + } result= FALSE; err: if (result && !thd->killed) + { + const char *msg= error_handler.message(); + if (!msg || !msg[0]) + msg= cause; sql_print_error("Failed to write to mysql.general_log: %s", - error_handler.message()); + msg); + } if (need_rnd_end) { @@ -850,6 +879,8 @@ bool Log_to_csv_event_handler:: { TABLE_LIST table_list; TABLE *table; + const char *cause= 0; + const char *msg; bool result= TRUE; bool need_close= FALSE; bool need_rnd_end= FALSE; @@ -874,13 +905,19 @@ bool Log_to_csv_event_handler:: TL_WRITE_CONCURRENT_INSERT); if (!(table= open_log_table(thd, &table_list, &open_tables_backup))) + { + cause= "can't open file"; goto err; + } need_close= TRUE; if (table->file->extra(HA_EXTRA_MARK_AS_LOG_TABLE) || table->file->ha_rnd_init_with_error(0)) + { + cause= "can't initialize table handler"; goto err; + } need_rnd_end= TRUE; @@ -891,12 +928,19 @@ bool Log_to_csv_event_handler:: /* check that all columns exist */ if (table->s->fields < 13) + { + cause= "incorrect number of fields in the log table"; goto err; + } + + // It can be used in 13 places below so assign it here + cause= "Can't write data (possible incorrect log table structure)"; /* store the time and user values */ DBUG_ASSERT(table->field[0]->type() == MYSQL_TYPE_TIMESTAMP); - table->field[0]->store_timestamp( - hrtime_to_my_time(current_time), hrtime_sec_part(current_time)); + if(table->field[0]->store_timestamp(hrtime_to_my_time(current_time), + hrtime_sec_part(current_time))) + goto err; if (table->field[1]->store(user_host, user_host_len, client_cs)) goto err; @@ -976,9 +1020,13 @@ bool Log_to_csv_event_handler:: (longlong) thd->get_stmt_da()->affected_rows() : 0, TRUE)) goto err; + cause= 0; // just for safety if (table->file->ha_write_row(table->record[0])) + { + cause= "Can't write record"; goto err; + } result= FALSE; @@ -986,8 +1034,13 @@ err: thd->pop_internal_handler(); if (result && !thd->killed) + { + msg= error_handler.message(); + if (!msg || !msg[0]) + msg= cause; sql_print_error("Failed to write to mysql.slow_log: %s", - error_handler.message()); + msg); + } if (need_rnd_end) {