search

benoitc / gunicorn

gunicorn 'Green Unicorn' is a WSGI HTTP Server for UNIX, fast clients and sleepy applications.
http://www.gunicorn.org
Other
9.84k stars 1.75k forks source link

Gunicorn too slow after login on twilio python package #2162

Closed franciscopaniskaseker closed 3 months ago

franciscopaniskaseker commented 5 years ago

May be relationated with #1801

I have the same problem on issue #1801 , but after I changed timetout to 120 and changed the worker_class to eventlet, gevent or gthread, the timeout (#1801) is gone, but the performance continue slow.

Basically I use last gunirco and flask versions to connect with my twilio service, which is in last stable version too. When I login in my system, I see a very low performance to load the page (10-15 seconds). I not see any problem on logs, even using debug mode.

What I checked:

I tried set debug mode, but I did not see any error in logs. I enabled "spew", but is too much log, too much confusing separate what is about login interface.

I want help how can I debug gunicorn to see where is the problem. I mean, I can do gunicorn code changes to test, but before I want to know if there are some procedure and well bugs known by gunicorn or community.

benoitc commented 5 years ago

wha does your app?

franciscopaniskaseker commented 5 years ago

wha does your app?

Simple integration between server and twilio network to send sms.

Simply put, Twilio is a developer platform for communications. Software teams use Twilio APIs to add capabilities like voice, video, and messaging to their applications.

https://www.twilio.com/learn/twilio-101/what-is-twilio

With older version of twilio, flask and gunircon my customer does not has this problem. Unfortunately my customer does not know which versions. I tried some versions permutations (base on release dates) without success.

Log about since I do login until I get page loaded:

201.69.54.253 - - [11/Nov/2019:09:30:26 -0500] "GET /static/main.css HTTP/1.1" 200 0 "http://XXXXXX:5001/" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/78.0.3904.97 Safari/537.36"

201.69.54.253 - - [11/Nov/2019:09:30:37 -0500] "GET / HTTP/1.1" 200 5773987 "http://XXXXXX:5001/login" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/78.0.3904.97 Safari/537.36"

[2019-11-11 09:30:38 +0000] [5116] [DEBUG] GET /static/main.js

201.69.54.253 - - [11/Nov/2019:09:30:38 -0500] "GET /static/main.js HTTP/1.1" 200 0 "http://XXXXXX:5001/" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/78.0.3904.97 Safari/537.36"

[2019-11-11 09:30:44 +0000] [5116] [DEBUG] GET /ajax_get_messages

[2019-11-11 09:31:18 +0000] [5116] [DEBUG] Closing connection.
benoitc commented 5 years ago

Which gunicorn version are you using?

Timeout happen when the worker didn't notify the arbiter in time. So one part of the application is actually blocking the worker to do it. In the case of an async worker it also means the event loop is blocked.

Did you try to catch any exceptions around the twillio calls?

tilgovi commented 5 years ago

Are you connecting directly to Gunicorn or connecting through a load balancer or reverse proxy? Do you experience the same problem when connecting directly?

benoitc commented 4 years ago

@franciscopaniskaseker bump

benoitc commented 4 years ago

@franciscopaniskaseker do you still reproduce the issue? We need more details to try to reproduce the issue if needed.

franciscopaniskaseker commented 4 years ago

@benoitc Sorry about delay, I am really busy. I will try run with nginx as a proxy and then I will return.

@tilgovi I am not using any kind of load balance and proxy. I saw on documentation that is really recommended use http server like nginx or apache2 to proxy, but my customer is asking why something like that is happening if the service worked for 3 years by few users without any high performance http server. And because of that I am trying to understand how to debug this.

I know they updated some gems and probably we get some kind of regression, but I tried all combinations from repository without success (they do not have documentation about which versions of gems they had).

I will retry using high performance http server like apache and nginx and return.

benoitc commented 4 years ago

@franciscopaniskaseker is this happening with latest stable verison of gunicorn (20.0.4) ? About the combination you tried ddid you try with an older version of twillio/request? I am not sure for now what could cause an issue in gunicorn. Apart the wsgi.input_terminated thing there is no huge change that could trigger such a regression imo.

heckad commented 4 years ago

Hello everybody, seems I have a similar error. I use gunicorn (20.0.4) and sometimes I got Closing connection. after a long wait time. If set breakpoint onto b /usr/local/lib/python3.8/site-packages/gunicorn/workers/sync.py:138 and print exec when exception captured then will be printed

Traceback (most recent call last):
  File "/usr/local/lib/python3.8/site-packages/gunicorn/workers/sync.py", line 133, in handle
    req = next(parser)
  File "/usr/local/lib/python3.8/site-packages/gunicorn/http/parser.py", line 41, in __next__
    self.mesg = self.mesg_class(self.cfg, self.unreader, self.req_count)
  File "/usr/local/lib/python3.8/site-packages/gunicorn/http/message.py", line 186, in __init__
    super().__init__(cfg, unreader)
  File "/usr/local/lib/python3.8/site-packages/gunicorn/http/message.py", line 53, in __init__
    unused = self.parse(self.unreader)
  File "/usr/local/lib/python3.8/site-packages/gunicorn/http/message.py", line 198, in parse
    self.get_data(unreader, buf, stop=True)
  File "/usr/local/lib/python3.8/site-packages/gunicorn/http/message.py", line 192, in get_data
    raise StopIteration()

Also on line 138 in sync.py logger tried to capture message from expectation but you don't put anything in StopIteration. Maybe add more helpful info?

tilgovi commented 4 years ago

The StopIteration should never bubble. It's used as flow control to abort processing of a request parsing when the client disconnects before sending a full request.

heckad commented 4 years ago

If it's expected behaviour then Closing connection. shouldn't be writing.

benoitc commented 4 years ago

If it's expected behaviour then Closing connection. shouldn't be writing.

what do you mean?

benoitc commented 3 months ago

no activity since awhile. closing the issue.