Bug #20548 Events: crash if InnoDB, multiple events, busy procedures, partitions
Submitted: 19 Jun 2006 21:21 Modified: 2 Sep 2006 4:32
Reporter: Peter Gulutzan Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: Partitions Severity:S3 (Non-critical)
Version:5.1.12-beta-debug OS:Linux (SUSE 10.0 / 64-bit)
Assigned to: Sergei Glukhov CPU Architecture:Any

[19 Jun 2006 21:21] Peter Gulutzan
Description:
I create a partitioned InnoDB table.
I create a procedure which does a variety of statements.
I create four events which all call this procedure many times.
I say "set global event_scheduler = 1".
Crash after a few minutes, shortly after the following display by mysqld:
"
InnoDB: We now intentionally generate a seg fault so that
InnoDB: on Linux we get a stack trace.
"

How to repeat:
delimiter //

create table tp
(s1 int, s2 varchar(2500),s3 timestamp)
engine=innodb
partition by list (mod(s1,5))
(partition pn values in (null),
 partition p0 values in (0),
 partition p1 values in (1),
 partition p2 values in (2),
 partition p3 values in (3),
 partition p4 values in (4),
 partition p5 values in (5))//

create index itp1 on tp (s1)//
create index itp2 on tp (s2)//

create procedure pp (ppar int)
begin
  declare v int default 1;
  declare v2 int;
  declare v3 int;
  declare continue handler for sqlexception
  begin
    declare continue handler for sqlexception begin end;
    delete from tp where s1 = rand()*ppar;
    end;
  while v < ppar do
    set v2 = mod(v,10);
    if v2 = 0 then
      insert into tp values (rand()*ppar,repeat('a',mod(v,1000)),current_timestamp);
      end if;
    if v2 = 1 then
      update tp set s1 = mod(rand()*ppar,5) where s1 = mod(rand()*ppar,5);
      end if;
    if v2 = 2 then
      show processlist;
      end if;
    if v2 = 3 then
      delete from tp where s2 = repeat('a',mod(v,1000));
      end if;
    if v2 = 4 then
      alter table tp modify column s1 smallint;
      end if;
    if v2 = 5 then
      kill 999999;
      end if;
    if v2 = 6 then
      alter table tp modify column s1 int;
      end if;
    if v2 = 7 then
      set v3 = (select count(*) from tp);
      end if;
    if v2 = 8 then
      create index i2tp on tp (s2);
      end if;
    if v2 = 9 then
      drop index i2tp on tp;
      end if;
    set v = v + 1;
    end while;
  end;//

create event e1 on schedule every 1 second do call pp(1000)//
create event e2 on schedule every 1 second do call pp(1000)//
create event e3 on schedule every 1 second do call pp(1000)//
create event e4 on schedule every 1 second do call pp(1000)//

set global event_scheduler = 1//
[19 Jun 2006 21:42] Andrey Hristov
Verified on SuSE 9.3, older tree but still crashing, in InnoDB. This seems not to be an events bug but they help crashing the server.

Here is the select * from i_s.processlist output:
mysql> select * from information_schema.processlist\G
*************************** 1. row ***************************
     ID: 6
   USER: root
   HOST: localhost
     DB: db1
COMMAND: Connect
   TIME: 39
  STATE: Waiting for table
   INFO: update tp set s1 = mod(rand()*ppar,5) where s1 =
mod(rand()*ppar,5)
*************************** 2. row ***************************
     ID: 5
   USER: root
   HOST: localhost
     DB: db1
COMMAND: Connect
   TIME: 39
  STATE: Waiting for table
   INFO: insert into tp values
(rand()*ppar,repeat('a',mod(v,1000)),current_timestamp)
*************************** 3. row ***************************
     ID: 4
   USER: root
   HOST: localhost
     DB: db1
COMMAND: Connect
   TIME: 39
  STATE: copy to tmp table
   INFO: drop index i2tp on tp
*************************** 4. row ***************************
     ID: 3
   USER: root
   HOST: localhost
     DB: db1
