Commit 51cd70da authored by unknown's avatar unknown

A fix for Bug#9141 "4.1 does not log into slow log

ALTER, OPTIMIZE and ANALYZE statements".
In 4.1 we disabled logging of slow admin statements. The fix adds an 
option to enable it back.
No test case (slow log is not tested in the test suite), but tested
manually.
+ post-review fixes (word police mainly).


sql/mysql_priv.h:
  - declaration for a new option
sql/mysqld.cc:
  Add server option '--log-slow-admin-statements' to log slow
  optimize/alter/etc statements to the slow log if it's enabled.
  Add warnings that this option works only if the slow log is open.
sql/sql_class.h:
  Rename 'thd->slow_command' to thd->enable_slow_log (negates
  the meaning of this variable, and so resolves the need to negate
  value opt_log_slow_admin_statements when setting it).
sql/sql_parse.cc:
  Implement optional logging of administrative statements in the slow log.
parent b0d82705
...@@ -918,6 +918,7 @@ extern my_bool opt_slave_compressed_protocol, use_temp_pool; ...@@ -918,6 +918,7 @@ extern my_bool opt_slave_compressed_protocol, use_temp_pool;
extern my_bool opt_readonly, lower_case_file_system; extern my_bool opt_readonly, lower_case_file_system;
extern my_bool opt_enable_named_pipe, opt_sync_frm, opt_allow_suspicious_udfs; extern my_bool opt_enable_named_pipe, opt_sync_frm, opt_allow_suspicious_udfs;
extern my_bool opt_secure_auth; extern my_bool opt_secure_auth;
extern my_bool opt_log_slow_admin_statements;
extern uint opt_crash_binlog_innodb; extern uint opt_crash_binlog_innodb;
extern char *shared_memory_base_name, *mysqld_unix_port; extern char *shared_memory_base_name, *mysqld_unix_port;
extern bool opt_enable_shared_memory; extern bool opt_enable_shared_memory;
......
...@@ -294,6 +294,7 @@ my_bool opt_sync_bdb_logs, opt_sync_frm, opt_allow_suspicious_udfs; ...@@ -294,6 +294,7 @@ my_bool opt_sync_bdb_logs, opt_sync_frm, opt_allow_suspicious_udfs;
my_bool opt_secure_auth= 0; my_bool opt_secure_auth= 0;
my_bool opt_short_log_format= 0; my_bool opt_short_log_format= 0;
my_bool opt_log_queries_not_using_indexes= 0; my_bool opt_log_queries_not_using_indexes= 0;
my_bool opt_log_slow_admin_statements= 0;
my_bool lower_case_file_system= 0; my_bool lower_case_file_system= 0;
my_bool opt_innodb_safe_binlog= 0; my_bool opt_innodb_safe_binlog= 0;
volatile bool mqh_used = 0; volatile bool mqh_used = 0;
...@@ -4196,7 +4197,8 @@ enum options_mysqld ...@@ -4196,7 +4197,8 @@ enum options_mysqld
OPT_TIME_FORMAT, OPT_TIME_FORMAT,
OPT_DATETIME_FORMAT, OPT_DATETIME_FORMAT,
OPT_LOG_QUERIES_NOT_USING_INDEXES, OPT_LOG_QUERIES_NOT_USING_INDEXES,
OPT_DEFAULT_TIME_ZONE OPT_DEFAULT_TIME_ZONE,
OPT_LOG_SLOW_ADMIN_STATEMENTS
}; };
...@@ -4456,7 +4458,7 @@ Disable with --skip-isam.", ...@@ -4456,7 +4458,7 @@ Disable with --skip-isam.",
"Log some extra information to update log. Please note that this option is deprecated; see --log-short-format option.", "Log some extra information to update log. Please note that this option is deprecated; see --log-short-format option.",
0, 0, 0, GET_NO_ARG, NO_ARG, 0, 0, 0, 0, 0, 0}, 0, 0, 0, GET_NO_ARG, NO_ARG, 0, 0, 0, 0, 0, 0},
{"log-queries-not-using-indexes", OPT_LOG_QUERIES_NOT_USING_INDEXES, {"log-queries-not-using-indexes", OPT_LOG_QUERIES_NOT_USING_INDEXES,
"Log queries that are executed without benefit of any index.", "Log queries that are executed without benefit of any index to the slow log if it is open.",
(gptr*) &opt_log_queries_not_using_indexes, (gptr*) &opt_log_queries_not_using_indexes, (gptr*) &opt_log_queries_not_using_indexes, (gptr*) &opt_log_queries_not_using_indexes,
0, GET_BOOL, NO_ARG, 0, 0, 0, 0, 0, 0}, 0, GET_BOOL, NO_ARG, 0, 0, 0, 0, 0, 0},
{"log-short-format", OPT_SHORT_LOG_FORMAT, {"log-short-format", OPT_SHORT_LOG_FORMAT,
...@@ -4467,8 +4469,13 @@ Disable with --skip-isam.", ...@@ -4467,8 +4469,13 @@ Disable with --skip-isam.",
"Tells the slave to log the updates from the slave thread to the binary log. You will need to turn it on if you plan to daisy-chain the slaves.", "Tells the slave to log the updates from the slave thread to the binary log. You will need to turn it on if you plan to daisy-chain the slaves.",
(gptr*) &opt_log_slave_updates, (gptr*) &opt_log_slave_updates, 0, GET_BOOL, (gptr*) &opt_log_slave_updates, (gptr*) &opt_log_slave_updates, 0, GET_BOOL,
NO_ARG, 0, 0, 0, 0, 0, 0}, NO_ARG, 0, 0, 0, 0, 0, 0},
{"log-slow-admin-statements", OPT_LOG_SLOW_ADMIN_STATEMENTS,
"Log slow OPTIMIZE, ANALYZE, ALTER and other administrative statements to the slow log if it is open.",
(gptr*) &opt_log_slow_admin_statements,
(gptr*) &opt_log_slow_admin_statements,
0, GET_BOOL, NO_ARG, 0, 0, 0, 0, 0, 0},
{"log-slow-queries", OPT_SLOW_QUERY_LOG, {"log-slow-queries", OPT_SLOW_QUERY_LOG,
"Log slow queries to this log file. Defaults logging to hostname-slow.log file.", "Log slow queries to this log file. Defaults logging to hostname-slow.log file. Must be enabled to activate other slow log options.",
(gptr*) &opt_slow_logname, (gptr*) &opt_slow_logname, 0, GET_STR, OPT_ARG, (gptr*) &opt_slow_logname, (gptr*) &opt_slow_logname, 0, GET_STR, OPT_ARG,
0, 0, 0, 0, 0, 0}, 0, 0, 0, 0, 0, 0},
{"log-update", OPT_UPDATE_LOG, {"log-update", OPT_UPDATE_LOG,
...@@ -6084,6 +6091,9 @@ get_one_option(int optid, const struct my_option *opt __attribute__((unused)), ...@@ -6084,6 +6091,9 @@ get_one_option(int optid, const struct my_option *opt __attribute__((unused)),
case (int) OPT_SLOW_QUERY_LOG: case (int) OPT_SLOW_QUERY_LOG:
opt_slow_log=1; opt_slow_log=1;
break; break;
case (int) OPT_LOG_SLOW_ADMIN_STATEMENTS:
opt_log_slow_admin_statements= 1;
break;
case (int) OPT_SKIP_NEW: case (int) OPT_SKIP_NEW:
opt_specialflag|= SPECIAL_NO_NEW_FUNC; opt_specialflag|= SPECIAL_NO_NEW_FUNC;
delay_key_write_options= (uint) DELAY_KEY_WRITE_NONE; delay_key_write_options= (uint) DELAY_KEY_WRITE_NONE;
...@@ -6443,6 +6453,9 @@ static void get_options(int argc,char **argv) ...@@ -6443,6 +6453,9 @@ static void get_options(int argc,char **argv)
if (opt_bdb) if (opt_bdb)
sql_print_warning("this binary does not contain BDB storage engine"); sql_print_warning("this binary does not contain BDB storage engine");
#endif #endif
if ((opt_log_slow_admin_statements || opt_log_queries_not_using_indexes) &&
!opt_slow_log)
sql_print_warning("options --log-slow-admin-statements and --log-queries-not-using-indexes have no effect if --log-slow-queries is not set");
/* /*
Check that the default storage engine is actually available. Check that the default storage engine is actually available.
......
...@@ -916,7 +916,7 @@ public: ...@@ -916,7 +916,7 @@ public:
bool query_error, bootstrap, cleanup_done; bool query_error, bootstrap, cleanup_done;
bool tmp_table_used; bool tmp_table_used;
bool charset_is_system_charset, charset_is_collation_connection; bool charset_is_system_charset, charset_is_collation_connection;
bool slow_command; bool enable_slow_log; /* enable slow log for current statement */
my_bool volatile killed; my_bool volatile killed;
/* /*
......
...@@ -1342,10 +1342,10 @@ bool dispatch_command(enum enum_server_command command, THD *thd, ...@@ -1342,10 +1342,10 @@ bool dispatch_command(enum enum_server_command command, THD *thd,
thd->command=command; thd->command=command;
/* /*
Commands which will always take a long time should be marked with Commands which always take a long time are logged into
this so that they will not get logged to the slow query log the slow log only if opt_log_slow_admin_statements is set.
*/ */
thd->slow_command=FALSE; thd->enable_slow_log= TRUE;
thd->set_time(); thd->set_time();
VOID(pthread_mutex_lock(&LOCK_thread_count)); VOID(pthread_mutex_lock(&LOCK_thread_count));
thd->query_id=query_id; thd->query_id=query_id;
...@@ -1383,7 +1383,7 @@ bool dispatch_command(enum enum_server_command command, THD *thd, ...@@ -1383,7 +1383,7 @@ bool dispatch_command(enum enum_server_command command, THD *thd,
uint tbl_len= *(uchar*) (packet + db_len + 1); uint tbl_len= *(uchar*) (packet + db_len + 1);
statistic_increment(com_other, &LOCK_status); statistic_increment(com_other, &LOCK_status);
thd->slow_command= TRUE; thd->enable_slow_log= opt_log_slow_admin_statements;
db= thd->alloc(db_len + tbl_len + 2); db= thd->alloc(db_len + tbl_len + 2);
tbl_name= strmake(db, packet + 1, db_len)+1; tbl_name= strmake(db, packet + 1, db_len)+1;
strmake(tbl_name, packet + db_len + 2, tbl_len); strmake(tbl_name, packet + db_len + 2, tbl_len);
...@@ -1658,7 +1658,7 @@ bool dispatch_command(enum enum_server_command command, THD *thd, ...@@ -1658,7 +1658,7 @@ bool dispatch_command(enum enum_server_command command, THD *thd,
uint32 slave_server_id; uint32 slave_server_id;
statistic_increment(com_other,&LOCK_status); statistic_increment(com_other,&LOCK_status);
thd->slow_command = TRUE; thd->enable_slow_log= opt_log_slow_admin_statements;
if (check_global_access(thd, REPL_SLAVE_ACL)) if (check_global_access(thd, REPL_SLAVE_ACL))
break; break;
...@@ -1848,8 +1848,11 @@ static void log_slow_query(THD *thd) ...@@ -1848,8 +1848,11 @@ static void log_slow_query(THD *thd)
time_t start_of_query=thd->start_time; time_t start_of_query=thd->start_time;
thd->end_time(); // Set start time thd->end_time(); // Set start time
/* If not reading from backup and if the query took too long */ /*
if (!thd->slow_command && !thd->user_time) // do not log 'slow_command' queries Do not log administrative statements unless the appropriate option is
set; do not log into slow log if reading from backup.
*/
if (thd->enable_slow_log && !thd->user_time)
{ {
thd->proc_info="logging slow query"; thd->proc_info="logging slow query";
...@@ -2292,7 +2295,7 @@ mysql_execute_command(THD *thd) ...@@ -2292,7 +2295,7 @@ mysql_execute_command(THD *thd)
check_table_access(thd,SELECT_ACL, tables,0) || check_table_access(thd,SELECT_ACL, tables,0) ||
check_global_access(thd, FILE_ACL)) check_global_access(thd, FILE_ACL))
goto error; /* purecov: inspected */ goto error; /* purecov: inspected */
thd->slow_command=TRUE; thd->enable_slow_log= opt_log_slow_admin_statements;
res = mysql_backup_table(thd, tables); res = mysql_backup_table(thd, tables);
break; break;
...@@ -2303,7 +2306,7 @@ mysql_execute_command(THD *thd) ...@@ -2303,7 +2306,7 @@ mysql_execute_command(THD *thd)
check_table_access(thd, INSERT_ACL, tables,0) || check_table_access(thd, INSERT_ACL, tables,0) ||
check_global_access(thd, FILE_ACL)) check_global_access(thd, FILE_ACL))
goto error; /* purecov: inspected */ goto error; /* purecov: inspected */
thd->slow_command=TRUE; thd->enable_slow_log= opt_log_slow_admin_statements;
res = mysql_restore_table(thd, tables); res = mysql_restore_table(thd, tables);
break; break;
} }
...@@ -2538,7 +2541,7 @@ unsent_create_error: ...@@ -2538,7 +2541,7 @@ unsent_create_error:
case SQLCOM_CREATE_INDEX: case SQLCOM_CREATE_INDEX:
if (check_one_table_access(thd, INDEX_ACL, tables)) if (check_one_table_access(thd, INDEX_ACL, tables))
goto error; /* purecov: inspected */ goto error; /* purecov: inspected */
thd->slow_command=TRUE; thd->enable_slow_log= opt_log_slow_admin_statements;
if (end_active_trans(thd)) if (end_active_trans(thd))
res= -1; res= -1;
else else
...@@ -2624,7 +2627,7 @@ unsent_create_error: ...@@ -2624,7 +2627,7 @@ unsent_create_error:
res= -1; res= -1;
else else
{ {
thd->slow_command=TRUE; thd->enable_slow_log= opt_log_slow_admin_statements;
res= mysql_alter_table(thd, select_lex->db, lex->name, res= mysql_alter_table(thd, select_lex->db, lex->name,
&lex->create_info, &lex->create_info,
tables, lex->create_list, tables, lex->create_list,
...@@ -2716,7 +2719,7 @@ unsent_create_error: ...@@ -2716,7 +2719,7 @@ unsent_create_error:
if (check_db_used(thd,tables) || if (check_db_used(thd,tables) ||
check_table_access(thd,SELECT_ACL | INSERT_ACL, tables,0)) check_table_access(thd,SELECT_ACL | INSERT_ACL, tables,0))
goto error; /* purecov: inspected */ goto error; /* purecov: inspected */
thd->slow_command=TRUE; thd->enable_slow_log= opt_log_slow_admin_statements;
res = mysql_repair_table(thd, tables, &lex->check_opt); res = mysql_repair_table(thd, tables, &lex->check_opt);
/* ! we write after unlocking the table */ /* ! we write after unlocking the table */
if (!res && !lex->no_write_to_binlog) if (!res && !lex->no_write_to_binlog)
...@@ -2736,7 +2739,7 @@ unsent_create_error: ...@@ -2736,7 +2739,7 @@ unsent_create_error:
if (check_db_used(thd,tables) || if (check_db_used(thd,tables) ||
check_table_access(thd, SELECT_ACL | EXTRA_ACL , tables,0)) check_table_access(thd, SELECT_ACL | EXTRA_ACL , tables,0))
goto error; /* purecov: inspected */ goto error; /* purecov: inspected */
thd->slow_command=TRUE; thd->enable_slow_log= opt_log_slow_admin_statements;
res = mysql_check_table(thd, tables, &lex->check_opt); res = mysql_check_table(thd, tables, &lex->check_opt);
break; break;
} }
...@@ -2745,7 +2748,7 @@ unsent_create_error: ...@@ -2745,7 +2748,7 @@ unsent_create_error:
if (check_db_used(thd,tables) || if (check_db_used(thd,tables) ||
check_table_access(thd,SELECT_ACL | INSERT_ACL, tables,0)) check_table_access(thd,SELECT_ACL | INSERT_ACL, tables,0))
goto error; /* purecov: inspected */ goto error; /* purecov: inspected */
thd->slow_command=TRUE; thd->enable_slow_log= opt_log_slow_admin_statements;
res = mysql_analyze_table(thd, tables, &lex->check_opt); res = mysql_analyze_table(thd, tables, &lex->check_opt);
/* ! we write after unlocking the table */ /* ! we write after unlocking the table */
if (!res && !lex->no_write_to_binlog) if (!res && !lex->no_write_to_binlog)
...@@ -2766,7 +2769,7 @@ unsent_create_error: ...@@ -2766,7 +2769,7 @@ unsent_create_error:
if (check_db_used(thd,tables) || if (check_db_used(thd,tables) ||
check_table_access(thd,SELECT_ACL | INSERT_ACL, tables,0)) check_table_access(thd,SELECT_ACL | INSERT_ACL, tables,0))
goto error; /* purecov: inspected */ goto error; /* purecov: inspected */
thd->slow_command=TRUE; thd->enable_slow_log= opt_log_slow_admin_statements;
res= (specialflag & (SPECIAL_SAFE_MODE | SPECIAL_NO_NEW_FUNC)) ? res= (specialflag & (SPECIAL_SAFE_MODE | SPECIAL_NO_NEW_FUNC)) ?
mysql_recreate_table(thd, tables, 1) : mysql_recreate_table(thd, tables, 1) :
mysql_optimize_table(thd, tables, &lex->check_opt); mysql_optimize_table(thd, tables, &lex->check_opt);
......
Markdown is supported
0%
or
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment