Bug #47566 | rpl.rpl_semi_sync fails sporadically | ||
---|---|---|---|
Submitted: | 23 Sep 2009 19:06 | Modified: | 30 Sep 2009 7:03 |
Reporter: | Alexander Nozdrin | Email Updates: | |
Status: | Duplicate | Impact on me: | |
Category: | Tests: Replication | Severity: | S3 (Non-critical) |
Version: | 6.0 | OS: | Any |
Assigned to: | Assigned Account | CPU Architecture: | Any |
Tags: | experimental, pb2, sporadic, test failure |
[23 Sep 2009 19:06]
Alexander Nozdrin
[30 Sep 2009 7:03]
Zhenxing He
Dup of bug#45852
[7 Dec 2009 2:27]
Luis Soares
There is also a failure in mysql-pe. Failure context: Where Build Test Run Suite Case Mode When mysql-pe 739652 binary-max-ubuntu-x86_64-tar-gz 739711 loki38 test-max-ubuntu-x86_64 739992 tyr20 n_mix rpl rpl_semi_sync None 2009-12-05 23:32:41 Failure symptom: rpl.rpl_semi_sync [ fail ] Test ended at 2009-12-06 07:40:18 CURRENT_TEST: rpl.rpl_semi_sync === SHOW MASTER STATUS === ---- 1. ---- File slave-bin.000001 Position 108062 Binlog_Do_DB Binlog_Ignore_DB ========================== === SHOW SLAVE STATUS === ---- 1. ---- Slave_IO_State Master_Host 127.0.0.1 Master_User rpl Master_Port 13010 Connect_Retry 1 Master_Log_File master-bin.000001 Read_Master_Log_Pos 840 Relay_Log_File slave-relay-bin.000004 Relay_Log_Pos 438 Relay_Master_Log_File master-bin.000001 Slave_IO_Running No Slave_SQL_Running Yes Replicate_Do_DB Replicate_Ignore_DB Replicate_Do_Table Replicate_Ignore_Table Replicate_Wild_Do_Table Replicate_Wild_Ignore_Table Last_Errno 0 Last_Error Skip_Counter 0 Exec_Master_Log_Pos 840 Relay_Log_Space 924 Until_Condition None Until_Log_File Until_Log_Pos 0 Master_SSL_Allowed No Master_SSL_CA_File Master_SSL_CA_Path Master_SSL_Cert Master_SSL_Cipher Master_SSL_Key Seconds_Behind_Master Master_SSL_Verify_Server_Cert No Last_IO_Errno 0 Last_IO_Error Last_SQL_Errno 0 Last_SQL_Error Replicate_Ignore_Server_Ids Master_Server_Id 1 ========================= === SHOW PROCESSLIST === ---- 1. ---- Id 2 User root Host localhost:37995 db test Command Query Time 0 State Info SHOW PROCESSLIST ---- 2. ---- Id 3 User root Host localhost:37996 db test Command Sleep Time 330 State Info ---- 3. ---- Id 25 User system user Host db Command Connect Time 300 State Slave has read all relay log; waiting for the slave I/O thread to update it Info ======================== analyze: sync_with_master mysqltest: At line 583: sync_slave_with_master failed: 'select master_pos_wait('master-bin.000001', 916, 300)' returned -1 indicating timeout after 300 seconds The result from queries just before the failure was: < snip > SHOW VARIABLES LIKE 'rpl_semi_sync_slave_enabled'; Variable_name Value rpl_semi_sync_slave_enabled OFF SHOW STATUS LIKE 'Rpl_semi_sync_slave_status'; Variable_name Value Rpl_semi_sync_slave_status OFF include/start_slave.inc SHOW STATUS LIKE 'Rpl_semi_sync_slave_status'; Variable_name Value Rpl_semi_sync_slave_status OFF # # Clean up # include/stop_slave.inc UNINSTALL PLUGIN rpl_semi_sync_slave; UNINSTALL PLUGIN rpl_semi_sync_master; Warnings: Warning 1620 Plugin is busy and will be uninstalled on shutdown include/start_slave.inc drop table t1; More results from queries before failure can be found in /export/home2/pb2/test/sb_1-1043204-1260080501.89/mysql-6.0.14-alpha-linux-x86_64-test/mysql-test/var/log/rpl_semi_sync.log == /export/home2/pb2/test/sb_1-1043204-1260080501.89/mysql-6.0.14-alpha-linux-x86_64-test/mysql-test/var/tmp/analyze-sync_with_master-mysqld.1.err == SHOW PROCESSLIST; Id User Host db Command Time State Info 14 rpl localhost:39940 NULL Binlog Dump 300 NULL NULL 26 root localhost NULL Query 0 NULL SHOW PROCESSLIST SHOW BINLOG EVENTS IN 'master-bin.000001'; Log_name Pos Event_type Server_id End_log_pos Info master-bin.000001 4 Format_desc 1 107 Server ver: 6.0.14-alpha-log, Binlog ver: 4 master-bin.000001 107 Query 1 175 BEGIN master-bin.000001 175 Query 1 263 use `test`; insert into t1 values (4) master-bin.000001 263 Xid 1 290 COMMIT /* xid=952 */ master-bin.000001 290 Query 1 358 BEGIN master-bin.000001 358 Query 1 446 use `test`; insert into t1 values (5) master-bin.000001 446 Xid 1 473 COMMIT /* xid=953 */ master-bin.000001 473 Query 1 541 BEGIN master-bin.000001 541 Query 1 629 use `test`; insert into t1 values (8) master-bin.000001 629 Xid 1 656 COMMIT /* xid=974 */ master-bin.000001 656 Query 1 724 BEGIN master-bin.000001 724 Query 1 813 use `test`; insert into t1 values (10) master-bin.000001 813 Xid 1 840 COMMIT /* xid=993 */ master-bin.000001 840 Query 1 916 use `test`; drop table t1 == /export/home2/pb2/test/sb_1-1043204-1260080501.89/mysql-6.0.14-alpha-linux-x86_64-test/mysql-test/var/tmp/analyze-sync_with_master-mysqld.2.err == SHOW PROCESSLIST; Id User Host db Command Time State Info 25 system user NULL Connect 300 Slave has read all relay log; waiting for the slave I/O thread to update it NULL 26 root localhost NULL Query 0 NULL SHOW PROCESSLIST SHOW BINLOG EVENTS IN 'slave-bin.000001'; Log_name Pos Event_type Server_id End_log_pos Info slave-bin.000001 4 Format_desc 2 107 Server ver: 6.0.14-alpha-log, Binlog ver: 4 slave-bin.000001 107 Query 1 313 use `mtr`; INSERT INTO test_suppressions (pattern) VALUES ( NAME_CONST('pattern',_latin1'Timeout waiting for reply of binlog' COLLATE 'latin1_swedish_ci')) slave-bin.000001 313 Query 2 524 use `mtr`; INSERT INTO test_suppressions (pattern) VALUES ( NAME_CONST('pattern',_latin1'Master server does not support semi-sync' COLLATE 'latin1_swedish_ci')) slave-bin.000001 524 Query 1 715 use `mtr`; INSERT INTO test_suppressions (pattern) VALUES ( NAME_CONST('pattern',_latin1'Read semi-sync reply' COLLATE 'latin1_swedish_ci')) slave-bin.000001 715 Query 2 910 use `mtr`; INSERT INTO test_suppressions (pattern) VALUES ( NAME_CONST('pattern',_latin1'Semi-sync slave .* reply' COLLATE 'latin1_swedish_ci')) slave-bin.000001 910 Query 1 1011 use `test`; create table t1(a int) engine = InnoDB slave-bin.000001 1011 Query 1 1070 BEGIN slave-bin.000001 1070 Query 1 1160 use `test`; insert into t1 values (300) slave-bin.000001 1160 Xid 1 1187 COMMIT /* xid=73 */ slave-bin.000001 1187 Query 1 1246 BEGIN slave-bin.000001 1246 Query 1 1336 use `test`; insert into t1 values (299) slave-bin.000001 1336 Xid 1 1363 COMMIT /* xid=75 */ slave-bin.000001 1363 Query 1 1422 BEGIN slave-bin.000001 1422 Query 1 1512 use `test`; insert into t1 values (298) slave-bin.000001 1512 Xid 1 1539 COMMIT /* xid=77 */ slave-bin.000001 1539 Query 1 1598 BEGIN slave-bin.000001 1598 Query 1 1688 use `test`; insert into t1 values (297) slave-bin.000001 1688 Xid 1 1715 COMMIT /* xid=79 */ slave-bin.000001 1715 Query 1 1774 BEGIN slave-bin.000001 1774 Query 1 1864 use `test`; insert into t1 values (296) slave-bin.000001 1864 Xid 1 1891 COMMIT /* xid=81 */ slave-bin.000001 1891 Query 1 1950 BEGIN slave-bin.000001 1950 Query 1 2040 use `test`; insert into t1 values (295) slave-bin.000001 2040 Xid 1 2067 COMMIT /* xid=83 */ slave-bin.000001 2067 Query 1 2126 BEGIN URL: http://pb2.norway.sun.com/web.py?template=mysql_show_test_failure&search=yes&push_id=73965... Push: http://pb2.norway.sun.com/web.py?template=push_details&push=739652
[7 Dec 2009 2:28]
Luis Soares
Ignore previous comment. This was meant for BUG#49492.