3.12.0 Issue with SQL - Githubissues

The 3.12.0 version keeps crashing periodically with the following errors:

E 221018 12:26:15 web:1221] Uncaught exception Oct 18 12:26:15 ip-100-122-4-171 rootthebox.py[7726]: Oct 18 12:26:15 ip-100-122-4-171 rootthebox.py[7726]: Oct 18 12:26:15 ip-100-122-4-171 rootthebox.py[7726]: Oct 18 12:26:15 ip-100-122-4-171 rootthebox.py[7726]: Oct 18 12:26:15 ip-100-122-4-171 rootthebox.py[7726]: Oct 18 12:26:15 ip-100-122-4-171 rootthebox.py[7726]: Oct 18 12:26:15 ip-100-122-4-171 rootthebox.py[7726]: Oct 18 12:26:15 ip-100-122-4-171 rootthebox.py[7726]: Oct 18 12:26:15 ip-100-122-4-171 rootthebox.py[7726]: Oct 18 12:26:15 ip-100-122-4-171 rootthebox.py[7726]: Oct 18 12:26:15 ip-100-122-4-171 rootthebox.py[7726]: Oct 18 12:26:15 ip-100-122-4-171 rootthebox.py[7726]: Oct 18 12:26:15 ip-100-122-4-171 rootthebox.py[7726]: Oct 18 12:26:15 ip-100-122-4-171 rootthebox.py[7726]: Oct 18 12:26:15 ip-100-122-4-171 rootthebox.py[7726]: Oct 18 12:26:15 ip-100-122-4-171 rootthebox.py[7726]: Oct 18 12:26:15 ip-100-122-4-171 rootthebox.py[7726]: Oct 18 12:26:15 ip-100-122-4-171 rootthebox.py[7726]: Oct 18 12:26:15 ip-100-122-4-171 rootthebox.py[7726]: Oct 18 12:26:15 ip-100-122-4-171 rootthebox.py[7726]: Oct 18 12:26:15 ip-100-122-4-171 rootthebox.py[7726]: Oct 18 12:26:15 ip-100-122-4-171 rootthebox.py[7726]: Oct 18 12:26:15 ip-100-122-4-171 rootthebox.py[7726]: Oct 18 12:26:15 ip-100-122-4-171 rootthebox.py[7726]: Oct 18 12:26:15 ip-100-122-4-171 rootthebox.py[7726]: Oct 18 12:26:15 ip-100-122-4-171 rootthebox.py[7726]: Oct 18 12:26:15 ip-100-122-4-171 rootthebox.py[7726]: Oct 18 12:26:15 ip-100-122-4-171 rootthebox.py[7726]: Oct 18 12:26:15 ip-100-122-4-171 rootthebox.py[7726]: Oct 18 12:26:15 ip-100-122-4-171 rootthebox.py[7726]: Oct 18 12:26:15 ip-100-122-4-171 rootthebox.py[7726]: Oct 18 12:26:15 ip-100-122-4-171 rootthebox.py[7726]: Oct 18 12:26:15 ip-100-122-4-171 rootthebox.py[7726]: Oct 18 12:26:15 ip-100-122-4-171 rootthebox.py[7726]: Oct 18 12:26:15 ip-100-122-4-171 rootthebox.py[7726]: Oct 18 12:26:15 ip-100-122-4-171 rootthebox.py[7726]: Oct 18 12:26:15 ip-100-122-4-171 rootthebox.py[7726]: Oct 18 12:26:15 ip-100-122-4-171 rootthebox.py[7726]: Oct 18 12:26:15 ip-100-122-4-171 rootthebox.py[7726]: Oct 18 12:26:15 ip-100-122-4-171 rootthebox.py[7726]: Oct 18 12:26:15 ip-100-122-4-171 rootthebox.py[7726]: Oct 18 12:26:15 ip-100-122-4-171 rootthebox.py[7726]: Oct 18 12:26:15 ip-100-122-4-171 rootthebox.py[7726]: Oct 18 12:26:15 ip-100-122-4-171 rootthebox.py[7726]: Oct 18 12:26:15 ip-100-122-4-171 rootthebox.py[7726]: Oct 18 12:26:15 ip-100-122-4-171 rootthebox.py[7726]: Oct 18 12:26:15 ip-100-122-4-171 rootthebox.py[7726]: Oct 18 12:26:15 ip-100-122-4-171 rootthebox.py[7726]: Oct 18 12:26:15 ip-100-122-4-171 rootthebox.py[7726]: Oct 18 12:26:15 ip-100-122-4-171 rootthebox.py[7726]: Oct 18 12:26:15 ip-100-122-4-171 rootthebox.py[7726]:
self.path_kwargs) File "/opt/CTF/RootTheBox/handlers/UserHandlers.py", line 106, in get scoreboard_visible=options.scoreboard_visibility != "admins", File "/usr/local/lib/python3.7/dist-packages/tornado/web.py", line 865, in render html = self.render_string(template_name, kwargs) File "/usr/local/lib/python3.7/dist-packages/tornado/web.py", line 1014, in render_string return t.generate(namespace) File "/usr/local/lib/python3.7/dist-packages/tornado/template.py", line 362, in generate return execute() File "user/home_html.generated.py", line 513, in _tt_execute _tt_tmp = ( len(team.level_flags(level.number)) / float(len(level.flags)) ) * 100.0 # user/home.html:252 (via main.html:33) File "/opt/CTF/RootTheBox/models/GameLevel.py", line 174, in flags _flags += sorted(box.flags) File "/opt/CTF/RootTheBox/models/Box.py", line 182, in flags for flag in self.flags: File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/orm/attributes.py", line 482, in get return self.impl.get(state, dict) File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/orm/attributes.py", line 942, in get value = self._fire_loader_callables(state, key, passive) File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/orm/attributes.py", line 978, in _fire_loadercallables return self.callable(state, passive) File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/orm/strategies.py", line 918, in _load_for_state extra_criteria, File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/orm/strategies.py", line 1050, in _emit_lazyload result = result.unique().scalars().all() File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/engine/result.py", line 1430, in all return self._allrows() File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/engine/result.py", line 401, in _allrows rows = self._fetchall_impl() File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/engine/result.py", line 1343, in _fetchall_impl return self._real_result._fetchall_impl() File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/engine/result.py", line 1755, in _fetchall_impl return list(self.iterator) File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/orm/loading.py", line 147, in chunks fetch = cursor._raw_all_rows() File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/engine/result.py", line 391, in _raw_all_rows make_row = self._row_getter File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/util/langhelpers.py", line 1184, in get obj.dict[self.name] = result = self.fget(obj) File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/engine/result.py", line 320, in _row_getter keymap = metadata._keymap File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/engine/cursor.py", line 1207, in _keymap self._we_dont_return_rows() File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/engine/cursor.py", line 1193, in _we_dont_return_rows replacecontext=err, File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/util/compat.py", line 208, in raise raise exception sqlalchemy.exc.ResourceClosedError: This result object does not return rows. It has been closed automatically. /> During handling of the above exception, another exception occurred: /> Traceback (most recent call last): File "/usr/local/lib/python3.7/dist-packages/tornado/web.py", line 1219, in send_error self.write_error(status_code, kwargs) File "/opt/CTF/RootTheBox/handlers/BaseHandlers.py", line 207, in write_error self.render("public/404.html") File "/usr/local/lib/python3.7/dist-packages/tornado/web.py", line 865, in render html = self.render_string(template_name, kwargs) File "/usr/local/lib/python3.7/dist-packages/tornado/web.py", line 1014, in render_string return t.generate(*namespace) File "/usr/local/lib/python3.7/dist-packages/tornado/template.py", line 362, in generate return execute() File "public/404_html.generated.py", line 14, in _tt_execute _tt_tmp = _tt_modules.Menu() # main.html:31 File "/usr/local/lib/python3.7/dist-packages/tornado/web.py", line 1811, in render rendered = self._active_modules[name].render(args, kwargs) File "/opt/CTF/RootTheBox/modules/Menu.py", line 36, in render user = User.by_id(self.handler.session["user_id"]) File "/opt/CTF/RootTheBox/models/User.py", line 131, in by_id return dbsession.query(cls).filter_by(id=_id).first() File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/orm/query.py", line 2823, in first return self.limit(1)._iter().first() File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/orm/query.py", line 2910, in _iter execution_options={"_sa_orm_load_options": self.load_options}, File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/orm/session.py", line 1712, in execute result = conn._execute_20(statement, params or {}, execution_options) File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/engine/base.py", line 1705, in _execute_20 return meth(self, args_10style, kwargs_10style, execution_options) File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/sql/elements.py", line 334, in _execute_on_connection self, multiparams, params, execution_options File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/engine/base.py", line 1582, in _execute_clauseelement cache_hit=cache_hit, File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/engine/base.py", line 1798, in _execute_context conn = self._revalidate_connection() File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/engine/base.py", line 645, in _revalidate_connection self._invalid_transaction() File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/engine/base.py", line 625, in _invalid_transaction code="8s2b", sqlalchemy.exc.PendingRollbackError: Can't reconnect until invalid transaction is rolled back. (Background on this error at: https://sqlalche.me/e/14/8s2b)

