matomo-org / matomo

Empowering People Ethically with the leading open source alternative to Google Analytics that gives you full control over your data. Matomo lets you easily collect data from websites & apps and visualise this data and extract insights. Privacy is built-in. Liberating Web Analytics. Star us on Github? +1. And we love Pull Requests!
https://matomo.org/
GNU General Public License v3.0
19.92k stars 2.66k forks source link

[Bug] High concurrency archiving causes deadlocks upon archive invalidation and archive insertion #22772

Open samjf opened 3 days ago

samjf commented 3 days ago

What happened?

When executing archiving in a more concurrent way, we experience a significant amount of deadlocks compared to when we run it without concurrency. This behavior can occur on a very low amount of concurrency, and forces us to prevent multiple websites from being archived simultaneously.

In an effort to improve concurrency we allowed multiple websites to be processed at the same time however this produced so many deadlock errors in our logs that it became untenable to continue. The following stack traces were common:

no.1 The updateArchiveAsInvalidated error (~300 occurences):

[2024-10-07 01:43:06] piwik.ERROR: Uncaught exception in API: PDOException: SQLSTATE[40001]: Serialization failure: 1213 Deadlock found when trying to get lock; try restarting transaction in code/libs/Zend/Db/Statement/Pdo.php:233 Stack trace: 
#0 code/libs/Zend/Db/Statement/Pdo.php(233): PDOStatement->execute() 
#1 code/libs/Zend/Db/Statement.php(300): Zend_Db_Statement_Pdo->_execute() 
#2 code/libs/Zend/Db/Adapter/Abstract.php(479): Zend_Db_Statement->execute() 
#3 code/libs/Zend/Db/Adapter/Pdo/Abstract.php(238): Zend_Db_Adapter_Abstract->query() 
#4 code/core/Db/Adapter/Pdo/Mysql.php(334): Zend_Db_Adapter_Pdo_Abstract->query() 
#5 code/core/Db.php(286): Piwik\Db\Adapter\Pdo\Mysql->query() 
#6 code/core/DataAccess/Model.php(192): Piwik\Db::query() 
#7 code/core/Archive/ArchiveInvalidator.php(728): Piwik\DataAcces
s\Model->updateArchiveAsInvalidated() 
#8 code/core/Archive/ArchiveInvalidator.php(334): Piwik\Archive\ArchiveInvalidator->markArchivesInvalidated() 
#9 code/core/ArchiveProcessor.php(797): Piwik\Archive\ArchiveInvalidator->markArchivesAsInvalidated() 
#10 code/core/Plugin/Archiver.php(411): Piwik\ArchiveProcessor->processDependentArchive() 
#11 code/core/Plugin/Archiver.php(274): Piwik\Plugin\Archiver->processDependentArchivesForPlugins() 
#12 code/core/ArchiveProcessor/PluginsArchiver.php(190): Piwik\Plugin\Archiver->callAggregateMultipleReports() 
#13 code/core/ArchiveProcessor/Loader.php(317): Piwik\ArchiveProcessor\PluginsArchiver->callAggregateAllPlugins() 
#14 code/core/ArchiveProcessor/Loader.php(186): Piwik\ArchiveProcessor\Loader->prepareAllPluginsArchive() 
#15 code/core/ArchiveProcessor/Loader.php(165): Piwik\ArchiveProcessor\Loader->insertArchiveData() 
#16 code/core/ArchiveProcessor/Loader.php(105)
: Piwik\ArchiveProcessor\Loader->prepareArchiveImpl() 
#17 code/core/Context.php(76): Piwik\ArchiveProcessor\Loader->Piwik\ArchiveProcessor\{closure}() 
#18 code/core/ArchiveProcessor/Loader.php(109): Piwik\Context::changeIdSite() 
#19 code/plugins/CoreAdminHome/API.php(306): Piwik\ArchiveProcessor\Loader->prepareArchive() 
#20 [internal function]: Piwik\Plugins\CoreAdminHome\API->archiveReports() 
#21 code/core/API/Proxy.php(256): call_user_func_array() 
#22 code/core/Context.php(29): Piwik\API\Proxy->Piwik\API\{closure}() 
#23 code/core/API/Proxy.php(347): Piwik\Context::executeWithQueryParameters() 
#24 code/core/API/Request.php(274): Piwik\API\Proxy->call() 
#25 code/plugins/API/Controller.php(46): Piwik\API\Request->process() 
#26 [internal function]: Piwik\Plugins\API\Controller->index() 
#27 code/core/FrontController.php(645): call_user_func_array() 
#28 code/core/FrontController.php(169): Piwik\Fro
ntController->doDispatch() 
#29 code/core/dispatch.php(33): Piwik\FrontController->dispatch() 
#30 code/index.php(25): require_once('...') 
#31 code/core/CliMulti/RequestCommand.php(76): require_once('...') 
#32 code/core/Plugin/ConsoleCommand.php(109): Piwik\CliMulti\RequestCommand->doExecute() 
#33 code/vendor/symfony/console/Command/Command.php(298): Piwik\Plugin\ConsoleCommand->execute() 
#34 code/core/Plugin/ConsoleCommand.php(124): Symfony\Component\Console\Command\Command->run() 
#35 code/vendor/symfony/console/Application.php(1040): Piwik\Plugin\ConsoleCommand->run() 
#36 code/vendor/symfony/console/Application.php(301): Symfony\Component\Console\Application->doRunCommand() 
#37 code/core/Console.php(113): Symfony\Component\Console\Application->doRun() 
#38 [internal function]: Piwik\Console->originDoRun() 
#39 code/core/Console.php(152): call_user_func() 
#40 code/core/Access.php(672): Piwik\Console->Piwik\{closure}() 
#41 code/core/Console.php(153): Piwik\Access::doAsSuperUser() 
#42 code/core/Console.php(92): Piwik\Console->doRunImpl() 
#43 code/vendor/symfony/console/Application.php(171): Piwik\Console->doRun() 
#44 code/console(32): Symfony\Component\Console\Application->run() 
#45 {main} Next Zend_Db_Statement_Exception: SQLSTATE[40001]: Serialization failure: 1213 Deadlock found when trying to get lock; try restarting transaction in code/libs/Zend/Db/Statement/Pdo.php:236

