Calendar Server Reported Error: Operation CalDAVAccountRefreshQueueableOperation

Question

Level 1

6 points

Calendar Server Reported Error: Operation CalDAVAccountRefreshQueueableOperation

I have setup several Users on a MAC OS X Server Lion with the sole purpose to use their Calendar and Addressbook as repository for calendar and address information for the Mac, Macbook and iPhone and shared calendars for all users of the OD. This worked quite well for a time. It seems to have stopped working a while ago (noone realised it because the individual device did not show an obvious problem and had all the required dates), definitively after the Update to 10.7.2, but presumably a couple of weeks before. To my knowledge I did not change anything beyond applying the apple updates.

One of the clients shows the dates of a shared calendar multiple times (depending on date up to 7 times, but mostly 3 times), the mobile devices and the other iMac only once.

Upon looking at the calendars (even as Admin on the Mac Server itself) the error message displayed is

Calendar Server Reported Error

Operation CalDAVAccountRefreshQueueableOperation

I hope there is a solution as we lost qiute a few dates on the iPhones during update to iOS 5 (the shared calendar data are apparently not backed-up).

Mac OS X (10.7.1), Server

Posted on Oct 16, 2011 10:10 AM

Reply

Answer 1

mappler

Level 1

0 points

Oct 20, 2011 12:33 PM in response to aef5023

Client's system.log:

