diff --git a/CHANGELOG.md b/CHANGELOG.md index 5af4447..ac37528 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -1,5 +1,8 @@ ## Changelog +6.0.3 - 2026-10-26 +- Fixed a queue worker crashing and keeping its queue locked when a database deadlock was caught while tracking the last request of a request set; the request set is now retried + 6.0.2 - 2026-10-20 - Fixed queue processing failing with a fatal error, and some hits being counted twice, after a database deadlock or a MariaDB snapshot isolation conflict; requests hit by a snapshot isolation conflict are now retried - Fixed requests being lost when the retry after a database deadlock or snapshot isolation conflict failed because of a different request diff --git a/Queue/Processor.php b/Queue/Processor.php index e3af985..6dd31de 100644 --- a/Queue/Processor.php +++ b/Queue/Processor.php @@ -217,6 +217,14 @@ public function process(Tracker $tracker = null) } catch (Exception $e) { Common::printDebug('Failed to process a request set: ' . $e->getMessage()); + try { + // the MySQL backend shares the tracker's connection, which refuses to unlock while an aborted + // transaction is still open + $this->handler->rollBack($tracker); + } catch (Exception $rollBackException) { + Common::printDebug('Failed to roll back: ' . $rollBackException->getMessage()); + } + $this->queueManager->unlock(); $request->restoreEnvironment(); throw $e; diff --git a/Queue/Processor/Handler.php b/Queue/Processor/Handler.php index 167ddd6..06498e0 100644 --- a/Queue/Processor/Handler.php +++ b/Queue/Processor/Handler.php @@ -12,9 +12,12 @@ use Piwik\Common; use Piwik\Container\StaticContainer; +use Piwik\Db\TransactionErrors; use Piwik\Exception\UnexpectedWebsiteFoundException; use Piwik\Plugins\QueuedTracking\Configuration; use Piwik\Tracker; +use Piwik\Tracker\Db as TrackerDb; +use Piwik\Tracker\Db\DbException; use Piwik\Tracker\RequestSet; use Exception; @@ -48,6 +51,7 @@ public function process(Tracker $tracker, RequestSet $requestSet) $startMs = round(microtime(true) * 1000); $tracker->trackRequest($request); + $this->failIfTransactionAborted(); $diffInMs = round(microtime(true) * 1000) - $startMs; if ($diffInMs > 2000) { @@ -143,15 +147,33 @@ public function commit() } /** - * Deadlock (1213), lock wait timeout (1205) and MariaDB's snapshot isolation conflict (1020). + * Deadlock (1213), lock wait timeout (1205), MariaDB's snapshot isolation conflict (1020) and, on Matomo versions + * that list them, the other errors that end the transaction. */ private function isRetryableTransactionError(Exception $e): bool { $db = $this->getDb(); + if (class_exists(TransactionErrors::class)) { + return TransactionErrors::endsTransaction($db, $e) || TransactionErrors::isStatementOnly($db, $e); + } + return $db->isErrNo($e, 1213) || $db->isErrNo($e, 1205) || $db->isErrNo($e, 1020); } + /** + * A tracking step may catch an error that made the server roll back the transaction. Matomo then refuses every + * later query, but when that was the request set's last query nothing notices until the lock or commit queries. + */ + private function failIfTransactionAborted(): void + { + $db = $this->getDb(); + + if (method_exists($db, 'isTransactionAborted') && $db->isTransactionAborted()) { + throw new DbException(TrackerDb::TRANSACTION_ABORTED_MESSAGE, TransactionErrors::ERROR_CODE_DEADLOCK); + } + } + /** * These errors can end the transaction on the server, after which PDO runs every later query in autocommit * mode, so the remaining request sets would be stored even though the batch is rolled back and retried. diff --git a/plugin.json b/plugin.json index 595c6b7..ee9f99f 100644 --- a/plugin.json +++ b/plugin.json @@ -1,6 +1,6 @@ { "name": "QueuedTracking", - "version": "6.0.2", + "version": "6.0.3", "description": "Scale your large traffic Matomo service by queuing tracking requests in Redis or MySQL for better performance and reliability when experiencing peaks.", "theme": false, "keywords": ["tracker", "tracking", "queue", "redis"], diff --git a/tests/Integration/Queue/Processor/HandlerTest.php b/tests/Integration/Queue/Processor/HandlerTest.php index 8d7229b..25a9acb 100644 --- a/tests/Integration/Queue/Processor/HandlerTest.php +++ b/tests/Integration/Queue/Processor/HandlerTest.php @@ -15,8 +15,11 @@ use Piwik\Plugins\QueuedTracking\tests\Framework\Mock\ForcedException; use Piwik\Plugins\QueuedTracking\tests\Framework\Mock\Tracker; use Piwik\Plugins\QueuedTracking\tests\Framework\TestCase\IntegrationTestCase; +use Piwik\Tests\Framework\DbErrorRaiser; use Piwik\Tests\Framework\Fixture; use Piwik\Tests\Framework\Mock\Tracker\RequestSet; +use Piwik\Tracker\Db\DbException; +use Piwik\Tracker\Request; class TestHandler extends Handler { @@ -350,6 +353,53 @@ public function getRetryableTransactionErrors(): array ]; } + public function testProcessShouldFailTheRequestSetIfATrackingStepSwallowedAnErrorThatEndedTheTransaction() + { + if (!method_exists(Tracker::getDatabase(), 'isTransactionAborted')) { + $this->markTestSkipped('Needs a Matomo version that refuses queries once the transaction was rolled back'); + } + + // creating the procedure would commit the open transaction + $this->handler->rollBack($this->tracker); + DbErrorRaiser::install(); + $this->handler->init($this->tracker); + + $tracker = new class extends Tracker { + public function trackRequest(Request $request) + { + parent::trackRequest($request); + + try { + DbErrorRaiser::raise(self::getDatabase(), 1213, 'Deadlock found when trying to get lock; try restarting transaction'); + } catch (\Exception $e) { + // like a tracking step that logs a failed write and carries on + } + } + }; + + $requestSet = $this->buildRequestSet(1); + $this->insertOption('QueuedTrackingTest_beforeError'); + + try { + $this->handler->process($tracker, $requestSet); + $this->fail('The request set must not count as processed'); + } catch (DbException $e) { + $this->handler->onException($requestSet, $e); + } + + // the handler started a new transaction + $this->insertOption('QueuedTrackingTest_afterError'); + $this->handler->rollBack($this->tracker); + DbErrorRaiser::uninstall(); + + $this->assertEquals([$requestSet], $this->handler->getRequestSetsToRetry()); + $this->assertEquals([$requestSet], $this->handler->getRequestSetsWithTransactionErrors()); + $this->assertSame(0, (int) Db::fetchOne( + 'SELECT COUNT(*) FROM `' . Common::prefixTable('option') . '` WHERE option_name LIKE ?', + ['QueuedTrackingTest_%'] + )); + } + private function insertOption(string $name): void { Tracker::getDatabase()->query(