HiveBrain v1.2.0
Get Started
← Back to all entries
patternsqlMinor

Where is the INNODB Performance Leak?

Submitted by: @import:stackexchange-dba··
0
Viewed 0 times
theinnodbwhereleakperformance

Problem

I have a weird problem which I cannot seem to fix. I'm more an web programmer than a Server/DB Admin, so I hope someone here can help me.

The Situation

I am working on a system which handles a lot of update, insert and delete requests. Because of that, I chose INNODB as my storage engine for its row lock capability. We are updating 60,000 Records every 10 Minutes, using Gearman to parallelize our work on different servers. The code is in PHP and we are using Zend Framework.

The Problem

SQLSTATE[HY000]: General error: 1205 Lock wait timeout exceeded; try restarting transaction


We get the above error nearly every 30 minutes, from one of our Gearman workers.

The mysql_report

```
MySQL 5.1.63-0+squeeze1 uptime 15 9:52:12 Tue Sep 11 21:25:23 2012

__ Key _________________________________________________________________
Buffer used 55.00k of 16.00M %Used: 0.34
Current 2.92M %Usage: 18.24
Write hit 99.95%
Read hit 100.00%

__ Questions ___________________________________________________________
Total 122.05M 91.7/s
DMS 106.63M 80.1/s %Total: 87.37
Com_ 10.23M 7.7/s 8.38
COM_QUIT 4.05M 3.0/s 3.32
QC Hits 1.09M 0.8/s 0.90
+Unknown 47.77k 0.0/s 0.04
Slow 2 s 11.14M 8.4/s 9.13 %DMS: 10.45 Log: ON
DMS 106.63M 80.1/s 87.37
INSERT 69.21M 52.0/s 56.70 64.90
UPDATE 22.94M 17.2/s 18.79 21.51
DELETE 11.19M 8.4/s 9.17 10.49
SELECT 3.30M 2.5/s 2.70 3.09
REPLACE 0 0/s 0.00 0.00
Com_ 10.23M 7.7/s 8.38
set_option 4.11M 3.1/s 3.37
show_fields 3.44M 2.6/s 2.82
begin 1.33M 1.0/s 1.09

__ SELECT and Sort _________________

Solution

OBSERVATION #1

Just looking at the output of your SHOW ENGINE INNODB STATUS\G I see a variety of table lock message at the bottom of each transaction. You have one transaction that is holding lock 38096 rows

------------------
---TRANSACTION 0 20639508, ACTIVE 30 sec, process no 1655, OS thread id 47843558143744 fetching rows
mysql tables in use 1, locked 1
LOCK WAIT 700 lock struct(s), heap size 63472, 38096 row lock(s)
MySQL thread id 99117, query id 2086890 s16468810.onlinehome-server.info 87.106.82.83 web0 Updating
UPDATE userproducts SET lowest_price=109.9, last_lowest_price_update='2012-09-12 17:14:53' WHERE product_id LIKE 'B002AL8F72'
------- TRX HAS BEEN WAITING 1 SEC FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 631 page no 985 n bits 136 index `PRIMARY` of table `usr_web0_1`.`userproducts` trx id 0 20639508 lock_mode X waiting
Record lock, heap no 59 PHYSICAL RECORD: n_fields 34; compact format; info bits 0
 0: len 4; hex 815d9f43; asc  ] C;; 1: len 6; hex 0000013aef08; asc    :  ;; 2: len 7; hex 00000000391358; asc     9 X;; 3: len 4; hex 80006f9a; asc   o ;; 4: len 12; hex 30302d3956335a2d47555a34; asc 00-9V3Z-GUZ4;; 5: len 10; hex 42303032414c38463732; asc B002AL8F72;; 6: len 4; hex cdccdb42; asc    B;; 7: len 4; hex 00000000; asc     ;; 8: len 4; hex cdccdb42; asc    B;; 9: len 4; hex 000080bf; asc     ;; 10: len 4; hex 800003e7; asc     ;; 11: len 4; hex cdccdb42; asc    B;; 12: len 30; hex 537572706c75732056696e74616765204a61636b65204d36352052656769; asc Surplus Vintage Jacke M65 Regi;...(truncated); 13: len 30; hex 687474703a2f2f6563782e696d616765732d616d617a6f6e2e636f6d2f69; asc http://ecx.images-amazon.com/i;...(truncated); 14: len 4; hex 800034c5; asc   4 ;; 15: len 10; hex 42656b6c656964756e67; asc Bekleidung;; 16: len 3; hex 4e2f41; asc N/A;; 17: len 3; hex 4e2f41; asc N/A;; 18: len 4; hex 80000000; asc     ;; 19: len 4; hex 80000000; asc     ;; 20: len 4; hex 80000000; asc     ;; 21: len 4; hex 80000000; asc     ;; 22: len 4; hex 80000000; asc     ;; 23: len 4; hex 80000000; asc     ;; 24: len 1; hex 80; asc  ;; 25: SQL NULL; 26: SQL NULL; 27: len 4; hex 00000000; asc     ;; 28: len 4; hex 00000000; asc     ;; 29: len 4; hex 00000000; asc     ;; 30: len 4; hex 6575726f; asc euro;; 31: len 4; hex 00000000; asc     ;; 32: len 8; hex 8000124cc3d291ec; asc    L    ;; 33: len 8; hex 8000124cc3d28fc6; asc    L    ;;


OBSERVATION #2

Looking back at the table structure, I see the userproducts table has no index on product_id. Because of this, you are doing full table scans to perform the update of a single row.

OBSERVATION #3

You also have a duplicate index in the userproducts table. Two indexes start with the userinfos_id column. No need to bloat indexes with duplicate leading columns.

OBSERVATION #4

You have innodb_thread_concurrency = 8. It should be set to zero for infinite concurrency

See my past posts on this

  • May 26, 2011 : About single threaded versus multithreaded databases performance



  • Sep 12, 2011 : Possible to make MySQL use more than one core?



  • Feb 24, 2012 : Tuning dedicated Percona Server with XtraDB for OLTP



  • Mar 16, 2012 : Using multiple cores for single MySQL queries on Debian



RECOMMENDATION #1

Add this to /etc/my.cnf

[mysqld]
innodb_thread_concurrency = 0


and restart MySQL

RECOMMENDATION #2

Please run this during your off period

ALTER TABLE userproducts ADD INDEX product_id (product_id),DROP INDEX userinfos_id;


RECOMMENDATION #3 (Optional Long Term Goal)

You need to restructure your InnoDB Layout because you have innodb_file_per_table on. That nullifies the need for multiple ibdata files. You only need one. Please see my past posts on this:

  • Oct 29, 2010 : My Original Post in StackOverflow



  • Apr 01, 2012 : Is innodb_file_per_table advisable?



  • Mar 25, 2012 : Why does InnoDB store all databases in one file?



  • Feb 03, 2012 : Scheduled optimization of tables in MySQL InnoDB



Give it a Try !!!

Code Snippets

------------------
---TRANSACTION 0 20639508, ACTIVE 30 sec, process no 1655, OS thread id 47843558143744 fetching rows
mysql tables in use 1, locked 1
LOCK WAIT 700 lock struct(s), heap size 63472, 38096 row lock(s)
MySQL thread id 99117, query id 2086890 s16468810.onlinehome-server.info 87.106.82.83 web0 Updating
UPDATE userproducts SET lowest_price=109.9, last_lowest_price_update='2012-09-12 17:14:53' WHERE product_id LIKE 'B002AL8F72'
------- TRX HAS BEEN WAITING 1 SEC FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 631 page no 985 n bits 136 index `PRIMARY` of table `usr_web0_1`.`userproducts` trx id 0 20639508 lock_mode X waiting
Record lock, heap no 59 PHYSICAL RECORD: n_fields 34; compact format; info bits 0
 0: len 4; hex 815d9f43; asc  ] C;; 1: len 6; hex 0000013aef08; asc    :  ;; 2: len 7; hex 00000000391358; asc     9 X;; 3: len 4; hex 80006f9a; asc   o ;; 4: len 12; hex 30302d3956335a2d47555a34; asc 00-9V3Z-GUZ4;; 5: len 10; hex 42303032414c38463732; asc B002AL8F72;; 6: len 4; hex cdccdb42; asc    B;; 7: len 4; hex 00000000; asc     ;; 8: len 4; hex cdccdb42; asc    B;; 9: len 4; hex 000080bf; asc     ;; 10: len 4; hex 800003e7; asc     ;; 11: len 4; hex cdccdb42; asc    B;; 12: len 30; hex 537572706c75732056696e74616765204a61636b65204d36352052656769; asc Surplus Vintage Jacke M65 Regi;...(truncated); 13: len 30; hex 687474703a2f2f6563782e696d616765732d616d617a6f6e2e636f6d2f69; asc http://ecx.images-amazon.com/i;...(truncated); 14: len 4; hex 800034c5; asc   4 ;; 15: len 10; hex 42656b6c656964756e67; asc Bekleidung;; 16: len 3; hex 4e2f41; asc N/A;; 17: len 3; hex 4e2f41; asc N/A;; 18: len 4; hex 80000000; asc     ;; 19: len 4; hex 80000000; asc     ;; 20: len 4; hex 80000000; asc     ;; 21: len 4; hex 80000000; asc     ;; 22: len 4; hex 80000000; asc     ;; 23: len 4; hex 80000000; asc     ;; 24: len 1; hex 80; asc  ;; 25: SQL NULL; 26: SQL NULL; 27: len 4; hex 00000000; asc     ;; 28: len 4; hex 00000000; asc     ;; 29: len 4; hex 00000000; asc     ;; 30: len 4; hex 6575726f; asc euro;; 31: len 4; hex 00000000; asc     ;; 32: len 8; hex 8000124cc3d291ec; asc    L    ;; 33: len 8; hex 8000124cc3d28fc6; asc    L    ;;
[mysqld]
innodb_thread_concurrency = 0
ALTER TABLE userproducts ADD INDEX product_id (product_id),DROP INDEX userinfos_id;

Context

StackExchange Database Administrators Q#24189, answer score: 8

Revisions (0)

No revisions yet.