On 10/12/16 1:51 AM, Simon King wrote:
You could use the before_cursor_execute event to log the SQL based on
some debugging flag.

http://docs.sqlalchemy.org/en/latest/core/events.html#sqlalchemy.events.ConnectionEvents.before_cursor_execute

For example:

from sqlalchemy import event

DEBUGGING = False

@event.listens_for(SomeEngine, 'before_cursor_execute', named=True)
def receive_before_cursor_execute(**kw):
     if DEBUGGING:
         print kw['statement']

Simon
Oh nice!! Will this be called in the context of the same thread executing the sql? This would allow me to debug without formatting all debugs I believe...

-Alfred


On Wed, Oct 12, 2016 at 8:13 AM, Alfred Perlstein
<alfred.perlst...@gmail.com> wrote:
Mike,

I'm trying to find a nice way to say that this doesn't totally make life
difficult for us.

Even if we were to use the filter as described, we couldn't use it for an
existing connection, we would HAVE to restart the connection?

Does that really sound reasonable to you to force users to write all this
scaffolding just to get the SQL emitted for a few lines of code?  To me it
really doesn't sound like a framework that facilitates easy debugging.  We
basically have to slow down the *entire app* just to get a very small
segment of debug code.

Is there no way to "toggle" the optimization to reset itself, specifically
this:

The SQLAlchemy Engine conserves Python function call overhead by only
emitting log statements when the current logging level is detected as
logging.INFO or logging.DEBUG. It only checks this level when a new
connection is procured from the connection pool. Therefore when changing the
logging configuration for an already-running application, any Connection
that’s currently active, or more commonly a Session object that’s active in
a transaction, won’t log any SQL according to the new configuration until a
new Connection is procured (in the case of Session, this is after the
current transaction ends and a new one begins).
Really?  this is really bad and makes what should be a simple debugging
session into a nightmare of scaffolding that has to be written just to do
something that should be super simple, namely:

"get the sql emitted between these two points of code without having to
write a ton of scaffolding to do so."

I'm sort of speechless, if possible any advice going forward would help,
even pointers on where to get started in the code. Turning on global debug
and taking a performance hit is not possible.

Appreciate your help on the matter.

thanks,

-Alfred


On 10/11/16 11:18 PM, Mike Bayer wrote:


On 10/11/2016 09:59 PM, Alfred Perlstein wrote:
Hello folks, we are using SqlA in a pretty large flask app.

One issue we have is that sometimes due to orm, serializers
(marshmallow) or other complex code paths we find ourselves doing many
more queries than we expected and this causes us a lot of headache.  We
need to be able to track down the code paths causing the extra SQL.

In addition because the codebase is large we can't turn on logging
globally otherwise we would drown in noise.

The solution we thought would be simple would be to be able to
temporarily turn on logging in a single thread of execution or on a
single session object... however that seems to be an elusive thing to be
able to do.

What we have found is that while sqlA offers the ability to *create* an
engine with "echo=True", there doesn't seem to be a sane way to *set*
echo=True with an existing session.

Well first off, SQL logging is a function of the Core, not the ORM, so the
Session wouldn't know anything about it.

One could try to set session.engine.echo=True, however it appears that
the connection object hung from the engine object grabs the value of
"echo" when instantiated and never checks to see if the engine has been
reconfigured.

this is actually documented in the green note at the end of
http://docs.sqlalchemy.org/en/rel_1_1/core/engines.html#configuring-logging



  Surely a better way to do this would be to have a method
to pass down to the Connection object to enable echo.

That's not how Python logging works.   Logging in Python is organized as a
"cross-cutting" concern, meaning a logger presents itself as an open stream
in which log messages are unconditionally dropped.   The configuration of
what messages to log, when, and where, is accomplished within the logging
configuration, not within the system that is emitting messages to logging.
SQLAlchemy's "echo" flag is merely a quick shortcut to a very simplistic log
output, and additionally it adds a small "block" to remove the overhead of
emitting messages to the log object if we've detected they aren't being used
(this occurs independently of the "echo" flag itself).

Any non-trivial use of logging should be using Python's logging system
directly.  The loggers in use are described at
http://docs.sqlalchemy.org/en/rel_1_1/core/engines.html#configuring-logging.

In this case I'd in the simple case just add "threadid" to the log format
(https://docs.python.org/2/library/logging.html#logrecord-attributes) and
use grep against the stream.  More ambitiously I'd write a simple
logging.Filter that only allows messages from a certain thread (some example
filters such as
https://docs.python.org/2/howto/logging-cookbook.html#using-filters-to-impart-contextual-information).



I've done quite a bit of looking through google and the docs and have
simply been unable to find a way do to the following:

.... lots of code previous to this line...
old_enable = session.log_enable()  # turn on logging, return the
previous value of logging (so this can be nested)
... do some stuff and see which SQL queries are being made ...
session.log_set(old_enable)  # restore logging to prior to it being set.
... lots more code without any logging happening.

If I were to create a method on engine that would then reconfigure its
connection object as well to remedy this, would that be an acceptable
patch to the project? Or is there some other trick I am missing?

Thank you!
-Alfred

--
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 sqlalchemy+unsubscr...@googlegroups.com
<mailto:sqlalchemy+unsubscr...@googlegroups.com>.
To post to this group, send email to sqlalchemy@googlegroups.com
<mailto:sqlalchemy@googlegroups.com>.
Visit this group at https://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 sqlalchemy+unsubscr...@googlegroups.com.
To post to this group, send email to sqlalchemy@googlegroups.com.
Visit this group at https://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 sqlalchemy+unsubscr...@googlegroups.com.
To post to this group, send email to sqlalchemy@googlegroups.com.
Visit this group at https://groups.google.com/group/sqlalchemy.
For more options, visit https://groups.google.com/d/optout.

Reply via email to