Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

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

Closed
jamesRUS52 opened this issue Nov 13, 2023 · 9 comments
Closed

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

jamesRUS52 opened this issue Nov 13, 2023 · 9 comments
Assignees

Comments

@jamesRUS52
Copy link

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
Copy link
Member

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.

Thanks!

@Kovah
Copy link

Kovah commented Jan 7, 2024

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
Copy link
Member

Which log channel are you both using?

@driesvints
Copy link
Member

@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
Copy link

Kovah commented Jan 8, 2024

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
Copy link
Contributor

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

if (method_exists($app['log']->driver(), 'withoutContext')) {
$app['log']->withoutContext();
}

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
Copy link
Member

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

@driesvints
Copy link
Member

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
Copy link
Contributor

@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.

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

No branches or pull requests

6 participants