Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

@app.teardown_request function doesn't called in debug mode [NOT-A-BUG] #661

Closed
seriyps opened this issue Jan 5, 2013 · 7 comments
Closed

Comments

@seriyps
Copy link

seriyps commented Jan 5, 2013

UPD: not a bug, see #661 (comment)

from flask import Flask

app = Flask('teardown')

@app.teardown_request
def shutdown_session(err):
    print repr(err)

@app.route('/')
def index():
    raise ValueError('test exc')

if __name__ == '__main__':
    app.run()

So, when I open index page and see 500 error page, console output is ValueError('test exc'). But when I start app in debug mode, eg

if __name__ == '__main__':
    app.run(debug=True)

Output is None, when expected ValueError('test exc').

This is important for me, because I use teardown_request for sqlalchemy transaction management like

@app.teardown_request
def shutdown_session(exception):
    if exception:
        db.session.rollback()
    else:
        db.session.commit()
@mgax
Copy link
Contributor

mgax commented Jan 6, 2013

What Flask version are you using? I just ran your example, and with debug=True, it printed a traceback to the console, and did not enter shutdown_session at all. If you open the page in a browser expect multiple requests to the app (the favicon plus several calls by the werkzeug debugger), maybe that's where you see err==None.

@mgax
Copy link
Contributor

mgax commented Jan 6, 2013

There's a pull request for flask-sqlalchemy that implements commit on app teardown, would you consider testing and helping improve it?

@seriyps
Copy link
Author

seriyps commented Jan 6, 2013

Thanks for review!
I use Flask 0.9
Sorry, my case code was broken, I didn't check enough before reporting. This is correct code:

from flask import Flask  # , Blueprint

app = Flask('teardown')

# user = Blueprint('user', __name__)
# @user.route('/')
@app.route('/')
def index():
    # do some DB work
    raise ValueError('test exc')

# app.register_blueprint(user, url_prefix='/user')

@app.teardown_request
def shutdown_session(err):
    from flask import request
    print 'shutdown_session:', repr(err), request.base_url, request.method

if __name__ == '__main__':
    app.run(debug=True)

(FYI: if you uncomment commented lines and comment "@app.route('/')" /How I actually do in my app/ issue reproduced too)
This will output

127.0.0.1 - - [06/Jan/2013 16:41:16] "GET / HTTP/1.1" 500 -
Traceback (most recent call last):
  File "/home/seriy/workspace/wannatop/env/lib/python2.7/site-packages/flask/app.py", line 1701, in __call__
    return self.wsgi_app(environ, start_response)
  File "/home/seriy/workspace/wannatop/env/lib/python2.7/site-packages/flask/app.py", line 1689, in wsgi_app
    response = self.make_response(self.handle_exception(e))
  File "/home/seriy/workspace/wannatop/env/lib/python2.7/site-packages/flask/app.py", line 1687, in wsgi_app
    response = self.full_dispatch_request()
  File "/home/seriy/workspace/wannatop/env/lib/python2.7/site-packages/flask/app.py", line 1360, in full_dispatch_request
    rv = self.handle_user_exception(e)
  File "/home/seriy/workspace/wannatop/env/lib/python2.7/site-packages/flask/app.py", line 1358, in full_dispatch_request
    rv = self.dispatch_request()
  File "/home/seriy/workspace/wannatop/env/lib/python2.7/site-packages/flask/app.py", line 1344, in dispatch_request
    return self.view_functions[rule.endpoint](**req.view_args)
  File "/home/seriy/workspace/wannatop/pb.py", line 11, in index
    raise ValueError('test exc')
ValueError: test exc
127.0.0.1 - - [06/Jan/2013 16:41:16] "GET /?__debugger__=yes&cmd=resource&f=style.css HTTP/1.1" 200 -
127.0.0.1 - - [06/Jan/2013 16:41:16] "GET /?__debugger__=yes&cmd=resource&f=jquery.js HTTP/1.1" 200 -
127.0.0.1 - - [06/Jan/2013 16:41:16] "GET /?__debugger__=yes&cmd=resource&f=debugger.js HTTP/1.1" 200 -
127.0.0.1 - - [06/Jan/2013 16:41:16] "GET /?__debugger__=yes&cmd=resource&f=console.png HTTP/1.1" 200 -
127.0.0.1 - - [06/Jan/2013 16:41:16] "GET /?__debugger__=yes&cmd=resource&f=source.png HTTP/1.1" 200 -
shutdown_session: None http://127.0.0.1:5000/ GET  <<--------- problem there!!!!!!!
shutdown_session: None http://127.0.0.1:5000/favicon.ico GET
127.0.0.1 - - [06/Jan/2013 16:41:16] "GET /favicon.ico HTTP/1.1" 404 -

My current workaround is

from flask import got_request_exception

@got_request_exception.connect_via(app)
def _rollback_transaction(sender, exception):
    db.session.rollback()

Your flask-sqlalchemy pull-request looks awesome! I will try it soon and comment on it.

PS: flask also doesn't trigger @app.errorhandler(500) in debug mode, but I think that fact should be documented.

@mgax
Copy link
Contributor

mgax commented Jan 6, 2013

