[CalendarServer-changes] [11732] CalendarServer/trunk

source_changes at macosforge.org source_changes at macosforge.org
Tue Sep 17 16:08:55 PDT 2013


Revision: 11732
          http://trac.calendarserver.org//changeset/11732
Author:   glyph at apple.com
Date:     2013-09-17 16:08:55 -0700 (Tue, 17 Sep 2013)
Log Message:
-----------
Merge in log and adbapi coding-standard cleanups.

Modified Paths:
--------------
    CalendarServer/trunk/twext/enterprise/adbapi2.py
    CalendarServer/trunk/twext/enterprise/ienterprise.py
    CalendarServer/trunk/twext/python/log.py
    CalendarServer/trunk/twext/python/test/test_log.py

Property Changed:
----------------
    CalendarServer/trunk/


Property changes on: CalendarServer/trunk
___________________________________________________________________
Modified: svn:mergeinfo
   - /CalDAVTester/trunk:11193-11198
/CalendarServer/branches/config-separation:4379-4443
/CalendarServer/branches/egg-info-351:4589-4625
/CalendarServer/branches/generic-sqlstore:6167-6191
/CalendarServer/branches/new-store:5594-5934
/CalendarServer/branches/new-store-no-caldavfile:5911-5935
/CalendarServer/branches/new-store-no-caldavfile-2:5936-5981
/CalendarServer/branches/release/CalendarServer-4.3-dev:10180-10190,10192
/CalendarServer/branches/users/cdaboo/batchupload-6699:6700-7198
/CalendarServer/branches/users/cdaboo/cached-subscription-calendars-5692:5693-5702
/CalendarServer/branches/users/cdaboo/component-set-fixes:8130-8346
/CalendarServer/branches/users/cdaboo/directory-cache-on-demand-3627:3628-3644
/CalendarServer/branches/users/cdaboo/fix-no-ischedule:11612
/CalendarServer/branches/users/cdaboo/implicituidrace:8137-8141
/CalendarServer/branches/users/cdaboo/ischedule-dkim:9747-9979
/CalendarServer/branches/users/cdaboo/managed-attachments:9985-10145
/CalendarServer/branches/users/cdaboo/more-sharing-5591:5592-5601
/CalendarServer/branches/users/cdaboo/partition-4464:4465-4957
/CalendarServer/branches/users/cdaboo/pods:7297-7377
/CalendarServer/branches/users/cdaboo/pycalendar:7085-7206
/CalendarServer/branches/users/cdaboo/pycard:7227-7237
/CalendarServer/branches/users/cdaboo/queued-attendee-refreshes:7740-8287
/CalendarServer/branches/users/cdaboo/relative-config-paths-5070:5071-5105
/CalendarServer/branches/users/cdaboo/shared-calendars-5187:5188-5440
/CalendarServer/branches/users/cdaboo/store-scheduling:10876-11129
/CalendarServer/branches/users/cdaboo/timezones:7443-7699
/CalendarServer/branches/users/cdaboo/txn-debugging:8730-8743
/CalendarServer/branches/users/gaya/sharedgroups-3:11088-11204
/CalendarServer/branches/users/glyph/always-abort-txn-on-error:9958-9969
/CalendarServer/branches/users/glyph/case-insensitive-uid:8772-8805
/CalendarServer/branches/users/glyph/conn-limit:6574-6577
/CalendarServer/branches/users/glyph/contacts-server-merge:4971-5080
/CalendarServer/branches/users/glyph/dalify:6932-7023
/CalendarServer/branches/users/glyph/db-reconnect:6824-6876
/CalendarServer/branches/users/glyph/deploybuild:7563-7572
/CalendarServer/branches/users/glyph/digest-auth-redux:10624-10635
/CalendarServer/branches/users/glyph/disable-quota:7718-7727
/CalendarServer/branches/users/glyph/dont-start-postgres:6592-6614
/CalendarServer/branches/users/glyph/enforce-max-requests:11640-11643
/CalendarServer/branches/users/glyph/hang-fix:11465-11491
/CalendarServer/branches/users/glyph/imip-and-admin-html:7866-7984
/CalendarServer/branches/users/glyph/ipv6-client:9054-9105
/CalendarServer/branches/users/glyph/launchd-wrapper-bis:11413-11436
/CalendarServer/branches/users/glyph/linux-tests:6893-6900
/CalendarServer/branches/users/glyph/migrate-merge:8690-8713
/CalendarServer/branches/users/glyph/misc-portability-fixes:7365-7374
/CalendarServer/branches/users/glyph/more-deferreds-6:6322-6368
/CalendarServer/branches/users/glyph/more-deferreds-7:6369-6445
/CalendarServer/branches/users/glyph/multiget-delete:8321-8330
/CalendarServer/branches/users/glyph/new-export:7444-7485
/CalendarServer/branches/users/glyph/one-home-list-api:10048-10073
/CalendarServer/branches/users/glyph/oracle:7106-7155
/CalendarServer/branches/users/glyph/oracle-nulls:7340-7351
/CalendarServer/branches/users/glyph/other-html:8062-8091
/CalendarServer/branches/users/glyph/parallel-sim:8240-8251
/CalendarServer/branches/users/glyph/parallel-upgrade:8376-8400
/CalendarServer/branches/users/glyph/parallel-upgrade_to_1:8571-8583
/CalendarServer/branches/users/glyph/q:9560-9688
/CalendarServer/branches/users/glyph/queue-locking-and-timing:10204-10289
/CalendarServer/branches/users/glyph/quota:7604-7637
/CalendarServer/branches/users/glyph/sendfdport:5388-5424
/CalendarServer/branches/users/glyph/shared-pool-fixes:8436-8443
/CalendarServer/branches/users/glyph/shared-pool-take2:8155-8174
/CalendarServer/branches/users/glyph/sharedpool:6490-6550
/CalendarServer/branches/users/glyph/sharing-api:9192-9205
/CalendarServer/branches/users/glyph/skip-lonely-vtimezones:8524-8535
/CalendarServer/branches/users/glyph/sql-store:5929-6073
/CalendarServer/branches/users/glyph/start-service-start-loop:11060-11065
/CalendarServer/branches/users/glyph/subtransactions:7248-7258
/CalendarServer/branches/users/glyph/table-alias:8651-8664
/CalendarServer/branches/users/glyph/uidexport:7673-7676
/CalendarServer/branches/users/glyph/unshare-when-access-revoked:10562-10595
/CalendarServer/branches/users/glyph/use-system-twisted:5084-5149
/CalendarServer/branches/users/glyph/uuid-normalize:9268-9296
/CalendarServer/branches/users/glyph/warning-cleanups:11347-11357
/CalendarServer/branches/users/glyph/xattrs-from-files:7757-7769
/CalendarServer/branches/users/sagen/applepush:8126-8184
/CalendarServer/branches/users/sagen/inboxitems:7380-7381
/CalendarServer/branches/users/sagen/locations-resources:5032-5051
/CalendarServer/branches/users/sagen/locations-resources-2:5052-5061
/CalendarServer/branches/users/sagen/purge_old_events:6735-6746
/CalendarServer/branches/users/sagen/resource-delegates-4038:4040-4067
/CalendarServer/branches/users/sagen/resource-delegates-4066:4068-4075
/CalendarServer/branches/users/sagen/resources-2:5084-5093
/CalendarServer/branches/users/sagen/testing:10827-10851,10853-10855
/CalendarServer/branches/users/wsanchez/transations:5515-5593
   + /CalDAVTester/trunk:11193-11198
