[CalendarServer-users] Problems with external invites

Frank Keller fkeller at datameer.com
Fri Sep 20 08:19:40 PDT 2013


Dear list,

please find below some more details about this error. 
The exact error message the user is receiving is:

The server responded:
"403"
to operation CalDAVWriteEntityQueueableOperation.

Log entries:

access.log:
-----------------
xxx.xxx.xxx.xxx - USERNAME [16/Sep/2013:21:25:16 +0200] "PROPFIND /principals/__uids__/XXXXXXXX-XXXX-XXXX-XXXX-XXXXXXXXXXXX/ HTTP/1.1" 207 1377 "-" "Mac OS X/10.8.4 (12E55) CalendarAgent/57" i=3 t=16.3 or=1
xxx.xxx.xxx.xxx - USERNAME [16/Sep/2013:21:25:16 +0200] "PROPFIND /calendars/__uids__/XXXXXXXX-XXXX-XXXX-XXXX-XXXXXXXXXXXX/XXXXXXXX-XXXX-XXXX-XXXX-XXXXXXXXXXXX/ HTTP/1.1" 207 389 "-" "Mac OS X/10.8.4 (12E55) CalendarAgent/57" i=3 t=25.7 or=1 responses=1
xxx.xxx.xxx.xxx - USERNAME [16/Sep/2013:21:25:16 +0200] "PUT /calendars/__uids__/XXXXXXXX-XXXX-XXXX-XXXX-XXXXXXXXXXXX/XXXXXXXX-XXXX-XXXX-XXXX-XXXXXXXXXXXX/XXXXXXXX-XXXX-XXXX-XXXX-XXXXXXXXXXXX.ics HTTP/1.1" 403 256 "-" "Mac OS X/10.8.4 (12E55) CalendarAgent/57" i=3 t=48.8 or=1 cl=1363

