- logging scale-back; the echo_uow flag on Session is deprecated, and unit of work logging is now

class level like all the other logging.
- trimmed back the logging API, centralized class_logger() as the single point of configuration for
logging, removed per-instance logging checks from ORM.
- Engine and Pool logging remain at the instance level.  The modulus of "instance ids" has been upped
to 65535.  I'd like to remove the modulus altogether but I do see a couple of users each month
calling create_engine() on a per-request basis, an incorrect practice but I'd rather their applications
don't just run out of memory.

8 files changed, 37 insertions, 44 deletions

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.