no.2: the insertNumericRecord error (~ 180 events)

[2024-10-07 02:34:53] piwik.ERROR: Uncaught exception in API: PDOException: SQLSTATE[40001]: Serialization failure: 1213 Deadlock found when trying to get lock; try restarting transaction in code/libs/Zend/Db/Statement/Pdo.php:233 Stack trace: 
#0 code/libs/Zend/Db/Statement/Pdo.php(233): PDOStatement->execute() 
#1 code/libs/Zend/Db/Statement.php(300): Zend_Db_Statement_Pdo->_execute() 
#2 code/core/Db/Adapter/Pdo/Mysql.php(330): Zend_Db_Statement->execute() 
#3 code/core/Db.php(286): Piwik\Db\Adapter\Pdo\Mysql->query() 
#4 code/core/Db/BatchInsert.php(70): Piwik\Db::query() 
#5 code/core/DataAccess/ArchiveWriter.php(296): Piwik\Db\B
atchInsert::tableInsertBatchSql() 
#6 code/core/DataAccess/ArchiveWriter.php(349): Piwik\DataAccess\ArchiveWriter->batchInsertSpool() 
#7 code/core/DataAccess/ArchiveWriter.php(325): Piwik\DataAccess\ArchiveWriter->flushSpool() 
#8 code/core/ArchiveProcessor.php(345): Piwik\DataAccess\ArchiveWriter->insertRecord() 
#9 code/core/ArchiveProcessor.php(289): Piwik\ArchiveProcessor->insertNumericRecord() 
#10 code/core/ArchiveProcessor/RecordBuilder.php(236): Piwik\ArchiveProcessor->aggregateNumericMetrics() 
#11 code/plugins/CustomReports/RecordBuilders/CustomReport.php(154): Piwik\ArchiveProcessor\RecordBuilder->buildForNonDayPeriod() 
#12 code/core/Plugin/Archiver.php(265): Piwik\Plugins\CustomReports\RecordBuilders\CustomReport->buildForNonDayPeriod() 
#13 code/core/ArchiveProcessor/PluginsArchiver.php(190): Piwik\Plugin\Archiver->callAggregateMultipleReports() 
#14 code/core/ArchiveProcessor/Loader.php(317): Piw
ik\ArchiveProcessor\PluginsArchiver->callAggregateAllPlugins() 
#15 code/core/ArchiveProcessor/Loader.php(186): Piwik\ArchiveProcessor\Loader->prepareAllPluginsArchive() 
#16 code/core/ArchiveProcessor/Loader.php(165): Piwik\ArchiveProcessor\Loader->insertArchiveData() 
#17 code/core/ArchiveProcessor/Loader.php(105): Piwik\ArchiveProcessor\Loader->prepareArchiveImpl() 
#18 code/core/Context.php(76): Piwik\ArchiveProcessor\Loader->Piwik\ArchiveProcessor\{closure}() 
#19 code/core/ArchiveProcessor/Loader.php(109): Piwik\Context::changeIdSite() 
#20 code/plugins/CoreAdminHome/API.php(306): Piwik\ArchiveProcessor\Loader->prepareArchive() 
#21 [internal function]: Piwik\Plugins\CoreAdminHome\API->archiveReports() 
#22 code/core/API/Proxy.php(256): call_user_func_array() 
#23 code/core/Context.php(29): Piwik\API\Proxy->Piwik\API\{closure}() 
#24 code/core/API/Proxy.php(347): Piwik\Context::executeWithQueryParameters()
#25 code/core/API/Request.php(274): Piwik\API\Proxy->call() 
#26 code/plugins/API/Controller.php(46): Piwik\API\Request->process() 
#27 [internal function]: Piwik\Plugins\API\Controller->index() 
#28 code/core/FrontController.php(645): call_user_func_array() 
#29 code/core/FrontController.php(169): Piwik\FrontController->doDispatch() 
#30 code/core/dispatch.php(33): Piwik\FrontController->dispatch() 
#31 code/index.php(25): require_once('...') 
#32 code/core/CliMulti/RequestCommand.php(76): require_once('...') 
#33 code/core/Plugin/ConsoleCommand.php(109): Piwik\CliMulti\RequestCommand->doExecute() 
#34 code/vendor/symfony/console/Command/Command.php(298): Piwik\Plugin\ConsoleCommand->execute() 
#35 code/core/Plugin/ConsoleCommand.php(124): Symfony\Component\Console\Command\Command->run() 
#36 code/vendor/symfony/console/Application.php(1040): Piwik\Plugin\ConsoleCommand->run() 
#37 code/
vendor/symfony/console/Application.php(301): Symfony\Component\Console\Application->doRunCommand() 
#38 code/core/Console.php(113): Symfony\Component\Console\Application->doRun() 
#39 [internal function]: Piwik\Console->originDoRun() 
#40 code/core/Console.php(152): call_user_func() 
#41 code/core/Access.php(672): Piwik\Console->Piwik\{closure}() 
#42 code/core/Console.php(153): Piwik\Access::doAsSuperUser() 
#43 code/core/Console.php(92): Piwik\Console->doRunImpl() 
#44 code/vendor/symfony/console/Application.php(171): Piwik\Console->doRun() 
#45 code/console(32): Symfony\Component\Console\Application->run() 
#46 {main} Next Zend_Db_Statement_Exception: SQLSTATE[40001]: Serialization failure: 1213 Deadlock found when trying to get lock; try restarting transaction in code/libs/Zend/Db/Statement/Pdo.php:236

