[CalendarServer-changes] [1959]
CalendarServer/branches/users/cdaboo/better-logging-1957
source_changes at macosforge.org
source_changes at macosforge.org
Fri Oct 12 11:39:49 PDT 2007
Revision: 1959
http://trac.macosforge.org/projects/calendarserver/changeset/1959
Author: cdaboo at apple.com
Date: 2007-10-12 11:39:49 -0700 (Fri, 12 Oct 2007)
Log Message:
-----------
New logging scheme that uses a separate log configuration file to specify what default logging level should be,
as well as allowing overridding of log levels for different sub-systems. A new USR2 signal handler can be used
to force the logging options to be re-read so that logging can be changed in a running server. The log api was
also changed to allow a class or instance to be identified as a sub-system as well as a string. Use of the
previous apis has been updated everywhere.
Modified Paths:
--------------
CalendarServer/branches/users/cdaboo/better-logging-1957/conf/caldavd.plist
CalendarServer/branches/users/cdaboo/better-logging-1957/twistedcaldav/__init__.py
CalendarServer/branches/users/cdaboo/better-logging-1957/twistedcaldav/authkerb.py
CalendarServer/branches/users/cdaboo/better-logging-1957/twistedcaldav/config.py
CalendarServer/branches/users/cdaboo/better-logging-1957/twistedcaldav/directory/appleopendirectory.py
CalendarServer/branches/users/cdaboo/better-logging-1957/twistedcaldav/itip.py
CalendarServer/branches/users/cdaboo/better-logging-1957/twistedcaldav/logging.py
CalendarServer/branches/users/cdaboo/better-logging-1957/twistedcaldav/method/put_common.py
CalendarServer/branches/users/cdaboo/better-logging-1957/twistedcaldav/pdmonster.py
CalendarServer/branches/users/cdaboo/better-logging-1957/twistedcaldav/schedule.py
CalendarServer/branches/users/cdaboo/better-logging-1957/twistedcaldav/tap.py
CalendarServer/branches/users/cdaboo/better-logging-1957/twistedcaldav/test/test_config.py
Added Paths:
-----------
CalendarServer/branches/users/cdaboo/better-logging-1957/conf/logger.plist
CalendarServer/branches/users/cdaboo/better-logging-1957/twistedcaldav/logger.py
CalendarServer/branches/users/cdaboo/better-logging-1957/twistedcaldav/test/test_logger.py
Modified: CalendarServer/branches/users/cdaboo/better-logging-1957/conf/caldavd.plist
===================================================================
--- CalendarServer/branches/users/cdaboo/better-logging-1957/conf/caldavd.plist 2007-10-12 14:06:00 UTC (rev 1958)
+++ CalendarServer/branches/users/cdaboo/better-logging-1957/conf/caldavd.plist 2007-10-12 18:39:49 UTC (rev 1959)
@@ -189,8 +189,9 @@
Logging
-->
- <key>Verbose</key>
- <false/>
+ <!-- Options for the logger system -->
+ <key>LoggerOptionsFile</key>
+ <string>/etc/caldavd/logger.plist</string>
<!-- Apache-style access log -->
<key>AccessLogFile</key>
Added: CalendarServer/branches/users/cdaboo/better-logging-1957/conf/logger.plist
===================================================================
--- CalendarServer/branches/users/cdaboo/better-logging-1957/conf/logger.plist (rev 0)
+++ CalendarServer/branches/users/cdaboo/better-logging-1957/conf/logger.plist 2007-10-12 18:39:49 UTC (rev 1959)
@@ -0,0 +1,43 @@
+<?xml version="1.0" encoding="UTF-8"?>
+<!DOCTYPE plist PUBLIC "-//Apple Computer//DTD PLIST 1.0//EN" "http://www.apple.com/DTDs/PropertyList-1.0.dtd">
+<plist version="1.0">
+<dict>
+
+<!--
+ Logging levels:
+ "none" - no logging.
+ "error" - errors only.
+ "warning" - errors and warnings only.
+ "info" - errors, warnings and info.
+ "debug" - errors, warnings, info and debug.
+-->
+
+ <!-- Default log level for all systems. -->
+ <key>Default Log Level</key>
+ <string>error</string>
+
+ <!-- Log levels overriding the default level for specific systems. -->
+ <!-- The keys in the dict are the system names, the string values the overridden log levels. -->
+ <key>System Log Levels</key>
+ <dict>
+ <!-- Its useful to have a higher than normal logging for the startup phase. -->
+ <key>Startup</key>
+ <string>info</string>
+ <key>OpenDirectoryService:starting</key>
+ <string>info</string>
+
+ <!-- To track down auto-response issues enable this. -->
+ <!--
+ <key>iTIP</key>
+ <string>info</string>
+ -->
+
+ <!-- To track down iTIP messaging issues enable this. -->
+ <!--
+ <key>CalDAV Outbox POST</key>
+ <string>info</string>
+ -->
+ </dict>
+
+</dict>
+</plist>
Modified: CalendarServer/branches/users/cdaboo/better-logging-1957/twistedcaldav/__init__.py
===================================================================
--- CalendarServer/branches/users/cdaboo/better-logging-1957/twistedcaldav/__init__.py 2007-10-12 14:06:00 UTC (rev 1958)
+++ CalendarServer/branches/users/cdaboo/better-logging-1957/twistedcaldav/__init__.py 2007-10-12 18:39:49 UTC (rev 1959)
@@ -29,8 +29,6 @@
"caldavxml",
"customxml",
"dateops",
- "db",
- "directory",
"dropbox",
"extensions",
"ical",
@@ -38,9 +36,9 @@
"index",
"instance",
"itip",
+ "logger",
"logging",
"notifications",
- "principalindex",
"resource",
"root",
"schedule",
Modified: CalendarServer/branches/users/cdaboo/better-logging-1957/twistedcaldav/authkerb.py
===================================================================
--- CalendarServer/branches/users/cdaboo/better-logging-1957/twistedcaldav/authkerb.py 2007-10-12 14:06:00 UTC (rev 1958)
+++ CalendarServer/branches/users/cdaboo/better-logging-1957/twistedcaldav/authkerb.py 2007-10-12 18:39:49 UTC (rev 1959)
@@ -45,7 +45,7 @@
from twisted.web2.auth.interfaces import ICredentialFactory
from twisted.web2.dav.auth import IPrincipalCredentials
-from twistedcaldav import logging
+from twistedcaldav.logger import logger
import kerberos
@@ -77,7 +77,7 @@
try:
principal = kerberos.getServerPrincipalDetails(type, hostname)
except kerberos.KrbError, ex:
- logging.err("getServerPrincipalDetails: %s" % (ex[0],), system="KerberosCredentialFactoryBase")
+ logger.err("getServerPrincipalDetails: %s" % (ex[0],), id=self)
raise ValueError('Authentication System Failure: %s' % (ex[0],))
try:
@@ -87,11 +87,12 @@
service = splits[0].upper()
realm = splits[1]
except IndexError:
- logging.err("Invalid Kerberos principal: %s" % (principal,), system="KerberosCredentialFactoryBase")
+ logger.err("Invalid Kerberos principal: %s" % (principal,), id=self)
raise ValueError('Authentication System Failure: Invalid Kerberos principal: %s' % (principal,))
self.service = "%s@%s" % (servicetype, service,)
self.realm = realm
+ logger.info("Service: %s Realm: %s" % (self.service, self.realm,), id=self)
class BasicKerberosCredentials(credentials.UsernamePassword):
"""
@@ -171,7 +172,7 @@
try:
kerberos.checkPassword(creds.username, creds.password, creds.service, creds.default_realm)
except kerberos.BasicAuthError, ex:
- logging.err("%s" % (ex[0],), system="BasicKerberosCredentialsChecker")
+ logger.err("%s" % (ex[0],), id=self)
raise error.UnauthorizedLogin("Bad credentials for: %s (%s: %s)" % (pcreds.authnURI, ex[0], ex[1],))
else:
return succeed((pcreds.authnURI, pcreds.authzURI,))
@@ -222,18 +223,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")
+ logger.debug("authGSSServerInit: %s(%s)" % (ex[0][0], ex[1][0],), id=self)
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")
+ logger.debug("authGSSServerStep: %s(%s)" % (ex[0][0], ex[1][0],), id=self)
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")
+ logger.debug("authGSSServerStep: %s" % (ex[0],), id=self)
kerberos.authGSSServerClean(context)
raise error.UnauthorizedLogin('Bad credentials: %s' % (ex[0],))
@@ -247,10 +248,10 @@
username = splits[0]
realmname = splits[1]
- # We currently do not support cross-realm authentciation, so we
+ # We currently do not support cross-realm authentication, 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")
+ logger.err("authGSSServer Realms do not match: %s vs %s" % (realmname, self.realm,), id=self)
kerberos.authGSSServerClean(context)
raise error.UnauthorizedLogin('Bad credentials: mismatched realm')
@@ -259,7 +260,7 @@
try:
kerberos.authGSSServerClean(context);
except kerberos.GSSError, ex:
- logging.err("authGSSServerClean: %s" % (ex[0][0], ex[1][0],), system="NegotiateCredentialFactory")
+ logger.debug("authGSSServerClean: %s" % (ex[0][0], ex[1][0],), id=self)
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/users/cdaboo/better-logging-1957/twistedcaldav/config.py
===================================================================
--- CalendarServer/branches/users/cdaboo/better-logging-1957/twistedcaldav/config.py 2007-10-12 14:06:00 UTC (rev 1958)
+++ CalendarServer/branches/users/cdaboo/better-logging-1957/twistedcaldav/config.py 2007-10-12 18:39:49 UTC (rev 1959)
@@ -105,12 +105,12 @@
#
# Logging
#
- "Verbose": False,
- "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,
+ "LoggerOptionsFile" : "/etc/caldavd/logger.plist", # Options for the logger system
+ "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,
#
# SSL/TLS
@@ -214,6 +214,10 @@
del self._data["DirectoryService"]["params"][param]
self.updateServerCapabilities()
+
+ # Make sure logger levels are read in and setup
+ from twistedcaldav.logger import logger
+ logger.readOptions()
def updateServerCapabilities(self):
"""
Modified: CalendarServer/branches/users/cdaboo/better-logging-1957/twistedcaldav/directory/appleopendirectory.py
===================================================================
--- CalendarServer/branches/users/cdaboo/better-logging-1957/twistedcaldav/directory/appleopendirectory.py 2007-10-12 14:06:00 UTC (rev 1958)
+++ CalendarServer/branches/users/cdaboo/better-logging-1957/twistedcaldav/directory/appleopendirectory.py 2007-10-12 18:39:49 UTC (rev 1959)
@@ -38,7 +38,7 @@
from twisted.cred.credentials import UsernamePassword
from twisted.web2.auth.digest import DigestedCredentials
-from twistedcaldav import logging
+from twistedcaldav.logger import logger
from twistedcaldav.config import config
from twistedcaldav.directory.directory import DirectoryService, DirectoryRecord
from twistedcaldav.directory.directory import DirectoryError, UnknownRecordTypeError
@@ -71,7 +71,7 @@
try:
directory = opendirectory.odInit(node)
except opendirectory.ODError, e:
- logging.err("Open Directory (node=%s) Initialization error: %s" % (node, e), system="OpenDirectoryService")
+ logger.err("Open Directory (node=%s) Initialization error: %s" % (node, e), id=self)
raise
self.realmName = node
@@ -90,7 +90,7 @@
try:
self._lookupVHostRecord()
except Exception, e:
- logging.err("Unable to locate virtual host record: %s" % (e,), system="OpenDirectoryService")
+ logger.err("Unable to locate virtual host record: %s" % (e,), id=self)
raise
if os.path.exists(_serverPreferences):
@@ -101,7 +101,7 @@
'IsWorkgroupServer', False)
if self.isWorkgroupServer:
- logging.info("Enabling Workgroup Server compatibility mode", system="OpenDirectoryService")
+ logger.info("Enabling Workgroup Server compatibility mode", id="OpenDirectoryService:starting")
for recordType in self.recordTypes():
self.recordsForType(recordType)
@@ -137,7 +137,7 @@
dsattributes.kDSNAttrNestedGroups])
if not result:
- logging.err("Couldn't find group %s when trying to expand nested groups." % (groupGUID,), system="OpenDirectoryService")
+ logger.err("Couldn't find group %s when trying to expand nested groups." % (groupGUID,), id=self)
continue
group = result[0][1]
@@ -216,16 +216,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" % (
+ logger.info("Matched Directory record: %s with ServicesLocator: %s, state: %s" % (
key,
servicetag,
{True:"enabled", False:"disabled"}[enabled]
- ), system="OpenDirectoryService")
+ ), id="OpenDirectoryService:starting")
# 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")
+ logger.info("Enabled ServicesLocator: %s" % (tag,), id="OpenDirectoryService:starting")
else:
raise OpenDirectoryInitError(
"Open Directory (node=%s) no /Computers records with an enabled and valid "
@@ -248,10 +248,10 @@
plist = readPlistFromString(plist)
vhosts = plist.get("com.apple.macosxserver.virtualhosts", None)
if not vhosts:
- logging.err(
+ logger.err(
"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,), id=self
)
return False
@@ -272,10 +272,10 @@
# Get host name
hostname = vhosts[hostguid].get("hostname", None)
if not hostname:
- logging.err(
+ logger.err(
"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, ), id=self
)
return False
if hostname != vhostname:
@@ -286,20 +286,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(
+ logger.err(
"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, ), id=self
)
return False
# Look at the service data
serviceInfos = vhosts[hostguid].get("serviceInfo", None)
if not serviceInfos or not serviceInfos.has_key("calendar"):
- logging.err(
+ logger.err(
"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), id=self
)
return False
serviceInfo = serviceInfos["calendar"]
@@ -374,8 +374,8 @@
def onError(f):
storage["status"] = "stale" # Keep trying
- logging.err("Unable to load records of type %s from OpenDirectory due to unexpected error: %s"
- % (recordType, f), system="OpenDirectoryService")
+ logger.err("Unable to load records of type %s from OpenDirectory due to unexpected error: %s"
+ % (recordType, f), id=self)
d = deferToThread(self.reloadCache, recordType)
d.addErrback(onError)
@@ -415,9 +415,9 @@
def reloadCache(self, recordType, shortName=None):
if shortName:
- logging.info("Trying to add record %s to %s record cache" % (shortName, recordType,), system="OpenDirectoryService")
+ logger.info("Trying to add record %s to %s record cache" % (shortName, recordType,), id=self)
else:
- logging.info("Reloading %s record cache" % (recordType,), system="OpenDirectoryService")
+ logger.info("Reloading %s record cache" % (recordType,), id=self)
results = self._queryDirectory(recordType, shortName)
@@ -433,9 +433,9 @@
if not value.get(dsattributes.kDSNAttrServicesLocator):
if recordType == DirectoryService.recordType_groups:
enabledForCalendaring = False
- logging.debug("Group %s is not enabled for calendaring but may be used in ACLs" % (key,), system="OpenDirectoryService")
+ logger.debug("Group %s is not enabled for calendaring but may be used in ACLs" % (key,), id=self)
else:
- logging.err("Directory (incorrectly) returned a record with no ServicesLocator attribute: %s" % (key,), system="OpenDirectoryService")
+ logger.err("Directory (incorrectly) returned a record with no ServicesLocator attribute: %s" % (key,), id=self)
continue
# Now get useful record info.
@@ -495,7 +495,7 @@
if recordShortName in disabled_names or guid in disabled_guids:
disabled_names.add(recordShortName)
disabled_guids.add(guid)
- logging.warn("Record disabled: %s, with GUID: %s" % (recordShortName, guid,), system="OpenDirectoryService")
+ logger.warn("Record disabled: %s, with GUID: %s" % (recordShortName, guid,), id=self)
else:
# Check for duplicate items and disable all names/guids for mismatched duplicates.
ok_to_add = True
@@ -507,8 +507,8 @@
disabled_guids.add(existing_record.guid)
del records[existing_record.shortName]
del guids[existing_record.guid]
- logging.warn("Record disabled: %s, with GUID: %s" % (existing_record.shortName, existing_record.guid,), system="OpenDirectoryService")
- logging.warn("Record disabled: %s, with GUID: %s" % (recordShortName, guid,), system="OpenDirectoryService")
+ logger.warn("Record disabled: %s, with GUID: %s" % (existing_record.shortName, existing_record.guid,), id=self)
+ logger.warn("Record disabled: %s, with GUID: %s" % (recordShortName, guid,), id=self)
ok_to_add = False
elif guid in guids:
existing_record = guids[guid]
@@ -518,13 +518,13 @@
disabled_names.add(existing_record.shortName)
del records[existing_record.shortName]
del guids[existing_record.guid]
- logging.warn("Record disabled: %s, with GUID: %s" % (existing_record.shortName, existing_record.guid,), system="OpenDirectoryService")
- logging.warn("Record disabled: %s, with GUID: %s" % (recordShortName, guid,), system="OpenDirectoryService")
+ logger.warn("Record disabled: %s, with GUID: %s" % (existing_record.shortName, existing_record.guid,), id=self)
+ logger.warn("Record disabled: %s, with GUID: %s" % (recordShortName, guid,), id=self)
ok_to_add = False
if ok_to_add:
records[recordShortName] = guids[guid] = record
- logging.debug("Populated record: %s, with GUID: %s" % (records[recordShortName], guid,), system="OpenDirectoryService")
+ logger.debug("Populated record: %s, with GUID: %s" % (records[recordShortName], guid,), id=self)
if shortName is None:
#
@@ -562,23 +562,23 @@
if shortName in storage["disabled_names"] or record.guid in storage["disabled_guids"]:
storage["disabled_guids"].add(record.guid)
storage["disabled_names"].add(shortName)
- logging.warn("Record disabled: %s, with GUID: %s" % (shortName, record.guid,), system="OpenDirectoryService")
+ logger.warn("Record disabled: %s, with GUID: %s" % (shortName, record.guid,), id=self)
records = {}
elif record.guid in storage["guids"]:
# Got a duplicate GUID - for now we disable the record being looked up. On the next cache refresh
# the existing record will also get disabled.
storage["disabled_guids"].add(record.guid)
storage["disabled_names"].add(shortName)
- logging.warn("Record disabled: %s, with GUID: %s" % (shortName, record.guid,), system="OpenDirectoryService")
+ logger.warn("Record disabled: %s, with GUID: %s" % (shortName, record.guid,), id=self)
records = {}
else:
storage["records"][shortName] = record
storage["guids"][record.guid] = record
if shortName:
- logging.info("Added %d records for %s in %s record cache" % (len(records), shortName, recordType,), system="OpenDirectoryService")
+ logger.info("Added %d records for %s in %s record cache" % (len(records), shortName, recordType,), id=self)
else:
- logging.info("Found %d records for %s record cache" % (len(self._records[recordType]["guids"]), recordType,), system="OpenDirectoryService")
+ logger.info("Found %d records for %s record cache" % (len(self._records[recordType]["guids"]), recordType,), id=self)
def _queryDirectory(self, recordType, shortName=None):
@@ -698,7 +698,7 @@
attrs,
)
except opendirectory.ODError, ex:
- logging.err("Open Directory (node=%s) error: %s" % (self.realmName, str(ex)), system="OpenDirectoryService")
+ logger.err("Open Directory (node=%s) error: %s" % (self.realmName, str(ex)), id=self)
raise
return results
@@ -747,7 +747,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")
+ logger.err("No record for proxy in %s with GUID %s" % (self.shortName, guid), id=self)
else:
yield proxyRecord
@@ -764,8 +764,8 @@
try:
return opendirectory.authenticateUserBasic(self.service.directory, self._nodename, self.shortName, credentials.password)
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")
+ logger.err("Open Directory (node=%s) error while performing basic authentication for user %s: %s"
+ % (self.service.realmName, self.shortName, e), id=self)
return False
elif isinstance(credentials, DigestedCredentials):
try:
@@ -781,8 +781,8 @@
'response="%(response)s",'
'algorithm=%(algorithm)s') % credentials.fields
except KeyError, e:
- logging.err("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")
+ logger.err("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), id=self)
return False
return opendirectory.authenticateUserDigest(
@@ -794,8 +794,8 @@
credentials.method
)
except opendirectory.ODError, e:
- logging.err("Open Directory (node=%s) error while performing digest authentication for user %s: %s"
- % (self.service.realmName, self.shortName, e), system="OpenDirectoryService")
+ logger.err("Open Directory (node=%s) error while performing digest authentication for user %s: %s"
+ % (self.service.realmName, self.shortName, e), id=self)
return False
return super(OpenDirectoryRecord, self).verifyCredentials(credentials)
Modified: CalendarServer/branches/users/cdaboo/better-logging-1957/twistedcaldav/itip.py
===================================================================
--- CalendarServer/branches/users/cdaboo/better-logging-1957/twistedcaldav/itip.py 2007-10-12 14:06:00 UTC (rev 1958)
+++ CalendarServer/branches/users/cdaboo/better-logging-1957/twistedcaldav/itip.py 2007-10-12 18:39:49 UTC (rev 1959)
@@ -45,7 +45,7 @@
from twisted.web2.dav.resource import AccessDeniedError
from twistedcaldav import caldavxml
-from twistedcaldav import logging
+from twistedcaldav.logger import logger
from twistedcaldav.ical import Property, iCalendarProductID
from twistedcaldav.method import report_common
from twistedcaldav.method.put_common import storeCalendarObjectResource
@@ -111,7 +111,7 @@
@param child: the L{CalDAVFile} for the iTIP message resource already saved to the Inbox.
"""
- logging.info("Auto-processing iTIP REQUEST for: %s" % (str(principal),), system="iTIP")
+ logger.info("Auto-processing iTIP REQUEST for: %s" % (str(principal),), id="iTIP")
processed = "ignored"
# First determine whether this is a full or partial update. A full update is one containing the master
@@ -158,29 +158,29 @@
newchild = waitForDeferred(writeResource(request, calURL, updatecal, calmatch, calendar))
yield newchild
newchild = newchild.getResult()
- logging.info("Replaced calendar component %s with new iTIP message in %s." % (calmatch, calURL), system="iTIP")
+ logger.info("Replaced calendar component %s with new iTIP message in %s." % (calmatch, calURL), id="iTIP")
else:
newchild = waitForDeferred(writeResource(request, calURL, updatecal, None, calendar))
yield newchild
newchild.getResult()
- logging.info("Added new calendar component in %s." % (calURL,), system="iTIP")
+ logger.info("Added new calendar component in %s." % (calURL,), id="iTIP")
else:
if calmatch:
d = waitForDeferred(deleteResource(updatecal, calmatch))
yield d
d.getResult()
- logging.info("Deleted calendar component %s in %s as update was not accepted." % (calmatch, calURL), system="iTIP")
+ logger.info("Deleted calendar component %s in %s as update was not accepted." % (calmatch, calURL), id="iTIP")
# Send a reply if needed.
if doreply:
- logging.info("Sending iTIP REPLY %s" % (("declined","accepted")[accepted],), system="iTIP")
+ logger.info("Sending iTIP REPLY %s" % (("declined","accepted")[accepted],), id="iTIP")
newchild = waitForDeferred(writeReply(request, principal, replycal, inbox))
yield newchild
newchild = newchild.getResult()
newInboxResource(child, newchild)
processed = "processed"
except:
- logging.err("Error while auto-processing iTIP: %s" % (failure.Failure(),), system="iTIP")
+ logger.err("Error while auto-processing iTIP: %s" % (failure.Failure(),), id="iTIP")
raise iTipException
else:
@@ -231,17 +231,17 @@
newchild = waitForDeferred(writeResource(request, calURL, updatecal, calmatch, cal))
yield newchild
newchild = newchild.getResult()
- logging.info("Merged calendar component %s with new iTIP message in %s." % (calmatch, calURL), system="iTIP")
+ logger.info("Merged calendar component %s with new iTIP message in %s." % (calmatch, calURL), id="iTIP")
else:
if accepted:
newchild = waitForDeferred(writeResource(request, calURL, updatecal, None, calendar))
yield newchild
newchild.getResult()
- logging.info("Added new calendar component in %s." % (calURL,), system="iTIP")
+ logger.info("Added new calendar component in %s." % (calURL,), id="iTIP")
# Do reply if needed.
if doreply:
- logging.info("Sending iTIP REPLY %s" % (("declined","accepted")[accepted],), system="iTIP")
+ logger.info("Sending iTIP REPLY %s" % (("declined","accepted")[accepted],), id="iTIP")
newchild = waitForDeferred(writeReply(request, principal, replycal, inbox))
yield newchild
newchild = newchild.getResult()
@@ -249,7 +249,7 @@
processed = "processed"
except:
- logging.err("Error while auto-processing iTIP: %s" % (failure.Failure(),), system="iTIP")
+ logger.err("Error while auto-processing iTIP: %s" % (failure.Failure(),), id="iTIP")
raise iTipException
# Remove the now processed incoming request.
@@ -257,13 +257,13 @@
d = waitForDeferred(deleteResource(inbox, child.fp.basename()))
yield d
d.getResult()
- logging.info("Deleted new iTIP message %s in Inbox because it has been %s." %
+ logger.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],), system="iTIP")
+ "ignored": "ignored: no match"}[processed],), id="iTIP")
except:
- logging.err("Error while auto-processing iTIP: %s" % (failure.Failure(),), system="iTIP")
+ logger.err("Error while auto-processing iTIP: %s" % (failure.Failure(),), id="iTIP")
raise iTipException
yield None
return
@@ -281,7 +281,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("Auto-processing iTIP ADD for: %s" % (str(principal),), system="iTIP")
+ logger.info("Auto-processing iTIP ADD for: %s" % (str(principal),), id="iTIP")
raise NotImplementedError
@@ -322,7 +322,7 @@
@param child: the L{CalDAVFile} for the iTIP message resource already saved to the Inbox.
"""
- logging.info("Auto-processing iTIP CANCEL for: %s" % (str(principal),), system="iTIP")
+ logger.info("Auto-processing iTIP CANCEL for: %s" % (str(principal),), id="iTIP")
processed = "ignored"
# Get all component info for this iTIP message
@@ -366,9 +366,9 @@
d = waitForDeferred(deleteResource(updatecal, calmatch,))
yield d
d.getResult()
- logging.info("Delete calendar component %s in %s as it was cancelled." % (calmatch, calURL), system="iTIP")
+ logger.info("Delete calendar component %s in %s as it was cancelled." % (calmatch, calURL), id="iTIP")
except:
- logging.err("Error while auto-processing iTIP: %s" % (failure.Failure(),), system="iTIP")
+ logger.err("Error while auto-processing iTIP: %s" % (failure.Failure(),), id="iTIP")
raise iTipException
processed = "processed"
else:
@@ -429,13 +429,13 @@
d = waitForDeferred(deleteResource(updatecal, calmatch))
yield d
d.getResult()
- logging.info("Deleted calendar component %s after cancellations from iTIP message in %s." % (calmatch, calURL), system="iTIP")
+ logger.info("Deleted calendar component %s after cancellations from iTIP message in %s." % (calmatch, calURL), id="iTIP")
else:
# Update the existing calendar object
newchild = waitForDeferred(writeResource(request, calURL, updatecal, calmatch, existing_calendar))
yield newchild
newchild = newchild.getResult()
- logging.info("Updated calendar component %s with cancellations from iTIP message in %s." % (calmatch, calURL), system="iTIP")
+ logger.info("Updated calendar component %s with cancellations from iTIP message in %s." % (calmatch, calURL), id="iTIP")
processed = "processed"
else:
processed = "older"
@@ -448,13 +448,13 @@
d = waitForDeferred(deleteResource(inbox, child.fp.basename()))
yield d
d.getResult()
- logging.info("Deleted new iTIP message %s in Inbox because it has been %s." %
+ logger.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],), system="iTIP")
+ "ignored": "ignored: no match"}[processed],), id="iTIP")
except:
- logging.err("Error while auto-processing iTIP: %s" % (failure.Failure(),), system="iTIP")
+ logger.err("Error while auto-processing iTIP: %s" % (failure.Failure(),), id="iTIP")
raise iTipException
yield None
return
@@ -519,7 +519,7 @@
break
except NumberOfMatchesWithinLimits:
accepted = False
- logging.info("Exceeded number of matches whilst trying to find free-time.", system="iTIP")
+ logger.warn("Exceeded number of matches whilst trying to find free-time.", id="iTIP")
break
if not accepted:
@@ -610,7 +610,7 @@
yield d
d.getResult()
except AccessDeniedError:
- logging.info("Could not send reply as %s does not have CALDAV:schedule permission on %s Inbox." % (principal.principalURL(), organizer), system="iTIP")
+ logger.warn("Could not send reply as %s does not have CALDAV:schedule permission on %s Inbox." % (principal.principalURL(), organizer), id="iTIP")
yield None
return
@@ -751,9 +751,9 @@
d = waitForDeferred(deleteResource(inbox, i[0]))
yield d
d.getResult()
- logging.info("Deleted iTIP message %s in Inbox that was older than the new one." % (i[0],), system="iTIP")
+ logger.info("Deleted iTIP message %s in Inbox that was older than the new one." % (i[0],), id="iTIP")
except:
- logging.err("Error while auto-processing iTIP: %s" % (failure.Failure(),), system="iTIP")
+ logger.err("Error while auto-processing iTIP: %s" % (failure.Failure(),), id="iTIP")
raise iTipException
else:
# For any that are newer or the same, mark the new one to be deleted.
@@ -765,9 +765,9 @@
d = waitForDeferred(deleteResource(inbox, child.fp.basename()))
yield d
d.getResult()
- logging.info("Deleted new iTIP message %s in Inbox because it was older than existing ones." % (child.fp.basename(),), system="iTIP")
+ logger.info("Deleted new iTIP message %s in Inbox because it was older than existing ones." % (child.fp.basename(),), id="iTIP")
except:
- logging.err("Error while auto-processing iTIP: %s" % (failure.Failure(),), system="iTIP")
+ logger.err("Error while auto-processing iTIP: %s" % (failure.Failure(),), id="iTIP")
raise iTipException
yield delete_child
@@ -797,7 +797,7 @@
continue
calmatch = matchComponentInCalendar(updatecal, calendar)
if calmatch:
- logging.info("Found calendar component %s matching new iTIP message in %s." % (calmatch, calURL), system="iTIP")
+ logger.info("Found calendar component %s matching new iTIP message in %s." % (calmatch, calURL), id="iTIP")
break
if calmatch is None and len(fbset):
Added: CalendarServer/branches/users/cdaboo/better-logging-1957/twistedcaldav/logger.py
===================================================================
--- CalendarServer/branches/users/cdaboo/better-logging-1957/twistedcaldav/logger.py (rev 0)
+++ CalendarServer/branches/users/cdaboo/better-logging-1957/twistedcaldav/logger.py 2007-10-12 18:39:49 UTC (rev 1959)
@@ -0,0 +1,175 @@
+##
+# 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.
+"""
+
+from twisted.python import log
+
+from twistedcaldav.config import config
+
+from plistlib import readPlist
+import os
+import types
+
+
+class LoggerOptions(object):
+ """
+ Manages the set of options controlling logging.
+ """
+
+ def __init__(self):
+
+ self.fname = None
+
+ self.currentLogLevel = Logger.logtypes["error"]
+ self.previousLogLevel = Logger.logtypes["debug"]
+
+ self.systemLogLevels = {}
+
+ def read(self, fname=None):
+
+ if not fname:
+ fname = config.LoggerOptionsFile
+
+ if fname and os.path.exists(fname):
+ options = readPlist(fname)
+
+ level = options.get("Default Log Level", "error")
+ if not Logger.logtypes.has_key(level):
+ log.msg("Unknown default logger level '%s', using 'error' level instead" % (level,))
+ level = "error"
+ self.currentLogLevel = Logger.logtypes[level]
+
+ systems = options.get("System Log Levels", {})
+ newLogLevels = {}
+ for key, value in systems.iteritems():
+ if Logger.logtypes.has_key(value):
+ newLogLevels[key] = Logger.logtypes[value]
+ else:
+ log.msg("Ignoring unknown logging level '%s' for system: %s" % (value, key,), system="Logger")
+
+ self.systemLogLevels = newLogLevels
+
+class Logger(object):
+ #
+ # 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}
+
+ def __init__(self):
+
+ self.options = LoggerOptions()
+
+ def readOptions(self):
+ """
+ Read or re-read the options file.
+ """
+
+ log.msg("Reading logger options file.", system="Logger")
+ self.options.read()
+
+ def toggle(self):
+ """
+ Toggle between normal mode and full debug mode.
+ """
+
+ tempLevel = self.options.currentLogLevel
+ self.options.currentLogLevel = self.options.previousLogLevel
+ self.options.previousLogLevel = tempLevel
+
+ for key, value in Logger.logtypes.iteritems():
+ if value == self.options.currentLogLevel:
+ log.msg("Switching to default log level: %s" % (key,), system="Logger")
+ break
+ else:
+ log.msg("Switching to default log level: %d" % (self.options.currentLogLevel,), system="Logger")
+
+ def canLog(self, level, kwargs):
+ """
+ Determine whether a particular log level type is current active for the current system.
+
+ @param level: a string with one of the supported levels.
+ @param kwargs: a dict containing logging parameters.
+ @return: True if the log level is currently active.
+ """
+
+ if kwargs.has_key("id"):
+ id = kwargs["id"]
+ if type(id) == types.ClassType:
+ kwargs["system"] = id.__name__
+ elif type(id) == types.InstanceType:
+ kwargs["system"] = id.__class__.__name__
+ elif type(id) in types.StringTypes:
+ kwargs["system"] = id
+ current_level = self.options.systemLogLevels.get(kwargs.get("system", ""), self.options.currentLogLevel)
+ return current_level >= Logger.logtypes.get(level, 1)
+
+ def info(self, message, **kwargs):
+ """
+ Log a message at the "info" level.
+
+ @param message: message to log.
+ @param **kwargs: additional log arguments.
+ """
+
+ if self.canLog("info", kwargs):
+ log.msg(message, **kwargs)
+
+ def warn(self, message, **kwargs):
+ """
+ Log a message at the "warning" level.
+
+ @param message: message to log.
+ @param **kwargs: additional log arguments.
+ """
+
+ if self.canLog("warning", kwargs):
+ log.msg(message, **kwargs)
+
+ def err(self, message, **kwargs):
+ """
+ Log a message at the "error" level.
+
+ @param message: message to log.
+ @param **kwargs: additional log arguments.
+ """
+
+ if self.canLog("error", kwargs):
+ log.msg(message, **kwargs)
+
+ def debug(self, message, **kwargs):
+ """
+ Log a message at the "debug" level.
+
+ @param message: message to log.
+ @param **kwargs: additional log arguments.
+ """
+
+ if self.canLog("debug", kwargs):
+ log.msg(message, debug=True, **kwargs)
+
+# Create the global instance of the logger
+logger = Logger()
Modified: CalendarServer/branches/users/cdaboo/better-logging-1957/twistedcaldav/logging.py
===================================================================
--- CalendarServer/branches/users/cdaboo/better-logging-1957/twistedcaldav/logging.py 2007-10-12 14:06:00 UTC (rev 1958)
+++ CalendarServer/branches/users/cdaboo/better-logging-1957/twistedcaldav/logging.py 2007-10-12 18:39:49 UTC (rev 1959)
@@ -34,94 +34,8 @@
from twistedcaldav.config import config
from twistedcaldav.directory.directory import DirectoryService
+from twistedcaldav.logger import logger
-#
-# 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"]
-previousLogLevel = logtypes["debug"]
-
-def toggle():
- """
- Toggle between normal mode and full debug mode.
- """
-
- global currentLogLevel
- global previousLogLevel
- tempLevel = currentLogLevel
- currentLogLevel = previousLogLevel
- previousLogLevel = tempLevel
-
- for key, value in logtypes.iteritems():
- if value == currentLogLevel:
- log.msg("Switching to log level: %s" % (key,))
- break
- else:
- log.msg("Switching to log level: %d" % (currentLogLevel,))
-
-
-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):
@@ -194,7 +108,6 @@
)
)
-
class RotatingFileAccessLoggingObserver(CommonAccessLoggingObserverExtensions):
"""
Class to do 'apache' style access logging to a rotating log file. The log
@@ -304,7 +217,7 @@
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")
+ logger.info("Rotating log file to: %s" % (newpath,), id="Logging")
self.f.close()
os.rename(self.logpath, newpath)
self._open()
Modified: CalendarServer/branches/users/cdaboo/better-logging-1957/twistedcaldav/method/put_common.py
===================================================================
--- CalendarServer/branches/users/cdaboo/better-logging-1957/twistedcaldav/method/put_common.py 2007-10-12 14:06:00 UTC (rev 1958)
+++ CalendarServer/branches/users/cdaboo/better-logging-1957/twistedcaldav/method/put_common.py 2007-10-12 18:39:49 UTC (rev 1959)
@@ -43,7 +43,7 @@
from twisted.web2.iweb import IResponse
from twisted.web2.stream import MemoryStream
-from twistedcaldav import logging
+from twistedcaldav.logger import logger
from twistedcaldav.config import config
from twistedcaldav.caldavxml import NoUIDConflict
from twistedcaldav.caldavxml import NumberOfRecurrencesWithinLimits
@@ -125,35 +125,35 @@
"""
if self.active:
self.active = False
- logging.debug("Rollback: rollback", system="Store Resource")
+ logger.debug("Rollback: rollback", id="Store Resource")
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")
+ logger.debug("Rollback: source restored %s to %s" % (self.source_copy.path, source.fp.path), id="Store Resource")
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")
+ logger.debug("Rollback: destination restored %s to %s" % (self.destination_copy.path, destination.fp.path), id="Store Resource")
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")
+ logger.debug("Rollback: destination index removed %s" % (destination.fp.path,), id="Store Resource")
self.destination_index_deleted = False
destination.fp.remove()
- logging.debug("Rollback: destination removed %s" % (destination.fp.path,), system="Store Resource")
+ logger.debug("Rollback: destination removed %s" % (destination.fp.path,), id="Store Resource")
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")
+ logger.debug("Rollback: destination re-indexed %s" % (destination.fp.path,), id="Store Resource")
if self.source_index_deleted:
doSourceIndexRecover()
self.destination_index_deleted = False
- logging.debug("Rollback: soyurce re-indexed %s" % (source.fp.path,), system="Store Resource")
+ logger.debug("Rollback: soyurce re-indexed %s" % (source.fp.path,), id="Store Resource")
except:
log.err("Rollback: exception caught and not handled: %s" % failure.Failure())
@@ -162,15 +162,15 @@
Commit the resource changes by wiping the rollback state.
"""
if self.active:
- logging.debug("Rollback: commit", system="Store Resource")
+ logger.debug("Rollback: commit", id="Store Resource")
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")
+ logger.debug("Rollback: removed source backup %s" % (self.source_copy.path,), id="Store Resource")
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")
+ logger.debug("Rollback: removed destination backup %s" % (self.destination_copy.path,), id="Store Resource")
self.destination_copy = None
self.destination_created = False
self.source_deleted = False
@@ -440,16 +440,16 @@
rollback.destination_copy = FilePath(destination.fp.path)
rollback.destination_copy.path += ".rollback"
destination.fp.copyTo(rollback.destination_copy)
- logging.debug("Rollback: backing up destination %s to %s" % (destination.fp.path, rollback.destination_copy.path), system="Store Resource")
+ logger.debug("Rollback: backing up destination %s to %s" % (destination.fp.path, rollback.destination_copy.path), id="Store Resource")
else:
rollback.destination_created = True
- logging.debug("Rollback: will create new destination %s" % (destination.fp.path,), system="Store Resource")
+ logger.debug("Rollback: will create new destination %s" % (destination.fp.path,), id="Store Resource")
if deletesource:
rollback.source_copy = FilePath(source.fp.path)
rollback.source_copy.path += ".rollback"
source.fp.copyTo(rollback.source_copy)
- logging.debug("Rollback: backing up source %s to %s" % (source.fp.path, rollback.source_copy.path), system="Store Resource")
+ logger.debug("Rollback: backing up source %s to %s" % (source.fp.path, rollback.source_copy.path), id="Store Resource")
"""
Handle actual store operations here.
@@ -503,7 +503,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")
+ logger.debug("Destination indexed %s" % (destination.fp.path,), id="Store Resource")
except TooManyInstancesError, ex:
log.err("Cannot index calendar resource as there are too many recurrence instances %s" % destination)
raise HTTPError(ErrorResponse(
@@ -526,19 +526,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")
+ logger.debug("Destination index removed %s" % (destination.fp.path,), id="Store Resource")
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")
+ logger.debug("Source index removed %s" % (source.fp.path,), id="Store Resource")
# 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")
+ logger.debug("Source removed %s" % (source.fp.path,), id="Store Resource")
def doSourceIndexRecover():
"""
Modified: CalendarServer/branches/users/cdaboo/better-logging-1957/twistedcaldav/pdmonster.py
===================================================================
--- CalendarServer/branches/users/cdaboo/better-logging-1957/twistedcaldav/pdmonster.py 2007-10-12 14:06:00 UTC (rev 1958)
+++ CalendarServer/branches/users/cdaboo/better-logging-1957/twistedcaldav/pdmonster.py 2007-10-12 18:39:49 UTC (rev 1959)
@@ -4,7 +4,7 @@
from twisted.web2.resource import WrapperResource
-from twistedcaldav import logging
+from twistedcaldav.logger import logger
class PDClientAddressWrapper(WrapperResource):
def __init__(self, resource, socket, directory):
@@ -31,10 +31,10 @@
result.trap(amp.RemoteAmpError)
if result.value.errorCode != 'UNKNOWN_PORT':
return result
- logging.err('Unknown Port: %s' % (request.remoteAddr,), system="PDClientAddressWrapper")
+ logger.err('Unknown Port: %s' % (request.remoteAddr,), id=self)
def _gotAddress(result):
- logging.debug('result = %r' % (result,), system="PDClientAddressWrapper")
+ logger.debug('result = %r' % (result,), id=self)
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), system="PDClientAddressWrapper")
+ logger.debug("GetClientAddress(host=%r, port=%r)" % (host, port), id=self)
d = self.protocol.callRemoteString("GetClientAddress",
host=host,
port=str(port))
Modified: CalendarServer/branches/users/cdaboo/better-logging-1957/twistedcaldav/schedule.py
===================================================================
--- CalendarServer/branches/users/cdaboo/better-logging-1957/twistedcaldav/schedule.py 2007-10-12 14:06:00 UTC (rev 1958)
+++ CalendarServer/branches/users/cdaboo/better-logging-1957/twistedcaldav/schedule.py 2007-10-12 18:39:49 UTC (rev 1959)
@@ -38,7 +38,7 @@
from twistedcaldav import caldavxml
from twistedcaldav import itip
-from twistedcaldav import logging
+from twistedcaldav.logger import logger
from twistedcaldav.resource import CalDAVResource
from twistedcaldav.caldavxml import caldav_namespace, TimeRange
from twistedcaldav.config import config
@@ -204,13 +204,13 @@
# Must be content-type text/calendar
content_type = request.headers.getHeader("content-type")
if content_type is not None and (content_type.mediaType, content_type.mediaSubtype) != ("text", "calendar"):
- logging.err("MIME type %s not allowed in calendar collection" % (content_type,), system="CalDAV Outbox POST")
+ logger.warn("MIME type %s not allowed in calendar collection" % (content_type,), id="CalDAV Outbox POST")
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):
- logging.err("POST request must have Originator header", system="CalDAV Outbox POST")
+ logger.warn("POST request must have Originator header", id="CalDAV Outbox POST")
raise HTTPError(ErrorResponse(responsecode.FORBIDDEN, (caldav_namespace, "originator-specified")))
else:
originator = originator[0]
@@ -218,23 +218,23 @@
# Verify that Originator is a valid calendar user (has an INBOX)
oprincipal = self.principalForCalendarUserAddress(originator)
if oprincipal is None:
- logging.err("Could not find principal for originator: %s" % (originator,), system="CalDAV Outbox POST")
+ logger.warn("Could not find principal for originator: %s" % (originator,), id="CalDAV Outbox POST")
raise HTTPError(ErrorResponse(responsecode.FORBIDDEN, (caldav_namespace, "originator-allowed")))
inboxURL = oprincipal.scheduleInboxURL()
if inboxURL is None:
- logging.err("Could not find inbox for originator: %s" % (originator,), system="CalDAV Outbox POST")
+ logger.warn("Could not find inbox for originator: %s" % (originator,), id="CalDAV Outbox POST")
raise HTTPError(ErrorResponse(responsecode.FORBIDDEN, (caldav_namespace, "originator-allowed")))
# Verify that Originator matches the authenticated user
if davxml.Principal(davxml.HRef(oprincipal.principalURL())) != self.currentPrincipal(request):
- logging.err("Originator: %s does not match authorized user: %s" % (originator, self.currentPrincipal(request).children[0],), system="CalDAV Outbox POST")
+ logger.warn("Originator: %s does not match authorized user: %s" % (originator, self.currentPrincipal(request).children[0],), id="CalDAV Outbox POST")
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):
- logging.err("POST request must have at least one Recipient header", system="CalDAV Outbox POST")
+ logger.warn("POST request must have at least one Recipient header", id="CalDAV Outbox POST")
raise HTTPError(ErrorResponse(responsecode.FORBIDDEN, (caldav_namespace, "recipient-specified")))
# Recipient header may be comma separated list
@@ -254,24 +254,24 @@
yield d
calendar = d.getResult()
except:
- logging.err("Error while handling POST: %s" % (Failure(),), system="CalDAV Outbox POST")
+ logger.warn("Error while handling POST: %s" % (Failure(),), id="CalDAV Outbox POST")
raise HTTPError(ErrorResponse(responsecode.FORBIDDEN, (caldav_namespace, "valid-calendar-data")))
# Must be a valid calendar
try:
calendar.validCalendarForCalDAV()
except ValueError:
- logging.err("POST request calendar component is not valid: %s" % (calendar,), system="CalDAV Outbox POST")
+ logger.warn("POST request calendar component is not valid: %s" % (calendar,), id="CalDAV Outbox POST")
raise HTTPError(ErrorResponse(responsecode.FORBIDDEN, (caldav_namespace, "valid-calendar-data")))
# Must have a METHOD
if not calendar.isValidMethod():
- logging.err("POST request must have valid METHOD property in calendar component: %s" % (calendar,), system="CalDAV Outbox POST")
+ logger.warn("POST request must have valid METHOD property in calendar component: %s" % (calendar,), id="CalDAV Outbox POST")
raise HTTPError(ErrorResponse(responsecode.FORBIDDEN, (caldav_namespace, "valid-calendar-data")))
# Verify iTIP behaviour
if not calendar.isValidITIP():
- logging.err("POST request must have a calendar component that satisfies iTIP requirements: %s" % (calendar,), system="CalDAV Outbox POST")
+ logger.warn("POST request must have a calendar component that satisfies iTIP requirements: %s" % (calendar,), id="CalDAV Outbox POST")
raise HTTPError(ErrorResponse(responsecode.FORBIDDEN, (caldav_namespace, "valid-calendar-data")))
# Verify that the ORGANIZER's cu address maps to the request.uri
@@ -282,12 +282,12 @@
if oprincipal is not None:
outboxURL = oprincipal.scheduleOutboxURL()
if outboxURL is None:
- logging.err("ORGANIZER in calendar data is not valid: %s" % (calendar,), system="CalDAV Outbox POST")
+ logger.warn("ORGANIZER in calendar data is not valid: %s" % (calendar,), id="CalDAV Outbox POST")
raise HTTPError(ErrorResponse(responsecode.FORBIDDEN, (caldav_namespace, "organizer-allowed")))
# Prevent spoofing of ORGANIZER with specific METHODs
if (calendar.propertyValue("METHOD") in ("PUBLISH", "REQUEST", "ADD", "CANCEL", "DECLINECOUNTER")) and (outboxURL != request.uri):
- logging.err("ORGANIZER in calendar data does not match owner of Outbox: %s" % (calendar,), system="CalDAV Outbox POST")
+ logger.warn("ORGANIZER in calendar data does not match owner of Outbox: %s" % (calendar,), id="CalDAV Outbox POST")
raise HTTPError(ErrorResponse(responsecode.FORBIDDEN, (caldav_namespace, "organizer-allowed")))
# Prevent spoofing when doing reply-like METHODs
@@ -298,7 +298,7 @@
# Must have only one
if len(attendees) != 1:
- logging.err("ATTENDEE list in calendar data is wrong: %s" % (calendar,), system="CalDAV Outbox POST")
+ logger.warn("ATTENDEE list in calendar data is wrong: %s" % (calendar,), id="CalDAV Outbox POST")
raise HTTPError(ErrorResponse(responsecode.FORBIDDEN, (caldav_namespace, "attendee-allowed")))
# Attendee's Outbox MUST be the request URI
@@ -307,21 +307,21 @@
if aprincipal is not None:
aoutboxURL = aprincipal.scheduleOutboxURL()
if aoutboxURL is None or aoutboxURL != request.uri:
- logging.err("ATTENDEE in calendar data does not match owner of Outbox: %s" % (calendar,), system="CalDAV Outbox POST")
+ logger.warn("ATTENDEE in calendar data does not match owner of Outbox: %s" % (calendar,), id="CalDAV Outbox POST")
raise HTTPError(ErrorResponse(responsecode.FORBIDDEN, (caldav_namespace, "attendee-allowed")))
# For free-busy do immediate determination of iTIP result rather than fan-out
- logging.info("METHOD: %s, Component: %s" % (calendar.propertyValue("METHOD"), calendar.mainType(),), system="CalDAV Outbox POST")
+ logger.info("METHOD: %s, Component: %s" % (calendar.propertyValue("METHOD"), calendar.mainType(),), id="CalDAV Outbox POST")
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:
- logging.err("iTIP data is not valid for a VFREEBUSY request: %s" % (calendar,), system="CalDAV Outbox POST")
+ logger.warn("iTIP data is not valid for a VFREEBUSY request: %s" % (calendar,), id="CalDAV Outbox POST")
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:
- logging.err("VFREEBUSY start/end not valid: %s" % (calendar,), system="CalDAV Outbox POST")
+ logger.warn("VFREEBUSY start/end not valid: %s" % (calendar,), id="CalDAV Outbox POST")
raise HTTPError(ErrorResponse(responsecode.FORBIDDEN, (caldav_namespace, "valid-calendar-data")))
timerange.start = dtstart
timerange.end = dtend
@@ -351,7 +351,7 @@
# Map recipient to their inbox
inbox = None
if principal is None:
- logging.err("No principal for calendar user address: %s" % (recipient,), system="CalDAV Outbox POST")
+ logger.warn("No principal for calendar user address: %s" % (recipient,), id="CalDAV Outbox POST")
else:
inboxURL = principal.scheduleInboxURL()
if inboxURL:
@@ -359,7 +359,7 @@
yield inbox
inbox = inbox.getResult()
else:
- logging.err("No schedule inbox for principal: %s" % (principal,), system="CalDAV Outbox POST")
+ logger.warn("No schedule inbox for principal: %s" % (principal,), id="CalDAV Outbox POST")
if inbox is None:
err = HTTPError(ErrorResponse(responsecode.NOT_FOUND, (caldav_namespace, "recipient-exists")))
@@ -377,7 +377,7 @@
yield d
d.getResult()
except AccessDeniedError:
- logging.err("Could not access Inbox for recipient: %s" % (recipient,), system="CalDAV Outbox POST")
+ logger.warn("Could not access Inbox for recipient: %s" % (recipient,), id="CalDAV Outbox POST")
err = HTTPError(ErrorResponse(responsecode.NOT_FOUND, (caldav_namespace, "recipient-permisions")))
responses.add(recipient, Failure(exc_value=err), reqstatus="3.8;No authority")
recipients_state["BAD"] += 1
@@ -444,8 +444,8 @@
responses.add(recipient, responsecode.OK, reqstatus="2.0;Success", calendar=fbresult)
recipients_state["OK"] += 1
- except:
- logging.err("Could not determine free busy information: %s" % (recipient,), system="CalDAV Outbox POST")
+ except Exception, ex:
+ logger.err("Could not determine free busy information: %s, %s" % (recipient, ex), id="CalDAV Outbox POST")
err = HTTPError(ErrorResponse(responsecode.FORBIDDEN, (caldav_namespace, "recipient-permissions")))
responses.add(recipient, Failure(exc_value=err), reqstatus="3.8;No authority")
recipients_state["BAD"] += 1
@@ -489,8 +489,8 @@
# Look for auto-schedule option
if principal.autoSchedule():
autoresponses.append((principal, inbox, child))
- except:
- logging.err("Could not store data in Inbox : %s" % (inbox,), system="CalDAV Outbox POST")
+ except Exception, ex:
+ logger.err("Could not store data in Inbox : %s, %s" % (inbox, ex), id="CalDAV Outbox POST")
err = HTTPError(ErrorResponse(responsecode.FORBIDDEN, (caldav_namespace, "recipient-permissions")))
responses.add(recipient, Failure(exc_value=err), reqstatus="3.8;No authority")
recipients_state["BAD"] += 1
@@ -573,7 +573,7 @@
raise AssertionError("Unknown data type: %r" % (what,))
if code > 400: # Error codes only
- logging.err("Error during %s for %s: %s" % (self.method, recipient, message), system="CalDAV Outbox POST")
+ logger.err("Error during %s for %s: %s" % (self.method, recipient, message), id="CalDAV Outbox POST")
children = []
children.append(caldavxml.Recipient(davxml.HRef.fromString(recipient)))
Modified: CalendarServer/branches/users/cdaboo/better-logging-1957/twistedcaldav/tap.py
===================================================================
--- CalendarServer/branches/users/cdaboo/better-logging-1957/twistedcaldav/tap.py 2007-10-12 14:06:00 UTC (rev 1958)
+++ CalendarServer/branches/users/cdaboo/better-logging-1957/twistedcaldav/tap.py 2007-10-12 18:39:49 UTC (rev 1959)
@@ -41,6 +41,7 @@
from twisted.web2.server import Site
from twistedcaldav import logging
+from twistedcaldav.logger import logger
from twistedcaldav.cluster import makeService_Combined, makeService_Master
from twistedcaldav.config import config, parseConfig, defaultConfig, ConfigurationError
from twistedcaldav.root import RootResource
@@ -347,11 +348,6 @@
def makeService_Slave(self, options):
- # Change log level to at least "info" as its useful to have that during startup
- old_logging = logging.currentLogLevel
- if logging.currentLogLevel < logging.logtypes["info"]:
- logging.currentLogLevel = logging.logtypes["info"]
-
#
# Setup the Directory
#
@@ -359,8 +355,8 @@
directoryClass = namedClass(config.DirectoryService['type'])
- logging.info("Configuring directory service of type: %s"
- % (config.DirectoryService['type'],), system="startup")
+ logger.info("Configuring directory service of type: %s"
+ % (config.DirectoryService['type'],), id="Startup")
baseDirectory = directoryClass(**config.DirectoryService['params'])
@@ -369,8 +365,8 @@
sudoDirectory = None
if config.SudoersFile and os.path.exists(config.SudoersFile):
- logging.info("Configuring SudoDirectoryService with file: %s"
- % (config.SudoersFile,), system="startup")
+ logger.info("Configuring SudoDirectoryService with file: %s"
+ % (config.SudoersFile,), id="Startup")
sudoDirectory = SudoDirectoryService(config.SudoersFile)
sudoDirectory.realmName = baseDirectory.realmName
@@ -378,8 +374,8 @@
CalDAVResource.sudoDirectory = sudoDirectory
directories.insert(0, sudoDirectory)
else:
- logging.info("Not using SudoDirectoryService; file doesn't exist: %s"
- % (config.SudoersFile,), system="startup")
+ logger.info("Not using SudoDirectoryService; file doesn't exist: %s"
+ % (config.SudoersFile,), id="Startup")
directory = AggregateDirectoryService(directories)
@@ -391,9 +387,9 @@
# Setup Resource hierarchy
#
- logging.info("Setting up document root at: %s" % (config.DocumentRoot,), system="startup")
+ logger.info("Setting up document root at: %s" % (config.DocumentRoot,), id="Startup")
- logging.info("Setting up principal collection: %r" % (self.principalResourceClass,), system="startup")
+ logger.info("Setting up principal collection: %r" % (self.principalResourceClass,), id="Startup")
principalCollection = self.principalResourceClass(
os.path.join(config.DocumentRoot, 'principals'),
@@ -401,7 +397,7 @@
directory
)
- logging.info("Setting up calendar collection: %r" % (self.calendarResourceClass,), system="startup")
+ logger.info("Setting up calendar collection: %r" % (self.calendarResourceClass,), id="Startup")
calendarCollection = self.calendarResourceClass(
os.path.join(config.DocumentRoot, 'calendars'),
@@ -409,7 +405,7 @@
'/calendars/'
)
- logging.info("Setting up root resource: %r" % (self.rootResourceClass,), system="startup")
+ logger.info("Setting up root resource: %r" % (self.rootResourceClass,), id="Startup")
root = self.rootResourceClass(
config.DocumentRoot,
@@ -421,7 +417,7 @@
# Configure default ACLs on the root resource
- logging.info("Setting up default ACEs on root resource", system="startup")
+ logger.info("Setting up default ACEs on root resource", id="Startup")
rootACEs = [
davxml.ACE(
@@ -430,10 +426,10 @@
),
]
- logging.info("Setting up AdminPrincipals", system="startup")
+ logger.info("Setting up AdminPrincipals", id="Startup")
for principal in config.AdminPrincipals:
- logging.info("Added %s as admin principal" % (principal,), system="startup")
+ logger.info("Added %s as admin principal" % (principal,), id="Startup")
rootACEs.append(
davxml.ACE(
@@ -444,7 +440,7 @@
)
)
- logging.info("Setting root ACL", system="startup")
+ logger.info("Setting root ACL", id="Startup")
root.setAccessControlList(davxml.ACL(*rootACEs))
@@ -460,7 +456,7 @@
realm = directory.realmName or ""
- logging.info("Configuring authentication for realm: %s" % (realm,), system="startup")
+ logger.info("Configuring authentication for realm: %s" % (realm,), id="Startup")
for scheme, schemeConfig in config.Authentication.iteritems():
scheme = scheme.lower()
@@ -468,11 +464,11 @@
credFactory = None
if schemeConfig['Enabled']:
- logging.info("Setting up scheme: %s" % (scheme,), system="startup")
+ logger.info("Setting up scheme: %s" % (scheme,), id="Startup")
if scheme == 'kerberos':
if not NegotiateCredentialFactory:
- logging.info("Kerberos support not available", system="startup")
+ logger.info("Kerberos support not available", id="Startup")
continue
try:
@@ -482,7 +478,7 @@
else:
credFactory = NegotiateCredentialFactory(principal=principal)
except ValueError:
- logging.info("Could not start Kerberos", system="startup")
+ logger.info("Could not start Kerberos", id="Startup")
continue
elif scheme == 'digest':
@@ -497,12 +493,12 @@
credFactory = BasicCredentialFactory(realm)
else:
- logging.err("Unknown scheme: %s" % (scheme,), system="startup")
+ logger.err("Unknown scheme: %s" % (scheme,), id="Startup")
if credFactory:
credentialFactories.append(credFactory)
- logging.info("Configuring authentication wrapper", system="startup")
+ logger.info("Configuring authentication wrapper", id="Startup")
authWrapper = auth.AuthenticationWrapper(
root,
@@ -517,7 +513,7 @@
# Configure the service
#
- logging.info("Setting up service", system="startup")
+ logger.info("Setting up service", id="Startup")
if config.ProcessType == 'Slave':
if config.MultiProcess['ProcessCount'] > 1 and config.MultiProcess['LoadBalancer']['Enabled']:
@@ -536,8 +532,7 @@
logObserver = logging.RotatingFileAccessLoggingObserver(config.AccessLogFile)
- logging.info("Configuring log observer: %s" % (
- logObserver,), system="startup")
+ logger.info("Configuring log observer: %s" % (logObserver,), id="Startup")
service = CalDAVService(logObserver)
@@ -562,21 +557,18 @@
config.BindSSLPorts = [config.SSLPort]
for port in config.BindHTTPPorts:
- logging.info("Adding server at %s:%s" % (bindAddress, port), system="startup")
+ logger.info("Adding server at %s:%s" % (bindAddress, port), id="Startup")
httpService = internet.TCPServer(int(port), channel, interface=bindAddress)
httpService.setServiceParent(service)
for port in config.BindSSLPorts:
- logging.info("Adding SSL server at %s:%s" % (bindAddress, port), system="startup")
+ logger.info("Adding SSL server at %s:%s" % (bindAddress, port), id="Startup")
contextFactory = ChainingOpenSSLContextFactory(config.SSLPrivateKey, config.SSLCertificate, certificateChainFile=config.SSLAuthorityChain)
httpsService = internet.SSLServer(int(port), channel, contextFactory, interface=bindAddress)
httpsService.setServiceParent(service)
- # Change log level back to what it was before
- logging.currentLogLevel = old_logging
-
return service
makeService_Combined = makeService_Combined
@@ -605,7 +597,7 @@
location = "Unknown"
else:
location = str(frame.f_code.co_name) + ": " + str(frame.f_lineno)
- log.msg("SIGHUP recieved at " + location)
+ log.msg("SIGHUP received at " + location)
signal.signal(signal.SIGHUP, sighup_handler)
def sigusr1_handler(num, frame):
@@ -613,10 +605,20 @@
location = "Unknown"
else:
location = str(frame.f_code.co_name) + ": " + str(frame.f_lineno)
- log.msg("SIGUSR1 recieved at " + location)
- logging.toggle()
+ log.msg("SIGUSR1 received at " + location)
+ logger.toggle()
signal.signal(signal.SIGUSR1, sigusr1_handler)
+ def sigusr2_handler(num, frame):
+ if frame is None:
+ location = "Unknown"
+ else:
+ location = str(frame.f_code.co_name) + ": " + str(frame.f_lineno)
+ log.msg("SIGUSR2 received at " + location)
+ logger.readOptions()
+
+ signal.signal(signal.SIGUSR2, sigusr2_handler)
+
return service
Modified: CalendarServer/branches/users/cdaboo/better-logging-1957/twistedcaldav/test/test_config.py
===================================================================
--- CalendarServer/branches/users/cdaboo/better-logging-1957/twistedcaldav/test/test_config.py 2007-10-12 14:06:00 UTC (rev 1958)
+++ CalendarServer/branches/users/cdaboo/better-logging-1957/twistedcaldav/test/test_config.py 2007-10-12 18:39:49 UTC (rev 1959)
@@ -26,17 +26,16 @@
<!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>HTTPPort</key>
- <integer>8008</integer>
+ <key>RotateAccessLog</key>
+ <true/>
+ <key>HTTPPort</key>
+ <integer>8008</integer>
</dict>
</plist>
"""
-def _testVerbose(testCase):
- from twistedcaldav.config import config
- testCase.assertEquals(config.Verbose, True)
+def _testRotateAccessLog(testCase):
+ testCase.assertEquals(config.RotateAccessLog, True)
class ConfigTests(unittest.TestCase):
@@ -55,20 +54,20 @@
self.assertEquals(getattr(config, key), value)
def testLoadConfig(self):
- self.assertEquals(config.Verbose, False)
+ self.assertEquals(config.RotateAccessLog, False)
config.loadConfig(self.testConfig)
- self.assertEquals(config.Verbose, True)
+ self.assertEquals(config.RotateAccessLog, True)
def testScoping(self):
- self.assertEquals(config.Verbose, False)
+ self.assertEquals(config.RotateAccessLog, False)
config.loadConfig(self.testConfig)
- self.assertEquals(config.Verbose, True)
+ self.assertEquals(config.RotateAccessLog, True)
- _testVerbose(self)
+ _testRotateAccessLog(self)
def testReloading(self):
self.assertEquals(config.HTTPPort, 0)
@@ -175,7 +174,7 @@
self.assertEquals(
config.DirectoryService["params"],
- SuperDuperAwesomeService.defaultParameters
+ SuperDuperAwesomeService.defaultParameters #@UndefinedVariable
)
testDirectoryService_unknownType.todo = "unimplemented"
Added: CalendarServer/branches/users/cdaboo/better-logging-1957/twistedcaldav/test/test_logger.py
===================================================================
--- CalendarServer/branches/users/cdaboo/better-logging-1957/twistedcaldav/test/test_logger.py (rev 0)
+++ CalendarServer/branches/users/cdaboo/better-logging-1957/twistedcaldav/test/test_logger.py 2007-10-12 18:39:49 UTC (rev 1959)
@@ -0,0 +1,191 @@
+##
+# 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.
+#
+# DRI: David Reid, dreid at apple.com
+##
+
+from twisted.trial import unittest
+
+from twistedcaldav.config import config, defaultConfig
+from twistedcaldav.logger import logger, Logger
+from twistedcaldav.logger import LoggerOptions
+
+testConfig = """<?xml version="1.0" encoding="UTF-8"?>
+<!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>LoggerOptionsFile</key>
+ <string>%s</string>
+</dict>
+</plist>
+"""
+
+testLogger_Standard = """<?xml version="1.0" encoding="UTF-8"?>
+<!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>Default Log Level</key>
+ <string>error</string>
+ <key>System Log Levels</key>
+ <dict>
+ <key>Startup</key>
+ <string>info</string>
+ </dict>
+</dict>
+</plist>
+"""
+
+systemLogLevels_Standard = {
+ "Startup": Logger.logtypes["info"],
+}
+
+testLogger_More = """<?xml version="1.0" encoding="UTF-8"?>
+<!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>Default Log Level</key>
+ <string>none</string>
+ <key>System Log Levels</key>
+ <dict>
+ <key>Startup</key>
+ <string>info</string>
+ <key>iTIP</key>
+ <string>debug</string>
+ <key>CalDAV Outbox POST</key>
+ <string>warning</string>
+ </dict>
+</dict>
+</plist>
+"""
+
+systemLogLevels_More = {
+ "Startup": Logger.logtypes["info"],
+ "iTIP": Logger.logtypes["debug"],
+ "CalDAV Outbox POST": Logger.logtypes["warning"],
+}
+
+testLogger_Broken = """<?xml version="1.0" encoding="UTF-8"?>
+<!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>Default Log Level</key>
+ <string>bogus</string>
+ <key>System Log Levels</key>
+ <dict>
+ <key>Startup</key>
+ <string>info</string>
+ <key>iTIP</key>
+ <string>busted</string>
+ </dict>
+</dict>
+</plist>
+"""
+
+systemLogLevels_Broken = {
+ "Startup": Logger.logtypes["info"],
+}
+
+class LoggerTests(unittest.TestCase):
+ def setUp(self):
+ config.update(defaultConfig)
+ self.testLogger = self.mktemp()
+ self.testConfig = self.mktemp()
+ open(self.testConfig, 'w').write(testConfig % (self.testLogger,))
+ config.loadConfig(self.testConfig)
+
+ def tearDown(self):
+ self.loadLogfile(testLogger_Standard)
+
+ def loadLogfile(self, plist):
+ open(self.testLogger, 'w').write(plist)
+ logger.readOptions()
+
+ def verify(self, options, current, previous, system):
+ self.assertEquals(options.currentLogLevel, current)
+ self.assertEquals(options.previousLogLevel, previous)
+ self.assertEquals(options.systemLogLevels, system)
+
+ def testDefaultLogger(self):
+ options = LoggerOptions()
+ self.verify(options, Logger.logtypes["error"], Logger.logtypes["debug"], {})
+
+ def testStandardLogger(self):
+ self.loadLogfile(testLogger_Standard)
+
+ self.verify(logger.options, Logger.logtypes["error"], Logger.logtypes["debug"], systemLogLevels_Standard)
+
+ def testMoreLogger(self):
+ self.loadLogfile(testLogger_Standard)
+
+ self.loadLogfile(testLogger_More)
+
+ self.verify(logger.options, Logger.logtypes["none"], Logger.logtypes["debug"], systemLogLevels_More)
+
+ def testBrokenLogger(self):
+ self.testDefaultLogger()
+
+ self.loadLogfile(testLogger_Broken)
+
+ self.verify(logger.options, Logger.logtypes["error"], Logger.logtypes["debug"], systemLogLevels_Broken)
+
+ def testToggle(self):
+ self.loadLogfile(testLogger_Standard)
+
+ logger.toggle()
+
+ self.verify(logger.options, Logger.logtypes["debug"], Logger.logtypes["error"], systemLogLevels_Standard)
+
+ logger.toggle()
+
+ self.verify(logger.options, Logger.logtypes["error"], Logger.logtypes["debug"], systemLogLevels_Standard)
+
+ def testDefaultLogging(self):
+ self.loadLogfile(testLogger_Standard)
+
+ self.assertTrue(logger.canLog("error", {"id":"Dummy"}))
+ self.assertFalse(logger.canLog("warning", {"id":"Dummy"}))
+ self.assertFalse(logger.canLog("info", {"id":"Dummy"}))
+ self.assertFalse(logger.canLog("debug", {"id":"Dummy"}))
+
+ def testStandardLogging(self):
+ self.loadLogfile(testLogger_Standard)
+
+ self.assertTrue(logger.canLog("error", {"id":"Startup"}))
+ self.assertTrue(logger.canLog("warning", {"id":"Startup"}))
+ self.assertTrue(logger.canLog("info", {"id":"Startup"}))
+ self.assertFalse(logger.canLog("debug", {"id":"Startup"}))
+
+ def testMoreLogging(self):
+ self.loadLogfile(testLogger_More)
+
+ self.assertTrue(logger.canLog("error", {"id":"Startup"}))
+ self.assertTrue(logger.canLog("warning", {"id":"Startup"}))
+ self.assertTrue(logger.canLog("info", {"id":"Startup"}))
+ self.assertFalse(logger.canLog("debug", {"id":"Startup"}))
+
+ self.assertTrue(logger.canLog("error", {"id":"iTIP"}))
+ self.assertTrue(logger.canLog("warning", {"id":"iTIP"}))
+ self.assertTrue(logger.canLog("info", {"id":"iTIP"}))
+ self.assertTrue(logger.canLog("debug", {"id":"iTIP"}))
+
+ self.assertTrue(logger.canLog("error", {"id":"CalDAV Outbox POST"}))
+ self.assertTrue(logger.canLog("warning", {"id":"CalDAV Outbox POST"}))
+ self.assertFalse(logger.canLog("info", {"id":"CalDAV Outbox POST"}))
+ self.assertFalse(logger.canLog("debug", {"id":"CalDAV Outbox POST"}))
+
+ self.assertFalse(logger.canLog("error", {"id":"Dummy"}))
+ self.assertFalse(logger.canLog("warning", {"id":"Dummy"}))
+ self.assertFalse(logger.canLog("info", {"id":"Dummy"}))
+ self.assertFalse(logger.canLog("debug", {"id":"Dummy"}))
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.macosforge.org/pipermail/calendarserver-changes/attachments/20071012/88085789/attachment-0001.html
More information about the calendarserver-changes
mailing list