Bug #35477 sort_union() leaks file descriptors whenever goes over sort_buffer
Submitted: 21 Mar 2008 11:10 Modified: 1 May 2008 1:52
Reporter: Domas Mituzas Email Updates:
Status: Duplicate Impact on me:
None 
Category:MySQL Server: General Severity:S2 (Serious)
Version:5.0-bk, 5.1.24, 6.0 OS:Any
Assigned to: Assigned Account
Tags: fd leak, memory leak
Triage: D2 (Serious) / R2 (Low) / E2 (Low)

[21 Mar 2008 11:10] Domas Mituzas
Description:
whenever sort_union() is used, and sort_buffer_size is reached, temporary files are leaked:

mysqld  3988 mysql  122u     REG      14,2      78654 16999463 /private/var/tmp/MY69MtDm
mysqld  3988 mysql  123u     REG      14,2      78654 16999469 /private/var/tmp/MYuUS218
mysqld  3988 mysql  124u     REG      14,2      78654 16999475 /private/var/tmp/MYXTIgLK
mysqld  3988 mysql  125u     REG      14,2      78654 16999481 /private/var/tmp/MYhnvrNz
mysqld  3988 mysql  126u     REG      14,2      78654 16999487 /private/var/tmp/MYXAYcoG
mysqld  3988 mysql  127u     REG      14,2      78654 16999493 /private/var/tmp/MYhOGRAZ
mysqld  3988 mysql  128u     REG      14,2      78654 16999499 /private/var/tmp/MY1RLE4Q
mysqld  3988 mysql  129u     REG      14,2      78654 16999505 /private/var/tmp/MYwXVR6D
mysqld  3988 mysql  130u     REG      14,2      78654 16999511 /private/var/tmp/MYh8SGBC

How to repeat:
CREATE TABLE `jtest` (
  `a` varchar(255) default NULL,
  `b` varchar(255) default NULL,
  `c` varchar(255) default NULL,
  KEY `a` (`a`),
  KEY `b` (`b`),
  KEY `c` (`c`)
) ENGINE=MyISAM 

fill with few megabytes of random data, so that hitting sort buffer problems would be easier

set sort_buffer_size=10000;
then loop: 
select * from jtest where a like '5%' or b like '5%' order by c limit 1;

mysql> explain select * from jtest where a like '5%' or b like '5%' order by c limit 1 \G
*************************** 1. row ***************************
           id: 1
  select_type: SIMPLE
        table: jtest
         type: index_merge
possible_keys: a,b
          key: a,b
      key_len: 258,258
          ref: NULL
         rows: 23746
        Extra: Using sort_union(a,b); Using where; Using filesort
1 row in set (0.00 sec)

Suggested fix:
close the files?
[21 Mar 2008 11:18] Domas Mituzas
example dump file

Attachment: jtest.sql.gz (application/x-gzip, text), 465.77 KiB.

[21 Mar 2008 11:22] Domas Mituzas
This bug got a brother at #35478 - it also returns invalid data
[26 Mar 2008 23:43] Domas Mituzas
My amateurish fix, seems to handle the situation without too much crashing, and doesn't leak FDs. Bug#35478 still there, though:
flute:~/Development/mysql-5.0/sql midom$ diff -U 7 filesort.cc filesort.cc.fixed 
--- filesort.cc 2008-03-27 01:41:17.000000000 +0200
+++ filesort.cc.fixed   2008-03-27 01:41:08.000000000 +0200
@@ -553,14 +553,15 @@
   if (quick_select)
   {
     /*
       index_merge quick select uses table->sort when retrieving rows, so free
       resoures it has allocated.
     */
     end_read_record(&read_record_info);
+    free_io_cache(select->quick->head);
   }
   else
   {
     (void) file->extra(HA_EXTRA_NO_CACHE);     /* End cacheing of records */
     if (!next_pos)
       file->ha_rnd_end();
   }
[27 Mar 2008 6:20] Domas Mituzas
patch seems to pass testsuite
[27 Mar 2008 9:34] Domas Mituzas
This bug also leaks memory:

==18833== 66,073 (510 direct, 65,563 indirect) bytes in 6 blocks are definitely lost in loss record 6 of 7
==18833==    at 0x4022765: malloc (vg_replace_malloc.c:149)
==18833==    by 0x831A874: my_malloc (in /usr/local/mysql-5.0/libexec/mysqld)
==18833==    by 0x8219CFF: Unique::get(st_table*) (in /usr/local/mysql-5.0/libexec/mysqld)
==18833==    by 0x824B166: QUICK_INDEX_MERGE_SELECT::read_keys_and_merge() (in /usr/local/mysql-5.0/libexec/mysqld)
==18833==    by 0x825B5AD: find_all_keys(st_sort_param*, SQL_SELECT*, unsigned char**, st_io_cache*, st_io_cache*, st_io_cache*) (in /usr/local/mysql-5.0/libexec/mysqld)
==18833==    by 0x825D7A8: filesort(THD*, st_table*, st_sort_field*, unsigned, SQL_SELECT*, unsigned long, unsigned long*) (in /usr/local/mysql-5.0/libexec/mysqld)
==18833==    by 0x81F56A4: create_sort_index(THD*, JOIN*, st_order*, unsigned long, unsigned long) (in /usr/local/mysql-5.0/libexec/mysqld)
==18833==    by 0x8201904: JOIN::exec() (in /usr/local/mysql-5.0/libexec/mysqld)
==18833==    by 0x8203AE7: mysql_select(THD*, Item***, TABLE_LIST*, unsigned, List<Item>&, Item*, unsigned, st_order*, st_order*, Item*, st_order*, unsigned long long, select_result*, st_select_lex_unit*, st_select_lex*) (in /usr/local/mysql-5.0/libexec/mysqld)
==18833==    by 0x820436E: handle_select(THD*, st_lex*, select_result*, unsigned long) (in /usr/local/mysql-5.0/libexec/mysqld)
==18833==    by 0x81AC028: mysql_execute_command(THD*) (in /usr/local/mysql-5.0/libexec/mysqld)
==18833==    by 0x81B14BB: mysql_parse(THD*, char const*, unsigned, char const**) (in /usr/local/mysql-5.0/libexec/mysqld)
==18833== 
==18833== 
==18833== 818,984 bytes in 4 blocks are possibly lost in loss record 7 of 7
==18833==    at 0x4022765: malloc (vg_replace_malloc.c:149)
==18833==    by 0x831A874: my_malloc (in /usr/local/mysql-5.0/libexec/mysqld)
==18833==    by 0x825AA8F: init_read_record(st_read_record*, THD*, st_table*, SQL_SELECT*, int, bool) (in /usr/local/mysql-5.0/libexec/mysqld)
==18833==    by 0x824B1A9: QUICK_INDEX_MERGE_SELECT::read_keys_and_merge() (in /usr/local/mysql-5.0/libexec/mysqld)
==18833==    by 0x825B5AD: find_all_keys(st_sort_param*, SQL_SELECT*, unsigned char**, st_io_cache*, st_io_cache*, st_io_cache*) (in /usr/local/mysql-5.0/libexec/mysqld)
==18833==    by 0x825D7A8: filesort(THD*, st_table*, st_sort_field*, unsigned, SQL_SELECT*, unsigned long, unsigned long*) (in /usr/local/mysql-5.0/libexec/mysqld)
==18833==    by 0x81F56A4: create_sort_index(THD*, JOIN*, st_order*, unsigned long, unsigned long) (in /usr/local/mysql-5.0/libexec/mysqld)
==18833==    by 0x8201904: JOIN::exec() (in /usr/local/mysql-5.0/libexec/mysqld)
==18833==    by 0x8203AE7: mysql_select(THD*, Item***, TABLE_LIST*, unsigned, List<Item>&, Item*, unsigned, st_order*, st_order*, Item*, st_order*, unsigned long long, select_result*, st_select_lex_unit*, st_select_lex*) (in /usr/local/mysql-5.0/libexec/mysqld)
==18833==    by 0x820436E: handle_select(THD*, st_lex*, select_result*, unsigned long) (in /usr/local/mysql-5.0/libexec/mysqld)
==18833==    by 0x81AC028: mysql_execute_command(THD*) (in /usr/local/mysql-5.0/libexec/mysqld)
==18833==    by 0x81B14BB: mysql_parse(THD*, char const*, unsigned, char const**) (in /usr/local/mysql-5.0/libexec/mysqld)
[27 Mar 2008 9:39] Domas Mituzas
slightly better formatted valgrind output at:

http://p.defau.lt/?_ZxrNXcfnAPoKHSYrgqQSw
[27 Mar 2008 12:03] Domas Mituzas
Fix for memory leak:

--- opt_range.cc        2008-03-27 08:03:13.000000000 -0400
+++ opt_range.cc.new    2008-03-27 08:03:04.000000000 -0400
@@ -1035,14 +1035,16 @@
   QUICK_RANGE_SELECT* quick;
   DBUG_ENTER("QUICK_INDEX_MERGE_SELECT::~QUICK_INDEX_MERGE_SELECT");
   quick_it.rewind();
   while ((quick= quick_it++))
     quick->file= NULL;
   quick_selects.delete_elements();
   delete pk_quick_select;