Oct 20 21:06:59 macbook01 iCal[14597]: Account refresh failed with error: Error Domain=NSURLErrorDomain Code=-1004 "Verbindung zum Server konnte nicht hergestellt werden." UserInfo=0x7f8a846f0320 {NSLocalizedDescription=Verbindung zum Server konnte nicht hergestellt werden., NSErrorFailingURLStringKey=https://user.name@server01.domain.net:8443/principals/__uids__/B8F10BEC-4CC5-40C 0-B367-16C94B290CC1///user.name@server01.domain.net:8443/principals/__uids__/B8F10BEC-4CC5-40C0-B367-16C94B290CC1/, NSErrorFailingURLKey=https://user.name@server01.domain.net:8443/principals/__uids__/B8F10BEC-4CC5-40C 0-B367-16C94B290CC1///user.name@server01.domain.net:8443/principals/__uids__/B8F10BEC-4CC5-40C0-B367-16C94B290CC1/, AccountName=server01, CalDAVErrFromRefresh=YES, NSUnderlyingError=0x7f8a84674070 "Verbindung zum Server konnte nicht hergestellt werden."}

Server's postgresql service is RUNNING

Server's system.log:

Oct 20 21:18:49 server01 com.apple.launchd[1] (com.apple.devicemanager[18824]): Exited with code: 1

Oct 20 21:18:49 server01 com.apple.launchd[1] (com.apple.devicemanager): Throttling respawn: Will start in 7 seconds

Oct 20 21:18:49 server01 com.apple.launchd[1] (com.apple.collabd.notifications[18830]): Tried to setup shared memory more than once

Oct 20 21:18:51 server01 CoreCollaborationServer[146]: [CSConnectionPool:91 9556a0 +3ms] Could not open a connection to Postgres. Please make sure it is running and has the correct access.

Oct 20 21:18:51 server01 CoreCollaborationServer[146]: [CSServiceDispatchHTTPConnection:197 9556a0 +0ms] Caught exception "-[__NSCFDictionary setObject:forKey:]: attempt to insert nil value (key: com.apple.server.collab.DBConn)" [NSInvalidArgumentException] executing Request{SessionService.currentOrNewSession()}:

(

0 CoreFoundation 0x00007fff8b8cf286 __exceptionPreprocess + 198

1 libobjc.A.dylib 0x00007fff84fa1d5e objc_exception_throw + 43

2 CoreFoundation 0x00007fff8b8cf0ba +[NSException raise:format:arguments:] + 106

3 CoreFoundation 0x00007fff8b8cf044 +[NSException raise:format:] + 116

4 CoreFoundation 0x00007fff8b88c29b -[__NSCFDictionary setObject:forKey:] + 219

5 CSService 0x0000000104b5fe34 -[CSConnectionPool currentConnection] + 115

6 CSService 0x0000000104b89e8d -[CSEntitySchema calculateSchemaChecksum] + 42

7 CSService 0x0000000104b8a954 -[CSEntitySchema checkForSchemaChanges] + 33

8 CSService 0x0000000104b5d23c -[CSServiceDispatcher executeRequest:asPartOfBatch:] + 1355

9 CSService 0x0000000104b5d6e6 -[CSServiceDispatcher executeRequest:] + 74

10 collabd 0x0000000104b0d692 -[CSServiceDispatchHTTPConnection httpResponseForMethod:URI:] + 1081

11 collabd 0x0000000104af2315 -[HTTPConnection replyToHTTPRequest] + 614

12 collabd 0x0000000104b03e5b __37-[GCDAsyncSocket completeCurrentRead]_block_invoke_0 + 91

13 libdispatch.dylib 0x00007fff8aa388ba _dispatch_call_block_and_release + 18

14 libdispatch.dylib 0x00007fff8aa3a10a _dispatch_queue_drain + 264

15 libdispatch.dylib 0x00007fff8aa39f66 _dispatch_queue_invoke + 54

16 libdispatch.dylib 0x00007fff8aa39760 _dispatch_worker_thread2 + 198

17 libsystem_c.dylib 0x00007fff866c93da _pthread_wqthread + 316

18 libsystem_c.dylib 0x00007fff866cab85 start_wqthread + 13

)

Oct 20 21:18:51 server01 com.apple.collabd.notifications[18830]: /usr/share/collabd/server/ruby/lib/collaboration/service_client.rb:128:in `sendRequest'

Oct 20 21:18:51 server01 com.apple.collabd.notifications[18830]: :

Oct 20 21:18:51 server01 com.apple.collabd.notifications[18830]: -[__NSCFDictionary setObject:forKey:]: attempt to insert nil value (key: com.apple.server.collab.DBConn)

Oct 20 21:18:51 server01 com.apple.collabd.notifications[18830]: (

Oct 20 21:18:51 server01 com.apple.collabd.notifications[18830]: Collaboration::NSInvalidArgumentException

Oct 20 21:18:51 server01 com.apple.collabd.notifications[18830]: )

Oct 20 21:18:51 server01 com.apple.collabd.notifications[18830]: from /usr/share/collabd/server/ruby/lib/collaboration/service_client.rb:116:in `map'

Oct 20 21:18:51 server01 com.apple.collabd.notifications[18830]: from /usr/share/collabd/server/ruby/lib/collaboration/service_client.rb:116:in `sendRequest'

Oct 20 21:18:51 server01 com.apple.collabd.notifications[18830]: from /usr/share/collabd/server/ruby/lib/collaboration/service_client.rb:153:in `execute'

Oct 20 21:18:51 server01 com.apple.collabd.notifications[18830]: from notifications.rb:145:in `initialize'

Oct 20 21:18:51 server01 com.apple.collabd.notifications[18830]: from notifications.rb:439:in `new'

Oct 20 21:18:51 server01 com.apple.collabd.notifications[18830]: from notifications.rb:439

Oct 20 21:18:51 server01 com.apple.launchd[1] (com.apple.collabd.notifications[18830]): Exited with code: 1

Oct 20 21:18:51 server01 com.apple.launchd[1] (com.apple.collabd.notifications): Throttling respawn: Will start in 6 seconds

Oct 20 21:18:56 server01 com.apple.devicemanager[18838]: DEBUG: Initializing DeviceManagerDaemon with ports 3320,3321,3322,3323 (physmem = 4GB)

Oct 20 21:18:56 server01 com.apple.devicemanager[18838]: DEBUG: Making sure Rails is configured properly

Oct 20 21:18:56 server01 com.apple.devicemanager[18838]: DEBUG: Running rake command: /usr/bin/rake db:migrate

What can I do?

Reply

Answer 2

mappler

Level 1

0 points

Oct 20, 2011 12:33 PM in response to Cyrus Daboo

server01:~ root# ps aux | grep postgres

root 19531 0.6 0.0 2434892 432 s000 S+ 9:29PM 0:00.01 grep postgres

_postgres 239 0.0 0.0 2441124 468 ?? Ss 13Oct11 0:34.47 postgres: stats collector process

_postgres 238 0.0 0.0 2478340 1652 ?? Ss 13Oct11 0:20.33 postgres: autovacuum launcher process

_postgres 237 0.0 0.0 2478208 512 ?? Ss 13Oct11 0:52.43 postgres: wal writer process

_postgres 236 0.0 0.0 2478208 756 ?? Ss 13Oct11 1:15.21 postgres: writer process

_postgres 223 0.0 0.0 2441124 356 ?? Ss 13Oct11 1:21.49 postgres: logger process

_postgres 87 0.0 0.1 2478208 4792 ?? Ss 13Oct11 1:17.65 /usr/bin/postgres_real -D /var/pgsql -c listen_addresses= -c log_connections=on -c log_directory=/Library/Logs -c log_filename=PostgreSQL.log -c log_line_prefix=%t -c log_lock_waits=on -c log_statement=ddl -c logging_collector=on -c unix_socket_directory=/var/pgsql_socket -c unix_socket_group=_postgres -c unix_socket_permissions=0770

server01:~ root# ps aux | grep caldavd

root 19550 0.0 0.0 2435492 0 s000 R+ 9:29PM 0:00.00 grep caldavd

server01:~ root# sudo ls -l /var/pgsql_socket/

total 8

srwxrwx--- 1 _postgres _postgres 0 Oct 20 21:17 .s.PGSQL.5432

-rw------- 1 _postgres _postgres 14 Oct 20 21:17 .s.PGSQL.5432.lock

Reply

Answer 3

Oct 20, 2011 12:40 PM in response to mappler

Please try this:

sudo -u calendar psql -U _postgres caldav

Does it get you in to the postgres shell (if so ctrl-D to get out).

What do you see in /Library/Logs/PostgreSQL.log (specifically anything related to database=caldav)?

Reply

Answer 4

mappler

Level 1

0 points

Oct 20, 2011 12:50 PM in response to Cyrus Daboo

https://<<your os x server hostname>>:8443

does not work!

http://<<your os x server hostname>>:8008

does not work!

https://<<your os x server hostname>>

http://<<your os x server hostname>>

results in:

Collaboration::NSInvalidArgumentException in Sources#index

Showing /usr/share/collabd/coreclient/app/views/layouts/application.html.erb where line #5 raised:

-[__NSCFDictionary setObject:forKey:]: attempt to insert nil value (key: com.apple.server.collab.DBConn)

Extracted source (around line #5):

2:      :user => @user,3:      :entity => @entity,4:      :owner => @owner,5:      :service_client => service_client,6:      :controller => controller7: }) %>8:

