[CalendarServer-changes] [7333] CalendarServer/trunk/contrib/performance/loadtest
source_changes at macosforge.org
source_changes at macosforge.org
Wed Apr 20 09:46:42 PDT 2011
Revision: 7333
http://trac.macosforge.org/projects/calendarserver/changeset/7333
Author: exarkun at twistedmatrix.com
Date: 2011-04-20 09:46:42 -0700 (Wed, 20 Apr 2011)
Log Message:
-----------
Add overall operation logging and a realtime reporter and summarizer for those operations
Modified Paths:
--------------
CalendarServer/trunk/contrib/performance/loadtest/population.py
CalendarServer/trunk/contrib/performance/loadtest/profiles.py
Added Paths:
-----------
CalendarServer/trunk/contrib/performance/loadtest/logger.py
Added: CalendarServer/trunk/contrib/performance/loadtest/logger.py
===================================================================
--- CalendarServer/trunk/contrib/performance/loadtest/logger.py (rev 0)
+++ CalendarServer/trunk/contrib/performance/loadtest/logger.py 2011-04-20 16:46:42 UTC (rev 7333)
@@ -0,0 +1,52 @@
+from stats import mean, median, stddev, mad
+
+class SummarizingMixin(object):
+ def printHeader(self, fields):
+ """
+ Print a header for the summarization data which will be reported.
+
+ @param fields: A C{list} of two-tuples. Each tuple describes one
+ column in the summary. The first element gives a label to appear
+ at the top of the column. The second element gives the width of
+ the column.
+ """
+ format = []
+ labels = []
+ for (label, width) in fields:
+ format.append('%%%ds' % (width,))
+ labels.append(label)
+ print ' '.join(format) % tuple(labels)
+
+
+ def _summarizeData(self, operation, data):
+ failed = 0
+ threesec = 0
+ durations = []
+ for (success, duration) in data:
+ if not success:
+ failed += 1
+ if duration > 3:
+ threesec += 1
+ durations.append(duration)
+
+ return operation, len(data), failed, threesec, mean(durations), median(durations)
+
+
+ def _printRow(self, formats, values):
+ format = ' '.join(formats)
+ print format % values
+
+
+ def printData(self, formats, perOperationTimes):
+ """
+ Print one or more rows of data with the given formatting.
+
+ @param formats: A C{list} of C{str} giving formats into which each
+ data field will be interpolated.
+
+ @param perOperationTimes: A C{list} of all of the data to summarize.
+ Each element is a two-tuple of whether the operation succeeded
+ (C{True} if so, C{False} if not) and how long the operation took.
+ """
+ for method, data in perOperationTimes:
+ self._printRow(formats, self._summarizeData(method, data))
Modified: CalendarServer/trunk/contrib/performance/loadtest/population.py
===================================================================
--- CalendarServer/trunk/contrib/performance/loadtest/population.py 2011-04-20 16:44:54 UTC (rev 7332)
+++ CalendarServer/trunk/contrib/performance/loadtest/population.py 2011-04-20 16:46:42 UTC (rev 7333)
@@ -26,10 +26,10 @@
from twisted.python.log import msg, err
from stats import mean, median, stddev, mad
+from loadtest.logger import SummarizingMixin
from loadtest.ical import SnowLeopard, RequestLogger
from loadtest.profiles import Eventer, Inviter, Accepter
-
class ClientType(object, FancyEqMixin):
"""
@ivar clientType: An L{ICalendarClient} implementation
@@ -206,7 +206,7 @@
-class ReportStatistics(StatisticsBase):
+class ReportStatistics(StatisticsBase, SummarizingMixin):
_fields = [
('operation', 10, '%10s'),
('count', 8, '%8s'),
@@ -225,39 +225,15 @@
dataset.append((event['success'], event['duration']))
- def _printHeader(self):
- format = []
- labels = []
- for (label, width, fmt) in self._fields:
- format.append('%%%ds' % (width,))
- labels.append(label)
- print ''.join(format) % tuple(labels)
-
-
- def _summarizeData(self, method, data):
- failed = 0
- threesec = 0
- durations = []
- for (success, duration) in data:
- if not success:
- failed += 1
- if duration > 3:
- threesec += 1
- durations.append(duration)
-
- return method, len(data), failed, threesec, mean(durations), median(durations)
-
-
- def _printData(self, *values):
- format = ''.join(fmt for (label, width, fmt) in self._fields)
- print format % values
-
-
def report(self):
print
- self._printHeader()
- for method, data in self._perMethodTimes.iteritems():
- self._printData(*self._summarizeData(method, data))
+ self.printHeader([
+ (label, width)
+ for (label, width, fmt)
+ in self._fields])
+ self.printData(
+ [fmt for (label, width, fmt) in self._fields],
+ sorted(self._perMethodTimes.items()))
def main():
Modified: CalendarServer/trunk/contrib/performance/loadtest/profiles.py
===================================================================
--- CalendarServer/trunk/contrib/performance/loadtest/profiles.py 2011-04-20 16:44:54 UTC (rev 7332)
+++ CalendarServer/trunk/contrib/performance/loadtest/profiles.py 2011-04-20 16:46:42 UTC (rev 7333)
@@ -31,10 +31,12 @@
from protocol.caldav.definitions import caldavxml
from twisted.python.log import msg
+from twisted.python.failure import Failure
from twisted.internet.defer import succeed, fail
-from twisted.internet.task import LoopingCall
+from twisted.internet.task import LoopingCall, deferLater
from twisted.web.http import PRECONDITION_FAILED
+from loadtest.logger import SummarizingMixin
from loadtest.ical import IncorrectResponseCode
@@ -68,7 +70,26 @@
return attendee.params[u'EMAIL'][0] == self._client.email[len('mailto:'):]
+ def _newOperation(self, label, deferred):
+ """
+ Helper to emit a log event when a new operation is started and
+ another one when it completes.
+ """
+ before = self._reactor.seconds()
+ msg(type="operation", phase="start",
+ user=self._client.user, label=label)
+ def finished(passthrough):
+ success = not isinstance(passthrough, Failure)
+ after = self._reactor.seconds()
+ msg(type="operation", phase="end", duration=after - before,
+ user=self._client.user, label=label, success=success)
+ return passthrough
+ deferred.addBoth(finished)
+ return deferred
+
+
+
class CannotAddAttendee(Exception):
"""
Indicates no new attendees can be invited to a particular event.
@@ -170,7 +191,7 @@
self._client.addEventAttendee(
href, attendee),
lambda reason: reason.trap(CannotAddAttendee))
- return d
+ return self._newOperation("invite", d)
@@ -210,9 +231,10 @@
# XXX Base this on something real
delay = self.random.gauss(10, 2)
self._accepting.add(href)
- self._reactor.callLater(
- delay, self._acceptInvitation, href, attendee)
- return
+ d = deferLater(
+ self._reactor, delay,
+ self._acceptInvitation, href, attendee)
+ return self._newOperation("accept", d)
def _acceptInvitation(self, href, attendee):
@@ -331,4 +353,48 @@
href = '%s%s.ics' % (
calendar.url, vevent.contents[u'uid'][0].value)
- return self._client.addEvent(href, vcalendar)
+ d = self._client.addEvent(href, vcalendar)
+ return self._newOperation("new-event", d)
+
+
+class OperationLogger(SummarizingMixin):
+ """
+ Profiles will initiate operations which may span multiple requests. Start
+ and stop log messages are emitted for these operations and logged by this
+ logger.
+ """
+ formats = {
+ u"start": u"%(user)s %(label)s begin",
+ u"end": u"%(user)s %(label)s end [%(duration)5.2f s]",
+ }
+
+ _fields = [
+ ('operation', 10, '%10s'),
+ ('count', 8, '%8s'),
+ ('failed', 8, '%8s'),
+ ('>3sec', 8, '%8s'),
+ ('mean', 8, '%8.4f'),
+ ('median', 8, '%8.4f'),
+ ]
+
+ def __init__(self):
+ self._perOperationTimes = {}
+
+
+ def observe(self, event):
+ if event.get("type") == "operation":
+ print (self.formats[event[u'phase']] % event).encode('utf-8')
+ if event[u'phase'] == u'end':
+ dataset = self._perOperationTimes.setdefault(event[u'label'], [])
+ dataset.append((event[u'success'], event[u'duration']))
+
+
+ def report(self):
+ print
+ self.printHeader([
+ (label, width)
+ for (label, width, fmt)
+ in self._fields])
+ self.printData(
+ [fmt for (label, width, fmt) in self._fields],
+ sorted(self._perOperationTimes.items()))
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.macosforge.org/pipermail/calendarserver-changes/attachments/20110420/7ca6b136/attachment-0001.html>
More information about the calendarserver-changes
mailing list