MySQL Bugs: #40531: Slow performances on INSERT ... SELECT

Bug #40531	Slow performances on INSERT ... SELECT
Submitted:	5 Nov 2008 14:58	Modified:	5 Nov 2008 16:52
Reporter:	jocelyn fournier (Silver Quality Contributor)	Email Updates:
Status:	Not a Bug	Impact on me:	None
Category:	MySQL Server	Severity:	S5 (Performance)
Version:	5.0.67	OS:	Linux
Assigned to:		CPU Architecture:	Any
Tags:	qc

Description:
Hi,

I'm experiencing a weird performance issue : 

when executing a specific really small INSERT ... SELECT, it takes at lot of time to finish the query (1.90 sec for 6 lines to be inserted).

The SELECT in itself is really fast, the INSERT with hardcoded values also, but not the INSERT ... SELECT.

According to the profiling, all the time is spent inside the init phase, with a lot of page faults and context switches :

             Status: init
           Duration: 1.802935
           CPU_user: 0.768048
         CPU_system: 1.036065
  Context_voluntary: 180
Context_involuntary: 97
       Block_ops_in: 0
      Block_ops_out: 0
      Messages_sent: 0
  Messages_received: 0
  Page_faults_major: 0
  Page_faults_minor: 524293
              Swaps: 0
    Source_function: mysql_select
        Source_file: sql_select.cc
        Source_line: 2261

What kind of parameters in the config file could influence this kind of result ?

Regards,
  Jocelyn

How to repeat:
DROP TABLE IF EXISTS t1;
CREATE TABLE `t1` (`id_tag` int(10) unsigned NOT NULL default '0',
`id_media` int(10) unsigned NOT NULL default '0',
`id_user` int(10) unsigned NOT NULL default '0',
type tinyint(1) unsigned NOT NULL default '0',
`score` mediumint(8) unsigned NOT NULL default '0',
PRIMARY KEY (id_tag, id_media),
UNIQUE (id_media, id_tag),
UNIQUE id_media_2 (id_user, id_tag, id_media, type),
KEY id_user (id_user, id_tag, score, type),
KEY type (type, id_tag)
) ENGINE=MyISAM;

INSERT INTO `t1` (`id_tag`, `id_media`, `id_user`, `type`, `score`) VALUES
(1, 1, 1, 2, 0),
(1, 2, 1, 2, 0),
(1, 3, 1, 2, 0),
(1, 4, 1, 2, 0),
(1, 5, 1, 2, 0),
(1, 6, 1, 2, 0),
(1, 7, 1, 2, 0),
(1, 8, 1, 2, 0),
(1, 9, 1, 2, 0),
(1, 10, 1, 2, 0),
(1, 11, 1, 2, 0),
(1, 12, 1, 2, 0),
(1, 13, 1, 2, 0),
(1, 14, 1, 2, 0),
(1, 15, 1, 2, 0),
(1, 16, 1, 2, 0),
(1, 17, 1, 2, 0),
(1, 18, 1, 2, 0),
(1, 19, 1, 2, 0),
(1, 20, 1, 2, 0),
(1, 21, 1, 2, 0),
(1, 22, 1, 2, 0),
(1, 23, 1, 2, 0),
(2, 35, 3, 2, 0),
(3, 35, 3, 2, 0),
(2, 34, 3, 2, 0),
(3, 34, 3, 2, 0),
(2, 33, 3, 2, 0),
(3, 33, 3, 2, 0),
(2, 32, 3, 2, 0),
(3, 32, 3, 2, 0),
(2, 31, 3, 2, 0),
(3, 31, 3, 2, 0),
(4, 49, 4, 2, 0),
(4, 48, 4, 2, 0),
(4, 47, 4, 2, 0),
(4, 46, 4, 2, 0),
(4, 45, 4, 2, 0),
(4, 44, 4, 2, 0),
(4, 43, 4, 2, 0),
(5, 54, 3, 2, 0),
(1, 62, 3, 2, 0),
(6, 71, 3, 3, 0);

DROP TABLE IF EXISTS t2;
CREATE TABLE `t2` (
`id_tag` int(10) unsigned NOT NULL default '0',
 type tinyint(1) unsigned NOT NULL default '0',
 `score` mediumint(8) unsigned NOT NULL default '0',
 `count` mediumint(8) unsigned NOT NULL default '0',
 PRIMARY KEY (id_tag, type),
 KEY type (type)
) ENGINE=MyISAM;

INSERT IGNORE INTO t2 (id_tag, score, count, type) SELECT tm.id_tag, SUM(tm.score), COUNT(*), 0 FROM t1 tm FORCE INDEX (PRIMARY) GROUP BY tm.id_tag;

