List:General Discussion« Previous MessageNext Message »
From:Max Bube Date:March 18 2010 3:56pm
Subject:Re: Innodb and bulk writes
View as plain text  
This is an output from console when its performnace goes dows

Query OK, 65469 rows affected (0.82 sec)
Records: 65469  Duplicates: 0  Warnings: 0

Query OK, 65469 rows affected (0.78 sec)
Records: 65469  Duplicates: 0  Warnings: 0

Query OK, 65469 rows affected (10 min 57.30 sec)
Records: 65469  Duplicates: 0  Warnings: 0

Query OK, 65469 rows affected (10 min 56.58 sec)
Records: 65469  Duplicates: 0  Warnings: 0

and the show full processlist is, I cut the insert its about 65k rows like
you can see above


*************************** 1. row ***************************
     Id: 1
   User: event_scheduler
   Host: localhost
     db: NULL
Command: Daemon
   Time: 4730
  State: Waiting on empty queue
   Info: NULL
*************************** 2. row ***************************
     Id: 3
   User: root
   Host: localhost
     db: test
Command: Query
   Time: 603
  State: update
  Info: INSERT INTO `challenge` VALUES
(95794260,2,0),(95794261,3,1),(95794262,2,1),(95794263,5,0)

*************************** 3. row ***************************
     Id: 7
   User: root
   Host: localhost
     db: NULL
Command: Query
   Time: 0
  State: NULL
   Info: show full processlist

regards
Max

2010/3/18 Ananda Kumar <anandkl@stripped>

