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

upstream prematurely closed #92

Closed
federicopuntoni opened this issue Oct 12, 2018 · 10 comments
Closed

upstream prematurely closed #92

federicopuntoni opened this issue Oct 12, 2018 · 10 comments

Comments

@federicopuntoni
Copy link

Hi all,

I recently released an app on AWS ECS using "uwsgi-nginx-flask: python3.7"

The problem is that sporadically, without any reason, the server starts responding with "upstream prematurely closed connection while reading response".

Reading some information on the internet the cause could be due to the use of keepalive on nginx, instead of uwsgi side:

https://stackoverflow.com/a/46092301

or to use proxy_buffering:

owncloud/client#5706 (comment)

Has anyone encountered the same problem?

Thank you all

@tiangolo
Copy link
Owner

That's a sort of generic Nginx error that sadly doesn't say much, only that there was a problem in the connection between Nginx and uWSGI, all inside the container.

First, check the Docker logs (docker logs mycontainer) and see if there's any error. Also, let me suggest you Sentry, is amazing.

Is your endpoint doing a computationally expensive or inherently long computation?

You can try adding the proxy_buffering in your image directly, it's easy, check the instructions here: https://github.com/tiangolo/uwsgi-nginx-flask-docker#customizing-nginx-configurations

Please let me know anything else you discover.

@federicopuntoni
Copy link
Author

First, check the Docker logs (docker logs mycontainer) and see if there's any error.

I have to wait for it to occur because it does not depend on any variable

Also, let me suggest you Sentry, is amazing.

I'll try it

Is your endpoint doing a computationally expensive or inherently long computation?

Absolutely not.
Also the last time occurred at night, and being a stage environment no one was connected to the app

@tiangolo
Copy link
Owner

Also the last time occurred at night, and being a stage environment no one was connected to the app

That's quite strange 🤔 . Is your endpoint receiving a big request? Like a file upload? Or is it returning a long response? Like a big JSON or a big file?

Here are the docs for proxy_buffering. But all the proxy buffering settings tend to have to do with buffering content that should go to your Python app from your client or to your client from your Python app. But by the docs it seems like the buffering settings would only help if there's a big payload in one of the directions.

Nevertheless, you could try adding the config and see how it changes. Is just that it would be nice to pinpoint better the actual problem.

@federicopuntoni
Copy link
Author

That's quite strange 🤔 . Is your endpoint receiving a big request? Like a file upload? Or is it returning a long response? Like a big JSON or a big file?

No, it's a simple bootstrap-based flask dashboard with peewee.
There are no particular features yet implemented.

@tiangolo
Copy link
Owner

Strange. Then maybe try that and let me know how it goes.

@federicopuntoni
Copy link
Author

Tonight it happened again and I checked the docker logs.

It seems like the exception

"upstream prematurely closed connection while reading response header from upstream"

occur as a result of another exception.

So nothing to do with this.

Even if I do not understand why this exception is triggered sporadically.

Following the log:

