What exactly does m_query_time_cnt mean?

I’m a bit confused about the meaning of m_query_time_cnt:
m_query_time_cnt Float32 COMMENT ‘The statement execution time in seconds was met.’,

At first I thought that m_query_time_cnt and num_queries were the same, but I found out that they are not

In this blog, there is a sql statement to query the average execution time:

# Average Query Execution Time for Last 6 hours 
 
select avg(m_query_time_sum/m_query_time_cnt)  from metrics where period_start>subtractHours(now(),6);

In practice, however, this result does not appear to be correct

SELECT avg(m_query_time_sum / m_query_time_cnt)
FROM metrics
WHERE (period_start >= formatDateTime(yesterday() - 1, '%Y-%m-%d 16:00:00')) AND (period_start < formatDateTime(today() - 1, '%Y-%m-%d 16:00:00')) AND (queryid = '743A2DB74D4CE96F')

Query id: 5ce4af64-4279-4879-bc66-290a84b3c5b5

┌─avg(divide(m_query_time_sum, m_query_time_cnt))─┐
│                               75.04540252685547 │
└─────────────────────────────────────────────────┘

I think the correct sql is

SELECT sum(m_query_time_sum) / sum(num_queries)
FROM metrics
WHERE (period_start >= formatDateTime(yesterday() - 1, '%Y-%m-%d 16:00:00')) AND (period_start < formatDateTime(today() - 1, '%Y-%m-%d 16:00:00')) AND (queryid = '743A2DB74D4CE96F')

Query id: 29eef184-dda9-4729-ace5-6909598c3d91

┌─divide(sum(m_query_time_sum), sum(num_queries))─┐
│                              0.7504540252685546 │
└─────────────────────────────────────────────────┘

This is also true via qan-api

SELECT
    num_queries,
    m_query_time_cnt,
    m_query_time_sum,
    m_query_time_min,
    m_query_time_max,
    m_query_time_p99
FROM metrics
WHERE queryid = '743A2DB74D4CE96F'
ORDER BY period_start DESC
LIMIT 1

Query id: 4fa1b6e4-9c70-4828-b2b9-9e0976e19d1b

Row 1:
──────
num_queries:      100
m_query_time_cnt: 1
m_query_time_sum: 71.1733
m_query_time_min: 0.711733
m_query_time_max: 0.711733
m_query_time_p99: 0.711733

The above query also shows that query_time_avg should be equal to query_time_sum/num_queries

So, I’m a bit confused about the meaning of m_query_time_cnt, what does it do and how is it calculated?

2021.11.08
It seems that m_xx_xx_cnt represents the number of times the statement appears in the slow query log within this collection window

So, using the above result as an example, m_query_time_cnt=1, means that this query statement appeared in the slow query log once during this collection period, and then with my parameter log_slow_rate_limit=100, so num_queries= m_query_time_cnt* log_ slow_rate_limit=1*100=100. Is that right?

The Dashboard RED Method for MySQL Queries - Designed for PMM2 has a panel

SELECT
    num_queries,
    m_query_time_cnt,
    m_query_time_sum,
    m_query_time_min,
    m_query_time_max,
    m_query_time_p99
FROM pmm.metrics
WHERE (period_start = '2021-11-09 05:02:00') AND (period_start < '2021-11-09 16:00:00') AND (1 = 1) AND (service_type = 'mysql') AND (queryid = 'A3F4BE1B0BE03335')

Query id: 6e8a09d7-da0e-4927-ba1f-ca4d503acb0a

Row 1:
──────
num_queries:      14400
m_query_time_cnt: 144
m_query_time_sum: 2.1127
m_query_time_min: 0.000103
m_query_time_max: 0.000222
m_query_time_p99: 0.000212

1 rows in set. Elapsed: 0.008 sec. Processed 8.19 thousand rows, 457.58 KB (1.03 million rows/s., 57.63 MB/s.)

This query returns only one row

SELECT sum(m_query_time_sum) / sum(m_query_time_cnt)
FROM pmm.metrics
WHERE (period_start = '2021-11-09 05:02:00') AND (1 = 1) AND (service_type = 'mysql') AND (queryid = 'A3F4BE1B0BE03335')

Query id: 333f32e1-dab2-4839-adaf-579c774409df

┌─divide(sum(m_query_time_sum), sum(m_query_time_cnt))─┐
│                                 0.014671527677112155 │
└──────────────────────────────────────────────────────┘
1 rows in set. Elapsed: 0.008 sec. Processed 8.19 thousand rows, 326.51 KB (983.38 thousand rows/s., 39.20 MB/s.)

sum(m_query_time_sum) / sum(m_query_time_cnt)= 0.014671527677112155

0.014671527677112155 > (m_query_time_max = 0.000222)
why?

At first I thought that m_xx_xx_cnt represents the number of times the statement appears in the slow query log within this collection window

So, with my parameter log_slow_rate_limit=100, num_queries= m_query_time_cnt * log_ slow_rate_limit=1*100=100.

But I find it doesn’t seem that way either

SELECT
    queryid,
    num_queries,
    m_query_time_cnt,
    m_query_time_sum,
    m_query_time_min,
    m_query_time_max,
    m_query_time_p99
FROM pmm.metrics
WHERE (queryid = '25924BD87338F559') AND (period_start = '2021-11-05 16:00:00') AND (period_start < '2021-11-09 16:00:00')

Query id: bfccd505-e0a6-439e-a5b9-ff474abac76a

┌─queryid──────────┬─num_queries─┬─m_query_time_cnt─┬─m_query_time_sum─┬─m_query_time_min─┬─m_query_time_max─┬─m_query_time_p99─┐
│ 25924BD87338F559 │        3600 │               36 │           0.9135 │         0.000171 │         0.000753 │         0.000753 │
│ 25924BD87338F559 │        3101 │               32 │         2.234573 │         0.000219 │         1.212773 │         1.212773 │
│ 25924BD87338F559 │        6301 │               64 │          4.29576 │         0.000194 │          1.76006 │          1.76006 │
└──────────────────┴─────────────┴──────────────────┴──────────────────┴──────────────────┴──────────────────┴──────────────────┘

3 rows in set. Elapsed: 0.007 sec. Processed 8.19 thousand rows, 237.94 KB (1.16 million rows/s., 33.57 MB/s.)

num_queries, m_query_time_cnt
3101, 32
6301, 64

3 Likes

Hi @Fan
you correct re

num_queries - is a real number of queries (calculated with log_slow_rate_limit)
and m_query_time_cnt - “How many times the metric appeared”
It’s not exactly 100 times the difference in your case because of roundings in intervals.
We need to review the blog post and revisit the implementations and fields usage to decrease confusion.

2 Likes

Thank you @roma.novikov, i get it

1 Like