I've created a PHP daemon that reads records from a MySQL InnoDB-table, analyses it and then updates the record. This process is spread between multiple workers (and servers) using Redis.
However, the performance of MySQL is horrible. I've tried to optimize the MySQL-config using multiple tools, but I can't seem to figure out the exact problem. All I can see is that there is a lot of IO waiting to be done.
The setup is a VMware running on Oracle Linux Enterprise v6.3 with 12GB RAM and cores.
When I run "SHOW ENGINE INNODB STATUS" I see a lot of IO requests. Since row updates are so high, I assume that my workers are processing data efficiently?
=====================================
141201 19:32:52 INNODB MONITOR OUTPUT
=====================================
Per second averages calculated from the last 27 seconds
-----------------
BACKGROUND THREAD
-----------------
srv_master_thread loops: 9829 1_second, 9828 sleeps, 974 10_second, 94 background, 94 flush
srv_master_thread log flush and writes: 9911
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 10197, signal count 11313
Mutex spin waits 54011, rounds 230308, OS waits 4959
RW-shared spins 6084, rounds 94790, OS waits 2201
RW-excl spins 2837, rounds 113156, OS waits 2946
Spin rounds per wait: 4.26 mutex, 15.58 RW-shared, 39.89 RW-excl
------------
TRANSACTIONS
------------
Trx id counter 4CE7EF
Purge done for trx's n:o < 4CD06D undo n:o < 0
History list length 5131
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 0, not started
MySQL thread id 44630, OS thread handle 0x7fbd7f5a7700, query id 1006406 localhost root
SHOW ENGINE INNODB STATUS
---TRANSACTION 4CE7CD, not started
MySQL thread id 44628, OS thread handle 0x7fbd7f462700, query id 1006382 192.168.83.211 uzmsgusr
---TRANSACTION 4CC79D, not started
MySQL thread id 42572, OS thread handle 0x7fbd7f629700, query id 1000942 localhost uzmsgusr
---TRANSACTION 4CC233, not started
MySQL thread id 39337, OS thread handle 0x7fbd7f29b700, query id 1000163 192.168.85.227 uzmsgusr
---TRANSACTION 4CE6B0, not started
MySQL thread id 13910, OS thread handle 0x7fbd67fff700, query id 1006203 192.168.83.211 uzmsgusr
---TRANSACTION 4CE287, not started
MySQL thread id 13906, OS thread handle 0x7fbd7f6ec700, query id 1005432 192.168.83.211 uzmsgusr
---TRANSACTION 4CE7D4, not started
MySQL thread id 13900, OS thread handle 0x7fbd7f3e0700, query id 1006392 192.168.83.211 uzmsgusr
---TRANSACTION 4CE289, not started
MySQL thread id 13903, OS thread handle 0x7fbd7f5e8700, query id 1005436 192.168.83.211 uzmsgusr
---TRANSACTION 4CE6AC, not started
MySQL thread id 13895, OS thread handle 0x7fbd7f35e700, query id 1006198 192.168.83.211 uzmsgusr
---TRANSACTION 4CE757, not started
MySQL thread id 13899, OS thread handle 0x7fbd7f31d700, query id 1006305 192.168.83.211 uzmsgusr
---TRANSACTION 4CE752, not started
MySQL thread id 13894, OS thread handle 0x7fbd7f72d700, query id 1006300 192.168.83.211 uzmsgusr
---TRANSACTION 4CE5E6, not started
MySQL thread id 13893, OS thread handle 0x7fbed404d700, query id 1006075 192.168.83.211 uzmsgusr
---TRANSACTION 4CE24E, not started
MySQL thread id 12411, OS thread handle 0x7fbd7f421700, query id 1005371 172.16.81.239 uzmsgusr
---TRANSACTION 4CE7B3, not started
MySQL thread id 5142, OS thread handle 0x7fbd7f39f700, query id 1006367 192.168.85.227 uzmsgusr
---TRANSACTION 4CE76D, not started
MySQL thread id 5141, OS thread handle 0x7fbd7f6ab700, query id 1006324 192.168.85.227 uzmsgusr
---TRANSACTION 4CD63E, not started
MySQL thread id 5140, OS thread handle 0x7fbd7f4e4700, query id 1003410 192.168.85.227 uzmsgusr
---TRANSACTION 4CE5F2, not started
MySQL thread id 2, OS thread handle 0x7fbed40cf700, query id 1006081 127.0.0.1 uzmsgusr
---TRANSACTION 4CE7EE, ACTIVE 0 sec inserting, thread declared inside InnoDB 500
mysql tables in use 1, locked 1
ROLLING BACK 2 lock struct(s), heap size 376, 1 row lock(s)
MySQL thread id 39339, OS thread handle 0x7fbd7f25a700, query id 1006405 192.168.85.227 uzmsgusr update
INSERT INTO iplist_dhcp (mac, ip, hostname, client, wifi_device, wifi_profile, pxe_enabled, source, polltime) VALUES ('00:18:78:00:62:8D', '172.20.18.67', 'RND-91548', 'RND-91548', 0, NULL, '', 'uzgent', 1417458772) ON DUPLICATE KEY UPDATE mac = '00:18:78:00:62:8D', ip = '172.20.18.67', hostname = 'RND-91548', client = 'RND-91548', wifi_device = 0, wifi_profile = NULL, pxe_enabled = '', source = 'uzgent', polltime = 1417458772
--------
FILE I/O
--------
I/O thread 0 state: waiting for completed aio requests (insert buffer thread)
I/O thread 1 state: waiting for completed aio requests (log thread)
I/O thread 2 state: waiting for completed aio requests (read thread)
I/O thread 3 state: waiting for completed aio requests (read thread)
I/O thread 4 state: waiting for completed aio requests (read thread)
I/O thread 5 state: waiting for completed aio requests (read thread)
I/O thread 6 state: waiting for completed aio requests (read thread)
I/O thread 7 state: waiting for completed aio requests (read thread)
I/O thread 8 state: waiting for completed aio requests (read thread)
I/O thread 9 state: waiting for completed aio requests (read thread)
I/O thread 10 state: waiting for completed aio requests (read thread)
I/O thread 11 state: waiting for completed aio requests (read thread)
I/O thread 12 state: waiting for completed aio requests (read thread)
I/O thread 13 state: waiting for completed aio requests (read thread)
I/O thread 14 state: waiting for completed aio requests (read thread)
I/O thread 15 state: waiting for completed aio requests (read thread)
I/O thread 16 state: waiting for completed aio requests (read thread)
I/O thread 17 state: waiting for completed aio requests (read thread)
I/O thread 18 state: waiting for completed aio requests (read thread)
I/O thread 19 state: waiting for completed aio requests (read thread)
I/O thread 20 state: waiting for completed aio requests (read thread)
I/O thread 21 state: waiting for completed aio requests (read thread)
I/O thread 22 state: waiting for completed aio requests (read thread)
I/O thread 23 state: waiting for completed aio requests (read thread)
I/O thread 24 state: waiting for completed aio requests (read thread)
I/O thread 25 state: waiting for completed aio requests (read thread)
I/O thread 26 state: waiting for completed aio requests (read thread)
I/O thread 27 state: waiting for completed aio requests (read thread)
I/O thread 28 state: waiting for completed aio requests (read thread)
I/O thread 29 state: waiting for completed aio requests (read thread)
I/O thread 30 state: waiting for completed aio requests (read thread)
I/O thread 31 state: waiting for completed aio requests (read thread)
I/O thread 32 state: waiting for completed aio requests (read thread)
I/O thread 33 state: waiting for completed aio requests (read thread)
I/O thread 34 state: waiting for completed aio requests (read thread)
I/O thread 35 state: waiting for completed aio requests (read thread)
I/O thread 36 state: waiting for completed aio requests (read thread)
I/O thread 37 state: waiting for completed aio requests (read thread)
I/O thread 38 state: waiting for completed aio requests (read thread)
I/O thread 39 state: waiting for completed aio requests (read thread)
I/O thread 40 state: waiting for completed aio requests (read thread)
I/O thread 41 state: waiting for completed aio requests (read thread)
I/O thread 42 state: waiting for completed aio requests (read thread)
I/O thread 43 state: waiting for completed aio requests (read thread)
I/O thread 44 state: waiting for completed aio requests (read thread)
I/O thread 45 state: waiting for completed aio requests (read thread)
I/O thread 46 state: waiting for completed aio requests (read thread)
I/O thread 47 state: waiting for completed aio requests (read thread)
I/O thread 48 state: waiting for completed aio requests (read thread)
I/O thread 49 state: waiting for completed aio requests (read thread)
I/O thread 50 state: waiting for completed aio requests (read thread)
I/O thread 51 state: waiting for completed aio requests (read thread)
I/O thread 52 state: waiting for completed aio requests (read thread)
I/O thread 53 state: waiting for completed aio requests (read thread)
I/O thread 54 state: waiting for completed aio requests (read thread)
I/O thread 55 state: waiting for completed aio requests (read thread)
I/O thread 56 state: waiting for completed aio requests (read thread)
I/O thread 57 state: waiting for completed aio requests (read thread)
I/O thread 58 state: waiting for completed aio requests (read thread)
I/O thread 59 state: waiting for completed aio requests (read thread)
I/O thread 60 state: waiting for completed aio requests (read thread)
I/O thread 61 state: waiting for completed aio requests (read thread)
I/O thread 62 state: waiting for completed aio requests (read thread)
I/O thread 63 state: waiting for completed aio requests (read thread)
I/O thread 64 state: waiting for completed aio requests (read thread)
I/O thread 65 state: waiting for completed aio requests (read thread)
I/O thread 66 state: waiting for completed aio requests (write thread)
I/O thread 67 state: waiting for completed aio requests (write thread)
I/O thread 68 state: waiting for completed aio requests (write thread)
I/O thread 69 state: waiting for completed aio requests (write thread)
I/O thread 70 state: waiting for completed aio requests (write thread)
I/O thread 71 state: waiting for completed aio requests (write thread)
I/O thread 72 state: waiting for completed aio requests (write thread)
I/O thread 73 state: waiting for completed aio requests (write thread)
I/O thread 74 state: waiting for completed aio requests (write thread)
I/O thread 75 state: waiting for completed aio requests (write thread)
I/O thread 76 state: waiting for completed aio requests (write thread)
I/O thread 77 state: waiting for completed aio requests (write thread)
I/O thread 78 state: waiting for completed aio requests (write thread)
I/O thread 79 state: waiting for completed aio requests (write thread)
I/O thread 80 state: waiting for completed aio requests (write thread)
I/O thread 81 state: waiting for completed aio requests (write thread)
I/O thread 82 state: waiting for completed aio requests (write thread)
I/O thread 83 state: waiting for completed aio requests (write thread)
I/O thread 84 state: waiting for completed aio requests (write thread)
I/O thread 85 state: waiting for completed aio requests (write thread)
I/O thread 86 state: waiting for completed aio requests (write thread)
I/O thread 87 state: waiting for completed aio requests (write thread)
I/O thread 88 state: waiting for completed aio requests (write thread)
I/O thread 89 state: waiting for completed aio requests (write thread)
I/O thread 90 state: waiting for completed aio requests (write thread)
I/O thread 91 state: waiting for completed aio requests (write thread)
I/O thread 92 state: waiting for completed aio requests (write thread)
I/O thread 93 state: waiting for completed aio requests (write thread)
I/O thread 94 state: waiting for completed aio requests (write thread)
I/O thread 95 state: waiting for completed aio requests (write thread)
I/O thread 96 state: waiting for completed aio requests (write thread)
I/O thread 97 state: waiting for completed aio requests (write thread)
I/O thread 98 state: waiting for completed aio requests (write thread)
I/O thread 99 state: waiting for completed aio requests (write thread)
I/O thread 100 state: waiting for completed aio requests (write thread)
I/O thread 101 state: waiting for completed aio requests (write thread)
I/O thread 102 state: waiting for completed aio requests (write thread)
I/O thread 103 state: waiting for completed aio requests (write thread)
I/O thread 104 state: waiting for completed aio requests (write thread)
I/O thread 105 state: waiting for completed aio requests (write thread)
I/O thread 106 state: waiting for completed aio requests (write thread)
I/O thread 107 state: waiting for completed aio requests (write thread)
I/O thread 108 state: waiting for completed aio requests (write thread)
I/O thread 109 state: waiting for completed aio requests (write thread)
I/O thread 110 state: waiting for completed aio requests (write thread)
I/O thread 111 state: waiting for completed aio requests (write thread)
I/O thread 112 state: waiting for completed aio requests (write thread)
I/O thread 113 state: waiting for completed aio requests (write thread)
I/O thread 114 state: waiting for completed aio requests (write thread)
I/O thread 115 state: waiting for completed aio requests (write thread)
I/O thread 116 state: waiting for completed aio requests (write thread)
I/O thread 117 state: waiting for completed aio requests (write thread)
I/O thread 118 state: waiting for completed aio requests (write thread)
I/O thread 119 state: waiting for completed aio requests (write thread)
I/O thread 120 state: waiting for completed aio requests (write thread)
I/O thread 121 state: waiting for completed aio requests (write thread)
I/O thread 122 state: waiting for completed aio requests (write thread)
I/O thread 123 state: waiting for completed aio requests (write thread)
I/O thread 124 state: waiting for completed aio requests (write thread)
I/O thread 125 state: waiting for completed aio requests (write thread)
I/O thread 126 state: waiting for completed aio requests (write thread)
I/O thread 127 state: waiting for completed aio requests (write thread)
I/O thread 128 state: waiting for completed aio requests (write thread)
I/O thread 129 state: waiting for completed aio requests (write thread)
Pending normal aio reads: 0 [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0] , aio writes: 0 [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0] ,
ibuf aio reads: 0, log i/o's: 0, sync i/o's: 0
Pending flushes (fsync) log: 1; buffer pool: 0
5286 OS file reads, 1113142 OS file writes, 877192 OS fsyncs
0.00 reads/s, 0 avg bytes/read, 457.72 writes/s, 391.95 fsyncs/s
-------------------------------------
INSERT BUFFER AND ADAPTIVE HASH INDEX
-------------------------------------
Ibuf: size 1, free list len 111, seg size 113, 39 merges
merged operations:
insert 2, delete mark 40885, delete 82
discarded operations:
insert 0, delete mark 0, delete 0
Hash table size 8850419, node heap has 67 buffer(s)
4250.25 hash searches/s, 2649.12 non-hash searches/s
---
LOG
---
Log sequence number 3801641954
Log flushed up to 3801641496
Last checkpoint at 3800177774
1 pending log writes, 0 pending chkp writes
863877 log i/o's done, 389.62 log i/o's/second
----------------------
BUFFER POOL AND MEMORY
----------------------
Total memory allocated 4395630592; in additional pool allocated 0
Dictionary memory allocated 270767
Buffer pool size 262142
Free buffers 255645
Database pages 6430
Old database pages 2369
Modified db pages 506
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 2, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 5062, created 1368, written 243108
0.00 reads/s, 0.00 creates/s, 66.89 writes/s
Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 6430, unzip_LRU len: 0
I/O sum[0]:cur[0], unzip sum[0]:cur[0]
----------------------
INDIVIDUAL BUFFER POOL INFO
----------------------
---BUFFER POOL 0
Buffer pool size 131071
Free buffers 127486
Database pages 3552
Old database pages 1310
Modified db pages 302
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 0, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 2819, created 733, written 154429
0.00 reads/s, 0.00 creates/s, 47.55 writes/s
Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 3552, unzip_LRU len: 0
I/O sum[0]:cur[0], unzip sum[0]:cur[0]
---BUFFER POOL 1
Buffer pool size 131071
Free buffers 128159
Database pages 2878
Old database pages 1059
Modified db pages 204
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 2, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 2243, created 635, written 88679
0.00 reads/s, 0.00 creates/s, 19.33 writes/s
Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 2878, unzip_LRU len: 0
I/O sum[0]:cur[0], unzip sum[0]:cur[0]
--------------
ROW OPERATIONS
--------------
1 queries inside InnoDB, 0 queries in queue
1 read views open inside InnoDB
Main thread process no. 3200, id 140451872171776, state: sleeping
Number of rows inserted 30209, updated 855477, deleted 46558, read 226025567
2.26 inserts/s, 391.24 updates/s, 0.00 deletes/s, 663427.10 reads/s
----------------------------
END OF INNODB MONITOR OUTPUT
============================`
However, the mysql_slow.log doesn't log any particular long query's.
/etc/my.cnf is as following:
[mysqld]
skip-character-set-client-handshake
skip-name-resolve
datadir=/var/lib/mysql
socket=/var/lib/mysql/mysql.sock
#log=/var/log/mysqld.log
log-error=/var/log/mysqld-error.log
user=mysql
log_warnings = 2
wait_timeout=30
connect_timeout=30
interactive_timeout=30
max_connections=150
max_allowed_packet=96M
max_heap_table_size=128M
#sort_buffer_size=12M
join_buffer_size=2M
table_open_cache=10K
key_buffer_size=16M
myisam_repair_threads=1
myisam_recover
# Cache aanpassen
query_cache_size=16M
query_cache_type=1
query_cache_limit=24M
tmp_table_size=64M
thread_cache_size=50
innodb_buffer_pool_size=4096M
innodb_lock_wait_timeout=30
innodb_log_buffer_size=4M
# Performance enhance
innodb_flush_method=O_DIRECT
innodb_log_file_size=128M
innodb_buffer_pool_instances=2
innodb_thread_concurrency=50
innodb_read_io_threads=64
innodb_write_io_threads=64
innodb_io_capacity=5000
#innodb_flush_log_at_trx_commit=2
innodb_file_per_table=1
innodb_file_format=barracuda
# Log slow query's
slow-query-log=ON
long_query_time=2
log-queries-not-using-indexes=0
slow-query-log-file=/var/log/mysqld/mysql_slow.log
[mysqld_safe]
#log-error=/var/log/mysqldsafe_error.log
pid-file=/var/run/mysqld/mysqld.pid
Is there anything major that I can modify? Or would the disk IO be the bottleneck for sure?
This is some vmstat output:
[root@vuzmessage ~]# vmstat 1
procs -----------memory---------- ---swap-- -----io---- --system-- -----cpu-----
r b swpd free buff cache si so bi bo in cs us sy id wa st
1 1 45340 224720 256988 1339232 0 0 24 744 33 55 14 3 79 4 0
2 0 45340 224712 257000 1339272 0 0 20 3104 4868 4496 29 4 51 17 0
1 1 45340 224712 257000 1339316 0 0 0 2824 5572 4739 29 4 50 16 0
1 1 45340 223712 257000 1339340 0 0 0 32696 5612 4842 28 8 48 16 0
1 1 45412 231588 256992 1335240 0 72 0 2816 5209 4616 30 4 50 17 0
1 1 45412 229844 256992 1335264 0 0 0 2920 5006 4512 27 7 49 16 0
2 0 45412 229728 257004 1335292 0 0 0 3216 5549 4916 30 4 50 16 0
1 1 45412 229340 257008 1335316 0 0 0 3024 5263 4534 24 9 50 16 0
1 1 45412 228472 257012 1335344 0 0 0 3000 5591 4924 29 8 48 16 0
1 1 45412 228596 257016 1335368 0 0 0 2972 5204 4631 28 7 49 16 0
2 1 45412 228596 257024 1335392 0 0 0 3020 5114 4686 26 4 54 16 0
1 1 45412 228472 257036 1335416 0 0 0 3104 5548 4718 30 4 50 16 0
Aucun commentaire:
Enregistrer un commentaire