search

overthesun / simoc

A scalable model of an interactive, off-world community
https://ngs.simoc.space/
GNU General Public License v3.0
2 stars 2 forks source link

sqlalchemy.exc.TimeoutError: QueuePool limit of size 10 overflow 10 reached #101

Open ezio-melotti opened 5 years ago

ezio-melotti commented 5 years ago

A teacher reported some issues and when I went looking at the logs I found this:

flask-app_1      | 2019-11-25T17:37:51.840156842Z Traceback (most recent call last):
flask-app_1      | 2019-11-25T17:37:51.840200375Z   File "/usr/local/lib/python3.6/dist-packages/flask/app.py", line 1949, in full_dispatch_request
flask-app_1      | 2019-11-25T17:37:51.840217784Z     rv = self.dispatch_request()
flask-app_1      | 2019-11-25T17:37:51.840230341Z   File "/usr/local/lib/python3.6/dist-packages/flask/app.py", line 1935, in dispatch_request
flask-app_1      | 2019-11-25T17:37:51.840243480Z     return self.view_functions[rule.endpoint](**req.view_args)
flask-app_1      | 2019-11-25T17:37:51.840255612Z   File "/simoc/simoc_server/front_end_routes.py", line 88, in get_energy
flask-app_1      | 2019-11-25T17:37:51.840268164Z     .filter(AgentTypeAttribute.name == attribute_name).all():
flask-app_1      | 2019-11-25T17:37:51.840280223Z   File "/usr/local/lib/python3.6/dist-packages/sqlalchemy/orm/query.py", line 3186, in all
flask-app_1      | 2019-11-25T17:37:51.840292715Z     return list(self)
flask-app_1      | 2019-11-25T17:37:51.840304693Z   File "/usr/local/lib/python3.6/dist-packages/sqlalchemy/orm/query.py", line 3342, in __iter__
flask-app_1      | 2019-11-25T17:37:51.840317982Z     return self._execute_and_instances(context)
flask-app_1      | 2019-11-25T17:37:51.840359565Z   File "/usr/local/lib/python3.6/dist-packages/sqlalchemy/orm/query.py", line 3364, in _execute_and_instances
flask-app_1      | 2019-11-25T17:37:51.840404451Z     querycontext, self._connection_from_session, close_with_result=True
flask-app_1      | 2019-11-25T17:37:51.840471291Z   File "/usr/local/lib/python3.6/dist-packages/sqlalchemy/orm/query.py", line 3379, in _get_bind_args
flask-app_1      | 2019-11-25T17:37:51.840486690Z     mapper=self._bind_mapper(), clause=querycontext.statement, **kw
flask-app_1      | 2019-11-25T17:37:51.840498776Z   File "/usr/local/lib/python3.6/dist-packages/sqlalchemy/orm/query.py", line 3357, in _connection_from_session
flask-app_1      | 2019-11-25T17:37:51.840511088Z     conn = self.session.connection(**kw)
flask-app_1      | 2019-11-25T17:37:51.840535367Z   File "/usr/local/lib/python3.6/dist-packages/sqlalchemy/orm/session.py", line 1124, in connection
flask-app_1      | 2019-11-25T17:37:51.840573914Z     execution_options=execution_options,
flask-app_1      | 2019-11-25T17:37:51.840587965Z   File "/usr/local/lib/python3.6/dist-packages/sqlalchemy/orm/session.py", line 1130, in _connection_for_bind
flask-app_1      | 2019-11-25T17:37:51.840600506Z     engine, execution_options
flask-app_1      | 2019-11-25T17:37:51.840628910Z   File "/usr/local/lib/python3.6/dist-packages/sqlalchemy/orm/session.py", line 431, in _connection_for_bind
flask-app_1      | 2019-11-25T17:37:51.840642634Z     conn = bind._contextual_connect()
flask-app_1      | 2019-11-25T17:37:51.840654480Z   File "/usr/local/lib/python3.6/dist-packages/sqlalchemy/engine/base.py", line 2239, in _contextual_connect
flask-app_1      | 2019-11-25T17:37:51.840666867Z     self._wrap_pool_connect(self.pool.connect, None),
flask-app_1      | 2019-11-25T17:37:51.840678587Z   File "/usr/local/lib/python3.6/dist-packages/sqlalchemy/engine/base.py", line 2275, in _wrap_pool_connect
flask-app_1      | 2019-11-25T17:37:51.840691018Z     return fn()
flask-app_1      | 2019-11-25T17:37:51.840702563Z   File "/usr/local/lib/python3.6/dist-packages/sqlalchemy/pool/base.py", line 363, in connect
flask-app_1      | 2019-11-25T17:37:51.840716424Z     return _ConnectionFairy._checkout(self)
flask-app_1      | 2019-11-25T17:37:51.840728407Z   File "/usr/local/lib/python3.6/dist-packages/sqlalchemy/pool/base.py", line 760, in _checkout
flask-app_1      | 2019-11-25T17:37:51.840740717Z     fairy = _ConnectionRecord.checkout(pool)
flask-app_1      | 2019-11-25T17:37:51.840752503Z   File "/usr/local/lib/python3.6/dist-packages/sqlalchemy/pool/base.py", line 492, in checkout
flask-app_1      | 2019-11-25T17:37:51.840764768Z     rec = pool._do_get()
flask-app_1      | 2019-11-25T17:37:51.840776379Z   File "/usr/local/lib/python3.6/dist-packages/sqlalchemy/pool/impl.py", line 131, in _do_get
flask-app_1      | 2019-11-25T17:37:51.840788772Z     code="3o7r",
flask-app_1      | 2019-11-25T17:37:51.840801302Z sqlalchemy.exc.TimeoutError: QueuePool limit of size 10 overflow 10 reached, connection timed out, timeout 30 (Background on this error at: http://sqlalche.me/e/3o7r)
flask-app_1      | 2019-11-25T17:37:51.840813947Z [2019-11-25 17:37:51 +0000] [9] [ERROR] ERROR: handling exception QueuePool limit of size 10 overflow 10 reached, connection timed out, timeout 30 (Background on this error at: http://sqlalche.me/e/3o7r)
ezio-melotti commented 5 years ago

This is another error that might be related. There seem to be lot of people connected and some simulations are running fine, but there are timeout errors here and there:

flask-app_1      | 2019-11-25T17:41:25.721774274Z Traceback (most recent call last):
flask-app_1      | 2019-11-25T17:41:25.721821537Z   File "/usr/local/lib/python3.6/dist-packages/celery/backends/asynchronous.py", line 255, in _wait_for_pending
flask-app_1      | 2019-11-25T17:41:25.721870616Z     on_interval=on_interval):
flask-app_1      | 2019-11-25T17:41:25.721897075Z   File "/usr/local/lib/python3.6/dist-packages/celery/backends/asynchronous.py", line 54, in drain_events_until
flask-app_1      | 2019-11-25T17:41:25.721921475Z     raise socket.timeout()
flask-app_1      | 2019-11-25T17:41:25.721958594Z socket.timeout
flask-app_1      | 2019-11-25T17:41:25.722003457Z 
flask-app_1      | 2019-11-25T17:41:25.722237255Z During handling of the above exception, another exception occurred:
flask-app_1      | 2019-11-25T17:41:25.722323143Z 
flask-app_1      | 2019-11-25T17:41:25.722376041Z Traceback (most recent call last):
flask-app_1      | 2019-11-25T17:41:25.722425474Z   File "/usr/local/lib/python3.6/dist-packages/flask/app.py", line 1949, in full_dispatch_request
flask-app_1      | 2019-11-25T17:41:25.722477450Z     rv = self.dispatch_request()
flask-app_1      | 2019-11-25T17:41:25.722530095Z   File "/usr/local/lib/python3.6/dist-packages/flask/app.py", line 1935, in dispatch_request
flask-app_1      | 2019-11-25T17:41:25.722581243Z     return self.view_functions[rule.endpoint](**req.view_args)
flask-app_1      | 2019-11-25T17:41:25.722635937Z   File "/usr/local/lib/python3.6/dist-packages/flask_login/utils.py", line 261, in decorated_view
flask-app_1      | 2019-11-25T17:41:25.722687704Z     return func(*args, **kwargs)
flask-app_1      | 2019-11-25T17:41:25.722740441Z   File "/simoc/simoc_server/views.py", line 119, in new_game
flask-app_1      | 2019-11-25T17:41:25.722791197Z     result = tasks.new_game.delay(get_standard_user_obj().username, game_config).get(timeout=60)
flask-app_1      | 2019-11-25T17:41:25.722867714Z   File "/usr/local/lib/python3.6/dist-packages/celery/result.py", line 226, in get
flask-app_1      | 2019-11-25T17:41:25.723017467Z     on_message=on_message,
flask-app_1      | 2019-11-25T17:41:25.723103259Z   File "/usr/local/lib/python3.6/dist-packages/celery/backends/asynchronous.py", line 188, in wait_for_pending
flask-app_1      | 2019-11-25T17:41:25.723204659Z     for _ in self._wait_for_pending(result, **kwargs):
flask-app_1      | 2019-11-25T17:41:25.723436232Z   File "/usr/local/lib/python3.6/dist-packages/celery/backends/asynchronous.py", line 259, in _wait_for_pending
flask-app_1      | 2019-11-25T17:41:25.723490403Z     raise TimeoutError('The operation timed out.')
flask-app_1      | 2019-11-25T17:41:25.723551548Z celery.exceptions.TimeoutError: The operation timed out.
flask-app_1      | 2019-11-25T17:41:25.723604063Z [2019-11-25 17:41:25 +0000] [10] [ERROR] ERROR: handling exception The operation timed out.
flask-app_1      | 2019-11-25T17:41:25.724770019Z [2019-11-25 17:41:25 +0000] [10] [DEBUG] Closing connection.
ezio-melotti commented 5 years ago

When I tried to start a new simulation I got the same error reported in #88, even after logging off and logging in again.