Bug #41425 Assertion in Protocol::end_statement() (pushbuild2) (diagnostics_area)
Submitted: 12 Dec 2008 10:55 Modified: 7 Mar 2010 18:14
Reporter: Guilhem Bichot Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: General Severity:S3 (Non-critical)
Version:6.0-bzr OS:Linux
Assigned to: Magne Mæhre CPU Architecture:Any

[12 Dec 2008 10:55] Guilhem Bichot
Description:
This piece of code is, I think, the Runtime team's.
mysqld: protocol.cc:471: void Protocol::end_statement(): Assertion `0' failed.
/export/home/pb2/test/sb_1-177975-1229075110.51/mysql-6.0.9-alpha-linux-i686-test/libexec/mysqld(my_print_stacktrace+0x26) [0x87ff10f]
/export/home/pb2/test/sb_1-177975-1229075110.51/mysql-6.0.9-alpha-linux-i686-test/libexec/mysqld(handle_segfault+0x2cd) [0x82b5f5f]
[0x898420]
/lib/libc.so.6(abort+0x101) [0x74b621]
/lib/libc.so.6(__assert_fail+0xfb) [0x74315b]
/export/home/pb2/test/sb_1-177975-1229075110.51/mysql-6.0.9-alpha-linux-i686-test/libexec/mysqld(Protocol::end_statement()+0x238) [0x82a7976]
/export/home/pb2/test/sb_1-177975-1229075110.51/mysql-6.0.9-alpha-linux-i686-test/libexec/mysqld(dispatch_command(enum_server_command, THD*, char*, unsigned int)+0x168b) [0x82d155f]
/export/home/pb2/test/sb_1-177975-1229075110.51/mysql-6.0.9-alpha-linux-i686-test/libexec/mysqld(do_command(THD*)+0x242) [0x82d19f8]
/export/home/pb2/test/sb_1-177975-1229075110.51/mysql-6.0.9-alpha-linux-i686-test/libexec/mysqld(handle_one_connection+0x11d) [0x82bed3f]

see private post for URLs.

How to repeat:
pushbuild2 stress test myisam_bulk_insert
[16 Mar 2009 14:39] 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/69302

2745 Magne Mahre	2009-03-16
      Bug #41425 Assertion in Protocol::end_statement()
      
      This is work in progress.  Patch committed for
      discussion.
      
      The assert is triggered because of an error that
      is not properly caught, so the diagnostics_area is
      empty.
      
      In open_table, the MDL excl.lock is prematurely downgraded
      in this case.
[7 May 2009 18:49] Dmitry Lenev
Review sent by e-mail.
[10 Jun 2009 18:47] 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/76060

2798 Magne Mahre	2009-06-10
      Bug #41425 Assertion in Protocol::end_statement() (pushbuild2) 
                 (diagnostics_area)
      
      Execution of CREATE TABLE ... SELECT statement was not atomic in
      the sense that concurrent statements trying to affect its target
      table might have sneaked in between the moment when the table was
      created and moment when it was filled according to SELECT clause.
      This resulted in inconsistent binary log, unexpected target table
      contents. In cases when concurrent statement was a DDL statement
      CREATE TABLE ... SELECT might have failed with ER_CANT_LOCK error.
      
      In more detail:
      Due to premature metadata lock downgrade which occured after CREATE
      TABLE SELECT statement created table but before it managed to obtain
      table-level lock on it other statements were allowed to open, lock
      and change target table in the middle of CREATE TABLE SELECT
      execution. This also meant that it was possible that CREATE TABLE
      SELECT would wait in mysql_lock_tables() when it was called for newly
      created table and that this wait could have been aborted by concurrent
      DDL. The latter led to execution of unexpected branch of code and
      CREATE TABLE SELECT ending with ER_CANT_LOCK error.
      
      The premature downgrade occured because open_table(), which was called
      for newly created table, decided that it is OK to downgrade metadata
      lock from exclusive to shared since table exists, even although it
      was not acquired within this call.
      
      This fix ensures that open_table() does not downgrade metadata lock
      if it is not acquired during its current invocation.
      
      Testing:
      The bug is exposed in a race condition, and is thus difficult to
      expose in a standard mysql-test-run test case.  Instead, a stress
      test using the Random Query Generator (https://launchpad.net/randgen)
      will trip the problem occasionally.
      
      % perl  runall.pl \
             --basedir=<build dir> \
             --mysqld=--table-lock-wait-timeout=5 \
             --mysqld=--skip-safemalloc \
             --grammar=conf/maria_bulk_insert.yy \
             --reporters=ErrorLog,Backtrace,WinPackage \
             --mysqld=--log-output=file  \
             --queries=100000 \
             --threads=10 \
             --engine=myisam
      
      Note: You will need a debug build to expose the bug
      
      When the bug is tripped, the server will abort and dump core.
[11 Jun 2009 9:53] Dmitry Lenev
Approved with one minor comment sent by e-mail.
[13 Jun 2009 12:42] 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/76233

2794 Magne Mahre	2009-06-13
      Bug #41425 Assertion in Protocol::end_statement() (pushbuild2) 
                 (diagnostics_area)
      
      Execution of CREATE TABLE ... SELECT statement was not atomic in
      the sense that concurrent statements trying to affect its target
      table might have sneaked in between the moment when the table was
      created and moment when it was filled according to SELECT clause.
      This resulted in inconsistent binary log, unexpected target table
      contents. In cases when concurrent statement was a DDL statement
      CREATE TABLE ... SELECT might have failed with ER_CANT_LOCK error.
      
      In more detail:
      Due to premature metadata lock downgrade which occured after CREATE
      TABLE SELECT statement created table but before it managed to obtain
      table-level lock on it other statements were allowed to open, lock
      and change target table in the middle of CREATE TABLE SELECT
      execution. This also meant that it was possible that CREATE TABLE
      SELECT would wait in mysql_lock_tables() when it was called for newly
      created table and that this wait could have been aborted by concurrent
      DDL. The latter led to execution of unexpected branch of code and
      CREATE TABLE SELECT ending with ER_CANT_LOCK error.
      
      The premature downgrade occured because open_table(), which was called
      for newly created table, decided that it is OK to downgrade metadata
      lock from exclusive to shared since table exists, even although it
      was not acquired within this call.
      
      This fix ensures that open_table() does not downgrade metadata lock
      if it is not acquired during its current invocation.
      
      Testing:
      The bug is exposed in a race condition, and is thus difficult to
      expose in a standard mysql-test-run test case.  Instead, a stress
      test using the Random Query Generator (https://launchpad.net/randgen)
      will trip the problem occasionally.
      
      % perl  runall.pl \
             --basedir=<build dir> \
             --mysqld=--table-lock-wait-timeout=5 \
             --mysqld=--skip-safemalloc \
             --grammar=conf/maria_bulk_insert.yy \
             --reporters=ErrorLog,Backtrace,WinPackage \
             --mysqld=--log-output=file  \
             --queries=100000 \
             --threads=10 \
             --engine=myisam
      
      Note: You will need a debug build to expose the bug
      
      When the bug is tripped, the server will abort and dump core.
[18 Jun 2009 6:48] Bugs System
Pushed into 5.4.4-alpha (revid:alik@sun.com-20090617073019-azsawauatv99124t) (version source revid:jon.hauglid@sun.com-20090616092759-pelq3sqh8ql0qxoa) (merge vers: 5.4.4-alpha) (pib:11)
[29 Jun 2009 0:51] Paul DuBois
Noted in 5.4.4 changelog.

Premature metadata lock downgrade for CREATE TABLE ... SELECT could 
result in an inconsistent binary log or failure with an ER_CANT_LOCK
error.
[12 Aug 2009 22:47] Paul DuBois
Noted in 5.4.2 changelog because next 5.4 version will be 5.4.2 and not 5.4.4.
[15 Aug 2009 2:02] Paul DuBois
Ignore previous comment about 5.4.2.
[10 Dec 2009 14:49] 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/93528

3031 Magne Mahre	2009-12-10
      Bug#41425 Assertion in Protocol::end_statement() (pushbuild2) 
                (diagnostics_area)
            
      Execution of CREATE TABLE ... SELECT statement was not atomic in
      the sense that concurrent statements trying to affect its target
      table might have sneaked in between the moment when the table was
      created and moment when it was filled according to SELECT clause.
      This resulted in inconsistent binary log, unexpected target table
      contents. In cases when concurrent statement was a DDL statement
      CREATE TABLE ... SELECT might have failed with ER_CANT_LOCK error.
            
      In more detail:
      Due to premature metadata lock downgrade which occured after CREATE
      TABLE SELECT statement created table but before it managed to obtain
      table-level lock on it other statements were allowed to open, lock
      and change target table in the middle of CREATE TABLE SELECT
      execution. This also meant that it was possible that CREATE TABLE
      SELECT would wait in mysql_lock_tables() when it was called for newly
      created table and that this wait could have been aborted by concurrent
      DDL. The latter led to execution of unexpected branch of code and
      CREATE TABLE SELECT ending with ER_CANT_LOCK error.
            
      The premature downgrade occured because open_table(), which was called
      for newly created table, decided that it is OK to downgrade metadata
      lock from exclusive to shared since table exists, even although it
      was not acquired within this call.
            
      This fix ensures that open_table() does not downgrade metadata lock
      if it is not acquired during its current invocation.
            
      Testing:
      The bug is exposed in a race condition, and is thus difficult to
      expose in a standard mysql-test-run test case.  Instead, a stress
      test using the Random Query Generator (https://launchpad.net/randgen)
      will trip the problem occasionally.
            
         % perl  runall.pl \
                  --basedir=<build dir> \
                   --mysqld=--table-lock-wait-timeout=5 \
                   --mysqld=--skip-safemalloc \
                   --grammar=conf/maria_bulk_insert.yy \
                   --reporters=ErrorLog,Backtrace,WinPackage \
                   --mysqld=--log-output=file  \
                   --queries=100000 \
                   --threads=10 \
                   --engine=myisam
            
      Note: You will need a debug build to expose the bug
            
      When the bug is tripped, the server will abort and dump core.
      
      
      Backport from 6.0-codebase   (revid: 2617.53.4)
[16 Feb 2010 16:48] Bugs System
Pushed into 6.0.14-alpha (revid:alik@sun.com-20100216101445-2ofzkh48aq2e0e8o) (version source revid:kostja@sun.com-20091211154405-c9yhiewr9o5d20rq) (merge vers: 6.0.14-alpha) (pib:16)
[16 Feb 2010 16:57] Bugs System
Pushed into mysql-next-mr (revid:alik@sun.com-20100216101208-33qkfwdr0tep3pf2) (version source revid:kostja@sun.com-20091211103945-198h3pt8w7ypk20u) (pib:16)
[16 Feb 2010 18:31] Dmitry Lenev
Closing this bug as it is not repeatable in publicly available trees with versions < 6.0.
[6 Mar 2010 11:04] 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)
[7 Mar 2010 18:14] Paul DuBois
No changelog entry needed.