+  if (&read_record)
+    end_read_record(&read_record);
   free_root(&alloc,MYF(0));
   DBUG_VOID_RETURN;
 }
 
 
 QUICK_ROR_INTERSECT_SELECT::QUICK_ROR_INTERSECT_SELECT(THD *thd_param,
                                                        TABLE *table,
[4 Apr 2008 13:54] Georgi Kodinov
Domas,

I've tried with the latest 5.0-opt-bk and I'm not getting the effect (no leaked fds) even after repeating the query several times. But I'm probably missing something in recreating the problem.

Can we please get a real test script (for mysqltest) that uses e.g. INSERT INTO t1 ...  SELECT ... FROM t1 ... to generate data (as looking at your test data dump this seems doable) ?
[4 Apr 2008 14:35] Shane Bester
Georgi, I haven't tested this, but you can try setting the lowest possible sort_buffer_size and see if it leaks then.
[10 Apr 2008 7:20] Shane Bester
standalone testcase to show 20MB/s memory leak, and file handle leak
--------------------------------------------------------------------

delimiter ;
drop table if exists `bug35477`;
create table `bug35477` (`a` varchar(255),`b` varchar(255),`c` varchar(255),key(`a`),key(`b`),key(`c`)) engine=myisam;
insert into `bug35477`values ('1','2','3'),('4','5','6'),('7','8','9');
set @a=1,@b=1,@c=1;
insert into `bug35477` select @a:=@a+1,@b:=@b+2,@c:=@c+3 from `bug35477` a,`bug35477` b,`bug35477` c;
insert into `bug35477` select @a:=@a+1,@b:=@b+2,@c:=@c+3 from `bug35477` a,`bug35477` b,`bug35477` c;

drop procedure if exists `p_bug35477`;
delimiter //
create procedure `p_bug35477`(`numtimes` int)
begin

        declare `i` int default '0';
        repeat
                select * from `bug35477` where `a` like '5%' or `b` like '5%' order by `c` limit 1 into @a,@b,@c;
                if(`i` % 100 =0) then select `i` as repetition; end if;
                set `i`=`i`+1;
        until `i`>`numtimes` end repeat;

end//

delimiter ;

set session sort_buffer_size=1024;

call `p_bug35477`(50000);
[10 Apr 2008 12:11] Shane Bester
Georgi, if my above testcase doesn't repeat the problem on your internal BK builds, i wonder if this bug was fixed in bug #27732 (Possible memory leak with index_merge) ?
[10 Apr 2008 14:17] Sergey Petrunya
Using 5.0-opt with tip cset:

ChangeSet@1.2601, 2008-03-27 20:05:51+04:00, gshchepa@host.loc +2 -0
  Merge host.loc:/home/uchum/work/mysql-5.0
  into  host.loc:/home/uchum/work/5.0-opt
  MERGE: 1.2599.1.2

(i.e. BUG#27732 is in the tree), I still can see the fd leaks.
[10 Apr 2008 14:42] Sergey Petrunya
Can observe leaks on the latest 6.0 opt also. tip cset:
ChangeSet@1.2604, 2008-04-07 13:21:26-06:00, malff@lambda.hsd1.co.comcast.net. +1 -0
  Merge malff@bk-internal.mysql.com:/home/bk/mysql-5.0-opt
  into  lambda.hsd1.co.comcast.net.:/home/malff/TREE/mysql-5.0-35658
  MERGE: 1.2598.5.1
[10 Apr 2008 14:43] Sergey Petrunya
The above two observations were made by using Domas's testcase
[21 Apr 2008 4:21] Sergey Petrunya
The fix is at http://lists.mysql.com/commits/45739
[1 May 2008 1:52] Sergey Petrunya
Fixed by fix for BUG#35478. Changing status to duplicate.
[22 Jul 2008 18:36] Bugs System
Pushed into 5.0.68
[28 Jul 2008 13:46] Bugs System
Pushed into 5.0.68  (revid:kpettersson@mysql.com-20080716141220-83aobe5fdgd9ye5l) (pib:2)
(Retry automatic marking, to ensure nothing is missed. cm01)
[28 Jul 2008 14:45] Bugs System
Pushed into 6.0.7-alpha  (revid:alik@mysql.com-20080725172155-fnc73o50e4tgl23k) (version source revid:alik@mysql.com-20080725172155-fnc73o50e4tgl23k) (pib:3)
[28 Jul 2008 16:44] Bugs System
Pushed into 5.1.28  (revid:davi.arnaut@sun.com-20080722182431-0i2f1yc4uocime9q) (version source revid:davi.arnaut@sun.com-20080722182431-0i2f1yc4uocime9q) (pib:3)
[14 Sep 2008 2:21] Bugs System
Pushed into 6.0.7-alpha  (revid:sergefp@mysql.com-20080715141321-2vlk93j5blqa7kxe) (version source revid:sven@mysql.com-20080818195835-r615g9zz6xphmkzg) (pib:3)