List:General Discussion« Previous MessageNext Message »
From:Alexandre Vieira Date:September 2 2010 11:50am
Subject:Performance problems on MySQL
View as plain text  
Hi list,

I'm having some performance problems on my 5.0.45-log DB running on Solaris
8 (V240).

We only have one table and two apps selecting, updating, inserting and
deleting massively and randomly from this table.

The table is very simple. All SELECTs,INSERTs,UPDATEs and DELETEs have only
one condition on an unique varchar indexed column.

The table has 500k records and has been OPTIMIZED 32h ago.

I've ran some sampling and:

A SELECT costs between 400ms and 600ms.
An UPDATE costs between 800ms and 1300ms.
A DELETE costs between 900ms and 1300ms
An INSERT costs always 900ms 2000ms.

At any given time the DB is handling 60-80 operations every second. It does
not scale any more than this because all the application connections to the
DB are being used and waiting for the DB to move. Our application queues
requests and it lags our clients.

The perl mysqltuner only whines about "Query cache disabled" but since I get
an ~20 updates every second I can't get any query cache hits, so I disabled
it.

If it makes any difference, we're replicating everything to another server
that don't serve any queries.

The DB has a 32 hour uptime.

Any help is most welcome.

You can find my.cnf, show status and show innodb status below.

Kind regards
Alex

###############################
my.cnf:

sql-mode                        ="STRICT_ALL_TABLES"
old_passwords                   =1
skip-bdb
max_connections                 =100
max_allowed_packet              =1M
table_cache                     =512
sort_buffer_size                =2M
read_buffer_size                =4M
read_rnd_buffer_size            =8M
thread_cache_size               =16
query_cache_limit               =32M
thread_concurrency              =8
max_heap_table_size             =28M
tmp_table_size                  =12M
innodb_buffer_pool_size         =350M
innodb_additional_mem_pool_size =15M
innodb_log_buffer_size          =6M
innodb_flush_log_at_trx_commit  =1
innodb_lock_wait_timeout        =50

###############################

