Core:archive has "Serialization failure: 1213 Deadlock" when running with more than --concurrent-archivers 1

Thomas_Oliver_Moll · July 1, 2024, 9:58am

Hi,
I’m not sure if this is a bug or a performance issue so here are our specs:

Matomo installation

over a 1000 sites (most of them tiny)
DB size ~42GB.
Matomo in Docker containers (one for PHP-FPM one for the webserver)
MariaDB 10.6 on same machine connected via local socket

Our Machine:

8 CPU cores (VMWare Guest)
20GB RAM. (16GB RAM was a bit tight with Matomo 4.x, so we gave 5.1 20GB)

Since migrating to the new machine and upgrading to Matomo 5.0 (later 5.1) we get the error message below several times a day. Our cron job runs every 15 minutes, but is usually restricted to --concurrent-archivers 8. In the past we had no problems but now we get these deadlocks even with a maximum of 2 concurrent archivers.

ERROR     [2024-07-01 02:38:55] 1418677  Uncaught exception: /var/www/html/libs/Zend/Db/Statement/Pdo.php(236): SQLSTATE[40001]: Serialization failure: 1213 Deadlock found when trying to get lock; try restarting transaction [Query: , CLI mode: 1]
 
In Pdo.php line 236:
                                                                               
  SQLSTATE[40001]: Serialization failure: 1213 Deadlock found when trying to   
  get lock; try restarting transaction                                         
                                                                               
 
In Pdo.php line 233:
                                                                               
  SQLSTATE[40001]: Serialization failure: 1213 Deadlock found when trying to   
  get lock; try restarting transaction                                         
                                                                               
 
core:archive [--url URL] [--skip-idsites [SKIP-IDSITES]] [--skip-all-segments] [--force-idsites [FORCE-IDSITES]] [--skip-segments-today] [--force-periods [FORCE-PERIODS]] [--force-date-last-n [FORCE-DATE-LAST-N]] [--force-date-range [FORCE-DATE-RANGE]] [--force-idsegments FORCE-IDSEGMENTS] [--concurrent-requests-per-website [CONCURRENT-REQUESTS-PER-WEBSITE]] [--concurrent-archivers [CONCURRENT-ARCHIVERS]] [--max-websites-to-process MAX-WEBSITES-TO-PROCESS] [--max-archives-to-process MAX-ARCHIVES-TO-PROCESS] [--disable-scheduled-tasks] [--accept-invalid-ssl-certificate] [--php-cli-options [PHP-CLI-OPTIONS]] [--force-all-websites] [--force-report [FORCE-REPORT]]

We migrated the VM to faster hardware. We migrated the database to SSD-based storrage. We upped the Caching of MariaDB… but now we are running out of ideas, what else we could try.
One single archiver seems to be not fast enough to keep up with the incoming data, so we relied on the cron starting additional jobs utilizing more CPU cores when they were needed.

Any Ideas what goes wrong?

Best
TOM

heurteph-ei · July 2, 2024, 7:28am

Hi @Thomas_Oliver_Moll
I think this is related to:

github.com/matomo-org/matomo

[Bug] Serialization failure: 1213 Deadlock found when marking archives as invalid

opened 08:54PM - 02 Jan 24 UTC

tsteur

Regression Potential Bug

