[CalendarServer-changes] [2389] CalendarServer/branches/release/CalendarServer-1.3-dev

source_changes at macosforge.org source_changes at macosforge.org
Wed May 7 15:25:08 PDT 2008


Revision: 2389
          http://trac.macosforge.org/projects/calendarserver/changeset/2389
Author:   wsanchez at apple.com
Date:     2008-05-07 15:25:07 -0700 (Wed, 07 May 2008)

Log Message:
-----------
Pull up r2388: sweet logging hookups

Modified Paths:
--------------
    CalendarServer/branches/release/CalendarServer-1.3-dev/conf/caldavd-test.plist
    CalendarServer/branches/release/CalendarServer-1.3-dev/conf/caldavd.plist
    CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/__init__.py
    CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/authkerb.py
    CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/caldavxml.py
    CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/cluster.py
    CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/config.py
    CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/directory/appleopendirectory.py
    CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/directory/digest.py
    CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/directory/directory.py
    CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/directory/principal.py
    CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/dropbox.py
    CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/extensions.py
    CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/ical.py
    CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/index.py
    CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/itip.py
    CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/method/copymove.py
    CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/method/mkcalendar.py
    CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/method/propfind.py
    CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/method/put.py
    CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/method/put_common.py
    CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/method/report.py
    CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/method/report_calquery.py
    CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/method/report_common.py
    CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/method/report_freebusy.py
    CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/method/report_multiget.py
    CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/pdmonster.py
    CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/root.py
    CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/schedule.py
    CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/sql.py
    CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/static.py
    CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/tap.py
    CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/test/test_config.py
    CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/timezones.py
    CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/util.py

Added Paths:
-----------
    CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/accesslog.py
    CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/accounting.py
    CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/log.py
    CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/test/test_log.py

Removed Paths:
-------------
    CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/logging.py

Modified: CalendarServer/branches/release/CalendarServer-1.3-dev/conf/caldavd-test.plist
===================================================================
--- CalendarServer/branches/release/CalendarServer-1.3-dev/conf/caldavd-test.plist	2008-05-07 21:56:53 UTC (rev 2388)
+++ CalendarServer/branches/release/CalendarServer-1.3-dev/conf/caldavd-test.plist	2008-05-07 22:25:07 UTC (rev 2389)
@@ -186,7 +186,7 @@
   <!-- Principals with "DAV:all" access (relative URLs) -->
   <key>AdminPrincipals</key>
   <array>
-    <string>/principals/__uids__/admin/</string>
+    <string>/principals/users/admin/</string>
   </array>
 
   <!-- Principals that can pose as other principals -->
@@ -239,9 +239,6 @@
     Logging
   -->
 
-  <key>Verbose</key>
-  <false/>
-
   <!-- Apache-style access log -->
   <key>AccessLogFile</key>
   <string>logs/access.log</string>
@@ -252,6 +249,25 @@
   <key>ErrorLogFile</key>
   <string>logs/error.log</string>
 
+  <!-- Log Levels -->
+  <key>DefaultLogLevel</key>
+  <string>info</string> <!-- debug, info, warn, error -->
+
+  <key>LogLevels</key>
+  <dict>
+  </dict>
+
+  <!-- Accounting -->
+  <key>AccountingCategories</key>
+  <dict>
+    <key>iTIP</key><false/>
+  </dict>
+
+  <key>AccountingPrincipals</key>
+  <array>
+    <!--<string>/principals/users/foo/</string>-->
+  </array>
+
   <!-- Server statistics file -->
   <key>ServerStatsFile</key>
   <string>logs/stats.plist</string>

Modified: CalendarServer/branches/release/CalendarServer-1.3-dev/conf/caldavd.plist
===================================================================
--- CalendarServer/branches/release/CalendarServer-1.3-dev/conf/caldavd.plist	2008-05-07 21:56:53 UTC (rev 2388)
+++ CalendarServer/branches/release/CalendarServer-1.3-dev/conf/caldavd.plist	2008-05-07 22:25:07 UTC (rev 2389)
@@ -189,9 +189,6 @@
     Logging
   -->
 
-  <key>Verbose</key>
-  <false/>
-
   <!-- Apache-style access log -->
   <key>AccessLogFile</key>
   <string>/var/log/caldavd/access.log</string>
@@ -202,6 +199,10 @@
   <key>ErrorLogFile</key>
   <string>/var/log/caldavd/error.log</string>
 
+  <!-- Log Levels -->
+  <key>DefaultLogLevel</key>
+  <string>info</string> <!-- debug, info, warn, error -->
+
   <!-- Server statistics file -->
   <key>ServerStatsFile</key>
   <string>/var/run/caldavd/stats.plist</string>

Modified: CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/__init__.py
===================================================================
--- CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/__init__.py	2008-05-07 21:56:53 UTC (rev 2388)
+++ CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/__init__.py	2008-05-07 22:25:07 UTC (rev 2389)
@@ -25,6 +25,8 @@
 from twisted.web2.static import File, loadMimeTypes
 
 __all__ = [
+    "accesslog",
+    "accounting",
     "authkerb",
     "caldavxml",
     "customxml",
@@ -39,7 +41,7 @@
     "index",
     "instance",
     "itip",
-    "logging",
+    "log",
     "notifications",
     "principalindex",
     "resource",

Copied: CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/accesslog.py (from rev 2388, CalendarServer/trunk/twistedcaldav/accesslog.py)
===================================================================
--- CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/accesslog.py	                        (rev 0)
+++ CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/accesslog.py	2008-05-07 22:25:07 UTC (rev 2389)
@@ -0,0 +1,310 @@
+##
+# Copyright (c) 2006-2007 Apple Inc. All rights reserved.
+#
+# Licensed under the Apache License, Version 2.0 (the "License");
+# you may not use this file except in compliance with the License.
+# You may obtain a copy of the License at
+#
+# http://www.apache.org/licenses/LICENSE-2.0
+#
+# Unless required by applicable law or agreed to in writing, software
+# distributed under the License is distributed on an "AS IS" BASIS,
+# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+# See the License for the specific language governing permissions and
+# limitations under the License.
+##
+
+"""
+Access logs.
+"""
+
+__all__ = [
+    "DirectoryLogWrapperResource",
+    "RotatingFileAccessLoggingObserver",
+    "AMPCommonAccessLoggingObserver",
+    "AMPLoggingFactory",
+]
+
+import datetime
+import os
+import time
+
+from twisted.internet import protocol
+
+from twisted.web2 import iweb
+from twisted.web2.dav import davxml
+from twisted.web2.log import BaseCommonAccessLoggingObserver
+from twisted.web2.log import LogWrapperResource
+
+from twistedcaldav.config import config
+from twistedcaldav.directory.directory import DirectoryService
+from twistedcaldav.log import Logger
+
+log = Logger()
+
+class DirectoryLogWrapperResource(LogWrapperResource):
+    
+    def __init__(self, resource, directory):
+        super(DirectoryLogWrapperResource, self).__init__(resource)
+        
+        self.directory = directory
+        
+    def getDirectory(self):
+        return self.directory
+
+class CommonAccessLoggingObserverExtensions(BaseCommonAccessLoggingObserver):
+    """
+    A base class for our extension to the L{BaseCommonAccessLoggingObserver}
+    """
+
+    def emit(self, eventDict):
+        if eventDict.get('interface') is not iweb.IRequest:
+            return
+
+        request = eventDict['request']
+        response = eventDict['response']
+        loginfo = eventDict['loginfo']
+        firstLine = '%s %s HTTP/%s' %(
+            request.method,
+            request.uri,
+            '.'.join([str(x) for x in request.clientproto]))
+
+        # Try to determine authentication and authorization identifiers
+        uid = "-"
+        if hasattr(request, "authnUser"):
+            if isinstance(request.authnUser.children[0], davxml.HRef):
+                uidn = str(request.authnUser.children[0])
+                uidz = None
+                if hasattr(request, "authzUser") and str(request.authzUser.children[0]) != uidn:
+                    uidz = str(request.authzUser.children[0])
+                    
+                def convertUIDtoShortName(uid):
+                    uid = uid.rstrip("/")
+                    uid = uid[uid.rfind("/") + 1:]
+                    record = request.site.resource.getDirectory().recordWithGUID(uid)
+                    if record:
+                        if record.recordType == DirectoryService.recordType_users:
+                            return record.shortName
+                        else:
+                            return "(%s)%s" % (record.recordType, record.shortName,)
+                    else:
+                        return uid
+                    
+                uidn = convertUIDtoShortName(uidn)
+                if uidz:
+                    uidz = convertUIDtoShortName(uidz)
+                    
+                if uidn and uidz:
+                    uid = '"%s as %s"' % (uidn, uidz,)
+                else:
+                    uid = uidn
+
+        self.logMessage(
+            '%s - %s [%s] "%s" %s %d "%s" "%s" [%.1f ms]' %(
+                request.remoteAddr.host,
+                uid,
+                self.logDateString(
+                    response.headers.getHeader('date', 0)),
+                firstLine,
+                response.code,
+                loginfo.bytesSent,
+                request.headers.getHeader('referer', '-'),
+                request.headers.getHeader('user-agent', '-'),
+                (time.time() - request.initTime) * 1000,
+                )
+            )
+
+
+class RotatingFileAccessLoggingObserver(CommonAccessLoggingObserverExtensions):
+    """
+    Class to do 'apache' style access logging to a rotating log file. The log
+    file is rotated after midnight each day.
+    """
+
+    def __init__(self, logpath):
+        self.logpath = logpath
+
+    def logMessage(self, message, allowrotate=True):
+        """
+        Log a message to the file and possibly rotate if date has changed.
+
+        @param message: C{str} for the message to log.
+        @param allowrotate: C{True} if log rotate allowed, C{False} to log to current file
+            without testing for rotation.
+        """
+
+        if self.shouldRotate() and allowrotate:
+            self.flush()
+            self.rotate()
+        self.f.write(message + '\n')
+
+    def start(self):
+        """
+        Start logging. Open the log file and log an 'open' message.
+        """
+
+        super(RotatingFileAccessLoggingObserver, self).start()
+        self._open()
+        self.logMessage("Log opened - server start: [%s]." % (datetime.datetime.now().ctime(),))
+
+    def stop(self):
+        """
+        Stop logging. Close the log file and log an 'open' message.
+        """
+
+        self.logMessage("Log closed - server stop: [%s]." % (datetime.datetime.now().ctime(),), False)
+        super(RotatingFileAccessLoggingObserver, self).stop()
+        self._close()
+
+    def _open(self):
+        """
+        Open the log file.
+        """
+
+        self.f = open(self.logpath, 'a', 1)
+        self.lastDate = self.toDate(os.stat(self.logpath)[8])
+
+    def _close(self):
+        """
+        Close the log file.
+        """
+
+        self.f.close()
+
+    def flush(self):
+        """
+        Flush the log file.
+        """
+
+        self.f.flush()
+
+    def shouldRotate(self):
+        """
+        Rotate when the date has changed since last write
+        """
+
+        if config.RotateAccessLog:
+            return self.toDate() > self.lastDate
+        else:
+            return False
+
+    def toDate(self, *args):
+        """
+        Convert a unixtime to (year, month, day) localtime tuple,
+        or return the current (year, month, day) localtime tuple.
+
+        This function primarily exists so you may overload it with
+        gmtime, or some cruft to make unit testing possible.
+        """
+
+        # primarily so this can be unit tested easily
+        return time.localtime(*args)[:3]
+
+    def suffix(self, tupledate):
+        """
+        Return the suffix given a (year, month, day) tuple or unixtime
+        """
+
+        try:
+            return '_'.join(map(str, tupledate))
+        except:
+            # try taking a float unixtime
+            return '_'.join(map(str, self.toDate(tupledate)))
+
+    def rotate(self):
+        """
+        Rotate the file and create a new one.
+
+        If it's not possible to open new logfile, this will fail silently,
+        and continue logging to old logfile.
+        """
+
+        newpath = "%s.%s" % (self.logpath, self.suffix(self.lastDate))
+        if os.path.exists(newpath):
+            log.msg("Cannot rotate log file to %s because it already exists." % (newpath,))
+            return
+        self.logMessage("Log closed - rotating: [%s]." % (datetime.datetime.now().ctime(),), False)
+        log.msg("Rotating log file to: %s" % (newpath,), system="Logging")
+        self.f.close()
+        os.rename(self.logpath, newpath)
+        self._open()
+        self.logMessage("Log opened - rotated: [%s]." % (datetime.datetime.now().ctime(),), False)
+
+
+from twisted.protocols import amp
+
+
+class LogMessage(amp.Command):
+    arguments = [('message', amp.String())]
+
+
+class AMPCommonAccessLoggingObserver(CommonAccessLoggingObserverExtensions):
+    def __init__(self, socket):
+        self.socket = socket
+        self.protocol = None
+        self._buffer = []
+
+    def flushBuffer(self):
+        if self._buffer:
+            for msg in self._buffer:
+                self.logMessage(msg)
+
+    def start(self):
+        super(AMPCommonAccessLoggingObserver, self).start()
+
+        from twisted.internet import reactor
+
+        def _gotProtocol(proto):
+            self.protocol = proto
+            self.flushBuffer()
+
+        self.client = protocol.ClientCreator(reactor, amp.AMP)
+        d = self.client.connectUNIX(self.socket)
+        d.addCallback(_gotProtocol)
+
+    def stop(self):
+        super(AMPCommonAccessLoggingObserver, self).stop()
+        self.client.disconnect()
+
+    def logMessage(self, message):
+        """
+        Log a message to the remote AMP Protocol
+        """
+        if self.protocol is not None:
+            # XXX: Yeah we're not waiting for anything to happen here.
+            #      but we will log an error.
+            d = self.protocol.callRemote(LogMessage, message=message)
+            d.addErrback(log.err)
+        else:
+            self._buffer.append(message)
+
+
+class AMPLoggingProtocol(amp.AMP):
+    """
+    A server side protocol for logging to the given observer.
+    """
+
+    def __init__(self, observer):
+        self.observer = observer
+
+        super(AMPLoggingProtocol, self).__init__()
+
+    def logMessage(self, message):
+        self.observer.logMessage(message)
+        return {}
+
+    LogMessage.responder(logMessage)
+
+
+class AMPLoggingFactory(protocol.ServerFactory):
+    def __init__(self, observer):
+        self.observer = observer
+
+    def doStart(self):
+        self.observer.start()
+
+    def doStop(self):
+        self.observer.stop()
+
+    def buildProtocol(self, addr):
+        return AMPLoggingProtocol(self.observer)

Copied: CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/accounting.py (from rev 2388, CalendarServer/trunk/twistedcaldav/accounting.py)
===================================================================
--- CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/accounting.py	                        (rev 0)
+++ CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/accounting.py	2008-05-07 22:25:07 UTC (rev 2389)
@@ -0,0 +1,111 @@
+##
+# Copyright (c) 2006-2007 Apple Inc. All rights reserved.
+#
+# Licensed under the Apache License, Version 2.0 (the "License");
+# you may not use this file except in compliance with the License.
+# You may obtain a copy of the License at
+#
+# http://www.apache.org/licenses/LICENSE-2.0
+#
+# Unless required by applicable law or agreed to in writing, software
+# distributed under the License is distributed on an "AS IS" BASIS,
+# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+# See the License for the specific language governing permissions and
+# limitations under the License.
+##
+
+"""
+Extended account-specific logging.
+Allows different sub-systems to log data on a per-principal basis.
+"""
+
+__all__ = [
+    "accountingEnabled",
+    "emitAccounting",
+]
+
+import datetime
+import os
+
+from twistedcaldav.config import config
+from twistedcaldav.log import Logger
+
+log = Logger()
+
+def accountingEnabled(category, principal):
+    """
+    Determine if accounting is enabled for the given category and principal.
+    """
+    return (
+        accountingEnabledForCategory(category) and
+        accountingEnabledForPrincipal(principal)
+    )
+
+def accountingEnabledForCategory(category):
+    """
+    Determine if accounting is enabled for the given category.
+    """
+    return config.AccountingCategories.get(category, False)
+
+def accountingEnabledForPrincipal(principal):
+    """
+    Determine if accounting is enabled for the given principal.
+    """
+    enabledPrincipalURIs = config.AccountingPrincipals
+
+    if "*" in enabledPrincipalURIs:
+        return True
+
+    if principal.principalURL() in enabledPrincipalURIs:
+        return True
+
+    for principal in principal.alternateURIs():
+        if principal in enabledPrincipalURIs:
+            return True
+
+    return False
+
+def emitAccounting(category, principal, data):
+    """
+    Write the supplied data to the appropriate location for the given
+    category and principal.
+
+    @param principal: the principal for whom a log entry is to be created.
+    @type principal: L{DirectoryPrincipalResource}
+    @param category: accounting category
+    @type category: C{tuple}
+    @param data: data to write.
+    @type data: C{str}
+    """    
+    if not accountingEnabled(category, principal):
+        return
+
+    #
+    # Obtain the accounting log file name
+    #
+    logRoot = config.AccountingLogRoot
+    logDirectory = os.path.join(logRoot, principal.record.recordType, principal.record.shortName, category)
+    logFilename = os.path.join(logDirectory, datetime.datetime.now().isoformat())
+
+    if not os.path.isdir(logDirectory):
+        os.makedirs(logDirectory)
+        logFilename = "%s-01" % (logFilename,)
+    else:
+        index = 1
+        while True:
+            path = "%s-%02d" % (logFilename, index)
+            if not os.path.isfile(path):
+                logFilename = path
+                break
+            if index == 1000:
+                log.error("Too many %s accounting files for %s" % (category, principal))
+                return
+
+    #
+    # Now write out the data to the log file
+    #
+    logFile = open(logFilename, "a")
+    try:
+        logFile.write(data)
+    finally:
+        logFile.close()

Modified: CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/authkerb.py
===================================================================
--- CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/authkerb.py	2008-05-07 21:56:53 UTC (rev 2388)
+++ CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/authkerb.py	2008-05-07 22:25:07 UTC (rev 2389)
@@ -40,16 +40,16 @@
 
 from zope.interface import implements
 
+import kerberos
+
 from twisted.cred import checkers, credentials, error
 from twisted.internet.defer import succeed
 from twisted.web2.auth.interfaces import ICredentialFactory
 from twisted.web2.dav.auth import IPrincipalCredentials
 
-from twistedcaldav import logging
+from twistedcaldav.log import LoggingMixIn
 
-import kerberos
-
-class KerberosCredentialFactoryBase(object):
+class KerberosCredentialFactoryBase(LoggingMixIn):
     """
     Code common to Kerberos-based credential factories.
     """
@@ -77,7 +77,7 @@
             try:
                 principal = kerberos.getServerPrincipalDetails(type, hostname)
             except kerberos.KrbError, ex:
-                logging.err("getServerPrincipalDetails: %s" % (ex[0],), system="KerberosCredentialFactoryBase")
+                self.log_error("getServerPrincipalDetails: %s" % (ex[0],))
                 raise ValueError('Authentication System Failure: %s' % (ex[0],))
 
         try:
@@ -87,7 +87,7 @@
             service = splits[0].upper()
             realm = splits[1]
         except IndexError:
-            logging.err("Invalid Kerberos principal: %s" % (principal,), system="KerberosCredentialFactoryBase")
+            self.log_error("Invalid Kerberos principal: %s" % (principal,))
             raise ValueError('Authentication System Failure: Invalid Kerberos principal: %s' % (principal,))
                 
         self.service = "%s@%s" % (servicetype, service,)
@@ -155,7 +155,7 @@
             return c
         raise error.LoginFailed('Invalid credentials')
 
-class BasicKerberosCredentialsChecker(object):
+class BasicKerberosCredentialsChecker(LoggingMixIn):
 
     implements(checkers.ICredentialsChecker)
 
@@ -171,7 +171,7 @@
             try:
                 kerberos.checkPassword(creds.username, creds.password, creds.service, creds.default_realm)
             except kerberos.BasicAuthError, ex:
-                logging.err("%s" % (ex[0],), system="BasicKerberosCredentialsChecker")
+                self.log_error("%s" % (ex[0],))
                 raise error.UnauthorizedLogin("Bad credentials for: %s (%s: %s)" % (pcreds.authnURI, ex[0], ex[1],))
             else:
                 return succeed((pcreds.authnURI, pcreds.authzURI,))
@@ -222,18 +222,18 @@
         try:
             _ignore_result, context = kerberos.authGSSServerInit(self.service);
         except kerberos.GSSError, ex:
-            logging.err("authGSSServerInit: %s(%s)" % (ex[0][0], ex[1][0],), system="NegotiateCredentialFactory")
+            self.log_error("authGSSServerInit: %s(%s)" % (ex[0][0], ex[1][0],))
             raise error.LoginFailed('Authentication System Failure: %s(%s)' % (ex[0][0], ex[1][0],))
 
         # Do the GSSAPI step and get response and username
         try:
             kerberos.authGSSServerStep(context, base64data);
         except kerberos.GSSError, ex:
-            logging.err("authGSSServerStep: %s(%s)" % (ex[0][0], ex[1][0],), system="NegotiateCredentialFactory")
+            self.log_error("authGSSServerStep: %s(%s)" % (ex[0][0], ex[1][0],))
             kerberos.authGSSServerClean(context)
             raise error.UnauthorizedLogin('Bad credentials: %s(%s)' % (ex[0][0], ex[1][0],))
         except kerberos.KrbError, ex:
-            logging.err("authGSSServerStep: %s" % (ex[0],), system="NegotiateCredentialFactory")
+            self.log_error("authGSSServerStep: %s" % (ex[0],))
             kerberos.authGSSServerClean(context)
             raise error.UnauthorizedLogin('Bad credentials: %s' % (ex[0],))
 
@@ -250,7 +250,7 @@
         # We currently do not support cross-realm authentciation, so we
         # must verify that the realm we got exactly matches the one we expect.
         if realmname != self.realm:
-            logging.err("authGSSServer Realms do not match: %s vs %s" % (realmname, self.realm,), system="NegotiateCredentialFactory")
+            self.log_error("authGSSServer Realms do not match: %s vs %s" % (realmname, self.realm,))
             kerberos.authGSSServerClean(context)
             raise error.UnauthorizedLogin('Bad credentials: mismatched realm')
 
@@ -259,7 +259,7 @@
         try:
             kerberos.authGSSServerClean(context);
         except kerberos.GSSError, ex:
-            logging.err("authGSSServerClean: %s" % (ex[0][0], ex[1][0],), system="NegotiateCredentialFactory")
+            self.log_error("authGSSServerClean: %s" % (ex[0][0], ex[1][0],))
             raise error.LoginFailed('Authentication System Failure %s(%s)' % (ex[0][0], ex[1][0],))
         
         # If we successfully decoded and verified the Kerberos credentials we need to add the Kerberos

Modified: CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/caldavxml.py
===================================================================
--- CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/caldavxml.py	2008-05-07 21:56:53 UTC (rev 2388)
+++ CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/caldavxml.py	2008-05-07 22:25:07 UTC (rev 2389)
@@ -27,19 +27,20 @@
 See draft spec: http://ietf.webdav.org/caldav/draft-dusseault-caldav.txt
 """
 
-from twisted.python import log
+import datetime
 
+from vobject.icalendar import utc
+
 from twisted.web2.dav import davxml
 
 from twistedcaldav.dateops import clipPeriod, timeRangesOverlap
 from twistedcaldav.ical import Component as iComponent
 from twistedcaldav.ical import Property as iProperty
 from twistedcaldav.ical import parse_date_or_datetime
+from twistedcaldav.log import Logger
 
-from vobject.icalendar import utc
+log = Logger()
 
-import datetime
-
 ##
 # CalDAV objects
 ##

Modified: CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/cluster.py
===================================================================
--- CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/cluster.py	2008-05-07 21:56:53 UTC (rev 2388)
+++ CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/cluster.py	2008-05-07 22:25:07 UTC (rev 2389)
@@ -20,16 +20,16 @@
 import sys
 import tempfile
 
-from twisted.python import log
-
 from twisted.runner import procmon
 from twisted.application import internet, service
 
-from twistedcaldav import logging
+from twistedcaldav.accesslog import AMPLoggingFactory, RotatingFileAccessLoggingObserver
 from twistedcaldav.config import config, ConfigurationError
-
 from twistedcaldav.util import getNCPU
+from twistedcaldav.log import Logger
 
+log = Logger()
+
 serviceTemplate = """
     <service name="%(name)s">
         %(listeningInterfaces)s
@@ -283,8 +283,8 @@
                                      fname],
                            env=parentEnv)
 