/CalendarServer/branches/config-separation:4379-4443
/CalendarServer/branches/egg-info-351:4589-4625
/CalendarServer/branches/generic-sqlstore:6167-6191
/CalendarServer/branches/new-store:5594-5934
/CalendarServer/branches/new-store-no-caldavfile:5911-5935
/CalendarServer/branches/new-store-no-caldavfile-2:5936-5981
/CalendarServer/branches/release/CalendarServer-4.3-dev:10180-10190,10192
/CalendarServer/branches/users/cdaboo/batchupload-6699:6700-7198
/CalendarServer/branches/users/cdaboo/cached-subscription-calendars-5692:5693-5702
/CalendarServer/branches/users/cdaboo/component-set-fixes:8130-8346
/CalendarServer/branches/users/cdaboo/directory-cache-on-demand-3627:3628-3644
/CalendarServer/branches/users/cdaboo/fix-no-ischedule:11612
/CalendarServer/branches/users/cdaboo/implicituidrace:8137-8141
/CalendarServer/branches/users/cdaboo/ischedule-dkim:9747-9979
/CalendarServer/branches/users/cdaboo/managed-attachments:9985-10145
/CalendarServer/branches/users/cdaboo/more-sharing-5591:5592-5601
/CalendarServer/branches/users/cdaboo/partition-4464:4465-4957
/CalendarServer/branches/users/cdaboo/pods:7297-7377
/CalendarServer/branches/users/cdaboo/pycalendar:7085-7206
/CalendarServer/branches/users/cdaboo/pycard:7227-7237
/CalendarServer/branches/users/cdaboo/queued-attendee-refreshes:7740-8287
/CalendarServer/branches/users/cdaboo/relative-config-paths-5070:5071-5105
/CalendarServer/branches/users/cdaboo/shared-calendars-5187:5188-5440
/CalendarServer/branches/users/cdaboo/store-scheduling:10876-11129
/CalendarServer/branches/users/cdaboo/timezones:7443-7699
/CalendarServer/branches/users/cdaboo/txn-debugging:8730-8743
/CalendarServer/branches/users/gaya/sharedgroups-3:11088-11204
/CalendarServer/branches/users/glyph/always-abort-txn-on-error:9958-9969
/CalendarServer/branches/users/glyph/case-insensitive-uid:8772-8805
/CalendarServer/branches/users/glyph/conn-limit:6574-6577
/CalendarServer/branches/users/glyph/contacts-server-merge:4971-5080
/CalendarServer/branches/users/glyph/dalify:6932-7023
/CalendarServer/branches/users/glyph/db-reconnect:6824-6876
/CalendarServer/branches/users/glyph/deploybuild:7563-7572
/CalendarServer/branches/users/glyph/digest-auth-redux:10624-10635
/CalendarServer/branches/users/glyph/disable-quota:7718-7727
/CalendarServer/branches/users/glyph/dont-start-postgres:6592-6614
/CalendarServer/branches/users/glyph/enforce-max-requests:11640-11643
/CalendarServer/branches/users/glyph/hang-fix:11465-11491
/CalendarServer/branches/users/glyph/imip-and-admin-html:7866-7984
/CalendarServer/branches/users/glyph/ipv6-client:9054-9105
/CalendarServer/branches/users/glyph/launchd-wrapper-bis:11413-11436
/CalendarServer/branches/users/glyph/linux-tests:6893-6900
/CalendarServer/branches/users/glyph/log-cleanups:11691-11731
/CalendarServer/branches/users/glyph/migrate-merge:8690-8713
/CalendarServer/branches/users/glyph/misc-portability-fixes:7365-7374
/CalendarServer/branches/users/glyph/more-deferreds-6:6322-6368
/CalendarServer/branches/users/glyph/more-deferreds-7:6369-6445
/CalendarServer/branches/users/glyph/multiget-delete:8321-8330
/CalendarServer/branches/users/glyph/new-export:7444-7485
/CalendarServer/branches/users/glyph/one-home-list-api:10048-10073
/CalendarServer/branches/users/glyph/oracle:7106-7155
/CalendarServer/branches/users/glyph/oracle-nulls:7340-7351
/CalendarServer/branches/users/glyph/other-html:8062-8091
/CalendarServer/branches/users/glyph/parallel-sim:8240-8251
/CalendarServer/branches/users/glyph/parallel-upgrade:8376-8400
/CalendarServer/branches/users/glyph/parallel-upgrade_to_1:8571-8583
/CalendarServer/branches/users/glyph/q:9560-9688
/CalendarServer/branches/users/glyph/queue-locking-and-timing:10204-10289
/CalendarServer/branches/users/glyph/quota:7604-7637
/CalendarServer/branches/users/glyph/sendfdport:5388-5424
/CalendarServer/branches/users/glyph/shared-pool-fixes:8436-8443
/CalendarServer/branches/users/glyph/shared-pool-take2:8155-8174
/CalendarServer/branches/users/glyph/sharedpool:6490-6550
/CalendarServer/branches/users/glyph/sharing-api:9192-9205
/CalendarServer/branches/users/glyph/skip-lonely-vtimezones:8524-8535
/CalendarServer/branches/users/glyph/sql-store:5929-6073
/CalendarServer/branches/users/glyph/start-service-start-loop:11060-11065
/CalendarServer/branches/users/glyph/subtransactions:7248-7258
/CalendarServer/branches/users/glyph/table-alias:8651-8664
/CalendarServer/branches/users/glyph/uidexport:7673-7676
/CalendarServer/branches/users/glyph/unshare-when-access-revoked:10562-10595
/CalendarServer/branches/users/glyph/use-system-twisted:5084-5149
/CalendarServer/branches/users/glyph/uuid-normalize:9268-9296
/CalendarServer/branches/users/glyph/warning-cleanups:11347-11357
/CalendarServer/branches/users/glyph/xattrs-from-files:7757-7769
/CalendarServer/branches/users/sagen/applepush:8126-8184
/CalendarServer/branches/users/sagen/inboxitems:7380-7381
/CalendarServer/branches/users/sagen/locations-resources:5032-5051
/CalendarServer/branches/users/sagen/locations-resources-2:5052-5061
/CalendarServer/branches/users/sagen/purge_old_events:6735-6746
/CalendarServer/branches/users/sagen/resource-delegates-4038:4040-4067
/CalendarServer/branches/users/sagen/resource-delegates-4066:4068-4075
/CalendarServer/branches/users/sagen/resources-2:5084-5093
/CalendarServer/branches/users/sagen/testing:10827-10851,10853-10855
/CalendarServer/branches/users/wsanchez/transations:5515-5593

Modified: CalendarServer/trunk/twext/enterprise/adbapi2.py
===================================================================
--- CalendarServer/trunk/twext/enterprise/adbapi2.py	2013-09-17 23:02:36 UTC (rev 11731)
+++ CalendarServer/trunk/twext/enterprise/adbapi2.py	2013-09-17 23:08:55 UTC (rev 11732)
@@ -18,10 +18,10 @@
 """
 Asynchronous multi-process connection pool.
 
-This is similar to L{twisted.enterprise.adbapi}, but can hold a transaction (and
-thereby a thread) open across multiple asynchronous operations, rather than
-forcing the transaction to be completed entirely in a thread and/or entirely in
-a single SQL statement.
+This is similar to L{twisted.enterprise.adbapi}, but can hold a transaction
+(and thereby a thread) open across multiple asynchronous operations, rather
+than forcing the transaction to be completed entirely in a thread and/or
+entirely in a single SQL statement.
 
 Also, this module includes an AMP protocol for multiplexing connections through
 a single choke-point host.  This is not currently in use, however, as AMP needs
@@ -118,6 +118,7 @@
     return derived
 
 
+
 def _deriveQueryEnded(cursor, derived):
     """
     A query which involved some L{IDerivedParameter}s just ended.  Execute any
