Take the 2-minute tour ×
Server Fault is a question and answer site for professional system and network administrators. It's 100% free, no registration required.

I am currently doing some stress testing where I am pushing inserts to the database as fast as I can. The simulation inserts 10000 records per second. After inserting around 200 million records I found that the inserts were very slow. So I stopped the simulation.

Currently I have stopped pushing any transactions to the database. As such there are no inserts, updates. There have been no deletes to this database in this entire simulation. Yet there are so many IO operations to the disk going on.

When I check the innodb status and iostat, i can see that the Mysql Innodb engine is busy doing disk operations. I am not able to figure out the reason for these IO.

The IO rate is pretty high and as such its causing a bottleneck to push further requests to the Database.

Any help is appreciated. I have attached the InnodB engine status.

-----------------
my.cnf configuration:
-----------------
innodb_file_per_table=1
innodb_buffer_pool_size=6G
innodb_log_file_size=1G
innodb_flush_log_at_trx_commit=0
innodb_io_capacity=100
innodb_flush_method=O_DIRECT
innodb_doublewrite=OFF
innodb_max_dirty_pages_pct=75
innodb_max_dirty_pages_pct_lwm=60
innodb_buffer_pool_instances=1


| InnoDB |      | 
=====================================
2014-08-26 00:02:50 7fc41d38f700 INNODB MONITOR OUTPUT
=====================================
Per second averages calculated from the last 28 seconds
-----------------
BACKGROUND THREAD
-----------------
srv_master_thread loops: 16554 srv_active, 0 srv_shutdown, 6695 srv_idle
srv_master_thread log flush and writes: 23248
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 74717
--Thread 140480424269568 has waited at btr0cur.cc line 545 for 0.00 seconds the semaphore:
S-lock on RW-latch at 0x7fc5ecdc7af8 created in file dict0dict.cc line 2505
a writer (thread id 140480399091456) has reserved it in mode  exclusive
number of readers 0, waiters flag 1, lock_word: fffffffffff00000
Last time read locked in file btr0cur.cc line 545
Last time write locked in file /build/buildd/mysql-5.6-5.6.19/storage/innobase/ibuf/ibuf0ibuf.cc line 409
OS WAIT ARRAY INFO: signal count 72822
Mutex spin waits 234298, rounds 1620740, OS waits 42193
RW-shared spins 9405, rounds 170212, OS waits 5011
RW-excl spins 23541, rounds 884561, OS waits 26158
Spin rounds per wait: 6.92 mutex, 18.10 RW-shared, 37.58 RW-excl
------------
TRANSACTIONS
------------
Trx id counter 5263484
Purge done for trx's n:o < 5198325 undo n:o < 0 state: running but idle
History list length 604
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 0, not started
MySQL thread id 76, OS thread handle 0x7fc41d38f700, query id 1482925 localhost ddosprofile init
show engine innodb status
--------
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: complete io for buf page (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: complete io for buf page (read thread)
I/O thread 6 state: waiting for completed aio requests (write thread)
I/O thread 7 state: waiting for completed aio requests (write thread)
I/O thread 8 state: waiting for completed aio requests (write thread)
I/O thread 9 state: waiting for completed aio requests (write thread)
Pending normal aio reads: 22 [3, 2, 8, 9] , aio writes: 0 [0, 0, 0, 0] ,
 ibuf aio reads: 0, log i/o's: 0, sync i/o's: 0
Pending flushes (fsync) log: 0; buffer pool: 2
25561 OS file reads, 10271392 OS file writes, 138838 OS fsyncs
0 pending preads, 1 pending pwrites
23.57 reads/s, 16384 avg bytes/read, 263.95 writes/s, 8.36 fsyncs/s
-------------------------------------
INSERT BUFFER AND ADAPTIVE HASH INDEX
-------------------------------------
Ibuf: size 562, free list len 24162, seg size 24725, 18712 merges
merged operations:
 insert 169928, delete mark 0, delete 0
discarded operations:
 insert 0, delete mark 0, delete 0
Hash table size 12749951, node heap has 3 buffer(s)
0.00 hash searches/s, 113.57 non-hash searches/s
---
LOG
---
Log sequence number 183651147315
Log flushed up to   183651127940
Pages flushed up to 183242751536
Last checkpoint at  183241671211
0 pending log writes, 0 pending chkp writes
98244 log i/o's done, 0.54 log i/o's/second
----------------------
BUFFER POOL AND MEMORY
----------------------
Total memory allocated 6593445888; in additional pool allocated 0
Dictionary memory allocated 87500
Buffer pool size   393215
Free buffers       1
Database pages     393211
Old database pages 145154
Modified db pages  178594
Pending reads 25
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 15953492, not young 42560
0.00 youngs/s, 0.00 non-youngs/s
Pages read 25519, created 1321453, written 10147162
22.71 reads/s, 0.00 creates/s, 263.45 writes/s
Buffer pool hit rate 969 / 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: 393211, unzip_LRU len: 0
I/O sum[11937]:cur[103], unzip sum[0]:cur[0]
--------------
ROW OPERATIONS
--------------
0 queries inside InnoDB, 0 queries in queue
0 read views open inside InnoDB
Main thread process no. 8090, id 140480331949824, state: doing insert buffer merge
Number of rows inserted 196205997, updated 0, deleted 972, read 1134
0.00 inserts/s, 0.00 updates/s, 0.00 deletes/s, 0.00 reads/s
----------------------------
END OF INNODB MONITOR OUTPUT
============================
share|improve this question
    
What does SHOW FULL PROCESSLIST; output? –  Janne Pikkarainen Aug 26 at 9:11

1 Answer 1

Your InnoDB database buffer pool is about 6,6 gigabytes.

When inserting data to the database, InnoDB engine first adds the data to the buffer pool, and then writes it to the disk.

So, what happened here is that when the buffer pool got full, InnoDB started to write its contents to the disk. Therefore the insert performance dropped.

Now, when you stopped your process, there was still data left in the buffer pool that wasn't committed to disk. So, InnoDB continued to write data to disk to reach the state when all data is on disk.

This can be seen from the Buffer pool and memory part of the output. There you can see that there are 178k modified pages in the buffer pool.

share|improve this answer

Your Answer

 
discard

By posting your answer, you agree to the privacy policy and terms of service.

Not the answer you're looking for? Browse other questions tagged or ask your own question.