Bug #30771 log more info about threads KILL'd and Sort Aborted messages

Description:
In mysql error logs you might see this:

070230 01:22:12 [ERROR] /opt/mysql/bin/mysqld: Sort aborted

In some cases it's impossible to know which query had an aborted sort, because often clients are badly written and don't check all results/errors.

It's possible for variety of reasons, including somebody had KILL'd the query during a sort operation.

Other reason is out of disk space in tmpdir.  It's hard to figure out exact query causing the error.

How to repeat:
kill a query busy sorting and try figure out from the logs what happened and why.

Suggested fix:
I suggest that sort aborted errors contain the query, the connection id, the user@host combination.

Then, if KILL <id> is issued it would be nice to log who sent the command and which query (connection_id) got killed.

All this extra logging could be included in --log-warnings=2 or 3?

A proposed patch for this - I have tried to add as many language translations as possible, but can not find out how to say 'By KILL command' in all of those provided.

A sample of the output:

070905 11:50:39 [ERROR] Sort aborted. By KILL command: YES SQL: update t1 set j = 6 order by i desc, j asc
070905 11:50:55 [ERROR] Sort aborted. By KILL command: YES SQL: update t1 set j = 6 order by i desc, j asc

medusa:/Users/markleith/mysql/mysql-5.2-runtime root# bk -r diffs -u
===== sql/filesort.cc 1.134 vs edited =====
--- 1.134/sql/filesort.cc       2007-07-25 21:23:37 +01:00
+++ edited/sql/filesort.cc      2007-09-04 19:38:12 +01:00
@@ -306,8 +306,9 @@
     }
   }
   if (error)
-    my_message(ER_FILSORT_ABORT, ER(ER_FILSORT_ABORT),
-               MYF(ME_ERROR+ME_WAITTANG));
+    sql_print_error(ER(ER_FILSORT_ABORT),
+                    thd->killed ? ER(ER_YES) : ER(ER_NO),
+                                       thd->query);
   else
     statistic_add(thd->status_var.filesort_rows,
                  (ulong) records, &LOCK_status);
===== sql/share/errmsg.txt 1.109 vs edited =====
--- 1.109/sql/share/errmsg.txt  2007-08-26 07:11:37 +01:00
+++ edited/sql/share/errmsg.txt 2007-09-05 12:30:53 +01:00
@@ -646,30 +646,30 @@
         swe "'%-.192s' är låst mot användning"
         ukr "'%-.192s' ÚÁÂÌÏËÏ×ÁÎÉÊ ÎÁ ×ÎÅÓÅÎÎÑ ÚͦÎ"
 ER_FILSORT_ABORT  
