slogger / laravel
Tracing and observability for Laravel with dispatchers, masking, and profiling.
Requires
- php: ^8.2
- ext-pcntl: *
- ext-posix: *
- laravel/framework: ^10.26 | ^11.0 | ^12.0
- symfony/process: ^6.4|^7.0
Requires (Dev)
- friendsofphp/php-cs-fixer: ^3.94
- guzzlehttp/guzzle: ^7.0
- orchestra/testbench: ^8.14 | ^9.0 | ^10.0
- phpstan/phpstan: ^2.1
- phpunit/phpunit: ^10.5 | ^11.0
This package is auto-updated.
Last update: 2026-08-30 20:05:32 UTC
README
English | Русский
SLogger Laravel is a tracing/observability package for Laravel apps. It records request/command/job/event/etc. traces and delivers them to a remote backend via configurable dispatchers.
This README documents installation, configuration, watchers, masking, dispatchers, and usage patterns.
Upgrading to 2.0
Masking moved out of the traced application and into the dispatcher job.
-
Per-watcher masking is gone.
input.headers_masking,input.parameters_masking,output.headers_masking,output.fields_maskingand the model watcher'smasksare no longer read. Leftovers in a published config are ignored, not an error - which means any key you added there stops being masked. Check your own keys againstmasking.full_keysand port over what the shipped list does not already cover - it covers the shipped defaults plusssn,ibanandcard_number, not whatever else you added yourself. -
Keys are masks, not substrings. A mask is matched against the whole key and against each of its word components, so
authcoversphp-auth-pwandx-auth-userand notauthor, and*token*coversapi_tokenandtokenizer. If you ported keys from the old per-watcher lists, they wereStr::ispatterns there too -*token*,*password*- so they carry over unchanged. -
Global lists instead, under
masking.full_keys,masking.partial_keysandmasking.value_patterns- the last matching the value rather than the key. They are read from your config, so republish the config (or add themaskingsection by hand): a published config from before 2.0 has no section at all, and a list that is missing is a list that masks nothing. -
A masked secret keeps nothing. A value under a
masking.full_keyskey becomes********- the previous release left the first and last third of every string readable, which for a token or a password is not a mask. Values undermasking.partial_keys(addresses, phone numbers, names) keep two characters at each end, which is what tells two records apart. -
Restart the slogger workers together with the application. Masking happens in the worker now, so a worker still running 1.x drains a 2.0 queue and ships those batches unmasked. Deploy the workers first, or drain the slogger queue across the switch.
-
The slogger queue now holds unmasked trace data. Masking happens on the way out, so whatever the watchers collected sits in the queue store until the batch is sent. Give that queue the retention and access rules the data deserves - a separate Redis database or queue connection, and no long-lived
failed_jobsrows for it. -
Trace data changed shape where the old shape put application data out of the masker's reach, or into a tag, which nothing masks:
- cache values are nested under their cache key (
cache.<key>.value); - mail addresses are nested under
messageand carried asemail/full_namepairs instead of address-as-key; - an anonymous notifiable's routes moved out of the
Anonymous:...string intorecipients(and an address left in a string like that is now masked by a value pattern anyway); - a url's query string is split off into
queryandquery_string; - route parameter values are no longer tags, and no longer the
uri. A request is tagged and titled with the route pattern -/reset/{token}- and the values live inroute_parameters, where the key list reaches them by parameter name. - the outbound
uriloses its userinfo, so credentials written into a url do not reach a tag; - values added through
TraceDataComplementer::add()land under__addrather than at the top level, which is what puts them in the masker's reach. A plain value added there belongs to the current unit of work and is dropped when it ends - the next job in aqueue:workworker, and the next request under Octane, do not inherit it. AClosureis the other half: registered once, for the process, and evaluated afresh for every trace, which is what afn() => auth()->id()in a service provider needs.
- cache values are nested under their cache key (
-
An XML body is now recorded, under
__xml, where before it was dropped: both watchers ran every body throughjson_decode, and an XML one gave[]. A consumer that assumed a body is always a decoded structure will now also see a single-key array holding the document as a string. -
The outbound parent-trace header changed value. It used to carry the trace enclosing the call; it now carries the trace of the call itself, so a service you call hangs its trace under that call rather than beside it. Cross-service trees gain a level. Nothing has to be reconfigured, but a receiver that reasons about depth will see the difference.
Anything consuming those fields on the receiving side needs updating.
-
Laravel 10.26 is the new floor.
src/needs 10.12 (JobTimedOutlanded there), but the test suite runs on testbench's workbench, whose earliest release requires 10.26 - and an untested floor is not a supported one. 10.17 was claimed for a while and was never true: the suite installs there and 152 of its tests error out, because the testbench that pairs with 10.17 does not know how to discover the workbench config, so the package reads itself as disabled. -
API changes if you build formatters yourself:
RequestDataFormatterlost itsrequestHeaders,requestParameters,responseHeadersandresponseFieldsarguments along with the matchingadd*()methods, andMaskHelper::maskArrayByList()/maskArrayByPatterns()are gone.MaskHelper::maskValue()now masks a string whole;maskValuePartially()is the one that keeps a couple of characters. -
API changes if you extend the core:
Processor::stopDetached()is gone -stop()closes a parent trace whichever way it was started - and so areProcessor::handleSeparateTracing()andProcessor::registerWatcher(), which the service provider now does itself.DispatcherProcessorInterfacegainedgetChildCommandName(): the master saves that name and looks its children up by it, so it has to be what the process table will show.
Requirements
- PHP >= 8.2
ext-pcntlandext-posix- the dispatcher supervises worker processes- Laravel 10.26+ (tested on 10, 11 and 12)
- Queue driver for
queuedispatcher
Installation
- Install the package (via Composer in your app):
composer require slogger/laravel
- Publish config:
php artisan vendor:publish --tag=slogger-laravel
- Configure env and
config/slogger.php(see below).
Quick Start
Enable and use the queue dispatcher:
SLOGGER_ENABLED=true SLOGGER_TOKEN=your-api-token SLOGGER_DISPATCHER=queue SLOGGER_DISPATCHER_QUEUE_CONNECTION=redis SLOGGER_DISPATCHER_QUEUE_NAME=slogger SLOGGER_LOG_REQUESTS_ENABLED=true
Then start dispatcher workers:
php artisan slogger:dispatcher:start
Trace Collection Backend
SLogger Laravel sends traces to a separate backend service. The reference backend project is:
https://github.com/sprust/slogger
Use its setup instructions to provision the server and configure the API client URL/token in this package.
Custom backend / client
You can replace the backend by providing your own API client. Redefine ApiClientFactory::create and return a custom implementation of SLoggerLaravel\\Dispatcher\\ApiClients\\ApiClientInterface that sends traces to your backend.
Configuration
All configuration lives in config/slogger.php with environment overrides. Key sections:
General
SLOGGER_ENABLED=false SLOGGER_TOKEN= SLOGGER_TRACE_ID_PREFIX= SLOGGER_LOG_CHANNEL=daily SLOGGER_CONTEXT=array
SLOGGER_ENABLED: globally toggle all tracing.SLOGGER_TOKEN: API token for dispatchers.SLOGGER_TRACE_ID_PREFIX: custom prefix for trace IDs. If empty, uses sluggedapp.nameorapp.SLOGGER_LOG_CHANNEL: where internal errors are logged.SLOGGER_CONTEXT: where the state of one unit of work is kept -arrayunless you run several requests or jobs at once in one process. See Concurrency.
Dispatchers
SLOGGER_DISPATCHER=queue SLOGGER_DISPATCHER_QUEUE_CONNECTION=slogger-rabbitmq SLOGGER_DISPATCHER_QUEUE_NAME=slogger SLOGGER_DISPATCHER_QUEUE_WORKERS_COUNT=3 SLOGGER_DISPATCHER_QUEUE_API_CLIENT=socket SLOGGER_DISPATCHER_QUEUE_SOCKET_CLIENT_URL=tcp://0.0.0.0:0002 SLOGGER_DISPATCHER_QUEUE_SOCKET_CLIENT_TIMEOUT=10
SLOGGER_DISPATCHER:queueormemory.queuedispatcher runs worker processes (similar to Horizon) and sends traces via HTTP or socket client.memorydispatcher stores traces in memory (useful for tests/dev).
SLOGGER_DISPATCHER_QUEUE_CONNECTION is required for the queue dispatcher — there is
no fallback to QUEUE_CONNECTION on purpose: telemetry must not silently share the
application queue connection. Use a dedicated connection.
SLOGGER_DISPATCHER_QUEUE_SOCKET_CLIENT_TIMEOUT is the read/write timeout of the socket
client in seconds (default 10). It gives headroom when the receiver is saturated and its
acknowledgement is genuinely late; the connect timeout is separate and stays at 2 seconds.
If the receiver closes the connection (restart, deploy, network fault), the client detects it and reconnects transparently — exactly one retry per batch. Timeouts are not retried this way: that would turn a saturated receiver into a reconnect storm; they are handled by the job retry policy below.
Send retries are fixed by design: 5 attempts with backoff of 5/10/30/60 seconds between them.
After the attempts are exhausted the batch is dropped with a rate-limited warning in the
SLogger log channel — telemetry never fills the failed_jobs storage.
Request parent trace header
SLOGGER_REQUESTS_HEADER_PARENT_TRACE_ID_KEY=x-parent-trace-id
Allows linking child traces to parent requests via a custom header. The middleware
reads it from the incoming request and sets it on the response it returns, so the
client actually receives it. (It used to be set in terminate(), which under FPM runs
after the response has already been sent - cross-service correlation only ever worked
in tests.)
Watchers (enable/disable)
SLOGGER_LOG_COMMANDS_ENABLED=true SLOGGER_LOG_JOBS_ENABLED=true SLOGGER_LOG_REQUESTS_ENABLED=true SLOGGER_LOG_CACHE_ENABLED=true SLOGGER_LOG_DATABASE_ENABLED=true SLOGGER_LOG_DUMP_ENABLED=true SLOGGER_LOG_EVENT_ENABLED=true SLOGGER_LOG_GATE_ENABLED=true SLOGGER_LOG_HTTP_ENABLED=true SLOGGER_LOG_LOG_ENABLED=true SLOGGER_LOG_MAIL_ENABLED=true SLOGGER_LOG_MODEL_ENABLED=true SLOGGER_LOG_NOTIFICATION_ENABLED=true SLOGGER_LOG_SCHEDULE_ENABLED=true
What SLogger Writes
Each trace contains:
trace_id,parent_trace_id,type,status,tagsdata(watcher-specific payload)duration,memory,cpu,logged_at
memory is the percentage of memory_limit in use, and is null when there is no
limit (memory_limit = -1, the CLI default) - there is nothing to be a percentage
of. cpu is the one-minute load average as a percentage of the machine's capacity,
normalised by core count, and can exceed 100 on an overloaded machine.
Watcher data highlights:
request: url (without the query string), method, action, query/query_string, route_parameters, headers/params, response (for JSON and XML responses)job: connection, payload, status (processed,failed,released_after_exception,timed_out,exception_occurred), exceptionevent: listeners, broadcast, optional serialized payloadmodel: action, model class, key, changesmail: mailable/notification, queued,message(from/reply_to/to/cc/bcc asemail/full_namepairs, subject)notification: notifiable, channel, queued,recipients, responsecache: type, key, andcache.<key>(value, tags, expiration). A value too long for the masker to read is recorded as__skippedinsteaddb: query, bindings, time. The watcher masks a binding itself, by length: a string longer than five characters becomes********, a shorter or numeric one is kepthttp-client: method, url, query/query_string, request/response (concurrent requests are traced independently, soHttp::pool()works)schedule: command, description, cron, output (read up to the masker's limit)dump,log,gate: dump/message/ability info
A queue worker fails a timed out job from its SIGALRM handler, i.e. in the middle of
whatever the job was doing, and kills itself right after. Traces started by the job and
still open at that moment are closed as failed and tagged __interrupted, keeping the
data they had collected; a job that is retried instead of failed is closed by the
JobTimedOut event. A trace can still be left in the started status when the signal
arrives while a trace is being pushed to the dispatcher — tracing is paused there, so the
timeout events are dropped — or when the worker is killed by a signal it does not handle.
Requests
Middleware
For HTTP request tracing, add the middleware to the routes you want traced:
\SLoggerLaravel\Middleware\HttpMiddleware::class
Request watcher config
config/slogger.php:
'watchers' => [ [ 'class' => \SLoggerLaravel\Watchers\Parents\RequestWatcher::class, 'enabled' => env('SLOGGER_LOG_REQUESTS_ENABLED', false), 'config' => [ // log only matched paths (optional) 'only_paths' => [ // 'api/*', ], // skip matched paths 'excepted_paths' => [ // 'health', ], 'input' => [ // apply input formatting only for these paths 'only_paths' => [ // 'api/*', ], // hide all request params for these paths 'hidden_paths' => [ // 'auth/*', ], ], 'output' => [ // apply response formatting only for these paths 'only_paths' => [ // 'api/*', ], // hide all response data for these paths 'hidden_paths' => [ // 'auth/*', ], // limit json response size (bytes) 'max_content_length' => 1000000, ], ], ], ],
only_paths
only_paths(top-level): log only matched request paths.input.only_paths: apply input formatting only to matched paths (others are scrubbed).output.only_paths: apply output formatting only to matched paths (others are scrubbed).
Patterns use Laravel Str::is matching.
JSON response size
A body that is not JSON but parses as XML - a SOAP envelope, an XML API - is
carried as the document itself, under __xml:
{"__xml": "<order><api_token>********</api_token></order>"}
Not as an array converted from it: that would lose attributes, repeated elements and
namespaces, and a trace that no longer matches the document it describes is worth
little. The masker looks inside such a string (see "Masking Rules"), so the document is
masked in place. This applies in both directions and to both watchers - an incoming
request body Laravel does not parse into input(), an outgoing one, and either
response.
The sender has to say so. A body is recorded as XML only when its Content-Type
is one (application/xml, text/xml, application/soap+xml, *+xml) and it parses
as XML. Parsing alone is not enough: an HTML fragment - what an htmx or Turbo endpoint
returns - is well-formed markup carrying a CSRF token in value="…", and the masker
matches names, so it cannot reach it. A body that is neither JSON nor labelled XML is
dropped, as it always was.
A body is also dropped, with {"__skipped": "body_too_large"}, above the size the
masker will read (1 MB), and with {"__skipped": "non_utf8_body"} when it is not
valid UTF-8 - a trace's data is serialised with json_encode, and invalid bytes there
would replace the whole payload of that trace with an encoding error, not just the
body.
Large responses are skipped and marked with:
{"__skipped": "response_too_large"}
Masking Rules
Masking runs in the dispatcher job, right before a batch is sent, and never in the traced application. Building a trace costs the application only what it takes to collect and hand off the data; walking a payload key by key is paid for by the dispatcher workers instead. Two consequences follow:
- The queue holds unmasked trace data. Whatever the watchers collected sits in the
queue store until the batch is sent, so the slogger queue is as sensitive as the
traces themselves: give it its own connection, keep its retention short, and do not
let failed batches pile up in
failed_jobs. - The
memorydispatcher never masks - it has no job. It is a development and testing aid and sends nothing anywhere.
Watchers do not mask. What they do at runtime is hide and truncate: only_paths,
excepted_paths, hidden_paths, max_content_length, per-watcher excepted lists.
The one exception is the database watcher: query bindings are positional, so no key list
can reach them and the dispatcher job has nothing to decide by. It masks them itself, by
length - a string of more than five characters becomes ********, a shorter one and a
numeric binding are recorded as they were. Nothing in a binding says whether it is a
password or a page number, so a short or numeric secret - a PIN, an OTP, a card number
held as an integer - does reach the receiver. Do not keep those in cleartext columns, or
turn the watcher off.
The key lists
'masking' => [ // the value under a matching key is replaced whole, and everything below it. // matched case-insensitively against the whole key and each of its components. 'full_keys' => [ // a word, so `auth` covers `php-auth-pw` and not `author` 'auth', 'authentication', 'authorization', 'oauth', 'passwd', 'pass', 'passcode', 'passphrase', 'pw', // not bare `signed`: it would take `signed_at` and `signed_by` too 'signed_payload', 'signed_request', 'signed_url', 'private', 'privatekey', 'session', 'sessionid', 'csrf', 'jwt', 'bearer', 'otp', 'totp', 'cvv', 'cvc', 'pin', 'pincode', 'iban', 'ssn', 'recovery', // spelled out: a bare `card` would take `card_type` with it 'cardnumber', 'creditcard', 'credit_card', // not covered by `pass`, `passwd` or `pw`: `user_pwd` splits to `pwd` 'pwd', // a wildcard matches the whole key, and the bare form with it - so a // word listed here is not repeated above '*token*', '*password*', '*secret*', '*api_key*', '*apikey*', '*api-key*', '*credential*', '*cookie*', '*signature*', '*session_id*', '*card_number*', '*recovery_code*', ], // two characters kept at each end, so two records still look different. // these identify a person rather than authenticate one - never a secret here. // // no bare `name`: it is matched as a word component, and `job.name` holds a // job class, `listeners[].name` a listener class, a file's `name` its filename 'partial_keys' => [ 'username', 'user_name', 'nickname', 'surname', 'middlename', 'middle_name', 'fullname', 'full_name', '*email*', '*phone*', '*recipient*', '*firstname*', '*first_name*', '*lastname*', '*last_name*', ], // matched against the value and masked in place, for what no key name points // at - an address in a log line. an invalid pattern is ignored, not fatal. // // order matters: first match wins, so narrow before broad. a capture group // masks the group and keeps the rest. 'value_patterns' => [ // postgres://app:secret@db. a scheme is required, so `//assets:v2@2x.png` // is left alone; the group runs to the last `@` 'url_credentials' => '/\b[a-z][a-z0-9+.-]*:\/\/[^\/\s:@]+:([^\/\s]+)@/i', // a secret in a url, wherever it turns up. the parameter name is a word, // not a substring: unbounded, it took `?author=` and `?country_code=` 'url_secret' => '/[?&](?:[\w.-]*[_-])?(?:token|apikey|api_key|api-key|secret|password|passwd|auth|authorization|signature|credential|session|sessionid)(?:[_-][\w.-]*)?=([^&\s"\'<>]+)/i', // whole parameter name only, or it takes `country_code` and `zip_code` 'url_oauth_code' => '/[?&]code=([^&\s"\'<>]+)/i', 'email' => '/[\w.+-]+@[\w-]+\.[\w.-]*[\w-]/u', ], ],
Both lists are masks, case-insensitive, with * as a wildcard. A mask is matched
against the whole key and against each of its word components — a key is split on
_, -, ., : and camelCase boundaries:
| Mask | Matches | Does not match |
|---|---|---|
pass |
pass, db_pass, smtp_pass, pass_hash |
passengers, compass, bypass_cache |
auth |
auth, basic_auth, x-auth-user, php-auth-pw |
author, authorized |
token |
token, api_token, apiToken |
tokenizer |
*token* |
api_token, tokenizer |
stock |
Neither a substring search nor a whole-key match on its own would do. A substring rule
cannot be narrowed once it is too broad: auth also took author, and each match took
the whole value and, through inheritance, the subtree under it. A whole-key rule cannot
be widened without wildcards that bring the false positives back: auth then stopped
matching php-auth-pw — the plaintext password Symfony puts beside the base64 header.
Matching a component gives both, and a mask with wildcards is still available for names
that are one word.
A match on a parent key applies to its subtree, so auth covers auth.method too -
that needs the parent to be one level in, since the top level is not matched at all
(see below). A key in both lists is masked whole: the stricter list wins.
Masking is off only when all three lists (value_patterns included) are empty. That
switch does not reach the database watcher's bindings: they are positional, no key list
can say which one is a password, so the watcher masks them itself, by length, whatever
these lists hold.
The split is the point. A secret is worthless the moment any of it leaks, so
masking.full_keys replaces the value entirely: ********, a fixed width, so the length of
the secret does not leak either. An address, a phone number or a name is mostly there
to tell two records apart, so masking.partial_keys keeps two characters at each end -
john.doe@example.com becomes jo****************om. Never put a secret in
partial_keys: what is left is enough to correlate records, and for a short value it
is enough to guess it.
A value that is a string containing a document is parsed, masked and serialised
back: applications hand whole documents over as strings - an Eloquent array cast puts
one straight into a model's changes, a SOAP call arrives as one - and the key carrying
such a string says nothing about what is inside it. Two formats are looked into:
- JSON, for strings that open and close like a document -
{…}or[…], so a line of prose beginning with{is still prose. Re-encoding normalises escaping, and a number too large or too precise for a PHP float loses precision. One that opens like a document and cannot be read as one - NDJSON, a raw control character, deeper thanjson_decodegoes - is masked whole: nothing has read it, so nothing can vouch for it. - XML, for strings that parse as XML. Element and attribute names are matched the
way object keys are, a match covers the subtree (
<auth>masks everything under it), a namespace prefix does not hide a name (soap:Envelopematches onEnvelope), CDATA is masked in place, and comments and processing instructions get the value patterns. Re-serialising may normalise insignificant whitespace and attribute quoting; a document that had no XML declaration does not gain one. - PHP's own serialisation, for strings starting with
a:<n>:{. A session stored in the cache is one of those, holding the CSRF token and the password hash under keys the lists match. Objects are never instantiated while reading one, and a blob holding a serialised object or a back-reference is not taken apart at all - the first cannot be put back together without its class, the second unserialises into an array that contains itself. Both are left to the value patterns, which read them as the plain strings they are.
A document in which nothing matched is kept byte for byte.
Whatever the shape, the walk stops at a fixed depth and masks what is left whole. It is a backstop rather than a limit anyone should meet: running out of memory is a fatal error, and a fatal error in the dispatcher job takes the worker with it.
A trace the masker cannot read is replaced, not dropped and not shipped. Its data
becomes a single __mask_error key naming what went wrong. Masking is deterministic, so
letting the exception out would cost the whole batch and every one of its retries - the
traces around the broken one included.
XML entities are never expanded, so a document that arrived from outside cannot make
the dispatcher read a local file or unfold a billion-laughs bomb while it is being
masked - masking runs in a worker over payloads the application did not write. Two
consequences follow, and both fail closed: a document whose values live in an
internal DTD is masked whole, because masking around &secret; while leaving its
declaration in place reads as protection without being any; and a document carrying
declarations that does not parse at all is masked whole for the same reason.
Anything else that merely starts with < - a fragment of prose, a page - is left
alone, with the value patterns applied to it as ordinary text.
A value under a query_string key is masked parameter by parameter rather than as
a whole, so page=2&api_token=secret keeps the page and loses the token. This is where
the request watchers put a url's query string: a url is also a tag and a title, and
nothing masks those.
Value patterns
Some things identify a person by their own shape, wherever they turn up, and no key
name points at them: an address inside Anonymous:mail,john@example.com, or in the
middle of a log message. masking.value_patterns are regular expressions matched
against the value, and what they match is masked in place - partially, so the rest
of the string stays readable:
'invoice sent to john.doe@example.com' -> 'invoice sent to jo****************om'
They are not bound to a key, so unlike the key lists they apply at the top level too,
and they reach inside JSON strings and query strings, into array keys, and into a
trace's tags - which nothing else masks. A key match still wins: a token holding
an address loses all of it, not just the middle. An invalid pattern is dropped rather
than raising a warning for every string in every trace.
The key lists and the patterns cover different things and are meant to be used
together - recipient in partial_keys catches a phone number under
recipients.vonage, which no address pattern would ever match.
The top level of a trace's data is never masked. That level belongs to the
watcher, not to the application: connection_name, request, changes, context,
bindings and so on are a fixed structure, and the traced data starts one level in.
Matching therefore begins inside it - context.customer_email and
job.data.customer_email are masked, while connection_name is left readable even
though it contains _name. Watchers whose own top level used to hold application data
were reshaped so this rule holds for them too: a cache value sits under its cache key
(cache.<key>.value, so the key itself is what the list matches against), and mail
addresses sit under message as email/full_name pairs.
Widen a mask when the shipped list misses something of yours - *ssn* instead of
ssn, *iban* instead of iban - and narrow one when it catches a field you need.
Over-masking is the safe direction for telemetry, but it is a choice you make per mask
rather than one the package makes for you.
What a key list cannot reach
Some fields are free text, and no key name describes what is inside them. The key lists
do not apply to these; only value_patterns do, and only for what has a shape worth
matching:
| Field | What it holds |
|---|---|
log.message |
whatever was logged |
dump.dump |
whatever was dumped - dd($user->api_token) is exactly this |
schedule.output |
the scheduled command's stdout |
db.sql, and the sql fragment in a db trace's tags |
the statement, though its values travel as bindings, which the watcher masks by length |
For those, the controls are the watcher's own: turn the watcher off, or keep secrets out of what you log and dump. A trace's tags are in the same position - bare strings with no key naming them - which is why value patterns apply to them too.
Masked values
Masked values keep basic types, so a masked payload stays shaped like the original:
null->nullbool->falseint->0float->0.0string->********, or two characters at each end for a partial mask- an object -> whatever
json_encodewould make of it, walked as an array like any other (one with__toString()is masked as its string instead). It only becomes********when there is nothing to walk - no public state, or nothing encodable
An empty string is left as it is: a mask there would claim something had been hidden.
An array is walked, not replaced. A matching key covers its subtree, so every
leaf under it is masked while the structure and the key names survive:
{"token":{"a":"secret","b":2}} becomes {"token":{"a":"********","b":0}}. Keys are
data too when the application chooses them - a cache key is otp:<address> often
enough - so value_patterns are applied to array keys and to tags as well, the two
places no key list can reach.
Guzzle / HTTP Client tracing
You can attach the SLogger handler to Guzzle:
new \GuzzleHttp\Client([ 'base_uri' => 'https://url.com', 'handler' => app(\SLoggerLaravel\Guzzle\GuzzleHandlerFactory::class)->prepareHandler( (new \SLoggerLaravel\RequestPreparer\RequestDataFormatters()) ->add( new \SLoggerLaravel\RequestPreparer\RequestDataFormatter( urlPatterns: ['/api/auth/*', '*sensitive/some/*'], hideAllRequestParameters: true, hideAllResponseData: true ) ) ), ])
Formatters hide and truncate; sensitive values are masked later, by the dispatcher job.
Concurrency
A trace has state while it runs: which trace is the current parent, which parent traces
are still open, whether the watchers are paused, what add() said about this request.
Where a process handles one request, one job or one command at a time, that state is the
process's, and keeping it in fields on a few singletons is correct.
Under a runtime that handles several at once in one process - coroutines, an event loop,
fibers - a field is shared by all of them. A second request reads the first one's parent
id and files itself underneath it; a request inside a paused section silences the
watchers of every other request in flight; one request's user_id is written onto
another's traces.
So the state lives in a store, and the store decides what "current" means.
Choosing a store
# array (default) | fiber | App\Tracing\YourStore SLOGGER_CONTEXT=array
arrayis a single map for the whole process - what every version before this one did, and the right answer for php-fpm,artisanandqueue:work. It is the default, so upgrading changes nothing.fiberkeeps a map per runningFiber, and a single map when none is running. Set it when your runtime gives each request or each job its own PHP fiber.- anything else is taken for the class name of a store you brought yourself.
Check that fiber is the right answer before setting it. It tells units apart by
Fiber::getCurrent(), so under a runtime whose coroutines are not PHP fibers - Swoole,
or a scheduler outside PHP - it silently degrades to array and nothing is fixed. One
line inside a request settles it:
Log::debug('slogger: in a fiber?', ['yes' => Fiber::getCurrent() !== null]);
If that is false, write a store instead.
Writing your own store
Two methods, no dependencies:
namespace App\Tracing; use SLoggerLaravel\Context\TraceContextInterface; class CoroutineTraceContext implements TraceContextInterface { public function get(string $key, mixed $default = null): mixed { /* ... */ } public function set(string $key, mixed $value): void { /* ... */ } }
Then SLOGGER_CONTEXT=App\Tracing\CoroutineTraceContext. Four things it has to honour:
- The store is a singleton and holds no state of its own. It works out where to look on every call. Watchers are built once at bootstrap and keep the objects they were given, so a store that decided its scope in its constructor would keep answering for whichever unit of work happened to build it.
- A key holding
nullis not an absent key.get()must returnnullfor the first and the default only for the second. Writing$value ?? $defaultconflates them, and "no parent trace" is written asnull. - Writing must actually write. If the underlying context has a "do not replace an existing key" mode, do not use it: a store that quietly keeps the first value ever written to a key reproduces the bug this exists to fix.
- Values must come back by value. Everything kept here is an array or a scalar, so handing a unit of work a copy is enough - but a store that hands two units the same mutable object shares their state again.
There is deliberately no way to remove a key. A store whose reads fall through to an
enclosing unit of work - a coroutine context with inheritance usually does - would
uncover the enclosing unit's value; "there is nothing here" is written as null or as
an empty list instead.
What fiber does not do
Reads do not fall through to the fiber that created the current one. PHP cannot say which fiber that was, and guessing is how unrelated traces get stitched into one tree.
The consequence is worth knowing before you switch: a fiber started inside a traced
request begins with no state of its own, so child traces pushed from inside it are
dropped - a query, a log line or an event recorded there has no open parent trace in
that fiber, and push() returns early. Parent traces started there are recorded, as
roots rather than nested under the request, and so is anything a watcher marks as able
to stand alone (can_be_orphan). If your host code runs fibers inside a unit of work
(amphp/revolt and anything built on them), fiber will cost you that telemetry; a store
that can name the enclosing coroutine will not.
The same applies to an outbound HTTP call whose response is handled somewhere other than
where the call was made. Guzzle's response hook runs wherever the promise is resolved:
with curl and wait() that is the fiber that made the call, and everything works - but
under a runtime that settles promises on a loop fiber of its own, the call is opened in
one unit of work and answered in another, and the trace is never closed. This is not
about which map the watcher keeps its entry in; the processor's own record of the call
lives with the unit that made it either way.
A unit of work that never reports back
Any store that scopes state to a unit of work - this one, or your own - changes what happens when a unit ends without saying so. Worth knowing before you switch.
An exception is not that case: the framework still fires RequestHandled, JobFailed
or CommandFinished, so the trace closes as failed and everything below is irrelevant.
The case is a unit dropped while suspended - the scheduler killed it, a timeout took
it, the process is shutting down.
Nothing the store holds is leaked. The state goes with the unit: PHP unwinds a
destroyed fiber's stack, and the store releases its map along with it - the open traces,
the parent id, the outbound calls, the values add() collected. (The profiler is not in
the store and could not survive this, which is why it is refused outright - see below.)
What is lost is the closing update. The parent trace stays started in the backend, and
the outbound calls it left in flight are never tagged __interrupted, because the
processor's sweeps only ever see the current unit and no later unit can reach them. With
array a later request or job in the same process swept them, which is the one thing
this gives up.
It cannot be fixed from inside the package. Cleanup during a fiber's destruction is not
allowed to do I/O - Fiber::suspend() throws Cannot suspend in a force-closed fiber
from a finally there, and Cannot suspend outside of a fiber from a destructor after
it - while dispatching a trace is exactly a suspension point under such a runtime.
Age them out on the receiver instead: a trace with no update for some minutes is over, whatever happened to the process that started it. That is the only place still looking after the process is gone, and it covers a fatal error or an out-of-memory kill too, which nothing running inside the process ever will.
Durations in a long-lived process
LARAVEL_START is defined once, in the entry script, where the process begins. Under
php-fpm the process is this request, the bootstrap it measures is this request's, and
both boot_time and the duration are counted from it. Under a server that boots once and
then serves for hours - Octane, RoadRunner, FrankenPHP's worker mode, a coroutine runtime
- it is the worker's start, and counting from it reports the worker's uptime as every request's duration: the same number on every trace, growing all day.
So the constant is taken only where it is this request's own start. A process booted from
the console and answering HTTP is a long-lived server whatever it says about itself, and
never takes it. Under any other SAPI it is spent by the first request the process traces
and by no other. Everything else measures from the moment this package's middleware saw
the request - taken inside that request's own flow, so it is the request's own - and
reports boot_time as -1, since the boot it did not wait through is not its to claim.
Never from Kernel::requestStartedAt(), whichever runtime: it is one field for a whole
process, and a request starting alongside replaces it with a later one - a start in the
future, which is a negative duration.
Two things this leaves out, both small and both unavoidable from inside a package. Where
the constant is not taken, the stretch from entering the kernel to reaching this
middleware - the global middleware in front of it - is not counted; a runtime that wants
it back has to hand over the moment it accepted the request, because there is no earlier
point to read in a worker that booted hours ago (REQUEST_TIME_FLOAT is the process's
start there too). And under a worker whose SAPI is not the console, its first request
counts a boot it did not wait through: one trace per worker, and nothing that can tell
that boot from a slow one.
What is per unit of work, and what is not
Per unit of work: the current parent trace id, the stack of open parent traces, the
pause flag, the map of detached (outbound) traces, the requests and commands a parent
watcher has open, the outbound calls the HTTP-client watcher has open, the jobs the job
watcher is processing, and the values add() collected.
Per process, on purpose: which watchers are enabled, the callbacks registered with
add(fn() => ...), and the trace dispatcher's batching buffer - per unit it would stop
batching and multiply the jobs.
Those callbacks are shared, which is what makes them rules rather than values - so
register them once, from a service provider, and let them read what they need when they
run: add('tenant', fn() => tenant()?->id()). A closure registered per request, closing
over that request's own objects, is evaluated for every other unit's traces too, and
puts one request's data on another's - the very thing the rest of this section is about.
A plain value is this unit's own and is safe anywhere.
The socket client is neither: it keeps a small pool of connections - the one it was
built with, plus any it opens through Connection::fresh() - and a sender holds one from
the first byte written to the last byte read. A process sending one batch at a time opens
exactly one and keeps it, as before; concurrent senders each get one of their own rather
than interleaving frames on a shared stream, and up to eight are kept for reuse, the rest
closed on the way back. None of it is aware of fibers, so it holds for any way of running
things at once.
Whether senders can get inside each other's exchange at all is a property of the runtime,
not of this package: a bare PHP fiber suspends only where it says so, and Connection
says so nowhere. A runtime that turns a stream call into a suspension point - which is
what makes coroutines worth having in the first place - can. The pool costs nothing where
they cannot.
Two watchers that concurrency does not suit
- Profiling (
SLOGGER_PROFILING_ENABLED) measures the process, so it is refused outright unless the store isarray- the config asks and the answer is no. A run covers everything the process did while it lasted, every other unit's work included, filed under the one trace that started it; and a unit that ends without stopping owns the profiler for good, leaving the extension instrumenting every call the process makes and no later trace ever profiled. - The dump watcher swaps
VarDumper's handler, which is global to PHP, for the length of onedump(). Adump()from another unit of work inside that window is not traced. Harmless, but it is telemetry you will not see.
Upgrading to 2.1
The default behaviour does not change, and neither does any public method. Two constructors did, which matters only if you build one yourself or override one in a subclass:
| Class | Change |
|---|---|
TraceIdContainer |
now takes TraceContextInterface; it had no constructor before |
HttpMiddleware |
now takes TraceIdContainer as a second argument |
Connection gained fresh(), and SocketClient and ApiClientFactory kept their
arguments.
Processor, RequestWatcher, CommandWatcher, JobWatcher, HttpClientWatcher and
TraceDataComplementer each take a TraceContextInterface as their last argument.
All of these are resolved from the container, so nothing else has to change.
Dispatchers
Queue dispatcher
Start the dispatcher (spawns queue workers):
php artisan slogger:dispatcher:start
- Parent traces are sent immediately.
- Child traces are batched (default batch size: 5).
- Orphan traces are sent immediately.
- On shutdown, remaining traces are flushed.
The master keeps every worker slot filled. One that keeps dying on boot is replaced with a growing delay rather than once a second, and a slot counts as settled only once its worker has stayed up a minute. Starting a second dispatcher takes over from the first: it stops the running one, then starts its own fleet.
Stop the dispatcher:
php artisan slogger:dispatcher:stop
Memory dispatcher
Stores traces in memory only. Intended for tests/local development.
Storage
SLogger does not persist traces locally. The only local files are the dispatcher state file and the lock beside it:
storage/slogger/dispatcher-state-*.json
storage/slogger/dispatcher-state-*.json.lock
You may want to ignore the folder:
storage/slogger/*
Testing
Run tests:
vendor/bin/phpunit
The testbench config uses in-memory sqlite and memory dispatcher.
Troubleshooting
- Dispatcher not starting: verify
SLOGGER_ENABLED=trueand correct dispatcher name. - No traces: ensure watchers are enabled and middleware is applied for requests.
- Queue dispatcher not sending: check queue workers and API client URL.
- Socket client errors: verify socket address and backend availability.
License
MIT