@@ -142,6 +143,8 @@
     """
     implements(IAsyncTransaction)
 
+    noisy = False
+
     def __init__(self, pool, threadHolder, connection, cursor):
         self._pool       = pool
         self._completed  = "idle"
@@ -169,33 +172,31 @@
         """
         Execute the given SQL on a thread, using a DB-API 2.0 cursor.
 
-        This method is invoked internally on a non-reactor thread, one dedicated
-        to and associated with the current cursor.  It executes the given SQL,
-        re-connecting first if necessary, re-cycling the old connection if
-        necessary, and then, if there are results from the statement (as
-        determined by the DB-API 2.0 'description' attribute) it will fetch all
-        the rows and return them, leaving them to be relayed to
+        This method is invoked internally on a non-reactor thread, one
+        dedicated to and associated with the current cursor.  It executes the
+        given SQL, re-connecting first if necessary, re-cycling the old
+        connection if necessary, and then, if there are results from the
+        statement (as determined by the DB-API 2.0 'description' attribute) it
+        will fetch all the rows and return them, leaving them to be relayed to
         L{_ConnectedTxn.execSQL} via the L{ThreadHolder}.
 
         The rules for possibly reconnecting automatically are: if this is the
         very first statement being executed in this transaction, and an error
         occurs in C{execute}, close the connection and try again.  We will
-        ignore any errors from C{close()} (or C{rollback()}) and log them during
-        this process.  This is OK because adbapi2 always enforces transaction
-        discipline: connections are never in autocommit mode, so if the first
-        statement in a transaction fails, nothing can have happened to the
-        database; as per the ADBAPI spec, a lost connection is a rolled-back
-        transaction.  In the cases where some databases fail to enforce
-        transaction atomicity (i.e. schema manipulations), re-executing the same
-        statement will result, at worst, in a spurious and harmless error (like
-        "table already exists"), not corruption.
+        ignore any errors from C{close()} (or C{rollback()}) and log them
+        during this process.  This is OK because adbapi2 always enforces
+        transaction discipline: connections are never in autocommit mode, so if
+        the first statement in a transaction fails, nothing can have happened
+        to the database; as per the ADBAPI spec, a lost connection is a
+        rolled-back transaction.  In the cases where some databases fail to
+        enforce transaction atomicity (i.e.  schema manipulations),
+        re-executing the same statement will result, at worst, in a spurious
+        and harmless error (like "table already exists"), not corruption.
 
         @param sql: The SQL string to execute.
-
         @type sql: C{str}
 
         @param args: The bind parameters to pass to adbapi, if any.
-
         @type args: C{list} or C{None}
 
         @param raiseOnZeroRowCount: If specified, an exception to raise when no
@@ -203,7 +204,6 @@
 
         @return: all the rows that resulted from execution of the given C{sql},
             or C{None}, if the statement is one which does not produce results.
-
         @rtype: C{list} of C{tuple}, or C{NoneType}
 
         @raise Exception: this function may raise any exception raised by the
@@ -234,9 +234,9 @@
             # happen in the transaction, then the connection has probably gone
             # bad in the meanwhile, and we should try again.
             if wasFirst:
-                # Report the error before doing anything else, since doing other
-                # things may cause the traceback stack to be eliminated if they
-                # raise exceptions (even internally).
+                # Report the error before doing anything else, since doing
+                # other things may cause the traceback stack to be eliminated
+                # if they raise exceptions (even internally).
                 log.err(
                     Failure(),
                     "Exception from execute() on first statement in "
@@ -292,11 +292,9 @@
             return None
 
 
-    noisy = False
-
     def execSQL(self, *args, **kw):
         result = self._holder.submit(
-            lambda : self._reallyExecSQL(*args, **kw)
+            lambda: self._reallyExecSQL(*args, **kw)
         )
         if self.noisy:
             def reportResult(results):
@@ -305,7 +303,7 @@
                     "SQL: %r %r" % (args, kw),
                     "Results: %r" % (results,),
                     "",
-                    ]))
+                ]))
                 return results
             result.addBoth(reportResult)
         return result
@@ -328,8 +326,8 @@
             self._completed = "ended"
             def reallySomething():
                 """
-                Do the database work and set appropriate flags.  Executed in the
-                cursor thread.
+                Do the database work and set appropriate flags.  Executed in
+                the cursor thread.
                 """
                 if self._cursor is None or self._first:
                     return
@@ -384,8 +382,8 @@
 class _NoTxn(object):
     """
     An L{IAsyncTransaction} that indicates a local failure before we could even
-    communicate any statements (or possibly even any connection attempts) to the
-    server.
+    communicate any statements (or possibly even any connection attempts) to
+    the server.
     """
     implements(IAsyncTransaction)
 
@@ -401,7 +399,6 @@
         """
         return fail(ConnectionError(self.reason))
 
-
     execSQL = _everything
     commit  = _everything
     abort   = _everything
@@ -411,9 +408,9 @@
 class _WaitingTxn(object):
     """
     A L{_WaitingTxn} is an implementation of L{IAsyncTransaction} which cannot
-    yet actually execute anything, so it waits and spools SQL requests for later
-    execution.  When a L{_ConnectedTxn} becomes available later, it can be
-    unspooled onto that.
+    yet actually execute anything, so it waits and spools SQL requests for
+    later execution.  When a L{_ConnectedTxn} becomes available later, it can
+    be unspooled onto that.
     """
 
     implements(IAsyncTransaction)
@@ -639,9 +636,9 @@
             d = self._currentBlock._startExecuting()
             d.addCallback(self._finishExecuting)
         elif self._blockedQueue is not None:
-            # If there aren't any pending blocks any more, and there are spooled
-            # statements that aren't part of a block, unspool all the statements
-            # that have been held up until this point.
+            # If there aren't any pending blocks any more, and there are
+            # spooled statements that aren't part of a block, unspool all the
+            # statements that have been held up until this point.
             bq = self._blockedQueue
             self._blockedQueue = None
             bq._unspool(self)
@@ -649,8 +646,8 @@
 
     def _finishExecuting(self, result):
         """
-        The active block just finished executing.  Clear it and see if there are
-        more blocks to execute, or if all the blocks are done and we should
+        The active block just finished executing.  Clear it and see if there
+        are more blocks to execute, or if all the blocks are done and we should
         execute any queued free statements.
         """
         self._currentBlock = None
@@ -659,8 +656,9 @@
 
     def commit(self):
         if self._blockedQueue is not None:
-            # We're in the process of executing a block of commands.  Wait until
-            # they're done.  (Commit will be repeated in _checkNextBlock.)
+            # We're in the process of executing a block of commands.  Wait
+            # until they're done.  (Commit will be repeated in
+            # _checkNextBlock.)
             return self._blockedQueue.commit()
         def reallyCommit():
             self._markComplete()
@@ -785,9 +783,9 @@
 
         @param raiseOnZeroRowCount: see L{IAsyncTransaction.execSQL}
 
-        @param track: an internal parameter; was this called by application code
-            or as part of unspooling some previously-queued requests?  True if
-            application code, False if unspooling.
+        @param track: an internal parameter; was this called by application
+            code or as part of unspooling some previously-queued requests?
+            True if application code, False if unspooling.
         """
         if track and self._ended:
             raise AlreadyFinishedError()
@@ -970,8 +968,8 @@
         super(ConnectionPool, self).stopService()
         self._stopping = True
 
