Archive for the ‘InnoDB’ Category

Tip: faster than TRUNCATE

Март 9th, 2010

TRUNCATE is usually a fast operation (much faster than DELETE FROM). But sometimes it just hangs; I’ve has several such uncheerful events with InnoDB (Plugin) tables which were extensively written to. The TRUNCATE hanged; nothing else would work; minutes pass.

TRUNCATE on tables with no FOREIGN KEYs should act fast: it translate to dropping the table and creating a new one (and it all depends on the MySQL version, see the manual).

What’s faster than TRUNCATE, then? If you don’t have triggers nor FOREIGN KEYs, a RENAME TABLE can come to the rescue. Instead of:

TRUNCATE log_table

Do:

CREATE TABLE log_table_new LIKE log_table;
RENAME TABLE log_table TO log_table_old, log_table_new TO log_table;
DROP TABLE log_table_old;

I found this to work well for me. Do note that AUTO_INCREMENT values can be tricky here: the “new” table is created with an AUTO_INCREMENT value which is immediately taken in the “working” table. If you care about not using same AUTO_INCREMENT values, you can:

ALTER TABLE log_table_new AUTO_INCREMENT=some high enough value;

Just before renaming.

I do not have a good explanation as for why the RENAME TABLE succeeds to respond faster than TRUNCATE.


PlanetMySQL Voting: Vote UP / Vote DOWN

my SHOW INNODB STATUS walkthrough

Март 8th, 2010

I am very fortunate to be sent to a Percona innodb low level conference - with one of the guys who has written the High Performance MySQL book. One of the key items will be to dive deep into the Innodb kernel and find out what the hell the thing is doing. To that end I'm going post what I know about the 'show innodb status' output - now my aim from this conference is to pick up on some of the areas that I'm green in to identify and resolve more MySQL performance problems.

So here is my 'show innodb status' walkthrough:


mysql> show innodb status\G
*************************** 1. row ***************************
Type: InnoDB
Name:
Status:
=====================================
100308 17:05:14 INNODB MONITOR OUTPUT
=====================================
Per second averages calculated from the last 14 seconds
The following information is based on stats gathered in the last 14 seconds - Generally a good 30 seconds should pass before the output can be considered an accurate average. There are some stats that are counters since server start however.

----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 74964888, signal count 66577404
Mutex spin waits 0, rounds 3978408534, OS waits 51856599
RW-shared spins 16155677, OS waits 7409510; RW-excl spins 19774799, OS waits 3870167
Since server stat, Innodb has had to reserve 74964888 'slots' and innodb has signaled 66577404 threads to proceed - OS waits are very expensive relative to spin waits.
If there is a high concurrency performance issue, there would also be a line under 'OS WAIT' regarding a transaction(s) waiting on a semaphore. Also if there is a transaction, the output also references a c source file - and the name can usually be extracted to find the location of the bottlekneck.

Also, 19774799 times Innodb has used spin waits, and 3870167 Innodb has had to resort to OS waits - OS waits are more expensive.

