Logo Questions Linux Laravel Mysql Ubuntu Git Menu
 

Django - Deployment with Gunicorn, Nginx and Supervisor, Gunicorn error log

I've deployed a Django 1.6 app with Gunicorn + Nginx + Supervisor. Everything is working OK, but I have the Gunicorn error.log sending errors all the time. The file is huge, it sends errors to the log file every second.

The error from the Gunicorn error.log:

2014-02-27 14:25:09 [9235] [INFO] Starting gunicorn 18.0
2014-02-27 14:25:09 [9235] [ERROR] Connection in use: ('127.0.0.1', 8000)
2014-02-27 14:25:09 [9235] [ERROR] Retrying in 1 second.
2014-02-27 14:25:10 [9235] [ERROR] Connection in use: ('127.0.0.1', 8000)
2014-02-27 14:25:10 [9235] [ERROR] Retrying in 1 second.
2014-02-27 14:25:11 [9235] [ERROR] Connection in use: ('127.0.0.1', 8000)
2014-02-27 14:25:11 [9235] [ERROR] Retrying in 1 second.
2014-02-27 14:25:12 [9235] [ERROR] Connection in use: ('127.0.0.1', 8000)
2014-02-27 14:25:12 [9235] [ERROR] Retrying in 1 second.
2014-02-27 14:25:13 [9235] [ERROR] Connection in use: ('127.0.0.1', 8000)
2014-02-27 14:25:13 [9235] [ERROR] Retrying in 1 second.
2014-02-27 14:25:14 [9235] [ERROR] Can't connect to ('127.0.0.1', 8000)
2014-02-27 14:25:16 [9250] [INFO] Starting gunicorn 18.0
    2014-02-27 14:25:16 [9250] [ERROR] Connection in use: ('127.0.0.1', 8000)
2014-02-27 14:25:16 [9250] [ERROR] Retrying in 1 second.
2014-02-27 14:25:17 [9250] [ERROR] Connection in use: ('127.0.0.1', 8000)
2014-02-27 14:25:17 [9250] [ERROR] Retrying in 1 second.
2014-02-27 14:25:18 [9250] [ERROR] Connection in use: ('127.0.0.1', 8000)
2014-02-27 14:25:18 [9250] [ERROR] Retrying in 1 second.
2014-02-27 14:25:19 [9250] [ERROR] Connection in use: ('127.0.0.1', 8000)
2014-02-27 14:25:19 [9250] [ERROR] Retrying in 1 second.
2014-02-27 14:25:20 [9250] [ERROR] Connection in use: ('127.0.0.1', 8000)
2014-02-27 14:25:20 [9250] [ERROR] Retrying in 1 second.
2014-02-27 14:25:21 [9250] [ERROR] Can't connect to ('127.0.0.1', 8000)
2014-02-27 14:25:24 [9261] [INFO] Starting gunicorn 18.0
2014-02-27 14:25:24 [9261] [ERROR] Connection in use: ('127.0.0.1', 8000)
2014-02-27 14:25:24 [9261] [ERROR] Retrying in 1 second.
2014-02-27 14:25:25 [9261] [ERROR] Connection in use: ('127.0.0.1', 8000)
2014-02-27 14:25:25 [9261] [ERROR] Retrying in 1 second.
2014-02-27 14:25:26 [9261] [ERROR] Connection in use: ('127.0.0.1', 8000)
2014-02-27 14:25:26 [9261] [ERROR] Retrying in 1 second.
2014-02-27 14:25:27 [9261] [ERROR] Connection in use: ('127.0.0.1', 8000)
2014-02-27 14:25:27 [9261] [ERROR] Retrying in 1 second.
2014-02-27 14:25:28 [9261] [ERROR] Connection in use: ('127.0.0.1', 8000)
2014-02-27 14:25:28 [9261] [ERROR] Retrying in 1 second.
2014-02-27 14:25:29 [9261] [ERROR] Can't connect to ('127.0.0.1', 8000)

My supervisor.conf:

[program:mydjangoapp]
command=/home/myuser/virtualenv_mydjangoapp/bin/python manage.py run_gunicorn
directory=/home/myuser/webapps/mydjangoapp
user=myuser
autostart=True
autorestart=True
stdout_logfile = /home/myuser/webapps/mydjangoapp_logs/gunicorn/out.log
stderr_logfile = /home/myuser/webapps/mydjangoapp_logs/gunicorn/err.log

My Nginx virtual.conf:

server {
   listen 80;
   client_max_body_size 1G;
   server_name 0.0.0.0;

   keepalive_timeout 5;
   access_log /home/myuser/webapps/mydjangoapp_logs/nginx/access.log;
   error_log /home/myuser/webapps/mydjangoapp_logs/nginx/error.log;

   location /static {
       alias /home/myuser/webapps/mydjangoapp_static;
   }

   location / {
       proxy_set_header X-Forwarded-For $proxy_add_x_forwarded_for;

       proxy_set_header Host $http_host;
       proxy_redirect off;
       proxy_pass http://localhost:8000;
   }
}

My netstat -tulpn:

