Bug #54734 assert in Diagnostics_area::set_ok_status
Submitted: 23 Jun 2010 11:33 Modified: 15 Oct 2010 13:29
Reporter: Matthias Leich Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: Errors Severity:S3 (Non-critical)
Version:5.5.5-m3,5.1.49 OS:Any
Assigned to: Jon Olav Hauglid CPU Architecture:Any
Triage: Triaged: D1 (Critical)

[23 Jun 2010 11:33] Matthias Leich
Description:
The assert happens in sql/sql_error.cc line 360:
void
Diagnostics_area::set_ok_status(THD *thd, ulonglong affected_rows_arg,
                                ulonglong last_insert_id_arg,
                                const char *message_arg)
{
  DBUG_ENTER("set_ok_status");
  DBUG_ASSERT(! is_set()); <----------
  /*
    In production, refuse to overwrite an error or a custom response
    with an OK packet.
  */

RQG test with concurrent DDL/DML workload.

Result on mysql-trunk-runtime last pull 2010-06-15
--------------------------------------------------
Thread 1 (Thread 5854):
#0  0x000000382860bd02 in pthread_kill () from /lib64/libpthread.so.0
#1  0x0000000000b595bd in my_write_core (sig=6) at stacktrace.c:326
#2  0x00000000006993a3 in handle_segfault (sig=6) at mysqld.cc:2791
#3  <signal handler called>
#4  0x0000003827a30265 in raise () from /lib64/libc.so.6
#5  0x0000003827a31d10 in abort () from /lib64/libc.so.6
#6  0x0000003827a296e6 in __assert_fail () from /lib64/libc.so.6
#7  0x0000000000764b6a in Diagnostics_area::set_ok_status (
    this=0x2aaab8259b70, thd=0x2aaab82570a8, affected_rows_arg=0,
    last_insert_id_arg=0,
    message_arg=0x4a032ed0 "Rows matched: 0  Changed: 0  Warnings: 14")
    at sql_error.cc:360
#8  0x00000000005a3a32 in my_ok (thd=0x2aaab82570a8, affected_rows=0, id=0,
    message=0x4a032ed0 "Rows matched: 0  Changed: 0  Warnings: 14")
    at sql_class.h:2745
#9  0x000000000076e9d5 in mysql_update (thd=0x2aaab82570a8,
    table_list=0x2aaabc0abca8, fields=..., values=..., conds=0x1ed9cb38,
    order_num=0, order=0x0, limit=1, handle_duplicates=DUP_ERROR, ignore=true,
    found_return=0x4a034078, updated_return=0x4a034070) at sql_update.cc:850
#10 0x00000000006ad52a in mysql_execute_command (thd=0x2aaab82570a8)
    at sql_parse.cc:3114
#11 0x00000000006b2995 in mysql_parse (thd=0x2aaab82570a8,
    inBuf=0x2aaabc0abb28 "UPDATE  IGNORE testdb_N . t1_view1_N  SET `pk` = 3
     WHERE SLEEP( 0.5 * 1 * 1 ) = 0 LIMIT 1", length=89, parser_state=0x4a0349b0)
    at sql_parse.cc:5889
#12 0x00000000006b3ef1 in dispatch_command (command=COM_QUERY,
    thd=0x2aaab82570a8,
    packet=0x2aaab8259dd9 "UPDATE  IGNORE testdb_N . t1_view1_N  SET `pk` = 3
     WHERE SLEEP( 0.5 * 1 * 1 ) = 0 LIMIT 1", packet_length=89) at sql_parse.cc:1114
#13 0x00000000006b541e in do_command (thd=0x2aaab82570a8) at sql_parse.cc:800
#14 0x00000000006a3481 in do_handle_one_connection (thd_arg=0x2aaab82570a8)
    at sql_connect.cc:1194
#15 0x00000000006a3547 in handle_one_connection (arg=0x2aaab82570a8)
    at sql_connect.cc:1133
#16 0x000000382860673d in start_thread () from /lib64/libpthread.so.0
#17 0x0000003827ad3d1d in clone () from /lib64/libc.so.6
Waiting for mysqld with pid 5545 to terminate...

How to repeat:
Please have a look into the attached archive.
Log of RQG run with server settings etc.
   ./storage/1276601155/1-8.log
The grammars
   conf/runtime/WL5004_data.zz
   ./storage/1276601155/1.yy
The probability to hit the assert is very low.
I will try to simplify the test and reach a better
probability.
[23 Jun 2010 11:36] Matthias Leich
Archive with log and RQG grammars

Attachment: problem.tgz (application/x-compressed-tar, text), 48.79 KiB.

[1 Jul 2010 17:39] Matthias Leich
Simplified test for MTR:

CREATE TABLE t1 (PRIMARY KEY(pk)) ENGINE = MyISAM PARTITION BY KEY (pk) PARTITIONS 2 AS SELECT 1 AS pk;
CREATE FUNCTION f1() RETURNS INTEGER RETURN (SELECT 1 FROM not_exists);
CREATE ALGORITHM = UNDEFINED VIEW v1 AS SELECT pk FROM t1 A WHERE f1() = 13;
UPDATE v1 SET pk = 7 WHERE pk > 0;
[1 Jul 2010 17:53] Matthias Leich
Result on
1. 5.1.49-log
   mysql-5.1 revno: 3410 2010-06-03
-----------------------------------
CREATE TABLE t1 (PRIMARY KEY(pk)) ENGINE = MyISAM PARTITION BY KEY (pk) PARTITIONS 2 AS SELECT 1 AS pk;
CREATE FUNCTION f1() RETURNS INTEGER RETURN (SELECT 1 FROM not_exists);
CREATE ALGORITHM = UNDEFINED VIEW v1 AS SELECT pk FROM t1 A WHERE f1() = 13;
UPDATE v1 SET pk = 7 WHERE pk > 0;
ERROR HY000: View 'test.v1' references invalid table(s) or column(s) or function(s) or definer/invoker of view lack rights to use them
     <==== OK
2. 5.1.49-debug-log 
   mysql-5.1 revno: 3410 2010-06-03
-----------------------------------
Thread 1 (process 29124):
#0  0x00007f9ab0404ce6 in pthread_kill () from /lib64/libpthread.so.0
#1  0x0000000000b21a1f in my_write_core (sig=6) at stacktrace.c:329
#2  0x00000000006bd0ed in handle_segfault (sig=6) at mysqld.cc:2571
#3  <signal handler called>
#4  0x00007f9aaf60d5c5 in raise () from /lib64/libc.so.6
#5  0x00007f9aaf60ebb3 in abort () from /lib64/libc.so.6
#6  0x00007f9aaf6061e9 in __assert_fail () from /lib64/libc.so.6
#7  0x00000000006a30f2 in Diagnostics_area::set_ok_status (this=0x11c5050, thd=0x11c3998, affected_rows_arg=0, last_insert_id_arg=0, message_arg=0x419c7040 "Rows matched: 0  Changed: 0  Warnings: 0")
    at sql_class.cc:499
#8  0x00000000005cf8d6 in my_ok (thd=0x11c3998, affected_rows=0, id=0, message=0x419c7040 "Rows matched: 0  Changed: 0  Warnings: 0") at sql_class.h:2366
#9  0x0000000000787395 in mysql_update (thd=0x11c3998, table_list=0x12512e8, fields=@0x11c59b8, values=@0x11c5d98, conds=0x1236a50, order_num=0, order=0x0, limit=18446744073709551615, handle_duplicates=DUP_ERROR,
    ignore=false) at sql_update.cc:837
#10 0x00000000006d1b30 in mysql_execute_command (thd=0x11c3998) at sql_parse.cc:3090
#11 0x00000000006d81ac in mysql_parse (thd=0x11c3998, inBuf=0x12511f8 "UPDATE v1 SET pk = 7 WHERE pk > 0", length=33, found_semicolon=0x419c8ee0) at sql_parse.cc:5994
#12 0x00000000006d9034 in dispatch_command (command=COM_QUERY, thd=0x11c3998, packet=0x1218269 "UPDATE v1 SET pk = 7 WHERE pk > 0", packet_length=33) at sql_parse.cc:1241
#13 0x00000000006da502 in do_command (thd=0x11c3998) at sql_parse.cc:882
#14 0x00000000006c688c in handle_one_connection (arg=0x11c3998) at sql_connect.cc:1134
#15 0x00007f9ab0400040 in start_thread () from /lib64/libpthread.so.0
#16 0x00007f9aaf6ae08d in clone () from /lib64/libc.so.6
#17 0x0000000000000000 in ?? ()
[2 Jul 2010 8:29] Jon Olav Hauglid
Partitioned tables not needed:

