5.5.12 main.percona_xtradb_bug317074 - segfault

Bug #786573 reported by Valentine Gostev
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
Percona Server moved to https://jira.percona.com/projects/PS
Fix Released
High
Unassigned
5.5
Fix Released
High
Unassigned
percona-projects-qa
Invalid
High
Unassigned

Bug Description

# ./sql/mysqld --version
./sql/mysqld Ver 5.5.12-debug-log for Linux on x86_64 (Source distribution)

main.percona_xtradb_bug317074 [ fail ]
        Test ended at 2011-05-22 08:15:45

CURRENT_TEST: main.percona_xtradb_bug317074
==22046== Memcheck, a memory error detector
==22046== Copyright (C) 2002-2009, and GNU GPL'd, by Julian Seward et al.
==22046== Using Valgrind-3.5.0 and LibVEX; rerun with -h for copyright info
==22046== Command: /root/Percona-Server-5.5.12-rel20.3/client//mysqltest --defaults-file=/root/Percona-Server-5.5.12-rel20.3/mysql-test/var/my.cnf --silent --tmpdir=/root/Percona-Server-5.5.12-rel20.3/mysql-test/var/tmp --character-sets-dir=/root/Percona-Server-5.5.12-rel20.3/sql/share/charsets --logdir=/root/Percona-Server-5.5.12-rel20.3/mysql-test/var/log --plugin_dir=/root/Percona-Server-5.5.12-rel20.3/plugin/auth --database=test --timer-file=/root/Percona-Server-5.5.12-rel20.3/mysql-test/var/log/timer --test-file=/root/Percona-Server-5.5.12-rel20.3/mysql-test/t/percona_xtradb_bug317074.test --tail-lines=20 --result-file=/root/Percona-Server-5.5.12-rel20.3/mysql-test/r/percona_xtradb_bug317074.result
==22046==
mysqltest: At line 38: query 'call insert_many(100000)' failed: 2013: Lost connection to MySQL server during query

The result from queries just before the failure was:
SET @old_innodb_file_format=@@innodb_file_format;
SET @old_innodb_file_format_max=@@innodb_file_format_max;
SET @old_innodb_file_per_table=@@innodb_file_per_table;
SET GLOBAL innodb_file_format='Barracuda';
SET GLOBAL innodb_file_per_table=ON;
==22046==
==22046== HEAP SUMMARY:
==22046== in use at exit: 56 bytes in 1 blocks
==22046== total heap usage: 248 allocs, 247 frees, 396,323 bytes allocated
==22046==
==22046== LEAK SUMMARY:
==22046== definitely lost: 0 bytes in 0 blocks
==22046== indirectly lost: 0 bytes in 0 blocks
==22046== possibly lost: 0 bytes in 0 blocks
==22046== still reachable: 0 bytes in 0 blocks
==22046== suppressed: 56 bytes in 1 blocks
==22046==
==22046== For counts of detected and suppressed errors, rerun with: -v
==22046== ERROR SUMMARY: 0 errors from 0 contexts (suppressed: 4 from 4)

Server [mysqld.1 - pid: 21401, winpid: 21401, exit: 256] failed during test run
Server log from this test:
----------SERVER LOG START-----------
InnoDB: DEBUG: update_statistics for test/test1.
<snip>
InnoDB: DEBUG: update_statistics for test/test1.
110522 7:15:40 InnoDB: Assertion failure in thread 68348224 in file buf0lru.c line 621
InnoDB: Failing assertion: mutex_own(&buf_pool->zip_mutex)
InnoDB: We intentionally generate a memory trap.
InnoDB: Submit a detailed bug report to http://bugs.mysql.com.
InnoDB: If you get repeated assertion failures or crashes, even
InnoDB: immediately after the mysqld startup, there may be
InnoDB: corruption in the InnoDB tablespace. Please refer to
InnoDB: http://dev.mysql.com/doc/refman/5.5/en/forcing-innodb-recovery.html
InnoDB: about forcing recovery.
110522 7:15:40 - mysqld got signal 6 ;
This could be because you hit a bug. It is also possible that this binary
or one of the libraries it was linked against is corrupt, improperly built,
or misconfigured. This error can also be caused by malfunctioning hardware.
We will try our best to scrape up some info that will hopefully help diagnose
the problem, but since we have already crashed, something is definitely wrong
and this may fail.

key_buffer_size=1048576
read_buffer_size=131072
max_used_connections=4
max_threads=151
thread_count=1
connection_count=1
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 60913 K
bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

Thread pointer: 0x12f2ee80
Attempting backtrace. You can use the following information to find out
where mysqld died. If you see no messages after this, something went
terribly wrong...
stack_bottom = 0x412e078 thread_stack 0x40000
/root/Percona-Server-5.5.12-rel20.3/sql/mysqld(my_print_stacktrace+0x32)[0x8ab052]
/root/Percona-Server-5.5.12-rel20.3/sql/mysqld(handle_segfault+0x2ac)[0x52c482]
/lib64/libpthread.so.0[0x4e33b10]
/lib64/libc.so.6(gsignal+0x35)[0x6047265]
/lib64/libc.so.6(abort+0x110)[0x6048d10]
/root/Percona-Server-5.5.12-rel20.3/sql/mysqld[0x9aec30]
/root/Percona-Server-5.5.12-rel20.3/sql/mysqld[0x9b21b4]
/root/Percona-Server-5.5.12-rel20.3/sql/mysqld[0x9af181]
/root/Percona-Server-5.5.12-rel20.3/sql/mysqld[0x9aef26]
/root/Percona-Server-5.5.12-rel20.3/sql/mysqld[0x9aff44]
/root/Percona-Server-5.5.12-rel20.3/sql/mysqld[0x9a37c4]
/root/Percona-Server-5.5.12-rel20.3/sql/mysqld[0x9f6183]
/root/Percona-Server-5.5.12-rel20.3/sql/mysqld[0x9f6456]
/root/Percona-Server-5.5.12-rel20.3/sql/mysqld[0x9698a9]
/root/Percona-Server-5.5.12-rel20.3/sql/mysqld[0x97042c]
/root/Percona-Server-5.5.12-rel20.3/sql/mysqld[0x97d43c]
/root/Percona-Server-5.5.12-rel20.3/sql/mysqld[0xa835e5]
/root/Percona-Server-5.5.12-rel20.3/sql/mysqld[0xa83b5a]
/root/Percona-Server-5.5.12-rel20.3/sql/mysqld[0xa83e9c]
/root/Percona-Server-5.5.12-rel20.3/sql/mysqld[0xa83fb0]
/root/Percona-Server-5.5.12-rel20.3/sql/mysqld[0xa8471c]
/root/Percona-Server-5.5.12-rel20.3/sql/mysqld[0x901f14]
/root/Percona-Server-5.5.12-rel20.3/sql/mysqld[0x8e791a]
/root/Percona-Server-5.5.12-rel20.3/sql/mysqld(_ZN7handler12ha_write_rowEPh+0x53)[0x727835]
/root/Percona-Server-5.5.12-rel20.3/sql/mysqld(_Z12write_recordP3THDP5TABLEP12st_copy_info+0xaa7)[0x5acb3f]
/root/Percona-Server-5.5.12-rel20.3/sql/mysqld(_Z12mysql_insertP3THDP10TABLE_LISTR4ListI4ItemERS3_IS5_ES6_S6_15enum_duplicatesb+0xbb1)[0x5b1d85]
/root/Percona-Server-5.5.12-rel20.3/sql/mysqld(_Z21mysql_execute_commandP3THD+0x2527)[0x5c4e29]
/root/Percona-Server-5.5.12-rel20.3/sql/mysqld(_ZN13sp_instr_stmt9exec_coreEP3THDPj+0x1d)[0x82f533]
/root/Percona-Server-5.5.12-rel20.3/sql/mysqld(_ZN13sp_lex_keeper23reset_lex_and_exec_coreEP3THDPjbP8sp_instr+0x16a)[0x82ff00]
/root/Percona-Server-5.5.12-rel20.3/sql/mysqld(_ZN13sp_instr_stmt7executeEP3THDPj+0x193)[0x830627]
/root/Percona-Server-5.5.12-rel20.3/sql/mysqld(_ZN7sp_head7executeEP3THDb+0x5be)[0x832b20]
/root/Percona-Server-5.5.12-rel20.3/sql/mysqld(_ZN7sp_head17execute_procedureEP3THDP4ListI4ItemE+0x880)[0x833994]
/root/Percona-Server-5.5.12-rel20.3/sql/mysqld(_Z21mysql_execute_commandP3THD+0x5e89)[0x5c878b]
/root/Percona-Server-5.5.12-rel20.3/sql/mysqld(_Z11mysql_parseP3THDPcjP12Parser_state+0x314)[0x5ca0d0]
/root/Percona-Server-5.5.12-rel20.3/sql/mysqld(_Z16dispatch_command19enum_server_commandP3THDPcj+0xb46)[0x5cbe94]
/root/Percona-Server-5.5.12-rel20.3/sql/mysqld(_Z10do_commandP3THD+0x2a4)[0x5cd3bc]
/root/Percona-Server-5.5.12-rel20.3/sql/mysqld(_Z24do_handle_one_connectionP3THD+0x5ae)[0x69db0c]
/root/Percona-Server-5.5.12-rel20.3/sql/mysqld(handle_one_connection+0x2d)[0x69dc25]
/root/Percona-Server-5.5.12-rel20.3/sql/mysqld(pfs_spawn_thread+0x92)[0x8d26f8]
/lib64/libpthread.so.0[0x4e2b73d]
/lib64/libc.so.6(clone+0x6d)[0x60eaf6d]

Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
Query (0x1304b960): insert into test1 set b=1
Connection ID (thread ID): 191
Status: NOT_KILLED

