I have a PHP script that sync a local DB against external datasource. Each time the script runs I perform some triggers on the DB where INSERT or UPDATE happen. These are the the triggers for that purpose:
CREATE DEFINER=`root`@`localhost` TRIGGER `veeva_bi`.`account_ai` AFTER INSERT ON `account` FOR EACH ROW
BEGIN
INSERT INTO pdone.targets
(`veeva_account_id`,`veeva_timestamp`,`display_name`,`avatar_url`,`title`,`first`,`last`,`suffix`,`address1`,`address2`,`city`,`state`,`zip`,`phone`,`fax`,`target_type`,`npi`,`inactive`,`lastSyncAt`,`createdAt`,`updatedAt`)
SELECT
account.id AS veeva_account_id,
account.lastmodifieddate AS veeva_timestamp,
veeva_bi.LCAPITAL(CONCAT(account.firstname,' ',account.lastname)) as display_name,
'https://pdone.s3.amazonaws.com/avatar/no_avatar.png' AS avatar_url,
account.title__c AS `title`,
veeva_bi.LCAPITAL(account.firstname) AS `first`,
veeva_bi.LCAPITAL(account.lastname) AS `last`,
account.suffix_vod__c AS `suffix`,
address_vod__c.name AS `address1`,
address_vod__c.address_line_2_vod__c AS `address2`,
address_vod__c.city_vod__c AS `city`,
address_vod__c.state_vod__c AS `state`,
address_vod__c.zip_vod__c AS `zip`,
address_vod__c.phone_vod__c AS `phone`,
address_vod__c.fax_vod__c AS `fax`,
'VEEVA' AS `target_type`,
account.npi_vod__c AS `npi`,
FALSE AS `inactive`,
NOW() AS `lastSyncAt`,
NOW() AS `createdAt`,
NOW() AS `updatedAt`
FROM
account
JOIN
address_vod__c ON address_vod__c.account_vod__c = account.id
WHERE
account.id = NEW.id
AND external_id_vod__c IS NOT NULL
AND address_vod__c.primary_vod__c = 1
AND account.recordtypeid COLLATE utf8_general_ci IN (SELECT id FROM veeva_bi.recordtype WHERE name = 'Professional_vod')
ON DUPLICATE KEY UPDATE
`veeva_timestamp` = NEW.lastmodifieddate,
`display_name` = veeva_bi.LCAPITAL(CONCAT(account.firstname,' ',account.lastname)),
`avatar_url` = 'https://pdone.s3.amazonaws.com/avatar/no_avatar.png',
`title` = account.title__c,
`first` = veeva_bi.LCAPITAL(account.firstname),
`last` = veeva_bi.LCAPITAL(account.lastname),
`suffix` = account.suffix_vod__c,
`address1` = address_vod__c.name,
`address2` = address_vod__c.address_line_2_vod__c,
`city` = address_vod__c.city_vod__c,
`state` = address_vod__c.state_vod__c,
`zip` = address_vod__c.zip_vod__c,
`phone` = address_vod__c.phone_vod__c,
`fax` = address_vod__c.fax_vod__c,
`target_type` ='VEEVA',
`npi` = account.npi_vod__c,
`inactive` = FALSE,
`lastSyncAt` = NOW(),
`updatedAt` = NOW();
END
CREATE DEFINER=`root`@`localhost` TRIGGER `veeva_bi`.`account_au` AFTER UPDATE ON `account` FOR EACH ROW
BEGIN
INSERT INTO pdone.targets
(`veeva_account_id`,`veeva_timestamp`,`display_name`,`avatar_url`,`title`,`first`,`last`,`suffix`,`address1`,`address2`,`city`,`state`,`zip`,`phone`,`fax`,`target_type`,`npi`,`inactive`,`lastSyncAt`,`createdAt`,`updatedAt`)
SELECT
account.id AS veeva_account_id,
account.lastmodifieddate AS veeva_timestamp,
veeva_bi.LCAPITAL(CONCAT(account.firstname,' ',account.lastname)) as display_name,
'no_avatar.png' AS avatar_url,
account.title__c AS `title`,
veeva_bi.LCAPITAL(account.firstname) AS `first`,
veeva_bi.LCAPITAL(account.lastname) AS `last`,
account.suffix_vod__c AS `suffix`,
address_vod__c.name AS `address1`,
address_vod__c.address_line_2_vod__c AS `address2`,
address_vod__c.city_vod__c AS `city`,
address_vod__c.state_vod__c AS `state`,
address_vod__c.zip_vod__c AS `zip`,
address_vod__c.phone_vod__c AS `phone`,
address_vod__c.fax_vod__c AS `fax`,
'VEEVA' AS `target_type`,
account.npi_vod__c AS `npi`,
FALSE AS `inactive`,
NOW() AS `lastSyncAt`,
NOW() AS `createdAt`,
NOW() AS `updatedAt`
FROM
account
JOIN
address_vod__c ON address_vod__c.account_vod__c = account.id
WHERE
account.id = OLD.id
AND external_id_vod__c IS NOT NULL
AND address_vod__c.primary_vod__c = 1
AND account.recordtypeid COLLATE utf8_general_ci IN (SELECT id FROM veeva_bi.recordtype WHERE name = 'Professional_vod')
ON DUPLICATE KEY UPDATE
`veeva_timestamp` = OLD.lastmodifieddate,
`display_name` = pdone.LCAPITAL(CONCAT(account.firstname,' ',account.lastname)),
`avatar_url` = 'no_avatar.png',
`title` = account.title__c,
`first` = veeva_bi.LCAPITAL(account.firstname),
`last` = veeva_bi.LCAPITAL(account.lastname),
`suffix` = account.suffix_vod__c,
`address1` = address_vod__c.name,
`address2` = address_vod__c.address_line_2_vod__c,
`city` = address_vod__c.city_vod__c,
`state` = address_vod__c.state_vod__c,
`zip` = address_vod__c.zip_vod__c,
`phone` = address_vod__c.phone_vod__c,
`fax` = address_vod__c.fax_vod__c,
`target_type` ='VEEVA',
`npi` = account.npi_vod__c,
`inactive` = FALSE,
`lastSyncAt` = NOW(),
`updatedAt` = NOW();
END
For some reason, unknow to me at the moment, the script fails with this message from MariaDB server:
General error: 1205 Lock wait timeout exceeded; try restarting transaction.
I've found several topics about this but I am not an expert on DBA so I can't get the right path to go and need some help and/or advice. Some people says: Kill the running process as shown in this answer, another topic talks about It is evident by the statement that the query was attempting to change at least one row in one or more InnoDB tables and should run the command SHOW ENGINE INNODB STATUS\G as shown in this which, the result on my server, I will show below the problem is I don't know how to read that information since is kind of advanced topic for me (this is where I need a push). I don't think the problem is on the MariaDB DB side but I need to be shure before try to find another solution. If I run this query from MariaDB console I got this results:
MariaDB [(none)]> SHOW PROCESSLIST;
+----+------+-----------------+----------+---------+------+-------+------------------------------------------------------------------------------------------------------+----------+
| Id | User | Host | db | Command | Time | State | Info | Progress |
+----+------+-----------------+----------+---------+------+-------+------------------------------------------------------------------------------------------------------+----------+
| 2 | root | localhost | veeva_bi | Query | 1449 | NULL | INSERT INTO pdone.targets
(`veeva_account_id`,`veeva_timestamp`,`display_name`,`avatar_url`,`tit | 0.000 |
| 3 | root | localhost:34320 | veeva_bi | Sleep | 54 | | NULL | 0.000 |
| 4 | root | localhost:34321 | veeva_bi | Sleep | 55 | | NULL | 0.000 |
| 5 | root | localhost | NULL | Query | 0 | NULL | SHOW PROCESSLIST | 0.000 |
+----+------+-----------------+----------+---------+------+-------+------------------------------------------------------------------------------------------------------+----------+
MariaDB [(none)]> SHOW PROCESSLIST;
+----+------+-----------------+----------+---------+------+--------------+------------------------------------------------------------------------------------------------------+----------+
| Id | User | Host | db | Command | Time | State | Info | Progress |
+----+------+-----------------+----------+---------+------+--------------+------------------------------------------------------------------------------------------------------+----------+
| 2 | root | localhost | veeva_bi | Query | 1485 | Sending data | INSERT INTO pdone.targets
(`veeva_account_id`,`veeva_timestamp`,`display_name`,`avatar_url`,`tit | 0.000 |
| 3 | root | localhost:34320 | veeva_bi | Sleep | 90 | | NULL | 0.000 |
| 4 | root | localhost:34321 | veeva_bi | Sleep | 91 | | NULL | 0.000 |
| 5 | root | localhost | NULL | Query | 0 | NULL | SHOW PROCESSLIST | 0.000 |
+----+------+-----------------+----------+---------+------+--------------+------------------------------------------------------------------------------------------------------+----------+
MariaDB [(none)]> SHOW PROCESSLIST;
+----+------+-----------------+----------+---------+------+-------+------------------------------------------------------------------------------------------------------+----------+
| Id | User | Host | db | Command | Time | State | Info | Progress |
+----+------+-----------------+----------+---------+------+-------+------------------------------------------------------------------------------------------------------+----------+
| 2 | root | localhost | veeva_bi | Query | 1534 | NULL | INSERT INTO pdone.targets
(`veeva_account_id`,`veeva_timestamp`,`display_name`,`avatar_url`,`tit | 0.000 |
| 3 | root | localhost:34320 | veeva_bi | Sleep | 139 | | NULL | 0.000 |
| 4 | root | localhost:34321 | veeva_bi | Sleep | 140 | | NULL | 0.000 |
| 5 | root | localhost | NULL | Query | 0 | NULL | SHOW PROCESSLIST | 0.000 |
+----+------+-----------------+----------+---------+------+-------+------------------------------------------------------------------------------------------------------+----------+
MariaDB [(none)]> SHOW PROCESSLIST;
+----+------+-----------------+----------+---------+------+--------------+------------------------------------------------------------------------------------------------------+----------+
| Id | User | Host | db | Command | Time | State | Info | Progress |
+----+------+-----------------+----------+---------+------+--------------+------------------------------------------------------------------------------------------------------+----------+
| 2 | root | localhost | veeva_bi | Query | 1708 | Sending data | INSERT INTO pdone.targets
(`veeva_account_id`,`veeva_timestamp`,`display_name`,`avatar_url`,`tit | 0.000 |
| 3 | root | localhost:34320 | veeva_bi | Sleep | 10 | | NULL | 0.000 |
| 4 | root | localhost:34321 | veeva_bi | Sleep | 10 | | NULL | 0.000 |
| 5 | root | localhost | NULL | Query | 0 | NULL | SHOW PROCESSLIST | 0.000 |
+----+------+-----------------+----------+---------+------+--------------+------------------------------------------------------------------------------------------------------+----------+
MariaDB [(none)]> SHOW PROCESSLIST;
+----+------+-----------------+----------+---------+------+--------------+------------------------------------------------------------------------------------------------------+----------+
| Id | User | Host | db | Command | Time | State | Info | Progress |
+----+------+-----------------+----------+---------+------+--------------+------------------------------------------------------------------------------------------------------+----------+
| 2 | root | localhost | veeva_bi | Query | 1798 | Sending data | INSERT INTO pdone.targets
(`veeva_account_id`,`veeva_timestamp`,`display_name`,`avatar_url`,`tit | 0.000 |
| 3 | root | localhost:34320 | veeva_bi | Sleep | 100 | | NULL | 0.000 |
| 4 | root | localhost:34321 | veeva_bi | Sleep | 100 | | NULL | 0.000 |
| 5 | root | localhost | NULL | Query | 0 | NULL | SHOW PROCESSLIST | 0.000 |
+----+------+-----------------+----------+---------+------+--------------+------------------------------------------------------------------------------------------------------+----------+
4 rows in set (0.00 sec)
MariaDB [(none)]> SHOW PROCESSLIST;
+----+------+-----------------+----------+---------+------+--------------+------------------------------------------------------------------------------------------------------+----------+
| Id | User | Host | db | Command | Time | State | Info | Progress |
+----+------+-----------------+----------+---------+------+--------------+------------------------------------------------------------------------------------------------------+----------+
| 2 | root | localhost | veeva_bi | Query | 1799 | Sending data | INSERT INTO pdone.targets
(`veeva_account_id`,`veeva_timestamp`,`display_name`,`avatar_url`,`tit | 0.000 |
| 3 | root | localhost:34320 | veeva_bi | Sleep | 101 | | NULL | 0.000 |
| 4 | root | localhost:34321 | veeva_bi | Sleep | 101 | | NULL | 0.000 |
| 5 | root | localhost | NULL | Query | 0 | NULL | SHOW PROCESSLIST | 0.000 |
+----+------+-----------------+----------+---------+------+--------------+------------------------------------------------------------------------------------------------------+----------+
You will notice that process Id = 2 still alive but in NULL state in some cases while in others says Sending data. So my question is: how to fix this? Is a problem on trigger side? Is a problem on innodb_lock_wait_timeout? Where is the issue here and how I can fix it in order to get triggers executed properly?
FYI, the table account where triggers exists and should be executed has exactly 168041 records.
This is the info from the command SHOW ENGINE INNODB STATUS\G:
MariaDB [(none)]> SHOW ENGINE INNODB STATUS\G
*************************** 1. row ***************************
Type: InnoDB
Name:
Status:
=====================================
150720 17:57:38 INNODB MONITOR OUTPUT
=====================================
Per second averages calculated from the last 59 seconds
-----------------
BACKGROUND THREAD
-----------------
srv_master_thread loops: 15185 1_second, 15184 sleeps, 1517 10_second, 13 background, 13 flush
srv_master_thread log flush and writes: 8569
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 1576, signal count 1580
Mutex spin waits 29647, rounds 141294, OS waits 22
RW-shared spins 1544, rounds 45778, OS waits 1522
RW-excl spins 0, rounds 724, OS waits 24
Spin rounds per wait: 4.77 mutex, 29.65 RW-shared, 724.00 RW-excl
--------
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
22264 OS file reads, 34731 OS file writes, 13116 OS fsyncs
0.44 reads/s, 16384 avg bytes/read, 3.29 writes/s, 1.49 fsyncs/s
-------------------------------------
INSERT BUFFER AND ADAPTIVE HASH INDEX
-------------------------------------
Ibuf: size 1, free list len 0, seg size 2, 1 merges
merged operations:
insert 1, delete mark 0, delete 0
discarded operations:
insert 0, delete mark 0, delete 0
Hash table size 276671, node heap has 74 buffer(s)
3.76 hash searches/s, 4.47 non-hash searches/s
---
LOG
---
Log sequence number 938559677
Log flushed up to 938558878
Last checkpoint at 938556484
Max checkpoint age 7782360
Checkpoint age target 7539162
Modified age 3193
Checkpoint age 3193
0 pending log writes, 0 pending chkp writes
9912 log i/o's done, 1.15 log i/o's/second
----------------------
BUFFER POOL AND MEMORY
----------------------
Total memory allocated 137756672; in additional pool allocated 0
Total memory allocated by read views 200
Internal hash tables (constant factor + variable factor)
Adaptive hash index 3430000 (2213368 + 1216632)
Page hash 139112 (buffer pool 0 only)
Dictionary cache 688328 (554768 + 133560)
File system 83536 (82672 + 864)
Lock system 1102064 (332872 + 769192)
Recovery system 0 (0 + 0)
Dictionary memory allocated 133560
Buffer pool size 8191
Buffer pool size, bytes 134201344
Free buffers 1
Database pages 8070
Old database pages 2958
Modified db pages 8
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 31248, not young 0
1.07 youngs/s, 0.00 non-youngs/s
Pages read 22253, created 244, written 23202
0.44 reads/s, 0.02 creates/s, 1.97 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: 8070, unzip_LRU len: 0
I/O sum[132]:cur[0], unzip sum[0]:cur[0]
--------------
ROW OPERATIONS
--------------
0 queries inside InnoDB, 0 queries in queue
1 read views open inside InnoDB
1 transactions active inside InnoDB
1 out of 1000 descriptors used
---OLDEST VIEW---
Normal read view
Read view low limit trx n:o 57617
Read view up limit trx id 57616
Read view low limit trx id 57617
Read view individually stored trx ids:
Read view trx id 57616
-----------------
Main thread process no. 16184, id 139777416341248, state: sleeping
Number of rows inserted 1949, updated 52504, deleted 0, read 7234324767
0.15 inserts/s, 2.46 updates/s, 0.00 deletes/s, 752359.20 reads/s
------------
TRANSACTIONS
------------
Trx id counter 57617
Purge done for trx's n:o < 57614 undo n:o < 0
History list length 1124
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 0, not started
MySQL thread id 7, OS thread handle 0x7f20623ff700, query id 1106421 localhost root
SHOW ENGINE INNODB STATUS
---TRANSACTION 0, not started
MySQL thread id 4, OS thread handle 0x7f2062fb6700, query id 1067637 localhost 127.0.0.1 root
---TRANSACTION 57616, ACTIVE 517 sec fetching rows
mysql tables in use 9, locked 9
7950 lock struct(s), heap size 768440, 536566 row lock(s), undo log entries 15778
MySQL thread id 6, OS thread handle 0x7f2093d5e700, query id 1106420 localhost root Sending data
INSERT INTO pdone.targets
(`veeva_account_id`,`veeva_timestamp`,`display_name`,`avatar_url`,`title`,`first`,`last`,`suffix`,`address1`,`address2`,`city`,`state`,`zip`,`phone`,`fax`,`target_type`,`npi`,`inactive`,`lastSyncAt`,`createdAt`,`up datedAt`)
SELECT
account.id AS veeva_account_id,
account.lastmodifieddate AS veeva_timestamp,
veeva_bi.LCAPITAL(CONCAT(account.firstname,' ',account.lastname)) as display_name,
'https://pdone.s3.amazonaws.com/avatar/no_avatar.png' AS avatar_url,
account.title__c AS `title`,
veeva_bi.LCAPITAL(account.fi
----------------------------
END OF INNODB MONITOR OUTPUT
============================
1 row in set (0.00 sec)
I'm not seeing anything wrong there but as I said before I am not an expert so need some help, can any give me a solution to this? Is a PHP problem? (don't think so but is good to ask also), how can this be fixed? Can a trigger be executed as a batch to avoid this behavior?
