Bug #50412 Assertion `! is_set()' failed in Diagnostics_area::set_ok_status at PREPARE
Submitted: 18 Jan 2010 13:25 Modified: 6 Mar 2010 20:35
Reporter: John Embretsen Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server Severity:S1 (Critical)
Version:bzr_5.6.0 (mysql-next-4284) OS:Any
Assigned to: Jon Olav Hauglid CPU Architecture:Any
Tags: rqg_pb2

[18 Jan 2010 13:25] John Embretsen
Description:
Assertion failed upon statement PREPARE st1 FROM " CALL testdb_N . p1_1_N  " during a concurrent workload designed to test MDL locking.

Pushbuild test case rqg_mdl_stress is affected.

mysqld: sql_error.cc:359: void Diagnostics_area::set_ok_status(THD*, ulonglong, ulonglong, const char*): Assertion `! is_set()' failed.
100115 15:38:48 - mysqld got signal 6 ;
This could be because you hit a bug.
(...)

Stacktrace:

(...)
# 13:38:50 #8  0x0074315b in __assert_fail () from /lib/libc.so.6
# 13:38:50 #9  0x082f9fac in Diagnostics_area::set_ok_status (this=0xaf0ea8c, 
# 13:38:50     thd=0xaf0d100, affected_rows_arg=0, last_insert_id_arg=0, 
# 13:38:50     message_arg=0x8713e35 "Statement prepared") at sql_error.cc:359
# 13:38:50 #10 0x0816a3cf in my_ok (thd=0xaf0d100, affected_rows=0, id=0, 
# 13:38:50     message=0x8713e35 "Statement prepared") at sql_class.h:2600
# 13:38:50 #11 0x082f8462 in mysql_sql_stmt_prepare (thd=0xaf0d100) at sql_prepare.cc:2324
# 13:38:50 #12 0x08258061 in mysql_execute_command (thd=0xaf0d100) at sql_parse.cc:2056
# 13:38:50 #13 0x0825fd53 in mysql_parse (thd=0xaf0d100, 
# 13:38:50     inBuf=0xaee50c8 "PREPARE st1 FROM \" CALL testdb_N . p1_1_N  \"", 
# 13:38:50     length=44, found_semicolon=0xa65ce278) at sql_parse.cc:5593
# 13:38:50 #14 0x08260e38 in dispatch_command (command=COM_QUERY, thd=0xaf0d100, 
# 13:38:50     packet=0xaeb3c89 "PREPARE st1 FROM \" CALL testdb_N . p1_1_N  \" ", 
# 13:38:50     packet_length=45) at sql_parse.cc:1011
# 13:38:50 #15 0x082620c6 in do_command (thd=0xaf0d100) at sql_parse.cc:695
# 13:38:50 #16 0x08250ece in handle_one_connection (arg=0xaf0d100) at sql_connect.cc:1163
# 13:38:50 #17 0x0089a45b in start_thread () from /lib/libpthread.so.0
# 13:38:50 #18 0x007f1c4e in clone () from /lib/libc.so.6

There are several other reported bugs for the same assertion, but this reporter did not find one with more or less the same backtrace, so leaving this for separate analysis for now.

How to repeat:
Run the Random Query Generator's WL5004_sql.yy grammar against mysql-next-4284 bazaar branch.

Linux, bash:

export CODE=/my/path/to/mysql-next-4284
bzr branch lp:randgen
cd randgen
perl ./pb2gentest.pl $CODE $CODE/mysql-test/var-randgen mysql-next-4284 rqg_mdl_stress

RQG options used (implicitly) are:

--gendata=
--reporter=Deadlock
--reporter=ErrorLog
--reporter=Backtrace
--reporter=Shutdown
--threads=10
--queries=1M
--duration=1800
--grammar=conf/WL5004_sql.yy
[19 Jan 2010 9:43] Philip Stoev
See also bug #49962
[19 Jan 2010 13:58] Jon Olav Hauglid
Based on the core, the problem is that my_ok() is called
when ER_SP_PROC_TABLE_CORRUPT (errno 1457) has already been set.
[20 Jan 2010 8:17] 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/97488

3053 Jon Olav Hauglid	2010-01-20
      Bug #50412 Assertion `! is_set()' failed in
                 Diagnostics_area::set_ok_status at PREPARE
      
      The problem occured during processing of stored routines. 
      Routines are loaded from mysql.proc, parsed and put into the sp cache by
      sp_cache_routine().  The assert occured because the return value from
      sp_cache_routine() was not checked for top level CALLs. This meant that any
      errors during sp_cache_routine() went unoticed and triggered the assert when
      my_ok() was later called.
      
      This is a regression introduced by the patch for Bug#30977, only visible in
      source trees with MDL and using debug builds of the server.
      
      This patch fixes the problem by checking the return value from sp_cache_routine() 
      for top level CALLs and propagating any errors similar to what is done for other 
      calls to sp_cache_routine().
      
      No test case added.
[20 Jan 2010 10:10] Jon Olav Hauglid
Pushed to mysql-next-4284 and merged to mysql-6.0-codebase-4284.
[16 Feb 2010 16:47] Bugs System
Pushed into 6.0.14-alpha (revid:alik@sun.com-20100216101445-2ofzkh48aq2e0e8o) (version source revid:jon.hauglid@sun.com-20100120100711-9vpxnuwkwgh55e9v) (merge vers: 6.0.14-alpha) (pib:16)
[16 Feb 2010 16:56] Bugs System
Pushed into mysql-next-mr (revid:alik@sun.com-20100216101208-33qkfwdr0tep3pf2) (version source revid:jon.hauglid@sun.com-20100120081731-1itayyo38bxgoi9j) (pib:16)
[25 Feb 2010 20:31] Paul Dubois
Noted in 6.0.14 changelog.

The return value for calls to put information into the stored routine
cache were not consistently checked, causing an assertion to be
raised. 

Setting report to Need Merge pending push of Celosia to release tree.
[6 Mar 2010 11:03] Bugs System
Pushed into 5.5.3-m3 (revid:alik@sun.com-20100306103849-hha31z2enhh7jwt3) (version source revid:vvaintroub@mysql.com-20100216221947-luyhph0txl2c5tc8) (merge vers: 5.5.99-m3) (pib:16)
[6 Mar 2010 20:35] Paul Dubois
Noted in 5.5.3 changelog.