.py[26122]: MySQLdb.OperationalError: (2000, 'Unknown MySQL error') Oct 18 12:46:11 ip-100-122-4-190 rootthebox.py[26122]:
Oct 18 12:46:11 ip-100-122-4-190 rootthebox.py[26122]: The above exception was the direct cause of the following exception: Oct 18 12:46:11 ip-100-122-4-190 rootthebox.py[26122]:
Oct 18 12:46:11 ip-100-122-4-190 rootthebox.py[26122]: Traceback (most recent call last): Oct 18 12:46:11 ip-100-122-4-190 rootthebox.py[26122]: File "/usr/local/lib/python3.7/dist-packages/tornado/web.py", line 1711, in _execute Oct 18 12:46:11 ip-100-122-4-190 rootthebox.py[26122]: result = method(*self.path_args, **self.path_kwargs) Oct 18 12:46:11 ip-100-122-4-190 rootthebox.py[26122]: File "/opt/CTF/RootTheBox/handlers/ScoreboardHandlers.py", line 134, in get Oct 18 12:46:11 ip-100-122-4-190 rootthebox.py[26122]: uri[args[0]]() Oct 18 12:46:11 ip-100-122-4-190 rootthebox.py[26122]: File "/opt/CTF/RootTheBox/handlers/ScoreboardHandlers.py", line 189, in mvp_table Oct 18 12:46:11 ip-100-122-4-190 rootthebox.py[26122]: self.render("scoreboard/mvp_table.html", users=User.ranks()) Oct 18 12:46:11 ip-100-122-4-190 rootthebox.py[26122]: File "/opt/CTF/RootTheBox/models/User.py", line 186, in ranks Oct 18 12:46:11 ip-100-122-4-190 rootthebox.py[26122]: return dbsession.query(cls).order_by(desc(cls.money)).all() Oct 18 12:46:11 ip-100-122-4-190 rootthebox.py[26122]: File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/orm/query.py", line 2772, in all Oct 18 12:46:11 ip-100-122-4-190 rootthebox.py[26122]: return self._iter().all() Oct 18 12:46:11 ip-100-122-4-190 rootthebox.py[26122]: File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/orm/query.py", line 2910, in _iter Oct 18 12:46:11 ip-100-122-4-190 rootthebox.py[26122]: execution_options={"_sa_orm_load_options": self.load_options}, Oct 18 12:46:11 ip-100-122-4-190 rootthebox.py[26122]: File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/orm/session.py", line 1712, in execute Oct 18 12:46:11 ip-100-122-4-190 rootthebox.py[26122]: result = conn._execute_20(statement, params or {}, execution_options) Oct 18 12:46:11 ip-100-122-4-190 rootthebox.py[26122]: File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/engine/base.py", line 1705, in _execute_20 Oct 18 12:46:11 ip-100-122-4-190 rootthebox.py[26122]: return meth(self, args_10style, kwargs_10style, execution_options) Oct 18 12:46:11 ip-100-122-4-190 rootthebox.py[26122]: File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/sql/elements.py", line 334, in _execute_on_connection Oct 18 12:46:11 ip-100-122-4-190 rootthebox.py[26122]: self, multiparams, params, execution_options Oct 18 12:46:11 ip-100-122-4-190 rootthebox.py[26122]: File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/engine/base.py", line 1582, in _execute_clauseelement Oct 18 12:46:11 ip-100-122-4-190 rootthebox.py[26122]: cache_hit=cache_hit, Oct 18 12:46:11 ip-100-122-4-190 rootthebox.py[26122]: File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/engine/base.py", line 1944, in _execute_context Oct 18 12:46:11 ip-100-122-4-190 rootthebox.py[26122]: e, statement, parameters, cursor, context Oct 18 12:46:11 ip-100-122-4-190 rootthebox.py[26122]: File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/engine/base.py", line 2125, in _handle_dbapi_exception Oct 18 12:46:11 ip-100-122-4-190 rootthebox.py[26122]: sqlalchemy_exception, with_traceback=excinfo[2], from=e Oct 18 12:46:11 ip-100-122-4-190 rootthebox.py[26122]: File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/util/compat.py", line 208, in raise_ Oct 18 12:46:11 ip-100-122-4-190 rootthebox.py[26122]: raise exception Oct 18 12:46:11 ip-100-122-4-190 rootthebox.py[26122]: File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/engine/base.py", line 1901, in _execute_context Oct 18 12:46:11 ip-100-122-4-190 rootthebox.py[26122]: cursor, statement, parameters, context Oct 18 12:46:11 ip-100-122-4-190 rootthebox.py[26122]: File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/engine/default.py", line 736, in do_execute Oct 18 12:46:11 ip-100-122-4-190 rootthebox.py[26122]: cursor.execute(statement, parameters) Oct 18 12:46:11 ip-100-122-4-190 rootthebox.py[26122]: File "/usr/local/lib/python3.7/dist-packages/MySQLdb/cursors.py", line 206, in execute Oct 18 12:46:11 ip-100-122-4-190 rootthebox.py[26122]: res = self._query(query) Oct 18 12:46:11 ip-100-122-4-190 rootthebox.py[26122]: File "/usr/local/lib/python3.7/dist-packages/MySQLdb/cursors.py", line 320, in _query Oct 18 12:46:11 ip-100-122-4-190 rootthebox.py[26122]: self._do_get_result(db) Oct 18 12:46:11 ip-100-122-4-190 rootthebox.py[26122]: File "/usr/local/lib/python3.7/dist-packages/MySQLdb/cursors.py", line 145, in _do_get_result Oct 18 12:46:11 ip-100-122-4-190 rootthebox.py[26122]: self._result = result = self._get_result() Oct 18 12:46:11 ip-100-122-4-190 rootthebox.py[26122]: File "/usr/local/lib/python3.7/dist-packages/MySQLdb/cursors.py", line 352, in _get_result Oct 18 12:46:11 ip-100-122-4-190 rootthebox.py[26122]: return self._get_db().store_result() Oct 18 12:46:11 ip-100-122-4-190 rootthebox.py[26122]: sqlalchemy.exc.OperationalError: (MySQLdb.OperationalError) (2000, 'Unknown MySQL error')

I may be out of my depth on this one. Let me call in the big gun for review @moloch-- I expect this is due to this commit https://github.com/moloch--/RootTheBox/commit/0358437b4d070e4b18c1b1e66801e1f9b79cbc6c

The attempt to async the gamestate update didn't work right, so I tried to go to a thread model. It works, but db sessions are not thread safe. scoped_session was suppose to fix that, but I'm not sure I totally implemented it properly based on your errors. Perhaps the main thread scope needs to be removed after the transaction is closed and then recreated? I didn't think that would be necessary for the main thread. Hopefully Moloch can provide some advise.

