From f10b395982f1b607dafce92ac3dfcd6e5a4bbbbf Mon Sep 17 00:00:00 2001 From: "konstantin@mysql.com" <> Date: Thu, 16 Jun 2005 23:05:38 +0400 Subject: [PATCH] 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 | 1 + sql/mysqld.cc | 19 ++++++++++++++++--- sql/sql_class.h | 2 +- sql/sql_parse.cc | 33 ++++++++++++++++++--------------- 4 files changed, 36 insertions(+), 19 deletions(-) diff --git a/sql/mysql_priv.h b/sql/mysql_priv.h index 0d058190a46..e9e8b52270c 100644 --- a/sql/mysql_priv.h +++ b/sql/mysql_priv.h @@ -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_enable_named_pipe, opt_sync_frm, opt_allow_suspicious_udfs; extern my_bool opt_secure_auth; +extern my_bool opt_log_slow_admin_statements; extern uint opt_crash_binlog_innodb; extern char *shared_memory_base_name, *mysqld_unix_port; extern bool opt_enable_shared_memory; diff --git a/sql/mysqld.cc b/sql/mysqld.cc index 67a80c4ca20..951de53724f 100644 --- a/sql/mysqld.cc +++ b/sql/mysqld.cc @@ -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_short_log_format= 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 opt_innodb_safe_binlog= 0; volatile bool mqh_used = 0; @@ -4196,7 +4197,8 @@ enum options_mysqld OPT_TIME_FORMAT, OPT_DATETIME_FORMAT, 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.", "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}, {"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, 0, GET_BOOL, NO_ARG, 0, 0, 0, 0, 0, 0}, {"log-short-format", OPT_SHORT_LOG_FORMAT, @@ -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.", (gptr*) &opt_log_slave_updates, (gptr*) &opt_log_slave_updates, 0, GET_BOOL, 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 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, 0, 0, 0, 0, 0, 0}, {"log-update", OPT_UPDATE_LOG, @@ -6084,6 +6091,9 @@ get_one_option(int optid, const struct my_option *opt __attribute__((unused)), case (int) OPT_SLOW_QUERY_LOG: opt_slow_log=1; break; + case (int) OPT_LOG_SLOW_ADMIN_STATEMENTS: + opt_log_slow_admin_statements= 1; + break; case (int) OPT_SKIP_NEW: opt_specialflag|= SPECIAL_NO_NEW_FUNC; delay_key_write_options= (uint) DELAY_KEY_WRITE_NONE; @@ -6443,6 +6453,9 @@ static void get_options(int argc,char **argv) if (opt_bdb) sql_print_warning("this binary does not contain BDB storage engine"); #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. diff --git a/sql/sql_class.h b/sql/sql_class.h index fbd60373498..b6bf0dcdc45 100644 --- a/sql/sql_class.h +++ b/sql/sql_class.h @@ -916,7 +916,7 @@ public: bool query_error, bootstrap, cleanup_done; bool tmp_table_used; 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; /* diff --git a/sql/sql_parse.cc b/sql/sql_parse.cc index cd84c66cbba..4e714e70c5f 100644 --- a/sql/sql_parse.cc +++ b/sql/sql_parse.cc @@ -1342,10 +1342,10 @@ bool dispatch_command(enum enum_server_command command, THD *thd, thd->command=command; /* - Commands which will always take a long time should be marked with - this so that they will not get logged to the slow query log + Commands which always take a long time are logged into + the slow log only if opt_log_slow_admin_statements is set. */ - thd->slow_command=FALSE; + thd->enable_slow_log= TRUE; thd->set_time(); VOID(pthread_mutex_lock(&LOCK_thread_count)); thd->query_id=query_id; @@ -1383,7 +1383,7 @@ bool dispatch_command(enum enum_server_command command, THD *thd, uint tbl_len= *(uchar*) (packet + db_len + 1); 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); tbl_name= strmake(db, packet + 1, db_len)+1; strmake(tbl_name, packet + db_len + 2, tbl_len); @@ -1658,7 +1658,7 @@ bool dispatch_command(enum enum_server_command command, THD *thd, uint32 slave_server_id; 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)) break; @@ -1848,8 +1848,11 @@ static void log_slow_query(THD *thd) time_t start_of_query=thd->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"; @@ -2292,7 +2295,7 @@ mysql_execute_command(THD *thd) check_table_access(thd,SELECT_ACL, tables,0) || check_global_access(thd, FILE_ACL)) goto error; /* purecov: inspected */ - thd->slow_command=TRUE; + thd->enable_slow_log= opt_log_slow_admin_statements; res = mysql_backup_table(thd, tables); break; @@ -2303,7 +2306,7 @@ mysql_execute_command(THD *thd) check_table_access(thd, INSERT_ACL, tables,0) || check_global_access(thd, FILE_ACL)) goto error; /* purecov: inspected */ - thd->slow_command=TRUE; + thd->enable_slow_log= opt_log_slow_admin_statements; res = mysql_restore_table(thd, tables); break; } @@ -2538,7 +2541,7 @@ unsent_create_error: case SQLCOM_CREATE_INDEX: if (check_one_table_access(thd, INDEX_ACL, tables)) goto error; /* purecov: inspected */ - thd->slow_command=TRUE; + thd->enable_slow_log= opt_log_slow_admin_statements; if (end_active_trans(thd)) res= -1; else @@ -2624,7 +2627,7 @@ unsent_create_error: res= -1; else { - thd->slow_command=TRUE; + thd->enable_slow_log= opt_log_slow_admin_statements; res= mysql_alter_table(thd, select_lex->db, lex->name, &lex->create_info, tables, lex->create_list, @@ -2716,7 +2719,7 @@ unsent_create_error: if (check_db_used(thd,tables) || check_table_access(thd,SELECT_ACL | INSERT_ACL, tables,0)) 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); /* ! we write after unlocking the table */ if (!res && !lex->no_write_to_binlog) @@ -2736,7 +2739,7 @@ unsent_create_error: if (check_db_used(thd,tables) || check_table_access(thd, SELECT_ACL | EXTRA_ACL , tables,0)) 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); break; } @@ -2745,7 +2748,7 @@ unsent_create_error: if (check_db_used(thd,tables) || check_table_access(thd,SELECT_ACL | INSERT_ACL, tables,0)) 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); /* ! we write after unlocking the table */ if (!res && !lex->no_write_to_binlog) @@ -2766,7 +2769,7 @@ unsent_create_error: if (check_db_used(thd,tables) || check_table_access(thd,SELECT_ACL | INSERT_ACL, tables,0)) 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)) ? mysql_recreate_table(thd, tables, 1) : mysql_optimize_table(thd, tables, &lex->check_opt);