MariaDB

Pre- and post-recovery crash in Aria in _ma_read_block_record2 and _ma_put_key_in_record

Bug #716890 reported by Philip Stoev
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
MariaDB
Fix Released
Critical
Michael Widenius
MariaDB 5.1

Bug Description

The folowing two crashes almost always go together, so I am filing them with a single bug and a single RQG command line to execute:

pre-recovery:

#5 0x00000000009570b5 in _ma_read_block_record2 (info=0x7f03e0032e68, record=0x2 <Address 0x2 out of bounds>, data=0x7f03e0033596 "",
    end_of_data=0x7f03e0033c54 "") at ma_blockrec.c:4732
#6 0x0000000000958487 in _ma_read_block_record (info=0x7f03e0032e68, record=0x2 <Address 0x2 out of bounds>, record_pos=256) at ma_blockrec.c:5100
#7 0x000000000095f9f2 in maria_rnext (info=0x7f03e0032e68, buf=0x2 <Address 0x2 out of bounds>, inx=0) at ma_rnext.c:133
#8 0x00000000009789ee in maria_rfirst (info=0x7f03e0032e68, buf=0x2 <Address 0x2 out of bounds>, inx=0) at ma_rfirst.c:25
#9 0x000000000093e26e in ha_maria::index_first (this=0x7f03e0013880, buf=0x2 <Address 0x2 out of bounds>) at ha_maria.cc:2169
#10 0x00000000007d8e61 in ha_partition::handle_ordered_index_scan (this=0x7f03e00130d0, buf=0x7f03e001b9f0 "\377\377\377", reverse_order=false)
    at ha_partition.cc:4808
#11 0x00000000007d7b59 in ha_partition::common_first_last (this=0x7f03e00130d0, buf=0x7f03e001b9f0 "\377\377\377") at ha_partition.cc:4265
#12 0x00000000007d7a2b in ha_partition::index_first (this=0x7f03e00130d0, buf=0x7f03e001b9f0 "\377\377\377") at ha_partition.cc:4214
#13 0x00000000007bd6fe in rr_index_first (info=0x7f04701eec70) at records.cc:350
#14 0x0000000000749bce in mysql_delete (thd=0x3f491c8, table_list=0x7f03e0014b98, conds=0x7f03e0015298, order=0x3f4b488, limit=1, options=0,
    reset_auto_increment=false) at sql_delete.cc:305
#15 0x000000000068bfe4 in mysql_execute_command (thd=0x3f491c8) at sql_parse.cc:3418
#16 0x00000000006946e1 in mysql_parse (thd=0x3f491c8,
    rawbuf=0x7f03e0014910 "DELETE FROM `table1000_maria_key_pk_parts_2_int_autoinc` WHERE `col_set_utf8_key` <= REPEAT( _LATIN1 0x6 , 192 ) ORDER BY `pk` LIMIT 1", length=134, found_semicolon=0x7f04701efc70) at sql_parse.cc:6156
#17 0x00000000006864e4 in dispatch_command (command=COM_QUERY, thd=0x3f491c8,
    packet=0x3fe73b9 "DELETE FROM `table1000_maria_key_pk_parts_2_int_autoinc` WHERE `col_set_utf8_key` <= REPEAT( _LATIN1 0x6 , 192 ) ORDER BY `pk` LIMIT 1", packet_length=134) at sql_parse.cc:1273
#18 0x0000000000685504 in do_command (thd=0x3f491c8) at sql_parse.cc:899
#19 0x00000000006824f5 in handle_one_connection (arg=0x3f491c8) at sql_connect.cc:1138
#20 0x0000003e05c07761 in start_thread (arg=0x7f04701f0710) at pthread_create.c:301
#21 0x0000003e058e14fd in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:115

post-recovery:

#4 0x000000000097a498 in _ma_put_key_in_record (info=0x7fb5a009b4e8, keynr=3, record=0x2 <Address 0x2 out of bounds>) at ma_key.c:512
#5 0x000000000097aabf in _ma_read_key_record (info=0x7fb5a009b4e8, buf=0x2 <Address 0x2 out of bounds>, filepos=28416) at ma_key.c:637
#6 0x000000000095f9f2 in maria_rnext (info=0x7fb5a009b4e8, buf=0x2 <Address 0x2 out of bounds>, inx=3) at ma_rnext.c:133
#7 0x00000000009789ee in maria_rfirst (info=0x7fb5a009b4e8, buf=0x2 <Address 0x2 out of bounds>, inx=3) at ma_rfirst.c:25
#8 0x000000000093e26e in ha_maria::index_first (this=0x7fb5a006a700, buf=0x2 <Address 0x2 out of bounds>) at ha_maria.cc:2169
#9 0x00000000007d8e61 in ha_partition::handle_ordered_index_scan (this=0x7fb5a002bce0,
    buf=0x7fb5a00886b0 "\336\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376"..., reverse_order=false) at ha_partition.cc:4808
