MySQL Bugs: #25398: Trigger on InnoDB table with composite PK crashes server

Bug #25398	Trigger on InnoDB table with composite PK crashes server
Submitted:	3 Jan 2007 21:52	Modified:	1 Feb 2007 2:01
Reporter:	Todd Farmer (OCA)	Email Updates:
Status:	Closed	Impact on me:	None
Category:	MySQL Server: Optimizer	Severity:	S1 (Critical)
Version:	5.0	OS:
Assigned to:	Igor Babaev	CPU Architecture:	Any
Tags:	bfsm_2007_01_18, composite, crashing, primary key, regression, trigger

Description:
AFTER UPDATE trigger on InnoDB table with composite primary key causes server crash.  This issue is reproducible on both Windows and Linux on 5.0.27 and 5.0.32.  It cannot be reproduced using MyISAM tables or on tables with a single primary key column.

Please see attached test case and stack trace.

How to repeat:
See attached test case.

Suggested fix:
Don't crash server.

test case

Attachment: TriggerBugScript.sql (text/x-sql), 1.85 KiB.

stack trace

Attachment: tfarmer-desktop.err (application/octet-stream, text), 7.11 KiB.

Verified that the INSERT statement embedded in the trigger does not cause an error outside the context of the trigger:

mysql> update fubar set c='Bang!' where id=1;
ERROR 2013 (HY000): Lost connection to MySQL server during query
mysql> 
mysql> 
mysql> 
mysql> -e 
Number of processes running now: 0
070103 13:36:14  mysqld restarted
select now();
ERROR 2006 (HY000): MySQL server has gone away
No connection. Trying to reconnect...
Connection id:    1
Current database: test

+---------------------+
| now()               |
+---------------------+
| 2007-01-03 13:39:04 | 
+---------------------+
1 row in set (0.01 sec)

mysql>             INSERT INTO fubar_changes (fubar_id, last_change_time)
    -> 
    ->                 SELECT DISTINCT id AS fubar_id, NOW() AS last_change_time
    -> 
    ->                 FROM fubar WHERE (id = 1)
    -> 
    ->                 AND
    -> 
    ->                 (
    -> 
    ->                     (c != 'Bang!')
    -> 
    ->                 )
    -> 
    ->             ON DUPLICATE KEY UPDATE
    -> 
    ->                 last_change_time =
    -> 
    ->                 IF ((fubar_id = 1)
    -> 
    ->                 AND
    -> 
    ->                 (
    -> 
    ->                     (c != 'Bang!')
    -> 
    ->                 ) , NOW() , last_change_time);
Query OK, 1 row affected (0.01 sec)
Records: 1  Duplicates: 0  Warnings: 0

mysql> select * from fubar_changes;
+----------+---------------------+
| fubar_id | last_change_time    |
+----------+---------------------+
|        1 | 2007-01-03 13:41:31 | 
+----------+---------------------+

Starting program: /home/heikki/mysql-5.0/sql/mysqld
[Thread debugging using libthread_db enabled]
[New Thread 1075726944 (LWP 16991)]
070104 16:13:50 [Warning] Changed limits: max_open_files: 1024  max_connections: 886  table_cache: 64
InnoDB: !!!!!!!!!!!!!! UNIV_DEBUG switched on !!!!!!!!!!!!!!!
InnoDB: !!!!!!!!!!!!!! UNIV_SYNC_DEBUG switched on !!!!!!!!!!!!!!!
InnoDB: !!!!!!!!!!!!!! UNIV_SEARCH_DEBUG switched on !!!!!!!!!!!!!!!
InnoDB: !!!!!!!!!!!!!! UNIV_MEM_DEBUG switched on !!!!!!!!!!!!!!!
[New Thread 1198783408 (LWP 16994)]
[New Thread 1207172016 (LWP 16995)]
[New Thread 1215560624 (LWP 16996)]
[New Thread 1223949232 (LWP 16997)]
InnoDB: Warning: we did not need to do crash recovery, but log scan
InnoDB: progressed past the checkpoint lsn 0 51098489 up to lsn 0 51104989
070104 16:13:50  InnoDB: Starting an apply batch of log records to the database...
InnoDB: Progress in percents: 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99
InnoDB: Apply batch completed
[New Thread 1232337840 (LWP 16998)]
[New Thread 1244453808 (LWP 16999)]
[New Thread 1252916144 (LWP 17000)]
[Thread 1232337840 (zombie) exited]
[New Thread 1261304752 (LWP 17001)]
070104 16:13:52  InnoDB: Started; log sequence number 0 51098489
070104 16:13:52 [Note] Recovering after a crash using 1
070104 16:13:52 [Note] Starting crash recovery...
070104 16:13:52 [Note] Crash recovery finished.
[New Thread 1285082032 (LWP 17002)]
[New Thread 1285278640 (LWP 17003)]
070104 16:13:52 [Note] /home/heikki/mysql-5.0/sql/mysqld: ready for connections.
Version: '5.0.32-debug-log'  socket: '/home/heikki/bugsocket'  port: 3307  Source distribution
[New Thread 1285475248 (LWP 17017)]

