Bug #70427 when using multi-threaded slave, gtid_executed does not report the latest transa
Submitted: 26 Sep 2013 1:48 Modified: 15 Nov 2013 18:22
Reporter: Giuseppe Maxia Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: Replication Severity:S2 (Serious)
Version:5.7.2 OS:Linux
Assigned to: Paul DuBois CPU Architecture:Any
Tags: Monitoring, parallel, replication

[26 Sep 2013 1:48] Giuseppe Maxia
Description:
With several threads enabled, gtid_executed does not report the latest transaction.

See for example this:

select worker_id,service_state,last_seen_transaction from performance_schema . replication_execute_status_by_worker; select variable_value from information_schema .global_variables where variable_name = 'gtid_executed';

+-----------+---------------+----------------------------------------------+
| worker_id | service_state | last_seen_transaction                        |
+-----------+---------------+----------------------------------------------+
|         0 | ON            | 71f8cf76-2644-11e3-bc64-00265531a0cc:1300478 |
|         1 | ON            | 71f8cf76-2644-11e3-bc64-00265531a0cc:1300476 |
|         2 | ON            | 71f8cf76-2644-11e3-bc64-00265531a0cc:1300473 |
|         3 | ON            | 71f8cf76-2644-11e3-bc64-00265531a0cc:1300480 |
+-----------+---------------+----------------------------------------------+
4 rows in set (0.01 sec)

+------------------------------------------------+
| variable_value                                 |
+------------------------------------------------+
| 71f8cf76-2644-11e3-bc64-00265531a0cc:1-1300478 |
+------------------------------------------------+
1 row in set (0.00 sec)

The highest transaction reported by parallel workers is 1300480. But 'gtid_executed' reports 1300478.

How to repeat:
start replication with N channels.
run these queries together (several times):

select worker_id,service_state,last_seen_transaction from performance_schema . replication_execute_status_by_worker; select variable_value from information_schema .global_variables where variable_name = 'gtid_executed';
[26 Sep 2013 12:23] MySQL Verification Team
Hello Giuseppe,

Thank you for the bug report.
Noticed similar behavior on my local test box:

// gtid_executed does not report the latest transaction

mysql> select worker_id,service_state,last_seen_transaction from performance_schema . replication_execute_status_by_worker; select variable_value from information_schema .global_variables where variable_name = 'gtid_executed';
+-----------+---------------+------------------------------------------+
| worker_id | service_state | last_seen_transaction                    |
+-----------+---------------+------------------------------------------+
|         0 | ON            | a666e4ac-2744-11e3-82ec-5628c563a202:752 |
|         1 | ON            | a666e4ac-2744-11e3-82ec-5628c563a202:734 |
|         2 | ON            | a666e4ac-2744-11e3-82ec-5628c563a202:721 |
|         3 | ON            | a666e4ac-2744-11e3-82ec-5628c563a202:748 |
|         4 | ON            | a666e4ac-2744-11e3-82ec-5628c563a202:718 |
|         5 | ON            | a666e4ac-2744-11e3-82ec-5628c563a202:717 |
|         6 | ON            | a666e4ac-2744-11e3-82ec-5628c563a202:738 |
|         7 | ON            | a666e4ac-2744-11e3-82ec-5628c563a202:691 |
|         8 | ON            | a666e4ac-2744-11e3-82ec-5628c563a202:715 |
|         9 | ON            | a666e4ac-2744-11e3-82ec-5628c563a202:697 |
+-----------+---------------+------------------------------------------+
10 rows in set (0.00 sec)

+------------------------------------------------------------------------------------------------------------------------------------------+
| variable_value                                                                                                                           |
+------------------------------------------------------------------------------------------------------------------------------------------+
| 1a8ff025-2747-11e3-82fc-4d042cd1967a:1-2,
a666e4ac-2744-11e3-82ec-5628c563a202:1-690:692-696:698-710:712-714:716:719:722-730:735:744:746 |
+------------------------------------------------------------------------------------------------------------------------------------------+
1 row in set (0.00 sec)

mysql> select worker_id,service_state,last_seen_transaction from performance_schema . replication_execute_status_by_worker; select variable_value from information_schema .global_variables where variable_name = 'gtid_executed';
+-----------+---------------+------------------------------------------+
| worker_id | service_state | last_seen_transaction                    |
+-----------+---------------+------------------------------------------+
|         0 | ON            | a666e4ac-2744-11e3-82ec-5628c563a202:803 |
|         1 | ON            | a666e4ac-2744-11e3-82ec-5628c563a202:784 |
|         2 | ON            | a666e4ac-2744-11e3-82ec-5628c563a202:766 |
|         3 | ON            | a666e4ac-2744-11e3-82ec-5628c563a202:775 |
|         4 | ON            | a666e4ac-2744-11e3-82ec-5628c563a202:785 |
|         5 | ON            | a666e4ac-2744-11e3-82ec-5628c563a202:777 |
|         6 | ON            | a666e4ac-2744-11e3-82ec-5628c563a202:756 |
|         7 | ON            | a666e4ac-2744-11e3-82ec-5628c563a202:753 |
|         8 | ON            | a666e4ac-2744-11e3-82ec-5628c563a202:767 |
|         9 | ON            | a666e4ac-2744-11e3-82ec-5628c563a202:720 |
+-----------+---------------+------------------------------------------+
10 rows in set (0.00 sec)

+--------------------------------------------------------------------------------------------------------------------------------------------------------------+
| variable_value                                                                                                                                               |
+--------------------------------------------------------------------------------------------------------------------------------------------------------------+
| 1a8ff025-2747-11e3-82fc-4d042cd1967a:1-2,
a666e4ac-2744-11e3-82ec-5628c563a202:1-719:721-746:748-749:751-752:754-755:757-762:765:769:773:778:781:783:790:799 |
+--------------------------------------------------------------------------------------------------------------------------------------------------------------+
1 row in set (0.00 sec)

Thanks,
Umesh
[14 Nov 2013 15:11] Giuseppe Maxia
This is a replication bug, not a documentation problem.
gtid_executed must report the latest transaction executed, or else something is wrong.
[15 Nov 2013 18:22] Paul DuBois
Thank you for your bug report. This issue has been addressed in the documentation. The updated documentation will appear on our website shortly, and will be included in the next release of the relevant products.

Added to description of LAST_SEEN_TRANSACTION:

The transaction that the worker has last seen. The worker has not
necessarily executed this transaction because it could still be in
the process of doing so.