The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains
information that should help you find out what is causing the crash.
Writing a core file

Related branches

Changed in percona-projects-qa:
milestone: none → 5.5.12-20.3
description: updated
Revision history for this message
Oleg Tsarev (tsarev) wrote :
Download full text (3.8 KiB)

Bug was reproduced on Fedora x86_64 release vesrsion
oleg.tsarev (0) /storage/dev/percona/5.5.12/Percona-Server-release/mysql-test$ ./mysql-test-run main.percona_xtradb_bug317074 --valgrind
Logging: /storage/dev/percona/5.5.12/Percona-Server/mysql-test/mysql-test-run.pl main.percona_xtradb_bug317074 --valgrind
110602 18:25:11 [Note] Flashcache bypass: disabled
110602 18:25:11 [Note] Flashcache setup error is : open flash device failed

MySQL Version 5.5.12
Turning on valgrind for all executables
Running valgrind with options " --show-reachable=yes "
Checking supported features...
 - skipping ndbcluster
 - skipping SSL, mysqld not compiled with SSL
Collecting tests...
vardir: /storage/dev/percona/5.5.12/Percona-Server-release/mysql-test/var
Removing old var directory...
Creating var directory '/storage/dev/percona/5.5.12/Percona-Server-release/mysql-test/var'...
Installing system database...
Using server port 48481

==============================================================================

TEST RESULT TIME (ms) or COMMENT
--------------------------------------------------------------------------

worker[1] Using MTR_BUILD_THREAD 300, with reserved ports 13000..13009
main.percona_xtradb_bug317074 [ pass ] 255714
worker[1] Valgrind report from /storage/dev/percona/5.5.12/Percona-Server-release/mysql-test/var/log/mysqld.1.err after tests:
 main.percona_xtradb_bug317074
--------------------------------------------------------------------------
HEAP SUMMARY:
    in use at exit: 30,570,344 bytes in 207 blocks
  total heap usage: 1,464,025 allocs, 1,463,818 frees, 7,849,406,315 bytes allocated

128 bytes in 1 blocks are possibly lost in loss record 107 of 136
   at 0x4A05E46: malloc (vg_replace_malloc.c:195)
   by 0x932408: mem_area_alloc (mem0pool.c:385)
   by 0x93168E: mem_heap_create_block (mem0mem.c:333)
   by 0x89F23E: btr_search_sys_create (mem0mem.ic:443)
   by 0x8A9B23: buf_pool_init (buf0buf.c:1902)
   by 0x85D4DA: innobase_start_or_create_for_mysql (srv0start.c:1511)
   by 0x82068C: innobase_init(void*) (ha_innodb.cc:2858)
   by 0x688197: ha_initialize_handlerton(st_plugin_int*) (handler.cc:462)
   by 0x58A889: plugin_initialize(st_plugin_int*) (sql_plugin.cc:1063)
   by 0x58FA87: plugin_init(int*, char**, int) (sql_plugin.cc:1349)
   by 0x50EE25: init_server_components() (mysqld.cc:3962)
   by 0x51259C: mysqld_main(int, char**) (mysqld.cc:4634)
   by 0x37E701EE5C: (below main) (libc-start.c:226)

