Log Context not working on queue:work running in daemon mode

[jamesRUS52]

Laravel Version

10.28

PHP Version

8.2

Database Driver & Version

No response

Description

When adding log context to app service provider and try to logging in queue job no context appear in a log

this behavior only if queue:work in daemon mode running e.g. artisan queue:work

if we run artisan queue:work --once or artisan queue:listen

log context appears in the log as expected

Steps To Reproduce

Add to boot method of AppServiceProvider

Log::shareContext(['foo' => 'bar']);

in any job throw any Exception

run artisan queue:work

No foo bar in log aapears

[driesvints]

Hey there,

Can you first please try one of the support channels below? If you can actually identify this as a bug, feel free to open up a new issue with a link to the original one and we'll gladly help you out.

• Laracasts Forums
• Laravel.io Forums
• StackOverflow
• Discord
• Larachat
• IRC

Thanks!

[Kovah]

Hi @driesvints would you consider re-opening this issue? I have this issue too and have not found any solution yet. Also posted to Laracast discussions, but nobody seems to know an answer.

I have also set up a clean repo with the latest Laravel version to replicate this: https://github.com/Kovah/Horizon-Log-Context-Test

[driesvints]

Which log channel are you both using?

[driesvints]

@Kovah can you please re-create your repo and commit your custom changes separately from the Laravel app?

laravel new bug-report --github="--public"

[Kovah]

I have updated the repo with a new setup where Laravel, horizon and the testing changes are separate commits: https://github.com/Kovah/Horizon-Log-Context-Test/commits/main/

This issue seems to be independent from the log channel, as it happens with the file, stderr and a custom Monolog driver for Loki.

[rodrigopedra]

@driesvints the Log::withoutContext() method, which clears any previous context, before each worker loop, as its $resetScope closure.

https://github.com/laravel/framework/blob/ab9f7c4cf563be95f6e9046bce4a92801627b282/src/Illuminate/Queue/QueueServiceProvider.php#L201-L203

This change was introduced by PR #37865 3 years ago.

There is no info on the PR about the reasoning, but I guess it is to avoid a memory leak in case several different jobs call Log::shareContext() from within their handle() method.

Which makes sense to prevent shared info across jobs, but if someone follows the doc's recommendation, they shouldn't be calling Log::shareContext() from within a job.

@jamesRUS52 and @Kovah one workaround is to create a listener for the Illuminate\Queue\Events\JobProcessing and also share the context from there.

[driesvints]

Yeah it indeed does seem that PR is the reason for this. I'll investigate.

[driesvints]

So this is actually all expected. I'll try to explain as best as I can. The shared log context is reset after each job handling or after an Octane request. It's only meant to live once during a request lifecycle. So in daemon mode it gets reset. The example in the docs also only demonstrates it being used in a middleware: https://laravel.com/docs/10.x/logging#contextual-information

This is probably to prevent memory leaks. If you need a persistent context between jobs, it's probably best to add that context to the job directly.

[rodrigopedra]

@driesvints I agree there is not much we can do about this, but the example about the Log::shareContext() is the last one in that section, which advises adding a call to this method to a Service Provider's boot() method.

See: https://laravel.com/docs/10.x/logging#contextual-information (scroll to the end of this section)

Note that there are two different methods being referred to in that doc's section Log::withContext() (which the example advises to be added to a middleware) and the Log::shareContext() referred above, and which is the object of the issue report.

IMO, adding a note to the docs should suffice to clarify the Log::shareContext() behavior on queues.