Early Bird Registration for DrupalCon Portland 2024 is open! Register by 23:59 PST on 31 March 2024, to get $100 off your ticket.
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
Comment #1
catchMarking duplicate of #937284: DEADLOCK errors on MergeQuery INSERT due to InnoDB gap locking when condition in SELECT ... FOR UPDATE results in 0 rows.
Comment #2
Damien Tournoud CreditAttribution: Damien Tournoud commented3 out of 4 here are *not* merge queries.
Comment #3
BerdirYes, 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.
Comment #4
yched CreditAttribution: yched commentedHit another one on an INSERT (on state/keyValue too):
http://qa.drupal.org/pifr/test/406773
Comment #5
BerdirMost 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?
Comment #6
Fabianx CreditAttribution: Fabianx commenteda) 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 :).
Comment #7
catchI 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.
Comment #8
catchSo.. 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.