Authentication issue? Something else?

23 Feb 2009

      We have been using iCal/CalDAV server along with iCal clients now for  
about 2-weeks and we have had some of the same issues others on this  
list have reported but we have either been able to resolve these or at  
least understand them. Since Monday, 2/16 an issue has started to  
appear that is new and I believe it is directly iCal/CalDAV related.  
The problem appears to be with authentication.

On the iCal/CalDAV server the DirectoryServices process is eating up  
CPU performance and response times for Calendar Server requests have  
started to become so long they are timing out for most but not all  
users. This was not an issue before as the DirectoryServices process  
typically was something under 10% of the CPU load at any given moment.  
We use an Open Directory (OD) server with Kerberos and this has been  
working well for the past 6-months. The iCal/CalDAV server is set up  
as "Connected to a Directory System" to get authentication from the  
OD. Our internal network appears to be OK, it is not saturated and is  
performing well. The OD server appears normal too.

There is an error repeating in the CalDAV log about a single UID not  
being found, this error repeats so many times I wonder if requests for  
this calendar are causing the slow down. This error repeats several  
thousand times per minute or 59 times per second so I can see why this  
might be it. So how do I make this go away because this may be an  
issue on the client side right? Users are making requests for a  
calendar/user that no longer is available in OD. Also would there be  
any advantage to making the iCal/CalDAV server an OD replica?

Any insight is greatly appreciated.

Here is some of the data:

Calendar Server | Mac OS X 10.5.6

This one entry repeats in the caldav log over and over (in fact there  
is very little else). I assume it is related to a user deleted from  
the OD but I'm not sure why this won't go away and it makes me  
suspicious this is at least partly what is delaying authentication  
requests. Below the log is the server performance snapshot showing the  
DirectoryServices PID at the top.

caldav log:
2009-02-18 14:28:51-0800 [-] [caldav-8016]  [OpenDirectoryService]  
Unable to find any record with GUID 77C3A32E-7315-4FD9-ABE4-1F3BDA78EAD0
2009-02-18 14:28:51-0800 [-] [caldav-8016]  [-] u'No principal found  
for UID: 77C3A32E-7315-4FD9-ABE4-1F3BDA78EAD0'

Processes:  72 total, 5 running, 67 sleeping... 271 threads
Load Avg:  3.37,  4.45,  4.75    CPU usage: 18.99% user,  8.77% sys,  
72.24% idle
SharedLibs: num =    7, resident =   45M code, 1388K data, 4448K  
linkedit.
MemRegions: num =  8365, resident =  889M +   15M private, 1737M shared.
PhysMem:  789M wired,  973M active,   36M inactive, 1806M used, 8434M  
free.
VM: 3251M + 371M   20873(0) pageins, 0(0) pageouts

   PID COMMAND      %CPU   TIME   #TH #PRTS #MREGS RPRVT  RSHRD   
RSIZE  VSIZE
    26 DirectoryS 152.4%  6:48:49  13   115    164 9644K+  584K    12M 
+   32M+
   202 Python       9.5%  3:29:02   5    44-   453   99M- 1696K   101M 
+  116M-
   204 Python       7.7%  3:43:18   4    39    402   80M  1696K     
82M    97M
   210 Python       7.0%  7:09:21   5    46    643  148M  1696K    
150M   164M
   200 Python       6.5%  3:13:29   4    39    364   69M  1696K     
71M    86M
  2040 UserNotifi   5.8% 42:09.88   2    87     93 1380K    14M   
5136K   148M
   203 Python       5.8%  2:36:24   5    46    376   73M  1696K     
75M    90M
   201 Python       5.8%  1:45:34   4    39    363   70M  1696K     
72M    86M
     0 kernel_tas   4.5% 24:12.76  65     2    405 7376K      0    
329M   156M
   465 top          3.9% 47:49.61   1    21     34 1480K   200K   
2072K    19M
    69 CoreRAIDSe   2.5%  6:05.67   2    67     35  408K  1500K   
2196K    30M
    43 Python       2.2%  8:30.92   1    15    219   11M  1672K     
13M    28M

Open Directory Server | Mac OS X 10.5.6

This all seems really typical so I could not find any red-flags here  
or in any logs I scanned.

Processes:  87 total, 2 running, 85 sleeping... 475 threads
Load Avg:  1.72,  1.35,  0.93    CPU usage: 12.65% user, 25.71% sys,  
61.63% idle
SharedLibs: num =    2, resident =   40M code,     0 data, 3608K  
linkedit.
MemRegions: num = 11086, resident =  551M +   16M private,   54M shared.
PhysMem:  253M wired,  700M active,  129M inactive, 1083M used,  965M  
free.
VM: 3486M + 129M   130707(0) pageins, 20334(0) pageouts

   PID COMMAND      %CPU   TIME   #TH #PRTS #MREGS RPRVT  RSHRD   
RSIZE  VSIZE
43853 slapd       18.5% 89:50.06   9    51    124   13M   624K     
16M   200M
  3761 AppleFileS  13.3%  3:25:40 202   492   1454  118M  3060K    
120M   324M
46661 top         12.7%  0:02.60   1    21     33 1244K   200K   
1836K    19M
     0 kernel_tas  10.4%  6:12:47  51     2    833   14M      0    
246M   157M
    25 DirectoryS   2.9%  2:46:42   8    91    113 4744K   636K   
7196K    25M
  8805 SecurityAg   1.8%  3:11:20   3    93    100 1700K  4708K   
6244K   120M
   419 smbd         0.3%  2:20.13   1    17     53  128K  2392K   
2136K    23M
    82 named        0.3% 14:37.08   1    14    107   24M   200K     
25M    38M
  8797 WindowServ   0.1% 15:46.87   4   105     63 4996K   992K   
6628K    81M
    81 mysqld       0.1% 15:42.35   9    40     55   53M   200K     
55M   119M
     1 launchd      0.1%  3:29.61   3   140     26  240K   320K    
600K    19M
   109 emond        0.1%  8:44.22   1    32     23  364K   464K   
1824K    27M

Don Kruse
Information Technology Manager
tel 503-314-7361

Don Kruse

Cyrus Daboo

Don Kruse

Don Kruse

Sean McAvoy

Don Kruse

Sean McAvoy

tags

participants (4)