| Bug #56505 | rpl_events fails sporadically if MTR with --mysqld=--query-cache-size=1000000 | ||
|---|---|---|---|
| Submitted: | 2 Sep 2010 16:17 | Modified: | 13 Dec 2010 12:16 |
| Reporter: | Sveta Smirnova | Email Updates: | |
| Status: | Verified | Impact on me: | |
| Category: | Tests: Replication | Severity: | S3 (Non-critical) |
| Version: | 5.1, 5.6.1 | OS: | Any |
| Assigned to: | Assigned Account | CPU Architecture: | Any |
[2 Sep 2010 16:18]
Sveta Smirnova
More stack:
Using host libthread_db library "/lib64/libthread_db.so.1".
Core was generated by `/users/ssmirnova/blade12/src/mysql-5.1/sql/mysqld --defaults-group-suffix=.1 --'.
Program terminated with signal 6, Aborted.
#0 0x0000003429e0b002 in pthread_kill () from /lib64/libpthread.so.0
#0 0x0000003429e0b002 in pthread_kill () from /lib64/libpthread.so.0
#1 0x0000000000b28c5d in my_write_core (sig=6) at stacktrace.c:331
#2 0x0000000000697ca2 in handle_segfault (sig=6) at mysqld.cc:2606
#3 <signal handler called>
#4 0x0000003429230015 in raise () from /lib64/libc.so.6
#5 0x0000003429231980 in abort () from /lib64/libc.so.6
#6 0x0000003429229726 in __assert_fail () from /lib64/libc.so.6
#7 0x00000000008501a9 in query_cache_end_of_result (thd=dwarf2_read_address: Corrupted DWARF expression.
) at sql_cache.cc:1000
#8 0x0000000000898404 in sp_instr_stmt::execute (this=0x13221c18, thd=0x13219748, nextp=0x40bc6ba8) at sp_head.cc:2900
#9 0x000000000089433c in sp_head::execute (this=0x13220198, thd=0x13219748) at sp_head.cc:1280
#10 0x0000000000895fe6 in sp_head::execute_procedure (this=0x13220198, thd=0x13219748, args=0x40bc6f50) at sp_head.cc:2011
#11 0x00000000008b2176 in Event_job_data::execute (this=0x40bc6fe0, thd=0x13219748, drop=false) at event_data_objects.cc:1466
#12 0x00000000008aca43 in Event_worker_thread::run (this=0x40bc710f, thd=0x13219748, event=0x131a8ab0) at event_scheduler.cc:308
#13 0x00000000008ac8c0 in event_worker_thread (arg=0x131a8ab0) at event_scheduler.cc:265
#14 0x0000003429e061b5 in start_thread () from /lib64/libpthread.so.0
#15 0x00000034292cd39d in clone () from /lib64/libc.so.6
#16 0x0000000000000000 in ?? ()
Thread 8 (process 29802):
#0 0x00000034292c6952 in __select_nocancel () from /lib64/libc.so.6
#1 0x000000000069bc80 in handle_connections_sockets (arg=0x0) at mysqld.cc:5103
#2 0x000000000069b0a7 in main (argc=9, argv=0x7fff1b595178) at mysqld.cc:4587
Thread 7 (process 29805):
#0 0x0000003429e0da78 in do_sigwait () from /lib64/libpthread.so.0
#1 0x0000003429e0db1d in sigwait () from /lib64/libpthread.so.0
#2 0x0000000000698505 in signal_hand (arg=0x0) at mysqld.cc:2808
#3 0x0000003429e061b5 in start_thread () from /lib64/libpthread.so.0
#4 0x00000034292cd39d in clone () from /lib64/libc.so.6
#5 0x0000000000000000 in ?? ()
Thread 6 (process 30202):
#0 0x0000003429e0cb5b in __read_nocancel () from /lib64/libpthread.so.0
#1 0x0000000000b02544 in vio_read (vio=0x13194998, buf=0x1318eae8 "\001", size=4) at viosocket.c:44
#2 0x000000000068a08f in my_real_read (net=0x1320b150, complen=0x40a81fe8) at net_serv.cc:816
#3 0x000000000068a832 in my_net_read (net=0x1320b150) at net_serv.cc:1011
#4 0x00000000006a684d in do_command (thd=0x1320b068) at sql_parse.cc:830
#5 0x00000000006a4c43 in handle_one_connection (arg=0x1320b068) at sql_connect.cc:1136
#6 0x0000003429e061b5 in start_thread () from /lib64/libpthread.so.0
#7 0x00000034292cd39d in clone () from /lib64/libc.so.6
#8 0x0000000000000000 in ?? ()
Thread 5 (process 30203):
#0 0x0000000000b0e3c7 in _checkchunk (irem=0x131bbe70, filename=0xcae90c "handler.cc", lineno=171) at safemalloc.c:482
#1 0x0000000000b0e59e in _sanity (filename=0xcae90c "handler.cc", lineno=171) at safemalloc.c:527
#2 0x0000000000b0d5e0 in _mymalloc (size=8, filename=0xcae90c "handler.cc", lineno=171, MyFlags=16) at safemalloc.c:130
#3 0x00000000008bba93 in intern_plugin_lock (lex=0x131c3628, rc=0x1190668, sFile=0xcae90c "handler.cc", uLine=171) at sql_plugin.cc:644
#4 0x00000000008bbc5e in plugin_lock (thd=0x131c1bd8, ptr=0x40b021f8, sFile=0xcae90c "handler.cc", uLine=171) at sql_plugin.cc:667
#5 0x00000000007ecd79 in ha_lock_engine (thd=0x131c1bd8, hton=0x1312cd78) at handler.cc:171
#6 0x00000000007ecddb in ha_resolve_by_legacy_type (thd=0x131c1bd8, db_type=DB_TYPE_MYISAM) at handler.cc:194
#7 0x00000000007ece32 in ha_checktype (thd=0x131c1bd8, database_type=DB_TYPE_MYISAM, no_substitute=false, report_error=true) at handler.cc:210
#8 0x00000000008253cd in check_engine (thd=0x131c1bd8, table_name=0x131a5fb0 "t1", create_info=0x40b02740) at sql_table.cc:8091
#9 0x0000000000817f1a in mysql_create_table_no_lock (thd=0x131c1bd8, db=0x131a5fa8 "test", table_name=0x131a5fb0 "t1", create_info=0x40b02740, alter_info=0x40b03040, internal_tmp_table=false,
select_field_count=0) at sql_table.cc:3670
#10 0x0000000000819184 in mysql_create_table (thd=0x131c1bd8, db=0x131a5fa8 "test", table_name=0x131a5fb0 "t1", create_info=0x40b02740, alter_info=0x40b03040, internal_tmp_table=false,
select_field_count=0) at sql_table.cc:4075
#11 0x00000000006ab608 in mysql_execute_command (thd=0x131c1bd8) at sql_parse.cc:2786
#12 0x00000000006b558b in mysql_parse (thd=0x131c1bd8, rawbuf=0x131a5ee8 "CREATE TABLE test.t1(details CHAR(30))", length=38, found_semicolon=0x40b03eb0) at sql_parse.cc:6032
#13 0x00000000006a7aa3 in dispatch_command (command=COM_QUERY, thd=0x131c1bd8, packet=0x131e4b89 "CREATE TABLE test.t1(details CHAR(30))", packet_length=38) at sql_parse.cc:1260
#14 0x00000000006a6a06 in do_command (thd=0x131c1bd8) at sql_parse.cc:888
#15 0x00000000006a4c43 in handle_one_connection (arg=0x131c1bd8) at sql_connect.cc:1136
#16 0x0000003429e061b5 in start_thread () from /lib64/libpthread.so.0
#17 0x00000034292cd39d in clone () from /lib64/libc.so.6
#18 0x0000000000000000 in ?? ()
Current language: auto; currently c
Description: rpl.rpl_events fails sporadically if MTR started with option --mysqld=--query-cache-size=1000000 How to repeat: $./mtr --mysqld=--query-cache-size=1000000 rpl_events --repeat=100 Logging: ./mtr --mysqld=--query-cache-size=1000000 rpl_events --repeat=100 100902 18:10:26 [Note] Plugin 'FEDERATED' is disabled. 100902 18:10:26 [Note] Plugin 'ndbcluster' is disabled. MySQL Version 5.1.51 Checking supported features... - using ndbcluster when necessary, mysqld supports it - SSL connections supported - binaries are debug compiled Collecting tests... - adding combinations for rpl vardir: /users/ssmirnova/blade12/src/mysql-5.1/mysql-test/var Checking leftover processes... Removing old var directory... - WARNING: Using the 'mysql-test/var' symlink Creating var directory '/users/ssmirnova/blade12/src/mysql-5.1/mysql-test/var'... Installing system database... Using server port 48035 worker[1] Using MTR_BUILD_THREAD 300, with reserved ports 13000..13009 ============================================================================== TEST RESULT TIME (ms) ------------------------------------------------------------ rpl.rpl_events 'row' [ pass ] 378 rpl.rpl_events 'row' [ pass ] 362 rpl.rpl_events 'row' [ fail ] Test ended at 2010-09-02 18:10:29 CURRENT_TEST: rpl.rpl_events mysqltest: At line 55: query 'CREATE TABLE test.t1(details CHAR(30))' failed: 2013: Lost connection to MySQL server during query The result from queries just before the failure was: < snip > "Dropping event test.slave_terminate on the slave" DROP EVENT test.slave_terminate; "Creating event test.slave_terminate with DISABLE ON SLAVE on the slave" CREATE EVENT test.slave_terminate ON SCHEDULE EVERY 3 SECOND DISABLE ON SLAVE DO INSERT IGNORE INTO t1(c) VALUES (7, 'from slave_terminate'); "Checking event status on the slave" SELECT db, name, status, originator FROM mysql.event WHERE db = 'test' AND name = 'slave_terminate'; db name status originator test slave_terminate SLAVESIDE_DISABLED 2 "Dropping event test.slave_terminate on the slave" DROP EVENT test.slave_terminate; "Cleanup" DROP TABLE t1; CREATE TABLE t28953 (a INT); CREATE EVENT event1 ON SCHEDULE EVERY 1 YEAR DO BEGIN select * from t28953; END;| ALTER EVENT event1 RENAME TO event2; DROP EVENT event2; More results from queries before failure can be found in /users/ssmirnova/blade12/src/mysql-5.1/mysql-test/var/log/rpl_events.log Server [mysqld.1 - pid: 29801, winpid: 29801, exit: 256] failed during test run Server log from this test: 100902 19:10:28 [Note] Event Scheduler: scheduler thread started with id 28 mysqld: sql_cache.cc:1000: void query_cache_end_of_result(THD*): Assertion `0' failed. 100902 19:10:28 - 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=5 max_threads=151 threads_connected=6 It is possible that mysqld could use up to key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 60584 K bytes of memory Hope that's ok; if not, decrease some variables in the equation. thd: 0x13219748 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 = 0x40bc70ce thread_stack 0x40000 /users/ssmirnova/blade12/src/mysql-5.1/sql/mysqld(my_print_stacktrace+0x35)[0xb28bd9] /users/ssmirnova/blade12/src/mysql-5.1/sql/mysqld(handle_segfault+0x288)[0x697aa2] /lib64/libpthread.so.0[0x3429e0dd40] /lib64/libc.so.6(gsignal+0x35)[0x3429230015] /lib64/libc.so.6(abort+0x110)[0x3429231980] /lib64/libc.so.6(__assert_fail+0xf6)[0x3429229726] /users/ssmirnova/blade12/src/mysql-5.1/sql/mysqld(_Z25query_cache_end_of_resultP3THD+0x25c)[0x8501a9] /users/ssmirnova/blade12/src/mysql-5.1/sql/mysqld(_ZN13sp_instr_stmt7executeEP3THDPj+0x210)[0x898404] /users/ssmirnova/blade12/src/mysql-5.1/sql/mysqld(_ZN7sp_head7executeEP3THD+0x5e8)[0x89433c] /users/ssmirnova/blade12/src/mysql-5.1/sql/mysqld(_ZN7sp_head17execute_procedureEP3THDP4ListI4ItemE+0x74c)[0x895fe6] /users/ssmirnova/blade12/src/mysql-5.1/sql/mysqld(_ZN14Event_job_data7executeEP3THDb+0x46c)[0x8b2176] /users/ssmirnova/blade12/src/mysql-5.1/sql/mysqld(_ZN19Event_worker_thread3runEP3THDP28Event_queue_element_for_exec+0x177)[0x8aca43] /users/ssmirnova/blade12/src/mysql-5.1/sql/mysqld(event_worker_thread+0x37)[0x8ac8c0] /lib64/libpthread.so.0[0x3429e061b5] /lib64/libc.so.6(clone+0x6d)[0x34292cd39d] Trying to get some variables. Some pointers may be invalid and cause the dump to abort... thd->query at 0x1322a8c8 = select * from t28953 thd->thread_id=31 thd->killed=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 - saving '/users/ssmirnova/blade12/src/mysql-5.1/mysql-test/var/log/rpl.rpl_events-row/' to '/users/ssmirnova/blade12/src/mysql-5.1/mysql-test/var/log/rpl.rpl_events-row/' - found 'core.29802' (0/5)