Bug #81928 Feature request for sys.profiling
Submitted: 20 Jun 2016 10:19 Modified: 22 Jun 2016 1:37
Reporter: tsubasa tanaka (OCA) Email Updates:
Status: Verified Impact on me:
None 
Category:MySQL Server: SYS Schema Severity:S4 (Feature request)
Version:5.7.13 OS:Any
Assigned to: CPU Architecture:Any
Tags: profiling, show profile, sys
Triage: Needs Triage: D5 (Feature request)

[20 Jun 2016 10:19] tsubasa tanaka
Description:
This is feature request.

After MySQL 5.6.7, SHOW PROFILE has been deprecated.

http://dev.mysql.com/doc/refman/5.6/en/show-profile.html

Alternative way for query profiling has been described, but it's troublesome.

http://dev.mysql.com/doc/refman/5.7/en/performance-schema-query-profiling.html

How to repeat:
This is feature request.

Suggested fix:
See attached patch.

I can use it like these.

```
mysql57> CALL sys.show_profiles();
+----------+----------+-------------------------------------------------------------------+
| query_id | duration | sql_text                                                          |
+----------+----------+-------------------------------------------------------------------+
|        3 |   0.0002 | select @@version_comment limit 1                                  |
|       20 |   0.0002 | SELECT DATABASE()                                                 |
|       42 |   0.0023 | CREATE DEFINER=`root`@`localho ... y_id ORDER BY timer_start; END |
|       61 |   0.0017 | CREATE DEFINER=`root`@`localho ...  AND sql_text IS NOT NULL; end |
|       76 |   0.0002 | SELECT DATABASE()                                                 |
|       98 |   0.0019 | drop procedure show_profile                                       |
|      127 |   0.0017 | drop procedure show_profiles                                      |
|      156 |   0.0002 | SELECT DATABASE()                                                 |
|      178 |   0.0001 | shwo tables                                                       |
|      183 |   0.0004 | show tables                                                       |
|      204 |   0.0006 | SELECT * FROM t1                                                  |
|      264 |   0.0002 | SET @sys.statement_truncate_le ... ('statement_truncate_len', 64) |
+----------+----------+-------------------------------------------------------------------+
12 rows in set (0.01 sec)

mysql57> CALL sys.show_profile(204);
+------------------------------------------+----------+
| stage                                    | duration |
+------------------------------------------+----------+
| stage/sql/starting                       |   0.0000 |
| stage/sql/Waiting for query cache lock   |   0.0000 |
| stage/sql/starting                       |   0.0000 |
| stage/sql/checking query cache for query |   0.0001 |
| stage/sql/checking permissions           |   0.0000 |
| stage/sql/Opening tables                 |   0.0001 |
| stage/sql/init                           |   0.0000 |
| stage/sql/System lock                    |   0.0000 |
| stage/sql/optimizing                     |   0.0000 |
| stage/sql/statistics                     |   0.0000 |
| stage/sql/preparing                      |   0.0000 |
| stage/sql/executing                      |   0.0000 |
| stage/sql/Sending data                   |   0.0003 |
| stage/sql/end                            |   0.0000 |
| stage/sql/query end                      |   0.0000 |
| stage/sql/closing tables                 |   0.0000 |
| stage/sql/freeing items                  |   0.0000 |
| stage/sql/cleaning up                    |   0.0000 |
+------------------------------------------+----------+
18 rows in set (0.00 sec)

Query OK, 0 rows affected (0.00 sec)
```
[20 Jun 2016 10:20] tsubasa tanaka
procedure like show profile

(*) I confirm the code being submitted is offered under the terms of the OCA, and that I am authorized to contribute it.

Contribution: bug81928_show_profile.sql (application/octet-stream, text), 748 bytes.

[20 Jun 2016 10:22] tsubasa tanaka
Procedures use `events_stages_history_long` and `events_statements_history_long`.
Need setup_consumers's events_statements_history_long and events_stages_history_long are ENABLED = 'YES'.
[21 Jun 2016 8:34] Umesh Shastry
Hello Tanaka-San,

Thank you for the reasonable feature request and contribution.

Thanks,
Umesh
[21 Jun 2016 14:15] Mark Leith
Hello Tanaka-San,

Thanks for the contribution - do you also think it may be worth adding another routine that enables/disables profiling for just a specific thread (i.e. does all of the other configuration steps listed in the documentation page you linked)?

It could even turn on/off the history reporting per thread / globally in setup_actors to allow tracing just the one specific thread too, as an option..

Cheers,

Mark
[22 Jun 2016 1:37] tsubasa tanaka
Hello Mark,

IMHO, I don't think p_s.setup_actors is enough to control.
Because threads already connected (connection-pooled connections) are not effected by p_s.setup_actors.
If I'd like to turn off such connections'es instrumentation, I would have to update p_s.threads.instrumentation = NO.

After that, I think there are 2 ways to turn on/off profiling by sys.

# Enable profiling and leave all instrumented threads at all

1. Back up p_s settings by sys.ps_setup_save
2. UPDATE setup_instruments and UPDATE setup_consumers
3. Executing query
4. Profiling by sys.show_profiles and sys.show_profile
5. Restore p_s settings by sys.ps_setup_reload_saved

## Problems

- ps_setup_save and ps_setup_reload_saved use temporary table as copying original data. If closing connection without step 5, original p_s settings are lost.
- This may occur performance-hit under heavy workload.

# Enable profiling and turn off instrumented threads without itself

1. Back up p_s settings by sys.ps_setup_save
2. UPDATE setup_instruments and UPDATE setup_consumers and UPDATE setup_consumers
3. UPDATE threads SET instrumented = OFF WHERE thread_id <> @not_my_thread AND type = 'FOREGROUND'
4. Executing query
5. Profiling by sys.show_profiles and sys.show_profile
6. restore p_s settings by sys.ps_setup_reload_saved
7. UPDATE threads SET instrumented = ON WHERE thread_id <> @not_my_thread AND type = 'FOREGROUND'

## Problems

- ps_setup_save and ps_setup_reload_saved use temporary table as copying original data. If closing connection without step 6, original p_s settings are lost(Same as first one)
- Normal traffic's data will not be recorded (lost) between step 3 and step 7 (i.e. events_statements_summary_by_digest)

I think they are too troublesome because I don't decide users will go to final step correctly or not.
If I can use UDF, seal all steps into UDF and I will be able to call it like this.

`SELECT profilling("SELECT .. FROM .. WHERE ..");`
..(query result and profiling result are displayed)

How do you think?