Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

gunicorn socket Ignoring EPIPE #1695

Closed
zhan9san opened this issue Feb 2, 2018 · 21 comments
Closed

gunicorn socket Ignoring EPIPE #1695

zhan9san opened this issue Feb 2, 2018 · 21 comments

Comments

@zhan9san
Copy link
Contributor

zhan9san commented Feb 2, 2018

gunicorn == 0.17.4
Django == 1.5.1
nginx version: openresty/1.9.7.3

If I use "proxy_set_header Host $http_host;", django will raise SuspiciousOperation. So I add "proxy_set_header Host "${host}:${server_port}";" to nginx's config and set server_name naked ip.
It is based on this tips.django get_host

Why there is some difference when testing by curl and nc? Load balance uses the command nc to check whether gunicorn is ok. But its reponse code is not 2xx or 3xx when using "nc". 4xx is considered to be unhealthy.

Or is there some graceful configration to process the requests when using nc?

Thanks!

nginx-gunicorn.conf

upstream app_server {
server unix:/tmp/gunicorn.sock fail_timeout=0;
}
server {
    listen 8086;
    server_name 192.168.1.2;
    keepalive_timeout 5;
    proxy_ignore_client_abort on;
    access_log   logs/gunicorn.access.log;
    error_log     logs/gunicorn.error.log;
    location / {
        try_files $uri @proxy_to_app;
    }

    location @proxy_to_app {
        proxy_set_header X-Forwarded-For $proxy_add_x_forwarded_for;
        proxy_set_header Host "${host}:${server_port}";
        proxy_redirect off;
        proxy_pass http://app_server;
    }
}

gunicorn.conf.py

bind="unix:/tmp/gunicorn.sock"
workers = 1
pidfile = "/ebs/var/gunicorn/pidx.file"
loglevel = "debug"
accesslog = "/ebs/var/log/gunicornx_access.log"
errorlog = "/ebs/var/log/gunicornx_error.log"
pythonpath = "/ebs/zh/test_host1"
worker_connections = 200
max_requests = 1024
keepalive = 3
preload_app = True

supervisord.conf

[program:gunicorn]
command=/ebs/zh/bin/gunicorn -c /ebs/zh/test_host1/gunicorn.conf.py wsgi:application
directory=/ebs/zh/test_host1/test_host1
numprocs = 1
autostart=true
autorestart=true
redirect_stderr=true
stdout_logfile = /ebs/var/log/workers/test.log
stdout_logfile_maxbytes = 10KB
stdout_logfile_backups = 5
stderr_logfile = /ebs/var/log/workers/test.log

Test using curl

curl -I 192.168.1.2:8086/index
HTTP/1.1 301 MOVED PERMANENTLY
Server: st/
Date: Thu, 01 Feb 2018 19:33:37 GMT
Content-Type: text/html; charset=utf-8
Connection: keep-alive
Location: http://192.168.1.2:8086/index/

gunicorn_error.log(gunicorn)

2018-02-01 13:33:37 [8221] [DEBUG] HEAD /index

gunicorn.access.log(nginx)

192.168.1.3 - - [02/Feb/2018:03:33:37 +0800] "HEAD /index HTTP/1.1" 301 0 "-" "curl/7.19.7 (x86_64-redhat-linux-gnu) libcurl/7.26.0 OpenSSL/0.9.8b zlib/1.2.3 libidn/1.18"

Test using nc

echo -e 'HEAD /index HTTP/1.0\r\n\r\n' | nc -w 192.168.1.2 8086

gunicorn_error.log(gunicorn)

2018-02-01 12:40:58 [16203] [DEBUG] HEAD /index
2018-02-01 12:40:58 [16203] [DEBUG] Ignoring EPIPE

gunicorn.access.log(nginx)

192.168.1.3 - - [02/Feb/2018:02:57:43 +0800] "HEAD /index HTTP/1.0" 499 0 "-" "-"
@budimm
Copy link

budimm commented Mar 18, 2019

same with me,,
[DEBUG] Ignoring EPIPE

@tilgovi
Copy link
Collaborator

tilgovi commented Mar 18, 2019

499 is NGINX is a client disconnect, I believe. That's also the same reason Gunicorn will log "Ignoring EPIPE". It sounds as though nc is not reading the full response.

@tilgovi
Copy link
Collaborator

tilgovi commented Mar 18, 2019

Your nc command seems malformed, too, unless it's a copy-paste error. -w should specify a timeout.

@budimm
Copy link

budimm commented Mar 19, 2019

Idk, but for me, its just warning, iam still could using my command using 'subprocess'

