Failing assertion: level <= 50 in file btr0btr.ic line 143 | abort (sig=6) in btr_page_set_level from btr_page_empty

Bug #1369520 reported by Roel Van de Paar on 2014-09-15
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
MySQL Server
Unknown
Unknown
Percona Server moved to https://jira.percona.com/projects/PS
Fix Released
Low
Unassigned
5.1
Invalid
Undecided
Unassigned
5.5
Fix Released
Low
Unassigned
5.6
Fix Released
Low
Unassigned

Bug Description

2014-09-16 07:04:52 7fb1c11d3700 InnoDB: Assertion failure in thread 140401425856256 in file btr0btr.ic line 143
InnoDB: Failing assertion: level <= 50
[...]
Query (7fb0c741f010): SELECT * FROM t2

There was only 1 thread of SQL running, but at the time of the crash I had a secondary connection (via mysql CLI) and had executed "show processlist;" - so issue may have been triggered by one thread executing 'SELECT * FROM t2' and the other 'show processlist'.

Also, the level <=50 issue seems clear as to what it means - the stack trace is humongous. Some sort of infinte loop?

(gdb) bt
#0 0x00007fb1c0c22771 in pthread_kill () from /lib64/libpthread.so.0
#1 0x0000000000ab09a2 in my_write_core (sig=6) at /mnt/workspace/percona-server-5.6-binaries-debug-yassl/label_exp/centos6-64/percona-server-5.6.20-68.0/mysys/stacktrace.c:422
#2 0x000000000072ca03 in handle_fatal_signal (sig=6) at /mnt/workspace/percona-server-5.6-binaries-debug-yassl/label_exp/centos6-64/percona-server-5.6.20-68.0/sql/signal_handler.cc:236
#3 <signal handler called>
#4 0x00007fb1bf826989 in raise () from /lib64/libc.so.6
#5 0x00007fb1bf828098 in abort () from /lib64/libc.so.6
#6 0x0000000000c7ace1 in btr_page_set_level (page=0x7fb18f3f8000 "\274\060\206", <incomplete sequence \364>, page_zip=0x0, level=51, mtr=0x7fb1c11ce980) at /mnt/workspace/percona-server-5.6-binaries-debug-yassl/label_exp/centos6-64/percona-server-5.6.20-68.0/storage/innobase/include/btr0btr.ic:143
#7 0x0000000000c7e94a in btr_page_empty (block=0x7fb17f3ffa70, page_zip=0x0, index=0x7fb0c744fff8, level=51, mtr=0x7fb1c11ce980) at /mnt/workspace/percona-server-5.6-binaries-debug-yassl/label_exp/centos6-64/percona-server-5.6.20-68.0/storage/innobase/btr/btr0btr.cc:2134
#8 0x0000000000c7ee94 in btr_root_raise_and_insert (flags=7, cursor=0x7fb1c11bef00, offsets=0x7fb1c11bef90, heap=0x7fb1c11bef88, tuple=0x7fb0c74b6378, n_ext=0, mtr=0x7fb1c11ce980) at /mnt/workspace/percona-server-5.6-binaries-debug-yassl/label_exp/centos6-64/percona-server-5.6.20-68.0/storage/innobase/btr/btr0btr.cc:2272
#9 0x0000000000c92030 in btr_cur_pessimistic_insert (flags=7, cursor=0x7fb1c11bef00, offsets=0x7fb1c11bef90, heap=0x7fb1c11bef88, entry=0x7fb0c74b6378, rec=0x7fb1c11bef98, big_rec=0x7fb1c11befa0, n_ext=0, thr=0x0, mtr=0x7fb1c11ce980) at /mnt/workspace/percona-server-5.6-binaries-debug-yassl/label_exp/centos6-64/percona-server-5.6.20-68.0/storage/innobase/btr/btr0cur.cc:1728
#10 0x0000000000c7f953 in btr_insert_on_non_leaf_level_func (flags=7, index=0x7fb0c744fff8, level=50, tuple=0x7fb0c74b6378, file=0x1090a40 "/mnt/workspace/percona-server-5.6-binaries-debug-yassl/label_exp/centos6-64/percona-server-5.6.20-68.0/storage/innobase/btr/btr0btr.cc", line=2767, mtr=0x7fb1c11ce980) at /mnt/workspace/percona-server-5.6-binaries-debug-yassl/label_exp/centos6-64/percona-server-5.6.20-68.0/storage/innobase/btr/btr0btr.cc:2674
#11 0x0000000000c7fd14 in btr_attach_half_pages (flags=7, index=0x7fb0c744fff8, block=0x7fb15c3f3a88, split_rec=0x7fb0c75b6d1f "testt2", new_block=0x7fb15c3f37c0, direction=111, mtr=0x7fb1c11ce980) at /mnt/workspace/percona-server-5.6-binaries-debug-yassl/label_exp/centos6-64/percona-server-5.6.20-68.0/storage/innobase/btr/btr0btr.cc:2767
#12 0x0000000000c808bd in btr_page_split_and_insert (flags=7, cursor=0x7fb1c11bf400, offsets=0x7fb1c11bf490, heap=0x7fb1c11bf488, tuple=0x7fb0c74b5978, n_ext=0, mtr=0x7fb1c11ce980) at /mnt/workspace/percona-server-5.6-binaries-debug-yassl/label_exp/centos6-64/percona-server-5.6.20-68.0/storage/innobase/btr/btr0btr.cc:3007
#13 0x0000000000c7efc7 in btr_root_raise_and_insert (flags=7, cursor=0x7fb1c11bf400, offsets=0x7fb1c11bf490, heap=0x7fb1c11bf488, tuple=0x7fb0c74b5978, n_ext=0, mtr=0x7fb1c11ce980) at /mnt/workspace/percona-server-5.6-binaries-debug-yassl/label_exp/centos6-64/percona-server-5.6.20-68.0/storage/innobase/btr/btr0btr.cc:2311
#14 0x0000000000c92030 in btr_cur_pessimistic_insert (flags=7, cursor=0x7fb1c11bf400, offsets=0x7fb1c11bf490, heap=0x7fb1c11bf488, entry=0x7fb0c74b5978, rec=0x7fb1c11bf498, big_rec=0x7fb1c11bf4a0, n_ext=0, thr=0x0, mtr=0x7fb1c11ce980) at /mnt/workspace/percona-server-5.6-binaries-debug-yassl/label_exp/centos6-64/percona-server-5.6.20-68.0/storage/innobase/btr/btr0cur.cc:1728
#15 0x0000000000c7f953 in btr_insert_on_non_leaf_level_func (flags=7, index=0x7fb0c744fff8, level=49, tuple=0x7fb0c74b5978, file=0x1090a40 "/mnt/workspace/percona-server-5.6-binaries-debug-yassl/label_exp/centos6-64/percona-server-5.6.20-68.0/storage/innobase/btr/btr0btr.cc", line=2767, mtr=0x7fb1c11ce980) at /mnt/workspace/percona-server-5.6-binaries-debug-yassl/label_exp/centos6-64/percona-server-5.6.20-68.0/storage/innobase/btr/btr0btr.cc:2674
#16 0x0000000000c7fd14 in btr_attach_half_pages (flags=7, index=0x7fb0c744fff8, block=0x7fb16dbf3a88, split_rec=0x7fb0c75b6c7f "testt2", new_block=0x7fb15c3f3d50, direction=111, mtr=0x7fb1c11ce980) at /mnt/workspace/percona-server-5.6-binaries-debug-yassl/label_exp/centos6-64/percona-server-5.6.20-68.0/storage/innobase/btr/btr0btr.cc:2767
#17 0x0000000000c808bd in btr_page_split_and_insert (flags=7, cursor=0x7fb1c11bf900, offsets=0x7fb1c11bf990, heap=0x7fb1c11bf988, tuple=0x7fb0c74b4f78, n_ext=0, mtr=0x7fb1c11ce980) at /mnt/workspace/percona-server-5.6-binaries-debug-yassl/label_exp/centos6-64/percona-server-5.6.20-68.0/storage/innobase/btr/btr0btr.cc:3007
#18 0x0000000000c7efc7 in btr_root_raise_and_insert (flags=7, cursor=0x7fb1c11bf900, offsets=0x7fb1c11bf990, heap=0x7fb1c11bf988, tuple=0x7fb0c74b4f78, n_ext=0, mtr=0x7fb1c11ce980) at /mnt/workspace/percona-server-5.6-binaries-debug-yassl/label_exp/centos6-64/percona-server-5.6.20-68.0/storage/innobase/btr/btr0btr.cc:2
311
[...]
#271 0x0000000000d0d8c8 in dict_stats_save (table_orig=0x7fb0c7528778, only_for_index=0x0) at /mnt/workspace/percona-server-5.6-binaries-debug-yassl/label_exp/centos6-64/percona-server-5.6.20-68.0/storage/innobase/dict/dict0stats.cc:2424
#272 0x0000000000d0eebe in dict_stats_update (table=0x7fb0c7528778, stats_upd_option=DICT_STATS_RECALC_PERSISTENT) at /mnt/workspace/percona-server-5.6-binaries-debug-yassl/label_exp/centos6-64/percona-server-5.6.20-68.0/storage/innobase/dict/dict0stats.cc:3133
#273 0x0000000000d0f17f in dict_stats_update (table=0x7fb0c7528778, stats_upd_option=DICT_STATS_FETCH_ONLY_IF_NOT_IN_MEMORY) at /mnt/workspace/percona-server-5.6-binaries-debug-yassl/label_exp/centos6-64/percona-server-5.6.20-68.0/storage/innobase/dict/dict0stats.cc:3248
#274 0x0000000000ac6765 in dict_stats_init (table=0x7fb0c7528778) at /mnt/workspace/percona-server-5.6-binaries-debug-yassl/label_exp/centos6-64/percona-server-5.6.20-68.0/storage/innobase/include/dict0stats.ic:174
#275 0x0000000000accbd8 in ha_innobase::open (this=0x7fb0c74da010, name=0x7fb0c745db48 "./test/t2", mode=2, test_if_locked=2) at /mnt/workspace/percona-server-5.6-binaries-debug-yassl/label_exp/centos6-64/percona-server-5.6.20-68.0/storage/innobase/handler/ha_innodb.cc:5508
#276 0x000000000063f1a9 in handler::ha_open (this=0x7fb0c74da010, table_arg=0x7fb0c7425200, name=0x7fb0c745db48 "./test/t2", mode=2, test_if_locked=2) at /mnt/workspace/percona-server-5.6-binaries-debug-yassl/label_exp/centos6-64/percona-server-5.6.20-68.0/sql/handler.cc:2683
#277 0x00000000008a82a6 in open_table_from_share (thd=0x7fb101b12000, share=0x7fb0c745d810, alias=0x7fb0c741f1f8 "t2", db_stat=39, prgflag=44, ha_open_flags=0,outparam=0x7fb0c7425200, is_create_table=false) at /mnt/workspace/percona-server-5.6-binaries-debug-yassl/label_exp/centos6-64/percona-server-5.6.20-68.0/sql/table.cc:2364
#278 0x000000000076e0dd in open_table (thd=0x7fb101b12000, table_list=0x7fb0c741f200, ot_ctx=0x7fb1c11d0a50) at /mnt/workspace/percona-server-5.6-binaries-debug-yassl/label_exp/centos6-64/percona-server-5.6.20-68.0/sql/sql_base.cc:3205
#279 0x0000000000770892 in open_and_process_table (thd=0x7fb101b12000, lex=0x7fb101b14540, tables=0x7fb0c741f200, counter=0x7fb101b14600, flags=0, prelocking_strategy=0x7fb1c11d0b50, has_prelocking_list=false, ot_ctx=0x7fb1c11d0a50) at /mnt/workspace/percona-server-5.6-binaries-debug-yassl/label_exp/centos6-64/percona-server-5.6.20-68.0/sql/sql_base.cc:4699
#280 0x0000000000771797 in open_tables (thd=0x7fb101b12000, start=0x7fb1c11d0b10, counter=0x7fb101b14600, flags=0, prelocking_strategy=0x7fb1c11d0b50) at /mnt/workspace/percona-server-5.6-binaries-debug-yassl/label_exp/centos6-64/percona-server-5.6.20-68.0/sql/sql_base.cc:5213
#281 0x0000000000772926 in open_normal_and_derived_tables (thd=0x7fb101b12000, tables=0x7fb0c741f200, flags=0) at /mnt/workspace/percona-server-5.6-binaries-debug-yassl/label_exp/centos6-64/percona-server-5.6.20-68.0/sql/sql_base.cc:5913
#282 0x00000000007e75da in execute_sqlcom_select (thd=0x7fb101b12000, all_tables=0x7fb0c741f200) at /mnt/workspace/percona-server-5.6-binaries-debug-yassl/label_exp/centos6-64/percona-server-5.6.20-68.0/sql/sql_parse.cc:5541
#283 0x00000000007dfd7a in mysql_execute_command (thd=0x7fb101b12000) at /mnt/workspace/percona-server-5.6-binaries-debug-yassl/label_exp/centos6-64/percona-server-5.6.20-68.0/sql/sql_parse.cc:2953
#284 0x00000000007ea051 in mysql_parse (thd=0x7fb101b12000, rawbuf=0x7fb0c741f010 "SELECT * FROM t2", length=16, parser_state=0x7fb1c11d1df0) at /mnt/workspace/percona-server-5.6-binaries-debug-yassl/label_exp/centos6-64/percona-server-5.6.20-68.0/sql/sql_parse.cc:6744
#285 0x00000000007dc5ec in dispatch_command (command=COM_QUERY, thd=0x7fb101b12000, packet=0x7fb101b16001 "SELECT * FROM t2;", packet_length=17) at /mnt/workspace/percona-server-5.6-binaries-debug-yassl/label_exp/centos6-64/percona-server-5.6.20-68.0/sql/sql_parse.cc:1432
#286 0x00000000007db518 in do_command (thd=0x7fb101b12000) at /mnt/workspace/percona-server-5.6-binaries-debug-yassl/label_exp/centos6-64/percona-server-5.6.20-68.0/sql/sql_parse.cc:1049
#287 0x00000000007a34d5 in do_handle_one_connection (thd_arg=0x7fb111fc0000) at /mnt/workspace/percona-server-5.6-binaries-debug-yassl/label_exp/centos6-64/percona-server-5.6.20-68.0/sql/sql_connect.cc:1532
#288 0x00000000007a2fdd in handle_one_connection (arg=0x7fb111fc0000) at /mnt/workspace/percona-server-5.6-binaries-debug-yassl/label_exp/centos6-64/percona-server-5.6.20-68.0/sql/sql_connect.cc:1443
#289 0x0000000000dbdbb8 in pfs_spawn_thread (arg=0x7fb1a4bccb00) at /mnt/workspace/percona-server-5.6-binaries-debug-yassl/label_exp/centos6-64/percona-server-5.6.20-68.0/storage/perfschema/pfs.cc:1860
#290 0x00007fb1c0c1ddf3 in start_thread () from /lib64/libpthread.so.0
#291 0x00007fb1bf8e73dd in clone () from /lib64/libc.so.6

