[CalendarServer-changes] [11826] CalendarServer/branches/users/cdaboo/performance-tweaks
source_changes at macosforge.org
source_changes at macosforge.org
Wed Mar 12 11:18:02 PDT 2014
Revision: 11826
http://trac.calendarserver.org//changeset/11826
Author: cdaboo at apple.com
Date: 2013-10-18 12:38:34 -0700 (Fri, 18 Oct 2013)
Log Message:
-----------
Various performance tweaks and fixes to extended log items.
Modified Paths:
--------------
CalendarServer/branches/users/cdaboo/performance-tweaks/calendarserver/accesslog.py
CalendarServer/branches/users/cdaboo/performance-tweaks/twistedcaldav/resource.py
CalendarServer/branches/users/cdaboo/performance-tweaks/twistedcaldav/scheduling_store/caldav/resource.py
CalendarServer/branches/users/cdaboo/performance-tweaks/txdav/base/datastore/util.py
CalendarServer/branches/users/cdaboo/performance-tweaks/txdav/caldav/datastore/file.py
CalendarServer/branches/users/cdaboo/performance-tweaks/txdav/caldav/datastore/schedule.py
CalendarServer/branches/users/cdaboo/performance-tweaks/txdav/caldav/datastore/scheduling/implicit.py
CalendarServer/branches/users/cdaboo/performance-tweaks/txdav/caldav/datastore/scheduling/utils.py
CalendarServer/branches/users/cdaboo/performance-tweaks/txdav/caldav/datastore/sql.py
CalendarServer/branches/users/cdaboo/performance-tweaks/txdav/common/datastore/sql.py
Modified: CalendarServer/branches/users/cdaboo/performance-tweaks/calendarserver/accesslog.py
===================================================================
--- CalendarServer/branches/users/cdaboo/performance-tweaks/calendarserver/accesslog.py 2013-10-18 19:37:48 UTC (rev 11825)
+++ CalendarServer/branches/users/cdaboo/performance-tweaks/calendarserver/accesslog.py 2013-10-18 19:38:34 UTC (rev 11826)
@@ -173,7 +173,7 @@
formatArgs["t"] = (nowtime - request.timeStamps[0][1]) * 1000
if hasattr(request, "extendedLogItems"):
- for k, v in request.extendedLogItems.iteritems():
+ for k, v in sorted(request.extendedLogItems.iteritems(), key=lambda x: x[0]):
k = str(k).replace('"', "%22")
v = str(v).replace('"', "%22")
if " " in v:
Modified: CalendarServer/branches/users/cdaboo/performance-tweaks/twistedcaldav/resource.py
===================================================================
--- CalendarServer/branches/users/cdaboo/performance-tweaks/twistedcaldav/resource.py 2013-10-18 19:37:48 UTC (rev 11825)
+++ CalendarServer/branches/users/cdaboo/performance-tweaks/twistedcaldav/resource.py 2013-10-18 19:38:34 UTC (rev 11826)
@@ -333,6 +333,12 @@
else:
yield transaction.commit()
+ # Log extended item
+ if transaction.logItems:
+ if not hasattr(request, "extendedLogItems"):
+ request.extendedLogItems = {}
+ request.extendedLogItems.update(transaction.logItems)
+
# May need to reset the last-modified header in the response as txn.commit() can change it due to pre-commit hooks
if response.headers.hasHeader("last-modified"):
response.headers.setHeader("last-modified", self.lastModified())
@@ -2551,15 +2557,6 @@
return self._newStoreHome.hasCalendarResourceUIDSomewhereElse(uid, ok_object._newStoreObject, mode)
- def getCalendarResourcesForUID(self, uid, allow_shared=False):
- """
- Return all child object resources with the specified UID.
-
- Pass through direct to store.
- """
- return self._newStoreHome.getCalendarResourcesForUID(uid, allow_shared)
-
-
def defaultAccessControlList(self):
myPrincipal = self.principalForRecord()
Modified: CalendarServer/branches/users/cdaboo/performance-tweaks/twistedcaldav/scheduling_store/caldav/resource.py
===================================================================
--- CalendarServer/branches/users/cdaboo/performance-tweaks/twistedcaldav/scheduling_store/caldav/resource.py 2013-10-18 19:37:48 UTC (rev 11825)
+++ CalendarServer/branches/users/cdaboo/performance-tweaks/twistedcaldav/scheduling_store/caldav/resource.py 2013-10-18 19:38:34 UTC (rev 11826)
@@ -422,8 +422,12 @@
authz = (yield request.locateResource(principalURL))
self._associatedTransaction._authz_uid = authz.record.guid
+ # Log extended item
+ if not hasattr(request, "extendedLogItems"):
+ request.extendedLogItems = {}
+
# This is a local CALDAV scheduling operation.
- scheduler = CalDAVScheduler(self._associatedTransaction, self.parent._newStoreHome.uid())
+ scheduler = CalDAVScheduler(self._associatedTransaction, self.parent._newStoreHome.uid(), logItems=request.extendedLogItems)
# Do the POST processing treating
result = (yield scheduler.doSchedulingViaPOST(originator, recipients, calendar))
Modified: CalendarServer/branches/users/cdaboo/performance-tweaks/txdav/base/datastore/util.py
===================================================================
--- CalendarServer/branches/users/cdaboo/performance-tweaks/txdav/base/datastore/util.py 2013-10-18 19:37:48 UTC (rev 11825)
+++ CalendarServer/branches/users/cdaboo/performance-tweaks/txdav/base/datastore/util.py 2013-10-18 19:38:34 UTC (rev 11826)
@@ -92,6 +92,12 @@
return "objectWithName:%s:%s" % (homeResourceID, name)
+ # Home child objects by id
+
+ def keyForObjectWithResourceID(self, homeResourceID, resourceID):
+ return "objectWithName:%s:%s" % (homeResourceID, resourceID)
+
+
# Home metadata (Created/Modified)
def keyForHomeMetaData(self, homeResourceID):
Modified: CalendarServer/branches/users/cdaboo/performance-tweaks/txdav/caldav/datastore/file.py
===================================================================
--- CalendarServer/branches/users/cdaboo/performance-tweaks/txdav/caldav/datastore/file.py 2013-10-18 19:37:48 UTC (rev 11825)
+++ CalendarServer/branches/users/cdaboo/performance-tweaks/txdav/caldav/datastore/file.py 2013-10-18 19:38:34 UTC (rev 11826)
@@ -128,7 +128,7 @@
@inlineCallbacks
def hasCalendarResourceUIDSomewhereElse(self, uid, ok_object, type):
- objectResources = (yield self.objectResourcesWithUID(uid, ("inbox",)))
+ objectResources = (yield self.getCalendarResourcesForUID(uid))
for objectResource in objectResources:
if ok_object and objectResource._path == ok_object._path:
continue
@@ -140,14 +140,9 @@
@inlineCallbacks
- def getCalendarResourcesForUID(self, uid, allow_shared=False):
+ def getCalendarResourcesForUID(self, uid):
- results = []
- objectResources = (yield self.objectResourcesWithUID(uid, ("inbox",)))
- for objectResource in objectResources:
- if allow_shared or objectResource._parentCollection.owned():
- results.append(objectResource)
-
+ results = (yield self.objectResourcesWithUID(uid, ("inbox",), allowShared=False))
returnValue(results)
Modified: CalendarServer/branches/users/cdaboo/performance-tweaks/txdav/caldav/datastore/schedule.py
===================================================================
--- CalendarServer/branches/users/cdaboo/performance-tweaks/txdav/caldav/datastore/schedule.py 2013-10-18 19:37:48 UTC (rev 11825)
+++ CalendarServer/branches/users/cdaboo/performance-tweaks/txdav/caldav/datastore/schedule.py 2013-10-18 19:38:34 UTC (rev 11826)
@@ -112,8 +112,8 @@
return self._calendarHome.hasCalendarResourceUIDSomewhereElse(uid, ok_object, type)
- def getCalendarResourcesForUID(self, uid, allow_shared=False):
- return self._calendarHome.getCalendarResourcesForUID(uid, allow_shared)
+ def getCalendarResourcesForUID(self, uid):
+ return self._calendarHome.getCalendarResourcesForUID(uid)
Modified: CalendarServer/branches/users/cdaboo/performance-tweaks/txdav/caldav/datastore/scheduling/implicit.py
===================================================================
--- CalendarServer/branches/users/cdaboo/performance-tweaks/txdav/caldav/datastore/scheduling/implicit.py 2013-10-18 19:37:48 UTC (rev 11825)
+++ CalendarServer/branches/users/cdaboo/performance-tweaks/txdav/caldav/datastore/scheduling/implicit.py 2013-10-18 19:38:34 UTC (rev 11826)
@@ -56,10 +56,10 @@
STATUS_ORPHANED_CANCELLED_EVENT = 1
STATUS_ORPHANED_EVENT = 2
- def __init__(self):
+ def __init__(self, logItems=None):
self.return_status = ImplicitScheduler.STATUS_OK
- self.logItems = {}
+ self.logItems = logItems
self.allowed_to_schedule = True
self.suppress_refresh = False
@@ -383,7 +383,7 @@
if self.txn.doing_attendee_refresh == 0:
delattr(self.txn, "doing_attendee_refresh")
- if refreshCount:
+ if refreshCount and self.logItems is not None:
self.logItems["itip.refreshes"] = refreshCount
@@ -925,7 +925,8 @@
if self.action in ("create", "modify",):
total += (yield self.processRequests())
- self.logItems["itip.requests"] = total
+ if self.logItems is not None:
+ self.logItems["itip.requests"] = total
@inlineCallbacks
@@ -1304,7 +1305,8 @@
# First make sure we are allowed to schedule
self.testSchedulingAllowed()
- self.logItems["itip.reply"] = "reply"
+ if self.logItems is not None:
+ self.logItems["itip.reply"] = "reply"
itipmsg = iTipGenerator.generateAttendeeReply(self.calendar, self.attendee, changedRids=changedRids)
@@ -1317,7 +1319,8 @@
# First make sure we are allowed to schedule
self.testSchedulingAllowed()
- self.logItems["itip.reply"] = "cancel"
+ if self.logItems is not None:
+ self.logItems["itip.reply"] = "cancel"
itipmsg = iTipGenerator.generateAttendeeReply(self.calendar, self.attendee, force_decline=True)
Modified: CalendarServer/branches/users/cdaboo/performance-tweaks/txdav/caldav/datastore/scheduling/utils.py
===================================================================
--- CalendarServer/branches/users/cdaboo/performance-tweaks/txdav/caldav/datastore/scheduling/utils.py 2013-10-18 19:37:48 UTC (rev 11825)
+++ CalendarServer/branches/users/cdaboo/performance-tweaks/txdav/caldav/datastore/scheduling/utils.py 2013-10-18 19:38:34 UTC (rev 11826)
@@ -21,7 +21,7 @@
log = Logger()
@inlineCallbacks
-def getCalendarObjectForRecord(txn, record, uid, allow_shared=False):
+def getCalendarObjectForRecord(txn, record, uid):
"""
Get a copy of the event for a calendar user identified by a directory record.
@@ -34,7 +34,7 @@
calendar_home = yield txn.calendarHomeWithUID(record.uid)
# Get matching newstore objects
- objectResources = (yield calendar_home.getCalendarResourcesForUID(uid, allow_shared))
+ objectResources = (yield calendar_home.getCalendarResourcesForUID(uid))
if len(objectResources) > 1:
# Delete all but the first one
Modified: CalendarServer/branches/users/cdaboo/performance-tweaks/txdav/caldav/datastore/sql.py
===================================================================
--- CalendarServer/branches/users/cdaboo/performance-tweaks/txdav/caldav/datastore/sql.py 2013-10-18 19:37:48 UTC (rev 11825)
+++ CalendarServer/branches/users/cdaboo/performance-tweaks/txdav/caldav/datastore/sql.py 2013-10-18 19:38:34 UTC (rev 11826)
@@ -527,9 +527,7 @@
# refer to calendar *object* UIDs, since calendar *resources* are an
# HTTP protocol layer thing, not a data store thing. (See also
# objectResourcesWithUID.)
- objectResources = (
- yield self.objectResourcesWithUID(uid, ["inbox"], False)
- )
+ objectResources = (yield self.getCalendarResourcesForUID(uid))
for objectResource in objectResources:
if ok_object and objectResource._resourceID == ok_object._resourceID:
continue
@@ -541,15 +539,22 @@
@inlineCallbacks
- def getCalendarResourcesForUID(self, uid, allow_shared=False):
+ def getCalendarResourcesForUID(self, uid):
+ """
+ Find all calendar object resources in the calendar home that are not in the "inbox" collection
+ and not in shared collections.
+ Cache the result of this query as it can happen multiple times during scheduling under slightly
+ different circumstances.
- results = []
- objectResources = (yield self.objectResourcesWithUID(uid, ["inbox"]))
- for objectResource in objectResources:
- if allow_shared or objectResource._parentCollection.owned():
- results.append(objectResource)
+ @param uid: the UID of the calendar object resources to find
+ @type uid: C{str}
+ """
- returnValue(results)
+ if not hasattr(self, "_cachedCalendarResourcesForUID"):
+ self._cachedCalendarResourcesForUID = {}
+ if uid not in self._cachedCalendarResourcesForUID:
+ self._cachedCalendarResourcesForUID[uid] = (yield self.objectResourcesWithUID(uid, ["inbox"], allowShared=False))
+ returnValue(self._cachedCalendarResourcesForUID[uid])
@inlineCallbacks
@@ -1953,7 +1958,7 @@
user_uuid = self._parentCollection.viewerHome().uid()
component = PerUserDataFilter(user_uuid).filter(component.duplicate())
- scheduler = ImplicitScheduler()
+ scheduler = ImplicitScheduler(logItems=self._txn.logItems)
# PUT
do_implicit_action, is_scheduling_resource = (yield scheduler.testImplicitSchedulingPUT(
@@ -2610,7 +2615,7 @@
if not isinbox and internal_state == ComponentRemoveState.NORMAL:
# Get data we need for implicit scheduling
calendar = (yield self.componentForUser())
- scheduler = ImplicitScheduler()
+ scheduler = ImplicitScheduler(logItems=self._txn.logItems)
do_implicit_action, _ignore = (yield scheduler.testImplicitSchedulingDELETE(
self.calendar(),
self,
@@ -2929,7 +2934,7 @@
# Only allow organizers to manipulate managed attachments for now
calendar = (yield self.componentForUser())
- scheduler = ImplicitScheduler()
+ scheduler = ImplicitScheduler(logItems=self._txn.logItems)
is_attendee = (yield scheduler.testAttendeeEvent(self.calendar(), self, calendar,))
if is_attendee:
raise InvalidAttachmentOperation("Attendees are not allowed to manipulate managed attachments")
Modified: CalendarServer/branches/users/cdaboo/performance-tweaks/txdav/common/datastore/sql.py
===================================================================
--- CalendarServer/branches/users/cdaboo/performance-tweaks/txdav/common/datastore/sql.py 2013-10-18 19:37:48 UTC (rev 11825)
+++ CalendarServer/branches/users/cdaboo/performance-tweaks/txdav/common/datastore/sql.py 2013-10-18 19:38:34 UTC (rev 11826)
@@ -352,14 +352,18 @@
Print a report of all the SQL statements executed to date.
"""
+ total_statements = len(self.statements)
+ total_rows = sum([statement[1] for statement in self.statements])
+ total_time = sum([statement[2] for statement in self.statements]) * 1000.0
+
toFile = StringIO()
toFile.write("*** SQL Stats ***\n")
toFile.write("\n")
toFile.write("Label: %s\n" % (self.label,))
toFile.write("Unique statements: %d\n" % (len(set([statement[0] for statement in self.statements]),),))
- toFile.write("Total statements: %d\n" % (len(self.statements),))
- toFile.write("Total rows: %d\n" % (sum([statement[1] for statement in self.statements]),))
- toFile.write("Total time (ms): %.3f\n" % (sum([statement[2] for statement in self.statements]) * 1000.0,))
+ toFile.write("Total statements: %d\n" % (total_statements,))
+ toFile.write("Total rows: %d\n" % (total_rows,))
+ toFile.write("Total time (ms): %.3f\n" % (total_time,))
for sql, rows, t in self.statements:
toFile.write("\n")
toFile.write("SQL: %s\n" % (sql,))
@@ -372,8 +376,10 @@
else:
log.error(toFile.getvalue())
+ return (total_statements, total_rows, total_time,)
+
class CommonStoreTransactionMonitor(object):
"""
Object that monitors the state of a transaction over time and logs or times out
@@ -483,7 +489,9 @@
self.iudCount = 0
self.currentStatement = None
+ self.logItems = {}
+
def enqueue(self, workItem, **kw):
"""
Enqueue a L{twext.enterprise.queue.WorkItem} for later execution.
@@ -1032,7 +1040,7 @@
# Do stats logging as a postCommit because there might be some pending preCommit SQL we want to log
if self._stats:
- self.postCommit(self._stats.printReport)
+ self.postCommit(self.statsReport)
return self._sqlTxn.commit()
@@ -1043,6 +1051,16 @@
return self._sqlTxn.abort()
+ def statsReport(self):
+ """
+ Print the stats report and record log items
+ """
+ sql_statements, sql_rows, sql_time = self._stats.printReport()
+ self.logItems["sql-s"] = str(sql_statements)
+ self.logItems["sql-r"] = str(sql_rows)
+ self.logItems["sql-t"] = "%.1f" % (sql_time,)
+
+
def _oldEventsBase(self, limit):
ch = schema.CALENDAR_HOME
co = schema.CALENDAR_OBJECT
@@ -2329,16 +2347,20 @@
raise NotImplementedError()
- @classproperty
- def _objectNamesSinceRevisionQuery(cls): #@NoSelf
+ @classmethod
+ def _objectNamesSinceRevisionQuery(cls, deleted=True): #@NoSelf
"""
DAL query for (resource, deleted-flag)
"""
rev = cls._revisionsSchema
- return Select([rev.RESOURCE_NAME, rev.DELETED],
- From=rev,
- Where=(rev.REVISION > Parameter("revision")).And(
- rev.RESOURCE_ID == Parameter("resourceID")))
+ where = (rev.REVISION > Parameter("revision")).And(rev.RESOURCE_ID == Parameter("resourceID"))
+ if not deleted:
+ where = where.And(rev.DELETED == False)
+ return Select(
+ [rev.RESOURCE_NAME, rev.DELETED],
+ From=rev,
+ Where=where,
+ )
def resourceNamesSinceToken(self, token):
@@ -2363,10 +2385,10 @@
"""
results = [
- (name if name else "", deleted)
- for name, deleted in
- (yield self._objectNamesSinceRevisionQuery.on(
- self._txn, revision=revision, resourceID=self._resourceID))
+ (name if name else "", deleted) for name, deleted in
+ (yield self._objectNamesSinceRevisionQuery(deleted=(revision != 0)).on(
+ self._txn, revision=revision, resourceID=self._resourceID)
+ )
]
results.sort(key=lambda x: x[1])
@@ -3024,7 +3046,9 @@
queryCacher = self._txn._queryCacher
if queryCacher:
cacheKey = queryCacher.keyForObjectWithName(shareeView._home._resourceID, shareeView._name)
- queryCacher.invalidateAfterCommit(self._txn, cacheKey)
+ yield queryCacher.invalidateAfterCommit(self._txn, cacheKey)
+ cacheKey = queryCacher.keyForObjectWithResourceID(shareeView._home._resourceID, shareeView._resourceID)
+ yield queryCacher.invalidateAfterCommit(self._txn, cacheKey)
shareeView._name = sharedname[0][0]
@@ -3082,7 +3106,9 @@
queryCacher = self._txn._queryCacher
if queryCacher:
cacheKey = queryCacher.keyForObjectWithName(shareeHome._resourceID, shareeChild._name)
- queryCacher.invalidateAfterCommit(self._txn, cacheKey)
+ yield queryCacher.invalidateAfterCommit(self._txn, cacheKey)
+ cacheKey = queryCacher.keyForObjectWithResourceID(shareeHome._resourceID, shareeChild._resourceID)
+ yield queryCacher.invalidateAfterCommit(self._txn, cacheKey)
else:
deletedBindName = None
@@ -3347,10 +3373,9 @@
def invalidateQueryCache(self):
queryCacher = self._txn._queryCacher
if queryCacher is not None:
- cacheKey = queryCacher.keyForHomeChildMetaData(self._resourceID)
- yield queryCacher.invalidateAfterCommit(self._txn, cacheKey)
- cacheKey = queryCacher.keyForObjectWithName(self._home._resourceID, self._name)
- yield queryCacher.invalidateAfterCommit(self._txn, cacheKey)
+ yield queryCacher.invalidateAfterCommit(self._txn, queryCacher.keyForHomeChildMetaData(self._resourceID))
+ yield queryCacher.invalidateAfterCommit(self._txn, queryCacher.keyForObjectWithName(self._home._resourceID, self._name))
+ yield queryCacher.invalidateAfterCommit(self._txn, queryCacher.keyForObjectWithResourceID(self._home._resourceID, self._resourceID))
@@ -3527,6 +3552,7 @@
if rows and queryCacher:
# Cache the result
queryCacher.setAfterCommit(home._txn, cacheKey, rows)
+ queryCacher.setAfterCommit(home._txn, queryCacher.keyForObjectWithResourceID(home._resourceID, rows[0][2]), rows)
if not rows:
returnValue(None)
@@ -3567,8 +3593,24 @@
@return: an L{CommonHomeChild} or C{None} if no such child
exists.
"""
- rows = yield cls._bindForResourceIDAndHomeID.on(
- home._txn, resourceID=resourceID, homeID=home._resourceID)
+
+ rows = None
+ queryCacher = home._txn._queryCacher
+
+ if queryCacher:
+ # Retrieve data from cache
+ cacheKey = queryCacher.keyForObjectWithResourceID(home._resourceID, resourceID)
+ rows = yield queryCacher.get(cacheKey)
+
+ if rows is None:
+ # No cached copy
+ rows = yield cls._bindForResourceIDAndHomeID.on(home._txn, resourceID=resourceID, homeID=home._resourceID)
+
+ if rows and queryCacher:
+ # Cache the result (under both the ID and name values)
+ queryCacher.setAfterCommit(home._txn, cacheKey, rows)
+ queryCacher.setAfterCommit(home._txn, queryCacher.keyForObjectWithName(home._resourceID, rows[0][3]), rows)
+
if not rows:
returnValue(None)
@@ -3749,6 +3791,8 @@
if queryCacher:
cacheKey = queryCacher.keyForObjectWithName(self._home._resourceID, oldName)
yield queryCacher.invalidateAfterCommit(self._home._txn, cacheKey)
+ cacheKey = queryCacher.keyForObjectWithResourceID(self._home._resourceID, self._resourceID)
+ yield queryCacher.invalidateAfterCommit(self._home._txn, cacheKey)
yield self._renameQuery.on(self._txn, name=name,
resourceID=self._resourceID,
@@ -3782,6 +3826,8 @@
if queryCacher:
cacheKey = queryCacher.keyForObjectWithName(self._home._resourceID, self._name)
yield queryCacher.invalidateAfterCommit(self._home._txn, cacheKey)
+ cacheKey = queryCacher.keyForObjectWithResourceID(self._home._resourceID, self._resourceID)
+ yield queryCacher.invalidateAfterCommit(self._home._txn, cacheKey)
yield self._deletedSyncToken()
yield self._deleteQuery.on(self._txn, NoSuchHomeChildError,
@@ -4498,7 +4544,7 @@
@inlineCallbacks
def create(cls, parent, name, component, options=None):
- child = (yield cls.objectWithName(parent, name, None))
+ child = (yield parent.objectResourceWithName(name))
if child:
raise ObjectResourceNameAlreadyExistsError(name)
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://lists.macosforge.org/pipermail/calendarserver-changes/attachments/20140312/1eb844d8/attachment.html>
More information about the calendarserver-changes
mailing list