mysql> show status where Value NOT LIKE 0;
+-----------------------------------+------------+
| Variable_name                     | Value      |
+-----------------------------------+------------+
| Aborted_clients                   | 88         |
| Aborted_connects                  | 37590      |
| Binlog_cache_use                  | 2148392    |
| Bytes_received                    | 1117       |
| Bytes_sent                        | 8772       |
| Com_change_db                     | 1          |
| Com_delete                        | 4          |
| Com_insert                        | 3          |
| Com_select                        | 2          |
| Com_show_databases                | 1          |
| Com_show_fields                   | 3          |
| Com_show_status                   | 2          |
| Com_show_tables                   | 1          |
| Compression                       | OFF        |
| Connections                       | 276096     |
| Created_tmp_files                 | 5          |
| Created_tmp_tables                | 4          |
| Flush_commands                    | 1          |
| Handler_commit                    | 14         |
| Handler_prepare                   | 14         |
| Handler_read_key                  | 8          |
| Handler_read_rnd_next             | 263        |
| Handler_write                     | 395        |
| Innodb_buffer_pool_pages_data     | 6019       |
| Innodb_buffer_pool_pages_dirty    | 1858       |
| Innodb_buffer_pool_pages_flushed  | 593993     |
| Innodb_buffer_pool_pages_free     | 15784      |
| Innodb_buffer_pool_pages_misc     | 597        |
| Innodb_buffer_pool_pages_total    | 22400      |
| Innodb_buffer_pool_read_ahead_rnd | 1          |
| Innodb_buffer_pool_read_requests  | 42797013   |
| Innodb_buffer_pool_reads          | 3497       |
| Innodb_buffer_pool_write_requests | 19096507   |
| Innodb_data_fsyncs                | 4319683    |
| Innodb_data_pending_fsyncs        | 1          |
| Innodb_data_read                  | 60231680   |
| Innodb_data_reads                 | 3514       |
| Innodb_data_writes                | 4496721    |
| Innodb_data_written               | 1259458560 |
| Innodb_dblwr_pages_written        | 593993     |
| Innodb_dblwr_writes               | 12967      |
| Innodb_log_write_requests         | 2111208    |
| Innodb_log_writes                 | 4285654    |
| Innodb_os_log_fsyncs              | 4303114    |
| Innodb_os_log_pending_fsyncs      | 1          |
| Innodb_os_log_written             | 3264897024 |
| Innodb_page_size                  | 16384      |
| Innodb_pages_created              | 2476       |
| Innodb_pages_read                 | 3543       |
| Innodb_pages_written              | 593993     |
| Innodb_row_lock_time              | 1339668    |
| Innodb_row_lock_time_avg          | 379        |
| Innodb_row_lock_time_max          | 10631      |
| Innodb_row_lock_waits             | 3531       |
| Innodb_rows_deleted               | 31904      |
| Innodb_rows_inserted              | 530870     |
| Innodb_rows_read                  | 7885336    |
| Innodb_rows_updated               | 2100083    |
| Key_blocks_unused                 | 7159       |
| Key_blocks_used                   | 14         |
| Key_read_requests                 | 106        |
| Key_reads                         | 14         |
| Last_query_cost                   | 10.499000  |
| Max_used_connections              | 66         |
| Ndb_config_from_host              |            |
| Open_files                        | 54         |
| Open_tables                       | 126        |
| Qcache_free_blocks                | 1          |
| Qcache_hits                       | 18         |
| Qcache_inserts                    | 595        |
| Qcache_not_cached                 | 7611       |
| Questions                         | 12971115   |
| Rpl_status                        | NULL       |
| Select_scan                       | 4          |
| Slave_running                     | OFF        |
| Ssl_cipher                        |            |
| Ssl_cipher_list                   |            |
| Ssl_session_cache_mode            | NONE       |
| Ssl_version                       |            |
| Table_locks_immediate             | 4927708    |
| Table_locks_waited                | 67         |
| Threads_cached                    | 10         |
| Threads_connected                 | 42         |
| Threads_created                   | 4133       |
| Threads_running                   | 36         |
| Uptime                            | 120796     |
| Uptime_since_flush_status         | 120796     |
+-----------------------------------+------------+
87 rows in set (0.01 sec)

###############################