Query OK, 6 rows affected (1.91 sec)

=> really slow insertion time

mysql> show profile;
+----------------------+----------+
| Status               | Duration |
+----------------------+----------+
| starting             | 0.000044 |
| checking permissions | 0.000003 |
| Opening tables       | 0.000074 |
| System lock          | 0.000002 |
| Table lock           | 0.000011 |
| init                 | 1.799125 |
| optimizing           | 0.000011 |
| statistics           | 0.000021 |
| preparing            | 0.000011 |
| executing            | 0.000006 |
| Sorting result       | 0.000002 |
| Sending data         | 0.102791 |
| Creating index       | 0.000020 |
| Repair by sorting    | 0.000104 |
| Saving state         | 0.000016 |
| Creating index       | 0.000002 |
| Sending data         | 0.000066 |
| end                  | 0.000004 |
| end                  | 0.000007 |
| query end            | 0.000003 |
| freeing items        | 0.000009 |
| closing tables       | 0.000004 |
| logging slow query   | 0.000001 |
| cleaning up          | 0.000002 |
+----------------------+----------+
24 rows in set (0.00 sec)

SELECT tm.id_tag, SUM(tm.score), COUNT(*), 0 FROM t1 tm FORCE INDEX (PRIMARY) GROUP BY tm.id_tag;
+--------+---------------+----------+---+
| id_tag | SUM(tm.score) | COUNT(*) | 0 |
+--------+---------------+----------+---+
|      1 |             0 |        1 | 0 |
|      2 |             0 |        1 | 0 |
|      3 |             0 |        1 | 0 |
|      4 |             0 |        1 | 0 |
|      5 |             0 |        1 | 0 |
|      6 |             0 |        1 | 0 |
+--------+---------------+----------+---+
6 rows in set (0.00 sec)

=> really quick select

INSERT IGNORE INTO t2 (id_tag, score, count, type) VALUES (1,0,24,0),(2,0,5,0),(3,0,5,0),(4,0,7,0),(5,0,1,0),(6,0,1,0);
Query OK, 0 rows affected (0.00 sec)

=> really quick insert

Thank you for a problem report. Sorry, but I can not repeat the behaviour described with a newer version:

C:\Program Files\MySQL\MySQL Server 5.0\bin>mysql -P3308 -uroot -proot test
Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 13
Server version: 5.0.70-enterprise-gpl-nt-log MySQL Enterprise Server (GPL)

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

mysql> DROP TABLE IF EXISTS t1;
Query OK, 0 rows affected, 1 warning (0.03 sec)

mysql> CREATE TABLE `t1` (`id_tag` int(10) unsigned NOT NULL default '0',
    -> `id_media` int(10) unsigned NOT NULL default '0',
    -> `id_user` int(10) unsigned NOT NULL default '0',
    -> type tinyint(1) unsigned NOT NULL default '0',
    -> `score` mediumint(8) unsigned NOT NULL default '0',
    -> PRIMARY KEY (id_tag, id_media),
    -> UNIQUE (id_media, id_tag),
    -> UNIQUE id_media_2 (id_user, id_tag, id_media, type),
    -> KEY id_user (id_user, id_tag, score, type),
    -> KEY type (type, id_tag)
    -> ) ENGINE=MyISAM;
Query OK, 0 rows affected (0.14 sec)

mysql> INSERT INTO `t1` (`id_tag`, `id_media`, `id_user`, `type`, `score`) VALUE
S
    -> (1, 1, 1, 2, 0),
    -> (1, 2, 1, 2, 0),
    -> (1, 3, 1, 2, 0),
    -> (1, 4, 1, 2, 0),
    -> (1, 5, 1, 2, 0),
    -> (1, 6, 1, 2, 0),
    -> (1, 7, 1, 2, 0),
    -> (1, 8, 1, 2, 0),
    -> (1, 9, 1, 2, 0),
    -> (1, 10, 1, 2, 0),
    -> (1, 11, 1, 2, 0),
    -> (1, 12, 1, 2, 0),
    -> (1, 13, 1, 2, 0),
    -> (1, 14, 1, 2, 0),
    -> (1, 15, 1, 2, 0),
    -> (1, 16, 1, 2, 0),
    -> (1, 17, 1, 2, 0),
    -> (1, 18, 1, 2, 0),
    -> (1, 19, 1, 2, 0),
    -> (1, 20, 1, 2, 0),
    -> (1, 21, 1, 2, 0),
    -> (1, 22, 1, 2, 0),
    -> (1, 23, 1, 2, 0),
    -> (2, 35, 3, 2, 0),
    -> (3, 35, 3, 2, 0),
    -> (2, 34, 3, 2, 0),
    -> (3, 34, 3, 2, 0),
    -> (2, 33, 3, 2, 0),
    -> (3, 33, 3, 2, 0),
    -> (2, 32, 3, 2, 0),
    -> (3, 32, 3, 2, 0),
    -> (2, 31, 3, 2, 0),
    -> (3, 31, 3, 2, 0),
    -> (4, 49, 4, 2, 0),
    -> (4, 48, 4, 2, 0),
    -> (4, 47, 4, 2, 0),
    -> (4, 46, 4, 2, 0),
    -> (4, 45, 4, 2, 0),
    -> (4, 44, 4, 2, 0),
    -> (4, 43, 4, 2, 0),
    -> (5, 54, 3, 2, 0),
    -> (1, 62, 3, 2, 0),
    -> (6, 71, 3, 3, 0);