Program received signal SIGSEGV, Segmentation fault.
[Switching to Thread 1285475248 (LWP 17017)]
0x081e9595 in Field::offset (this=0xa5a5a5a5) at field.cc:1240
1240      return (uint) (ptr - (char*) table->record[0]);
(gdb) bt
#0  0x081e9595 in Field::offset (this=0xa5a5a5a5) at field.cc:1240
#1  0x08289cc8 in remove_duplicates (join=0x9781fa0, entry=0x9784070,
    fields=@0x9782d08, having=0x0) at sql_select.cc:12341
#2  0x082719eb in JOIN::exec (this=0x9781fa0) at sql_select.cc:1663
#3  0x082729cf in mysql_select (thd=0x96d2c68, rref_pointer_array=0x9773a64,
    tables=0x976dc10, wild_num=0, fields=@0x97739c8, conds=0x976e2d0,
    og_num=0, order=0x0, group=0x0, having=0x0, proc_param=0x0,
    select_options=3500165633, result=0x9781f38, unit=0x977370c,
    select_lex=0x977393c) at sql_select.cc:2017
#4  0x0826d0b6 in handle_select (thd=0x96d2c68, lex=0x97736a8,
    result=0x9781f38, setup_tables_done_option=1073741824) at sql_select.cc:245
#5  0x082321aa in mysql_execute_command (thd=0x96d2c68) at sql_parse.cc:3444
#6  0x083a1b5b in sp_instr_stmt::exec_core (this=0x976ecc0, thd=0x96d2c68,
    nextp=0x4c9eb9d8) at sp_head.cc:2492
#7  0x083a178f in sp_lex_keeper::reset_lex_and_exec_core (this=0x976ece8,
    thd=0x96d2c68, nextp=0x4c9eb9d8, open_tables=false, instr=0x976ecc0)
    at sp_head.cc:2368
#8  0x083a19e7 in sp_instr_stmt::execute (this=0x976ecc0, thd=0x96d2c68,
    nextp=0x4c9eb9d8) at sp_head.cc:2445
#9  0x0839e277 in sp_head::execute (this=0x976d270, thd=0x96d2c68)
    at sp_head.cc:1057
#10 0x0839eaa9 in sp_head::execute_trigger (this=0x976d270, thd=0x96d2c68,
    db=0x976c248 "test", table=0x96ed0b0 "fubar", grant_info=0x976c04c)
    at sp_head.cc:1320
#11 0x083b12af in Table_triggers_list::process_triggers (this=0x976bfb0,
    thd=0x96d2c68, event=TRG_EVENT_UPDATE, time_type=TRG_ACTION_AFTER,
    old_row_is_record1=true) at sql_trigger.cc:1509
#12 0x082a45eb in mysql_update (thd=0x96d2c68, table_list=0x97467a0,
    fields=@0x96d2fc8, values=@0x96d31a8, conds=0x9746b78, order_num=0,
    order=0x0, limit=18446744073709551615, handle_duplicates=DUP_ERROR,
    ignore=false) at sql_update.cc:478
#13 0x08231cec in mysql_execute_command (thd=0x96d2c68) at sql_parse.cc:3310
#14 0x08238a64 in mysql_parse (thd=0x96d2c68,
    inBuf=0x9746710 "update fubar set c='Bang!' where id=1", length=37)
    at sql_parse.cc:5825