> when the writes are happening, please run "show full processlist" and let
> us know the out put.
>
> regards
> anandkl
>
> On Thu, Mar 18, 2010 at 9:09 PM, Max Bube <maxbube@stripped> wrote:
>
>> Hi list,
>>
>> Im having problems with bulk writes (restores from mysqldumps, alters,
>> delete in (select ...)) with innodb. The servers are at amazon EC2
>> instances
>> w/ 15G ram and raid0 4disks EBS.
>> The problem starts when I run bulk writes like an alter table or a restore
>> from mysqldump, its starts processing more than 50000 rows/s but suddenly
>> the ratio goes down to 100 rows /sec. and then its stucked at this ratio
>> even if I restart MySQL. The only way to get good perfomance again is
>> deleting all innodb files (ibdata, iblog files) and restoring the DB
>> again.
>>
>> The DBs are relative small about 70M rows and 10Gb size. I can repeat this
>> behavior all the time just running 2 restores of the same database.
>>
>> Another example when its stucked:
>>
>> I want to delete 1M rows
>> "delete from table where id IN (select id from ....)"  deletes 100 rows /
>> sec
>> but if I run 1 Million "delete from table where id = xxx" deletes 10000
>> rows
>> / sec
>>
>> The problem is just only with writes on innodb, I can perfectly run
>> mysqldumps and bulk inserts on MyISAM.
>>
>> This is happening with all MySQL 5.1.x versions I tested.
>>
>> Any one have a clue about this issue??
>>
>> Thanks in advance
>> Max
>>
>> ########################
>> #    INNODB Settings   #
>> ########################
>> innodb_file_per_table
>> innodb_buffer_pool_size = 10G
>> innodb_additional_mem_pool_size = 20M
>> innodb_thread_concurrency = 8
>> innodb_support_xa = 0
>> innodb_thread_sleep_delay = 2000
>> innodb_flush_log_at_trx_commit = 0
>> innodb_log_file_size = 700M
>> innodb_log_buffer_size = 8M
>> innodb_lock_wait_timeout = 50
>> innodb_max_purge_lag = 10
>> innodb_max_dirty_pages_pct = 90
>> innodb_use_purge_thread = 4
>> innodb_extra_undoslots = 1
>> innodb_adaptive_checkpoint = estimate
>> innodb_io_capacity = 500
>> innodb_read_io_threads = 4
>> innodb_write_io_threads = 4
>>
>> and this is a innodb status when was running at low preformance
>>
>> mysql> show engine innodb status\G
>> *************************** 1. row ***************************
>>  Type: InnoDB
>>  Name:
>> Status:
>> =====================================
>> 100310 13:12:07 INNODB MONITOR OUTPUT
>> =====================================
>> Per second averages calculated from the last 42 seconds
>> ----------
>> BACKGROUND THREAD
>> ----------
>> srv_master_thread loops: 4409 1_second, 4408 sleeps, 439 10_second, 399
>> background, 399 flush
>> srv_master_thread log flush and writes: 4925
>> ----------
>> SEMAPHORES
>> ----------
>> OS WAIT ARRAY INFO: reservation count 37498, signal count 37467
>> Mutex spin waits 115051, rounds 948698, OS waits 24706
>> RW-shared spins 1458, OS waits 778; RW-excl spins 0, OS waits 11943
>> Spin rounds per wait: 8.25 mutex, 17.61 RW-shared, 358898.00 RW-excl
>> --------
>> 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 (read thread)
>> I/O thread 4 state: waiting for i/o request (read thread)
>> I/O thread 5 state: waiting for i/o request (read thread)
>> I/O thread 6 state: waiting for i/o request (write thread)
>> I/O thread 7 state: waiting for i/o request (write thread)
>> I/O thread 8 state: waiting for i/o request (write thread)
>> I/O thread 9 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: 0; buffer pool: 0
>> 70 OS file reads, 367420 OS file writes, 113414 OS fsyncs
>> 0.00 reads/s, 0 avg bytes/read, 13.12 writes/s, 2.02 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 25499809, node heap has 5416 buffer(s)
>> 98.74 hash searches/s, 1.43 non-hash searches/s
>> ---
>> LOG
>> ---
>> Log sequence number 34171430524
>> Log flushed up to   34171425746
>> Last checkpoint at  33506703349
>> Max checkpoint age    1187902219
>> Checkpoint age target 1150780275
>> Modified age          664727175
>> Checkpoint age        664727175
>> 0 pending log writes, 0 pending chkp writes
>> 37839 log i/o's done, 1.05 log i/o's/second
>> ----------------------
>> BUFFER POOL AND MEMORY
>> ----------------------
>> Total memory allocated 13205766144; in additional pool allocated 0
>> Internal hash tables (constant factor + variable factor)
>>    Adaptive hash index 292738424     (203998472 + 88739952)
>>    Page hash           12750664
>>    Dictionary cache    51124680     (51001072 + 123608)
>>    File system         90728     (82672 + 8056)
>>    Lock system         31876248     (31875512 + 736)
>>    Recovery system     0     (0 + 0)
>>    Threads             407416     (406936 + 480)
>> Dictionary memory allocated 123608
>> Buffer pool size        786431
>> Buffer pool size, bytes 12884885504
>> Free buffers            1
>> Database pages          781014
>> Old database pages      288283
>> Modified db pages       36334
>> Pending reads 0
>> Pending writes: LRU 0, flush list 0, single page 0
>> Pages made young 190597, not young 0
>> 0.00 youngs/s, 0.00 non-youngs/s
>> Pages read 70, created 1620259, written 4087613
>> 0.00 reads/s, 0.29 creates/s, 45.36 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
>> LRU len: 781014, unzip_LRU len: 0
>> I/O sum[2109]: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. 15552, id 1182845248, state: sleeping
>> Number of rows inserted 270830867, updated 0, deleted 0, read 0
>> 99.59 inserts/s, 0.00 updates/s, 0.00 deletes/s, 0.00 reads/s
>> ------------
>> TRANSACTIONS
>> ------------
>> Trx id counter 43DF
>> Purge done for trx's n:o < 43D2 undo n:o < 0
>> History list length 11
>> LIST OF TRANSACTIONS FOR EACH SESSION:
>> ---TRANSACTION 0, not started, process no 15552, OS thread id 1192302912
>> MySQL thread id 9, query id 16776 localhost root
>> show engine innodb status
>> ---TRANSACTION 43DE, ACTIVE 156 sec, process no 15552, OS thread id
>> 1192036672 inserting, thread declared inside InnoDB 17
>> mysql tables in use 1, locked 1
>> 1 lock struct(s), heap size 368, 0 row lock(s), undo log entries 15513
>> MySQL thread id 8, query id 16774 localhost root update
>> INSERT INTO `t1` VALUES
>>
>>
> (136032,'xxx',213),(136032,'xxx',86),(136032,'xxx',193),(136032,'xxx',24),(136032,'xxx',72),(136032,'xxx',8),(136032,'xxx',14),(136032,'xxx',13),(136032,'xxx',153),(136032,'xxx',42),(136032,'xxx',8),(136032,'xxx',2),(136040,'xxx',1),(136044,'xxx',261),(136044,'xxx',36),(136044,'xxx',398),(136044,'xxx',76),(136044,'-xxx',7),(136044,'-xxx',87),(136044,'-xxx',60),(136044,'-xxx',114),(136044,'x
>> TABLE LOCK table `db`.`t1` trx id 43DE lock mode IX
>> ----------------------------
>> END OF INNODB MONITOR OUTPUT
>> ============================
>>
>
>

Thread
Innodb and bulk writesMax Bube18 Mar
  • Re: Innodb and bulk writesAnanda Kumar18 Mar
    • Re: Innodb and bulk writesMax Bube18 Mar
  • Re: Innodb and bulk writesRaj Shekhar19 Mar
    • Re: Innodb and bulk writesAnanda Kumar19 Mar
    • Re: Innodb and bulk writesMax Bube19 Mar