502 Bad Gateway from relocated instance on AWS EC2

Question

I tried to move some instance from tokio region (which by the way, it's working normally) to sao paulo region, then I followed this basic steps to perform but when I launch the instance from the generated AMI and turn on, it shows me "502 Bad Gateway" message in browser.

The principal components on this relocated server are: nginx, uwsgi, django, supervisor, new relic.

All configurations are the same for this relocated server, so I restarted all services, it seems that nginx is working well however it has a detail to apply the next config which is config file of my site:

nginx/sites-available/mysite:

server {
    listen 80;
    server_name mysite.com;

    access_log /var/log/nginx/site_access.log;
    error_log /var/log/nginx/site_error.log;

    location /static {
        alias  /home/ubuntu/apps/site/static/;
    }

    location /media/  {
        alias /home/ubuntu/apps/site/media/;
    }

    location / {
    client_max_body_size 400M;
    proxy_read_timeout 120;
        proxy_connect_timeout 120;
    proxy_set_header Host $http_host; 
        proxy_set_header X-Real-IP $remote_addr;
        proxy_set_header Client-IP $remote_addr;
        proxy_set_header X-Forwarded-For $remote_addr;
        proxy_pass http://127.0.0.1:8888;
    proxy_buffering off;
    }
}

To be honest, I expected it operate normally since http://127.0.0.1:8888 is working but I don't understand the reason why nginx conexion is broken, I need some help so that I can research a little more. what else am I forgetting?

UPDATE:

Well ... By the @Michael - sqlbot's suggestion I checked log files, according to this file:

/var/log/nginx/site_error.log

2015/04/06 15:34:31 [error] 832#0: *12 connect() failed (111: Connection refused)
while connecting to upstream, client:
190.233.157.2, server: mysite.com, request: "GET /favicon.ico HTTP/1.1", upstream:
"http://127.0.0.1:8888/favicon.ico", host: "54.207.136.99"

By what I'm going to verify the conexion again and it's what shows me:

$ ping 127.0.0.1

PING 127.0.0.1 (127.0.0.1) 56(84) bytes of data.
64 bytes from 127.0.0.1: icmp_req=1 ttl=64 time=0.035 ms
64 bytes from 127.0.0.1: icmp_req=2 ttl=64 time=0.028 ms
64 bytes from 127.0.0.1: icmp_req=3 ttl=64 time=0.028 ms
64 bytes from 127.0.0.1: icmp_req=4 ttl=64 time=0.026 ms
--- 127.0.0.1 ping statistics ---

And then I tried it with curl and after about 30 seconds, it prints the following:

$ curl 127.0.0.1:8888

curl: (56) Recv failure: Connection reset by peer

I'm having this strange error, what does it mean really ?

UPDATE 2:

There are config file of mysite on uwsgi and their logs file, however it's the same kind of messages of server on tokio (which is working normally), so I discard that this was a problem of uwsgi:

/etc/uwsgi/apps-enabled/mysite.ini

[uwsgi]
vhost = true
plugins = python
socket = /tmp/mysite.sock
master = true
enable-threads = true
processes = 2
wsgi-file = /home/ubuntu/apps/mysite/mysite/wsgi.py
virtualenv = /home/ubuntu/.venv/mysite
chdir = /home/ubuntu/apps/mysite
touch-reload = /home/ubuntu/apps/mysite/reload

/var/log/uwsgi/app/mysite.log

[uWSGI] getting INI configuration from /usr/share/uwsgi/conf/default.ini
[uWSGI] getting INI configuration from /etc/uwsgi/apps-enabled/mysite.ini
Sun Apr 12 18:29:55 2015 - *** Starting uWSGI 1.0.3-debian (64bit) on [Sun Apr 12 18:29:55 2015] ***
Sun Apr 12 18:29:55 2015 - compiled with version: 4.6.3 on 17 July 2012 02:26:54
Sun Apr 12 18:29:55 2015 - current working directory: /
Sun Apr 12 18:29:55 2015 - writing pidfile to /run/uwsgi/app/mysite/pid
Sun Apr 12 18:29:55 2015 - detected binary path: /usr/bin/uwsgi-core
Sun Apr 12 18:29:55 2015 - setgid() to 33
Sun Apr 12 18:29:55 2015 - setuid() to 33
Sun Apr 12 18:29:55 2015 - your memory page size is 4096 bytes
Sun Apr 12 18:29:55 2015 - VirtualHosting mode enabled.
Sun Apr 12 18:29:55 2015 - uwsgi socket 0 bound to UNIX address /run/uwsgi/app/mysite/socket fd 5
Sun Apr 12 18:29:55 2015 - uwsgi socket 1 bound to UNIX address /tmp/mysite.sock fd 6
Sun Apr 12 18:29:55 2015 - Python version: 2.7.3 (default, Aug  1 2012, 05:25:23)  [GCC 4.6.3]
Sun Apr 12 18:29:55 2015 - Set PythonHome to /home/ubuntu/.venv/mysite
Sun Apr 12 18:29:55 2015 - Python main interpreter initialized at 0x916120
Sun Apr 12 18:29:55 2015 - threads support enabled
Sun Apr 12 18:29:55 2015 - your server socket listen backlog is limited to 100 connections
Sun Apr 12 18:29:55 2015 - *** Operational MODE: preforking ***
Sun Apr 12 18:29:57 2015 - WSGI application 0 (mountpoint='') ready on interpreter 0x916120 pid: 1137 (default app)
Sun Apr 12 18:29:57 2015 - *** uWSGI is running in multiple interpreter mode ***
Sun Apr 12 18:29:57 2015 - spawned uWSGI master process (pid: 1137)
Sun Apr 12 18:29:57 2015 - spawned uWSGI worker 1 (pid: 1236, cores: 1)
Sun Apr 12 18:29:57 2015 - spawned uWSGI worker 2 (pid: 1237, cores: 1)
Sun Apr 12 18:29:57 2015 - unable to stat() /home/ubuntu/apps/mysite/reload, reload will be triggered as soon as the file is created

UPDATE 3:

I typed netstat -nap -p | grep 8888 and it shows me:

tcp        0      0 127.0.0.1:8888          0.0.0.0:*               LISTEN      7550/python

then I typed ps aux | grep 7550 and ...

ubuntu    7550  2.4  0.4  65752 15568 ?        S    21:44   0:00 /home/ubuntu/.venv/mysite/bin/python /home/ubuntu/.venv/mysite/bin/gunicorn_django -w 3 --user=ubuntu --group=ubuntu --log-level=debug --timeout 120 --log-file=/var/log/gunicorn/mysite.log -b 127.0.0.1:8888
ubuntu    7585  0.0  0.0   8104   924 pts/1    S+   21:44   0:00 grep --color=auto 7550

Well, I checked with cat /var/log/gunicorn/mysite.log and I got this:

Traceback (most recent call last):
  File "/home/ubuntu/.venv/mysite/bin/gunicorn_django", line 8, in <module>
    load_entry_point('gunicorn==0.14.6', 'console_scripts', 'gunicorn_django')()
  File "/home/ubuntu/.venv/mysite/local/lib/python2.7/site-packages/gunicorn/app/djangoapp.py", line 132, in run
    DjangoApplication("%prog [OPTIONS] [SETTINGS_PATH]").run()
  File "/home/ubuntu/.venv/mysite/local/lib/python2.7/site-packages/gunicorn/app/base.py", line 124, in run
    Arbiter(self).run()
  File "/home/ubuntu/.venv/mysite/local/lib/python2.7/site-packages/gunicorn/arbiter.py", line 185, in run
    self.halt(reason=inst.reason, exit_status=inst.exit_status)
  File "/home/ubuntu/.venv/mysite/local/lib/python2.7/site-packages/gunicorn/arbiter.py", line 280, in halt
    self.stop()
  File "/home/ubuntu/.venv/mysite/local/lib/python2.7/site-packages/gunicorn/arbiter.py", line 328, in stop
    self.reap_workers()
  File "/home/ubuntu/.venv/mysite/local/lib/python2.7/site-packages/gunicorn/arbiter.py", line 419, in reap_workers
    raise HaltServer(reason, self.WORKER_BOOT_ERROR)
gunicorn.errors.HaltServer: <HaltServer 'Worker failed to boot.' 3>
2015-04-12 21:44:36 [7550] [INFO] Starting gunicorn 0.14.6
2015-04-12 21:44:36 [7550] [DEBUG] Arbiter booted
2015-04-12 21:44:36 [7550] [INFO] Listening at: http://127.0.0.1:8888 (7550)
2015-04-12 21:44:36 [7550] [INFO] Using worker: sync
2015-04-12 21:44:36 [7558] [INFO] Booting worker with pid: 7558
2015-04-12 21:44:36 [7559] [INFO] Booting worker with pid: 7559
2015-04-12 21:44:36 [7560] [INFO] Booting worker with pid: 7560
Production environment is up!
Production environment is up!
Production environment is up!

Well ... Gunicorn seems to be failing (it's inside virtualenv), so I checked the exucution on debug mode:

gunicorn mysite.wsgi:application --preload --debug --log-level debug

2015-04-12 22:32:42 [9085] [DEBUG] Current configuration:
2015-04-12 22:32:42 [9085] [DEBUG]   access_log_format: "%(h)s %(l)s %(u)s %(t)s "%(r)s" %(s)s %(b)s "%(f)s" "%(a)s"
2015-04-12 22:32:42 [9085] [DEBUG]   accesslog: None
2015-04-12 22:32:42 [9085] [DEBUG]   backlog: 2048
2015-04-12 22:32:42 [9085] [DEBUG]   bind: 127.0.0.1:8000
2015-04-12 22:32:42 [9085] [DEBUG]   check_config: False
2015-04-12 22:32:42 [9085] [DEBUG]   config: None
2015-04-12 22:32:42 [9085] [DEBUG]   daemon: False
2015-04-12 22:32:42 [9085] [DEBUG]   debug: True
2015-04-12 22:32:42 [9085] [DEBUG]   default_proc_name: mysite.wsgi:application
2015-04-12 22:32:42 [9085] [DEBUG]   django_settings: None
2015-04-12 22:32:42 [9085] [DEBUG]   errorlog: -
2015-04-12 22:32:42 [9085] [DEBUG]   graceful_timeout: 30
2015-04-12 22:32:42 [9085] [DEBUG]   group: 1000
2015-04-12 22:32:42 [9085] [DEBUG]   keepalive: 2
2015-04-12 22:32:42 [9085] [DEBUG]   limit_request_field_size: 8190
2015-04-12 22:32:42 [9085] [DEBUG]   limit_request_fields: 100
2015-04-12 22:32:42 [9085] [DEBUG]   limit_request_line: 4094
2015-04-12 22:32:42 [9085] [DEBUG]   logconfig: None
2015-04-12 22:32:42 [9085] [DEBUG]   logger_class: simple
2015-04-12 22:32:42 [9085] [DEBUG]   loglevel: debug
2015-04-12 22:32:42 [9085] [DEBUG]   max_requests: 0
2015-04-12 22:32:42 [9085] [DEBUG]   on_reload: <function on_reload at 0x7f6f421e9320>
2015-04-12 22:32:42 [9085] [DEBUG]   on_starting: <function on_starting at 0x7f6f421e91b8>
2015-04-12 22:32:42 [9085] [DEBUG]   pidfile: None
2015-04-12 22:32:42 [9085] [DEBUG]   post_fork: <function post_fork at 0x7f6f421e9758>
2015-04-12 22:32:42 [9085] [DEBUG]   post_request: <function post_request at 0x7f6f421e9b18>
2015-04-12 22:32:42 [9085] [DEBUG]   pre_exec: <function pre_exec at 0x7f6f421e98c0>
2015-04-12 22:32:42 [9085] [DEBUG]   pre_fork: <function pre_fork at 0x7f6f421e95f0>
2015-04-12 22:32:42 [9085] [DEBUG]   pre_request: <function pre_request at 0x7f6f421e9a28>
2015-04-12 22:32:42 [9085] [DEBUG]   preload_app: True
2015-04-12 22:32:42 [9085] [DEBUG]   proc_name: None
2015-04-12 22:32:42 [9085] [DEBUG]   pythonpath: None
2015-04-12 22:32:42 [9085] [DEBUG]   secure_scheme_headers: {'X-FORWARDED-PROTOCOL': 'ssl', 'X-FORWARDED-SSL': 'on'}
2015-04-12 22:32:42 [9085] [DEBUG]   spew: False
2015-04-12 22:32:42 [9085] [DEBUG]   timeout: 30
2015-04-12 22:32:42 [9085] [DEBUG]   tmp_upload_dir: None
2015-04-12 22:32:42 [9085] [DEBUG]   umask: 0
2015-04-12 22:32:42 [9085] [DEBUG]   user: 1000
2015-04-12 22:32:42 [9085] [DEBUG]   when_ready: <function when_ready at 0x7f6f421e9488>
2015-04-12 22:32:42 [9085] [DEBUG]   worker_class: sync
2015-04-12 22:32:42 [9085] [DEBUG]   worker_connections: 1000
2015-04-12 22:32:42 [9085] [DEBUG]   worker_exit: <function worker_exit at 0x7f6f421e9c80>
2015-04-12 22:32:42 [9085] [DEBUG]   workers: 1
2015-04-12 22:32:42 [9085] [DEBUG]   x_forwarded_for_header: X-FORWARDED-FOR
2015-04-12 22:32:42 [9085] [WARNING] debug mode: app isn't preloaded.
2015-04-12 22:32:42 [9085] [INFO] Starting gunicorn 0.14.6
2015-04-12 22:32:42 [9085] [DEBUG] Arbiter booted
2015-04-12 22:32:42 [9085] [INFO] Listening at: http://127.0.0.1:8000 (9085)
2015-04-12 22:32:42 [9085] [INFO] Using worker: sync
2015-04-12 22:32:42 [9088] [INFO] Booting worker with pid: 9088
^[[A^C2015-04-12 22:34:38 [9088] [INFO] Worker exiting (pid: 9088)
2015-04-12 22:34:38 [9085] [INFO] Handling signal: int
2015-04-12 22:34:38 [9085] [INFO] Shutting down: Master

I know there's a problem with gunicorn so far, it fails and restart itself and fails again, but these messages does not shows me a clear error ... is there another ideas ? I'm starting to feel very confunsed :S

@Michael-sqlbot take a look again please, I added an update. — geoom, Apr 06 '15 at 16:24
So, nginx is actually fine, but your service that's listening on port 8888 is not. That's where you need to look. The "peer" refers to the service on 8888. — Michael - sqlbot, Apr 06 '15 at 21:39
It does indeed, I checked this by pytting `netstat -na | grep 8888` on terminal and I got this: `tcp 0 0 127.0.0.1:8888 0.0.0.0:* LISTEN` — geoom, Apr 08 '15 at 22:45
You'll need to check the logs or output of whatever that process is to find out why it's apparently unstable. — Michael - sqlbot, Apr 08 '15 at 23:59
What does uwsgi log reads? Please, provide `netstat -nap | grep 8888` with PID/Program name -p key output a well. — Serj Zaharchenko, Apr 10 '15 at 12:21
@Michael-sqlbot I looked all related log files and it seems to work normally .. do you know another way (command, instruccion or tool) to find out why is my program unstable? ... I added uwsgi but is the same messages of server on tokio (which is working normally) — geoom, Apr 12 '15 at 21:34
@Serj Zaharchenko I traced uwsgi, can you see it on update 3 please ? — geoom, Apr 12 '15 at 22:58
@geoom, I've checked the logs (initially, I've assumed that you're using uwsgi, but it seems that it is gunicorn as server); 'Worker failed to boot' for gunicorn basically means - something went wrong. To limit the search: is django's runserver (`python manage.py runserver`) starts without errors? — Serj Zaharchenko, Apr 13 '15 at 15:27
You're not showing gunicorn error logs. If you're running it with supervisor, you should add lines similar to these: `stdout_logfile=/var/log/gunicorn/out.log stderr_logfile=/var/log/gunicorn/err.log` And then tell us what you're getting in the err.log file. — bad_keypoints, Apr 14 '15 at 09:05
@bad_keypoints I don't using supervisor to run gunicorn ... but I think gunicorn's errors logs was showed above in `/var/log/gunicorn/mysite.log` on **UPDATE 3** — geoom, Apr 14 '15 at 09:56
@Serj Zaharchenko your suggestion was very useful because I was able to see another debug messages that shows I have problems with some environment variables ... I'll check it later, I hope this works this time — geoom, Apr 14 '15 at 10:04
Do one thing: Try to run your app with runserver instead. Or whatever development server you've got, and go on about using your app, just to check if your app is actually able to start up. I'm guessing if some environment variable is not set, your app is crashing. But in that case still, something would have been in the logs. Anyways.. Just check. — bad_keypoints, Apr 14 '15 at 11:42

score 3 · Accepted Answer · answered Apr 15 '15 at 09:08

Effectively ... Environment variables were the culprits (and me, for not realizing), they were not configured properly therefore Django crashes when Gunicorn tries to run it.

And I solved this problem by checking all environment vars and setup properly according to my instance EC2 ... thnks so much to @Serj Zaharchenko for the simple but powerful clue.

score 1 · Answer 2 · answered Apr 13 '15 at 04:28

1

I found this, don't know if solves your problem.

The first line of the gunicorn_django file was "#!/opt/django/env/mysite/bin/python", which is the path of my virtualenviroment python path. The problem solved by replace it as "#!/usr/bin/env python"

answered Apr 13 '15 at 04:28

Onur Salk

156
1
6

dou you mean I should replace first one line of `/bin/gunicorn_django` file ? ... I don't think so, the machine from tokio does not has this modification, I prefer to try a way less intrusive... thnks for suggest – geoom Apr 14 '15 at 10:15

502 Bad Gateway from relocated instance on AWS EC2

2 Answers2