-    logger = logging.AMPLoggingFactory(
-        logging.RotatingFileAccessLoggingObserver(config.AccessLogFile))
+    logger = AMPLoggingFactory(
+        RotatingFileAccessLoggingObserver(config.AccessLogFile))
 
     loggingService = internet.UNIXServer(config.ControlSocket, logger)
 

Modified: CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/config.py
===================================================================
--- CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/config.py	2008-05-07 21:56:53 UTC (rev 2388)
+++ CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/config.py	2008-05-07 22:25:07 UTC (rev 2389)
@@ -19,10 +19,13 @@
 import os
 import copy
 
-from twisted.python import log
 
 from twistedcaldav.py.plistlib import readPlist
+from twistedcaldav.log import Logger
+from twistedcaldav.log import clearLogLevels, setLogLevelForNamespace, InvalidLogLevelError
 
+log = Logger()
+
 defaultConfigFile = "/etc/caldavd/caldavd.plist"
 
 serviceDefaultParams = {
@@ -91,8 +94,8 @@
     # Authentication
     #
     "Authentication": {
-        "Basic"   : { "Enabled": False },   # Clear text; best avoided
-        "Digest"  : {                       # Digest challenge/response
+        "Basic": { "Enabled": False },     # Clear text; best avoided
+        "Digest": {                        # Digest challenge/response
             "Enabled": True,
             "Algorithm": "md5",
             "Qop": "",
@@ -106,12 +109,18 @@
     #
     # Logging
     #
-    "Verbose": False,
-    "AccessLogFile"  : "/var/log/caldavd/access.log",                   # Apache-style access log
-    "ErrorLogFile"   : "/var/log/caldavd/error.log",                    # Server activity log
+    "AccessLogFile"  : "/var/log/caldavd/access.log",  # Apache-style access log
+    "ErrorLogFile"   : "/var/log/caldavd/error.log",   # Server activity log
     "ServerStatsFile": "/var/run/caldavd/stats.plist",
     "PIDFile"        : "/var/run/caldavd.pid",
     "RotateAccessLog": False,
+    "DefaultLogLevel": "",
+    "LogLevels": {},
+    "AccountingCategories": {
+        "iTIP": False,
+    },
+    "AccountingPrincipals": [],
+    "AccountingLogRoot": "/var/log/caldavd/accounting",
 
     #
     # SSL/TLS
@@ -220,20 +229,32 @@
             if param not in serviceDefaultParams[self._data["DirectoryService"]["type"]]:
                 del self._data["DirectoryService"]["params"][param]
 
-        self.updateServerCapabilities()
-
-    def updateServerCapabilities(self):
-        """
-        Change server capabilities based on the current config parameters.
-        Here are the "features" in the config that need special treatment:
-        
-        EnableDropBox
-        EnableNotifications
-        """
+        #
+        # FIXME: Use the config object instead of doing this here
+        #
         from twistedcaldav.resource import CalendarPrincipalResource
         CalendarPrincipalResource.enableDropBox(self.EnableDropBox)
         CalendarPrincipalResource.enableNotifications(self.EnableNotifications)
 
+        self.updateLogLevels()
+
+    def updateLogLevels(self):
+        clearLogLevels()
+
+        try:
+            if "DefaultLogLevel" in self._data:
+                level = self._data["DefaultLogLevel"]
+                if not level:
+                    level = "info"
+                setLogLevelForNamespace(None, level)
+
+            if "LogLevels" in self._data:
+                for namespace in self._data["LogLevels"]:
+                    setLogLevelForNamespace(namespace, self._data["LogLevels"][namespace])
+
+        except InvalidLogLevelError, e:
+            raise ConfigurationError("Invalid log level: %s" % (e.level))
+
     def updateDefaults(self, items):
         _mergeData(self._defaults, items)
         self.update(items)
@@ -242,7 +263,7 @@
         self._defaults = copy.deepcopy(defaults)
 
     def __setattr__(self, attr, value):
-        if '_data' in self.__dict__ and attr in self.__dict__['_data']:
+        if "_data" in self.__dict__ and attr in self.__dict__["_data"]:
             self._data[attr] = value
         else:
             self.__dict__[attr] = value

Modified: CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/directory/appleopendirectory.py
===================================================================
--- CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/directory/appleopendirectory.py	2008-05-07 21:56:53 UTC (rev 2388)
+++ CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/directory/appleopendirectory.py	2008-05-07 22:25:07 UTC (rev 2389)
@@ -37,7 +37,6 @@
 from twisted.cred.credentials import UsernamePassword
 from twisted.web2.auth.digest import DigestedCredentials
 
-from twistedcaldav import logging
 from twistedcaldav.config import config
 from twistedcaldav.directory.directory import DirectoryService, DirectoryRecord
 from twistedcaldav.directory.directory import DirectoryError, UnknownRecordTypeError
@@ -68,7 +67,7 @@
         try:
             directory = opendirectory.odInit(node)
         except opendirectory.ODError, e:
-            logging.err("Open Directory (node=%s) Initialization error: %s" % (node, e), system="OpenDirectoryService")
+            self.log_error("Open Directory (node=%s) Initialization error: %s" % (node, e))
             raise
 
         self.realmName = node
@@ -88,7 +87,7 @@
                 try:
                     self._lookupVHostRecord()
                 except Exception, e:
-                    logging.err("Unable to locate virtual host record: %s" % (e,), system="OpenDirectoryService")
+                    self.log_error("Unable to locate virtual host record: %s" % (e,))
                     raise
 
                 if os.path.exists(serverPreferences):
@@ -97,7 +96,7 @@
                     self.isWorkgroupServer = serverInfo.get('ServiceConfig', {}).get('IsWorkgroupServer', False)
 
                     if self.isWorkgroupServer:
-                        logging.info("Enabling Workgroup Server compatibility mode", system="OpenDirectoryService")
+                        self.log_info("Enabling Workgroup Server compatibility mode")
 
             for recordType in self.recordTypes():
                 self.recordsForType(recordType)
@@ -133,10 +132,8 @@
             )
 
             if not result:
-                logging.err(
-                    "Couldn't find group %s when trying to expand nested groups."
-                    % (groupGUID,), system="OpenDirectoryService"
-                )
+                self.log_error("Couldn't find group %s when trying to expand nested groups."
+                             % (groupGUID,))
                 continue
 
             group = result[0][1]
@@ -216,16 +213,16 @@
         # Log all the matching records
         for key, value in self.computerRecords.iteritems():
             _ignore_recordname, enabled, servicetag = value
-            logging.info("Matched Directory record: %s with ServicesLocator: %s, state: %s" % (
+            self.log_info("Matched Directory record: %s with ServicesLocator: %s, state: %s" % (
                 key,
                 servicetag,
                 {True:"enabled", False:"disabled"}[enabled]
-            ), system="OpenDirectoryService")
+            ))
 
         # Log all the enabled service tags - or generate an error if there are none
         if self.servicetags:
             for tag in self.servicetags:
-                logging.info("Enabled ServicesLocator: %s" % (tag,), system="OpenDirectoryService")
+                self.log_info("Enabled ServicesLocator: %s" % (tag,))
         else:
             raise OpenDirectoryInitError(
                 "Open Directory (node=%s) no /Computers records with an enabled and valid "
@@ -248,10 +245,10 @@
         plist = readPlistFromString(plist)
         vhosts = plist.get("com.apple.macosxserver.virtualhosts", None)
         if not vhosts:
-            logging.err(
+            self.log_error(
                 "Open Directory (node=%s) %s record does not have a "
                 "com.apple.macosxserver.virtualhosts in its apple-serviceinfo attribute value"
-                % (self.realmName, recordlocation), system="OpenDirectoryService"
+                % (self.realmName, recordlocation)
             )
             return False
         
@@ -272,10 +269,10 @@
         # Get host name
         hostname = vhosts[hostguid].get("hostname", None)
         if not hostname:
-            logging.err(
+            self.log_error(
                 "Open Directory (node=%s) %s record does not have "
                 "any host name in its apple-serviceinfo attribute value"
-                % (self.realmName, recordlocation, ), system="OpenDirectoryService"
+                % (self.realmName, recordlocation)
             )
             return False
         if hostname != vhostname:
@@ -286,20 +283,20 @@
         # ignore the details themselves (scheme/port) as we use our own config for that.
         hostdetails = vhosts[hostguid].get("hostDetails", None)
         if not hostdetails:
-            logging.err(
+            self.log_error(
                 "Open Directory (node=%s) %s record does not have "
                 "any host details in its apple-serviceinfo attribute value"
-                % (self.realmName, recordlocation, ), system="OpenDirectoryService"
+                % (self.realmName, recordlocation)
             )
             return False
         
         # Look at the service data
         serviceInfos = vhosts[hostguid].get("serviceInfo", None)
         if not serviceInfos or not serviceInfos.has_key("calendar"):
-            logging.err(
+            self.log_error(
                 "Open Directory (node=%s) %s record does not have a "
                 "calendar service in its apple-serviceinfo attribute value"
-                % (self.realmName, recordlocation), system="OpenDirectoryService"
+                % (self.realmName, recordlocation)
             )
             return False
         serviceInfo = serviceInfos["calendar"]
@@ -356,7 +353,7 @@
             autoaccept = wpframework.get("AutoAcceptsInvitation", False)
             proxy = wpframework.get("CalendaringDelegate")
         except AttributeError:
-            logging.err(
+            self.log_error(
                 "Failed to parse ResourceInfo attribute of record %s (%s): %s" %
                 (shortname, guid, plist,)
             )
@@ -385,9 +382,9 @@
 
                 def onError(f):
                     storage["status"] = "stale" # Keep trying
-                    logging.err(
+                    self.log_error(
                         "Unable to load records of type %s from OpenDirectory due to unexpected error: %s"
-                        % (recordType, f), system="OpenDirectoryService"
+                        % (recordType, f)
                     )
 
                 d = deferToThread(self.reloadCache, recordType)
@@ -433,18 +430,19 @@
                 self.reloadCache(recordType, guid=guid)
                 record = lookup()
                 if record is not None:
-                    logging.info("Faulted record with GUID %s into %s record cache" % (guid, recordType), system="OpenDirectoryService")
+                    self.log_info("Faulted record with GUID %s into %s record cache"
+                                  % (guid, recordType))
                     break
             else:
-                logging.info("Unable to find any record with GUID %s" % (guid,), system="OpenDirectoryService")
+                self.log_info("Unable to find any record with GUID %s" % (guid,))
 
         return record
 
     def reloadCache(self, recordType, shortName=None, guid=None):
         if shortName:
-            logging.info("Faulting record %s into %s record cache" % (shortName, recordType), system="OpenDirectoryService")
+            self.log_info("Faulting record %s into %s record cache" % (shortName, recordType))
         elif guid is None:
-            logging.info("Reloading %s record cache" % (recordType,), system="OpenDirectoryService")
+            self.log_info("Reloading %s record cache" % (recordType,))
 
         results = self._queryDirectory(recordType, shortName=shortName, guid=guid)
         
@@ -476,16 +474,16 @@
                     )
 
                 def disableForCalendaring():
-                    logging.debug(
+                    self.log_debug(
                         "Record (%s) %s is not enabled for calendaring but may be used in ACLs"
-                        % (recordType, recordShortName), system="OpenDirectoryService"
+                        % (recordType, recordShortName)
                     )
 
                 def invalidRecord():
-                    logging.err(
+                    self.log_error(
                         "Directory (incorrectly) returned a record with no applicable "
                         "ServicesLocator attribute: (%s) %s"
-                        % (recordType, recordShortName), system="OpenDirectoryService"
+                        % (recordType, recordShortName)
                     )
 
                 if servicesLocators:
@@ -516,8 +514,8 @@
             recordNodeName = value.get(dsattributes.kDSNAttrMetaNodeLocation)
 
             if not recordGUID:
-                logging.debug("Record (%s)%s in node %s has no GUID; ignoring." % (recordType, recordShortName, recordNodeName),
-                              system="OpenDirectoryService")
+                self.log_debug("Record (%s)%s in node %s has no GUID; ignoring."
+                               % (recordType, recordShortName, recordNodeName))
                 continue
 
             # Get calendar user addresses from directory record.
@@ -566,7 +564,7 @@
             )
 
             def disableRecord(record):
-                logging.warn("Record disabled due to conflict: %s" % (record,), system="OpenDirectoryService")
+                self.log_warn("Record disabled due to conflict: %s" % (record,))
 
                 shortName = record.shortName
                 guid      = record.guid
@@ -598,7 +596,7 @@
 
                 if record.shortName not in disabledNames:
                     records[record.shortName] = guids[record.guid] = record
-                    logging.debug("Added record %s to OD record cache" % (record,), system="OpenDirectoryService")
+                    self.log_debug("Added record %s to OD record cache" % (record,))
 
         if shortName is None and guid is None:
             #
@@ -632,10 +630,9 @@
 
             self._records[recordType] = storage
 
-            logging.info(
+            self.log_info(
                 "Added %d records to %s OD record cache; expires in %d seconds"
-                % (len(self._records[recordType]["guids"]), recordType, cacheTimeout),
-                system="OpenDirectoryService"
+                % (len(self._records[recordType]["guids"]), recordType, cacheTimeout)
             )
 
     def _queryDirectory(self, recordType, shortName=None, guid=None):
@@ -695,7 +692,7 @@
                         )
 
                     if not guidQueries:
-                        logging.warn("No SACL enabled users found.", system="OpenDirectoryService")
+                        self.log_warn("No SACL enabled users found.")
                         return ()
 
                     query = dsquery.expression(dsquery.expression.OR, guidQueries)
@@ -763,7 +760,7 @@
                     attrs,
                 )
         except opendirectory.ODError, ex:
-            logging.err("Open Directory (node=%s) error: %s" % (self.realmName, str(ex)), system="OpenDirectoryService")
+            self.log_error("Open Directory (node=%s) error: %s" % (self.realmName, str(ex)))
             raise
 
         return results
@@ -828,7 +825,7 @@
         for guid in self._proxyGUIDs:
             proxyRecord = self.service.recordWithGUID(guid)
             if proxyRecord is None:
-                logging.err("No record for proxy in %s with GUID %s" % (self.shortName, guid), system="OpenDirectoryService")
+                self.log_error("No record for proxy in %s with GUID %s" % (self.shortName, guid))
             else:
                 yield proxyRecord
 
@@ -856,8 +853,8 @@
                     self.password = credentials.password
                     return True
             except opendirectory.ODError, e:
-                logging.err("Open Directory (node=%s) error while performing basic authentication for user %s: %s"
-                            % (self.service.realmName, self.shortName, e), system="OpenDirectoryService")
+                self.log_error("Open Directory (node=%s) error while performing basic authentication for user %s: %s"
+                            % (self.service.realmName, self.shortName, e))
 
             return False
 
@@ -877,11 +874,10 @@
                     'algorithm=%(algorithm)s'
                 ) % credentials.fields
             except KeyError, e:
-                logging.err(
+                self.log_error(
                     "Open Directory (node=%s) error while performing digest authentication for user %s: "
                     "missing digest response field: %s in: %s"
-                    % (self.service.realmName, self.shortName, e, credentials.fields),
-                    system="OpenDirectoryService"
+                    % (self.service.realmName, self.shortName, e, credentials.fields)
                 )
                 return False
 
@@ -909,9 +905,9 @@
 
                     return True
             except opendirectory.ODError, e:
-                logging.err(
+                self.log_error(
                     "Open Directory (node=%s) error while performing digest authentication for user %s: %s"
-                    % (self.service.realmName, self.shortName, e), system="OpenDirectoryService"
+                    % (self.service.realmName, self.shortName, e)
                 )
                 return False
 

Modified: CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/directory/digest.py
===================================================================
--- CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/directory/digest.py	2008-05-07 21:56:53 UTC (rev 2388)
+++ CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/directory/digest.py	2008-05-07 22:25:07 UTC (rev 2389)
@@ -20,7 +20,6 @@
 from twistedcaldav.sql import db_prefix
 
 from twisted.cred import error
-from twisted.python import log
 from twisted.web2.auth.digest import DigestCredentialFactory
 from twisted.web2.auth.digest import DigestedCredentials
 
@@ -35,6 +34,10 @@
 except ImportError:
     from pysqlite2.dbapi2 import OperationalError
 
+from twistedcaldav.log import Logger
+
+log = Logger()
+
 """
 Overrides twisted.web2.auth.digest to allow specifying a qop value as a configuration parameter.
 Also adds an sqlite-based credentials cache that is multi-process safe.

Modified: CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/directory/directory.py
===================================================================
--- CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/directory/directory.py	2008-05-07 21:56:53 UTC (rev 2388)
+++ CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/directory/directory.py	2008-05-07 22:25:07 UTC (rev 2389)
@@ -32,15 +32,15 @@
 
 from zope.interface import implements
 
-from twisted.python import log
 from twisted.cred.error import UnauthorizedLogin
 from twisted.cred.checkers import ICredentialsChecker
 from twisted.web2.dav.auth import IPrincipalCredentials
 
+from twistedcaldav.log import LoggingMixIn
 from twistedcaldav.directory.idirectory import IDirectoryService, IDirectoryRecord
 from twistedcaldav.directory.util import uuidFromName
 
-class DirectoryService(object):
+class DirectoryService(LoggingMixIn):
     implements(IDirectoryService, ICredentialsChecker)
 
     ##
@@ -61,10 +61,10 @@
             assert self.baseGUID, "Class %s must provide a baseGUID attribute" % (self.__class__.__name__,)
 
             if realmName is None:
-                log.err("Directory service %s has no realm name or GUID; generated service GUID will not be unique." % (self,))
+                self.log_error("Directory service %s has no realm name or GUID; generated service GUID will not be unique." % (self,))
                 realmName = ""
             else:
-                log.err("Directory service %s has no GUID; generating service GUID from realm name." % (self,))
+                self.log_error("Directory service %s has no GUID; generating service GUID from realm name." % (self,))
 
             self._guid = uuidFromName(self.baseGUID, realmName)
 
@@ -141,7 +141,7 @@
                 yield record
 
 
-class DirectoryRecord(object):
+class DirectoryRecord(LoggingMixIn):
     implements(IDirectoryRecord)
 
     def __repr__(self):

Modified: CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/directory/principal.py
===================================================================
--- CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/directory/principal.py	2008-05-07 21:56:53 UTC (rev 2388)
+++ CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/directory/principal.py	2008-05-07 22:25:07 UTC (rev 2389)
@@ -33,7 +33,6 @@
 from urllib import unquote
 from urlparse import urlparse
 
-from twisted.python import log
 from twisted.python.failure import Failure
 from twisted.internet.defer import succeed
 from twisted.web2 import responsecode
@@ -50,7 +49,10 @@
 from twistedcaldav.resource import CalendarPrincipalCollectionResource, CalendarPrincipalResource
 from twistedcaldav.static import AutoProvisioningFileMixIn
 from twistedcaldav.directory.idirectory import IDirectoryService
+from twistedcaldav.log import Logger
 
+log = Logger()
+
 # Use __underbars__ convention to avoid conflicts with directory resource types.
 uidsResourceName = "__uids__"
 

Modified: CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/dropbox.py
===================================================================
--- CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/dropbox.py	2008-05-07 21:56:53 UTC (rev 2388)
+++ CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/dropbox.py	2008-05-07 22:25:07 UTC (rev 2389)
@@ -32,7 +32,6 @@
 import time
 
 from twisted.internet.defer import deferredGenerator, waitForDeferred
-from twisted.python import log
 from twisted.web2 import responsecode
 from twisted.web2.dav import davxml
 from twisted.web2.dav.http import HTTPError, ErrorResponse, StatusResponse
@@ -42,7 +41,10 @@
 from twistedcaldav import customxml
 from twistedcaldav.config import config
 from twistedcaldav.customxml import calendarserver_namespace
+from twistedcaldav.log import Logger
 
+log = Logger()
+
 class DropBoxHomeResource (DAVResource):
     """
     Drop box collection resource.

Modified: CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/extensions.py
===================================================================
--- CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/extensions.py	2008-05-07 21:56:53 UTC (rev 2388)
+++ CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/extensions.py	2008-05-07 22:25:07 UTC (rev 2389)
@@ -32,7 +32,6 @@
 import cgi
 import time
 
-from twisted.python import log
 from twisted.internet.defer import succeed, deferredGenerator, waitForDeferred
 from twisted.web2 import responsecode
 from twisted.web2.http import HTTPError, Response, RedirectResponse
@@ -46,9 +45,46 @@
 from twisted.web2.dav.resource import DAVResource as SuperDAVResource
 from twisted.web2.dav.resource import DAVPrincipalResource as SuperDAVPrincipalResource
 from twisted.web2.dav.util import joinURL
+
+from twistedcaldav.log import Logger, LoggingMixIn
+from twistedcaldav.util import submodule
 from twistedcaldav.directory.sudo import SudoDirectoryService
 from twistedcaldav.directory.directory import DirectoryService
 
+log = Logger()
+
+#
+# Alter logger for some twisted stuff
+#
+import twisted
+for m in (
+    "web2.dav.fileop",
+    "web2.dav.element.base",
+    "web2.dav.fileop",
+    "web2.dav.http",
+    "web2.dav.method.acl",
+    "web2.dav.method.copymove",
+    "web2.dav.method.delete",
+    "web2.dav.method.mkcol",
+    "web2.dav.method.prop_common",
+    "web2.dav.method.propfind",
+    "web2.dav.method.proppatch",
+    "web2.dav.method.put",
+    "web2.dav.method.put_common",
+    "web2.dav.method.report",
+    "web2.dav.method.report_acl_principal_prop_set",
+    "web2.dav.method.report_expand",
+    "web2.dav.method.report_principal_match",
+    "web2.dav.method.report_principal_property_search",
+    "web2.dav.method.report_principal_search_property_set",
+    "web2.dav.resource",
+    "web2.dav.static",
+    "web2.dav.util",
+    "web2.dav.xattrprops",
+):
+    submodule(twisted, m).log = Logger("twisted." + m)
+del m
+
 class SudoSACLMixin(object):
     """
     Mixin class to let DAVResource, and DAVFile subclasses below know
@@ -149,7 +185,7 @@
     authorizationPrincipal = deferredGenerator(authorizationPrincipal)
 
 
-class DAVResource (SudoSACLMixin, SuperDAVResource):
+class DAVResource (SudoSACLMixin, SuperDAVResource, LoggingMixIn):
     """
     Extended L{twisted.web2.dav.resource.DAVResource} implementation.
     """
@@ -350,7 +386,7 @@
             
         yield match
 
-class DAVPrincipalResource (SuperDAVPrincipalResource):
+class DAVPrincipalResource (SuperDAVPrincipalResource, LoggingMixIn):
     """
     Extended L{twisted.web2.dav.static.DAVFile} implementation.
     """
@@ -375,7 +411,7 @@
             return davxml.ResourceType(davxml.Principal())
 
 
-class DAVFile (SudoSACLMixin, SuperDAVFile):
+class DAVFile (SudoSACLMixin, SuperDAVFile, LoggingMixIn):
     """
     Extended L{twisted.web2.dav.static.DAVFile} implementation.
     """

Modified: CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/ical.py
===================================================================
--- CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/ical.py	2008-05-07 21:56:53 UTC (rev 2388)
+++ CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/ical.py	2008-05-07 22:25:07 UTC (rev 2389)
@@ -42,13 +42,15 @@
 from vobject.icalendar import stringToDate, stringToDateTime, stringToDurations
 from vobject.icalendar import utc
 
-from twisted.python import log
 from twisted.web2.stream import IStream
 from twisted.web2.dav.util import allDataFromStream
 
 from twistedcaldav.dateops import compareDateTime, normalizeToUTC, timeRangesOverlap
 from twistedcaldav.instance import InstanceList
+from twistedcaldav.log import Logger
 
+log = Logger()
+
 iCalendarProductID = "-//CALENDARSERVER.ORG//NONSGML Version 1//EN"
 
 allowedComponents = (

Modified: CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/index.py
===================================================================
--- CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/index.py	2008-05-07 21:56:53 UTC (rev 2388)
+++ CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/index.py	2008-05-07 22:25:07 UTC (rev 2389)
@@ -37,15 +37,16 @@
 except ImportError:
     from pysqlite2 import dbapi2 as sqlite
 
-from twisted.python import log
+from vobject.icalendar import utc
 
 from twistedcaldav.ical import Component
 from twistedcaldav.query import calendarquery
 from twistedcaldav.sql import AbstractSQLDatabase
 from twistedcaldav.sql import db_prefix
 from twistedcaldav import caldavxml
+from twistedcaldav.log import Logger
 
-from vobject.icalendar import utc
+log = Logger()
 
 db_basename = db_prefix + "sqlite"
 schema_version = "6"

Modified: CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/itip.py
===================================================================
--- CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/itip.py	2008-05-07 21:56:53 UTC (rev 2388)
+++ CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/itip.py	2008-05-07 22:25:07 UTC (rev 2389)
@@ -46,11 +46,14 @@
 from twisted.web2.dav.resource import AccessDeniedError
 
 from twistedcaldav import caldavxml
+from twistedcaldav.log import Logger
 from twistedcaldav.ical import Property, iCalendarProductID
 from twistedcaldav.method import report_common
 from twistedcaldav.method.put_common import storeCalendarObjectResource
 from twistedcaldav.resource import isCalendarCollectionResource
 
+log = Logger()
+
 __version__ = "0.0"
 
 __all__ = [
@@ -111,7 +114,7 @@
     @param child: the L{CalDAVFile} for the iTIP message resource already saved to the Inbox.
     """
     
-    logging.info("[ITIP]: Auto-processing iTIP REQUEST for: %s" % (str(principal),))
+    log.info("Auto-processing iTIP REQUEST for: %s" % (str(principal),))
     processed = "ignored"
 
     # First determine whether this is a full or partial update. A full update is one containing the master
@@ -158,22 +161,22 @@
                         newchild = waitForDeferred(writeResource(request, calURL, updatecal, calmatch, calendar))
                         yield newchild
                         newchild = newchild.getResult()
-                        logging.info("[ITIP]: replaced calendar component %s with new iTIP message in %s." % (calmatch, calURL))
+                        log.info("Replaced calendar component %s with new iTIP message in %s." % (calmatch, calURL))
                     else:
                         newchild = waitForDeferred(writeResource(request, calURL, updatecal, None, calendar))
                         yield newchild
                         newchild.getResult()
-                        logging.info("[ITIP]: added new calendar component in %s." % (calURL,))
+                        log.info("Added new calendar component in %s." % (calURL,))
                 else:
                     if calmatch:
                         d = waitForDeferred(deleteResource(updatecal, calmatch))
                         yield d
                         d.getResult()
-                        logging.info("[ITIP]: deleted calendar component %s in %s as update was not accepted." % (calmatch, calURL))
+                        log.info("Deleted calendar component %s in %s as update was not accepted." % (calmatch, calURL))
                         
                 # Send a reply if needed. 
                 if doreply:
-                    logging.info("[ITIP]: sending iTIP REPLY %s" % (("declined","accepted")[accepted],))
+                    log.info("Sending iTIP REPLY %s" % (("declined","accepted")[accepted],))
                     newchild = waitForDeferred(writeReply(request, principal, replycal, inbox))
                     yield newchild
                     newchild = newchild.getResult()
@@ -231,17 +234,17 @@
                     newchild = waitForDeferred(writeResource(request, calURL, updatecal, calmatch, cal))
                     yield newchild
                     newchild = newchild.getResult()
-                    logging.info("[ITIP]: merged calendar component %s with new iTIP message in %s." % (calmatch, calURL))
+                    log.info("Merged calendar component %s with new iTIP message in %s." % (calmatch, calURL))
                 else:
                     if accepted:
                         newchild = waitForDeferred(writeResource(request, calURL, updatecal, None, calendar))
                         yield newchild
                         newchild.getResult()
-                        logging.info("[ITIP]: added new calendar component in %s." % (calURL,))
+                        log.info("Added new calendar component in %s." % (calURL,))
                         
                 # Do reply if needed. 
                 if doreply:
-                    logging.info("[ITIP]: sending iTIP REPLY %s" % (("declined","accepted")[accepted],))
+                    log.info("Sending iTIP REPLY %s" % (("declined","accepted")[accepted],))
                     newchild = waitForDeferred(writeReply(request, principal, replycal, inbox))
                     yield newchild
                     newchild = newchild.getResult()
@@ -257,11 +260,14 @@
         d = waitForDeferred(deleteResource(inbox, child.fp.basename()))
         yield d
         d.getResult()
-        logging.info("[ITIP]: deleted new iTIP message %s in Inbox because it has been %s." %
-            (child.fp.basename(),
-             {"processed":"processed",
-              "older":    "ignored: older",
-              "ignored":  "ignored: no match"}[processed],))
+        log.info("Deleted new iTIP message %s in Inbox because it has been %s." % (
+                   child.fp.basename(),
+                   {
+                     "processed": "processed",
+                     "older"    : "ignored: older",
+                     "ignored"  : "ignored: no match"
+                   }[processed]
+                ))
     except:
         log.err("Error while auto-processing iTIP: %s" % (failure.Failure(),))
         raise iTipException
@@ -281,7 +287,7 @@
     @param calendar: the L{Component} for the iTIP message we are processing.
     @param child: the L{CalDAVFile} for the iTIP message resource already saved to the Inbox.
     """
-    logging.info("[ITIP]: Auto-processing iTIP ADD for: %s" % (str(principal),))
+    log.info("Auto-processing iTIP ADD for: %s" % (str(principal),))
 
     raise NotImplementedError
 
@@ -322,7 +328,7 @@
     @param child: the L{CalDAVFile} for the iTIP message resource already saved to the Inbox.
     """
     
-    logging.info("[ITIP]: Auto-processing iTIP CANCEL for: %s" % (str(principal),))
+    log.info("Auto-processing iTIP CANCEL for: %s" % (str(principal),))
     processed = "ignored"
 
     # Get all component info for this iTIP message
@@ -366,7 +372,7 @@
                     d = waitForDeferred(deleteResource(updatecal, calmatch,))
                     yield d
                     d.getResult()
-                    logging.info("[ITIP]: delete calendar component %s in %s as it was cancelled." % (calmatch, calURL))
+                    log.info("Delete calendar component %s in %s as it was cancelled." % (calmatch, calURL))
                 except:
                     log.err("Error while auto-processing iTIP: %s" % (failure.Failure(),))
                     raise iTipException
@@ -429,13 +435,13 @@
                     d = waitForDeferred(deleteResource(updatecal, calmatch))
                     yield d
                     d.getResult()
-                    logging.info("[ITIP]: deleted calendar component %s after cancellations from iTIP message in %s." % (calmatch, calURL))
+                    log.info("Deleted calendar component %s after cancellations from iTIP message in %s." % (calmatch, calURL))
                 else:
                     # Update the existing calendar object
                     newchild = waitForDeferred(writeResource(request, calURL, updatecal, calmatch, existing_calendar))
                     yield newchild
                     newchild = newchild.getResult()
-                    logging.info("[ITIP]: updated calendar component %s with cancellations from iTIP message in %s." % (calmatch, calURL))
+                    log.info("Updated calendar component %s with cancellations from iTIP message in %s." % (calmatch, calURL))
                 processed = "processed"
             else:
                 processed = "older"
@@ -448,11 +454,14 @@
         d = waitForDeferred(deleteResource(inbox, child.fp.basename()))
         yield d
         d.getResult()
-        logging.info("[ITIP]: deleted new iTIP message %s in Inbox because it has been %s." %
-            (child.fp.basename(),
-             {"processed":"processed",
-              "older":    "ignored: older",
-              "ignored":  "ignored: no match"}[processed],))
+        log.info("Deleted new iTIP message %s in Inbox because it has been %s." % (
+                  child.fp.basename(),
+                  {
+                    "processed": "processed",
+                    "older"    : "ignored: older",
+                    "ignored"  : "ignored: no match"
+                  }[processed]
+                ))
     except:
         log.err("Error while auto-processing iTIP: %s" % (failure.Failure(),))
         raise iTipException
@@ -519,7 +528,7 @@
                     break
             except NumberOfMatchesWithinLimits:
                 accepted = False
-                logging.info("[ITIP]: exceeded number of matches whilst trying to find free-time.")
+                log.info("Exceeded number of matches whilst trying to find free-time.")
                 break
             
         if not accepted:
@@ -610,7 +619,7 @@
         yield d
         d.getResult()
     except AccessDeniedError:
-        logging.info("[ITIP]: could not send reply as %s does not have CALDAV:schedule permission on %s Inbox." % (principal.principalURL(), organizer))
+        log.info("Could not send reply as %s does not have CALDAV:schedule permission on %s Inbox." % (principal.principalURL(), organizer))
         yield None
         return
     
@@ -751,7 +760,7 @@
                 d = waitForDeferred(deleteResource(inbox, i[0]))
                 yield d
                 d.getResult()
-                logging.info("[ITIP]: deleted iTIP message %s in Inbox that was older than the new one." % (i[0],))
+                log.info("Deleted iTIP message %s in Inbox that was older than the new one." % (i[0],))
             except:
                 log.err("Error while auto-processing iTIP: %s" % (failure.Failure(),))
                 raise iTipException
@@ -765,7 +774,7 @@
             d = waitForDeferred(deleteResource(inbox, child.fp.basename()))
             yield d
             d.getResult()
-            logging.info("[ITIP]: deleted new iTIP message %s in Inbox because it was older than existing ones." % (child.fp.basename(),))
+            log.info("Deleted new iTIP message %s in Inbox because it was older than existing ones." % (child.fp.basename(),))
         except:
             log.err("Error while auto-processing iTIP: %s" % (failure.Failure(),))
             raise iTipException
@@ -797,7 +806,7 @@
             continue
         calmatch = matchComponentInCalendar(updatecal, calendar)
         if calmatch:
-            logging.info("[ITIP]: found calendar component %s matching new iTIP message in %s." % (calmatch, calURL))
+            log.info("Found calendar component %s matching new iTIP message in %s." % (calmatch, calURL))
             break
     
     if calmatch is None and len(fbset):

Copied: CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/log.py (from rev 2388, CalendarServer/trunk/twistedcaldav/log.py)
===================================================================
--- CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/log.py	                        (rev 0)
+++ CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/log.py	2008-05-07 22:25:07 UTC (rev 2389)
@@ -0,0 +1,257 @@
+##
+# Copyright (c) 2006-2007 Apple Inc. All rights reserved.
+#
+# Licensed under the Apache License, Version 2.0 (the "License");
+# you may not use this file except in compliance with the License.
+# You may obtain a copy of the License at
+#
+# http://www.apache.org/licenses/LICENSE-2.0
+#
+# Unless required by applicable law or agreed to in writing, software
+# distributed under the License is distributed on an "AS IS" BASIS,
+# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+# See the License for the specific language governing permissions and
+# limitations under the License.
+##
+
+"""
+Classes and functions to do better logging.
+
+Example usage in a module:
+
+    from twistedcaldav.log import Logger
+    log = Logger()
+
+    log.info("Blah blah")
+
+Or in a class:
+
+    from twistedcaldav.log import LoggingMixIn
+
+    class Foo (LoggingMixIn):
+        def oops(self):
+            self.log_error("Oops!")
+
+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} when instantiating it, but if none
+is given, the logger will derive its own namespace by using the module
+name of the callable that instantiating it, or, in the case of a
+L{LoggingMixIn}, by using the fully qualified name of the class.
+
+In the first example above, the namespace would be C{some.module}, and
+in the second example, it would be C{some.module.Foo}.
+"""
+
+__all__ = [
+    "logLevels",
+    "cmpLogLevels",
+    "lowestLogLevel",
+    "highestLogLevel",
+    "logLevelForNamespace",
+    "setLogLevelForNamespace",
+    "clearLogLevels",
+    "Logger",
+    "LoggingMixIn",
+]
+
+import inspect
+
+from twisted.python import log
+
+logLevels = (
+    "debug",
+    "info",
+    "warn",
+    "error",
+)
+
+logLevelIndexes = dict(zip(logLevels, xrange(0, len(logLevels))))
+
+def cmpLogLevels(a, b):
+    return cmp(logLevelIndexes[a], logLevelIndexes[b])
+
+def lowestLogLevel(*levels):
+    return sorted(levels, cmpLogLevels)[0]
+
+def highestLogLevel(*levels):
+    return sorted(levels, cmpLogLevels, reverse=True)[0]
+
+##
+# Tools for manageing log levels
+##
+
+defaultLogLevel = "info"
+
+logLevelsByNamespace = {}
+
+def logLevelForNamespace(namespace):
+    """
+    @param namespace: a logging namespace, or C{None} to set the
+        default log level.
+    @return: the log level for the given namespace.
+    """
+    if not namespace:
+        return defaultLogLevel
+
+    if namespace in logLevelsByNamespace:
+        return logLevelsByNamespace[namespace]
+
+    segments = namespace.split(".")
+    index = len(segments) - 1
+
+    while index > 0:
+        namespace = ".".join(segments[:index])
+        if namespace in logLevelsByNamespace:
+            return logLevelsByNamespace[namespace]
+        index -= 1
+
+    return defaultLogLevel
+
+def setLogLevelForNamespace(namespace, level):
+    """
+    Sets the log level for a logging namespace.
+    @param namespace: a logging namespace
+    @param level: the log level for the given namespace.
+    """
+    if level not in logLevels:
+        raise InvalidLogLevelError(level)
+
+    if not namespace:
+        global defaultLogLevel
+        defaultLogLevel = level
+
+    logLevelsByNamespace[namespace] = level
+
+def clearLogLevels():
+    """
+    Clears all log levels to the default.
+    """
+    logLevelsByNamespace.clear()
+
+##
+# Loggers
+##
+
+class Logger (object):
+    """
+    Logging object.
+    """
+    def __init__(self, namespace=None):
+        """
+        @param namespace: The namespace for this logger.  Uses a
+            dotted notation, as used by python modules.  If not
+            C{None}, then the name of the module of the caller
+            is used.
+        """
+        if namespace is None:
+            currentFrame = inspect.currentframe()
+            callerFrame  = currentFrame.f_back
+            callerModule = callerFrame.f_globals["__name__"]
+
+            namespace = callerModule
+
+        self.namespace = namespace
+
+    def __repr__(self):
+        return "<%s %r>" % (self.__class__.__name__, self.namespace)
+
+    def emit(self, level, message, **kwargs):
+        """
+        Called internally to emit log messages at a given log level.
+        """
+        assert level in logLevels
+
+        if self.willLogAtLevel(level):
+            log.msg(
+                "[#%s] %s" % (level, message),
+                isError = (cmpLogLevels(level, "error") >= 0),
+                level = level,
+                namespace = self.namespace,
+                **kwargs
+            )
+
+    def level(self):
+        """
+        @return: the logging level for this logger's namespace.
+        """
+        return logLevelForNamespace(self.namespace)
+
+    def setLevel(self, level):
+        """
+        Set the logging level for this logger's namespace.
+        @param level: a logging level
+        """
+        setLogLevelForNamespace(self.namespace, level)
+
+    def willLogAtLevel(self, level):
+        """
+        @param level: a logging level
+        @return: C{True} if this logger will log at the given logging
+            level.
+        """
+        return cmpLogLevels(self.level(), level) <= 0
+
+class LoggingMixIn (object):
+    """
+    Mix-in class for logging methods.
+    """
+    def _getLogger(self):
+        try:
+            return self._logger
+        except AttributeError:
+            namespace = repr(self.__class__)[8:-2]
+
+            assert repr(self.__class__)[:8] == "<class '"
+            assert repr(self.__class__)[-2:] == "'>"
+            assert namespace.find("'") == -1
+
+            self._logger = Logger(namespace)
+
+        return self._logger
+
+    def _setLogger(self, value):
+        self._logger = value
+
+    logger = property(_getLogger, _setLogger)
+
+for level in logLevels:
+    doc = """
+    Emit a log message at log level C{%s}.
+    @param message: The message to emit.
+    """ % (level,)
+
+    #
+    # Attach methods to Logger
+    #
+    def log_emit(self, message, level=level, **kwargs):
+        self.emit(level, message, **kwargs)
+
+    log_emit.__doc__ = doc
+
+    setattr(Logger, level, log_emit)
+
+    #
+    # Attach methods to LoggingMixIn
+    #
+    def log_emit(self, message, level=level, **kwargs):
+        self.logger.emit(level, message, **kwargs)
+
+    log_emit.__doc__ = doc
+
+    setattr(LoggingMixIn, "log_%s" % (level,), log_emit)
+
+del level, log_emit
+
+# Add some compatibility with twisted's log module
+Logger.msg = Logger.info
+Logger.err = Logger.error
+
+##
+# Errors
+##
+
+class InvalidLogLevelError (RuntimeError):
+    def __init__(self, level):
+        super(InvalidLogLevelError, self).__init__(str(level))
+        self.level = level

Deleted: CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/logging.py
===================================================================
--- CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/logging.py	2008-05-07 21:56:53 UTC (rev 2388)
+++ CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/logging.py	2008-05-07 22:25:07 UTC (rev 2389)
@@ -1,371 +0,0 @@
-##
-# Copyright (c) 2006-2007 Apple Inc. All rights reserved.
-#
-# Licensed under the Apache License, Version 2.0 (the "License");
-# you may not use this file except in compliance with the License.
-# You may obtain a copy of the License at
-#
-# http://www.apache.org/licenses/LICENSE-2.0
-#
-# Unless required by applicable law or agreed to in writing, software
-# distributed under the License is distributed on an "AS IS" BASIS,
-# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
-# See the License for the specific language governing permissions and
-# limitations under the License.
-#
-# DRI: Cyrus Daboo, cdaboo at apple.com
-##
-
-"""
-Classes and functions to do better logging.
-"""
-
-import datetime
-import os
-import time
-
-from twisted.python import log
-from twisted.internet import protocol
-
-from twisted.web2 import iweb
-from twisted.web2.dav import davxml
-from twisted.web2.log import BaseCommonAccessLoggingObserver
-from twisted.web2.log import LogWrapperResource
-
-from twistedcaldav.config import config
-from twistedcaldav.directory.directory import DirectoryService
-
-#
-# Logging levels:
-#  0 - no logging
-#  1 - errors only
-#  2 - errors and warnings only
-#  3 - errors, warnings and info
-#  4 - errors, warnings, info and debug
-#
-
-logtypes = {"none": 0, "error": 1, "warning": 2, "info": 3, "debug": 4}
-
-currentLogLevel = logtypes["error"]
-
-def canLog(type):
-    """
-    Determine whether a particular log level type is current active.
-
-    @param type: a string with one of the types above.
-    @return:     True if the log level is currently active.
-    """
-
-    return currentLogLevel >= logtypes.get(type, 1)
-
-def info(message, **kwargs):
-    """
-    Log a message at the "info" level.
-
-    @param message:  message to log.
-    @param **kwargs: additional log arguments.
-    """
-
-    if canLog("info"):
-        log.msg(message, **kwargs)
-
-def warn(message, **kwargs):
-    """
-    Log a message at the "warning" level.
-
-    @param message:  message to log.
-    @param **kwargs: additional log arguments.
-    """
-
-    if canLog("warning"):
-        log.msg(message, **kwargs)
-
-def err(message, **kwargs):
-    """
-    Log a message at the "error" level.
-
-    @param message:  message to log.
-    @param **kwargs: additional log arguments.
-    """
-
-    if canLog("error"):
-        log.msg(message, **kwargs)
-
-def debug(message, **kwargs):
-    """
-    Log a message at the "debug" level.
-
-    @param message:  message to log.
-    @param **kwargs: additional log arguments.
-    """
-
-    if canLog("debug"):
-        log.msg(message, debug=True, **kwargs)
-
-class DirectoryLogWrapperResource(LogWrapperResource):
-    
-    def __init__(self, resource, directory):
-        super(DirectoryLogWrapperResource, self).__init__(resource)
-        
-        self.directory = directory
-        
-    def getDirectory(self):
-        return self.directory
-
-class CommonAccessLoggingObserverExtensions(BaseCommonAccessLoggingObserver):
-    """
-    A base class for our extension to the L{BaseCommonAccessLoggingObserver}
-    """
-
-    def emit(self, eventDict):
-        if eventDict.get('interface') is not iweb.IRequest:
-            return
-
-        request = eventDict['request']
-        response = eventDict['response']
-        loginfo = eventDict['loginfo']
-        firstLine = '%s %s HTTP/%s' %(
-            request.method,
-            request.uri,
-            '.'.join([str(x) for x in request.clientproto]))
-
-        # Try to determine authentication and authorization identifiers
-        uid = "-"
-        if hasattr(request, "authnUser"):
-            if isinstance(request.authnUser.children[0], davxml.HRef):
-                uidn = str(request.authnUser.children[0])
-                uidz = None
-                if hasattr(request, "authzUser") and str(request.authzUser.children[0]) != uidn:
-                    uidz = str(request.authzUser.children[0])
-                    
-                def convertUIDtoShortName(uid):
-                    uid = uid.rstrip("/")
-                    uid = uid[uid.rfind("/") + 1:]
-                    record = request.site.resource.getDirectory().recordWithGUID(uid)
-                    if record:
-                        if record.recordType == DirectoryService.recordType_users:
-                            return record.shortName
-                        else:
-                            return "(%s)%s" % (record.recordType, record.shortName,)
-                    else:
-                        return uid
-                    
-                uidn = convertUIDtoShortName(uidn)
-                if uidz:
-                    uidz = convertUIDtoShortName(uidz)
-                    
-                if uidn and uidz:
-                    uid = '"%s as %s"' % (uidn, uidz,)
-                else:
-                    uid = uidn
-
-        self.logMessage(
-            '%s - %s [%s] "%s" %s %d "%s" "%s" [%.1f ms]' %(
-                request.remoteAddr.host,
-                uid,
-                self.logDateString(
-                    response.headers.getHeader('date', 0)),
-                firstLine,
-                response.code,
-                loginfo.bytesSent,
-                request.headers.getHeader('referer', '-'),
-                request.headers.getHeader('user-agent', '-'),
-                (time.time() - request.initTime) * 1000,
-                )
-            )
-
-
-class RotatingFileAccessLoggingObserver(CommonAccessLoggingObserverExtensions):
-    """
-    Class to do 'apache' style access logging to a rotating log file. The log
-    file is rotated after midnight each day.
-    """
-
-    def __init__(self, logpath):
-        self.logpath = logpath
-
-    def logMessage(self, message, allowrotate=True):
-        """
-        Log a message to the file and possibly rotate if date has changed.
-
-        @param message: C{str} for the message to log.
-        @param allowrotate: C{True} if log rotate allowed, C{False} to log to current file
-            without testing for rotation.
-        """
-
-        if self.shouldRotate() and allowrotate:
-            self.flush()
-            self.rotate()
-        self.f.write(message + '\n')
-
-    def start(self):
-        """
-        Start logging. Open the log file and log an 'open' message.
-        """
-
-        super(RotatingFileAccessLoggingObserver, self).start()
-        self._open()
-        self.logMessage("Log opened - server start: [%s]." % (datetime.datetime.now().ctime(),))
-
-    def stop(self):
-        """
-        Stop logging. Close the log file and log an 'open' message.
-        """
-
-        self.logMessage("Log closed - server stop: [%s]." % (datetime.datetime.now().ctime(),), False)
-        super(RotatingFileAccessLoggingObserver, self).stop()
-        self._close()
-
-    def _open(self):
-        """
-        Open the log file.
-        """
-
-        self.f = open(self.logpath, 'a', 1)
-        self.lastDate = self.toDate(os.stat(self.logpath)[8])
-
-    def _close(self):
-        """
-        Close the log file.
-        """
-
-        self.f.close()
-
-    def flush(self):
-        """
-        Flush the log file.
-        """
-
-        self.f.flush()
-
-    def shouldRotate(self):
-        """
-        Rotate when the date has changed since last write
-        """
-
-        if config.RotateAccessLog:
-            return self.toDate() > self.lastDate
-        else:
-            return False
-
-    def toDate(self, *args):
-        """
-        Convert a unixtime to (year, month, day) localtime tuple,
-        or return the current (year, month, day) localtime tuple.
-
-        This function primarily exists so you may overload it with
-        gmtime, or some cruft to make unit testing possible.
-        """
-
-        # primarily so this can be unit tested easily
-        return time.localtime(*args)[:3]
-
-    def suffix(self, tupledate):
-        """
-        Return the suffix given a (year, month, day) tuple or unixtime
-        """
-
-        try:
-            return '_'.join(map(str, tupledate))
-        except:
-            # try taking a float unixtime
-            return '_'.join(map(str, self.toDate(tupledate)))
-
-    def rotate(self):
-        """
-        Rotate the file and create a new one.
-
-        If it's not possible to open new logfile, this will fail silently,
-        and continue logging to old logfile.
-        """
-
-        newpath = "%s.%s" % (self.logpath, self.suffix(self.lastDate))
-        if os.path.exists(newpath):
-            log.msg("Cannot rotate log file to %s because it already exists." % (newpath,))
-            return
-        self.logMessage("Log closed - rotating: [%s]." % (datetime.datetime.now().ctime(),), False)
-        info("Rotating log file to: %s" % (newpath,), system="Logging")
-        self.f.close()
-        os.rename(self.logpath, newpath)
-        self._open()
-        self.logMessage("Log opened - rotated: [%s]." % (datetime.datetime.now().ctime(),), False)
-
-
-from twisted.protocols import amp
-
-
-class LogMessage(amp.Command):
-    arguments = [('message', amp.String())]
-
-
-class AMPCommonAccessLoggingObserver(CommonAccessLoggingObserverExtensions):
-    def __init__(self, socket):
-        self.socket = socket
-        self.protocol = None
-        self._buffer = []
-
-    def flushBuffer(self):
-        if self._buffer:
-            for msg in self._buffer:
-                self.logMessage(msg)
-
-    def start(self):
-        super(AMPCommonAccessLoggingObserver, self).start()
-
-        from twisted.internet import reactor
-
-        def _gotProtocol(proto):
-            self.protocol = proto
-            self.flushBuffer()
-
-        self.client = protocol.ClientCreator(reactor, amp.AMP)
-        d = self.client.connectUNIX(self.socket)
-        d.addCallback(_gotProtocol)
-
-    def stop(self):
-        super(AMPCommonAccessLoggingObserver, self).stop()
-        self.client.disconnect()
-
-    def logMessage(self, message):
-        """
-        Log a message to the remote AMP Protocol
-        """
-        if self.protocol is not None:
-            # XXX: Yeah we're not waiting for anything to happen here.
-            #      but we will log an error.
-            d = self.protocol.callRemote(LogMessage, message=message)
-            d.addErrback(log.err)
-        else:
-            self._buffer.append(message)
-
-
-class AMPLoggingProtocol(amp.AMP):
-    """
-    A server side protocol for logging to the given observer.
-    """
-
-    def __init__(self, observer):
-        self.observer = observer
-
-        super(AMPLoggingProtocol, self).__init__()
-
-    def logMessage(self, message):
-        self.observer.logMessage(message)
-        return {}
-
-    LogMessage.responder(logMessage)
-
-
-class AMPLoggingFactory(protocol.ServerFactory):
-    def __init__(self, observer):
-        self.observer = observer
-
-    def doStart(self):
-        self.observer.start()
-
-    def doStop(self):
-        self.observer.stop()
-
-    def buildProtocol(self, addr):
-        return AMPLoggingProtocol(self.observer)
-

Modified: CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/method/copymove.py
===================================================================
--- CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/method/copymove.py	2008-05-07 21:56:53 UTC (rev 2388)
+++ CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/method/copymove.py	2008-05-07 22:25:07 UTC (rev 2389)
@@ -25,7 +25,6 @@
 from urlparse import urlsplit
 
 from twisted.internet.defer import deferredGenerator, waitForDeferred
-from twisted.python import log
 from twisted.web2 import responsecode
 from twisted.web2.filter.location import addLocation
 from twisted.web2.dav import davxml
@@ -36,7 +35,10 @@
 from twistedcaldav.caldavxml import caldav_namespace
 from twistedcaldav.method.put_common import storeCalendarObjectResource
 from twistedcaldav.resource import isCalendarCollectionResource
+from twistedcaldav.log import Logger
 
+log = Logger()
+
 def http_COPY(self, request):
     """
     Special handling of COPY request if parents are calendar collections.

Modified: CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/method/mkcalendar.py
===================================================================
--- CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/method/mkcalendar.py	2008-05-07 21:56:53 UTC (rev 2388)
+++ CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/method/mkcalendar.py	2008-05-07 22:25:07 UTC (rev 2389)
@@ -23,7 +23,6 @@
 __all__ = ["http_MKCALENDAR"]
 
 from twisted.internet.defer import deferredGenerator, waitForDeferred
-from twisted.python import log
 from twisted.python.failure import Failure
 from twisted.web2 import responsecode
 from twisted.web2.dav import davxml
@@ -33,7 +32,10 @@
 from twisted.web2.http import HTTPError, StatusResponse
 
 from twistedcaldav import caldavxml
+from twistedcaldav.log import Logger
 
+log = Logger()
+
 def http_MKCALENDAR(self, request):
     """
     Respond to a MKCALENDAR request.

Modified: CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/method/propfind.py
===================================================================
--- CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/method/propfind.py	2008-05-07 21:56:53 UTC (rev 2388)
+++ CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/method/propfind.py	2008-05-07 22:25:07 UTC (rev 2389)
@@ -27,7 +27,6 @@
 
 __all__ = ["http_PROPFIND"]
 
-from twisted.python import log
 from twisted.python.failure import Failure
 from twisted.internet.defer import deferredGenerator, waitForDeferred
 from twisted.web2.http import HTTPError
@@ -37,6 +36,10 @@
 from twisted.web2.dav.http import MultiStatusResponse, statusForFailure
 from twisted.web2.dav.util import normalizeURL, davXMLFromStream
 
+from twistedcaldav.log import Logger
+
+log = Logger()
+
 """
 This is a direct copy of the twisted implementation of PROPFIND except that it uses the
 findChildrenFaster method to optimize child privilege checking.

Modified: CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/method/put.py
===================================================================
--- CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/method/put.py	2008-05-07 21:56:53 UTC (rev 2388)
+++ CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/method/put.py	2008-05-07 22:25:07 UTC (rev 2389)
@@ -23,7 +23,6 @@
 __all__ = ["http_PUT"]
 
 from twisted.internet.defer import deferredGenerator, waitForDeferred
-from twisted.python import log
 from twisted.web2 import responsecode
 from twisted.web2.dav.http import ErrorResponse
 from twisted.web2.dav.util import allDataFromStream, parentForURL
@@ -32,7 +31,10 @@
 from twistedcaldav.caldavxml import caldav_namespace
 from twistedcaldav.method.put_common import storeCalendarObjectResource
 from twistedcaldav.resource import isPseudoCalendarCollectionResource
+from twistedcaldav.log import Logger
 
+log = Logger()
+
 def http_PUT(self, request):
 
     parentURL = parentForURL(request.uri)

Modified: CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/method/put_common.py
===================================================================
--- CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/method/put_common.py	2008-05-07 21:56:53 UTC (rev 2388)
+++ CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/method/put_common.py	2008-05-07 22:25:07 UTC (rev 2389)
@@ -28,7 +28,7 @@
 from twisted.internet.defer import maybeDeferred
 from twisted.internet.defer import succeed
 from twisted.internet.defer import waitForDeferred
-from twisted.python import failure, log
+from twisted.python import failure
 from twisted.python.filepath import FilePath
 from twisted.web2 import responsecode
 from twisted.web2.dav import davxml
@@ -44,7 +44,6 @@
 from twisted.web2.iweb import IResponse
 from twisted.web2.stream import MemoryStream
 
-from twistedcaldav import logging
 from twistedcaldav.config import config
 from twistedcaldav.caldavxml import NoUIDConflict
 from twistedcaldav.caldavxml import NumberOfRecurrencesWithinLimits
@@ -58,7 +57,10 @@
 from twistedcaldav.index import ReservationError
 from twistedcaldav.instance import TooManyInstancesError
 from twistedcaldav.resource import CalDAVResource
+from twistedcaldav.log import Logger
 
+log = Logger()
+
 @deferredGenerator
 def storeCalendarObjectResource(
     request,
@@ -133,36 +135,35 @@
             """
             if self.active:
                 self.active = False
-                if logging.canLog("debug"):    
-                    logging.debug("Rollback: rollback", system="Store Resource")
+                log.debug("Rollback: rollback")
                 try:
                     if self.source_copy and self.source_deleted:
                         self.source_copy.moveTo(source.fp)
-                        logging.debug("Rollback: source restored %s to %s" % (self.source_copy.path, source.fp.path), system="Store Resource")
+                        log.debug("Rollback: source restored %s to %s" % (self.source_copy.path, source.fp.path))
                         self.source_copy = None
                         self.source_deleted = False
                     if self.destination_copy:
                         destination.fp.remove()
-                        logging.debug("Rollback: destination restored %s to %s" % (self.destination_copy.path, destination.fp.path), system="Store Resource")
+                        log.debug("Rollback: destination restored %s to %s" % (self.destination_copy.path, destination.fp.path))
                         self.destination_copy.moveTo(destination.fp)
                         self.destination_copy = None
                     elif self.destination_created:
                         if destinationcal:
                             doRemoveDestinationIndex()
-                            logging.debug("Rollback: destination index removed %s" % (destination.fp.path,), system="Store Resource")
+                            log.debug("Rollback: destination index removed %s" % (destination.fp.path,))
                             self.destination_index_deleted = False
                         destination.fp.remove()
-                        logging.debug("Rollback: destination removed %s" % (destination.fp.path,), system="Store Resource")
+                        log.debug("Rollback: destination removed %s" % (destination.fp.path,))
                         self.destination_created = False
                     if self.destination_index_deleted:
                         # Must read in calendar for destination being re-indexed
                         doDestinationIndex(destination.iCalendar())
                         self.destination_index_deleted = False
-                        logging.debug("Rollback: destination re-indexed %s" % (destination.fp.path,), system="Store Resource")
+                        log.debug("Rollback: destination re-indexed %s" % (destination.fp.path,))
                     if self.source_index_deleted:
                         doSourceIndexRecover()
                         self.destination_index_deleted = False
-                        logging.debug("Rollback: source re-indexed %s" % (source.fp.path,), system="Store Resource")
+                        log.debug("Rollback: source re-indexed %s" % (source.fp.path,))
                 except:
                     log.err("Rollback: exception caught and not handled: %s" % failure.Failure())
 
@@ -171,15 +172,15 @@
             Commit the resource changes by wiping the rollback state.
             """
             if self.active:
-                logging.debug("Rollback: commit", system="Store Resource")
+                log.debug("Rollback: commit")
                 self.active = False
                 if self.source_copy:
                     self.source_copy.remove()
-                    logging.debug("Rollback: removed source backup %s" % (self.source_copy.path,), system="Store Resource")
+                    log.debug("Rollback: removed source backup %s" % (self.source_copy.path,))
                     self.source_copy = None
                 if self.destination_copy:
                     self.destination_copy.remove()
-                    logging.debug("Rollback: removed destination backup %s" % (self.destination_copy.path,), system="Store Resource")
+                    log.debug("Rollback: removed destination backup %s" % (self.destination_copy.path,))
                     self.destination_copy = None
                 self.destination_created = False
                 self.source_deleted = False
@@ -489,16 +490,16 @@
             rollback.destination_copy = FilePath(destination.fp.path)
             rollback.destination_copy.path += ".rollback"
             copyToWithXAttrs(destination.fp, rollback.destination_copy)
-            logging.debug("Rollback: backing up destination %s to %s" % (destination.fp.path, rollback.destination_copy.path), system="Store Resource")
+            log.debug("Rollback: backing up destination %s to %s" % (destination.fp.path, rollback.destination_copy.path))
         else:
             rollback.destination_created = True
-            logging.debug("Rollback: will create new destination %s" % (destination.fp.path,), system="Store Resource")
+            log.debug("Rollback: will create new destination %s" % (destination.fp.path,))
 
         if deletesource:
             rollback.source_copy = FilePath(source.fp.path)
             rollback.source_copy.path += ".rollback"
             copyToWithXAttrs(source.fp, rollback.source_copy)
-            logging.debug("Rollback: backing up source %s to %s" % (source.fp.path, rollback.source_copy.path), system="Store Resource")
+            log.debug("Rollback: backing up source %s to %s" % (source.fp.path, rollback.source_copy.path))
     
         """
         Handle actual store operations here.
@@ -562,7 +563,7 @@
             # Add or update the index for this resource.
             try:
                 destination_index.addResource(destination.fp.basename(), caltoindex)
-                logging.debug("Destination indexed %s" % (destination.fp.path,), system="Store Resource")
+                log.debug("Destination indexed %s" % (destination.fp.path,))
             except TooManyInstancesError, ex:
                 log.err("Cannot index calendar resource as there are too many recurrence instances %s" % destination)
                 raise HTTPError(ErrorResponse(
@@ -585,19 +586,19 @@
             if destinationcal:
                 destination_index.deleteResource(destination.fp.basename())
                 rollback.destination_index_deleted = True
-                logging.debug("Destination index removed %s" % (destination.fp.path,), system="Store Resource")
+                log.debug("Destination index removed %s" % (destination.fp.path,))
 
         def doSourceDelete():
             # Delete index for original item
             if sourcecal:
                 source_index.deleteResource(source.fp.basename())
                 rollback.source_index_deleted = True
-                logging.debug("Source index removed %s" % (source.fp.path,), system="Store Resource")
+                log.debug("Source index removed %s" % (source.fp.path,))
 
             # Delete the source resource
             delete(source_uri, source.fp, "0")
             rollback.source_deleted = True
-            logging.debug("Source removed %s" % (source.fp.path,), system="Store Resource")
+            log.debug("Source removed %s" % (source.fp.path,))
 
         def doSourceIndexRecover():
             """

Modified: CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/method/report.py
===================================================================
--- CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/method/report.py	2008-05-07 21:56:53 UTC (rev 2388)
+++ CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/method/report.py	2008-05-07 22:25:07 UTC (rev 2389)
@@ -31,7 +31,6 @@
 
 import string
 
-from twisted.python import log
 from twisted.internet.defer import deferredGenerator, waitForDeferred
 from twisted.web2 import responsecode
 from twisted.web2.http import HTTPError, StatusResponse
@@ -41,7 +40,10 @@
 from twisted.web2.dav.util import davXMLFromStream
 
 from twistedcaldav import caldavxml
+from twistedcaldav.log import Logger
 
+log = Logger()
+
 max_number_of_matches = 500
 
 class NumberOfMatchesWithinLimits(Exception):

Modified: CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/method/report_calquery.py
===================================================================
--- CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/method/report_calquery.py	2008-05-07 21:56:53 UTC (rev 2388)
+++ CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/method/report_calquery.py	2008-05-07 22:25:07 UTC (rev 2389)
@@ -22,8 +22,9 @@
 
 __all__ = ["report_urn_ietf_params_xml_ns_caldav_calendar_query"]
 
+import urllib
+
 from twisted.internet.defer import deferredGenerator, succeed, waitForDeferred
-from twisted.python import log
 from twisted.web2 import responsecode
 from twisted.web2.dav import davxml
 from twisted.web2.dav.element.base import dav_namespace
@@ -35,8 +36,9 @@
 from twistedcaldav.caldavxml import caldav_namespace
 from twistedcaldav.customxml import TwistedCalendarAccessProperty
 from twistedcaldav.method import report_common
+from twistedcaldav.log import Logger
 
-import urllib
+log = Logger()
 
 max_number_of_results = 1000
 

Modified: CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/method/report_common.py
===================================================================
--- CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/method/report_common.py	2008-05-07 21:56:53 UTC (rev 2388)
+++ CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/method/report_common.py	2008-05-07 22:25:07 UTC (rev 2389)
@@ -28,8 +28,13 @@
     "buildFreeBusyResult",
 ]
 
+import datetime
+import md5
+import time
+
+from vobject.icalendar import utc
+
 from twisted.internet.defer import deferredGenerator, waitForDeferred
-from twisted.python import log
 from twisted.python.failure import Failure
 from twisted.web2 import responsecode
 from twisted.web2.dav import davxml
@@ -47,13 +52,10 @@
 from twistedcaldav.dateops import clipPeriod, normalizePeriodList, timeRangesOverlap
 from twistedcaldav.ical import Component, Property, iCalendarProductID
 from twistedcaldav.instance import InstanceList
+from twistedcaldav.log import Logger
 
-from vobject.icalendar import utc
+log = Logger()
 
-import datetime
-import md5
-import time
-
 def applyToCalendarCollections(resource, request, request_uri, depth, apply, privileges):
     """
     Run an operation on all calendar collections, starting at the specified

Modified: CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/method/report_freebusy.py
===================================================================
--- CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/method/report_freebusy.py	2008-05-07 21:56:53 UTC (rev 2388)
+++ CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/method/report_freebusy.py	2008-05-07 22:25:07 UTC (rev 2389)
@@ -23,7 +23,6 @@
 __all__ = ["report_urn_ietf_params_xml_ns_caldav_free_busy_query"]
 
 from twisted.internet.defer import deferredGenerator, waitForDeferred
-from twisted.python import log
 from twisted.web2 import responsecode
 from twisted.web2.dav.element.base import dav_namespace
 from twisted.web2.dav.http import ErrorResponse
@@ -34,7 +33,10 @@
 
 from twistedcaldav import caldavxml
 from twistedcaldav.method import report_common
+from twistedcaldav.log import Logger
 
+log = Logger()
+
 def report_urn_ietf_params_xml_ns_caldav_free_busy_query(self, request, freebusy): #@UnusedVariable
     """
     Generate a free-busy REPORT.

Modified: CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/method/report_multiget.py
===================================================================
--- CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/method/report_multiget.py	2008-05-07 21:56:53 UTC (rev 2388)
+++ CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/method/report_multiget.py	2008-05-07 22:25:07 UTC (rev 2389)
@@ -22,8 +22,9 @@
 
 __all__ = ["report_urn_ietf_params_xml_ns_caldav_calendar_multiget"]
 
+from urllib import unquote
+
 from twisted.internet.defer import deferredGenerator, waitForDeferred
-from twisted.python import log
 from twisted.web2 import responsecode
 from twisted.web2.dav import davxml
 from twisted.web2.dav.element.base import dav_namespace
@@ -34,8 +35,9 @@
 
 from twistedcaldav.caldavxml import caldav_namespace
 from twistedcaldav.method import report_common
+from twistedcaldav.log import Logger
 
-from urllib import unquote
+log = Logger()
 
 max_number_of_multigets = 5000
 

Modified: CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/pdmonster.py
===================================================================
--- CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/pdmonster.py	2008-05-07 21:56:53 UTC (rev 2388)
+++ CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/pdmonster.py	2008-05-07 22:25:07 UTC (rev 2389)
@@ -4,9 +4,9 @@
 
 from twisted.web2.resource import WrapperResource
 
-from twistedcaldav import logging
+from twistedcaldav.log import LoggingMixIn
 
-class PDClientAddressWrapper(WrapperResource):
+class PDClientAddressWrapper(WrapperResource, LoggingMixIn):
     def __init__(self, resource, socket, directory):
         super(PDClientAddressWrapper, self).__init__(resource)
 
@@ -31,10 +31,10 @@
             result.trap(amp.RemoteAmpError)
             if result.value.errorCode != 'UNKNOWN_PORT':
                 return result
-            logging.err('Unknown Port: %s' % (request.remoteAddr,))
+            self.log_error('Unknown Port: %s' % (request.remoteAddr,))
 
         def _gotAddress(result):
-            logging.debug('result = %r' % (result,))
+            self.log_debug('result = %r' % (result,))
             request.remoteAddr = address.IPv4Address(
                 'TCP',
                 result['host'],
@@ -46,7 +46,7 @@
                 return
 
             host, port = request.remoteAddr.host, request.remoteAddr.port
-            logging.debug("GetClientAddress(host=%r, port=%r)" % (host, port))
+            self.log_debug("GetClientAddress(host=%r, port=%r)" % (host, port))
             d = self.protocol.callRemoteString("GetClientAddress",
                                                   host=host,
                                                   port=str(port))

Modified: CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/root.py
===================================================================
--- CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/root.py	2008-05-07 21:56:53 UTC (rev 2388)
+++ CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/root.py	2008-05-07 22:25:07 UTC (rev 2389)
@@ -17,7 +17,6 @@
 ##
 
 from twisted.internet import defer
-from twisted.python import log
 from twisted.python.failure import Failure
 from twisted.cred.error import LoginFailed, UnauthorizedLogin
 
@@ -28,7 +27,10 @@
 
 from twistedcaldav.extensions import DAVFile
 from twistedcaldav.config import config
+from twistedcaldav.log import Logger
 
+log = Logger()
+
 class RootResource(DAVFile):
     """
     A special root resource that contains support checking SACLs

Modified: CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/schedule.py
===================================================================
--- CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/schedule.py	2008-05-07 21:56:53 UTC (rev 2388)
+++ CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/schedule.py	2008-05-07 22:25:07 UTC (rev 2389)
@@ -25,6 +25,9 @@
     "ScheduleOutboxResource",
 ]
 
+import md5
+import time
+
 from twisted.internet import reactor
 from twisted.internet.defer import deferredGenerator, maybeDeferred, succeed, waitForDeferred
 from twisted.python import log
@@ -39,6 +42,8 @@
 
 from twistedcaldav import caldavxml
 from twistedcaldav import itip
+from twistedcaldav.log import LoggingMixIn
+from twistedcaldav.accounting import accountingEnabled, emitAccounting
 from twistedcaldav.resource import CalDAVResource
 from twistedcaldav.caldavxml import caldav_namespace, TimeRange
 from twistedcaldav.config import config
@@ -48,9 +53,6 @@
 from twistedcaldav.method.put_common import storeCalendarObjectResource
 from twistedcaldav.resource import isCalendarCollectionResource
 
-import md5
-import time
-
 class CalendarSchedulingCollectionResource (CalDAVResource):
     """
     CalDAV principal resource.
@@ -204,13 +206,13 @@
         # Must be content-type text/calendar
         contentType = request.headers.getHeader("content-type")
         if contentType is not None and (contentType.mediaType, contentType.mediaSubtype) != ("text", "calendar"):
-            log.err("MIME type %s not allowed in calendar collection" % (contentType,))
+            self.log_error("MIME type %s not allowed in calendar collection" % (contentType,))
             raise HTTPError(ErrorResponse(responsecode.FORBIDDEN, (caldav_namespace, "supported-calendar-data")))
     
         # Must have Originator header
         originator = request.headers.getRawHeaders("originator")
         if originator is None or (len(originator) != 1):
-            log.err("POST request must have Originator header")
+            self.log_error("POST request must have Originator header")
             raise HTTPError(ErrorResponse(responsecode.FORBIDDEN, (caldav_namespace, "originator-specified")))
         else:
             originator = originator[0]
@@ -218,23 +220,23 @@
         # Verify that Originator is a valid calendar user (has an INBOX)
         originatorPrincipal = self.principalForCalendarUserAddress(originator)
         if originatorPrincipal is None:
-            log.err("Could not find principal for originator: %s" % (originator,))
+            self.log_error("Could not find principal for originator: %s" % (originator,))
             raise HTTPError(ErrorResponse(responsecode.FORBIDDEN, (caldav_namespace, "originator-allowed")))
 
         inboxURL = originatorPrincipal.scheduleInboxURL()
         if inboxURL is None:
-            log.err("Could not find inbox for originator: %s" % (originator,))
+            self.log_error("Could not find inbox for originator: %s" % (originator,))
             raise HTTPError(ErrorResponse(responsecode.FORBIDDEN, (caldav_namespace, "originator-allowed")))
     
         # Verify that Originator matches the authenticated user
         if davxml.Principal(davxml.HRef(originatorPrincipal.principalURL())) != self.currentPrincipal(request):
-            log.err("Originator: %s does not match authorized user: %s" % (originator, self.currentPrincipal(request).children[0],))
+            self.log_error("Originator: %s does not match authorized user: %s" % (originator, self.currentPrincipal(request).children[0],))
             raise HTTPError(ErrorResponse(responsecode.FORBIDDEN, (caldav_namespace, "originator-allowed")))
 
         # Get list of Recipient headers
         rawRecipients = request.headers.getRawHeaders("recipient")
         if rawRecipients is None or (len(rawRecipients) == 0):
-            log.err("POST request must have at least one Recipient header")
+            self.log_error("POST request must have at least one Recipient header")
             raise HTTPError(ErrorResponse(responsecode.FORBIDDEN, (caldav_namespace, "recipient-specified")))
 
         # Recipient header may be comma separated list
@@ -254,29 +256,29 @@
             yield d
             calendar = d.getResult()
         except:
-            log.err("Error while handling POST: %s" % (Failure(),))
+            self.log_error("Error while handling POST: %s" % (Failure(),))
             raise HTTPError(ErrorResponse(responsecode.FORBIDDEN, (caldav_namespace, "valid-calendar-data")))
  
         # Must be a valid calendar
         try:
             calendar.validCalendarForCalDAV()
         except ValueError:
-            log.err("POST request calendar component is not valid: %s" % (calendar,))
+            self.log_error("POST request calendar component is not valid: %s" % (calendar,))
             raise HTTPError(ErrorResponse(responsecode.FORBIDDEN, (caldav_namespace, "valid-calendar-data")))
 
         # Must have a METHOD
         if not calendar.isValidMethod():
-            log.err("POST request must have valid METHOD property in calendar component: %s" % (calendar,))
+            self.log_error("POST request must have valid METHOD property in calendar component: %s" % (calendar,))
             raise HTTPError(ErrorResponse(responsecode.FORBIDDEN, (caldav_namespace, "valid-calendar-data")))
         
         # Verify iTIP behaviour
         if not calendar.isValidITIP():
-            log.err("POST request must have a calendar component that satisfies iTIP requirements: %s" % (calendar,))
+            self.log_error("POST request must have a calendar component that satisfies iTIP requirements: %s" % (calendar,))
             raise HTTPError(ErrorResponse(responsecode.FORBIDDEN, (caldav_namespace, "valid-calendar-data")))
 
         # X-CALENDARSERVER-ACCESS is not allowed in Outbox POSTs
         if calendar.hasProperty(Component.ACCESS_PROPERTY):
-            log.err("X-CALENDARSERVER-ACCESS not allowed in a calendar component POST request: %s" % (calendar,), system="CalDAV Outbox POST")
+            self.log_error("X-CALENDARSERVER-ACCESS not allowed in a calendar component POST request: %s" % (calendar,))
             raise HTTPError(ErrorResponse(responsecode.FORBIDDEN, (calendarserver_namespace, "no-access-restrictions")))
     
         # Verify that the ORGANIZER's cu address maps to the request.uri
@@ -287,7 +289,7 @@
             organizerPrincipal = self.principalForCalendarUserAddress(organizer)
 
         if organizerPrincipal is None:
-            log.err("ORGANIZER in calendar data is not valid: %s" % (calendar,))
+            self.log_error("ORGANIZER in calendar data is not valid: %s" % (calendar,))
             raise HTTPError(ErrorResponse(responsecode.FORBIDDEN, (caldav_namespace, "organizer-allowed")))
 
         # Prevent spoofing of ORGANIZER with specific METHODs
@@ -295,7 +297,7 @@
             calendar.propertyValue("METHOD") in ("PUBLISH", "REQUEST", "ADD", "CANCEL", "DECLINECOUNTER") and
             organizerPrincipal.record != self.parent.record
         ):
-            log.err("ORGANIZER in calendar data does not match owner of Outbox: %s" % (calendar,))
+            self.log_error("ORGANIZER in calendar data does not match owner of Outbox: %s" % (calendar,))
             raise HTTPError(ErrorResponse(responsecode.FORBIDDEN, (caldav_namespace, "organizer-allowed")))
 
         # Prevent spoofing when doing reply-like METHODs
@@ -306,26 +308,27 @@
         
             # Must have only one
             if len(attendees) != 1:
-                log.err("ATTENDEE list in calendar data is wrong: %s" % (calendar,))
+                self.log_error("ATTENDEE list in calendar data is wrong: %s" % (calendar,))
                 raise HTTPError(ErrorResponse(responsecode.FORBIDDEN, (caldav_namespace, "attendee-allowed")))
             
             # Attendee's Outbox MUST be the request URI
             attendeePrincipal = self.principalForCalendarUserAddress(attendees[0])
             if attendeePrincipal is None or attendeePrincipal.record != self.parent.record:
-                log.err("ATTENDEE in calendar data does not match owner of Outbox: %s" % (calendar,))
+                self.log_error("ATTENDEE in calendar data does not match owner of Outbox: %s" % (calendar,))
                 raise HTTPError(ErrorResponse(responsecode.FORBIDDEN, (caldav_namespace, "attendee-allowed")))
 
         # For free-busy do immediate determination of iTIP result rather than fan-out
+        self.log_info("METHOD: %s, Component: %s" % (calendar.propertyValue("METHOD"), calendar.mainType(),))
         if (calendar.propertyValue("METHOD") == "REQUEST") and (calendar.mainType() == "VFREEBUSY"):
             # Extract time range from VFREEBUSY object
             vfreebusies = [v for v in calendar.subcomponents() if v.name() == "VFREEBUSY"]
             if len(vfreebusies) != 1:
-                log.err("iTIP data is not valid for a VFREEBUSY request: %s" % (calendar,))
+                self.log_error("iTIP data is not valid for a VFREEBUSY request: %s" % (calendar,))
                 raise HTTPError(ErrorResponse(responsecode.FORBIDDEN, (caldav_namespace, "valid-calendar-data")))
             dtstart = vfreebusies[0].getStartDateUTC()
             dtend = vfreebusies[0].getEndDateUTC()
             if dtstart is None or dtend is None:
-                log.err("VFREEBUSY start/end not valid: %s" % (calendar,))
+                self.log_error("VFREEBUSY start/end not valid: %s" % (calendar,))
                 raise HTTPError(ErrorResponse(responsecode.FORBIDDEN, (caldav_namespace, "valid-calendar-data")))
             timeRange.start = dtstart
             timeRange.end = dtend
@@ -339,6 +342,21 @@
             # Do regular invite (fan-out)
             freebusy = False
 
+        #
+        # Accounting
+        #
+        # Note that we associate logging with the organizer, not the
+        # originator, which is good for looking for why something
+        # shows up in a given principal's calendars, rather than
+        # tracking the activities of a specific user.
+        #
+        if accountingEnabled("iTIP", organizerPrincipal):
+            emitAccounting(
+                "iTIP", organizerPrincipal,
+                "Originator: %s\nRecipients: %s\n\n%s"
+                % (originator, ", ".join(recipients), str(calendar))
+            )
+
         # Prepare for multiple responses
         responses = ScheduleResponseQueue("POST", responsecode.OK)
     
@@ -351,7 +369,7 @@
             # Map recipient to their inbox
             inbox = None
             if principal is None:
-                log.err("No schedulable principal for calendar user address: %s" % (recipient,))
+                self.log_error("No schedulable principal for calendar user address: %r" % (recipient,))
             else:
                 inboxURL = principal.scheduleInboxURL()
                 if inboxURL:
@@ -359,7 +377,7 @@
                     yield inbox
                     inbox = inbox.getResult()
                 else:
-                    log.err("No schedule inbox for principal: %s" % (principal,))
+                    self.log_error("No schedule inbox for principal: %s" % (principal,))
 
             if inbox is None:
                 err = HTTPError(ErrorResponse(responsecode.NOT_FOUND, (caldav_namespace, "recipient-exists")))
@@ -377,7 +395,7 @@
                     yield d
                     d.getResult()
                 except AccessDeniedError:
-                    log.err("Could not access Inbox for recipient: %s" % (recipient,))
+                    self.log_error("Could not access Inbox for recipient: %s" % (recipient,))
                     err = HTTPError(ErrorResponse(responsecode.NOT_FOUND, (caldav_namespace, "recipient-permisions")))
                     responses.add(recipient, Failure(exc_value=err), reqstatus="3.8;No authority")
                     recipientsState["BAD"] += 1
@@ -453,7 +471,7 @@
                         recipientsState["OK"] += 1
                 
                     except:
-                        log.err("Could not determine free busy information: %s" % (recipient,))
+                        self.log_error("Could not determine free busy information: %s" % (recipient,))
                         err = HTTPError(ErrorResponse(responsecode.FORBIDDEN, (caldav_namespace, "recipient-permissions")))
                         responses.add(recipient, Failure(exc_value=err), reqstatus="3.8;No authority")
                         recipientsState["BAD"] += 1
@@ -498,7 +516,7 @@
                         if principal.autoSchedule():
                             autoresponses.append((principal, inbox, child))
                     except:
-                        log.err("Could not store data in Inbox : %s" % (inbox,))
+                        self.log_error("Could not store data in Inbox : %s" % (inbox,))
                         err = HTTPError(ErrorResponse(responsecode.FORBIDDEN, (caldav_namespace, "recipient-permissions")))
                         responses.add(recipient, Failure(exc_value=err), reqstatus="3.8;No authority")
                         recipientsState["BAD"] += 1
@@ -538,7 +556,7 @@
         if location is not None:
             self.headers.setHeader("location", location)
 
-class ScheduleResponseQueue (object):
+class ScheduleResponseQueue (LoggingMixIn):
     """
     Stores a list of (typically error) responses for use in a
     L{ScheduleResponse}.
@@ -581,7 +599,7 @@
             raise AssertionError("Unknown data type: %r" % (what,))
 
         if code > 400: # Error codes only
-            log.err("Error during %s for %s: %s" % (self.method, recipient, message))
+            self.log_error("Error during %s for %s: %s" % (self.method, recipient, message))
 
         children = []
         children.append(caldavxml.Recipient(davxml.HRef.fromString(recipient)))

Modified: CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/sql.py
===================================================================
--- CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/sql.py	2008-05-07 21:56:53 UTC (rev 2388)
+++ CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/sql.py	2008-05-07 22:25:07 UTC (rev 2389)
@@ -31,8 +31,10 @@
 except ImportError:
     from pysqlite2 import dbapi2 as sqlite
 
-from twisted.python import log
+from twistedcaldav.log import Logger
 
+log = Logger()
+
 db_prefix = ".db."
 
 class AbstractSQLDatabase(object):

Modified: CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/static.py
===================================================================
--- CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/static.py	2008-05-07 21:56:53 UTC (rev 2388)
+++ CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/static.py	2008-05-07 22:25:07 UTC (rev 2389)
@@ -42,7 +42,6 @@
 from urlparse import urlsplit
 
 from twisted.internet.defer import deferredGenerator, fail, succeed, waitForDeferred
-from twisted.python import log
 from twisted.web2 import responsecode
 from twisted.web2.http import HTTPError, StatusResponse
 from twisted.web2.dav import davxml
@@ -73,7 +72,10 @@
 from twistedcaldav.directory.calendar import DirectoryCalendarHomeUIDProvisioningResource
 from twistedcaldav.directory.calendar import DirectoryCalendarHomeResource
 from twistedcaldav.directory.resource import AutoProvisioningResourceMixIn
+from twistedcaldav.log import Logger
 
+log = Logger()
+
 class CalDAVFile (CalDAVResource, DAVFile):
     """
     CalDAV-accessible L{DAVFile} resource.

Modified: CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/tap.py
===================================================================
--- CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/tap.py	2008-05-07 21:56:53 UTC (rev 2388)
+++ CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/tap.py	2008-05-07 22:25:07 UTC (rev 2389)
@@ -21,7 +21,7 @@
 
 from zope.interface import implements
 
-from twisted.python import log
+from twisted.python.log import FileLogObserver
 from twisted.python.usage import Options, UsageError
 from twisted.python.reflect import namedClass
 
@@ -40,7 +40,10 @@
 
 from twisted.web2.server import Site
 
-from twistedcaldav import logging
+from twistedcaldav.log import Logger, logLevelForNamespace, setLogLevelForNamespace
+from twistedcaldav.accesslog import DirectoryLogWrapperResource
+from twistedcaldav.accesslog import RotatingFileAccessLoggingObserver
+from twistedcaldav.accesslog import AMPCommonAccessLoggingObserver
 from twistedcaldav.cluster import makeService_Combined, makeService_Master
 from twistedcaldav.config import config, parseConfig, defaultConfig, ConfigurationError
 from twistedcaldav.root import RootResource
@@ -49,11 +52,12 @@
 from twistedcaldav.directory.principal import DirectoryPrincipalProvisioningResource
 from twistedcaldav.directory.aggregate import AggregateDirectoryService
 from twistedcaldav.directory.sudo import SudoDirectoryService
-
-from twistedcaldav import pdmonster
 from twistedcaldav.static import CalendarHomeProvisioningFile
 from twistedcaldav.timezones import TimezoneCache
+from twistedcaldav import pdmonster
 
+log = Logger()
+
 try:
     from twistedcaldav.authkerb import NegotiateCredentialFactory
 except ImportError:
@@ -238,7 +242,7 @@
         #
 
         if not config.ErrorLogFile and config.ProcessType == "Slave":
-            log.FileLogObserver.timeFormat = ""
+            FileLogObserver.timeFormat = ""
 
         # Check current umask and warn if changed
         oldmask = os.umask(config.umask)
@@ -389,8 +393,7 @@
     sslPrivKey.close()
 
     if type is None:
-        logging.err("Could not get private key type for %s"
-                    % (config.SSLPrivateKey,))
+        log.err("Could not get private key type for %s" % (config.SSLPrivateKey,))
         return False
 
     import commands
@@ -452,11 +455,12 @@
     calendarResourceClass  = CalendarHomeProvisioningFile
 
     def makeService_Slave(self, options):
-        # Change log level to at least "info" as its useful to have
+        #
+        # Change default log level to "info" as its useful to have
         # that during startup
-        old_logging = logging.currentLogLevel
-        if logging.currentLogLevel < logging.logtypes["info"]:
-            logging.currentLogLevel = logging.logtypes["info"]
+        #
+        oldLogLevel = logLevelForNamespace(None)
+        setLogLevelForNamespace(None, "info")
 
         #
         # Setup the Directory
@@ -465,8 +469,8 @@
 
         directoryClass = namedClass(config.DirectoryService["type"])
 
-        logging.info("Configuring directory service of type: %s"
-                     % (config.DirectoryService['type'],), system="startup")
+        log.info("Configuring directory service of type: %s"
+                 % (config.DirectoryService["type"],))
 
         baseDirectory = directoryClass(**config.DirectoryService["params"])
 
@@ -475,8 +479,8 @@
         sudoDirectory = None
 
         if config.SudoersFile and os.path.exists(config.SudoersFile):
-            logging.info("Configuring SudoDirectoryService with file: %s"
-                         % (config.SudoersFile,), system="startup")
+            log.info("Configuring SudoDirectoryService with file: %s"
+                     % (config.SudoersFile,))
 
             sudoDirectory = SudoDirectoryService(config.SudoersFile)
             sudoDirectory.realmName = baseDirectory.realmName
@@ -484,8 +488,8 @@
             CalDAVResource.sudoDirectory = sudoDirectory
             directories.insert(0, sudoDirectory)
         else:
-            logging.info("Not using SudoDirectoryService; file doesn't exist: %s"
-                         % (config.SudoersFile,), system="startup")
+            log.info("Not using SudoDirectoryService; file doesn't exist: %s"
+                     % (config.SudoersFile,))
 
         directory = AggregateDirectoryService(directories)
 
@@ -497,27 +501,22 @@
         # Setup Resource hierarchy
         #
 
-        logging.info("Setting up document root at: %s"
-                     % (config.DocumentRoot,), system="startup")
+        log.info("Setting up document root at: %s" % (config.DocumentRoot,))
+        log.info("Setting up principal collection: %r" % (self.principalResourceClass,))
 
-        logging.info("Setting up principal collection: %r"
-                     % (self.principalResourceClass,), system="startup")
-
         principalCollection = self.principalResourceClass(
             os.path.join(config.DocumentRoot, "principals"),
             "/principals/", directory
         )
 
-        logging.info("Setting up calendar collection: %r"
-                     % (self.calendarResourceClass,), system="startup")
+        log.info("Setting up calendar collection: %r" % (self.calendarResourceClass,))
 
         calendarCollection = self.calendarResourceClass(
             os.path.join(config.DocumentRoot, "calendars"),
             directory, "/calendars/"
         )
 
-        logging.info("Setting up root resource: %r"
-                     % (self.rootResourceClass,), system="startup")
+        log.info("Setting up root resource: %r" % (self.rootResourceClass,))
 
         root = self.rootResourceClass(
             config.DocumentRoot,
@@ -529,8 +528,7 @@
 
         # Configure default ACLs on the root resource
 
-        logging.info("Setting up default ACEs on root resource",
-                     system="startup")
+        log.info("Setting up default ACEs on root resource")
 
         rootACEs = [
             davxml.ACE(
@@ -539,11 +537,10 @@
             ),
         ]
 
-        log.msg("Setting up AdminPrincipals")
+        log.info("Setting up AdminPrincipals")
 
         for principal in config.AdminPrincipals:
-            logging.info("Added %s as admin principal"
-                         % (principal,), system="startup")
+            log.info("Added %s as admin principal" % (principal,))
 
             rootACEs.append(
                 davxml.ACE(
@@ -554,14 +551,14 @@
                 )
             )
 
-        log.msg("Setting root ACL")
+        log.info("Setting root ACL")
 
         root.setAccessControlList(davxml.ACL(*rootACEs))
 
         #
         # Configure ancillary data
         #
-        logging.info("Setting up Timezone Cache", system="startup")
+        log.info("Setting up Timezone Cache")
         TimezoneCache.create()
 
         #
@@ -576,8 +573,7 @@
 
         realm = directory.realmName or ""
 
-        logging.info("Configuring authentication for realm: %s"
-                     % (realm,), system="startup")
+        log.info("Configuring authentication for realm: %s" % (realm,))
 
         for scheme, schemeConfig in config.Authentication.iteritems():
             scheme = scheme.lower()
@@ -585,13 +581,11 @@
             credFactory = None
 
             if schemeConfig["Enabled"]:
-                logging.info("Setting up scheme: %s"
-                             % (scheme,), system="startup")
+                log.info("Setting up scheme: %s" % (scheme,))
 
                 if scheme == "kerberos":
                     if not NegotiateCredentialFactory:
-                        logging.info("Kerberos support not available",
-                                     system="startup")
+                        log.info("Kerberos support not available")
                         continue
 
                     try:
@@ -606,8 +600,7 @@
                                 principal=principal
                             )
                     except ValueError:
-                        logging.info("Could not start Kerberos",
-                                     system="startup")
+                        log.info("Could not start Kerberos")
                         continue
 
                 elif scheme == 'digest':
@@ -622,13 +615,12 @@
                     credFactory = BasicCredentialFactory(realm)
 
                 else:
-                    logging.err("Unknown scheme: %s"
-                                % (scheme,), system="startup")
+                    log.err("Unknown scheme: %s" % (scheme,))
 
             if credFactory:
                 credentialFactories.append(credFactory)
 
-        log.msg("Configuring authentication wrapper")
+        log.info("Configuring authentication wrapper")
 
         authWrapper = auth.AuthenticationWrapper(
             root,
@@ -637,7 +629,7 @@
             (auth.IPrincipal,)
         )
 
-        logWrapper = logging.DirectoryLogWrapperResource(
+        logWrapper = DirectoryLogWrapperResource(
             authWrapper,
             directory
         )
@@ -646,7 +638,7 @@
         # Configure the service
         #
 
-        log.msg("Setting up service")
+        log.info("Setting up service")
 
         if config.ProcessType == "Slave":
             if (
@@ -661,19 +653,18 @@
             else:
                 realRoot = logWrapper
 
-            logObserver = logging.AMPCommonAccessLoggingObserver(
+            logObserver = AMPCommonAccessLoggingObserver(
                 config.ControlSocket
             )
 
         elif config.ProcessType == "Single":
             realRoot = logWrapper
 
-            logObserver = logging.RotatingFileAccessLoggingObserver(
+            logObserver = RotatingFileAccessLoggingObserver(
                 config.AccessLogFile
             )
 
-        logging.info("Configuring log observer: %s"
-                     % (logObserver,), system="startup")
+        log.info("Configuring log observer: %s" % (logObserver,))
 
         service = CalDAVService(logObserver)
 
@@ -702,8 +693,7 @@
                 config.BindSSLPorts = [config.SSLPort]
 
             for port in config.BindHTTPPorts:
-                logging.info("Adding server at %s:%s"
-                             % (bindAddress, port), system="startup")
+                log.info("Adding server at %s:%s" % (bindAddress, port))
 
                 httpService = internet.TCPServer(
                     int(port), channel,
@@ -712,8 +702,7 @@
                 httpService.setServiceParent(service)
 
             for port in config.BindSSLPorts:
-                logging.info("Adding SSL server at %s:%s"
-                             % (bindAddress, port), system="startup")
+                log.info("Adding SSL server at %s:%s" % (bindAddress, port))
 
                 contextFactory = ChainingOpenSSLContextFactory(
                     config.SSLPrivateKey,
@@ -728,6 +717,9 @@
                 )
                 httpsService.setServiceParent(service)
 
+        # Change log level back to what it was before
+        setLogLevelForNamespace(None, oldLogLevel)
+
         return service
 
     makeService_Combined = makeService_Combined
@@ -749,14 +741,12 @@
             service = serviceMethod(options)
 
             #
-            # Temporary hack to work around SIGHUP problem
-            # If there is a stopped process in the same session as the
-            # calendar server and the calendar server is the group
-            # leader then when twistd forks to drop privelages a
-            # SIGHUP may be sent by the kernel. This SIGHUP should be
+            # Note: if there is a stopped process in the same session
+            # as the calendar server and the calendar server is the
+            # group leader then when twistd forks to drop privileges a
+            # SIGHUP may be sent by the kernel, which can cause the
+            # process to exit. This SIGHUP should be, at a minimum,
             # ignored.
-            # Note that this handler is not unset, so any further
-            # SIGHUPs are also ignored.
             #
 
             def location(frame):
@@ -767,12 +757,15 @@
 
             import signal
             def sighup_handler(num, frame):
-                log.msg("SIGHUP recieved at %s" % (location(frame),))
+                log.error("SIGHUP recieved at %s" % (location(frame),))
+
+                # Reload the config file
+                config.reload()
+
             signal.signal(signal.SIGHUP, sighup_handler)
 
-            def sigusr1_handler(num, frame):
-                log.msg("SIGUSR1 recieved at %s" % (location(frame),))
-                logging.toggle()
-            signal.signal(signal.SIGUSR1, sigusr1_handler)
+            #def sigusr1_handler(num, frame):
+            #    log.debug("SIGUSR1 recieved at %s" % (location(frame),))
+            #signal.signal(signal.SIGUSR1, sigusr1_handler)
 
             return service

Modified: CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/test/test_config.py
===================================================================
--- CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/test/test_config.py	2008-05-07 21:56:53 UTC (rev 2388)
+++ CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/test/test_config.py	2008-05-07 22:25:07 UTC (rev 2389)
@@ -19,7 +19,7 @@
 from twisted.trial import unittest
 
 from twistedcaldav.py.plistlib import writePlist
-
+from twistedcaldav.log import logLevelForNamespace
 from twistedcaldav.config import config, defaultConfig, ConfigurationError
 from twistedcaldav.static import CalDAVFile
 
@@ -27,17 +27,28 @@
 <!DOCTYPE plist PUBLIC "-//Apple Computer//DTD PLIST 1.0//EN" "http://www.apple.com/DTDs/PropertyList-1.0.dtd">
 <plist version="1.0">
 <dict>
-  <key>Verbose</key>
-  <true/>
+
+  <key>ResponseCompression</key>
+  <false/>
+
   <key>HTTPPort</key>
   <integer>8008</integer>
+
+  <key>DefaultLogLevel</key>
+  <string>warn</string>
+  <key>LogLevels</key>
+  <dict>
+    <key>some.namespace</key>
+    <string>debug</string>
+  </dict>
+
 </dict>
 </plist>
 """
 
-def _testVerbose(testCase):
+def _testResponseCompression(testCase):
     from twistedcaldav.config import config
-    testCase.assertEquals(config.Verbose, True)
+    testCase.assertEquals(config.ResponseCompression, False)
 
 
 class ConfigTests(unittest.TestCase):
@@ -56,20 +67,20 @@
             self.assertEquals(getattr(config, key), value)
 
     def testLoadConfig(self):
-        self.assertEquals(config.Verbose, False)
+        self.assertEquals(config.ResponseCompression, True)
 
         config.loadConfig(self.testConfig)
 
-        self.assertEquals(config.Verbose, True)
+        self.assertEquals(config.ResponseCompression, False)
 
     def testScoping(self):
-        self.assertEquals(config.Verbose, False)
+        self.assertEquals(config.ResponseCompression, True)
 
         config.loadConfig(self.testConfig)
 
-        self.assertEquals(config.Verbose, True)
+        self.assertEquals(config.ResponseCompression, False)
 
-        _testVerbose(self)
+        _testResponseCompression(self)
 
     def testReloading(self):
         self.assertEquals(config.HTTPPort, 0)
@@ -216,7 +227,6 @@
         self.assertNotIn('Foo', defaultConfig)
 
     def testComplianceClasses(self):
-        
         resource = CalDAVFile("/")
         
         config.EnableProxyPrincipals = True
@@ -224,3 +234,21 @@
         
         config.EnableProxyPrincipals = False
         self.assertTrue("calendar-proxy" not in resource.davComplianceClasses())
+
+    def test_logging(self):
+        """
+        Logging module configures properly.
+        """
+        self.assertEquals(logLevelForNamespace(None), "info")
+        self.assertEquals(logLevelForNamespace("some.namespace"), "info")
+
+        config.loadConfig(self.testConfig)
+
+        self.assertEquals(logLevelForNamespace(None), "warn")
+        self.assertEquals(logLevelForNamespace("some.namespace"), "debug")
+
+        writePlist({}, self.testConfig)
+        config.reload()
+
+        self.assertEquals(logLevelForNamespace(None), "info")
+        self.assertEquals(logLevelForNamespace("some.namespace"), "info")

Copied: CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/test/test_log.py (from rev 2388, CalendarServer/trunk/twistedcaldav/test/test_log.py)
===================================================================
--- CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/test/test_log.py	                        (rev 0)
+++ CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/test/test_log.py	2008-05-07 22:25:07 UTC (rev 2389)
@@ -0,0 +1,124 @@
+##
+# Copyright (c) 2005-2007 Apple Inc. All rights reserved.
+#
+# Licensed under the Apache License, Version 2.0 (the "License");
+# you may not use this file except in compliance with the License.
+# You may obtain a copy of the License at
+#
+# http://www.apache.org/licenses/LICENSE-2.0
+#
+# Unless required by applicable law or agreed to in writing, software
+# distributed under the License is distributed on an "AS IS" BASIS,
+# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+# See the License for the specific language governing permissions and
+# limitations under the License.
+##
+
+from twistedcaldav.log import *
+from twistedcaldav.log import defaultLogLevel
+
+import twisted.trial.unittest
+
+class TestLogger (Logger):
+    def __init__(self, namespace=None):
+        super(TestLogger, self).__init__(namespace)
+
+    def emit(self, level, message, **kwargs):
+        super(TestLogger, self).emit(level, message, **kwargs)
+
+        self.emitted = {
+            "level"  : level,
+            "message": message,
+            "kwargs" : kwargs,
+        }
+
+class LoggingEnabledObject (LoggingMixIn):
+    pass
+
+class Logging (twisted.trial.unittest.TestCase):
+    def test_cmpLogLevels(self):
+        self.assertEquals(cmpLogLevels("info" , "error"), -1)
+        self.assertEquals(cmpLogLevels("debug", "debug"),  0)
+        self.assertEquals(cmpLogLevels("warn" , "debug"),  1)
+
+    def test_lowestLogLevel(self):
+        self.assertEquals(lowestLogLevel(*logLevels), "debug")
+        self.assertEquals(lowestLogLevel(*reversed(logLevels)), "debug")
+        self.assertEquals(lowestLogLevel("warn", "info"), "info")
+
+    def test_highestLogLevel(self):
+        self.assertEquals(highestLogLevel(*logLevels), "error")
+        self.assertEquals(highestLogLevel(*reversed(logLevels)), "error")
+        self.assertEquals(highestLogLevel("warn", "info"), "warn")
+
+    def test_namespace_default(self):
+        """
+        Default namespace is module name.
+        """
+        log = Logger()
+        self.assertEquals(log.namespace, __name__)
+
+    def test_namespace_mixin(self):
+        """
+        Default namespace for classes using L{LoggingMixIn} is the class name.
+        """
+        object = LoggingEnabledObject()
+        self.assertEquals(object.logger.namespace, "twistedcaldav.test.test_log.LoggingEnabledObject")
+
+    def test_basic(self):
+        """
+        Test that log levels and messages are emitted correctly.
+        Tests both Logger and LoggingMixIn.
+        """
+        object = LoggingEnabledObject()
+
+        for level in logLevels:
+            message = "This is a %s message" % (level,)
+
+            log = TestLogger()
+            object.logger = log
+
+            for method in (getattr(log, level), getattr(object, "log_" + level)):
+                method(message, junk=message)
+
+                # Ensure that test_emit got called with expected arguments
+                self.assertEquals(log.emitted["level"], level)
+                self.assertEquals(log.emitted["message"], message)
+                self.assertEquals(log.emitted["kwargs"]["junk"], message)
+
+    def test_defaultLogLevel(self):
+        """
+        Default log level is used.
+        """
+        clearLogLevels()
+        self.failUnless(logLevelForNamespace("rocker.cool.namespace"), defaultLogLevel)
+
+    def test_logLevel(self):
+        """
+        Setting and retrieving log levels.
+        """
+        clearLogLevels()
+
+        setLogLevelForNamespace("twisted.web2", "debug")
+        setLogLevelForNamespace("twisted.web2.dav", "error")
+
+        self.assertEquals(logLevelForNamespace("twisted"                     ), defaultLogLevel)
+        self.assertEquals(logLevelForNamespace("twisted.web2"                ), "debug")
+        self.assertEquals(logLevelForNamespace("twisted.web2.dav"            ), "error")
+        self.assertEquals(logLevelForNamespace("twisted.web2.dav.test"       ), "error")
+        self.assertEquals(logLevelForNamespace("twisted.web2.dav.test1.test2"), "error")
+
+    def test_clearLogLevel(self):
+        """
+        Clearing log levels.
+        """
+        setLogLevelForNamespace("twisted.web2", "debug")
+        setLogLevelForNamespace("twisted.web2.dav", "error")
+
+        clearLogLevels()
+
+        self.assertEquals(logLevelForNamespace("twisted"                     ), defaultLogLevel)
+        self.assertEquals(logLevelForNamespace("twisted.web2"                ), defaultLogLevel)
+        self.assertEquals(logLevelForNamespace("twisted.web2.dav"            ), defaultLogLevel)
+        self.assertEquals(logLevelForNamespace("twisted.web2.dav.test"       ), defaultLogLevel)
+        self.assertEquals(logLevelForNamespace("twisted.web2.dav.test1.test2"), defaultLogLevel)

Modified: CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/timezones.py
===================================================================
--- CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/timezones.py	2008-05-07 21:56:53 UTC (rev 2388)
+++ CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/timezones.py	2008-05-07 22:25:07 UTC (rev 2389)
@@ -16,16 +16,17 @@
 # DRI: Cyrus Daboo, cdaboo at apple.com
 ##
 
-from twistedcaldav.ical import Component
+import os
 
-from twisted.python import log
-
+import vobject
 from vobject.icalendar import getTzid
 from vobject.icalendar import registerTzid
 
-import os
-import vobject
+from twistedcaldav.ical import Component
+from twistedcaldav.log import Logger
 
+log = Logger()
+
 """
 Timezone caching.
 

Modified: CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/util.py
===================================================================
--- CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/util.py	2008-05-07 21:56:53 UTC (rev 2388)
+++ CalendarServer/branches/release/CalendarServer-1.3-dev/twistedcaldav/util.py	2008-05-07 22:25:07 UTC (rev 2389)
@@ -18,6 +18,10 @@
 
 import sys
 
+##
+# getNCPU
+##
+
 try:
     from ctypes import *
     import ctypes.util
@@ -25,39 +29,50 @@
 except ImportError:
     hasCtypes = False
 
-if sys.platform == 'darwin' and hasCtypes:
-    from ctypes import *
-    import ctypes.util
+if sys.platform == "darwin" and hasCtypes:
+    libc = cdll.LoadLibrary(ctypes.util.find_library("libc"))
 
-    libc = cdll.LoadLibrary(ctypes.util.find_library('libc'))
-
     def getNCPU():
         ncpu = c_int(0)
-
         size = c_int(sizeof(ncpu))
 
-        libc.sysctlbyname('hw.ncpu',
-                          c_voidp(addressof(ncpu)),
-                          addressof(size),
-                          None, 0)
+        libc.sysctlbyname(
+            "hw.ncpu",
+            c_voidp(addressof(ncpu)),
+            addressof(size),
+            None, 0
+        )
 
         return int(ncpu.value)
 
-elif sys.platform == 'linux2' and hasCtypes:
-    from ctypes import *
-    import ctypes.util
+elif sys.platform == "linux2" and hasCtypes:
+    libc = cdll.LoadLibrary(ctypes.util.find_library("libc"))
 
-    libc = cdll.LoadLibrary(ctypes.util.find_library('libc'))
-
     def getNCPU():
         return libc.get_nprocs()
 
 else:
     def getNCPU():
         if not hasCtypes:
-            msg = "without ctypes"
+            msg = " without ctypes"
         else:
             msg = ""
 
-        raise NotImplementedError(
-            "getNCPU not supported on %s %s" % (sys.platform, msg))
+        raise NotImplementedError("getNCPU not supported on %s%s" % (sys.platform, msg))
+
+##
+#
+##
+
+def submodule(module, name):
+    fullname = module.__name__ + "." + name
+
+    try:
+        submodule = __import__(fullname)
+    except ImportError, e:
+        raise ImportError("Unable to import submodule %s from module %s: %s" % (name, module, e))
+
+    for m in fullname.split(".")[1:]:
+        submodule = getattr(submodule, m)
+
+    return submodule

-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.macosforge.org/pipermail/calendarserver-changes/attachments/20080507/46d910c6/attachment-0001.html


More information about the calendarserver-changes mailing list