From: Tor Didriksen
Date: January 19 2011 3:49pm
Subject: bzr commit into mysql-trunk branch (tor.didriksen:3535) Bug#36022
List-Archive: http://lists.mysql.com/commits/129220
X-Bug: 36022
Message-Id: <20110119154916.4CD6E3727@atum07.norway.sun.com>
MIME-Version: 1.0
Content-Type: multipart/mixed; boundary="===============2962805240579379767=="

--===============2962805240579379767==
MIME-Version: 1.0
Content-Type: text/plain; charset="us-ascii"
Content-Transfer-Encoding: 7bit
Content-Disposition: inline

#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 */


--===============2962805240579379767==
MIME-Version: 1.0
Content-Type: text/bzr-bundle; charset="us-ascii";
	name="bzr/tor.didriksen@stripped"
Content-Transfer-Encoding: 7bit
Content-Disposition: inline

# Bazaar merge directive format 2 (Bazaar 0.90)
# revision_id: tor.didriksen@stripped\
#   q9i9er12nmmc69do
# target_branch: file:///export/home/didrik/repo/trunk-sortaborted/
# testament_sha1: 5db7f50a38aa29864d881ee7b783ca8b0458256e
# timestamp: 2011-01-19 16:49:16 +0100
# base_revision_id: bar@stripped
# 
# Begin bundle
IyBCYXphYXIgcmV2aXNpb24gYnVuZGxlIHY0CiMKQlpoOTFBWSZTWd21o5YABu9/gFA9FABb////
f+ff6r////pgDs+15YrtPm7xYKFUiWCDWbHLdPR3s57tz2xzvdc6DcA9dQkkSNNBNMNFN6JgxTJo
xoU0A0BoDQaADQSSCDRoJppoTU00TaGKeoyBpoGTQYTCNDTygcZME0MhkZGTQ0AaDIwgGg0aZDEN
ABIiI0jVT9U/1UeTI9U/ajVNhT2qaNqNqeiADamgGgaMj1AikgIVP2mlT9lPSE8mqfpqnmSn6IaN
QAAHpAAABJEBBMjRoIyaNAlP01TanlMg0aZGgHqaAaBpEuphYdkwrLGGT7cc2XMz9GWJzZO27BAn
OB3Yjhms9dh9Ol9zmzLvhHAR5wVKjYw2Z4PqhEvCSVJew2Phc9Ws/PBPZq3A5vNRCBTv+NvSnwSD
pYSvzwJNHhpDPJjhJzqsZkaNsnbGNXoPkV0y0JB7t7gCoCX2riv5bSdA7p2948+XYYT7wvOLhE20
22DaY0sz0ZcgDfAyLtPLBnxRs2RFsJjLyjhXvjrqmJYUck4T5no0+tO2jjNoaTCdirLsacpTi161
ZnTw6zIwPPSHidN7L+n6LPhPtpx5TxjHnHlvKYHdMjmoyCARIjl7FIkFUSzv5Cgy2aCe/vEXEgYX
JFw2iakCrLmgdBwoic4x3goFUS990KCDVujJRT+0aFvbssLOG+SY/nbsmoFFMHV3qLmZyKDIuKQm
LBSHVl6dKiIEQJrJlav4iVMeoOwfsMHWbiYLs/38M8tWsm44NufRhufCrZnxmrViDgwYsuyDTWG3
F1NRTVetUFVjr0G31F5r94nSKsaclJgQ/yswxvHddh6n1QC0JnyfG/IyxqdhEYCB7xhiVwy3LTzY
69mp0WIo84xSLWAeRJxAYDEZjXfU1be162zEGC+dDdQPh4YXj9O9+iCO+9S9ZkO4Uil/GULwlWJC
bkt+rleLxYYZHlNDzMlSblmexf98IysofOHqS7pHg5aIpyY64GoqaCHN0s+4A5eFTaVvD4Rfllp0
1y1aI/CU7EydtckQTIBy9IL5HGgMDNRF4jx8v5ebjFK3VW1tkEQfALAdPOkVMNXTv5poDPXCOtwx
Q0VcsjWdedtF68JYo50e1YF81C2NYBORA0JNIUSTwDhOgLVYoVKYq+DUMD1Nzy2KVZjIK+l0JYMu
WR6bQNseJfXT6+1gFBkDD7nA8IOMi0VRjY9uiJ7ozQqUJN9bhwLfS6AmHjE3m3v3FUkptaanBE6e
E8bzeAUjDDyjdfTdjY79oBbUyooHUKDmADof3V06KgEMByd+qNphqOHncfqymkEgWWuHNthx4mp2
GGcwFonAgZi4nU4JzkZqfbpsuNzVg7bMXbI+eKrDmTANdkkkpHG617I0oXQVg+glmUjz7L6x6t65
SwsuMKD4NhSWb88HiMRwuq467jl39KrAJ8StTKCz214Pqa6L04HcLbdYdhtBXl2Wg7u8iMQnoB0c
uUyArK0IrSYN2/WnkcdhDKpB7pl2jJyY4+qVsvvida4jGJs4reurguOrvOSw0a8zLBPzi7xlyGWc
SnhVHaymKzQcCMMy1+7mSXXQuvLiAvFcTgXywLXyasIkACzEiPZo+BeebrUs5HAcrVCsI3EyOi3H
QsILZQ5bh/GZ7JxWbeGX4VwMlQU6RcqAUs3mYyx0UJKfHSROpqm2Fo+YqGFO5MHC88MDcUQJlxRj
q6U5TnljKV77LawaYyoa2FeQpW14LIl7mzVpqMjngazP0xlE32MAZX6aOk6mWERynhRQ8FNfSpLs
VmO/dmMa2uBXYcbEIs5RguxHLGJtNhmZuMCDVM8sJnJwI4kjCWLxd+vhr16moAjWXYDziVZWaLHc
LGDGGTPdjLXnaQI3ENZIcQibI1FJGVBqKpmnPkRv2XnPuyxcxN29eyRp1WQg6EyqcKwAJXpBaPKe
estsHkUpKHBgUIjDFSFgLqkQ4ONkPnnvhnJsC42jz3FcIAFhSZcQAx3EBLpnrxYdky7na2SpRphj
nuohnTaxFRLkigq3b+81Ol1SlKJvoBIos4Ai94Fwi2DwWHxd+yY/jiVDSmHLTeNCjiTeU9CW/rsE
HTJv8JgMGD4WNjEdAnEX2DPqFPt84iDdmoNQYLQ0B+5q+QX+h6jzRgP7Q8s6OAbBg2N+gRQCgV5Y
PwLwodgn4wu+i8X7XnYDFKrkL0iiFzjreTLjFgrkY+UKFBfax+/v9PUWlKuHIJYXHU8NhaI9pTI2
sKwkFFXtC01EAiKY959wpg4uDiLwvriRKIERMi4Tpp5EWW0rIkQiJhFYYloYoviFMaArsF7r633g
wvWDGRUSQxTZigiHXuFBKSRWJMgn1uLyRmOL3F0RtoNPEXotRmUMC4d0TE5QMoWKop0KIHCdl1pm
BkLYglqomT4lJ852Byd2hLoUQ8NwX6a2iGlRldSRXQGv8TFdHImeI6DpGIaPhcyMiKgMTCv2EE3w
g+u+aXuswrFCMOyZSVKl6Int6oDbHqqXbrgPoGFgfQfVI+s+kfKzYrl899lxOUrj7qFfzvSNTI8h
7B7bUI2YXGoqdieY+Tm6qkKSCVw2aNzk/HiFulD0ERTyxJFvk8+q1dhdJokqzD1L1svEmlStZ01b
xazGJ2snsXCgjPW3oFXQuzCwlSvBSa6RyqWF5OeJO4E2wsdQ7j1F5w2OQzvRaVnISLgoZrwmbSTA
P7kJ92S5ocSjzS50G06YG/eZDA4ZrQDbtNE4riE+yxadsDeMWFJpdaeuojrOTuzT1iqlYSYSIqZq
NAhY7/4upFwyK3b1cXIlKZA7let5Sg32i1U2o7UQLiFOl7xtNmzPmF4LzFd0YawHOREvZWgcydSO
cwsQmFIg0VmczoeXH4hNdOBpPx3roXnNhHcwzDgWYm1f1evWd+mh0Xcr0guJWuLsNqqgEgI2syn2
WHq1Pd5nMyxircqnUFNh1OR7tLqGqyYwbmQF0XFPQVygZxHN5zO66nY09x4nsIEy08ym4XIW+ybZ
sh5rIFoLkE6SZbppw1Dr2GszSEx4q9UOww4GhFWWtguaOY+EhygZlLWMu8SNnfgvI242q3fo1Y5W
5I4aclmTbfg7kzrILm1Pb0gnXDzztSwbWCQG/HOc5eybsWcAl0xiSL+kGXljo7h08pslNeSezpBk
lkJRERBO2SIAdfWKURVGQcyt52sWoVhXnf+nsS6Av2FhiJZnigBi+SGeUiIlqHmrDCd7ns8hpMiI
RQlg3qYuFQnAtDIvpVuQyqZc67RW8omFIKO4tw6BnM3Ea+9tTXPuTwRfARHHO5ZZslQogY1G5nMs
UUCXB5JwmFqaZnkU4Qp2PdpssoedznB07X8c2UnU3htirKroAncKh0gkytcCpIDpYw1BnaxQq4e+
wM5k1wOSw8AQ0lRjnD0AN37SrnCh6hxZATzSCE1L7IpY9FIEakcAEZQKnDNYhG/dFYnRBLZREK/D
k5krq1ELDtc87L0SAYYQzNVJFZxIGcVS1d0PUSCPWs8cRoVNR4xUY3EpC6fjNJsM2zsCGxV3HuWq
i/IutBt9/yZTBG3hBNjFDLJcERkOI2hRBHxXGK8rFQGnqWV3ZmqdGDAWKW1CGEFidYkElf3C9Voh
FtPe+Rp1FVnnajtb20djIr9uocth3jwxuS8RwZ21qn0WYW9/vmBvW422AG5jg8w9Tl6YaMwYiZ7q
JWrGXPHI4r3e5GADLUUnmcTSKMktSjbvJ+K3l0mvosPnV7wgV34IwYBmeMwNrayTF7FLkgmR8CmN
ArFXcdY0YNBeoKTxW0qw0yFFkmYI2uwqoc2j+1cADOdxdydQVlqwxUkLTA4QQNNiLEyrunXtH4O+
tniZNKpZ2gd7K9opio3Usjraq8w2+xWB2jom4yd5tHHIRzQXgvdLHDHa022S9MGhhnULJesiTIXN
C4zxQuSRYCwopZhltWhwGy0uKy0sci/FWUV8WcKhBs7K8W+QwL41LtLW1qZmp899lbOUnHJx41YO
kOvDqk4MgDqOFO13YuYR1hcw4NzbolcYOlchBBZA6qJ1CauATjFLEM9MTECt8pn0MzhQ56iDY21m
xJihXsTwc7q9ElzUsevD2AmBEHxmclnXW1qW9DK01deXFUMEspU4ySwqxCMR5GvEqJUbqOGNprud
wuK0fV5MqSc0kHhRTjFiYc+7kQsqaAO8v8QRsTrlw4pWsB7TsAwmLzawXy2lgG9hgLVIVy+bWdzC
ZSAySV8/QX3mwd3d3d3iuCHiDFPh/55JWAKxMI7Tezkmxc3uQpIiWoIo3PMWxTLG6IIXGagmHgoL
PiQCES4CHvpCIOrXlNETJlpBdy+aGFOsqIwGtFOTXpmXaCeIScDmvRVtZqNNahgNVXg8Tju1HoDH
WWEIAn0q+ovQXxPu+yFQNjct6r16jXxIpbMHFOZYsSBGh1nakwn/NVB1qoXPJi9gL7ViKZA2VWKq
LlJaRREbdQG1elkwwCyKEtqWjA8ulA6CQkyrBsicSnVDqO9X1p53vReTMfuB3te9ORgsV6rnoFdL
QsS97f8Ox8LNaFLS99jOdLpsLoahwZnV0MmjDVdsIbS27prxs4Do7U4nQmW1b/VgZiIx4MF5wVgu
fkczrcbsSkGNNd97rExsOPN2uWXL5oj/xdyRThQkN21o5YA=


--===============2962805240579379767==--