Bug #1027 slow INSERTS on MySQL 4.0.14
Submitted: 11 Aug 2003 0:32 Modified: 12 Aug 2003 23:08
Reporter: Paul Coldrey Email Updates:
Status: Can't repeat Impact on me:
None 
Category:MySQL Server Severity:S2 (Serious)
Version:4.0.14 OS:Linux (RedHat 9.0)
Assigned to: Alexander Keremidarski CPU Architecture:Any

[11 Aug 2003 0:32] Paul Coldrey
Description:
Here is another follow up to bugs #712 and #914, I don't beleive it is related to what you guys have found in relation to #914 but it is at least one of the problems that has been making my life difficult (I'm not convinced that it explains all that I have seen - but a resolution would make me very happy!)

As originally reported in #712 inserts are slow!

With relation to the how to repeat section the execution times I have seen are:

MySQL 3.23.49, RedHat 7.3:

    inserts.sh       1 minute  12 seconds
    inserts.sql                 3 seconds

MySQL 4.0.14, RedHat 9.0:

    inserts.sh       3 minutes 16 seconds
    inserts.sql      3 minutes 12 seconds

I've uploaded my test case in a tarball called bugme3.tgz to support.mysql.com/pub/mysql/secret and I have also put it at http://www.ensigma.com.au/bugme3.tgz

How to repeat:
Create a database and table:

   mysql < table.sql

Run single instance of MySQL test and note execution time:

   date; mysql < inserts.sql; date;

Run multiple instances of MySQL test and note execution time:

   date; mysql < ./inserts.sh; date;

Obvious differences, as noted above, can be seen between MySQL 4.0.14 and 3.23.49.
[11 Aug 2003 2:54] Alexander Keremidarski
Not enough information was provided for us to be able
to handle this bug. Please re-read the instructions at
http://bugs.mysql.com/how-to-report.php

If you can provide more information, feel free to add it
to this bug and change the status back to 'Open'.

Thank you for your interest in MySQL.

I have repeated your tests with debug versions current 3.23 and 4.0 from bk tree (post-3.23.57 and post-4.0.14) both on RedHat 9.0, with same my.cnf settings.
my.cnf i.e. startup options is most important to be absolutely the same!

result is as follows:

MySQL 3.23
    inserts.sh       1 minute  42 seconds

MySQL 4.0
    inserts.sh       1 minute  45 seconds

Sorry to say this, but your results are meaningless without making sure both versions are tested on exactly same platform (Hardware + OS) and exactly the same startup options.
[11 Aug 2003 15:46] Paul Coldrey
Hi Alexander,

After your great work tracking down the causes of #914 I am surprised you gave up on this so easily (perhaps this will level up our beer tally, although right now I think I still owe you :-)) Like bug 914 this might be related the OS, but I have found a 60x speed reduction between two identical machines, running identical software, apart from OS and MySQL, surely that warrants a little investigation. 

Note that THERE ARE TWO TEST CASES. These may be different bugs (and so perhaps I am again a fool for reporting two possible bugs in one report - but these seemed so likely to be related). The most serious speed difference is seen with the test case you didn't try - perhaps you should give it a shot.

Also, I don't seem to be able to reopen this bug - maybe that is only available to developers??

Here are my my.cnf files (I don't think they're the problem).

MySQL 3.23.49, RedHat 7.3
=========================

[mysqld]
datadir=/var/lib/mysql
socket=/var/lib/mysql/mysql.sock
log-bin
server-id=1
     
[mysql.server]
user=mysql
basedir=/var/lib

[safe_mysqld]
err-log=/var/log/mysqld.log
pid-file=/var/run/mysqld/mysqld.pid

MySQL 4.0.14, RedHat 9.0
========================

[mysqld]
ft_min_word_len=2
[11 Aug 2003 18:42] Alexander Keremidarski
Here it is:

3.23.58
date; mysql < inserts.sql; date
Tue Aug 12 04:28:32 EEST 2003
Tue Aug 12 04:28:45 EEST 2003

= 13 seconds

4.0.15
# date; mysql < inserts.sql; date
Tue Aug 12 04:32:03 EEST 2003
Tue Aug 12 04:32:18 EEST 2003

= 15 seconds

Considering that machine runs several other processes I don't agree this is noticeable difference

Yes 4.0.15 appears to be slower, but not 60 times slower.