------------------------
LATEST FOREIGN KEY ERROR
------------------------
100303 12:03:03 Transaction:
TRANSACTION 2 1356465249, ACTIVE 0 sec, process no 16670, OS thread id 1166653776 inserting, thread declared inside InnoDB 500
mysql tables in use 1, locked 1
3 lock struct(s), heap size 368, 1 row lock(s), undo log entries 1
MySQL thread id 6773466308, query id 23928955894 172.24.0.2 readwrite update
insert into `AlertCriteria` (`AlertID`, `Field`, `Value`)
values ('7695501', 'tb', 'WESTMEAD,WATTLE GROVE,HOLSWORTHY,PARRAMATTA,PENDLE HILL,QUAKERS HILL')
Foreign key constraint fails for table `AlertSystem`.`AlertCriteria`:
,
CONSTRAINT `AlertCriteria_ibfk_1` FOREIGN KEY (`AlertID`) REFERENCES `Alerts` (`AlertID`) ON DELETE CASCADE
Trying to add in child table, in index `AlertID_index` tuple:
DATA TUPLE: 2 fields;
0: len 4; hex 80756c8d; asc ul ;; 1: len 4; hex 04650c45; asc e E;;
But in parent table `AlertSystem`.`Alerts`, in index `PRIMARY`,
the closest match we can find is record:
PHYSICAL RECORD: n_fields 13; compact format; info bits 0
0: len 4; hex 80756c92; asc ul ;; 1: len 6; hex 000250d61ec0; asc P ;; 2: len 7; hex 800000288e0110; asc ( ;; 3: len 5; hex 72656e2331; asc ren#1;; 4: len 23; hex 4e4557414c4552544e414d452d50616c6d204265616368; asc NEWALERTNAME-Palm Beach;; 5: len 4; hex 803497c6; asc 4 ;; 6: len 1; hex 81; asc ;; 7: len 4; hex 80000000; asc ;; 8: len 4; hex 80000000; asc ;; 9: len 6; hex 5765656b6c79; asc Weekly;; 10: len 1; hex 81; asc ;; 11: len 4; hex 80000000; asc ;; 12: len 4; hex 80000000; asc ;;
This output only appears if there has been a foreign key constraint issue since server restart.
The above shows that there was a foreign key constraint that was not met and Innodb aborted the transaction - the bellow junk is the actual parts of the Innodb code where it discovered the foreign key miss match and aborted. (Nothing to be scared about).
---- Last detected deadlock---
The last detected deadlock would appear if there was a deadlock since last server restart- unfortunately this is not the case therefore its not in the output of 'show innodb status'.
-----
------------
TRANSACTIONS
------------
Trx id counter 2 1594638995
Purge done for trx's n:o <>
History list length 928
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 0 0, not started, process no 16670, OS thread id 1206856016
mysql tables in use 1, locked 1
MySQL thread id 6976314925, query id 24543783827 172.24.0.2 readwrite init
UPDATE Subscribers SET EmailAddress = '12618060932336258813', RealEstProps = '106370836 104481172 105731349 105958174 105958282 105969863 105974146 105998765 106010720 106078593 106102921 106150346 106322759 106337015 106340214 106312885 106343690 106159839 106207162 106290970', LastAccess = 1268028314 WHERE EmailAddress = '12618060932336258813'
---TRANSACTION 2 1594638991, not started, process no 16670, OS thread id 1331722576
MySQL thread id 6976315115, query id 24543783821 172.24.0.2 readwrite
---TRANSACTION 2 1594638994, not started, process no 16670, OS thread id 1366600016
MySQL thread id 6976315285, query id 24543783824 172.24.0.2 readwrite
---TRANSACTION 2 1594638982, not started, process no 16670, OS thread id 1161062736
MySQL thread id 6976315282, query id 24543783797 172.24.0.2 readonly
---TRANSACTION 2 1594638980, not started, process no 16670, OS thread id 1406802256
MySQL thread id 6976315278, query id 24543783787 172.24.0.2 readonly
---TRANSACTION 2 1594638978, not started, process no 16670, OS thread id 1079593296
MySQL thread id 6976315275, query id 24543783783 172.24.0.2 readonly
---TRANSACTION 2 1594638983, not started, process no 16670, OS thread id 1378847056
MySQL thread id 6976315277, query id 24543783782 172.24.21.19 readonly
---TRANSACTION 2 1594638977, not started, process no 16670, OS thread id 1226025296
MySQL thread id 6976314965, query id 24543783781 172.24.0.2 readwrite
---TRANSACTION 2 1594638989, not started, process no 16670, OS thread id 1394821456
MySQL thread id 6976315274, query id 24543783819 172.24.0.2 readonly
---TRANSACTION 2 1594638971, not started, process no 16670, OS thread id 1227622736
MySQL thread id 6976315097, query id 24543783748 172.24.0.2 readwrite
---TRANSACTION 2 1594638974, not started, process no 16670, OS thread id 1186355536
MySQL thread id 6976315255, query id 24543783755 172.24.0.2 readwrite
---TRANSACTION 2 1594638970, not started, process no 16670, OS thread id 1250785616
MySQL thread id 6976315261, query id 24543783747 172.24.0.2 readonly
---TRANSACTION 2 1594638967, not started, process no 16670, OS thread id 1384438096
MySQL thread id 6976315262, query id 24543783740 172.24.0.2 readonly
---TRANSACTION 2 1594638990, not started, process no 16670, OS thread id 1105054032
MySQL thread id 6976315258, query id 24543783820 172.24.0.2 readonly
---TRANSACTION 2 1594638962, not started, process no 16670, OS thread id 1326664016
MySQL thread id 6976315256, query id 24543783723 172.24.0.2 readonly
---TRANSACTION 2 1594638959, not started, process no 16670, OS thread id 1189816656
MySQL thread id 6976315251, query id 24543783709 172.24.0.2 readonly
---TRANSACTION 2 1594638955, not started, process no 16670, OS thread id 1337313616
MySQL thread id 6976314577, query id 24543783701 172.24.0.2 readwrite
---TRANSACTION 2 1594638954, not started, process no 16670, OS thread id 1386568016
MySQL thread id 6976315246, query id 24543783698 172.24.0.2 readwrite
---TRANSACTION 2 1594638952, not started, process no 16670, OS thread id 1349560656
MySQL thread id 6976315241, query id 24543783690 172.24.21.19 readonly
---TRANSACTION 2 1594638949, not started, process no 16670, OS thread id 1331456336
MySQL thread id 6976314979, query id 24543783684 172.24.0.2 readwrite
---TRANSACTION 2 1594638944, not started, process no 16670, OS thread id 1263831376
MySQL thread id 6976314994, query id 24543783675 172.24.0.2 readwrite
---TRANSACTION 2 1594638942, not started, process no 16670, OS thread id 1252649296
MySQL thread id 6976315228, query id 24543783669 172.24.0.2 readonly
---TRANSACTION 2 1594638940, not started, process no 16670, OS thread id 1183959376
MySQL thread id 6976315232, query id 24543783666 172.24.0.2 readonly
---TRANSACTION 2 1594638938, not started, process no 16670, OS thread id 1289124176
MySQL thread id 6976315103, query id 24543783663 172.24.0.2 readwrite
---TRANSACTION 2 1594638948, not started, process no 16670, OS thread id 1376184656
MySQL thread id 6976315205, query id 24543783772 172.24.0.2 readwrite
---TRANSACTION 2 1594638933, not started, process no 16670, OS thread id 1324534096
MySQL thread id 6976315224, query id 24543783641 172.24.0.2 readonly
---TRANSACTION 2 1594638931, not started, process no 16670, OS thread id 1272617296
MySQL thread id 6976315222, query id 24543783634 172.24.0.2 readonly
---TRANSACTION 2 1594638930, not started, process no 16670, OS thread id 1201531216
MySQL thread id 6976315221, query id 24543783630 172.24.0.2 readonly
---TRANSACTION 2 1594638929, not started, process no 16670, OS thread id 1355950416
MySQL thread id 6976315219, query id 24543783624 172.24.0.2 readonly
---TRANSACTION 2 1594638953, not started, process no 16670, OS thread id 1192212816
MySQL thread id 6976315217, query id 24543783694 172.24.0.2 readonly
---TRANSACTION 2 1594638919, not started, process no 16670, OS thread id 1225492816
MySQL thread id 6976315037, query id 24543783602 172.24.0.2 readwrite
---TRANSACTION 2 1594638917, not started, process no 16670, OS thread id 1391360336
MySQL thread id 6976315215, query id 24543783600 172.24.21.19 readonly
---TRANSACTION 2 1594638916, not started, process no 16670, OS thread id 1415588176
MySQL thread id 6976315213, query id 24543783599 172.24.0.2 readonly
---TRANSACTION 2 1594638913, not started, process no 16670, OS thread id 1157601616
MySQL thread id 6976315191, query id 24543783798 172.24.0.2 readwrite
---TRANSACTION 2 1594638905, not started, process no 16670, OS thread id 1314949456
MySQL thread id 6976315202, query id 24543783823 172.24.0.2 readonly
---TRANSACTION 2 1594638903, not started, process no 16670, OS thread id 1237207376
MySQL thread id 6976315200, query id 24543783555 172.24.0.2 readwrite
---TRANSACTION 2 1594638901, not started, process no 16670, OS thread id 1242532176
MySQL thread id 6976315195, query id 24543783543 172.24.0.2 readonly
---TRANSACTION 2 1594638896, not started, process no 16670, OS thread id 1268091216
MySQL thread id 6976315189, query id 24543783526 172.24.0.2 readonly
---TRANSACTION 2 1594638892, not started, process no 16670, OS thread id 1234811216
MySQL thread id 6976314982, query id 24543783521 172.24.0.2 readwrite
---TRANSACTION 2 1594638888, not started, process no 16670, OS thread id 1265428816
MySQL thread id 6976315186, query id 24543783692 172.24.0.2 readonly
---TRANSACTION 2 1594638899, not started, process no 16670, OS thread id 1369262416
MySQL thread id 6976315182, query id 24543783538 172.24.21.19 readonly
---TRANSACTION 2 1594638860, not started, process no 16670, OS thread id 1367132496
MySQL thread id 6976315178, query id 24543783465 172.24.0.2 readonly
---TRANSACTION 2 1594638850, not started, process no 16670, OS thread id 1398016336
MySQL thread id 6976315172, query id 24543783443 172.24.0.2 readonly
---TRANSACTION 2 1594638843, not started, process no 16670, OS thread id 1384171856
MySQL thread id 6976315133, query id 24543783760 172.24.0.2 readwrite
---TRANSACTION 2 1594638907, not started, process no 16670, OS thread id 1319475536
MySQL thread id 6976315152, query id 24543783567 172.24.0.2 readonly
---TRANSACTION 2 1594638802, not started, process no 16670, OS thread id 1310157136
MySQL thread id 6976315119, query id 24543783303 172.24.0.2 readonly
---TRANSACTION 2 1594638795, not started, process no 16670, OS thread id 1275013456
MySQL thread id 6976315110, query id 24543783296 172.24.0.2 readonly
---TRANSACTION 2 1594638951, not started, process no 16670, OS thread id 1288857936
MySQL thread id 6976315118, query id 24543783686 172.24.0.2 readonly
---TRANSACTION 2 1594638897, not started, process no 16670, OS thread id 1075738960
MySQL thread id 6976315049, query id 24543783528 172.24.0.2 readwrite
---TRANSACTION 2 1594638771, not started, process no 16670, OS thread id 1234544976
MySQL thread id 6976315095, query id 24543783365 172.24.0.2 readwrite
---TRANSACTION 2 1594638731, not started, process no 16670, OS thread id 1345300816
MySQL thread id 6976315077, query id 24543783797 172.24.0.2 readonly
---TRANSACTION 2 1594638923, not started, process no 16670, OS thread id 1406269776
MySQL thread id 6976315021, query id 24543783608 172.24.0.2 readwrite
---TRANSACTION 2 1594638975, not started, process no 16670, OS thread id 1348229456
MySQL thread id 6976315074, query id 24543783772 172.24.0.2 readonly
---TRANSACTION 2 1594638687, not started, process no 16670, OS thread id 1244129616
MySQL thread id 6976315053, query id 24543783681 172.24.0.2 readonly
---TRANSACTION 2 1594638780, not started, process no 16670, OS thread id 1395087696
MySQL thread id 6976315033, query id 24543783276 172.24.0.2 readonly
---TRANSACTION 2 1594638782, not started, process no 16670, OS thread id 1202329936
MySQL thread id 6976315030, query id 24543783278 172.24.21.19 readonly
---TRANSACTION 2 1594638645, not started, process no 16670, OS thread id 1203394896
MySQL thread id 6976315028, query id 24543782985 172.24.0.2 readonly
---TRANSACTION 2 1594638634, not started, process no 16670, OS thread id 1310689616
MySQL thread id 6976315022, query id 24543782969 172.24.21.19 readonly
---TRANSACTION 2 1594638633, not started, process no 16670, OS thread id 1190082896
MySQL thread id 6976315023, query id 24543783737 172.24.0.2 readonly
---TRANSACTION 2 1594638787, not started, process no 16670, OS thread id 1385503056
MySQL thread id 6976315011, query id 24543783285 172.24.0.2 readonly
---TRANSACTION 2 1594638602, not started, process no 16670, OS thread id 1409997136
MySQL thread id 6976315007, query id 24543782912 172.24.21.19 readonly
---TRANSACTION 2 1594638579, not started, process no 16670, OS thread id 1346365776
MySQL thread id 6976314184, query id 24543782960 172.24.0.2 readwrite
---TRANSACTION 2 1594638935, not started, process no 16670, OS thread id 1269156176
MySQL thread id 6976314961, query id 24543783645 172.24.0.2 readonly
---TRANSACTION 2 1594638458, not started, process no 16670, OS thread id 1429698896
MySQL thread id 6976314942, query id 24543783593 172.24.0.2 readonly
---TRANSACTION 2 1594638926, not started, process no 16670, OS thread id 1081129296
MySQL thread id 6976314918, query id 24543783618 172.24.0.2 readonly
---TRANSACTION 2 1594638427, not started, process no 16670, OS thread id 1402276176
MySQL thread id 6976314858, query id 24543782714 172.24.0.2 readwrite
---TRANSACTION 2 1594638324, not started, process no 16670, OS thread id 1219103056
MySQL thread id 6976314865, query id 24543782531 172.24.0.2 readonly
---TRANSACTION 2 1594638304, not started, process no 16670, OS thread id 1217505616
MySQL thread id 6976314851, query id 24543782334 172.24.0.2 readonly
---TRANSACTION 2 1594638242, not started, process no 16670, OS thread id 1204992336
MySQL thread id 6976314781, query id 24543782210 172.24.0.2 readwrite
---TRANSACTION 2 1594638104, not started, process no 16670, OS thread id 1208985936
MySQL thread id 6976314732, query id 24543782126 172.24.0.2 readonly
---TRANSACTION 2 1594638084, not started, process no 16670, OS thread id 1372457296
MySQL thread id 6976314714, query id 24543781873 172.24.0.2 readonly
---TRANSACTION 2 1594638083, not started, process no 16670, OS thread id 1227090256
MySQL thread id 6976314689, query id 24543783323 172.24.21.19 readwrite
---TRANSACTION 2 1594638152, not started, process no 16670, OS thread id 1285130576
MySQL thread id 6976314673, query id 24543782470 172.24.21.19 readonly
---TRANSACTION 2 1594638133, not started, process no 16670, OS thread id 1236408656
MySQL thread id 6976314670, query id 24543781963 172.24.0.2 readonly
---TRANSACTION 2 1594638689, not started, process no 16670, OS thread id 1378314576
MySQL thread id 6976314661, query id 24543783582 172.24.0.2 readonly
---TRANSACTION 2 1594637919, not started, process no 16670, OS thread id 1294981456
MySQL thread id 6976314582, query id 24543781464 172.24.0.2 readonly
---TRANSACTION 2 1594638993, not started, process no 16670, OS thread id 1230285136
MySQL thread id 6976314565, query id 24543783822 172.24.0.2 readonly
---TRANSACTION 2 1594637889, not started, process no 16670, OS thread id 1176504656
MySQL thread id 6976314558, query id 24543781388 172.24.0.2 readonly
---TRANSACTION 2 1594637695, not started, process no 16670, OS thread id 1188219216
MySQL thread id 6976314435, query id 24543783810 172.24.0.2 readonly
---TRANSACTION 2 1594636477, not started, process no 16670, OS thread id 1379645776
MySQL thread id 6976313272, query id 24543778354 172.24.0.2 readwrite
---TRANSACTION 2 1594638804, not started, process no 16670, OS thread id 1332521296
MySQL thread id 6976313552, query id 24543783311 172.24.0.2 readonly
---TRANSACTION 2 1594636327, not started, process no 16670, OS thread id 1392159056
MySQL thread id 6976313460, query id 24543777763 172.24.0.2 readonly
---TRANSACTION 2 1594638848, not started, process no 16670, OS thread id 1358080336
MySQL thread id 6976313203, query id 24543783542 172.24.21.19 readonly
---TRANSACTION 2 1594635033, not started, process no 16670, OS thread id 1082997072
MySQL thread id 6976312502, query id 24543774736 172.24.0.2 readwrite
---TRANSACTION 2 1594634847, not started, process no 16670, OS thread id 1302436176
MySQL thread id 6976312376, query id 24543780952 172.24.0.2 readwrite
---TRANSACTION 2 1594634012, not started, process no 16670, OS thread id 1280604496
MySQL thread id 6976311989, query id 24543772726 172.24.0.2 readonly
---TRANSACTION 2 1594633833, not started, process no 16670, OS thread id 1390827856
MySQL thread id 6976311765, query id 24543772353 172.24.0.2 readonly
---TRANSACTION 2 1594638984, not started, process no 16670, OS thread id 1180498256
MySQL thread id 6976311498, query id 24543783824 172.24.0.2 readonly
---TRANSACTION 2 1594638855, not started, process no 16670, OS thread id 1312819536
MySQL thread id 6976311467, query id 24543783563 172.24.0.2 readonly
---TRANSACTION 2 1594633289, not started, process no 16670, OS thread id 1084356944
MySQL thread id 6976311315, query id 24543783517 172.24.0.2 readonly
---TRANSACTION 2 1594633524, not started, process no 16670, OS thread id 1077754192
MySQL thread id 6976311161, query id 24543783604 172.24.0.2 readonly
---TRANSACTION 2 1594632775, not started, process no 16670, OS thread id 1387366736
MySQL thread id 6976310798, query id 24543783824 172.24.0.2 readonly
---TRANSACTION 2 1594638274, not started, process no 16670, OS thread id 1336781136
MySQL thread id 6976308416, query id 24543783827 172.24.0.2 readwrite
---TRANSACTION 2 1594637914, not started, process no 16670, OS thread id 1319209296
MySQL thread id 6976305431, query id 24543781455 172.24.0.2 readonly
---TRANSACTION 2 1594637639, not started, process no 16670, OS thread id 1360476496
MySQL thread id 6976286463, query id 24543780813 172.24.0.2 readonly
---TRANSACTION 2 1594601131, not started, process no 16670, OS thread id 1376450896
MySQL thread id 6976275163, query id 24543671866 172.24.0.2 readonly
---TRANSACTION 0 0, not started, process no 16670, OS thread id 1161861456
MySQL thread id 6976021353, query id 24543783828 localhost root
show innodb status
---TRANSACTION 2 1594617250, not started, process no 16670, OS thread id 1284864336
MySQL thread id 6976219191, query id 24543722876 172.24.0.2 readonly
---TRANSACTION 2 1594503382, not started, process no 16670, OS thread id 1229486416
MySQL thread id 6976183067, query id 24543401940 172.24.0.2 readwrite
---TRANSACTION 2 1594615159, not started, process no 16670, OS thread id 1166653776
MySQL thread id 6976103244, query id 24543716049 172.24.0.2 readonly
---TRANSACTION 2 1594261924, not started, process no 16670, OS thread id 1313085776
MySQL thread id 6975951203, query id 24542727637 172.24.21.19 readonly
---TRANSACTION 2 1593727564, not started, process no 16670, OS thread id 1166387536
MySQL thread id 6975473457, query id 24541302242 172.24.21.19 readonly
---TRANSACTION 2 1593159738, not started, process no 16670, OS thread id 1284331856
MySQL thread id 6975003450, query id 24539858051 172.24.21.19 readonly
---TRANSACTION 2 1594638985, not started, process no 16670, OS thread id 1169848656
MySQL thread id 6974686686, query id 24543783806 172.24.0.2 readonly
---TRANSACTION 2 1592767036, not started, process no 16670, OS thread id 1176770896
MySQL thread id 6974686679, query id 24543783798 172.24.0.2 readwrite
---TRANSACTION 2 1592133017, not started, process no 16670, OS thread id 1225759056
MySQL thread id 6974128272, query id 24537203401 172.24.21.19 readonly
---TRANSACTION 0 0, not started, process no 16670, OS thread id 1615534416
MySQL thread id 5962897775, query id 24543752819 localhost mysqlmonitor
---TRANSACTION 2 1594456162, not started, process no 16670, OS thread id 1185290576
MySQL thread id 4250603963, query id 24543259479 Has read all relay log; waiting for the slave I/O thread to update it
The above details some of the ongoing transaction - similar to 'show processlist' "Trx id counter 2 1594638995" Is a counter that increments upon transactions since server start.
"Purge done for trx's n:o <>
"History list length 928" - Again, I'm not entirely sure that this variable means.
---TRANSACTION 0 0, not started, process no 16670, OS thread id 1206856016
mysql tables in use 1, locked 1
MySQL thread id 6976314925, query id 24543783827 172.24.0.2 readwrite init
UPDATE Subscribers SET EmailAddress = '12618060932336258813', RealEstProps = '106370836 104481172 105731349 105958174 105958282 105969863 105974146 105998765 106010720 106078593 106102921 106150346 106322759 106337015 106340214 106312885 106343690 106159839 106207162 106290970', LastAccess = 1268028314 WHERE EmailAddress = '12618060932336258813'

Information like the above is similar to the output of 'show processlist' at that exact point in time. As I understand it, similar to 'show processlist', if you see many transactions here you have a concurrency performance issue.

--------
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: 0; buffer pool: 0
35818914 OS file reads, 248305163 OS file writes, 47414036 OS fsyncs
4.57 reads/s, 27392 avg bytes/read, 16.57 writes/s, 2.14 fsyncs/s
This shows how Innodb is going reading and writing to disk. There are four threads by default - the buffer pool thread, the log thread, reading and writing. What we see is no pending 'aios' (async io) - which means the server is not waiting on disk. The second last line shows the number of reads, writes and filesystem syncs that have been performed since sever stat - this database server (readb01.kp) is mixed and does slightly more reads than writes.
The last line shows the averages per second since the interval listed at the top of the 'show innodb status' output. So clearly there were some write transactions and not mean read transactions going on.
Again, theres no pending aio's so the server is not IO bound.

-------------------------------------
INSERT BUFFER AND ADAPTIVE HASH INDEX
-------------------------------------
Ibuf: size 1, free list len 131, seg size 133,
4000946 inserts, 4000946 merged recs, 601283 merges
Hash table size 26690981, node heap has 69134 buffer(s)
678.95 hash searches/s, 2176.34 non-hash searches/s
Now I'm a little green on the output of the above. The insert buffer is related to the insert buffer thread and the adaptive hash index in the algorithm Innodb uses to insert data into the tablespace.
---
LOG
---
Log sequence number 327 3878392573
Log flushed up to 327 3878369439
Last checkpoint at 327 3640927886
0 pending log writes, 0 pending chkp writes
36089932 log i/o's done, 1.36 log i/o's/second
The above information pertains to the circle logs in Innodb - This shows how much data has not been flushed to disk that still remains in the innodb circle logs. (3878392573-3878369439) 23134 bytes. The innodb log files are set to around 160Mb to reduce the amount of IO at the cost of start up time upon crash.
----------------------
BUFFER POOL AND MEMORY
----------------------
Total memory allocated 15308894706; in additional pool allocated 45677312
Dictionary memory allocated 658920
Buffer pool size 823168
Free buffers 0
Database pages 754034
Modified db pages 29518
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages read 44983219, created 3689633, written 250224524
7.64 reads/s, 0.07 creates/s, 19.64 writes/s
Buffer pool hit rate 1000 / 1000
The total memory is the total memory Innodb has allocated - 15Gb - the additional buffer pool is set to ~400Mb (for data dictionary etc).
Dictionary memory allocated is much less than the additional buffer pool size suggesting that the additional buffer pool memory size can be dropped.
The buffer pool is used to cache the tablespace, store locks and most things innodb so it needs to be set quiet large. What I take into account is the last line which is a ratio output of the usefulness of the innodb buffer pool - the hit rate is currently 1000/1000 or 100% - in other words all transactions, be them read or write can go via the buffer pool instead of missing the buffer pool and going directly to disk.

--------------
ROW OPERATIONS
--------------
1 queries inside InnoDB, 0 queries in queue
1 read views open inside InnoDB
Main thread process no. 16670, id 1156270416, state: sleeping
Number of rows inserted 200754864, updated 1377590681, deleted 77291280, read 722941029741
4.50 inserts/s, 116.85 updates/s, 0.00 deletes/s, 96297.19 reads/s
----------------------------
END OF INNODB MONITOR OUTPUT
============================
1 row in set, 1 warning (0.00 sec)

The '0 queries in the queue' shows that there are currently no transactions in the Innodb kernel waiting to execute. The remaining lines show the type of work Innodb is doing.


PlanetMySQL Voting: Vote UP / Vote DOWN

A growing trend: InnoDB mutex contention

Март 4th, 2010

I’ve been noticing an undeniable trend in my consulting engagements in the last year or so, and when I vocalized this today, heads nodded all around me. Everyone sees a growth in the number of cases where otherwise well-optimized systems are artificially limited by InnoDB contention problems.

A year ago, I simply wasn’t seeing the need for analysis of GDB backtraces en masse. These days, I’m writing custom tools to gather and analyze backtraces. A year ago, I simply looked at the SEMAPHORE section of SHOW INNODB STATUS. These days I’m writing custom tools to aggregate and reformat that data so I can interpret it more easily. And I’m actually seeing cases of this type of problem multiple times every week. I remember the first time I ran into a server that was literally optimized to the limit, but struggling under the load. It was something new for me, not that long ago. Oh, I’d seen it before, plenty, but was always able to point out where something could be improved without changing InnoDB itself. Now it’s commonplace: schemas are fine — check. Queries are all well-indexed — check. Everything else — check. InnoDB is bottlenecked and absolutely nothing can be improved — check.

Part of the difference is the rapidly improving hardware. It’s getting hard to buy a server with fewer than 8 or even 16 cores, and 16GB of RAM feels like something I’d install in a wristwatch. But I also suspect that if I’d been characterizing the workload of servers over time in a way that was easy to compare, I’d see a clear trend towards bigger data and more queries per second. We’re just pushing MySQL + InnoDB harder today than we ever have before.

What can be done? Well, InnoDB needs to be improved, that’s all. Oracle, Percona, Google, Facebook and others are working on it, and in many cases these efforts have yielded dramatic results. But there is still much room for improvement.

Related posts:

  1. Hindsight on a scalable replacement for InnoDB A while ag
  2. What do you know about Oracle’s InnoDB+ storage engine? That
  3. Xtrabackup is for InnoDB tables too, not just XtraDB Just thoug

Related posts brought to you by Yet Another Related Posts Plugin.


PlanetMySQL Voting: Vote UP / Vote DOWN

The innodb_plugin – a pleasant surprise!

Март 4th, 2010

I’ve heard about the innodb_plugin but not had time to put it to the test.

Recently though due to some problems I’ve been having with the MySQL Enterprise Monitor (Merlin) I’ve had to try a few changes and had the opportunity to try out the innodb plugin.

I have been using Merlin for some time and like it a lot. It is not perfect but does a good job for me.  However, since upgrading to version 2.1 I have been having some database load problems. I long ago split the merlin server into a front- and back-end server with the backend running a standard MySQL 5.1 Advanced package. That has been working fine.

I have been monitoring more and more mysqld servers and recently the database backend could not cope. Basically the writes of data collected from the agents and the deletes of old date (purging) caused too much I/O and that is on a box with 6 disks in RAID-10 with a battery backed write-cache.

So I upgraded the db server to a new box with lots of memory and a 300 GB Fusion IO card. I expected all problems to go away. Well not quite. In spite of the solid state drive which was not I/O bound, and the CPU which was not CPU bound, mysqld could not keep up with the load. This was running the MySQL 5.1.44 Advanced rpm. Looking more deeply it seems that mysqld itself was the bottleneck and there was too much contention on the PK by the different INSERTing and DELETing threads.

The Merlin team suggested trying the innodb_plugin (1.0.6) and all of a sudden the bottleneck seems to have gone away.

This is the iostat output taken before switching to the innodb plugin:

Device:    rrqm/s wrqm/s   r/s     w/s  rsec/s  wsec/s    rkB/s    wkB/s avgrq-sz avgqu-sz   await  svctm  %util
fioa         0.00   0.00  4.21 4049.50   33.67 32337.07    16.83 16168.54     7.99   192.42    6.31   0.25 100.22
fioa         0.00   0.00  9.78 4379.44  153.29 34942.12    76.65 17471.06     8.00     0.00    6.17   0.00   0.00
fioa         0.00   0.00 20.80 4455.40  408.00 35552.60   204.00 17776.30     8.03     0.00    5.96   0.00   0.00
fioa         0.00   0.00 21.80 4685.00  267.20 37391.20   133.60 18695.60     8.00    24.00    5.87   0.21 100.02
fioa         0.00   0.00 23.60 5200.40  320.00 41490.40   160.00 20745.20     8.00     0.00    6.04   0.00   0.00
fioa         0.00   0.00 15.17 5020.36  202.79 40055.09   101.40 20027.54     7.99     0.00    5.65   0.00   0.00

This is the iostat output taken after switching to the innodb plugin:

Device:    rrqm/s wrqm/s   r/s     w/s  rsec/s   wsec/s   avgrq-sz avgqu-sz   await  svctm  %util
fioa         0.00   0.00  4.40 2344.80  160.00 201520.00     85.85     0.00    0.41   0.00   0.00
fioa         0.00   0.00  2.00 2188.20   64.00 193500.80     88.38     0.00    0.41   0.00   0.00
fioa         0.00   0.00  1.80 2113.60   57.60 200889.20     94.99     0.00    0.44   0.00   0.00
fioa         0.00   0.00  0.40 1961.60   12.80 194291.20     99.03     0.00    0.43   0.00   0.00
fioa         0.00   0.00  0.00 2118.00    0.00 202496.40     95.61     0.00    0.47   0.00   0.00
fioa         0.00   0.00  0.00 2030.00    0.00 191482.40     94.33     0.00    0.46   0.00   0.00
fioa         0.00   0.00  0.00 2152.60    0.00 208485.20     96.85     0.00    0.44   0.00   0.00
fioa         0.00   0.00  0.00 1936.20    0.00 178732.40     92.31     0.00    0.42   0.00   0.00
fioa         0.00   0.00  4.79 1249.70  153.29 115475.45     92.17     0.00    0.40   0.00   0.00

Note: the first set of figures was taken using CentOS 4, and the second using CentOS 5. The IO statistics aren’t exactly identical and on CentOS 5 for some reason the driver appears not to be providing all the stats. However the wsec/s value clearly shows a significant performance improvement and the original problem mysqld was having of not being able to purge as fast as it was inserting data seems to have been solved. At least initial signs seem to indicate this. The only configuration change made to the server was the following:

ignore_builtin_innodb
plugin-load=innodb=ha_innodb_plugin.so;innodb_trx=ha_innodb_plugin.so;innodb_locks=ha_innodb_plugin.so;innodb_lock_waits=ha_innodb_plugin.so;innodb_cmp=ha_innodb_plugin.so;innodb_cmp_reset=ha_innodb_plugin.so;innodb_cmpmem=ha_innodb_plugin.so;innodb_cmpmem_reset=ha_innodb_plugin.so

innodb_adaptive_flushing = 1
innodb_io_capacity = 1000

Conclusion, if you are having performance problems on your MySQL server and perhaps the hardware is not the bottleneck then try using the plugin. It may make a big difference.

Also a big thanks to the Merlin team for helping me out with this problem and getting things up and running.


PlanetMySQL Voting: Vote UP / Vote DOWN

More MySQL releases

Март 1st, 2010

Shortly after I posted my last summary of MySQL releases, our son Mats was born and I went on a 2.5-week vacation. Our developers did not rest in the meanwhile and I'd like to give you a quick update of what's new since then:

MySQL Connector/Net 6.3.0

  • Visual Studio 2010 RC support
  • Nested transaction scope support

MySQL Workbench 5.2.16 Beta 6

  • Fixed 67 bugs
  • Saving your profile/connection passwords in OSX keychain, gnome-keyring or in an encrypted password-vault-file.
  • New rapid development features for generating complete SQL Select/DML statements or names for selected objects in Query Editor to either the query area or clipboard.
  • The ability to set a preference for the placement  (left or right side) of the sidebar in the Query Editor (Currently on Windows only, coming to Mac and Linux soon).
  • Further optimization and stabilization of the administrator components

MySQL Server 5.1.44

  • This release now includes InnoDB Plugin version 1.0.6, wich is considered to be of Release Candidate (RC) quality.
  • Lots of bug fixes - see the ChangeLog for details.

MySQL Server 5.5.2 Milestone 2

  • Also includes the updated InnoDB Plugin 1.0.6 and several fixes - see the ChangeLog for details. For an overview of new features in the 5.5 code base, check out the "What's new in 5.5" page in the reference manual.

Please note that the MySQL downloads section has been split into two parts. As usual, you will find downloads of both GA and development versions of all MySQL products and releases on the MySQL DevZone. In addition to that, we've now added a pointer to the downloads of officially released (GA) versions to the main web site on http://www.mysql.com/downloads/.


PlanetMySQL Voting: Vote UP / Vote DOWN

Maximal write througput in MySQL

Март 1st, 2010

I recently was asked what maximal amount transactions per second we can get using MySQL and XtraDB / InnoDB storage engine if we have high-end server. Good questions, though not easy to answer, as it depends on:

- durability setting ( innodb_flush_log_at_trx_commit = 0 or 1 ) ?
- do we use binary logs ( I used ROW based replication for 5.1)
- do we have sync_binlog options.

So why would not take these as variable parameters and run simple benchmark.
I took sysbench update_key scenario ( update indexed field on simple table)
and used Dell PowerEdge R900 with 16 cores, FusionIO as storage for table and RAID 10 with BBU as storage for innodb log files, innodb system table space and binary logs. And I used Percon-XtraDB-5.1.43-9.1 for benchmarks. All used partitions are formatted in XFS and mounted with nobarrier option.

I run update key for various threads and with next parameters

  • trx_commit=0 : innodb_flush_log_at_trx_commit = 0 and no binary logs
  • trx_commit=1 : innodb_flush_log_at_trx_commit = 1 and no binary logs
  • trx_commit=0 & binlog : innodb_flush_log_at_trx_commit = 0 and binary logs
  • trx_commit=1 & binlog : innodb_flush_log_at_trx_commit = 1 and binary logs
  • trx_commit=1 & binlog & sync_bin : innodb_flush_log_at_trx_commit = 1 and binary logs and sync_binlog=1
  • There are results I get:

    I found results being quite interesting.
    with innodb_flush_log_at_trx_commit = 0 maximal tps is 36332.02 tps, which drops to 23115.04 tps as
    we switch to innodb_flush_log_at_trx_commit = 1. As we use RAID10 with BBU, I did not expect the drops is going to be significant. In second case InnoDB spends

    With enabling binary logs, the results drops to 17451.01 tps with innodb_flush_log_at_trx_commit = 0 and to 12097.39 tps with innodb_flush_log_at_trx_commit = 1. So with binary logs serialization is getting even worse.

    Enabling sync_binlog makes things really bad, and maximal results I have is
    3086.7 tps. So this is good decision if binary log protection is worth such drop.


    Entry posted by Vadim | No comment

    Add to: delicious | digg | reddit | netscape | Google Bookmarks


    PlanetMySQL Voting: Vote UP / Vote DOWN

Maximal write througput in MySQL

Март 1st, 2010

I recently was asked what maximal amount transactions per second we can get using MySQL and XtraDB / InnoDB storage engine if we have high-end server. Good questions, though not easy to answer, as it depends on:

- durability setting ( innodb_flush_log_at_trx_commit = 0 or 1 ) ?
- do we use binary logs ( I used ROW based replication for 5.1)
- do we have sync_binlog options.

So why would not take these as variable parameters and run simple benchmark.
I took sysbench update_key scenario ( update indexed field on simple table)
and used Dell PowerEdge R900 with 16 cores, FusionIO as storage for table and RAID 10 with BBU as storage for innodb log files, innodb system table space and binary logs. And I used Percon-XtraDB-5.1.43-9.1 for benchmarks. All used partitions are formatted in XFS and mounted with nobarrier option.

I run update key for various threads and with next parameters

  • trx_commit=0 : innodb_flush_log_at_trx_commit = 0 and no binary logs
  • trx_commit=1 : innodb_flush_log_at_trx_commit = 1 and no binary logs
  • trx_commit=0 & binlog : innodb_flush_log_at_trx_commit = 0 and binary logs
  • trx_commit=1 & binlog : innodb_flush_log_at_trx_commit = 1 and binary logs
  • trx_commit=1 & binlog & sync_bin : innodb_flush_log_at_trx_commit = 1 and binary logs and sync_binlog=1
  • There are results I get:

    I found results being quite interesting.
    with innodb_flush_log_at_trx_commit = 0 maximal tps is 36332.02 tps, which drops to 23115.04 tps as
    we switch to innodb_flush_log_at_trx_commit = 1. As we use RAID10 with BBU, I did not expect the drops is going to be significant. In second case InnoDB spends

    With enabling binary logs, the results drops to 17451.01 tps with innodb_flush_log_at_trx_commit = 0 and to 12097.39 tps with innodb_flush_log_at_trx_commit = 1. So with binary logs serialization is getting even worse.

    Enabling sync_binlog makes things really bad, and maximal results I have is
    3086.7 tps. So this is good decision if binary log protection is worth such drop.


    Entry posted by Vadim | No comment

    Add to: delicious | digg | reddit | netscape | Google Bookmarks


    PlanetMySQL Voting: Vote UP / Vote DOWN

MySQL 5.5-m2 scalability

Февраль 28th, 2010

Oracle recently announcent MySQL-5.5.2-m2 milestone, and I have a predition that MySQL-5.5 will be announced as GA on MySQL UC 2010 in April.

So let’s make quick on scalability characteristics we should expect from new release.

I made sysbench oltp benchmarks on 10 mln rows (worth 2.5GB of data), on our Dell R900 system ( 16 cores, 32GB of RAM, FusionIO + RAID10, but disk in this case does not matter).

There is results for various threads (results are in tps, more is better)

I think it is good results, and there couple conclusions we can come with

  • InnoDB now can scale up to 16 threads pretty well
  • InnoDB can keep load up to 128 threads, and for 256 threads the result is still acceptable, but drops by 25% comparing to peak in 16 threads

If you interested what is issue in scaling over 16 threads, that in current
benchmarks – this is concurrency on rollback segment (which is global shared structure in InnoDB)

sysbench command for reference:

./sysbench --test=oltp --oltp-table-size=10000000 --init-rng=1 --num-threads=$i --max-requests=0 --oltp-dist-type=uniform --max-time=180 run


Entry posted by Vadim | No comment

Add to: delicious | digg | reddit | netscape | Google Bookmarks


PlanetMySQL Voting: Vote UP / Vote DOWN

Index lock and adaptive search – next two biggest InnoDB problems

Февраль 26th, 2010

Running many benchmarks on fast storage (FusionIO, SSDs) and multi-cores CPUs system I constantly face two contention problems.

So I suspect it’s going to be next biggest issues to make InnoDB scaling on high-end system.

This is also reason why in benchmarks I posted previously CPU usage is only about 50%, leaving other 50% in idle state.

First problem is index->lock mutex.
InnoDB uses single mutex per index, so when you run mixed read / write queries, InnoDB locks index for write operation and thus keeps all selects waiting when update/insert is done. This is implemented in this way because write operation may cause B-Tree page split, and InnoDB needs to move records between pages to finish operation. It is getting even worse when for write you need to perform some additional IO to bring page into buffer_pool.

What could be done there internally: there is B-Tree lock free or only page-level lock algorithms, so operation does not need to block whole B-Tree.
From end user point, to fight with this problem, you may need to partition (manually or using 5.1 partitions) table with big index into couple smaller table. It’s ugly, but it can help while main problem is not solved.

Second problem is adaptive_search index.
It appears when you have some scanning by secondary key select queries and write queries at the same time.
InnoDB again uses single global mutex for adaptive_search (single mutex for ALL table and ALL indexes), so write query blocks ALL select queries.
Usually first action is to disable adaptive_search (it is possible via global variable), but it rarely helps actually. With disabled adaptive index InnoDB needs to perform much more operations reading secondary keys.

How it can be solved internally: I think some hashing algorithms may be applied to not lock select queries. We may look how to implement it.

Until that InnoDB basically can’t utilize powerful hardware.
For example even in IO intensive load I am getting the same result
for single FusionIO card and for two FusionIO cards coupled in RAID0 (which theoretically doubles througput).


Entry posted by Vadim | No comment

Add to: delicious | digg | reddit | netscape | Google Bookmarks


PlanetMySQL Voting: Vote UP / Vote DOWN

Missleading Innodb message on recovery

Февраль 16th, 2010

As I wrote about 2 years ago the feature of Innodb to store copy of master’s position in Slave’s Innodb tablespace got broken. There is a lot of discussions at the corresponding bug report while outcome of the fix remained uncertain for me (the bug is market duplicate while the bugs it seems to be duplicate for describe different issues).
Anyway. The customer came to me today having the following message in the error log after Slave crash while running MySQL 5.1.41 (extra virgin version without XtraDB or Percona Patches)

InnoDB: In a MySQL replication slave the last master binlog file
InnoDB: position 0 10000000, file name mysql-bin.005000
InnoDB: Last MySQL binlog file position 0 20000000, file name ./mysql-bin.003000

He has tried to restart replication from mysql-bin.005000 position 10000000 which failed with “Could not find first log file name in binary log index file” error message

Looking at the Master for this slave I could see its binary log files going only to about 2000, so the binary log file mentioned did not ever exist on this master. What is going on ?
The thing is Innodb does not update this information any more however if it is stored in the tablespace the code is still there to print it. This database was running older MySQL version a while back which was updated to MySQL 5.1 months ago, moved to the new hardware by physical copy and the log file numbers restarted back from 1 but tablespace still contained the ancient data.

I reported the bug on this which should be easy to fix. Otherwise it is easy mistake to make. We also have a patch which restores this information and uses it on slave crash recovery.


Entry posted by peter | No comment

Add to: delicious | digg | reddit | netscape | Google Bookmarks


PlanetMySQL Voting: Vote UP / Vote DOWN