Bug #15811 extremely long time for mysql client to execute long INSERT
Submitted: 16 Dec 2005 12:52 Modified: 9 Aug 2006 20:21
Reporter: Yoshiaki Tajika (Basic Quality Contributor) Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: Charsets Severity:S5 (Performance)
Version:5.0.19-BK, 5.0.15 OS:Linux (Linux)
Assigned to: Tomash Brechko CPU Architecture:Any

[16 Dec 2005 12:52] Yoshiaki Tajika
Description:
It takes extremely long time for mysql client tool to execute long INSERT statement. This occurs at 5.0.15, but not at 5.0.13 or 4.1.15.
I think this is a serious problem, because mysqldump creates very long 
INSERT statement. 

How to repeat:
mysql> use test;
drop table if exists t1;
create table t1(c1 char(10)) engine=myisam default charset=latin1;
insert into t1 values('1234567890');
insert into t1 select * from t1;
insert into t1 select * from t1;
insert into t1 select * from t1;
insert into t1 select * from t1;
insert into t1 select * from t1;
insert into t1 select * from t1;
insert into t1 select * from t1;
insert into t1 select * from t1;
insert into t1 select * from t1;
insert into t1 select * from t1;
insert into t1 select * from t1;
insert into t1 select * from t1;
insert into t1 select * from t1;
insert into t1 select * from t1;

Now 16384 records there. Then, dump it, and load it again.
# mysqldump test t1 > temp.sql
# mysql test < temp.sql

At my PC, loading took about 60 sec with 5.0.15,
while it's <1 sec at 4.0.15.

Suggested fix:
I checked mysql.cc of 5.0.15, 5.0.13, and 4.0.15.
I found that my_strcasecmp() was add into add_line() at 5.0.15.
Calling my_strcasecmp many times maybe wastes time.
When I replace 'my_strcasecmp(...)' with '0' (i.e, false),
the problem goes away!!
[16 Dec 2005 12:53] Yoshiaki Tajika
Sorry. Not 4.0.15 but 4.1.15!!
[17 Dec 2005 13:28] Valeriy Kravchuk
Thank you for a problem report. I've tried to repeat with latest 5.0-BK build, and saw nothing similar to your 60 seconds, on my old Celeron 300 MHz:

mysql> select version();
+-----------+
| version() |
+-----------+
| 4.1.17    |
+-----------+
1 row in set (0.00 sec)

mysql> drop table if exists t1;
Query OK, 0 rows affected (0.06 sec)

mysql> create table t1(c1 char(10)) engine=myisam default charset=latin1;
Query OK, 0 rows affected (0.01 sec)

mysql> insert into t1 values('1234567890');
Query OK, 1 row affected (0.00 sec)

mysql> insert into t1 select * from t1;
Query OK, 1 row affected (0.00 sec)
Records: 1  Duplicates: 0  Warnings: 0

mysql> insert into t1 select * from t1;
Query OK, 2 rows affected (0.00 sec)
Records: 2  Duplicates: 0  Warnings: 0

mysql> insert into t1 select * from t1;
Query OK, 4 rows affected (0.00 sec)
Records: 4  Duplicates: 0  Warnings: 0

mysql> insert into t1 select * from t1;
Query OK, 8 rows affected (0.00 sec)
Records: 8  Duplicates: 0  Warnings: 0

mysql> insert into t1 select * from t1;
Query OK, 16 rows affected (0.00 sec)
Records: 16  Duplicates: 0  Warnings: 0

mysql> insert into t1 select * from t1;
Query OK, 32 rows affected (0.00 sec)
Records: 32  Duplicates: 0  Warnings: 0

mysql> insert into t1 select * from t1;
Query OK, 64 rows affected (0.00 sec)
Records: 64  Duplicates: 0  Warnings: 0

mysql> insert into t1 select * from t1;
Query OK, 128 rows affected (0.01 sec)
Records: 128  Duplicates: 0  Warnings: 0

mysql> insert into t1 select * from t1;
Query OK, 256 rows affected (0.01 sec)
Records: 256  Duplicates: 0  Warnings: 0

mysql> insert into t1 select * from t1;
Query OK, 512 rows affected (0.00 sec)
Records: 512  Duplicates: 0  Warnings: 0

mysql> insert into t1 select * from t1;
Query OK, 1024 rows affected (0.01 sec)
Records: 1024  Duplicates: 0  Warnings: 0

mysql> insert into t1 select * from t1;
Query OK, 2048 rows affected (0.02 sec)
Records: 2048  Duplicates: 0  Warnings: 0

