Percona Server with XtraDB

Failing assertion: i->in_files.count > 0 in file log0online.cc line 1511 | abort in log_online_bitmap_iterator_init

Reported by Roel Van de Paar on 2013-05-26
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
Percona Server
Status tracked in 5.6
5.1
High
Laurynas Biveinis
5.5
High
Laurynas Biveinis
5.6
Critical
Laurynas Biveinis

Bug Description

2013-05-24 18:37:58 18c7f700 InnoDB: Assertion failure in thread 415758080 in file log0online.cc line 1511
InnoDB: Failing assertion: i->in_files.count > 0

Query (20fc4ef0): SELECT COUNT(*) FROM INFORMATION_SCHEMA.INNODB_CHANGED_PAGES

Thread 2 (LWP 10130):
+bt
#0 0x0000003fde20c69c in pthread_kill () from /lib64/libpthread.so.0
#1 0x00000000006e47ad in handle_fatal_signal (sig=6) at /ssd/5.6-merge-3_val/Percona-Server-5.6.10-alpha60.2/sql/signal_handler.cc:251
#2 <signal handler called>
#3 0x0000003fdde328a5 in raise () from /lib64/libc.so.6
#4 0x0000003fdde34085 in abort () from /lib64/libc.so.6
#5 0x00000000009e7703 in log_online_bitmap_iterator_init (i=0x18c7ce80, min_lsn=<optimized out>, max_lsn=<optimized out>) at /ssd/5.6-merge-3_val/Percona-Server-5.6.10-alpha60.2/storage/innobase/log/log0online.cc:1511
#6 0x00000000009b37f8 in i_s_innodb_changed_pages_fill (thd=0x11da0530, tables=<optimized out>, cond=0x0) at /ssd/5.6-merge-3_val/Percona-Server-5.6.10-alpha60.2/storage/innobase/handler/i_s.cc:8206
#7 0x0000000000797c0d in do_fill_table (thd=0x11da0530, table_list=0x20fc5260, join_table=0x20fc6ab8) at /ssd/5.6-merge-3_val/Percona-Server-5.6.10-alpha60.2/sql/sql_show.cc:7682
#8 0x0000000000797ef6 in get_schema_tables_result (join=0x20fc5e00, executed_place=PROCESSED_BY_JOIN_EXEC) at /ssd/5.6-merge-3_val/Percona-Server-5.6.10-alpha60.2/sql/sql_show.cc:7783
#9 0x000000000078fdf5 in JOIN::prepare_result (this=0x20fc5e00, columns_list=<optimized out>) at /ssd/5.6-merge-3_val/Percona-Server-5.6.10-alpha60.2/sql/sql_select.cc:823
#10 0x000000000074837a in JOIN::exec (this=0x20fc5e00) at /ssd/5.6-merge-3_val/Percona-Server-5.6.10-alpha60.2/sql/sql_executor.cc:116
#11 0x0000000000790208 in mysql_execute_select (thd=0x11da0530, select_lex=0x11da2ff0, free_join=true) at /ssd/5.6-merge-3_val/Percona-Server-5.6.10-alpha60.2/sql/sql_select.cc:1101
#12 0x0000000000790964 in mysql_select (thd=0x11da0530, tables=0x20fc5260, wild_num=0, fields=..., conds=<optimized out>, order=0x11da31b8, group=0x11da30f0, having=0x0, select_options=2684619520, result=0x20fc5dd8, unit=0x11da29a8, select_lex=0x11da2ff0) at /ssd/5.6-merge-3_val/Percona-Server-5.6.10-alpha60.2/sql/sql_select.cc:1222
#13 0x0000000000790b38 in handle_select (thd=0x11da0530, result=0x20fc5dd8, setup_tables_done_option=0) at /ssd/5.6-merge-3_val/Percona-Server-5.6.10-alpha60.2/sql/sql_select.cc:111
#14 0x0000000000765a7d in execute_sqlcom_select (thd=0x11da0530, all_tables=0x20fc5260) at /ssd/5.6-merge-3_val/Percona-Server-5.6.10-alpha60.2/sql/sql_parse.cc:5272
#15 0x0000000000767fd7 in mysql_execute_command (thd=0x11da0618) at /ssd/5.6-merge-3_val/Percona-Server-5.6.10-alpha60.2/sql/sql_parse.cc:2732
#16 0x000000000076d110 in mysql_parse (thd=0x11da0530, rawbuf=<optimized out>, length=<optimized out>, parser_state=<optimized out>) at /ssd/5.6-merge-3_val/Percona-Server-5.6.10-alpha60.2/sql/sql_parse.cc:6443
#17 0x000000000076dbaf in dispatch_command (command=<optimized out>, thd=0x11da0530, packet=<optimized out>, packet_length=553406252) at /ssd/5.6-merge-3_val/Percona-Server-5.6.10-alpha60.2/sql/sql_parse.cc:1359
#18 0x000000000076e800 in do_command (thd=0x11da0530) at /ssd/5.6-merge-3_val/Percona-Server-5.6.10-alpha60.2/sql/sql_parse.cc:1051
#19 0x000000000073910f in do_handle_one_connection (thd_arg=<optimized out>) at /ssd/5.6-merge-3_val/Percona-Server-5.6.10-alpha60.2/sql/sql_connect.cc:1617
#20 0x0000000000739220 in handle_one_connection (arg=0x18a2fa50) at /ssd/5.6-merge-3_val/Percona-Server-5.6.10-alpha60.2/sql/sql_connect.cc:1528
#21 0x0000000000c0b949 in pfs_spawn_thread (arg=0x188f04f0) at /ssd/5.6-merge-3_val/Percona-Server-5.6.10-alpha60.2/storage/perfschema/pfs.cc:1853
#22 0x0000003fde207851 in start_thread () from /lib64/libpthread.so.0
#23 0x0000003fddee890d in clone () from /lib64/libc.so.6

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