### What happened? Since Matomo 5 we're seeing 3-6 times per day below fatal er…rors. We're currently on 5.0.0-rc9. This did not happen in Matomo 4 or only very rarely. There must have been some change. ## Stack trace 1 > > Error: {"message":"SQLSTATE[40001]: Serialization failure: 1213 Deadlock found when trying to get lock; try restarting transaction","file":"\/libs\/Zend\/Db\/Statement\/Pdo.php","line":236,"backtrace":" on \/libs\/Zend\/Db\/Statement\/Pdo.php(236)\n#0 \/libs\/Zend\/Db\/Statement.php(300): Zend_Db_Statement_Pdo->_execute(Array)\n#1 \/libs\/Zend\/Db\/Adapter\/Abstract.php(479): Zend_Db_Statement->execute(Array)\n#2 \/libs\/Zend\/Db\/Adapter\/Pdo\/Abstract.php(238): Zend_Db_Adapter_Abstract->query('UPDATE archive_...', Array)\n#3 \/core\/Db\/Adapter\/Pdo\/Mysql.php(332): Zend_Db_Adapter_Pdo_Abstract->query('UPDATE archive_...', Array)\n#4 \/core\/Db.php(281): Piwik\\Db\\Adapter\\Pdo\\Mysql->query('UPDATE archive_...', Array)\n#5 \/core\/DataAccess\/Model.php(340): Piwik\\Db::query('UPDATE archive_...', Array)\n#6 \/core\/Archive\/ArchiveInvalidator.php(701): Piwik\\DataAccess\\Model->updateRangeArchiveAsInvalidated('archive_numeric...', Array, Array, Object(Piwik\\Segment))\n#7 \/core\/Archive\/ArchiveInvalidator.php(328): Piwik\\Archive\\ArchiveInvalidator->markArchivesInvalidated(Array, Array, Object(Piwik\\Segment), true, false, NULL)\n#8 \/plugins\/CoreAdminHome\/API.php(175): Piwik\\Archive\\ArchiveInvalidator->markArchivesAsInvalidated(Array, Array, 'day', Object(Piwik\\Segment), false, false)\n#9 \/core\/CronArchive.php(982): Piwik\\Plugins\\CoreAdminHome\\API->invalidateArchivedReports(Array, Array, 'day', Object(Piwik\\Segment), false, false)\n#10 \/core\/CronArchive.php(908): Piwik\\CronArchive->invalidateWithSegments(Array, '2023-12-31', 'day', false, false)\n#11 \/core\/CronArchive.php(858): Piwik\\CronArchive->invalidateRecentDate('today', '12')\n#12 \/core\/CronArchive.php(812): Piwik\\CronArchive->invalidateArchivedReportsForSitesThatNeedToBeArchivedAgainImpl('12')\n#13 \/core\/Tracker\/Cache.php(296): Piwik\\CronArchive->Piwik\\{closure}()\n#14 \/core\/CronArchive.php(813): Piwik\\Tracker\\Cache::withDelegatedCacheClears(Object(Closure))\n#15 \/core\/CronArchive\/QueueConsumer.php(178): Piwik\\CronArchive->invalidateArchivedReportsForSitesThatNeedToBeArchivedAgain('12')\n#16 \/core\/CronArchive.php(390): Piwik\\CronArchive\\QueueConsumer->getNextArchivesToProcess()\n#17 \/core\/CronArchive.php(276): Piwik\\CronArchive->run()\n#18 \/core\/Access.php(661): Piwik\\CronArchive->Piwik\\{closure}()\n#19 \/core\/CronArchive.php(282): Piwik\\Access::doAsSuperUser(Object(Closure))\n#20 \/plugins\/CoreConsole\/Commands\/CoreArchiver.php(32): Piwik\\CronArchive->main()\n#21 \/core\/Plugin\/ConsoleCommand.php(110): Piwik\\Plugins\\CoreConsole\\Commands\\CoreArchiver->doExecute()\n#22 \/vendor\/symfony\/console\/Command\/Command.php(298): Piwik\\Plugin\\ConsoleCommand->execute(Object(Symfony\\Component\\Console\\Input\\ArgvInput), Object(Symfony\\Component\\Console\\Output\\ConsoleOutput))\n#23 \/core\/Plugin\/ConsoleCommand.php(125): Symfony\\Component\\Console\\Command\\Command->run(Object(Symfony\\Component\\Console\\Input\\ArgvInput), Object(Symfony\\Component\\Console\\Output\\ConsoleOutput))\n#24 \/vendor\/symfony\/console\/Application.php(1040): Piwik\\Plugin\\ConsoleCommand->run(Object(Symfony\\Component\\Console\\Input\\ArgvInput), Object(Symfony\\Component\\Console\\Output\\ConsoleOutput))\n#25 \/vendor\/symfony\/console\/Application.php(301): Symfony\\Component\\Console\\Application->doRunCommand(Object(Piwik\\Plugins\\CoreConsole\\Commands\\CoreArchiver), Object(Symfony\\Component\\Console\\Input\\ArgvInput), Object(Symfony\\Component\\Console\\Output\\ConsoleOutput))\n#26 \/core\/Console.php(106): Symfony\\Component\\Console\\Application->doRun(Object(Symfony\\Component\\Console\\Input\\ArgvInput), Object(Symfony\\Component\\Console\\Output\\ConsoleOutput))\n#27 [internal function]: Piwik\\Console->originDoRun(Object(Symfony\\Component\\Console\\Input\\ArgvInput), Object(Symfony\\Component\\Console\\Output\\ConsoleOutput))\n#28 \/core\/Console.php(145): call_user_func(Array, Object(Symfony\\Component\\Console\\Input\\ArgvInput), Object(Symfony\\Component\\Console\\Output\\ConsoleOutput))\n#29 \/core\/Access.php(670): Piwik\\Console->Piwik\\{closure}()\n#30 \/core\/Console.php(146): Piwik\\Access::doAsSuperUser(Object(Closure))\n#31 \/core\/Console.php(85): Piwik\\Console->doRunImpl(Object(Symfony\\Component\\Console\\Input\\ArgvInput), Object(Symfony\\Component\\Console\\Output\\ConsoleOutput))\n#32 \/vendor\/symfony\/console\/Application.php(171): Piwik\\Console->doRun(Object(Symfony\\Component\\Console\\Input\\ArgvInput), Object(Symfony\\Component\\Console\\Output\\ConsoleOutput))\n#33 \/console(32): Symfony\\Component\\Console\\Application->run()\n#34 {main}\ncaused by: SQLSTATE[40001]: Serialization failure: 1213 Deadlock found when trying to get lock; try restarting transaction on \/libs\/Zend\/Db\/Statement\/Pdo.php(233)\n#0 \/libs\/Zend\/Db\/Statement\/Pdo.php(233): PDOStatement->execute()\n#1 \/libs\/Zend\/Db\/Statement.php(300): Zend_Db_Statement_Pdo->_execute(Array)\n#2 \/libs\/Zend\/Db\/Adapter\/Abstract.php(479): Zend_Db_Statement->execute(Array)\n#3 \/libs\/Zend\/Db\/Adapter\/Pdo\/Abstract.php(238): Zend_Db_Adapter_Abstract->query('UPDATE archive_...', Array)\n#4 \/core\/Db\/Adapter\/Pdo\/Mysql.php(332): Zend_Db_Adapter_Pdo_Abstract->query('UPDATE archive_...', Array)\n#5 \/core\/Db.php(281): Piwik\\Db\\Adapter\\Pdo\\Mysql->query('UPDATE archive_...', Array)\n#6 \/core\/DataAccess\/Model.php(340): Piwik\\Db::query('UPDATE archive_...', Array)\n#7 \/core\/Archive\/ArchiveInvalidator.php(701): Piwik\\DataAccess\\Model->updateRangeArchiveAsInvalidated('archive_numeric...', Array, Array, Object(Piwik\\Segment))\n#8 \/core\/Archive\/ArchiveInvalidator.php(328): Piwik\\Archive\\ArchiveInvalidator->markArchivesInvalidated(Array, Array, Object(Piwik\\Segment), true, false, NULL)\n#9 \/plugins\/CoreAdminHome\/API.php(175): Piwik\\Archive\\ArchiveInvalidator->markArchivesAsInvalidated(Array, Array, 'day', Object(Piwik\\Segment), false, false)\n#10 \/core\/CronArchive.php(982): Piwik\\Plugins\\CoreAdminHome\\API->invalidateArchivedReports(Array, Array, 'day', Object(Piwik\\Segment), false, false)\n#11 \/core\/CronArchive.php(908): Piwik\\CronArchive->invalidateWithSegments(Array, '2023-12-31', 'day', false, false)\n#12 \/core\/CronArchive.php(858): Piwik\\CronArchive->invalidateRecentDate('today', '12')\n#13 \/core\/CronArchive.php(812): Piwik\\CronArchive->invalidateArchivedReportsForSitesThatNeedToBeArchivedAgainImpl('12')\n#14 \/core\/Tracker\/Cache.php(296): Piwik\\CronArchive->Piwik\\{closure}()\n#15 \/core\/CronArchive.php(813): Piwik\\Tracker\\Cache::withDelegatedCacheClears(Object(Closure))\n#16 \/core\/CronArchive\/QueueConsumer.php(178): Piwik\\CronArchive->invalidateArchivedReportsForSitesThatNeedToBeArchivedAgain('12')\n#17 \/core\/CronArchive.php(390): Piwik\\CronArchive\\QueueConsumer->getNextArchivesToProcess()\n#18 \/core\/CronArchive.php(276): Piwik\\CronArchive->run()\n#19 \/core\/Access.php(661): Piwik\\CronArchive->Piwik\\{closure}()\n#20 \/core\/CronArchive.php(282): Piwik\\Access::doAsSuperUser(Object(Closure))\n#21 \/plugins\/CoreConsole\/Commands\/CoreArchiver.php(32): Piwik\\CronArchive->main()\n#22 \/core\/Plugin\/ConsoleCommand.php(110): Piwik\\Plugins\\CoreConsole\\Commands\\CoreArchiver->doExecute()\n#23 \/vendor\/symfony\/console\/Command\/Command.php(298): Piwik\\Plugin\\ConsoleComman ## Stack trace 2 > [2023-12-31 01:58:08] piwik.ERROR: Scheduler: Error SQLSTATE[40001]: Serialization failure: 1213 Deadlock found when trying to get lock; try restarting transaction for task 'Piwik\Plugins\CoreAdminHome\Tasks.purgeInvalidatedArchives' {"errorMessage":"SQLSTATE[40001]: Serialization failure: 1213 Deadlock found when trying to get lock; try restarting transaction","task":"Piwik\\Plugins\\CoreAdminHome\\Tasks.purgeInvalidatedArchives"} {"class":"CoreAdminHome","request_id":"29337"} ### What should happen? No fatal error ### How can this be reproduced? Unsure. Executed command for stack trace 1 was: > SERVER ARGV: ["\/var\/www\/html\/console", "core:archive","--disable-scheduled-tasks","--force-idsites=12","--force-periods=week,month,year","--force-date-range=2023-01-01,2023-01-01"] Which seems to be triggered by GA Importer. Unsure if there was maybe any change in GA importer that this is being triggered more often? I don't know why GA Importer executes this command. Executed command for stack trace 2 was: > console core:archive --concurrent-requests-per-website=1 --skip-segments-today --concurrent-archivers=4 --no-ansi ### Matomo version 5.0 ### PHP version _No response_ ### Server operating system _No response_ ### What browsers are you seeing the problem on? _No response_ ### Computer operating system _No response_ ### Relevant log output _No response_ ### Validations - [X] Read our [Contributing Guidelines](https://github.com/matomo-org/matomo/blob/5.x-dev/CONTRIBUTING.md). - [X] Follow our [Security Policy](https://github.com/matomo-org/matomo/blob/5.x-dev/SECURITY.md). - [X] Check that there isn't already an issue that reports the same bug to avoid creating duplicates. - [X] The provided steps to reproduce is a [minimal reproducible](https://stackoverflow.com/help/minimal-reproducible-example) of the Bug.

