<html><head><meta http-equiv="Content-Type" content="text/html charset=utf-8"></head><body style="word-wrap: break-word; -webkit-nbsp-mode: space; -webkit-line-break: after-white-space;" class=""><div class="">Daniel is correct.</div><div class=""><br class=""></div>I have been dealing with issues like this a lot recently with our internal LNT. Assuming this is the same issue, I’ll share what I have figured out so far. I run LNT from gunicorn, proxied with apache. We were getting a lot of timeouts on submissions, and exhausted database connections. In our case, we are using Postgres, and LNT would easily use all 100 connections Postgres creates by default. Apache like to mask these things by timing you out early.<div class=""><br class=""></div><div class="">I traced our issue back to the submitRun being extremely slow on about 1 in 5 submissions. I get a feeling it was the submissions for particular machines possibly some of the older machines, though I could not reproduce it reliably. I found that with timeout removed, some submissions were taking 200s to process, and a few were as long as 400s. I did this by putting print statements in our production server and watching the submit requests being processed. All this time is spent generating the field changes, I did not dig in any further than that. What was happening is that as we were running more runs, we had more and more submissions taking that long, and eventually the server would start throwing errors like this, because all database connections were in use doing submissions.</div><div class=""><br class=""></div><div class="">My solution: I jacked our timeouts way up (1000s) and upped our database connections even further. We do now process all our submissions, and I only feel sort of dirty when I think about it.</div><div class=""><br class=""></div><div class="">The real solution: we have to find out what is going in in field change generation that is sucking up so much time! Submit run is interesting, it is the only place in LNT were we write into the database, and we are doing a lot of processing of the data when it comes in.</div><div class=""><br class=""></div><div class="">Maybe we should track this with a PR? I am willing to help track this down. I’ve found the lack of request logging makes it sort of tricky to nail down how often this happens, the only insights I have are from adding print statements to suspect code paths.<br class=""><div class=""><br class=""><div><blockquote type="cite" class=""><div class="">On May 10, 2015, at 2:09 PM, Daniel Dunbar <<a href="mailto:daniel@zuster.org" class="">daniel@zuster.org</a>> wrote:</div><br class="Apple-interchange-newline"><div class=""><div dir="ltr" class="">Hi Kristof,<div class=""><br class=""></div><div class="">It has been a long time since I looked at this, but aren't we just caching the DB on the request object, thus ensuring there is one opened DB, and hence session, per request? The V4DB is essentially just wrapping the session.</div><div class=""><br class=""></div><div class=""> - Daniel</div></div><div class="gmail_extra"><br class=""><div class="gmail_quote">On Sun, May 10, 2015 at 11:21 AM, Kristof Beyls <span dir="ltr" class=""><<a href="mailto:kristof.beyls@arm.com" target="_blank" class="">kristof.beyls@arm.com</a>></span> wrote:<br class=""><blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex"><div lang="EN-GB" link="blue" vlink="purple" class=""><div class=""><p class="MsoNormal">Daniel, Tobias, Renato and myself have been looking a little bit at the potential underlying reason<br class="">for why <a href="http://llvm.org/perf/" target="_blank" class="">http://llvm.org/perf/</a> is instable, and have found some clues. I want to share them here<br class="">to give people with more experience in the frameworks used by LNT (flask, sqlalchemy, wsgi, …)<br class="">a chance to check if our reasoning below seems plausible.<u class=""></u><u class=""></u></p><p class="MsoNormal"><u class=""></u> <u class=""></u></p><p class="MsoNormal">Daniel noticed the following backtrace in the log after <a href="http://llvm.org/perf" target="_blank" class="">http://llvm.org/perf</a> started giving “Internal Server Error”<br class="">again:<u class=""></u><u class=""></u></p><div style="margin: 0cm 0cm 0.0001pt;" class=""><span style="font-size:8.5pt;font-family:"Menlo","serif"" class="">2015-05-08 22:57:05,309 ERROR: Exception on /db_default/v4/nts/287/graph [GET] [in /opt/venv/perf/lib/python2.7/site-packages/Flask-0.10.1-py2.7.egg/flask/app.py:1423]<u class=""></u><u class=""></u></span></div><div style="margin: 0cm 0cm 0.0001pt;" class=""><span style="font-size:8.5pt;font-family:"Menlo","serif"" class="">Traceback (most recent call last):<u class=""></u><u class=""></u></span></div><div style="margin: 0cm 0cm 0.0001pt;" class=""><span style="font-size:8.5pt;font-family:"Menlo","serif"" class=""> File "/opt/venv/perf/lib/python2.7/site-packages/Flask-0.10.1-py2.7.egg/flask/app.py", line 1817, in wsgi_app<u class=""></u><u class=""></u></span></div><div style="margin: 0cm 0cm 0.0001pt;" class=""><span style="font-size:8.5pt;font-family:"Menlo","serif"" class=""> response = self.full_dispatch_request()<u class=""></u><u class=""></u></span></div><div style="margin: 0cm 0cm 0.0001pt;" class=""><span style="font-size:8.5pt;font-family:"Menlo","serif"" class=""> File "/opt/venv/perf/lib/python2.7/site-packages/Flask-0.10.1-py2.7.egg/flask/app.py", line 1477, in full_dispatch_request<u class=""></u><u class=""></u></span></div><div style="margin: 0cm 0cm 0.0001pt;" class=""><span style="font-size:8.5pt;font-family:"Menlo","serif"" class=""> rv = self.handle_user_exception(e)<u class=""></u><u class=""></u></span></div><div style="margin: 0cm 0cm 0.0001pt;" class=""><span style="font-size:8.5pt;font-family:"Menlo","serif"" class=""> File "/opt/venv/perf/lib/python2.7/site-packages/Flask-0.10.1-py2.7.egg/flask/app.py", line 1381, in handle_user_exception<u class=""></u><u class=""></u></span></div><div style="margin: 0cm 0cm 0.0001pt;" class=""><span style="font-size:8.5pt;font-family:"Menlo","serif"" class=""> reraise(exc_type, exc_value, tb)<u class=""></u><u class=""></u></span></div><div style="margin: 0cm 0cm 0.0001pt;" class=""><span style="font-size:8.5pt;font-family:"Menlo","serif"" class=""> File "/opt/venv/perf/lib/python2.7/site-packages/Flask-0.10.1-py2.7.egg/flask/app.py", line 1475, in full_dispatch_request<u class=""></u><u class=""></u></span></div><div style="margin: 0cm 0cm 0.0001pt;" class=""><span style="font-size:8.5pt;font-family:"Menlo","serif"" class=""> rv = self.dispatch_request()<u class=""></u><u class=""></u></span></div><div style="margin: 0cm 0cm 0.0001pt;" class=""><span style="font-size:8.5pt;font-family:"Menlo","serif"" class=""> File "/opt/venv/perf/lib/python2.7/site-packages/Flask-0.10.1-py2.7.egg/flask/app.py", line 1461, in dispatch_request<u class=""></u><u class=""></u></span></div><div style="margin: 0cm 0cm 0.0001pt;" class=""><span style="font-size:8.5pt;font-family:"Menlo","serif"" class=""> return self.view_functions[rule.endpoint](**req.view_args)<u class=""></u><u class=""></u></span></div><div style="margin: 0cm 0cm 0.0001pt;" class=""><span style="font-size:8.5pt;font-family:"Menlo","serif"" class=""> File "/opt/venv/perf/lib/python2.7/site-packages/LNT-0.4.1dev-py2.7.egg/lnt/server/ui/decorators.py", line 67, in wrap<u class=""></u><u class=""></u></span></div><div style="margin: 0cm 0cm 0.0001pt;" class=""><span style="font-size:8.5pt;font-family:"Menlo","serif"" class=""> result = f(**args)<u class=""></u><u class=""></u></span></div><div style="margin: 0cm 0cm 0.0001pt;" class=""><span style="font-size:8.5pt;font-family:"Menlo","serif"" class=""> File "/opt/venv/perf/lib/python2.7/site-packages/LNT-0.4.1dev-py2.7.egg/lnt/server/ui/views.py", line 385, in v4_run_graph<u class=""></u><u class=""></u></span></div><div style="margin: 0cm 0cm 0.0001pt;" class=""><span style="font-size:8.5pt;font-family:"Menlo","serif"" class=""> ts = request.get_testsuite()<u class=""></u><u class=""></u></span></div><div style="margin: 0cm 0cm 0.0001pt;" class=""><span style="font-size:8.5pt;font-family:"Menlo","serif"" class=""> File "/opt/venv/perf/lib/python2.7/site-packages/LNT-0.4.1dev-py2.7.egg/lnt/server/ui/app.py", line 76, in get_testsuite<u class=""></u><u class=""></u></span></div><div style="margin: 0cm 0cm 0.0001pt;" class=""><span style="font-size:8.5pt;font-family:"Menlo","serif"" class=""> testsuites = self.get_db().testsuite<u class=""></u><u class=""></u></span></div><div style="margin: 0cm 0cm 0.0001pt;" class=""><span style="font-size:8.5pt;font-family:"Menlo","serif"" class=""> File "/opt/venv/perf/lib/python2.7/site-packages/LNT-0.4.1dev-py2.7.egg/lnt/server/ui/app.py", line 55, in get_db<u class=""></u><u class=""></u></span></div><div style="margin: 0cm 0cm 0.0001pt;" class=""><span style="font-size:8.5pt;font-family:"Menlo","serif"" class=""> self.db = current_app.old_config.get_database(g.db_name, echo=echo)<u class=""></u><u class=""></u></span></div><div style="margin: 0cm 0cm 0.0001pt;" class=""><span style="font-size:8.5pt;font-family:"Menlo","serif"" class=""> File "/opt/venv/perf/lib/python2.7/site-packages/LNT-0.4.1dev-py2.7.egg/lnt/server/config.py", line 148, in get_database<u class=""></u><u class=""></u></span></div><div style="margin: 0cm 0cm 0.0001pt;" class=""><span style="font-size:8.5pt;font-family:"Menlo","serif"" class=""> return lnt.server.db.v4db.V4DB(db_entry.path, self, echo=echo)<u class=""></u><u class=""></u></span></div><div style="margin: 0cm 0cm 0.0001pt;" class=""><span style="font-size:8.5pt;font-family:"Menlo","serif"" class=""> File "/opt/venv/perf/lib/python2.7/site-packages/LNT-0.4.1dev-py2.7.egg/lnt/server/db/v4db.py", line 108, in __init__<u class=""></u><u class=""></u></span></div><div style="margin: 0cm 0cm 0.0001pt;" class=""><span style="font-size:8.5pt;font-family:"Menlo","serif"" class=""> .filter_by(id = lnt.testing.PASS).first()<u class=""></u><u class=""></u></span></div><div style="margin: 0cm 0cm 0.0001pt;" class=""><span style="font-size:8.5pt;font-family:"Menlo","serif"" class=""> File "/opt/venv/perf/lib/python2.7/site-packages/SQLAlchemy-0.9.6-py2.7.egg/sqlalchemy/orm/query.py", line 2334, in first<u class=""></u><u class=""></u></span></div><div style="margin: 0cm 0cm 0.0001pt;" class=""><span style="font-size:8.5pt;font-family:"Menlo","serif"" class=""> ret = list(self[0:1])<u class=""></u><u class=""></u></span></div><div style="margin: 0cm 0cm 0.0001pt;" class=""><span style="font-size:8.5pt;font-family:"Menlo","serif"" class=""> File "/opt/venv/perf/lib/python2.7/site-packages/SQLAlchemy-0.9.6-py2.7.egg/sqlalchemy/orm/query.py", line 2201, in __getitem__<u class=""></u><u class=""></u></span></div><div style="margin: 0cm 0cm 0.0001pt;" class=""><span style="font-size:8.5pt;font-family:"Menlo","serif"" class=""> return list(res)<u class=""></u><u class=""></u></span></div><div style="margin: 0cm 0cm 0.0001pt;" class=""><span style="font-size:8.5pt;font-family:"Menlo","serif"" class=""> File "/opt/venv/perf/lib/python2.7/site-packages/SQLAlchemy-0.9.6-py2.7.egg/sqlalchemy/orm/query.py", line 2405, in __iter__<u class=""></u><u class=""></u></span></div><div style="margin: 0cm 0cm 0.0001pt;" class=""><span style="font-size:8.5pt;font-family:"Menlo","serif"" class=""> return self._execute_and_instances(context)<u class=""></u><u class=""></u></span></div><div style="margin: 0cm 0cm 0.0001pt;" class=""><span style="font-size:8.5pt;font-family:"Menlo","serif"" class=""> File "/opt/venv/perf/lib/python2.7/site-packages/SQLAlchemy-0.9.6-py2.7.egg/sqlalchemy/orm/query.py", line 2418, in _execute_and_instances<u class=""></u><u class=""></u></span></div><div style="margin: 0cm 0cm 0.0001pt;" class=""><span style="font-size:8.5pt;font-family:"Menlo","serif"" class=""> close_with_result=True)<u class=""></u><u class=""></u></span></div><div style="margin: 0cm 0cm 0.0001pt;" class=""><span style="font-size:8.5pt;font-family:"Menlo","serif"" class=""> File "/opt/venv/perf/lib/python2.7/site-packages/SQLAlchemy-0.9.6-py2.7.egg/sqlalchemy/orm/query.py", line 2409, in _connection_from_session<u class=""></u><u class=""></u></span></div><div style="margin: 0cm 0cm 0.0001pt;" class=""><span style="font-size:8.5pt;font-family:"Menlo","serif"" class=""> **kw)<u class=""></u><u class=""></u></span></div><div style="margin: 0cm 0cm 0.0001pt;" class=""><span style="font-size:8.5pt;font-family:"Menlo","serif"" class=""> File "/opt/venv/perf/lib/python2.7/site-packages/SQLAlchemy-0.9.6-py2.7.egg/sqlalchemy/orm/session.py", line 846, in connection<u class=""></u><u class=""></u></span></div><div style="margin: 0cm 0cm 0.0001pt;" class=""><span style="font-size:8.5pt;font-family:"Menlo","serif"" class=""> close_with_result=close_with_result)<u class=""></u><u class=""></u></span></div><div style="margin: 0cm 0cm 0.0001pt;" class=""><span style="font-size:8.5pt;font-family:"Menlo","serif"" class=""> File "/opt/venv/perf/lib/python2.7/site-packages/SQLAlchemy-0.9.6-py2.7.egg/sqlalchemy/orm/session.py", line 850, in _connection_for_bind<u class=""></u><u class=""></u></span></div><div style="margin: 0cm 0cm 0.0001pt;" class=""><span style="font-size:8.5pt;font-family:"Menlo","serif"" class=""> return self.transaction._connection_for_bind(engine)<u class=""></u><u class=""></u></span></div><div style="margin: 0cm 0cm 0.0001pt;" class=""><span style="font-size:8.5pt;font-family:"Menlo","serif"" class=""> File "/opt/venv/perf/lib/python2.7/site-packages/SQLAlchemy-0.9.6-py2.7.egg/sqlalchemy/orm/session.py", line 315, in _connection_for_bind<u class=""></u><u class=""></u></span></div><div style="margin: 0cm 0cm 0.0001pt;" class=""><span style="font-size:8.5pt;font-family:"Menlo","serif"" class=""> conn = bind.contextual_connect()<u class=""></u><u class=""></u></span></div><div style="margin: 0cm 0cm 0.0001pt;" class=""><span style="font-size:8.5pt;font-family:"Menlo","serif"" class=""> File "/opt/venv/perf/lib/python2.7/site-packages/SQLAlchemy-0.9.6-py2.7.egg/sqlalchemy/engine/base.py", line 1737, in contextual_connect<u class=""></u><u class=""></u></span></div><div style="margin: 0cm 0cm 0.0001pt;" class=""><span style="font-size:8.5pt;font-family:"Menlo","serif"" class=""> self.pool.connect(),<u class=""></u><u class=""></u></span></div><div style="margin: 0cm 0cm 0.0001pt;" class=""><span style="font-size:8.5pt;font-family:"Menlo","serif"" class=""> File "/opt/venv/perf/lib/python2.7/site-packages/SQLAlchemy-0.9.6-py2.7.egg/sqlalchemy/pool.py", line 332, in connect<u class=""></u><u class=""></u></span></div><div style="margin: 0cm 0cm 0.0001pt;" class=""><span style="font-size:8.5pt;font-family:"Menlo","serif"" class=""> return _ConnectionFairy._checkout(self)<u class=""></u><u class=""></u></span></div><div style="margin: 0cm 0cm 0.0001pt;" class=""><span style="font-size:8.5pt;font-family:"Menlo","serif"" class=""> File "/opt/venv/perf/lib/python2.7/site-packages/SQLAlchemy-0.9.6-py2.7.egg/sqlalchemy/pool.py", line 630, in _checkout<u class=""></u><u class=""></u></span></div><div style="margin: 0cm 0cm 0.0001pt;" class=""><span style="font-size:8.5pt;font-family:"Menlo","serif"" class=""> fairy = _ConnectionRecord.checkout(pool)<u class=""></u><u class=""></u></span></div><div style="margin: 0cm 0cm 0.0001pt;" class=""><span style="font-size:8.5pt;font-family:"Menlo","serif"" class=""> File "/opt/venv/perf/lib/python2.7/site-packages/SQLAlchemy-0.9.6-py2.7.egg/sqlalchemy/pool.py", line 433, in checkout<u class=""></u><u class=""></u></span></div><div style="margin: 0cm 0cm 0.0001pt;" class=""><span style="font-size:8.5pt;font-family:"Menlo","serif"" class=""> rec = pool._do_get()<u class=""></u><u class=""></u></span></div><div style="margin: 0cm 0cm 0.0001pt;" class=""><span style="font-size:8.5pt;font-family:"Menlo","serif"" class=""> File "/opt/venv/perf/lib/python2.7/site-packages/SQLAlchemy-0.9.6-py2.7.egg/sqlalchemy/pool.py", line 945, in _do_get<u class=""></u><u class=""></u></span></div><div style="margin: 0cm 0cm 0.0001pt;" class=""><span style="font-size:8.5pt;font-family:"Menlo","serif"" class=""> (self.size(), self.overflow(), self._timeout))<u class=""></u><u class=""></u></span></div><div style="margin: 0cm 0cm 0.0001pt;" class=""><span style="font-size:8.5pt;font-family:"Menlo","serif"" class="">TimeoutError: QueuePool limit of size 5 overflow 10 reached, connection timed out, timeout 30<u class=""></u><u class=""></u></span></div><p class="MsoNormal"><u class=""></u> <u class=""></u></p><p class="">After browsing through the sqlalchemy documentation and bits of the LNT implementation,<br class="">it seems so far that the following pieces may be the key parts that cause the problem<br class="">shown in the log.<u class=""></u><u class=""></u></p><p class=""><u class=""></u> <u class=""></u></p><p class="">The SQLAlchemy documentation seems to recommend to have a sqlalchemy session per web<br class="">request. Looking at the following pieces of LNT, I got the impression that instead a<br class="">session is shared between many or all requests:<u class=""></u><u class=""></u></p><p class=""><u class=""></u> <u class=""></u></p><p class="">From ui/app.py, it shows Request.get_db() basically caches get_database from "config":<u class=""></u><u class=""></u></p><p class="">...<u class=""></u><u class=""></u></p><p class="">class Request(flask.Request):<u class=""></u><u class=""></u></p><p class="">...<u class=""></u><u class=""></u></p><p class=""> def get_db(self):<u class=""></u><u class=""></u></p><p class="">...<u class=""></u><u class=""></u></p><p class=""> if self.db is None:<u class=""></u><u class=""></u></p><p class=""> echo = bool(self.args.get('db_log') or self.form.get('db_log'))<u class=""></u><u class=""></u></p><p class=""> self.db = current_app.old_config.get_database(g.db_name, echo=echo)<br class="">...<u class=""></u><u class=""></u></p><p class=""> return self.db<u class=""></u><u class=""></u></p><p class=""><u class=""></u> <u class=""></u></p><p class="">in config.py, it is shown that get_database returns a V4DB object by calling a constructor:<u class=""></u><u class=""></u></p><p class="">...<u class=""></u><u class=""></u></p><p class=""> def get_database(self, name, echo=False):<u class=""></u><u class=""></u></p><p class="">...<u class=""></u><u class=""></u></p><p class=""> # Instantiate the appropriate database version.<u class=""></u><u class=""></u></p><p class=""> if db_entry.db_version == '0.4':<u class=""></u><u class=""></u></p><p class=""> return lnt.server.db.v4db.V4DB(db_entry.path, self,<u class=""></u><u class=""></u></p><p class=""> db_entry.baseline_revision,<u class=""></u><u class=""></u></p><p class=""> echo)<br class="">...<u class=""></u><u class=""></u></p><p class=""><u class=""></u> <u class=""></u></p><p class="">This constructor is in db/v4db.py:<u class=""></u><u class=""></u></p><p class="">...<u class=""></u><u class=""></u></p><p class="">class V4DB(object):<u class=""></u><u class=""></u></p><p class="">...<u class=""></u><u class=""></u></p><p class=""> def __init__(self, path, config, baseline_revision=0, echo=False):<u class=""></u><u class=""></u></p><p class="">...<u class=""></u><u class=""></u></p><p class=""> self.session = sqlalchemy.orm.sessionmaker(self.engine)()<u class=""></u><u class=""></u></p><p class="">...<u class=""></u><u class=""></u></p><p class=""> # Add several shortcut aliases.<u class=""></u><u class=""></u></p><p class=""> self.add = self.session.add<u class=""></u><u class=""></u></p><p class=""> self.commit = self.session.commit<u class=""></u><u class=""></u></p><p class=""> self.query = self.session.query<u class=""></u><u class=""></u></p><p class=""> self.rollback = self.session.rollback<br class="">...<u class=""></u><u class=""></u></p><p class=""><u class=""></u> <u class=""></u></p><p class=""><u class=""></u> <u class=""></u></p><p class=""><u class=""></u> <u class=""></u></p><p class="">It seems like a single session object is created in this constructor that will ultimately<br class="">be shared across all Requests. It seems that instead, the request.get_db method should<br class="">create a new session for each request. And close that session when the request is finalized<br class="">which probably needs to be done by hooking into something Flask-specific.<u class=""></u><u class=""></u></p><p class=""><u class=""></u> <u class=""></u></p><p class="">The self.add and following lines in the constructor show that it probably will be<br class="">non-trivial to refactor code so that there will not be a single session per v4db object.<u class=""></u><u class=""></u></p><p class=""><u class=""></u> <u class=""></u></p><p class="">We’re not sure if making separate sessions per Request is going to solve the <a href="http://llvm.org/perf" target="_blank" class="">http://llvm.org/perf</a><br class="">instability problems; but that’s the best idea we’ve got so far. <u class=""></u><u class=""></u></p><p class=""><u class=""></u> <u class=""></u></p><p class="">Thanks,<span class="HOEnZb"><font color="#888888" class=""><u class=""></u><u class=""></u></font></span></p><span class="HOEnZb"><font color="#888888" class=""><p class=""><u class=""></u> <u class=""></u></p><p class="">Kristof<u class=""></u><u class=""></u></p><p class="MsoNormal"><u class=""></u> <u class=""></u></p></font></span></div></div></blockquote></div><br class=""></div>
</div></blockquote></div><br class=""></div></div></body></html>