Bug #47338 assertion in handler::ha_external_lock
Submitted: 15 Sep 2009 20:29 Modified: 23 Nov 2010 2:58
Reporter: Matthias Leich Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: Optimizer Severity:S3 (Non-critical)
Version:6.0 OS:Any
Assigned to: Tor Didriksen
Tags: locking, mrr, optimizer_switch
Triage: Triaged: D1 (Critical)

[15 Sep 2009 20:29] Matthias Leich
Description:
The corresponding source line handler.cc:5495 is
 DBUG_ASSERT(next_insert_id == 0);
There are other mostly closed bugs which mention
assertion in handler::ha_external_lock.
The current case differs in the fact that neither
partitioned tables nor a direct call of
HANDLER is involved.

My script:
----------
--disable_abort_on_error
CREATE TEMPORARY TABLE t1 ( f2 INT, f1 INTEGER, PRIMARY KEY (f1)) ENGINE = MyISAM;
DELIMITER |;
CREATE PROCEDURE p1 () BEGIN SELECT f1,f2 FROM t1 A WHERE f1 BETWEEN 0 AND 1; UPDATE t1 SET f1 = 7 ; END|
DELIMITER ;|
ALTER TABLE t1 ENGINE = MyISAM;
INSERT t1 ( f1 ) VALUES ( 5 );
PREPARE st1 FROM " CALL p1 ";
EXECUTE st1;
INSERT t1 ( f1 ) VALUES ( 5 );
ANALYZE TABLE t1;
PREPARE st1 FROM " CALL p1 ";
# This EXECUTE gets the assertion
EXECUTE st1;

Backtrace from mysql-next-bugfixing 2009-09-15:
-----------------------------------------------
Thread 1 (process 16887):
#0  0x00007f2301f07ce6 in pthread_kill () from /lib64/libpthread.so.0
#1  0x0000000000b7410c in my_write_core (sig=6) at stacktrace.c:309
#2  0x00000000006f359d in handle_segfault (sig=6) at mysqld.cc:2739
#3  <signal handler called>
#4  0x00007f2300e035c5 in raise () from /lib64/libc.so.6
#5  0x00007f2300e04bb3 in abort () from /lib64/libc.so.6
#6  0x00007f2300dfc1e9 in __assert_fail () from /lib64/libc.so.6
#7  0x0000000000854d8c in handler::ha_external_lock (this=0x16a3638, thd=0x1614938, lock_type=2) at handler.cc:5495
#8  0x00000000008569e9 in DsMrr_impl::dsmrr_close (this=0x16a76e0) at handler.cc:4597
#9  0x0000000000a56f79 in ha_myisam::reset (this=0x16a74e0) at ha_myisam.cc:1764
#10 0x0000000000855753 in handler::ha_reset (this=0x16a74e0) at handler.cc:5566
#11 0x000000000075d67b in mark_temp_tables_as_free_for_reuse (thd=0x1614938) at sql_base.cc:1166
#12 0x000000000075f879 in close_thread_tables (thd=0x1614938) at sql_base.cc:1417
#13 0x00000000008f66f4 in sp_lex_keeper::reset_lex_and_exec_core (this=0x169a720, thd=0x1614938, nextp=0x41c67bd8, open_tables=false, instr=0x169a6e0) at sp_head.cc:2759
#14 0x00000000008fc98e in sp_instr_stmt::execute (this=0x169a6e0, thd=0x1614938, nextp=0x41c67bd8) at sp_head.cc:2864
#15 0x00000000008f89b9 in sp_head::execute (this=0x16988c0, thd=0x1614938) at sp_head.cc:1248
#16 0x00000000008f9804 in sp_head::execute_procedure (this=0x16988c0, thd=0x1614938, args=0x166cbb0) at sp_head.cc:1988
#17 0x000000000070cd05 in mysql_execute_command (thd=0x1614938) at sql_parse.cc:4400
#18 0x00000000007c19bb in Prepared_statement::execute (this=0x166e358, expanded_query=0x41c692f0, open_cursor=false) at sql_prepare.cc:3765
#19 0x00000000007c5c6e in Prepared_statement::execute_loop (this=0x166e358, expanded_query=0x41c692f0, open_cursor=false, packet=0x0, packet_end=0x0) at sql_prepare.cc:3397
#20 0x00000000007c5f06 in mysql_sql_stmt_execute (thd=0x1614938) at sql_prepare.cc:2570
#21 0x000000000070624c in mysql_execute_command (thd=0x1614938) at sql_parse.cc:2132
#22 0x000000000070e790 in mysql_parse (thd=0x1614938, inBuf=0x168f830 "EXECUTE st1", length=11, found_semicolon=0x41c6af20) at sql_parse.cc:5957
#23 0x000000000070f3cc in dispatch_command (command=COM_QUERY, thd=0x1614938, packet=0x165faf9 "", packet_length=11) at sql_parse.cc:1073
#24 0x0000000000710893 in do_command (thd=0x1614938) at sql_parse.cc:755
#25 0x00000000006fd730 in handle_one_connection (arg=0x1614938) at sql_connect.cc:1163
#26 0x00007f2301f03040 in start_thread () from /lib64/libpthread.so.0
#27 0x00007f2300ea408d in clone () from /lib64/libc.so.6
#28 0x0000000000000000 in ?? ()