COMMAND: Connect
   TIME: 39
  STATE: Waiting for table
   INFO: call pp(1000
*************************** 5. row ***************************
     ID: 2
   USER: root
   HOST: localhost
     DB: db1
COMMAND: Query
   TIME: 0
  STATE: preparing
   INFO: select * from information_schema.processlist
*************************** 6. row ***************************
     ID: 1
   USER: event_scheduler
   HOST: localhost
     DB: NULL
COMMAND: Connect
   TIME: 0
  STATE: Sleeping
   INFO: NULL
6 rows in set (0.01 sec)

In the console I get the following message, very disturbing because it seems memory gets corrupted:
060619 23:35:04  InnoDB: Error: cannot allocate 3044334664 bytes of
InnoDB: memory with malloc! Total allocated memory
InnoDB: by InnoDB 20003614 bytes. Operating system errno: 12
InnoDB: Check if you should increase the swap file or
InnoDB: ulimits of your operating system.
InnoDB: On FreeBSD check you have compiled the OS with
InnoDB: a big enough maximum process size.
InnoDB: Note that in most 32-bit computers the process
InnoDB: memory space is limited to 2 GB or 4 GB.
InnoDB: We keep retrying the allocation for 60 seconds...

Previous try to reproduce crashed at the same place, but the error above was:

060619 23:28:51  InnoDB: Error: cannot allocate 2779096520 bytes of
InnoDB: memory with malloc! Total allocated memory
InnoDB: by InnoDB 20003614 bytes. Operating system errno: 12
InnoDB: Check if you should increase the swap file or
InnoDB: ulimits of your operating system.
InnoDB: On FreeBSD check you have compiled the OS with
InnoDB: a big enough maximum process size.
InnoDB: Note that in most 32-bit computers the process
InnoDB: memory space is limited to 2 GB or 4 GB.
InnoDB: We keep retrying the allocation for 60 seconds...

Here is the backtrace:

#0  0x08507e3d in ut_malloc_low (n=3044334664, set_to_zero=1, assert_on_error=1) at ut0mem.c:141
#1  0x08507efb in ut_malloc (n=3044334664) at ut0mem.c:178
#2  0x084c8cd0 in mem_area_alloc (size=3044334664, pool=0x8ca6840) at mem0pool.c:354
#3  0x084c800a in mem_heap_create_block (heap=0x0, n=3044334596, init_block=0x0, type=0, file_name=0x86afd9e "ha_innodb.cc", line=2989) at mem0mem.c:183
#4  0x084c74a3 in mem_heap_create_func (n=3044334596, init_block=0x0, type=0, file_name=0x86afd9e "ha_innodb.cc", line=2989) at mem0mem.ic:409
#5  0x084c75bb in mem_alloc_func (n=3044334596, file_name=0x86afd9e "ha_innodb.cc", line=2989) at mem0mem.ic:498
#6  0x084c7ecf in mem_alloc_func_noninline (n=3044334596, file_name=0x86afd9e "ha_innodb.cc", line=2989) at mem0mem.c:100
#7  0x082ffef8 in ha_innobase::build_template (this=0x92d0200, prebuilt=0x405a2868, thd=0x9211b00, table=0x4239b640, templ_type=0) at ha_innodb.cc:2987
#8  0x083015bc in ha_innobase::change_active_index (this=0x92d0200, keynr=64) at ha_innodb.cc:3991
#9  0x0830190c in ha_innobase::rnd_init (this=0x92d0200, scan=true) at ha_innodb.cc:4194
#10 0x0815a362 in handler::ha_rnd_init (this=0x92d0200, scan=true) at handler.h:1015
#11 0x082f91c0 in ha_partition::rnd_init (this=0x92d0048, scan=true) at ha_partition.cc:2897
#12 0x0815a362 in handler::ha_rnd_init (this=0x92d0048, scan=true) at handler.h:1015
#13 0x082e09ae in init_read_record (info=0x4239bd30, thd=0x9211b00, table=0x91a5a00, select=0x0, use_record_cache=1, print_error=true) at records.cc:232
#14 0x08325c35 in copy_data_between_tables (from=0x91a5a00, to=0x927c4c0, create=@0x4239c250, handle_duplicates=DUP_ERROR, ignore=false, order_num=0,
    order=0x0, copied=0x4239c4b8, deleted=0x4239c4b0) at sql_table.cc:6225
#15 0x08324985 in mysql_alter_table (thd=0x9211b00, new_db=0x9231e80 "db1", new_name=0x9231ca8 "tp", create_info=0x4239d1d0, table_list=0x9231ce0,
    fields=@0x4239d260, keys=@0x4239d250, order_num=0, order=0x0, handle_duplicates=DUP_ERROR, ignore=false, alter_info=0x925f998, do_send_ok=true)
    at sql_table.cc:5712
#16 0x0822753c in mysql_drop_index (thd=0x9211b00, table_list=0x9231ce0, alter_info=0x925f998) at sql_parse.cc:7206
#17 0x0821ed2b in mysql_execute_command (thd=0x9211b00) at sql_parse.cc:3519
#18 0x0838396b in sp_instr_stmt::exec_core (this=0x9231e88, thd=0x9211b00, nextp=0x4239d950) at sp_head.cc:2356
#19 0x083835a7 in sp_lex_keeper::reset_lex_and_exec_core (this=0x9231eb0, thd=0x9211b00, nextp=0x4239d950, open_tables=false, instr=0x9231e88)
    at sp_head.cc:2230
