diff options
| -rw-r--r-- | CHANGES | 3 | ||||
| -rw-r--r-- | lib/sqlalchemy/databases/mysql.py | 2 | ||||
| -rw-r--r-- | lib/sqlalchemy/databases/oracle.py | 2 | ||||
| -rw-r--r-- | lib/sqlalchemy/log.py | 67 | ||||
| -rw-r--r-- | lib/sqlalchemy/orm/dynamic.py | 2 | ||||
| -rw-r--r-- | lib/sqlalchemy/orm/interfaces.py | 5 | ||||
| -rw-r--r-- | lib/sqlalchemy/orm/mapper.py | 25 | ||||
| -rw-r--r-- | lib/sqlalchemy/orm/properties.py | 9 | ||||
| -rw-r--r-- | lib/sqlalchemy/orm/query.py | 2 | ||||
| -rw-r--r-- | lib/sqlalchemy/orm/session.py | 13 | ||||
| -rw-r--r-- | lib/sqlalchemy/orm/strategies.py | 17 | ||||
| -rw-r--r-- | lib/sqlalchemy/orm/unitofwork.py | 8 | ||||
| -rw-r--r-- | test/orm/inheritance/polymorph2.py | 2 |
13 files changed, 74 insertions, 83 deletions
@@ -69,6 +69,9 @@ CHANGES may now be a mix of lists and tuples. (Previously members were always lists.) + - The `echo_uow` flag on `Session` is deprecated, and unit-of-work + logging is now application-level only, not per-session level. + - schema - Added "sorted_tables" accessor to MetaData, which returns Table objects sorted in order of dependency as a list. diff --git a/lib/sqlalchemy/databases/mysql.py b/lib/sqlalchemy/databases/mysql.py index 46e692463..ed8712748 100644 --- a/lib/sqlalchemy/databases/mysql.py +++ b/lib/sqlalchemy/databases/mysql.py @@ -2664,7 +2664,7 @@ class MySQLSchemaReflector(object): return self._re_keyexprs.findall(identifiers) -MySQLSchemaReflector.logger = log.class_logger(MySQLSchemaReflector) +log.class_logger(MySQLSchemaReflector) class _MySQLIdentifierPreparer(compiler.IdentifierPreparer): diff --git a/lib/sqlalchemy/databases/oracle.py b/lib/sqlalchemy/databases/oracle.py index 7b12e5af1..12b22f445 100644 --- a/lib/sqlalchemy/databases/oracle.py +++ b/lib/sqlalchemy/databases/oracle.py @@ -566,8 +566,6 @@ class OracleDialect(default.DefaultDialect): table.append_constraint(schema.ForeignKeyConstraint(value[0], value[1], name=name)) -OracleDialect.logger = log.class_logger(OracleDialect) - class _OuterJoinColumn(sql.ClauseElement): __visit_name__ = 'outer_join_column' def __init__(self, column): diff --git a/lib/sqlalchemy/log.py b/lib/sqlalchemy/log.py index 762f56ef5..40f4fe812 100644 --- a/lib/sqlalchemy/log.py +++ b/lib/sqlalchemy/log.py @@ -6,16 +6,13 @@ """Logging control and utilities. -Provides a few functions used by instances to turn on/off their logging, -including support for the usual "echo" parameter. - Control of logging for SA can be performed from the regular python logging module. The regular dotted module namespace is used, starting at -'sqlalchemy'. For class-level logging, the class name is appended, and for -instance-level logging, the hex id of the instance is appended. +'sqlalchemy'. For class-level logging, the class name is appended. -The "echo" keyword parameter which is available on some SA objects corresponds -to an instance-level logger for that instance. +The "echo" keyword parameter which is available on SQLA ``Engine`` +and ``Pool`` objects corresponds to a logger specific to that +instance only. E.g.:: @@ -26,11 +23,12 @@ is equivalent to:: import logging logger = logging.getLogger('sqlalchemy.engine.Engine.%s' % hex(id(engine))) logger.setLevel(logging.DEBUG) + """ import logging import sys -import weakref + rootlogger = logging.getLogger('sqlalchemy') if rootlogger.level == logging.NOTSET: @@ -48,27 +46,34 @@ def default_logging(name): '%(asctime)s %(levelname)s %(name)s %(message)s')) rootlogger.addHandler(handler) -def _get_instance_name(instance): - # since getLogger() does not have any way of removing logger objects from - # memory, instance logging displays the instance id as a modulus of 16 to - # prevent endless memory growth also speeds performance as logger - # initialization is apparently slow - return "%s.%s.0x..%s" % (instance.__class__.__module__, - instance.__class__.__name__, - hex(id(instance))[-2:]) - -def class_logger(cls): - return logging.getLogger(cls.__module__ + "." + cls.__name__) - -def is_debug_enabled(logger): - return logger.isEnabledFor(logging.DEBUG) - -def is_info_enabled(logger): - return logger.isEnabledFor(logging.INFO) +def class_logger(cls, enable=False): + logger = logging.getLogger(cls.__module__ + "." + cls.__name__) + if enable == 'debug': + logger.setLevel(logging.DEBUG) + elif enable == 'info': + logger.setLevel(logging.INFO) + cls._should_log_debug = logger.isEnabledFor(logging.DEBUG) + cls._should_log_info = logger.isEnabledFor(logging.INFO) + cls.logger = logger def instance_logger(instance, echoflag=None): + """create a logger for an instance. + + Warning: this is an expensive call which also results in a permanent + increase in memory overhead for each call. Use only for + low-volume, long-time-spanning objects. + + """ + + # limit the number of loggers by chopping off the hex(id). + # many novice users unfortunately create an unlimited number + # of Engines in their applications which would otherwise + # cause the app to run out of memory. + name = "%s.%s.0x...%s" % (instance.__class__.__module__, + instance.__class__.__name__, + hex(id(instance))[-4:]) + if echoflag is not None: - name = _get_instance_name(instance) l = logging.getLogger(name) if echoflag == 'debug': default_logging(name) @@ -78,15 +83,8 @@ def instance_logger(instance, echoflag=None): l.setLevel(logging.INFO) elif echoflag is False: l.setLevel(logging.NOTSET) - - def cleanup(ref): - # the id() of an instance may be reused again after the - # previous instance has been gc'ed. set a cleanup handler - # to remove logging config - logging.getLogger(name).setLevel(logging.NOTSET) - instance._logging_cleanup = weakref.ref(instance, cleanup) else: - l = logging.getLogger(_get_instance_name(instance)) + l = logging.getLogger(name) instance._should_log_debug = l.isEnabledFor(logging.DEBUG) instance._should_log_info = l.isEnabledFor(logging.INFO) return l @@ -95,7 +93,6 @@ class echo_property(object): __doc__ = """\ When ``True``, enable log output for this element. - This has the effect of setting the Python logging level for the namespace of this element's class and object reference. A value of boolean ``True`` indicates that the loglevel ``logging.INFO`` will be set for the logger, diff --git a/lib/sqlalchemy/orm/dynamic.py b/lib/sqlalchemy/orm/dynamic.py index 3d139dff1..8c77547da 100644 --- a/lib/sqlalchemy/orm/dynamic.py +++ b/lib/sqlalchemy/orm/dynamic.py @@ -29,7 +29,7 @@ class DynaLoader(strategies.AbstractRelationLoader): def create_row_processor(self, selectcontext, path, mapper, row, adapter): return (None, None) -DynaLoader.logger = log.class_logger(DynaLoader) +log.class_logger(DynaLoader) class DynamicAttributeImpl(attributes.AttributeImpl): uses_objects = True diff --git a/lib/sqlalchemy/orm/interfaces.py b/lib/sqlalchemy/orm/interfaces.py index 29bc980bc..ff15062aa 100644 --- a/lib/sqlalchemy/orm/interfaces.py +++ b/lib/sqlalchemy/orm/interfaces.py @@ -623,8 +623,6 @@ class PropertyOption(MapperOption): self._process(query, False) def _process(self, query, raiseerr): - if self._should_log_debug: - self.logger.debug("applying option to Query, property key '%s'" % self.key) paths = self.__get_paths(query, raiseerr) if paths: self.process_query_property(query, paths) @@ -703,9 +701,6 @@ class PropertyOption(MapperOption): return l -PropertyOption.logger = log.class_logger(PropertyOption) -PropertyOption._should_log_debug = log.is_debug_enabled(PropertyOption.logger) - class AttributeExtension(object): """An abstract class which specifies `append`, `delete`, and `set` event handlers to be attached to an object property. diff --git a/lib/sqlalchemy/orm/mapper.py b/lib/sqlalchemy/orm/mapper.py index 921d08b83..ac14b5daf 100644 --- a/lib/sqlalchemy/orm/mapper.py +++ b/lib/sqlalchemy/orm/mapper.py @@ -189,9 +189,6 @@ class Mapper(object): self.compiled = False - self.__should_log_info = log.is_info_enabled(self.logger) - self.__should_log_debug = log.is_debug_enabled(self.logger) - self.__compile_inheritance() self.__compile_extensions() self.__compile_class() @@ -202,11 +199,11 @@ class Mapper(object): self.__log("constructed") def __log(self, msg): - if self.__should_log_info: + if self._should_log_info: self.logger.info("(" + self.class_.__name__ + "|" + (self.local_table and self.local_table.description or str(self.local_table)) + (self.non_primary and "|non-primary" or "") + ") " + msg) def __log_debug(self, msg): - if self.__should_log_debug: + if self._should_log_debug: self.logger.debug("(" + self.class_.__name__ + "|" + (self.local_table and self.local_table.description or str(self.local_table)) + (self.non_primary and "|non-primary" or "") + ") " + msg) def _is_orphan(self, state): @@ -1042,7 +1039,7 @@ class Mapper(object): mapper which does not inherit from any other mapper. """ - if self.__should_log_debug: + if self._should_log_debug: self.__log_debug("_save_obj() start, " + (single and "non-batched" or "batched")) # if batch=false, call _save_obj separately for each object @@ -1080,7 +1077,7 @@ class Mapper(object): existing = attributes.instance_state(instance) if not uowtransaction.is_deleted(existing): raise exc.FlushError("New instance %s with identity key %s conflicts with persistent instance %s" % (state_str(state), str(instance_key), state_str(existing))) - if self.__should_log_debug: + if self._should_log_debug: self.__log_debug("detected row switch for identity %s. will update %s, remove %s from transaction" % (instance_key, state_str(state), state_str(existing))) uowtransaction.set_row_switch(existing) @@ -1102,7 +1099,7 @@ class Mapper(object): pks = mapper._pks_by_table[table] instance_key = mapper._identity_key_from_state(state) - if self.__should_log_debug: + if self._should_log_debug: self.__log_debug("_save_obj() table '%s' instance %s identity %s" % (table.name, state_str(state), str(instance_key))) isinsert = not instance_key in uowtransaction.session.identity_map and not postupdate and not has_identity @@ -1119,7 +1116,7 @@ class Mapper(object): if value is not None: params[col.key] = value elif mapper.polymorphic_on and mapper.polymorphic_on.shares_lineage(col): - if self.__should_log_debug: + if self._should_log_debug: self.__log_debug("Using polymorphic identity '%s' for insert column '%s'" % (mapper.polymorphic_identity, col.key)) value = mapper.polymorphic_identity if ((col.default is None and @@ -1297,7 +1294,7 @@ class Mapper(object): flush operation. """ - if self.__should_log_debug: + if self._should_log_debug: self.__log_debug("_delete_obj() start") if 'connection_callable' in uowtransaction.mapper_flush_opts: @@ -1479,7 +1476,7 @@ class Mapper(object): instance = session_identity_map[identitykey] state = attributes.instance_state(instance) - if self.__should_log_debug: + if self._should_log_debug: self.__log_debug("_instance(): using existing instance %s identity %s" % (instance_str(instance), str(identitykey))) isnew = state.runid != context.runid @@ -1498,7 +1495,7 @@ class Mapper(object): currentload = True loaded_instance = False else: - if self.__should_log_debug: + if self._should_log_debug: self.__log_debug("_instance(): identity key %s not in session" % str(identitykey)) if self.allow_null_pks: @@ -1527,7 +1524,7 @@ class Mapper(object): else: instance = self.class_manager.new_instance() - if self.__should_log_debug: + if self._should_log_debug: self.__log_debug("_instance(): created new instance %s identity %s" % (instance_str(instance), str(identitykey))) state = attributes.instance_state(instance) @@ -1633,7 +1630,7 @@ class Mapper(object): cond = sql.and_(*allconds) return sql.select(tables, cond, use_labels=True) -Mapper.logger = log.class_logger(Mapper) +log.class_logger(Mapper) def reconstructor(fn): diff --git a/lib/sqlalchemy/orm/properties.py b/lib/sqlalchemy/orm/properties.py index ceabc2792..075dde081 100644 --- a/lib/sqlalchemy/orm/properties.py +++ b/lib/sqlalchemy/orm/properties.py @@ -96,7 +96,7 @@ class ColumnProperty(StrategizedProperty): def __str__(self): return str(self.parent.class_.__name__) + "." + self.key -ColumnProperty.logger = log.class_logger(ColumnProperty) +log.class_logger(ColumnProperty) class CompositeProperty(ColumnProperty): """subclasses ColumnProperty to provide composite type support.""" @@ -204,7 +204,8 @@ class SynonymProperty(MapperProperty): def merge(self, session, source, dest, dont_load, _recursive): pass -SynonymProperty.logger = log.class_logger(SynonymProperty) + +log.class_logger(SynonymProperty) class ComparableProperty(MapperProperty): """Instruments a Python property for use in query expressions.""" @@ -735,7 +736,7 @@ class PropertyLoader(StrategizedProperty): def _post_init(self): - if log.is_info_enabled(self.logger): + if self._should_log_info: self.logger.info(str(self) + " setup primary join %s" % self.primaryjoin) self.logger.info(str(self) + " setup secondary join %s" % self.secondaryjoin) self.logger.info(str(self) + " synchronize pairs [%s]" % ",".join("(%s => %s)" % (l, r) for l, r in self.synchronize_pairs)) @@ -861,7 +862,7 @@ class PropertyLoader(StrategizedProperty): if not self.viewonly: self._dependency_processor.register_dependencies(uowcommit) -PropertyLoader.logger = log.class_logger(PropertyLoader) +log.class_logger(PropertyLoader) class BackRef(object): """Attached to a PropertyLoader to indicate a complementary reverse relationship. diff --git a/lib/sqlalchemy/orm/query.py b/lib/sqlalchemy/orm/query.py index 784d30c8d..4cd6ec877 100644 --- a/lib/sqlalchemy/orm/query.py +++ b/lib/sqlalchemy/orm/query.py @@ -1693,7 +1693,7 @@ class _ColumnEntity(_QueryEntity): def __str__(self): return str(self.column) -Query.logger = log.class_logger(Query) +log.class_logger(Query) class QueryContext(object): def __init__(self, query): diff --git a/lib/sqlalchemy/orm/session.py b/lib/sqlalchemy/orm/session.py index b1a1ebe16..bd271e96d 100644 --- a/lib/sqlalchemy/orm/session.py +++ b/lib/sqlalchemy/orm/session.py @@ -135,8 +135,7 @@ def sessionmaker(bind=None, class_=None, autoflush=True, autocommit=False, directly to the constructor for ``Session``. echo_uow - When ``True``, configure Python logging to dump all unit-of-work - transactions. This is the equivalent of + Deprecated. Use ``logging.getLogger('sqlalchemy.orm.unitofwork').setLevel(logging.DEBUG)``. extension @@ -526,7 +525,7 @@ class Session(object): def __init__(self, bind=None, autoflush=True, expire_on_commit=True, _enable_transaction_accounting=True, - autocommit=False, twophase=False, echo_uow=False, + autocommit=False, twophase=False, echo_uow=None, weak_identity_map=True, binds=None, extension=None, query_cls=query.Query): """Construct a new Session. @@ -534,7 +533,13 @@ class Session(object): [sqlalchemy.orm#sessionmaker()] function. """ - self.echo_uow = echo_uow + + if echo_uow is not None: + util.warn_deprecated( + "echo_uow is deprecated. " + "Use logging.getLogger('sqlalchemy.orm.unitofwork').setLevel(logging.DEBUG).") + log.class_logger(UOWTransaction, echo_uow) + if weak_identity_map: self._identity_cls = identity.WeakInstanceDict else: diff --git a/lib/sqlalchemy/orm/strategies.py b/lib/sqlalchemy/orm/strategies.py index d6b53b9c8..e0166e56c 100644 --- a/lib/sqlalchemy/orm/strategies.py +++ b/lib/sqlalchemy/orm/strategies.py @@ -40,13 +40,12 @@ class DefaultColumnLoader(LoaderStrategy): active_history=active_history ) -DefaultColumnLoader.logger = log.class_logger(DefaultColumnLoader) +log.class_logger(DefaultColumnLoader) class ColumnLoader(DefaultColumnLoader): def init(self): self.columns = self.parent_property.columns - self._should_log_debug = log.is_debug_enabled(self.logger) self.is_composite = hasattr(self.parent_property, 'composite_class') def setup_query(self, context, entity, path, adapter, column_collection=None, **kwargs): @@ -91,7 +90,7 @@ class ColumnLoader(DefaultColumnLoader): self.logger.debug("%s deferring load" % self) return (new_execute, None) -ColumnLoader.logger = log.class_logger(ColumnLoader) +log.class_logger(ColumnLoader) class CompositeColumnLoader(ColumnLoader): def init_class_attribute(self): @@ -146,7 +145,7 @@ class CompositeColumnLoader(ColumnLoader): return (new_execute, None) -CompositeColumnLoader.logger = log.class_logger(CompositeColumnLoader) +log.class_logger(CompositeColumnLoader) class DeferredColumnLoader(DefaultColumnLoader): """Deferred column loader, a per-column or per-column-group lazy loader.""" @@ -176,7 +175,6 @@ class DeferredColumnLoader(DefaultColumnLoader): raise NotImplementedError("Deferred loading for composite types not implemented yet") self.columns = self.parent_property.columns self.group = self.parent_property.group - self._should_log_debug = log.is_debug_enabled(self.logger) def init_class_attribute(self): self.is_class_level = True @@ -213,7 +211,7 @@ class DeferredColumnLoader(DefaultColumnLoader): def setup_loader(self, state, props=None, create_statement=None): return LoadDeferredColumns(state, self.key, props) -DeferredColumnLoader.logger = log.class_logger(DeferredColumnLoader) +log.class_logger(DeferredColumnLoader) class LoadDeferredColumns(object): """serializable loader object used by DeferredColumnLoader""" @@ -289,7 +287,6 @@ class AbstractRelationLoader(LoaderStrategy): def init(self): for attr in ['mapper', 'target', 'table', 'uselist']: setattr(self, attr, getattr(self.parent_property, attr)) - self._should_log_debug = log.is_debug_enabled(self.logger) def _init_instance_attribute(self, state, callable_=None): if callable_: @@ -335,7 +332,7 @@ class NoLoader(AbstractRelationLoader): ) return (new_execute, None) -NoLoader.logger = log.class_logger(NoLoader) +log.class_logger(NoLoader) class LazyLoader(AbstractRelationLoader): def init(self): @@ -485,7 +482,7 @@ class LazyLoader(AbstractRelationLoader): return (lazywhere, bind_to_col, equated_columns) _create_lazy_clause = classmethod(_create_lazy_clause) -LazyLoader.logger = log.class_logger(LazyLoader) +log.class_logger(LazyLoader) class LoadLazyAttribute(object): """serializable loader object used by LazyLoader""" @@ -743,7 +740,7 @@ class EagerLoader(AbstractRelationLoader): self.logger.debug("%s degrading to lazy loader" % self) return self.parent_property._get_strategy(LazyLoader).create_row_processor(context, path, mapper, row, adapter) -EagerLoader.logger = log.class_logger(EagerLoader) +log.class_logger(EagerLoader) class EagerLazyOption(StrategizedOption): def __init__(self, key, lazy=True, chained=False, mapper=None): diff --git a/lib/sqlalchemy/orm/unitofwork.py b/lib/sqlalchemy/orm/unitofwork.py index 2b5b8ae1f..f4d2b51bd 100644 --- a/lib/sqlalchemy/orm/unitofwork.py +++ b/lib/sqlalchemy/orm/unitofwork.py @@ -85,8 +85,6 @@ def register_attribute(class_, key, *args, **kwargs): return attributes.register_attribute(class_, key, *args, **kwargs) - - class UOWTransaction(object): """Handles the details of organizing and executing transaction tasks during a UnitOfWork object's flush() operation. @@ -111,9 +109,7 @@ class UOWTransaction(object): # dictionary used by external actors to store arbitrary state # information. self.attributes = {} - - self.logger = log.instance_logger(self, echoflag=session.echo_uow) - + def get_attribute_history(self, state, key, passive=True): hashkey = ("history", state, key) @@ -313,6 +309,8 @@ class UOWTransaction(object): self.logger.debug("Dependency sort:\n"+ str(ret)) return ret +log.class_logger(UOWTransaction) + class UOWTask(object): """Represents all of the objects in the UOWTransaction which correspond to a particular mapper. diff --git a/test/orm/inheritance/polymorph2.py b/test/orm/inheritance/polymorph2.py index 6e9cf305e..2dec5a86b 100644 --- a/test/orm/inheritance/polymorph2.py +++ b/test/orm/inheritance/polymorph2.py @@ -692,7 +692,7 @@ class GenerativeTest(TestBase, AssertsExecutionResults): manager_mapper = mapper(Manager, managers, inherits=person_mapper, polymorphic_identity='manager') car_mapper = mapper(Car, cars, properties= {'employee':relation(person_mapper), 'status':relation(status_mapper)}) - session = create_session(echo_uow=False) + session = create_session() active = Status(name="active") dead = Status(name="dead") |