Percona Server moved to https://jira.percona.com/projects/PS

InnoDB: Failing assertion: dict_table_get_format(table) >= UNIV_FORMAT_B in file row0sel.cc line 115 | abort in row_sel_sec_rec_is_for_blob

Bug #1168660 reported by Roel Van de Paar
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
Percona Server moved to https://jira.percona.com/projects/PS
Status tracked in 5.7
5.1
Won't Fix
Undecided
Unassigned
5.5
New
Undecided
Unassigned
5.6
New
High
Unassigned
5.7
New
High
Unassigned

Bug Description

2013-04-11 21:00:41 2107 [ERROR] /data/opt/roel/Percona-Server-5.6.8-alpha60.2-314-debug.Linux.x86_64/bin/mysqld-debug: Sort aborted: Deadlock found when trying to get lock; try restarting transaction
2013-04-11 21:00:42 7fcd04045700 InnoDB: Assertion failure in thread 140518512416512 in file row0sel.cc line 115
InnoDB: Failing assertion: dict_table_get_format(table) >= UNIV_FORMAT_B

Thread 1 (Thread 0x7fcd04045700 (LWP 2176)):
+bt
#0 0x00007fcd205a269c in pthread_kill () from /lib64/libpthread.so.0
#1 0x0000000000673dce in handle_fatal_signal (sig=6) at /ssd/ps56-univ-log-archive-qa_HACK/Percona-Server-5.6.8-alpha60.2/sql/signal_handler.cc:249
#2 <signal handler called>
#3 0x00007fcd1f2518a5 in raise () from /lib64/libc.so.6
#4 0x00007fcd1f253085 in abort () from /lib64/libc.so.6
#5 0x0000000000a8272d in row_sel_sec_rec_is_for_blob (sec_rec=0x7fcd11c9c591 "\377\377\377\377\066-02-11 07:19:29.017433\200", sec_index=0x7fcce41f94a8, clust_rec=0x7fcd11c520ab "\377\377\377\377", clust_index=0x7fcce41ed0d8) at /ssd/ps56-univ-log-archive-qa_HACK/Percona-Server-5.6.8-alpha60.2/storage/innobase/row/row0sel.cc:115
#6 row_sel_sec_rec_is_for_clust_rec (sec_rec=0x7fcd11c9c591 "\377\377\377\377\066-02-11 07:19:29.017433\200", sec_index=0x7fcce41f94a8, clust_rec=0x7fcd11c520ab "\377\377\377\377", clust_index=0x7fcce41ed0d8) at /ssd/ps56-univ-log-archive-qa_HACK/Percona-Server-5.6.8-alpha60.2/storage/innobase/row/row0sel.cc:232
#7 0x0000000000a85746 in row_sel_get_clust_rec_for_mysql (buf=0x7fcca40fce20 "\357\276\347\377", mode=2, prebuilt=0x7fcca40f15c8, match_mode=1, direction=<value optimized out>) at /ssd/ps56-univ-log-archive-qa_HACK/Percona-Server-5.6.8-alpha60.2/storage/innobase/row/row0sel.cc:3162
#8 row_search_for_mysql (buf=0x7fcca40fce20 "\357\276\347\377", mode=2, prebuilt=0x7fcca40f15c8, match_mode=1, direction=<value optimized out>) at /ssd/ps56-univ-log-archive-qa_HACK/Percona-Server-5.6.8-alpha60.2/storage/innobase/row/row0sel.cc:4689
#9 0x000000000099ea71 in ha_innobase::index_read (this=0x7fcca41b3f10, buf=0x7fcca40fce20 "\357\276\347\377", key_ptr=<value optimized out>, key_len=<value optimized out>, find_flag=<value optimized out>) at /ssd/ps56-univ-log-archive-qa_HACK/Percona-Server-5.6.8-alpha60.2/storage/innobase/handler/ha_innodb.cc:7437
#10 0x00000000005ab754 in handler::ha_index_read_map (this=0x7fcca41b3f10, buf=0x7fcca40fce20 "\357\276\347\377", key=0x7fcc6c08f360 "\001", keypart_map=1, find_flag=HA_READ_KEY_EXACT) at /ssd/ps56-univ-log-archive-qa_HACK/Percona-Server-5.6.8-alpha60.2/sql/handler.cc:2668
#11 0x00000000005acc37 in handler::read_range_first (this=0x7fcca41b3f10, start_key=0x7fcca41b3ff0, end_key=0x7fcca41b4010, eq_range_arg=<value optimized out>, sorted=<value optimized out>) at /ssd/ps56-univ-log-archive-qa_HACK/Percona-Server-5.6.8-alpha60.2/sql/handler.cc:6578
#12 0x00000000005aae95 in handler::multi_range_read_next (this=0x7fcca41b3f10, range_info=0x7fcd04042a88) at /ssd/ps56-univ-log-archive-qa_HACK/Percona-Server-5.6.8-alpha60.2/sql/handler.cc:5749
#13 0x00000000005ad8a8 in DsMrr_impl::dsmrr_next (this=0x7fcca41b59d8, range_info=0x7fcd04042a88) at /ssd/ps56-univ-log-archive-qa_HACK/Percona-Server-5.6.8-alpha60.2/sql/handler.cc:6108
#14 0x000000000082d98d in QUICK_RANGE_SELECT::get_next (this=0x7fcc6c09b720) at /ssd/ps56-univ-log-archive-qa_HACK/Percona-Server-5.6.8-alpha60.2/sql/opt_range.cc:10409
#15 0x0000000000803064 in find_all_keys (param=0x7fcd04042f10, select=0x7fcc6c08f648, fs_info=0x7fcd04042f90, buffpek_pointers=0x7fcd04042cd0, tempfile=0x7fcd04042df0, pq=0x0, found_rows=0x7fcd04043230) at /ssd/ps56-univ-log-archive-qa_HACK/Percona-Server-5.6.8-alpha60.2/sql/filesort.cc:756
#16 0x0000000000804567 in filesort (thd=0x2f74250, table=<value optimized out>, filesort=<value optimized out>, sort_positions=208, examined_rows=0x7fcd04043238, found_rows=0x7fcd04043230) at /ssd/ps56-univ-log-archive-qa_HACK/Percona-Server-5.6.8-alpha60.2/sql/filesort.cc:337
#17 0x00000000006dcf1e in create_sort_index (this=0x7fcc6c08ed60) at /ssd/ps56-univ-log-archive-qa_HACK/Percona-Server-5.6.8-alpha60.2/sql/sql_executor.cc:3306
#18 st_join_table::sort_table (this=0x7fcc6c08ed60) at /ssd/ps56-univ-log-archive-qa_HACK/Percona-Server-5.6.8-alpha60.2/sql/sql_executor.cc:2471
#19 0x00000000006dd1ee in join_init_read_record (tab=0x7fcc6c08ed60) at /ssd/ps56-univ-log-archive-qa_HACK/Percona-Server-5.6.8-alpha60.2/sql/sql_executor.cc:2382
#20 0x00000000006dc7bd in sub_select (join=0x7fcc6c1da4b0, join_tab=0x7fcc6c08ed60, end_of_records=<value optimized out>) at /ssd/ps56-univ-log-archive-qa_HACK/Percona-Server-5.6.8-alpha60.2/sql/sql_executor.cc:1256
#21 0x00000000006db2a6 in do_select (this=0x7fcc6c1da4b0) at /ssd/ps56-univ-log-archive-qa_HACK/Percona-Server-5.6.8-alpha60.2/sql/sql_executor.cc:941
#22 JOIN::exec (this=0x7fcc6c1da4b0) at /ssd/ps56-univ-log-archive-qa_HACK/Percona-Server-5.6.8-alpha60.2/sql/sql_executor.cc:191
#23 0x0000000000724058 in mysql_execute_select (thd=0x2f74250, tables=0x7fcc6c0052c0, wild_num=0, fields=..., conds=0x7fcc6c005950, order=<value optimized out>, group=0x2f76b88, having=0x0, select_options=2147748608, result=0x7fcc6c1da488, unit=0x2f76448, select_lex=0x2f76a88) at /ssd/ps56-univ-log-archive-qa_HACK/Percona-Server-5.6.8-alpha60.2/sql/sql_select.cc:1100
#24 mysql_select (thd=0x2f74250, tables=0x7fcc6c0052c0, wild_num=0, fields=..., conds=0x7fcc6c005950, order=<value optimized out>, group=0x2f76b88, having=0x0, select_options=2147748608, result=0x7fcc6c1da488, unit=0x2f76448, select_lex=0x2f76a88) at /ssd/ps56-univ-log-archive-qa_HACK/Percona-Server-5.6.8-alpha60.2/sql/sql_select.cc:1221
#25 0x0000000000724a23 in handle_select (thd=0x2f74250, result=0x7fcc6c1da488, setup_tables_done_option=0) at /ssd/ps56-univ-log-archive-qa_HACK/Percona-Server-5.6.8-alpha60.2/sql/sql_select.cc:110
#26 0x00000000006f9cfd in execute_sqlcom_select (thd=0x2f74250, all_tables=<value optimized out>) at /ssd/ps56-univ-log-archive-qa_HACK/Percona-Server-5.6.8-alpha60.2/sql/sql_parse.cc:5065
#27 0x00000000006ff3ef in mysql_execute_command (thd=0x2f74250) at /ssd/ps56-univ-log-archive-qa_HACK/Percona-Server-5.6.8-alpha60.2/sql/sql_parse.cc:2592
#28 0x0000000000705408 in mysql_parse (thd=0x2f74250, rawbuf=<value optimized out>, length=<value optimized out>, parser_state=<value optimized out>) at /ssd/ps56-univ-log-archive-qa_HACK/Percona-Server-5.6.8-alpha60.2/sql/sql_parse.cc:6195
#29 0x0000000000707174 in dispatch_command (command=COM_QUERY, thd=0x2f74250, packet=0x7fcd04044ab0 "PB\367\002", packet_length=1811958864) at /ssd/ps56-univ-log-archive-qa_HACK/Percona-Server-5.6.8-alpha60.2/sql/sql_parse.cc:1335
#30 0x0000000000707819 in do_command (thd=0x2f74250) at /ssd/ps56-univ-log-archive-qa_HACK/Percona-Server-5.6.8-alpha60.2/sql/sql_parse.cc:1037
#31 0x00000000006cd7bf in do_handle_one_connection (thd_arg=<value optimized out>) at /ssd/ps56-univ-log-archive-qa_HACK/Percona-Server-5.6.8-alpha60.2/sql/sql_connect.cc:970
#32 0x00000000006cd8e7 in handle_one_connection (arg=0x2f74250) at /ssd/ps56-univ-log-archive-qa_HACK/Percona-Server-5.6.8-alpha60.2/sql/sql_connect.cc:886
#33 0x000000000097ca19 in pfs_spawn_thread (arg=0x2ecf8e0) at /ssd/ps56-univ-log-archive-qa_HACK/Percona-Server-5.6.8-alpha60.2/storage/perfschema/pfs.cc:1853
#34 0x00007fcd2059d851 in start_thread () from /lib64/libpthread.so.0
#35 0x00007fcd1f30711d in clone () from /lib64/libc.so.6