#10 0x00000000007d7b59 in ha_partition::common_first_last (this=0x7fb5a002bce0,
    buf=0x7fb5a00886b0 "\336\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376"...) at ha_partition.cc:4265
#11 0x00000000007d7a2b in ha_partition::index_first (this=0x7fb5a002bce0,
    buf=0x7fb5a00886b0 "\336\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376\376"...) at ha_partition.cc:4214
#12 0x0000000000716e72 in join_read_first (tab=0x7fb5a004c6f0) at sql_select.cc:12498
#13 0x0000000000714ef8 in sub_select (join=0x7fb5a004ab70, join_tab=0x7fb5a004c6f0, end_of_records=false) at sql_select.cc:11704
#14 0x00000000007149b1 in do_select (join=0x7fb5a004ab70, fields=0x371b5b0, table=0x0, procedure=0x0) at sql_select.cc:11457
#15 0x00000000006fc39e in JOIN::exec (this=0x7fb5a004ab70) at sql_select.cc:2341
#16 0x00000000006fcbab in mysql_select (thd=0x3719388, rref_pointer_array=0x371b678, tables=0x7fb5a002ca18, wild_num=0, fields=..., conds=0x7fb5a002d408,
    og_num=0, order=0x0, group=0x0, having=0x0, proc_param=0x0, select_options=2147764736, result=0x7fb5a002d9c0, unit=0x371b080, select_lex=0x371b4a8)
    at sql_select.cc:2556
#17 0x00000000006f502f in handle_select (thd=0x3719388, lex=0x371afe0, result=0x7fb5a002d9c0, setup_tables_done_option=0) at sql_select.cc:280
#18 0x0000000000691df9 in execute_sqlcom_select (thd=0x3719388, all_tables=0x7fb5a002ca18) at sql_parse.cc:5174
#19 0x0000000000688c32 in mysql_execute_command (thd=0x3719388) at sql_parse.cc:2332
#20 0x00000000006946e1 in mysql_parse (thd=0x3719388,
    rawbuf=0x7fb5a002c4c0 "SELECT `col_char_255_ucs2_key` FROM `test`.`table1000_maria_key_pk_parts_2_int_autoinc` FORCE INDEX (col_char_255_ucs2_key) WHERE `col_char_255_ucs2_key` = '' OR `col_char_255_ucs2_key` != '' OR `col_"..., length=265, found_semicolon=0x7fb5abffec70) at sql_parse.cc:6156
#21 0x00000000006864e4 in dispatch_command (command=COM_QUERY, thd=0x3719388, packet=0x391b369 "", packet_length=265) at sql_parse.cc:1273
#22 0x0000000000685504 in do_command (thd=0x3719388) at sql_parse.cc:899

usually the crash is observed with maria page cache size of 128K, but the RQG command below does uses the default cache size:

 /home/buildbot/randgen/runall.pl \
 --queries=1M \
 --engine=Maria \
 --mysqld=--default-storage-engine=Maria \
 --mysqld=--safe-mode \
 --mysqld=--loose-debug-assert-if-crashed-table \
 --mysqld=--sync-sys=0 \
 --mysqld=--log-output=file \
 --mysqld=--maria_log_purge_type=at_flush \
 --reporters=ErrorLog,Backtrace,Recovery,Shutdown \
 --duration=480 \
 --threads=1 \
 --rows=1000 \
 --mask-level=1 \
 --mysqld=--maria-repair-threads=2 \
 --mysqld=--loose-maria-group-commit=hard \
 --mysqld=--loose-maria_group_commit_interval=0 \
 --mysqld=--maria-checkpoint-interval=32K \
 --mysqld=--maria-block-size=2K \
 --mysqld=--maria-pagecache-division-limit=75 \
 --queries=100000000 \
 --mask=11191 \
 --seed=1297380387 \
 --basedir=. \
 --grammar=conf/engines/many_indexes.yy \
 --gendata=conf/engines/many_indexes.zz

Related branches

lp:~maria-captains/maria/5.1-merge (Merged)
Philip Stoev (pstoev-askmonty)
Changed in maria:
milestone: none → 5.1
assignee: nobody → Michael Widenius (monty)
importance: Undecided → Critical
Michael Widenius (monty)
Changed in maria:
status: New → In Progress
Revision history for this message
Michael Widenius (monty) wrote :

Fix pushed into 5.1-merge. Will push it into 5.1 when the merge tree is completely green

Michael Widenius (monty)
Changed in maria:
status: In Progress → Fix Committed
Michael Widenius (monty)
Changed in maria:
status: Fix Committed → Fix Released
To post a comment you must log in.
This report contains Public information  
Everyone can see this information.
Subscribing...

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.