Bug #49141 Encode function is significantly slower in 5.1 compared to 5.0
Submitted: 26 Nov 2009 15:31 Modified: 12 Mar 2010 16:42
Reporter: Oli Sennhauser Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: General Severity:S3 (Non-critical)
Version:5.1 OS:Any
Assigned to: Davi Arnaut
Tags: encode, performance, regression
Triage: Triaged: D2 (Serious)

[26 Nov 2009 15:31] Oli Sennhauser
Description:
Encode function is significantly slower in 5.1 compared to 5.0

How to repeat:
select benchmark(1000000, encode('hello','goodbye'));

4.1.24 - 0.54 s

5.0.58 - 0.57 s
5.0.87 - 0.59 s

5.1.28 - ~20 s
5.1.38 - ~23 s

Suggested fix:
Approximately same performance is expected.
[26 Nov 2009 15:38] Valerii Kravchuk
Same on Mac OS X with 5.0.89 vs 5.1.42:

77-52-12-228:5.0 openxs$ bin/mysql -uroot test
Reading table information for completion of table and column names
You can turn off this feature to get a quicker startup with -A

Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 1
Server version: 5.0.89-debug Source distribution

Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.

mysql> select benchmark(1000000,encode('hello','goodbye'));
+----------------------------------------------+
| benchmark(1000000,encode('hello','goodbye')) |
+----------------------------------------------+
|                                            0 | 
+----------------------------------------------+
1 row in set (0.37 sec)

mysql> select benchmark(1000000,encode('hello','goodbye'));
+----------------------------------------------+
| benchmark(1000000,encode('hello','goodbye')) |
+----------------------------------------------+
|                                            0 | 
+----------------------------------------------+
1 row in set (0.37 sec)

mysql> select benchmark(10000000,encode('hello','goodbye'));
+-----------------------------------------------+
| benchmark(10000000,encode('hello','goodbye')) |
+-----------------------------------------------+
|                                             0 | 
+-----------------------------------------------+
1 row in set (3.73 sec)

mysql> exit
Bye
77-52-12-228:5.0 openxs$ bin/mysqladmin -uroot shutdown
STOPPING server from pid file /Users/openxs/dbs/5.0/var/77-52-12-148.dialup.umc.net.ua.pid
091126 15:33:59  mysqld ended

Compare to these:

77-52-12-228:5.1 openxs$ bin/mysql -uroot test
Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 1
Server version: 5.1.42-debug Source distribution

Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.

mysql> select benchmark(10000000,encode('hello','goodbye'));
+-----------------------------------------------+
| benchmark(10000000,encode('hello','goodbye')) |
+-----------------------------------------------+
|                                             0 |
+-----------------------------------------------+
1 row in set (2 min 47.59 sec)

mysql> select benchmark(1000000,encode('hello','goodbye'));
+----------------------------------------------+
| benchmark(1000000,encode('hello','goodbye')) |
+----------------------------------------------+
|                                            0 |
+----------------------------------------------+
1 row in set (18.20 sec)

So, it looks like a serious performance regression.
[2 Dec 2009 13:39] Georgi Kodinov
This is the effect of implementing Bug #22684.

Here's the 5.1 gprof:

  %   cumulative   self              self     total     
 time   seconds   seconds    calls   s/call   s/call  name    
 92.72     15.40    15.40 261000051     0.00     0.00  my_rnd
  5.36     16.29     0.89  1000000     0.00     0.00  SQL_CRYPT::SQL_CRYPT(char const*, unsigned int) 
  1.32     16.51     0.22  1000012     0.00     0.00  randominit
  0.48     16.59     0.08  1000000     0.00     0.00  hash_password
  0.06     16.60     0.01  1000000     0.00     0.00  Item_func_encode::val_str(String*)
  0.06     16.61     0.01  1000000     0.00     0.00  SQL_CRYPT::encode(char*, unsigned int) 
  0.00     16.61     0.00  2000000     0.00     0.00  Item_string::val_str(String*)
  0.00     16.61     0.00  1000000     0.00     0.00  copy_if_not_alloced(String*, String*, unsigned int) 
  0.00     16.61     0.00  1000000     0.00     0.00  Item_str_func::result_type() const
...

Here's the 5.0 gprof:
  %   cumulative   self              self     total
 time   seconds   seconds    calls  ms/call  ms/call  name
 96.97      0.32     0.32  5000303     0.00     0.00  my_rnd
  1.52      0.33     0.01  1000000     0.00     0.00  Item_str_func::result_type() const
  1.52      0.33     0.01                             Item_func_set_collation::fix_length_and_dec()
  0.00      0.33     0.00  1000000     0.00     0.00  copy_if_not_alloced(String*, String*, unsigned int)
  0.00      0.33     0.00  1000000     0.00     0.00  Item_string::val_str(String*)
  0.00      0.33     0.00  1000000     0.00     0.00  Item_func_encode::val_str(String*)
  0.00      0.33     0.00  1000000     0.00     0.00  SQL_CRYPT::encode(char*, unsigned int)
......

Before this fix (in plan 5.0) the password can only be a constant string literal.
Because of this you don't have to initialize the random structures for the password each time (as it's done at compile time).
This raises the my_rnd calls from 5 millions to 261 millions.
[2 Dec 2009 15:09] Bugs System
A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/92484

3237 Georgi Kodinov	2009-12-02
      Bug #49141: Encode function is significantly slower in 5.1 compared to 5.0
      
      The fix for bug 22684 moved all the calculations to run time.
      For some special cases (e.g. a constant password) it's greatly beneficial
      to initialize the random structures at compile time and only calculate
      the outcome of the operation at run time.
      Implemented such caching of the random structures initialization.
      Fixed both ENCODE() and DECODE() functions.
[3 Dec 2009 20:58] Davi Arnaut
For future reference: the slowdown happens when a ENCODE or DECODE function is evaluated multiple times within the execution of a statement. In 5.0, the function would be initialized once at parsing time and evaluating didn't require the function to be initialized. In 5.1, the initialization was moved to runtime and needs to be performed each time the function is evaluated.

Hence, there is now slowdown for the simple case where the function is called directly and only once (ie: SELECT ENCODE('a','b')). The slowdown happens when the function is evaluated multiple times -- for example, within a BENCHMARK function, prepared statement, stored procedure, subquery or multiple rows in SELECT.
[4 Dec 2009 15:07] Bugs System
A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/92896

3244 Davi Arnaut	2009-12-04
      Bug#49141: Encode function is significantly slower in 5.1 compared to 5.0
      
      The problem was that the multiple evaluations of a ENCODE or
      DECODE function within a single statement caused the random
      generator to be reinitialized at each evaluation, even though
      the parameters were constants.
      
      The solution is to initialize the random generator only once
      if the password (seed) parameter is constant.
     @ mysql-test/r/func_str.result
        Add test case result.
     @ mysql-test/r/ps.result
        Add test case result.
     @ mysql-test/t/func_str.test
        Add test case for Bug#49141
     @ mysql-test/t/ps.test
        Add test case for Bug#49141
     @ sql/item_strfunc.cc
        Move seed generation code to a separate method.
        Seed only once if the password (seed) argument
        is constant.
        Remove duplicated code and use a transform method
        to apply encoding or decoding.
     @ sql/item_strfunc.h
        Add parameter to signal whether the PRNG is already seeded.
        Introduce transform method.
        Combine val_str methods.
     @ sql/sql_crypt.cc
        Remove method.
     @ sql/sql_crypt.h
        Seed is supplied as two long integers.
[4 Dec 2009 15:11] Bugs System
A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/92898

3245 Davi Arnaut	2009-12-04
      Bug#49141: Encode function is significantly slower in 5.1 compared to 5.0
      
      The problem was that the multiple evaluations of a ENCODE or
      DECODE function within a single statement caused the random
      generator to be reinitialized at each evaluation, even though
      the parameters were constants.
      
      The solution is to initialize the random generator only once
      if the password (seed) parameter is constant.
      
      This patch borrows code and ideas from Georgi Kodinov's patch.
     @ mysql-test/r/func_str.result
        Add test case result.
     @ mysql-test/r/ps.result
        Add test case result.
     @ mysql-test/t/func_str.test
        Add test case for Bug#49141
     @ mysql-test/t/ps.test
        Add test case for Bug#49141
     @ sql/item_strfunc.cc
        Move seed generation code to a separate method.
        Seed only once if the password (seed) argument
        is constant.
        Remove duplicated code and use a transform method
        to apply encoding or decoding.
     @ sql/item_strfunc.h
        Add parameter to signal whether the PRNG is already seeded.
        Introduce transform method.
        Combine val_str methods.
     @ sql/sql_crypt.cc
        Remove method.
     @ sql/sql_crypt.h
        Seed is supplied as two long integers.
