Failing assertion: mutex_own(&(log_sys->mutex)) in file log0log.cc line 224 | abort in log_check_tracking_margin

Bug #1184435 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
Fix Released
Critical
Laurynas Biveinis
5.1
Invalid
Undecided
Unassigned
5.5
Invalid
Undecided
Unassigned
5.6
Fix Released
Critical
Laurynas Biveinis

Bug Description

2013-05-26 17:43:32 18e7f700 InnoDB: Assertion failure in thread 417855232 in file log0log.cc line 224
InnoDB: Failing assertion: mutex_own(&(log_sys->mutex))

Query (20ca81a0): INSERT /*! IGNORE */ INTO table100_innodb_dynamic VALUES ('2000-03-24', 'vpnigwiymxonsrfqzbzeeofuxqiynfgvxvkedxpprlifglddajtyqowctqbrhwpttrnklteqywbuckdbnvlgnnzenqekloznzxldkzvtrfftwvngcoullsephyewzwhflyiqyllzvvtibomnpzzjmqniehuouhqyoogyjuwoyifabeejbkeyxnafkyeseuormrjfkrsqqjcivmtmcyhpmehphlfpbryfhjhlnmsurdzqwrxtywlixkbpjtgcvzdbeahnwuyynhfvneytgxotqjebedpjqpvidevdiymqfzeyvdyqkycmufsxhujynonuuyngzxrotuiaqhsjgrsxtohduvhoeiyxzbiwtmsmjvverjokgxmbrhmsautllwbukfsbeppbmahtxlgdrhvkdjdnvglnmjpbypjkqnazmkgzyofedjwybmootogjojuefcxgsznmfmvyojfxsicilhiiimszpat', LOAD_FILE('/ssd/randgen/data/earth215kb.jpg'), 'hey', LOAD_FILE('/ssd/randgen/data/earth81kb.jpg'), 'a', -573964288, 'pnigwiymxonsrfqzbzeeofuxqiynfgvxvkedxpprlifglddajtyqowctqbrhwpttrnklteqywbuckdbnvlgnnzenqekloznzxldkz', 'f', LOAD_FILE('/ssd/randgen/data/earth81kb.jpg'), 'and', 'not', 'do', 0, '2009-03-13', LOAD_FILE('/ssd/randgen/data/earth1886kb.jpg'), 'nigwiymxonsrfqzbzeeofuxqiynfgvxvkedxpprlifglddajtyqowctqbrhwpttrnklteqywbuckdbnvlgnnzenqekloznzxldkzvtrfftwvn[...]

(This is a fairly normal query in RQG, nothing special here)

Thread 1 (LWP 14432):
+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 0x00000000009e00a0 in log_check_tracking_margin (lsn_advance=21338) at /ssd/5.6-merge-3_val/Percona-Server-5.6.10-alpha60.2/storage/innobase/log/log0log.cc:224
#6 0x00000000009e38fc in log_open (len=<optimized out>) at /ssd/5.6-merge-3_val/Percona-Server-5.6.10-alpha60.2/storage/innobase/log/log0log.cc:278
#7 0x00000000009f75df in mtr_log_reserve_and_write (mtr=0x18e7be00) at /ssd/5.6-merge-3_val/Percona-Server-5.6.10-alpha60.2/storage/innobase/mtr/mtr0mtr.cc:278
#8 0x00000000009f7837 in mtr_commit (mtr=0x18e7be00) at /ssd/5.6-merge-3_val/Percona-Server-5.6.10-alpha60.2/storage/innobase/mtr/mtr0mtr.cc:323
#9 0x0000000000adf426 in btr_store_big_rec_extern_fields (index=0x193f94e8, rec_block=<optimized out>, rec=0x9bde051 "j", offsets=0x8abcd88, big_rec_vec=0x24b19618, btr_mtr=0x18e7c410, op=BTR_STORE_INSERT) at /ssd/5.6-merge-3_val/Percona-Server-5.6.10-alpha60.2/storage/innobase/btr/btr0cur.cc:4973
#10 0x0000000000a3ffb9 in row_ins_index_entry_big_rec_func (entry=0x9bde051, big_rec=0x24b19618, offsets=0x8abcd88, heap=0x18e7cf58, index=0x193f94e8, file=0xdc8b20 "/ssd/5.6-merge-3_val/Percona-Server-5.6.10-alpha60.2/storage/innobase/row/row0ins.cc", thd=0x18cb6bb0, line=2529) at /ssd/5.6-merge-3_val/Percona-Server-5.6.10-alpha60.2/storage/innobase/row/row0ins.cc:2840
#11 0x0000000000a42ddb in row_ins_clust_index_entry_low (flags=0, mode=417845080, index=0x193f94e8, n_uniq=<optimized out>, entry=0x214de488, n_ext=0, thr=0x20f7a240) at /ssd/5.6-merge-3_val/Percona-Server-5.6.10-alpha60.2/storage/innobase/row/row0ins.cc:2529
#12 0x0000000000a45ca9 in row_ins_clust_index_entry (index=0x193f94e8, entry=0x214de488, thr=0x20f7a240, n_ext=0) at /ssd/5.6-merge-3_val/Percona-Server-5.6.10-alpha60.2/storage/innobase/row/row0ins.cc:2908
#13 0x0000000000a45d74 in row_ins_index_entry_step (node=0x20f795f8, thr=0x20f7a240) at /ssd/5.6-merge-3_val/Percona-Server-5.6.10-alpha60.2/storage/innobase/row/row0ins.cc:3058
#14 0x0000000000a45e4b in row_ins (node=0x20f795f8, thr=0x20f7a240) at /ssd/5.6-merge-3_val/Percona-Server-5.6.10-alpha60.2/storage/innobase/row/row0ins.cc:3198
#15 0x0000000000a460cb in row_ins_step (thr=0x20f7a240) at /ssd/5.6-merge-3_val/Percona-Server-5.6.10-alpha60.2/storage/innobase/row/row0ins.cc:3323
#16 0x0000000000a5d154 in row_insert_for_mysql (mysql_rec=<optimized out>, prebuilt=<optimized out>) at /ssd/5.6-merge-3_val/Percona-Server-5.6.10-alpha60.2/storage/innobase/row/row0mysql.cc:1312
#17 0x00000000009a1b88 in ha_innobase::write_row (this=0x20f2ff70, record=0x199a59e0 " \f") at /ssd/5.6-merge-3_val/Percona-Server-5.6.10-alpha60.2/storage/innobase/handler/ha_innodb.cc:6895
#18 0x0000000000637ca8 in handler::ha_write_row (this=0x20f2ff70, buf=0x199a59e0 " \f") at /ssd/5.6-merge-3_val/Percona-Server-5.6.10-alpha60.2/sql/handler.cc:7424
#19 0x000000000074eb69 in write_record (thd=0x18cb6bb0, table=0x199a50b0, info=0x18e7d510, update=0x18e7d490) at /ssd/5.6-merge-3_val/Percona-Server-5.6.10-alpha60.2/sql/sql_insert.cc:1905
#20 0x0000000000753637 in mysql_insert (thd=0x18cb6bb0, table_list=0x18b46f28, fields=..., values_list=..., update_fields=..., update_values=..., duplic=DUP_ERROR, ignore=true) at /ssd/5.6-merge-3_val/Percona-Server-5.6.10-alpha60.2/sql/sql_insert.cc:1054
#21 0x000000000076a87e in mysql_execute_command (thd=0x18cb6bb0) at /ssd/5.6-merge-3_val/Percona-Server-5.6.10-alpha60.2/sql/sql_parse.cc:3626
#22 0x000000000076d110 in mysql_parse (thd=0x18cb6bb0, 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
#23 0x000000000076dbaf in dispatch_command (command=<optimized out>, thd=0x18cb6bb0, packet=<optimized out>, packet_length=550668008) at /ssd/5.6-merge-3_val/Percona-Server-5.6.10-alpha60.2/sql/sql_parse.cc:1359
#24 0x000000000076e800 in do_command (thd=0x18cb6bb0) at /ssd/5.6-merge-3_val/Percona-Server-5.6.10-alpha60.2/sql/sql_parse.cc:1051
#25 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
#26 0x0000000000739220 in handle_one_connection (arg=0x18cb6bb0) at /ssd/5.6-merge-3_val/Percona-Server-5.6.10-alpha60.2/sql/sql_connect.cc:1528
#27 0x0000000000c0b949 in pfs_spawn_thread (arg=0x18b46b60) at /ssd/5.6-merge-3_val/Percona-Server-5.6.10-alpha60.2/storage/perfschema/pfs.cc:1853
#28 0x0000003fde207851 in start_thread () from /lib64/libpthread.so.0
#29 0x0000003fddee890d in clone () from /lib64/libc.so.6

Valgrinds seen in log before assert (first same as bug #1184427 and second similar as bug #1184427 but not the same)

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

and

2013-05-26 17:42:41 14404 [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_5/tmp/master.sock' port: 13080 Percona Server with XtraDB (GPL), Release alpha60.2, Revision 347-debug-valgrind
==14404== Thread 12:
==14404== Conditional jump or move depends on uninitialised value(s)
==14404== at 0x9E70F7: log_online_start_bitmap_file() (log0online.cc:526)
==14404== by 0x9E8831: log_online_write_bitmap() (log0online.cc:1131)
==14404== by 0x9E8AA2: log_online_follow_redo_log() (log0online.cc:1223)
==14404== by 0xA8FC94: srv_redo_log_follow_thread (srv0srv.cc:2177)
==14404== by 0x3FDE207850: start_thread (in /lib64/libpthread-2.12.so)
==14404== by 0x3FDDEE890C: clone (in /lib64/libc-2.12.so)
==14404==

Tags: bitmap qa qablock

Related branches

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

Blocks bitmap testing. Seen heaps.

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 :

Single thread issue

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

Should be fixed in the "merge-4" branch already, lp:~laurynas-biveinis/percona-server/5.6-merge-4.

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

The merge-4 fixes the assert but not the Valgrind error. That one is bug 1182793.

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-365

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

Other bug subscribers

Remote bug watches

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