`10.0.201.237 - - [15/Oct/2018:07:06:47 +0000] "GET / HTTP/1.1" 200 4014 "-" "ELB-HealthChecker/2.0" "-"
[pid: 12|app: 0|req: 8582/17163] 10.0.201.237 () {34 vars in 396 bytes} [Mon Oct 15 07:06:46 2018] GET / => generated 4014 bytes in 11 msecs (HTTP/1.1 200) 4 headers in 328 bytes (1 switches on core 0)
10.0.200.253 - - [15/Oct/2018:07:06:51 +0000] "GET / HTTP/1.1" 200 4014 "-" "ELB-HealthChecker/2.0" "-"
[pid: 13|app: 0|req: 8582/17164] 10.0.200.253 () {34 vars in 396 bytes} [Mon Oct 15 07:06:51 2018] GET / => generated 4014 bytes in 21 msecs (HTTP/1.1 200) 4 headers in 329 bytes (1 switches on core 0)
10.0.201.237 - - [15/Oct/2018:07:07:17 +0000] "GET / HTTP/1.1" 200 4014 "-" "ELB-HealthChecker/2.0" "-"
[pid: 12|app: 0|req: 8583/17165] 10.0.201.237 () {34 vars in 396 bytes} [Mon Oct 15 07:07:16 2018] GET / => generated 4014 bytes in 17 msecs (HTTP/1.1 200) 4 headers in 329 bytes (1 switches on core 0)
10.0.200.253 - - [15/Oct/2018:07:07:21 +0000] "GET / HTTP/1.1" 200 4014 "-" "ELB-HealthChecker/2.0" "-"
[pid: 13|app: 0|req: 8583/17166] 10.0.200.253 () {34 vars in 396 bytes} [Mon Oct 15 07:07:21 2018] GET / => generated 4014 bytes in 13 msecs (HTTP/1.1 200) 4 headers in 329 bytes (1 switches on core 0)
10.0.201.237 - - [15/Oct/2018:07:07:47 +0000] "GET / HTTP/1.1" 200 4014 "-" "ELB-HealthChecker/2.0" "-"
[pid: 12|app: 0|req: 8584/17167] 10.0.201.237 () {34 vars in 396 bytes} [Mon Oct 15 07:07:47 2018] GET / => generated 4014 bytes in 11 msecs (HTTP/1.1 200) 4 headers in 329 bytes (1 switches on core 0)

Traceback (most recent call last):
File "/usr/local/lib/python3.7/site-packages/pymysql/connections.py", line 708, in _write_bytes
self._sock.sendall(data)
TimeoutError: [Errno 110] Connection timed out

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
File "/usr/local/lib/python3.7/site-packages/peewee.py", line 2683, in execute_sql
cursor.execute(sql, params or ())
File "/usr/local/lib/python3.7/site-packages/pymysql/cursors.py", line 170, in execute
result = self._query(query)
File "/usr/local/lib/python3.7/site-packages/pymysql/cursors.py", line 328, in _query
conn.query(q)
File "/usr/local/lib/python3.7/site-packages/pymysql/connections.py", line 515, in query
self._execute_command(COMMAND.COM_QUERY, sql)
File "/usr/local/lib/python3.7/site-packages/pymysql/connections.py", line 766, in _execute_command
self._write_bytes(packet)
File "/usr/local/lib/python3.7/site-packages/pymysql/connections.py", line 713, in _write_bytes
"MySQL server has gone away (%r)" % (e,))
pymysql.err.OperationalError: (2006, "MySQL server has gone away (TimeoutError(110, 'Connection timed out'))")

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
File "/usr/local/lib/python3.7/site-packages/flask/app.py", line 2309, in call
return self.wsgi_app(environ, start_response)
File "/usr/local/lib/python3.7/site-packages/flask/app.py", line 2295, in wsgi_app
response = self.handle_exception(e)
File "/usr/local/lib/python3.7/site-packages/flask/app.py", line 1741, in handle_exception
reraise(exc_type, exc_value, tb)
File "/usr/local/lib/python3.7/site-packages/flask/_compat.py", line 35, in reraise
raise value
File "/usr/local/lib/python3.7/site-packages/flask/app.py", line 2292, in wsgi_app
response = self.full_dispatch_request()
File "/usr/local/lib/python3.7/site-packages/flask/app.py", line 1815, in full_dispatch_request
rv = self.handle_user_exception(e)
File "/usr/local/lib/python3.7/site-packages/flask/app.py", line 1718, in handle_user_exception
reraise(exc_type, exc_value, tb)
File "/usr/local/lib/python3.7/site-packages/flask/_compat.py", line 35, in reraise
raise value
File "/usr/local/lib/python3.7/site-packages/flask/app.py", line 1813, in full_dispatch_request
rv = self.dispatch_request()
File "/usr/local/lib/python3.7/site-packages/flask/app.py", line 1799, in dispatch_request
return self.view_functionsrule.endpoint
File "./starthubb/views/login_controller.py", line 37, in login
if current_user.is_authenticated:
File "/usr/local/lib/python3.7/site-packages/werkzeug/local.py", line 347, in getattr
return getattr(self._get_current_object(), name)
File "/usr/local/lib/python3.7/site-packages/werkzeug/local.py", line 306, in _get_current_object
return self.__local()
File "/usr/local/lib/python3.7/site-packages/flask_login/utils.py", line 26, in
current_user = LocalProxy(lambda: _get_user())
File "/usr/local/lib/python3.7/site-packages/flask_login/utils.py", line 335, in _get_user
current_app.login_manager._load_user()
File "/usr/local/lib/python3.7/site-packages/flask_login/login_manager.py", line 359, in _load_user
return self.reload_user()
File "/usr/local/lib/python3.7/site-packages/flask_login/login_manager.py", line 321, in reload_user
user = self.user_callback(user_id)
File "./myapp/init.py", line 66, in load_user
user = User.select().where(User.id == int(us_id)).first()
File "/usr/local/lib/python3.7/site-packages/peewee.py", line 1604, in inner
return method(self, database, *args, **kwargs)
File "/usr/local/lib/python3.7/site-packages/peewee.py", line 1841, in first
return self.peek(database, n=n)
File "/usr/local/lib/python3.7/site-packages/peewee.py", line 1604, in inner
return method(self, database, *args, **kwargs)
File "/usr/local/lib/python3.7/site-packages/peewee.py", line 1832, in peek
rows = self.execute(database)[:n]
File "/usr/local/lib/python3.7/site-packages/peewee.py", line 1604, in inner
return method(self, database, *args, **kwargs)
File "/usr/local/lib/python3.7/site-packages/peewee.py", line 1675, in execute
return self._execute(database)
File "/usr/local/lib/python3.7/site-packages/peewee.py", line 1826, in _execute
cursor = database.execute(self)
File "/usr/local/lib/python3.7/site-packages/peewee.py", line 2696, in execute
return self.execute_sql(sql, params, commit=commit)
File "/usr/local/lib/python3.7/site-packages/peewee.py", line 2690, in execute_sql
self.commit()
File "/usr/local/lib/python3.7/site-packages/peewee.py", line 2481, in exit
reraise(new_type, new_type(*exc_args), traceback)
File "/usr/local/lib/python3.7/site-packages/peewee.py", line 178, in reraise
raise value.with_traceback(tb)
File "/usr/local/lib/python3.7/site-packages/peewee.py", line 2683, in execute_sql
cursor.execute(sql, params or ())
File "/usr/local/lib/python3.7/site-packages/pymysql/cursors.py", line 170, in execute
result = self._query(query)
File "/usr/local/lib/python3.7/site-packages/pymysql/cursors.py", line 328, in _query
conn.query(q)
File "/usr/local/lib/python3.7/site-packages/pymysql/connections.py", line 515, in query
self._execute_command(COMMAND.COM_QUERY, sql)
File "/usr/local/lib/python3.7/site-packages/pymysql/connections.py", line 766, in _execute_command
self._write_bytes(packet)
File "/usr/local/lib/python3.7/site-packages/pymysql/connections.py", line 713, in _write_bytes
"MySQL server has gone away (%r)" % (e,))
peewee.OperationalError: (2006, "MySQL server has gone away (TimeoutError(110, 'Connection timed out'))")

2018/10/15 07:07:49 [error] 11#11: *34318 upstream prematurely closed connection while reading response header from upstream, client: 10.0.200.253, server: , request: "GET / HTTP/1.1", upstream: "uwsgi://unix:///tmp/uwsgi.sock:", host: "myapp.mysite.com"
10.0.200.253 - - [15/Oct/2018:07:07:49 +0000] "GET / HTTP/1.1" 502 576 "-" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/69.0.3497.100 Safari/537.36" "79.49.200.147"
[pid: 13|app: 0|req: 8584/17168] 10.0.200.253 () {48 vars in 1205 bytes} [Mon Oct 15 07:07:49 2018] GET / => generated 0 bytes in 48 msecs (HTTP/1.1 500) 0 headers in 0 bytes (0 switches on core 0)
10.0.200.253 - - [15/Oct/2018:07:07:49 +0000] "GET /favicon.ico HTTP/1.1" 404 233 "http://myapp.mysite.com/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/69.0.3497.100 Safari/537.36" "79.49.200.147"
[pid: 12|app: 0|req: 8585/17169] 10.0.200.253 () {48 vars in 1198 bytes} [Mon Oct 15 07:07:49 2018] GET /favicon.ico => generated 233 bytes in 11 msecs (HTTP/1.1 404) 3 headers in 506 bytes (1 switches on core 0)

10.0.200.253 - - [15/Oct/2018:07:07:51 +0000] "GET / HTTP/1.1" 200 4014 "-" "ELB-HealthChecker/2.0" "-"
[pid: 13|app: 0|req: 8585/17170] 10.0.200.253 () {34 vars in 396 bytes} [Mon Oct 15 07:07:51 2018] GET / => generated 4014 bytes in 16 msecs (HTTP/1.1 200) 4 headers in 329 bytes (1 switches on core 0)
10.0.201.237 - - [15/Oct/2018:07:08:17 +0000] "GET / HTTP/1.1" 200 4014 "-" "ELB-HealthChecker/2.0" "-"
[pid: 12|app: 0|req: 8586/17171] 10.0.201.237 () {34 vars in 396 bytes} [Mon Oct 15 07:08:17 2018] GET / => generated 4014 bytes in 13 msecs (HTTP/1.1 200) 4 headers in 329 bytes (1 switches on core 0)
10.0.200.253 - - [15/Oct/2018:07:08:21 +0000] "GET / HTTP/1.1" 200 4014 "-" "ELB-HealthChecker/2.0" "-"
[pid: 13|app: 0|req: 8586/17172] 10.0.200.253 () {34 vars in 396 bytes} [Mon Oct 15 07:08:21 2018] GET / => generated 4014 bytes in 14 msecs (HTTP/1.1 200) 4 headers in 329 bytes (1 switches on core 0)
10.0.201.237 - - [15/Oct/2018:07:08:47 +0000] "GET / HTTP/1.1" 200 4014 "-" "ELB-HealthChecker/2.0" "-"
[pid: 12|app: 0|req: 8587/17173] 10.0.201.237 () {34 vars in 396 bytes} [Mon Oct 15 07:08:47 2018] GET / => generated 4014 bytes in 14 msecs (HTTP/1.1 200) 4 headers in 329 bytes (1 switches on core 0)`

