InnoDB: Failing assertion: prefix_len >= sec_len in file row0sel.c line 115 | InnoDB: Failing assertion: dict_table_get_format(table) >= 1 in file row0sel.c line 113 | Abort in row_sel_sec_rec_is_for_blob

[Roel Van de Paar]

130127 0:20:37 InnoDB: Assertion failure in thread 139668893398784 in file row0sel.c line 115
InnoDB: Failing assertion: prefix_len >= sec_len

Thread 1 (LWP 28868):
+bt
#0 0x0000003da180c60c in pthread_kill () from /lib64/libpthread.so.0
#1 0x00000000007dea38 in my_write_core (sig=6) at /ssd/QA-16274-5.5/Percona-Server-5.5.28-rel29.3/mysys/stacktrace.c:433
#2 0x00000000006b3104 in handle_fatal_signal (sig=6) at /ssd/QA-16274-5.5/Percona-Server-5.5.28-rel29.3/sql/signal_handler.cc:249
#3 <signal handler called>
#4 0x0000003da1435935 in raise () from /lib64/libc.so.6
#5 0x0000003da14370e8 in abort () from /lib64/libc.so.6
#6 0x0000000000854105 in row_sel_sec_rec_is_for_blob (table=<optimized out>, prefix_len=255, sec_len=4294967295, sec_field=0x7f073cc502c9 "\200", clust_len=20, clust_field=0x7f073fe4666d "", mbminmaxlen=6, prtype=524540, mtype=5) at /ssd/QA-16274-5.5/Percona-Server-5.5.28-rel29.3/storage/innobase/row/row0sel.c:115
#7 row_sel_sec_rec_is_for_clust_rec (sec_rec=sec_rec@entry=0x7f073cc502c9 "\200", sec_index=sec_index@entry=0x7f071fee0788, clust_rec=clust_rec@entry=0x7f073fe46651 "\200", clust_index=clust_index@entry=0x7f071cadec98) at /ssd/QA-16274-5.5/Percona-Server-5.5.28-rel29.3/storage/innobase/row/row0sel.c:230
#8 0x000000000085bc7e in row_sel_get_clust_rec_for_mysql (mtr=0x7f0732c6c9c0, offset_heap=0x7f0732c6c9b8, offsets=0x7f0732c6c688, out_rec=<synthetic pointer>, thr=0x7f06ac078310, rec=0x7f073cc502c9 "\200", sec_index=0x7f071fee0788, prebuilt=0x7f06ac075f08) at /ssd/QA-16274-5.5/Percona-Server-5.5.28-rel29.3/storage/innobase/row/row0sel.c:3044
#9 row_search_for_mysql (buf=0x7f06ac0626c0 "\357\377\377\377\375\377\377\377", mode=2, prebuilt=0x7f06ac075f08, match_mode=1, direction=0) at /ssd/QA-16274-5.5/Percona-Server-5.5.28-rel29.3/storage/innobase/row/row0sel.c:4496
#10 0x00000000008170ea in ha_innobase::index_read (this=0x7f06ac060a60, buf=0x7f06ac0626c0 "\357\377\377\377\375\377\377\377", key_ptr=<optimized out>, key_len=258, find_flag=<optimized out>) at /ssd/QA-16274-5.5/Percona-Server-5.5.28-rel29.3/storage/innobase/handler/ha_innodb.cc:6834
#11 0x00000000006bc857 in handler::index_read_map (this=0x7f06ac060a60, buf=0x7f06ac0626c0 "\357\377\377\377\375\377\377\377", key=0x7f06c8006388 "\001", keypart_map=<optimized out>, find_flag=HA_READ_KEY_EXACT) at /ssd/QA-16274-5.5/Percona-Server-5.5.28-rel29.3/sql/handler.h:1649
#12 0x00000000005d1896 in join_read_always_key (tab=0x7f06c8006130) at /ssd/QA-16274-5.5/Percona-Server-5.5.28-rel29.3/sql/sql_select.cc:12446
#13 0x00000000005c616f in sub_select (join=join@entry=0x7f06c81f2780, join_tab=join_tab@entry=0x7f06c8006130, end_of_records=end_of_records@entry=false) at /ssd/QA-16274-5.5/Percona-Server-5.5.28-rel29.3/sql/sql_select.cc:11794
#14 0x00000000005d01bc in do_select (join=join@entry=0x7f06c81f2780, fields=fields@entry=0x2c49ea0, table=table@entry=0x0, procedure=0x0) at /ssd/QA-16274-5.5/Percona-Server-5.5.28-rel29.3/sql/sql_select.cc:11560
#15 0x00000000005e22bc in JOIN::exec (this=0x7f06c81f2780) at /ssd/QA-16274-5.5/Percona-Server-5.5.28-rel29.3/sql/sql_select.cc:2403
#16 0x00000000005dca3d in mysql_select (thd=thd@entry=0x2c47ac0, rref_pointer_array=rref_pointer_array@entry=0x2c49f68, tables=0x7f06c80051a0, wild_num=0, fields=..., conds=<optimized out>, og_num=0, order=0x0, group=0x0, having=0x0, proc_param=0x0, select_options=select_options@entry=2147748608, result=result@entry=0x7f06c8005920, unit=unit@entry=0x2c49770, select_lex=select_lex@entry=0x2c49d90) at /ssd/QA-16274-5.5/Percona-Server-5.5.28-rel29.3/sql/sql_select.cc:2612
#17 0x00000000005e2946 in handle_select (thd=0x2c47ac0, lex=0x2c496b0, result=0x7f06c8005920, setup_tables_done_option=<optimized out>) at /ssd/QA-16274-5.5/Percona-Server-5.5.28-rel29.3/sql/sql_select.cc:313
#18 0x0000000000594724 in execute_sqlcom_select (thd=thd@entry=0x2c47ac0, all_tables=0x7f06c80051a0) at /ssd/QA-16274-5.5/Percona-Server-5.5.28-rel29.3/sql/sql_parse.cc:4774
#19 0x000000000059ab08 in mysql_execute_command (thd=thd@entry=0x2c47ac0) at /ssd/QA-16274-5.5/Percona-Server-5.5.28-rel29.3/sql/sql_parse.cc:2284
#20 0x00000000005a1f2d in mysql_parse (thd=thd@entry=0x2c47ac0, rawbuf=<optimized out>, length=78, parser_state=parser_state@entry=0x7f0732c6e760) at /ssd/QA-16274-5.5/Percona-Server-5.5.28-rel29.3/sql/sql_parse.cc:5844
#21 0x00000000005a2a08 in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x2c47ac0, packet=packet@entry=0x2c4b201 "", packet_length=packet_length@entry=80) at /ssd/QA-16274-5.5/Percona-Server-5.5.28-rel29.3/sql/sql_parse.cc:1061
#22 0x00000000005a3fc3 in do_command (thd=0x2c47ac0) at /ssd/QA-16274-5.5/Percona-Server-5.5.28-rel29.3/sql/sql_parse.cc:788
#23 0x000000000064e14c in do_handle_one_connection (thd_arg=thd_arg@entry=0x2c47ac0) at /ssd/QA-16274-5.5/Percona-Server-5.5.28-rel29.3/sql/sql_connect.cc:1497
#24 0x000000000064e242 in handle_one_connection (arg=0x2c47ac0) at /ssd/QA-16274-5.5/Percona-Server-5.5.28-rel29.3/sql/sql_connect.cc:1404
#25 0x0000003da1807d14 in start_thread () from /lib64/libpthread.so.0
#26 0x0000003da14f168d in clone () from /lib64/libc.so.6

