Skip to content

Conversation

@cosmastech
Copy link
Contributor

Imagine you're embarking on a legacy codebase started on Laravel 5. The engineers were adding lots and lots of log statements, but because something like Context didn't exist, they were repeatedly writing logs like this:

logs()->info('Return in progress', [
    'shopId' => $shop->id,
    'returnId' => $return->id,
]);
// ...
logs()->info('Return completed', [
    'shopId' => $shop->id,
    'returnId' => $return->id,
]);

Obviously duplicating these contextual pieces of data is arduous and error-prone. Along comes the Context facade and this can be simplified to:

Context::add([
    'shopId' => $shop->id,
    'returnId' => $return->id,
]);

logs()->info('Return in progress');
// ...
logs()->info('Return completed');

But for keen observers, they'll realize these two snippets of code actually function differently. In the first, the data lives under the log's context, whereas in the second, the data now lives under extra. For DataDog queries that search for logs based on contextual data, the first goes from @context.shopId=123 to @context.extra.shopId=123

This can be changed, of course, by binding our own log processor. However, I have done this on the last 3 projects I have worked on, so I figured it may be helpful to others.

With this MR, a developer would simply add something like this to their AppServiceProvider@boot():

Context::writeContextToLogContext();

Note: This gives the values set in the log method precedence over what is stored in the Context repository.

@timacdonald
Copy link
Member

If this is to support legacy system upgrades, I feel I would rather see the existing tools be used rather than introducing another usage dimension to Context for this usecase, e.g.,

Log::shareContext([
    'shopId' => $shop->id,
    'returnId' => $return->id,
]);

Log::info('Return in progress');

Log::info('Return completed');

Is there anything that wouldn't be possible with that approach instead, @cosmastech?

Context data is intentionally put in extra as it isn't meant to be related to the individual log messages but the state of the world the log message occur within. Having it written to the log's context array would mean individual log messages could override its data, which I would find unexpected.

@cosmastech
Copy link
Contributor Author

I did not know about the Log::sharedContext() method. TIL.

Context data is intentionally put in extra as it isn't meant to be related to the individual log messages but the state of the world the log message occur within. Having it written to the log's context array would mean individual log messages could override its data, which I would find unexpected.

Conceptually, having two distinct buckets of structured log data (context vs extra) ends up being more confusing for me in practice, especially when the API surfaces both use the name context, but the data from Context ultimately lives under extra.

Context::scope(function () {
    Log::info('Processing athlete payment', context: ['athlete_id' => 123]);
}, data: ['athlete_id' => 987]);

To me, reading the facade name and second parameter of the info() method, I would expect those two things to be writing data to the same place, with the Log::info() context taking higher precedence.

In order to be able to write queries to extract, say, all logs related to processing payment_id=abc-123, I need to write a query like "@context.payment_id=abc-123 OR @context.extra.payment_id=abc-123". It's more verbose, and it requires knowing how the data was attached, which becomes fragile once logs pass through multiple modules owned by different teams with slightly different practices.

That said, I have patched the Context functionality a few times so I am aware of how it works. Maybe the average Laravel dev doesn't really care or think about this fact. But the functionality I'm proposing is tucked away pretty nicely and I doubt most people would even use it.

This suggestion is less about feasibility and more about whether the default aligns with how devs intuitively reason about structured log context.

*
* @var 'extra'|'context'
*/
public static string $writeContextTo = 'extra';
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Can this not be an instance property?

Comment on lines +69 to +79
public static function writeContextToLogExtra(): void
{
Repository::$writeContextTo = 'extra';
}

/**
* Write context data under the structured log's "context" key.
*/
public static function writeContextToLogContext(): void
{
Repository::$writeContextTo = 'context';
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Can these not live on the context repository class?

@timacdonald
Copy link
Member

I'll leave the decision to Taylor. I've dropped some comments in case Taylor is keen on it. I feel these should all be instance methods and called via the Facade in your service provider, so it should all work without the need for statics, unless I'm missing something.

@cosmastech
Copy link
Contributor Author

I'll leave the decision to Taylor. I've dropped some comments in case Taylor is keen on it. I feel these should all be instance methods and called via the Facade in your service provider, so it should all work without the need for statics, unless I'm missing something.

Thanks @timacdonald. 🙇

I'll wait for Taylor's input before I make the changes just to save myself the time if the functionality isn't desired at this time.

@taylorotwell
Copy link
Member

Hmm, I think I'll table for now. May revisit later. 🫶

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

3 participants