First pass.

Author: noise

.travis.yml

@@ -0,0 +1,7 @@
+language: python
+python:
+  - 2.7
+  - 3.3
+  - 3.4
+
+script: python setup.py test

LICENSE

@@ -1,6 +1,6 @@
 The MIT License (MIT)
 
-Copyright (c) 2014 bret barker
+Copyright (c) 2014 Bret Barker
 
 Permission is hereby granted, free of charge, to any person obtaining a copy
 of this software and associated documentation files (the "Software"), to deal

README.md

@@ -1,2 +1,53 @@
-flask-queryinspect
-==================
+# Flask QueryInspect Extension
+
+Flask-QueryInspect is a Flask extension that provides metrics on SQL queries executed for each request.
+
+It assumes use of and relies upon SQLAlchemy as the underlying ORM.
+
+I've used this method for several Flask projects and was finally inspired to turn it into an extension after seeing
+https://github.com/dobarkod/django-queryinspect.
+
+Flask-QueryInspect tracks the count of SQL reads and writes, new DB connections, and total request and total query time for each request. It does not yet handle reporting of duplicate queries like Django-QueryInspect.
+
+# Installation #
+
+```
+pip install Flask-QueryInspect
+```
+
+## Usage ##
+
+```python
+app = Flask(__name__)
+db = SQLAlchemy(cls.app)
+app.config['QUERYINSPECT_ENABLED'] = True
+qi = QueryInspect(cls.app)
+```
+
+## Configuration ##
+
+QueryInspect has the following optional config vars that can be set in
+Flask's app.config:
+
+Variable | Default | Description
+------------- | ------------- | -------------
+QUERYINSPECT_ENABLED | True | False to completely disable QueryInspect
+QUERYINSPECT_HEADERS | True | Enable response header injection
+QUERYINSPECT_HEADERS_COMBINED | True | Enable combined single header, else use [Django QueryInspect's](https://github.com/dobarkod/django-queryinspect) style
+QUERYINSPECT_LOG | True | Enable logging, in Librato style
+
+## Combined Header Format ##
+
+```
+X-QueryInspect-Combined: reads=1,writes=1,conns=0,q_time=0.2ms,r_time=2.9ms
+```
+
+## Log Format ##
+
+Logging is output using the standard Python logging module (logger name is 'flask_queryinspect') and formatted so it can be easily read by Librato, see: https://devcenter.heroku.com/articles/librato#custom-log-based-metrics
+
+E.g.:
+```
+INFO measure#qi.r_time=2.9ms, measure#qi.q_time=0.2ms,count#qi.reads=1, count#qi.writes=1, count#qi.conns=0
+```
+

flask_queryinspect.py

@@ -0,0 +1,93 @@
+import logging
+import time
+from flask import current_app
+from sqlalchemy.engine import Engine
+from sqlalchemy.event import listen
+
+log = logging.getLogger(__name__)
+
+# Find the stack on which we want to store metrics
+# Starting with Flask 0.9, the _app_ctx_stack is the correct one,
+# before that we need to use the _request_ctx_stack.
+try:
+    from flask import _app_ctx_stack as stack
+except ImportError:
+    from flask import _request_ctx_stack as stack
+
+
+class QueryInspect(object):
+
+    def __init__(self, app=None):
+        self.app = app
+        if app is not None:
+            self.init_app(app)
+
+    def init_app(self, app):
+        app.config.setdefault('QUERYINSPECT_ENABLED', False)
+        app.config.setdefault('QUERYINSPECT_HEADERS', True)
+        app.config.setdefault('QUERYINSPECT_HEADERS_COMBINED', True)
+        app.config.setdefault('QUERYINSPECT_LOG', True)
+
+        app.before_request(self.before_request)
+        app.after_request(self.after_request)
+
+        listen(Engine, 'connect', self.connect)
+        listen(Engine, 'before_cursor_execute', self.before_cursor_execute)
+        listen(Engine, 'after_cursor_execute', self.after_cursor_execute)
+
+    def connect(self, dbapi_connection, connection_record):
+        if not current_app or not current_app.config.get('QUERYINSPECT_ENABLED'):
+            return
+        stack.queryinspect['conns'] += 1
+
+    def before_cursor_execute(self, conn, cursor, statement, parameters, context, executemany):
+        if not current_app or not current_app.config.get('QUERYINSPECT_ENABLED'):
+            return
+        stack.queryinspect['q_start'] = time.time()
+
+    def after_cursor_execute(self, conn, cursor, statement, parameters, context, executemany):
+        if not current_app or not current_app.config.get('QUERYINSPECT_ENABLED'):
+            return
+        stack.queryinspect['q_time'] += time.time() - stack.queryinspect['q_start']
+        if statement.lower().startswith('select'):
+            stack.queryinspect['reads'] += 1
+        else:
+            stack.queryinspect['writes'] += 1
+
+    def before_request(self, *kw1, **kw2):
+        if not current_app or not current_app.config.get('QUERYINSPECT_ENABLED'):
+            return
+        stack.queryinspect = {
+            'r_start': time.time(),
+            'q_start': 0,
+            'r_time': 0,
+            'q_time': 0,
+            'reads': 0,
+            'writes': 0,
+            'conns': 0
+        }
+
+    def after_request(self, response, *kw1, **kw2):
+        if not current_app or not current_app.config.get('QUERYINSPECT_ENABLED'):
+            return
+
+        qi = stack.queryinspect
+        qi['r_time'] = time.time() - qi['r_start']
+        qi['q_time_ms'] = round(qi['q_time'] * 1000, 1)
+        qi['r_time_ms'] = round(qi['r_time'] * 1000, 1)
+
+        if current_app.config.get('QUERYINSPECT_LOG'):
+            log.info('measure#qi.r_time=%(r_time_ms).1fms, measure#qi.q_time=%(q_time_ms).1fms,' +
+                     'count#qi.reads=%(reads)d, count#qi.writes=%(writes)d, count#qi.conns=%(conns)d', qi)
+
+        if current_app.config.get('QUERYINSPECT_HEADERS'):
+            if current_app.config.get('QUERYINSPECT_HEADERS_COMBINED'):
+                combo = ('reads=%(reads)d,writes=%(writes)d,conns=%(conns)d,q_time=%(q_time_ms).1fms,' +
+                         'r_time=%(r_time_ms).1fms') % qi
+                response.headers['X-QueryInspect-Combined'] = combo
+            else:
+                response.headers['X-QueryInspect-Num-SQL-Queries'] = qi['reads'] + qi['writes']
+                #response.headers['X-QueryInspect-Duplicate-SQL-Queries'] = qi['dupes']
+                response.headers['X-QueryInspect-Total-SQL-Time'] = qi['q_time']
+                response.headers['X-QueryInspect-Total-Request-Time'] = qi['r_time']
+        return response

setup.py

@@ -0,0 +1,46 @@
+"""
+Flask-QueryInspect
+-------------
+
+Flask-QueryInspect is a Flask extension that provides metrics on SQL queries executed for each request.
+
+It assumes use of and relies upon SQLAlchemy as the underlying ORM.
+
+This extension was inspired by internal tooling of this sort, and
+then directly by https://github.com/dobarkod/django-queryinspect
+
+"""
+from setuptools import setup
+
+
+setup(
+    name='Flask-QueryInspect',
+    version='0.1',
+    url='https://github.com/noise/flask-queryinspect',
+    license='MIT',
+    author='Bret Barker',
+    author_email='bret@abitrandom.net',
+    description='Flask extension to provide metrics on SQL queries per request.',
+    long_description=__doc__,
+    py_modules=['flask_queryinspect'],
+    zip_safe=False,
+    include_package_data=True,
+    platforms='any',
+    install_requires=[
+        'Flask',
+        'SQLAlchemy'
+    ],
+    tests_require=[
+        'Flask-SQLAlchemy'
+    ],
+    test_suite='test_queryinspect',
+    classifiers=[
+        'Environment :: Web Environment',
+        'Intended Audience :: Developers',
+        'License :: OSI Approved :: MIT License',
+        'Operating System :: OS Independent',
+        'Programming Language :: Python',
+        'Topic :: Internet :: WWW/HTTP :: Dynamic Content',
+        'Topic :: Software Development :: Libraries :: Python Modules'
+    ],
+)

test_queryinspect.py

@@ -0,0 +1,75 @@
+import logging
+import time
+import unittest
+from flask import Flask
+from flask.ext.sqlalchemy import SQLAlchemy
+from flask.ext.queryinspect import QueryInspect
+
+log = logging.getLogger(__name__)
+
+
+class TestQueryInspect(unittest.TestCase):
+    @classmethod
+    def setUpClass(cls):
+        logging.basicConfig(format='%(asctime)-15s %(levelname)s %(message)s')
+        logging.getLogger('flask_queryinspect').setLevel(logging.DEBUG)
+        logging.getLogger('test_queryinspect').setLevel(logging.DEBUG)
+
+        cls.app = Flask(__name__)
+        cls.app.config['TESTING'] = True
+
+        cls.app.config['SQLALCHEMY_DATABASE_URI'] = 'sqlite://'
+        #cls.app.config['SQLALCHEMY_ECHO'] = True
+        db = SQLAlchemy(cls.app)
+        cls.db = db
+
+        cls.app.config['QUERYINSPECT_ENABLED'] = True
+        cls.qi = QueryInspect(cls.app)
+
+        class TestModel(db.Model):
+            id = db.Column(db.Integer, primary_key=True)
+            foo = db.Column(db.Unicode(10))
+
+            def __init__(self, foo):
+                self.foo = foo
+
+        db.create_all(app=cls.app)
+        for i in xrange(10):
+            db.session.add(TestModel('test_%d' % i))
+        db.session.commit()
+
+        @cls.app.route('/')
+        def index():
+            return u'No Queries'
+
+        @cls.app.route('/mix')
+        def mix():
+            t = TestModel.query.first()
+            t.foo = 'bar'
+            db.session.commit()
+            return u'Reads and writes'
+
+        @cls.app.route('/slow')
+        def slow():
+            time.sleep(.1)
+            return u'Slow request'
+
+    def test_noqueries(self):
+        with self.app.test_client() as c:
+            res = c.get('/')
+            log.debug(res.headers)
+            self.assertTrue(res.headers['X-QueryInspect-Combined'].startswith('reads=0,writes=0,conns=0'))
+
+    def test_mix(self):
+        with self.app.test_client() as c:
+            res = c.get('/mix')
+            log.debug(res.headers)
+            self.assertTrue(res.headers['X-QueryInspect-Combined'].startswith('reads=1,writes=1'))
+
+    def test_rtime(self):
+        self.app.config['QUERYINSPECT_HEADERS_COMBINED'] = False
+        with self.app.test_client() as c:
+            res = c.get('/slow')
+            r_time = res.headers['X-QueryInspect-Total-Request-Time']
+            self.assertTrue(90 < r_time > 110)
+        self.app.config['QUERYINSPECT_HEADERS_COMBINED'] = True