maria-discuss team mailing list archive
-
maria-discuss team
-
Mailing list archive
-
Message #03585
New Question: Poor performance on inserts MariaDB
Hello,
A new question has been asked in "MariaDB Documentation" by aferrett. Please answer it at http://mariadb.com/kb/en/poor-performance-on-inserts-mariadb/ as the person asking the question may not be subscribed to the mailing list.
--------------------------------
We are running MariaDB Community Edition 10.1.11.
We are benchmarking inserts for an application that requires high volume inserts.
With MariaDB, we can insert about 476 rows for second.
The same job is able to load 2,500 rows/ second on Oracle.
Both environments are VMware with RedHat Linux. We have the same number of vCPUs and memory.
Overall performance declines if we try multiple jobs.
I tried increasing innodb_autoinc_lock_mode from 1 to 2 and bouncing without seeing improvement.
I see a of processes waiting on system locks such as this one:
SQL thread id 14, OS thread handle 0x7f9237bff700, query id 6743478 zlx70603.vci.att.com 130.9.221.47 pedadba System lock.
I see lots of WRITES for each insert:
20160509 09:16:29,zlx70756,pedadba,zlx70603.vci.att.com,32,11812785,QUERY,ped,'insert into ped_location_load (SRC_CPL_ID, STR_ADDR, CITY_NM, ST_CD, ZIP_CD, LAT_COORD, LONG_COORD, CLLI_8, FIBR_LIT_IND, FIBR_LIT_BLDG_IND, EGIS_FIBR_LIT_BLDG_IND, SRVG_WC_CLLI_8, LEIS_WC_CD, DA_PSA_NAME, DA_PSA_ID, DSTNC_TO_FIBR_FEET_MSRMT, DSTNC_TO_FIBR_MILE_MSRMT, GIS_LAT_COORD, GIS_LONG_COORD, SAG_HSE_NBR, SAG_STR_PRFX, SAG_STR_NM, SAG_CITY_NM, SAG_ST_CD, SAG_ZIP_CD, SAG_MTCH_CD, SITE_STS_CD, AREA_MGR_PLNG_NM, AREA_MGR_DSGN_NM, RGN_CD, SUB_TURF_CD, TERR_TYPE_CD, LATA_CD, BUS_UNIT_CNT, PRRTY_NBR, PRRTY_YR, ALT_SRVG_WC_CLLI_8, PROJ_MGT_TOOL_NBR, BLDG_NM, PROJ_ACTVN_DT, REACTVN_DT, UVERSE_GREEN_AREA_IND, CELL_SITE_IN_BLDG_IND, CELL_SITE_N_BLDG_FXD_ASSET_NBR, VCNTY_CELL_SITE_FXD_ASSET_NBR, EXSTG_ORD_NBR, SMALL_CELL_PLAN_FOR_BLDG_IND, LOC_CMNT_TXT, CRTD_DT, CRTD_BY, LAST_UPDTD_DT, LAST_UPDTD_BY, SVC_ORD_NBR, MKTG_STR_PRFX, MKTG_STR_DRCTN, RVISD_BUS_UNIT_CNT, BUS_JSTFCN, BLD_YR, BLDG_PASSED, BLDG_ON
_NET, FAP_STS, FAP_LOC, FDA_NM, FAA_NM, FAP_JOB_NBR, CLDS_REQUEST_ID, CLDS_STATUS, FIBR_RISER_RQRD, SAG_MTCH_MSG,',0
20160509 09:16:29,zlx70756,pedadba,zlx70603.vci.att.com,32,11812788,QUERY,ped,'SELECT FLOOR(RAND()*(50-1)+50) into st_rand',0
20160509 09:16:29,zlx70756,pedadba,zlx70603.vci.att.com,32,11812789,QUERY,ped,'SELECT FLOOR(RAND()*(6-1)+6) into reg_rand',0
20160509 09:16:29,zlx70756,isaac_all,%,32,11812791,WRITE,ped,ped_location_load,
20160509 09:16:29,zlx70756,isaac_all,%,32,11812791,WRITE,ped,ped_location_load,
< many more WRITES>
Here is the full innodb engine status: to shorten it, I put the full statement only once:
--------------
SHOW ENGINE INNODB STATUS
--------------
*************************** 1. row ***************************
Type: InnoDB
Name:
Status:
=====================================
2016-05-09 08:43:37 7f92323ff700 INNODB MONITOR OUTPUT
=====================================
Per second averages calculated from the last 34 seconds
-----------------
BACKGROUND THREAD
-----------------
srv_master_thread loops: 2785 srv_active, 0 srv_shutdown, 461 srv_idle
srv_master_thread log flush and writes: 3246
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 8038
OS WAIT ARRAY INFO: signal count 9256
Mutex spin waits 5940, rounds 76361, OS waits 1957
RW-shared spins 2417, rounds 70030, OS waits 2234
RW-excl spins 5242, rounds 133769, OS waits 3264
Spin rounds per wait: 12.86 mutex, 28.97 RW-shared, 25.52 RW-excl
------------
TRANSACTIONS
------------
Trx id counter 88326197
Purge done for trx's n:o < 88326196 undo n:o < 0 state: running but idle
History list length 180
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 0, not started
MySQL thread id 20, OS thread handle 0x7f92323ff700, query id 6743576 zlx70603.vci.att.com 130.9.221.47 isaac_all init
SHOW ENGINE INNODB STATUS
---TRANSACTION 88325944, not started
MySQL thread id 5, OS thread handle 0x7f92781db700, query id 955255 vpn-135-70-5-32.vpn.west.att.com 135.70.5.32 isaac_all cleaning up
---TRANSACTION 0, not started
MySQL thread id 4, OS thread handle 0x7f9281962700, query id 955574 vpn-135-70-5-32.vpn.west.att.com 135.70.5.32 isaac_all cleaning up
---TRANSACTION 88322307, not started
MySQL thread id 1, OS thread handle 0x7f92b3d84700, query id 0 Waiting for background binlog tasks
---TRANSACTION 88326196, ACTIVE 52 sec
mysql tables in use 131, locked 131
1 lock struct(s), heap size 360, 0 row lock(s), undo log entries 2238
MySQL thread id 13, OS thread handle 0x7f92459f3700, query id 6743448 zlx70603.vci.att.com 130.9.221.47 pedadba System lock
insert into ped_location_load
(SRC_CPL_ID,
STR_ADDR,
CITY_NM,
ST_CD,
ZIP_CD,
LAT_COORD,
LONG_COORD,
CLLI_8,
FIBR_LIT_IND,
FIBR_LIT_BLDG_IND,
EGIS_FIBR_LIT_BLDG_IND,
SRVG_WC_CLLI_8,
LEIS_WC_CD,
DA_PSA_NAME,
DA_PSA_ID,
DSTNC_TO_FIBR_FEET_MSRMT,
DSTNC_TO_FIBR_MILE_MSRMT,
GIS_LAT_COORD,
GIS_LONG_COORD,
SAG_HSE_NBR,
SAG_STR_PRFX,
SAG_STR_NM,
SAG_CITY_NM,
SAG_ST_CD,
SAG_ZIP_CD,
SAG_MTCH_CD,
SITE_STS_CD,
AREA_MGR_PLNG_NM,
AREA_MGR_DSGN_NM,
RGN_CD,
SUB_TURF_CD,
TERR_TYPE_CD,
LATA_CD,
BUS_UNIT_CNT,
PRRTY_NBR,
PRRTY_YR,
ALT_SRVG_WC_CLLI_8,
PROJ_MGT_TOOL_NBR,
BLDG_NM,
PROJ_ACTVN_DT,
REACTVN_DT,
UVERSE_GR
Trx #rec lock waits 0 #table lock waits 0
Trx total rec lock wait time 0 SEC
Trx total table lock wait time 0 SEC
---TRANSACTION 88326191, ACTIVE 83 sec
mysql tables in use 52, locked 52
1 lock struct(s), heap size 360, 0 row lock(s), undo log entries 3584
MySQL thread id 16, OS thread handle 0x7f9235fff700, query id 6743430 zlx70603.vci.att.com 130.9.221.47 pedadba System lock
insert into ped_location_load
(SRC_CPL_ID,
STR_ADDR,
<complete statement same as above>
Trx #rec lock waits 0 #table lock waits 0
Trx total rec lock wait time 0 SEC
Trx total table lock wait time 0 SEC
---TRANSACTION 88326190, ACTIVE 83 sec
mysql tables in use 5, locked 5
1 lock struct(s), heap size 360, 0 row lock(s), undo log entries 3658
MySQL thread id 19, OS thread handle 0x7f92333ff700, query id 6743606 zlx70603.vci.att.com 130.9.221.47 pedadba System lock
insert into ped_location_load
(SRC_CPL_ID,
<complete statement same as above>
Trx #rec lock waits 0 #table lock waits 0
Trx total rec lock wait time 0 SEC
Trx total table lock wait time 0 SEC
---TRANSACTION 88326188, ACTIVE 86 sec
mysql tables in use 59, locked 59
1 lock struct(s), heap size 360, 0 row lock(s), undo log entries 3697
MySQL thread id 15, OS thread handle 0x7f9236fff700, query id 6743327 zlx70603.vci.att.com 130.9.221.47 pedadba System lock
insert into ped_location_load
(SRC_CPL_ID,
<complete statement same as above>
Trx #rec lock waits 0 #table lock waits 0
Trx total rec lock wait time 0 SEC
Trx total table lock wait time 0 SEC
---TRANSACTION 88326187, ACTIVE 98 sec
mysql tables in use 66, locked 66
1 lock struct(s), heap size 360, 0 row lock(s), undo log entries 4320
MySQL thread id 12, OS thread handle 0x7f924ddee700, query id 6743575 zlx70603.vci.att.com 130.9.221.47 pedadba System lock
insert into ped_location_load
(SRC_CPL_ID,
<complete statement same as above>
Trx #rec lock waits 0 #table lock waits 0
Trx total rec lock wait time 0 SEC
Trx total table lock wait time 0 SEC
---TRANSACTION 88326186, ACTIVE 99 sec
mysql tables in use 33, locked 33
1 lock struct(s), heap size 360, 0 row lock(s), undo log entries 4506
MySQL thread id 17, OS thread handle 0x7f92353ff700, query id 6743630 zlx70603.vci.att.com 130.9.221.47 pedadba System lock
insert into ped_location_load
(SRC_CPL_ID,
<complete statement same as above>
Trx #rec lock waits 0 #table lock waits 0
Trx total rec lock wait time 0 SEC
Trx total table lock wait time 0 SEC
---TRANSACTION 88326185, ACTIVE 116 sec
mysql tables in use 59, locked 59
1 lock struct(s), heap size 360, 0 row lock(s), undo log entries 5086
MySQL thread id 11, OS thread handle 0x7f9281a63700, query id 6743446 zlx70603.vci.att.com 130.9.221.47 pedadba System lock
insert into ped_location_load
(SRC_CPL_ID,
<complete statement same as above>
Trx #rec lock waits 0 #table lock waits 0
Trx total rec lock wait time 0 SEC
Trx total table lock wait time 0 SEC
---TRANSACTION 88326184, ACTIVE 172 sec
mysql tables in use 7, locked 7
1 lock struct(s), heap size 360, 0 row lock(s), undo log entries 7919
MySQL thread id 18, OS thread handle 0x7f92343ff700, query id 6743538 zlx70603.vci.att.com 130.9.221.47 pedadba System lock
insert into ped_location_load
(SRC_CPL_ID,
<complete statement same as above>
Trx #rec lock waits 0 #table lock waits 0
Trx total rec lock wait time 0 SEC
Trx total table lock wait time 0 SEC
---TRANSACTION 88326183, ACTIVE 203 sec
mysql tables in use 52, locked 52
1 lock struct(s), heap size 360, 0 row lock(s), undo log entries 9102
MySQL thread id 8, OS thread handle 0x7f92393ff700, query id 6743600 zlx70603.vci.att.com 130.9.221.47 pedadba System lock
insert into ped_location_load
(SRC_CPL_ID,
<complete statement same as above>
Trx #rec lock waits 0 #table lock waits 0
Trx total rec lock wait time 0 SEC
Trx total table lock wait time 0 SEC
---TRANSACTION 88326178, ACTIVE 212 sec
mysql tables in use 75, locked 75
1 lock struct(s), heap size 360, 0 row lock(s), undo log entries 9706
MySQL thread id 14, OS thread handle 0x7f9237bff700, query id 6743478 zlx70603.vci.att.com 130.9.221.47 pedadba System lock
insert into ped_location_load
(SRC_CPL_ID,
<complete statement same as above>
Trx #rec lock waits 0 #table lock waits 0
Trx total rec lock wait time 0 SEC
Trx total table lock wait time 0 SEC
--------
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 (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: 0 [0, 0, 0, 0] , 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: 0
4272 OS file reads, 78139 OS file writes, 20899 OS fsyncs
0.00 reads/s, 0 avg bytes/read, 21.68 writes/s, 4.32 fsyncs/s
-------------------------------------
INSERT BUFFER AND ADAPTIVE HASH INDEX
-------------------------------------
Ibuf: size 1, free list len 62, seg size 64, 0 merges
merged operations:
insert 0, delete mark 0, delete 0
discarded operations:
insert 0, delete mark 0, delete 0
5981.97 hash searches/s, 406.66 non-hash searches/s
---
LOG
---
Log sequence number 375449925793
Log flushed up to 375449653000
Pages flushed up to 375438050350
Last checkpoint at 375435460923
Max checkpoint age 84223550
Checkpoint age target 81591565
Modified age 11875443
Checkpoint age 14464870
0 pending log writes, 0 pending chkp writes
6332 log i/o's done, 1.91 log i/o's/second
----------------------
BUFFER POOL AND MEMORY
----------------------
Total memory allocated 553648128; in additional pool allocated 0
Total memory allocated by read views 288
Internal hash tables (constant factor + variable factor)
Adaptive hash index 8888016 (8851048 + 36968)
Page hash 553976 (buffer pool 0 only)
Dictionary cache 46879130 (2214224 + 44664906)
File system 1307376 (812272 + 495104)
Lock system 1334216 (1329176 + 5040)
Recovery system 0 (0 + 0)
Dictionary memory allocated 44664906
Buffer pool size 32767
Buffer pool size, bytes 536854528
Free buffers 1014
Database pages 31748
Old database pages 11699
Modified db pages 500
Percent of dirty pages(LRU & free pages): 1.526
Max dirty pages percent: 75.000
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 3251, not young 49414
0.06 youngs/s, 0.00 non-youngs/s
Pages read 2853, created 52673, written 60872
0.00 reads/s, 16.56 creates/s, 18.56 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: 31748, unzip_LRU len: 0
I/O sum[982]:cur[0], unzip sum[0]:cur[0]
--------------
ROW OPERATIONS
--------------
0 queries inside InnoDB, 0 queries in queue
0 read views open inside InnoDB
10 RW transactions active inside InnoDB
0 RO transactions active inside InnoDB
10 out of 1000 descriptors used
Main thread process no. 2676, id 140266283443968, state: sleeping
Number of rows inserted 1123943, updated 0, deleted 0, read 20
423.72 inserts/s, 0.00 updates/s, 0.00 deletes/s, 0.00 reads/s
Number of system rows inserted 0, updated 0, deleted 0, read 0
0.00 inserts/s, 0.00 updates/s, 0.00 deletes/s, 0.00 reads/s
----------------------------
END OF INNODB MONITOR OUTPUT
============================
--------------------------------
To view or answer this question please visit: http://mariadb.com/kb/en/poor-performance-on-inserts-mariadb/
