[CalendarServer-changes] [4516] CalendarServer/branches/users/wsanchez/deployment
source_changes at macosforge.org
source_changes at macosforge.org
Mon Aug 31 11:57:22 PDT 2009
Revision: 4516
http://trac.macosforge.org/projects/calendarserver/changeset/4516
Author: cdaboo at apple.com
Date: 2009-08-31 11:57:22 -0700 (Mon, 31 Aug 2009)
Log Message:
-----------
Back-port extended access log logging.
Modified Paths:
--------------
CalendarServer/branches/users/wsanchez/deployment/conf/caldavd-test.plist
CalendarServer/branches/users/wsanchez/deployment/twistedcaldav/accesslog.py
CalendarServer/branches/users/wsanchez/deployment/twistedcaldav/config.py
CalendarServer/branches/users/wsanchez/deployment/twistedcaldav/extensions.py
CalendarServer/branches/users/wsanchez/deployment/twistedcaldav/httpfactory.py
CalendarServer/branches/users/wsanchez/deployment/twistedcaldav/method/propfind.py
CalendarServer/branches/users/wsanchez/deployment/twistedcaldav/method/report.py
CalendarServer/branches/users/wsanchez/deployment/twistedcaldav/method/report_calquery.py
CalendarServer/branches/users/wsanchez/deployment/twistedcaldav/method/report_multiget.py
CalendarServer/branches/users/wsanchez/deployment/twistedcaldav/schedule.py
Modified: CalendarServer/branches/users/wsanchez/deployment/conf/caldavd-test.plist
===================================================================
--- CalendarServer/branches/users/wsanchez/deployment/conf/caldavd-test.plist 2009-08-31 18:55:36 UTC (rev 4515)
+++ CalendarServer/branches/users/wsanchez/deployment/conf/caldavd-test.plist 2009-08-31 18:57:22 UTC (rev 4516)
@@ -285,8 +285,6 @@
<string>debug</string>
-->
</dict>
- <key>MoreAccessLogData</key>
- <true/>
<!-- Accounting -->
<key>AccountingCategories</key>
Modified: CalendarServer/branches/users/wsanchez/deployment/twistedcaldav/accesslog.py
===================================================================
--- CalendarServer/branches/users/wsanchez/deployment/twistedcaldav/accesslog.py 2009-08-31 18:55:36 UTC (rev 4515)
+++ CalendarServer/branches/users/wsanchez/deployment/twistedcaldav/accesslog.py 2009-08-31 18:57:22 UTC (rev 4516)
@@ -64,10 +64,6 @@
request = eventDict['request']
response = eventDict['response']
loginfo = eventDict['loginfo']
- firstLine = '%s %s HTTP/%s' %(
- request.method,
- request.uri.replace('"', '%22'),
- '.'.join([str(x) for x in request.clientproto]))
# Try to determine authentication and authorization identifiers
uid = "-"
@@ -99,46 +95,75 @@
else:
uid = uidn
- format_str = '%s - %s [%s] "%s" %s %d "%s" "%s" [%.1f ms]'
- format_data = (
- 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,
+ #
+ # For some methods which basically allow you to tunnel a
+ # custom request (eg. REPORT, POST), the method name
+ # itself doesn't tell you much about what action is being
+ # requested. This allows a method to tack a submethod
+ # attribute to the request, so we can provide a little
+ # more detail here.
+ #
+ if config.EnableExtendedAccessLog and hasattr(request, "submethod"):
+ method = "%s(%s)" % (request.method, request.submethod)
+ else:
+ method = request.method
+
+ # Standard Apache access log fields
+ format = (
+ '%(host)s - %(uid)s [%(date)s]'
+ ' "%(method)s %(uri)s HTTP/%(protocolVersion)s"'
+ ' %(statusCode)s %(bytesSent)d'
+ ' "%(referer)s" "%(userAgent)s"'
)
- if config.MoreAccessLogData:
- try:
- serverInstance = request.chanRequest.transport.server.port
- except AttributeError:
- serverInstance = "Unknown"
+
+ try:
+ serverInstance = request.chanRequest.transport.server.port
+ except AttributeError:
+ serverInstance = "Unknown"
+ if config.EnableExtendedAccessLog:
- format_str += ' [%s %s]'
- format_data += (
- serverInstance,
- request.chanRequest.channel.factory.outstandingRequests,
- )
- self.logMessage(format_str % format_data)
+ formats = [
+ format,
+ # Performance monitoring extensions
+ 'i=%(serverInstance)s t=%(timeSpent).1f or=%(outstandingRequests)s',
+ ]
+ if hasattr(request, "extendedLogItems"):
+ for k, v in request.extendedLogItems.iteritems():
+ v = str(v).replace('"', "%22")
+ if " " in v:
+ v = '"%s"' % (v,)
+ formats.append("%s=%s" % (k, v))
+ format = " ".join(formats)
+ formatArgs = {
+ "host" : request.remoteAddr.host,
+ "uid" : uid,
+ "date" : self.logDateString(response.headers.getHeader("date", 0)),
+ "method" : method,
+ "uri" : request.uri.replace('"', "%22"),
+ "protocolVersion" : ".".join(str(x) for x in request.clientproto),
+ "statusCode" : response.code,
+ "bytesSent" : loginfo.bytesSent,
+ "referer" : request.headers.getHeader("referer", "-"),
+ "userAgent" : request.headers.getHeader("user-agent", "-"),
+ "serverInstance" : serverInstance,
+ "timeSpent" : (time.time() - request.initTime) * 1000,
+ "outstandingRequests" : request.chanRequest.channel.factory.outstandingRequests,
+ }
+ self.logMessage(format % formatArgs)
+
elif "overloaded" in eventDict:
overloaded = eventDict.get("overloaded")
- format_str = '%s - - [%s] "???" 503 0 "-" "-" [0.0 ms]'
- format_data = (
- overloaded.transport.hostname,
- self.logDateString(time.time()),
- )
- if config.MoreAccessLogData:
- format_str += ' [%s %s]'
- format_data += (
- overloaded.transport.server.port,
- overloaded.outstandingRequests,
- )
- self.logMessage(format_str % format_data)
+ format = '%(host)s - - [%(date)s] "???" 503 0 "-" "-"'
+ formatArgs = {
+ "host": overloaded.transport.hostname,
+ "date": self.logDateString(time.time()),
+ }
+ if config.EnableExtendedAccessLog:
+ format += " i=%(serverInstance)s t=0.0 or=%(outstandingRequests)s"
+ formatArgs["serverInstance"] = overloaded.transport.server.port
+ formatArgs["outstandingRequests"] = overloaded.outstandingRequests
+ self.logMessage(format % formatArgs)
class RotatingFileAccessLoggingObserver(CommonAccessLoggingObserverExtensions):
"""
Modified: CalendarServer/branches/users/wsanchez/deployment/twistedcaldav/config.py
===================================================================
--- CalendarServer/branches/users/wsanchez/deployment/twistedcaldav/config.py 2009-08-31 18:55:36 UTC (rev 4515)
+++ CalendarServer/branches/users/wsanchez/deployment/twistedcaldav/config.py 2009-08-31 18:57:22 UTC (rev 4516)
@@ -164,8 +164,8 @@
"ErrorLogFile" : "/var/log/caldavd/error.log", # Server activity log
"ServerStatsFile": "/var/run/caldavd/stats.plist",
"PIDFile" : "/var/run/caldavd.pid",
- "RotateAccessLog" : False,
- "MoreAccessLogData" : True,
+ "RotateAccessLog" : False,
+ "EnableExtendedAccessLog" : True,
"DefaultLogLevel" : "",
"LogLevels" : {},
Modified: CalendarServer/branches/users/wsanchez/deployment/twistedcaldav/extensions.py
===================================================================
--- CalendarServer/branches/users/wsanchez/deployment/twistedcaldav/extensions.py 2009-08-31 18:55:36 UTC (rev 4515)
+++ CalendarServer/branches/users/wsanchez/deployment/twistedcaldav/extensions.py 2009-08-31 18:57:22 UTC (rev 4516)
@@ -52,6 +52,7 @@
from twistedcaldav.util import submodule, Alternator, printTracebacks
from twistedcaldav.directory.sudo import SudoDirectoryService
from twistedcaldav.directory.directory import DirectoryService
+from twistedcaldav.method.report import http_REPORT
log = Logger()
@@ -221,6 +222,7 @@
def http_ACL(self, request):
return super(DAVResource, self).http_ACL(request)
+ http_REPORT = http_REPORT
def findChildrenFaster(self, depth, request, okcallback, badcallback, names, privileges, inherited_aces):
"""
@@ -422,6 +424,9 @@
"""
Extended L{twisted.web2.dav.static.DAVFile} implementation.
"""
+
+ http_REPORT = http_REPORT
+
def readProperty(self, property, request):
if type(property) is tuple:
qname = property
Modified: CalendarServer/branches/users/wsanchez/deployment/twistedcaldav/httpfactory.py
===================================================================
--- CalendarServer/branches/users/wsanchez/deployment/twistedcaldav/httpfactory.py 2009-08-31 18:55:36 UTC (rev 4515)
+++ CalendarServer/branches/users/wsanchez/deployment/twistedcaldav/httpfactory.py 2009-08-31 18:57:22 UTC (rev 4516)
@@ -30,8 +30,7 @@
self.outstandingRequests = outstandingRequests
def connectionMade(self):
- if config.MoreAccessLogData:
- log.msg(overloaded=self)
+ log.msg(overloaded=self)
retryAfter = randint(int(config.HTTPRetryAfter * 1/2), int(config.HTTPRetryAfter * 3/2))
Modified: CalendarServer/branches/users/wsanchez/deployment/twistedcaldav/method/propfind.py
===================================================================
--- CalendarServer/branches/users/wsanchez/deployment/twistedcaldav/method/propfind.py 2009-08-31 18:55:36 UTC (rev 4515)
+++ CalendarServer/branches/users/wsanchez/deployment/twistedcaldav/method/propfind.py 2009-08-31 18:57:22 UTC (rev 4516)
@@ -193,6 +193,10 @@
xml_responses.append(xml_response)
+ if not hasattr(request, "extendedLogItems"):
+ request.extendedLogItems = {}
+ request.extendedLogItems["responses"] = len(xml_responses)
+
#
# Return response
#
Modified: CalendarServer/branches/users/wsanchez/deployment/twistedcaldav/method/report.py
===================================================================
--- CalendarServer/branches/users/wsanchez/deployment/twistedcaldav/method/report.py 2009-08-31 18:55:36 UTC (rev 4515)
+++ CalendarServer/branches/users/wsanchez/deployment/twistedcaldav/method/report.py 2009-08-31 18:57:22 UTC (rev 4516)
@@ -78,7 +78,22 @@
namespace = doc.root_element.namespace
name = doc.root_element.name
- def to_method(s):
+ if namespace:
+ if namespace == davxml.dav_namespace:
+ request.submethod = "DAV:" + name
+ elif namespace == caldavxml.caldav_namespace:
+ request.submethod = "CalDAV:" + name
+ else:
+ request.submethod = "{%s}%s" % (namespace, name)
+ else:
+ request.submethod = name
+
+ def to_method(namespace, name):
+ if namespace:
+ s = "_".join((namespace, name))
+ else:
+ s = name
+
ok = string.ascii_letters + string.digits + "_"
out = []
for c in s:
@@ -88,10 +103,7 @@
out.append("_")
return "report_" + "".join(out)
- if namespace:
- method_name = to_method(namespace + "_" + name)
- else:
- method_name = to_method(name)
+ method_name = to_method(namespace, name)
try:
method = getattr(self, method_name)
Modified: CalendarServer/branches/users/wsanchez/deployment/twistedcaldav/method/report_calquery.py
===================================================================
--- CalendarServer/branches/users/wsanchez/deployment/twistedcaldav/method/report_calquery.py 2009-08-31 18:55:36 UTC (rev 4515)
+++ CalendarServer/branches/users/wsanchez/deployment/twistedcaldav/method/report_calquery.py 2009-08-31 18:57:22 UTC (rev 4516)
@@ -252,6 +252,10 @@
log.err("Too many matching components in calendar-query report")
raise HTTPError(ErrorResponse(responsecode.FORBIDDEN, (dav_namespace, "number-of-matches-within-limits")))
+ if not hasattr(request, "extendedLogItems"):
+ request.extendedLogItems = {}
+ request.extendedLogItems["responses"] = len(responses)
+
yield MultiStatusResponse(responses)
report_urn_ietf_params_xml_ns_caldav_calendar_query = deferredGenerator(report_urn_ietf_params_xml_ns_caldav_calendar_query)
Modified: CalendarServer/branches/users/wsanchez/deployment/twistedcaldav/method/report_multiget.py
===================================================================
--- CalendarServer/branches/users/wsanchez/deployment/twistedcaldav/method/report_multiget.py 2009-08-31 18:55:36 UTC (rev 4515)
+++ CalendarServer/branches/users/wsanchez/deployment/twistedcaldav/method/report_multiget.py 2009-08-31 18:57:22 UTC (rev 4516)
@@ -61,7 +61,16 @@
propertyreq = multiget.property
resources = multiget.resources
+
+ if not hasattr(request, "extendedLogItems"):
+ request.extendedLogItems = {}
+ request.extendedLogItems["rcount"] = len(resources)
+ # Check size of results is within limit
+ if len(resources) > max_number_of_multigets:
+ log.err("Too many results in multiget report: %d" % len(resources))
+ raise HTTPError(ErrorResponse(responsecode.FORBIDDEN, davxml.NumberOfMatchesWithinLimits()))
+
if propertyreq.qname() == ("DAV:", "allprop"):
propertiesForResource = report_common.allPropertiesForResource
@@ -79,11 +88,6 @@
else:
raise AssertionError("We shouldn't be here")
- # Check size of results is within limit
- if len(resources) > max_number_of_multigets:
- log.err("Too many results in multiget report: %d" % len(resources))
- raise HTTPError(ErrorResponse(responsecode.FORBIDDEN, (dav_namespace, "number-of-matches-within-limits")))
-
"""
Three possibilities exist:
Modified: CalendarServer/branches/users/wsanchez/deployment/twistedcaldav/schedule.py
===================================================================
--- CalendarServer/branches/users/wsanchez/deployment/twistedcaldav/schedule.py 2009-08-31 18:55:36 UTC (rev 4515)
+++ CalendarServer/branches/users/wsanchez/deployment/twistedcaldav/schedule.py 2009-08-31 18:57:22 UTC (rev 4516)
@@ -415,6 +415,8 @@
# shows up in a given principal's calendars, rather than
# tracking the activities of a specific user.
#
+ if not hasattr(request, "extendedLogItems"):
+ request.extendedLogItems = {}
if freebusy:
if accountingEnabled("iTIP-VFREEBUSY", organizerPrincipal):
emitAccounting(
@@ -422,6 +424,8 @@
"Originator: %s\nRecipients: %s\n\n%s"
% (originator, ", ".join(recipients), str(calendar))
)
+ request.extendedLogItems["freebusy"] = len(recipients)
+
else:
if accountingEnabled("iTIP", organizerPrincipal):
emitAccounting(
@@ -429,6 +433,7 @@
"Originator: %s\nRecipients: %s\n\n%s"
% (originator, ", ".join(recipients), str(calendar))
)
+ request.extendedLogItems["itip.%s" % (calendar.propertyValue("METHOD").lower(),)] = len(recipients)
# Prepare for multiple responses
responses = ScheduleResponseQueue("POST", responsecode.OK)
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.macosforge.org/pipermail/calendarserver-changes/attachments/20090831/d1cdc8c7/attachment-0001.html>
More information about the calendarserver-changes
mailing list