3.23.58
date; mysql < ./inserts.sh; date;

Tue Aug 12 04:33:41 EEST 2003
Tue Aug 12 04:34:50 EEST 2003
date; mysql < ./inserts.sh; date;

= 1 min 09 seconds

4.0.15
date; mysql < ./inserts.sh; date;

Tue Aug 12 04:38:01 EEST 2003
Tue Aug 12 04:39:11 EEST 2003

= 1 min 10 seconds

Again 4.0.15
[11 Aug 2003 18:42] Alexander Keremidarski
Here it is:

3.23.58
date; mysql < inserts.sql; date
Tue Aug 12 04:28:32 EEST 2003
Tue Aug 12 04:28:45 EEST 2003

= 13 seconds

4.0.15
# date; mysql < inserts.sql; date
Tue Aug 12 04:32:03 EEST 2003
Tue Aug 12 04:32:18 EEST 2003

= 15 seconds

Considering that machine runs several other processes I don't agree this is noticeable difference

Yes 4.0.15 appears to be slower, but not 60 times slower.

3.23.58
date; mysql < ./inserts.sh; date;

Tue Aug 12 04:33:41 EEST 2003
Tue Aug 12 04:34:50 EEST 2003
date; mysql < ./inserts.sh; date;

= 1 min 09 seconds

4.0.15
date; mysql < ./inserts.sh; date;

Tue Aug 12 04:38:01 EEST 2003
Tue Aug 12 04:39:11 EEST 2003

= 1 min 10 seconds

Again 4.0.15
[11 Aug 2003 19:03] Alexander Keremidarski
As I said before my.cnf content is very important in your case.

You effectively run both servers with different InnoDB options.
In both cases you don't specify any InnoDB options which means you use default settings. However defaults are different.

In 3.23.49 innodb_flush_log_at_trx_commit defaults to 0 which was changed in 3.23.57 to 1

http://www.mysql.com/doc/en/News-3.23.57.html
...

The default option for innodb_flush_log_at_trx_commit was changed from 0 to 1 to make InnoDB tables ACID by default. See section 7.5.3 InnoDB Startup Options.

In 4.0.14 innodb_flush_log_at_trx_commit defaults to 1

This option only can explain difference in speed you have observed.
Check it with: 

SHOW VARIABLES LIKE "innodb_flush_log_at_trx_commit";

Setting it to 0 will always make InnoDB INSERTs faster for obvious reasons.
It has no effect on MyISAM tables.
[11 Aug 2003 19:04] Alexander Keremidarski
You are right that Bug Reports can be reopened by MySQL Developers only.
[12 Aug 2003 16:54] Paul Coldrey
I take your point about the test case, however, I felt (and I think Byron did too) that the performance on our RedHat 9.0 systems is so poor that it scarcely needs a comparison to say that it is a bug. The RedHat 7.3 test was included more to show the magnitude of the problem on 9.0 more than as a tool to help you isolate the problem.

Anyhow, once you tried the test case and failed to repeat the poor performance, I contacted a few fellow developers and got them to do some tests. Hopefully now much of what I have seen (and what you have seen) makes sense. It seems people with high-end systems (SMP, SCSI, RAID5, server motherboards) experience the problem and people running single drive PCs do not. I still have not been able to do any true side-by-side testing on a server that is effected by this problem as they are all busy doing other important jobs. This has been an issue in trying to track this down from the start and led me doing comparison between the two machines that I used when reporting this bug. I'm now trying to find a suitable machine on which to perform an incontrovertable test.

Tobias and Byron, if you're listening, is your server running SCSI and/or software-RAID5?

Can you guys out in MySQL-land test this on a RedHat 9, SCSI, software-RAID5 machine?

I'm hoping that your previous apparent ambivalence to this problem was due to a philosophical objection to my test case rather than an indifference to operating system bugs that manifest themselves in MySQL. It seems to me it would still be best if MySQL confirmed this problem and approach RedHat with suggestions about where the issue might lie. If you don't agree then let me know and I'll consider putting together a case for RedHat.
[12 Aug 2003 21:04] Paul Coldrey
Alas, but no, I found myself an SMP machine and installed RedHat 9.0 with sofware-RAID5. My test case doesn't show the problem on this machine but noteably my intial problem when running from PHP is still apparent.