128 bytes in 1 blocks are definitely lost in loss record 109 of 136
   at 0x4A05E46: malloc (vg_replace_malloc.c:195)
   by 0x932408: mem_area_alloc (mem0pool.c:385)
   by 0x93168E: mem_heap_create_block (mem0mem.c:333)
   by 0x89F2CF: btr_search_sys_create (mem0mem.ic:443)
   by 0x8A9B23: buf_pool_init (buf0buf.c:1902)
   by 0x85D4DA: innobase_start_or_create_for_mysql (srv0start.c:1511)
   by 0x82068C: innobase_init(void*) (ha_innodb.cc:2858)
   by 0x688197: ha_initialize_handlerton(st_plugin_int*) (handler.cc:462)
   by 0x58A889: plugin_initialize(st_plugin_int*) (sql_plugin.cc:1063)
   by 0x58FA87: plugin_init(int*, char**, int) (sql_plugin.cc:1349)
   by 0x50EE25: init_server_components...

Read more...

Changed in percona-projects-qa:
status: New → Confirmed
status: Confirmed → Incomplete
status: Incomplete → In Progress
assignee: nobody → Oleg Tsarev (tsarev)
Revision history for this message
Oleg Tsarev (tsarev) wrote :

Please ignore previous comment

Revision history for this message
Oleg Tsarev (tsarev) wrote :
Download full text (3.8 KiB)

Bug was reproduced on Fedora 14, debug, x86_64. Please note - test work not quick, about 15 minutes before complete

oleg.tsarev (0) /storage/dev/percona/5.5.12/Percona-Server-debug/mysql-test$ ./mysql-test-run --valgrind main.percona_xtradb_bug317074
Logging: /storage/dev/percona/5.5.12/Percona-Server/mysql-test/mysql-test-run.pl --valgrind main.percona_xtradb_bug317074
110602 18:26:04 [Note] Flashcache bypass: disabled
110602 18:26:04 [Note] Flashcache setup error is : open flash device failed

MySQL Version 5.5.12
Turning on valgrind for all executables
Running valgrind with options " --show-reachable=yes "
Checking supported features...
 - skipping ndbcluster
 - skipping SSL, mysqld not compiled with SSL
 - binaries are debug compiled
Collecting tests...
vardir: /storage/dev/percona/5.5.12/Percona-Server-debug/mysql-test/var
Removing old var directory...
Creating var directory '/storage/dev/percona/5.5.12/Percona-Server-debug/mysql-test/var'...
Installing system database...
Using server port 39063

==============================================================================

TEST RESULT TIME (ms) or COMMENT
--------------------------------------------------------------------------

worker[1] Using MTR_BUILD_THREAD 301, with reserved ports 13010..13019
main.percona_xtradb_bug317074 [ pass ] 649544
worker[1] Valgrind report from /storage/dev/percona/5.5.12/Percona-Server-debug/mysql-test/var/log/mysqld.1.err after tests:
 main.percona_xtradb_bug317074
--------------------------------------------------------------------------
HEAP SUMMARY:
    in use at exit: 30,570,808 bytes in 214 blocks
  total heap usage: 1,566,908 allocs, 1,566,694 frees, 7,928,326,960 bytes allocated

128 bytes in 1 blocks are possibly lost in loss record 124 of 151
   at 0x4A05E46: malloc (vg_replace_malloc.c:195)
   by 0xA17C46: mem_heap_create_block (mem0mem.c:333)
   by 0x961605: btr_search_sys_create (mem0mem.ic:443)
   by 0x96F57F: buf_pool_init (buf0buf.c:1902)
   by 0x90585C: innobase_start_or_create_for_mysql (srv0start.c:1511)
   by 0x8A85D7: innobase_init(void*) (ha_innodb.cc:2858)
   by 0x6CD31A: ha_initialize_handlerton(st_plugin_int*) (handler.cc:462)
   by 0x5AC7E3: plugin_initialize(st_plugin_int*) (sql_plugin.cc:1063)
   by 0x5B1E36: plugin_init(int*, char**, int) (sql_plugin.cc:1349)
   by 0x5119EC: init_server_components() (mysqld.cc:3962)
   by 0x515B86: mysqld_main(int, char**) (mysqld.cc:4634)
   by 0x37E701EE5C: (below main) (libc-start.c:226)