Roel Van de Paar (roel11) wrote :

Creating a testcase was not successful, likely due to (seemingly) two thread being needed to reproduce the issue.

Roel Van de Paar (roel11) wrote :

show processlist was not executing at time of crash according to core dump (query not present). Yet, it may have triggered it.

Roel Van de Paar (roel11) wrote :

This "very long stack trace" bug is also asserting itself in another way:

2014-09-19 01:05:33 7f8c80be0700 InnoDB: Assertion failure in thread 140241432086272 in file btr0btr.ic line 125
InnoDB: Failing assertion: level <= 50

i.e. btr0btr.ic line 143 instead of line 125.

Uploading details.

Roel Van de Paar (roel11) wrote :
Roel Van de Paar (roel11) wrote :

This bug was also seen in a single-threaded single-mysqld run.

Roel Van de Paar (roel11) wrote :

DROP DATABASE test;CREATE DATABASE test;USE test;
set global innodb_limit_optimistic_insert_debug=1;
CREATE TABLE t1(c1 CHAR (1),c2 VARCHAR(1),c3 INT);

Roel Van de Paar (roel11) wrote :

Upstream

tags: added: upstream

Not a bug (hard to maintain a B-tree if each node is limited to a single entry)

Or might be a bug in the allowed value range for innodb_limit_optimistic_insert_debug if we are splitting hairs, but that's upstream concern, definitely nothing to fix for us.

