PDO Deadlocks Galore on the Semaphore table

Question

I experience frequent deadlocks on the semaphore table that look like this:

PDOException: SQLSTATE[40001]: Serialization failure: 1213 Deadlock found when trying to get lock; try restarting transaction: DELETE FROM {semaphore} WHERE (name = :db_condition_placeholder_0) AND (value = :db_condition_placeholder_1) AND (expire <= :db_condition_placeholder_2) ; Array ( [:db_condition_placeholder_0] => variable_init [:db_condition_placeholder_1] => 298999494f343fc583c3e2.30542255 [:db_condition_placeholder_2] => 1328824262.5293 ) in lock_may_be_available() (line 181 of /var/www/drupal/includes/lock.inc).

This site sees fairly heavy traffic. Is the load the cause of this? Is this due to a faulty module? Is this something in Drupal core?

Most importantly, are there precautionary measures I can take to avoid this?

Answer 1

It appears that once we implemented memcache the problem began to dissipate. It appears the database was writing very frequently to the cache tables, specifically the cache_form table. These deadlocks would appear when there were just too many commands running on the box.

Answer 2

I had the same issue too. I realized that semaphore table is being used like a temporary table and works similar to how UNIX/LINUX runs semaphore commands.

I removed the primary and unique keys on the 'semaphore' table in the DB

