Example: logging and errors
Three endpoints that show what is logged and what the client sees, in development and in production.
Since 3.6.0
The presenter masks Authorization, Cookie, X-Api-Key and the other secret headers through setMaskedLogHeaders(), so the logger never sees them. With 3.5.0 remove that setup line and mask in the logger. 400, 401 and 429 are not logged in 3.x. See Logging.
| Request | Development | Production |
|---|---|---|
/api/v1/ping | 200, logged | 200, logged |
/api/v1/fail?kind=crash | 500 with detail, in Tracy log | 500 without detail |
/api/v1/fail?kind=maintenance | 503 from AppErrorHandler | 503 |
/api/v1/fail | 400 with detail, not logged | 400 without detail |
/api/v1/broken | 500, output does not match | 200, not checked |
The services
yaml
application:
mapping:
Api: Tomaj\NetteApi\Presenters\*Presenter
services:
router: App\RouterFactory::create
apiPresenter:
factory: Tomaj\NetteApi\Presenters\ApiPresenter
setup:
# since 3.6.0: the logger gets *** instead of the values of Authorization, Proxy-Authorization,
# Cookie, Set-Cookie and X-Api-Key; pass a list to mask other headers instead
- setMaskedLogHeaders()
# error details and output schema validation are on unless APP_ENV=production
- Tomaj\NetteApi\Output\Configurator\EnvConfigurator('APP_ENV', 'production')
# ApiPresenter uses the one autowired ErrorHandlerInterface, AppErrorHandler wraps the default one
defaultErrorHandler:
factory: Tomaj\NetteApi\Error\DefaultErrorHandler
autowired: false
- App\AppErrorHandler(@defaultErrorHandler)
# with an ApiLoggerInterface service every handled request is logged;
# the logger needs an IpDetectorInterface service for the client IP
- App\FileApiLogger(%appDir%/../log/api.log)
- Tomaj\NetteApi\Misc\IpDetector
apiDecider:
factory: Tomaj\NetteApi\ApiDecider
setup:
- addApi(Tomaj\NetteApi\EndpointIdentifier('GET', 1, 'ping'), App\Api\PingHandler(), Tomaj\NetteApi\Authorization\NoAuthorization())
- addApi(Tomaj\NetteApi\EndpointIdentifier('GET', 1, 'fail'), App\Api\FailHandler(), Tomaj\NetteApi\Authorization\NoAuthorization())
- addApi(Tomaj\NetteApi\EndpointIdentifier('GET', 1, 'broken'), App\Api\BrokenOutputHandler(), Tomaj\NetteApi\Authorization\NoAuthorization())The logger
php
<?php
declare(strict_types=1);
namespace App;
use Tomaj\NetteApi\Logger\ApiLoggerInterface;
/**
* Writes one JSON line per API request.
* The headers arrive as "Name: value" lines; secret values are already *** thanks to setMaskedLogHeaders().
*/
final class FileApiLogger implements ApiLoggerInterface
{
public function __construct(private string $file)
{
}
public function log(
int $responseCode,
string $requestMethod,
string $requestHeader,
string $requestUri,
string $requestIp,
string $requestAgent,
int $responseTime
): bool {
$headers = [];
foreach (explode(PHP_EOL, trim($requestHeader)) as $line) {
[$name, $value] = array_map('trim', explode(':', $line, 2)) + [1 => ''];
$headers[$name] = $value;
}
$line = json_encode([
'code' => $responseCode,
'method' => $requestMethod,
'uri' => $requestUri,
'ip' => $requestIp,
'agent' => $requestAgent,
'time_ms' => $responseTime,
'headers' => $headers,
], JSON_UNESCAPED_SLASHES);
return file_put_contents($this->file, $line . "\n", FILE_APPEND | LOCK_EX) !== false;
}
}The error handler
php
<?php
declare(strict_types=1);
namespace App;
use Throwable;
use Tomaj\NetteApi\Authorization\ApiAuthorizationInterface;
use Tomaj\NetteApi\Error\ErrorHandlerInterface;
use Tomaj\NetteApi\Response\JsonApiResponse;
/**
* Answers MaintenanceException with 503 and leaves everything else to DefaultErrorHandler.
*/
final class AppErrorHandler implements ErrorHandlerInterface
{
public function __construct(private ErrorHandlerInterface $inner)
{
}
public function handle(Throwable $exception, array $params): JsonApiResponse
{
if ($exception instanceof MaintenanceException) {
return new JsonApiResponse(503, ['status' => 'error', 'message' => 'Down for maintenance, try again later']);
}
return $this->inner->handle($exception, $params);
}
public function handleInputParams(array $errors): JsonApiResponse
{
return $this->inner->handleInputParams($errors);
}
public function handleSchema(array $errors, array $params): JsonApiResponse
{
return $this->inner->handleSchema($errors, $params);
}
public function handleAuthorization(ApiAuthorizationInterface $auth, array $params): JsonApiResponse
{
return $this->inner->handleAuthorization($auth, $params);
}
public function handleAuthorizationException(Throwable $exception, array $params): JsonApiResponse
{
return $this->inner->handleAuthorizationException($exception, $params);
}
}The failing handler
php
<?php
declare(strict_types=1);
namespace App\Api;
use App\MaintenanceException;
use RuntimeException;
use Tomaj\NetteApi\Handlers\BaseHandler;
use Tomaj\NetteApi\Params\GetInputParam;
use Tomaj\NetteApi\Response\ResponseInterface;
/**
* Always throws, to show what the error handler does with an exception.
*/
final class FailHandler extends BaseHandler
{
public function params(): array
{
return [
(new GetInputParam('kind'))->setAvailableValues(['crash', 'maintenance'])->setRequired(),
];
}
public function handle(array $params): ResponseInterface
{
if ($params['kind'] === 'maintenance') {
throw new MaintenanceException('Database migration is running');
}
throw new RuntimeException('Database connection refused');
}
}The test
bash
#!/usr/bin/env bash
# End-to-end check: request logging, error responses and how APP_ENV=production changes them.
set -euo pipefail
cd "$(dirname "$0")"
[[ -f vendor/autoload.php ]] || { echo "fail: vendor/ is missing, run composer install first" >&2; exit 1; }
source ../ci/lib.sh
rm -f log/api.log log/exception.log log/error.log
# development: APP_ENV is not set
APP_ENV= serve 8086
DEV="$BASE"
request -H 'Authorization: Bearer top-secret' -H 'Cookie: session=cookie-secret' -H 'X-Trace: visible-value' -A 'e2e/1.0' "$DEV/api/v1/ping"
expect_status 200 "ping"
ok "GET /api/v1/ping works"
grep -qF '"code":200' log/api.log || { echo "fail: log/api.log has no line for the ping" >&2; exit 1; }
grep -qF '"Authorization":"***"' log/api.log || { echo "fail: the Authorization header is not masked" >&2; cat log/api.log >&2; exit 1; }
if grep -qF 'top-secret' log/api.log; then echo "fail: the token leaked into log/api.log" >&2; exit 1; fi
grep -qF '"Cookie":"***"' log/api.log && ! grep -qF 'cookie-secret' log/api.log || { echo "fail: the Cookie header is not masked" >&2; exit 1; }
grep -qF '"X-Trace":"visible-value"' log/api.log || { echo "fail: a header that is not on the list was masked" >&2; exit 1; }
ok "the request is in log/api.log, Authorization and Cookie masked, other headers kept"
request "$DEV/api/v1/fail?kind=crash"
expect_status 500 "exception"
expect_body '"message":"Internal server error"' "exception"
expect_body '"detail":"Database connection refused"' "exception"
[[ -s log/exception.log ]] || { echo "fail: Tracy did not log the exception" >&2; exit 1; }
ok "an exception gives 500 with the detail, Tracy logs it"
request "$DEV/api/v1/fail?kind=maintenance"
expect_status 503 "custom error handler"
expect_body 'Down for maintenance' "custom error handler"
ok "AppErrorHandler turns MaintenanceException into 503"
request "$DEV/api/v1/fail"
expect_status 400 "wrong input"
expect_body '"message":"wrong input","detail":{"kind":["Field is required"]}' "wrong input"
if grep -qF '"code":400' log/api.log; then echo "fail: requests rejected before the handler should not be logged" >&2; exit 1; fi
ok "a missing parameter gives 400 with the detail and is not logged"
request "$DEV/api/v1/broken"
expect_status 500 "output schema"
expect_body '"detail":' "output schema"
ok "a response that breaks its output schema gives 500"
# production: no details and no output schema validation
APP_ENV=production serve 8087
PROD="$BASE"
request "$PROD/api/v1/fail?kind=crash"
expect_status 500 "production exception"
expect_body '{"status":"error","message":"Internal server error"}' "production exception"
ok "with APP_ENV=production the 500 has no detail"
request "$PROD/api/v1/fail"
expect_status 400 "production wrong input"
expect_body '{"status":"error","message":"wrong input"}' "production wrong input"
ok "with APP_ENV=production the 400 has no detail"
request "$PROD/api/v1/broken"
expect_status 200 "production output schema"
expect_body '"count":"three"' "production output schema"
ok "with APP_ENV=production the output schema is not checked"FAQ
How is production switched on?
EnvConfigurator('APP_ENV', 'production') turns details and output checks off when APP_ENV=production. See Outputs.
Where are the headers masked?
In the presenter, by setMaskedLogHeaders() in common.neon. The test sends a token and a cookie and checks that api.log has *** and keeps X-Trace. See Logging.
Why is the 400 not in api.log?
Wrong input returns before the logger in 3.x. See Logging.
Where are the exceptions?
In log/exception.log and Tracy's HTML files, written by DefaultErrorHandler.
Why wrap DefaultErrorHandler instead of extending it?
It is final. See Error handling.