diff --git a/CHANGELOG.md b/CHANGELOG.md index f1f71a7d..a9645f02 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -2,6 +2,17 @@ # Changelog All notable changes to this project will be documented in this file. +## [1.4.3] - 2026-09-26 + +### Fixed + +- Fix the container reporting itself healthy while its database was unreachable (#164) + - The `/up` health check returned 200 without touching the database. When the database container went missing, the container stayed healthy for 37 hours while every page returned a 500, so nothing alerted and nothing restarted. The health check now fails when the database cannot be reached. +- Fix exceptions being lost when the database is the thing that failed (#164) + - Exceptions were only ever written to the `logs` table, so a database outage discarded the very errors needed to diagnose it. They now fall back to the configured log channel, preserving the original exception rather than only the failed insert. +- Fix the container starting up without a database and never recovering (#164) + - The startup script waited 60 seconds for the database and then continued regardless, running migrations against an unreachable server and starting an unsupervised queue worker. The worker died at boot and stayed dead, so publish jobs accumulated unconsumed and the Articles page "Refresh" button silently did nothing. The container now exits so the restart policy retries, migration failures are no longer swallowed, and a worker that dies is restarted. + ## [1.4.2] - 2026-08-16 ### Fixed diff --git a/Dockerfile b/Dockerfile index 9ce1a488..9ffd5eef 100644 --- a/Dockerfile +++ b/Dockerfile @@ -67,7 +67,8 @@ EOF EXPOSE 8000 # Health check -HEALTHCHECK --interval=30s --timeout=3s --start-period=5s --retries=3 \ +# start-period must outlast the startup script's 60s database wait. +HEALTHCHECK --interval=30s --timeout=3s --start-period=75s --retries=3 \ CMD curl -f http://localhost:8000/up || exit 1 # Create startup script for production @@ -77,32 +78,44 @@ set -e # Wait for database to be ready echo "Waiting for database..." +db_ready=0 for i in $(seq 1 30); do if mysqladmin ping -h "$DB_HOST" -u "$DB_USERNAME" -p"$DB_PASSWORD" --silent 2>/dev/null; then echo "Database is ready!" + db_ready=1 break fi echo "Waiting for database... ($i/30)" sleep 2 done +if [ "$db_ready" -ne 1 ]; then + echo "Database unreachable at ${DB_HOST} after 60s; exiting so the restart policy retries." >&2 + exit 1 +fi + # Cache config with runtime env vars echo "Caching configuration..." php artisan config:cache -# Run migrations +# Run migrations. A partial schema is worse than a container that refuses to start. echo "Running migrations..." -php artisan migrate --force || echo "Migrations failed or already up-to-date" +php artisan migrate --force # Run seeders (idempotent - uses updateOrInsert) echo "Running seeders..." -php artisan db:seed --force || echo "Seeders failed or already run" +php artisan db:seed --force -# Start Horizon in the background -php artisan horizon & +# Restart a worker that dies instead of leaving the queue unconsumed. +supervise() { + while true; do + "$@" || echo "[supervisor] '$*' exited with $?; restarting in 5s." >&2 + sleep 5 + done +} -# Start the scheduler in the background -php artisan schedule:work & +supervise php artisan horizon & +supervise php artisan schedule:work & # Start FrankenPHP exec frankenphp run --config /etc/caddy/Caddyfile diff --git a/README.md b/README.md index 8c2672f0..b65c9153 100644 --- a/README.md +++ b/README.md @@ -71,7 +71,7 @@ ### docker-compose.yml ```yaml services: app: - image: forge.lvl0.xyz/lvl0/fedi-feed-router:v1.4.1 + image: forge.lvl0.xyz/lvl0/fedi-feed-router:v1.4.3 container_name: ffr_app restart: always ports: diff --git a/app/Listeners/LogExceptionToDatabase.php b/app/Listeners/LogExceptionToDatabase.php index 599e251f..d471424f 100644 --- a/app/Listeners/LogExceptionToDatabase.php +++ b/app/Listeners/LogExceptionToDatabase.php @@ -5,6 +5,8 @@ use App\Events\ExceptionLogged; use App\Events\ExceptionOccurred; use App\Models\Log; +use Illuminate\Support\Facades\Log as Logger; +use Throwable; class LogExceptionToDatabase { @@ -19,20 +21,51 @@ public function handle(ExceptionOccurred $event): void $log = Log::create([ 'level' => $event->level, 'message' => $message, - 'context' => [ - 'exception_class' => get_class($event->exception), - 'file' => $event->exception->getFile(), - 'line' => $event->exception->getLine(), - 'trace' => $event->exception->getTraceAsString(), - ...$event->context, - ], + 'context' => $this->buildContext($event), ]); ExceptionLogged::dispatch($log); - } catch (\Exception $e) { - // Prevent infinite recursion by not logging this exception - // Optionally log to file or other non-database destination - error_log('Failed to log exception to database: '.$e->getMessage()); + } catch (Throwable $e) { + $this->logToFallback($event, $e); } } + + /** + * The database is the thing that failed, so this must not touch it. + */ + private function logToFallback(ExceptionOccurred $event, Throwable $storageFailure): void + { + $context = [ + ...$this->buildContext($event), + 'storage_failure' => $storageFailure->getMessage(), + ]; + + try { + Logger::log($event->level->value, $event->message, $context); + } catch (Throwable $loggerFailure) { + error_log(sprintf( + '%s: %s in %s:%d (database and log channel both unavailable: %s / %s)', + get_class($event->exception), + $event->message, + $event->exception->getFile(), + $event->exception->getLine(), + $storageFailure->getMessage(), + $loggerFailure->getMessage(), + )); + } + } + + /** + * @return array + */ + private function buildContext(ExceptionOccurred $event): array + { + return [ + 'exception_class' => get_class($event->exception), + 'file' => $event->exception->getFile(), + 'line' => $event->exception->getLine(), + 'trace' => $event->exception->getTraceAsString(), + ...$event->context, + ]; + } } diff --git a/app/Listeners/VerifyDatabaseIsReachable.php b/app/Listeners/VerifyDatabaseIsReachable.php new file mode 100644 index 00000000..2522072d --- /dev/null +++ b/app/Listeners/VerifyDatabaseIsReachable.php @@ -0,0 +1,23 @@ +select('select 1'); + } catch (Throwable $e) { + throw new RuntimeException('The database is not reachable: '.$e->getMessage(), previous: $e); + } + } +} diff --git a/tests/Feature/EventListenerRegistrationTest.php b/tests/Feature/EventListenerRegistrationTest.php index a6fda0dc..f5fbac1e 100644 --- a/tests/Feature/EventListenerRegistrationTest.php +++ b/tests/Feature/EventListenerRegistrationTest.php @@ -9,6 +9,7 @@ use App\Events\RouteActivated; use App\Events\RouteArticleApproved; use Illuminate\Contracts\Debug\ExceptionHandler; +use Illuminate\Foundation\Events\DiagnosingHealth; use Illuminate\Support\Facades\Event; use PHPUnit\Framework\Attributes\DataProvider; use RuntimeException; @@ -28,6 +29,7 @@ public static function eventProvider(): array 'NewArticleFetched' => [NewArticleFetched::class], 'RouteActivated' => [RouteActivated::class], 'RouteArticleApproved' => [RouteArticleApproved::class], + 'DiagnosingHealth' => [DiagnosingHealth::class], ]; } diff --git a/tests/Feature/HealthEndpointTest.php b/tests/Feature/HealthEndpointTest.php new file mode 100644 index 00000000..a13f13e5 --- /dev/null +++ b/tests/Feature/HealthEndpointTest.php @@ -0,0 +1,41 @@ +get('/up')->assertOk(); + } + + public function test_up_fails_when_the_database_is_unreachable(): void + { + DB::shouldReceive('connection')->andThrow(new RuntimeException('getaddrinfo for db failed')); + + $this->get('/up')->assertServerError(); + } + + public function test_the_listener_throws_when_the_connection_fails(): void + { + DB::shouldReceive('connection')->andThrow(new RuntimeException('getaddrinfo for db failed')); + + $this->expectException(RuntimeException::class); + $this->expectExceptionMessage('The database is not reachable'); + + app(VerifyDatabaseIsReachable::class)->handle(new DiagnosingHealth); + } + + public function test_the_listener_passes_when_the_connection_works(): void + { + app(VerifyDatabaseIsReachable::class)->handle(new DiagnosingHealth); + + $this->addToAssertionCount(1); + } +} diff --git a/tests/Unit/Listeners/LogExceptionToDatabaseTest.php b/tests/Unit/Listeners/LogExceptionToDatabaseTest.php new file mode 100644 index 00000000..db17cfb9 --- /dev/null +++ b/tests/Unit/Listeners/LogExceptionToDatabaseTest.php @@ -0,0 +1,157 @@ +handle(new ExceptionOccurred( + new RuntimeException('boom'), + LogLevelEnum::ERROR, + 'boom', + )); + + $this->assertDatabaseHas('logs', [ + 'level' => 'error', + 'message' => 'boom', + ]); + } + + public function test_it_logs_the_original_exception_to_the_fallback_when_the_database_fails(): void + { + $exception = new RuntimeException('the original failure'); + + Logger::shouldReceive('log')->once()->withArgs( + function (string $level, string $message, array $context) use ($exception): bool { + return $level === 'error' + && $message === 'the original failure' + && $context['exception_class'] === RuntimeException::class + && $context['line'] === $exception->getLine() + && str_contains($context['storage_failure'], 'no such table'); + } + ); + + $this->failTheLogsTable(); + + app(LogExceptionToDatabase::class)->handle(new ExceptionOccurred( + $exception, + LogLevelEnum::ERROR, + 'the original failure', + )); + + $this->addToAssertionCount(1); + } + + public function test_it_preserves_the_event_context_in_the_fallback(): void + { + Logger::shouldReceive('log')->once()->withArgs( + fn (string $level, string $message, array $context): bool => $context['article_id'] === 42 + ); + + $this->failTheLogsTable(); + + app(LogExceptionToDatabase::class)->handle(new ExceptionOccurred( + new RuntimeException('boom'), + LogLevelEnum::ERROR, + 'boom', + ['article_id' => 42], + )); + + $this->addToAssertionCount(1); + } + + public function test_it_does_not_truncate_the_message_in_the_fallback(): void + { + $message = str_repeat('a', 300); + + Logger::shouldReceive('log')->once()->withArgs( + fn (string $level, string $logged, array $context): bool => $logged === $message + ); + + $this->failTheLogsTable(); + + app(LogExceptionToDatabase::class)->handle(new ExceptionOccurred( + new RuntimeException($message), + LogLevelEnum::ERROR, + $message, + )); + + $this->addToAssertionCount(1); + } + + public function test_it_swallows_a_failing_fallback_logger(): void + { + Logger::shouldReceive('log')->once()->andThrow(new RuntimeException('logger is down too')); + + $this->failTheLogsTable(); + + app(LogExceptionToDatabase::class)->handle(new ExceptionOccurred( + new RuntimeException('boom'), + LogLevelEnum::ERROR, + 'boom', + )); + + $this->addToAssertionCount(1); + } + + /** + * @return array + */ + public static function levelProvider(): array + { + return [ + 'debug' => [LogLevelEnum::DEBUG, 'debug'], + 'info' => [LogLevelEnum::INFO, 'info'], + 'warning' => [LogLevelEnum::WARNING, 'warning'], + 'error' => [LogLevelEnum::ERROR, 'error'], + 'critical' => [LogLevelEnum::CRITICAL, 'critical'], + ]; + } + + #[DataProvider('levelProvider')] + public function test_it_maps_every_level_to_a_psr_log_level(LogLevelEnum $level, string $expected): void + { + Logger::shouldReceive('log')->once()->withArgs( + fn (string $logged, string $message, array $context): bool => $logged === $expected + ); + + $this->failTheLogsTable(); + + app(LogExceptionToDatabase::class)->handle(new ExceptionOccurred( + new RuntimeException('boom'), + $level, + 'boom', + )); + + $this->addToAssertionCount(1); + } + + protected function tearDown(): void + { + Log::flushEventListeners(); + + parent::tearDown(); + } + + private function failTheLogsTable(): void + { + Log::creating(function (): void { + throw new RuntimeException('SQLSTATE[HY000]: no such table: logs'); + }); + } +}