=====================================
100902 12:39:47 INNODB MONITOR OUTPUT
=====================================
Per second averages calculated from the last 19 seconds
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 63731, signal count 62253
Mutex spin waits 0, rounds 1686893, OS waits 41516
RW-shared spins 23291, OS waits 11428; RW-excl spins 4076, OS waits 3446
------------
TRANSACTIONS
------------
Trx id counter 0 1953324058
Purge done for trx's n:o < 0 1953323526 undo n:o < 0 0
History list length 172
Total number of lock structs in row lock hash table 9
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 0 0, not started, OS thread id 4121 waiting in InnoDB queue
mysql tables in use 1, locked 1
MySQL thread id 276150, query id 12973147 192.168.87.6 myuser_adm Sorting
result
SELECT********************
---TRANSACTION 0 0, not started, OS thread id 4119 waiting in InnoDB queue
mysql tables in use 1, locked 0
MySQL thread id 276149, query id 12973129 192.168.87.6 myuser_adm statistics
SELECT********************
---TRANSACTION 0 0, not started, OS thread id 4067 waiting in InnoDB queue
mysql tables in use 1, locked 0
MySQL thread id 276148, query id 12973102 192.168.87.6 myuser_adm statistics
SELECT********************
---TRANSACTION 0 1953324017, not started, OS thread id 4098 waiting in
InnoDB queue
mysql tables in use 1, locked 1
MySQL thread id 276144, query id 12973093 192.168.87.6 myuser_adm Updating
UPDATE********************
---TRANSACTION 0 1953323942, not started, OS thread id 4140
MySQL thread id 276135, query id 12972947 192.168.87.6 myuser_adm
---TRANSACTION 0 1953324045, not started, OS thread id 4074 waiting in
InnoDB queue
mysql tables in use 1, locked 1
MySQL thread id 276133, query id 12973157 192.168.87.6 myuser_adm update
INSERT********************
---TRANSACTION 0 1953324021, not started, OS thread id 4038
MySQL thread id 276130, query id 12973043 192.168.87.6 myuser_adm
---TRANSACTION 0 1953323971, not started, OS thread id 3873 waiting in
InnoDB queue
mysql tables in use 1, locked 0
MySQL thread id 276129, query id 12973112 192.168.87.6 myuser_adm statistics
SELECT********************
---TRANSACTION 0 1953324024, not started, OS thread id 4145 waiting in
InnoDB queue
mysql tables in use 1, locked 0
MySQL thread id 276124, query id 12973159 192.168.87.6 myuser_adm statistics
SELECT********************
---TRANSACTION 0 1953324027, not started, OS thread id 4003
MySQL thread id 276111, query id 12973050 192.168.87.6 myuser_adm
---TRANSACTION 0 1953323945, not started, OS thread id 3918 waiting in
InnoDB queue
mysql tables in use 1, locked 1
MySQL thread id 276107, query id 12973115 192.168.87.6 myuser_adm Sorting
result
SELECT********************
---TRANSACTION 0 1953324023, not started, OS thread id 4089 waiting in
InnoDB queue
mysql tables in use 1, locked 1
MySQL thread id 276093, query id 12973106 192.168.87.6 myuser_adm Updating
UPDATE********************
---TRANSACTION 0 1953323946, not started, OS thread id 4102
MySQL thread id 276081, query id 12972959 192.168.87.6 myuser_adm
---TRANSACTION 0 1953324029, not started, OS thread id 4143 waiting in
InnoDB queue
mysql tables in use 1, locked 0
MySQL thread id 276079, query id 12973167 192.168.87.6 myuser_adm statistics
SELECT********************
---TRANSACTION 0 1953324048, not started, OS thread id 3945 waiting in
InnoDB queue
mysql tables in use 1, locked 1
MySQL thread id 275987, query id 12973161 192.168.87.6 myuser_adm Updating
UPDATE********************
---TRANSACTION 0 1953324026, not started, OS thread id 4048 waiting in
InnoDB queue
mysql tables in use 1, locked 1
MySQL thread id 275976, query id 12973110 192.168.87.6 myuser_adm Updating
UPDATE********************
---TRANSACTION 0 1953324040, not started, OS thread id 4142 waiting in
InnoDB queue
mysql tables in use 1, locked 1
MySQL thread id 275975, query id 12973154 192.168.87.6 myuser_adm Updating
UPDATE********************
---TRANSACTION 0 1953323944, not started, OS thread id 3979 waiting in
InnoDB queue
mysql tables in use 1, locked 1
MySQL thread id 275946, query id 12973121 192.168.87.6 myuser_adm Sorting
result
SELECT********************
---TRANSACTION 0 1953324016, not started, OS thread id 4058 waiting in
InnoDB queue
mysql tables in use 1, locked 1
MySQL thread id 275931, query id 12973092 192.168.87.6 myuser_adm Updating
UPDATE********************
---TRANSACTION 0 1953324015, not started, OS thread id 4065 waiting in
InnoDB queue
mysql tables in use 1, locked 1
MySQL thread id 275913, query id 12973090 192.168.87.6 myuser_adm Updating
UPDATE********************
---TRANSACTION 0 1953324033, not started, OS thread id 4111 waiting in
InnoDB queue
mysql tables in use 1, locked 1
MySQL thread id 275907, query id 12973137 192.168.87.6 myuser_adm Updating
UPDATE********************
---TRANSACTION 0 1953323993, not started, OS thread id 4078 waiting in
InnoDB queue
mysql tables in use 1, locked 0
MySQL thread id 275889, query id 12973132 192.168.87.6 myuser_adm statistics
SELECT********************
---TRANSACTION 0 1953324011, not started, OS thread id 4136 waiting in
InnoDB queue
mysql tables in use 1, locked 1
MySQL thread id 275887, query id 12973089 192.168.87.6 myuser_adm Updating
UPDATE********************
---TRANSACTION 0 1953324034, not started, OS thread id 4014 waiting in
InnoDB queue
mysql tables in use 1, locked 0
MySQL thread id 275888, query id 12973166 192.168.87.6 myuser_adm statistics
SELECT********************
---TRANSACTION 0 1953323997, not started, OS thread id 4123 waiting in
InnoDB queue
mysql tables in use 1, locked 0
MySQL thread id 275856, query id 12973133 192.168.87.6 myuser_adm statistics
SELECT********************
---TRANSACTION 0 1953324002, not started, OS thread id 3999 waiting in
InnoDB queue
mysql tables in use 1, locked 0
MySQL thread id 275827, query id 12973151 192.168.87.6 myuser_adm statistics
SELECT********************
---TRANSACTION 0 1953323985, not started, OS thread id 4115 waiting in
InnoDB queue
mysql tables in use 1, locked 0
MySQL thread id 275809, query id 12973105 192.168.87.6 myuser_adm statistics
SELECT********************
---TRANSACTION 0 1953324036, not started, OS thread id 4133 sleeping before
joining InnoDB queue
mysql tables in use 1, locked 0
MySQL thread id 275784, query id 12973169 192.168.87.6 myuser_adm statistics
SELECT********************
---TRANSACTION 0 1953324031, not started, OS thread id 4134 waiting in
InnoDB queue
mysql tables in use 1, locked 1
MySQL thread id 275715, query id 12973136 192.168.87.6 myuser_adm Updating
UPDATE********************
---TRANSACTION 0 1953324000, not started, OS thread id 4124 waiting in
InnoDB queue
mysql tables in use 1, locked 0
MySQL thread id 275665, query id 12973149 192.168.87.6 myuser_adm statistics
SELECT********************
---TRANSACTION 0 1953324009, not started, OS thread id 4130 waiting in
InnoDB queue
mysql tables in use 1, locked 0
MySQL thread id 275539, query id 12973155 192.168.87.6 myuser_adm statistics
SELECT********************
---TRANSACTION 0 1953323988, not started, OS thread id 4010 waiting in
InnoDB queue
mysql tables in use 1, locked 0
MySQL thread id 275263, query id 12973108 192.168.87.6 myuser_adm statistics
SELECT********************
---TRANSACTION 0 1953323990, not started, OS thread id 4086 waiting in
InnoDB queue
mysql tables in use 1, locked 0
MySQL thread id 274948, query id 12973123 192.168.87.6 myuser_adm statistics
SELECT********************
---TRANSACTION 0 1953324032, not started, OS thread id 3934 waiting in
InnoDB queue
mysql tables in use 1, locked 0
MySQL thread id 274703, query id 12973163 192.168.87.6 myuser_adm statistics
SELECT********************
---TRANSACTION 0 1953292243, not started, OS thread id 4046
MySQL thread id 274066, query id 12973170 localhost root
show innodb status
---TRANSACTION 0 1953324057, ACTIVE 0 sec, OS thread id 4127, thread
declared inside InnoDB 498
mysql tables in use 1, locked 1
2 lock struct(s), heap size 320, undo log entries 1
MySQL thread id 276140, query id 12973085 192.168.87.6 myuser_adm update
INSERT********************
---TRANSACTION 0 1953324055, ACTIVE 0 sec, OS thread id 4144, thread
declared inside InnoDB 498
mysql tables in use 1, locked 1
2 lock struct(s), heap size 320, undo log entries 1
MySQL thread id 276147, query id 12973082 192.168.87.6 myuser_adm update
INSERT********************
---TRANSACTION 0 1953324053, ACTIVE 0 sec, OS thread id 4141, thread
declared inside InnoDB 499
mysql tables in use 1, locked 1
2 lock struct(s), heap size 320, undo log entries 1
MySQL thread id 275720, query id 12973078 192.168.87.6 myuser_adm end
UPDATE********************
---TRANSACTION 0 1953324051, ACTIVE 0 sec, OS thread id 4029, thread
declared inside InnoDB 499
mysql tables in use 1, locked 1
2 lock struct(s), heap size 320, undo log entries 1
MySQL thread id 273472, query id 12973075 192.168.87.6 myuser_adm end
UPDATE********************
---TRANSACTION 0 1953324049, ACTIVE 1 sec, OS thread id 4109, thread
declared inside InnoDB 499
mysql tables in use 1, locked 1
2 lock struct(s), heap size 320, undo log entries 1
MySQL thread id 274973, query id 12973084 192.168.87.6 myuser_adm end
UPDATE********************
---TRANSACTION 0 1953324046, ACTIVE 1 sec, OS thread id 4126, thread
declared inside InnoDB 498
mysql tables in use 1, locked 1
2 lock struct(s), heap size 320, undo log entries 1
MySQL thread id 276146, query id 12973081 192.168.87.6 myuser_adm update
INSERT********************
---TRANSACTION 0 1953324043, ACTIVE 1 sec, OS thread id 4122, thread
declared inside InnoDB 499
mysql tables in use 1, locked 1
2 lock struct(s), heap size 320, undo log entries 1
MySQL thread id 274989, query id 12973069 192.168.87.6 myuser_adm end
UPDATE********************
---TRANSACTION 0 1953324041, ACTIVE 1 sec, OS thread id 4099, thread
declared inside InnoDB 498
mysql tables in use 1, locked 1
2 lock struct(s), heap size 320, undo log entries 1
MySQL thread id 276145, query id 12973066 192.168.87.6 myuser_adm update
INSERT********************
---TRANSACTION 0 1953324038, ACTIVE (PREPARED) 1 sec, OS thread id 4077
preparing
mysql tables in use 1, locked 1
2 lock struct(s), heap size 320, undo log entries 1
MySQL thread id 275321, query id 12973067 192.168.87.6 myuser_adm end
UPDATE********************
--------
FILE I/O
--------
I/O thread 0 state: waiting for i/o request (insert buffer thread)
I/O thread 1 state: waiting for i/o request (log thread)
I/O thread 2 state: waiting for i/o request (read thread)
I/O thread 3 state: waiting for i/o request (write thread)
Pending normal aio reads: 0, aio writes: 0,
 ibuf aio reads: 0, log i/o's: 0, sync i/o's: 0
