SaneLog

· laravel, monolog, syslog, stack-traces

Laravel stack traces split across multiple syslog lines: why, and how to fix it

UDP syslog splits Laravel stack traces into separate events or fails with "Message too long". Why Monolog does this, and two ways to fix it.

You set up a hosted log service, pointed a UDP syslog channel at it from Laravel, and the first exception arrived like this: one line with the error message, then forty-nine more, each a separate event with its own timestamp, reading #1 /var/www/app/Payments/GatewayClient.php(88): ..., #2 ..., with nginx’s lines from the same moment mixed in between. Search for the error and you find the first line. The rest of the trace is somewhere above it, in pieces.

Or the lines stopped arriving altogether, and PHP’s error log filled up with:

socket_sendto(): unable to write to socket [40]: Message too long

Both problems have the same cause, and it isn’t your log service.

What the UDP handler does

A UDP syslog channel in Laravel is a thin wrapper around Monolog’s SyslogUdpHandler. The stock config/logging.php includes one, named after a hosted service, and a hand-written one looks the same:

'remote-syslog' => [
    'driver' => 'monolog',
    'level' => env('LOG_LEVEL', 'debug'),
    'handler' => SyslogUdpHandler::class,
    'handler_with' => [
        'host' => env('SYSLOG_HOST'),
        'port' => env('SYSLOG_PORT'),
    ],
    'processors' => [PsrLogMessageProcessor::class],
],

Here is the handler’s write() method from Monolog 3:

protected function write(LogRecord $record): void
{
    $lines = $this->splitMessageIntoLines($record->formatted);
    $header = $this->makeCommonSyslogHeader($this->toSyslogPriority($record->level), $record->datetime);

    foreach ($lines as $line) {
        $this->socket->write($line, $header);
    }
}

It splits the formatted entry at every line break and sends each line as its own UDP packet, each with its own syslog header. That is a reasonable choice for UDP, which has no way to mark where a message ends, and it is exactly why a fifty-frame stack trace becomes fifty events. Each packet is a valid syslog message. Nothing in it says “I belong with the line before me”, so the receiving end can’t reliably put them back together, and under load other servers’ lines arrive in between.

The size error comes from the same handler. A UDP packet has a maximum size, 65,023 bytes by default in Monolog, and packets anywhere near that are split into fragments on the way, which many routers simply drop. That is where both “Message too long” errors and silently truncated log lines come from. Newer Monolog versions accept a maxLength to keep packets below the fragmentation point, which stops the drops by cutting long lines short instead.

So UDP syslog straight from PHP gives you a choice between split traces and truncated ones. There are two better routes.

Fix 1: let the server’s syslog daemon do the sending

Log to the local syslog daemon with Laravel’s syslog channel, and have rsyslog forward over TCP with TLS. Laravel logs from multiple servers in one place walks through the whole setup. The part that matters here is the channel:

LOG_CHANNEL=syslog

This channel uses a different Monolog handler. SyslogHandler calls PHP’s syslog() once per entry, with the whole formatted message, line breaks included:

protected function write(LogRecord $record): void
{
    openlog($this->ident, $this->logopts, $this->facility);
    syslog($this->toSyslogPriority($record->level), (string) $record->formatted);
}

rsyslog receives one message. By default it escapes control characters on arrival: each line break becomes the text #012 and each tab #011. The trace stays one message, and because it now contains no raw line breaks, it can travel over TCP without being mistaken for several messages. TLS protects it on the way, and rsyslog’s disk queue holds it through a reconnect.

You also need this. rsyslog’s default maximum message size is 8 KB, and a full Laravel stack trace is often longer. Over the limit, rsyslog cuts the message off without telling you. Add this at the very top of /etc/rsyslog.conf, before any module(load=...) line, and restart rsyslog:

global(maxMessageSize="64k")

At the receiving end, the #012 escapes need turning back into line breaks. In SaneLog, Decode control characters does this and is on by default, so the trace arrives as one event that reads exactly as it did in laravel.log. If you see #012 in your messages with another service, look for an equivalent setting.

You get one more thing for free: the syslog program name is your APP_NAME, so your lines are filed under your application and not under php.

Fix 2: send JSON over HTTPS

If you’d rather not depend on the server’s syslog daemon, or your code runs where there isn’t one, send events over HTTPS. A log event is a JSON object, a batch is one object per line, and a line break inside a JSON string is \n, which survives any transport.

SaneLog’s ingest endpoint takes exactly that, with a source token:

curl -X POST https://app.sanelog.com/ingest \
  -H "Authorization: Bearer <source token>" \
  -H "Content-Type: application/json" \
  -d '{"message":"Charge failed: card_declined\n#0 /var/www/app/Payments/GatewayClient.php(88): ...","level":"err","program":"my-shop","order_id":88231}'

Any top-level key that isn’t message, level, program or a timestamp is stored as a field, so a Laravel context array maps straight onto it. For a Laravel app, the natural shape is a Monolog handler that collects entries during a request and sends them in one compressed batch after the response has gone out. SaneLog’s own Laravel package that does this isn’t released yet. Until it is, HTTPS is the route for scripts, functions and services that already speak it, and the syslog channel is the route for the Laravel app.

When the lines are already split

Some senders you can’t change: a service that prints tracebacks line by line, or a logger that writes one syslog line per stack frame. For those, the receiving end has to recognise a continuation line and attach it to the line that started it. SaneLog’s Merge multi-line entries setting does this: PHP #N frames, Stack trace: lines and indented lines are folded into the event before them, up to 500 lines, and nothing is dropped. It waits about a second after the last line before storing, so a trace that arrives in a burst becomes one event. It is off by default, because merging means guessing, and the two fixes above don’t need it.

Side by side

Route A stack trace arrives as Size limit Transport
UDP syslog from PHP One event per line UDP packet; large ones get dropped UDP, no queue
syslog channel + rsyslog One event 64 KB once raised (8 KB default) TCP + TLS, disk queue
JSON over HTTPS One event 256 KB per message HTTPS, compressed

If you’re moving your logs somewhere new, the one thing not to bring along is the UDP channel. Set LOG_CHANNEL=syslog, raise rsyslog’s limit, let the daemon forward, and the next stack trace is one line you can click.

← all posts