Details
Critical Description
There's at least one code path, maybe more, in Log_to_csv_event_handler::log_slow() that logs an error, but does not print an actuall error message so that the cause / reason of the error is unclear.
/* check that all columns exist */
|
if (table->s->fields < 13)
|
goto err;
|
Attachments
Issue Links
- relates to
-
MDEV-24339 "[ERROR] Failed to write to mysql.slow_log:" without reason
-
- Closed
-
Activity
commit 6a4b85ce1cca8ec07be460ddfeddfcd1908492fd (HEAD -> bb-10.5-MDEV-20281, origin/bb-10.5-MDEV-20281)
|
Author: Oleksandr Byelkin <sanja@mariadb.com>
|
Date: Fri Jan 24 17:08:04 2025 +0100
|
|
|
MDEV-20281 "[ERROR] Failed to write to mysql.slow_log:" without error reason
|
|
Add "backup" (in case of absence issued by error) reasons for failed logging.
|
it whould be nice to have some way to repeat... I made fix with a lot of reasons, but how to test I have not so much ideas
diff --git a/sql/log.cc b/sql/log.cc
|
index 32a1436f9a6..a34710b9a13 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;
|
+ 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= (char *)"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= (char *)"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= (char *)"incorrect number of fields in the 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= (char *)"Can't write data (possible incorrect 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= (char *)"Can't write data (possible incorrect 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= (char *)"Can't write data (possible incorrect table structure)";
|
goto err;
|
+ }
|
|
/* mark all fields as not null */
|
table->field[1]->set_notnull();
|
@@ -790,14 +811,20 @@ bool Log_to_csv_event_handler::
|
}
|
|
if (table->file->ha_write_row(table->record[0]))
|
+ {
|
+ cause= (char *)"Can't write record";
|
goto err;
|
+ }
|
|
result= FALSE;
|
|
err:
|
if (result && !thd->killed)
|
- sql_print_error("Failed to write to mysql.general_log: %s",
|
+ {
|
+ sql_print_error("Failed to write to mysql.general_log (%s): %s",
|
+ cause,
|
error_handler.message());
|
+ }
|
|
if (need_rnd_end)
|
{
|
@@ -850,6 +877,7 @@ bool Log_to_csv_event_handler::
|
{
|
TABLE_LIST table_list;
|
TABLE *table;
|
+ char *cause= 0;
|
bool result= TRUE;
|
bool need_close= FALSE;
|
bool need_rnd_end= FALSE;
|
@@ -874,13 +902,19 @@ bool Log_to_csv_event_handler::
|
TL_WRITE_CONCURRENT_INSERT);
|
|
if (!(table= open_log_table(thd, &table_list, &open_tables_backup)))
|
+ {
|
+ cause= (char *)"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= (char *)"can't initialize table handler";
|
goto err;
|
+ }
|
|
need_rnd_end= TRUE;
|
|
@@ -891,14 +925,18 @@ bool Log_to_csv_event_handler::
|
|
/* check that all columns exist */
|
if (table->s->fields < 13)
|
+ {
|
+ cause= (char *)"incorrect number of fields in the table";
|
goto err;
|
+ }
|
|
/* 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 store_err;
|
if (table->field[1]->store(user_host, user_host_len, client_cs))
|
- goto err;
|
+ goto store_err;
|
|
/*
|
A TIME field can not hold the full longlong range; query_time or
|
@@ -911,23 +949,23 @@ bool Log_to_csv_event_handler::
|
/* fill in query_time field */
|
calc_time_from_sec(&t, query_time, query_time_micro);
|
if (table->field[2]->store_time(&t))
|
- goto err;
|
+ goto store_err;
|
/* lock_time */
|
calc_time_from_sec(&t, lock_time, lock_time_micro);
|
if (table->field[3]->store_time(&t))
|
- goto err;
|
+ goto store_err;
|
/* rows_sent */
|
if (table->field[4]->store((longlong) thd->get_sent_row_count(), TRUE))
|
- goto err;
|
+ goto store_err;
|
/* rows_examined */
|
if (table->field[5]->store((longlong) thd->get_examined_row_count(), TRUE))
|
- goto err;
|
+ goto store_err;
|
|
/* fill database field */
|
if (thd->db.str)
|
{
|
if (table->field[6]->store(thd->db.str, thd->db.length, client_cs))
|
- goto err;
|
+ goto store_err;
|
table->field[6]->set_notnull();
|
}
|
|
@@ -937,7 +975,7 @@ bool Log_to_csv_event_handler::
|
field[7]->store((longlong)
|
thd->first_successful_insert_id_in_prev_stmt_for_binlog,
|
TRUE))
|
- goto err;
|
+ goto store_err;
|
table->field[7]->set_notnull();
|
}
|
|
@@ -952,12 +990,12 @@ bool Log_to_csv_event_handler::
|
if (table->
|
field[8]->store((longlong)
|
thd->auto_inc_intervals_in_cur_stmt_for_binlog.minimum(), TRUE))
|
- goto err;
|
+ goto store_err;
|
table->field[8]->set_notnull();
|
}
|
|
if (table->field[9]->store((longlong)global_system_variables.server_id, TRUE))
|
- goto err;
|
+ goto store_err;
|
table->field[9]->set_notnull();
|
|
/*
|
@@ -966,19 +1004,22 @@ bool Log_to_csv_event_handler::
|
Still logging a message in the log in this case.
|
*/
|
if (table->field[10]->store(sql_text, sql_text_len, client_cs) < 0)
|
- goto err;
|
+ goto store_err;
|
|
if (table->field[11]->store((longlong) thd->thread_id, TRUE))
|
- goto err;
|
+ goto store_err;
|
|
/* Rows_affected */
|
if (table->field[12]->store(thd->get_stmt_da()->is_ok() ?
|
(longlong) thd->get_stmt_da()->affected_rows() :
|
0, TRUE))
|
- goto err;
|
+ goto store_err;
|
|
if (table->file->ha_write_row(table->record[0]))
|
+ {
|
+ cause= (char *)"Can't write record";
|
goto err;
|
+ }
|
|
result= FALSE;
|
|
@@ -986,7 +1027,8 @@ bool Log_to_csv_event_handler::
|
thd->pop_internal_handler();
|
|
if (result && !thd->killed)
|
- sql_print_error("Failed to write to mysql.slow_log: %s",
|
+ sql_print_error("Failed to write to mysql.slow_log (%s): %s",
|
+ cause,
|
error_handler.message());
|
|
if (need_rnd_end)
|
@@ -998,6 +1040,9 @@ bool Log_to_csv_event_handler::
|
close_log_table(thd, &open_tables_backup);
|
thd->time_zone_used= save_time_zone_used;
|
DBUG_RETURN(result);
|
+store_err: // spagetty, but reduce size of the code
|
+ cause= (char *)"Can't write data (possible incorrect table structure)";
|
+ goto err;
|
}
|
|
int Log_to_csv_event_handler::
|
|
Update,
I havent seen the error with 10.7.6 for a while.
and
The 10.7.7 not yet occured within a week so far.
Still here.
on 10.7.4.
It rarely occurred.
And I set the config for slowlog to Table type
on Windows 11.
table->s->fields < 13 check (if it is users table) mean old system files earlier then 3.23 or the same (do not remember on the top of my head)
ok to push after fixing as in the email review.
https://lists.mariadb.org/hyperkitty/list/developers@lists.mariadb.org/thread/VUY632VX6RQLQCWDDP7CHPK65SVBXFKM/