Query OK, 43 rows affected (0.11 sec)
Records: 43  Duplicates: 0  Warnings: 0

mysql> DROP TABLE IF EXISTS t2;
Query OK, 0 rows affected (0.08 sec)

mysql> CREATE TABLE `t2` (
    -> `id_tag` int(10) unsigned NOT NULL default '0',
    ->  type tinyint(1) unsigned NOT NULL default '0',
    ->  `score` mediumint(8) unsigned NOT NULL default '0',
    ->  `count` mediumint(8) unsigned NOT NULL default '0',
    ->  PRIMARY KEY (id_tag, type),
    ->  KEY type (type)
    -> ) ENGINE=MyISAM;
Query OK, 0 rows affected (0.13 sec)

mysql> SELECT tm.id_tag, SUM(tm.score),
    -> COUNT(*), 0 FROM t1 tm FORCE INDEX (PRIMARY) GROUP BY tm.id_tag;
+--------+---------------+----------+---+
| id_tag | SUM(tm.score) | COUNT(*) | 0 |
+--------+---------------+----------+---+
|      1 |             0 |       24 | 0 |
|      2 |             0 |        5 | 0 |
|      3 |             0 |        5 | 0 |
|      4 |             0 |        7 | 0 |
|      5 |             0 |        1 | 0 |
|      6 |             0 |        1 | 0 |
+--------+---------------+----------+---+
6 rows in set (0.20 sec)

mysql> SELECT tm.id_tag, SUM(tm.score),
    -> COUNT(*), 0 FROM t1 tm GROUP BY tm.id_tag;
+--------+---------------+----------+---+
| id_tag | SUM(tm.score) | COUNT(*) | 0 |
+--------+---------------+----------+---+
|      1 |             0 |       24 | 0 |
|      2 |             0 |        5 | 0 |
|      3 |             0 |        5 | 0 |
|      4 |             0 |        7 | 0 |
|      5 |             0 |        1 | 0 |
|      6 |             0 |        1 | 0 |
+--------+---------------+----------+---+
6 rows in set (0.02 sec)

mysql> INSERT IGNORE INTO t2 (id_tag, score, count, type) SELECT tm.id_tag, SUM(
tm.score),
    -> COUNT(*), 0 FROM t1 tm FORCE INDEX (PRIMARY) GROUP BY tm.id_tag;
Query OK, 6 rows affected (0.06 sec)
Records: 6  Duplicates: 0  Warnings: 0

Am I missing something?

Hi,

No, I can't reproduce the problem on all of my server, that's why I suspect a particular configuration (CPU/cache, or MySQL parameters) which could cause this kind of issue. (context switch + page fault)
The server is a 64 bit, on Debien Etch 64, BiXEON E5420 @ 2.5GHz + 4GB RAM, 8GB Swap. 
MySQL is running replication (it's the master).
If I transform the t2 table into a Memory table the issue doesn't occur anymore.

Regards,
  Jocelyn

Then, please, send your my.cnf, SHOW PROCESSLIST results while INSERT is "hanging" (if possible) and SHOW GLOBAL STATUS results for a review.

Just curious : even if it's not slow on your system, do you have a lot of page_fault during the init phase ? (on one of my other servers, the query is not slow, but still have a few page_fault)

Ok, copy pasting the my.cnf helps : there were a typo in the my.cnf on the read_buffer_size value (8888M instead of 8M), which causes this issue :)
I think you can close the bug report now ;)

Thanks and regards,
  Jocelyn

So this is not a bug.

Although it doesn't seems to be a bug, I'm curious to know why only the INSERT ... SELECT kind of query was affected by the slow perf issue, and not a standard SELECT ... query ?

Thanks and regards,
  Jocelyn

Jocelyn, take a look at bug #45840 which is probably what you were hitting..