MySQL instrumentation unit mystery

I read MySQL manual and here is what I see on our system:

select * from performance_schema.setup_timers;
±------------±------------+
| NAME | TIMER_NAME |
±------------±------------+
| idle | MICROSECOND |
| wait | CYCLE |
| stage | NANOSECOND |
| statement | NANOSECOND |
| transaction | NANOSECOND |
±------------±------------+

SELECT * FROM performance_schema.performance_timers;
±------------±----------------±-----------------±---------------+
| TIMER_NAME | TIMER_FREQUENCY | TIMER_RESOLUTION | TIMER_OVERHEAD |
±------------±----------------±-----------------±---------------+
| CYCLE | 2498825870 | 1 | 22 |
| NANOSECOND | 1000000000 | 1 | 112 |
| MICROSECOND | 1000000 | 1 | 116 |
| MILLISECOND | 1037 | 1 | 112 |
| TICK | 105 | 1 | 692 |
±------------±----------------±-----------------±---------------+

So any “wait” event is in CYCLE and the cycle unit is 2498825870 (2.4Ghz cpu) per second.

Now, I see the output below:

select processlist_id,processlist_user,event_name,processlist_info,connection_type,event_name,object_name,object_type,timer_wait/2498825870,(case when end_event_id is null then ‘yes’ else ‘no’ end) still_waiting from performance_schema.events_waits_current a, performance_schema.threads b where a.thread_id=b.thread_id and processlist_user!=‘rdsadmin’ and event_name!=‘idle’;
±---------------±-----------------±---------------------------------±-----------------------------------------------------±----------------±---------------------------------±------------±------------±----------------------±--------------+
| processlist_id | processlist_user | event_name | processlist_info | connection_type | event_name | object_name | object_type | timer_wait/2498825870 | still_waiting |
±---------------±-----------------±---------------------------------±-----------------------------------------------------±----------------±---------------------------------±------------±------------±----------------------±--------------+
| 5241873 | app-blah-rw | wait/io/aurora_respond_to_client | SET NAMES ‘utf8mb4’ COLLATE ‘utf8mb4_unicode_520_ci’ | TCP/IP | wait/io/aurora_respond_to_client | NULL | NULL | 4620074577.7955 | yes |
±---------------±-----------------±---------------------------------±-----------------------------------------------------±----------------±---------------------------------±------------±------------±----------------------±--------------+

This doesn’t make sense. The SET NAMES certainly does not use 4620074577.7955 seconds (based on cpu cycles). What could I be missing?

1 Like

In performance_schema.events_waits_current, the timer_wait values are in picoseconds.

Internally, times within events are stored in units given by the timer in effect when event timing begins. For display when events are retrieved from Performance Schema tables, times are shown in picoseconds (trillionths of a second) to normalize them to a standard unit, regardless of which timer is selected.

https://dev.mysql.com/doc/mysql-perfschema-excerpt/5.7/en/performance-schema-timing.html

2 Likes

That perfectly made sense. Thanks a TON, @matthewb!

Regards.
Venkat

1 Like