I run 'drush updatedb --debug'

drush goes through this process then seem to hang on:

Calling drush_cache_clear_both() [26.02 sec, 109.96 MB] [debug]

Then eventually I get the PDOException error below.

Is there a problem with this module and clearing cache?

WD facebook_publication_type: PDOException: SQLSTATE[HY000]: General [error]
error: 1205 Lock wait timeout exceeded; try restarting transaction:
UPDATE {facebook_publication_type} SET type=:db_update_placeholder_0,
label=:db_update_placeholder_1, weight=:db_update_placeholder_2,
description=:db_update_placeholder_3, data=:db_update_placeholder_4,
status=:db_update_placeholder_5, module=:db_update_placeholder_6
WHERE (id = :db_condition_placeholder_0) ; Array
(
[:db_update_placeholder_0] => album
[:db_update_placeholder_1] => Album
[:db_update_placeholder_2] => 0
[:db_update_placeholder_3] =>
[:db_update_placeholder_4] => N;
[:db_update_placeholder_5] => 2
[:db_update_placeholder_6] => fb_autopost_types
[:db_condition_placeholder_0] => 1
)
in drupal_write_record() (line 7212 of
/var/aegir/platforms/7/servers/openatrium-7.x-2.x-dev-2/includes/common.inc).

Comments

socialnicheguru’s picture

Taking a look at my innodb log

------------
TRANSACTIONS
------------
Trx id counter 238A5AE
Purge done for trx's n:o < 23873E4 undo n:o < 0
History list length 3597
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 0, not started
MySQL thread id 338, OS thread handle 0x74affb40, query id 50060 localhost root
show engine innodb status
---TRANSACTION 2386F39, not started
MySQL thread id 147, OS thread handle 0x75293b40, query id 8576 localhost 127.0.0.1 mydb
---TRANSACTION 2389D55, ACTIVE 152 sec starting index read
mysql tables in use 1, locked 1
LOCK WAIT 2 lock struct(s), heap size 320, 1 row lock(s)
MySQL thread id 323, OS thread handle 0x717b9b40, query id 46185 localhost 127.0.0.1 mydb updating
DELETE FROM facebook_publication_type
WHERE (id IN ('1', '2', '3', '4', '5', '6', '7', '8'))
------- TRX HAS BEEN WAITING 152 SEC FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 234635 page no 3 n bits 80 index "PRIMARY" of table "mydb"."facebook_publication_type" trx id 2389D55 lock_mode X waiting
Record lock, heap no 2 PHYSICAL RECORD: n_fields 10; compact format; info bits 0
0: len 4; hex 80000001; asc ;;
1: len 6; hex 0000023873de; asc 8s ;;
2: len 7; hex 1d0000252d23a3; asc %-# ;;
3: len 5; hex 616c62756d; asc album;;
4: len 5; hex 416c62756d; asc Album;;
5: len 1; hex 80; asc ;;
6: len 0; hex ; asc ;;
7: len 2; hex 4e3b; asc N;;;
8: len 1; hex 82; asc ;;
9: len 17; hex 66625f6175746f706f73745f7479706573; asc fb_autopost_types;;

socialnicheguru’s picture

this link and the links in the issue might be helpful
https://drupal.org/node/2082859

e0ipso’s picture

@SocialNicheGuru can you please help me reproduce this issue? I cannot get it to fail. What is the db update that is running that causes the error?

e0ipso’s picture

Status: Active » Fixed

I'm closing this as fixed since it's highly improbable that the lock timeout is related to this module (since there are no locks being used here). This is probably from another process.

If you encounter this and think that is related to the Facebook Autopost module, then feel free to reopen this and provide more information.

Status: Fixed » Closed (fixed)

Automatically closed - issue fixed for 2 weeks with no activity.

socialnicheguru’s picture

Status: Closed (fixed) » Active

I get this intermittently.

Can you give me suggestions on how to debug it?

It doesn't happen all the time, but when it does it looks like this:

WD facebook_publication_type: PDOException: SQLSTATE[HY000]: General [error]
error: 1205 Lock wait timeout exceeded; try restarting transaction:
UPDATE {facebook_publication_type} SET type=:db_update_placeholder_0,
label=:db_update_placeholder_1, weight=:db_update_placeholder_2,
description=:db_update_placeholder_3, data=:db_update_placeholder_4,
status=:db_update_placeholder_5, module=:db_update_placeholder_6
WHERE (id = :db_condition_placeholder_0) ; Array
(
[:db_update_placeholder_0] => album
[:db_update_placeholder_1] => Album
[:db_update_placeholder_2] => 0
[:db_update_placeholder_3] =>
[:db_update_placeholder_4] => N;
[:db_update_placeholder_5] => 2
[:db_update_placeholder_6] => fb_autopost_types
[:db_condition_placeholder_0] => 1
)
in drupal_write_record() (line 7243 of
/var/aegir/platforms/7/servers/sng-contrib/sng-d7.27-oa-2.16/includes/common.inc).
[517.55 sec, 333.66 MB]
WD php: PDOException: SQLSTATE[HY000]: General error: 1205 Lock wait [error]
timeout exceeded; try restarting transaction: UPDATE
{facebook_publication_type} SET type=:db_update_placeholder_0,
label=:db_update_placeholder_1, weight=:db_update_placeholder_2,
description=:db_update_placeholder_3, data=:db_update_placeholder_4,
status=:db_update_placeholder_5, module=:db_update_placeholder_6
WHERE (id = :db_condition_placeholder_0) ; Array
(
[:db_update_placeholder_0] => album
[:db_update_placeholder_1] => Album
[:db_update_placeholder_2] => 0
[:db_update_placeholder_3] =>
[:db_update_placeholder_4] => N;
[:db_update_placeholder_5] => 2
[:db_update_placeholder_6] => fb_autopost_types
[:db_condition_placeholder_0] => 1
)
in drupal_write_record() (line 7243 of
/var/aegir/platforms/7/servers/sng-contrib/sng-d7.27-oa-2.16/includes/common.inc).
[520.76 sec, 353.76 MB]
Cannot modify header information - headers already sent by (output [warning]
started at /usr/share/php/drush/includes/output.inc:37)
bootstrap.inc:1231 [520.77 sec, 353.76 MB]
PDOException: SQLSTATE[HY000]: General error: 1205 Lock wait timeout exceeded; try restarting transaction: UPDATE {facebook_publication_type} SET type=:db_update_placeholder_0, label=:db_update_placeholder_1, weight=:db_update_placeholder_2, description=:db_update_placeholder_3, data=:db_update_placeholder_4, status=:db_update_placeholder_5, module=:db_update_placeholder_6
WHERE (id = :db_condition_placeholder_0) ; Array
(
[:db_update_placeholder_0] => album
[:db_update_placeholder_1] => Album
[:db_update_placeholder_2] => 0
[:db_update_placeholder_3] =>
[:db_update_placeholder_4] => N;
[:db_update_placeholder_5] => 2
[:db_update_placeholder_6] => fb_autopost_types
[:db_condition_placeholder_0] => 1
)
in drupal_write_record() (line 7243 of /var/aegir/platforms/7/servers/sng-contrib/sng-d7.27-oa-2.16/includes/common.inc).

socialnicheguru’s picture

I did the following:

drush dis -y fb_autopost_types
drush cron --debug

I got the following in cron:

WD facebook_publication_type: PDOException: SQLSTATE[HY000]: General [error]
error: 1205 Lock wait timeout exceeded; try restarting transaction:
DELETE FROM {facebook_publication_type}
WHERE (id IN (:db_condition_placeholder_0)) ; Array
(
[:db_condition_placeholder_0] => 1
)
in EntityAPIController->delete() (line 383 of
modules/all/entity/includes/entity.controller.inc).
[207.44 sec, 262.99 MB]
WD cron: PDOException: SQLSTATE[HY000]: General error: 1205 Lock wait [error]
timeout exceeded; try restarting transaction: DELETE FROM
{facebook_publication_type}
WHERE (id IN (:db_condition_placeholder_0)) ; Array
(
[:db_condition_placeholder_0] => 1
)
in EntityAPIController->delete() (line 383 of
modules/all/entity/includes/entity.controller.inc).
[207.44 sec, 262.97 MB]