From 35192aaadc25ced2e3acafba57379491bd106e97 Mon Sep 17 00:00:00 2001 From: Jared Vititoe Date: Sat, 12 Sep 2026 01:18:13 -0400 Subject: [PATCH] Retry failed Matrix webhook notifications with backoff (#78) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit NotificationHelper::fire() logged a failed webhook post via error_log() only, with no retry and no persistent record — once a notification failed, it was gone with no trace beyond the log line, even though the underlying DB write (audit_log entry, status change, etc.) it was reporting on had already committed. Extracted the curl POST into attemptDelivery(), shared between fire() (unchanged best-effort caller-facing behavior) and the new cron/retry_failed_notifications.php. On failure, fire() now also queues the payload to notification_retry_queue (migration 007) via Database::getConnection() — most fire() call sites don't have a $conn handy, and threading one through every caller would be a much larger, more invasive change than reusing the existing connection singleton. The cron script processes due rows with exponential backoff (2, 4, 8... capped at 60 minutes) up to each row's max_attempts (default 6), then leaves an exhausted row in place — not deleted — so it stays visible for manual investigation instead of disappearing a second time. Verified against real MariaDB and a local HTTP server standing in for the Matrix webhook, toggled between failing and succeeding: confirmed a real failure via fire() is correctly queued; the retry script reschedules a still-failing row with the expected backoff delay; flipping the fake webhook to succeed lets the same row's next retry delete it; a row that exhausts all attempts is left in place and correctly excluded from the next run's due-row query; and a success via fire() queues nothing (no regression on the common case). Co-Authored-By: Claude Sonnet 5 Claude-Session: https://claude.ai/code/session_0117oBw2jN4kALYeS8HPq4zV --- README.md | 3 + cron/retry_failed_notifications.php | 133 ++++++++++++++++++++ helpers/NotificationHelper.php | 74 ++++++++--- migrations/007_notification_retry_queue.sql | 20 +++ 4 files changed, 216 insertions(+), 14 deletions(-) create mode 100644 cron/retry_failed_notifications.php create mode 100644 migrations/007_notification_retry_queue.sql diff --git a/README.md b/README.md index 286ba3b..f9c7d4d 100644 --- a/README.md +++ b/README.md @@ -525,6 +525,9 @@ Add to crontab for recurring tickets and maintenance cleanup: # Delete orphaned upload files with no attachment row, past a 24h grace period (daily). # Add --dry-run to preview without deleting. 0 4 * * * php /path/to/tinkertickets/scripts/cleanup_orphan_uploads.php + +# Retry failed Matrix webhook notifications (exponential backoff, every 5 minutes) +*/5 * * * * php /path/to/tinkertickets/cron/retry_failed_notifications.php ``` ### 3. File Uploads diff --git a/cron/retry_failed_notifications.php b/cron/retry_failed_notifications.php new file mode 100644 index 0000000..36e3b19 --- /dev/null +++ b/cron/retry_failed_notifications.php @@ -0,0 +1,133 @@ +#!/usr/bin/env php +getMessage()); + exit(1); +} + +// Process a bounded batch per run so one cron tick can't run indefinitely if +// the queue has backed up. +$batchLimit = 50; + +$stmt = $conn->prepare( + "SELECT retry_id, payload, attempts, max_attempts + FROM notification_retry_queue + WHERE next_attempt_at <= NOW() AND attempts < max_attempts + ORDER BY retry_id ASC + LIMIT ?" +); +$stmt->bind_param('i', $batchLimit); +$stmt->execute(); +$dueRows = $stmt->get_result()->fetch_all(MYSQLI_ASSOC); +$stmt->close(); + +if (empty($dueRows)) { + logMessage('No notifications due for retry.'); + exit(0); +} + +$succeeded = 0; +$failed = 0; +$exhausted = 0; + +foreach ($dueRows as $row) { + $payload = json_decode($row['payload'], true); + if (!is_array($payload)) { + // Corrupt row — can't retry something unparseable. Remove it rather + // than retrying forever against a row that will never succeed. + $del = $conn->prepare("DELETE FROM notification_retry_queue WHERE retry_id = ?"); + $del->bind_param('i', $row['retry_id']); + $del->execute(); + $del->close(); + logMessage("Discarded retry #{$row['retry_id']}: payload is not valid JSON"); + continue; + } + + $result = NotificationHelper::attemptDelivery($webhookUrl, $payload); + + if ($result['success']) { + $del = $conn->prepare("DELETE FROM notification_retry_queue WHERE retry_id = ?"); + $del->bind_param('i', $row['retry_id']); + $del->execute(); + $del->close(); + $succeeded++; + logMessage("Retry #{$row['retry_id']} succeeded (attempt " . ((int)$row['attempts'] + 1) . ')'); + continue; + } + + $newAttempts = (int)$row['attempts'] + 1; + if ($newAttempts >= (int)$row['max_attempts']) { + // Exhausted: leave the row (attempts is now == max_attempts, so the + // WHERE clause above naturally excludes it from future runs) rather + // than deleting it, so it stays visible for manual investigation. + $upd = $conn->prepare( + "UPDATE notification_retry_queue SET attempts = ?, last_error = ? WHERE retry_id = ?" + ); + $upd->bind_param('isi', $newAttempts, $result['error'], $row['retry_id']); + $upd->execute(); + $upd->close(); + $exhausted++; + logMessage("Retry #{$row['retry_id']} exhausted after {$newAttempts} attempts: {$result['error']}"); + continue; + } + + $delayMinutes = nextAttemptDelayMinutes($newAttempts); + $upd = $conn->prepare( + "UPDATE notification_retry_queue + SET attempts = ?, last_error = ?, next_attempt_at = DATE_ADD(NOW(), INTERVAL ? MINUTE) + WHERE retry_id = ?" + ); + $upd->bind_param('isii', $newAttempts, $result['error'], $delayMinutes, $row['retry_id']); + $upd->execute(); + $upd->close(); + $failed++; + logMessage("Retry #{$row['retry_id']} failed (attempt {$newAttempts}), next attempt in {$delayMinutes}m: {$result['error']}"); +} + +logMessage("Done: {$succeeded} succeeded, {$failed} rescheduled, {$exhausted} exhausted (of " . count($dueRows) . ' processed)'); diff --git a/helpers/NotificationHelper.php b/helpers/NotificationHelper.php index f4590e5..6535f2c 100644 --- a/helpers/NotificationHelper.php +++ b/helpers/NotificationHelper.php @@ -7,13 +7,16 @@ class NotificationHelper { // ─── Internal: fire a webhook ───────────────────────────────────────────── - private static function fire(array $payload): void + /** + * POST a payload to the configured Matrix webhook and report the raw + * result. Shared by fire() (best-effort, queues on failure) and + * cron/retry_failed_notifications.php (retries a previously-queued + * payload) so both use identical request handling. + * + * @return array{success: bool, http_code: ?int, error: ?string} + */ + public static function attemptDelivery(string $webhookUrl, array $payload): array { - $webhookUrl = $GLOBALS['config']['MATRIX_WEBHOOK_URL'] ?? null; - if (empty($webhookUrl)) { - return; - } - $ch = curl_init($webhookUrl); curl_setopt($ch, CURLOPT_HTTPHEADER, ['Content-Type: application/json']); curl_setopt($ch, CURLOPT_POST, 1); @@ -21,10 +24,11 @@ class NotificationHelper curl_setopt($ch, CURLOPT_RETURNTRANSFER, true); curl_setopt($ch, CURLOPT_TIMEOUT, 10); // A slow-but-not-fully-hung hookshot endpoint could otherwise add up - // to the full CURLOPT_TIMEOUT per fire() call, and a single request - // can call fire() (via notifyWatchers/sendCommentNotification/etc.) - // more than once sequentially — capping just the connect phase keeps - // that from stacking into tens of seconds of added latency. + // to the full CURLOPT_TIMEOUT per call, and a single request can + // trigger more than one notification sequentially (via + // notifyWatchers/sendCommentNotification/etc.) — capping just the + // connect phase keeps that from stacking into tens of seconds of + // added latency. curl_setopt($ch, CURLOPT_CONNECTTIMEOUT, 3); $response = curl_exec($ch); @@ -32,12 +36,54 @@ class NotificationHelper $curlError = curl_error($ch); curl_close($ch); - $id = $payload['ticket_id'] ?? '?'; if ($curlError) { - error_log("Matrix webhook cURL error for ticket #{$id}: {$curlError}"); - } elseif ($httpCode < 200 || $httpCode >= 300) { - error_log("Matrix webhook failed for ticket #{$id}. HTTP {$httpCode}: {$response}"); + return ['success' => false, 'http_code' => null, 'error' => $curlError]; } + if ($httpCode < 200 || $httpCode >= 300) { + return ['success' => false, 'http_code' => $httpCode, 'error' => "HTTP {$httpCode}: {$response}"]; + } + return ['success' => true, 'http_code' => $httpCode, 'error' => null]; + } + + /** + * Persist a failed payload for later retry by + * cron/retry_failed_notifications.php. Best-effort: a DB failure here + * must not throw back into the original (already-failed) notification + * attempt — it just means this particular failure isn't retried, no + * worse than the pre-existing behavior. + */ + private static function queueForRetry(array $payload, string $error): void + { + try { + require_once dirname(__DIR__) . '/helpers/Database.php'; + $conn = Database::getConnection(); + $stmt = $conn->prepare( + "INSERT INTO notification_retry_queue (payload, last_error) VALUES (?, ?)" + ); + $payloadJson = json_encode($payload); + $stmt->bind_param("ss", $payloadJson, $error); + $stmt->execute(); + $stmt->close(); + } catch (Throwable $e) { + error_log('NotificationHelper: failed to queue notification for retry: ' . $e->getMessage()); + } + } + + private static function fire(array $payload): void + { + $webhookUrl = $GLOBALS['config']['MATRIX_WEBHOOK_URL'] ?? null; + if (empty($webhookUrl)) { + return; + } + + $result = self::attemptDelivery($webhookUrl, $payload); + if ($result['success']) { + return; + } + + $id = $payload['ticket_id'] ?? '?'; + error_log("Matrix webhook failed for ticket #{$id}: {$result['error']}"); + self::queueForRetry($payload, $result['error']); } private static function notifyUsers(): array diff --git a/migrations/007_notification_retry_queue.sql b/migrations/007_notification_retry_queue.sql new file mode 100644 index 0000000..fa995b8 --- /dev/null +++ b/migrations/007_notification_retry_queue.sql @@ -0,0 +1,20 @@ +-- Queue for Matrix webhook notifications that failed to send (#78). +-- +-- NotificationHelper::fire() previously logged a failed webhook post via +-- error_log() only, with no retry and no persistent record — once a +-- notification failed, it was gone. Failed payloads are now queued here and +-- retried by cron/retry_failed_notifications.php with exponential backoff. +-- +-- Safe to re-run. + +CREATE TABLE IF NOT EXISTS `notification_retry_queue` ( + `retry_id` int(11) NOT NULL AUTO_INCREMENT, + `payload` longtext CHARACTER SET utf8mb4 COLLATE utf8mb4_bin NOT NULL CHECK (json_valid(`payload`)), + `attempts` int(11) NOT NULL DEFAULT 0, + `max_attempts` int(11) NOT NULL DEFAULT 6, + `next_attempt_at` timestamp NULL DEFAULT current_timestamp(), + `last_error` varchar(500) DEFAULT NULL, + `created_at` timestamp NULL DEFAULT current_timestamp(), + PRIMARY KEY (`retry_id`), + KEY `idx_next_attempt` (`next_attempt_at`) +) ENGINE=InnoDB DEFAULT CHARSET=utf8mb4 COLLATE=utf8mb4_general_ci;