Bug #59495 | rpl.rpl_read_old_relay_log_info fails intermittently in PB2 | ||
---|---|---|---|
Submitted: | 14 Jan 2011 8:44 | Modified: | 29 Jun 2011 13:27 |
Reporter: | Jørgen Løland | Email Updates: | |
Status: | Can't repeat | Impact on me: | |
Category: | MySQL Server: Replication | Severity: | S3 (Non-critical) |
Version: | 5.6 | OS: | Any |
Assigned to: | Alfranio Junior | CPU Architecture: | Any |
[14 Jan 2011 8:44]
Jørgen Løland
[14 Jan 2011 10:43]
Luis Soares
Symptom: rpl.rpl_read_old_relay_log_info w24 [ fail ] Test ended at 2011-01-13 18:42:38 CURRENT_TEST: rpl.rpl_read_old_relay_log_info mysqltest: At line 27: query 'START SLAVE IO_THREAD' failed: 1201: Could not initialize master info structure; more error messages can be found in the MySQL error log The result from queries just before the failure was: include/master-slave.inc [connection master] CREATE TABLE t1 (a INT); INSERT INTO t1 VALUES (1); DROP TABLE t1; ==== Check that we still understand the old format of relay-log.info ==== include/stop_slave.inc RESET SLAVE; # Read relay-log.info - saving '/tmp/mtr-29889/var-n_mix/24/log/rpl.rpl_read_old_relay_log_info/' to '/tmp/mtr-29889/var-n_mix/log/rpl.rpl_read_old_relay_log_info/' Retrying test rpl.rpl_read_old_relay_log_info, attempt(2/3)... In slave's error log, one finds: CURRENT_TEST: rpl.rpl_read_old_relay_log_info 110113 20:42:37 [Note] 'CHANGE MASTER TO executed'. Previous state master_host='127.0.0.1', master_port='21230', master_log_file='', master_log_pos='4', master_bind=''. New state master_host='127.0.0.1', master_port='21230', master_log_file='master-bin.000001', master_log_pos='4', master_bind=''. 110113 20:42:37 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000001' at position 4, relay log './slave-relay-bin.000002' position: 4 110113 20:42:37 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:21230',replication started in log 'master-bin.000001' at position 4 110113 20:42:38 [Note] Slave I/O thread killed while reading event 110113 20:42:38 [Note] Slave I/O thread exiting, read up to log 'master-bin.000001', position 529 110113 20:42:38 [Note] Error reading relay log event: slave SQL thread was killed 110113 20:42:38 [ERROR] Failed to open the relay log './slave-relay-bin.000001' (relay_log_pos 4) 110113 20:42:38 [ERROR] Could not find target log during relay log initialization CURRENT_TEST: rpl.rpl_read_old_relay_log_info 110113 20:42:41 [Warning] The syntax '--master-retry-count' is deprecated and will be removed in a future release. Please use 'CHANGE MASTER TO master_retry_count = <num>' instead. 110113 20:42:41 [Note] Plugin 'FEDERATED' is disabled. 110113 20:42:41 InnoDB: The InnoDB memory heap is disabled 110113 20:42:41 InnoDB: Mutexes and rw_locks use Solaris atomic functions 110113 20:42:41 InnoDB: Compressed tables use zlib 1.2.3 110113 20:42:41 InnoDB: Initializing buffer pool, size = 8.0M 110113 20:42:41 InnoDB: Completed initialization of buffer pool 110113 20:42:41 InnoDB: highest supported file format is Barracuda. 110113 20:42:41 InnoDB: 1.2.1 started; log sequence number 1595675 110113 20:42:41 [Warning] /export/home/pb2/test/sb_1-2793391-1294940277.84/mysql-5.6.2-m5-solaris10-sparc-64bit-test/bin/mysqld: unknown variable 'loose-debug-sync-timeout=300' 110113 20:42:41 [Warning] No existing UUID has been found, so we assume that this is the first time that this server has been started. Generating a new UUID: 853baca5-1f3c-11e0-be8b-8d4fe17fd5ae. 110113 20:42:41 [Note] Event Scheduler: Loaded 0 events 110113 20:42:41 [Note] /export/home/pb2/test/sb_1-2793391-1294940277.84/mysql-5.6.2-m5-solaris10-sparc-64bit-test/bin/mysqld: ready for connections. Version: '5.6.2-m5-log' socket: '/tmp/mtr-29889/var-n_mix/tmp/24/mysqld.2.sock' port: 21231 Source distribution 110113 20:42:43 [Note] 'CHANGE MASTER TO executed'. Previous state master_host='', master_port='3306', master_log_file='', master_log_pos='4', master_bind=''. New state master_host='127.0.0.1', master_port='21230', master_log_file='master-bin.000001', master_log_pos='4', master_bind=''. 110113 20:42:43 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000001' at position 4, relay log './slave-relay-bin.000001' position: 4 110113 20:42:43 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:21230',replication started in log 'master-bin.000001' at position 4 110113 20:42:43 [Note] Slave I/O thread killed while reading event 110113 20:42:43 [Note] Slave I/O thread exiting, read up to log 'master-bin.000001', position 529 110113 20:42:43 [Note] Error reading relay log event: slave SQL thread was killed 110113 20:42:43 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:21230',replication started in log 'FIRST' at position 4 110113 20:42:43 [Note] Slave I/O thread killed while reading event 110113 20:42:43 [Note] Slave I/O thread exiting, read up to log 'master-bin.000001', position 529 110113 20:42:47 [Note] /export/home/pb2/test/sb_1-2793391-1294940277.84/mysql-5.6.2-m5-solaris10-sparc-64bit-test/bin/mysqld: Normal shutdown 110113 20:42:47 [Note] Event Scheduler: Purging the queue. 0 events 110113 20:42:47 InnoDB: Starting shutdown... 110113 20:42:48 InnoDB: Shutdown completed; log sequence number 1595675 110113 20:42:48 [Note] /export/home/pb2/test/sb_1-2793391-1294940277.84/mysql-5.6.2-m5-solaris10-sparc-64bit-test/bin/mysqld: Shutdown complete CURRENT_TEST: rpl.rpl_read_old_relay_log_info (...) Logs taken form failure: http://pb2.norway.sun.com/web.py?template=mysql_show_test_failure&search=yes&push_id=19042...
[28 Jan 2011 1:23]
Alfranio Junior
The problem was introduced while developing WL#344 and the failure popped up in the development tree used to hold the WL: http://pb2.norway.sun.com/?template=mysql_show_test_failure&test_failure_id=&test_output_i... The test case fails because the START SLAVE IO_THREAD fails while opening a relay log, although it exists: 110104 14:14:15 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000001' at position 4, relay log './slave-relay-bin.000003' position: 4 110104 14:14:15 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:20010',replication started in log 'master-bin.000001' at position 4 110104 14:14:16 [Note] Slave I/O thread killed while reading event 110104 14:14:16 [Note] Slave I/O thread exiting, read up to log 'master-bin.000001', position 516 110104 14:14:16 [Note] Error reading relay log event: slave SQL thread was killed 110104 14:14:16 [ERROR] Failed to open the relay log './slave-relay-bin.000001' (relay_log_pos 4) One can find a tar-ball with the error files at http://trollheim.norway.sun.com/archive/2732162.mysql-5.6.2-m5-solaris10-sparc-64bit-test....
[28 Jan 2011 1:32]
Alfranio Junior
The test only fails on Solaris.
[29 Jun 2011 13:27]
Jon Stephens
Not enough information was provided for us to be able to handle this bug. Please re-read the instructions at http://bugs.mysql.com/how-to-report.php If you can provide more information, feel free to add it to this bug and change the status back to 'Open'. Thank you for your interest in MySQL.