Changed in percona-server:
importance: High → Low
Ramesh Sivaraman (rameshvs02) wrote :

** Testcase (for crash - btr0btr.ic line 125)

DROP DATABASE test;CREATE DATABASE test;USE test;
set global innodb_file_format=Barracuda;
create TABLE t1(a int key)engine=innodb row_format=compressed;
set global innodb_limit_optimistic_insert_debug=1;
INSERT INTO t1 VALUES(0xC8),(0xC9),(0xCA),(0xCB),(0xCC),(0xCD),(0xCE),(0xCF);

Ramesh Sivaraman (rameshvs02) wrote :

Please note the last testcase (comment #12) crashes in a different location as the original one.

Roel Van de Paar (roel11) wrote :

One more testcase which is solved on 5.6.22 but still crashes Percona (pre-5.6.22 merge) for the time being. Good verify testcase.

DROP DATABASE test;CREATE DATABASE test;USE test;
set global innodb_limit_optimistic_insert_debug=1;
CREATE TABLE t1(c1 INT,c2 CHAR,c3 INT,c4 CHAR KEY,c5 INT UNIQUE KEY,c6 DECIMAL(0,0)DEFAULT 3.141592);

Changed in percona-server:
status: Invalid → Fix Released

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

To post a comment you must log in.
This report contains Public information  Edit
Everyone can see this information.

Other bug subscribers

Remote bug watches

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