Last days I constantly see deadlock issues on the testbot. I'm not sure if it's a testbot or drupal issue or what status this issue should be. Copy of the logs:

Fetch tests 66 passes, 0 fails, and 0 exceptions
exception 'PDOException' with message 'SQLSTATE[40001]: Serialization failure: 1213 Deadlock found when trying to get lock; try restarting transaction' in /var/lib/drupaltestbot/sites/default/files/checkout/core/lib/Drupal/Core/Database/Statement.php:58
Stack trace:
#0 /var/lib/drupaltestbot/sites/default/files/checkout/core/lib/Drupal/Core/Database/Statement.php(58): PDOStatement->execute(Array)
#1 /var/lib/drupaltestbot/sites/default/files/checkout/core/lib/Drupal/Core/Database/Connection.php(523): Drupal\Core\Database\Statement->execute(Array, Array)
#2 /var/lib/drupaltestbot/sites/default/files/checkout/core/lib/Drupal/Core/Database/Driver/mysql/Insert.php(34): Drupal\Core\Database\Connection->query('INSERT INTO {se...', Array, Array)
#3 /var/lib/drupaltestbot/sites/default/files/checkout/core/lib/Drupal/Core/Lock/DatabaseLockBackend.php(50): Drupal\Core\Database\Driver\mysql\Insert->execute()
#4 /var/lib/drupaltestbot/sites/default/files/checkout/core/includes/bootstrap.inc(975): Drupal\Core\Lock\DatabaseLockBackend->acquire('variable_init', 1)
#5 /var/lib/drupaltestbot/sites/default/files/checkout/core/modules/simpletest/lib/Drupal/simpletest/WebTestBase.php(810): variable_initialize()
#6 /var/lib/drupaltestbot/sites/default/files/checkout/core/modules/simpletest/lib/Drupal/simpletest/WebTestBase.php(838): Drupal\simpletest\WebTestBase->refreshVariables()
#7 /var/lib/drupaltestbot/sites/default/files/checkout/core/modules/simpletest/lib/Drupal/simpletest/TestBase.php(705): Drupal\simpletest\WebTestBase->tearDown()
#8 /var/lib/drupaltestbot/sites/default/files/checkout/core/scripts/run-tests.sh(381): Drupal\simpletest\TestBase->run()
#9 /var/lib/drupaltestbot/sites/default/files/checkout/core/scripts/run-tests.sh(22): simpletest_script_run_one_test('141', 'Drupal\system\T...')
#10 {main}

Next exception 'Drupal\Core\Database\DatabaseExceptionWrapper' with message 'SQLSTATE[40001]: Serialization failure: 1213 Deadlock found when trying to get lock; try restarting transaction: INSERT INTO {semaphore} (name, value, expire) VALUES (:db_insert_placeholder_0, :db_insert_placeholder_1, :db_insert_placeholder_2); Array
(
    [:db_insert_placeholder_0] => variable_init
    [:db_insert_placeholder_1] => 33568428750c45a33003979.10797645
    [:db_insert_placeholder_2] => 1355045428.0008
)
' in /var/lib/drupaltestbot/sites/default/files/checkout/core/lib/Drupal/Core/Database/Connection.php:554
Stack trace:
#0 /var/lib/drupaltestbot/sites/default/files/checkout/core/lib/Drupal/Core/Database/Driver/mysql/Insert.php(34): Drupal\Core\Database\Connection->query('INSERT INTO {se...', Array, Array)
#1 /var/lib/drupaltestbot/sites/default/files/checkout/core/lib/Drupal/Core/Lock/DatabaseLockBackend.php(50): Drupal\Core\Database\Driver\mysql\Insert->execute()
#2 /var/lib/drupaltestbot/sites/default/files/checkout/core/includes/bootstrap.inc(975): Drupal\Core\Lock\DatabaseLockBackend->acquire('variable_init', 1)
#3 /var/lib/drupaltestbot/sites/default/files/checkout/core/modules/simpletest/lib/Drupal/simpletest/WebTestBase.php(810): variable_initialize()
#4 /var/lib/drupaltestbot/sites/default/files/checkout/core/modules/simpletest/lib/Drupal/simpletest/WebTestBase.php(838): Drupal\simpletest\WebTestBase->refreshVariables()
#5 /var/lib/drupaltestbot/sites/default/files/checkout/core/modules/simpletest/lib/Drupal/simpletest/TestBase.php(705): Drupal\simpletest\WebTestBase->tearDown()
#6 /var/lib/drupaltestbot/sites/default/files/checkout/core/scripts/run-tests.sh(381): Drupal\simpletest\TestBase->run()
#7 /var/lib/drupaltestbot/sites/default/files/checkout/core/scripts/run-tests.sh(22): simpletest_script_run_one_test('141', 'Drupal\system\T...')
#8 {main}FATAL Drupal\system\Tests\Database\RegressionTest: test runner returned a non-zero error code (1).