Revision history for this message
Roel Van de Paar (roel11) wrote :
Revision history for this message
Roel Van de Paar (roel11) wrote :
Revision history for this message
Roel Van de Paar (roel11) wrote :
Revision history for this message
Roel Van de Paar (roel11) wrote :

======================== Run details
[roel@hppro1 531287]$ cat cmd605
ps -ef | grep 'cmdrun_605' | grep -v grep | awk '{print $2}' | xargs sudo kill -9
rm -Rf /data/opt/roel/531287/cmdrun_605
mkdir /data/opt/roel/531287/cmdrun_605
cd /data/opt/roel/randgen
bash -c "set -o pipefail; perl runall.pl --queries=100000000 --seed=22399 --duration=900 --sqltrace --querytimeout=60 --short_column_names --reporter=Shutdown,B
acktrace,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.6.8-alpha60.2-314-debug.Linux.x86_64 --threads=25 --views --notnull --mysqld=--innodb_log_archive=1 --mysqld=--innodb_log_arch_expire_sec=1 --mysqld=--innodb_log_file_size=10485761 --mysqld=--innodb_log_files_in_group=3 --mysqld=--innodb_log_buffer_size=1048577 --mysqld=--innodb_fast_shutdown=0 --mysqld=--skip-innodb_doublewrite --mysqld=--innodb_file_per_table=1 --mysqld=--innodb_flush_log_at_trx_commit=2 --mysqld=--innodb_flush_log_at_timeout=1 --mtr-build-thread=766 --mask=50689 --vardir1=/data/opt/roel/531287/cmdrun_605 > /data/opt/roel/531287/cmdrun605.log 2>&1"

