Laravel logging not working from job handle method

Question

I can't log anything from my Job's handle method, with the Log facade. Logging from controller or other part of the application with this facade works fine.

I have tried the solution here : Logging not working in laravel queue job, but it does not work with Laravel 6.17, and here : https://stackoverflow.com/a/55206727/10767428 , but it does not affect behaviour in any way.

PHP 7.2
Laravel 6.17
APP_ENV=local
APP_LOG_LEVEL=debug
Laravel runs inside Docker with Alpine image and other stuff unrelated

Here is my job :

class MyJob implements ShouldQueue
{
    use Dispatchable;
    use InteractsWithQueue;
    use Queueable;
    use SerializesModels;

    public function handle()
    {
       Log::warning("HI");
    }
}

The Job is correctly handled when I dispatch if, but nothing shows up in my storage/app/logs/laravel.log.

This file and the entire folder storage has 777 permissions.

I use "single" driver in config/logging.php :

        'single' => [
            'driver' => 'single',
            'path' => storage_path('logs/laravel.log'),
            'level' => 'debug',
        ],

Any ideas?

EDIT 07/17/2020

As requested, here is my config.horizon.php :

https://pastebin.com/jkQLcDKF

EDIT 07/20/2020

I can log from the same job when I use dipatchNow method to call it, instead of dispatch one. Any ideas why ?

I don't know your docker image, did you try docker logs Many docker images redirect default log files, to stderr... so maybe, the unrelated stuff might be related — Danny Ebbers, Jul 17 '20 at 13:30
If you have run the worker as php artisan queue:work, it needs to be resarted, if you modify config. And what queue connection (driver) are you using? — Danny Ebbers, Jul 17 '20 at 13:32
I am with @DannyEbbers here, I think it is a docker config issue. I would check to make sure you are using app/storage as shared volume with your container. — Kurt Friars, Jul 17 '20 at 13:44
Thank you guys @DannyEbbers, and Kurt Friars, and N69S , let me try what you suggest, and I'll tell you if I get results. I use Horizon to get the worker runnings, so I start the workers with `php artisan horizon`. I think horizon takes care of restarting the workers, but I'll try to restart it manually. The queue connection is `redis` and also `rabbitmq`, depending on the job. But they all don't log anything. — vittorio, Jul 17 '20 at 13:54
So I checked, and yes I am already sharing my entire root project with the docker container : `"./:/www"` in docker-compose file. If it was a docker problem, I shouldn't be able to log from anywhere in the app, should I ? I am able to log to `laravel.log` file from everywhere, except from these very job's handle methods. `docker logs` shows only the logs of the http calls to internal nginx server. Whether I use `queue:work` or `horizon` to start workers don't change anything. Both workers are incapable of looging. I tried to restart worker manually, no result. I'll keep looking. — vittorio, Jul 17 '20 at 14:16
can you add your horizon config to your question ? `config/horizon.php` — N69S, Jul 17 '20 at 14:44
Hi @vittorio, did you managed to solve this issue? I am experiencing the exact same thing, not being able to log from Job's handle method when executing through queue:work on supervisor. Thanks in advance! — Igor de Lorenzi, Aug 11 '21 at 13:25
I just forgot to restart job after changes made in function. — softech, Sep 14 '22 at 14:14

score 1 · Answer 1 · answered Jul 17 '20 at 13:43

1

If your queue is running on Supervisor, your log would be in the Supervisor logs. Share your queue/supervisor configuration if you're not able to find it. You could also check your docker logs as well.

answered Jul 17 '20 at 13:43

sykez

2,015
15
14

Thank you @sykez. I am not running supervisor at the moment, cause I'm working only locally for development. I just lauch `php artisan horizon` from project container and keep this process in the foreground of my terminal. I checked for docker logs, but I get only http calls, not custom message or php exceptions. I'll keep looking. – vittorio Jul 17 '20 at 14:24
@vittorio I see. Sorry, for the late reply. Are you able to confirm your dispatched jobs are executed or not? Do see any output on your foreground terminal running horizon or your horizon dashboard? Also how exactly are your jobs dispatched, calling via tinker, http request, cron/schedule? I assume your `QUEUE_DRIVER` is already set to `redis`, correct? If you recently changed this, perhaps you'll need to clear cache with `php artisan config:clear`. When you use `dipatchNow`, basically it runs synchronously (like sync driver). – sykez Jul 20 '20 at 15:11
Thank you @sykez. Yes, I can confirm my dispatched jobs are executed, since Horizon show them in "recent jobs" section and I see expected results in database (the job performs some update in database). Yes, I see output on my terminal from horizon (things like "processing MyJob... processed MyJob", etc.). When I var_dump from the job, I get the output in the terminal (in the same TTY as horizon is running). For testing purpose, I dispatch the jobs via a simple API call, so via http request. But I get same result when I dispatch them from smw else. Yes QUEUE_DRIVER is set to 'redis'. – vittorio Jul 21 '20 at 14:19
@vittorio I see. I suggest to setup Supervisor to run your Horizon. I believe it might help :) – sykez Jul 21 '20 at 19:44
All right @sykez, I will try what you suggest. Right now, I'm still on local. As soon as I go on production with Supervisor, I'll see if it changes. If it does, I'll mark your response as accepted. Thank you for your help. – vittorio Jul 22 '20 at 19:16

score 1 · Answer 2 · answered Dec 24 '21 at 15:34

If anyone else is having issues, Horizon has to be restarted when changes are made to the jobs. Otherwise, the job that runs will not reflect your code changes.

This is regardless of the environment. That's why it's a good idea to restart horizon when you re-deploy to the server.

Laravel logging not working from job handle method

2 Answers2