Below is the list of changes that have just been committed into a local
5.0 repository of davi. When davi 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-12-21 08:49:53-02:00, davi@stripped +5 -0
Bug#28386 the general log is incomplete
The problem is that the commands COM_STMT_CLOSE, COM_STMT_RESET,
COM_STMT_SEND_LONG_DATA, COM_PING and COM_REFRESH (detailed)
weren't being logged to the general log, which prevents more
detailed debugging and analysis of the server.
The solution is to log the general log the aforementioned
commands, detailing the commands arguments where it matters.
mysys/mf_iocache2.c@stripped, 2007-12-21 08:49:51-02:00, davi@stripped +8 -7
Don't call my_b_write if there is no bytes to write.
sql/sql_class.cc@stripped, 2007-12-21 08:49:51-02:00, davi@stripped +1 -0
Zero initialize name length.
sql/sql_parse.cc@stripped, 2007-12-21 08:49:52-02:00, davi@stripped +40 -1
Write to the general log PING commands and detail the
REFRESH command.
sql/sql_prepare.cc@stripped, 2007-12-21 08:49:52-02:00, davi@stripped +29 -2
Log COM_STMT_CLOSE, COM_STMT_RESET and COM_STMT_SEND_LONG_DATA
to the general log if not inside a stored procedure.
tests/mysql_client_test.c@stripped, 2007-12-21 08:49:52-02:00, davi@stripped +100 -7
Add test case for Bug#28386
diff -Nrup a/mysys/mf_iocache2.c b/mysys/mf_iocache2.c
--- a/mysys/mf_iocache2.c 2007-01-22 10:10:36 -02:00
+++ b/mysys/mf_iocache2.c 2007-12-21 08:49:51 -02:00
@@ -253,7 +253,7 @@ uint my_b_vprintf(IO_CACHE *info, const
uint out_length=0;
uint minimum_width; /* as yet unimplemented */
uint minimum_width_sign;
- uint precision; /* as yet unimplemented for anything but %b */
+ uint precision;
/*
Store the location of the beginning of a format directive, for the
@@ -295,7 +295,7 @@ uint my_b_vprintf(IO_CACHE *info, const
/* Skip if max size is used (to be compatible with printf) */
while (*fmt == '-') { fmt++; minimum_width_sign= -1; }
if (*fmt == '*') {
- precision= (int) va_arg(args, int);
+ precision= va_arg(args, uint);
fmt++;
} else {
while (my_isdigit(&my_charset_latin1, *fmt)) {
@@ -308,7 +308,7 @@ uint my_b_vprintf(IO_CACHE *info, const
if (*fmt == '.') {
fmt++;
if (*fmt == '*') {
- precision= (int) va_arg(args, int);
+ precision= va_arg(args, uint);
fmt++;
} else {
while (my_isdigit(&my_charset_latin1, *fmt)) {
@@ -317,21 +317,22 @@ uint my_b_vprintf(IO_CACHE *info, const
}
}
}
+ else
+ precision= ~0;
if (*fmt == 's') /* String parameter */
{
reg2 char *par = va_arg(args, char *);
- uint length2 = (uint) strlen(par);
- /* TODO: implement minimum width and precision */
+ uint length2 = (uint) strnlen(par, precision);
out_length+= length2;
- if (my_b_write(info, par, length2))
+ if (length2 && my_b_write(info, par, length2))
goto err;
}
else if (*fmt == 'b') /* Sized buffer parameter, only precision makes sense */
{
char *par = va_arg(args, char *);
out_length+= precision;
- if (my_b_write(info, par, precision))
+ if (precision && my_b_write(info, par, precision))
goto err;
}
else if (*fmt == 'd' || *fmt == 'u') /* Integer parameter */
diff -Nrup a/sql/sql_class.cc b/sql/sql_class.cc
--- a/sql/sql_class.cc 2007-11-20 14:14:49 -02:00
+++ b/sql/sql_class.cc 2007-12-21 08:49:51 -02:00
@@ -1739,6 +1739,7 @@ Statement::Statement(LEX *lex_arg, MEM_R
cursor(0)
{
name.str= NULL;
+ name.length= 0;
}
diff -Nrup a/sql/sql_parse.cc b/sql/sql_parse.cc
--- a/sql/sql_parse.cc 2007-12-10 09:19:46 -02:00
+++ b/sql/sql_parse.cc 2007-12-21 08:49:52 -02:00
@@ -782,6 +782,44 @@ static void reset_mqh(LEX_USER *lu, bool
#endif /* NO_EMBEDDED_ACCESS_CHECKS */
}
+static void log_refresh_cmd(THD *thd, ulong options)
+{
+ char buff[512];
+ String str(buff,(uint32) sizeof(buff), system_charset_info);
+ static struct {
+ ulong option;
+ const char *str;
+ } const refresh_opt[]= {
+ { REFRESH_GRANT, "PRIVILEGES, " },
+ { REFRESH_LOG, "LOGS, " },
+ { REFRESH_TABLES, "TABLES, " },
+ { REFRESH_HOSTS, "HOSTS, " },
+ { REFRESH_STATUS, "STATUS, " },
+ { REFRESH_THREADS, "THREADS, " },
+ { REFRESH_SLAVE, "SLAVE, " },
+ { REFRESH_MASTER, "MASTER, " },
+ { REFRESH_READ_LOCK, "TABLES WITH READ LOCK, " },
+ { REFRESH_QUERY_CACHE, "QUERY CACHE, " },
+ { REFRESH_QUERY_CACHE_FREE, "QUERY CACHE FREE, " },
+ { REFRESH_DES_KEY_FILE, "DES_KEY_FILE, " },
+ { REFRESH_USER_RESOURCES, "USER_RESOURCES, " }
+ };
+
+ str.length(0);
+
+ for (uint i= 0; i < array_elements(refresh_opt); i++)
+ {
+ if (refresh_opt[i].option & options)
+ str.append(refresh_opt[i].str);
+ }
+
+ if (str.is_empty())
+ mysql_log.write(thd, thd->command, NullS);
+ else
+ mysql_log.write(thd, thd->command, "%.*s",
+ str.length() - 2, str.c_ptr_quick());
+}
+
void thd_init_client_charset(THD *thd, uint cs_number)
{
/*
@@ -2079,7 +2117,7 @@ bool dispatch_command(enum enum_server_c
ulong options= (ulong) (uchar) packet[0];
if (check_global_access(thd,RELOAD_ACL))
break;
- mysql_log.write(thd,command,NullS);
+ log_refresh_cmd(thd, options);
if (!reload_acl_and_cache(thd, options, (TABLE_LIST*) 0, ¬_used))
send_ok(thd);
break;
@@ -2159,6 +2197,7 @@ bool dispatch_command(enum enum_server_c
}
case COM_PING:
statistic_increment(thd->status_var.com_other, &LOCK_status);
+ mysql_log.write(thd, command, NullS);
send_ok(thd); // Tell client we are alive
break;
case COM_PROCESS_INFO:
diff -Nrup a/sql/sql_prepare.cc b/sql/sql_prepare.cc
--- a/sql/sql_prepare.cc 2007-11-19 14:59:43 -02:00
+++ b/sql/sql_prepare.cc 2007-12-21 08:49:52 -02:00
@@ -2458,6 +2458,11 @@ void mysql_stmt_reset(THD *thd, char *pa
stmt->state= Query_arena::PREPARED;
+ /* Don't print if inside a stored procedure. */
+ if (thd->spcont == NULL)
+ mysql_log.write(thd, thd->command, "[%lu] %.*s", stmt->id,
+ stmt->name.length, stmt->name.str);
+
send_ok(thd);
DBUG_VOID_RETURN;
@@ -2543,6 +2548,8 @@ void mysql_stmt_get_longdata(THD *thd, c
uint param_number;
Prepared_statement *stmt;
Item_param *param;
+ char *extra_data;
+ ulong extra_length;
#ifndef EMBEDDED_LIBRARY
char *packet_end= packet + packet_length - 1;
#endif
@@ -2582,15 +2589,29 @@ void mysql_stmt_get_longdata(THD *thd, c
param= stmt->param_array[param_number];
#ifndef EMBEDDED_LIBRARY
- if (param->set_longdata(packet, (ulong) (packet_end - packet)))
+ extra_data= packet;
+ extra_length= (ulong) (packet_end - packet);
#else
- if (param->set_longdata(thd->extra_data, thd->extra_length))
+ extra_data= thd->extra_data;
+ extra_length= thd->extra_length;
#endif
+
+ if (param->set_longdata(extra_data, extra_length))
{
stmt->state= Query_arena::ERROR;
stmt->last_errno= ER_OUTOFMEMORY;
sprintf(stmt->last_error, ER(ER_OUTOFMEMORY), 0);
}
+
+ /* Don't print if inside a stored procedure. */
+ if (thd->spcont == NULL)
+ {
+ const char fmt[]= "[%lu] %.*s %.*b";
+ mysql_log.write(thd, thd->command, fmt, stmt->id,
+ stmt->name.length, stmt->name.str,
+ extra_length, extra_data);
+ }
+
DBUG_VOID_RETURN;
}
@@ -3064,6 +3085,12 @@ bool Prepared_statement::deallocate()
my_error(ER_PS_NO_RECURSION, MYF(0));
return TRUE;
}
+
+ /* Don't print if inside a stored procedure. */
+ if (thd->spcont == NULL)
+ mysql_log.write(thd, thd->command, "[%lu] %.*s", id,
+ name.length, name.str);
+
/* Statement map calls delete stmt on erase */
thd->stmt_map.erase(this);
return FALSE;
diff -Nrup a/tests/mysql_client_test.c b/tests/mysql_client_test.c
--- a/tests/mysql_client_test.c 2007-12-01 07:12:28 -02:00
+++ b/tests/mysql_client_test.c 2007-12-21 08:49:52 -02:00
@@ -15037,6 +15037,21 @@ static void test_bug15613()
mysql_stmt_close(stmt);
}
+static FILE *open_master_log(void)
+{
+ FILE *log_file;
+ char *master_log_filename;
+
+ master_log_filename = (char *) malloc(strlen(opt_vardir) + strlen("/log/master.log") + 1);
+ strcpy(master_log_filename, opt_vardir);
+ strcat(master_log_filename, "/log/master.log");
+ printf("Opening '%s'\n", master_log_filename);
+ log_file= my_fopen(master_log_filename, (int) (O_RDONLY | O_BINARY), MYF(MY_WME));
+ free(master_log_filename);
+
+ return log_file;
+}
+
/*
Bug#17667: An attacker has the opportunity to bypass query logging.
@@ -15067,7 +15082,6 @@ static void test_bug17667()
struct buffer_and_length *statement_cursor;
FILE *log_file;
- char *master_log_filename;
myheader("test_bug17667");
@@ -15109,12 +15123,7 @@ static void test_bug17667()
rc= mysql_query(mysql, "flush logs");
myquery(rc);
- master_log_filename = (char *) malloc(strlen(opt_vardir) + strlen("/log/master.log") + 1);
- strcpy(master_log_filename, opt_vardir);
- strcat(master_log_filename, "/log/master.log");
- printf("Opening '%s'\n", master_log_filename);
- log_file= my_fopen(master_log_filename, (int) (O_RDONLY | O_BINARY), MYF(MY_WME));
- free(master_log_filename);
+ log_file= open_master_log();
if (log_file != NULL) {
@@ -16152,6 +16161,89 @@ static void test_bug31669()
DBUG_VOID_RETURN;
}
+
+/**
+ Bug#28386 the general log is incomplete
+*/
+
+static void test_bug28386()
+{
+ int rc;
+ uint i;
+ MYSQL_STMT *stmt;
+ FILE *log_file;
+ char buffer[MAX_TEST_QUERY_LENGTH*2], *line;
+ struct {
+ const char *str;
+ size_t len;
+ int found;
+ } tokens[] = {
+ { "Close stmt", 0, 0 },
+ { "Reset stmt", 0, 0 },
+ { "Long Data", 0, 0 },
+ { "Ping", 0, 0 },
+ { "Refresh", 0, 0 },
+ { "PRIVILEGES, STATUS", 0, 0 }
+ };
+ DBUG_ENTER("test_bug28386");
+ myheader("test_bug28386");
+
+ sleep(30);
+
+ for (i= 0; i < array_elements(tokens); i++)
+ tokens[i].len= strlen(tokens[i].str);
+
+ stmt= mysql_simple_prepare(mysql, "SELECT 1");
+ check_stmt(stmt);
+
+ rc= mysql_stmt_execute(stmt);
+ check_execute(stmt, rc);
+
+ rc= my_process_stmt_result(stmt);
+ DIE_UNLESS(rc == 1);
+
+ rc= mysql_stmt_reset(stmt);
+ check_execute(stmt, rc);
+
+ rc= mysql_stmt_close(stmt);
+ DIE_UNLESS(!rc);
+
+ rc= mysql_ping(mysql);
+ DIE_UNLESS(!rc);
+
+ mysql_refresh(mysql, REFRESH_GRANT);
+ mysql_refresh(mysql, REFRESH_STATUS | REFRESH_GRANT);
+
+ log_file= open_master_log();
+
+ if (log_file == NULL)
+ {
+ fprintf(stderr, "Could not find the log file, VARDIR/log/master.log, so "
+ "test_bug28386 is \ninconclusive. Run test from the "
+ "mysql-test/mysql-test-run* program \nto set up the correct "
+ "environment for this test.\n\n");
+ DBUG_VOID_RETURN;
+ }
+
+ while ((line= fgets(buffer, MAX_TEST_QUERY_LENGTH*2, log_file)))
+ {
+ for (i= 0; i < array_elements(tokens); i++)
+ {
+ if (my_memmem(line, MAX_TEST_QUERY_LENGTH*2, tokens[i].str,
+ tokens[i].len))
+ tokens[i].found= 1;
+ }
+ }
+
+ for (i= 0; i < array_elements(tokens); i++)
+ DIE_UNLESS(tokens[i].found == 1);
+
+ my_fclose(log_file, MYF(0));
+
+ DBUG_VOID_RETURN;
+}
+
+
/*
Read and parse arguments and MySQL options from my.cnf
*/
@@ -16446,6 +16538,7 @@ static struct my_tests_st my_tests[]= {
{ "test_bug29948", test_bug29948 },
{ "test_bug29306", test_bug29306 },
{ "test_bug31669", test_bug31669 },
+ { "test_bug28386", test_bug28386 },
{ 0, 0 }
};