-        # Phase 1: Cancel any transactions that are waiting so they won't try to
-        # eagerly acquire new connections as they flow into the free-list.
+        # Phase 1: Cancel any transactions that are waiting so they won't try
+        # to eagerly acquire new connections as they flow into the free-list.
         while self._waiting:
             waiting = self._waiting[0]
             waiting._stopWaiting()
@@ -991,10 +989,10 @@
         # ThreadHolders.
         while self._free:
             # Releasing a L{_ConnectedTxn} doesn't automatically recycle it /
-            # remove it the way aborting a _SingleTxn does, so we need to .pop()
-            # here.  L{_ConnectedTxn.stop} really shouldn't be able to fail, as
-            # it's just stopping the thread, and the holder's stop() is
-            # independently submitted from .abort() / .close().
+            # remove it the way aborting a _SingleTxn does, so we need to
+            # .pop() here.  L{_ConnectedTxn.stop} really shouldn't be able to
+            # fail, as it's just stopping the thread, and the holder's stop()
+            # is independently submitted from .abort() / .close().
             yield self._free.pop()._releaseConnection()
 
         tp = self.reactor.getThreadPool()
@@ -1011,8 +1009,8 @@
     def connection(self, label="<unlabeled>"):
         """
         Find and immediately return an L{IAsyncTransaction} object.  Execution
-        of statements, commit and abort on that transaction may be delayed until
-        a real underlying database connection is available.
+        of statements, commit and abort on that transaction may be delayed
+        until a real underlying database connection is available.
 
         @return: an L{IAsyncTransaction}
         """
@@ -1158,6 +1156,7 @@
     def toString(self, inObject):
         return dumps(inObject)
 
+
     def fromString(self, inString):
         return loads(inString)
 
@@ -1193,8 +1192,7 @@
                 if f.type in command.errors:
                     returnValue(f)
                 else:
-                    log.err(Failure(),
-                            "shared database connection pool encountered error")
+                    log.err(Failure(), "shared database connection pool error")
                     raise FailsafeException()
             else:
                 returnValue(val)
@@ -1286,6 +1284,7 @@
     """
 
 
+
 class ConnectionPoolConnection(AMP):
     """
     A L{ConnectionPoolConnection} is a single connection to a
@@ -1402,7 +1401,8 @@
     A client which can execute SQL.
     """
 
-    def __init__(self, dialect=POSTGRES_DIALECT, paramstyle=DEFAULT_PARAM_STYLE):
+    def __init__(self, dialect=POSTGRES_DIALECT,
+                 paramstyle=DEFAULT_PARAM_STYLE):
         # See DEFAULT_PARAM_STYLE FIXME above.
         super(ConnectionPoolClient, self).__init__()
         self._nextID    = count().next
@@ -1428,8 +1428,8 @@
         """
         Create a new networked provider of L{IAsyncTransaction}.
 
-        (This will ultimately call L{ConnectionPool.connection} on the other end
-        of the wire.)
+        (This will ultimately call L{ConnectionPool.connection} on the other
+        end of the wire.)
 
         @rtype: L{IAsyncTransaction}
         """
@@ -1478,12 +1478,12 @@
         @param derived: either C{None} or a C{list} of L{IDerivedParameter}
             providers initially passed into the C{execSQL} that started this
             query.  The values of these object swill mutate the original input
-            parameters to resemble them.  Although L{IDerivedParameter.preQuery}
-            and L{IDerivedParameter.postQuery} are invoked on the other end of
-            the wire, the local objects will be made to appear as though they
-            were called here.
+            parameters to resemble them.  Although
+            L{IDerivedParameter.preQuery} and L{IDerivedParameter.postQuery}
+            are invoked on the other end of the wire, the local objects will be
+            made to appear as though they were called here.
 
-        @param noneResult: should the result of the query be C{None} (i.e. did
+        @param noneResult: should the result of the query be C{None} (i.e.  did
             it not have a C{description} on the cursor).
         """
         if noneResult and not self.results:
@@ -1492,8 +1492,8 @@
             results = self.results
         if derived is not None:
             # 1) Bleecchh.
-            # 2) FIXME: add some direct tests in test_adbapi2, the unit test for
-            # this crosses some abstraction boundaries so it's a little
+            # 2) FIXME: add some direct tests in test_adbapi2, the unit test
+            # for this crosses some abstraction boundaries so it's a little
             # integration-y and in the tests for twext.enterprise.dal
             for remote, local in zip(derived, self._deriveDerived()):
                 local.__dict__ = remote.__dict__
@@ -1519,8 +1519,8 @@
 class _NetTransaction(_CommitAndAbortHooks):
     """
     A L{_NetTransaction} is an L{AMP}-protocol-based provider of the
-    L{IAsyncTransaction} interface.  It sends SQL statements, query results, and
-    commit/abort commands via an AMP socket to a pooling process.
+    L{IAsyncTransaction} interface.  It sends SQL statements, query results,
+    and commit/abort commands via an AMP socket to a pooling process.
     """
 
     implements(IAsyncTransaction)
@@ -1562,7 +1562,8 @@
             args = []
         client = self._client
         queryID = str(client._nextID())
