Uploaded image for project: 'Percona Server'
  1. Percona Server
  2. PS-2260

LP #1684078: Test rpl.rpl_server_uuid is unstable

    XMLWordPrintable

    Details

    • Type: Bug
    • Status: Done
    • Priority: Low
    • Resolution: Fixed
    • Affects Version/s: None
    • Fix Version/s: None
    • Component/s: None

      Description

      **Reported in Launchpad by Laurynas Biveinis last update 23-04-2017 18:06:43

      On 5.6 trunk:

      rpl.rpl_server_uuid 'mix' w3 [ fail ]
      Test ended at 2017-04-04 09:00:00

      CURRENT_TEST: rpl.rpl_server_uuid
      mysqltest: In included file "./include/assert_grep.inc":
      included from ./include/assert_grep.inc at line 150:
      At line 149: assert_grep.inc failed.
      ...

            • SHOW SLAVE STATUS on server_2 ****
              ...
              Slave_IO_Running No
              ...
              Last_IO_Errno 1236
              Last_IO_Error Got fatal error 1236 from master when reading data from binary log: 'A slave with the same server_uuid/server_id as this slave has connected to the master; the first event 'master-bin.000004' at 120, the last event read from './master-bin.000004' at 120, the last byte read from './master-bin.000004' at 120.'
              ...
            • SHOW SLAVE STATUS on server_3 ****
              SHOW SLAVE STATUS;
              Slave_IO_State Waiting for master to send event
              ...
            • SHOW PROCESSLIST on server_1 ****
              SHOW PROCESSLIST;
              Id User Host db Command Time State Info Rows_sent Rows_examined
              1 root localhost test Sleep 8 NULL 411 411
              2 root localhost:36026 test Sleep 7 NULL 1 0
              3 root localhost:36027 test Sleep 7 NULL 411 411
              4 root localhost:36036 test Query 0 init SHOW PROCESSLIST 0 0
              5 root localhost:36037 test Sleep 7 NULL 1 0
              11 root localhost:36209 NULL Binlog Dump 0 Master has sent all binlog to slave; waiting for binlog to be updated NULL 0 0
              ...
              include/assert_grep.inc failed!
              assert_text: 'Found the expected line in master's error log for server 2 disconnection'
              assert_file: '/mnt/workspace/percona-server-5.6-trunk/BUILD_TYPE/debug/Host/centos5-64/build/mysql-test/var/3/log/mysqld.1.err'
              assert_select: 'found a zombie dump thread with the same UUID'
              assert_match: ''
              assert_count: '1'
              assert_only_after: 'Start binlog_dump to master_thread_id(9)'
              number of matching lines: 2
              ...
              Server [mysqld.1 - pid: 18799, winpid: 18799] log:
              Server log from this test:
              ---------SERVER LOG START----------
              ...
              2017-04-04 15:59:53 18800 [Note] Start binlog_dump to master_thread_id(9) slave_server(2), pos(master-bin.000004, 120)
              2017-04-04 15:59:53 18800 [Note] While initializing dump thread for slave with UUID <80fa2b30-1936-11e7-bc99-525400e0d484>, found a zombie dump thread with the same UUID. Master is killing the zombie dump thread(9).
              2017-04-04 15:59:53 18800 [Note] Start binlog_dump to master_thread_id(10) slave_server(2), pos(master-bin.000004, 120)
              2017-04-04 16:00:00 18800 [Note] While initializing dump thread for slave with UUID <80fa2b30-1936-11e7-bc99-525400e0d484>, found a zombie dump thread with the same UUID. Master is killing the zombie dump thread(10).
              2017-04-04 16:00:00 18800 [Note] Start binlog_dump to master_thread_id(11) slave_server(3), pos(master-bin.000003, 120)
              ---------SERVER LOG END------------

      Server [mysqld.2 - pid: 17691, winpid: 17691] log:
      Server log from this test:
      ---------SERVER LOG START----------
      ...
      2017-04-04 15:59:53 17692 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:13021',replication started in log 'master-bin.000004' at position 120
      2017-04-04 15:59:53 17692 [Warning] Slave SQL: If a crash happens this configuration does not guarantee that the relay log info will be consistent, Error_code: 0
      2017-04-04 15:59:53 17692 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000004' at position 120, relay log './slave-relay-bin.000001' position: 4
      2017-04-04 16:00:00 17692 [ERROR] Error reading packet from server: A slave with the same server_uuid/server_id as this slave has connected to the master; the first event 'master-bin.000004' at 120, the last event read from './master-bin.000004' at 120, the last byte read from './master-bin.000004' at 120. (server_errno=1236)
      2017-04-04 16:00:00 17692 [ERROR] Slave I/O: Got fatal error 1236 from master when reading data from binary log: 'A slave with the same server_uuid/server_id as this slave has connected to the master; the first event 'master-bin.000004' at 120, the last event read from './master-bin.000004' at 120, the last byte read from './master-bin.000004' at 120.', Error_code: 1236
      2017-04-04 16:00:00 17692 [Note] Slave I/O thread exiting, read up to log 'master-bin.000004', position 120
      ---------SERVER LOG END------------

      Server [mysqld.3 - pid: 19039, winpid: 19039] log:
      Server log from this test:
      ---------SERVER LOG START----------
      ...
      2017-04-04 16:00:00 19040 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:13021',replication started in log 'master-bin.000003' at position 120

        Smart Checklist

          Attachments

            Activity

              People

              • Assignee:
                Unassigned
                Reporter:
                lpjirasync lpjirasync (Inactive)
              • Votes:
                0 Vote for this issue
                Watchers:
                1 Start watching this issue

                Dates

                • Created:
                  Updated:
                  Resolved: