Serialization failure: 1213 Deadlock found when trying to get lock; try restarting transaction

[adrianbj]

Short description of the issue

I received the following exception when updating an existing row in a Profields Table field.

ProcessWire\WireDatabaseQueryException: SQLSTATE[40001]: Serialization failure: 1213 Deadlock found when trying to get lock; try restarting transaction #40001 in /var/www/html/wire/core/FieldtypeMulti.php:253 caused by PDOException: SQLSTATE[40001]: Serialization failure: 1213 Deadlock found when trying to get lock; try restarting transaction #4000

Steps to reproduce the issue

This is the code that triggered this error, but I have been using this code for a long time and this is the first time I have seen this, Given the nature of the error, I am not really surprised though as it's probably all about timing. Anyway, I don't know how you can really reproduce this, but

$item = $recipient->received_emails->get('email_message.id=' . $email->id);
if($item) {
    $item->message_id = $data->message->headers->{'message-id'};
    $item->delivery_status = $data->event;
    $recipient->save('received_emails');
}

Here's what looks to be the relevant parts of the stack trace.

I'm not completely sure, but perhaps there is some useful info here: https://www.drupal.org/node/1369332 ? There are many other references to / solutions for this error, but it's not a one size fits all issue. Let me know if there is anything else I can provide.

Setup/Environment

Server Details

Software	Version
ProcessWire	3.0.196
PHP	8.0.17
Webserver	Apache
MySQL Server	10.3.34-MariaDB-0+deb10u1-log
MySQL Client	mysqlnd 8.0.17

Server Settings

Parameter	Value
allow_url_fopen	1
max_execution_time	180 (changeable)
max_input_nesting_level	64
max_input_time	60
max_input_vars	10000
memory_limit	1024M
post_max_size	220M
upload_max_filesize	200M
xdebug
xdebug.max_nesting_level
mod_rewrite	1
mod_security
EXIF Support	1
FreeType	1

GD Settings

Parameter	Value
Version	2.2.5
GIF	1
JPG	1
PNG	1
WebP	1

iMagick Settings

Parameter	Value
Version	6.9.10
GIF	1
JPG	1
PNG	1
SVG	1
PDF	1
WebP	1

Module Details

Module ClassName	Version
TextformatterVideoEmbedOptions	0.3.6
TextformatterVideoEmbed	2.0.2
AddUserSwitcherAction	0.0.1
AdminModalception	1.0.1
AdminOnSteroids	2.0.21
AdminPageFieldEditLinks	3.1.4
BreadcrumbDropdowns	0.3.7
CustomInputfieldDependencies	0.2.4
Dashboard	1.2.1
DashboardPanelAddNew	1.2.1
DashboardPanelChart	1.2.1
DashboardPanelCollection	1.2.1
DashboardPanelHelloWorld	0.0.1
DashboardPanelNotice	1.2.1
DashboardPanelNumber	1.2.1
DashboardPanelPageList	1.2.1
DashboardPanelShortcuts	1.2.1
DashboardPanelTemplate	1.2.1
Duplicator	1.4.21
DynamicDescriptionNotes	0.1.6
FieldtypeAdminComments	1.0.8
FieldtypeAssistedURL	1.0.0
FieldtypeColor	1.1.7
FieldtypeFields	0.0.2
FieldtypePhone	3.1.0
FieldtypeQRCode	1.0.13
FieldtypeRepeaterMatrix	0.0.5
FieldtypeRuntimeOnly	0.1.8
FieldtypeSeoMaestro	1.1.0
FieldtypeTable	0.2.2
FieldtypeVerifiedURL	0.0.5
FileValidatorSvgSanitizer	0.0.5
HannaCodeDialog	0.4.4
InputfieldAceExtended	1.1.3
InputfieldAdminComments	1.0.8
InputfieldAssistedURL	1.0.1
InputfieldColor	1.1.5
InputfieldPhone	3.1.0
InputfieldRepeaterMatrix	0.0.5
InputfieldRepeaterMatrixDuplicate	2.0.1
InputfieldSeoMaestro	1.1.0
InputfieldTable	0.2.2
Less	0.0.3
ListerNativeDateFormat	0.1.2
LoginRegister	0.0.2
MarkupSitemap	0.8.2
ModuleReleaseNotes	0.11.1
ModuleSettingsImportExport	0.2.9
PageActionEmail	0.0.2
PageActionExportCSV	0.0.6
PageActionExportPDF	0.0.1
PageActionExportText	0.0.1
PageRenameOptions	2.0.1
PageSnapshot	2.1.1
PasswordForceChange	1.0.5
PasswordGenerator	0.1.7
ProCache	4.0.1
ProcessAdminActions	0.8.10
ProcessAdminComments	1.0.7
ProcessChangelog	1.14.7
ProcessChangelogHooks	1.10.3
ProcessDatabaseBackups	0.0.6
ProcessDuplicator	1.4.21
ProcessEmails	0.0.1
ProcessGoogleAnalytics	1.2.1
ProcessHannaCode	0.3.0
ProcessJumplinks	1.5.61
ProcessLinkChecker	0.9.10
ProcessMessages	0.0.1
ProcessMigrator	0.7.7
ProcessPageFieldSelectCreator	0.5.11
ProcessPageListerPro	1.1.3
ProcessProCache	4.0.1
ProcessProfilerPro	0.0.2
ProcessSettingsFactory	1.0.7
ProcessTemplateParents	0.0.7
ProcessTracyAdminer	1.1.3
ProcessUserActivity	0.0.4
ProcessVersionControl	2.4.3
ProcessWireUpgrade	0.1.1
ProcessWireUpgradeCheck	0.0.9
ProfilerPro	0.0.3
ProtectedMode	1.1.0
RockPdf	2.0.6
SeoMaestro	1.1.0
SettingsFactory	1.0.7
TemplateParents	0.0.7
TextformatterHannaCode	0.3.0
TfaTotp	0.0.4
TracyDebugger	4.23.26
UserActivity	0.0.4
VersionControl	2.4.6
VersionControlCleanup	1.0.2
WireMailgun	1.2.1

[adrianbj]

Just wanted to note that I saw this again recently, so there is definitely something going on, but it's hard to reproduce.

[jlahijani]

I came here to say I'm experiencing the exact same issue from time to time. Will look into it.

[jlahijani]

I have a live site where this error was occurring. My suspicion was that it would occur if the site was getting hammered with traffic or spiked in some kind of way.

Two weeks ago after my last comment, I made a local copy of it running a similar LAMP stack. I made a php script that simply creates 1000 pages that utilize FieldtypeTable and I ran that script at the same time in 3 separate terminals. I was able to reliably and quickly replicate the error.

I then tried some things to see if I could replicate it in the same way in a clean ProcessWire installation, but I wasn't able to dedicate much time to it and while I can't state this for a fact, it seemed to not be occurring.

Today, for reasons not related to this issue, I decided to upgrade my dev server from MySQL to MariaDB in Ubuntu 22.04. To do this, I had to dump all my databases from MySQL (skipping the various system tables), uninstall it, install MariaDB and then import the dump. Before I could import the mass dump, I had run this on the dump file because in a default installation, utf8mb4_0900_ai_ci won't work in MariaDB:

sed -i 's/utf8mb4_0900_ai_ci/utf8mb4_unicode_ci/g' all-dbs.sql

I then imported my dump and made sure everything worked. My motivation to switching to MariaDB was due to importing database dumps being a lot faster (I often sync my live sites to dev). I wasn't sure why this was the case originally, but afterwards I learned it's because binary logs in MariaDB are disabled by default, while they are enabled by default in MySQL (at least that's the default settings when installing it with apt in Ubuntu).

I then turned my sights on to this issue again and conducted the same test and it seems to no longer occur.

[jlahijani]

@adrianbj It might be worth a try disabling binary logs in MySQL to see if that resolves this issue.

[jlahijani]

@adrianbj I enabled binary logs in MariaDB but no issues there either.

[jlahijani]

OK another update. Despite switching to a new production server with Ubuntu 24.04 and MariaDB (and with binary logs disabled by default), this issue is still occurring. On my dev server which also now has MariaDB I wasn't able to replicate the issue like I was able to originally. Will need to dive deeper into this again.

[jlahijani]

I don't know if this related, but when I view MariaDB logs on my new production server for the site that's experiencing this deadlock issue, I see this:

root@host:/var/log# journalctl -u mariadb -f
...
May 04 18:38:50 pwe mariadbd[6098]: 2024-05-04 18:38:50 0 [Warning] InnoDB: Total InnoDB FTS size 11429196 for the table `pwe`.`field_title` exceeds the innodb_ft_cache_size 8000000
May 04 18:38:52 pwe mariadbd[6098]: 2024-05-04 18:38:52 0 [Warning] InnoDB: Total InnoDB FTS size 11452141 for the table `pwe`.`forms_entries` exceeds the innodb_ft_cache_size 8000000

Googling lead me to this GitHub post:
mattermost/mattermost#20882

Based on a commenter, I see that my innodb_ft_cache_size is:

MariaDB [(none)]> show variables like "innodb_ft_cache_size";
+----------------------+---------+
| Variable_name        | Value   |
+----------------------+---------+
| innodb_ft_cache_size | 8000000 |
+----------------------+---------+
1 row in set (0.001 sec)

I increased it by adding this line to /etc/mysql/mariadb.conf.d/50-server.cnf:

innodb_ft_cache_size = 16000000

I then restarted MariaDB and verified the new value is now active.

I didn't run this yet however:

alter table field_title Engine=InnoDB;
alter table field_entries Engine=InnoDB;

I've cleared my error and exceptions log file in ProcessWire. Will report back in a day or two to see if the deadlock issue is still occurring (happens about 1-2 times a day, which is less than before).

[netcarver]

@jlahijani Hello Jonathan. Is there any correlation between the code which is triggering the deadlock exception (might need to go back in the stack trace), and the two fields with incomplete FTS size you mentioned in your post above? (field_title and forms_entries)?

[netcarver]

This post on Stack Overflow may help with your info-gathering, @jlahijani

[jlahijani]

OK... I came across this issue again and I've resolved it.

First, this has nothing to do with using a FieldtypeTable. It has everything to do with MySQL/MariaDB just being completely inundated and not being able to keep up. I'm not sure if that falls within the hands of how ProcessWire is doing queries or MySQL/MariaDB itself.

I was able to trigger this issue reliably with a site that I'm working on and went to work figuring out a fix.

I first went with the approach of trying to modify a bunch MySQL/MariaDB settings but didn't have any luck there.

Then ChatGPT recommended as a final resort to simply catch the exception (which ProcessWire already does), but retrying the transaction instead of throwing exception, which seems to work around and effectively resolve this issue.

In ProcessWire 3.0.247 /wire/core/FieldtypeMulti.php we have this bit of code:

try {
  $result = $query->execute();
} catch(\Exception $e) {
  $exception = $e;
}

We can replace that with this:

$maxRetries = 5;  // Number of times to retry
$attempt = 0;

while ($attempt < $maxRetries) {
  try {
    $result = $query->execute();
    $exception = false;  // If successful, clear exception
    break;  // Exit the loop if successful
  } catch (\Exception $e) {
    if ($e->getCode() == 40001) {  // Deadlock error
      $attempt++;
      usleep(100000 * $attempt);  // Exponential backoff (100ms, 200ms, 300ms, etc.)
    } else {
      $exception = $e;  // Store non-deadlock exceptions
      break;  // Exit loop for other exceptions
    }
  }
}

@ryancramerdesign What do you think about that? It may be hard for you to replicate the issue, but even if you can't, would you consider retrying 40001 errors?

[adrianbj]

@jlahijani and @ryancramerdesign - there is also this related issue #2038 with another mysql error that needs retrying. I think this is desperately in need of being made more robust.