Details
-
Task
-
Status: Closed (View Workflow)
-
Major
-
Resolution: Duplicate
-
None
Description
Hello MariaDB Team
On a server with large amount of databases, tables, and functions/stored procedures, SHOW FUNCTION STATUS is slower than reaching mysql.proc table.
This is impacting performance for tools like mydumper when there are many objects.
To reproduce, start MariaDB with default options (tested on official docker image with MariaDB 11.8.2), then run:
# rm -f create.sql; for db in $(seq 1 3000); do echo "create database if not exists database${db};" >> create.sql; for f in $(seq 1 120); do echo "CREATE FUNCTION IF NOT EXISTS database${db}.hello${f} (s CHAR(20)) RETURNS CHAR(50) DETERMINISTIC RETURN CONCAT('Hello, ',s,'.');" >> create.sql ; done;done
|
|
# time mariadb < create.sql |
Then:
time mariadb database1 -e "show function status where cast(db as binary)=database()" > /dev/null |
|
real 0m9.314s
|
user 0m0.033s
|
sys 0m0.010s
|
|
time mariadb database1 -e "select * FROM mysql.proc where cast(db as binary) = database()" > /dev/null |
|
real 0m0.548s
|
user 0m0.020s
|
sys 0m0.005s
|
Could SHOW FUNCTION STATUS be (almost) as fast as accessing the proc table ?
Slow query log output for above queries:
# Time: 250720 7:29:51 |
# User@Host: root[root] @ localhost [] |
# Thread_id: 259496 Schema: database1 QC_hit: No |
# Query_time: 9.267892 Lock_time: 0.005626 Rows_sent: 120 Rows_examined: 360022
|
# Rows_affected: 0 Bytes_sent: 18607
|
# Tmp_tables: 1 Tmp_disk_tables: 1 Tmp_table_sizes: 134160384
|
# Max_tmp_disk_space_used: 134152192
|
# Full_scan: Yes Full_join: No Tmp_table: Yes Tmp_table_on_disk: Yes |
# Filesort: No Filesort_on_disk: No Merge_passes: 0 Priority_queue: No |
#
|
# explain: id select_type table type possible_keys key key_len ref rows r_rows filtered r_filtered Extra |
# explain: 1 SIMPLE ROUTINES ALL NULL NULL NULL NULL NULL 360022.00 NULL 0.03 Using where |
#
|
SET timestamp=1752996591; |
show function status where cast(db as binary)=database(); |
# Time: 250720 7:30:06 |
# User@Host: root[root] @ localhost [] |
# Thread_id: 259512 Schema: database1 QC_hit: No |
# Query_time: 0.519084 Lock_time: 0.000573 Rows_sent: 120 Rows_examined: 360053
|
# Rows_affected: 0 Bytes_sent: 49174
|
# Pages_accessed: 0 Pages_read: 0 Pages_prefetched: 0 Pages_updated: 0 Old_rows_read: 0
|
# Pages_read_time: 0.0000 Engine_time: 498.9571
|
# Full_scan: Yes Full_join: No Tmp_table: No Tmp_table_on_disk: No |
# Filesort: No Filesort_on_disk: No Merge_passes: 0 Priority_queue: No |
#
|
# explain: id select_type table type possible_keys key key_len ref rows r_rows filtered r_filtered Extra |
# explain: 1 SIMPLE proc ALL NULL NULL NULL NULL 360053 360053.00 100.00 0.03 Using where |
#
|
SET timestamp=1752996606; |
select * FROM mysql.proc where cast(db as binary) = database(); |
Profiling Information for above queries:
MariaDB [database1]> show profile;
|
+------------------------+----------+ |
| Status | Duration |
|
+------------------------+----------+ |
| Starting | 0.002056 |
|
| Opening tables | 0.010726 |
|
| After opening tables | 0.000031 | |
| System lock | 0.000003 |
|
| table lock | 0.000233 | |
| init | 0.001241 |
|
| Optimizing | 0.000110 |
|
| Statistics | 0.000604 | |
| Preparing | 0.000587 |
|
| Executing | 0.000003 |
|
| Filling schema table | 0.000003 | |
| checking permissions | 0.000025 |
|
| Opening tables | 0.000832 |
|
| After opening tables | 0.000006 | |
| System lock | 0.000014 |
|
| table lock | 9.587971 | |
| Unlocking tables | 0.000014 |
|
| closing tables | 0.000076 |
|
| Executing | 0.000010 |
|
| Sending data | 0.711731 |
|
| End of update loop | 0.000040 | |
| Query end | 0.000003 | |
| closing tables | 0.000001 |
|
| Removing tmp table | 0.009210 | |
| closing tables | 0.000005 |
|
| Unlocking tables | 0.000001 |
|
| closing tables | 0.000000 |
|
| Query end | 0.000006 | |
| Starting cleanup | 0.000012 |
|
| Freeing items | 0.000043 |
|
| Updating status | 0.000064 |
|
| Logging slow query | 0.000445 |
|
| Reset for next command | 0.008566 | |
+------------------------+----------+ |
33 rows in set (0.010 sec) |
|
MariaDB [database1]> show profile;
|
+------------------------+----------+ |
| Status | Duration |
|
+------------------------+----------+ |
| Starting | 0.005065 |
|
| checking permissions | 0.000035 |
|
| Opening tables | 0.001756 |
|
| After opening tables | 0.000144 | |
| System lock | 0.000130 |
|
| table lock | 0.000893 | |
| init | 0.002397 |
|
| Optimizing | 0.000543 |
|
| Statistics | 0.000588 | |
| Preparing | 0.000113 |
|
| Executing | 0.000002 |
|
| Sending data | 0.378533 |
|
| End of update loop | 0.000011 | |
| Query end | 0.000006 | |
| Commit | 0.000015 | |
| Query end | 0.000002 | |
| closing tables | 0.000001 |
|
| Unlocking tables | 0.000005 |
|
| closing tables | 0.000018 |
|
| Query end | 0.000015 | |
| Starting cleanup | 0.000002 |
|
| Freeing items | 0.000010 |
|
| Updating status | 0.000030 |
|
| Logging slow query | 0.000217 |
|
| Reset for next command | 0.000002 | |
+------------------------+----------+ |
25 rows in set (0.003 sec) |
The cast(db as binary) is currently based on mydumper's implementation.
Referenced issue: https://github.com/mydumper/mydumper/issues/1943
I am Available to reproduce further and discuss.
Thank you & Cheers
Joffrey
Attachments
Issue Links
- relates to
-
MDEV-5844 Case sensitive problem with routines SHOW <P/F> STATUS;
-
- Closed
-
-
MDEV-20609 Full table scan in INFORMATION_SCHEMA.PARAMETERS/ROUTINES
-
- Closed
-
- links to