exception 'PDOException' with message 'SQLSTATE[40001]: Serialization failure: 1213 Deadlock found when trying to get lock; try restarting transaction' in /var/lib/drupaltestbot/sites/default/files/checkout/core/lib/Drupal/Core/Database/Statement.php:58
Stack trace:
#0 /var/lib/drupaltestbot/sites/default/files/checkout/core/lib/Drupal/Core/Database/Statement.php(58): PDOStatement->execute(Array)
#1 /var/lib/drupaltestbot/sites/default/files/checkout/core/lib/Drupal/Core/Database/Connection.php(523): Drupal\Core\Database\Statement->execute(Array, Array)
#2 /var/lib/drupaltestbot/sites/default/files/checkout/core/lib/Drupal/Core/Database/Driver/mysql/Insert.php(34): Drupal\Core\Database\Connection->query('INSERT INTO {ke...', Array, Array)
#3 /var/lib/drupaltestbot/sites/default/files/checkout/core/lib/Drupal/Core/Database/Query/Merge.php(424): Drupal\Core\Database\Driver\mysql\Insert->execute()
#4 /var/lib/drupaltestbot/sites/default/files/checkout/core/lib/Drupal/Core/KeyValueStore/DatabaseStorage.php(95): Drupal\Core\Database\Query\Merge->execute()
#5 /var/lib/drupaltestbot/sites/default/files/checkout/core/modules/system/system.module(3012): Drupal\Core\KeyValueStore\DatabaseStorage->set('system.theme.da...', Array)
#6 /var/lib/drupaltestbot/sites/default/files/checkout/core/includes/module.inc(211): system_rebuild_theme_data()
#7 /var/lib/drupaltestbot/sites/default/files/checkout/core/includes/module.inc(105): system_list('module_enabled')
#8 /var/lib/drupaltestbot/sites/default/files/checkout/core/includes/module.inc(917): module_list()
#9 /var/lib/drupaltestbot/sites/default/files/checkout/core/includes/module.inc(828): module_hook_info()
#10 /var/lib/drupaltestbot/sites/default/files/checkout/core/includes/module.inc(998): module_implements('stream_wrappers')
#11 /var/lib/drupaltestbot/sites/default/files/checkout/core/includes/file.inc(195): module_invoke_all('stream_wrappers')
#12 /var/lib/drupaltestbot/sites/default/files/checkout/core/includes/file.inc(251): file_get_stream_wrappers()
#13 /var/lib/drupaltestbot/sites/default/files/checkout/core/includes/file.inc(288): file_stream_wrapper_get_class(false)
#14 /var/lib/drupaltestbot/sites/default/files/checkout/core/includes/file.inc(503): file_stream_wrapper_valid_scheme(false)
#15 /var/lib/drupaltestbot/sites/default/files/checkout/core/modules/simpletest/lib/Drupal/simpletest/TestBase.php(853): file_prepare_directory('sites/default/f...', 3)
#16 /var/lib/drupaltestbot/sites/default/files/checkout/core/modules/simpletest/lib/Drupal/simpletest/WebTestBase.php(649): Drupal\simpletest\TestBase->prepareEnvironment()
#17 /var/lib/drupaltestbot/sites/default/files/checkout/core/modules/shortcut/lib/Drupal/shortcut/Tests/ShortcutTestBase.php(46): Drupal\simpletest\WebTestBase->setUp()
#18 /var/lib/drupaltestbot/sites/default/files/checkout/core/modules/simpletest/lib/Drupal/simpletest/TestBase.php(696): Drupal\shortcut\Tests\ShortcutTestBase->setUp()
#19 /var/lib/drupaltestbot/sites/default/files/checkout/core/scripts/run-tests.sh(381): Drupal\simpletest\TestBase->run()
#20 /var/lib/drupaltestbot/sites/default/files/checkout/core/scripts/run-tests.sh(22): simpletest_script_run_one_test('466', 'Drupal\shortcut...')
#21 {main}
Next exception 'Drupal\Core\Database\DatabaseExceptionWrapper' with message 'SQLSTATE[40001]: Serialization failure: 1213 Deadlock found when trying to get lock; try restarting transaction: INSERT INTO {key_value} (name, collection, value) VALUES (:db_insert_placeholder_0, :db_insert_placeholder_1, :db_insert_placeholder_2); Array
(
    [:db_insert_placeholder_0] => system.theme.data
    [:db_insert_placeholder_1] => state
    [:db_insert_placeholder_2] => a:3:{s:6:"bartik";O:8:"stdClass":8:{s:3:"uri";s:30:"core/themes/bartik/bartik.info";s:8:"filename";s:30:"core/themes/bartik/bartik.info";s:4:"name";s:6:"bartik";s:4:"info";a:17:{s:4:"name";s:6:"Bartik";s:11:"description";s:86:"A flexible, recolorable theme with many regions and a responsive, mobile-first layout.";s:7:"package";s:4:"Core";s:7:"version";s:7:"8.0-dev";s:4:"core";s:3:"8.x";s:11:"stylesheets";a:2:{s:3:"all";a:3:{s:14:"css/layout.css";s:33:"core/themes/bartik/css/layout.css";s:13:"css/style.css";s:32:"core/themes/bartik/css/style.css";s:14:"css/colors.css";s:33:"core/themes/bartik/css/colors.css";}s:5:"print";a:1:{s:13:"css/print.css";s:32:"core/themes/bartik/css/print.css";}}s:7:"regions";a:17:{s:6:"header";s:6:"Header";s:4:"help";s:4:"Help";s:8:"page_top";s:8:"Page top";s:11:"page_bottom";s:11:"Page bottom";s:11:"highlighted";s:11:"Highlighted";s:8:"featured";s:8:"Featured";s:7:"content";s:7:"Content";s:13:"sidebar_first";s:13:"Sidebar first";s:14:"sidebar_second";s:14:"Sidebar second";s:14:"triptych_first";s:14:"Triptych first";s:15:"triptych_middle";s:15:"Triptych middle";s:13:"triptych_last";s:13:"Triptych last";s:18:"footer_firstcolumn";s:19:"Footer first column";s:19:"footer_secondcolumn";s:20:"Footer second column";s:18:"footer_thirdcolumn";s:19:"Footer third column";s:19:"footer_fourthcolumn";s:20:"Footer fourth column";s:6:"footer";s:6:"Footer";}s:8:"settings";a:1:{s:20:"shortcut_module_link";s:1:"0";}s:6:"engine";s:11:"phptemplate";s:8:"features";a:9:{i:0;s:4:"logo";i:1;s:7:"favicon";i:2;s:4:"name";i:3;s:6:"slogan";i:4;s:17:"node_user_picture";i:5;s:20:"comment_user_picture";i:6;s:25:"comment_user_verification";i:7;s:9:"main_menu";i:8;s:14:"secondary_menu";}s:10:"screenshot";s:33:"core/themes/bartik/screenshot.png";s:3:"php";s:5:"5.3.5";s:7:"scripts";a:0:{}s:5:"mtime";i:1355045045;s:15:"overlay_regions";a:2:{i:0;s:7:"content";i:1;s:4:"help";}s:14:"regions_hidden";a:2:{i:0;s:8:"page_top";i:1;s:11:"page_bottom";}s:28:"overlay_supplemental_regions";a:1:{i:0;s:8:"page_top";}}s:5:"owner";s:50:"core/themes/engines/phptemplate/phptemplate.engine";s:6:"prefix";s:11:"phptemplate";s:8:"template";b:1;s:6:"status";i:1;}s:5:"seven";O:8:"stdClass":8:{s:3:"uri";s:28:"core/themes/seven/seven.info";s:8:"filename";s:28:"core/themes/seven/seven.info";s:4:"name";s:5:"seven";s:4:"info";a:17:{s:4:"name";s:5:"Seven";s:11:"description";s:65:"A simple one-column, tableless, fluid width administration theme.";s:7:"package";s:4:"Core";s:7:"version";s:7:"8.0-dev";s:4:"core";s:3:"8.x";s:11:"stylesheets";a:1:{s:6:"screen";a:1:{s:9:"style.css";s:27:"core/themes/seven/style.css";}}s:8:"settings";a:1:{s:20:"shortcut_module_link";s:1:"1";}s:7:"regions";a:5:{s:7:"content";s:7:"Content";s:4:"help";s:4:"Help";s:8:"page_top";s:8:"Page top";s:11:"page_bottom";s:11:"Page bottom";s:13:"sidebar_first";s:13:"First sidebar";}s:14:"regions_hidden";a:3:{i:0;s:13:"sidebar_first";i:1;s:8:"page_top";i:2;s:11:"page_bottom";}s:6:"engine";s:11:"phptemplate";s:8:"features";a:9:{i:0;s:4:"logo";i:1;s:7:"favicon";i:2;s:4:"name";i:3;s:6:"slogan";i:4;s:17:"node_user_picture";i:5;s:20:"comment_user_picture";i:6;s:25:"comment_user_verification";i:7;s:9:"main_menu";i:8;s:14:"secondary_menu";}s:10:"screenshot";s:32:"core/themes/seven/screenshot.png";s:3:"php";s:5:"5.3.5";s:7:"scripts";a:0:{}s:5:"mtime";i:1355045045;s:15:"overlay_regions";a:2:{i:0;s:7:"content";i:1;s:4:"help";}s:28:"overlay_supplemental_regions";a:1:{i:0;s:8:"page_top";}}s:5:"owner";s:50:"core/themes/engines/phptemplate/phptemplate.engine";s:6:"prefix";s:11:"phptemplate";s:8:"template";b:1;s:6:"status";i:1;}s:5:"stark";O:8:"stdClass":8:{s:3:"uri";s:28:"core/themes/stark/stark.info";s:8:"filename";s:28:"core/themes/stark/stark.info";s:4:"name";s:5:"stark";s:4:"info";a:16:{s:4:"name";s:5:"Stark";s:11:"description";s:208:"This theme demonstrates Drupal's default HTML markup and CSS styles. To learn how to build your own theme and override Drupal's default code, see the Theming Guide.";s:7:"package";s:4:"Core";s:7:"version";s:7:"8.0-dev";s:4:"core";s:3:"8.x";s:11:"stylesheets";a:1:{s:3:"all";a:1:{s:14:"css/layout.css";s:32:"core/themes/stark/css/layout.css";}}s:6:"engine";s:11:"phptemplate";s:7:"regions";a:9:{s:13:"sidebar_first";s:12:"Left sidebar";s:14:"sidebar_second";s:13:"Right sidebar";s:7:"content";s:7:"Content";s:6:"header";s:6:"Header";s:6:"footer";s:6:"Footer";s:11:"highlighted";s:11:"Highlighted";s:4:"help";s:4:"Help";s:8:"page_top";s:8:"Page top";s:11:"page_bottom";s:11:"Page bottom";}s:8:"features";a:9:{i:0;s:4:"logo";i:1;s:7:"favicon";i:2;s:4:"name";i:3;s:6:"slogan";i:4;s:17:"node_user_picture";i:5;s:20:"comment_user_picture";i:6;s:25:"comment_user_verification";i:7;s:9:"main_menu";i:8;s:14:"secondary_menu";}s:10:"screenshot";s:32:"core/themes/stark/screenshot.png";s:3:"php";s:5:"5.3.5";s:7:"scripts";a:0:{}s:5:"mtime";i:1355045045;s:15:"overlay_regions";a:2:{i:0;s:7:"content";i:1;s:4:"help";}s:14:"regions_hidden";a:2:{i:0;s:8:"page_top";i:1;s:11:"page_bottom";}s:28:"overlay_supplemental_regions";a:1:{i:0;s:8:"page_top";}}s:5:"owner";s:50:"core/themes/engines/phptemplate/phptemplate.engine";s:6:"prefix";s:11:"phptemplate";s:8:"template";b:1;s:6:"status";i:0;}}
)
' in /var/lib/drupaltestbot/sites/default/files/checkout/core/lib/Drupal/Core/Database/Connection.php:554
Stack trace:
#0 /var/lib/drupaltestbot/sites/default/files/checkout/core/lib/Drupal/Core/Database/Driver/mysql/Insert.php(34): Drupal\Core\Database\Connection->query('INSERT INTO {ke...', Array, Array)
#1 /var/lib/drupaltestbot/sites/default/files/checkout/core/lib/Drupal/Core/Database/Query/Merge.php(424): Drupal\Core\Database\Driver\mysql\Insert->execute()
#2 /var/lib/drupaltestbot/sites/default/files/checkout/core/lib/Drupal/Core/KeyValueStore/DatabaseStorage.php(95): Drupal\Core\Database\Query\Merge->execute()
#3 /var/lib/drupaltestbot/sites/default/files/checkout/core/modules/system/system.module(3012): Drupal\Core\KeyValueStore\DatabaseStorage->set('system.theme.da...', Array)
#4 /var/lib/drupaltestbot/sites/default/files/checkout/core/includes/module.inc(211): system_rebuild_theme_data()
#5 /var/lib/drupaltestbot/sites/default/files/checkout/core/includes/module.inc(105): system_list('module_enabled')
#6 /var/lib/drupaltestbot/sites/default/files/checkout/core/includes/module.inc(917): module_list()
#7 /var/lib/drupaltestbot/sites/default/files/checkout/core/includes/module.inc(828): module_hook_info()
#8 /var/lib/drupaltestbot/sites/default/files/checkout/core/includes/module.inc(998): module_implements('stream_wrappers')
#9 /var/lib/drupaltestbot/sites/default/files/checkout/core/includes/file.inc(195): module_invoke_all('stream_wrappers')
#10 /var/lib/drupaltestbot/sites/default/files/checkout/core/includes/file.inc(251): file_get_stream_wrappers()
#11 /var/lib/drupaltestbot/sites/default/files/checkout/core/includes/file.inc(288): file_stream_wrapper_get_class(false)
#12 /var/lib/drupaltestbot/sites/default/files/checkout/core/includes/file.inc(503): file_stream_wrapper_valid_scheme(false)
#13 /var/lib/drupaltestbot/sites/default/files/checkout/core/modules/simpletest/lib/Drupal/simpletest/TestBase.php(853): file_prepare_directory('sites/default/f...', 3)
#14 /var/lib/drupaltestbot/sites/default/files/checkout/core/modules/simpletest/lib/Drupal/simpletest/WebTestBase.php(649): Drupal\simpletest\TestBase->prepareEnvironment()
#15 /var/lib/drupaltestbot/sites/default/files/checkout/core/modules/shortcut/lib/Drupal/shortcut/Tests/ShortcutTestBase.php(46): Drupal\simpletest\WebTestBase->setUp()
#16 /var/lib/drupaltestbot/sites/default/files/checkout/core/modules/simpletest/lib/Drupal/simpletest/TestBase.php(696): Drupal\shortcut\Tests\ShortcutTestBase->setUp()
#17 /var/lib/drupaltestbot/sites/default/files/checkout/core/scripts/run-tests.sh(381): Drupal\simpletest\TestBase->run()
#18 /var/lib/drupaltestbot/sites/default/files/checkout/core/scripts/run-tests.sh(22): simpletest_script_run_one_test('466', 'Drupal\shortcut...')
#19 {main}FATAL Drupal\shortcut\Tests\ShortcutLinksTest: test runner returned a non-zero error code (1).

