On 10/12/2016 03:13 AM, Alfred Perlstein wrote:
Mike,
I'm trying to find a nice way to say that this doesn't totally make life
difficult for us.
Hi Alfred -
I'd point out that you've spent the time and energy here to produce
about eight paragraphs describing how disappointed you'd be if you had
to at least experiment with the approach I'm describing, most include
hyperbolic, emotion-inducing terminology like "does that really sound
reasonable?" "this is really bad", "I'm sort of speechless".
I know it's not because of the effort involved, because you offered to
go through and patch all the logging in Connection to make your desired
feature work, which would be much more effort than my proposal, not to
mention there are at least five other ways to do this too (though a
logging filter IMO is the most idiomatic).
I don't get too many threads like these where the pushback response is
highly disproportionate to the proposal, but when I do, they are very
draining. I'm not sure what the desired effect is except that I'd be
pushed to write more code to ease your emotions and frustrations. Or if
you just wanted to vent for awhile, I can try to be OK with that.
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.