[Roel Van de Paar (roel11)]

Not a QA blocker.

[Laurynas Biveinis (laurynas-biveinis)]

The stacktrace does not show anything XtraDB specific, please see if you can reproduce it with Percona Server 5.1, and MySQL 5.1, 5.5? For now it seems to be some upstream bug.

[Roel Van de Paar (roel11)]

Run details

[Roel@qaserver 832905]$ cat cmd475
ps -ef | grep 'cmdrun_475' | grep -v grep | awk '{print $2}' | xargs sudo kill -9
rm -Rf /ssd/832905/cmdrun_475
mkdir /ssd/832905/cmdrun_475
cd /ssd/randgen
bash -c "set -o pipefail; perl runall.pl --queries=100000000 --seed=30806 --duration=180 --querytimeout=60 --short_column_names --sqltrace --reporter=Shutdown,Backtrace,QueryTimeout,ErrorLog,ErrorLogAlarm --mysqld=--log-output=none --mysqld=--sql_mode=ONLY_FULL_GROUP_BY --grammar=conf/percona_qa/percona_qa.yy --gendata
=conf/percona_qa/percona_qa.zz --basedir=/ssd/Percona-Server-5.5.28-rel29.3-416-debug.Linux.x86_64 --threads=25 --views --mysqld=--innodb_track_changed_pages=1--mysqld=--innodb_max_bitmap_file_size=4096 --mysqld=--innodb_log_file_size=1048576 --mysqld=--innodb_log_files_in_group=2 --mysqld=--innodb_log_buffer_size=104
8576 --mysqld=--innodb_log_block_size=512 --mysqld=--innodb_fast_shutdown=2 --mysqld=--innodb_adaptive_flushing_method=native --mysqld=--innodb_use_global_flush_log_at_trx_commit=0 --mysqld=--userstat --mysqld=--innodb_flush_method=O_DSYNC --mysqld=--innodb_file_per_table=1 --mysqld=--innodb_file_format=barracuda --mtr-build-thread=701 --mask=49083 --vardir1=/ssd/832905/cmdrun_475 > /ssd/832905/cmdrun475.log 2>&1"

