On 10/12/16 10:44 AM, Mike Bayer wrote:
On 10/12/2016 02:18 AM, Mike Bayer wrote:
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).
here is the filter:
import logging
import threading
class MyFilter(logging.Filter):
def __init__(self):
self.flags = threading.local()
def log_sql(self):
self.flags.log = True
def unlog_sql(self):
del self.flags.log
def filter(self, record):
return getattr(self.flags, 'log', False)
here's how to stick it on an Engine, note using engine.logger instead
of hardcoding "sqlalchemy.engine.base.Engine", using the filter on
loggers instead of handlers means it must be applied directly:
my_filter = MyFilter()
engine.logger.setLevel(logging.INFO)
engine.logger.addFilter(my_filter)
"engine.logger" is not documented but is not an underscored attribute
and I will gladly document this as a public attribute. The filter can
also be put on the handler in use.
Setting logger.setLevel() back to logging.WARN will cause all
subsequent connections to revert to sending no messages to the logger
and the filter will remain un-invoked at that point. The filter
itself can also be removed using engine.logger.removeFilter(my_filter).
Using normal Python logging patterns is preferable to adding new flags
and behaviors to SQLAlchemy's "echo" feature. Adding per-connection,
detectable-during-change "echo" flags would add complexity and testing
burden to the SQLAlchemy project, as this would mean special code and
conditionals would need to be added to Connection's logging logic that
must be guaranteed to behave in a very specific way to suit this
specific use case.
here is a demo. hope this helps.
import logging
import threading
class MyFilter(logging.Filter):
def __init__(self):
self.flags = threading.local()
def log_sql(self):
self.flags.log = True
def unlog_sql(self):
del self.flags.log
def filter(self, record):
return getattr(self.flags, 'log', False)
if __name__ == '__main__':
from sqlalchemy import Integer, Column, create_engine, ForeignKey
from sqlalchemy.orm import relationship, Session
from sqlalchemy.ext.declarative import declarative_base
import time
Base = declarative_base()
class A(Base):
__tablename__ = 'a'
id = Column(Integer, primary_key=True)
bs = relationship("B")
class B(Base):
__tablename__ = 'b'
id = Column(Integer, primary_key=True)
a_id = Column(ForeignKey('a.id'))
e = create_engine("postgresql://scott:tiger@localhost/test")
Base.metadata.drop_all(e)
Base.metadata.create_all(e)
def worker(log=False):
for j in range(5):
s = Session(e)
a1 = A(bs=[B(), B(), B()])
s.add(a1)
s.flush()
# note we are mid-transaction.
if log:
my_filter.log_sql()
for a in s.query(A).filter_by(id=a1.id):
a.bs
if log:
my_filter.unlog_sql()
s.commit()
time.sleep(.5)
my_filter = MyFilter()
logging.basicConfig(
format='%(thread)d %(message)s'
)
e.logger.setLevel(logging.INFO)
e.logger.addFilter(my_filter)
threads = [threading.Thread(
target=worker, args=(i == 6, )) for i in range(10)]
for t in threads:
t.start()
for t in threads:
t.join()
Mike,
Thank you, in fact thank you very, very much. Writing out the code was
really above and beyond my expectations. I will use this snippet in our
app.
The following problems remain for us (and also likely other users of
sqla) although they are not immediate issues:
1) I need to make sure that I can use "theading.local", since we are
based on flask we actually use werkzeug's threads, which I now have to
investigate if they are compatible with this snippet. Likewise anyone
using greenlets may have to modify the snippet to fit with greenlets.
That said, I do believe that porting this snippet to werkzeug's thread
primatives should insulate us from greenlet/native-threads problems, but
then those folks not using werkzeug don't have that option. This is why
overall it's a appears problematic to me.... however I've not confirmed
this yet, it's possible that "threading.local" works for most cases
(greenlets and werkzeug) but... I have to test.
2) It looks like to me that by using the engine's logger we would be
turning on logging across all threads. What happens when we have 1000
threads? What will happen to us performance wise?
So as a question, if I ever get to it, would you entertain patches to do
this without turning on global logging and/or being tied to the
threading implementation?
btw, if you're wondering where I'm coming from with these insane scaling
questions.... I used to be CTO of OKCupid and scaled them, now at a new
place, so these things matter to me and my team.
thanks again Mike and apologies for the tone of my original email!
-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.
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.