Revision history for this message
Laurynas Biveinis (laurynas-biveinis) wrote :

My first guess that this is not log archiving-related, nor that this is Percona-related neither.

Roel, would it be possible to test with Oracle MySQL?

Revision history for this message
Roel Van de Paar (roel11) wrote :

Tested w/ mysql-5.6.10-linux-glibc2.5-x86_64 w/o AL options. Did not assert.

Revision history for this message
Roel Van de Paar (roel11) wrote :

Tested s/--mysqld=--innodb_log_archive=1 --mysqld=--innodb_log_arch_expire_sec=1/--mysqld=--innodb_log_archive=0/. Did still assert. So, looks to be PS+InnoDB related, but not AL.

tags: added: innodb
removed: archivelogs
Revision history for this message
Roel Van de Paar (roel11) wrote :

If this is a debug assert, it may still be present in mysql 5.6 (which was compiled optimized)

Revision history for this message
Alexey Kopytov (akopytov) wrote :

Yes, it is a debug assertion.

Roel Van de Paar (roel11)
tags: added: 56qual
Laurynas Biveinis (laurynas-biveinis)
tags: removed: 56qual
Revision history for this message
Roel Van de Paar (roel11) wrote :

Likely upstream, and marking as such ftm.

tags: added: upstream
Revision history for this message
Shahriyar Rzayev (rzayev-sehriyar) wrote :

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

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.