Comments

catch’s picture

Damien Tournoud’s picture

Status: Closed (duplicate) » Active

3 out of 4 here are *not* merge queries.

Berdir’s picture

Yes, I've seen these relatively frequentely recently. I guess #1862914: Random test failures could be a duplicate of this.

Just like those examples, I've mostly seen things for lock/keyvalue.

yched’s picture

Hit another one on an INSERT (on state/keyValue too):
http://qa.drupal.org/pifr/test/406773

Berdir’s picture

Most of these happen on merge queries, specifically keyvalue ones, even the same key I think (theme data stuff). All that I've seen so far happen in tearDown(), when restoring the original environment. Many tearDown()'s are possibly running at the same time, each restoring the original environment and doing cache clears/rebuilds at the same time.

I guess we're not as good at supporting that as we were with the system table. Any ideas on what we could do to fix this? Will the themes need an installation status issue help? Do we need a lock on the cache clear? Can we change it to somehow only change local/static caches and not trigger things like theme rebuilding as we seem to be doing currently?

Fabianx’s picture

a) I think those queries happening on INSERT are just the counter-part to another merge query.
b) Maybe we can remove the MERGE part as in http://drupal.org/node/937284#comment-6838176 and then re-run the tests?

However a lock() on the cache clear all sounds fine :).

catch’s picture

I agree with Fabianx on (a), was thinking the same thing that it's just the other side of the deadlock.

If we add a lock here then surely we'll end up adding one around every merge query eventually?

It's only frequency that's happening to trigger this one, but the bug exists on real sites especially with node updates as well.

catch’s picture

Status: Active » Closed (duplicate)

So.. back to duplicate of #937284: DEADLOCK errors on MergeQuery INSERT due to InnoDB gap locking when condition in SELECT ... FOR UPDATE results in 0 rows. If by some chance that turns out not to fix this, we can re-open this one.