[Roel Van de Paar (roel11)]

This also asserts in another way :

130202 6:28:12 InnoDB: Assertion failure in thread 140673066948352 in file row0sel.c line 113
InnoDB: Failing assertion: dict_table_get_format(table) >= 1

[Roel Van de Paar (roel11)]

[Roel@qaserver 861716]$ cat cmd173
ps -ef | grep 'cmdrun_173' | grep -v grep | awk '{print $2}' | xargs sudo kill -9
rm -Rf /ssd/861716/cmdrun_173
mkdir /ssd/861716/cmdrun_173
cd /ssd/randgen
bash -c "set -o pipefail; perl runall.pl --queries=100000000 --seed=17510 --duration=200 --querytimeout=60 --short_column_names --reporter=Shutdown,Backtrace,QueryTimeout,ErrorLog,ErrorLogAlarm --mysqld=--log-output=none --mysqld=--sql_mode=ONLY_FULL_GROUP_BY --grammar=conf/percona_qa/percona_qa.yy --gendata=conf/percona_qa/percona_qa.zz --basedir=/ssd/Percona-Server-5.5.28-rel29.3-422-debug.Linux.x86_64 --threads=25 --views --notnull --mysqld=--innodb_track_changed_pages=0 --mysqld=--innodb_changed_pages=FORCE --mysqld=--innodb_max_changed_pages=0 --mysqld=--innodb_flush_method=O_DSYNC --mysqld=--innodb_file_per_table=1 --mtr-build-thread=732 --mask=23063 --vardir1=/ssd/861716/cmdrun_173 > /ssd/861716/cmdrun173.log 2>&1"

[Roel Van de Paar (roel11)]

Laurynas, mind having a look if these added stacks reveal anything more?

[Laurynas Biveinis (laurynas-biveinis)]

Roel, the updated stacks keep on suggesting that this must be an upstream bug.

[Roel Van de Paar (roel11)]

Seen in a customer's fork of MS 5.5 as well, so 'confirmed' upstream.

[Roel Van de Paar (roel11)]

Ramesh, can you re-test please and log bug upstream if you can reproduce at least once?

[Shahriyar Rzayev (rzayev-sehriyar)]

Percona now uses JIRA for bug reports so this bug report is migrated to: https://jira.percona.com/browse/PS-2885