I'm setting up an Ubuntu EC2 instance by following this droplet tutorial. Everything seems to be working fine on my local development machine but I am getting timeout errors(502,504) on my EC2 instance.
I checked my gunicorn logs and there was a [CRITICAL] WORKED TIMEOUT message so I increased the "timeout" parameter for gunicorn to 300 and set the proxy_connect_timeout to 75s and proxy_read_timeout to 300s on my site's nginx config even though the process should have taken much less time than that. I think the error is not with the process taking the time but some misconfiguration in my nginx or gunicorn config.
GET requests that retrieve data from the DB seem to be working fine but POST requests that write to the DB don't seem to work.
Here are my config and log files
Gunicorn.service
[Unit]
Description=gunicorn daemon
After=network.target
[Service]
User=ubuntu
Group=www-data
WorkingDirectory=/home/ubuntu/standalone_ntp_backend
ExecStart=/home/ubuntu/standalone_ntp_backend/venv/bin/gunicorn --access-logfile - --workers 3 --bind unix:/home/ubuntu/standalone_ntp_backend/standalone_ntp_backend.sock standalone_ntp_backend.wsgi:application --timeout 300
[Install]
WantedBy=multi-user.target
/etc/nginx/sites-available/www.example.com.conf
server {
listen 80;
listen [::]:80;
server_name example.com www.example.com;
location / {
proxy_set_header X-Forwarded-For $proxy_add_x_forwarded_for;
proxy_set_header Host $http_host;
proxy_redirect off;
# include proxy_params;
proxy_connect_timeout 75s;
proxy_read_timeout 300s;
proxy_pass http://unix:/home/ubuntu/standalone_ntp_backend/standalone_ntp_backend.sock;
}
client_max_body_size 50m;
}
/var/log/nginx/error.log
2019/06/14 12:10:40 [error] 1062#1062: *3 upstream timed out (110: Connection timed out) while reading response header from upstream, client: 110.44.xxx.xxx, server: example.com, request: "POST /core/create-trip HTTP/1.1", upstream: "http://unix:/home/ubuntu/standalone_ntp_backend/standalone_ntp_backend.sock/core/create-trip", host: "example.com", referrer: "http://example.com/core/create-trip"
2019/06/14 12:10:58 [error] 1062#1062: *7 upstream prematurely closed connection while reading response header from upstream, client: 110.44.xx.xxx, server: example.com, request: "POST /core/create-trip HTTP/1.1", upstream: "http://unix:/home/ubuntu/standalone_ntp_backend/standalone_ntp_backend.sock:/core/create-trip", host: "example.com", referrer: "http://example.com/core/create-trip"
2019/06/14 12:26:32 [error] 1062#1062: *9 upstream timed out (110: Connection timed out) while reading response header from upstream, client: 110.44.xx.xxx, server: example.com, request: "POST /core/rest-auth/password/reset/ HTTP/1.1", upstream: "http://unix:/home/ubuntu/standalone_ntp_backend/standalone_ntp_backend.sock/core/rest-auth/password/reset/", host: "example.com", referrer: "http://example.com/core/rest-auth/password/reset/"
Gunicorn debug log
[2019-06-14 12:53:38 +0000] [2229] [DEBUG] Current configuration:
config: None
bind: ['0.0.0.0:8000']
backlog: 2048
workers: 1
worker_class: sync
threads: 1
worker_connections: 1000
max_requests: 0
max_requests_jitter: 0
timeout: 30
graceful_timeout: 30
keepalive: 2
limit_request_line: 4094
limit_request_fields: 100
limit_request_field_size: 8190
reload: False
reload_engine: auto
reload_extra_files: []
spew: False
check_config: False
preload_app: False
sendfile: None
reuse_port: False
chdir: /home/ubuntu/standalone_ntp_backend
daemon: False
raw_env: []
pidfile: None
worker_tmp_dir: None
user: 1000
group: 1000
umask: 0
initgroups: False
tmp_upload_dir: None
secure_scheme_headers: {'X-FORWARDED-PROTOCOL': 'ssl', 'X-FORWARDED-PROTO': 'https', 'X-FORWARDED-SSL': 'on'}
forwarded_allow_ips: ['127.0.0.1']
accesslog: None
disable_redirect_access_to_syslog: False
access_log_format: %(h)s %(l)s %(u)s %(t)s "%(r)s" %(s)s %(b)s "%(f)s" "%(a)s"
errorlog: -
loglevel: DEBUG
capture_output: False
logger_class: gunicorn.glogging.Logger
logconfig: None
logconfig_dict: {}
syslog_addr: udp://localhost:514
syslog: False
syslog_prefix: None
syslog_facility: user
enable_stdio_inheritance: False
statsd_host: None
statsd_prefix:
proc_name: None
default_proc_name: standalone_ntp_backend.wsgi:application
pythonpath: None
paste: None
on_starting: <function OnStarting.on_starting at 0x7f50e62bbf28>
on_reload: <function OnReload.on_reload at 0x7f50e62cd0d0>
when_ready: <function WhenReady.when_ready at 0x7f50e62cd1e0>
pre_fork: <function Prefork.pre_fork at 0x7f50e62cd2f0>
post_fork: <function Postfork.post_fork at 0x7f50e62cd400>
post_worker_init: <function PostWorkerInit.post_worker_init at 0x7f50e62cd510>
worker_int: <function WorkerInt.worker_int at 0x7f50e62cd620>
worker_abort: <function WorkerAbort.worker_abort at 0x7f50e62cd730>
pre_exec: <function PreExec.pre_exec at 0x7f50e62cd840>
pre_request: <function PreRequest.pre_request at 0x7f50e62cd950>
post_request: <function PostRequest.post_request at 0x7f50e62cd9d8>
child_exit: <function ChildExit.child_exit at 0x7f50e62cdae8>
worker_exit: <function WorkerExit.worker_exit at 0x7f50e62cdbf8>
nworkers_changed: <function NumWorkersChanged.nworkers_changed at 0x7f50e62cdd08>
on_exit: <function OnExit.on_exit at 0x7f50e62cde18>
proxy_protocol: False
proxy_allow_ips: ['127.0.0.1']
keyfile: None
certfile: None
ssl_version: 2
cert_reqs: 0
ca_certs: None
suppress_ragged_eofs: True
do_handshake_on_connect: False
ciphers: TLSv1
raw_paste_global_conf: []
[2019-06-14 12:53:38 +0000] [2229] [INFO] Starting gunicorn 19.8.1
[2019-06-14 12:53:38 +0000] [2229] [DEBUG] Arbiter booted
[2019-06-14 12:53:38 +0000] [2229] [INFO] Listening at: http://0.0.0.0:8000 (2229)
[2019-06-14 12:53:38 +0000] [2229] [INFO] Using worker: sync
[2019-06-14 12:53:38 +0000] [2232] [INFO] Booting worker with pid: 2232
[2019-06-14 12:53:38 +0000] [2229] [DEBUG] 1 workers
api_views.py
class CreateTripView(APIView):
def get(self, request):
print("INSIDE GET")
return Response("Hi from GET")
def post(self, request):
print("INSIDE POST")
#logic here(serializer validation and save)
return Response(data)
I've added those print statements above so that it might help with the following systemctl gunicorn log:
Jun 14 12:57:23 ip-172-31-41-70 systemd[1]: Started gunicorn daemon.
Jun 14 12:57:23 ip-172-31-41-70 gunicorn[2367]: [2019-06-14 12:57:23 +0000] [2367] [INFO] Starting gunicorn 19.8.1
Jun 14 12:57:23 ip-172-31-41-70 gunicorn[2367]: [2019-06-14 12:57:23 +0000] [2367] [INFO] Listening at: unix:/home/ubuntu/standalone_ntp_backend/standalone_ntp_backend.sock (2367)
Jun 14 12:57:23 ip-172-31-41-70 gunicorn[2367]: [2019-06-14 12:57:23 +0000] [2367] [INFO] Using worker: sync
Jun 14 12:57:23 ip-172-31-41-70 gunicorn[2367]: [2019-06-14 12:57:23 +0000] [2385] [INFO] Booting worker with pid: 2385
Jun 14 12:57:23 ip-172-31-41-70 gunicorn[2367]: [2019-06-14 12:57:23 +0000] [2387] [INFO] Booting worker with pid: 2387
Jun 14 12:57:23 ip-172-31-41-70 gunicorn[2367]: [2019-06-14 12:57:23 +0000] [2388] [INFO] Booting worker with pid: 2388
Jun 14 12:57:24 ip-172-31-41-70 gunicorn[2367]: Loading : /home/ubuntu/standalone_ntp_backend/.env
Jun 14 12:57:24 ip-172-31-41-70 gunicorn[2367]: The .env file has been loaded. See base.py for more information
Jun 14 12:57:24 ip-172-31-41-70 gunicorn[2367]: Loading : /home/ubuntu/standalone_ntp_backend/.env
Jun 14 12:57:24 ip-172-31-41-70 gunicorn[2367]: The .env file has been loaded. See base.py for more information
Jun 14 12:57:24 ip-172-31-41-70 gunicorn[2367]: Loading : /home/ubuntu/standalone_ntp_backend/.env
Jun 14 12:57:24 ip-172-31-41-70 gunicorn[2367]: The .env file has been loaded. See base.py for more information
Jun 14 12:57:36 ip-172-31-41-70 gunicorn[2367]: - - [14/Jun/2019:12:57:36 +0000] "GET /core/view-trip/10 HTTP/1.0" 200 15811 "-" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/72.0.3626.81 Safari/537.36"
Jun 14 12:57:42 ip-172-31-41-70 gunicorn[2367]: INSIDE GET
Jun 14 12:57:42 ip-172-31-41-70 gunicorn[2367]: - - [14/Jun/2019:12:57:42 +0000] "GET /core/create-trip HTTP/1.0" 200 7204 "-" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/72.0.3626.81 Safari/537.36"
Jun 14 12:59:24 ip-172-31-41-70 gunicorn[2367]: - - [14/Jun/2019:12:59:24 +0000] "GET / HTTP/1.0" 404 74 "-" "Mozilla/5.0 (compatible; Nimbostratus-Bot/v1.3.2; http://cloudsystemnetworks.com)"
Jun 14 13:02:50 ip-172-31-41-70 gunicorn[2367]: [2019-06-14 13:02:50 +0000] [2367] [CRITICAL] WORKER TIMEOUT (pid:2387)
Jun 14 13:02:50 ip-172-31-41-70 gunicorn[2367]: [2019-06-14 13:02:50 +0000] [2387] [INFO] Worker exiting (pid: 2387)
Jun 14 13:02:50 ip-172-31-41-70 gunicorn[2367]: INSIDE POST
Jun 14 13:02:51 ip-172-31-41-70 gunicorn[2367]: [2019-06-14 13:02:51 +0000] [2402] [INFO] Booting worker with pid: 2402
Jun 14 13:02:51 ip-172-31-41-70 gunicorn[2367]: Loading : /home/ubuntu/standalone_ntp_backend/.env
Jun 14 13:02:51 ip-172-31-41-70 gunicorn[2367]: The .env file has been loaded. See base.py for more information
Jun 14 13:03:24 ip-172-31-41-70 gunicorn[2367]: - - [14/Jun/2019:13:03:24 +0000] "GET /core/rest-auth/password/reset/ HTTP/1.0" 405 7744 "-" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/72.0.3626.81 Safa
Jun 14 13:07:48 ip-172-31-41-70 gunicorn[2367]: [2019-06-14 13:07:48 +0000] [2367] [CRITICAL] WORKER TIMEOUT (pid:2385)
Jun 14 13:07:48 ip-172-31-41-70 gunicorn[2367]: [2019-06-14 13:07:48 +0000] [2385] [INFO] Worker exiting (pid: 2385)
Jun 14 13:07:48 ip-172-31-41-70 gunicorn[2367]: INSIDE POST
Jun 14 13:07:48 ip-172-31-41-70 gunicorn[2367]: [2019-06-14 13:07:48 +0000] [2409] [INFO] Booting worker with pid: 2409
Jun 14 13:07:48 ip-172-31-41-70 gunicorn[2367]: Loading : /home/ubuntu/standalone_ntp_backend/.env
Jun 14 13:07:48 ip-172-31-41-70 gunicorn[2367]: The .env file has been loaded. See base.py for more information
Jun 14 13:08:32 ip-172-31-41-70 gunicorn[2367]: [2019-06-14 13:08:32 +0000] [2367] [CRITICAL] WORKER TIMEOUT (pid:2402)
Jun 14 13:08:32 ip-172-31-41-70 gunicorn[2367]: [2019-06-14 13:08:32 +0000] [2402] [INFO] Worker exiting (pid: 2402)
Jun 14 13:08:32 ip-172-31-41-70 gunicorn[2367]: [2019-06-14 13:08:32 +0000] [2411] [INFO] Booting worker with pid: 2411
Jun 14 13:08:33 ip-172-31-41-70 gunicorn[2367]: Loading : /home/ubuntu/standalone_ntp_backend/.env
Jun 14 13:08:33 ip-172-31-41-70 gunicorn[2367]: The .env file has been loaded. See base.py for more information
When I send a POST request(json) to myendpoint /create-trip, I get 504 Gateway Time-out(gunicorn logs above) but GET request to my /view-trip/trip_id endpoint which retrieves values from the database seems to be working just fine.
How do I configure Nginx and Gunicorn to fix these timeout issues? Thanks.
edit: It seems the 'print("Inside POST")' in api_viewsets.py executes only after I see the 504- Gateway timeout.