128 bytes in 1 blocks are definitely lost in loss record 125 of 151
   at 0x4A05E46: malloc (vg_replace_malloc.c:195)
   by 0xA17C46: mem_heap_create_block (mem0mem.c:333)
   by 0x9616C4: btr_search_sys_create (mem0mem.ic:443)
   by 0x96F57F: buf_pool_init (buf0buf.c:1902)
   by 0x90585C: innobase_start_or_create_for_mysql (srv0start.c:1511)
   by 0x8A85D7: innobase_init(void*) (ha_innodb.cc:2858)
   by 0x6CD31A: ha_initialize_handlerton(st_plugin_int*) (handler.cc:462)
   by 0x5AC7E3: plugin_initialize(st_plugin_int*) (sql_plugin.cc:1063)
   by 0x5B1E36: plugin_init(int*, char**, int) (sql_plugin.cc:1349)
   by 0x5119EC: init_server_components() (mysq...

Read more...

Changed in percona-projects-qa:
status: In Progress → Confirmed
assignee: Oleg Tsarev (tsarev) → Stewart Smith (stewart)
Stewart Smith (stewart)
Changed in percona-projects-qa:
assignee: Stewart Smith (stewart) → nobody
Changed in percona-projects-qa:
assignee: nobody → Yasufumi Kinoshita (yasufumi-kinoshita)
Revision history for this message
Yasufumi Kinoshita (yasufumi-kinoshita) wrote :

I cannot reproduce.
I didn't find path in the source code to do so.

Is it real server? I think it may be hardware bug.

Changed in percona-projects-qa:
status: Confirmed → New
Revision history for this message
Oleg Tsarev (tsarev) wrote :

yes, this is real hardware (my lenovo laptop)

Revision history for this message
Yasufumi Kinoshita (yasufumi-kinoshita) wrote :

OK. give me several days to analyze more carefully.

Changed in percona-projects-qa:
status: New → Confirmed
Revision history for this message
Yasufumi Kinoshita (yasufumi-kinoshita) wrote :

Then, where and how to reproduce it for confirming when will try to fix ?

Revision history for this message
Yasufumi Kinoshita (yasufumi-kinoshita) wrote :

Oleg,

I mean
"InnoDB: Failing assertion: mutex_own(&buf_pool->zip_mutex)" crash.

Did you get crash at your PC?

I don't mean valgrind case.
You reported here is not related to the bug of this topic.

Revision history for this message
Oleg Tsarev (tsarev) wrote :

Yasufumi,

Sorry,
"InnoDB: Failing assertion: mutex_own(&buf_pool->zip_mutex)" crash.
not resproduced.
I'm not carefully read the valgrind output.
valgrind output in my comment - this is a bug:
https://bugs.launchpad.net/percona-projects-qa/+bug/791849
what already fixed.

Sorry for a worry.

Changed in percona-projects-qa:
status: Confirmed → Invalid
assignee: Yasufumi Kinoshita (yasufumi-kinoshita) → Valentine Gostev (longbow)
Revision history for this message
Yasufumi Kinoshita (yasufumi-kinoshita) wrote :

Oleg, I found the very little possibility to cause the crash, yesterday, through the careful reviewing of the source code.

So, I'd like to revive this bug for now, even if it cannot reproduce easily.

Changed in percona-projects-qa:
assignee: Valentine Gostev (longbow) → Yasufumi Kinoshita (yasufumi-kinoshita)
importance: Undecided → High
status: Invalid → Confirmed
Changed in percona-projects-qa:
status: Confirmed → Fix Committed
Revision history for this message
Stewart Smith (stewart) wrote :

Move to be being tracked in Percona Server. Looks like heading for 5.5.13 ?

Changed in percona-server:
status: New → Fix Committed
importance: Undecided → High
assignee: nobody → Yasufumi Kinoshita (yasufumi-kinoshita)
milestone: none → 5.5.13-20.4
Changed in percona-projects-qa:
status: Fix Committed → Invalid
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-477

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.