Active Internet connections (only servers)
Proto Recv-Q Send-Q Local Address           Foreign Address         State       PID/Program name
tcp        0      0 127.0.0.1:8000          0.0.0.0:*               LISTEN      2719/python     
tcp        0      0 127.0.0.1:3306          0.0.0.0:*               LISTEN      2606/mysqld     
tcp        0      0 0.0.0.0:46028           0.0.0.0:*               LISTEN      2757/beam.smp     
tcp        0      0 0.0.0.0:80              0.0.0.0:*               LISTEN      2613/nginx      
tcp        0      0 0.0.0.0:4369            0.0.0.0:*               LISTEN      2663/epmd       
tcp        0      0 0.0.0.0:85              0.0.0.0:*               LISTEN      2613/nginx      
tcp        0      0 0.0.0.0:22              0.0.0.0:*               LISTEN      2469/sshd       
tcp6       0      0 :::5672                 :::*                    LISTEN      2757/beam.smp   
tcp6       0      0 :::22                   :::*                    LISTEN      2469/sshd       
udp        0      0 0.0.0.0:68              0.0.0.0:*                           2395/dhclient3        
udp        0      0 0.0.0.0:123             0.0.0.0:*                           3127/ntpd       
udp        0      0 0.0.0.0:1900            0.0.0.0:*                           2551/minissdpd        
udp6       0      0 ::1:123                 :::*                                3127/ntpd       
udp6       0      0 :::123                  :::*                                3127/ntpd       

My supervisord.log:

2014-02-27 16:14:56,300 CRIT Supervisor running as root (no user in config file)
2014-02-27 16:14:56,303 CRIT Supervisor running as root (no user in config file)
2014-02-27 16:14:56,413 INFO RPC interface 'supervisor' initialized
2014-02-27 16:14:56,413 CRIT Server 'unix_http_server' running without any HTTP authentication checking
2014-02-27 16:14:56,414 INFO supervisord started with pid 2510
2014-02-27 16:14:56,651 INFO RPC interface 'supervisor' initialized
2014-02-27 16:14:56,651 CRIT Server 'unix_http_server' running without any HTTP authentication checking
2014-02-27 16:14:56,657 INFO daemonizing the supervisord process
2014-02-27 16:14:56,658 INFO supervisord started with pid 2687
2014-02-27 16:14:57,453 INFO spawned: 'celery' with pid 2786
2014-02-27 16:14:57,466 INFO spawned: 'mydjangoapp' with pid 2787
2014-02-27 16:14:57,666 INFO spawned: 'celery' with pid 2842
2014-02-27 16:14:57,673 INFO spawned: 'mydjangoapp' with pid 2846
2014-02-27 16:14:58,471 INFO success: mydjangoapp entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2014-02-27 16:14:58,676 INFO success: mydjangoapp entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2014-02-27 16:15:09,284 INFO success: celery entered RUNNING state, process has stayed up for > than 10 seconds (startsecs)
2014-02-27 16:15:09,313 INFO success: celery entered RUNNING state, process has stayed up for > than 10 seconds (startsecs)
2014-02-27 16:15:13,438 INFO exited: mydjangoapp (exit status 1; not expected)
2014-02-27 16:15:14,445 INFO spawned: 'mydjangoapp' with pid 3164
2014-02-27 16:15:15,830 INFO success: mydjangoapp entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2014-02-27 16:15:20,539 INFO exited: mydjangoapp (exit status 1; not expected)
2014-02-27 16:15:21,546 INFO spawned: 'mydjangoapp' with pid 3264
2014-02-27 16:15:22,549 INFO success: mydjangoapp entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2014-02-27 16:15:27,669 INFO exited: mydjangoapp (exit status 1; not expected)
2014-02-27 16:15:28,676 INFO spawned: 'mydjangoapp' with pid 3275
2014-02-27 16:15:29,679 INFO success: mydjangoapp entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2014-02-27 16:15:35,166 INFO exited: mydjangoapp (exit status 1; not expected)
2014-02-27 16:15:36,173 INFO spawned: 'mydjangoapp' with pid 3286
2014-02-27 16:15:37,175 INFO success: mydjangoapp entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2014-02-27 16:15:42,332 INFO exited: mydjangoapp (exit status 1; not expected)
2014-02-27 16:15:43,339 INFO spawned: 'mydjangoapp' with pid 3295

My supervisorctl status output:

root@li199-188:/var/log# supervisorctl status
celery                           RUNNING    pid 2842, uptime 0:04:05
mydjangoapp                      RUNNING    pid 3815, uptime 0:00:03

Any clue on what's causing the errors in the Gunicorn log file? As I said everything is working without a problem. The only problem is this log that keeps sending errors.

Best Regards,

like image 621
André Avatar asked Feb 27 '14 14:02

André


People also ask

How do I get Gunicorn error logs?

To watch the logs in the console you need to use the option --log-file=- . In version 19.2, Gunicorn logs to the console by default again.

Can I use Gunicorn without nginx?

Nginx Configuration Although there are many HTTP proxies available, we strongly advise that you use Nginx. If you choose another proxy server you need to make sure that it buffers slow clients when you use default Gunicorn workers. Without this buffering Gunicorn will be easily susceptible to denial-of-service attacks.

Why do I need nginx with Gunicorn?

Nginx and Gunicorn work togetherGunicorn translates requests which it gets from Nginx into a format which your web application can handle, and makes sure that your code is executed when needed. They make a great team! Each can do something, which the other can't.


2 Answers

This usually happens when gunicorn processes are retried a few times and if you happens to start a process on a port (8000 in your case) while the previous proc is about to finish and so on. So, you need to terminate all such processes individually.

  • You can use netstat -tulpn to see the PID
  • kill -9 PID

The other waiting procs will autostart in the cyclic wait case. so repeatedly check with netstat and kill them until no more processes are found running on that port.

Gunicorn processes should work fine at this point.

like image 128
user4212639 Avatar answered Oct 07 '22 11:10

user4212639


As the error logs says, it looks like there's an application already listening on port 8000. Maybe you launched gunicorn from command line ant it is already running in that port.

You could use netstat -tulpn to see if there's an instance of python listening on that port and kill it.

Hope that helps.

like image 39
Guilherme Vierno Avatar answered Oct 07 '22 12:10

Guilherme Vierno