#15 0x0822ddcd in dispatch_command (command=COM_QUERY, thd=0x96d2c68,
    packet=0x973e6b1 "update fubar set c='Bang!' where id=1", packet_length=38)
    at sql_parse.cc:1773
#16 0x0822d51d in do_command (thd=0x96d2c68) at sql_parse.cc:1557
#17 0x0822c607 in handle_one_connection (arg=0x96d2c68) at sql_parse.cc:1188
#18 0x40041b63 in start_thread () from /lib/tls/libpthread.so.0
#19 0x4018718a in clone () from /lib/tls/libc.so.6
(gdb) frame 2
#2  0x082719eb in JOIN::exec (this=0x9781fa0) at sql_select.cc:1663
1663          if (remove_duplicates(curr_join, curr_tmp_table,
(gdb) list
1658        if (curr_join->select_distinct && ! curr_join->group_list)
1659        {
1660          thd->proc_info="Removing duplicates";
1661          if (curr_join->tmp_having)
1662            curr_join->tmp_having->update_used_tables();
1663          if (remove_duplicates(curr_join, curr_tmp_table,
1664                                *curr_fields_list, curr_join->tmp_having))
1665            DBUG_VOID_RETURN;
1666          curr_join->tmp_having=0;
1667          curr_join->select_distinct=0;
(gdb) frame 1
#1  0x08289cc8 in remove_duplicates (join=0x9781fa0, entry=0x9784070,
    fields=@0x9782d08, having=0x0) at sql_select.cc:12341
12341     offset= field_count ?
(gdb) list
12336     {                    // only const items with no OPTION_FOUND_ROWS
12337       join->unit->select_limit_cnt= 1;            // Only send first row
12338       DBUG_RETURN(0);
12339     }
12340     Field **first_field=entry->field+entry->s->fields - field_count;
12341     offset= field_count ?
12342             entry->field[entry->s->fields - field_count]->offset() : 0;
12343     reclength=entry->s->reclength-offset;
12344
12345     free_io_cache(entry);                         // Safety
(gdb) print offset
$1 = 158790104
(gdb) print field_count
$2 = 1
(gdb) print entry->s->fields
$3 = 0
(gdb) print *Field
A syntax error in expression, near `'.
(gdb) print *first_field
$4 = (class Field *) 0xa5a5a5a5
(gdb) print first_field
$5 = (class Field **) 0x97847e4
(gdb) print entry->field
$6 = (class Field **) 0x97847e8
(gdb) print *entry->field
$7 = (class Field *) 0x0
(gdb)

This looks like a MySQL bug.

entry->s->fields - field_count = -1, thus first_field points to position -1 in the field array, which probably does not make sense.

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/18006

ChangeSet@1.2378, 2007-01-11 21:12:50-08:00, igor@olga.mysql.com +3 -0
  Fixed bug #25398: crash in a trigger when using trigger fields 
  in a select list.
  The objects of the Item_trigger_field class inherited the methods
  copy_or_same and get_tmp_table_item from the class Item_field while
  they rather should have used the default implementations defined 
  for the base class Item.
  It could cause catastrophic problems for triggers that used SELECTs
  with select list containing trigger fields such as NEW.<table column>
  under DISTINCT.

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/18080

ChangeSet@1.2378, 2007-01-12 13:43:25-08:00, igor@olga.mysql.com +3 -0
  Fixed bug #25398: crash in a trigger when using trigger fields 
  in a select list.
  The objects of the Item_trigger_field class inherited the implementations
  of the methods copy_or_same, get_tmp_table_item and get_tmp_table_field
  from the class Item_field while they rather should have used the default
  implementations defined for the base class Item.
  It could cause catastrophic problems for triggers that used SELECTs
  with select list containing trigger fields such as NEW.<table column>
  under DISTINCT.

The fix has been pushed into 5.0.36, 5.1.16-beta main trees.

Thank you for your bug report. This issue has been committed to our source repository of that product and will be incorporated into the next release.

If necessary, you can access the source repository and build the latest available version, including the bug fix. More information about accessing the source trees is available at

    http://dev.mysql.com/doc/en/installing-source.html

Documented bugfix in 5.0.36 and 5.1.16 changelogs.