#At file:///export/home/didrik/repo/trunk-sortaborted/ based on revid:bar@stripped
3535 Tor Didriksen 2011-01-19
Bug #36022 please log more information about "Sort aborted" queries
Write an additional warning message to the server log,
explaining why a sort operation is aborted.
The output in mysqld.err will look something like:
[ERROR] bin-dbg/sql/mysqld: Sort aborted
[Warning] Sort aborted : Out of memory (Needed 24 bytes)
[ERROR] bin-dbg/sql/mysqld: Out of sort memory; increase server sort buffer size
[ERROR] bin-dbg/sql/mysqld: Sort aborted
[Warning] Sort aborted : Out of sort memory; increase server sort buffer size
[ERROR] bin-dbg/sql/mysqld: Sort aborted
[Warning] Sort aborted : Incorrect number of arguments for FUNCTION test.f1; expected 0, got 1
If --log-warn=2 is enabled, we output information about host/user/query as well.
@ include/my_sys.h
Update comment for ME_NOREFRESH
@ mysql-test/r/filesort_debug.result
New test case.
@ mysql-test/t/filesort_debug.test
New test case.
@ sql/filesort.cc
Output an explanation using the error message from the THD Diagnostics_area.
@ sql/protocol.cc
Do not DBUG_RETURN(function_call_with DBUG_RETURN)
as it messes up the call stack in the debug output.
@ sql/unireg.h
Remove unused/confusing ERRMAPP macro.
modified:
include/my_sys.h
mysql-test/r/filesort_debug.result
mysql-test/t/filesort_debug.test
sql/filesort.cc
sql/protocol.cc
sql/unireg.h
=== modified file 'include/my_sys.h'
--- a/include/my_sys.h 2011-01-17 09:52:59 +0000
+++ b/include/my_sys.h 2011-01-19 15:49:12 +0000
@@ -104,7 +104,7 @@ typedef struct my_aio_result {
#define ME_HOLDTANG 8 /* Don't delete last keys */
#define ME_WAITTOT 16 /* Wait for errtime secs of for a action */
#define ME_WAITTANG 32 /* Wait for a user action */
-#define ME_NOREFRESH 64 /* Dont refresh screen */
+#define ME_NOREFRESH 64 /* Write the error message to error log */
#define ME_NOINPUT 128 /* Dont use the input libary */
#define ME_COLOUR1 ((1 << ME_HIGHBYTE)) /* Possibly error-colours */
#define ME_COLOUR2 ((2 << ME_HIGHBYTE))
=== modified file 'mysql-test/r/filesort_debug.result'
--- a/mysql-test/r/filesort_debug.result 2011-01-10 13:23:11 +0000
+++ b/mysql-test/r/filesort_debug.result 2011-01-19 15:49:12 +0000
@@ -1,11 +1,27 @@
#
# Bug#59331 filesort with priority queue: handling of out-of-memory
#
+SET @old_debug = @@session.debug;
CREATE TABLE t1(f0 int auto_increment primary key, f1 int, f2 varchar(200));
INSERT INTO t1(f1, f2) VALUES
(0,"0"),(1,"1"),(2,"2"),(3,"3"),(4,"4"),(5,"5"),
(6,"6"),(7,"7"),(8,"8"),(9,"9"),(10,"10");
-set debug= '+d,bounded_queue_init_fail';
+set session debug= '+d,bounded_queue_init_fail';
SELECT * FROM t1 ORDER BY f1 ASC, f0 LIMIT 1;
ERROR HY000: Out of memory (Needed NN bytes)
+set session debug=@old_debug;
DROP TABLE t1;
+#
+# Bug#36022 please log more information about "Sort aborted" queries
+#
+CREATE TABLE t1(f0 int auto_increment primary key, f1 int);
+INSERT INTO t1(f1) VALUES (0),(1),(2),(3),(4),(5);
+set session debug= '+d,make_char_array_fail';
+SELECT * FROM t1 ORDER BY f1 ASC, f0;
+ERROR HY001: Out of sort memory; increase server sort buffer size
+set session debug=@old_debug;
+CREATE FUNCTION f1() RETURNS INT RETURN 1;
+DELETE FROM t1 ORDER BY (f1(10)) LIMIT 1;
+ERROR 42000: Incorrect number of arguments for FUNCTION test.f1; expected 0, got 1
+DROP TABLE t1;
+DROP FUNCTION f1;
=== modified file 'mysql-test/t/filesort_debug.test'
--- a/mysql-test/t/filesort_debug.test 2011-01-10 13:23:11 +0000
+++ b/mysql-test/t/filesort_debug.test 2011-01-19 15:49:12 +0000
@@ -4,14 +4,36 @@
--echo # Bug#59331 filesort with priority queue: handling of out-of-memory
--echo #
+SET @old_debug = @@session.debug;
+
CREATE TABLE t1(f0 int auto_increment primary key, f1 int, f2 varchar(200));
INSERT INTO t1(f1, f2) VALUES
(0,"0"),(1,"1"),(2,"2"),(3,"3"),(4,"4"),(5,"5"),
(6,"6"),(7,"7"),(8,"8"),(9,"9"),(10,"10");
-set debug= '+d,bounded_queue_init_fail';
+set session debug= '+d,bounded_queue_init_fail';
--replace_regex /Needed [0-9]* bytes/Needed NN bytes/
--error 5
SELECT * FROM t1 ORDER BY f1 ASC, f0 LIMIT 1;
+set session debug=@old_debug;
+
+DROP TABLE t1;
+
+--echo #
+--echo # Bug#36022 please log more information about "Sort aborted" queries
+--echo #
+
+CREATE TABLE t1(f0 int auto_increment primary key, f1 int);
+INSERT INTO t1(f1) VALUES (0),(1),(2),(3),(4),(5);
+
+set session debug= '+d,make_char_array_fail';
+--error ER_OUT_OF_SORTMEMORY
+SELECT * FROM t1 ORDER BY f1 ASC, f0;
+set session debug=@old_debug;
+
+CREATE FUNCTION f1() RETURNS INT RETURN 1;
+--error ER_SP_WRONG_NO_OF_ARGS
+DELETE FROM t1 ORDER BY (f1(10)) LIMIT 1;
DROP TABLE t1;
+DROP FUNCTION f1;
=== modified file 'sql/filesort.cc'
--- a/sql/filesort.cc 2011-01-11 09:09:21 +0000
+++ b/sql/filesort.cc 2011-01-19 15:49:12 +0000
@@ -356,8 +356,25 @@ ha_rows filesort(THD *thd, TABLE *table,
}
}
if (error)
- my_message(ER_FILSORT_ABORT, ER(ER_FILSORT_ABORT),
+ {
+ DBUG_ASSERT(thd->stmt_da->status() == Diagnostics_area::DA_ERROR);
+ my_message(ER_FILSORT_ABORT,
+ ER_THD(thd, ER_FILSORT_ABORT),
MYF(ME_ERROR+ME_WAITTANG));
+ // Add explanation about why we aborted to the server log.
+ sql_print_warning("%s, %s",
+ ER_THD(thd, ER_FILSORT_ABORT),
+ thd->stmt_da->message());
+ if (global_system_variables.log_warnings > 1)
+ {
+ sql_print_warning("%s, host:%s, user:%s, thread: %lu, query: %-.4096s",
+ ER_THD(thd, ER_FILSORT_ABORT),
+ thd->security_ctx->host_or_ip,
+ &thd->security_ctx->priv_user[0],
+ (ulong) thd->thread_id,
+ thd->query());
+ }
+ }
else
statistic_add(thd->status_var.filesort_rows,
(ulong) num_rows, &LOCK_status);
@@ -408,6 +425,9 @@ static void make_char_array(FILESORT_INF
DBUG_PRINT("info", ("num_records %u length %u", num_records, length));
+ DBUG_EXECUTE_IF("make_char_array_fail",
+ DBUG_SET("+d,simulate_out_of_memory"););
+
if (!info->sort_keys)
info->sort_keys=
(uchar**) my_malloc(num_records * (length + sizeof(uchar*)), MYF(0));
=== modified file 'sql/protocol.cc'
--- a/sql/protocol.cc 2010-12-21 12:23:49 +0000
+++ b/sql/protocol.cc 2011-01-19 15:49:12 +0000
@@ -543,9 +543,10 @@ bool Protocol::send_ok(uint server_statu
const char *message)
{
DBUG_ENTER("Protocol::send_ok");
-
- DBUG_RETURN(net_send_ok(thd, server_status, statement_warn_count,
- affected_rows, last_insert_id, message));
+ const bool retval=
+ net_send_ok(thd, server_status, statement_warn_count,
+ affected_rows, last_insert_id, message);
+ DBUG_RETURN(retval);
}
@@ -558,8 +559,8 @@ bool Protocol::send_ok(uint server_statu
bool Protocol::send_eof(uint server_status, uint statement_warn_count)
{
DBUG_ENTER("Protocol::send_eof");
-
- DBUG_RETURN(net_send_eof(thd, server_status, statement_warn_count));
+ const bool retval= net_send_eof(thd, server_status, statement_warn_count);
+ DBUG_RETURN(retval);
}
@@ -573,8 +574,8 @@ bool Protocol::send_error(uint sql_errno
const char *sql_state)
{
DBUG_ENTER("Protocol::send_error");
-
- DBUG_RETURN(net_send_error_packet(thd, sql_errno, err_msg, sql_state));
+ const bool retval= net_send_error_packet(thd, sql_errno, err_msg, sql_state);
+ DBUG_RETURN(retval);
}
=== modified file 'sql/unireg.h'
--- a/sql/unireg.h 2010-07-16 21:00:50 +0000
+++ b/sql/unireg.h 2011-01-19 15:49:12 +0000
@@ -56,8 +56,6 @@ typedef struct st_ha_create_information
#define ER_THD_OR_DEFAULT(thd,X) ((thd) ? ER_THD(thd, X) : ER_DEFAULT(X))
-#define ERRMAPP 1 /* Errormap f|r my_error */
-
#define ME_INFO (ME_HOLDTANG+ME_OLDWIN+ME_NOREFRESH)
#define ME_ERROR (ME_BELL+ME_OLDWIN+ME_NOREFRESH)
#define MYF_RW MYF(MY_WME+MY_NABP) /* Vid my_read & my_write */
Attachment: [text/bzr-bundle] bzr/tor.didriksen@oracle.com-20110119154912-q9i9er12nmmc69do.bundle