Pending flushes (fsync) log: 1; buffer pool: 0
3514 OS file reads, 4497412 OS file writes, 4320374 OS fsyncs
0.00 reads/s, 0 avg bytes/read, 41.05 writes/s, 40.73 fsyncs/s
-------------------------------------
INSERT BUFFER AND ADAPTIVE HASH INDEX
-------------------------------------
Ibuf: size 1, free list len 0, seg size 2,
0 inserts, 0 merged recs, 0 merges
Hash table size 1452727, used cells 496505, node heap has 597 buffer(s)
31.26 hash searches/s, 15.31 non-hash searches/s
---
LOG
---
Log sequence number 61 3783563525
Log flushed up to   61 3783563173
Last checkpoint at  61 3778869606
1 pending log writes, 0 pending chkp writes
4297652 log i/o's done, 40.63 log i/o's/second
----------------------
BUFFER POOL AND MEMORY
----------------------
Total memory allocated 419047082; in additional pool allocated 2578048
Buffer pool size   22400
Free buffers       15784
Database pages     6019
Modified db pages  1895
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages read 3543, created 2476, written 594057
0.00 reads/s, 0.00 creates/s, 6.47 writes/s
Buffer pool hit rate 1000 / 1000
--------------
ROW OPERATIONS
--------------
8 queries inside InnoDB, 29 queries in queue
1 read views open inside InnoDB
Main thread id 11, state: sleeping
Number of rows inserted 530873, updated 2100423, deleted 31904, read 7886015
0.21 inserts/s, 19.95 updates/s, 0.00 deletes/s, 40.05 reads/s
----------------------------
END OF INNODB MONITOR OUTPUT
============================

###############################

Thread
Performance problems on MySQLAlexandre Vieira2 Sep
  • Re: Performance problems on MySQLJohnny Withers2 Sep
  • Re: Performance problems on MySQLJohn Daisley2 Sep