[CalendarServer-users] Consistently getting memcache errors finding a directory

[Chris Cleeland]

BACKGROUND:

Debian 2.4 calendarserver package, upgraded from Debian 1.2.  No
user-initiated changes to the database of events, though that doesn't
mean that the package installer didn't do something unbeknownst to me.

One account with multiple calendars under it to achieve "sharing"

Clients: iCal from Snow Leopard; calendar app from iOS 5.0.1 on iPhone
4S and iPad 2.


SYMPTOM: calendars eventually fail to sync.  The scenario is strange
(they always are) but consistent.

If I add an account to iCal/SNL, the account syncs all events over a
period of time (there are several years worth of events).  Once the
initial sync is complete, I can add an event in one client, then
refresh the others and see the new event in the others.  I can also
delete an event in one client, then refresh and see the effect.  All
is good.

<Time goes on...maybe a few hours, maybe a day or two...and my wife
complains that calendars are broken again>

If I pop open the error.log, which I have fully cranked up to "debug"
threshold, I will see, amongst many things, stuff like this (see
original excerpt at
http://www.milodesigns.com/~chris/caldav2.4memcache.log ):

2012-03-12 08:21:53-0500 [-] [caldav-8008]  [-]
[twistedcaldav.cache.MemcacheResponseCache#debug] hashing key for get:
('PROPFIND', '{DAV:}unauthenticated',
'/principals/__uids__/212c90da-66c5-5aff-8e74-df7a2418773c/', '0',
-2045049267) to '930e80ec74a58ff30214d9e18701eb71'
2012-03-12 08:21:53-0500 [-] [caldav-8008]  [-]
[twistedcaldav.cache.MemcacheResponseCache#debug] Checking cache for:
'930e80ec74a58ff30214d9e18701eb71' 2012-03-12 08:21:53-0500 [-]
[caldav-8008]  [-] [twistedcaldav.memcachepool.MemCachePool#debug]
Busied client: <twistedcaldav.memcachepool.PooledMemCacheProtocol
instance at 0xa5999ac>
2012-03-12 08:21:53-0500 [-] [caldav-8008]  [-]
[twistedcaldav.memcachepool.MemCachePool#debug] Clients #free: 1,
#busy: 1, #pending: 0, #queued: 0
2012-03-12 08:21:53-0500 [-] [caldav-8008]
[PooledMemCacheProtocol,client]
[twistedcaldav.memcachepool.MemCachePool#debug] Freed client:
<twistedcaldav.memcachepool.PooledMemCacheProtocol instance at
0xa5999ac>
2012-03-12 08:21:53-0500 [-] [caldav-8008]
[PooledMemCacheProtocol,client]
[twistedcaldav.memcachepool.MemCachePool#debug] Clients #free: 2,
#busy: 0, #pending: 0, #queued: 0
2012-03-12 08:21:53-0500 [-] [caldav-8008]
[PooledMemCacheProtocol,client]
[twistedcaldav.cache.MemcacheResponseCache#debug] Not in cache:
'930e80ec74a58ff30214d9e18701eb71'
2012-03-12 08:21:53-0500 [-] [caldav-8008]
[PooledMemCacheProtocol,client]
[twistedcaldav.directory.principal#error] No principal found for UID:
212c90da-66c5-5aff-8e74-df7a2418773c


Notice the last line, where it says that there is no principal for the
UID.  While that may well be true for memcached, the reality is that
the UID it's trying to look up does, indeed, exist in the filesystem,
as that is the UID for the one single user configured in the client.
And, in fact, the server was able to find the UID for initial
population.

While I would love it if somebody would be able to tell me what's
wrong and an easy fix, I've developed software far too long to think
that's realistic :)  What I *AM* hoping is that somebody could help me
make sense of what those 7 lines from the log are telling me, so that
maybe I can apply some logic and deduction to hunt down real problem.


Some additional questions/observations:

1. This package uses memcached from another debian package, but it's
the same version as that pulled down by calendarserver during the
build.
2. I have installed the memcache command line tools, though they
strangely don't seem to dump anything.
3. While I would dearly love to move to a later release, that's not a
realistic option at the moment, especially since it's not clear that
it would actually resolve my issue.
4. Are the data stores compatible between 1.2 and 2.4?  Was there some
sort of migration I was supposed to run?

Thank you so much for any help,
-cj

-- 
Chris Cleeland