Structured Logs in Laravel (Part 2)
The previous post showed you how to tweak Laravel’s default logging setup to output in json which is a key part of creating structured logs. With structured logs you can move yourself towards a more Observable future by tacking on a bunch of extra stuff to your logs which can then be parsed and acted upon by your various systems.
And Laravel supports this out of the box — it just isn’t called out that obviously in the docs. (It is the ‘contextual information’ section on the Logging doc page. (Or ‘Errors and Logging’ for pre-5.6 docs). Basically, you create an array and pass it as the second argument to your logging call and it gets written out in the ‘extras’ part of the log.
<pre lang="sh">
ubuntu@default:/var/www/tether$ sudo php artisan tinker
Psy Shell v0.9.7 (PHP 7.1.20-1+ubuntu16.04.1+deb.sury.org+1 — cli) by Justin Hileman
>>> use Ramsey\Uuid\Uuid;
>>> $observationId = Uuid::uuid4()->toString();
=> "daed8173-5bd0-4065-9696-85b83f167ead"
>>> $structure = ['id' => $observationId, 'person' => 'abc123', 'client' => 'def456', 'entry' => 'ghi789'];
=> [
"id" => "daed8173-5bd0-4065-9696-85b83f167ead",
"person" => "abc123",
"client" => "def456",
"entry" => "ghi789",
]
>>> \Log::debug('some debug message here', $structure);
=> null
which gets output like this
<pre lang="sh">
{"message":"some debug message here","context":{"id":"daed8173-5bd0-4065-9696-85b83f167ead","person":"abc123","client":"def456","entry":"ghi789"},"level":100,"level_name":"DEBUG","channel":"development","datetime":{"date":"2018-09-03 18:31:31.079921","timezone_type":3,"timezone":"UTC"},"extra":[]}
Of course there is no ‘standard’ for structured logs (nor should there be as they really are context sensitive), but most of the examples I’ve seen all have some sort of id for giving context for tracing things around.
Note: The id in this case is solely for dealing with logs message output. This is not for application request tracing which I think is also really interesting but have not delved into yet.