| Bug #36448 | Query running in parallel is 2 times slower than running from single client. | ||
|---|---|---|---|
| Submitted: | 1 May 2008 9:23 | Modified: | 13 May 2010 16:12 |
| Reporter: | Sveta Smirnova | Email Updates: | |
| Status: | Verified | Impact on me: | |
| Category: | MySQL Server: InnoDB storage engine | Severity: | S4 (Feature request) |
| Version: | 5.0 | OS: | Any (Mac OS X 10.4 Intel, Windows 2003) |
| Assigned to: | Assigned Account | CPU Architecture: | Any |
[1 May 2008 9:35]
Sveta Smirnova
Machine where tests were run with 2 cores.
[6 May 2008 21:16]
Sveta Smirnova
Not, this is not regression. But further investigation showed this seems to be only Windows and Mac issue. Actual results from my dev machine: 1 connection Average:0.13540138244629 2 connections Average:0.25121870994568
[7 May 2008 9:18]
Heikki Tuuri
Sveta, please show the CPU usage, disk usage, SHOW INNODB STATUS during the 1 client run and 2 client run. If 2 connections run slow, it might be 'thread thrashing'. Regards, Heikki
[13 May 2008 18:36]
Sveta Smirnova
iostat output for 1 client:
disk0 cpu
KB/t tps MB/s us sy id
0.00 0 0.00 21 9 69
0.00 0 0.00 23 8 69
0.00 0 0.00 21 13 66
0.00 0 0.00 20 11 69
0.00 0 0.00 21 7 71
0.00 0 0.00 15 15 70
0.00 0 0.00 7 7 86
32.00 1 0.03 12 12 76
0.00 0 0.00 13 5 82
0.00 0 0.00 14 9 77
0.00 0 0.00 15 6 80
0.00 0 0.00 17 9 74
0.00 0 0.00 25 8 67
0.00 0 0.00 11 13 76
0.00 0 0.00 18 8 74
0.00 0 0.00 9 9 82
0.00 0 0.00 13 8 79
4.00 1 0.00 10 9 80
0.00 0 0.00 9 13 77
0.00 0 0.00 14 8 79
iostat output for 2 clients:
disk0 cpu
KB/t tps MB/s us sy id
4.00 3 0.01 53 47 0
4.00 2 0.01 43 57 0
4.00 2 0.01 56 44 0
4.00 3 0.01 56 44 0
4.00 2 0.01 60 40 0
4.00 3 0.01 43 57 0
4.00 3 0.01 46 54 0
4.00 2 0.01 48 50 2
4.00 3 0.01 39 61 0
4.00 2 0.01 58 42 0
4.00 2 0.01 38 62 0
4.00 3 0.01 44 56 0
4.00 2 0.01 42 58 0
4.00 2 0.01 51 49 0
4.00 3 0.01 41 59 0
4.00 3 0.01 38 62 0
4.00 3 0.01 43 54 3
4.00 2 0.01 33 67 0
4.00 3 0.01 50 50 0
4.00 3 0.01 48 52 0
[13 May 2008 18:49]
Sveta Smirnova
SHOW INNODB STATUS for 1 client
Attachment: bug36448_1_client.txt.2 (application/octet-stream, text), 30.95 KiB.
[13 May 2008 18:50]
Sveta Smirnova
SHOW INNODB STATUS for 2 clients
Attachment: bug36448_2_client.txt.2 (application/octet-stream, text), 34.36 KiB.
[19 May 2008 17:29]
Sveta Smirnova
Total (instead of average) amount with 500 queries: 1 client: 301.83474326134 2 clients: 563.29699468613
[27 May 2008 11:31]
Sveta Smirnova
Results for 1 client: $php issue25343.php 4.8540599346161 3.7786149978638 2.7070178985596 2.1551229953766 3.8518319129944 2.8314869403839 2.9749522209167 2.7561650276184 2.6605479717255 2.5429630279541 Average:3.1112762928009 Total:31.112762928009 For 2 clients: $php issue25343.php 8.1746230125427 10.415666818619 12.733288049698 8.7776219844818 7.1542799472809 6.8446080684662 6.3468019962311 7.1387331485748 9.6486220359802 12.11611199379 Average:8.9350357055664 Total:89.350357055664
[27 May 2008 11:37]
Sveta Smirnova
New data is in file bug36448.sql.zip on the FTP server.
[24 Jun 2008 16:57]
Heikki Tuuri
Sveta, when you run SHOW INNODB STATUS\G, please put sleep(10) in between. In your run, it is executed many times per second, which may affect the running of the test program. This does not look like InnoDB congestion. There are quite few OS waits in InnoDB mutexes and rw-locks: ===================================== 080513 22:40:53 INNODB MONITOR OUTPUT ===================================== Per second averages calculated from the last 12 seconds ---------- SEMAPHORES ---------- OS WAIT ARRAY INFO: reservation count 12021, signal count 12022 Mutex spin waits 0, rounds 2667459, OS waits 1392 RW-shared spins 2379, OS waits 20; RW-excl spins 8041, OS waits 151 ... -------------- ROW OPERATIONS -------------- 2 queries inside InnoDB, 0 queries in queue 3 read views open inside InnoDB Main thread id 75666944, state: sleeping Number of rows inserted 5592, updated 0, deleted 0, read 19501745 0.00 inserts/s, 0.00 updates/s, 0.00 deletes/s, 32732.61 reads/s ===================================== 080513 22:40:53 INNODB MONITOR OUTPUT ===================================== Per second averages calculated from the last 0 seconds ---------- SEMAPHORES ---------- OS WAIT ARRAY INFO: reservation count 12021, signal count 12022 Mutex spin waits 0, rounds 2667459, OS waits 1392 RW-shared spins 2380, OS waits 20; RW-excl spins 8042, OS waits 151 In InnoDB 'thread thrashing' we should see threads in the OS wait array. The workload runs entirely in the buffer pool. No file I/O. What does vmstat 5 say during 1 thread and 2 thread runs? The congestion might be in the client programs (some strange mutex in the Perl/DBD library), or in MySQL's mutexes. Unfortunately, there is no command to check MySQL's mutexes. The vmstat output may reveal something. Regards, Heikki
[24 Jun 2008 19:28]
Sveta Smirnova
1 thread InnoDB status and vm_stat output
Attachment: bug36448_1.txt (text/plain), 6.97 KiB.
[24 Jun 2008 19:29]
Sveta Smirnova
2 threads InnoDB status and vm_stat output
Attachment: bug36448_2.txt (text/plain), 8.13 KiB.
[24 Jun 2008 19:31]
Sveta Smirnova
Heikki, requested data uploaded. As no vmstat on Mac, I used vm_stat which is similar.
Description: When running same query from 2 clients simultaneously results getting 2 times slower than if running from 1 client. Changing innodb_buffer_pool_size to larger value does not help. How to repeat: Load attached dump, then run following PHP script in 1, then 2 sessions and compare results: <?php mysql_connect('127.0.0.1:3350', 'root', ''); mysql_select_db('test'); $count = 50; $total = 0; for ($i = 0; $i < $count; $i ++) { $ts = microtime(true); mysql_query('select * from vault_safes_log where i64safeid = 48'); echo $time = (microtime(true) - $ts), "\n"; $total += $time; } echo 'Average:' . $total/$count . "\n"; ?>