[4 Dec 2009 15:37] Bugs System
A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/92904

3245 Davi Arnaut	2009-12-04
      Bug#49141: Encode function is significantly slower in 5.1 compared to 5.0
      
      The problem was that the multiple evaluations of a ENCODE or
      DECODE function within a single statement caused the random
      generator to be reinitialized at each evaluation, even though
      the parameters were constants.
      
      The solution is to initialize the random generator only once
      if the password (seed) parameter is constant.
      
      This patch borrows code and ideas from Georgi Kodinov's patch.
     @ mysql-test/r/func_str.result
        Add test case result.
     @ mysql-test/r/ps.result
        Add test case result.
     @ mysql-test/t/func_str.test
        Add test case for Bug#49141
     @ mysql-test/t/ps.test
        Add test case for Bug#49141
     @ sql/item_strfunc.cc
        Move seed generation code to a separate method.
        Seed only once if the password (seed) argument
        is constant.
        Remove duplicated code and use a transform method
        to apply encoding or decoding.
     @ sql/item_strfunc.h
        Add parameter to signal whether the PRNG is already seeded.
        Introduce transform method.
        Combine val_str methods.
     @ sql/sql_crypt.cc
        Remove method.
     @ sql/sql_crypt.h
        Seed is supplied as two long integers.
[4 Dec 2009 16:43] Davi Arnaut
Queued to mysql-5.1-bugteam
[19 Dec 2009 8:30] Bugs System
Pushed into 6.0.14-alpha (revid:alik@sun.com-20091219082307-f3i4fn0tm8trb3c0) (version source revid:alik@sun.com-20091216180721-eoa754i79j4ssd3m) (merge vers: 6.0.14-alpha) (pib:15)
[19 Dec 2009 8:33] Bugs System
Pushed into 5.5.1-m2 (revid:alik@sun.com-20091219082021-f34nq4jytwamozz0) (version source revid:alexey.kopytov@sun.com-20091211164058-ycpe0f20d1c4h1gl) (merge vers: 5.5.0-beta) (pib:15)
[19 Dec 2009 8:37] Bugs System
Pushed into mysql-next-mr (revid:alik@sun.com-20091219082213-nhjjgmphote4ntxj) (version source revid:alik@sun.com-20091216180221-a5ps59gajad3pip9) (pib:15)
[8 Jan 2010 17:20] Paul Dubois
Noted in 5.5.1, 6.0.14 changelogs.

Execution of DECODE() and ENCODE() could be inefficient because
multiple executions within a single statement reinitialized the
random generator multiple times even with constant parameters.

Setting report to NDI pending push to 5.1.x, Celosia.
[15 Jan 2010 9:02] Bugs System
Pushed into 5.1.43 (revid:joro@sun.com-20100115085139-qkh0i0fpohd9u9p5) (version source revid:davi.arnaut@sun.com-20091204153658-09w7l2edgszt8qe7) (merge vers: 5.1.42) (pib:16)
[15 Jan 2010 18:48] Paul Dubois
Noted in 5.1.43 changelog.

Setting report to NDI pending push to Celosia.
[12 Mar 2010 14:13] Bugs System
Pushed into 5.1.44-ndb-7.0.14 (revid:jonas@mysql.com-20100312135944-t0z8s1da2orvl66x) (version source revid:jonas@mysql.com-20100312115609-woou0te4a6s4ae9y) (merge vers: 5.1.44-ndb-7.0.14) (pib:16)
[12 Mar 2010 14:29] Bugs System
Pushed into 5.1.44-ndb-6.2.19 (revid:jonas@mysql.com-20100312134846-tuqhd9w3tv4xgl3d) (version source revid:jonas@mysql.com-20100312060623-mx6407w2vx76h3by) (merge vers: 5.1.44-ndb-6.2.19) (pib:16)
[12 Mar 2010 14:44] Bugs System
Pushed into 5.1.44-ndb-6.3.33 (revid:jonas@mysql.com-20100312135724-xcw8vw2lu3mijrhn) (version source revid:jonas@mysql.com-20100312103652-snkltsd197l7q2yg) (merge vers: 5.1.44-ndb-6.3.33) (pib:16)
[12 Mar 2010 16:42] Paul Dubois
Fixed in earlier 5.1.x, 5.5.x.