Cms: Getting SQLSTATE "error: 1205 Lock wait timeout" after upgrading from 3.4.30 -> 3.5.7

[JoshCoady]

Description

After updating from v3.4.30 to Craft 3.5 (this was tested in several versions of 3.5 up to 3.5.6), I ran our unit tests and noticed they were taking a lot longer and erroring out with errors like the following. We have multiple tests that we run in a random order, so the SQL being executed wasnt always the same thing, but the error message was. Also, the SQL being executed was always an insert.

[yii\db\Exception] SQLSTATE[HY000]: General error: 1205 Lock wait timeout exceeded; try restarting transaction
The SQL being executed was: INSERT INTO `craft_content` (`elementId`, `siteId`, `dateCreated`, `dateUpdated`, `uid`) VALUES (2, 2, '2020-08-29 02:28:09', '2020-08-29 02:28:09', 'd4a94f96-3973-4e3c-82ed-7758a45d57d7')  

This is not due to things like multiple mysql processes because it happens on the first run after killing all docker servers and this same situation is repeatable in GitHub's Workflow environments.

Steps to reproduce

To verify that the issue was not due to any custom code, I prepared a demo repo that has no customizations and a very simple test:

        $site = Craft::$app->getSites()->getSiteByHandle('site1');
        $section = Craft::$app->getSections()->getSectionByHandle('section1');
        $entry = new Entry();
        $entry->title = '';
        $entry->siteId = $site->id;
        $entry->sectionId = $section->id;
        $entry->typeId = $section->getEntryTypes()[0]->id;
        $entry->slug = ElementHelper::tempSlug();
        $entry->setScenario(Element::SCENARIO_ESSENTIALS);
        self::assertTrue(Craft::$app->getElements()->saveElement($entry));

Craft v3.4.30

Code: https://github.com/JoshCoady/craft35-test-demo/tree/3.4

Test run showing success: https://github.com/JoshCoady/craft35-test-demo/runs/1044113301?check_suite_focus=true (scroll to the very bottom of the "Test" step)

Craft v3.5.6

Code: https://github.com/JoshCoady/craft35-test-demo/tree/3.5 (note the only differences here are composer file changes to update the craft version to 3.5 and changes to the test project config to the new format, but the contents remain the same -- see https://github.com/JoshCoady/craft35-test-demo/commit/c8f9e1a1b7a2b27500d2459db4decc3aa64657f6 for a list of the differences)

Test run showing the error: https://github.com/JoshCoady/craft35-test-demo/runs/1044126971?check_suite_focus=true (scroll to the very bottom of the "Test" step)

Additional info

• Craft version: 3.5
• PHP version: 7.4.4
• Database driver & version: MariaDB 10.3
  PDO Driver for MySQL => enabled
  Client API version => mysqlnd 7.4.4
• Plugins & versions: none

[angrybrad]

This should be fixed in Craft 3.5.7. What version of Craft are you running?

[JoshCoady]

I didn't realize there was a newer version. The repro demo site is on 3.5.6. I'll update it and retry the test.

[angrybrad]

Cool. Updating to the latest should fix it, so going to go ahead and close this. If it's still an issue for you, just comment back here and we can re-open and investigate more.

[JoshCoady]

I thought this fixed it, but looks like it did not entirely fix.

If I change the test from
self::assertTrue(Craft::$app->getElements()->saveElement($entry));

to
self::assertTrue(Craft::$app->getDrafts()->saveElementAsDraft($entry, User::find()->admin()->one()->id));

It fails with the same error:
https://github.com/JoshCoady/craft35-test-demo/runs/1055096256?check_suite_focus=true

app_1  | 1) SmokeTest: Smoke
app_1  |  Test  tests/unit/SmokeTest.php:testSmoke
app_1  |                                                                                                                                                                                                                                                
app_1  |   [yii\db\Exception] SQLSTATE[HY000]: General error: 1205 Lock wait timeout exceeded; try restarting transaction
app_1  | The SQL being executed was: UPDATE `craft_drafts` SET `name`='First draft', `notes`=NULL, `dateLastMerged`=NULL WHERE `id`=1  
app_1  |                                                                                                                                                                                                                                                
app_1  | /var/app/vendor/yiisoft/yii2/db/Schema.php:677
app_1  | /var/app/vendor/yiisoft/yii2/db/Command.php:1298
app_1  | /var/app/vendor/yiisoft/yii2/db/Command.php:1093
app_1  | /var/app/vendor/craftcms/cms/src/helpers/Db.php:794
app_1  | /var/app/vendor/craftcms/cms/src/behaviors/DraftBehavior.php:109
app_1  | /var/app/vendor/yiisoft/yii2/base/Component.php:627
app_1  | /var/app/vendor/craftcms/cms/src/base/Element.php:3188
app_1  | /var/app/vendor/craftcms/cms/src/elements/Entry.php:1473
app_1  | /var/app/vendor/craftcms/cms/src/services/Elements.php:2372
app_1  | /var/app/vendor/craftcms/cms/src/services/Elements.php:691
app_1  | /var/app/vendor/craftcms/cms/src/services/Drafts.php:218
app_1  | /var/app/tests/unit/SmokeTest.php:25

So, the example code at https://github.com/JoshCoady/craft35-test-demo/tree/3.4 (v3.4.30) passes while the code at https://github.com/JoshCoady/craft35-test-demo/tree/3.5.7 fails. Also, the code at https://github.com/JoshCoady/craft35-test-demo/tree/6d62f8c2df87cbc3e025050632907703c9de193e (v3.5.7 before the change to test saving a draft instead of saving the element directly) passes.

This is the change that makes 3.5.7 fail:
https://github.com/JoshCoady/craft35-test-demo/commit/1a9ba5880f35b41695444b9fe9dc40211c1a3505

[angrybrad]

Hrm... it's got to be something environmental triggering it.

I cloned your 3.5 branch locally https://github.com/JoshCoady/craft35-test-demo/tree/3.5 and was able to run the test without any issues.

Not super-familiar with GH actions, but does the MySQL database they provide have limited resources assigned to it?

[JoshCoady]

It's not running in a DB they provide. The runner they provide has 2 cores and 7 GB memory. The test is being run on that with docker compose. Two servers, one php for craft and one mariadb (stock v10.3 -- not quite the latest, but matches the latest version used by AWS RDS).

You can run it in the same way on your local with the following assuming you have docker installed (this is all the github workflow is doing):

docker-compose up

It also hits the lock timeout on my local running the same way and I have docker allocated with 12 cores and 16 GB memory.

Never had this problem on my local or in github with 3.4.

[angrybrad]

@JoshCoady can you update to the latest 3.5.13 and try your test suite again? There have been several improvements around this in recent releases.

[JoshCoady]

@angrybrad I tested with 3.5.13.2 and that passed my smoke test I put up: https://github.com/JoshCoady/craft35-test-demo/runs/1283488539

I'll check again with our full test suite when I get a chance to update it - it has diverged a bit after being disabled for 8 weeks.

[angrybrad]

@JoshCoady w00t! Going to be glass-half-full and say this fixes it, but if you run into it again, comment back and I'll re-open!