Can you confirm?
If so, you may add some comments in the GitHub thread in order to help the bug fix.

Thomas_Oliver_Moll · July 2, 2024, 7:32am

Yes thank you for making the connection, I did not find anything while googeling it. I’ll continue over at git hub

Nis · December 19, 2024, 9:08am

Since yesterday we’ve got the same problem. We’ve got errors like:

Error: Got invalid response from API request: ?module=API&method=CoreAdminHome.archiveReports&idSite=147&period=month&date=2024-12-01&format=json&segment=pageUrl%3D%5Ehttps%25253A%25252F%25252Fwww.xyz.de%25252F2-handlungsfelder%25252F02-nachhaltigkeitsberichterstattung.html&trigger=archivephp. Response was '{"result":"error","message":"SQLSTATE[40001]: Serialization failure: 1213 Deadlock found when trying to get lock; when running the piwik-archive cron-job. This doesn’t always affect the same segments.

Our setting is:
Ubuntu 22.04.5 LTS
Matomo: 5.2.0
MariaDB: 10.6.18-MariaDB-0ubuntu0.22.04.1
PHP versions tested: from 8.1 to 8.3.14
213 web sites
227 segments
Piwik-DB: 109 GB

chriz · January 28, 2025, 2:07pm

Since we update Matomo from v5.1.2 to version 5.2.2 we also get the error message. After the archiv - cronjob has run. Not always, but very often.