no. 3 the updateRangeArchiveAsInvalidated error (~1000 events)

SQLSTATE[40001]: Serialization failure: 1213 Deadlock found when trying to get lock; try restarting transaction","file":"code_dir\/libs\/Zend\/Db\/Statement\/Pdo.php","line":236,"backtrace":" on code_dir\/libs\/Zend\/Db\/Statement\/Pdo.php(236)\n
#0 code_dir\/libs\/Zend\/Db\/Statement.php(300): Zend_Db_Statement_Pdo->_execute()\n
#1 code_dir\/libs\/Zend\/Db\/Adapter\/Abstract.php(479): Zend_Db_Statement->execute()\n
#2 code_dir\/libs\/Zend\/Db\/Adapter\/Pdo\/Abstract.php(238): Zend_Db_Adapter_Abstract->query()\n
#3 code_dir\/core\/Db\/Adapter\/Pdo\/Mysql.php(334): Zend_Db_Adapter_Pdo_Abstract->query()\n
#4 code_dir\/core\/Db.php(286): Piwik\\Db\\Adapter\\Pdo\\Mysql->query()\n
#5 code_dir\/core\/DataAccess\/Model.php(361): Piwik\\Db::query()\n
#6 code_dir\/core\/Archive\/ArchiveInvalidator.php(731): Piwik\\DataAccess\\Model->updateRangeArchiveAsInvalidated()\n
#7 code_dir\/core\/Archive\/ArchiveInvalidator.php(334): Piwik\\Archive\\ArchiveInvalidator->markArchivesInvalidated()\n
#8 code_dir\/plugins\/CoreAdminHome\/API.php(184): Piwik\\Archive\\ArchiveInvalidator->markArchivesAsInvalidated()\n
#9 code_dir\/core\/CronArchive.php(1041): Piwik\\Plugins\\CoreAdminHome\\API->invalidateArchivedReports()\n
#10 code_dir\/core\/CronArchive.php(931): Piwik\\CronArchive->invalidateWithSegments()\n
#11 code_dir\/core\/CronArchive.php(880): Piwik\\CronArchive->invalidateRecentDate()\n
#12 code_dir\/core\/CronArchive.php(830): Piwik\\CronArchive->invalidateArchivedReportsForSitesThatNeedToBeArchivedAgainImpl()\n
#13 code_dir\/core\/Tracker\/Cache.php(297): Piwik\\CronArchive->Piwik\\{closure}()\n
#14 code_dir\/core\/CronArchive.php(831): Piwik\\Tracker\\Cache::withDelegatedCacheClears()\n
#15 code_dir\/core\/CronArchive\/QueueConsumer.php(184): Piwik\\CronArchive->invalidateArchivedReportsForSitesThatNeedToBeArchivedAgain()\n
#16 code_dir\/core\/CronArchive.php(400): Piwik\\CronArchive\\QueueConsumer->getNextArchivesToProcess()\n
#17 code_dir\/core\/CronArchive.php(276): Piwik\\CronArchive->run()\n
#18 code_dir\/core\/Access.php(663): Piwik\\CronArchive->Piwik\\{closure}()\n
#19 code_dir\/core\/CronArchive.php(282): Piwik\\Access::doAsSuperUser()\n
#20 code_dir\/plugins\/CoreConsole\/Commands\/CoreArchiver.php(34): Piwik\\CronArchive->main()\n
#21 code_dir\/core\/Plugin\/ConsoleCommand.php(109): Piwik\\Plugins\\CoreConsole\\Commands\\CoreArchiver->doExecute()\n
#22 code_dir\/vendor\/symfony\/console\/Command\/Command.php(298): Piwik\\Plugin\\ConsoleCommand->execute()\n
#23 code_dir\/core\/Plugin\/ConsoleCommand.php(124): Symfony\\Component\\Console\\Command\\Command->run()\n
#24 code_dir\/vendor\/symfony\/console\/Application.php(1040): Piwik\\Plugin\\ConsoleCommand->run()\n
#25 code_dir\/vendor\/symfony\/console\/Application.php(301): Symfony\\Component\\Console\\Application->doRunCommand()\n
#26 code_dir\/core\/Console.php(113): Symfony\\Component\\Console\\Application->doRun()\n
#27 [internal function]: Piwik\\Console->originDoRun()\n
#28 code_dir\/core\/Console.php(152): call_user_func()\n
#29 code_dir\/core\/Access.php(672): Piwik\\Console->Piwik\\{closure}()\n
#30 code_dir\/core\/Console.php(153): Piwik\\Access::doAsSuperUser()\n
#31 code_dir\/core\/Console.php(92): Piwik\\Console->doRunImpl()\n
#32 code_dir\/vendor\/symfony\/console\/Application.php(171): Piwik\\Console->doRun()\n
#33 code_dir\/console(32): Symfony\\Component\\Console\\Application->run()\n
#34 {main}

I believe this is related to https://github.com/matomo-org/matomo/issues/21749 but that one seems to have a different direction, yet commenters have similar symptoms and causes.

What should happen?

When multiple processes are attempting to update the same table there should be some durability to ensure that information is written when under high concurrency. While deadlocks are probably something natural to high concurrency, it seems that the system isn't handling such conditions very well.

How can this be reproduced?

To reproduce this I would try to invoke high concurrency conditions by:

Matomo version

5.2

PHP version

8.1

Server operating system

Linux

What browsers are you seeing the problem on?

Not applicable (e.g. an API call etc.)

Computer operating system

N/A

Relevant log output

No response

Validations