Same as the first example, shutdown_session is not called at all when DEBUG=True. Use curl instead of a browser to make sure you only make one HTTP request. But do you need to explicitly do rollback? I think the session is automatically discarded with a rollback if you don't call commit.

@seriyps
Copy link
Author

seriyps commented Jan 6, 2013

Just discower that this issue is reproduced if I run python pb.py in first console, then call curl http://127.0.0.1/ in other console MORE then 1 times...

$ python pb.py                                                                                                       [17:42:20]
 * Running on http://127.0.0.1:5000/
 * Restarting with reloader
127.0.0.1 - - [06/Jan/2013 18:22:38] "GET / HTTP/1.1" 500 -
Traceback (most recent call last):
  File "/home/seriy/workspace/wannatop/env/lib/python2.7/site-packages/flask/app.py", line 1701, in __call__
    return self.wsgi_app(environ, start_response)
  File "/home/seriy/workspace/wannatop/env/lib/python2.7/site-packages/flask/app.py", line 1689, in wsgi_app
    response = self.make_response(self.handle_exception(e))
  File "/home/seriy/workspace/wannatop/env/lib/python2.7/site-packages/flask/app.py", line 1687, in wsgi_app
    response = self.full_dispatch_request()
  File "/home/seriy/workspace/wannatop/env/lib/python2.7/site-packages/flask/app.py", line 1360, in full_dispatch_request
    rv = self.handle_user_exception(e)
  File "/home/seriy/workspace/wannatop/env/lib/python2.7/site-packages/flask/app.py", line 1358, in full_dispatch_request
    rv = self.dispatch_request()
  File "/home/seriy/workspace/wannatop/env/lib/python2.7/site-packages/flask/app.py", line 1344, in dispatch_request
    return self.view_functions[rule.endpoint](**req.view_args)
  File "/home/seriy/workspace/wannatop/pb.py", line 11, in index
    raise ValueError('test exc')
ValueError: test exc
('shutdown_session:', 'None', 'http://127.0.0.1:5000/', 'GET', datetime.datetime(2013, 1, 6, 18, 22, 46, 368193))
127.0.0.1 - - [06/Jan/2013 18:22:46] "GET / HTTP/1.1" 500 -
Traceback (most recent call last):
  File "/home/seriy/workspace/wannatop/env/lib/python2.7/site-packages/flask/app.py", line 1701, in __call__
    return self.wsgi_app(environ, start_response)
...................
  File "/home/seriy/workspace/wannatop/pb.py", line 11, in index
    raise ValueError('test exc')
ValueError: test exc
('shutdown_session:', 'None', 'http://127.0.0.1:5000/', 'GET', datetime.datetime(2013, 1, 6, 18, 22, 57, 355056))
127.0.0.1 - - [06/Jan/2013 18:22:57] "GET / HTTP/1.1" 500 -
Traceback (most recent call last):
  File "/home/seriy/workspace/wannatop/env/lib/python2.7/site-packages/flask/app.py", line 1701, in __call__
    return self.wsgi_app(environ, start_response)
...............
  File "/home/seriy/workspace/wannatop/pb.py", line 11, in index
    raise ValueError('test exc')
ValueError: test exc

$ curl http://127.0.0.1:5000/
<!DOCTYPE HTML PUBLIC "-//W3C//DTD HTML 4.01 Transitional//EN"
  "http://www.w3.org/TR/html4/loose.dtd">
<html>
  <head>
    <title>ValueError: test exc // Werkzeug Debugger</title>
......
$ curl http://127.0.0.1:5000/
......
$ curl http://127.0.0.1:5000/
......

I also add datetime.datetime.now() to print statement. Looks like @teardown_request called not after request finishes, but before the next one started!!!

This is very strange behaviour. Anyway, if id doesn't called at all - this is not what I expect.


I realised that I doesn't need to call rollback explicitly, because db.session.remove() will call it anyway http://docs.sqlalchemy.org/en/rel_0_8/orm/session.html#sqlalchemy.orm.scoping.scoped_session.remove . My full transaction control code looked like this before @got_request_exception workaround

@app.teardown_request
def _manage_transaction(exception):
    if exception:
        db.session.rollback()
    else:
        db.session.commit()
    db.session.remove()

So it can be replaced by

@app.teardown_request
def _manage_transaction(exception):
    if not exception:
        db.session.commit()
    db.session.remove()

@seriyps
Copy link
Author

seriyps commented Jan 7, 2013

I discover, that this behaviour is little documented there http://flask.pocoo.org/docs/config/#builtin-configuration-values PRESERVE_CONTEXT_ON_EXCEPTION description.

So, the following piece of code fixes my issue

app.config['PRESERVE_CONTEXT_ON_EXCEPTION'] = False

But I think this should be documented there http://flask.pocoo.org/docs/api/#flask.Flask.teardown_request too!

@james-deee
Copy link

FYI, this also affects the teardown_appcontext. This is also the method that is mentioned in the SQLAlchemy setup doc page: http://flask.pocoo.org/docs/0.10/patterns/sqlalchemy/

So might want to add a note there too:
http://flask.pocoo.org/docs/0.10/api/#flask.Flask.teardown_appcontext

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

No branches or pull requests

4 participants