-        cze "TBøídìní pøeru¹eno"
-        dan "Sortering afbrudt"
-        nla "Sorteren afgebroken"
-        eng "Sort aborted"
-        jps "Sort ’†’f",
-        est "Sorteerimine katkestatud"
-        fre "Tri alphabétique abandonné"
-        ger "Sortiervorgang abgebrochen"
-        greek "Ç äéáäéêáóßá ôáîéíüìéóçò áêõñþèçêå"
-        hun "Sikertelen rendezes"
-        ita "Operazione di ordinamento abbandonata"
-        jpn "Sort ̾̂"
-        kor "¼ÒÆ®°¡ ÁߴܵǾú½À´Ï´Ù."
-        nor "Sortering avbrutt"
-        norwegian-ny "Sortering avbrote"
-        pol "Sortowanie przerwane"
-        por "Ordenação abortada"
-        rum "Sortare intrerupta"
-        rus "óÏÒÔÉÒÏ×ËÁ ÐÒÅÒ×ÁÎÁ"
-        serbian "Sortiranje je prekinuto"
-        slo "Triedenie preru¹ené"
-        spa "Ordeancion cancelada"
-        swe "Sorteringen avbruten"
-        ukr "óÏÒÔÕ×ÁÎÎÑ ÐÅÒÅÒ×ÁÎÏ"
+        cze "TBøídìní pøeru¹eno. By KILL command: %s SQL: %s"
+        dan "Sortering afbrudt. By KILL command: %s SQL: %s"
+        nla "Sorteren afgebroken. Door KILL commando: %s SQL: %s"
+        eng "Sort aborted. By KILL command: %s SQL: %s"
+        jps "Sort ’†’f. By KILL command: %s SQL: %s",
+        est "Sorteerimine katkestatud. By KILL command: %s SQL: %s"
+        fre "Tri alphabétique abandonné. Avec la commande KILL: %s SQL: %s"
+        ger "Sortiervorgang abgebrochen. Durch KILL kommando: %s SQL: %s"
+        greek "Ç äéáäéêáóßá ôáîéíüìéóçò áêõñþèçêå. By KILL command: %s SQL: %s"
+        hun "Sikertelen rendezes. By KILL command: %s SQL: %s"
+        ita "Operazione di ordinamento abbandonata. Ucciso: %s SQL: %s"
+        jpn "Sort ̾̂. By KILL command: %s SQL: %s"
+        kor "¼ÒÆ®°¡ ÁߴܵǾú½À´Ï´Ù. By KILL command: %s SQL: %s"
+        nor "Sortering avbrutt. By KILL command: %s SQL: %s"
+        norwegian-ny "Sortering avbrote. By KILL command: %s SQL: %s"
+        pol "Sortowanie przerwane. By KILL command: %s SQL: %s"
+        por "Ordenação abortada. Terminado por KILL commando: %s SQL: %s"
+        rum "Sortare intrerupta. By KILL command: %s SQL: %s"
+        rus "óÏÒÔÉÒÏ×ËÁ ÐÒÅÒ×ÁÎÁ. ÐÒÉ ÐÏÍÏÝÉ ËÏÍÁÎÄÙ KILL: %s SQL: %s"
+        serbian "Sortiranje je prekinuto. By KILL command: %s SQL: %s"
+        slo "Triedenie preru¹ené. By KILL command: %s SQL: %s"
+        spa "Ordeancion cancelada. Terminado por KILL commando: %s SQL: %s"
+        swe "Sorteringen avbruten. Av KILL kommandot: %s SQL: %s"
+        ukr "óÏÒÔÕ×ÁÎÎÑ ÐÅÒÅÒ×ÁÎÏ. ÐÒÉ ÐÏÍÏÝÉ ËÏÍÁÎÄÙ KILL: %s SQL: %s"
 ER_FORM_NOT_FOUND  
         cze "Pohled '%-.192s' pro '%-.192s' neexistuje"
         dan "View '%-.192s' eksisterer ikke for '%-.192s'"

Thank you for a reasonable feature request.

There are some known causes for "sort aborted" messages, such as :

o) insufficient disk space in tmpdir prevented tmpfile from being created
o) insufficient memory for sort_buffer_size to be allocated
o) somebody ran KILL <id> in the middle of a filesort
o) the server was shutdown while some queries were sorting
o) a transaction got rolled back or aborted due to lock wait timeout or deadlock
o) unexpected errors, such as source table or even tmp table was corrupt
o) processing of a subquery failed which was also sorting

duplicate of bug #36022 which is fixed.

Noted in 5.5.11, 5.6.2 changelogs.

Previously, for queries that were aborted due to a sort problem or
terminated with KILL in the middle of a sort, the server wrote the
message Sort aborted to the error log. Now the server writes more
information about the cause of the error. These causes include:

Insufficient disk space in tmpdir prevented tmpfile from being created
Insufficient memory for sort_buffer_size to be allocated
Somebody ran KILL <replaceable>id</replaceable> in the middle of a filesort
The server was shutdown while some queries were sorting
A transaction got rolled back or aborted due to lock wait timeout or
  deadlock
Unexpected errors, such as source table or even tmp table was corrupt
  processing of a subquery failed which was also sorting

CHANGESET - http://lists.mysql.com/commits/131988