Bug #79660 performance_schema transactions timer is inconsistent
Submitted: 16 Dec 2015 9:02 Modified: 24 Dec 2015 7:22
Reporter: Jervin R Email Updates:
Status: Not a Bug Impact on me:
None 
Category:MySQL Server: Performance Schema Severity:S3 (Non-critical)
Version:5.7.10 OS:Any
Assigned to: MySQL Verification Team CPU Architecture:Any

[16 Dec 2015 9:02] Jervin R
Description:
The timers for statement and transaction both uses nanosecond, however, coming from clean start and sending MTS workload, it seems the timer values for transaction is way higher that statement.

Perhaps this is related to http://bugs.mysql.com/?id=79658 as statement timers are not instrumented properly i.e. when using ROW, BEGIN is only instrumented.

slave1 [localhost] {msandbox} (performance_schema) > select * from setup_timers;
+-------------+-------------+
| NAME        | TIMER_NAME  |
+-------------+-------------+
| idle        | MICROSECOND |
| wait        | CYCLE       |
| stage       | NANOSECOND  |
| statement   | NANOSECOND  |
| transaction | NANOSECOND  |
+-------------+-------------+
5 rows in set (0.00 sec)

slave1 [localhost] {msandbox} (performance_schema) > SELECT THREAD_ID, EVENT_NAME, COUNT_STAR,
    ->   SUM_TIMER_WAIT/1000000 AS SUM_TIMER_WAIT_MS,
    ->   (SUM_TIMER_WAIT/COUNT_STAR)/1000000 AS AVG_TIME_MS
    -> FROM events_statements_summary_by_thread_by_event_name
    -> WHERE THREAD_ID IN (
    ->     SELECT THREAD_ID FROM replication_applier_status_by_worker
    -> ) AND COUNT_STAR > 0;
    SELECT THREAD_ID FROM replication_applier_status_by_worker
) AND COUNT_STAR > 0;+-----------+---------------------+------------+-------------------+-------------+
| THREAD_ID | EVENT_NAME          | COUNT_STAR | SUM_TIMER_WAIT_MS | AVG_TIME_MS |
+-----------+---------------------+------------+-------------------+-------------+
|        84 | statement/sql/begin |         43 |          757.5610 | 17.61769767 |
|        85 | statement/sql/begin |        339 |         5828.5290 | 17.19330088 |
|        86 | statement/sql/begin |       1332 |        23372.3000 | 17.54677177 |
|        87 | statement/sql/begin |       9692 |       170775.2900 | 17.62023215 |
+-----------+---------------------+------------+-------------------+-------------+
4 rows in set (0.01 sec)

slave1 [localhost] {msandbox} (performance_schema) >
slave1 [localhost] {msandbox} (performance_schema) > SELECT THREAD_ID, EVENT_NAME, COUNT_STAR,
    ->   SUM_TIMER_WAIT/1000000 AS SUM_TIMER_WAIT_MS,
    ->   (SUM_TIMER_WAIT/COUNT_STAR)/1000000 AS AVG_TIME_MS
    -> FROM events_transactions_summary_by_thread_by_event_name
    -> WHERE THREAD_ID IN (
    ->     SELECT THREAD_ID FROM replication_applier_status_by_worker
    -> ) AND COUNT_STAR > 0;
+-----------+-------------+------------+-------------------+----------------+
| THREAD_ID | EVENT_NAME  | COUNT_STAR | SUM_TIMER_WAIT_MS | AVG_TIME_MS    |
+-----------+-------------+------------+-------------------+----------------+
|        84 | transaction |         43 |       659353.3940 | 15333.79986047 |
|        85 | transaction |        339 |      4159381.0150 | 12269.56051622 |
|        86 | transaction |       1332 |     16427489.6860 | 12332.95021471 |
|        87 | transaction |       9692 |    101665237.7180 | 10489.60356149 |
+-----------+-------------+------------+-------------------+----------------+
4 rows in set (0.00 sec)

How to repeat:
Can repeat with standard MTS setup procedure and enabling statements instrumentation on performance_schema. ROW binlog_format on master.
[24 Dec 2015 7:22] MySQL Verification Team
Hi,

Not a bug. As mentioned in the related bug report 

https://dev.mysql.com/doc/refman/5.7/en/performance-schema-statement-tables.html

"The preceding description applies only for statement-based replication.
For row-based replication, table I/O done on the slave as it processes
row changes can be instrumented, but row events in the relay log do not
appear as discrete statements."

So the instrumentation is different when ROW and STATEMENT replication event arrives to slave.

all best
Bogdan Kecman