mysql> insert into t1 select * from t1;
Query OK, 4096 rows affected (0.03 sec)
Records: 4096  Duplicates: 0  Warnings: 0

mysql> insert into t1 select * from t1;
Query OK, 8192 rows affected (0.05 sec)
Records: 8192  Duplicates: 0  Warnings: 0

mysql> exit
Bye
[openxs@Fedora 4.1]$ bin/mysqldump -uroot test t1 >/tmp/temp.sql
[openxs@Fedora 4.1]$ time bin/mysql -uroot test </tmp/temp.sql

real    0m0.500s
user    0m0.100s
sys     0m0.020s
[openxs@Fedora 4.1]$ 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 4 to server version: 4.1.17

Type 'help;' or '\h' for help. Type '\c' to clear the buffer.

mysql> select count(*) from t1;
+----------+
| count(*) |
+----------+
|    16384 |
+----------+
1 row in set (0.00 sec)

mysql> exit
Bye
[openxs@Fedora 4.1]$ bin/mysqladmin -uroot shutdown
STOPPING server from pid file /home/openxs/dbs/4.1/var/Fedora.pid
051217 16:12:40  mysqld ended

[1]+  Done                    bin/mysqld_safe
[openxs@Fedora 4.1]$ cd ../5.0/
[openxs@Fedora 5.0]$ bin/mysqld_safe &
[1] 22057
[openxs@Fedora 5.0]$ Starting mysqld daemon with databases from /home/openxs/dbs/5.0/var

[openxs@Fedora 5.0]$ time bin/mysql -uroot test </tmp/temp.sql

real    0m1.465s
user    0m0.120s
sys     0m0.060s
[openxs@Fedora 5.0]$ 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 2 to server version: 5.0.18

Type 'help;' or '\h' for help. Type '\c' to clear the buffer.

mysql> select count(*) from t1;
+----------+
| count(*) |
+----------+
|    16384 |
+----------+
1 row in set (0.00 sec)

mysql> exit
Bye
[openxs@Fedora 5.0]$ uname -a
Linux Fedora 2.4.22-1.2115.nptl #1 Wed Oct 29 15:42:51 EST 2003 i686 i686 i386 GNU/Linux

It was a bit slower on 5.0.18, but not 60 times slower. About 1 second in both cases. So, please, check once more. With 5.0.16. Or wait till Monday and try with 5.0.17. it should be released officially next week.
[19 Dec 2005 1:23] Yoshiaki Tajika
Would you please try it like this?
# mysql test --default-character-set=ujis < temp.sql

As far as I tried,
a) --default-character-set latin1, utf8, and sjis are fast, 
   but ujis, big5, and gbk are slow.
b) Server side characterset defined in /etc/my.cnf has nothing 
   to do with this problem.
c) While I'm waiting, linux 'top' command shows that 
    mysql client tool's CPU% is over 95%.
d) 5.0.16 source build version has same result.
[21 Dec 2005 14:44] Valeriy Kravchuk
Thank you for the additional information. Please, try to repeat on 5.0.17. It is officially released already.
[22 Dec 2005 11:01] Yoshiaki Tajika
5.0.17 causes same problem, my co-worker says. I mean it's not only me who confronted this problem.
By the way did you try the command I showed previously?
# mysql test --default-character-set=ujis < temp.sql
If you can't reproduce it even with "--default-character-set=ujis",
it's me who should investigate further more. Please tell me your result.
[22 Dec 2005 18:30] Valeriy Kravchuk
Thank you for your persistency. I've tried with newest 5.0.19-BK (ChangeSet@1.1999, 2005-12-21 18:50:06+01:00), with the same amount of data, on the same Linux machine, and got:

[openxs@Fedora 5.0]$ time bin/mysql --default-character-set=ujis -uroot test </tmp/temp.sql

real    5m35.999s
user    5m35.040s
sys     0m0.020s

So, yes, there is a problem to solve, really.
[20 Jun 2006 12:18] Konstantin Osipov
Tomash, please keep in mind that this is somewhere in charsets code: Bar might give you a hint  where exactly
[22 Jun 2006 10:01] 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/8058
[22 Jun 2006 15:14] 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/8085
[28 Jun 2006 19:18] Konstantin Osipov
Pushed into 5.0 tree, currently tagged 5.0.23
[2 Aug 2006 15:57] Konstantin Osipov
Merged into 5.1.12
[9 Aug 2006 20:21] Paul DuBois
Noted in 5.0.23, 5.1.12 changelogs.

Long multiple-row INSERT statements could take a very long time for
some multi-byte character sets.