Calendarserver not recognized by Apple Calendar
Hi, I set up calendarserver on a Raspberry Pi. I can connect to it using an iPad and I can see the appropriate data in my web browser. Apple Calendar (OSX 10.8.4) however works for 30 seconds, then says "can not create a connection". The Console is logging
11.08.13 16:16:42,633 CalendarAgent[14934]: [com.apple.calendar.store.log.caldav.queue] [Got error on refresh, but not rectifying principal because it was manually configured: Error Domain=NSURLErrorDomain Code=-1001 "Zeitüberschreitung bei der Anforderung." UserInfo=0x7fb2a3336580 {NSUnderlyingError=0x7fb2a1b2f640 "Zeitüberschreitung bei der Anforderung.", NSErrorFailingURLStringKey=https://bastibe@cloud.bastibe.de:8443/calendars/__uids__/3e5c3ade-c0ea-5560-..., NSErrorFailingURLKey=https://bastibe@cloud.bastibe.de:8443/calendars/__uids__/3e5c3ade-c0ea-5560-..., NSLocalizedDescription=Zeitüberschreitung bei der Anforderung.}]
11.08.13 16:16:42,633 CalendarAgent[14934]: [com.apple.calendar.store.log.caldav.queue] [Account bastibe@https://cloud.bastibe.de:8443/principals/users/bastibe/ timed out when executing operation: <CalDAVAccountRefreshQueueableOperation: 0x7fb2a4a13ce0; Sequence: 0>]
11.08.13 16:16:42,636 CalendarAgent[14934]: [com.apple.calendar.store.log.caldav.queue] [Account refresh failed with error: Error Domain=NSURLErrorDomain Code=-1001 "Zeitüberschreitung bei der Anforderung." UserInfo=0x7fb2a4a69460 {NSUnderlyingError=0x7fb2a1b2f640 "Zeitüberschreitung bei der Anforderung.", NSErrorFailingURLStringKey=https://bastibe@cloud.bastibe.de:8443/calendars/__uids__/3e5c3ade-c0ea-5560-..., NSErrorFailingURLKey=https://bastibe@cloud.bastibe.de:8443/calendars/__uids__/3e5c3ade-c0ea-5560-..., AccountName=cloud.bastibe.de, CalDAVErrFromRefresh=YES, NSLocalizedDescription=Zeitüberschreitung bei der Anforderung.}]
where "Zeitüberschreitung bei der Anforderung" is German for "timeout for request". During those 30 seconds, the Raspberry Pi is running a Python process for the caldavd user at full CPU utilization. So I'm guessing that Apple Calendar has an internal timeout of 30 seconds and the Raspberry Pi is not fast enough to send the calendar data in that time frame. Do you have any idea how I could fix that? Any help would be greatly appreciated! Kind regards, Basti
Hi, We’d need to see the server’s /var/log/caldavd/error.log to be sure, but I have a guess at what might be wrong. On the Pi, run the command: netstat -na | egrep ‘8008|8443’ This will list all the network connections associated with the Calendar Server service ports. Calendar Server limits the amount of total request concurrency, and this limit is by default based on the server’s hw resources, so the setting might be fairly meager for a Pi. It should still be enough for such a simple test, however we’re tracking an issue right now (in trunk) that’s causing scalability problems that result in the behavior you’re seeing. You are probably affected by this bug if you see that all the connections slots are full when you really haven’t presented much load. Also, if there are a lot of network connections in FIN_WAIT2, that’s another sign. If instead you see in the error.log that the server is actually processing the requests which eventually finish (they don’t get logged to access.log until they finish), then maybe the Pi is just really slow? I’d still expect some bug, because it doesn’t take a great amount of server CPU do a basic CalDAV login. Cheers, -dre On Aug 11, 2013, at 7:43 AM, calendar@bastibe.de wrote:
Hi,
I set up calendarserver on a Raspberry Pi. I can connect to it using an iPad and I can see the appropriate data in my web browser. Apple Calendar (OSX 10.8.4) however works for 30 seconds, then says "can not create a connection".
The Console is logging
11.08.13 16:16:42,633 CalendarAgent[14934]: [com.apple.calendar.store.log.caldav.queue] [Got error on refresh, but not rectifying principal because it was manually configured: Error Domain=NSURLErrorDomain Code=-1001 "Zeitüberschreitung bei der Anforderung." UserInfo=0x7fb2a3336580 {NSUnderlyingError=0x7fb2a1b2f640 "Zeitüberschreitung bei der Anforderung.", NSErrorFailingURLStringKey=https://bastibe@cloud.bastibe.de:8443/calendars/__uids__/3e5c3ade-c0ea-5560-..., NSErrorFailingURLKey=https://bastibe@cloud.bastibe.de:8443/calendars/__uids__/3e5c3ade-c0ea-5560-..., NSLocalizedDescription=Zeitüberschreitung bei der Anforderung.}]
11.08.13 16:16:42,633 CalendarAgent[14934]: [com.apple.calendar.store.log.caldav.queue] [Account bastibe@https://cloud.bastibe.de:8443/principals/users/bastibe/ timed out when executing operation: <CalDAVAccountRefreshQueueableOperation: 0x7fb2a4a13ce0; Sequence: 0>]
11.08.13 16:16:42,636 CalendarAgent[14934]: [com.apple.calendar.store.log.caldav.queue] [Account refresh failed with error: Error Domain=NSURLErrorDomain Code=-1001 "Zeitüberschreitung bei der Anforderung." UserInfo=0x7fb2a4a69460 {NSUnderlyingError=0x7fb2a1b2f640 "Zeitüberschreitung bei der Anforderung.", NSErrorFailingURLStringKey=https://bastibe@cloud.bastibe.de:8443/calendars/__uids__/3e5c3ade-c0ea-5560-..., NSErrorFailingURLKey=https://bastibe@cloud.bastibe.de:8443/calendars/__uids__/3e5c3ade-c0ea-5560-..., AccountName=cloud.bastibe.de, CalDAVErrFromRefresh=YES, NSLocalizedDescription=Zeitüberschreitung bei der Anforderung.}]
where "Zeitüberschreitung bei der Anforderung" is German for "timeout for request".
During those 30 seconds, the Raspberry Pi is running a Python process for the caldavd user at full CPU utilization.
So I'm guessing that Apple Calendar has an internal timeout of 30 seconds and the Raspberry Pi is not fast enough to send the calendar data in that time frame.
Do you have any idea how I could fix that? Any help would be greatly appreciated!
Kind regards, Basti _______________________________________________ calendarserver-users mailing list calendarserver-users@lists.macosforge.org https://lists.macosforge.org/mailman/listinfo/calendarserver-users
Hi, I can give you the contents of the error log (only the latest entry):
2013-08-11 17:10:04+0000 [-] [caldav-1] [-] Unhandled Error 2013-08-11 17:10:05+0000 [-] [caldav-1] Traceback (most recent call last): 2013-08-11 17:10:05+0000 [-] [caldav-1] File "/usr/lib/python2.7/dist-packages/twisted/application/app.py", line 402, in startReactor 2013-08-11 17:10:05+0000 [-] [caldav-1] self.config, oldstdout, oldstderr, self.profiler, reactor) 2013-08-11 17:10:05+0000 [-] [caldav-1] File "/usr/lib/python2.7/dist-packages/twisted/application/app.py", line 323, in runReactorWithLogging 2013-08-11 17:10:05+0000 [-] [caldav-1] reactor.run() 2013-08-11 17:10:05+0000 [-] [caldav-1] File "/usr/lib/python2.7/dist-packages/twisted/internet/base.py", line 1169, in run 2013-08-11 17:10:05+0000 [-] [caldav-1] self.mainLoop()
2013-08-11 17:10:05+0000 [-] [caldav-1] File "/usr/lib/python2.7/dist-packages/twisted/internet/base.py", line 1178, in mainLoop
2013-08-11 17:10:05+0000 [-] [caldav-1] self.runUntilCurrent() 2013-08-11 17:10:05+0000 [-] [caldav-1] --- <exception caught here> --- 2013-08-11 17:10:05+0000 [-] [caldav-1] File "/usr/lib/python2.7/dist-packages/twisted/internet/base.py", line 800, in runUntilCurrent 2013-08-11 17:10:05+0000 [-] [caldav-1] call.func(*call.args, **call.kw) 2013-08-11 17:10:05+0000 [-] [caldav-1] File "/usr/lib/python2.7/dist-packages/twext/web2/channel/http.py", line 874, in _startNextRequest 2013-08-11 17:10:05+0000 [-] [caldav-1] self.resumeProducing() 2013-08-11 17:10:05+0000 [-] [caldav-1] File "/usr/lib/python2.7/dist-packages/twisted/protocols/basic.py", line 499, in resumeProducing 2013-08-11 17:10:05+0000 [-] [caldav-1] self.transport.resumeProducing() 2013-08-11 17:10:05+0000 [-] [caldav-1] File "/usr/lib/python2.7/dist-packages/twisted/internet/abstract.py", line 428, in resumeProducing 2013-08-11 17:10:05+0000 [-] [caldav-1] assert self.connected and not self.disconnecting 2013-08-11 17:10:05+0000 [-] [caldav-1] exceptions.AssertionError: 2013-08-11 17:10:05+0000 [-] [caldav-1] 2013-08-11 17:10:15+0000 [-] [caldav-1] [-] Unhandled Error 2013-08-11 17:10:15+0000 [-] [caldav-1] Traceback (most recent call last): 2013-08-11 17:10:15+0000 [-] [caldav-1] File "/usr/lib/python2.7/dist-packages/twisted/application/app.py", line 402, in startReactor 2013-08-11 17:10:15+0000 [-] [caldav-1] self.config, oldstdout, oldstderr, self.profiler, reactor) 2013-08-11 17:10:15+0000 [-] [caldav-1] File "/usr/lib/python2.7/dist-packages/twisted/application/app.py", line 323, in runReactorWithLogging 2013-08-11 17:10:15+0000 [-] [caldav-1] reactor.run() 2013-08-11 17:10:15+0000 [-] [caldav-1] File "/usr/lib/python2.7/dist-packages/twisted/internet/base.py", line 1169, in run 2013-08-11 17:10:15+0000 [-] [caldav-1] self.mainLoop()
2013-08-11 17:10:15+0000 [-] [caldav-1] File "/usr/lib/python2.7/dist-packages/twisted/internet/base.py", line 1178, in mainLoop
2013-08-11 17:10:15+0000 [-] [caldav-1] self.runUntilCurrent() 2013-08-11 17:10:15+0000 [-] [caldav-1] --- <exception caught here> --- 2013-08-11 17:10:15+0000 [-] [caldav-1] File "/usr/lib/python2.7/dist-packages/twisted/internet/base.py", line 800, in runUntilCurrent 2013-08-11 17:10:15+0000 [-] [caldav-1] call.func(*call.args, **call.kw) 2013-08-11 17:10:15+0000 [-] [caldav-1] File "/usr/lib/python2.7/dist-packages/twext/web2/channel/http.py", line 874, in _startNextRequest 2013-08-11 17:10:15+0000 [-] [caldav-1] self.resumeProducing() 2013-08-11 17:10:15+0000 [-] [caldav-1] File "/usr/lib/python2.7/dist-packages/twisted/protocols/basic.py", line 499, in resumeProducing 2013-08-11 17:10:15+0000 [-] [caldav-1] self.transport.resumeProducing() 2013-08-11 17:10:15+0000 [-] [caldav-1] File "/usr/lib/python2.7/dist-packages/twisted/internet/abstract.py", line 428, in resumeProducing 2013-08-11 17:10:15+0000 [-] [caldav-1] assert self.connected and not self.disconnecting 2013-08-11 17:10:15+0000 [-] [caldav-1] exceptions.AssertionError: 2013-08-11 17:10:15+0000 [-] [caldav-1] 2013-08-11 17:10:04+0000 [-] [caldav-1] [-] Unhandled Error 2013-08-11 17:10:05+0000 [-] [caldav-1] Traceback (most recent call last): 2013-08-11 17:10:05+0000 [-] [caldav-1] File "/usr/lib/python2.7/dist-packages/twisted/application/app.py", line 402, in startReactor 2013-08-11 17:10:05+0000 [-] [caldav-1] self.config, oldstdout, oldstderr, self.profiler, reactor) 2013-08-11 17:10:05+0000 [-] [caldav-1] File "/usr/lib/python2.7/dist-packages/twisted/application/app.py", line 323, in runReactorWithLogging 2013-08-11 17:10:05+0000 [-] [caldav-1] reactor.run() 2013-08-11 17:10:05+0000 [-] [caldav-1] File "/usr/lib/python2.7/dist-packages/twisted/internet/base.py", line 1169, in run 2013-08-11 17:10:05+0000 [-] [caldav-1] self.mainLoop()
2013-08-11 17:10:05+0000 [-] [caldav-1] File "/usr/lib/python2.7/dist-packages/twisted/internet/base.py", line 1178, in mainLoop
2013-08-11 17:10:05+0000 [-] [caldav-1] self.runUntilCurrent() 2013-08-11 17:10:05+0000 [-] [caldav-1] --- <exception caught here> --- 2013-08-11 17:10:05+0000 [-] [caldav-1] File "/usr/lib/python2.7/dist-packages/twisted/internet/base.py", line 800, in runUntilCurrent 2013-08-11 17:10:05+0000 [-] [caldav-1] call.func(*call.args, **call.kw) 2013-08-11 17:10:05+0000 [-] [caldav-1] File "/usr/lib/python2.7/dist-packages/twext/web2/channel/http.py", line 874, in _startNextRequest 2013-08-11 17:10:05+0000 [-] [caldav-1] self.resumeProducing() 2013-08-11 17:10:05+0000 [-] [caldav-1] File "/usr/lib/python2.7/dist-packages/twisted/protocols/basic.py", line 499, in resumeProducing 2013-08-11 17:10:05+0000 [-] [caldav-1] self.transport.resumeProducing() 2013-08-11 17:10:05+0000 [-] [caldav-1] File "/usr/lib/python2.7/dist-packages/twisted/internet/abstract.py", line 428, in resumeProducing 2013-08-11 17:10:05+0000 [-] [caldav-1] assert self.connected and not self.disconnecting 2013-08-11 17:10:05+0000 [-] [caldav-1] exceptions.AssertionError: 2013-08-11 17:10:05+0000 [-] [caldav-1] 2013-08-11 17:10:15+0000 [-] [caldav-1] [-] Unhandled Error 2013-08-11 17:10:15+0000 [-] [caldav-1] Traceback (most recent call last): 2013-08-11 17:10:15+0000 [-] [caldav-1] File "/usr/lib/python2.7/dist-packages/twisted/application/app.py", line 402, in startReactor 2013-08-11 17:10:15+0000 [-] [caldav-1] self.config, oldstdout, oldstderr, self.profiler, reactor) 2013-08-11 17:10:15+0000 [-] [caldav-1] File "/usr/lib/python2.7/dist-packages/twisted/application/app.py", line 323, in runReactorWithLogging 2013-08-11 17:10:15+0000 [-] [caldav-1] reactor.run() 2013-08-11 17:10:15+0000 [-] [caldav-1] File "/usr/lib/python2.7/dist-packages/twisted/internet/base.py", line 1169, in run 2013-08-11 17:10:15+0000 [-] [caldav-1] self.mainLoop()
2013-08-11 17:10:15+0000 [-] [caldav-1] File "/usr/lib/python2.7/dist-packages/twisted/internet/base.py", line 1178, in mainLoop
2013-08-11 17:10:15+0000 [-] [caldav-1] self.runUntilCurrent() 2013-08-11 17:10:15+0000 [-] [caldav-1] --- <exception caught here> --- 2013-08-11 17:10:15+0000 [-] [caldav-1] File "/usr/lib/python2.7/dist-packages/twisted/internet/base.py", line 800, in runUntilCurrent 2013-08-11 17:10:15+0000 [-] [caldav-1] call.func(*call.args, **call.kw) 2013-08-11 17:10:15+0000 [-] [caldav-1] File "/usr/lib/python2.7/dist-packages/twext/web2/channel/http.py", line 874, in _startNextRequest 2013-08-11 17:10:15+0000 [-] [caldav-1] self.resumeProducing() 2013-08-11 17:10:15+0000 [-] [caldav-1] File "/usr/lib/python2.7/dist-packages/twisted/protocols/basic.py", line 499, in resumeProducing 2013-08-11 17:10:15+0000 [-] [caldav-1] self.transport.resumeProducing() 2013-08-11 17:10:15+0000 [-] [caldav-1] File "/usr/lib/python2.7/dist-packages/twisted/internet/abstract.py", line 428, in resumeProducing 2013-08-11 17:10:15+0000 [-] [caldav-1] assert self.connected and not self.disconnecting 2013-08-11 17:10:15+0000 [-] [caldav-1] exceptions.AssertionError: 2013-08-11 17:10:15+0000 [-] [caldav-1]
So that definitely looks like something is wrong. Is this the issue you had in mind? Also, the outputs of netstat -na | egrep '8008|8443" is the following:
tcp 0 0 0.0.0.0:8443 0.0.0.0:* LISTEN
tcp 0 0 192.168.1.47:8443 192.168.1.1:56194 ESTABLISHED tcp 0 0 192.168.1.47:8443 192.168.1.1:56221 ESTABLISHED
Kind regards, Basti Am 2013-08-11 18:35, schrieb Andre LaBranche:
Hi,
We'd need to see the server's /var/log/caldavd/error.log to be sure, but I have a guess at what might be wrong. On the Pi, run the command:
netstat -na | egrep '8008|8443'
This will list all the network connections associated with the Calendar Server service ports. Calendar Server limits the amount of total request concurrency, and this limit is by default [4] based on the server's hw resources, so the setting might be fairly meager for a Pi. It should still be enough for such a simple test, however we're tracking an issue right now (in trunk) that's causing scalability problems that result in the behavior you're seeing. You are probably affected by this bug if you see that all the connections slots are full when you really haven't presented much load. Also, if there are a lot of network connections in FIN_WAIT2, that's another sign.
If instead you see in the error.log that the server is actually processing the requests which eventually finish (they don't get logged to access.log until they finish), then maybe the Pi is just really slow? I'd still expect some bug, because it doesn't take a great amount of server CPU do a basic CalDAV login.
Cheers, -dre
On Aug 11, 2013, at 7:43 AM, calendar@bastibe.de wrote:
Hi,
I set up calendarserver on a Raspberry Pi. I can connect to it using an iPad and I can see the appropriate data in my web browser. Apple Calendar (OSX 10.8.4) however works for 30 seconds, then says "can not create a connection".
The Console is logging
11.08.13 16:16:42,633 CalendarAgent[14934]: [com.apple.calendar.store.log.caldav.queue] [Got error on refresh, but not rectifying principal because it was manually configured: Error Domain=NSURLErrorDomain Code=-1001 "Zeitüberschreitung bei der Anforderung." UserInfo=0x7fb2a3336580 {NSUnderlyingError=0x7fb2a1b2f640 "Zeitüberschreitung bei der Anforderung.", NSErrorFailingURLStringKey=https://bastibe@cloud.bastibe.de:8443/calendars/__uids__/3e5c3ade-c0ea-5560-... [1], NSErrorFailingURLKey=https://bastibe@cloud.bastibe.de:8443/calendars/__uids__/3e5c3ade-c0ea-5560-... [1], NSLocalizedDescription=Zeitüberschreitung bei der Anforderung.}]
11.08.13 16:16:42,633 CalendarAgent[14934]: [com.apple.calendar.store.log.caldav.queue] [Account bastibe@https://cloud.bastibe.de:8443/principals/users/bastibe/ [2] timed out when executing operation: <CalDAVAccountRefreshQueueableOperation: 0x7fb2a4a13ce0; Sequence: 0>]
11.08.13 16:16:42,636 CalendarAgent[14934]: [com.apple.calendar.store.log.caldav.queue] [Account refresh failed with error: Error Domain=NSURLErrorDomain Code=-1001 "Zeitüberschreitung bei der Anforderung." UserI
ailingURLStringKey=https://bastibe@cloud.bastibe.de:8443/calendars/__uids__/3e5c3ade-c0ea-5560-... [1], NSErrorFailingURLKey=https://bastibe@cloud.bastibe.de:8443/calendars/__uids__/3e5c3ade-c0ea-5560-... [1], AccountName=cloud.bastibe.de [3], CalDAVErrFromRefresh=YES, NSLocalizedDescription=Zeitüberschreitung bei der Anforderung.}]
where "Zeitüberschreitung bei der Anforderung" is German for "timeout for request".
During those 30 seconds, the Raspberry Pi is running a Python process for the caldavd user at full CPU utilization.
So I'm guessing that Apple Calendar has an internal timeout of 30 second pberry Pi is not fast enough to send the calendar data in that time frame.
Do you have any idea how I could fix that? Any help would be greatly appreciated!
Kind regards, Basti _______________________________________________
calendarserver-users mailing list
calendarserver-users@lists.macosforge.org
https://lists.macosforge.org/mailman/listinfo/calendarserver-users
Links: ------ [1] https://bastibe@cloud.bastibe.de:8443/calendars/__uids__/3e5c3ade-c0ea-5560-... [2] https://cloud.bastibe.de:8443/principals/users/bastibe/ [3] http://cloud.bastibe.de [4] https://trac.calendarserver.org/browser/CalendarServer/trunk/twistedcaldav/s...
On Aug 11, 2013, at 10:17 AM, calendar@bastibe.de wrote:
So that definitely looks like something is wrong. Is this the issue you had in mind?
Also, the outputs of netstat -na | egrep '8008|8443" is the following:
tcp 0 0 0.0.0.0:8443 0.0.0.0:* LISTEN tcp 0 0 192.168.1.47:8443 192.168.1.1:56194 ESTABLISHED tcp 0 0 192.168.1.47:8443 192.168.1.1:56221 ESTABLISHED
Hi, Thanks for the info. The netstat results look normal; the problem is most likely whatever is causing the server to emit those tracebacks. Your exact tracebacks don’t match any issue I know of, but in general, there are problems around connection handling, so this could be related. Could you please file a bug at our trac site? Please include info about the client and server (including the platforms and versions of software on each), as well as that error.log snippet. https://trac.calendarserver.org/newticket If you’re looking for things to do, you could attempt to duplicate this problem using older (or newer) versions of Calendar Server. If you are currently using a port / package, doing this may be challenging, so don’t sweat it unless you want to :) Cheers, -dre
Hi, Thank you for your help! I opened the ticket at https://trac.calendarserver.org/ticket/814 Kind regards, Basti Am 2013-08-11 19:29, schrieb Andre LaBranche:
On Aug 11, 2013, at 10:17 AM, calendar@bastibe.de wrote:
So that definitely looks like something is wrong. Is this the issue you had in mind?
Also, the outputs of netstat -na | egrep '8008|8443" is the following:
tcp 0 0 0.0.0.0:8443 0.0.0.0:* LISTEN
tcp 0 0 192.168.1.47:8443 192.168.1.1:56194 ESTABLISHED tcp 0 0 192.168.1.47:8443 192.168.1.1:56221 ESTABLISHED
Hi,
Thanks for the info. The netstat results look normal; the problem is most likely whatever is causing the server to emit those tracebacks. Your exact tracebacks don't match any issue I know of, but in general, there are problems around connection handling, so this could be related.
Could you please file a bug at our trac site? Please include info about the client and server (including the platforms and versions of software on each), as well as that error.log snippet.
https://trac.calendarserver.org/newticket [1]
If you're looking
for things to do, you could attempt to duplicate this problem using older (or newer) versions of Calendar Server. If you are currently using a port / package, doing this may be challenging, so don't sweat it unless you want to :)
Cheers, -dre
Links: ------ [1] https://trac.calendarserver.org/newticket
participants (2)
-
Andre LaBranche
-
calendar＠bastibe.de