I pushed a new branch 3.12.1 that I'm hoping will help. It doesn't address the scoped_session (not sure that's even the issue), but it does focus on the query in the error, which was the MVP board. I moved that query into the gamestate as well, so it should be faster, but the main point is it removes that database query during refresh. I should had done that before but missed it. So, even if it doesn't fix the issue, it was a good change. Let me know if it helps.. I'm anxious that this is happening and want to get it fixed as soon as possible, but I'm currently only guessing the cause.

I updated to the 3.12.1 but without luck. Logs attached. Perfmance is much better than the previous version. At least until this from bellow happens :)

Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: Exception in thread Thread-6: Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: Traceback (most recent call last): Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/engine/base.py", line 1901, in _execute_context Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: cursor, statement, parameters, context Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/engine/default.py", line 736, in do_execute Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: cursor.execute(statement, parameters) Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: File "/usr/local/lib/python3.7/dist-packages/MySQLdb/cursors.py", line 183, in execute Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: while self.nextset(): Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: File "/usr/local/lib/python3.7/dist-packages/MySQLdb/cursors.py", line 137, in nextset Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: nr = db.next_result() Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: MySQLdb.ProgrammingError: (2014, "Commands out of sync; you can't run this command now") Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: The above exception was the direct cause of the following exception: Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: Traceback (most recent call last): Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: File "/usr/lib/python3.7/threading.py", line 917, in _bootstrap_inner Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: self.run() Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: File "/usr/lib/python3.7/threading.py", line 865, in run Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: self._target(*self._args, self._kwargs) Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: File "/opt/CTF/RootTheBox/libs/Scoreboard.py", line 69, in _update_gamestate Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: teams = Team.ranks(threadsession) Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: File "/opt/CTF/RootTheBox/models/Team.py", line 143, in ranks Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: if not team.locked: Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: File "/opt/CTF/RootTheBox/models/Team.py", line 205, in locked Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: if not user.locked: Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: File "/opt/CTF/RootTheBox/models/User.py", line 310, in locked Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: if self.is_admin(): Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: File "/opt/CTF/RootTheBox/models/User.py", line 381, in is_admin Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: return self.has_permission(ADMIN_PERMISSION) Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: File "/opt/CTF/RootTheBox/models/User.py", line 378, in has_permission Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: return True if permission in self.permissions_names else False Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: File "/opt/CTF/RootTheBox/models/User.py", line 302, in permissions_names Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: return [permission.name for permission in self.permissions_all] Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/orm/query.py", line 2900, in iter Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: return self._iter().iter() Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/orm/query.py", line 2910, in _iter Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: execution_options={"_sa_orm_load_options": self.load_options}, Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/orm/session.py", line 1712, in execute Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: result = conn._execute_20(statement, params or {}, execution_options) Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/engine/base.py", line 1705, in _execute_20 Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: return meth(self, args_10style, kwargs_10style, execution_options) Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/sql/elements.py", line 334, in _execute_on_connection Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: self, multiparams, params, execution_options Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/engine/base.py", line 1582, in _execute_clauseelement Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: cache_hit=cache_hit, Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/engine/base.py", line 1944, in _execute_context Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: e, statement, parameters, cursor, context Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/engine/base.py", line 2125, in _handle_dbapi_exception Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: sqlalchemy_exception, with_traceback=excinfo[2], from=e Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/util/compat.py", line 208, in raise_ Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: raise exception Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/engine/base.py", line 1901, in _execute_context Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: cursor, statement, parameters, context Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/engine/default.py", line 736, in do_execute Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: cursor.execute(statement, parameters) Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: File "/usr/local/lib/python3.7/dist-packages/MySQLdb/cursors.py", line 183, in execute Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: while self.nextset(): Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: File "/usr/local/lib/python3.7/dist-packages/MySQLdb/cursors.py", line 137, in nextset Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: nr = db.next_result() Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: sqlalchemy.exc.ProgrammingError: (MySQLdb.ProgrammingError) (2014, "Commands out of sync; you can't run this command now") Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: [SQL: SELECT permission.id AS permission_id, permission.created AS permission_created, permission.user_id AS permission_user_id, permission.name AS permission_name Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: FROM permission Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: WHERE permission.user_id = %s] Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: [parameters: (256,)] Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: (Background on this error at: https://sqlalche.me/e/14/f405) Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: Exception in thread Thread-5: Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: Traceback (most recent call last): Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/engine/base.py", line 1901, in _execute_context Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: cursor, statement, parameters, context Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/engine/default.py", line 736, in do_execute Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: cursor.execute(statement, parameters) Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: File "/usr/local/lib/python3.7/dist-packages/MySQLdb/cursors.py", line 206, in execute Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: res = self._query(query) Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: File "/usr/local/lib/python3.7/dist-packages/MySQLdb/cursors.py", line 320, in _query Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: self._do_get_result(db) Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: File "/usr/local/lib/python3.7/dist-packages/MySQLdb/cursors.py", line 145, in _do_get_result Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: self._result = result = self._get_result() Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: File "/usr/local/lib/python3.7/dist-packages/MySQLdb/cursors.py", line 352, in _get_result Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: return self._get_db().store_result() Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: MySQLdb.OperationalError: (2006, '') Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: The above exception was the direct cause of the following exception: Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: Traceback (most recent call last): Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: File "/usr/lib/python3.7/threading.py", line 917, in _bootstrap_inner Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: self.run() Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: File "/usr/lib/python3.7/threading.py", line 865, in run Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: self._target(*self._args, *self._kwargs) Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: File "/opt/CTF/RootTheBox/libs/Scoreboard.py", line 69, in _update_gamestate Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: teams = Team.ranks(threadsession) Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: File "/opt/CTF/RootTheBox/models/Team.py", line 143, in ranks Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: if not team.locked: Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: File "/opt/CTF/RootTheBox/models/Team.py", line 205, in locked Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: if not user.locked: Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: File "/opt/CTF/RootTheBox/models/User.py", line 310, in locked Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: if self.is_admin(): Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: File "/opt/CTF/RootTheBox/models/User.py", line 381, in is_admin Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: return self.has_permission(ADMIN_PERMISSION) Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: File "/opt/CTF/RootTheBox/models/User.py", line 378, in has_permission Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: return True if permission in self.permissions_names else False Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: File "/opt/CTF/RootTheBox/models/User.py", line 302, in permissions_names Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: return [permission.name for permission in self.permissions_all] Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/orm/query.py", line 2900, in iter Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: return self._iter().iter() Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/orm/query.py", line 2910, in _iter Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: execution_options={"_sa_orm_load_options": self.load_options}, Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/orm/session.py", line 1712, in execute Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: result = conn._execute_20(statement, params or {}, execution_options) Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/engine/base.py", line 1705, in _execute_20 Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: return meth(self, args_10style, kwargs_10style, execution_options) Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/sql/elements.py", line 334, in _execute_on_connection Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: self, multiparams, params, execution_options Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/engine/base.py", line 1582, in _execute_clauseelement Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: cache_hit=cache_hit, Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/engine/base.py", line 1944, in _execute_context Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: e, statement, parameters, cursor, context Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/engine/base.py", line 2125, in _handle_dbapi_exception Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: sqlalchemy_exception, with_traceback=excinfo[2], from=e Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/util/compat.py", line 208, in raise_ Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: raise exception Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/engine/base.py", line 1901, in _execute_context Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: cursor, statement, parameters, context Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/engine/default.py", line 736, in do_execute Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: cursor.execute(statement, parameters) Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: File "/usr/local/lib/python3.7/dist-packages/MySQLdb/cursors.py", line 206, in execute Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: res = self._query(query) Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: File "/usr/local/lib/python3.7/dist-packages/MySQLdb/cursors.py", line 320, in _query Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: self._do_get_result(db) Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: File "/usr/local/lib/python3.7/dist-packages/MySQLdb/cursors.py", line 145, in _do_get_result Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: self._result = result = self._get_result() Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: File "/usr/local/lib/python3.7/dist-packages/MySQLdb/cursors.py", line 352, in _get_result Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: return self._get_db().store_result() Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: sqlalchemy.exc.OperationalError: (MySQLdb.OperationalError) (2006, '') Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: [SQL: SELECT permission.id AS permission_id, permission.created AS permission_created, permission.user_id AS permission_user_id, permission.name AS permission_name Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: FROM permission Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: WHERE permission.user_id = %s] Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: [parameters: (282,)] Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: (Background on this error at: https://sqlalche.me/e/14/e3q8) Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: [I 221018 18:39:33 web:2275] 200 GET /static/images/favicon.svg () 0.48ms Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: Exception in thread Thread-7: Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: Traceback (most recent call last): Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: File "/usr/lib/python3.7/threading.py", line 917, in _bootstrap_inner Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: self.run() Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: File "/usr/lib/python3.7/threading.py", line 865, in run Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: self._target(self._args, self._kwargs) Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: File "/opt/CTF/RootTheBox/libs/Scoreboard.py", line 69, in _update_gamestate Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: teams = Team.ranks(threadsession) Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: File "/opt/CTF/RootTheBox/models/Team.py", line 143, in ranks Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: if not team.locked: Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: File "/opt/CTF/RootTheBox/models/Team.py", line 205, in locked Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: if not user.locked: Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: File "/opt/CTF/RootTheBox/models/User.py", line 310, in locked Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: if self.is_admin(): Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: File "/opt/CTF/RootTheBox/models/User.py", line 381, in is_admin Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: return self.has_permission(ADMIN_PERMISSION) Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: File "/opt/CTF/RootTheBox/models/User.py", line 378, in has_permission Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: return True if permission in self.permissions_names else False Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: File "/opt/CTF/RootTheBox/models/User.py", line 302, in permissions_names Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: return [permission.name for permission in self.permissions_all] Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/orm/query.py", line 2900, in iter Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: return self._iter().iter() Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/orm/query.py", line 2910, in _iter Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: execution_options={"_sa_orm_load_options": self.load_options}, Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/orm/session.py", line 1712, in execute Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: result = conn._execute_20(statement, params or {}, execution_options) Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/engine/base.py", line 1705, in _execute_20 Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: return meth(self, args_10style, kwargs_10style, execution_options) Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/sql/elements.py", line 334, in _execute_on_connection Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: self, multiparams, params, execution_options Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/engine/base.py", line 1582, in _execute_clauseelement Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: cache_hit=cache_hit, Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/engine/base.py", line 1798, in _execute_context Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: conn = self._revalidate_connection() Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/engine/base.py", line 645, in _revalidate_connection Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: self._invalid_transaction() Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/engine/base.py", line 625, in _invalid_transaction Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: code="8s2b", Oct 18 18:39:33 ip-100-122-4-171 rootthebox.py[12897]: sqlalchemy.exc.PendingRollbackError: Can't reconnect until invalid transaction is rolled back. (Background on this error at: https://sqlalche.me/e/14/8s2b)

After the above occurs the user sessions are removed and the all of players needs to login again.

Pushed up another update... on 3.12.1_dev branch. Let me know if it helps fix the problem. It's a bit more hacky than I'd like, but it worked in my tests. Otherwise, we might just have to go back to the synchronous version. I tried creating entirely new database sessions, but it still seems to think it's on the same connection. idk.. this problem may be beyond my skillset.

Still getting the error :/, it is appearing when submitting/capturing flag/box.

This might be a new one: BufferError: Existing exports of data: object cannot be re-sized Oct 19 13:10:44 ip-100-122-4-171 rootthebox.py[14304]: [E 221019 13:10:44 BaseHandlers:94] Failed call to get_current_user()

We may need to find outside help if you know any good python devs. It's a small thing to fix, but I just don't know how to do it.

Next fix attempt pushed to 3.12.1_dev. Let me know. 🤞

Thanks for working on this, I was not able to reproduce the same error so far but I am getting different one on most of the pages now:

Oct 19 20:17:07 ip-100-122-4-171 rootthebox.py[14661]: [I 221019 20:17:07 web:2275] 101 GET /connect/notifications/updates (100.122.1.43) 0.41ms Oct 19 20:17:07 ip-100-122-4-171 rootthebox.py[14661]: [E 221019 20:17:07 ioloop:760] Exception in callback functools.partial(<bound method EventManager.push_user of <libs.EventManager.EventManager object at 0x7f9b0451c9e8>>, 3, 4) Oct 19 20:17:07 ip-100-122-4-171 rootthebox.py[14661]: Traceback (most recent call last): Oct 19 20:17:07 ip-100-122-4-171 rootthebox.py[14661]: File "/usr/local/lib/python3.7/dist-packages/tornado/ioloop.py", line 740, in _run_callback Oct 19 20:17:07 ip-100-122-4-171 rootthebox.py[14661]: ret = callback() Oct 19 20:17:07 ip-100-122-4-171 rootthebox.py[14661]: File "/opt/CTF/RootTheBox/libs/EventManager.py", line 132, in push_user Oct 19 20:17:07 ip-100-122-4-171 rootthebox.py[14661]: dbsession.commit() Oct 19 20:17:07 ip-100-122-4-171 rootthebox.py[14661]: File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/orm/session.py", line 1449, in commit Oct 19 20:17:07 ip-100-122-4-171 rootthebox.py[14661]: raise sa_exc.InvalidRequestError("No transaction is begun.") Oct 19 20:17:07 ip-100-122-4-171 rootthebox.py[14661]: sqlalchemy.exc.InvalidRequestError: No transaction is begun. Oct 19 20:17:16 ip-100-122-4-171 rootthebox.py[14661]: [I 221019 20:17:16 web:2275] 200 GET /user/missions/boxes?uuid=94534cee-d883-4d44-b75b-123b7d4fe50e (100.122.1.43) 183.32ms Oct 19 20:17:16 ip-100-122-4-171 rootthebox.py[14661]: [I 221019 20:17:16 web:2275] 304 GET /static/js/pages/missions/box.js (100.122.1.43) 0.54ms Oct 19 20:17:16 ip-100-122-4-171 rootthebox.py[14661]: [I 221019 20:17:16 web:2275] 200 GET /static/images/favicon.svg (100.122.1.43) 0.51ms Oct 19 20:17:16 ip-100-122-4-171 rootthebox.py[14661]: [I 221019 20:17:16 web:2275] 101 GET /connect/notifications/updates (100.122.1.43) 0.33ms Oct 19 20:17:16 ip-100-122-4-171 rootthebox.py[14661]: [E 221019 20:17:16 ioloop:760] Exception in callback functools.partial(<bound method EventManager.push_user of <libs.EventManager.EventManager object at 0x7f9b0451c9e8>>, 3, 4) Oct 19 20:17:16 ip-100-122-4-171 rootthebox.py[14661]: Traceback (most recent call last): Oct 19 20:17:16 ip-100-122-4-171 rootthebox.py[14661]: File "/usr/local/lib/python3.7/dist-packages/tornado/ioloop.py", line 740, in _run_callback Oct 19 20:17:16 ip-100-122-4-171 rootthebox.py[14661]: ret = callback() Oct 19 20:17:16 ip-100-122-4-171 rootthebox.py[14661]: File "/opt/CTF/RootTheBox/libs/EventManager.py", line 132, in push_user Oct 19 20:17:16 ip-100-122-4-171 rootthebox.py[14661]: dbsession.commit() Oct 19 20:17:16 ip-100-122-4-171 rootthebox.py[14661]: File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/orm/session.py", line 1449, in commit Oct 19 20:17:16 ip-100-122-4-171 rootthebox.py[14661]: raise sa_exc.InvalidRequestError("No transaction is begun.") Oct 19 20:17:16 ip-100-122-4-171 rootthebox.py[14661]: sqlalchemy.exc.InvalidRequestError: No transaction is begun. Oct 19 20:17:56 ip-100-122-4-171 rootthebox.py[14661]: [I 221019 20:17:56 MissionsHandler:427] 8848 (Mt.Everest) capture the flag 'L3B7F1' Oct 19 20:17:56 ip-100-122-4-171 rootthebox.py[14661]: [E 221019 20:17:56 web:1802] Uncaught exception POST /user/missions/boxes?uuid=94534cee-d883-4d44-b75b-123b7d4fe50e (100.122.1.43) Oct 19 20:17:56 ip-100-122-4-171 rootthebox.py[14661]: HTTPServerRequest(protocol='http', host='100.122.4.171', method='POST', uri='/user/missions/boxes?uuid=94534cee-d883-4d44-b75b-123b7d4fe50e', version='HTTP/1.1', remote_ip='100.122.1.43') Oct 19 20:17:56 ip-100-122-4-171 rootthebox.py[14661]: Traceback (most recent call last): Oct 19 20:17:56 ip-100-122-4-171 rootthebox.py[14661]: File "/usr/local/lib/python3.7/dist-packages/tornado/web.py", line 1711, in _execute Oct 19 20:17:56 ip-100-122-4-171 rootthebox.py[14661]: result = method(*self.path_args, self.path_kwargs) Oct 19 20:17:56 ip-100-122-4-171 rootthebox.py[14661]: File "/opt/CTF/RootTheBox/libs/SecurityDecorators.py", line 46, in wrapper Oct 19 20:17:56 ip-100-122-4-171 rootthebox.py[14661]: return method(self, *args, *kwargs) Oct 19 20:17:56 ip-100-122-4-171 rootthebox.py[14661]: File "/opt/CTF/RootTheBox/libs/SecurityDecorators.py", line 77, in wrapper Oct 19 20:17:56 ip-100-122-4-171 rootthebox.py[14661]: return method(self, args, kwargs) Oct 19 20:17:56 ip-100-122-4-171 rootthebox.py[14661]: File "/opt/CTF/RootTheBox/handlers/MissionsHandler.py", line 200, in post Oct 19 20:17:56 ip-100-122-4-171 rootthebox.py[14661]: if flag is not None and self.attempt_capture(flag, submission): Oct 19 20:17:56 ip-100-122-4-171 rootthebox.py[14661]: File "/opt/CTF/RootTheBox/handlers/MissionsHandler.py", line 449, in attempt_capture Oct 19 20:17:56 ip-100-122-4-171 rootthebox.py[14661]: self.event_manager.flag_captured(user, flag) Oct 19 20:17:56 ip-100-122-4-171 rootthebox.py[14661]: File "/opt/CTF/RootTheBox/libs/EventManager.py", line 217, in flag_captured Oct 19 20:17:56 ip-100-122-4-171 rootthebox.py[14661]: Notification.create_broadcast(team, "Flag Capture", message, SUCCESS) Oct 19 20:17:56 ip-100-122-4-171 rootthebox.py[14661]: File "/opt/CTF/RootTheBox/models/Notification.py", line 112, in create_broadcast Oct 19 20:17:56 ip-100-122-4-171 rootthebox.py[14661]: cls.create_team(team, title, message, icon) Oct 19 20:17:56 ip-100-122-4-171 rootthebox.py[14661]: File "/opt/CTF/RootTheBox/models/Notification.py", line 107, in create_team Oct 19 20:17:56 ip-100-122-4-171 rootthebox.py[14661]: dbsession.commit() Oct 19 20:17:56 ip-100-122-4-171 rootthebox.py[14661]: File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/orm/session.py", line 1449, in commit Oct 19 20:17:56 ip-100-122-4-171 rootthebox.py[14661]: raise sa_exc.InvalidRequestError("No transaction is begun.") Oct 19 20:17:56 ip-100-122-4-171 rootthebox.py[14661]: sqlalchemy.exc.InvalidRequestError: No transaction is begun. Oct 19 20:17:56 ip-100-122-4-171 rootthebox.py[14661]: [E 221019 20:17:56 BaseHandlers:198] Request from 100.122.1.43 resulted in an error code 500: Oct 19 20:17:56 ip-100-122-4-171 rootthebox.py[14661]: Traceback (most recent call last): Oct 19 20:17:56 ip-100-122-4-171 rootthebox.py[14661]: File "/usr/local/lib/python3.7/dist-packages/tornado/web.py", line 1711, in _execute Oct 19 20:17:56 ip-100-122-4-171 rootthebox.py[14661]: result = method(*self.path_args, self.path_kwargs) Oct 19 20:17:56 ip-100-122-4-171 rootthebox.py[14661]: File "/opt/CTF/RootTheBox/libs/SecurityDecorators.py", line 46, in wrapper Oct 19 20:17:56 ip-100-122-4-171 rootthebox.py[14661]: return method(self, *args, *kwargs) Oct 19 20:17:56 ip-100-122-4-171 rootthebox.py[14661]: File "/opt/CTF/RootTheBox/libs/SecurityDecorators.py", line 77, in wrapper Oct 19 20:17:56 ip-100-122-4-171 rootthebox.py[14661]: return method(self, args, kwargs) Oct 19 20:17:56 ip-100-122-4-171 rootthebox.py[14661]: File "/opt/CTF/RootTheBox/handlers/MissionsHandler.py", line 200, in post Oct 19 20:17:56 ip-100-122-4-171 rootthebox.py[14661]: if flag is not None and self.attempt_capture(flag, submission): Oct 19 20:17:56 ip-100-122-4-171 rootthebox.py[14661]: File "/opt/CTF/RootTheBox/handlers/MissionsHandler.py", line 449, in attempt_capture Oct 19 20:17:56 ip-100-122-4-171 rootthebox.py[14661]: self.event_manager.flag_captured(user, flag) Oct 19 20:17:56 ip-100-122-4-171 rootthebox.py[14661]: File "/opt/CTF/RootTheBox/libs/EventManager.py", line 217, in flag_captured Oct 19 20:17:56 ip-100-122-4-171 rootthebox.py[14661]: Notification.create_broadcast(team, "Flag Capture", message, SUCCESS) Oct 19 20:17:56 ip-100-122-4-171 rootthebox.py[14661]: File "/opt/CTF/RootTheBox/models/Notification.py", line 112, in create_broadcast Oct 19 20:17:56 ip-100-122-4-171 rootthebox.py[14661]: cls.create_team(team, title, message, icon) Oct 19 20:17:56 ip-100-122-4-171 rootthebox.py[14661]: File "/opt/CTF/RootTheBox/models/Notification.py", line 107, in create_team Oct 19 20:17:56 ip-100-122-4-171 rootthebox.py[14661]: dbsession.commit() Oct 19 20:17:56 ip-100-122-4-171 rootthebox.py[14661]: File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/orm/session.py", line 1449, in commit Oct 19 20:17:56 ip-100-122-4-171 rootthebox.py[14661]: raise sa_exc.InvalidRequestError("No transaction is begun.") Oct 19 20:17:56 ip-100-122-4-171 rootthebox.py[14661]: sqlalchemy.exc.InvalidRequestError: No transaction is begun. Oct 19 20:17:56 ip-100-122-4-171 rootthebox.py[14661]:
Oct 19 20:17:56 ip-100-122-4-171 rootthebox.py[14661]: [E 221019 20:17:56 web:2275] 500 POST /user/missions/boxes?uuid=94534cee-d883-4d44-b75b-123b7d4fe50e (100.122.1.43) 218.11ms Oct 19 20:17:56 ip-100-122-4-171 rootthebox.py[14661]: [I 221019 20:17:56 web:2275] 101 GET /connect/notifications/updates (100.122.1.43) 0.45ms Oct 19 20:17:56 ip-100-122-4-171 rootthebox.py[14661]: [E 221019 20:17:56 ioloop:760] Exception in callback functools.partial(<bound method EventManager.push_user of <libs.EventManager.EventManager object at 0x7f9b0451c9e8>>, 3, 4) Oct 19 20:17:56 ip-100-122-4-171 rootthebox.py[14661]: Traceback (most recent call last): Oct 19 20:17:56 ip-100-122-4-171 rootthebox.py[14661]: File "/usr/local/lib/python3.7/dist-packages/tornado/ioloop.py", line 740, in _run_callback Oct 19 20:17:56 ip-100-122-4-171 rootthebox.py[14661]: ret = callback() Oct 19 20:17:56 ip-100-122-4-171 rootthebox.py[14661]: File "/opt/CTF/RootTheBox/libs/EventManager.py", line 132, in push_user Oct 19 20:17:56 ip-100-122-4-171 rootthebox.py[14661]: dbsession.commit() Oct 19 20:17:56 ip-100-122-4-171 rootthebox.py[14661]: File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/orm/session.py", line 1449, in commit Oct 19 20:17:56 ip-100-122-4-171 rootthebox.py[14661]: raise sa_exc.InvalidRequestError("No transaction is begun.") Oct 19 20:17:56 ip-100-122-4-171 rootthebox.py[14661]: sqlalchemy.exc.InvalidRequestError: No transaction is begun. ^C

Ooo, yeah - abort. Seems like that prevents the updates from taking affect. Dang.. thought that would do it.

Pushed another try...

I think we are getting some progress. Much less errors now, it occurs only when I capture a flag and then go to the scoreboard, on the first click it will just refresh the home page and throw the error and on second click on the scoreboard it will work as expected and open the scoreboard without any errors in the log.

ct 20 08:39:25 ip-100-122-4-171 rootthebox.py[15724]: [E 221020 08:39:25 _base:326] exception calling callback for <Future at 0x7fd4fed3e128 state=finished raised ProgrammingError> Oct 20 08:39:25 ip-100-122-4-171 rootthebox.py[15724]: Traceback (most recent call last): Oct 20 08:39:25 ip-100-122-4-171 rootthebox.py[15724]: File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/engine/base.py", line 1901, in _execute_context Oct 20 08:39:25 ip-100-122-4-171 rootthebox.py[15724]: cursor, statement, parameters, context Oct 20 08:39:25 ip-100-122-4-171 rootthebox.py[15724]: File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/engine/default.py", line 736, in do_execute Oct 20 08:39:25 ip-100-122-4-171 rootthebox.py[15724]: cursor.execute(statement, parameters) Oct 20 08:39:25 ip-100-122-4-171 rootthebox.py[15724]: File "/usr/local/lib/python3.7/dist-packages/MySQLdb/cursors.py", line 183, in execute Oct 20 08:39:25 ip-100-122-4-171 rootthebox.py[15724]: while self.nextset(): Oct 20 08:39:25 ip-100-122-4-171 rootthebox.py[15724]: File "/usr/local/lib/python3.7/dist-packages/MySQLdb/cursors.py", line 137, in nextset Oct 20 08:39:25 ip-100-122-4-171 rootthebox.py[15724]: nr = db.next_result() Oct 20 08:39:25 ip-100-122-4-171 rootthebox.py[15724]: MySQLdb.ProgrammingError: (2014, "Commands out of sync; you can't run this command now") Oct 20 08:39:25 ip-100-122-4-171 rootthebox.py[15724]:
Oct 20 08:39:25 ip-100-122-4-171 rootthebox.py[15724]: The above exception was the direct cause of the following exception: Oct 20 08:39:25 ip-100-122-4-171 rootthebox.py[15724]:
Oct 20 08:39:25 ip-100-122-4-171 rootthebox.py[15724]: Traceback (most recent call last): Oct 20 08:39:25 ip-100-122-4-171 rootthebox.py[15724]: File "/usr/lib/python3.7/concurrent/futures/thread.py", line 57, in run Oct 20 08:39:25 ip-100-122-4-171 rootthebox.py[15724]: result = self.fn(*self.args, **self.kwargs) Oct 20 08:39:25 ip-100-122-4-171 rootthebox.py[15724]: File "/opt/CTF/RootTheBox/libs/Scoreboard.py", line 75, in _update_gamestate Oct 20 08:39:25 ip-100-122-4-171 rootthebox.py[15724]: teams = Team.ranks(threadsession) Oct 20 08:39:25 ip-100-122-4-171 rootthebox.py[15724]: File "/opt/CTF/RootTheBox/models/Team.py", line 143, in ranks Oct 20 08:39:25 ip-100-122-4-171 rootthebox.py[15724]: if not team.locked: Oct 20 08:39:25 ip-100-122-4-171 rootthebox.py[15724]: File "/opt/CTF/RootTheBox/models/Team.py", line 205, in locked Oct 20 08:39:25 ip-100-122-4-171 rootthebox.py[15724]: if not user.locked: Oct 20 08:39:25 ip-100-122-4-171 rootthebox.py[15724]: File "/opt/CTF/RootTheBox/models/User.py", line 312, in locked Oct 20 08:39:25 ip-100-122-4-171 rootthebox.py[15724]: if self.is_admin(): Oct 20 08:39:25 ip-100-122-4-171 rootthebox.py[15724]: File "/opt/CTF/RootTheBox/models/User.py", line 383, in is_admin Oct 20 08:39:25 ip-100-122-4-171 rootthebox.py[15724]: return self.has_permission(ADMIN_PERMISSION) Oct 20 08:39:25 ip-100-122-4-171 rootthebox.py[15724]: File "/opt/CTF/RootTheBox/models/User.py", line 380, in has_permission Oct 20 08:39:25 ip-100-122-4-171 rootthebox.py[15724]: return True if permission in self.permissions_names else False Oct 20 08:39:25 ip-100-122-4-171 rootthebox.py[15724]: File "/opt/CTF/RootTheBox/models/User.py", line 304, in permissions_names Oct 20 08:39:25 ip-100-122-4-171 rootthebox.py[15724]: return [permission.name for permission in self.permissions_all] Oct 20 08:39:25 ip-100-122-4-171 rootthebox.py[15724]: File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/orm/query.py", line 2900, in iter Oct 20 08:39:25 ip-100-122-4-171 rootthebox.py[15724]: return self._iter().iter() Oct 20 08:39:25 ip-100-122-4-171 rootthebox.py[15724]: File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/orm/query.py", line 2910, in _iter Oct 20 08:39:25 ip-100-122-4-171 rootthebox.py[15724]: execution_options={"_sa_orm_load_options": self.load_options}, Oct 20 08:39:25 ip-100-122-4-171 rootthebox.py[15724]: File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/orm/session.py", line 1712, in execute Oct 20 08:39:25 ip-100-122-4-171 rootthebox.py[15724]: result = conn._execute_20(statement, params or {}, execution_options) Oct 20 08:39:25 ip-100-122-4-171 rootthebox.py[15724]: File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/engine/base.py", line 1705, in _execute_20 Oct 20 08:39:25 ip-100-122-4-171 rootthebox.py[15724]: return meth(self, args_10style, kwargs_10style, execution_options) Oct 20 08:39:25 ip-100-122-4-171 rootthebox.py[15724]: File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/sql/elements.py", line 334, in _execute_on_connection Oct 20 08:39:25 ip-100-122-4-171 rootthebox.py[15724]: self, multiparams, params, execution_options Oct 20 08:39:25 ip-100-122-4-171 rootthebox.py[15724]: File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/engine/base.py", line 1582, in _execute_clauseelement Oct 20 08:39:25 ip-100-122-4-171 rootthebox.py[15724]: cache_hit=cache_hit, Oct 20 08:39:25 ip-100-122-4-171 rootthebox.py[15724]: File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/engine/base.py", line 1944, in _execute_context Oct 20 08:39:25 ip-100-122-4-171 rootthebox.py[15724]: e, statement, parameters, cursor, context Oct 20 08:39:25 ip-100-122-4-171 rootthebox.py[15724]: File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/engine/base.py", line 2125, in _handle_dbapi_exception Oct 20 08:39:25 ip-100-122-4-171 rootthebox.py[15724]: sqlalchemy_exception, with_traceback=excinfo[2], from=e Oct 20 08:39:25 ip-100-122-4-171 rootthebox.py[15724]: File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/util/compat.py", line 208, in raise_ Oct 20 08:39:25 ip-100-122-4-171 rootthebox.py[15724]: raise exception Oct 20 08:39:25 ip-100-122-4-171 rootthebox.py[15724]: File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/engine/base.py", line 1901, in _execute_context Oct 20 08:39:25 ip-100-122-4-171 rootthebox.py[15724]: cursor, statement, parameters, context Oct 20 08:39:25 ip-100-122-4-171 rootthebox.py[15724]: File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/engine/default.py", line 736, in do_execute Oct 20 08:39:25 ip-100-122-4-171 rootthebox.py[15724]: cursor.execute(statement, parameters) Oct 20 08:39:25 ip-100-122-4-171 rootthebox.py[15724]: File "/usr/local/lib/python3.7/dist-packages/MySQLdb/cursors.py", line 183, in execute Oct 20 08:39:25 ip-100-122-4-171 rootthebox.py[15724]: while self.nextset(): Oct 20 08:39:25 ip-100-122-4-171 rootthebox.py[15724]: File "/usr/local/lib/python3.7/dist-packages/MySQLdb/cursors.py", line 137, in nextset Oct 20 08:39:25 ip-100-122-4-171 rootthebox.py[15724]: nr = db.next_result() Oct 20 08:39:25 ip-100-122-4-171 rootthebox.py[15724]: sqlalchemy.exc.ProgrammingError: (MySQLdb.ProgrammingError) (2014, "Commands out of sync; you can't run this command now") Oct 20 08:39:25 ip-100-122-4-171 rootthebox.py[15724]: [SQL: SELECT permission.id AS permission_id, permission.created AS permission_created, permission.user_id AS permission_user_id, permission.name AS permission_name Oct 20 08:39:25 ip-100-122-4-171 rootthebox.py[15724]: FROM permission Oct 20 08:39:25 ip-100-122-4-171 rootthebox.py[15724]: WHERE permission.user_id = %s] Oct 20 08:39:25 ip-100-122-4-171 rootthebox.py[15724]: [parameters: (492,)] Oct 20 08:39:25 ip-100-122-4-171 rootthebox.py[15724]: (Background on this error at: https://sqlalche.me/e/14/f405) Oct 20 08:39:25 ip-100-122-4-171 rootthebox.py[15724]:
Oct 20 08:39:25 ip-100-122-4-171 rootthebox.py[15724]: During handling of the above exception, another exception occurred: Oct 20 08:39:25 ip-100-122-4-171 rootthebox.py[15724]:
Oct 20 08:39:25 ip-100-122-4-171 rootthebox.py[15724]: Traceback (most recent call last): Oct 20 08:39:25 ip-100-122-4-171 rootthebox.py[15724]: File "/usr/lib/python3.7/concurrent/futures/_base.py", line 324, in _invoke_callbacks Oct 20 08:39:25 ip-100-122-4-171 rootthebox.py[15724]: callback(self) Oct 20 08:39:25 ip-100-122-4-171 rootthebox.py[15724]: File "/opt/CTF/RootTheBox/libs/EventManager.py", line 146, in _push_scoreboard Oct 20 08:39:25 ip-100-122-4-171 rootthebox.py[15724]: self.safe_write_message(connection, msg) Oct 20 08:39:25 ip-100-122-4-171 rootthebox.py[15724]: File "/opt/CTF/RootTheBox/libs/EventManager.py", line 154, in safe_write_message Oct 20 08:39:25 ip-100-122-4-171 rootthebox.py[15724]: connection.write_message(msg) Oct 20 08:39:25 ip-100-122-4-171 rootthebox.py[15724]: File "/usr/local/lib/python3.7/dist-packages/tornado/websocket.py", line 339, in write_message Oct 20 08:39:25 ip-100-122-4-171 rootthebox.py[15724]: return self.ws_connection.write_message(message, binary=binary) Oct 20 08:39:25 ip-100-122-4-171 rootthebox.py[15724]: File "/usr/local/lib/python3.7/dist-packages/tornado/websocket.py", line 1086, in write_message Oct 20 08:39:25 ip-100-122-4-171 rootthebox.py[15724]: fut = self._write_frame(True, opcode, message, flags=flags) Oct 20 08:39:25 ip-100-122-4-171 rootthebox.py[15724]: File "/usr/local/lib/python3.7/dist-packages/tornado/websocket.py", line 1061, in _write_frame Oct 20 08:39:25 ip-100-122-4-171 rootthebox.py[15724]: return self.stream.write(frame) Oct 20 08:39:25 ip-100-122-4-171 rootthebox.py[15724]: File "/usr/local/lib/python3.7/dist-packages/tornado/iostream.py", line 540, in write Oct 20 08:39:25 ip-100-122-4-171 rootthebox.py[15724]: self._write_buffer.append(data) Oct 20 08:39:25 ip-100-122-4-171 rootthebox.py[15724]: File "/usr/local/lib/python3.7/dist-packages/tornado/iostream.py", line 157, in append Oct 20 08:39:25 ip-100-122-4-171 rootthebox.py[15724]: b += data # type: ignore Oct 20 08:39:25 ip-100-122-4-171 rootthebox.py[15724]: BufferError: Existing exports of data: object cannot be re-sized Oct 20 08:39:43 ip-100-122-4-171 rootthebox.py[15724]: [E 221020 08:39:43 BaseHandlers:94] Failed call to get_current_user() Oct 20 08:39:43 ip-100-122-4-171 rootthebox.py[15724]: Traceback (most recent call last): Oct 20 08:39:43 ip-100-122-4-171 rootthebox.py[15724]: File "/opt/CTF/RootTheBox/handlers/BaseHandlers.py", line 90, in get_current_user Oct 20 08:39:43 ip-100-122-4-171 rootthebox.py[15724]: return User.by_uuid(self.session["user_uuid"]) Oct 20 08:39:43 ip-100-122-4-171 rootthebox.py[15724]: File "/opt/CTF/RootTheBox/models/User.py", line 136, in by_uuid Oct 20 08:39:43 ip-100-122-4-171 rootthebox.py[15724]: return dbsession.query(cls).filter_by(uuid=str(_uuid)).first() Oct 20 08:39:43 ip-100-122-4-171 rootthebox.py[15724]: File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/orm/query.py", line 2823, in first Oct 20 08:39:43 ip-100-122-4-171 rootthebox.py[15724]: return self.limit(1)._iter().first() Oct 20 08:39:43 ip-100-122-4-171 rootthebox.py[15724]: File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/orm/query.py", line 2910, in _iter Oct 20 08:39:43 ip-100-122-4-171 rootthebox.py[15724]: execution_options={"_sa_orm_load_options": self.load_options}, Oct 20 08:39:43 ip-100-122-4-171 rootthebox.py[15724]: File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/orm/session.py", line 1712, in execute Oct 20 08:39:43 ip-100-122-4-171 rootthebox.py[15724]: result = conn._execute_20(statement, params or {}, execution_options) Oct 20 08:39:43 ip-100-122-4-171 rootthebox.py[15724]: File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/engine/base.py", line 1705, in _execute_20 Oct 20 08:39:43 ip-100-122-4-171 rootthebox.py[15724]: return meth(self, args_10style, kwargs_10style, execution_options) Oct 20 08:39:43 ip-100-122-4-171 rootthebox.py[15724]: File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/sql/elements.py", line 334, in _execute_on_connection Oct 20 08:39:43 ip-100-122-4-171 rootthebox.py[15724]: self, multiparams, params, execution_options Oct 20 08:39:43 ip-100-122-4-171 rootthebox.py[15724]: File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/engine/base.py", line 1582, in _execute_clauseelement Oct 20 08:39:43 ip-100-122-4-171 rootthebox.py[15724]: cache_hit=cache_hit, Oct 20 08:39:43 ip-100-122-4-171 rootthebox.py[15724]: File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/engine/base.py", line 1798, in _execute_context Oct 20 08:39:43 ip-100-122-4-171 rootthebox.py[15724]: conn = self._revalidate_connection() Oct 20 08:39:43 ip-100-122-4-171 rootthebox.py[15724]: File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/engine/base.py", line 645, in _revalidate_connection Oct 20 08:39:43 ip-100-122-4-171 rootthebox.py[15724]: self._invalid_transaction() Oct 20 08:39:43 ip-100-122-4-171 rootthebox.py[15724]: File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/engine/base.py", line 625, in _invalid_transaction Oct 20 08:39:43 ip-100-122-4-171 rootthebox.py[15724]: code="8s2b", Oct 20 08:39:43 ip-100-122-4-171 rootthebox.py[15724]: sqlalchemy.exc.PendingRollbackError: Can't reconnect until invalid transaction is rolled back. (Background on this error at: https://sqlalche.me/e/14/8s2b)

Append header in PublicHandlers.py. Function name def create_validate_message add this code on line number 669 -> header.append(\r\n)

Append header in PublicHandlers.py. Function name def create_validate_message add this code on line number 669 -> header.append(\r\n)

That change should have already been included if you're referencing the same one from our chat.

I pushed out 3.12.1, which rolls back the threading of update_gamestate. This will have a performance impact, but until it's stable, threading will be delayed. It should fix these database issues. There should still be some performance gain on scoreboard refreshes if you use the scoreboard_lazy_update=True, but the threading was a good piece of the performance improvements. Please give it a test - thanks.

We use the lazy update, the performance is good, until the error from bellow appears, then it will freeze the platform for 20-30 seconds for all players and after that will continue normally. Is this a new bug in the latest version? I don't remember if it was present before.

Oct 20 20:28:49 ip-100-122-4-171 rootthebox.py[1216]: future: <Task finished coro=<WebSocketProtocol13.write_message..wrapper() done, defined at /usr/local/lib/python3.7/dist-packages/tornado/websocket.py:1090> exception=WebSocketClosedError()> Oct 20 20:28:49 ip-100-122-4-171 rootthebox.py[1216]: Traceback (most recent call last): Oct 20 20:28:49 ip-100-122-4-171 rootthebox.py[1216]: File "/usr/local/lib/python3.7/dist-packages/tornado/websocket.py", line 1092, in wrapper Oct 20 20:28:49 ip-100-122-4-171 rootthebox.py[1216]: await fut Oct 20 20:28:49 ip-100-122-4-171 rootthebox.py[1216]: tornado.iostream.StreamClosedError: Stream is closed Oct 20 20:28:49 ip-100-122-4-171 rootthebox.py[1216]:
Oct 20 20:28:49 ip-100-122-4-171 rootthebox.py[1216]: During handling of the above exception, another exception occurred: Oct 20 20:28:49 ip-100-122-4-171 rootthebox.py[1216]:
Oct 20 20:28:49 ip-100-122-4-171 rootthebox.py[1216]: Traceback (most recent call last): Oct 20 20:28:49 ip-100-122-4-171 rootthebox.py[1216]: File "/usr/local/lib/python3.7/dist-packages/tornado/websocket.py", line 1094, in wrapper Oct 20 20:28:49 ip-100-122-4-171 rootthebox.py[1216]: raise WebSocketClosedError() Oct 20 20:28:49 ip-100-122-4-171 rootthebox.py[1216]: tornado.websocket.WebSocketClosedError Oct 20 20:28:49 ip-100-122-4-171 rootthebox.py[1216]: [E 221020 20:28:49 ioloop:760] Exception in callback functools.partial(<bound method EventManager.remove_connection of <libs.EventManager.EventManager object at 0x7efd55ac71d0>>, <handlers.NotificationHandlers.NotifySocketHandler object at 0x7efd55699358>) Oct 20 20:28:49 ip-100-122-4-171 rootthebox.py[1216]: Traceback (most recent call last): Oct 20 20:28:49 ip-100-122-4-171 rootthebox.py[1216]: File "/usr/local/lib/python3.7/dist-packages/tornado/ioloop.py", line 740, in _run_callback Oct 20 20:28:49 ip-100-122-4-171 rootthebox.py[1216]: ret = callback() Oct 20 20:28:49 ip-100-122-4-171 rootthebox.py[1216]: File "/opt/CTF/RootTheBox/libs/EventManager.py", line 72, in remove_connection Oct 20 20:28:49 ip-100-122-4-171 rootthebox.py[1216]: team_connections[connection.user_id].remove(connection) Oct 20 20:28:49 ip-100-122-4-171 rootthebox.py[1216]: KeyError: <handlers.NotificationHandlers.NotifySocketHandler object at 0x7efd55699358> Oct 20 20:28:49 ip-100-122-4-171 rootthebox.py[1216]: [E 221020 20:28:49 ioloop:760] Exception in callback functools.partial(<bound method EventManager.remove_connection of <libs.EventManager.EventManager object at 0x7efd55ac71d0>>, <handlers.NotificationHandlers.NotifySocketHandler object at 0x7efd55699358>) Oct 20 20:28:49 ip-100-122-4-171 rootthebox.py[1216]: Traceback (most recent call last): Oct 20 20:28:49 ip-100-122-4-171 rootthebox.py[1216]: File "/usr/local/lib/python3.7/dist-packages/tornado/ioloop.py", line 740, in _run_callback Oct 20 20:28:49 ip-100-122-4-171 rootthebox.py[1216]: ret = callback() Oct 20 20:28:49 ip-100-122-4-171 rootthebox.py[1216]: File "/opt/CTF/RootTheBox/libs/EventManager.py", line 72, in remove_connection Oct 20 20:28:49 ip-100-122-4-171 rootthebox.py[1216]: team_connections[connection.user_id].remove(connection) Oct 20 20:28:49 ip-100-122-4-171 rootthebox.py[1216]: KeyError: <handlers.NotificationHandlers.NotifySocketHandler object at 0x7efd55699358> Oct 20 20:28:49 ip-100-122-4-171 rootthebox.py[1216]: [E 221020 20:28:49 ioloop:760] Exception in callback functools.partial(<bound method EventManager.remove_connection of <libs.EventManager.EventManager object at 0x7efd55ac71d0>>, <handlers.NotificationHandlers.NotifySocketHandler object at 0x7efd55699358>) Oct 20 20:28:49 ip-100-122-4-171 rootthebox.py[1216]: Traceback (most recent call last): Oct 20 20:28:49 ip-100-122-4-171 rootthebox.py[1216]: File "/usr/local/lib/python3.7/dist-packages/tornado/ioloop.py", line 740, in _run_callback Oct 20 20:28:49 ip-100-122-4-171 rootthebox.py[1216]: ret = callback() Oct 20 20:28:49 ip-100-122-4-171 rootthebox.py[1216]: File "/opt/CTF/RootTheBox/libs/EventManager.py", line 72, in remove_connection Oct 20 20:28:49 ip-100-122-4-171 rootthebox.py[1216]: team_connections[connection.user_id].remove(connection) Oct 20 20:28:49 ip-100-122-4-171 rootthebox.py[1216]: KeyError: <handlers.NotificationHandlers.NotifySocketHandler object at 0x7efd55699358>

Append header in PublicHandlers.py. Function name def create_validate_message add this code on line number 669 -> header.append(\r\n)

That change should have already been included if you're referencing the same one from our chat.

With reference to our chat, we have updated forget password email and added same header in that. This is related to registration, while confirmaing email address.

I am not getting above errors. But when I submit a flag, it is not updating on scoreboard. It updates after restart the game.

The latest version of 3.12.1_dev moves the processing to the process of the EventManager as I was running into some instances where the scoreboard wasn't updated after a score change. This was the reason the gamestate update was part of the scoreboard refresh, to make sure it was being run every time. The EventManager allows us to run the gamestate and then do a callback to then make the websocket notification. The issue is that the EventManager is part of the submission process. What I probably need to do is make the EventManager async.

moloch-- / RootTheBox

3.12.0 Issue with SQL #522