Description:
Hi,
There could be more fields in the slow log file with log_slow_extra (example of output in How to repeat). I can think of at least two (name from performance_schema.events_statements_summary_by_digest in parentheses):
- Rows_affected (SUM_ROWS_AFFECTED)
- CPU_time (SUM_CPU_TIME)
Note that many (most ?) relevant fields of performance_schema.events_statements_summary_by_digest are in the slow log file with log_slow_extra, inventory below:
- Query_time (SUM_TIMER_WAIT)
- Lock_time (SUM_LOCK_TIME)
- Rows_sent (SUM_ROWS_SENT)
- Rows_examined (SUM_ROWS_EXAMINED)
- Created_tmp_disk_tables (SUM_CREATED_TMP_DISK_TABLES)
- Created_tmp_tables (SUM_CREATED_TMP_TABLES)
- Sort_merge_passes (SUM_SORT_MERGE_PASSES)
- Sort_range_count (SUM_SORT_RANGE)
- Sort_rows (SUM_SORT_ROWS)
- Sort_scan_count (SUM_SORT_SCAN)
Somehow, I would expect all relevant fields from performance_schema.events_statements_summary_by_digest to be in the slow log file.
Changing this would need to be gated with a feature flag (log_slow_extra_extra = { OFF | ON }) so tooling parsing the slow log file would keep working.
When implementing this, please consider removing Thread_id from the slow log file with log_slow_extra: it is already in the line above (Id).
Many thanks for looking into this,
Jean-François Gagné
How to repeat:
N/A to feature request, but...
This is an example of a slow log entry with log_slow_extra...
# Time: 2024-05-10T19:41:28.293662Z
# User@Host: msandbox[msandbox] @ localhost [] Id: 15
# Query_time: 0.000256 Lock_time: 0.000005 Rows_sent: 0 Rows_examined: 0 Thread_id: 15 Errno: 0 Killed: 0 Bytes_received: 22 Bytes_sent: 56 Read_first: 1 Read_last: 0 Read_key: 1 Read_next: 0 Read_prev: 0 Read_rnd: 0 Read_rnd_next: 1 Sort_merge_passes: 0 Sort_range_count: 0 Sort_rows: 0 Sort_scan_count: 0 Created_tmp_disk_tables: 0 Created_tmp_tables: 0 Start: 2024-05-10T19:41:28.293406Z End: 2024-05-10T19:41:28.293662Z
SET timestamp=1715370088;
select * from t;
And this is the structure of the table performance_schema.events_statements_summary_by_digest.
mysql [localhost:8400] {msandbox} ((none)) > show create table performance_schema.events_statements_summary_by_digest\G
*************************** 1. row ***************************
Table: events_statements_summary_by_digest
Create Table: CREATE TABLE `events_statements_summary_by_digest` (
`SCHEMA_NAME` varchar(64) DEFAULT NULL,
`DIGEST` varchar(64) DEFAULT NULL,
`DIGEST_TEXT` longtext,
`COUNT_STAR` bigint unsigned NOT NULL,
`SUM_TIMER_WAIT` bigint unsigned NOT NULL,
`MIN_TIMER_WAIT` bigint unsigned NOT NULL,
`AVG_TIMER_WAIT` bigint unsigned NOT NULL,
`MAX_TIMER_WAIT` bigint unsigned NOT NULL,
`SUM_LOCK_TIME` bigint unsigned NOT NULL,
`SUM_ERRORS` bigint unsigned NOT NULL,
`SUM_WARNINGS` bigint unsigned NOT NULL,
`SUM_ROWS_AFFECTED` bigint unsigned NOT NULL,
`SUM_ROWS_SENT` bigint unsigned NOT NULL,
`SUM_ROWS_EXAMINED` bigint unsigned NOT NULL,
`SUM_CREATED_TMP_DISK_TABLES` bigint unsigned NOT NULL,
`SUM_CREATED_TMP_TABLES` bigint unsigned NOT NULL,
`SUM_SELECT_FULL_JOIN` bigint unsigned NOT NULL,
`SUM_SELECT_FULL_RANGE_JOIN` bigint unsigned NOT NULL,
`SUM_SELECT_RANGE` bigint unsigned NOT NULL,
`SUM_SELECT_RANGE_CHECK` bigint unsigned NOT NULL,
`SUM_SELECT_SCAN` bigint unsigned NOT NULL,
`SUM_SORT_MERGE_PASSES` bigint unsigned NOT NULL,
`SUM_SORT_RANGE` bigint unsigned NOT NULL,
`SUM_SORT_ROWS` bigint unsigned NOT NULL,
`SUM_SORT_SCAN` bigint unsigned NOT NULL,
`SUM_NO_INDEX_USED` bigint unsigned NOT NULL,
`SUM_NO_GOOD_INDEX_USED` bigint unsigned NOT NULL,
`SUM_CPU_TIME` bigint unsigned NOT NULL,
`MAX_CONTROLLED_MEMORY` bigint unsigned NOT NULL,
`MAX_TOTAL_MEMORY` bigint unsigned NOT NULL,
`COUNT_SECONDARY` bigint unsigned NOT NULL,
`FIRST_SEEN` timestamp(6) NOT NULL,
`LAST_SEEN` timestamp(6) NOT NULL,
`QUANTILE_95` bigint unsigned NOT NULL,
`QUANTILE_99` bigint unsigned NOT NULL,
`QUANTILE_999` bigint unsigned NOT NULL,
`QUERY_SAMPLE_TEXT` longtext,
`QUERY_SAMPLE_SEEN` timestamp(6) NOT NULL,
`QUERY_SAMPLE_TIMER_WAIT` bigint unsigned NOT NULL,
UNIQUE KEY `SCHEMA_NAME` (`SCHEMA_NAME`,`DIGEST`)
) ENGINE=PERFORMANCE_SCHEMA DEFAULT CHARSET=utf8mb4 COLLATE=utf8mb4_0900_ai_ci
1 row in set (0.00 sec)
Description: Hi, There could be more fields in the slow log file with log_slow_extra (example of output in How to repeat). I can think of at least two (name from performance_schema.events_statements_summary_by_digest in parentheses): - Rows_affected (SUM_ROWS_AFFECTED) - CPU_time (SUM_CPU_TIME) Note that many (most ?) relevant fields of performance_schema.events_statements_summary_by_digest are in the slow log file with log_slow_extra, inventory below: - Query_time (SUM_TIMER_WAIT) - Lock_time (SUM_LOCK_TIME) - Rows_sent (SUM_ROWS_SENT) - Rows_examined (SUM_ROWS_EXAMINED) - Created_tmp_disk_tables (SUM_CREATED_TMP_DISK_TABLES) - Created_tmp_tables (SUM_CREATED_TMP_TABLES) - Sort_merge_passes (SUM_SORT_MERGE_PASSES) - Sort_range_count (SUM_SORT_RANGE) - Sort_rows (SUM_SORT_ROWS) - Sort_scan_count (SUM_SORT_SCAN) Somehow, I would expect all relevant fields from performance_schema.events_statements_summary_by_digest to be in the slow log file. Changing this would need to be gated with a feature flag (log_slow_extra_extra = { OFF | ON }) so tooling parsing the slow log file would keep working. When implementing this, please consider removing Thread_id from the slow log file with log_slow_extra: it is already in the line above (Id). Many thanks for looking into this, Jean-François Gagné How to repeat: N/A to feature request, but... This is an example of a slow log entry with log_slow_extra... # Time: 2024-05-10T19:41:28.293662Z # User@Host: msandbox[msandbox] @ localhost [] Id: 15 # Query_time: 0.000256 Lock_time: 0.000005 Rows_sent: 0 Rows_examined: 0 Thread_id: 15 Errno: 0 Killed: 0 Bytes_received: 22 Bytes_sent: 56 Read_first: 1 Read_last: 0 Read_key: 1 Read_next: 0 Read_prev: 0 Read_rnd: 0 Read_rnd_next: 1 Sort_merge_passes: 0 Sort_range_count: 0 Sort_rows: 0 Sort_scan_count: 0 Created_tmp_disk_tables: 0 Created_tmp_tables: 0 Start: 2024-05-10T19:41:28.293406Z End: 2024-05-10T19:41:28.293662Z SET timestamp=1715370088; select * from t; And this is the structure of the table performance_schema.events_statements_summary_by_digest. mysql [localhost:8400] {msandbox} ((none)) > show create table performance_schema.events_statements_summary_by_digest\G *************************** 1. row *************************** Table: events_statements_summary_by_digest Create Table: CREATE TABLE `events_statements_summary_by_digest` ( `SCHEMA_NAME` varchar(64) DEFAULT NULL, `DIGEST` varchar(64) DEFAULT NULL, `DIGEST_TEXT` longtext, `COUNT_STAR` bigint unsigned NOT NULL, `SUM_TIMER_WAIT` bigint unsigned NOT NULL, `MIN_TIMER_WAIT` bigint unsigned NOT NULL, `AVG_TIMER_WAIT` bigint unsigned NOT NULL, `MAX_TIMER_WAIT` bigint unsigned NOT NULL, `SUM_LOCK_TIME` bigint unsigned NOT NULL, `SUM_ERRORS` bigint unsigned NOT NULL, `SUM_WARNINGS` bigint unsigned NOT NULL, `SUM_ROWS_AFFECTED` bigint unsigned NOT NULL, `SUM_ROWS_SENT` bigint unsigned NOT NULL, `SUM_ROWS_EXAMINED` bigint unsigned NOT NULL, `SUM_CREATED_TMP_DISK_TABLES` bigint unsigned NOT NULL, `SUM_CREATED_TMP_TABLES` bigint unsigned NOT NULL, `SUM_SELECT_FULL_JOIN` bigint unsigned NOT NULL, `SUM_SELECT_FULL_RANGE_JOIN` bigint unsigned NOT NULL, `SUM_SELECT_RANGE` bigint unsigned NOT NULL, `SUM_SELECT_RANGE_CHECK` bigint unsigned NOT NULL, `SUM_SELECT_SCAN` bigint unsigned NOT NULL, `SUM_SORT_MERGE_PASSES` bigint unsigned NOT NULL, `SUM_SORT_RANGE` bigint unsigned NOT NULL, `SUM_SORT_ROWS` bigint unsigned NOT NULL, `SUM_SORT_SCAN` bigint unsigned NOT NULL, `SUM_NO_INDEX_USED` bigint unsigned NOT NULL, `SUM_NO_GOOD_INDEX_USED` bigint unsigned NOT NULL, `SUM_CPU_TIME` bigint unsigned NOT NULL, `MAX_CONTROLLED_MEMORY` bigint unsigned NOT NULL, `MAX_TOTAL_MEMORY` bigint unsigned NOT NULL, `COUNT_SECONDARY` bigint unsigned NOT NULL, `FIRST_SEEN` timestamp(6) NOT NULL, `LAST_SEEN` timestamp(6) NOT NULL, `QUANTILE_95` bigint unsigned NOT NULL, `QUANTILE_99` bigint unsigned NOT NULL, `QUANTILE_999` bigint unsigned NOT NULL, `QUERY_SAMPLE_TEXT` longtext, `QUERY_SAMPLE_SEEN` timestamp(6) NOT NULL, `QUERY_SAMPLE_TIMER_WAIT` bigint unsigned NOT NULL, UNIQUE KEY `SCHEMA_NAME` (`SCHEMA_NAME`,`DIGEST`) ) ENGINE=PERFORMANCE_SCHEMA DEFAULT CHARSET=utf8mb4 COLLATE=utf8mb4_0900_ai_ci 1 row in set (0.00 sec)