error.log:
-----------------
2013-09-16 21:25:16+0200 [-] [caldav-3]  [HTTPChannel,17729,xxx.xxx.xxx.xxx] [twext.web2.server#info] PUT /calendars/__uids__/XXXXXXXX-XXXX-XXXX-XXXX-XXXXXXXXXXXX/XXXXXXXX-XXXX-XXXX-XXXX-XXXXXXXXXXXX/XXXXXXXX-XXXX-XXXX-XXXX-XXXXXXXXXXXX.ics HTTP/1.1
2013-09-16 21:25:16+0200 [-] [caldav-3]  [HTTPChannel,17729,xxx.xxx.xxx.xxx] [twistedcaldav.directory.digest.DigestCredentialsMemcache#debug] Getting Cache Token for '667401876552876251529133599083248041295625182628380460952'
2013-09-16 21:25:16+0200 [-] [caldav-3]  [HTTPChannel,17729,xxx.xxx.xxx.xxx] [twistedcaldav.memcachepool.MemCachePool#debug] Busied client: <twistedcaldav.memcachepool.PooledMemCacheProtocol instance at 0x10e861908>
2013-09-16 21:25:16+0200 [-] [caldav-3]  [HTTPChannel,17729,xxx.xxx.xxx.xxx] [twistedcaldav.memcachepool.MemCachePool#debug] Clients #free: 4, #busy: 1, #pending: 0, #queued: 0
2013-09-16 21:25:16+0200 [-] [caldav-3]  [PooledMemCacheProtocol,client] [twistedcaldav.memcachepool.MemCachePool#debug] Freed client: <twistedcaldav.memcachepool.PooledMemCacheProtocol instance at 0x10e861908>
2013-09-16 21:25:16+0200 [-] [caldav-3]  [PooledMemCacheProtocol,client] [twistedcaldav.memcachepool.MemCachePool#debug] Clients #free: 5, #busy: 0, #pending: 0, #queued: 0
2013-09-16 21:25:16+0200 [-] [caldav-3]  [PooledMemCacheProtocol,client] [calendarserver.platform.darwin.od.opendirectory#debug] Checking digest auth for user 'USERNAME' (tries remaining: 3)
2013-09-16 21:25:16+0200 [-] [caldav-3]  [PooledMemCacheProtocol,client] [calendarserver.platform.darwin.od.opendirectory#debug] Digest auth for user 'USERNAME' result: True
2013-09-16 21:25:16+0200 [-] [caldav-3]  [PooledMemCacheProtocol,client] [twistedcaldav.memcacher.Memcacher#debug] Getting Cache Token for 'XXXXXXXX-XXXX-XXXX-XXXX-XXXXXXXXXXXX'
2013-09-16 21:25:16+0200 [-] [caldav-3]  [PooledMemCacheProtocol,client] [twistedcaldav.memcachepool.MemCachePool#debug] Busied client: <twistedcaldav.memcachepool.PooledMemCacheProtocol instance at 0x10e85b998>
2013-09-16 21:25:16+0200 [-] [caldav-3]  [PooledMemCacheProtocol,client] [twistedcaldav.memcachepool.MemCachePool#debug] Clients #free: 4, #busy: 1, #pending: 0, #queued: 0
2013-09-16 21:25:16+0200 [-] [caldav-3]  [PooledMemCacheProtocol,client] [twistedcaldav.memcachepool.MemCachePool#debug] Freed client: <twistedcaldav.memcachepool.PooledMemCacheProtocol instance at 0x10e85b998>
2013-09-16 21:25:16+0200 [-] [caldav-3]  [PooledMemCacheProtocol,client] [twistedcaldav.memcachepool.MemCachePool#debug] Clients #free: 5, #busy: 0, #pending: 0, #queued: 0
2013-09-16 21:25:16+0200 [-] [caldav-3]  [PooledMemCacheProtocol,client] [twistedcaldav.memcacher.Memcacher#debug] Getting Cache Token for '179544'
2013-09-16 21:25:16+0200 [-] [caldav-3]  [PooledMemCacheProtocol,client] [twistedcaldav.memcachepool.MemCachePool#debug] Busied client: <twistedcaldav.memcachepool.PooledMemCacheProtocol instance at 0x10e0bfc20>
2013-09-16 21:25:16+0200 [-] [caldav-3]  [PooledMemCacheProtocol,client] [twistedcaldav.memcachepool.MemCachePool#debug] Clients #free: 4, #busy: 1, #pending: 0, #queued: 0
2013-09-16 21:25:16+0200 [-] [caldav-3]  [PooledMemCacheProtocol,client] [twistedcaldav.memcachepool.MemCachePool#debug] Freed client: <twistedcaldav.memcachepool.PooledMemCacheProtocol instance at 0x10e0bfc20>
2013-09-16 21:25:16+0200 [-] [caldav-3]  [PooledMemCacheProtocol,client] [twistedcaldav.memcachepool.MemCachePool#debug] Clients #free: 5, #busy: 0, #pending: 0, #queued: 0
2013-09-16 21:25:16+0200 [-] [caldav-3]  [-] [twistedcaldav.memcacher.Memcacher#debug] Getting Cache Token for 'XXXXXXXX-XXXX-XXXX-XXXX-XXXXXXXXXXXX'
2013-09-16 21:25:16+0200 [-] [caldav-3]  [-] [twistedcaldav.memcachepool.MemCachePool#debug] Busied client: <twistedcaldav.memcachepool.PooledMemCacheProtocol instance at 0x10e69f680>
2013-09-16 21:25:16+0200 [-] [caldav-3]  [-] [twistedcaldav.memcachepool.MemCachePool#debug] Clients #free: 4, #busy: 1, #pending: 0, #queued: 0
2013-09-16 21:25:16+0200 [-] [caldav-3]  [PooledMemCacheProtocol,client] [twistedcaldav.memcachepool.MemCachePool#debug] Freed client: <twistedcaldav.memcachepool.PooledMemCacheProtocol instance at 0x10e69f680>
2013-09-16 21:25:16+0200 [-] [caldav-3]  [PooledMemCacheProtocol,client] [twistedcaldav.memcachepool.MemCachePool#debug] Clients #free: 5, #busy: 0, #pending: 0, #queued: 0
2013-09-16 21:25:16+0200 [-] [caldav-3]  [PooledMemCacheProtocol,client] [twistedcaldav.memcacher.Memcacher#debug] Getting Cache Token for '66274'
2013-09-16 21:25:16+0200 [-] [caldav-3]  [PooledMemCacheProtocol,client] [twistedcaldav.memcachepool.MemCachePool#debug] Busied client: <twistedcaldav.memcachepool.PooledMemCacheProtocol instance at 0x10e842ef0>
2013-09-16 21:25:16+0200 [-] [caldav-3]  [PooledMemCacheProtocol,client] [twistedcaldav.memcachepool.MemCachePool#debug] Clients #free: 4, #busy: 1, #pending: 0, #queued: 0
2013-09-16 21:25:16+0200 [-] [caldav-3]  [PooledMemCacheProtocol,client] [twistedcaldav.memcachepool.MemCachePool#debug] Freed client: <twistedcaldav.memcachepool.PooledMemCacheProtocol instance at 0x10e842ef0>
2013-09-16 21:25:16+0200 [-] [caldav-3]  [PooledMemCacheProtocol,client] [twistedcaldav.memcachepool.MemCachePool#debug] Clients #free: 5, #busy: 0, #pending: 0, #queued: 0
2013-09-16 21:25:16+0200 [-] [caldav-3]  [-] [twistedcaldav.memcacher.Memcacher#debug] Getting Cache Token for '66276'
2013-09-16 21:25:16+0200 [-] [caldav-3]  [-] [twistedcaldav.memcachepool.MemCachePool#debug] Busied client: <twistedcaldav.memcachepool.PooledMemCacheProtocol instance at 0x10e861908>
2013-09-16 21:25:16+0200 [-] [caldav-3]  [-] [twistedcaldav.memcachepool.MemCachePool#debug] Clients #free: 4, #busy: 1, #pending: 0, #queued: 0
2013-09-16 21:25:16+0200 [-] [caldav-3]  [PooledMemCacheProtocol,client] [twistedcaldav.memcachepool.MemCachePool#debug] Freed client: <twistedcaldav.memcachepool.PooledMemCacheProtocol instance at 0x10e861908>
2013-09-16 21:25:16+0200 [-] [caldav-3]  [PooledMemCacheProtocol,client] [twistedcaldav.memcachepool.MemCachePool#debug] Clients #free: 5, #busy: 0, #pending: 0, #queued: 0
2013-09-16 21:25:16+0200 [-] [caldav-3]  [-] [twistedcaldav.directory.appleopendirectory.OpenDirectoryService#debug] Memcache: checking dir|xxx.xxx.xxx.xxx|guid|xxx.xxx.xxx.xxx|users|groups
2013-09-16 21:25:16+0200 [-] [caldav-3]  [-] [twistedcaldav.directory.appleopendirectory.OpenDirectoryService#debug] Memcache: miss dir|xxx.xxx.xxx.xxx|guid|xxx.xxx.xxx.xxx|users|groups
2013-09-16 21:25:16+0200 [-] [caldav-3]  [-] [twistedcaldav.directory.appleopendirectory.OpenDirectoryService#debug] Faulting record for attribute 'guid' with value 'xxx.xxx.xxx.xxx'
2013-09-16 21:25:16+0200 [-] [caldav-3]  [-] [twistedcaldav.directory.appleopendirectory.OpenDirectoryService#debug] opendirectory.queryRecordsWithAttribute_list(<calendarserver.platform.darwin.od.opendirectory.Directory object at 0x10e3335d0>,'dsAttrTypeStandard:GeneratedUID','xxx.xxx.xxx.xxx',8193,False,['dsRecTypeStandard:Users'],['dsAttrTypeStandard:GeneratedUID', 'dsAttrTypeStandard:RecordName', 'dsAttrTypeStandard:AltSecurityIdentities', 'dsAttrTypeStandard:RecordType', 'dsAttrTypeStandard:RealName', 'dsAttrTypeStandard:FirstName', 'dsAttrTypeStandard:LastName', 'dsAttrTypeStandard:EMailAddress', 'dsAttrTypeStandard:AppleMetaNodeLocation'])
2013-09-16 21:25:16+0200 [-] [caldav-3]  [-] [twistedcaldav.directory.appleopendirectory.OpenDirectoryService#debug] opendirectory.queryRecordsWithAttribute_list(<calendarserver.platform.darwin.od.opendirectory.Directory object at 0x10e3335d0>,'dsAttrTypeStandard:GeneratedUID','xxx.xxx.xxx.xxx',8193,False,['dsRecTypeStandard:Groups'],['dsAttrTypeStandard:GeneratedUID', 'dsAttrTypeStandard:RecordName', 'dsAttrTypeStandard:AltSecurityIdentities', 'dsAttrTypeStandard:RecordType', 'dsAttrTypeStandard:RealName', 'dsAttrTypeStandard:FirstName', 'dsAttrTypeStandard:LastName', 'dsAttrTypeStandard:EMailAddress', 'dsAttrTypeStandard:AppleMetaNodeLocation', 'dsAttrTypeStandard:GroupMembers', 'dsAttrTypeStandard:NestedGroups'])
2013-09-16 21:25:16+0200 [-] [caldav-3]  [-] [twistedcaldav.directory.appleopendirectory.OpenDirectoryService#debug] opendirectory.queryRecordsWithAttribute_list matched records: 1
2013-09-16 21:25:16+0200 [-] [caldav-3]  [-] [twistedcaldav.directory.appleopendirectory.OpenDirectoryService#debug] Storing (guid xxx.xxx.xxx.xxx) <OpenDirectoryRecord[users at xxxxxxxxxxxxxxxxxxxxxxxxxxx(server.domain.com->['/LDAPv3/127.0.0.1'])] xxx.xxx.xxx.xxx(otherusername) 'OTHER USER'> in internal cache
2013-09-16 21:25:16+0200 [-] [caldav-3]  [-] [twistedcaldav.directory.cachingdirectory.DictRecordTypeCache#debug] Memcache: storing dir|xxx.xxx.xxx.xxx|guid|xxx.xxx.xxx.xxx|users|groups
2013-09-16 21:25:16+0200 [-] [caldav-3]  [-] [twistedcaldav.directory.appleopendirectory.OpenDirectoryService#debug] Found record for attribute 'guid' with value 'xxx.xxx.xxx.xxx'
2013-09-16 21:25:16+0200 [-] [caldav-3]  [-] [twistedcaldav.directory.appleopendirectory.OpenDirectoryService#debug] Memcache: checking dir|xxx.xxx.xxx.xxx|cua|mailto:someuser at otherdomain.com|users|groups
2013-09-16 21:25:16+0200 [-] [caldav-3]  [-] [twistedcaldav.directory.appleopendirectory.OpenDirectoryService#debug] Memcache: miss dir|xxx.xxx.xxx.xxx|cua|mailto:someuser at otherdomain.com|users|groups
2013-09-16 21:25:16+0200 [-] [caldav-3]  [-] [twistedcaldav.directory.appleopendirectory.OpenDirectoryService#debug] Faulting record for attribute 'cua' with value 'mailto:someuser at otherdomain.com'
2013-09-16 21:25:16+0200 [-] [caldav-3]  [-] [twistedcaldav.directory.appleopendirectory.OpenDirectoryService#debug] opendirectory.queryRecordsWithAttribute_list(<calendarserver.platform.darwin.od.opendirectory.Directory object at 0x10e3335d0>,'dsAttrTypeStandard:EMailAddress','someuser at otherdomain.com',8193,True,['dsRecTypeStandard:Users'],['dsAttrTypeStandard:GeneratedUID', 'dsAttrTypeStandard:RecordName', 'dsAttrTypeStandard:AltSecurityIdentities', 'dsAttrTypeStandard:RecordType', 'dsAttrTypeStandard:RealName', 'dsAttrTypeStandard:FirstName', 'dsAttrTypeStandard:LastName', 'dsAttrTypeStandard:EMailAddress', 'dsAttrTypeStandard:AppleMetaNodeLocation'])
2013-09-16 21:25:16+0200 [-] [caldav-3]  [-] [twistedcaldav.directory.appleopendirectory.OpenDirectoryService#debug] opendirectory.queryRecordsWithAttribute_list matched records: 0
2013-09-16 21:25:16+0200 [-] [caldav-3]  [-] [twistedcaldav.directory.appleopendirectory.OpenDirectoryService#debug] Memcache: checking dir|xxx.xxx.xxx.xxx|cua|mailto:someuser at otherdomain.com|users|groups
2013-09-16 21:25:16+0200 [-] [caldav-3]  [-] [twistedcaldav.directory.appleopendirectory.OpenDirectoryService#debug] Memcache: miss dir|xxx.xxx.xxx.xxx|cua|mailto:someuser at otherdomain.com|users|groups
2013-09-16 21:25:16+0200 [-] [caldav-3]  [-] [twistedcaldav.directory.appleopendirectory.OpenDirectoryService#debug] Faulting record for attribute 'cua' with value 'mailto:someuser at otherdomain.com'
2013-09-16 21:25:16+0200 [-] [caldav-3]  [-] [twistedcaldav.directory.appleopendirectory.OpenDirectoryService#debug] opendirectory.queryRecordsWithAttribute_list(<calendarserver.platform.darwin.od.opendirectory.Directory object at 0x10e3335d0>,'dsAttrTypeStandard:EMailAddress','someuser at otherdomain.com',8193,True,['dsRecTypeStandard:Users'],['dsAttrTypeStandard:GeneratedUID', 'dsAttrTypeStandard:RecordName', 'dsAttrTypeStandard:AltSecurityIdentities', 'dsAttrTypeStandard:RecordType', 'dsAttrTypeStandard:RealName', 'dsAttrTypeStandard:FirstName', 'dsAttrTypeStandard:LastName', 'dsAttrTypeStandard:EMailAddress', 'dsAttrTypeStandard:AppleMetaNodeLocation'])
2013-09-16 21:25:16+0200 [-] [caldav-3]  [-] [twistedcaldav.directory.appleopendirectory.OpenDirectoryService#debug] opendirectory.queryRecordsWithAttribute_list matched records: 0
2013-09-16 21:25:16+0200 [-] [caldav-3]  [-] [twistedcaldav.directory.principal#debug] No principal for calendar user address: 'mailto:someuser at otherdomain.com'
2013-09-16 21:25:16+0200 [-] [caldav-3]  [-] [twistedcaldav.memcachelock.MemcacheLock#debug] Adding Cache Token for 'XXXXXXXX-XXXX-XXXX-XXXX-XXXXXXXXXXXX'
2013-09-16 21:25:16+0200 [-] [caldav-3]  [-] [twistedcaldav.memcachepool.MemCachePool#debug] Busied client: <twistedcaldav.memcachepool.PooledMemCacheProtocol instance at 0x10e85b998>
2013-09-16 21:25:16+0200 [-] [caldav-3]  [-] [twistedcaldav.memcachepool.MemCachePool#debug] Clients #free: 4, #busy: 1, #pending: 0, #queued: 0
2013-09-16 21:25:16+0200 [-] [caldav-3]  [PooledMemCacheProtocol,client] [twistedcaldav.memcachepool.MemCachePool#debug] Freed client: <twistedcaldav.memcachepool.PooledMemCacheProtocol instance at 0x10e85b998>
2013-09-16 21:25:16+0200 [-] [caldav-3]  [PooledMemCacheProtocol,client] [twistedcaldav.memcachepool.MemCachePool#debug] Clients #free: 5, #busy: 0, #pending: 0, #queued: 0
2013-09-16 21:25:16+0200 [-] [caldav-3]  [PooledMemCacheProtocol,client] [txdav.common.datastore.sql_legacy.MemcachedUIDReserver#debug] Reserving UID 'XXXXXXXX-XXXX-XXXX-XXXX-XXXXXXXXXXXX' @ <Calendar: 66276>
2013-09-16 21:25:16+0200 [-] [caldav-3]  [PooledMemCacheProtocol,client] [twistedcaldav.memcachepool.MemCachePool#debug] Busied client: <twistedcaldav.memcachepool.PooledMemCacheProtocol instance at 0x10e0bfc20>
2013-09-16 21:25:16+0200 [-] [caldav-3]  [PooledMemCacheProtocol,client] [twistedcaldav.memcachepool.MemCachePool#debug] Clients #free: 4, #busy: 1, #pending: 0, #queued: 0
2013-09-16 21:25:16+0200 [-] [caldav-3]  [PooledMemCacheProtocol,client] [twistedcaldav.memcachepool.MemCachePool#debug] Freed client: <twistedcaldav.memcachepool.PooledMemCacheProtocol instance at 0x10e0bfc20>
2013-09-16 21:25:16+0200 [-] [caldav-3]  [PooledMemCacheProtocol,client] [twistedcaldav.memcachepool.MemCachePool#debug] Clients #free: 5, #busy: 0, #pending: 0, #queued: 0
2013-09-16 21:25:16+0200 [-] [caldav-3]  [PooledMemCacheProtocol,client] [txdav.common.datastore.sql_legacy.MemcachedUIDReserver#debug] Unreserving UID 'XXXXXXXX-XXXX-XXXX-XXXX-XXXXXXXXXXXX' @ <Calendar: 66276>
2013-09-16 21:25:16+0200 [-] [caldav-3]  [PooledMemCacheProtocol,client] [twistedcaldav.memcachepool.MemCachePool#debug] Busied client: <twistedcaldav.memcachepool.PooledMemCacheProtocol instance at 0x10e69f680>
2013-09-16 21:25:16+0200 [-] [caldav-3]  [PooledMemCacheProtocol,client] [twistedcaldav.memcachepool.MemCachePool#debug] Clients #free: 4, #busy: 1, #pending: 0, #queued: 0
2013-09-16 21:25:16+0200 [-] [caldav-3]  [PooledMemCacheProtocol,client] [twistedcaldav.memcachepool.MemCachePool#debug] Freed client: <twistedcaldav.memcachepool.PooledMemCacheProtocol instance at 0x10e69f680>
2013-09-16 21:25:16+0200 [-] [caldav-3]  [PooledMemCacheProtocol,client] [twistedcaldav.memcachepool.MemCachePool#debug] Clients #free: 5, #busy: 0, #pending: 0, #queued: 0
2013-09-16 21:25:16+0200 [-] [caldav-3]  [-] [twistedcaldav.memcachelock.MemcacheLock#debug] Deleting Cache Token for 'XXXXXXXX-XXXX-XXXX-XXXX-XXXXXXXXXXXX'
2013-09-16 21:25:16+0200 [-] [caldav-3]  [-] [twistedcaldav.memcachepool.MemCachePool#debug] Busied client: <twistedcaldav.memcachepool.PooledMemCacheProtocol instance at 0x10e842ef0>
2013-09-16 21:25:16+0200 [-] [caldav-3]  [-] [twistedcaldav.memcachepool.MemCachePool#debug] Clients #free: 4, #busy: 1, #pending: 0, #queued: 0
2013-09-16 21:25:16+0200 [-] [caldav-3]  [PooledMemCacheProtocol,client] [twistedcaldav.memcachepool.MemCachePool#debug] Freed client: <twistedcaldav.memcachepool.PooledMemCacheProtocol instance at 0x10e842ef0>
2013-09-16 21:25:16+0200 [-] [caldav-3]  [PooledMemCacheProtocol,client] [twistedcaldav.memcachepool.MemCachePool#debug] Clients #free: 5, #busy: 0, #pending: 0, #queued: 0

Thanks in advance
Frank 

On Sep 18, 2013, at 2:35 PM, Frank Keller wrote:

> Dear list,
> 
> we are running an OSX lion server and using caldav on it. 
> 
> Server:
> 	System Version: 10.7.4 (Build 11E53)
> 	Kernel: Darwin 11.4.0
> 	Services: Mail, Open Directory, iCal
> 
> Clients are running OSX 10.7.x and 10.8.x
> 
> We had problems in the past with errors when refreshing calendars. It happened often that an error message 500 was shown when refreshing, especially if the user had more calendar delegations
> configured. After a long journey with the the apple support a workaround was mentioned to change the port from 'auto' to '8443' in the server settings for iCal on the client machines. We also changed the
> refresh rate for calendars from push to a fixed value. It seems that these changes solved the problems with the 500 error. 
> 
> Now we are facing a new error when receiving calendar invites as a attached ics file, mainly from outside our organization. When opening the attached ics file, an error 403 is shown and it is not possible to 
> accept the invite. Contacting Apple support again was not successful because they are saying it is a different error and we need to purchase a new support case to get help from them. 
> 
> So the question is, can anybody give us a hint on how to solve these issue? Maybe someone already has a fix or a workaround for this error? 
> If you need any further information, please let me know. 
> 
> Any help would be appreciated. 
> 
> Best Regards
> Frank 

-------------- next part --------------
A non-text attachment was scrubbed...
Name: signature.asc
Type: application/pgp-signature
Size: 496 bytes
Desc: Message signed with OpenPGP using GPGMail
URL: <http://lists.macosforge.org/pipermail/calendarserver-users/attachments/20130920/09e1e5c3/attachment-0001.sig>


More information about the calendarserver-users mailing list