@enderphan94
Copy link

getting the same issue :(

@benoitc
Copy link
Owner

benoitc commented May 4, 2019

@endrrphan94 how do you get this "issue" ? It's unclear for me for me since nc in this example doesn't send any a proper request.

@boddumanohar
Copy link

boddumanohar commented Oct 29, 2019

I too see the same error, but gunicorn recovers from this after sometime. I see this for a few minutes and then after sometime gunicorn starts taking requests. here are my gunicorn logs.

2019-10-29T11:07:19.924Z [2019-10-29 11:07:19 +0000] [1858] [DEBUG] GET /health/
 - - [29/Oct/2019:11:07:19 +0000] "GET /api-auth/login/ HTTP/1.1" 200 3010 "-" "ELB-HealthChecker/2.0"
2019-10-29T11:07:19.924Z [2019-10-29 11:07:19 +0000] [1858] [DEBUG] Closing connection. 
2019-10-29T11:07:19.924Z [2019-10-29 11:07:19 +0000] [1858] [DEBUG] Ignoring EPIPE
2019-10-29T11:07:19.924Z [2019-10-29 11:07:19 +0000] [1858] [DEBUG] Ignoring EPIPE
2019-10-29T11:07:19.924Z [2019-10-29 11:07:19 +0000] [1858] [DEBUG] Ignoring EPIPE
2019-10-29T11:07:19.924Z [2019-10-29 11:07:19 +0000] [1858] [DEBUG] Ignoring EPIPE
2019-10-29T11:07:19.924Z [2019-10-29 11:07:19 +0000] [1858] [DEBUG] Ignoring EPIPE
2019-10-29T11:07:19.924Z [2019-10-29 11:07:19 +0000] [1858] [DEBUG] Ignoring EPIPE
2019-10-29T11:07:19.924Z [2019-10-29 11:07:19 +0000] [1858] [DEBUG] Ignoring EPIPE
2019-10-29T11:07:19.924Z [2019-10-29 11:07:19 +0000] [1858] [DEBUG] Ignoring EPIPE
2019-10-29T11:07:19.924Z [2019-10-29 11:07:19 +0000] [1858] [DEBUG] Ignoring EPIPE
2019-10-29T11:07:19.924Z [2019-10-29 11:07:19 +0000] [1858] [DEBUG] Ignoring EPIPE
2019-10-29T11:07:19.924Z [2019-10-29 11:07:19 +0000] [1858] [DEBUG] Ignoring EPIPE
2019-10-29T11:07:19.924Z [2019-10-29 11:07:19 +0000] [1858] [DEBUG] Ignoring EPIPE
2019-10-29T11:07:19.924Z [2019-10-29 11:07:19 +0000] [1858] [DEBUG] Ignoring EPIPE
2019-10-29T11:07:19.924Z [2019-10-29 11:07:19 +0000] [1858] [DEBUG] Ignoring EPIPE
2019-10-29T11:07:19.924Z [2019-10-29 11:07:19 +0000] [1858] [DEBUG] Ignoring EPIPE
2019-10-29T11:07:19.924Z [2019-10-29 11:07:19 +0000] [1858] [DEBUG] Ignoring EPIPE
2019-10-29T11:07:19.924Z [2019-10-29 11:07:19 +0000] [1858] [DEBUG] Ignoring EPIPE
2019-10-29T11:07:19.924Z [2019-10-29 11:07:19 +0000] [1858] [DEBUG] Ignoring EPIPE
2019-10-29T11:07:19.924Z [2019-10-29 11:07:19 +0000] [1858] [DEBUG] Ignoring EPIPE
2019-10-29T11:07:19.924Z [2019-10-29 11:07:19 +0000] [1858] [DEBUG] Ignoring EPIPE
2019-10-29T11:07:19.924Z [2019-10-29 11:07:19 +0000] [1858] [DEBUG] Ignoring EPIPE
2019-10-29T11:07:19.924Z [2019-10-29 11:07:19 +0000] [1858] [DEBUG] Ignoring EPIPE
2019-10-29T11:07:19.924Z [2019-10-29 11:07:19 +0000] [1858] [DEBUG] Ignoring EPIPE
2019-10-29T11:07:19.924Z [2019-10-29 11:07:19 +0000] [1858] [DEBUG] Ignoring EPIPE
2019-10-29T11:07:19.924Z [2019-10-29 11:07:19 +0000] [1858] [DEBUG] Ignoring EPIPE
2019-10-29T11:07:19.924Z [2019-10-29 11:07:19 +0000] [1858] [DEBUG] Ignoring EPIPE
2019-10-29T11:07:24.925Z [2019-10-29 11:07:24 +0000] [1858] [DEBUG] GET /health/
 - - [29/Oct/2019:11:07:24 +0000] "GET /api-auth/login/ HTTP/1.1" 200 3010 "-" "ELB-HealthChecker/2.0"
2019-10-29T11:07:24.926Z [2019-10-29 11:07:24 +0000] [1858] [DEBUG] Closing connection. 
2019-10-29T11:07:32.928Z [2019-10-29 11:07:32 +0000] [1858] [DEBUG] GET /health/
 - - [29/Oct/2019:11:07:32 +0000] "GET /api-auth/login/ HTTP/1.1" 200 3010 "-" "ELB-HealthChecker/2.0"
2019-10-29T11:07:32.928Z [2019-10-29 11:07:32 +0000] [1858] [DEBUG] Closing connection. 
2019-10-29T11:07:39.930Z [2019-10-29 11:07:39 +0000] [1858] [DEBUG] GET /health/
 - - [29/Oct/2019:11:07:39 +0000] "GET /api-auth/login/ HTTP/1.1" 200 3010 "-" "ELB-HealthChecker/2.0"
2019-10-29T11:07:39.930Z [2019-10-29 11:07:39 +0000] [1858] [DEBUG] Closing connection. 
2019-10-29T11:07:47.932Z [2019-10-29 11:07:47 +0000] [1858] [DEBUG] GET /health/
 - - [29/Oct/2019:11:07:47 +0000] "GET /api-auth/login/ HTTP/1.1" 200 3010 "-" "ELB-HealthChecker/2.0"
2019-10-29T11:07:47.932Z [2019-10-29 11:07:47 +0000] [1858] [DEBUG] Closing connection. 

any idea why this happens?

@benoitc
Copy link
Owner

benoitc commented Oct 30, 2019 via email

@zhan9san
Copy link
Contributor Author

This issue cannot be reproduce these days. It's weird.
@tilgovi Sorry, It's typo

echo -e 'HEAD /index HTTP/1.0\r\n\r\n' | nc -t 192.168.1.2 8086

@boddumanohar
Copy link

@benoitc I am using worker class as gevent.

Earlier to this we were using the worker class as gthread we had the same issue where gunicorn has started dropping connection because of which elb health checks are failing. so we switched to genvent but problem still persists.

is there any suggestion that you can give to fix this?

@benoitc
Copy link
Owner

benoitc commented Nov 22, 2019

are you sending a close header? @boddumanohar

@boddumanohar
Copy link

boddumanohar commented Apr 17, 2020

@benoitc This happens when the ELB health check closed the request before gunicorn replies. The ELB health check has a timeout and within that timeout, if it doesn't receive any response. Its going to close the request.

So I think this is not a bug on gunicorn side.

@benoitc
Copy link
Owner

benoitc commented Apr 17, 2020

this epipe message is expected hence why it’s displayed in debug mode only. What is the issue there exactly?

@zhan9san
Copy link
Contributor Author

I tried many times and still cannot reproduce this issue.
If others can't reproduce it either, i think this ticket can be closed.

@dikokob
Copy link

dikokob commented Mar 24, 2021

Any solutions as yet?

@boddumanohar
Copy link

this error usually occurs when the client closes the connection. So I believe there isn't much that can be done from the gunicorn side.

@boddumanohar boddumanohar removed their assignment Mar 24, 2021
@zhan9san
Copy link
Contributor Author

Hi @dikokob
Maybe @boddumanohar is correct. It's client issue.

Besides, this issue can be reproduced through this repo Reproduce this issue.

@zhan9san
Copy link
Contributor Author

Besides, if proxy_ignore_client_abort on; is added in the Nginx proxy configuration, both 499 error from Nginx and Ignoring EPIPE from Gunicorn, are gone.

@dikokob
Copy link

dikokob commented Mar 24, 2021

@zhan9san I did that and it worked see answer

@benoitc
Copy link
Owner

benoitc commented Mar 25, 2021

Also again, what is the issue there? Apart displaying this log in debug mode? I

Ignorig aborted requests on Nginx is doing the same thing but one level above anyway, so that will remove useless calls to gunicorn which is fine. Would be good to have a pr to add it in the doc :)

@zhan9san
Copy link
Contributor Author

Thanks for your attention.
I'll create a PR for this aborted request issue.

b3n4kh added a commit to taranis-ai/taranis-ai that referenced this issue Apr 9, 2024
* disable sse due to a bug in gunicorn
benoitc/gunicorn#1695

* UI regressions in assessview
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

7 participants