Mastering PHP Observability: Structured Logs, Traces, and Actionable Alerts
A production incident rarely begins with a useful error message. More often, it begins with a vague symptom: latency climbed, customers retried, and several services emitted unrelated-looking failures. The difference between minutes and hours of diagnosis is whether logs, metrics, traces, and alerts describe the same request in the same language.
This tutorial builds that shared language for a PHP 8.3 HTTP service. The finished system emits JSON logs with correlation identifiers, exposes bounded-cardinality Prometheus metrics, propagates W3C trace context, exports OTLP traces, and routes an actionable error-rate alert through Alertmanager.
Architecture and trade-offs
The request path is Nginx to PHP-FPM. PHP writes structured logs to standard error, maintains process-shared counters in a lock-protected state file, and sends root spans to an OpenTelemetry Collector over OTLP/HTTP. Prometheus scrapes the application’s /metrics endpoint and evaluates alert rules. Alertmanager forwards notifications to a separate local sink that logs what it receives.
- Logs preserve detailed events but are expensive to search at high volume.
- Metrics make trends and alerts cheap, provided labels have bounded cardinality.
- Traces connect operations across services, but synchronous exporting adds latency.
- Correlation IDs give support teams a stable lookup key even when tracing is sampled.
The file-backed metric store is deliberately small and dependency-free. It works across PHP-FPM workers in one container, unlike ordinary PHP globals, but locking every request is not suitable for extreme traffic. At higher throughput, replace it with an in-process OpenTelemetry or Prometheus client that supports PHP’s multiprocess model, or emit metrics to a local collector.
Prerequisites and project layout
You need Docker Engine with Compose v2 and curl on the host. The published ports are 8080 for the application, 9090 for Prometheus, and 9093 for Alertmanager. Container-only telemetry traffic uses ports 4318 and 8081.
php-observability/
├── Dockerfile
├── compose.yaml
├── php/
│ └── zz-observability.conf
├── public/
│ └── index.php
├── src/
│ └── Observability.php
├── alert/
│ └── index.php
├── nginx/
│ └── default.conf
├── otel/
│ └── collector.yaml
├── prometheus/
│ ├── prometheus.yaml
│ └── alerts.yaml
└── alertmanager/
└── alertmanager.yamlBuild the PHP runtime and service network
The image installs PHP’s cURL extension for bounded OTLP requests. The FPM configuration forwards worker output to the container log. Runtime metric state lives under /var/run/app, owned by the unprivileged FPM user.
# Dockerfile
FROM php:8.3-fpm-alpine
RUN apk add --no-cache curl-dev \
&& docker-php-ext-install curl \
&& mkdir -p /var/run/app \
&& chown www-data:www-data /var/run/app
WORKDIR /app
COPY php/zz-observability.conf /usr/local/etc/php-fpm.d/zz-observability.conf
COPY public/ public/
COPY src/ src/
COPY alert/ alert/
CMD ["php-fpm", "-F"]; php/zz-observability.conf
[www]
catch_workers_output = yes
decorate_workers_output = no
clear_env = no
request_terminate_timeout = 10s# compose.yaml
services:
app:
build: .
environment:
OTEL_EXPORTER_OTLP_ENDPOINT: http://otel:4318/v1/traces
SERVICE_NAME: catalog-api
expose: ["9000"]
depends_on: [otel]
web:
image: nginx:1.27-alpine
ports: ["127.0.0.1:8080:80"]
volumes:
- ./nginx/default.conf:/etc/nginx/conf.d/default.conf:ro
depends_on: [app]
otel:
image: otel/opentelemetry-collector-contrib:0.104.0
command: ["--config=/etc/otelcol/config.yaml"]
volumes:
- ./otel/collector.yaml:/etc/otelcol/config.yaml:ro
prometheus:
image: prom/prometheus:v2.53.0
command: ["--config.file=/etc/prometheus/prometheus.yaml"]
ports: ["127.0.0.1:9090:9090"]
volumes:
- ./prometheus:/etc/prometheus:ro
depends_on: [web, alertmanager]
alertmanager:
image: prom/alertmanager:v0.27.0
command: ["--config.file=/etc/alertmanager/alertmanager.yaml"]
ports: ["127.0.0.1:9093:9093"]
volumes:
- ./alertmanager:/etc/alertmanager:ro
depends_on: [alert-sink]
alert-sink:
build: .
command: ["php", "-S", "0.0.0.0:8081", "-t", "/app/alert"]
expose: ["8081"]# nginx/default.conf
server {
listen 80;
server_name _;
location / {
include fastcgi_params;
fastcgi_param SCRIPT_FILENAME /app/public/index.php;
fastcgi_pass app:9000;
fastcgi_connect_timeout 1s;
fastcgi_read_timeout 9s;
fastcgi_send_timeout 2s;
}
}These timeouts are distinct: a connection timeout does not bound response reads. Nginx’s read timeout remains below PHP’s ten-second termination budget, preventing abandoned requests from occupying upstream capacity indefinitely.
Implement the observability boundary
The following class validates incoming identifiers instead of trusting arbitrary header content. Routes are supplied from a fixed set, preventing customer IDs or raw URLs from becoming unbounded metric labels. State updates hold an exclusive lock only while reading and rewriting a tiny JSON document.
<?php
// src/Observability.php
declare(strict_types=1);
final class Observability
{
private const METRICS_FILE = '/var/run/app/metrics.json';
public readonly string $correlationId;
public readonly string $traceId;
public readonly string $spanId;
private string $parentSpanId = '';
private string $traceFlags = '01';
private float $startedAt;
private int $startedMono;
private bool $sampled = true;
public function __construct(
private readonly string $method,
private readonly string $route
) {
$this->startedAt = microtime(true);
$this->startedMono = hrtime(true);
$candidate = $_SERVER['HTTP_X_CORRELATION_ID'] ?? '';
$this->correlationId = preg_match('/^[A-Za-z0-9_-]{8,64}$/D', $candidate)
? $candidate
: bin2hex(random_bytes(16));
$incoming = $_SERVER['HTTP_TRACEPARENT'] ?? '';
if (preg_match(
'/^00-([0-9a-f]{32})-([0-9a-f]{16})-([0-9a-f]{2})$/D',
$incoming,
$match
) && $match[1] !== str_repeat('0', 32)
&& $match[2] !== str_repeat('0', 16)) {
$this->traceId = $match[1];
$this->parentSpanId = $match[2];
$this->traceFlags = $match[3];
$this->sampled = (hexdec($match[3]) & 1) === 1;
} else {
$this->traceId = bin2hex(random_bytes(16));
}
$this->spanId = bin2hex(random_bytes(8));
}
public function log(string $level, string $message, array $context = []): void
{
$record = [
'timestamp' => gmdate('c'),
'level' => $level,
'service' => getenv('SERVICE_NAME') ?: 'catalog-api',
'message' => $message,
'correlation_id' => $this->correlationId,
'trace_id' => $this->traceId,
'span_id' => $this->spanId,
'context' => $context,
];
file_put_contents(
'php://stderr',
json_encode($record, JSON_THROW_ON_ERROR | JSON_UNESCAPED_SLASHES) . "\n"
);
}
public function finish(int $status): void
{
$seconds = (hrtime(true) - $this->startedMono) / 1_000_000_000;
$this->recordMetric($status, $seconds);
$this->log('info', 'request.completed', [
'method' => $this->method,
'route' => $this->route,
'status' => $status,
'duration_ms' => round($seconds * 1000, 2),
]);
if ($this->sampled) {
$this->exportTrace($status);
}
}
private function recordMetric(int $status, float $seconds): void
{
$handle = fopen(self::METRICS_FILE, 'c+');
if ($handle === false || !flock($handle, LOCK_EX)) {
$this->log('error', 'metrics.lock_failed');
return;
}
$raw = stream_get_contents($handle);
$state = $raw === '' ? [] : json_decode($raw, true, flags: JSON_THROW_ON_ERROR);
$key = implode('|', [$this->method, $this->route, (string) $status]);
$state[$key]['count'] = ($state[$key]['count'] ?? 0) + 1;
$state[$key]['sum'] = ($state[$key]['sum'] ?? 0.0) + $seconds;
rewind($handle);
ftruncate($handle, 0);
fwrite($handle, json_encode($state, JSON_THROW_ON_ERROR));
fflush($handle);
flock($handle, LOCK_UN);
fclose($handle);
}
private function exportTrace(int $status): void
{
$attributes = [
['key' => 'http.request.method', 'value' => ['stringValue' => $this->method]],
['key' => 'http.route', 'value' => ['stringValue' => $this->route]],
['key' => 'http.response.status_code', 'value' => ['intValue' => (string) $status]],
['key' => 'app.correlation_id', 'value' => ['stringValue' => $this->correlationId]],
];
$span = [
'traceId' => $this->traceId,
'spanId' => $this->spanId,
'name' => $this->method . ' ' . $this->route,
'kind' => 2,
'startTimeUnixNano' => sprintf('%.0f', $this->startedAt * 1_000_000_000),
'endTimeUnixNano' => sprintf('%.0f', microtime(true) * 1_000_000_000),
'attributes' => $attributes,
'status' => ['code' => $status >= 500 ? 2 : 1],
];
if ($this->parentSpanId !== '') {
$span['parentSpanId'] = $this->parentSpanId;
}
$payload = ['resourceSpans' => [[
'resource' => ['attributes' => [[
'key' => 'service.name',
'value' => ['stringValue' => getenv('SERVICE_NAME') ?: 'catalog-api'],
]]],
'scopeSpans' => [[
'scope' => ['name' => 'catalog-api.manual'],
'spans' => [$span],
]],
]]];
$curl = curl_init(getenv('OTEL_EXPORTER_OTLP_ENDPOINT'));
curl_setopt_array($curl, [
CURLOPT_POST => true,
CURLOPT_POSTFIELDS => json_encode($payload, JSON_THROW_ON_ERROR),
CURLOPT_HTTPHEADER => ['Content-Type: application/json'],
CURLOPT_RETURNTRANSFER => true,
CURLOPT_CONNECTTIMEOUT_MS => 50,
CURLOPT_TIMEOUT_MS => 200,
]);
curl_exec($curl);
$code = curl_getinfo($curl, CURLINFO_RESPONSE_CODE);
$error = curl_error($curl);
curl_close($curl);
if ($code < 200 || $code >= 300) {
$this->log('warning', 'trace.export_failed', [
'http_status' => $code,
'error' => $error,
]);
}
}
public static function renderMetrics(): string
{
$handle = @fopen(self::METRICS_FILE, 'r');
$state = [];
if ($handle !== false && flock($handle, LOCK_SH)) {
$raw = stream_get_contents($handle);
$state = $raw === '' ? [] : json_decode($raw, true, flags: JSON_THROW_ON_ERROR);
flock($handle, LOCK_UN);
fclose($handle);
}
$lines = [
'# HELP app_http_requests_total Completed HTTP requests.',
'# TYPE app_http_requests_total counter',
'# HELP app_http_request_duration_seconds Request duration.',
'# TYPE app_http_request_duration_seconds summary',
];
foreach ($state as $key => $value) {
[$method, $route, $status] = explode('|', $key, 3);
$labels = sprintf(
'method="%s",route="%s",status="%s"',
$method,
$route,
$status
);
$lines[] = "app_http_requests_total{{$labels}} {$value['count']}";
$lines[] = "app_http_request_duration_seconds_sum{{$labels}} {$value['sum']}";
$lines[] = "app_http_request_duration_seconds_count{{$labels}} {$value['count']}";
}
return implode("\n", $lines) . "\n";
}
}Connect request handling to the telemetry
The application normalizes every request to one of four route labels. It returns both identifiers to callers, making support tickets immediately searchable. Exceptions become safe client responses while detailed failure context remains in logs.
<?php
// public/index.php
declare(strict_types=1);
require __DIR__ . '/../src/Observability.php';
$path = parse_url($_SERVER['REQUEST_URI'] ?? '/', PHP_URL_PATH);
$route = match ($path) {
'/health' => '/health',
'/metrics' => '/metrics',
'/work' => '/work',
default => '/not-found',
};
if ($route === '/metrics') {
header('Content-Type: text/plain; version=0.0.4');
echo Observability::renderMetrics();
exit;
}
$obs = new Observability($_SERVER['REQUEST_METHOD'] ?? 'GET', $route);
header('X-Correlation-ID: ' . $obs->correlationId);
header('traceparent: 00-' . $obs->traceId . '-' . $obs->spanId . '-01');
header('Content-Type: application/json');
$status = 200;
try {
if ($route === '/health') {
echo json_encode(['status' => 'ok'], JSON_THROW_ON_ERROR);
} elseif ($route === '/work') {
usleep(25_000);
if (($_GET['fail'] ?? '') === '1') {
throw new RuntimeException('Synthetic dependency failure');
}
echo json_encode(['result' => 'completed'], JSON_THROW_ON_ERROR);
} else {
$status = 404;
http_response_code($status);
echo json_encode(['error' => 'not_found'], JSON_THROW_ON_ERROR);
}
} catch (Throwable $error) {
$status = 500;
http_response_code($status);
$obs->log('error', 'request.failed', [
'exception' => $error::class,
'error' => $error->getMessage(),
]);
echo json_encode([
'error' => 'internal_error',
'correlation_id' => $obs->correlationId,
], JSON_THROW_ON_ERROR);
} finally {
$obs->finish($status);
}Collect traces and create an actionable alert
The Collector’s debug exporter prints complete spans for verification. Replace it in production with a supported trace backend exporter. Prometheus alerts only when traffic exists, avoiding a misleading percentage derived from one isolated failure.
# otel/collector.yaml
receivers:
otlp:
protocols:
http:
endpoint: 0.0.0.0:4318
exporters:
debug:
verbosity: detailed
service:
pipelines:
traces:
receivers: [otlp]
exporters: [debug]
# prometheus/prometheus.yaml
global:
scrape_interval: 15s
evaluation_interval: 15s
rule_files:
- /etc/prometheus/alerts.yaml
alerting:
alertmanagers:
- static_configs:
- targets: ["alertmanager:9093"]
scrape_configs:
- job_name: catalog-api
metrics_path: /metrics
static_configs:
- targets: ["web:80"]
# prometheus/alerts.yaml
groups:
- name: catalog-api
rules:
- alert: CatalogApiHighErrorRate
expr: |
(
sum(rate(app_http_requests_total{status=~"5.."}[5m]))
/
clamp_min(sum(rate(app_http_requests_total[5m])), 0.001)
) > 0.05
and
sum(rate(app_http_requests_total[5m])) > 0.01
for: 1m
labels:
severity: page
service: catalog-api
annotations:
summary: "catalog-api is returning more than 5% server errors"
action: "Check recent deployments, dependency health, and traces for failing requests."
# alertmanager/alertmanager.yaml
route:
receiver: local-observability-sink
group_by: [alertname, service]
group_wait: 10s
group_interval: 5m
repeat_interval: 4h
receivers:
- name: local-observability-sink
webhook_configs:
- url: http://alert-sink:8081/
send_resolved: trueThe isolated sink proves that Alertmanager actually delivers notifications. It extracts only bounded fields and writes the original alert state plus operational annotations to standard error.
<?php
// alert/index.php
declare(strict_types=1);
$body = file_get_contents('php://input', false, null, 0, 1_048_576);
$payload = json_decode($body ?: '{}', true);
foreach (($payload['alerts'] ?? []) as $alert) {
$record = [
'timestamp' => gmdate('c'),
'level' => 'warning',
'service' => 'alert-sink',
'message' => 'alert.notification',
'status' => $alert['status'] ?? 'unknown',
'alertname' => $alert['labels']['alertname'] ?? 'unknown',
'target_service' => $alert['labels']['service'] ?? 'unknown',
'severity' => $alert['labels']['severity'] ?? 'unknown',
'summary' => $alert['annotations']['summary'] ?? '',
'action' => $alert['annotations']['action'] ?? '',
];
file_put_contents('php://stderr', json_encode($record, JSON_THROW_ON_ERROR) . "\n");
}
http_response_code(204);Test the complete signal path
Build and start the stack from the project directory. These commands create only project-scoped containers and volumes; they do not alter host firewall rules or system configuration.
docker compose config
docker compose up --build -d
curl -i http://127.0.0.1:8080/health
curl -i -H 'X-Correlation-ID: support-case-8472' \
http://127.0.0.1:8080/work
curl -i 'http://127.0.0.1:8080/work?fail=1'
curl -sS http://127.0.0.1:8080/metrics
docker compose logs app
docker compose logs otelThe successful request should return matching X-Correlation-ID and traceparent headers. Application logs should contain the same correlation ID, trace ID, and span ID. The Collector log should show a server span with that trace ID.
To exercise the alert, send enough traffic for the five-minute rate to be meaningful, then allow the one-minute pending period and evaluation interval to pass:
for request_number in $(seq 1 40); do
if [ $((request_number % 4)) -eq 0 ]; then
curl -sS -o /dev/null 'http://127.0.0.1:8080/work?fail=1'
else
curl -sS -o /dev/null http://127.0.0.1:8080/work
fi
done
docker compose logs -f alert-sinkThe sink should eventually log CatalogApiHighErrorRate with its summary and response action. Prometheus at http://127.0.0.1:9090 shows the expression, while Alertmanager at http://127.0.0.1:9093 shows delivery state.
Security, performance, and deployment
Keep Prometheus, Alertmanager, and Collector ingestion on private networks. The Compose bindings use loopback for administrative interfaces; on a remote host, access them through an authenticated tunnel or reverse proxy. Do not expose OTLP ingestion or the demonstration sink to the internet. A host firewall should allow only the application’s intended public TLS port.
Correlation headers are untrusted input, so validation and length limits are essential. Never attach access tokens, request bodies, email addresses, account IDs, exception arguments, or raw URLs to metric labels. Apply log redaction before records leave the process, and protect telemetry storage with the same seriousness as application data.
Synchronous trace export is intentionally visible here, but its 200-millisecond budget can still affect tail latency when the Collector is unhealthy. A production deployment should use a maintained OpenTelemetry PHP SDK with batching, bounded queues, sampling, and a local Collector. Telemetry failure must degrade observability, not application availability.
Replace the local alert sink with an independently hosted paging integration. Route warnings and pages differently, include a tested runbook, and ensure resolved notifications reach the same destination. Deploy alert rules before risky application changes so the monitoring path already exists when it is needed.
Common failures
- Metrics stay empty: verify that PHP runs as
www-dataand can write/var/run/app. - Prometheus reports the target down: check the internal target
web:80, not the host mapping127.0.0.1:8080. - Traces disappear: inspect
trace.export_failed, Collector health, and the exact/v1/tracesendpoint. - An alert never fires: evaluate its expression in Prometheus, confirm enough traffic exists, and remember that
for: 1mbegins only after the expression first becomes true. - Metrics explode in size: look for raw paths, identifiers, error messages, or other unbounded label values.
Final verification checklist
- The application returns validated correlation and trace headers.
- JSON logs connect failures to correlation IDs and trace IDs.
- Metrics aggregate across FPM workers and expose only bounded labels.
- OTLP requests have separate connection and total timeouts.
- The Collector receives spans without blocking application success.
- Prometheus evaluates a traffic-gated error-rate alert.
- Alertmanager delivers firing and resolved notifications.
- Administrative ports remain private or authenticated.
Good observability is not the volume of telemetry a service produces. It is the speed with which one signal leads to the next: an alert identifies the service, a metric establishes the shape of the failure, a trace exposes the slow or broken path, and a correlation ID finds the decisive log. Build that chain deliberately, and production failures become bounded investigations instead of archaeological expeditions.
