Logging: /home/laurynas/percona/upstream/5.5/mysql-test/mysql-test-run.pl --valgrind-mysqld rpl_heartbeat_basic MySQL Version 5.5.15 Turning on valgrind for mysqld(s) only 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... - adding combinations for rpl vardir: /home/laurynas/percona/upstream/5.5/obj/mysql-test/var Checking leftover processes... Removing old var directory... Creating var directory '/home/laurynas/percona/upstream/5.5/obj/mysql-test/var'... Installing system database... Using server port 47674 ============================================================================== TEST RESULT TIME (ms) or COMMENT -------------------------------------------------------------------------- worker[1] Using MTR_BUILD_THREAD 300, with reserved ports 13000..13009 rpl.rpl_heartbeat_basic 'mix' [ fail ] Found warnings/errors in server log file! Test ended at 2011-06-17 13:27:54 line ==1867== Thread 17: ==1867== Conditional jump or move depends on uninitialised value(s) ==1867== at 0x5256E40: inflateReset2 (in /lib/libz.so.1.2.3.4) ==1867== by 0x5256F2F: inflateInit2_ (in /lib/libz.so.1.2.3.4) ==1867== by 0x5251648: uncompress (in /lib/libz.so.1.2.3.4) ==1867== by 0x8DC1D1: my_uncompress (my_compress.c:122) ==1867== by 0x534EBC: my_net_read (net_serv.cc:1135) ==1867== by 0x716AAD: cli_safe_read (client.c:735) ==1867== by 0x71CA65: cli_read_query_result (client.c:3765) ==1867== by 0x71CF4E: mysql_real_query (client.c:3852) ==1867== by 0x549C5C: get_master_version_and_clock(st_mysql*, Master_info*) (slave.cc:1350) ==1867== by 0x54EA2F: handle_slave_io (slave.cc:2811) ==1867== by 0x90D840: pfs_spawn_thread (pfs.cc:1015) ==1867== by 0x4E35970: start_thread (pthread_create.c:304) ==1867== by 0x636192C: clone (clone.S:112) ^ Found warnings in /home/laurynas/percona/upstream/5.5/obj/mysql-test/var/log/mysqld.2.err ok - saving '/home/laurynas/percona/upstream/5.5/obj/mysql-test/var/log/rpl.rpl_heartbeat_basic-mix/' to '/home/laurynas/percona/upstream/5.5/obj/mysql-test/var/log/rpl.rpl_heartbeat_basic-mix/' worker[1] Valgrind report from /home/laurynas/percona/upstream/5.5/obj/mysql-test/var/log/mysqld.2.err after tests: rpl.rpl_heartbeat_basic -------------------------------------------------------------------------- HEAP SUMMARY: in use at exit: 30,570,112 bytes in 199 blocks total heap usage: 36,597 allocs, 36,398 frees, 85,482,602 bytes allocated LEAK SUMMARY: definitely lost: 0 bytes in 0 blocks indirectly lost: 0 bytes in 0 blocks possibly lost: 0 bytes in 0 blocks still reachable: 0 bytes in 0 blocks suppressed: 30,570,112 bytes in 199 blocks For counts of detected and suppressed errors, rerun with: -v ERROR SUMMARY: 0 errors from 0 contexts (suppressed: 69 from 69) Memcheck, a memory error detector Copyright (C) 2002-2010, and GNU GPL'd, by Julian Seward et al. Using Valgrind-3.6.0.SVN-Debian and LibVEX; rerun with -h for copyright info Command: /home/laurynas/percona/upstream/5.5/obj/sql/mysqld --defaults-group-suffix=.2 --defaults-file=/home/laurynas/percona/upstream/5.5/obj/mysql-test/var/my.cnf --log-output=file --default-storage-engine=MyISAM --binlog-format=mixed --core-file --loose-debug-sync-timeout=300 110617 13:24:34 InnoDB: !!!!!!!! UNIV_DEBUG switched on !!!!!!!!! 110617 13:24:34 InnoDB: The InnoDB memory heap is disabled 110617 13:24:34 InnoDB: Mutexes and rw_locks use GCC atomic builtins 110617 13:24:34 InnoDB: Compressed tables use zlib 1.2.3.4 110617 13:24:34 InnoDB: Using Linux native AIO 110617 13:24:35 InnoDB: Initializing buffer pool, size = 8.0M 110617 13:24:35 InnoDB: Completed initialization of buffer pool 110617 13:24:35 InnoDB: highest supported file format is Barracuda. 110617 13:24:40 InnoDB: Waiting for the background threads to start 110617 13:24:41 InnoDB: 1.1.8 started; log sequence number 1595675 110617 13:24:43 [Note] Event Scheduler: Loaded 0 events 110617 13:24:43 [Note] /home/laurynas/percona/upstream/5.5/obj/sql/mysqld: ready for connections. Version: '5.5.15-debug-log' socket: '/home/laurynas/percona/upstream/5.5/obj/mysql-test/var/tmp/mysqld.2.sock' port: 13001 Source distribution 110617 13:24:45 [Note] 'CHANGE MASTER TO executed'. Previous state master_host='127.0.0.1', master_port='13000', master_log_file='', master_log_pos='4'. New state master_host='127.0.0.1', master_port='13000', master_log_file='', master_log_pos='4'. 110617 13:24:45 [Note] Slave SQL thread initialized, starting replication in log 'FIRST' at position 0, relay log './slave-relay-bin.000001' position: 4 110617 13:24:45 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:13000',replication started in log 'FIRST' at position 4 110617 13:24:48 [Note] Error reading relay log event: slave SQL thread was killed 110617 13:24:48 [ERROR] Error reading packet from server: Lost connection to MySQL server during query ( server_errno=2013) 110617 13:24:48 [Note] Slave I/O thread killed while reading event 110617 13:24:48 [Note] Slave I/O thread exiting, read up to log 'master-bin.000001', position 107 110617 13:24:49 [Note] 'CHANGE MASTER TO executed'. Previous state master_host='127.0.0.1', master_port='13000', master_log_file='', master_log_pos='4'. New state master_host='127.0.0.1', master_port='13000', master_log_file='', master_log_pos='4'. 110617 13:24:50 [Note] 'CHANGE MASTER TO executed'. Previous state master_host='127.0.0.1', master_port='13000', master_log_file='', master_log_pos='4'. New state master_host='127.0.0.1', master_port='13000', master_log_file='', master_log_pos='4'. 110617 13:24:51 [Note] 'CHANGE MASTER TO executed'. Previous state master_host='127.0.0.1', master_port='13000', master_log_file='', master_log_pos='4'. New state master_host='127.0.0.1', master_port='13000', master_log_file='', master_log_pos='4'. 110617 13:24:51 [Note] 'CHANGE MASTER TO executed'. Previous state master_host='127.0.0.1', master_port='13000', master_log_file='', master_log_pos='4'. New state master_host='127.0.0.1', master_port='13000', master_log_file='', master_log_pos='4'. 110617 13:24:51 [Note] Slave SQL thread initialized, starting replication in log 'FIRST' at position 0, relay log './slave-relay-bin.000001' position: 4 110617 13:24:51 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:13000',replication started in log 'FIRST' at position 4 110617 13:24:52 [Note] Error reading relay log event: slave SQL thread was killed 110617 13:24:52 [Note] Slave I/O thread exiting, read up to log 'master-bin.000001', position 107 Warning: invalid file descriptor -1 in syscall write() 110617 13:24:54 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000001' at position 107, relay log './slave-relay-bin.000002' position: 254 110617 13:24:54 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:13000',replication started in log 'master-bin.000001' at position 107 110617 13:24:55 [ERROR] Error reading packet from server: Lost connection to MySQL server during query ( server_errno=2013) 110617 13:24:55 [Note] Slave I/O thread killed while reading event 110617 13:24:55 [Note] Slave I/O thread exiting, read up to log 'master-bin.000001', position 107 110617 13:24:57 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:13000',replication started in log 'master-bin.000001' at position 107 110617 13:24:58 [Note] Error reading relay log event: slave SQL thread was killed 110617 13:25:00 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000001' at position 107, relay log './slave-relay-bin.000004' position: 254 110617 13:25:02 [ERROR] Slave SQL: Error 'Duplicate entry '1' for key 'PRIMARY'' on query. Default database: 'test'. Query: 'INSERT INTO t1 VALUES (1, 'on master', NULL)', Error_code: 1062 110617 13:25:02 [Warning] Slave: Duplicate entry '1' for key 'PRIMARY' Error_code: 1062 110617 13:25:02 [ERROR] Error running query, slave SQL thread aborted. Fix the problem, and restart the slave SQL thread with "SLAVE START". We stopped at log 'master-bin.000001' position 232 110617 13:25:05 [ERROR] Error reading packet from server: Lost connection to MySQL server during query ( server_errno=2013) 110617 13:25:05 [Note] Slave I/O thread killed while reading event 110617 13:25:05 [Note] Slave I/O thread exiting, read up to log 'master-bin.000001', position 476 110617 13:25:06 [Note] 'CHANGE MASTER TO executed'. Previous state master_host='127.0.0.1', master_port='13000', master_log_file='', master_log_pos='4'. New state master_host='127.0.0.1', master_port='13000', master_log_file='', master_log_pos='4'. 110617 13:25:06 [Note] Slave SQL thread initialized, starting replication in log 'FIRST' at position 0, relay log './slave-relay-bin.000001' position: 4 110617 13:25:06 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:13000',replication started in log 'FIRST' at position 4 110617 13:25:11 [Note] Error reading relay log event: slave SQL thread was killed 110617 13:25:11 [ERROR] Error reading packet from server: Lost connection to MySQL server during query ( server_errno=2013) 110617 13:25:11 [Note] Slave I/O thread killed while reading event 110617 13:25:11 [Note] Slave I/O thread exiting, read up to log 'master-bin.000001', position 2184 110617 13:25:12 [Note] 'CHANGE MASTER TO executed'. Previous state master_host='127.0.0.1', master_port='13000', master_log_file='', master_log_pos='4'. New state master_host='127.0.0.1', master_port='13000', master_log_file='', master_log_pos='4'. 110617 13:25:12 [Note] Slave SQL thread initialized, starting replication in log 'FIRST' at position 0, relay log './slave-relay-bin.000001' position: 4 110617 13:25:12 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:13000',replication started in log 'FIRST' at position 4 110617 13:26:08 [Note] Error reading relay log event: slave SQL thread was killed 110617 13:26:08 [ERROR] Error reading packet from server: Lost connection to MySQL server during query ( server_errno=2013) 110617 13:26:08 [Note] Slave I/O thread killed while reading event 110617 13:26:08 [Note] Slave I/O thread exiting, read up to log 'master-bin.000001', position 107 110617 13:26:09 [Note] 'CHANGE MASTER TO executed'. Previous state master_host='127.0.0.1', master_port='13000', master_log_file='', master_log_pos='4'. New state master_host='127.0.0.1', master_port='13000', master_log_file='', master_log_pos='4'. 110617 13:26:09 [Note] Slave SQL thread initialized, starting replication in log 'FIRST' at position 0, relay log './slave-relay-bin.000001' position: 4 110617 13:26:09 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:13000',replication started in log 'FIRST' at position 4 Thread 17: Conditional jump or move depends on uninitialised value(s) at 0x5256E40: inflateReset2 (in /lib/libz.so.1.2.3.4) by 0x5256F2F: inflateInit2_ (in /lib/libz.so.1.2.3.4) by 0x5251648: uncompress (in /lib/libz.so.1.2.3.4) by 0x8DC1D1: my_uncompress (my_compress.c:122) by 0x534EBC: my_net_read (net_serv.cc:1135) by 0x716AAD: cli_safe_read (client.c:735) by 0x71CA65: cli_read_query_result (client.c:3765) by 0x71CF4E: mysql_real_query (client.c:3852) by 0x549C5C: get_master_version_and_clock(st_mysql*, Master_info*) (slave.cc:1350) by 0x54EA2F: handle_slave_io (slave.cc:2811) by 0x90D840: pfs_spawn_thread (pfs.cc:1015) by 0x4E35970: start_thread (pthread_create.c:304) by 0x636192C: clone (clone.S:112) 110617 13:26:10 [Note] Error reading relay log event: slave SQL thread was killed 110617 13:26:10 [ERROR] Error reading packet from server: Lost connection to MySQL server during query ( server_errno=2013) 110617 13:26:10 [Note] Slave I/O thread killed while reading event 110617 13:26:10 [Note] Slave I/O thread exiting, read up to log 'master-bin.000001', position 107 110617 13:26:10 [Note] 'CHANGE MASTER TO executed'. Previous state master_host='127.0.0.1', master_port='13000', master_log_file='', master_log_pos='4'. New state master_host='127.0.0.1', master_port='13000', master_log_file='', master_log_pos='4'. 110617 13:26:10 [Note] Slave SQL thread initialized, starting replication in log 'FIRST' at position 0, relay log './slave-relay-bin.000001' position: 4 110617 13:26:10 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:13000',replication started in log 'FIRST' at position 4 110617 13:26:13 [Note] Error reading relay log event: slave SQL thread was killed 110617 13:26:13 [ERROR] Error reading packet from server: Lost connection to MySQL server during query ( server_errno=2013) 110617 13:26:13 [Note] Slave I/O thread killed while reading event 110617 13:26:13 [Note] Slave I/O thread exiting, read up to log 'master-bin.000001', position 107 110617 13:26:14 [Note] 'CHANGE MASTER TO executed'. Previous state master_host='127.0.0.1', master_port='13000', master_log_file='', master_log_pos='4'. New state master_host='127.0.0.1', master_port='13000', master_log_file='', master_log_pos='4'. 110617 13:26:14 [Note] Slave SQL thread initialized, starting replication in log 'FIRST' at position 0, relay log './slave-relay-bin.000001' position: 4 110617 13:26:14 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:13000',replication started in log 'FIRST' at position 4 110617 13:26:14 [Note] Slave: received end packet from server, apparent master shutdown: 110617 13:26:14 [Note] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'master-bin.000001' at position 107 110617 13:26:14 [ERROR] Slave I/O: error reconnecting to master 'root@127.0.0.1:13000' - retry-time: 20 retries: 10, Error_code: 2003 110617 13:26:35 [Note] Slave: connected to master 'root@127.0.0.1:13000',replication resumed in log 'master-bin.000001' at position 107 110617 13:26:36 [Note] Error reading relay log event: slave SQL thread was killed 110617 13:26:36 [ERROR] Error reading packet from server: Lost connection to MySQL server during query ( server_errno=2013) 110617 13:26:36 [Note] Slave I/O thread killed while reading event 110617 13:26:36 [Note] Slave I/O thread exiting, read up to log 'master-bin.000002', position 107 110617 13:26:37 [Note] Slave SQL thread initialized, starting replication in log 'FIRST' at position 0, relay log './slave-relay-bin.000001' position: 4 110617 13:26:37 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:13000',replication started in log 'FIRST' at position 4 110617 13:26:37 [Note] Error reading relay log event: slave SQL thread was killed 110617 13:26:38 [ERROR] Error reading packet from server: Lost connection to MySQL server during query ( server_errno=2013) 110617 13:26:38 [Note] Slave I/O thread killed while reading event 110617 13:26:38 [Note] Slave I/O thread exiting, read up to log 'master-bin.000001', position 107 110617 13:26:39 [Note] Start binlog_dump to slave_server(1), pos(slave-bin.000001, 4) 110617 13:26:40 [Note] 'CHANGE MASTER TO executed'. Previous state master_host='127.0.0.1', master_port='13000', master_log_file='master-bin.000001', master_log_pos='107'. New state master_host='127.0.0.1', master_port='13000', master_log_file='master-bin.000001', master_log_pos='107'. 110617 13:26:40 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000001' at position 107, relay log './slave-relay-bin.000001' position: 4 110617 13:26:40 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:13000',replication started in log 'master-bin.000001' at position 107 110617 13:27:41 [Note] master sends heartbeat message 110617 13:27:42 [Note] Error reading relay log event: slave SQL thread was killed 110617 13:27:42 [Note] Slave I/O thread exiting, read up to log 'master-bin.000001', position 797 Warning: invalid file descriptor -1 in syscall write() 110617 13:27:52 [Note] /home/laurynas/percona/upstream/5.5/obj/sql/mysqld: Normal shutdown 110617 13:27:52 [Note] Event Scheduler: Purging the queue. 0 events 110617 13:27:52 InnoDB: Starting shutdown... 110617 13:27:54 InnoDB: Shutdown completed; log sequence number 1595675 110617 13:27:54 [Note] Debug sync points hit: 10233 110617 13:27:54 [Note] Debug sync points executed: 0 110617 13:27:54 [Note] Debug sync points max active per thread: 0 110617 13:27:54 [Note] /home/laurynas/percona/upstream/5.5/obj/sql/mysqld: Shutdown complete HEAP SUMMARY: in use at exit: 30,587,368 bytes in 553 blocks total heap usage: 82,308 allocs, 81,755 frees, 144,007,307 bytes allocated Thread 1: 768 bytes in 6 blocks are definitely lost in loss record 113 of 137 at 0x4C2815C: malloc (vg_replace_malloc.c:236) by 0x8E4D17: my_malloc (my_malloc.c:38) by 0x8BA1B1: init_dynamic_array2 (array.c:70) by 0x6EB274: MYSQLparse(void*) (sql_yacc.yy:1870) by 0x5DEAE6: parse_sql(THD*, Parser_state*, Object_creation_ctx*) (sql_parse.cc:7273) by 0x5DAF06: mysql_parse(THD*, char*, unsigned int, Parser_state*) (sql_parse.cc:5503) by 0x5CEC90: dispatch_command(enum_server_command, THD*, char*, unsigned int) (sql_parse.cc:1034) by 0x5CDE6A: do_command(THD*) (sql_parse.cc:771) by 0x6BBFC5: do_handle_one_connection(THD*) (sql_connect.cc:787) by 0x6BBA80: handle_one_connection (sql_connect.cc:706) by 0x90D840: pfs_spawn_thread (pfs.cc:1015) by 0x4E35970: start_thread (pthread_create.c:304) by 0x636192C: clone (clone.S:112) LEAK SUMMARY: definitely lost: 768 bytes in 6 blocks indirectly lost: 0 bytes in 0 blocks possibly lost: 0 bytes in 0 blocks still reachable: 0 bytes in 0 blocks suppressed: 30,586,600 bytes in 547 blocks For counts of detected and suppressed errors, rerun with: -v Use --track-origins=yes to see where uninitialised values come from ERROR SUMMARY: 3 errors from 2 contexts (suppressed: 98 from 98) rpl.rpl_heartbeat_basic 'row' [ skipped ] Doesn't support --binlog-format='row' rpl.rpl_heartbeat_basic 'stmt' [ skipped ] Doesn't support --binlog-format='statement' valgrind_report [ fail ] Test ended at 2011-06-17 13:27:54 Valgrind reported failures at shutdown, see above -------------------------------------------------------------------------- The servers were restarted 0 times Spent 0.000 of 245 seconds executing testcases mysql-test-run: WARNING: Got errors/warnings while running tests, please examine '/home/laurynas/percona/upstream/5.5/obj/mysql-test/var/log/warnings' for details. Completed: Failed 2/2 tests, 0.00% were successful. Failing test(s): rpl.rpl_heartbeat_basic valgrind_report The log files in var/log may give you some hint of what went wrong. If you want to report this error, please read first the documentation at http://dev.mysql.com/doc/mysql/en/mysql-test-suite.html 2 tests were skipped, 0 by the test itself. mysql-test-run: *** ERROR: there were failing test cases