Rails.root: /usr/share/collabd/coreclient

... much more ...

Message was edited by: mappler

Reply

Answer 5

Oct 20, 2011 12:46 PM in response to mappler

collabd errors are a different problem - that relates to the wiki having problems not calendar server. Can you please start a new thread on that as I want to concentrate on the calendar server specific issues in this thread.

Reply

Answer 6

mappler

Level 1

0 points

Oct 20, 2011 12:46 PM in response to Cyrus Daboo

/Library/Logs/PostgreSQL.log

2011-10-20 21:44:07 CEST LOG: connection received: host=[local]

2011-10-20 21:44:07 CEST LOG: connection authorized: user=_devicemgr database=device_management

2011-10-20 21:44:07 CEST FATAL: role "_devicemgr" does not exist

2011-10-20 21:44:07 CEST LOG: connection received: host=[local]

2011-10-20 21:44:07 CEST LOG: connection authorized: user=collab database=collab

2011-10-20 21:44:07 CEST FATAL: role "collab" does not exist

2011-10-20 21:44:10 CEST LOG: connection received: host=[local]

2011-10-20 21:44:10 CEST LOG: connection authorized: user=caldav database=caldav

2011-10-20 21:44:10 CEST FATAL: role "caldav" does not exist

Reply

Answer 7

