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.

Portions of this website are copyright © 2001, 2002 The PHP Group

Page generated in 0.063 sec. using MySQL 8.4.7-u6-cloud

Timestamp references displayed by the system are UTC.
Content reproduced on this site is the property of the respective copyright holders.
It is not reviewed in advance by Oracle and does not necessarily represent the opinion of Oracle or any other party.