-        query = client._queries[queryID] = _Query(sql, raiseOnZeroRowCount, args)
+        query = client._queries[queryID] = _Query(sql, raiseOnZeroRowCount,
+                                                  args)
         result = (
             client.callRemote(
                 ExecSQL, queryID=queryID, sql=sql, args=args,
@@ -1617,6 +1618,7 @@
             self.abort().addErrback(shush)
 
 
+
 class _NetCommandBlock(object):
     """
     Net command block.
@@ -1650,10 +1652,10 @@
         """
         Execute some SQL on this command block.
         """
-        if  (self._ended or
-             self._transaction._completed and
-             not self._transaction._committing or
-             self._transaction._committed):
+        if (
+            self._ended or self._transaction._completed and
+            not self._transaction._committing or self._transaction._committed
+        ):
             raise AlreadyFinishedError()
         return self._transaction.execSQL(sql, args, raiseOnZeroRowCount,
                                          self._blockID)
@@ -1670,4 +1672,3 @@
             EndBlock, blockID=self._blockID,
             transactionID=self._transaction._transactionID
         )
-

Modified: CalendarServer/trunk/twext/enterprise/ienterprise.py
===================================================================
--- CalendarServer/trunk/twext/enterprise/ienterprise.py	2013-09-17 23:02:36 UTC (rev 11731)
+++ CalendarServer/trunk/twext/enterprise/ienterprise.py	2013-09-17 23:08:55 UTC (rev 11732)
@@ -67,7 +67,6 @@
         A copy of the 'paramstyle' attribute from a DB-API 2.0 module.
         """)
 
-
     dialect = Attribute(
         """
         A copy of the 'dialect' attribute from the connection pool.  One of the
@@ -100,8 +99,8 @@
     """
     Asynchronous execution of SQL.
 
-    Note that there is no {begin()} method; if an L{IAsyncTransaction} exists at
-    all, it is assumed to have been started.
+    Note that there is no C{begin()} method; if an L{IAsyncTransaction} exists
+    at all, it is assumed to have been started.
     """
 
     def commit():
@@ -167,17 +166,18 @@
 
         This is useful when using database-specific features such as
         sub-transactions where order of execution is importnat, but where
-        application code may need to perform I/O to determine what SQL, exactly,
-        it wants to execute.  Consider this fairly contrived example for an
-        imaginary database::
+        application code may need to perform I/O to determine what SQL,
+        exactly, it wants to execute.  Consider this fairly contrived example
+        for an imaginary database::
 
             def storeWebPage(url, block):
                 block.execSQL("BEGIN SUB TRANSACTION")
                 got = getPage(url)
                 def gotPage(data):
-                    block.execSQL("INSERT INTO PAGES (TEXT) VALUES (?)", [data])
+                    block.execSQL("INSERT INTO PAGES (TEXT) VALUES (?)",
+                                  [data])
                     block.execSQL("INSERT INTO INDEX (TOKENS) VALUES (?)",
-                                 [tokenize(data)])
+                                  [tokenize(data)])
                     lastStmt = block.execSQL("END SUB TRANSACTION")
                     block.end()
                     return lastStmt
@@ -187,12 +187,12 @@
                             lambda x: txn.commit(), lambda f: txn.abort()
                           )
 
-        This fires off all the C{getPage} requests in parallel, and prepares all
-        the necessary SQL immediately as the results arrive, but executes those
-        statements in order.  In the above example, this makes sure to store the
-        page and its tokens together, another use for this might be to store a
-        computed aggregate (such as a sum) at a particular point in a
-        transaction, without sacrificing parallelism.
+        This fires off all the C{getPage} requests in parallel, and prepares
+        all the necessary SQL immediately as the results arrive, but executes
+        those statements in order.  In the above example, this makes sure to
+        store the page and its tokens together, another use for this might be
+        to store a computed aggregate (such as a sum) at a particular point in
+        a transaction, without sacrificing parallelism.
 
         @rtype: L{ICommandBlock}
         """
@@ -208,21 +208,21 @@
 
     def end():
         """
-        End this command block, allowing other commands queued on the underlying
-        transaction to end.
+        End this command block, allowing other commands queued on the
+        underlying transaction to end.
 
         @note: This is I{not} the same as either L{IAsyncTransaction.commit} or
             L{IAsyncTransaction.abort}, since it does not denote success or
             failure; merely that the command block has completed and other
             statements may now be executed.  Since sub-transactions are a
             database-specific feature, they must be implemented at a
-            higher-level than this facility provides (although this facility may
-            be useful in their implementation).  Also note that, unlike either
-            of those methods, this does I{not} return a Deferred: if you want to
-            know when the block has completed, simply add a callback to the last
-            L{ICommandBlock.execSQL} call executed on this L{ICommandBlock}.
-            (This may be changed in a future version for the sake of
-            convenience, however.)
+            higher-level than this facility provides (although this facility
+            may be useful in their implementation).  Also note that, unlike
+            either of those methods, this does I{not} return a Deferred: if you
+            want to know when the block has completed, simply add a callback to
+            the last L{ICommandBlock.execSQL} call executed on this
+            L{ICommandBlock}.  (This may be changed in a future version for the
+            sake of convenience, however.)
         """
 
 
@@ -306,7 +306,8 @@
             L{WorkProposal}
         """
 
+
     def transferProposalCallbacks(self, newQueuer):
         """
         Transfer the registered callbacks to the new queuer.
-        """
\ No newline at end of file
+        """

Modified: CalendarServer/trunk/twext/python/log.py
===================================================================
--- CalendarServer/trunk/twext/python/log.py	2013-09-17 23:02:36 UTC (rev 11731)
+++ CalendarServer/trunk/twext/python/log.py	2013-09-17 23:08:55 UTC (rev 11732)
@@ -34,7 +34,8 @@
         log = Logger()
 
         def oops(self, data):
-            self.log.error("Oops! Invalid data from server: {data!r}", data=data)
+            self.log.error("Oops! Invalid data from server: {data!r}",
+                           data=data)
 
 C{Logger}s have namespaces, for which logging can be configured independently.
 Namespaces may be specified by passing in a C{namespace} argument to L{Logger}
@@ -76,14 +77,16 @@
 from zope.interface import Interface, implementer
 from twisted.python.constants import NamedConstant, Names
 from twisted.python.failure import Failure
-from twisted.python.reflect import safe_str
+from twisted.python.reflect import safe_str, safe_repr
 import twisted.python.log
 from twisted.python.log import msg as twistedLogMessage
 from twisted.python.log import addObserver, removeObserver
 from twisted.python.log import ILogObserver as ILegacyLogObserver
 
+OBSERVER_REMOVED = (
+    "Temporarily removing observer {observer} due to exception: {e}"
+)
 
-
 #
 # Log level definitions
 #
@@ -162,11 +165,11 @@
 # Mappings to Python's logging module
 #
 pythonLogLevelMapping = {
-    LogLevel.debug   : logging.DEBUG,
-    LogLevel.info    : logging.INFO,
-    LogLevel.warn    : logging.WARNING,
-    LogLevel.error   : logging.ERROR,
-   #LogLevel.critical: logging.CRITICAL,
+    LogLevel.debug: logging.DEBUG,
+    LogLevel.info:  logging.INFO,
+    LogLevel.warn:  logging.WARNING,
+    LogLevel.error: logging.ERROR,
+    # LogLevel.critical: logging.CRITICAL,
 }
 
 
@@ -215,12 +218,14 @@
 
 def formatUnformattableEvent(event, error):
     """
-    Formats an event as a L{unicode} that describes the event
-    generically and a formatting error.
+    Formats an event as a L{unicode} that describes the event generically and a
+    formatting error.
 
     @param event: a logging event
+    @type dict: L{dict}
 
     @param error: the formatting error
+    @type error: L{Exception}
 
     @return: a L{unicode}
     """
@@ -230,45 +235,25 @@
             .format(event=event, error=error)
         )
     except BaseException:
-        #
         # Yikes, something really nasty happened.
         #
-        # Try to recover as much formattable data as possible;
-        # hopefully at least the namespace is sane, which will
-        # help you find the offending logger.
-        #
-        try:
-            failure = Failure()
+        # Try to recover as much formattable data as possible; hopefully at
+        # least the namespace is sane, which will help you find the offending
+        # logger.
+        failure = Failure()
 
-            items = []
+        text = ", ".join(" = ".join((safe_repr(key), safe_repr(value)))
+                         for key, value in event.items())
 
-            for key, value in event.items():
-                try:
-                    keyFormatted = u"{key!r}".format(key=key)
-                except BaseException:
-                    keyFormatted = u"<UNFORMATTABLE KEY>"
+        return (
+            u"MESSAGE LOST: unformattable object logged: {error}\n"
+            u"Recoverable data: {text}\n"
+            u"Exception during formatting:\n{failure}"
+            .format(error=safe_repr(error), failure=failure, text=text)
+        )
 
-                try:
-                    valueFormatted = u"{value!r}".format(value=value)
-                except BaseException:
-                    valueFormatted = u"<UNFORMATTABLE VALUE>"
 
-                items.append(" = ".join((keyFormatted, valueFormatted)))
 
-            text = ", ".join(items)
-
-            return (
-                u"MESSAGE LOST: unformattable object logged: {error}\n"
-                u"Recoverable data: {text}\n"
-                u"Exception during formatting:\n{failure}"
-                .format(error=error, failure=failure, text=text)
-            )
-        except BaseException as e:
-            # This should never happen...
-            return u"MESSAGE LOST: unable to recover any data from message: {e}".format(e=e)
-
-
-
 class Logger(object):
     """
     Logging object.
@@ -351,28 +336,24 @@
         @param kwargs: additional keyword parameters to include with
             the event.
         """
-        if level not in LogLevel.iterconstants(): # FIXME: Updated Twisted supports 'in' on constants container
+        # FIXME: Updated Twisted supports 'in' on constants container
+        if level not in LogLevel.iterconstants():
             self.failure(
                 "Got invalid log level {invalidLevel!r} in {logger}.emit().",
                 Failure(InvalidLogLevelError(level)),
-                invalidLevel = level,
-                logger = self,
+                invalidLevel=level,
+                logger=self,
             )
             #level = LogLevel.error
             # FIXME: continue to emit?
             return
 
-        event = kwargs
-        event.update(
-            log_logger    = self,
-            log_level     = level,
-            log_namespace = self.namespace,
-            log_source    = self.source,
-            log_format    = format,
-            log_time      = time.time(),
+        kwargs.update(
+            log_logger=self, log_level=level, log_namespace=self.namespace,
+            log_source=self.source, log_format=format, log_time=time.time(),
         )
 
-        self.publisher(event)
+        self.publisher(kwargs)
 
 
     def failure(self, format, failure=None, level=LogLevel.error, **kwargs):
@@ -388,8 +369,9 @@
 
         or::
 
-            d = deferred_frob(knob)
-            d.addErrback(lambda f: log.failure, "While frobbing {knob}", f, knob=knob)
+            d = deferredFrob(knob)
+            d.addErrback(lambda f: log.failure, "While frobbing {knob}",
+                         f, knob=knob)
 
         @param format: a message format using new-style (PEP 3101)
             formatting.  The logging event (which is a L{dict}) is
@@ -404,7 +386,7 @@
             event.
         """
         if failure is None:
-            failure=Failure()
+            failure = Failure()
 
         self.emit(level, format, log_failure=failure, **kwargs)
 
@@ -453,10 +435,12 @@
             _stuff = Failure(_stuff)
 
         if isinstance(_stuff, Failure):
-            self.newStyleLogger.emit(LogLevel.error, failure=_stuff, why=_why, isError=1, **kwargs)
+            self.newStyleLogger.emit(LogLevel.error, failure=_stuff, why=_why,
+                                     isError=1, **kwargs)
         else:
             # We got called with an invalid _stuff.
-            self.newStyleLogger.emit(LogLevel.error, repr(_stuff), why=_why, isError=1, **kwargs)
+            self.newStyleLogger.emit(LogLevel.error, repr(_stuff), why=_why,
+                                     isError=1, **kwargs)
 
 
 
@@ -482,13 +466,15 @@
 
     setattr(Logger, level.name, log_emit)
 
-for level in LogLevel.iterconstants(): 
-    bindEmit(level)
 
-del level
 
+def _bindLevels():
+    for level in LogLevel.iterconstants():
+        bindEmit(level)
 
+_bindLevels()
 
+
 #
 # Observers
 #
@@ -552,7 +538,7 @@
             pass
 
 
-    def __call__(self, event): 
+    def __call__(self, event):
         for observer in self.observers:
             try:
                 observer(event)
@@ -565,7 +551,7 @@
                 #
                 self.removeObserver(observer)
                 try:
-                    self.log.failure("Temporarily removing observer {observer} due to exception: {e}", observer=observer, e=e)
+                    self.log.failure(OBSERVER_REMOVED, observer=observer, e=e)
                 except BaseException:
                     pass
                 finally:
@@ -738,8 +724,8 @@
         """
         self.legacyObserver = legacyObserver
 
-    
-    def __call__(self, event): 
+
+    def __call__(self, event):
         prefix = "[{log_namespace}#{log_level.name}] ".format(**event)
 
         level = event["log_level"]
@@ -769,7 +755,9 @@
         if "log_failure" in event:
             event["failure"] = event["log_failure"]
             event["isError"] = 1
-            event["why"] = "{prefix}{message}".format(prefix=prefix, message=formatEvent(event))
+            event["why"] = "{prefix}{message}".format(
+                prefix=prefix, message=formatEvent(event)
+            )
 
         self.legacyObserver(**event)
 
@@ -827,7 +815,8 @@
         self.legacyLogObserver = LegacyLogObserver(twistedLogMessage)
         self.filteredPublisher = LogPublisher(self.legacyLogObserver)
         self.levels            = LogLevelFilterPredicate()
-        self.filters           = FilteringLogObserver(self.filteredPublisher, (self.levels,))
+        self.filters           = FilteringLogObserver(self.filteredPublisher,
+                                                      (self.levels,))
         self.rootPublisher     = LogPublisher(self.filters)
 
 
@@ -875,6 +864,7 @@
     def __init__(self, submapping):
         self._submapping = submapping
 
+
     def __getitem__(self, key):
         callit = key.endswith(u"()")
         realKey = key[:-2] if callit else key
@@ -884,6 +874,7 @@
         return value
 
 
+
 def formatWithCall(formatString, mapping):
     """
     Format a string like L{unicode.format}, but:
@@ -943,16 +934,20 @@
             continue
 
         for name, obj in module.__dict__.iteritems():
-            legacyLogger = LegacyLogger(logger=Logger(namespace=module.__name__))
+            newLogger = Logger(namespace=module.__name__)
+            legacyLogger = LegacyLogger(logger=newLogger)
 
             if obj is twisted.python.log:
-                log.info("Replacing Twisted log module object {0} in {1}".format(name, module.__name__))
+                log.info("Replacing Twisted log module object {0} in {1}"
+                         .format(name, module.__name__))
                 setattr(module, name, legacyLogger)
             elif obj is twisted.python.log.msg:
-                log.info("Replacing Twisted log.msg object {0} in {1}".format(name, module.__name__))
+                log.info("Replacing Twisted log.msg object {0} in {1}"
+                         .format(name, module.__name__))
                 setattr(module, name, legacyLogger.msg)
             elif obj is twisted.python.log.err:
-                log.info("Replacing Twisted log.err object {0} in {1}".format(name, module.__name__))
+                log.info("Replacing Twisted log.err object {0} in {1}"
+                         .format(name, module.__name__))
                 setattr(module, name, legacyLogger.err)
 
 

Modified: CalendarServer/trunk/twext/python/test/test_log.py
===================================================================
--- CalendarServer/trunk/twext/python/test/test_log.py	2013-09-17 23:02:36 UTC (rev 11731)
+++ CalendarServer/trunk/twext/python/test/test_log.py	2013-09-17 23:08:55 UTC (rev 11732)
@@ -27,7 +27,7 @@
     Logger, LegacyLogger,
     ILogObserver, LogPublisher, DefaultLogPublisher,
     FilteringLogObserver, PredicateResult,
-    LogLevelFilterPredicate,
+    LogLevelFilterPredicate, OBSERVER_REMOVED
 )
 
 
@@ -59,7 +59,7 @@
             twistedLogging.removeObserver(observer)
 
         self.emitted = {
-            "level" : level,
+            "level":  level,
             "format": format,
             "kwargs": kwargs,
         }
@@ -131,7 +131,8 @@
         """
         self.failUnless(logLevelForNamespace(None), defaultLogLevel)
         self.failUnless(logLevelForNamespace(""), defaultLogLevel)
-        self.failUnless(logLevelForNamespace("rocker.cool.namespace"), defaultLogLevel)
+        self.failUnless(logLevelForNamespace("rocker.cool.namespace"),
+                        defaultLogLevel)
 
 
     def test_setLogLevel(self):
@@ -142,38 +143,49 @@
         setLogLevelForNamespace("twext.web2", LogLevel.debug)
         setLogLevelForNamespace("twext.web2.dav", LogLevel.warn)
 
-        self.assertEquals(logLevelForNamespace(None                        ), LogLevel.error)
-        self.assertEquals(logLevelForNamespace("twisted"                   ), LogLevel.error)
-        self.assertEquals(logLevelForNamespace("twext.web2"                ), LogLevel.debug)
-        self.assertEquals(logLevelForNamespace("twext.web2.dav"            ), LogLevel.warn)
-        self.assertEquals(logLevelForNamespace("twext.web2.dav.test"       ), LogLevel.warn)
-        self.assertEquals(logLevelForNamespace("twext.web2.dav.test1.test2"), LogLevel.warn)
+        self.assertEquals(logLevelForNamespace(None),
+                          LogLevel.error)
+        self.assertEquals(logLevelForNamespace("twisted"),
+                          LogLevel.error)
+        self.assertEquals(logLevelForNamespace("twext.web2"),
+                          LogLevel.debug)
+        self.assertEquals(logLevelForNamespace("twext.web2.dav"),
+                          LogLevel.warn)
+        self.assertEquals(logLevelForNamespace("twext.web2.dav.test"),
+                          LogLevel.warn)
+        self.assertEquals(logLevelForNamespace("twext.web2.dav.test1.test2"),
+                          LogLevel.warn)
 
 
     def test_setInvalidLogLevel(self):
         """
         Can't pass invalid log levels to setLogLevelForNamespace().
         """
-        self.assertRaises(InvalidLogLevelError, setLogLevelForNamespace, "twext.web2", object())
+        self.assertRaises(InvalidLogLevelError, setLogLevelForNamespace,
+                          "twext.web2", object())
 
         # Level must be a constant, not the name of a constant
-        self.assertRaises(InvalidLogLevelError, setLogLevelForNamespace, "twext.web2", "debug")
+        self.assertRaises(InvalidLogLevelError, setLogLevelForNamespace,
+                          "twext.web2", "debug")
 
 
     def test_clearLogLevels(self):
         """
         Clearing log levels.
         """
-        setLogLevelForNamespace("twext.web2"    , LogLevel.debug)
+        setLogLevelForNamespace("twext.web2", LogLevel.debug)
         setLogLevelForNamespace("twext.web2.dav", LogLevel.error)
 
         clearLogLevels()
 
-        self.assertEquals(logLevelForNamespace("twisted"                   ), defaultLogLevel)
-        self.assertEquals(logLevelForNamespace("twext.web2"                ), defaultLogLevel)
-        self.assertEquals(logLevelForNamespace("twext.web2.dav"            ), defaultLogLevel)
-        self.assertEquals(logLevelForNamespace("twext.web2.dav.test"       ), defaultLogLevel)
-        self.assertEquals(logLevelForNamespace("twext.web2.dav.test1.test2"), defaultLogLevel)
+        self.assertEquals(logLevelForNamespace("twisted"), defaultLogLevel)
+        self.assertEquals(logLevelForNamespace("twext.web2"), defaultLogLevel)
+        self.assertEquals(logLevelForNamespace("twext.web2.dav"),
+                          defaultLogLevel)
+        self.assertEquals(logLevelForNamespace("twext.web2.dav.test"),
+                          defaultLogLevel)
+        self.assertEquals(logLevelForNamespace("twext.web2.dav.test1.test2"),
+                          defaultLogLevel)
 
 
     def test_namespace_default(self):
@@ -277,53 +289,51 @@
 
 
     def test_formatUnformattableEventWithUnformattableKey(self):
-         """
-         Formatting an unformattable event that has an unformattable key.
-         """
-         event = {
-             "log_format": "{evil()}",
-             "evil": lambda: 1/0,
-             Gurk(): "gurk",
-         }
-         result = formatEvent(event)
+        """
+        Formatting an unformattable event that has an unformattable key.
+        """
+        event = {
+            "log_format": "{evil()}",
+            "evil": lambda: 1/0,
+            Unformattable(): "gurk",
+        }
+        result = formatEvent(event)
+        self.assertIn("MESSAGE LOST: unformattable object logged:", result)
+        self.assertIn("Recoverable data:", result)
+        self.assertIn("Exception during formatting:", result)
 
-         self.assertIn("MESSAGE LOST: unformattable object logged:", result)
-         self.assertIn("Recoverable data:", result)
-         self.assertIn("Exception during formatting:", result)
 
-
     def test_formatUnformattableEventWithUnformattableValue(self):
-         """
-         Formatting an unformattable event that has an unformattable value.
-         """
-         event = dict(
-             log_format="{evil()}",
-             evil=lambda: 1/0,
-             gurk=Gurk(),
-         )
-         result = formatEvent(event)
+        """
+        Formatting an unformattable event that has an unformattable value.
+        """
+        event = dict(
+            log_format="{evil()}",
+            evil=lambda: 1/0,
+            gurk=Unformattable(),
+        )
+        result = formatEvent(event)
+        self.assertIn("MESSAGE LOST: unformattable object logged:", result)
+        self.assertIn("Recoverable data:", result)
+        self.assertIn("Exception during formatting:", result)
 
-         self.assertIn("MESSAGE LOST: unformattable object logged:", result)
-         self.assertIn("Recoverable data:", result)
-         self.assertIn("Exception during formatting:", result)
 
-
     def test_formatUnformattableEventWithUnformattableErrorOMGWillItStop(self):
-         """
-         Formatting an unformattable event that has an unformattable value.
-         """
-         event = dict(
-             log_format="{evil()}",
-             evil=lambda: 1/0,
-         )
+        """
+        Formatting an unformattable event that has an unformattable value.
+        """
+        event = dict(
+            log_format="{evil()}",
+            evil=lambda: 1/0,
+            recoverable="okay",
+        )
+        # Call formatUnformattableEvent() directly with a bogus exception.
+        result = formatUnformattableEvent(event, Unformattable())
+        self.assertIn("MESSAGE LOST: unformattable object logged:", result)
+        self.assertIn(repr("recoverable") + " = " + repr("okay"), result)
 
-         # Call formatUnformattableEvent() directly with a bogus exception.
-         result = formatUnformattableEvent(event, Gurk())
 
-         self.assertIn("MESSAGE LOST: unable to recover any data from message:", result)
 
-
-
 class LoggerTests(SetUpTearDown, unittest.TestCase):
     """
     Tests for L{Logger}.
@@ -355,8 +365,8 @@
 
     def test_sourceAvailableForFormatting(self):
         """
-        On instances that have a L{Logger} class attribute, the C{log_source} key
-        is available to format strings.
+        On instances that have a L{Logger} class attribute, the C{log_source}
+        key is available to format strings.
         """
         obj = LogComposedObject("hello")
         log = obj.log
@@ -398,11 +408,13 @@
                 self.assertEquals(log.event["log_namespace"], __name__)
                 self.assertEquals(log.event["log_source"], None)
 
-                self.assertEquals(log.event["logLevel"], pythonLogLevelMapping[level])
+                self.assertEquals(log.event["logLevel"],
+                                  pythonLogLevelMapping[level])
 
                 self.assertEquals(log.event["junk"], message)
 
-                # FIXME: this checks the end of message because we do formatting in emit()
+                # FIXME: this checks the end of message because we do
+                # formatting in emit()
                 self.assertEquals(
                     formatEvent(log.event),
                     message
@@ -441,10 +453,10 @@
 
         log.warn(
             "*",
-            log_format = "#",
-            log_level = LogLevel.error,
-            log_namespace = "*namespace*",
-            log_source = "*source*",
+            log_format="#",
+            log_level=LogLevel.error,
+            log_namespace="*namespace*",
+            log_source="*source*",
         )
 
         # FIXME: Should conflicts log errors?
@@ -583,12 +595,13 @@
         # Verify that the exception was logged
         for event in nonTestEvents:
             if (
-                event.get("log_format", None) == "Temporarily removing observer {observer} due to exception: {e}" and
+                event.get("log_format", None) == OBSERVER_REMOVED and
                 getattr(event.get("failure", None), "value") is exception
             ):
                 break
         else:
-            self.fail("Observer raised an exception and the exception was not logged.")
+            self.fail("Observer raised an exception "
+                      "and the exception was not logged.")
 
 
     def test_observerRaisesAndLoggerHatesMe(self):
@@ -690,8 +703,10 @@
     def test_filteredObserver(self):
         namespace = __name__
 
-        event_debug = dict(log_namespace=namespace, log_level=LogLevel.debug, log_format="")
-        event_error = dict(log_namespace=namespace, log_level=LogLevel.error, log_format="")
+        event_debug = dict(log_namespace=namespace,
+                           log_level=LogLevel.debug, log_format="")
+        event_error = dict(log_namespace=namespace,
+                           log_level=LogLevel.error, log_format="")
         events = []
 
         observer = lambda e: events.append(e)
@@ -726,8 +741,10 @@
     def test_unfilteredObserver(self):
         namespace = __name__
 
-        event_debug = dict(log_namespace=namespace, log_level=LogLevel.debug, log_format="")
-        event_error = dict(log_namespace=namespace, log_level=LogLevel.error, log_format="")
+        event_debug = dict(log_namespace=namespace, log_level=LogLevel.debug,
+                           log_format="")
+        event_error = dict(log_namespace=namespace, log_level=LogLevel.error,
+                           log_format="")
         events = []
 
         observer = lambda e: events.append(e)
@@ -797,7 +814,8 @@
         eventsSeen = []
         trackingObserver = lambda e: eventsSeen.append(e)
         filteringObserver = FilteringLogObserver(trackingObserver, predicates)
-        for e in events: filteringObserver(e)
+        for e in events:
+            filteringObserver(e)
 
         return [e["count"] for e in eventsSeen]
 
@@ -805,18 +823,24 @@
     def test_shouldLogEvent_noFilters(self):
         self.assertEquals(self.filterWith(), [0, 1, 2, 3])
 
+
     def test_shouldLogEvent_noFilter(self):
         self.assertEquals(self.filterWith("notTwo"), [0, 1, 3])
 
+
     def test_shouldLogEvent_yesFilter(self):
         self.assertEquals(self.filterWith("twoPlus"), [0, 1, 2, 3])
 
+
     def test_shouldLogEvent_yesNoFilter(self):
         self.assertEquals(self.filterWith("twoPlus", "no"), [2, 3])
 
+
     def test_shouldLogEvent_yesYesNoFilter(self):
-        self.assertEquals(self.filterWith("twoPlus", "twoMinus", "no"), [0, 1, 2, 3])
+        self.assertEquals(self.filterWith("twoPlus", "twoMinus", "no"),
+                          [0, 1, 2, 3])
 
+
     def test_shouldLogEvent_badPredicateResult(self):
         self.assertRaises(TypeError, self.filterWith, "bogus")
 
@@ -826,7 +850,8 @@
 
         def callWithPredicateResult(result):
             seen = []
-            observer = FilteringLogObserver(lambda e: seen.append(e), (lambda e: result,))
+            observer = FilteringLogObserver(lambda e: seen.append(e),
+                                            (lambda e: result,))
             observer(e)
             return seen
 
@@ -871,19 +896,22 @@
         log = TestLegacyLogger()
 
         message = "Hi, there."
-        kwargs = { "foo": "bar", "obj": object() }
+        kwargs = {"foo": "bar", "obj": object()}
 
         log.msg(message, **kwargs)
 
-        self.assertIdentical(log.newStyleLogger.emitted["level"], LogLevel.info)
+        self.assertIdentical(log.newStyleLogger.emitted["level"],
+                             LogLevel.info)
         self.assertEquals(log.newStyleLogger.emitted["format"], message)
 
         for key, value in kwargs.items():
-            self.assertIdentical(log.newStyleLogger.emitted["kwargs"][key], value)
+            self.assertIdentical(log.newStyleLogger.emitted["kwargs"][key],
+                                 value)
 
         log.msg(foo="")
 
-        self.assertIdentical(log.newStyleLogger.emitted["level"], LogLevel.info)
+        self.assertIdentical(log.newStyleLogger.emitted["level"],
+                             LogLevel.info)
         self.assertIdentical(log.newStyleLogger.emitted["format"], None)
 
 
@@ -894,7 +922,7 @@
         log = TestLegacyLogger()
 
         exception = RuntimeError("Oh me, oh my.")
-        kwargs = { "foo": "bar", "obj": object() }
+        kwargs = {"foo": "bar", "obj": object()}
 
         try:
             raise exception
@@ -911,7 +939,7 @@
         log = TestLegacyLogger()
 
         exception = RuntimeError("Oh me, oh my.")
-        kwargs = { "foo": "bar", "obj": object() }
+        kwargs = {"foo": "bar", "obj": object()}
         why = "Because I said so."
 
         try:
@@ -929,7 +957,7 @@
         log = TestLegacyLogger()
 
         exception = RuntimeError("Oh me, oh my.")
-        kwargs = { "foo": "bar", "obj": object() }
+        kwargs = {"foo": "bar", "obj": object()}
         why = "Because I said so."
 
         try:
@@ -947,7 +975,7 @@
         log = TestLegacyLogger()
 
         exception = RuntimeError("Oh me, oh my.")
-        kwargs = { "foo": "bar", "obj": object() }
+        kwargs = {"foo": "bar", "obj": object()}
         why = "Because I said so."
         bogus = object()
 
@@ -959,12 +987,14 @@
         errors = self.flushLoggedErrors(exception.__class__)
         self.assertEquals(len(errors), 0)
 
-        self.assertIdentical(log.newStyleLogger.emitted["level"], LogLevel.error)
+        self.assertIdentical(log.newStyleLogger.emitted["level"],
+                             LogLevel.error)
         self.assertEquals(log.newStyleLogger.emitted["format"], repr(bogus))
         self.assertIdentical(log.newStyleLogger.emitted["kwargs"]["why"], why)
 
         for key, value in kwargs.items():
-            self.assertIdentical(log.newStyleLogger.emitted["kwargs"][key], value)
+            self.assertIdentical(log.newStyleLogger.emitted["kwargs"][key],
+                                 value)
 
 
     def legacy_err(self, log, kwargs, why, exception):
@@ -976,18 +1006,24 @@
         errors = self.flushLoggedErrors(exception.__class__)
         self.assertEquals(len(errors), 1)
 
-        self.assertIdentical(log.newStyleLogger.emitted["level"], LogLevel.error)
+        self.assertIdentical(log.newStyleLogger.emitted["level"],
+                             LogLevel.error)
         self.assertEquals(log.newStyleLogger.emitted["format"], None)
-        self.assertIdentical(log.newStyleLogger.emitted["kwargs"]["failure"].__class__, Failure)
-        self.assertIdentical(log.newStyleLogger.emitted["kwargs"]["failure"].value, exception)
-        self.assertIdentical(log.newStyleLogger.emitted["kwargs"]["why"], why)
+        emittedKwargs = log.newStyleLogger.emitted["kwargs"]
+        self.assertIdentical(emittedKwargs["failure"].__class__, Failure)
+        self.assertIdentical(emittedKwargs["failure"].value, exception)
+        self.assertIdentical(emittedKwargs["why"], why)
 
         for key, value in kwargs.items():
-            self.assertIdentical(log.newStyleLogger.emitted["kwargs"][key], value)
+            self.assertIdentical(log.newStyleLogger.emitted["kwargs"][key],
+                                 value)
 
 
 
-class Gurk(object):
-    # Class that raises in C{__repr__()}.
+class Unformattable(object):
+    """
+    An object that raises an exception from C{__repr__}.
+    """
+
     def __repr__(self):
         return str(1/0)
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.macosforge.org/pipermail/calendarserver-changes/attachments/20130917/b7fa4e92/attachment-0001.html>


More information about the calendarserver-changes mailing list