Laravel Queue with Supervisor, running but not processing jobs

php laravel supervisord
Styphon picture Styphon · Oct 19, 2015 · Viewed 17.2k times · Source

I have set up Laravel Queue using the database and I've configured Supervisor to keep it running, however it stops processing the queue after a while.

I'm using Mail::queue to send e-mails. If I SSH into the server and run php /home/my/path/to/artisan --env=production --timeout=240 queue:listen --tries=5 then it works fine and the e-mails send. But obviously I don't want to have to SSH in to process the e-mails, I want the queue running 24/7 so I installed supervisor to manage this. I have edited my supervisord.conf file to include the following program:

[program:laravel_queue]
command=php /home/my/path/to/artisan --env=production --timeout=240 queue:listen --tries=5
autostart=true
autorestart=true
logfile=/var/log/laraqueue.log

And when I start the program it works, my e-mails send. However after some time (normally the next day) the e-mails wont send. I check the database and the jobs table is filling up. When I SSH into the server and run supervisorctl status I get:

laravel_queue  RUNNING    pid 21081, uptime 2 days, 23:18:51

It's saying 2 days as it's been running over the weekend and not working today (Monday). Clearly it's not running, so how do I get supervisord to recognise that it's not running and restart it?

If I manually restart it with supervisorctl restart laravel_queue, because it's not running supervisor can't stop it and just seems to hang until I press CTRL + C. At which point I get a traceback that I don't understand:

Traceback (most recent call last):
  File "/usr/bin/supervisorctl", line 6, in <module>
    main()
  File "/usr/lib/python2.6/site-packages/supervisor/supervisorctl.py", line 598, in main
    c.onecmd(" ".join(options.args))
  File "/usr/lib/python2.6/site-packages/supervisor/supervisorctl.py", line 86, in onecmd
    return func(arg)
  File "/usr/lib/python2.6/site-packages/supervisor/supervisorctl.py", line 467, in do_restart
    self.do_stop(arg)
  File "/usr/lib/python2.6/site-packages/supervisor/supervisorctl.py", line 433, in do_stop
    result = supervisor.stopProcess(processname)
  File "/usr/lib64/python2.6/xmlrpclib.py", line 1199, in __call__
    return self.__send(self.__name, args)
  File "/usr/lib64/python2.6/xmlrpclib.py", line 1489, in __request
    verbose=self.__verbose
  File "/usr/lib/python2.6/site-packages/supervisor/options.py", line 1309, in request
    errcode, errmsg, headers = h.getreply()
  File "/usr/lib64/python2.6/httplib.py", line 1064, in getreply
    response = self._conn.getresponse()
  File "/usr/lib64/python2.6/httplib.py", line 990, in getresponse
    response.begin()
  File "/usr/lib64/python2.6/httplib.py", line 391, in begin
    version, status, reason = self._read_status()
  File "/usr/lib64/python2.6/httplib.py", line 349, in _read_status
    line = self.fp.readline()
  File "/usr/lib64/python2.6/socket.py", line 433, in readline
    data = recv(1)
KeyboardInterrupt

Checking the status again reports the queue as stopped, so I run supervisorctl start laravel_queue and I get the same hang as when running restart, but it has started as the jobs are processed and e-mails sent. If I press CTRL + C again I get the same traceback as above.

Log

I've checked the laraqueue log after leaving it over night. I tried to send an e-mail this morning and the job table is just sitting there waiting to process. The log is just full of this:

X-Powered-By: PHP/5.6.10^M
Content-type: text/html; charset=UTF-8^M
^M

That's it. Just lots of that being repeated.

I've checked the supervisor log and it just reports the successful start of laravel_queue. For completion the log is:

2015-10-21 14:25:24,997 INFO /var/tmp/supervisor.sock:Medusa (V1.1.1.1) started at Wed Oct 21 14:25:24 2015
    Hostname: <unix domain socket>
    Port:/var/tmp/supervisor.sock