Result on mysql-5.1-bugteam 2009-08-28
--------------------------------------
....
EXECUTE st1;
f1	f2
ERROR 23000: Duplicate entry '7' for key 'PRIMARY'
This result is correct.

My environment:
---------------
- ./BUILD/compile-pentium64-debug-max
- Linux OpenSuSE 11.0 (64 Bit)
- Intel Core2Duo

How to repeat:
See above
[16 Sep 2009 5:59] Philip Stoev
Matthias, the backtrace says that MRR is involved, so please try your test case with set @@optimizer_use_mrr='disable'. If the bug goes away, please tag it as MRR and set category to Optimizer, lead to Timour.

For future testing runs, please use --mysqld=--init-file=/path/to/rqg/init/no_mrr.sql or something to disable MRR for the entire test run.

Philip Stoev
[16 Sep 2009 9:36] Matthias Leich
Thank you for the hint Philip.
If I add a
   SET optimizer_use_mrr='disable';
at the beginning of the test
than the crash disappears.
So I have a workaround.
[18 Nov 2009 7:57] Tor Didriksen
Simplified test case:

CREATE TEMPORARY TABLE t1 (f2 INT, f1 INT, PRIMARY KEY (f1)) ENGINE = MyISAM;

INSERT t1 ( f1 ) VALUES ( 5 );
INSERT t1 ( f1 ) VALUES ( 6 );

ALTER TABLE t1 ENGINE = MyISAM;
ANALYZE TABLE t1;

SELECT f1,f2 FROM t1 A WHERE f1 BETWEEN 0 AND 1;
[18 Nov 2009 8:09] Tor Didriksen
There's (at least) two separate bugs here.

- The combination CREATE TEMPORARY TABLE, ALTER TABLE, ANALYZE TABLE, yields
  ERROR HY000: Incorrect key file for table ........
- Cleanup after an underlying error is not handled gracefully in
  DsMrr_impl::dsmrr_init() and we segfault a bit later.

I'm fixing the second bug now, opening another bug for the first one.
[18 Nov 2009 8:16] Bugs System
A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/90793

3714 Tor Didriksen	2009-11-18
      Bug #47338 assertion in handler::ha_external_lock
      
      Cleanup after an underlying error was not handled gracefully in
      DsMrr_impl::dsmrr_init()
     @ mysql-test/r/analyse.result
        Add test case.
     @ mysql-test/t/analyse.test
        Add test case.
     @ mysys/my_open.c
        Dont call DBUG_RETURN(functio_call())
        it makes DEBUG output very confusing.
     @ sql/handler.cc
        Avoid double delete of member variable 'h2'
        
        Dont call DBUG_RETURN(functio_call())
        it makes DEBUG output very confusing.
[18 Nov 2009 9:21] Konstantin Osipov
Approved on IRC, no comments, OK to push.
[19 Nov 2009 14:37] Tor Didriksen
Pushed to:
bzr+ssh://bk-internal.mysql.com/bzrroot/server/mysql-6.0-codebase-bugfixing/
revision-id: tor.didriksen@sun.com-20091118081550-l8gv8m2lodyil1uv
[20 Nov 2009 12:58] Bugs System
Pushed into 6.0.14-alpha (revid:kostja@sun.com-20091120124947-yi6h2jbgw0kbciwm) (version source revid:tor.didriksen@sun.com-20091118081550-l8gv8m2lodyil1uv) (merge vers: 6.0.14-alpha) (pib:13)
[23 Nov 2009 20:16] Paul Dubois
I am unsure how to describe this bug. Could you suggest a sentence or two?
[24 Nov 2009 7:57] Tor Didriksen
re: how to describe the bug.
Initialization of MRR (multi range read) did not handle underlying errors
(e.g. corrupt index file) gracefully, and might crash the server.
[5 May 2010 15:00] Bugs System
A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/107546

3134 Tor Didriksen	2010-05-05
      Backport of
      Bug #47338 assertion in handler::ha_external_lock
[16 Aug 2010 6:36] Bugs System
Pushed into mysql-next-mr (revid:alik@sun.com-20100816062819-bluwgdq8q4xysmlg) (version source revid:alik@sun.com-20100816062612-enatdwnv809iw3s9) (pib:20)
[13 Nov 2010 16:17] Bugs System
Pushed into mysql-trunk 5.6.99-m5 (revid:alexander.nozdrin@oracle.com-20101113155825-czmva9kg4n31anmu) (version source revid:vasil.dimov@oracle.com-20100629074804-359l9m9gniauxr94) (merge vers: 5.6.99-m4) (pib:21)
[23 Nov 2010 2:58] Paul Dubois
Bug does not appear in any released 5.6.x version. No 5.6.1 changelog entry needed.