aef5023 Author

Level 1

6 points

Oct 20, 2011 12:46 PM in response to aef5023

http://<<your os x server hostname>> redirects to

https://<<your os x server hostname>> and yields "server error"

https://<<your os x server hostname>>:8443 yields "Safari can't connect to the server, .... because it cannot find the server"

apache log: There is no change until after the 10.7.2 update is introduced, then the SIGTerm bit starts

(shutdown of apache server, but initiated from what?)

At this point I am pretty sure things worked fine

[Mon Sep 05 13:41:26 2011] [warn] RSA server certificate CommonName (CN) `SharkServer.local' does NOT match server name!?

[Mon Sep 05 13:41:26 2011] [crit] (17)File exists: mod_rewrite: Parent could not create RewriteLock file /var/log/apache2/rewrite.lock

Configuration Failed

[Mon Sep 05 13:41:36 2011] [warn] RSA server certificate CommonName (CN) `SharkServer.local' does NOT match server name!?

httpd: Could not reliably determine the server's fully qualified domain name, using SharkServer.local for ServerName

[Mon Sep 05 13:41:36 2011] [warn] RSA server certificate CommonName (CN) `SharkServer.local' does NOT match server name!?

[Mon Sep 05 13:41:36 2011] [notice] Apache/2.2.19 (Unix) mod_ssl/2.2.19 OpenSSL/0.9.8r DAV/2 configured -- resuming normal operations

no definite proof it still worked

[Fri Sep 30 08:29:53 2011] [warn] RSA server certificate CommonName (CN) `SharkServer.local' does NOT match server name!?

[Fri Sep 30 08:29:53 2011] [crit] (17)File exists: mod_rewrite: Parent could not create RewriteLock file /var/log/apache2/rewrite.lock

Configuration Failed

[Fri Sep 30 08:30:02 2011] [warn] RSA server certificate CommonName (CN) `SharkServer.local' does NOT match server name!?

httpd: Could not reliably determine the server's fully qualified domain name, using SharkServer.local for ServerName

[Fri Sep 30 08:30:03 2011] [warn] RSA server certificate CommonName (CN) `SharkServer.local' does NOT match server name!?

[Fri Sep 30 08:30:04 2011] [notice] Apache/2.2.19 (Unix) mod_ssl/2.2.19 OpenSSL/0.9.8r DAV/2 configured -- resuming normal operations

just before the update

[Sun Oct 16 11:29:09 2011] [warn] RSA server certificate CommonName (CN) `SharkServer.local' does NOT match server name!?

[Sun Oct 16 11:29:10 2011] [crit] (17)File exists: mod_rewrite: Parent could not create RewriteLock file /var/log/apache2/rewrite.lock

Configuration Failed

[Sun Oct 16 11:29:29 2011] [warn] RSA server certificate CommonName (CN) `SharkServer.local' does NOT match server name!?

httpd: Could not reliably determine the server's fully qualified domain name, using SharkServer.local for ServerName

[Sun Oct 16 11:29:29 2011] [warn] RSA server certificate CommonName (CN) `SharkServer.local' does NOT match server name!?

[Sun Oct 16 11:29:30 2011] [notice] Apache/2.2.19 (Unix) mod_ssl/2.2.19 OpenSSL/0.9.8r DAV/2 configured -- resuming normal operations

after update this starts

[Sun Oct 16 11:53:29 2011] [notice] caught SIGTERM, shutting down

[Sun Oct 16 11:55:23 2011] [warn] RSA server certificate CommonName (CN) `SharkServer.local' does NOT match server name!?

httpd: Could not reliably determine the server's fully qualified domain name, using SharkServer.local for ServerName

