slave doesn't report Seconds_Behind_Master when running slave_parallel_workers > 0

Bug #1654091 reported by Marcelo Altmann on 2017-01-04
10
This bug affects 2 people
Affects Status Importance Assigned to Milestone
MySQL Server
Unknown
Unknown
Percona Server moved to https://jira.percona.com/projects/PS
Status tracked in 5.7
5.5
Invalid
Undecided
Robert Golebiowski
5.6
Fix Released
Medium
Robert Golebiowski
5.7
Fix Released
Medium
Robert Golebiowski

Bug Description

Reported here too http://bugs.mysql.com/bug.php?id=84415

When running mysql with slave_parallel_workers > 0 , Seconds_Behind_Master from SHOW SLAVE STATUS doesn't report replication lag.

From SHOW PROCESSLIST, Id 3 is executing an event from 76 seconds ago

slave1 [localhost] {msandbox} ((none)) > SHOW PROCESSLIST;
+----+-------------+-----------+------+---------+------+---------------------------------------------+------------------+
| Id | User | Host | db | Command | Time | State | Info |
+----+-------------+-----------+------+---------+------+---------------------------------------------+------------------+
| 1 | system user | | NULL | Connect | 274 | Waiting for master to send event | NULL |
| 2 | system user | | NULL | Connect | 11 | Waiting for dependent transaction to commit | NULL |
| 4 | system user | | NULL | Connect | 76 | Executing event | NULL |
| 5 | system user | | NULL | Connect | 274 | Waiting for an event from Coordinator | NULL |
| 6 | system user | | NULL | Connect | 274 | Waiting for an event from Coordinator | NULL |
| 7 | system user | | NULL | Connect | 274 | Waiting for an event from Coordinator | NULL |
| 8 | system user | | NULL | Connect | 274 | Waiting for an event from Coordinator | NULL |
| 9 | system user | | NULL | Connect | 274 | Waiting for an event from Coordinator | NULL |
| 10 | system user | | NULL | Connect | 274 | Waiting for an event from Coordinator | NULL |
| 11 | system user | | NULL | Connect | 274 | Waiting for an event from Coordinator | NULL |
| 12 | system user | | NULL | Connect | 274 | Waiting for an event from Coordinator | NULL |
| 13 | system user | | NULL | Connect | 274 | Waiting for an event from Coordinator | NULL |
| 14 | system user | | NULL | Connect | 274 | Waiting for an event from Coordinator | NULL |
| 15 | system user | | NULL | Connect | 274 | Waiting for an event from Coordinator | NULL |
| 16 | system user | | NULL | Connect | 274 | Waiting for an event from Coordinator | NULL |
| 17 | system user | | NULL | Connect | 274 | Waiting for an event from Coordinator | NULL |
| 18 | system user | | NULL | Connect | 274 | Waiting for an event from Coordinator | NULL |
| 19 | system user | | NULL | Connect | 274 | Waiting for an event from Coordinator | NULL |
| 20 | msandbox | localhost | NULL | Query | 0 | starting | SHOW PROCESSLIST |
+----+-------------+-----------+------+---------+------+---------------------------------------------+------------------+
19 rows in set (0.00 sec)

But SHOW SLAVE STATUS doesn't report any lag:
slave1 [localhost] {msandbox} ((none)) > SHOW SLAVE STATUS\G
*************************** 1. row ***************************
               Slave_IO_State: Waiting for master to send event
                  Master_Host: 127.0.0.1
                  Master_User: rsandbox
                  Master_Port: 28890
                Connect_Retry: 60
              Master_Log_File: mysql-bin.000001
          Read_Master_Log_Pos: 569563421
               Relay_Log_File: mysql-relay.000004
                Relay_Log_Pos: 284857134
        Relay_Master_Log_File: mysql-bin.000001
             Slave_IO_Running: Yes
            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: 284861060
              Relay_Log_Space: 569564180
              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: 0
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
                  Master_UUID: 00028890-1111-1111-1111-111111111111
             Master_Info_File: /home/marcelo.altmann/sandboxes/rsandbox_5_7_15/node1/data/master.info
                    SQL_Delay: 0
          SQL_Remaining_Delay: NULL
      Slave_SQL_Running_State: Waiting for dependent transaction to commit
           Master_Retry_Count: 86400
                  Master_Bind:
      Last_IO_Error_Timestamp:
     Last_SQL_Error_Timestamp:
               Master_SSL_Crl:
           Master_SSL_Crlpath:
           Retrieved_Gtid_Set:
            Executed_Gtid_Set:
                Auto_Position: 0
         Replicate_Rewrite_DB:
                 Channel_Name:
           Master_TLS_Version:
1 row in set (0.00 sec)

Same happens with slave_parallel_type=DATABASE .

How to repeat:
1) Start slave with slave_parallel_workers > 0

2) Create a table with some rows on master:
sysbench --test=/usr/share/sysbench/tests/db/oltp.lua --mysql-host=localhost --mysql-user=msandbox --mysql-password=msandbox --mysql-socket=/tmp/mysql_sandbox28890.sock --mysql-db=test --oltp-table-size=1500000 prepare

3) Delete a big amount of rows in your master:
DELETE FROM sbtest1 WHERE id > 100;

4) Compare output of SHOW PROCESSLIST and SHOW SLAVE STATUS\G

Changed in percona-server:
status: New → Confirmed
tags: added: i162291
tags: added: upstream

Percona now uses JIRA for bug reports so this bug report is migrated to: https://jira.percona.com/browse/PS-1770

To post a comment you must log in.
This report contains Public information  Edit
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.