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

Performance problems with a simple loop

Details

    Description

      First, try benchmarking an increment + assignment:

      SET @x := 0;
      DO BENCHMARK(1000000, @x := @x + 1);

      On my local system, this takes ~ .11 seconds.

      But try to do the same in a stored procedure:

      DELIMITER ||
      DROP PROCEDURE IF EXISTS test ||
      CREATE PROCEDURE test()
      BEGIN
      	SET @x := 0;        
      	WHILE @x < 1000000 DO	
                      SET @x := @x + 1;
              END WHILE;
      END ||
      DELIMITER ;
      CALL test();

      More than 13.6 seconds on my system!

      For some reason, the problem is notably less critical (but still annoying) if you use a local variable instead of a session variable:

      DELIMITER ||
      DROP PROCEDURE IF EXISTS test ||
      CREATE PROCEDURE test()
      BEGIN
      	DECLARE x INT UNSIGNED DEFAULT 0;        
      	WHILE x < 1000000 DO	
                      SET x := x + 1;
              END WHILE;
      END ||
      DELIMITER ;
      CALL test();

      Takes about 5.75.

      Attachments

        Issue Links

          Activity

            Same with MySQL 5.5, 5.7.

            Also, same is true for MariaDB 10.1 compound statements, so it's not related to the SP call as such.

            Here is some noticeable difference from P_S (although maybe it's not the difference that causes the performance problem, but it might be):

            select event_name, count_star, sum_timer_wait from
            performance_schema.events_waits_summary_global_by_event_name order by
            sum_timer_wait desc limit 5;

            BENCHMARK

             
            +--------------------------------------------------------+------------+------------------+
            | event_name                                             | count_star | sum_timer_wait   |
            +--------------------------------------------------------+------------+------------------+
            | idle                                                   |        155 | 1978525729000000 |
            | wait/synch/mutex/sql/THD::LOCK_thd_data                |    2000119 |    3819579725654 |
            | wait/synch/mutex/sql/TABLE_SHARE::tdc.LOCK_table_share |        169 |        449129871 |
            | wait/synch/rwlock/sql/MDL_lock::rwlock                 |         55 |        207316591 |
            | wait/io/socket/sql/client_connection                   |          4 |        154879998 |
            +--------------------------------------------------------+------------+------------------+

            (these values appear in the table right after TRUNCATE, they are barely modified by the BENCHMARK)

            Compound statement

            +--------------------------------------------------------+------------+------------------+
            | event_name                                             | count_star | sum_timer_wait   |
            +--------------------------------------------------------+------------+------------------+
            | idle                                                   |        174 | 2082422485000000 |
            | wait/synch/mutex/sql/THD::LOCK_thd_data                |    4000119 |    7561752296880 |
            | wait/synch/mutex/sql/TABLE_SHARE::tdc.LOCK_table_share |         66 |        124610181 |
            | wait/io/file/sql/FRM                                   |         12 |        113567436 |
            | wait/synch/rwlock/sql/MDL_lock::rwlock                 |         55 |        106337591 |
            +--------------------------------------------------------+------------+------------------+

            Stored procedure

            +--------------------------------------------------------+------------+------------------+
            | event_name                                             | count_star | sum_timer_wait   |
            +--------------------------------------------------------+------------+------------------+
            | idle                                                   |        194 | 2441441158000000 |
            | wait/synch/mutex/sql/THD::LOCK_thd_data                |    4000121 |    7569150979606 |
            | wait/synch/mutex/sql/TABLE_SHARE::tdc.LOCK_table_share |         93 |        186116029 |
            | wait/io/file/sql/FRM                                   |         16 |        134974565 |
            | wait/synch/rwlock/sql/MDL_lock::rwlock                 |         57 |        117695843 |
            +--------------------------------------------------------+------------+------------------+

            select event_name, count_star, sum_timer_wait from
            performance_schema.events_stages_summary_global_by_event_name order by
            sum_timer_wait desc limit 5;

            BENCHMARK

            +--------------------------------+------------+----------------+
            | event_name                     | count_star | sum_timer_wait |
            +--------------------------------+------------+----------------+
            | stage/sql/Opening tables       |         16 |     2494021000 |
            | stage/sql/init                 |         19 |     1333234000 |
            | stage/sql/Sorting result       |          1 |     1263361000 |
            | stage/sql/checking permissions |         14 |     1005380000 |
            | stage/sql/Unlocking tables     |         14 |      312488000 |
            +--------------------------------+------------+----------------+

            Compound statement

            +--------------------------------+------------+----------------+
            | event_name                     | count_star | sum_timer_wait |
            +--------------------------------+------------+----------------+
            | stage/sql/closing tables       |    2000018 | 13645989740000 |
            | stage/sql/Opening tables       |    2000016 |  4573616825000 |
            | stage/sql/After opening tables |    2000016 |  4293346982000 |
            | stage/sql/query end            |    1000017 |  2311569542000 |
            | stage/sql/Sorting result       |          1 |     1145411000 |
            +--------------------------------+------------+----------------+

            Stored procedure

            +--------------------------------+------------+----------------+
            | event_name                     | count_star | sum_timer_wait |
            +--------------------------------+------------+----------------+
            | stage/sql/closing tables       |    2000019 | 13698547142000 |
            | stage/sql/Opening tables       |    2000018 |  4561133838000 |
            | stage/sql/After opening tables |    2000018 |  4291648574000 |
            | stage/sql/query end            |    1000017 |  2313252823000 |
            | stage/sql/Sorting result       |          1 |     1117100000 |
            +--------------------------------+------------+----------------+

            I'll leave it to serg to decide whether there is a bug in here.

            elenst Elena Stepanova added a comment - Same with MySQL 5.5, 5.7. Also, same is true for MariaDB 10.1 compound statements, so it's not related to the SP call as such. Here is some noticeable difference from P_S (although maybe it's not the difference that causes the performance problem, but it might be): select event_name, count_star, sum_timer_wait from performance_schema.events_waits_summary_global_by_event_name order by sum_timer_wait desc limit 5; BENCHMARK   +--------------------------------------------------------+------------+------------------+ | event_name | count_star | sum_timer_wait | +--------------------------------------------------------+------------+------------------+ | idle | 155 | 1978525729000000 | | wait/synch/mutex/sql/THD::LOCK_thd_data | 2000119 | 3819579725654 | | wait/synch/mutex/sql/TABLE_SHARE::tdc.LOCK_table_share | 169 | 449129871 | | wait/synch/rwlock/sql/MDL_lock::rwlock | 55 | 207316591 | | wait/io/socket/sql/client_connection | 4 | 154879998 | +--------------------------------------------------------+------------+------------------+ (these values appear in the table right after TRUNCATE, they are barely modified by the BENCHMARK) Compound statement +--------------------------------------------------------+------------+------------------+ | event_name | count_star | sum_timer_wait | +--------------------------------------------------------+------------+------------------+ | idle | 174 | 2082422485000000 | | wait/synch/mutex/sql/THD::LOCK_thd_data | 4000119 | 7561752296880 | | wait/synch/mutex/sql/TABLE_SHARE::tdc.LOCK_table_share | 66 | 124610181 | | wait/io/file/sql/FRM | 12 | 113567436 | | wait/synch/rwlock/sql/MDL_lock::rwlock | 55 | 106337591 | +--------------------------------------------------------+------------+------------------+ Stored procedure +--------------------------------------------------------+------------+------------------+ | event_name | count_star | sum_timer_wait | +--------------------------------------------------------+------------+------------------+ | idle | 194 | 2441441158000000 | | wait/synch/mutex/sql/THD::LOCK_thd_data | 4000121 | 7569150979606 | | wait/synch/mutex/sql/TABLE_SHARE::tdc.LOCK_table_share | 93 | 186116029 | | wait/io/file/sql/FRM | 16 | 134974565 | | wait/synch/rwlock/sql/MDL_lock::rwlock | 57 | 117695843 | +--------------------------------------------------------+------------+------------------+ select event_name, count_star, sum_timer_wait from performance_schema.events_stages_summary_global_by_event_name order by sum_timer_wait desc limit 5; BENCHMARK +--------------------------------+------------+----------------+ | event_name | count_star | sum_timer_wait | +--------------------------------+------------+----------------+ | stage/sql/Opening tables | 16 | 2494021000 | | stage/sql/init | 19 | 1333234000 | | stage/sql/Sorting result | 1 | 1263361000 | | stage/sql/checking permissions | 14 | 1005380000 | | stage/sql/Unlocking tables | 14 | 312488000 | +--------------------------------+------------+----------------+ Compound statement +--------------------------------+------------+----------------+ | event_name | count_star | sum_timer_wait | +--------------------------------+------------+----------------+ | stage/sql/closing tables | 2000018 | 13645989740000 | | stage/sql/Opening tables | 2000016 | 4573616825000 | | stage/sql/After opening tables | 2000016 | 4293346982000 | | stage/sql/query end | 1000017 | 2311569542000 | | stage/sql/Sorting result | 1 | 1145411000 | +--------------------------------+------------+----------------+ Stored procedure +--------------------------------+------------+----------------+ | event_name | count_star | sum_timer_wait | +--------------------------------+------------+----------------+ | stage/sql/closing tables | 2000019 | 13698547142000 | | stage/sql/Opening tables | 2000018 | 4561133838000 | | stage/sql/After opening tables | 2000018 | 4291648574000 | | stage/sql/query end | 1000017 | 2313252823000 | | stage/sql/Sorting result | 1 | 1117100000 | +--------------------------------+------------+----------------+ I'll leave it to serg to decide whether there is a bug in here.
            danblack Daniel Black added a comment -

            using a JIT or compiling procedure code may optimize this - hence MDEV-10280 as a feature request.

            danblack Daniel Black added a comment - using a JIT or compiling procedure code may optimize this - hence MDEV-10280 as a feature request.

            I agree with Daniel that this is yet another reason why support for compiled stored procedures would be great.

            But I think that this is a separate problem, and should be fixed anyway, even if compiled procedures are implemented.

            f_razzoli Federico Razzoli added a comment - I agree with Daniel that this is yet another reason why support for compiled stored procedures would be great. But I think that this is a separate problem, and should be fixed anyway, even if compiled procedures are implemented.

            People

              serg Sergei Golubchik
              f_razzoli Federico Razzoli
              Votes:
              0 Vote for this issue
              Watchers:
              4 Start watching this issue

              Dates

                Created:
                Updated:

                Git Integration

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