Woes of using an outdated supervisord to run a node.js app (ghost)

The Situation

I wanted to run my ghost blog using supervisord. I decided to install supervisord by using yum. The result was pretty bad as it turned out that the version that I installed was waaayyyy behind, which caused so many problems. To install it properly check out these instructions. This is an account of the errors and issues I came upon. If you see any of these, you may need to update your supervisor.

Pre-requisites

  1. Root access to your server or have access to an account that has sudo powers on your servers – Instructions here to see how to give a linux user sudo powers.
  2. nodejs and npm installed – Instructions here.
  3. ghost installed and a ghost user made to run ghostInstructions here

What is supervisor

From the official supervisor page,

Supervisor is a client/server system that allows its users to monitor and control a number of processes on UNIX-like operating systems.

It shares some of the same goals of programs like launchd, daemontools, and runit. Unlike some of these programs, it is not meant to be run as a substitute for init as “process id 1”. Instead it is meant to be used to control processes related to a project or a customer, and is meant to start like any other program at boot time.

An important note here is it is meant to start like any other program at boot time. That means once supervisor is running our app we don’t have to worry about it surviving a reboot. It turns out that it survives a reboot by having an init script.

Installing supervisor

I am running CentOS, so my command was:

[ahmed@amayem ~]$ sudo yum install supervisor

You will be prompted to confirm, press y and enter. The output should end with Complete!.

Great. In the ghost deployment docs it is mentioned that we can check if it works by issuing the command:

[ahmed@amayem init.d]$ service supervisor start
supervisor: unrecognized service

It didn’t work. It might be a linux distro specific issue. Let’s try to figure it out.

Starting supervisor

First let’s go to where the services are registered and see what the name is: /etc/init.d.

[ahmed@amayem init.d]$ cd `/etc/init.d`
[ahmed@amayem init.d]$ ls | grep super
supervisord

Ah! So it had a different name. Let’s try it with the extra d

[ahmed@amayem init.d]$ service supervisord start
Starting supervisord: Traceback (most recent call last):
  File "/usr/bin/supervisord", line 6, in <module>
    main()
  File "/usr/lib/python2.6/site-packages/supervisor/supervisord.py", line 724, in main
    d.main(None, test, first)
  File "/usr/lib/python2.6/site-packages/supervisor/supervisord.py", line 453, in main
    self.options.make_logger(critical_messages, info_messages)
  File "/usr/lib/python2.6/site-packages/supervisor/options.py", line 1031, in make_logger
    backups=self.logfile_backups,
  File "/usr/lib/python2.6/site-packages/supervisor/options.py", line 494, in getLogger
    backups)
  File "/usr/lib/python2.6/site-packages/supervisor/options.py", line 162, in getLogger
    hdlr = RotatingRawFileHandler(filename, 'a', maxbytes, backups)
  File "/usr/lib/python2.6/site-packages/supervisor/options.py", line 103, in __init__
    RawFileHandler.__init__(self, filename, mode)
  File "/usr/lib/python2.6/site-packages/supervisor/options.py", line 32, in __init__
    logging.StreamHandler.__init__(self, open(filename, mode))
IOError: [Errno 13] Permission denied: '/var/log/supervisor/supervisord.log'
                                                           [FAILED]                                                            

Looks like the usual lack of permissions sudo error. However the error gave us some important information:

  1. We can run supervisor from /usr/bin/supervisord
  2. The python that the package manager installed is at /usr/lib/python2.6/

Anyways let’s add sudo:

[ahmed@amayem init.d]$ sudo service supervisord start
Starting supervisord:                                      [  OK  ]                                                           

It worked, but what is it doing now?

Checking supervised processes

We can see what supervisor is supervising by using supervisorctl. We didn’t see that name when we checked which services we had, so we will have to find it somewhere else. It was probably installed in the same place as supervisord. Luckily we already know that from the previous error: /usr/bin/ Let’s go there and check.

[ahmed@amayem bin]$ ls | grep supervisor
supervisorctl
supervisord

We found it. Let’s give it a try.

[ahmed@amayem bin]$ ./supervisorctl 
error: <class 'socket.error'>, [Errno 13] Permission denied: file: <string> line: 1
supervisor> 

Argh! Again with the sudo. Exit the process with ctrl+c then try again:

[ahmed@amayem bin]$ sudo ./supervisorctl 
supervisor> status
supervisor>

At the prompt we entered status to see what processes were running and we got back nothing. We have to setup the configuration to tell supervisor what to run.

Configuration Setup

First we need to find the configuration file. This should be somewhere in /etc

[ahmed@amayem ~]$ cd /etc/
[ahmed@amayem etc]$ ls | grep supervisor
supervisord.conf

There it is at /etc/supervisord.conf. The .conf file extension gives it away. If we take a look at the file we will see some examples of adding programs. Open the file with vi:

[ahmed@amayem etc]$ sudo vi supervisord.conf 

You need the sudo to be able to modify the file. Go to the bottom by pressing G, enter into insert mode i and paste the following:

[program:ghost]
command = node /path/to/ghost/index.js
directory = /path/to/ghost
user = ghost
autostart = true
autorestart = true
stdout_logfile = /var/log/supervisor/ghost.log
stderr_logfile = /var/log/supervisor/ghost_err.log
environment = NODE_ENV="production"

On my system the path to ghost is /var/www/ghost/. Also notice that we are using the ghost user. This should have been made when installing ghost. Please check these instructions for more information on how to do that. Exit insert mode with Esc or ctrl+c then save with :x and enter. Now lets try running it.

