On 9/18/15 3:22 PM, George Reilly wrote:
I find [SQLTap](http://sqltap.inconshreveable.com/) invaluable for
profiling SQLAlchemy queries. Currently, I've reduced one operation in
our system from nearly 12,000 queries to 800, and I'm not finished yet.
SQLTap listens for the before_execute and after_execute events. In
after_execute, it captures the query time, the text of the query, and
the parameters. These are aggregated into a profiling report.
For some queries, it fails to capture the actual parameter(s), instead
reporting param_1 as None. The queries work, of course, and do have a
non-None parameter. Typically these queries boil down to
query(class).get(id).
Here's what the after_execute listener in SQLTap looks like (simplified):
def _after_execute(self, conn, clause, multiparams, params, results):
duration = time.time() - conn._sqltap_query_start_time
try:
text = clause.compile(dialect=conn.engine.dialect)
except AttributeError:
text = clause
query_params = getattr(text, 'params', {})
I've set a breakpoint in _after_execute and examined the multiparams
and params arguments. The results typically look like
multiparams ({'%(4480418320 param)s': 37},)
params {}
query_params {u'param_1': None}
I've put some sample code up at
https://gist.github.com/georgevreilly/11f87d1d2f4664206df2
I'm using SQLAlchemy 0.9.9.
Is there a reliable way of capturing the actual query parameters?
the simplest way is to do it at the cursor using before_cursor_execute
and after_cursor_execute which places the SQL string and the final
parameters separately.
At the level of before_execute and after_execute, you'd need to recreate
the arguments as they come from the given Core construct which means
compiling it again which is not really something you want to be doing.
before_cursor_execute and after_cursor_execute provide all the
information about the statement, compiled object, and everything else
and is a more appropriate place to put performance-measuring callables,
not to mention they isolate the time spent with the database itself much
better. We've had an example of this at
https://bitbucket.org/zzzeek/sqlalchemy/wiki/UsageRecipes/Profiling for
many years so I'm surprised SQLTap used the outer events, which are more
intended for modifications to queries before they are invoked.
--
/George V. Reilly [email protected]
<mailto:[email protected]> Twitter: @georgevreilly
<https://twitter.com/georgevreilly>
_www.GeorgeVReilly.com <http://www.GeorgeVReilly.com>_
Please sponsor me for the End AIDS Walk:
http://tinyurl.com/gvr-2015-aidswalk
--
You received this message because you are subscribed to the Google
Groups "sqlalchemy" group.
To unsubscribe from this group and stop receiving emails from it, send
an email to [email protected]
<mailto:[email protected]>.
To post to this group, send email to [email protected]
<mailto:[email protected]>.
Visit this group at http://groups.google.com/group/sqlalchemy.
For more options, visit https://groups.google.com/d/optout.
--
You received this message because you are subscribed to the Google Groups
"sqlalchemy" group.
To unsubscribe from this group and stop receiving emails from it, send an email
to [email protected].
To post to this group, send email to [email protected].
Visit this group at http://groups.google.com/group/sqlalchemy.
For more options, visit https://groups.google.com/d/optout.