++Valgrinds seen in error log:

2013-05-24 17:15:32 10035 [Note] InnoDB: Highest supported file format is Barracuda.
==10035== Conditional jump or move depends on uninitialised value(s)
==10035== at 0x9E70F7: log_online_start_bitmap_file() (log0online.cc:526)
==10035== by 0x9E92CF: log_online_read_init() (log0online.cc:725)
==10035== by 0xA94A3C: init_log_online() (srv0start.cc:1456)
==10035== by 0xA97D81: innobase_start_or_create_for_mysql() (srv0start.cc:2327)
==10035== by 0x9A2E19: innobase_init(void*) (ha_innodb.cc:3492)
==10035== by 0x63CA4A: ha_initialize_handlerton(st_plugin_int*) (handler.cc:690)
==10035== by 0x77503F: plugin_initialize(st_plugin_int*) (sql_plugin.cc:1126)
==10035== by 0x7771A9: plugin_init(int*, char**, int) (sql_plugin.cc:1417)
==10035== by 0x624981: init_server_components() (mysqld.cc:4872)
==10035== by 0x6293CF: mysqld_main(int, char**) (mysqld.cc:5503)
==10035== by 0x3FDDE1ECDC: (below main) (in /lib64/libc-2.12.so)
==10035==
2013-05-24 17:15:33 10035 [Note] InnoDB: starting tracking changed pages from LSN 1625977

and

2013-05-24 17:15:41 10035 [Note] /ssd/Percona-Server-5.6.10-alpha60.2-347-debug-valgrind.Linux.x86_64/bin/mysqld-debug: ready for connections.
Version: '5.6.11-alpha60.2-debug-log' socket: '/ssd/271485/current1_4/tmp/master.sock' port: 13060 Percona Server with XtraDB (GPL), Release alpha60.2, Revision 347-debug-valgrind
2013-05-25T01:37:32 [11566] Query: INSERT IGNORE INTO `view_table100_innodb_default_int` ( `c65` , `c50` , `c74` ) VALUES ( e , 'all' , '22:02:49.049457' )
==10035== Thread 24:
==10035== Conditional jump or move depends on uninitialised value(s)
==10035== at 0x9E70F7: log_online_start_bitmap_file() (log0online.cc:526)
==10035== by 0x9E7451: log_online_purge_changed_page_bitmaps(unsigned long) (log0online.cc:1688)
==10035== by 0x9919A8: innobase_purge_changed_page_bitmaps(unsigned long long) (ha_innodb.cc:3633)
==10035== by 0x7722A5: plugin_foreach_with_mask(THD*, char (*)(THD*, st_plugin_int**, void*), int, unsigned int, void*) (sql_plugin.cc:2087)
==10035== by 0x6362B7: ha_purge_changed_page_bitmaps(unsigned long long) (handler.cc:7095)
==10035== by 0x781736: reload_acl_and_cache(THD*, unsigned long, TABLE_LIST*, int*) (sql_reload.cc:383)
==10035== by 0x767C33: mysql_execute_command(THD*) (sql_parse.cc:4374)
==10035== by 0x76D10F: mysql_parse(THD*, char*, unsigned int, Parser_state*) (sql_parse.cc:6443)
==10035== by 0x76DBAE: dispatch_command(enum_server_command, THD*, char*, unsigned int) (sql_parse.cc:1359)
==10035== by 0x76E7FF: do_command(THD*) (sql_parse.cc:1051)
==10035== by 0x73910E: do_handle_one_connection(THD*) (sql_connect.cc:1617)
==10035== by 0x73921F: handle_one_connection (sql_connect.cc:1528)
==10035== by 0xC0B948: pfs_spawn_thread (pfs.cc:1853)
==10035== by 0x3FDE207850: start_thread (in /lib64/libpthread-2.12.so)
==10035== by 0x3FDDEE890C: clone (in /lib64/libc-2.12.so)
==10035==

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

Blocks bitmap testing

Roel Van de Paar (roel11) wrote :

Another Valgrind found in another run (looks related, but may be different issue altogether)

Thread 12:
Conditional jump or move depends on uninitialised value(s)
   at 0x9E70F7: log_online_start_bitmap_file() (log0online.cc:526)
   by 0x9E8831: log_online_write_bitmap() (log0online.cc:1131)
   by 0x9E8AA2: log_online_follow_redo_log() (log0online.cc:1223)
   by 0xA8FC94: srv_redo_log_follow_thread (srv0srv.cc:2177)
   by 0x3FDE207850: start_thread (in /lib64/libpthread-2.12.so)
   by 0x3FDDEE890C: clone (in /lib64/libc-2.12.so)

The crash is either bug 1179974, either requires fixing that bug first. Closing as duplicate and raising 1179974 priority.

The Valgrind errors are yet another case of bug 1182793.

Roel Van de Paar (roel11) wrote :

This bug is still visible in QA tree (with latest updates 29/5/13). New details:

2013-05-29 03:15:34 7f169ffa0700 InnoDB: Assertion failure in thread 139735149971200 in file log0online.cc line 1562
InnoDB: Failing assertion: i->in_files.count > 0

#4 0x0000003fdde34085 in abort () from /lib64/libc.so.6
#5 0x0000000000972c1c in log_online_bitmap_iterator_init

Attaching full details in files.

Roel Van de Paar (roel11) wrote :
Roel Van de Paar (roel11) wrote :
Roel Van de Paar (roel11) wrote :
tags: added: qablock
To post a comment you must log in.
This report contains Public information  Edit
Everyone can see this information.

Other bug subscribers