Running the app (ghost)

We can do this in two ways:

Restarting supervisor

[ahmed@amayem etc]$ sudo service supervisord stop
Stopping supervisord:                                      [  OK  ]
[ahmed@amayem etc]$ sudo service supervisord start
Starting supervisord:                                      [  OK  ]
[ahmed@amayem etc]$ cd /usr/bin
[ahmed@amayem bin]$ sudo ./supervisorctl 
ghost          RUNNING    pid 4139, uptime 0:01:13
supervisor>

Using supervisorctl

[ahmed@amayem bin]$ sudo ./supervisorctl start ghost

Something weird happens here where no prompt is returned. When you press ctrl+c then you get the following output:

[ahmed@amayem bin]$ sudo ./supervisorctl start ghost

^CTraceback (most recent call last):
  File "./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 369, in do_start
    result = supervisor.startProcess(processname)
  File "/usr/lib/python2.6/xmlrpclib.py", line 1199, in __call__
    return self.__send(self.__name, args)
  File "/usr/lib/python2.6/xmlrpclib.py", line 1489, in __request
    verbose=self.__verbose
  File "/usr/lib/python2.6/site-packages/supervisor/options.py", line 1308, in request
    errcode, errmsg, headers = h.getreply()
  File "/usr/lib/python2.6/httplib.py", line 1064, in getreply
    response = self._conn.getresponse()
  File "/usr/lib/python2.6/httplib.py", line 990, in getresponse
    response.begin()
  File "/usr/lib/python2.6/httplib.py", line 391, in begin
    version, status, reason = self._read_status()
  File "/usr/lib/python2.6/httplib.py", line 349, in _read_status
    line = self.fp.readline()
  File "/usr/lib/python2.6/socket.py", line 433, in readline
    data = recv(1)
KeyboardInterrupt

This seems to be a bug. This is the another hint that there is something wrong with supervisor. Let’s check if ghost is running.

[ahmed@amayem bin]$ sudo ./supervisorctl 
ghost          RUNNING    pid 4157, uptime 0:00:47

Yup, looks like it is.

Testing the app

Great now that we have ghost running let’s check it is working properly. Visit your site at port 2368, in my case it was http://ahmed.amayem.com:2368. Hmm, I got nothing. Maybe it’s the ghost configuration. Check your ghost config file at /path/to/ghost/config.js and make sure your host and port are what you expect them. They look good for me.

Searching for the log files

I guess it’s time to check the logs. We specified where we wanted the logs here:

stdout_logfile = /var/log/supervisor/ghost.log
stderr_logfile = /var/log/supervisor/ghost_err.log

Let’s go there

[ahmed@amayem bin]$ cd /var/log/supervisor/
-bash: cd: /var/log/supervisor/: Permission denied
[ahmed@amayem ghost]$ sudo cd /var/log/supervisor/
sudo: cd: command not found

Hmm we have a problem. For more information on this problem and how to overcome it please see these instructions. Let’s switch to root.

[ahmed@amayem bin]$ sudo su
[root@amayem bin]# cd /var/log/supervisor/

We are in! Let’s see what logs we have:

[root@amayem supervisor]# ls
supervisord.log

Hmm, I don’t see my ghost.log file. But supervisorctl told me it was running. Let’s check the supervisord.log.

[root@amayem supervisor]# less supervisord.log 

The logs look pretty good, especially this line:

2014-04-14 22:49:35,731 INFO success: ghost entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)

Hmm, so why am I seeing no logs. Let’s check the supervisor config file:

[root@amayem supervisor]# less supervisord.log 

I notice that my program entry is the only place where stdout_logfile or stderr_logfile is mentioned. The example program near the top does however have a logfile. Let’s add a logfile entry to our program and check. Restart the process or restart supervisor as mentioned before and let’s see if it’s there:

[root@amayem supervisor]# ls
ghost.log   supervisord.log

Ah there it is. Let’s check what we have:

[root@amayem supervisor]# less ghost.log 

ESC[32mGhost is running in development...ESC[39m 
Listening on 127.0.0.1:2368 
Url configured as: http://my-ghost-blog.com

Well it’s working alright, but it seems to be running in development mode. This is concerning because I specified the environment as “production” in the config file:

environment = NODE_ENV="production"

I tried different things like removing the quotation marks, removing the spaces etc. but to no effect. I finally stumbled upon this github closed issue, which suggested that recent versions didn’t have such a problem.

Searching for the version

Let’s check which version we have:

[root@amayem supervisor]# /usr/bin/supervisord -v
Error: option -v not recognized
For help, use /usr/bin/supervisord -h
[root@amayem supervisor]# /usr/bin/supervisord --version
Error: option --version not recognized
For help, use /usr/bin/supervisord -h

It won’t even tell me. I did another search and stumbled upon this github closed issue, which mentioned how behind some package managers were in keeping the package up to date. Let’s check which version we have.

[root@amayem supervisor]# yum list | grep supervisor
supervisor.noarch                       2.1-8.el6                      @epel    
nodejs-supervisor.noarch                0.5.2-5.el6                    epel

Wow it’s version 2.1. According to Pypi that version was released in 2007. No wonder we were having so much trouble. Let’s uninstall this version and get the latest version.

[root@amayem ghost]# yum remove supervisor

Done. Now let’s do this the right way.

References

  1. Ghost deployment docs
  2. This github closed issue.
  3. This github closed issue.

Ahmed Amayem has written 90 articles

A Web Application Developer Entrepreneur.