2015-10-21 14:25:25,099 CRIT Running without any HTTP authentication checking
2015-10-21 14:25:25,107 INFO daemonizing the process
2015-10-21 14:25:25,108 INFO supervisord started with pid 3407
2015-10-21 14:25:25,115 INFO spawned: 'laravel_queue' with pid 3409
2015-10-21 14:25:26,729 INFO success: laravel_queue entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)



UPDATE

After updating supervisor to the latest version, I'm still having the same issue. The laraqueue.log has the same content as before, nothing useful. However the supervisor log has a little more in it this time:

2015-10-22 10:19:59,454 CRIT received SIGTERM indicating exit request
2015-10-22 10:19:59,454 INFO waiting for laravel_queue to die
2015-10-22 10:19:59,460 INFO stopped: laravel_queue (terminated by SIGTERM)
2015-10-22 10:19:59,460 INFO received SIGCLD indicating a child quit
2015-10-22 10:26:02,019 CRIT Supervisor running as root (no user in config file)
2015-10-22 10:26:02,085 CRIT Server 'inet_http_server' running without any HTTP authentication checking
2015-10-22 10:26:02,092 INFO daemonizing the supervisord process
2015-10-22 10:26:02,093 INFO supervisord started with pid 17268
2015-10-22 10:26:03,105 INFO spawned: 'laravel_queue' with pid 17269
2015-10-22 10:26:04,107 INFO success: laravel_queue entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2015-10-22 10:37:22,157 WARN received SIGTERM indicating exit request
2015-10-22 10:37:22,157 INFO waiting for laravel_queue to die
2015-10-22 10:37:22,163 INFO stopped: laravel_queue (terminated by SIGTERM)

There was a couple instances of supervisor receiving the exit request and starting it back up, and then the end of the log is above where it stops the queue, but doesn't start it again for some reason. I've checked the laravel log (in storage/logs) but there's nothing in there for around that time.

Answer

NickNo picture NickNo · Oct 22, 2015

Check what version of Supervisor you have. Some package managers have been known to forget to update Supervisor. I think your problem will be fixed by updating Supervisor. For example v2.1 of Supervisor is from 2007 and is still in some packages.

Current version of Supervisor is v3.13 though some say (see reference at bottom) v3 is the last stable version.

Check what version of Supervisor you are using

[root@test supervisor]# yum list | grep supervisor

Compare version shown to: https://pypi.python.org/pypi/supervisor

Remove and Install (easy install is nice)

[root@test ~]$ yum remove supervisor
[root@test ~]$ wget https://bitbucket.org/pypa/setuptools/raw/bootstrap/ez_setup.py -O - | sudo python
[root@test ~]$ sudo easy_install supervisor
Searching for supervisor
Reading https://pypi.python.org/simple/supervisor/
Best match: supervisor 3.0

Update:

Please take a moment to look here, it's well worth it ( http://ahmed.amayem.com/running-a-node-js-app-ghost-in-the-background-continuously-with-supervisor-supervisord/ ). Though he is running node.js/ghost with Supervisor, I don't think that matters since this is all about Supervisor!

Refs: https://github.com/Supervisor/supervisor/issues/165

http://ahmed.amayem.com/running-a-node-js-app-ghost-in-the-background-continuously-with-supervisor-supervisord/

http://ahmed.amayem.com/woes-of-using-an-outdated-supervisord-to-run-a-node-js-app-ghost/

Related questions

Laravel Queue Failed Jobs

I was trying to record some data from other table when the jobs fails. It works great in failed jobs table but I cant get the Queue::failing(function($connection, $job, $data) to work every time the job failed. I …

Read More
How Do I Get the Query Builder to Output Its Raw SQL Query as a String?

Given the following code: DB::table('users')->get(); I want to get the raw SQL query string that the database query builder above will generate. In this example, it would be SELECT * FROM users. How do I do …

Read More
How to Create Multiple Where Clause Query Using Laravel Eloquent?

I'm using the Laravel Eloquent query builder and I have a query where I want a WHERE clause on multiple conditions. It works, but it's not elegant. Example: $results = User::where('this', '=', 1) ->where('that', '=', 1) …

Read More