#20 0x083837ed in sp_instr_stmt::execute (this=0x9231e88, thd=0x9211b00, nextp=0x4239d950) at sp_head.cc:2307
#21 0x083807b4 in sp_head::execute (this=0x9240450, thd=0x9211b00) at sp_head.cc:1084
#22 0x08381990 in sp_head::execute_procedure (this=0x9240450, thd=0x9211b00, args=0x9223fa0) at sp_head.cc:1559
#23 0x08221be1 in mysql_execute_command (thd=0x9211b00) at sql_parse.cc:4602
#24 0x0838396b in sp_instr_stmt::exec_core (this=0x921de78, thd=0x9211b00, nextp=0x4239e170) at sp_head.cc:2356
#25 0x083835a7 in sp_lex_keeper::reset_lex_and_exec_core (this=0x921dea0, thd=0x9211b00, nextp=0x4239e170, open_tables=false, instr=0x921de78)
    at sp_head.cc:2230
#26 0x083837ed in sp_instr_stmt::execute (this=0x921de78, thd=0x9211b00, nextp=0x4239e170) at sp_head.cc:2307
#27 0x083807b4 in sp_head::execute (this=0x921dab8, thd=0x9211b00) at sp_head.cc:1084
#28 0x08381990 in sp_head::execute_procedure (this=0x921dab8, thd=0x9211b00, args=0x4239e2e0) at sp_head.cc:1559
#29 0x0839d008 in Event_timed::execute (this=0x9167e58, thd=0x9211b00, mem_root=0x9211b20) at event_timed.cc:1412
#30 0x083928b4 in event_worker_thread (arg=0x4233b300) at event_scheduler.cc:567
#31 0x40053aa7 in start_thread () from /lib/tls/libpthread.so.0
#32 0x40184c2e in clone () from /lib/tls/libc.so.6
[19 Jun 2006 22:27] MySQL Verification Team
Thank you for the bug report.

Program received signal SIGSEGV, Segmentation fault.
[Switching to Thread 1125235632 (LWP 18826)]
0x08351fa4 in ha_innobase::build_template (this=0x4325dba8, prebuilt=0x40691468, thd=0x43252e50, table=0x43118074, templ_type=0)
    at ha_innodb.cc:2984
2984            n_fields = (ulint)table->s->fields; /* number of columns */
(gdb)
[11 Aug 2006 8:18] Sergei Glukhov
Here is decreased test case(without Innodb) which leads to crash also:

delimiter //;

create table tp
(s1 int)
engine=myisam
partition by list (mod(s1,5))
(partition pn values in (null),
 partition p0 values in (0))//

create procedure pp (ppar int)
begin
  declare v int default 1;
  declare v2 int;
  declare v3 int;

  while v < ppar do
    set v2 = mod(v,10);

    if v2 = 6 then
      alter table tp modify column s1 int;
    end if;

    set v = v + 1;
    end while;
  end;//

create event e1 on schedule every 1 second do call pp(1000)//
create event e2 on schedule every 1 second do call pp(1000)//
#create event e3 on schedule every 1 second do call pp(1000)//
#create event e4 on schedule every 1 second do call pp(1000)//

set global event_scheduler = 1//

--sleep 10000

how to use:
create t/aaa.test with operators listed above
run ./mysql-test-run --debug aaa
(test passed without --debug and crash with --debug)
[22 Aug 2006 14:51] 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/10730

ChangeSet@1.2289, 2006-08-22 20:07:39+05:00, gluh@mysql.com +9 -0
  Bug#20548 Events: crash if InnoDB, multiple events, busy procedures, partitions
   setup 'share' struct for all partiton file elements. It's neccessary because we use
   m_file[0]->update_create_info(create_info) during ha_partition::update_create_info
   and 'share' for m_file[0] should be valid
[23 Aug 2006 8:04] 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/10745

ChangeSet@1.2281, 2006-08-23 13:20:36+05:00, gluh@mysql.com +3 -0
  Bug#20548 Events: crash if InnoDB, multiple events, busy procedures, partitions
  setup 'share' struct for all partiton file elements. It's neccessary because we use
  m_file[0]->update_create_info(create_info) during ha_partition::update_create_info
  and 'share' for m_file[0] should be valid
[23 Aug 2006 11:41] 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/10753

ChangeSet@1.2281, 2006-08-23 16:58:36+05:00, gluh@mysql.com +3 -0
  Bug#20548 Events: crash if InnoDB, multiple events, busy procedures, partitions
  setup 'share' struct for all partiton file elements. It's neccessary because we use
  m_file[0]->update_create_info(create_info) during ha_partition::update_create_info
  and 'share' for m_file[0] should be valid
[1 Sep 2006 7:51] Mikael Ronström
Patch will appear in 5.1.12
[2 Sep 2006 4:32] Jon Stephens
Documented bugfix in 5.1.12 changelog.