README

Laravel logger boost

Add useful processors to your app.

Requirements

PHP 8.2+, Laravel 12 or 13, Monolog 3.9+.

Installation

composer require yuriitatur/laravel-logger-boost

Testing

composer test

Usage

Disclaimer

This package is designed to work with the Laravel framework. Outside of Laravel only TimeProcessor, CliProcessor and CustomUidProcessor can be used as plain Monolog processors, everything else needs Laravel.

Laravel

Add BoostLogger to your channel config in config/logging.php

'channels' => [
    'single' => [
        'driver' => 'single',
        'tap' => [\YuriiTatur\LaravelLoggerBoost\BoostLogger::class],
        'path' => storage_path('logs/laravel.log'),
        'level' => env('LOG_LEVEL', 'debug'),
    ],
],

Or you can add even more context with AddMoreContext

'channels' => [
    'single' => [
        'driver' => 'single',
        'tap' => [
            \YuriiTatur\LaravelLoggerBoost\BoostLogger::class,
            \YuriiTatur\LaravelLoggerBoost\AddMoreContext::class
        ],
        'path' => storage_path('logs/laravel.log'),
        'level' => env('LOG_LEVEL', 'debug'),
    ],
],

This will add multiple extra fields like hostname, is_cli, route or user. Thus, returning all that data in each record is overhead. So make use of a stack driver with bubble option

 'channels' => [

        'stack' => [
            'driver' => 'stack',
            'channels' => [ // this is our main channels
                'single-error', // single-error channel will not bubble message to single
                'single',
            ],
            'ignore_exceptions' => false,
        ],

        'single' => [ // all debug+ messages goes with only BoostLogger
            'driver' => 'single',
            'path' => storage_path('logs/laravel.log'),
            'level' => 'debug',
            'formatter' => JsonFormatter::class,
            'tap' => [
                BoostLogger::class,
                BufferRecords::class . ':10', // optionally enable record buffering, with specified buffer size
            ],
        ],

        'single-error' => [ // if something happens, use AddMoreContext and bubble => false
            'driver' => 'single',
            'path' => storage_path('logs/laravel.log'),
            'level' => 'error',
            'bubble' => false, // if this is true, the message will be duplicated
            'formatter' => JsonFormatter::class,
            'tap' => [
                BoostLogger::class,
                AddMoreContext::class,
            ],
        ],
],

BufferRecords can go before or after the other taps: processors always run when a record is logged, not when the buffer is flushed.

How log keys work

Every record logged with BoostLogger carries three keys:

Key	Meaning
`uid`	the unit of work: a request, a queue job, a scheduled task, a nested command
`trace_id`	everything that belongs together: the request, the jobs it dispatched, the jobs those dispatched, the services it called
`parent_uid`	the unit that started this one, missing for the root of a trace

Search by trace_id to see everything one action caused, by uid to see one unit of it. When a custom key overrides the unit (overtakeLogs(), withKey()), the generated one is kept as original_uid.

Log key over HTTP

LogKeyMiddleware is prepended to the global middleware.

A client (or another service) can send its own log key in the X-Log-Key, X-Request-Id or X-Correlation-ID header (in that order) or in the trace_id query parameter, a header wins over the query. It becomes the request's uid and trace_id.
A valid W3C traceparent header continues the caller's trace: its trace id becomes trace_id, the caller becomes parent_uid. A log key next to it that only repeats the trace id does not rename the request.
The request's uid is returned in the X-Log-Key response header.
Keys that do not match logging.boost.log_key.pattern (by default up to 64 letters, digits, ., _, : and -) are ignored.

Propagation

The trace follows the work, all of it is enabled by default:

Queued jobs continue the trace of the request, command or job that dispatched them, which becomes their parent_uid. Chained jobs form one trace.
Child processes (scheduled commands, Process::run(), exec()) continue the trace of their parent through the LOG_BOOST_TRACE environment variable.
Outgoing Http client requests send the trace in the X-Log-Key header, and in traceparent / tracestate when the trace id is a W3C one (generated keys are). They are sent to every host by default, limit them to your own services with propagate.http_hosts, e.g. ['*.internal.example.com'].

Queue Jobs

This package automatically registers new LoggerAwareWorkerDecorator queue worker. Every job starts as a unit of its own and after every attempt all resolved log channels are reset (which also flushes buffered records), so each job can be traced using its own key, even if your default channel does not use BoostLogger. The job's uuid is its uid, so all attempts of a job share it (queue.job_uid). Jobs run by the sync driver keep the key of the request or command that dispatched them.

Log records about jobs (Running job, Job finished, Job released after exception, Job failed, Job timed out) contain the resolved job name (e.g. App\Jobs\SendInvite), not the generic Illuminate\Queue\CallQueuedHandler@call, along with the job id, queue, attempts and duration.

Open transactions. When a job finishes, the package rolls back database transactions the job opened and did not close, on every database connection, and logs a warning with the job name. Transactions that were open before the job started (a request dispatching a sync job, a test using RefreshDatabase) are left alone. Set logging.boost.rollback_open_transactions to false to disable it.

Scheduled tasks, commands and Octane

Every scheduled task is a unit inside the trace of schedule:run, its start, end and failure are logged.
Artisan::call() from a request, a job or another command is a nested unit. The command a console process was started for is the process' own unit.
Laravel Octane: every request, task and tick starts with a fresh log key, log channels are flushed after every request, and the peak memory is measured per request.