[Sun Oct 16 11:55:24 2011] [warn] RSA server certificate CommonName (CN) `SharkServer.local' does NOT match server name!?

[Sun Oct 16 11:55:24 2011] [notice] Apache/2.2.20 (Unix) mod_ssl/2.2.20 OpenSSL/0.9.8r DAV/2 configured -- resuming normal operations

a number of repetitions

Reply

Answer 8

mappler

Level 1

0 points

Oct 20, 2011 12:48 PM in response to Cyrus Daboo

server01:~ root# sudo -u calendar psql -U _postgres caldav

could not identify current directory: Permission denied

psql: FATAL: database "caldav" does not exist

Reply

Answer 9

aef5023 Author

Level 1

6 points

Oct 20, 2011 12:51 PM in response to Cyrus Daboo

ps aux | grep postgres

sharkmin 5389 0.0 0.0 2434892 532 s000 S+ 9:48PM 0:00.00 grep postgres

ps aux | grep caldavd

sharkmin 5431 0.0 0.0 2435492 308 s000 R+ 9:49PM 0:00.00 grep caldavd

sudo ls -l /var/pgsql_socket/

no output whatsoever

Reply

Answer 10

Oct 20, 2011 12:54 PM in response to aef5023

OK, so that looks like postgres is not running. So try:

sudo serveradmin stop postgres

sudo serveradmin start postgres

Monitor the /Library/Logs/PostgreSQL.log file for errors as it starts.

Reply

Answer 11

aef5023 Author

Level 1

6 points

Oct 20, 2011 1:07 PM in response to Cyrus Daboo

sudo -u calendar psql -U _postgres caldav

psql: could not connect to server: No such file or directory

Is the server running locally and accepting

connections on Unix domain socket "/var/pgsql_socket/.s.PGSQL.5432"?

There is no postgres log in /Library/Logs nor /var/log. There is a /var/pgsql folder but as server admin I cannot even list the contents of the folder without sudo

Reply

Answer 12

aef5023 Author

Level 1

6 points

Oct 20, 2011 1:10 PM in response to Cyrus Daboo

sudo serveradmin stop postgres

postgres:state = "STOPPED"

sudo serveradmin start postgres

postgres:error = "CANNOT_START_SERVICE_TIMEOUT_ERR"

So the postgres cannot start it seems. Shall I switch to a different discussion?

Reply

Answer 13

aef5023 Author

Level 1

6 points

Oct 20, 2011 1:25 PM in response to aef5023

I looked in one of the postgres discussion groups

sudo touch /Library/Logs/PostgreSQL.log

sudo chown _postgres:_postgres /Library/Logs/PostgreSQL.log

allowed me then tostart postgres

sudo serveradmin start postgrespostgres:state = "RUNNING"

Well I reboot now and see what happens

Reply

Answer 14

aef5023 Author

Level 1

6 points

Oct 20, 2011 1:38 PM in response to aef5023

After reboot, it still does not work. Can now trace the postgres startup

2011-10-20 22:35:08 CEST LOG: database system is ready to accept connections

2011-10-20 22:35:08 CEST LOG: autovacuum launcher started

2011-10-20 22:35:08 CEST LOG: connection received: host=[local]

2011-10-20 22:35:08 CEST LOG: connection authorized: user=_postgres database=postgres

2011-10-20 22:35:16 CEST LOG: connection received: host=[local]

2011-10-20 22:35:16 CEST LOG: connection authorized: user=caldav database=caldav

2011-10-20 22:35:16 CEST FATAL: role "caldav" does not exist

2011-10-20 22:35:17 CEST LOG: connection received: host=[local]

2011-10-20 22:35:17 CEST LOG: connection authorized: user=collab database=collab

2011-10-20 22:35:17 CEST FATAL: role "collab" does not exist

the last 6 lines then repeat themselves on a regular basis

Reply

Answer 15

aef5023 Author

Level 1

6 points

Oct 20, 2011 1:41 PM in response to aef5023

sudo -u calendar psql -U _postgres caldav

psql: FATAL: database "caldav" does not exist

Reply