[CalendarServer-changes] [13247] CalendarServer/branches/release/CalendarServer-5.3-dev
source_changes at macosforge.org
source_changes at macosforge.org
Thu Apr 10 13:09:41 PDT 2014
Revision: 13247
http://trac.calendarserver.org//changeset/13247
Author: cdaboo at apple.com
Date: 2014-04-10 13:09:41 -0700 (Thu, 10 Apr 2014)
Log Message:
-----------
Add extra logging/tracking of auto-scheduling.
Modified Paths:
--------------
CalendarServer/branches/release/CalendarServer-5.3-dev/conf/caldavd-test.plist
CalendarServer/branches/release/CalendarServer-5.3-dev/support/build.sh
CalendarServer/branches/release/CalendarServer-5.3-dev/twistedcaldav/accounting.py
CalendarServer/branches/release/CalendarServer-5.3-dev/twistedcaldav/stdconfig.py
CalendarServer/branches/release/CalendarServer-5.3-dev/twistedcaldav/test/test_accounting.py
CalendarServer/branches/release/CalendarServer-5.3-dev/txdav/caldav/datastore/scheduling/icaldiff.py
CalendarServer/branches/release/CalendarServer-5.3-dev/txdav/caldav/datastore/scheduling/processing.py
CalendarServer/branches/release/CalendarServer-5.3-dev/txdav/caldav/datastore/scheduling/scheduler.py
Modified: CalendarServer/branches/release/CalendarServer-5.3-dev/conf/caldavd-test.plist
===================================================================
--- CalendarServer/branches/release/CalendarServer-5.3-dev/conf/caldavd-test.plist 2014-04-10 20:08:50 UTC (rev 13246)
+++ CalendarServer/branches/release/CalendarServer-5.3-dev/conf/caldavd-test.plist 2014-04-10 20:09:41 UTC (rev 13247)
@@ -597,16 +597,24 @@
<!-- Enable accounting for certain operations -->
<key>AccountingCategories</key>
<dict>
+ <key>HTTP</key>
+ <false/>
<key>iTIP</key>
<false/>
- <key>HTTP</key>
+ <key>iTIP-VFREEBUSY</key>
<false/>
+ <key>Implicit Errors</key>
+ <false/>
+ <key>AutoScheduling</key>
+ <false/>
+ <key>iSchedule</key>
+ <false/>
</dict>
- <!-- Enable accounting for specific principals -->
+ <!-- Enable accounting for specific principal GUIDs or use "*" for all -->
<key>AccountingPrincipals</key>
<array>
- <!-- <string>/principals/__uids__/454D85C0-09F0-4DC6-A3C6-97DFEB4622CD/</string> -->
+ <!-- <string>454D85C0-09F0-4DC6-A3C6-97DFEB4622CD</string> -->
</array>
Modified: CalendarServer/branches/release/CalendarServer-5.3-dev/support/build.sh
===================================================================
--- CalendarServer/branches/release/CalendarServer-5.3-dev/support/build.sh 2014-04-10 20:08:50 UTC (rev 13246)
+++ CalendarServer/branches/release/CalendarServer-5.3-dev/support/build.sh 2014-04-10 20:09:41 UTC (rev 13247)
@@ -809,7 +809,7 @@
# XXX actually PyCalendar should be imported in-place.
py_dependency -fe -i "src" -r HEAD \
- "PyCalendar" "pycalendar" "pycalendar" \
+ "PyCalendar" "pycalendar" "pycalendar-2" \
"${svn_uri_base}/PyCalendar/branches/CalendarServer-5.2";
#
@@ -882,7 +882,7 @@
"${pypi}/p/${n}/${p}.tar.gz";
svn_get "CalDAVTester" "${top}/CalDAVTester" \
- "${svn_uri_base}/CalDAVTester/branches/release/CalDAVTester-5.2-dev" HEAD;
+ "${svn_uri_base}/CalDAVTester/branches/release/CalDAVTester-5.3-dev" HEAD;
local v="3.0.1";
local n="epydoc";
Modified: CalendarServer/branches/release/CalendarServer-5.3-dev/twistedcaldav/accounting.py
===================================================================
--- CalendarServer/branches/release/CalendarServer-5.3-dev/twistedcaldav/accounting.py 2014-04-10 20:08:50 UTC (rev 13246)
+++ CalendarServer/branches/release/CalendarServer-5.3-dev/twistedcaldav/accounting.py 2014-04-10 20:09:41 UTC (rev 13247)
@@ -33,15 +33,17 @@
log = Logger()
-def accountingEnabled(category, principal):
+def accountingEnabled(category, record):
"""
- Determine if accounting is enabled for the given category and principal.
+ Determine if accounting is enabled for the given category and directory record.
"""
return (
accountingEnabledForCategory(category) and
- accountingEnabledForPrincipal(principal)
+ accountingEnabledForRecord(record)
)
+
+
def accountingEnabledForCategory(category):
"""
Determine if accounting is enabled for the given category.
@@ -51,43 +53,40 @@
return False
return AccountingCategories.get(category, False)
-def accountingEnabledForPrincipal(principal):
+
+
+def accountingEnabledForRecord(record):
"""
- Determine if accounting is enabled for the given principal.
+ Determine if accounting is enabled for the given record.
"""
enabledPrincipalURIs = config.AccountingPrincipals
if "*" in enabledPrincipalURIs:
return True
- if principal.principalURL() in enabledPrincipalURIs:
- return True
+ return record.guid in enabledPrincipalURIs
- for principal in principal.alternateURIs():
- if principal in enabledPrincipalURIs:
- return True
- return False
-def emitAccounting(category, principal, data, tag=None):
+def emitAccounting(category, record, data, tag=None, filename=None):
"""
Write the supplied data to the appropriate location for the given
- category and principal.
+ category and record.
- @param principal: the principal for whom a log entry is to be created.
- @type principal: L{DirectoryPrincipalResource}
+ @param record: the record for whom a log entry is to be created.
+ @type record: L{DirectoryRecord}
@param category: accounting category
@type category: C{tuple}
@param data: data to write.
@type data: C{str}
- """
- if isinstance(principal, str):
- principalLogPath = principal
- elif accountingEnabled(category, principal):
+ """
+ if isinstance(record, str):
+ principalLogPath = record
+ elif accountingEnabled(category, record):
principalLogPath = os.path.join(
- principal.record.guid[0:2],
- principal.record.guid[2:4],
- principal.record.guid
+ record.guid[0:2],
+ record.guid[2:4],
+ record.guid
)
else:
return None
@@ -105,30 +104,32 @@
)
logFilename = os.path.join(
logDirectory,
- datetime.datetime.now().isoformat()
+ datetime.datetime.now().isoformat() if filename is None else filename
)
-
+
if not os.path.isdir(os.path.join(logRoot, logDirectory)):
os.makedirs(os.path.join(logRoot, logDirectory))
- logFilename = "%s-01" % (logFilename,)
- if tag:
- logFilename += " (%s)" % (tag,)
- logFilename += ".txt"
+ if filename is None:
+ logFilename = "%s-01" % (logFilename,)
+ if tag:
+ logFilename += " (%s)" % (tag,)
+ logFilename += ".txt"
else:
- index = 1
- while True:
- path = "%s-%02d" % (logFilename, index)
- if tag:
- path += " (%s)" % (tag,)
- path += ".txt"
- if not os.path.isfile(os.path.join(logRoot, path)):
- logFilename = path
- break
- if index == 1000:
- log.error("Too many %s accounting files for %s" % (category, principal))
- return None
- index += 1
-
+ if filename is None:
+ index = 1
+ while True:
+ path = "%s-%02d" % (logFilename, index)
+ if tag:
+ path += " (%s)" % (tag,)
+ path += ".txt"
+ if not os.path.isfile(os.path.join(logRoot, path)):
+ logFilename = path
+ break
+ if index == 1000:
+ log.error("Too many %s accounting files for %s" % (category, record))
+ return None
+ index += 1
+
#
# Now write out the data to the log file
#
@@ -137,7 +138,7 @@
logFile.write(data)
finally:
logFile.close()
-
+
return logFilename
except OSError, e:
Modified: CalendarServer/branches/release/CalendarServer-5.3-dev/twistedcaldav/stdconfig.py
===================================================================
--- CalendarServer/branches/release/CalendarServer-5.3-dev/twistedcaldav/stdconfig.py 2014-04-10 20:08:50 UTC (rev 13246)
+++ CalendarServer/branches/release/CalendarServer-5.3-dev/twistedcaldav/stdconfig.py 2014-04-10 20:09:41 UTC (rev 13247)
@@ -476,7 +476,12 @@
"LogID" : "",
"AccountingCategories": {
+ "HTTP": False,
"iTIP": False,
+ "iTIP-VFREEBUSY": False,
+ "Implicit Errors": False,
+ "AutoScheduling": False,
+ "iSchedule": False,
},
"AccountingPrincipals": [],
"AccountingLogRoot" : "accounting",
Modified: CalendarServer/branches/release/CalendarServer-5.3-dev/twistedcaldav/test/test_accounting.py
===================================================================
--- CalendarServer/branches/release/CalendarServer-5.3-dev/twistedcaldav/test/test_accounting.py 2014-04-10 20:08:50 UTC (rev 13246)
+++ CalendarServer/branches/release/CalendarServer-5.3-dev/twistedcaldav/test/test_accounting.py 2014-04-10 20:09:41 UTC (rev 13247)
@@ -33,18 +33,12 @@
os.mkdir(config.AccountingLogRoot)
- class _Principal(object):
+ class _Record(object):
- class _Record(object):
-
- def __init__(self, guid):
- self.guid = guid
-
def __init__(self, guid):
+ self.guid = guid
- self.record = self._Record(guid)
-
def test_permissions_makedirs(self):
"""
Test permissions when creating accounting
@@ -53,7 +47,7 @@
# Make log root non-writeable
os.chmod(config.AccountingLogRoot, stat.S_IRUSR)
- emitAccounting("iTIP", self._Principal("1234-5678"), "bogus")
+ emitAccounting("iTIP", self._Record("1234-5678"), "bogus")
def test_file_instead_of_directory(self):
@@ -64,7 +58,7 @@
# Make log root a file
config.AccountingLogRoot = "other"
open(config.AccountingLogRoot, "w").close()
- emitAccounting("iTIP", self._Principal("1234-5678"), "bogus")
+ emitAccounting("iTIP", self._Record("1234-5678"), "bogus")
Modified: CalendarServer/branches/release/CalendarServer-5.3-dev/txdav/caldav/datastore/scheduling/icaldiff.py
===================================================================
--- CalendarServer/branches/release/CalendarServer-5.3-dev/txdav/caldav/datastore/scheduling/icaldiff.py 2014-04-10 20:08:50 UTC (rev 13246)
+++ CalendarServer/branches/release/CalendarServer-5.3-dev/txdav/caldav/datastore/scheduling/icaldiff.py 2014-04-10 20:09:41 UTC (rev 13247)
@@ -497,6 +497,7 @@
# If PARTSTAT was changed by the attendee, add a timestamp if needed
if config.Scheduling.Options.TimestampAttendeePartStatChanges:
serverAttendee.setParameter("X-CALENDARSERVER-DTSTAMP", PyCalendarDateTime.getNowUTC().getText())
+ serverAttendee.removeParameter("X-CALENDARSERVER-AUTO")
replyNeeded = True
Modified: CalendarServer/branches/release/CalendarServer-5.3-dev/txdav/caldav/datastore/scheduling/processing.py
===================================================================
--- CalendarServer/branches/release/CalendarServer-5.3-dev/txdav/caldav/datastore/scheduling/processing.py 2014-04-10 20:08:50 UTC (rev 13246)
+++ CalendarServer/branches/release/CalendarServer-5.3-dev/txdav/caldav/datastore/scheduling/processing.py 2014-04-10 20:09:41 UTC (rev 13247)
@@ -19,7 +19,6 @@
from pycalendar.timezone import PyCalendarTimezone
from twext.python.log import Logger
-from twext.web2.dav.method.report import NumberOfMatchesWithinLimits
from twext.web2.http import HTTPError
from twisted.internet import reactor
@@ -40,9 +39,11 @@
import hashlib
import uuid
from txdav.caldav.icalendarstore import ComponentUpdateState, \
- ComponentRemoveState
+ ComponentRemoveState, QueryMaxResources
from twext.enterprise.locking import NamedLock
from txdav.caldav.datastore.scheduling.freebusy import generateFreeBusyInfo
+from twistedcaldav.accounting import emitAccounting, accountingEnabled
+import json
"""
CalDAV implicit processing.
@@ -543,7 +544,15 @@
if self.recipient.principal.canAutoSchedule(organizer=organizer):
# auto schedule mode can depend on who the organizer is
mode = self.recipient.principal.getAutoScheduleMode(organizer=organizer)
- send_reply, store_inbox, partstat = (yield self.checkAttendeeAutoReply(new_calendar, mode))
+ send_reply, store_inbox, partstat, accounting = (yield self.checkAttendeeAutoReply(new_calendar, mode))
+ if accounting is not None:
+ accounting["action"] = "create"
+ emitAccounting(
+ "AutoScheduling",
+ self.recipient.principal,
+ json.dumps(accounting) + "\r\n",
+ filename=self.uid + ".txt"
+ )
# Only store inbox item when reply is not sent or always for users
store_inbox = store_inbox or self.recipient.principal.getCUType() == "INDIVIDUAL"
@@ -577,7 +586,15 @@
if self.recipient.principal.canAutoSchedule(organizer=organizer) and not hasattr(self.txn, "doing_attendee_refresh"):
# auto schedule mode can depend on who the organizer is
mode = self.recipient.principal.getAutoScheduleMode(organizer=organizer)
- send_reply, store_inbox, partstat = (yield self.checkAttendeeAutoReply(new_calendar, mode))
+ send_reply, store_inbox, partstat, accounting = (yield self.checkAttendeeAutoReply(new_calendar, mode))
+ if accounting is not None:
+ accounting["action"] = "modify"
+ emitAccounting(
+ "AutoScheduling",
+ self.recipient.principal,
+ json.dumps(accounting) + "\r\n",
+ filename=self.uid + ".txt"
+ )
# Only store inbox item when reply is not sent or always for users
store_inbox = store_inbox or self.recipient.principal.getCUType() == "INDIVIDUAL"
@@ -655,6 +672,18 @@
# Check to see if this is a cancel of the entire event
processed_message, delete_original, rids = iTipProcessing.processCancel(self.message, self.recipient_calendar, autoprocessing=autoprocessed)
if processed_message:
+ if autoprocessed and accountingEnabled("AutoScheduling", self.recipient.principal):
+ accounting = {
+ "action": "cancel",
+ "when": PyCalendarDateTime.getNowUTC().getText(),
+ "deleting": delete_original,
+ }
+ emitAccounting(
+ "AutoScheduling",
+ self.recipient.principal,
+ json.dumps(accounting) + "\r\n",
+ filename=self.uid + ".txt"
+ )
if delete_original:
# Delete the attendee's copy of the event
@@ -774,9 +803,18 @@
should be added, and the new PARTSTAT.
"""
+ if accountingEnabled("AutoScheduling", self.recipient.principal):
+ accounting = {
+ "when": PyCalendarDateTime.getNowUTC().getText(),
+ "automode": automode,
+ "changed": False,
+ }
+ else:
+ accounting = None
+
# First ignore the none mode
if automode == "none":
- returnValue((False, True, "",))
+ returnValue((False, True, "", accounting,))
elif not automode or automode == "default":
automode = config.Scheduling.Options.AutoSchedule.DefaultMode
@@ -789,6 +827,10 @@
expand_max = PyCalendarDateTime.getToday() + default_future_expansion_duration
instances = calendar.expandTimeRanges(expand_max, ignoreInvalidInstances=True)
+ if accounting is not None:
+ accounting["expand-max"] = expand_max.getText()
+ accounting["instances"] = len(instances.instances)
+
# We are going to ignore auto-accept processing for anything more than a day old (actually use -2 days
# to add some slop to account for possible timezone offsets)
min_date = PyCalendarDateTime.getToday()
@@ -805,11 +847,15 @@
if instance.active:
allOld = False
+ instances = sorted(instances.instances.values(), key=lambda x: x.rid)
+
# If every instance is in the past we punt right here so we don't waste time on freebusy lookups etc.
# There will be no auto-accept and no inbox item stored (so as not to waste storage on items that will
# never be processed).
if allOld:
- returnValue((False, False, "",))
+ if accounting is not None:
+ accounting["status"] = "all instances are old"
+ returnValue((False, False, "", accounting))
# Extract UID from primary component as we want to ignore this one if we match it
# in any calendars.
@@ -818,6 +864,9 @@
# Now compare each instance time-range with the index and see if there is an overlap
fbset = (yield self.recipient.inbox.ownerHome().loadCalendars())
fbset = [fbcalendar for fbcalendar in fbset if fbcalendar.isUsedForFreeBusy()]
+ if accounting is not None:
+ accounting["fbset"] = [testcal.name() for testcal in fbset]
+ accounting["tr"] = []
for testcal in fbset:
@@ -827,8 +876,11 @@
tzinfo = tz.gettimezone() if tz is not None else PyCalendarTimezone(utc=True)
# Now do search for overlapping time-range and set instance.free based
- # on whether there is an overlap or not
- for instance in instances.instances.itervalues():
+ # on whether there is an overlap or not.
+ # NB Do this in reverse order so that the date farthest in the future is tested first - that will
+ # ensure that freebusy that far into the future is determined and will trigger time-range caching
+ # and indexing out that far - and that will happen only once through this loop.
+ for instance in reversed(instances):
if instance.partstat == "NEEDS-ACTION" and instance.free and instance.active:
try:
# First list is BUSY, second BUSY-TENTATIVE, third BUSY-UNAVAILABLE
@@ -854,19 +906,26 @@
# If any fbinfo entries exist we have an overlap
if len(fbinfo[0]) or len(fbinfo[1]) or len(fbinfo[2]):
instance.free = False
- except NumberOfMatchesWithinLimits:
- instance.free[instance] = False
+ if accounting is not None:
+ accounting["tr"].insert(0, (tr.attributes["start"], tr.attributes["end"], instance.free,))
+ except QueryMaxResources:
+ instance.free = False
log.info("Exceeded number of matches whilst trying to find free-time.")
+ if accounting is not None:
+ accounting["problem"] = "Exceeded number of matches"
# If everything is declined we can exit now
- if not any([instance.free for instance in instances.instances.itervalues()]):
+ if not any([instance.free for instance in instances]):
break
+ if accounting is not None:
+ accounting["tr"] = accounting["tr"][:30]
+
# Now adjust the instance.partstat currently set to "NEEDS-ACTION" to the
# value determined by auto-accept logic based on instance.free state. However,
# ignore any instance in the past - leave them as NEEDS-ACTION.
partstat_counts = collections.defaultdict(int)
- for instance in instances.instances.itervalues():
+ for instance in instances:
if instance.partstat == "NEEDS-ACTION" and instance.active:
if automode == "accept-always":
freePartstat = busyPartstat = "ACCEPTED"
@@ -880,14 +939,18 @@
if len(partstat_counts) == 0:
# Nothing to do
- returnValue((False, False, "",))
+ if accounting is not None:
+ accounting["status"] = "no partstat changes"
+ returnValue((False, False, "", accounting,))
elif len(partstat_counts) == 1:
# Do the simple case of all PARTSTATs the same separately
# Extract the ATTENDEE property matching current recipient from the calendar data
attendeeProps = calendar.getAttendeeProperties(cuas)
if not attendeeProps:
- returnValue((False, False, "",))
+ if accounting is not None:
+ accounting["status"] = "no attendee to change"
+ returnValue((False, False, "", accounting,))
made_changes = False
partstat = partstat_counts.keys()[0]
@@ -895,6 +958,10 @@
made_changes |= self.resetAttendeePartstat(component, cuas, partstat)
store_inbox = partstat == "NEEDS-ACTION"
+ if accounting is not None:
+ accounting["status"] = "setting all partstats to {}".format(partstat) if made_changes else "all partstats correct"
+ accounting["changed"] = made_changes
+
else:
# Hard case: some accepted, some declined, some needs-action
# What we will do is mark any master instance as accepted, then mark each existing
@@ -920,7 +987,7 @@
made_changes |= self.resetAttendeePartstat(master, cuas, defaultPartStat)
# Look at expanded instances and change partstat accordingly
- for instance in sorted(instances.instances.values(), key=lambda x: x.rid):
+ for instance in instances:
overridden = calendar.overriddenComponent(instance.rid)
if not overridden and instance.partstat == defaultPartStat:
@@ -945,11 +1012,15 @@
made_changes = True
calendar.addComponent(derived)
+ if accounting is not None:
+ accounting["status"] = "mixed partstat changes" if made_changes else "mixed partstats correct"
+ accounting["changed"] = made_changes
+
# Fake a SCHEDULE-STATUS on the ORGANIZER property
if made_changes:
calendar.setParameterToValueForPropertyWithValue("SCHEDULE-STATUS", iTIPRequestStatus.MESSAGE_DELIVERED_CODE, "ORGANIZER", None)
- returnValue((made_changes, store_inbox, partstat,))
+ returnValue((made_changes, store_inbox, partstat, accounting,))
@inlineCallbacks
@@ -1035,6 +1106,10 @@
# Adjust TRANSP to OPAQUE if PARTSTAT is ACCEPTED, otherwise TRANSPARENT
component.replaceProperty(Property("TRANSP", "OPAQUE" if partstat == "ACCEPTED" else "TRANSPARENT"))
+ if madeChanges:
+ attendee.setParameter("X-CALENDARSERVER-AUTO", PyCalendarDateTime.getNowUTC().getText())
+ attendee.removeParameter("X-CALENDARSERVER-DTSTAMP")
+
return madeChanges
Modified: CalendarServer/branches/release/CalendarServer-5.3-dev/txdav/caldav/datastore/scheduling/scheduler.py
===================================================================
--- CalendarServer/branches/release/CalendarServer-5.3-dev/txdav/caldav/datastore/scheduling/scheduler.py 2014-04-10 20:08:50 UTC (rev 13246)
+++ CalendarServer/branches/release/CalendarServer-5.3-dev/txdav/caldav/datastore/scheduling/scheduler.py 2014-04-10 20:09:41 UTC (rev 13247)
@@ -403,7 +403,8 @@
accountingType = "iTIP-VFREEBUSY" if self.calendar.mainType() == "VFREEBUSY" else "iTIP"
if accountingEnabled(accountingType, self.organizer.principal):
emitAccounting(
- accountingType, self.organizer.principal,
+ accountingType,
+ self.organizer.principal,
"Originator: %s\nRecipients:\n%sMethod:%s\n\n%s"
% (
str(self.originator),
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://lists.macosforge.org/pipermail/calendarserver-changes/attachments/20140410/2d3681be/attachment-0001.html>
More information about the calendarserver-changes
mailing list