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 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.
