log_slow_sp_statements log output statistics does not break down per statement
General
Escalation
General
Escalation
Description
Environment
None
Smart Checklist
Activity
Julia Vural May 6, 2024 at 8:41 PM
We appreciate this suggestion! However, based on current user feedback, we're prioritizing bug fixes and features with a wider impact.
Lalit Choudhary September 11, 2018 at 3:01 PM
Hi Jervin, Thank you for the report.
Validated as described.
Test:
mysql [localhost] {msandbox} (test) > show variables like 'log_slow_sp_statements';
+------------------------+-------+
| Variable_name | Value |
+------------------------+-------+
| log_slow_sp_statements | ON |
+------------------------+-------+
1 row in set (0.00 sec)
mysql [localhost] {msandbox} (test) > select count(*) from bug1;
+----------+
| count(*) |
+----------+
| 4 |
+----------+
1 row in set (0.00 sec)
CREATE PROCEDURE test_sp()
BEGIN
SELECT * FROM sbtest1 limit 50;
SELECT * FROM bug1;
END//
DELIMITER ;
CALL test_sp();
Slow Query log:
# Time: 2018-09-11T14:52:52.739138Z
# User@Host: msandbox[msandbox] @ localhost [] Id: 2
# Schema: test Last_errno: 0 Killed: 0
# Query_time: 0.000281 Lock_time: 0.000032 Rows_sent: 50 Rows_examined: 50 Rows_affected: 0
# Bytes_sent: 9897 Tmp_tables: 0 Tmp_disk_tables: 0 Tmp_table_sizes: 0
# Stored_routine: test.test_sp
# InnoDB_trx_id: C6E03
# QC_Hit: No Full_scan: Yes Full_join: No Tmp_table: No Tmp_table_on_disk: No
# Filesort: No Filesort_on_disk: No Merge_passes: 0
# InnoDB_IO_r_ops: 7 InnoDB_IO_r_bytes: 114688 InnoDB_IO_r_wait: 0.000104
# InnoDB_rec_lock_wait: 0.000000 InnoDB_queue_wait: 0.000000
# InnoDB_pages_distinct: 38
SET timestamp=1536677572;
SELECT * FROM sbtest1 limit 50;
# Time: 2018-09-11T14:52:52.739369Z
# User@Host: msandbox[msandbox] @ localhost [] Id: 2
# Schema: test Last_errno: 0 Killed: 0
# Query_time: 0.000191 Lock_time: 0.000017 Rows_sent: 54 Rows_examined: 54 Rows_affected: 0
# Bytes_sent: 9988 Tmp_tables: 0 Tmp_disk_tables: 0 Tmp_table_sizes: 0
# Stored_routine: test.test_sp
# QC_Hit: No Full_scan: Yes Full_join: No Tmp_table: No Tmp_table_on_disk: No
# Filesort: No Filesort_on_disk: No Merge_passes: 0
# InnoDB_IO_r_ops: 9 InnoDB_IO_r_bytes: 147456 InnoDB_IO_r_wait: 0.000132
# InnoDB_rec_lock_wait: 0.000000 InnoDB_queue_wait: 0.000000
# InnoDB_pages_distinct: 40
SET timestamp=1536677572;
SELECT * FROM bug1;
Won't Do
Details
Assignee
Oleksandr KachanOleksandr KachanReporter
Jervin RealJervin Real(Deactivated)Labels
Time tracking
3d 4h loggedAffects versions
Priority
High
Details
Details
Assignee
Oleksandr Kachan
Oleksandr KachanReporter
Jervin Real
Jervin Real(Deactivated)Labels
Time tracking
3d 4h logged
Affects versions
Priority
HighSmart Checklist
Open Smart Checklist
Smart Checklist
Open Smart Checklist
Smart Checklist
Open Smart Checklist
Created August 24, 2018 at 7:48 PM
Updated May 6, 2024 at 8:41 PM
Resolved May 6, 2024 at 8:41 PM
I don't know if this is a bug or not - so I am filing as Improvement.
# Time: 2018-08-24T15:16:58.058665Z # User@Host: jervin.real[jervin.real] @ localhost [] Id: 85 # Schema: percona Last_errno: 1051 Killed: 0 # Query_time: 0.000048 Lock_time: 0.000000 Rows_sent: 1 Rows_examined: 5119960729 Rows_affected: 0 # Bytes_sent: 0 Tmp_tables: 82383 Tmp_disk_tables: 10558 Tmp_table_sizes: 23736207448 # Stored_routine: percona.etl_rpt_test # QC_Hit: No Full_scan: Yes Full_join: Yes Tmp_table: Yes Tmp_table_on_disk: Yes # Filesort: Yes Filesort_on_disk: Yes Merge_passes: 49162 # InnoDB_IO_r_ops: 25639 InnoDB_IO_r_bytes: 420069376 InnoDB_IO_r_wait: 4.573045 # InnoDB_rec_lock_wait: 0.000000 InnoDB_queue_wait: 0.000000 # InnoDB_pages_distinct: 910449 SET timestamp=1535123818; drop table if exists tmp_item_exclude; # Time: 2018-08-24T15:16:58.060030Z # User@Host: jervin.real[jervin.real] @ localhost [] Id: 85 # Schema: percona Last_errno: 1051 Killed: 0 # Query_time: 0.001352 Lock_time: 0.000000 Rows_sent: 1 Rows_examined: 5119960729 Rows_affected: 0 # Bytes_sent: 0 Tmp_tables: 82383 Tmp_disk_tables: 10558 Tmp_table_sizes: 23736207448 # Stored_routine: percona.etl_rpt_test # QC_Hit: No Full_scan: Yes Full_join: Yes Tmp_table: Yes Tmp_table_on_disk: Yes # Filesort: Yes Filesort_on_disk: Yes Merge_passes: 49162 # InnoDB_IO_r_ops: 25639 InnoDB_IO_r_bytes: 420069376 InnoDB_IO_r_wait: 4.573045 # InnoDB_rec_lock_wait: 0.000000 InnoDB_queue_wait: 0.000000 # InnoDB_pages_distinct: 910449 SET timestamp=1535123818; create table texclude ( tid int(11), scount int(10), KEY tid (tid) ) engine=memory;As see above, both statements came from the same SP - however, the stats are accumulating and not per statement. It would be nice to see this broken down at the statement level. At the current form, only a few of the metrics can be used i.e. Query_time.