3

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?

  • Do you use any form of replication? (master-slave or galera) I've seen lock wait timeout with galera and insert .. select, not sure what the actual problem is but my intuition is that as insert .. select locks the selected table for a repeatable read, you can get "concurrent" transaction from other galera node which changes the table - so galera has to stop your insert .. select to apply that incoming transaction (it is already being commited so it wins by default), only the error message should say something about deadlock at least, or something better. – jkavalik Jul 21 '15 at 6:08
  • @jkavalik no, I am not use any of the replication form mentioned above, all happen on the same server but different DB. I am selecting from one and inserting in another one, this is what triggers does – ReynierPM Jul 21 '15 at 6:49

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

Browse other questions tagged or ask your own question.