Intermittent innodb_bug56680 crash

[Laurynas Biveinis]

http://jenkins.percona.com/job/percona-server-5.5-param/230/BUILD_TYPE=debug,Host=ubuntu-natty-32bit/
http://jenkins.percona.com/job/percona-server-5.5-param/230/BUILD_TYPE=debug,Host=centos6-32/

innodb.innodb_bug56680 w4 [ fail ]
        Test ended at 2011-12-16 21:38:49

111216 13:38:48 InnoDB: Assertion failure in thread 2895530864 in file buf0flu.c line 1195
InnoDB: Failing assertion: buf_block_get_state(block) == BUF_BLOCK_FILE_PAGE

Trying 'gdb' to get a backtrace
Guessing that core was generated by '/home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/sql/mysqld'
Output from gdb follows. The first stack trace is from the failing thread.
The following stack traces are from all threads (so the failing one is
duplicated).
--------------------------
Missing separate debuginfo for /usr/local/lib/libeatmydata.so
Try: yum --disablerepo='*' --enablerepo='*-debuginfo' install /usr/lib/debug/.build-id/c1/5540d06dff94f7db97f95ca6a8a7d29304f48e
Missing separate debuginfo for
Try: yum --disablerepo='*' --enablerepo='*-debuginfo' install /usr/lib/debug/.build-id/bb/eea94b5b45b3fa300d0a82cb276d78f062cfc0
[New Thread 9011]
[New Thread 9065]
[New Thread 9000]
[New Thread 9002]
[New Thread 8984]
[New Thread 9010]
[New Thread 9004]
[New Thread 8999]
[New Thread 9001]
[New Thread 13063]
[New Thread 9003]
[New Thread 9006]
[New Thread 9007]
[New Thread 9008]
[New Thread 9009]
[Thread debugging using libthread_db enabled]
Core was generated by `/home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-'.
Program terminated with signal 6, Aborted.
#0 0x00692424 in __kernel_vsyscall ()
#0 0x00692424 in __kernel_vsyscall ()
#1 0x007ca3e3 in pthread_kill () from /lib/libpthread.so.0
#2 0x08434897 in my_write_core (sig=6) at /home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/mysys/stacktrace.c:423
#3 0x08132d93 in handle_segfault (sig=6) at /home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/sql/mysqld.cc:2600
#4 <signal handler called>
#5 0x00692424 in __kernel_vsyscall ()
#6 0x0022ab71 in raise () from /lib/libc.so.6
#7 0x0022c44a in abort () from /lib/libc.so.6
#8 0x0856f619 in buf_flush_page_try (buf_pool=0x9394908, block=0xb3397ae8) at /home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/storage/innobase/buf/buf0flu.c:1195
#9 0x0856a81b in buf_page_get_gen (space=0, zip_size=0, offset=569, rw_latch=2, guess=0x0, mode=15, file=0x87b98c4 "/home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/storage/innobase/row/row0row.c", line=792, mtr=0xac963c90) at /home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/storage/innobase/buf/buf0buf.c:2822
#10 0x08550682 in btr_cur_search_to_nth_level (index=0x947ced0, level=0, tuple=0xabb007b8, mode=4, latch_mode=2, cursor=0xac963c18, has_search_latch=0, file=0x87b98c4 "/home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/storage/innobase/row/row0row.c", line=792, mtr=0xac963c90) at /home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/storage/innobase/btr/btr0cur.c:620
#11 0x084df180 in btr_pcur_open_func (index=0x947ced0, entry=0xabb007b8, mode=8194, pcur=0xac963c18, mtr=0xac963c90) at /home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/storage/innobase/include/btr0pcur.ic:470
#12 row_search_index_entry (index=0x947ced0, entry=0xabb007b8, mode=8194, pcur=0xac963c18, mtr=0xac963c90) at /home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/storage/innobase/row/row0row.c:792
#13 0x0863b893 in row_purge_remove_sec_if_poss_leaf (node=0x9474ab8, index=0x947ced0, entry=0xabb007b8) at /home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/storage/innobase/row/row0purge.c:375
#14 0x0863da3f in row_purge_remove_sec_if_poss (node=0x9474ab8) at /home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/storage/innobase/row/row0purge.c:433
#15 row_purge_del_mark (node=0x9474ab8) at /home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/storage/innobase/row/row0purge.c:484
#16 0x0863e56f in row_purge (thr=0x9474a50) at /home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/storage/innobase/row/row0purge.c:765
#17 row_purge_step (thr=0x9474a50) at /home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/storage/innobase/row/row0purge.c:805
#18 0x08629cfb in que_thr_step (thr=0x9474a50) at /home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/storage/innobase/que/que0que.c:1259
#19 que_run_threads_low (thr=0x9474a50) at /home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/storage/innobase/que/que0que.c:1319
#20 que_run_threads (thr=0x9474a50) at /home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/storage/innobase/que/que0que.c:1356
#21 0x0850e6ee in trx_purge (limit=20) at /home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/storage/innobase/trx/trx0purge.c:1194
#22 0x084fcad3 in srv_purge_thread (arg=0x0) at /home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/storage/innobase/srv/srv0srv.c:3897
#23 0x007c59e9 in start_thread () from /lib/libpthread.so.0
#24 0x002dcc2e in clone () from /lib/libc.so.6

Thread 15 (Thread 0xafb69b70 (LWP 9009)):
#0 0x00692424 in __kernel_vsyscall ()
#1 0x002d50f1 in select () from /lib/libc.so.6
#2 0x08607a03 in os_thread_sleep (tm=5000000) at /home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/storage/innobase/os/os0thread.c:259
#3 0x084fcbc0 in srv_LRU_dump_restore_thread (arg=0x0) at /home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/storage/innobase/srv/srv0srv.c:2929
#4 0x007c59e9 in start_thread () from /lib/libpthread.so.0
#5 0x002dcc2e in clone () from /lib/libc.so.6

Thread 14 (Thread 0xadd66b70 (LWP 9008)):
#0 0x00692424 in __kernel_vsyscall ()
#1 0x007c9604 in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
#2 0x086072a4 in os_cond_wait_timed (event=0x924f1b8, time_in_usec=5000000, reset_sig_count=1) at /home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/storage/innobase/os/os0sync.c:171
#3 os_event_wait_time_low (event=0x924f1b8, time_in_usec=5000000, reset_sig_count=1) at /home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/storage/innobase/os/os0sync.c:716
#4 0x084ff33c in srv_monitor_thread (arg=<value optimized out>) at /home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/storage/innobase/srv/srv0srv.c:2521
#5 0x007c59e9 in start_thread () from /lib/libpthread.so.0
#6 0x002dcc2e in clone () from /lib/libc.so.6

Thread 13 (Thread 0xae767b70 (LWP 9007)):
#0 0x00692424 in __kernel_vsyscall ()
#1 0x007c9604 in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
#2 0x086072a4 in os_cond_wait_timed (event=0x924f0f8, time_in_usec=1000000, reset_sig_count=1) at /home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/storage/innobase/os/os0sync.c:171
#3 os_event_wait_time_low (event=0x924f0f8, time_in_usec=1000000, reset_sig_count=1) at /home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/storage/innobase/os/os0sync.c:716
#4 0x08500c64 in srv_error_monitor_thread (arg=0x0) at /home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/storage/innobase/srv/srv0srv.c:2883
#5 0x007c59e9 in start_thread () from /lib/libpthread.so.0
#6 0x002dcc2e in clone () from /lib/libc.so.6

Thread 12 (Thread 0xaf168b70 (LWP 9006)):
#0 0x00692424 in __kernel_vsyscall ()
#1 0x007c9604 in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
#2 0x086072a4 in os_cond_wait_timed (event=0x924f158, time_in_usec=1000000, reset_sig_count=1) at /home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/storage/innobase/os/os0sync.c:171
#3 os_event_wait_time_low (event=0x924f158, time_in_usec=1000000, reset_sig_count=1) at /home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/storage/innobase/os/os0sync.c:716
#4 0x085004ce in srv_lock_timeout_thread (arg=0x0) at /home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/storage/innobase/srv/srv0srv.c:2671
#5 0x007c59e9 in start_thread () from /lib/libpthread.so.0
#6 0x002dcc2e in clone () from /lib/libc.so.6

Thread 11 (Thread 0xb13b6b70 (LWP 9003)):
#0 0x009b151a in ?? () from /lib/libaio.so.1
#1 0x085a66ca in fil_aio_wait (segment=4) at /home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/storage/innobase/fil/fil0fil.c:5496
#2 0x08502850 in io_handler_thread (arg=0x8ae0850) at /home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/storage/innobase/srv/srv0start.c:483
#3 0x007c59e9 in start_thread () from /lib/libpthread.so.0
#4 0x002dcc2e in clone () from /lib/libc.so.6

Thread 10 (Thread 0xaff83b70 (LWP 13063)):
#0 my_timer_cycles () at /home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/mysys/my_rdtsc.c:233
#1 0x0844886e in get_timer_value (timer_name=TIMER_NAME_CYCLE) at /home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/storage/perfschema/pfs_timer.cc:100
#2 0x0844e88c in start_rwlock_wrwait_v1 (locker=0xb6e8e6e4, src_file=0x87c87f0 "/home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/storage/innobase/btr/btr0sea.c", src_line=1825) at /home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/storage/perfschema/pfs.cc:1729
#3 0x08555e6d in pfs_rw_lock_x_lock_func (lock=0x942dd90, pass=0, file_name=0x87c87f0 "/home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/storage/innobase/btr/btr0sea.c", line=1825) at /home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/storage/innobase/include/sync0rw.ic:688
#4 0x0855840c in btr_search_update_hash_node_on_insert (cursor=0xaff8195c) at /home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/storage/innobase/btr/btr0sea.c:1825
#5 0x085460d1 in btr_cur_optimistic_insert (flags=0, cursor=0xaff8195c, entry=0xabe4bed8, rec=0xaff81958, big_rec=0xaff81954, n_ext=0, thr=0xabe20f90, mtr=0xaff814e4) at /home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/storage/innobase/btr/btr0cur.c:1465
#6 0x08638362 in row_ins_index_entry_low (mode=2, index=0xabe1e428, entry=0xabe4bed8, n_ext=0, thr=0xabe20f90) at /home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/storage/innobase/row/row0ins.c:2109
#7 0x0863a34b in row_ins_index_entry (index=0xabe1e428, entry=0xabe4bed8, n_ext=0, foreign=1, thr=0xabe20f90) at /home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/storage/innobase/row/row0ins.c:2206
#8 0x0863af5e in row_ins_index_entry_step (thr=0xabe20f90) at /home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/storage/innobase/row/row0ins.c:2291
#9 row_ins (thr=0xabe20f90) at /home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/storage/innobase/row/row0ins.c:2423
#10 row_ins_step (thr=0xabe20f90) at /home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/storage/innobase/row/row0ins.c:2540
#11 0x084d9ad7 in row_insert_for_mysql (mysql_rec=0xabe1ebf8 "\371R\v", prebuilt=0xabe13640) at /home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/storage/innobase/row/row0mysql.c:1216
#12 0x084b89c4 in ha_innobase::write_row (this=0xabe1e890, record=0xabe1ebf8 "\371R\v") at /home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/storage/innobase/handler/ha_innodb.cc:5694
#13 0x082edb92 in handler::ha_write_row (this=0xabe1e890, buf=0xabe1ebf8 "\371R\v") at /home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/sql/handler.cc:4980
#14 0x081a8ab8 in write_record (thd=0x947dd68, table=0xabe16b98, info=0xabe1ace0) at /home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/sql/sql_insert.cc:1733
#15 0x081a8ea9 in select_insert::send_data (this=0xabe1acc0, values=...) at /home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/sql/sql_insert.cc:3402
#16 0x081edde0 in end_send (join=0xabe1ad30, join_tab=0xabc38b14, end_of_records=false) at /home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/sql/sql_select.cc:12704
#17 0x081e6be9 in evaluate_join_record (join=0xabe1ad30, join_tab=0xabc38980, error=0) at /home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/sql/sql_select.cc:11917
#18 0x081ec9fd in sub_select (join=0xabe1ad30, join_tab=0xabc38980, end_of_records=false) at /home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/sql/sql_select.cc:11775
#19 0x08201cd2 in do_select (join=0xabe1ad30, fields=0xabe1be7c, table=0x0, procedure=0x0) at /home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/sql/sql_select.cc:11535
#20 0x0820487d in JOIN::exec (this=0xabe1ad30) at /home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/sql/sql_select.cc:2391
#21 0x082053ae in mysql_select (thd=0x947dd68, rref_pointer_array=0x947f498, tables=0xabe1a900, wild_num=0, fields=..., conds=0x0, og_num=0, order=0x0, group=0x0, having=0x0, proc_param=0x0, select_options=3490974464, result=0xabe1acc0, unit=0x947ef64, select_lex=0x947f3a0) at /home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/sql/sql_select.cc:2600
#22 0x08208902 in handle_select (thd=0x947dd68, lex=0x947ef00, result=0xabe1acc0, setup_tables_done_option=1073741824) at /home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/sql/sql_select.cc:312
#23 0x081c1a31 in mysql_execute_command (thd=0x947dd68) at /home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/sql/sql_parse.cc:3134
#24 0x081c634a in mysql_parse (thd=0x947dd68, rawbuf=0xabe1a288 "INSERT INTO bug56680 SELECT 0,b,c FROM bug56680", length=47, parser_state=0xaff82d14) at /home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/sql/sql_parse.cc:5805
#25 0x081c7868 in dispatch_command (command=COM_QUERY, thd=0x947dd68, packet=0x94f40a9 "INSERT INTO bug56680 SELECT 0,b,c FROM bug56680", packet_length=47) at /home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/sql/sql_parse.cc:1060
#26 0x081c9084 in do_command (thd=0x947dd68) at /home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/sql/sql_parse.cc:788
#27 0x082763c8 in do_handle_one_connection (thd_arg=0x947dd68) at /home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/sql/sql_connect.cc:1409
#28 0x082764d0 in handle_one_connection (arg=0x947dd68) at /home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/sql/sql_connect.cc:1315
#29 0x0845004f in pfs_spawn_thread (arg=0x94d50f0) at /home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/storage/perfschema/pfs.cc:1015
#30 0x007c59e9 in start_thread () from /lib/libpthread.so.0
#31 0x002dcc2e in clone () from /lib/libc.so.6

Thread 9 (Thread 0xb27b8b70 (LWP 9001)):
#0 0x009b151a in ?? () from /lib/libaio.so.1
#1 0x085a66ca in fil_aio_wait (segment=2) at /home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/storage/innobase/fil/fil0fil.c:5496
#2 0x08502850 in io_handler_thread (arg=0x8ae0848) at /home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/storage/innobase/srv/srv0start.c:483
#3 0x007c59e9 in start_thread () from /lib/libpthread.so.0
#4 0x002dcc2e in clone () from /lib/libc.so.6

Thread 8 (Thread 0xb78e9b70 (LWP 8999)):
#0 0x009b151a in ?? () from /lib/libaio.so.1
#1 0x085a66ca in fil_aio_wait (segment=0) at /home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/storage/innobase/fil/fil0fil.c:5496
#2 0x08502850 in io_handler_thread (arg=0x8ae0840) at /home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/storage/innobase/srv/srv0start.c:483
#3 0x007c59e9 in start_thread () from /lib/libpthread.so.0
#4 0x002dcc2e in clone () from /lib/libc.so.6

Thread 7 (Thread 0xb09b5b70 (LWP 9004)):
#0 0x009b151a in ?? () from /lib/libaio.so.1
#1 0x085a66ca in fil_aio_wait (segment=5) at /home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/storage/innobase/fil/fil0fil.c:5496
#2 0x08502850 in io_handler_thread (arg=0x8ae0854) at /home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/storage/innobase/srv/srv0start.c:483
#3 0x007c59e9 in start_thread () from /lib/libpthread.so.0
#4 0x002dcc2e in clone () from /lib/libc.so.6

Thread 6 (Thread 0xad365b70 (LWP 9010)):
#0 0x00692424 in __kernel_vsyscall ()
#1 0x002d50f1 in select () from /lib/libc.so.6
#2 0x08607a03 in os_thread_sleep (tm=1000000) at /home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/storage/innobase/os/os0thread.c:259
#3 0x08500f84 in srv_master_thread (arg=0x0) at /home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/storage/innobase/srv/srv0srv.c:3237
#4 0x007c59e9 in start_thread () from /lib/libpthread.so.0
#5 0x002dcc2e in clone () from /lib/libc.so.6

Thread 5 (Thread 0xb78eb6d0 (LWP 8984)):
#0 0x00692424 in __kernel_vsyscall ()
#1 0x002d1e46 in poll () from /lib/libc.so.6
#2 0x081353f7 in handle_connections_sockets () at /home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/sql/mysqld.cc:5372
#3 0x0813b881 in mysqld_main (argc=49, argv=0x8fd2140) at /home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/sql/mysqld.cc:4811
#4 0x0812feab in main (argc=7, argv=0xbfa2a254) at /home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/sql/main.cc:25

Thread 4 (Thread 0xb1db7b70 (LWP 9002)):
#0 0x009b151a in ?? () from /lib/libaio.so.1
#1 0x085a66ca in fil_aio_wait (segment=3) at /home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/storage/innobase/fil/fil0fil.c:5496
#2 0x08502850 in io_handler_thread (arg=0x8ae084c) at /home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/storage/innobase/srv/srv0start.c:483
#3 0x007c59e9 in start_thread () from /lib/libpthread.so.0
#4 0x002dcc2e in clone () from /lib/libc.so.6

Thread 3 (Thread 0xb31b9b70 (LWP 9000)):
#0 0x009b151a in ?? () from /lib/libaio.so.1
#1 0x085a66ca in fil_aio_wait (segment=1) at /home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/storage/innobase/fil/fil0fil.c:5496
#2 0x08502850 in io_handler_thread (arg=0x8ae0844) at /home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/storage/innobase/srv/srv0start.c:483
#3 0x007c59e9 in start_thread () from /lib/libpthread.so.0
#4 0x002dcc2e in clone () from /lib/libc.so.6

Thread 2 (Thread 0xaffb4b70 (LWP 9065)):
#0 0x00692424 in __kernel_vsyscall ()
#1 0x007cd570 in sigwait () from /lib/libpthread.so.0
#2 0x081345b4 in signal_hand (arg=0x0) at /home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/sql/mysqld.cc:2793
#3 0x0845004f in pfs_spawn_thread (arg=0x9074230) at /home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/storage/perfschema/pfs.cc:1015
#4 0x007c59e9 in start_thread () from /lib/libpthread.so.0
#5 0x002dcc2e in clone () from /lib/libc.so.6

Thread 1 (Thread 0xac964b70 (LWP 9011)):
#0 0x00692424 in __kernel_vsyscall ()
#1 0x007ca3e3 in pthread_kill () from /lib/libpthread.so.0
#2 0x08434897 in my_write_core (sig=6) at /home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/mysys/stacktrace.c:423
#3 0x08132d93 in handle_segfault (sig=6) at /home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/sql/mysqld.cc:2600
#4 <signal handler called>
#5 0x00692424 in __kernel_vsyscall ()
#6 0x0022ab71 in raise () from /lib/libc.so.6
#7 0x0022c44a in abort () from /lib/libc.so.6
#8 0x0856f619 in buf_flush_page_try (buf_pool=0x9394908, block=0xb3397ae8) at /home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/storage/innobase/buf/buf0flu.c:1195
#9 0x0856a81b in buf_page_get_gen (space=0, zip_size=0, offset=569, rw_latch=2, guess=0x0, mode=15, file=0x87b98c4 "/home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/storage/innobase/row/row0row.c", line=792, mtr=0xac963c90) at /home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/storage/innobase/buf/buf0buf.c:2822
#10 0x08550682 in btr_cur_search_to_nth_level (index=0x947ced0, level=0, tuple=0xabb007b8, mode=4, latch_mode=2, cursor=0xac963c18, has_search_latch=0, file=0x87b98c4 "/home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/storage/innobase/row/row0row.c", line=792, mtr=0xac963c90) at /home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/storage/innobase/btr/btr0cur.c:620
#11 0x084df180 in btr_pcur_open_func (index=0x947ced0, entry=0xabb007b8, mode=8194, pcur=0xac963c18, mtr=0xac963c90) at /home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/storage/innobase/include/btr0pcur.ic:470
#12 row_search_index_entry (index=0x947ced0, entry=0xabb007b8, mode=8194, pcur=0xac963c18, mtr=0xac963c90) at /home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/storage/innobase/row/row0row.c:792
#13 0x0863b893 in row_purge_remove_sec_if_poss_leaf (node=0x9474ab8, index=0x947ced0, entry=0xabb007b8) at /home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/storage/innobase/row/row0purge.c:375
#14 0x0863da3f in row_purge_remove_sec_if_poss (node=0x9474ab8) at /home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/storage/innobase/row/row0purge.c:433
#15 row_purge_del_mark (node=0x9474ab8) at /home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/storage/innobase/row/row0purge.c:484
#16 0x0863e56f in row_purge (thr=0x9474a50) at /home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/storage/innobase/row/row0purge.c:765
#17 row_purge_step (thr=0x9474a50) at /home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/storage/innobase/row/row0purge.c:805
#18 0x08629cfb in que_thr_step (thr=0x9474a50) at /home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/storage/innobase/que/que0que.c:1259
#19 que_run_threads_low (thr=0x9474a50) at /home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/storage/innobase/que/que0que.c:1319
#20 que_run_threads (thr=0x9474a50) at /home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/storage/innobase/que/que0que.c:1356
#21 0x0850e6ee in trx_purge (limit=20) at /home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/storage/innobase/trx/trx0purge.c:1194
#22 0x084fcad3 in srv_purge_thread (arg=0x0) at /home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/storage/innobase/srv/srv0srv.c:3897
#23 0x007c59e9 in start_thread () from /lib/libpthread.so.0
#24 0x002dcc2e in clone () from /lib/libc.so.6

Compressed file /home/jenkins/workspace/percona-server-5.5-param/BUILD_TYPE/debug/Host/centos6-32/Percona-Server-5.5.18-rel21.0/mysql-test/var/log/innodb.innodb_bug56680/mysqld.1/data/core.8984

[Kristian Nielsen (knielsen)]

 I am able to repeat the problem locally (Debian testing x86_64), by running
 the test in a loop until it fails:

    (cd mysql-test ; for i in `seq 1000`; do echo XXX $i XXX; ./mtr --parallel=2 innodb.innodb_bug56680 || exit 1 ; done)

[Kristian Nielsen (knielsen)]

We are still seeing this :-/

It has been 6 months since reporting, did anything happen on the bug?

Do you have a suggestion for what we should do to avoid this failure in MariaDB?

It should be relatively easy to bisect the Percona Server quilt patch series to find the offending patch that triggers this.

[Laurynas Biveinis (laurynas-biveinis)]

Seen on 64 bits too:
http://jenkins.percona.com/view/PS%205.5/job/percona-server-5.5-param/385/BUILD_TYPE=debug,Host=ubuntu-oneiric-64bit/testReport/%28root%29/innodb/innodb_bug56680/

(It's a param build, but the relevant code is not touched here).

[Laurynas Biveinis (laurynas-biveinis)]

Debugging still in progress. It looks like a race condition between buf_page_t::state and buf_page_t::io_fix updates due to insufficient locking, these fields sharing the same machine word.

[Stewart Smith (stewart)]

On Fri, 08 Jun 2012 15:19:36 -0000, Laurynas Biveinis <email address hidden> wrote:
> Debugging still in progress. It looks like a race condition between
> buf_page_t::state and buf_page_t::io_fix updates due to insufficient
> locking, these fields sharing the same machine word.

Perhaps we just need to audit where we're touching these? At least
according to comments it should be protected by same set of mutexes?
Perhaps even helgrind could help here?

--
Stewart Smith

[Laurynas Biveinis (laurynas-biveinis)]

Stewart -

In fact all these suggestions are in progress, I helground it too.

[Michael Widenius (monty)]

Some more information (Just got a new crash):

The assert buf_block_get_state(block) == BUF_BLOCK_FILE_PAGE fails for me because:
buf_block_get_state(block) = BUF_BLOCK_REMOVE_HASH

one likely reason is that in the caller buf_page_get_gen() we do just before:

mutex_lock(block->mutex);
call buf_LRU_free_block();
  mutex_unlock(block->mutex);
  ....
  mutex_lock(block->mutex);

What probably happens is that some other threads reuses the buffer during the mutex_unlock/mutex_lock in
buf_LRU_free_block().

Suggestions:
- Add test that if block changed during call of in buf_LRU_free_block() we don't call buf_flush_page_try()
- Remove the optimization of buf_pool->LRU_list_mutex as it's not safe.

The above code doesn't exist in Innobase and it's probably because of that we don't see this issue with InnoDB.

[Laurynas Biveinis (laurynas-biveinis)]

I have just pushed the fix for 5.1, and it should be merged to 5.1 trunk after testing and code review, and upmerged to 5.5.

Sorry that it took so long and thanks for your patience.

[Laurynas Biveinis (laurynas-biveinis)]

Reassigning 5.5 to Stewart as 5.1 -> 5.5 merge will have to be done in trunks here.

[Laurynas Biveinis (laurynas-biveinis)]

See also bug 1046389. Both will have to be merged in the same revision to 5.5. Stewart, reassigning to you as currently handling the 5.1 -> 5.5 merge.

[Shahriyar Rzayev (rzayev-sehriyar)]

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