1 total errors during this script execution, please investigate and try and fix these errors.

Settings:
Matomo-Version: 5.2.2
MySQL-Version: 10.5.26-MariaDB-0+deb11u2
PHP-Version: 8.3.16
Debain 11.11
53web sites
70 segments
Piwik-DB: 12,7 GB

INFO [2025-01-28 12:40:11] 2634497 Error: Got invalid response from API request: ?module=API&method=CoreAdminHome.archiveReports&idSite=106&period=month&date=2025-01-01&format=json&segment=pageTitle[...]&trigger=archivephp. Response was '{"result":"error","message":"SQLSTATE[40001]: Serialization failure: 1213 Deadlock found when trying to get lock; try restarting transaction - in plugin Goals. #0 [...]/matomo\/core\/ArchiveProcessor\/Loader.php(317): Piwik\\ArchiveProcessor\\PluginsArchiver->callAggregateAllPlugins(98.0, 31.0, false) #1 [...]/matomo\/core\/ArchiveProcessor\/Loader.php(186): Piwik\\ArchiveProcessor\\Loader->prepareAllPluginsArchive(98.0, 31.0) #2 [...]/matomo\/core\/ArchiveProcessor\/Loader.php(165): Piwik\\ArchiveProcessor\\Loader->insertArchiveData(98.0, 31.0, false, NULL) #3 [...]/matomo\/core\/ArchiveProcessor\/Loader.php(105): Piwik\\ArchiveProcessor\\Loader->prepareArchiveImpl(false) #4 [...]/matomo\/core\/Context.php(76): Piwik\\ArchiveProcessor\\Loader->Piwik\\ArchiveProcessor\\{closure}() #5 [...]\/matomo\/core\/ArchiveProcessor\/Loader.php(102): Piwik\\Context::changeIdSite(106, Object(Closure)) #6 [...]/matomo\/plugins\/CoreAdminHome\/API.php(306): Piwik\\ArchiveProcessor\\Loader->prepareArchive(false) #7 [internal function]: Piwik\\Plugins\\CoreAdminHome\\API->archiveReports('106', Object(Piwik\\Period\\Month), '2025-01-01', 'pageTitle%3D%40...', false, false) #8 [...]/matomo\/core\/API\/Proxy.php(256): call_user_func_array(Array, Array) #9 [...]/matomo\/core\/Context.php(29): Piwik\\API\\Proxy->Piwik\\API\\{closure}() #10 [...]/matomo\/core\/API\/Proxy.php(159): Piwik\\Context::executeWithQueryParameters(Array, Object(Closure)) #11 [...]/matomo\/core\/API\/Request.php(274): Piwik\\API\\Proxy->call('\\\\Piwik\\\\Plugins\\\\...', 'archiveReports', Array) #12 [...]/matomo\/plugins\/API\/Controller.php(46): Piwik\\API\\Request->process() #13 [internal function]: Piwik\\Plugins\\API\\Controller->index() #14 [...]/matomo\/core\/FrontController.php(645): call_user_func_array(Array, Array) #15 [...]/matomo\/core\/FrontController.php(169): Piwik\\FrontController->doDispatch('API', false, Array) #16 [...]/matomo\/core\/dispatch.php(33): Piwik\\FrontController->dispatch() #17 [...]/matomo\/index.php(25): require_once('[...]...') #18 [...]/matomo\/core\/CliMulti\/RequestCommand.php(76): require_once('\/[...]...') #19 [...]/matomo\/core\/Plugin\/ConsoleCommand.php(138): Piwik\\CliMulti\\RequestCommand->doExecute() #20 [...]/matomo\/vendor\/symfony\/console\/Command\/Command.php(298): Piwik\\Plugin\\ConsoleCommand->execute(Object(Symfony\\Component\\Console\\Input\\ArgvInput), Object(Symfony\\Component\\Console\\Output\\ConsoleOutput)) #21[...]/matomo\/core\/Plugin\/ConsoleCommand.php(153): Symfony\\Component\\Console\\Command\\Command->run(Object(Symfony\\Component\\Console\\Input\\ArgvInput), Object(Symfony\\Component\\Console\\Output\\ConsoleOutput)) #22 [...]/matomo\/vendor\/symfony\/console\/Application.php(1040): Piwik\\Plugin\\ConsoleCommand->run(Object(Symfony\\Component\\Console\\Input\\ArgvInput), Object(Symfony\\Component\\Console\\Output\\ConsoleOutput)) #23 [...]/matomo\/vendor\/symfony\/console\/Application.php(301): Symfony\\Component\\Console\\Application->doRunCommand(Object(Piwik\\CliMulti\\RequestCommand), Object(Symfony\\Component\\Console\\Input\\ArgvInput), Object(Symfony\\Component\\Console\\Output\\ConsoleOutput)) #24 [...]/matomo\/core\/Console.php(113): Symfony\\Component\\Console\\Application->doRun(Object(Symfony\\Component\\Console\\Input\\ArgvInput), Object(Symfony\\Component\\Console\\Output\\ConsoleOutput)) #25 [internal function]: Piwik\\Console->originDoRun(Object(Symfony\\Component\\Console\\Input\\ArgvInput), Object(Symfony\\Component\\Console\\Output\\ConsoleOutput)) #26 [...]/matomo\/core\/Console.php(152): call_user_func(Array, Object(Symfony\\Component\\Console\\Input\\ArgvInput), Object(Symfony\\Component\\Console\\Output\\ConsoleOutput)) #27 [...]/matomo\/core\/Access.php(672): Piwik\\Console->Piwik\\{closure}() #28 [...]/matomo\/core\/Console.php(150): Piwik\\Access::doAsSuperUser(Object(Closure)) #29 [...]/matomo\/core\/Console.php(92): Piwik\\Console->doRunImpl(Object(Symfony\\Component\\Console\\Input\\ArgvInput), Object(Symfony\\Component\\Console\\Output\\ConsoleOutput)) #30 [...]/matomo\/vendor\/symfony\/console\/Application.php(171): Piwik\\Console->doRun(Object(Symfony\\Component\\Console\\Input\\ArgvInput), Object(Symfony\\Component\\Console\\Output\\ConsoleOutput)) #31 \[...]/matomo\/console(32): Symfony\\Component\\Console\\Application->run() #32 {main}, caused by: SQLSTATE[40001]: Serialization failure: 1213 Deadlock found when trying to get lock; try restarting transaction #0 \[...]/matomo\/libs\/Zend\/Db\/Statement.php(300): Zend_Db_Statement_Pdo->_execute(Array) #1 [...]/matomo\/libs\/Zend\/Db\/Adapter\/Abstract.php(479): Zend_Db_Statement->execute(Array) #2[...]/matomo\/libs\/Zend\/Db\/Adapter\/Pdo\/Abstract.php(238): Zend_Db_Adapter_Abstract->query('UPDATE piwik_a…‘, Array) #3 […]/matomo/core/Db/Adapter/Pdo/Mysql.php(334): Zend_Db_Adapter_Pdo_Abstract->q … […]/matomo/console(32): Symfony\Component\Console\Application->run()\n#45 {main}"}’`

DrHase · February 3, 2025, 9:31am

+1 seit dem Update auf 5.2.2

Not always, but very often.