1. Drupal Semaphore table is similar to a Unix kernel Semaphore working where when a process needs to lock the table/file to perform some operation on that table/file puts a lock on it by adding an entry in the semaphore table. These entries are then deleted as soon as the process is done or the data is updated on the table/file and lock is removed for the next operation (In a general sense, what is the purpose of the Drupal DB Semaphore Table)
2. Drupal 7 was initially built for MyISAM Engine running primarily so InnoDB was not even considered or even tested out (fully when released) when Drupal was upgraded to support InnoDB. This semaphore table DEADLOCK issue still exists in Drupal 8 (https://www.drupal.org/project/drupal/issues/1898204 & https://www.drupal.org/node/2077827 ) and probably won't go away (https://docs.acquia.com/article/fixing-database-deadlocks). This also happens only on a very high load on the DB server and very difficult to test or replicate as a single threaded PHP process is interacting with a multi-threaded MySQL process.
3. PHP is a single process single thread running on the OS but MySQL runs in parallel and multiple threaded so multiple processes can update and delete a table at the same time which is why a deadlock happens as multiple requests to lock and unlock at the same time can occur (https://www.drupal.org/project/drupal/issues/1898204#comment-11080601)
4. MyISAM works differently in which the entire table is locked and the data is updated before it releases the lock so a concurrent transaction cannot occur until the table is unlocked. InnoDB works differently in the sense that a record on the table is locked rather than the entire table (row-level) locking (https://dba.stackexchange.com/questions/1/what-are-the-main-differences-between-innodb-and-myisam)
5. The steps taken where as per guidelines list in this article https://groups.drupal.org/node/415883. Unfortunately I could not perform the steps to convert it to a Memory Table is not allowed for data consistency (as a MySQL Cluster) and try and avoid changing PRIMARY and UNIQUE keys for this table.

    mysql> ALTER TABLE semaphore ENGINE = MEMORY;
   ERROR 1071 (42000): Specified key was too long; max key length is 1000 bytes
   Warning (Code 1105): Percona-XtraDB-Cluster doesn't recommend changing storage engine of a table (pdc.semaphore) from transactional to non-transactional with pxc_strict_mode = PERMISSIVE
   Error (Code 1071): Specified key was too long; max key length is 1000 bytes 

   As this table is updated and deleted and no data is maintained in this table, I am not worried about this table in regards to data or its working as at any given point of time this table may or may not have data in it. It is being used as "temporary table" way similar temporary tables and deletes/create/updates in the way it works. Since consistency is not present in this table and no data is of any value, this change is not significant enough to warrant a snapshot.

Now seeing that this option has been done on the DB level, it can be reverted also. The core PHP / Drupal code has not been modified.

Revert Option:

 mysql>
ALTER TABLE `semaphore`
  ADD PRIMARY KEY (`name`, `value`) USING BTREE,
  ADD UNIQUE KEY `name` (`name`) USING BTREE,
  ADD KEY `value` (`value`) USING BTREE,
  ADD KEY `expire` (`expire`) USING BTREE;

Also I have set in the configuration for MySQL (my.cnf) as below:

#optional
wsrep_retry_autocommit = 4
wsrep_slave_threads = 16
wsrep_log_conflicts = ON

which tell the DB to RETRY at least 4 times before failing and log all conflicts rather than give up and become deadlocked and lock the Server completely.

To prove that this solution is currently working and gives a warning. I checked the error logs and noticed the below: 2017-11-27T19:06:54.407016Z 802376 [Warning] WSREP: Percona-XtraDB-Cluster doesn't recommend use of DML command on a table (pdc.semaphore) without an explicit primary key with pxc_strict_mode = PERMISSIVE in the error log here:

2017-11-27T19:01:39.746506Z 800686 [Note] WSREP: Victim thread: 
   THD: 800686, mode: local, state: executing, conflict: cert failure, seqno: 14306430
   SQL: UPDATE users SET access='1511809315'
WHERE  (uid = '24216')


*** Priority TRANSACTION:
TRANSACTION 17680573, ACTIVE 0 sec starting index read
mysql tables in use 1, locked 1
MySQL thread id 13, OS thread handle 140297469130496, query id 50384064 System lock

*** Victim TRANSACTION:
TRANSACTION 17680570, ACTIVE (PREPARED) 0 sec rollback
mysql tables in use 1, locked 1
ROLLING BACK 
MySQL thread id 800686, OS thread handle 140296930600704, query id 50384061  wsrep: initiating pre-commit for write set (14306430)
UPDATE users SET access='1511809315'
WHERE  (uid = '24216')
*** WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 2178 page no 678 n bits 112 index PRIMARY of table "users" trx id 17680570 lock_mode X locks rec but not gap
2017-11-27T19:01:39.746856Z 13 [Note] WSREP: --------- CONFLICT DETECTED --------
2017-11-27T19:01:39.746871Z 13 [Note] WSREP: cluster conflict due to high priority abort for threads:

2017-11-27T19:01:39.746884Z 13 [Note] WSREP: Winning thread: 
   THD: 13, mode: applier, state: executing, conflict: no conflict, seqno: 14306429
   SQL: (null)

2017-11-27T19:01:39.746895Z 13 [Note] WSREP: Victim thread: 
   THD: 800686, mode: local, state: executing, conflict: cert failure, seqno: -1
   SQL: UPDATE users SET access='1511809315'
WHERE  (uid = '24216')

2017-11-27T19:06:54.407016Z 802376 [Warning] WSREP: Percona-XtraDB-Cluster doesn't recommend use of DML command on a table (pdc.semaphore) without an explicit primary key with pxc_strict_mode = PERMISSIVE
2017-11-27T19:06:54.476663Z 802376 [Warning] WSREP: Percona-XtraDB-Cluster doesn't recommend use of DML command on a table (pdc.semaphore) without an explicit primary key with pxc_strict_mode = PERMISSIVE
2017-11-27T19:06:54.854750Z 802376 [Warning] WSREP: Percona-XtraDB-Cluster doesn't recommend use of DML command on a table (pdc.semaphore) without an explicit primary key with pxc_strict_mode = PERMISSIVE
2017-11-27T19:08:23.716164Z 802666 [Note] WSREP: --------- CONFLICT DETECTED --------
2017-11-27T19:08:23.716206Z 802666 [Note] WSREP: cluster conflict due to certification failure for threads:

2017-11-27T19:08:23.716220Z 802666 [Note] WSREP: Victim thread: 
   THD: 802666, mode: local, state: executing, conflict: cert failure, seqno: 14316816
   SQL: UPDATE users SET access='1511809719'
WHERE  (uid = '52770')

Notice it tried doing this 3 times before reporting a "WSREP: --------- CONFLICT DETECTED" which helps in debugging and does not bring your server/nodes down.