Request handled records the duration and the peak memory, Finished console command the duration and the command's arguments and options.

Eloquent

You can also add log key to your eloquent models, to keep track of all that happened to them with one key. First, add log_key column to your table;

# in your migration
Schema::table('my_models', function (Blueprint $table) {
    $table->string('log_key')->nullable()->index();
});

Do not make the column unique: a model gets the log key of the current request or job, so every model created in the same request gets the same key.

The reason, why it's not in a separate thing called AddLogKeyColumn class/method is because, requirements to this column may vary. Create your own how you like it. Next, add LogKeyAwareTrait trait in your model. New models get the current log key when they are created, unless they have one already; return false from shouldAutoApplyLogKey() to opt out.

# in your model
class Product extends Model 
{
    use LogKeyAwareTrait;
}

# in your service
public function createProduct($params) 
{
    return Product::create($params); # log_key is the current log key
}

public function updateProduct($id, $params) 
{
    $product = Product::findOrFail($id);
    $product->overtakeLogs(); # the rest of the request or job is logged with the model's key
    $product->update($params);
}

public function updateProducts(Collection $products, $params) 
{
    foreach ($products as $product) {
        # only the callback is logged with the model's key, the previous key is restored afterwards
        $product->withOwnLogs(fn (Product $product) => $product->update($params));
    }
}

The same is available without a model: app(CustomUidProcessor::class)->withKey('some-key', $callback). applyLogKey() still assigns the current key explicitly.

Sensitive data

BoostLogger redacts values of sensitive keys (redact_keys: passwords, tokens, secrets, cookies, authorization, api keys) in the context, in extra and in Laravel Context, before placeholders of the message are replaced, so Log::info('Login {password}', [...]) does not leak either. Nested arrays are redacted, objects are not. Route parameters (redact_route_params) and command options are redacted the same way, bound Eloquent models in route parameters are logged as their route key, not as the whole model. UserProcessor only logs a user that is already authenticated, it never loads one.

OpenTelemetry

With open-telemetry/api installed, BoostLogger adds the active span as otel_trace_id and otel_span_id, so log records can be joined to traces.

Configuration

Every option has a default, override only what you need, nested options are merged with the defaults. Either add a boost key to config/logging.php, or publish the config file:

php artisan vendor:publish --tag=log-boost-config

Option	Default
`register_logger_aware_queue_worker`	`true`	give every queue job its own log key, reset loggers after every job
`register_log_key_middleware`	`true`	accept and return log keys over HTTP
`register_event_logs`	`true`	log requests, console commands, scheduled tasks and queue jobs
`rollback_open_transactions`	`true`	roll back transactions queue jobs left open
`event_logs_channel`	`null`	channel for the package's own records, `null` for the default one
`propagate.queue`	`true`	queued jobs continue the dispatcher's trace
`propagate.processes`	`true`	child processes continue the parent's trace
`propagate.http`	`true`	Http client requests carry the trace
`propagate.http_hosts`	`null`	hosts that receive the trace, `null` for all, wildcards allowed
`queue.job_uid`	`uuid`	`uuid`: the job's uuid is its uid, `random`: a new uid per attempt
`units.scheduled_tasks`	`true`	every scheduled task is a unit
`units.nested_commands`	`true`	`Artisan::call()` is a nested unit
`log_key.header`	`X-Log-Key`, `X-Request-Id`, `X-Correlation-ID`	request headers with the log key, the first one is the response header
`log_key.query`	`trace_id`	query parameter with the log key, `null` to accept headers only
`log_key.traceparent`	`true`	accept and send W3C `traceparent`
`log_key.pattern`	`/^[A-Za-z0-9._:\-]{1,64}$/`	log keys from clients and payloads must match it
`redact_keys`	`password`, `secret`, `token`, `authorization`, `cookie`, `api_key`, ...	keys logged as `[redacted]`
`redact_route_params`	`token`, `password`, `secret`, `hash`, `signature`	route parameters logged as `[redacted]`
`skip_namespaces`	`Illuminate\`, `Symfony\`, `Monolog\`	frames `IntrospectionProcessor` skips
`uid.length`	`32`	length of generated log keys
`processors.logger`	`RedactSensitiveDataProcessor`	processors `BoostLogger` adds to the channel's logger
`processors.default` / `processors.more_context`		processors added by `BoostLogger` / `AddMoreContext` to every handler

Upgrading from 1.1

Requires PHP 8.2+ and Laravel 12 or 13.
Records carry trace_id, and parent_uid for nested and dispatched units.
Log keys sent by clients must match log_key.pattern, and a header wins over the trace_id query parameter.
Models with LogKeyAwareTrait get the current log key when they are created.
Queue jobs: the uid is the job's uuid (36 characters) instead of a random key, and every job, the first one too, starts with a fresh key.
Generated keys are 32 characters instead of 30.
Request handled and log key overrides are logged at info instead of notice.
Context, extra, route parameters and command options with sensitive keys are logged as [redacted].
WebProcessor is no longer part of AddMoreContext, RouteProcessor logs the ip instead.
RouteProcessor takes the container instead of a request.
Open transactions are rolled back per job down to the level the job started with, on every connection, controlled by rollback_open_transactions instead of register_event_logs.
The trace is sent to every host your Http client calls, limit it with propagate.http_hosts.

License

This code is under MIT license, read more in the LICENSE file.

yuriitatur / laravel-logger-boost

Package info

Security

Statistics