search

pallets-eco / flask-session

Server side session extension for Flask
https://flask-session.readthedocs.io
BSD 3-Clause "New" or "Revised" License
501 stars 239 forks source link

Duplicate session ID in SQLAlchemy driver in ClosingIterator #69

Closed revmischa closed 7 months ago

revmischa commented 7 years ago

We have some extra logging code that makes use of the session in a ClosingIterator:

    def setup_logging_middleware(self):
        """Add local variables we will use per request.

        Right now we hang logging off of it.
        """
        from werkzeug.wsgi import ClosingIterator
        from werkzeug.local import release_local

        def my_release_locals():
            release_local(log_threadLocal)

        def my_make_middleware(app):
            """Wrap a WSGI application so that cleaning up happens after request end."""
            def application(environ, start_response):
                return ClosingIterator(app(environ, start_response), my_release_locals)

            return application
        self.wsgi_app = my_make_middleware(self.wsgi_app)

Every once in a great while we see the following error pop up:

2017-04-27T11:33:37.187730+00:00 app[web.1]: Traceback (most recent call last):
2017-04-27T11:33:37.187732+00:00 app[web.1]:   File "/app/.heroku/python/lib/python3.6/site-packages/sqlalchemy/engine/base.py", line 1182, in _execute_context
2017-04-27T11:33:37.187733+00:00 app[web.1]:     context)
2017-04-27T11:33:37.187734+00:00 app[web.1]:   File "/app/.heroku/python/lib/python3.6/site-packages/sqlalchemy/engine/default.py", line 470, in do_execute
2017-04-27T11:33:37.187735+00:00 app[web.1]:     cursor.execute(statement, parameters)
2017-04-27T11:33:37.187735+00:00 app[web.1]: psycopg2.IntegrityError: duplicate key value violates unique constraint "flask_session_session_id_key"
2017-04-27T11:33:37.187739+00:00 app[web.1]: DETAIL:  Key (session_id)=(session:redacted-8e4b-481a-8788-redacted) already exists.
2017-04-27T11:33:37.187740+00:00 app[web.1]: 
2017-04-27T11:33:37.187740+00:00 app[web.1]: 
2017-04-27T11:33:37.187741+00:00 app[web.1]: The above exception was the direct cause of the following exception:
2017-04-27T11:33:37.187742+00:00 app[web.1]: 
2017-04-27T11:33:37.187742+00:00 app[web.1]: Traceback (most recent call last):
2017-04-27T11:33:37.187743+00:00 app[web.1]:   File "/app/.heroku/python/lib/python3.6/site-packages/flask/app.py", line 1982, in wsgi_app
2017-04-27T11:33:37.187743+00:00 app[web.1]:     response = self.full_dispatch_request()
2017-04-27T11:33:37.187744+00:00 app[web.1]:   File "/app/.heroku/python/lib/python3.6/site-packages/flask/app.py", line 1615, in full_dispatch_request
2017-04-27T11:33:37.187745+00:00 app[web.1]:     return self.finalize_request(rv)
2017-04-27T11:33:37.187745+00:00 app[web.1]:   File "/app/.heroku/python/lib/python3.6/site-packages/flask/app.py", line 1632, in finalize_request
2017-04-27T11:33:37.187746+00:00 app[web.1]:     response = self.process_response(response)
2017-04-27T11:33:37.187747+00:00 app[web.1]:   File "/app/.heroku/python/lib/python3.6/site-packages/flask/app.py", line 1858, in process_response
2017-04-27T11:33:37.187748+00:00 app[web.1]:     self.save_session(ctx.session, response)
2017-04-27T11:33:37.187749+00:00 app[web.1]:   File "/app/.heroku/python/lib/python3.6/site-packages/flask/app.py", line 924, in save_session
2017-04-27T11:33:37.187749+00:00 app[web.1]:     return self.session_interface.save_session(self, session, response)
2017-04-27T11:33:37.187750+00:00 app[web.1]:   File "/app/.heroku/python/lib/python3.6/site-packages/flask_session/sessions.py", line 556, in save_session
2017-04-27T11:33:37.187751+00:00 app[web.1]:     self.db.session.commit()
2017-04-27T11:33:37.187752+00:00 app[web.1]:   File "/app/.heroku/python/lib/python3.6/site-packages/sqlalchemy/orm/scoping.py", line 157, in do
2017-04-27T11:33:37.187752+00:00 app[web.1]:     return getattr(self.registry(), name)(*args, **kwargs)
2017-04-27T11:33:37.187753+00:00 app[web.1]:   File "/app/.heroku/python/lib/python3.6/site-packages/sqlalchemy/orm/session.py", line 874, in commit
2017-04-27T11:33:37.187754+00:00 app[web.1]:     self.transaction.commit()
2017-04-27T11:33:37.187755+00:00 app[web.1]:   File "/app/.heroku/python/lib/python3.6/site-packages/sqlalchemy/orm/session.py", line 461, in commit
2017-04-27T11:33:37.187755+00:00 app[web.1]:     self._prepare_impl()
2017-04-27T11:33:37.187756+00:00 app[web.1]:   File "/app/.heroku/python/lib/python3.6/site-packages/sqlalchemy/orm/session.py", line 441, in _prepare_impl
2017-04-27T11:33:37.187757+00:00 app[web.1]:     self.session.flush()
2017-04-27T11:33:37.187757+00:00 app[web.1]:   File "/app/.heroku/python/lib/python3.6/site-packages/sqlalchemy/orm/session.py", line 2139, in flush
2017-04-27T11:33:37.187758+00:00 app[web.1]:     self._flush(objects)
2017-04-27T11:33:37.187758+00:00 app[web.1]:   File "/app/.heroku/python/lib/python3.6/site-packages/sqlalchemy/orm/session.py", line 2259, in _flush
2017-04-27T11:33:37.187759+00:00 app[web.1]:     transaction.rollback(_capture_exception=True)
2017-04-27T11:33:37.187760+00:00 app[web.1]:   File "/app/.heroku/python/lib/python3.6/site-packages/sqlalchemy/util/langhelpers.py", line 66, in __exit__
2017-04-27T11:33:37.187760+00:00 app[web.1]:     compat.reraise(exc_type, exc_value, exc_tb)
2017-04-27T11:33:37.187761+00:00 app[web.1]:   File "/app/.heroku/python/lib/python3.6/site-packages/sqlalchemy/util/compat.py", line 187, in reraise
2017-04-27T11:33:37.187761+00:00 app[web.1]:     raise value
2017-04-27T11:33:37.187762+00:00 app[web.1]:   File "/app/.heroku/python/lib/python3.6/site-packages/sqlalchemy/orm/session.py", line 2223, in _flush
2017-04-27T11:33:37.187763+00:00 app[web.1]:     flush_context.execute()
2017-04-27T11:33:37.187763+00:00 app[web.1]:   File "/app/.heroku/python/lib/python3.6/site-packages/sqlalchemy/orm/unitofwork.py", line 389, in execute
2017-04-27T11:33:37.187764+00:00 app[web.1]:     rec.execute(self)
2017-04-27T11:33:37.187765+00:00 app[web.1]:   File "/app/.heroku/python/lib/python3.6/site-packages/sqlalchemy/orm/unitofwork.py", line 548, in execute
2017-04-27T11:33:37.187765+00:00 app[web.1]:     uow
2017-04-27T11:33:37.187766+00:00 app[web.1]:   File "/app/.heroku/python/lib/python3.6/site-packages/sqlalchemy/orm/persistence.py", line 181, in save_obj
2017-04-27T11:33:37.187767+00:00 app[web.1]:     mapper, table, insert)
2017-04-27T11:33:37.187767+00:00 app[web.1]:   File "/app/.heroku/python/lib/python3.6/site-packages/sqlalchemy/orm/persistence.py", line 835, in _emit_insert_statements
2017-04-27T11:33:37.187768+00:00 app[web.1]:     execute(statement, params)
2017-04-27T11:33:37.187769+00:00 app[web.1]:   File "/app/.heroku/python/lib/python3.6/site-packages/sqlalchemy/engine/base.py", line 945, in execute
2017-04-27T11:33:37.187769+00:00 app[web.1]:     return meth(self, multiparams, params)
2017-04-27T11:33:37.187770+00:00 app[web.1]:   File "/app/.heroku/python/lib/python3.6/site-packages/sqlalchemy/sql/elements.py", line 263, in _execute_on_connection
2017-04-27T11:33:37.187770+00:00 app[web.1]:     return connection._execute_clauseelement(self, multiparams, params)
2017-04-27T11:33:37.187771+00:00 app[web.1]:   File "/app/.heroku/python/lib/python3.6/site-packages/sqlalchemy/engine/base.py", line 1053, in _execute_clauseelement
2017-04-27T11:33:37.187772+00:00 app[web.1]:     compiled_sql, distilled_params
2017-04-27T11:33:37.187772+00:00 app[web.1]:   File "/app/.heroku/python/lib/python3.6/site-packages/sqlalchemy/engine/base.py", line 1189, in _execute_context
2017-04-27T11:33:37.187773+00:00 app[web.1]:     context)
2017-04-27T11:33:37.187778+00:00 app[web.1]:   File "/app/.heroku/python/lib/python3.6/site-packages/sqlalchemy/engine/base.py", line 1402, in _handle_dbapi_exception
2017-04-27T11:33:37.187779+00:00 app[web.1]:     exc_info
2017-04-27T11:33:37.187780+00:00 app[web.1]:   File "/app/.heroku/python/lib/python3.6/site-packages/sqlalchemy/util/compat.py", line 203, in raise_from_cause
2017-04-27T11:33:37.187780+00:00 app[web.1]:     reraise(type(exception), exception, tb=exc_tb, cause=cause)
2017-04-27T11:33:37.187781+00:00 app[web.1]:   File "/app/.heroku/python/lib/python3.6/site-packages/sqlalchemy/util/compat.py", line 186, in reraise
2017-04-27T11:33:37.187781+00:00 app[web.1]:     raise value.with_traceback(tb)
2017-04-27T11:33:37.187782+00:00 app[web.1]:   File "/app/.heroku/python/lib/python3.6/site-packages/sqlalchemy/engine/base.py", line 1182, in _execute_context
2017-04-27T11:33:37.187783+00:00 app[web.1]:     context)
2017-04-27T11:33:37.187784+00:00 app[web.1]:   File "/app/.heroku/python/lib/python3.6/site-packages/sqlalchemy/engine/default.py", line 470, in do_execute
2017-04-27T11:33:37.187784+00:00 app[web.1]:     cursor.execute(statement, parameters)
2017-04-27T11:33:37.187786+00:00 app[web.1]: sqlalchemy.exc.IntegrityError: (psycopg2.IntegrityError) duplicate key value violates unique constraint "flask_session_session_id_key"
2017-04-27T11:33:37.187787+00:00 app[web.1]: DETAIL:  Key (session_id)=(session:redacted-8e4b-481a-8788-redacted) already exists.
2017-04-27T11:33:37.187789+00:00 app[web.1]:  [SQL: 'INSERT INTO flask_session (session_id, data, expiry) VALUES (%(session_id)s, %(data)s, %(expiry)s) RETURNING flask_session.id'] [parameters: {'session_id': 'session:redacted-8e4b-481a-8788-redacted', 'data': <psycopg2.extensions.Binary object at 0x7fb166e10120>, 'expiry': datetime.datetime(2017, 5, 28, 11, 33, 37, 174935)}]
Lxstr commented 7 months ago

Significant changes since this version of Flask-Session. Closing due to age. Reopen if it reoccurs.