CREATE TABLE t1 (PRIMARY KEY(pk)) AS SELECT 1 AS pk;
CREATE FUNCTION f1() RETURNS INTEGER RETURN (SELECT 1 FROM not_exists);
CREATE VIEW v1 AS SELECT pk FROM t1 WHERE f1() = 13;
UPDATE v1 SET pk = 7 WHERE pk > 0;
[2 Jul 2010 10: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/112727

3456 Jon Olav Hauglid	2010-07-02
      Bug #54734 assert in Diagnostics_area::set_ok_status
      
      This assert checks that the server does not try to send OK to the
      client if there has been some error during processing. This to make
      sure that the error is in fact sent to the client.
      
      The problem was that view errors during processing of WHERE conditions
      in UPDATE statements where not detected by the update code. It therefore
      tried to send OK to the client, triggering the assert.
      The bug was only noticeable in debug builds.
      
      This patch fixes the problem by making sure that the update code
      checks for errors during condition processing and acts accordingly.
[5 Jul 2010 13:54] 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/112896

3465 Jon Olav Hauglid	2010-07-05
      Bug #54734 assert in Diagnostics_area::set_ok_status
      
      This assert checks that the server does not try to send OK to the
      client if there has been some error during processing. This to make
      sure that the error is in fact sent to the client.
      
      The problem was that view errors during processing of WHERE conditions
      in UPDATE statements where not detected by the update code. It therefore
      tried to send OK to the client, triggering the assert.
      The bug was only noticeable in debug builds.
      
      This patch fixes the problem by making sure that the update code
      checks for errors during condition processing and acts accordingly.
[15 Jul 2010 6:41] Anitha Gopi
Also seen on mysql-next-mr-wl5136-stage
# 2010-07-15T08:07:23 #0  0x000000382860bd02 in pthread_kill () from /lib64/libpthread.so.0
# 2010-07-15T08:07:23 #1  0x0000000000b4904d in my_write_core (sig=6) at stacktrace.c:326
# 2010-07-15T08:07:23 #2  0x00000000006985c5 in handle_segfault (sig=6) at mysqld.cc:2789
# 2010-07-15T08:07:23 #3  <signal handler called>
# 2010-07-15T08:07:23 #4  0x0000003827a30265 in raise () from /lib64/libc.so.6
# 2010-07-15T08:07:23 #5  0x0000003827a31d10 in abort () from /lib64/libc.so.6
# 2010-07-15T08:07:23 #6  0x0000003827a296e6 in __assert_fail () from /lib64/libc.so.6
# 2010-07-15T08:07:23 #7  0x0000000000762dbe in Diagnostics_area::set_ok_status (this=0x135b95c0, thd=0x135b68d8, affected_rows_arg=0, 
# 2010-07-15T08:07:23     last_insert_id_arg=0, message_arg=0x4909eb40 "Rows matched: 0  Changed: 0  Warnings: 2") at sql_error.cc:360
# 2010-07-15T08:07:23 #8  0x00000000005a2c9a in my_ok (thd=0x135b68d8, affected_rows=0, id=0, 
# 2010-07-15T08:07:23     message=0x4909eb40 "Rows matched: 0  Changed: 0  Warnings: 2") at sql_class.h:2845
# 2010-07-15T08:07:23 #9  0x000000000076cc05 in mysql_update (thd=0x135b68d8, table_list=0x133f9120, fields=..., values=..., 
# 2010-07-15T08:07:23     conds=0x2aaab8174170, order_num=0, order=0x0, limit=1, handle_duplicates=DUP_ERROR, ignore=false, 
# 2010-07-15T08:07:23     found_return=0x4909fce0, updated_return=0x4909fcd8) at sql_update.cc:850
# 2010-07-15T08:07:23 #10 0x00000000006ac9ab in mysql_execute_command (thd=0x135b68d8) at sql_parse.cc:3080
# 2010-07-15T08:07:23 #11 0x00000000006b1d12 in mysql_parse (thd=0x135b68d8, 
# 2010-07-15T08:07:23     inBuf=0x133f8fa8 "UPDATE   testdb_S . t1_view2_N  SET `pk` = 7 WHERE SLEEP( 0.5 * 0.7 * 1 ) = 0 LIMIT 1", length=85, 
# 2010-07-15T08:07:23     parser_state=0x490a0610) at sql_parse.cc:5816
# 2010-07-15T08:07:23 #12 0x00000000006b326e in dispatch_command (command=COM_QUERY, thd=0x135b68d8, 
# 2010-07-15T08:07:23     packet=0x134fe699 "UPDATE   testdb_S . t1_view2_N  SET `pk` = 7 WHERE SLEEP( 0.5 * 0.7 * 1 ) = 0 LIMIT 1", 
# 2010-07-15T08:07:23     packet_length=85) at sql_parse.cc:1085
# 2010-07-15T08:07:23 #13 0x00000000006b47a0 in do_command (thd=0x135b68d8) at sql_parse.cc:771
# 2010-07-15T08:07:23 #14 0x00002aaaaabc3738 in tp_process_event (my_thread_data=0x2aaaaadc65e0) at thread_pool.cc:858
# 2010-07-15T08:07:23 #15 0x00002aaaaabc3ae9 in tp_group_low_level_wait_for_events (tp_group_low_level_cntx=0x132f7668, 
# 2010-07-15T08:07:23     my_tp_group=0x2aaaaadc6300, my_thread_data=0x2aaaaadc65e0, next_events=0x490a0f90, wait=true) at epoll.ic:237
# 2010-07-15T08:07:23 #16 0x00002aaaaabc3d29 in handle_waiting_thread (my_tp_group=0x2aaaaadc6300, my_thread_data=0x2aaaaadc65e0, wait=true)
# 2010-07-15T08:07:23     at thread_pool.cc:1176
# 2010-07-15T08:07:23 #17 0x00002aaaaabc3dff in high_concurrency_algorithm (my_tp_group=0x2aaaaadc6300, my_thread_data=0x2aaaaadc65e0)
# 2010-07-15T08:07:23     at thread_pool.cc:1318
# 2010-07-15T08:07:23 #18 0x00002aaaaabc3fec in tp_worker_thread_main (arg=0x2aaaaadc65e0) at thread_pool.cc:1466
# 2010-07-15T08:07:23 #19 0x000000382860673d in start_thread () from /lib64/libpthread.so.0
# 2010-07-15T08:07:23 #20 0x0000003827ad3d1d in clone () from /lib64/libc.so.6
[16 Jul 2010 9:03] 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/113739

3488 Jon Olav Hauglid	2010-07-16
      Bug #54734 assert in Diagnostics_area::set_ok_status
      
      This assert checks that the server does not try to send OK to the
      client if there has been some error during processing. This to make
      sure that the error is in fact sent to the client.
      
      The problem was that view errors during processing of WHERE conditions
      in UPDATE statements where not detected by the update code. It therefore
      tried to send OK to the client, triggering the assert.
      The bug was only noticeable in debug builds.
      
      This patch fixes the problem by making sure that the update code
      checks for errors during condition processing and acts accordingly.
[19 Jul 2010 9:05] 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/113834

3491 Jon Olav Hauglid	2010-07-19
      Bug #54734 assert in Diagnostics_area::set_ok_status
      
      This assert checks that the server does not try to send OK to the
      client if there has been some error during processing. This is done
      to make sure that the error is in fact sent to the client.
      
      The problem was that view errors during processing of WHERE conditions
      in UPDATE statements where not detected by the update code. It therefore
      tried to send OK to the client, triggering the assert.
      The bug was only noticeable in debug builds.
      
      This patch fixes the problem by making sure that the update code
      checks for errors during condition processing and acts accordingly.
[19 Jul 2010 9:23] Jon Olav Hauglid
Pushed to mysql-5.1-bugteam (5.1.49) and merged to mysql-trunk-merge.
[23 Jul 2010 12:22] Bugs System
Pushed into mysql-trunk 5.5.6-m3 (revid:alik@sun.com-20100723121820-jryu2fuw3pc53q9w) (version source revid:vasil.dimov@oracle.com-20100531152341-x2d4hma644icamh1) (merge vers: 5.5.5-m3) (pib:18)
[23 Jul 2010 12:29] Bugs System
Pushed into mysql-next-mr (revid:alik@sun.com-20100723121929-90e9zemk3jkr2ocy) (version source revid:vasil.dimov@oracle.com-20100531152341-x2d4hma644icamh1) (pib:18)
[30 Jul 2010 3:10] Paul Dubois
Noted in 5.1.50, 5.5.6 changelogs.

In debug builds, an assertion could be raised when the server tried
to send an OK packet to the client after having failed to detect
errors during processing of the WHERE condition of an UPDATE
statement.
[19 Aug 2010 15:41] Bugs System
Pushed into mysql-5.1 5.1.51 (revid:build@mysql.com-20100819151858-muaaor6jojb5ouzj) (version source revid:build@mysql.com-20100819151858-muaaor6jojb5ouzj) (merge vers: 5.1.51) (pib:20)
[14 Oct 2010 8:36] Bugs System
Pushed into mysql-5.1-telco-7.0 5.1.51-ndb-7.0.20 (revid:martin.skold@mysql.com-20101014082627-jrmy9xbfbtrebw3c) (version source revid:martin.skold@mysql.com-20101014082627-jrmy9xbfbtrebw3c) (merge vers: 5.1.51-ndb-7.0.20) (pib:21)
[14 Oct 2010 8:51] Bugs System
Pushed into mysql-5.1-telco-6.3 5.1.51-ndb-6.3.39 (revid:martin.skold@mysql.com-20101014083757-5qo48b86d69zjvzj) (version source revid:martin.skold@mysql.com-20101014083757-5qo48b86d69zjvzj) (merge vers: 5.1.51-ndb-6.3.39) (pib:21)
[14 Oct 2010 9:07] Bugs System
Pushed into mysql-5.1-telco-6.2 5.1.51-ndb-6.2.19 (revid:martin.skold@mysql.com-20101014084420-y54ecj85j5we27oa) (version source revid:martin.skold@mysql.com-20101014084420-y54ecj85j5we27oa) (merge vers: 5.1.51-ndb-6.2.19) (pib:21)
[15 Oct 2010 13:29] Jon Stephens
Already documented in the 5.1.50 changelog. Reverting to Closed state.