I will try to solve, thanks for the helpI will try to solve, thanks for the help

@federicopuntoni
Copy link
Author

I understood where the problem was.

My session had a 30-day lifetime but mysql timeout was 8 hours.

Saving the database connection within the session made sure that a previously expired connection remained in session and then the exception was triggered.

Thank you

@tiangolo
Copy link
Owner

Ah! I see. I'm glad you solved it!


Now, as a suggestion:

It might be better to create a new connection per request than keeping a single connection forever (I was having problems with that some time ago).

The other option that you can try later, would be to have a way to re-use old connections while they are still available but create new ones if they are not. It might get complex easily, so the first approach could be to create a new connection per request. You can have a function that creates it and returns the session to you, and then you can call that function inside each Flask route (function), and use that returned session in the Flask route.

If you are using SQLAlchemy, you can combine it with Flask-SQLAlchemy to handle the sessions for you.

You can check how to do that with this project generator I created. You can create a project from scratch just to copy the code you need (it's quite simple to generate). The generated project assumes PostgreSQL, but as it uses SQLAlchemy you can just switch the connection line to use MySQL. And just copy the DB related code.

@federicopuntoni
Copy link
Author

ok, I'll try it for sure! Thanks again

@jackadam1981
Copy link

It means closing session?
like session.close()

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

No branches or pull requests

3 participants