Uploaded image for project: 'MariaDB Server'
  1. MariaDB Server
  2. MDEV-37280

Improve SHOW FUNCTION STATUS / INFORMATION_SCHEMA.ROUTINES performance

    XMLWordPrintable

Details

    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

          Activity

            People

              danblack Daniel Black
              joffrey92 Joffrey MICHAIE
              Votes:
              0 Vote for this issue
              Watchers:
              2 Start watching this issue

              Dates

                Created:
                Updated:
                Resolved:

                Git Integration

                  Error rendering 'com.xiplink.jira.git.jira_git_plugin:git-issue-webpanel'. Please contact your Jira administrators.