fix/164-health-and-logging-resilience #167

Merged
myrmidex merged 4 commits from fix/164-health-and-logging-resilience into release/v1.4.3 2026-09-26 14:31:46 +02:00
8 changed files with 300 additions and 20 deletions

View file

@ -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

View file

@ -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

View file

@ -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:

View file

@ -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' => [
'context' => $this->buildContext($event),
]);
ExceptionLogged::dispatch($log);
} 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<string, mixed>
*/
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,
],
]);
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());
}
];
}
}

View file

@ -0,0 +1,23 @@
<?php
namespace App\Listeners;
use Illuminate\Foundation\Events\DiagnosingHealth;
use Illuminate\Support\Facades\DB;
use RuntimeException;
use Throwable;
class VerifyDatabaseIsReachable
{
/**
* A container whose database is unreachable is not healthy, however well it serves /up.
*/
public function handle(DiagnosingHealth $event): void
{
try {
DB::connection()->select('select 1');
} catch (Throwable $e) {
throw new RuntimeException('The database is not reachable: '.$e->getMessage(), previous: $e);
}
}
}

View file

@ -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],
];
}

View file

@ -0,0 +1,41 @@
<?php
namespace Tests\Feature;
use App\Listeners\VerifyDatabaseIsReachable;
use Illuminate\Foundation\Events\DiagnosingHealth;
use Illuminate\Support\Facades\DB;
use RuntimeException;
use Tests\TestCase;
class HealthEndpointTest extends TestCase
{
public function test_up_returns_ok_when_the_database_is_reachable(): void
{
$this->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);
}
}

View file

@ -0,0 +1,157 @@
<?php
namespace Tests\Unit\Listeners;
use App\Enums\LogLevelEnum;
use App\Events\ExceptionOccurred;
use App\Listeners\LogExceptionToDatabase;
use App\Models\Log;
use Illuminate\Foundation\Testing\RefreshDatabase;
use Illuminate\Support\Facades\Log as Logger;
use PHPUnit\Framework\Attributes\DataProvider;
use RuntimeException;
use Tests\TestCase;
class LogExceptionToDatabaseTest extends TestCase
{
use RefreshDatabase;
public function test_it_persists_the_exception_to_the_database(): void
{
$listener = app(LogExceptionToDatabase::class);
$listener->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<string, array{LogLevelEnum, string}>
*/
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');
});
}
}