Brooklyn Nine-Nine Fan

Q: Calendar Server Error

Hi all,
The following are my machine's specs -
Mac Pro (Early 2009)

Mac OS Version : OS X El Capitan Version 10.11.2

Server Version : 5.0.15(15S4033)


Server Services Running :
1) File Sharing
2) Mail
3) DNS

4) Open Directory

 

Now I want to enable Calendar Services and encountering a few errors.


The first error was that I could not access the calendar services folders. It was a user permission issue and only "_calendar" user have read/write access.

The second error that I encountered was the Calendar service would keep turing off by itself. However,it was solved by replacing the caldev plist file with a new one. Probably a syntax error.
Now,I am stuck at the third one.
The issue
"The status of calendar on the server app says the calendar is Reachable over the Internet at dns1.mycompanyname.com. However I cannot add any CalDav accounts."

Below are the logs from /Library/Server/Calendar and Contact/Logs -

1 ) servermgr_calendar.log (Note * Error at Line 439 / The error would keep looping.)



cal] 18/1/16, 3:43:01 PM SGT :   EnableSSL = 1
[cal] 18/1/16, 3:43:01 PM SGT :   RedirectHTTPToHTTPS = 1
[cal] 18/1/16, 3:43:01 PM SGT :   SSLAuthorityChain = 
[cal] 18/1/16, 3:43:01 PM SGT :   EnableSearchAddressBook = 1
[cal] 18/1/16, 3:43:01 PM SGT :   HTTPPort = 8008
[cal] 18/1/16, 3:43:01 PM SGT : Asking calendarserver_config to writeConfig
[cal] 18/1/16, 3:43:04 PM SGT : Returned from calendarserver_config
[cal] 18/1/16, 3:43:04 PM SGT : setState back from writeSettings
[cal] 18/1/16, 3:43:04 PM SGT : startService begin
[cal] 18/1/16, 3:43:04 PM SGT : getServiceUser begin
[cal] 18/1/16, 3:43:04 PM SGT : servermgr_calendar: Hiding com.apple.calendarserver
[cal] 18/1/16, 3:43:04 PM SGT : Setting hidden attribute returned True
[cal] 18/1/16, 3:43:04 PM SGT : Running pwpolicy (
    "-u",
    "com.apple.calendarserver",
    "-sethashtypes",
    RECOVERABLE,
    on,
    "CRAM-MD5",
    on
)
[cal] 18/1/16, 3:43:04 PM SGT : Error running pwpolicy: 1
[cal] 18/1/16, 3:43:04 PM SGT : Storing calendar user password in keychain
[cal] 18/1/16, 3:43:04 PM SGT : Calling checkMailAccessForServiceUser
[cal] 18/1/16, 3:43:04 PM SGT : checkMailAccessForServiceUser
[cal] 18/1/16, 3:43:04 PM SGT : serviceUserName is com.apple.calendarserver
[cal] 18/1/16, 3:43:05 PM SGT : checkMailAccessForServiceUser did not find all_services group
[cal] 18/1/16, 3:43:05 PM SGT : checkMailAccessForServiceUser did not find access_mail group
[cal] 18/1/16, 3:43:05 PM SGT : getServiceUser end
[cal] 18/1/16, 3:43:05 PM SGT : Running serverctl (
    enable,
    "service=org.calendarserver.calendarserver"
)
[cal] 18/1/16, 3:43:05 PM SGT : serverctl successful
[cal] 18/1/16, 3:43:05 PM SGT : startService returning
[cal] 18/1/16, 3:43:05 PM SGT : Configuring reverse proxies
[cal] 18/1/16, 3:43:49 PM SGT : Reverse proxies configured
[cal] 18/1/16, 3:43:49 PM SGT : Output:
Calling ['/Applications/Server.app/Contents/ServerRoot/usr/sbin/webappctl', 'start', 'com.apple.webapp.calendar']
Duration: 40.94
webappctl total time: 40.94
Proxy directives:
Setting webcalssl-enabled header and loading auth

[cal] 18/1/16, 3:43:49 PM SGT : setState is calling getState
[cal] 18/1/16, 3:43:49 PM SGT : getState begin
[cal] 18/1/16, 3:43:49 PM SGT : Read Settings
[cal] 18/1/16, 3:43:49 PM SGT : Asking calendarserver_config for a readConfig
[cal] 18/1/16, 3:43:54 PM SGT : Returned from calendarserver_config
[cal] 18/1/16, 3:43:54 PM SGT : No error parsing calendarserver_config output
[cal] 18/1/16, 3:43:54 PM SGT : Got settings from calendarserver_config
[cal] 18/1/16, 3:43:54 PM SGT : Read settings returning:
[cal] 18/1/16, 3:43:54 PM SGT :   configuration = {
[cal] 18/1/16, 3:43:54 PM SGT :     DefaultLogLevel = info
[cal] 18/1/16, 3:43:54 PM SGT :     EnableAPNS = 1
[cal] 18/1/16, 3:43:54 PM SGT :     EnableSSL = 1
[cal] 18/1/16, 3:43:54 PM SGT :     DirectoryAddressBook = {
[cal] 18/1/16, 3:43:54 PM SGT :       params = {
[cal] 18/1/16, 3:43:54 PM SGT :         queryPeopleRecords = 1
[cal] 18/1/16, 3:43:54 PM SGT :         queryUserRecords = 1
[cal] 18/1/16, 3:43:54 PM SGT :       }
[cal] 18/1/16, 3:43:54 PM SGT :     }
[cal] 18/1/16, 3:43:54 PM SGT :     EnableSearchAddressBook = 1
[cal] 18/1/16, 3:43:54 PM SGT :     HTTPPort = 8008
[cal] 18/1/16, 3:43:54 PM SGT :     AccountingCategories = {
[cal] 18/1/16, 3:43:54 PM SGT :       HTTP = 0
[cal] 18/1/16, 3:43:54 PM SGT :       Implicit Errors = 0
[cal] 18/1/16, 3:43:54 PM SGT :       iTIP = 0
[cal] 18/1/16, 3:43:54 PM SGT :       migration = 0
[cal] 18/1/16, 3:43:54 PM SGT :       AutoScheduling = 0
[cal] 18/1/16, 3:43:54 PM SGT :       iSchedule = 0
[cal] 18/1/16, 3:43:54 PM SGT :       iTIP-VFREEBUSY = 0
[cal] 18/1/16, 3:43:54 PM SGT :     }
[cal] 18/1/16, 3:43:54 PM SGT :     Authentication = {
[cal] 18/1/16, 3:43:54 PM SGT :       Digest = {
[cal] 18/1/16, 3:43:54 PM SGT :         Enabled = 0
[cal] 18/1/16, 3:43:54 PM SGT :         AllowedOverWireUnencrypted = 1
[cal] 18/1/16, 3:43:54 PM SGT :       }
[cal] 18/1/16, 3:43:54 PM SGT :       Kerberos = {
[cal] 18/1/16, 3:43:54 PM SGT :         Enabled = 0
[cal] 18/1/16, 3:43:54 PM SGT :         AllowedOverWireUnencrypted = 1
[cal] 18/1/16, 3:43:54 PM SGT :       }
[cal] 18/1/16, 3:43:54 PM SGT :       Wiki = {
[cal] 18/1/16, 3:43:54 PM SGT :         Enabled = 1
[cal] 18/1/16, 3:43:54 PM SGT :       }
[cal] 18/1/16, 3:43:54 PM SGT :       Basic = {
[cal] 18/1/16, 3:43:54 PM SGT :         Enabled = 1
[cal] 18/1/16, 3:43:54 PM SGT :         AllowedOverWireUnencrypted = 0
[cal] 18/1/16, 3:43:54 PM SGT :       }
[cal] 18/1/16, 3:43:54 PM SGT :     }
[cal] 18/1/16, 3:43:54 PM SGT :     EnableCardDAV = 0
[cal] 18/1/16, 3:43:54 PM SGT :     Scheduling = {
[cal] 18/1/16, 3:43:54 PM SGT :       iMIP = {
[cal] 18/1/16, 3:43:54 PM SGT :         Sending = {
[cal] 18/1/16, 3:43:54 PM SGT :           Server = mx.sapuraglobal.com
[cal] 18/1/16, 3:43:54 PM SGT :           UseSSL = 1
[cal] 18/1/16, 3:43:54 PM SGT :           Username = ical.service
[cal] 18/1/16, 3:43:54 PM SGT :           Address = ical.service@sapuraglobal.com
[cal] 18/1/16, 3:43:54 PM SGT :           Password = <hidden>
[cal] 18/1/16, 3:43:54 PM SGT :           Port = 465
[cal] 18/1/16, 3:43:54 PM SGT :         }
[cal] 18/1/16, 3:43:54 PM SGT :         Enabled = 1
[cal] 18/1/16, 3:43:54 PM SGT :         Receiving = {
[cal] 18/1/16, 3:43:54 PM SGT :           Server = mx.sapuraglobal.com
[cal] 18/1/16, 3:43:54 PM SGT :           UseSSL = 1
[cal] 18/1/16, 3:43:54 PM SGT :           Username = sam.aung
[cal] 18/1/16, 3:43:54 PM SGT :           Type = imap
[cal] 18/1/16, 3:43:54 PM SGT :           Password = <hidden>
[cal] 18/1/16, 3:43:54 PM SGT :           Port = 993
[cal] 18/1/16, 3:43:54 PM SGT :         }
[cal] 18/1/16, 3:43:54 PM SGT :       }
[cal] 18/1/16, 3:43:54 PM SGT :     }
[cal] 18/1/16, 3:43:54 PM SGT :     SSLPrivateKey = 
[cal] 18/1/16, 3:43:54 PM SGT :     LogLevels = {
[cal] 18/1/16, 3:43:55 PM SGT :     }
[cal] 18/1/16, 3:43:55 PM SGT :     DataRoot = /Library/Server/Calendar and Contacts/Data
[cal] 18/1/16, 3:43:55 PM SGT :     ServerRoot = /Library/Server/Calendar and Contacts
[cal] 18/1/16, 3:43:55 PM SGT :     SSLCertificate = 
[cal] 18/1/16, 3:43:55 PM SGT :     EnableCalDAV = 1
[cal] 18/1/16, 3:43:55 PM SGT :     Notifications = {
[cal] 18/1/16, 3:43:55 PM SGT :       Services = {
[cal] 18/1/16, 3:43:55 PM SGT :         APNS = {
[cal] 18/1/16, 3:43:55 PM SGT :           Enabled = 1
[cal] 18/1/16, 3:43:55 PM SGT :         }
[cal] 18/1/16, 3:43:55 PM SGT :       }
[cal] 18/1/16, 3:43:55 PM SGT :     }
[cal] 18/1/16, 3:43:55 PM SGT :     SSLPort = 8443
[cal] 18/1/16, 3:43:55 PM SGT :     RedirectHTTPToHTTPS = 1
[cal] 18/1/16, 3:43:55 PM SGT :     SSLAuthorityChain = 
[cal] 18/1/16, 3:43:55 PM SGT :     ServerHostName = dns1.sapuraglobal.com
[cal] 18/1/16, 3:43:55 PM SGT :   }
[cal] 18/1/16, 3:43:55 PM SGT :   readStatus = 0
[cal] 18/1/16, 3:43:55 PM SGT : CalendarRequestHandler caldavd is not ready
[cal] 18/1/16, 3:43:55 PM SGT : getState returning: {
    calendarState = STARTING;
    contactsState = STOPPED;
    readWriteSettingsVersion = 1;
    setStateVersion = 1;
    state = STARTING;
}
[cal] 18/1/16, 3:43:55 PM SGT : setState returning: {
    calendarState = STARTING;
    contactsState = STOPPED;
    readWriteSettingsVersion = 1;
    setStateVersion = 1;
    state = STARTING;
}
[cal] 18/1/16, 3:43:55 PM SGT : Command setState duration 60.43 seconds
[cal] 18/1/16, 3:43:55 PM SGT : setState releasing request lock
[cal] 18/1/16, 3:43:55 PM SGT : Command getState received
[cal] 18/1/16, 3:43:55 PM SGT : getState attempting to acquire request lock...
[cal] 18/1/16, 3:43:55 PM SGT : getState acquired request lock
[cal] 18/1/16, 3:43:55 PM SGT : getState begin
[cal] 18/1/16, 3:43:55 PM SGT : Read Settings
[cal] 18/1/16, 3:43:55 PM SGT : Asking calendarserver_config for a readConfig
[cal] 18/1/16, 3:43:58 PM SGT : Returned from calendarserver_config
[cal] 18/1/16, 3:43:58 PM SGT : No error parsing calendarserver_config output
[cal] 18/1/16, 3:43:58 PM SGT : Got settings from calendarserver_config
[cal] 18/1/16, 3:43:58 PM SGT : Read settings returning:
[cal] 18/1/16, 3:43:58 PM SGT :   configuration = {
[cal] 18/1/16, 3:43:58 PM SGT :     DefaultLogLevel = info
[cal] 18/1/16, 3:43:58 PM SGT :     EnableAPNS = 1
[cal] 18/1/16, 3:43:59 PM SGT :     EnableSSL = 1
[cal] 18/1/16, 3:43:59 PM SGT :     DirectoryAddressBook = {
[cal] 18/1/16, 3:43:59 PM SGT :       params = {
[cal] 18/1/16, 3:43:59 PM SGT :         queryPeopleRecords = 1
[cal] 18/1/16, 3:43:59 PM SGT :         queryUserRecords = 1
[cal] 18/1/16, 3:43:59 PM SGT :       }
[cal] 18/1/16, 3:43:59 PM SGT :     }
[cal] 18/1/16, 3:43:59 PM SGT :     EnableSearchAddressBook = 1
[cal] 18/1/16, 3:43:59 PM SGT :     HTTPPort = 8008
[cal] 18/1/16, 3:43:59 PM SGT :     AccountingCategories = {
[cal] 18/1/16, 3:43:59 PM SGT :       HTTP = 0
[cal] 18/1/16, 3:43:59 PM SGT :       Implicit Errors = 0
[cal] 18/1/16, 3:43:59 PM SGT :       iTIP = 0
[cal] 18/1/16, 3:43:59 PM SGT :       migration = 0
[cal] 18/1/16, 3:43:59 PM SGT :       AutoScheduling = 0
[cal] 18/1/16, 3:43:59 PM SGT :       iSchedule = 0
[cal] 18/1/16, 3:43:59 PM SGT :       iTIP-VFREEBUSY = 0
[cal] 18/1/16, 3:43:59 PM SGT :     }
[cal] 18/1/16, 3:43:59 PM SGT :     Authentication = {
[cal] 18/1/16, 3:43:59 PM SGT :       Digest = {
[cal] 18/1/16, 3:43:59 PM SGT :         Enabled = 0
[cal] 18/1/16, 3:43:59 PM SGT :         AllowedOverWireUnencrypted = 1
[cal] 18/1/16, 3:43:59 PM SGT :       }
[cal] 18/1/16, 3:43:59 PM SGT :       Kerberos = {
[cal] 18/1/16, 3:43:59 PM SGT :         Enabled = 0
[cal] 18/1/16, 3:43:59 PM SGT :         AllowedOverWireUnencrypted = 1
[cal] 18/1/16, 3:43:59 PM SGT :       }
[cal] 18/1/16, 3:43:59 PM SGT :       Wiki = {
[cal] 18/1/16, 3:44:00 PM SGT :         Enabled = 1
[cal] 18/1/16, 3:44:00 PM SGT :       }
[cal] 18/1/16, 3:44:00 PM SGT :       Basic = {
[cal] 18/1/16, 3:44:00 PM SGT :         Enabled = 1
[cal] 18/1/16, 3:44:00 PM SGT :         AllowedOverWireUnencrypted = 0
[cal] 18/1/16, 3:44:00 PM SGT :       }
[cal] 18/1/16, 3:44:00 PM SGT :     }
[cal] 18/1/16, 3:44:00 PM SGT :     EnableCardDAV = 0
[cal] 18/1/16, 3:44:00 PM SGT :     Scheduling = {
[cal] 18/1/16, 3:44:00 PM SGT :       iMIP = {
[cal] 18/1/16, 3:44:00 PM SGT :         Sending = {
[cal] 18/1/16, 3:44:00 PM SGT :           Server = mx.sapuraglobal.com
[cal] 18/1/16, 3:44:00 PM SGT :           UseSSL = 1
[cal] 18/1/16, 3:44:00 PM SGT :           Username = ical.service
[cal] 18/1/16, 3:44:00 PM SGT :           Address = ical.service@sapuraglobal.com
[cal] 18/1/16, 3:44:00 PM SGT :           Password = <hidden>
[cal] 18/1/16, 3:44:00 PM SGT :           Port = 465
[cal] 18/1/16, 3:44:00 PM SGT :         }
[cal] 18/1/16, 3:44:00 PM SGT :         Enabled = 1
[cal] 18/1/16, 3:44:00 PM SGT :         Receiving = {
[cal] 18/1/16, 3:44:00 PM SGT :           Server = mx.sapuraglobal.com
[cal] 18/1/16, 3:44:00 PM SGT :           UseSSL = 1
[cal] 18/1/16, 3:44:00 PM SGT :           Username = sam.aung
[cal] 18/1/16, 3:44:00 PM SGT :           Type = imap
[cal] 18/1/16, 3:44:00 PM SGT :           Password = <hidden>
[cal] 18/1/16, 3:44:00 PM SGT :           Port = 993
[cal] 18/1/16, 3:44:00 PM SGT :         }
[cal] 18/1/16, 3:44:00 PM SGT :       }
[cal] 18/1/16, 3:44:00 PM SGT :     }
[cal] 18/1/16, 3:44:00 PM SGT :     SSLPrivateKey = 
[cal] 18/1/16, 3:44:00 PM SGT :     LogLevels = {
[cal] 18/1/16, 3:44:00 PM SGT :     }
[cal] 18/1/16, 3:44:00 PM SGT :     DataRoot = /Library/Server/Calendar and Contacts/Data
[cal] 18/1/16, 3:44:00 PM SGT :     ServerRoot = /Library/Server/Calendar and Contacts
[cal] 18/1/16, 3:44:00 PM SGT :     SSLCertificate = 
[cal] 18/1/16, 3:44:00 PM SGT :     EnableCalDAV = 1
[cal] 18/1/16, 3:44:00 PM SGT :     Notifications = {
[cal] 18/1/16, 3:44:00 PM SGT :       Services = {
[cal] 18/1/16, 3:44:00 PM SGT :         APNS = {
[cal] 18/1/16, 3:44:00 PM SGT :           Enabled = 1
[cal] 18/1/16, 3:44:00 PM SGT :         }
[cal] 18/1/16, 3:44:00 PM SGT :       }
[cal] 18/1/16, 3:44:00 PM SGT :     }
[cal] 18/1/16, 3:44:00 PM SGT :     SSLPort = 8443
[cal] 18/1/16, 3:44:00 PM SGT :     RedirectHTTPToHTTPS = 1
[cal] 18/1/16, 3:44:00 PM SGT :     SSLAuthorityChain = 
[cal] 18/1/16, 3:44:00 PM SGT :     ServerHostName = dns1.sapuraglobal.com
[cal] 18/1/16, 3:44:00 PM SGT :   }
[cal] 18/1/16, 3:44:00 PM SGT :   readStatus = 0
[cal] 18/1/16, 3:44:00 PM SGT : CalendarRequestHandler caldavd is not ready
[cal] 18/1/16, 3:44:00 PM SGT : getState returning: {
    calendarState = STARTING;
    contactsState = STOPPED;
    readWriteSettingsVersion = 1;
    setStateVersion = 1;
    state = STARTING;
}
[cal] 18/1/16, 3:44:00 PM SGT : Command getState duration 5.24 seconds
[cal] 18/1/16, 3:44:00 PM SGT : getState releasing request lock
[cal] 18/1/16, 3:44:00 PM SGT : Command readSettings received
[cal] 18/1/16, 3:44:00 PM SGT : readSettings attempting to acquire request lock...
[cal] 18/1/16, 3:44:00 PM SGT : readSettings acquired request lock
[cal] 18/1/16, 3:44:00 PM SGT : Read Settings
[cal] 18/1/16, 3:44:00 PM SGT : Asking calendarserver_config for a readConfig
[cal] 18/1/16, 3:44:03 PM SGT : Returned from calendarserver_config
[cal] 18/1/16, 3:44:03 PM SGT : No error parsing calendarserver_config output
[cal] 18/1/16, 3:44:03 PM SGT : Got settings from calendarserver_config
[cal] 18/1/16, 3:44:03 PM SGT : Read settings returning:
[cal] 18/1/16, 3:44:03 PM SGT :   configuration = {
[cal] 18/1/16, 3:44:03 PM SGT :     DefaultLogLevel = info
[cal] 18/1/16, 3:44:03 PM SGT :     EnableAPNS = 1
[cal] 18/1/16, 3:44:03 PM SGT :     EnableSSL = 1
[cal] 18/1/16, 3:44:03 PM SGT :     DirectoryAddressBook = {
[cal] 18/1/16, 3:44:03 PM SGT :       params = {
[cal] 18/1/16, 3:44:03 PM SGT :         queryPeopleRecords = 1
[cal] 18/1/16, 3:44:03 PM SGT :         queryUserRecords = 1
[cal] 18/1/16, 3:44:03 PM SGT :       }
[cal] 18/1/16, 3:44:03 PM SGT :     }
[cal] 18/1/16, 3:44:03 PM SGT :     EnableSearchAddressBook = 1
[cal] 18/1/16, 3:44:03 PM SGT :     HTTPPort = 8008
[cal] 18/1/16, 3:44:03 PM SGT :     AccountingCategories = {
[cal] 18/1/16, 3:44:03 PM SGT :       HTTP = 0
[cal] 18/1/16, 3:44:03 PM SGT :       Implicit Errors = 0
[cal] 18/1/16, 3:44:03 PM SGT :       iTIP = 0
[cal] 18/1/16, 3:44:03 PM SGT :       migration = 0
[cal] 18/1/16, 3:44:03 PM SGT :       AutoScheduling = 0
[cal] 18/1/16, 3:44:03 PM SGT :       iSchedule = 0
[cal] 18/1/16, 3:44:03 PM SGT :       iTIP-VFREEBUSY = 0
[cal] 18/1/16, 3:44:03 PM SGT :     }
[cal] 18/1/16, 3:44:03 PM SGT :     Authentication = {
[cal] 18/1/16, 3:44:03 PM SGT :       Digest = {
[cal] 18/1/16, 3:44:03 PM SGT :         Enabled = 0
[cal] 18/1/16, 3:44:03 PM SGT :         AllowedOverWireUnencrypted = 1
[cal] 18/1/16, 3:44:03 PM SGT :       }
[cal] 18/1/16, 3:44:03 PM SGT :       Kerberos = {
[cal] 18/1/16, 3:44:03 PM SGT :         Enabled = 0
[cal] 18/1/16, 3:44:03 PM SGT :         AllowedOverWireUnencrypted = 1
[cal] 18/1/16, 3:44:03 PM SGT :       }
[cal] 18/1/16, 3:44:03 PM SGT :       Wiki = {
[cal] 18/1/16, 3:44:03 PM SGT :         Enabled = 1
[cal] 18/1/16, 3:44:03 PM SGT :       }
[cal] 18/1/16, 3:44:03 PM SGT :       Basic = {
[cal] 18/1/16, 3:44:03 PM SGT :         Enabled = 1
[cal] 18/1/16, 3:44:03 PM SGT :         AllowedOverWireUnencrypted = 0
[cal] 18/1/16, 3:44:03 PM SGT :       }
[cal] 18/1/16, 3:44:03 PM SGT :     }
[cal] 18/1/16, 3:44:03 PM SGT :     EnableCardDAV = 0
[cal] 18/1/16, 3:44:03 PM SGT :     Scheduling = {
[cal] 18/1/16, 3:44:03 PM SGT :       iMIP = {
[cal] 18/1/16, 3:44:03 PM SGT :         Sending = {
[cal] 18/1/16, 3:44:03 PM SGT :           Server = mx.sapuraglobal.com
[cal] 18/1/16, 3:44:03 PM SGT :           UseSSL = 1
[cal] 18/1/16, 3:44:03 PM SGT :           Username = ical.service
[cal] 18/1/16, 3:44:03 PM SGT :           Address = ical.service@sapuraglobal.com
[cal] 18/1/16, 3:44:03 PM SGT :           Password = <hidden>
[cal] 18/1/16, 3:44:03 PM SGT :           Port = 465
[cal] 18/1/16, 3:44:03 PM SGT :         }
[cal] 18/1/16, 3:44:03 PM SGT :         Enabled = 1
[cal] 18/1/16, 3:44:03 PM SGT :         Receiving = {
[cal] 18/1/16, 3:44:03 PM SGT :           Server = mx.sapuraglobal.com
[cal] 18/1/16, 3:44:03 PM SGT :           UseSSL = 1
[cal] 18/1/16, 3:44:03 PM SGT :           Username = sam.aung
[cal] 18/1/16, 3:44:03 PM SGT :           Type = imap
[cal] 18/1/16, 3:44:03 PM SGT :           Password = <hidden>
[cal] 18/1/16, 3:44:03 PM SGT :           Port = 993
[cal] 18/1/16, 3:44:03 PM SGT :         }
[cal] 18/1/16, 3:44:03 PM SGT :       }
[cal] 18/1/16, 3:44:03 PM SGT :     }
[cal] 18/1/16, 3:44:03 PM SGT :     SSLPrivateKey = 
[cal] 18/1/16, 3:44:03 PM SGT :     LogLevels = {
[cal] 18/1/16, 3:44:03 PM SGT :     }
[cal] 18/1/16, 3:44:03 PM SGT :     DataRoot = /Library/Server/Calendar and Contacts/Data
[cal] 18/1/16, 3:44:03 PM SGT :     ServerRoot = /Library/Server/Calendar and Contacts
[cal] 18/1/16, 3:44:03 PM SGT :     SSLCertificate = 
[cal] 18/1/16, 3:44:03 PM SGT :     EnableCalDAV = 1
[cal] 18/1/16, 3:44:03 PM SGT :     Notifications = {
[cal] 18/1/16, 3:44:03 PM SGT :       Services = {
[cal] 18/1/16, 3:44:03 PM SGT :         APNS = {
[cal] 18/1/16, 3:44:03 PM SGT :           Enabled = 1
[cal] 18/1/16, 3:44:03 PM SGT :         }
[cal] 18/1/16, 3:44:03 PM SGT :       }
[cal] 18/1/16, 3:44:03 PM SGT :     }
[cal] 18/1/16, 3:44:03 PM SGT :     SSLPort = 8443
[cal] 18/1/16, 3:44:03 PM SGT :     RedirectHTTPToHTTPS = 1
[cal] 18/1/16, 3:44:03 PM SGT :     SSLAuthorityChain = 
[cal] 18/1/16, 3:44:03 PM SGT :     ServerHostName = dns1.sapuraglobal.com
[cal] 18/1/16, 3:44:03 PM SGT :   }
[cal] 18/1/16, 3:44:03 PM SGT :   readStatus = 0
[cal] 18/1/16, 3:44:03 PM SGT : Command readSettings duration 3.38 seconds
[cal] 18/1/16, 3:44:03 PM SGT : readSettings releasing request lock
[cal] 18/1/16, 3:45:12 PM SGT : Command readSettings received
[cal] 18/1/16, 3:45:12 PM SGT : readSettings attempting to acquire request lock...
[cal] 18/1/16, 3:45:12 PM SGT : readSettings acquired request lock
[cal] 18/1/16, 3:45:12 PM SGT : Read Settings
[cal] 18/1/16, 3:45:12 PM SGT : Asking calendarserver_config for a readConfig
[cal] 18/1/16, 3:45:15 PM SGT : Returned from calendarserver_config
[cal] 18/1/16, 3:45:15 PM SGT : No error parsing calendarserver_config output
[cal] 18/1/16, 3:45:15 PM SGT : Got settings from calendarserver_config
[cal] 18/1/16, 3:45:15 PM SGT : Read settings returning:
[cal] 18/1/16, 3:45:15 PM SGT :   configuration = {
[cal] 18/1/16, 3:45:15 PM SGT :     DefaultLogLevel = info
[cal] 18/1/16, 3:45:15 PM SGT :     EnableAPNS = 1
[cal] 18/1/16, 3:45:15 PM SGT :     EnableSSL = 1
[cal] 18/1/16, 3:45:15 PM SGT :     DirectoryAddressBook = {
[cal] 18/1/16, 3:45:15 PM SGT :       params = {
[cal] 18/1/16, 3:45:15 PM SGT :         queryPeopleRecords = 1
[cal] 18/1/16, 3:45:15 PM SGT :         queryUserRecords = 1
[cal] 18/1/16, 3:45:15 PM SGT :       }
[cal] 18/1/16, 3:45:15 PM SGT :     }
[cal] 18/1/16, 3:45:15 PM SGT :     EnableSearchAddressBook = 1
[cal] 18/1/16, 3:45:15 PM SGT :     HTTPPort = 8008
[cal] 18/1/16, 3:45:15 PM SGT :     AccountingCategories = {
[cal] 18/1/16, 3:45:15 PM SGT :       HTTP = 0
[cal] 18/1/16, 3:45:15 PM SGT :       Implicit Errors = 0
[cal] 18/1/16, 3:45:15 PM SGT :       iTIP = 0
[cal] 18/1/16, 3:45:15 PM SGT :       migration = 0
[cal] 18/1/16, 3:45:15 PM SGT :       AutoScheduling = 0
[cal] 18/1/16, 3:45:15 PM SGT :       iSchedule = 0
[cal] 18/1/16, 3:45:15 PM SGT :       iTIP-VFREEBUSY = 0
[cal] 18/1/16, 3:45:15 PM SGT :     }
[cal] 18/1/16, 3:45:15 PM SGT :     Authentication = {
[cal] 18/1/16, 3:45:15 PM SGT :       Digest = {
[cal] 18/1/16, 3:45:15 PM SGT :         Enabled = 0
[cal] 18/1/16, 3:45:15 PM SGT :         AllowedOverWireUnencrypted = 1
[cal] 18/1/16, 3:45:15 PM SGT :       }
[cal] 18/1/16, 3:45:15 PM SGT :       Kerberos = {
[cal] 18/1/16, 3:45:15 PM SGT :         Enabled = 0
[cal] 18/1/16, 3:45:15 PM SGT :         AllowedOverWireUnencrypted = 1
[cal] 18/1/16, 3:45:15 PM SGT :       }
[cal] 18/1/16, 3:45:15 PM SGT :       Wiki = {
[cal] 18/1/16, 3:45:15 PM SGT :         Enabled = 1
[cal] 18/1/16, 3:45:15 PM SGT :       }
[cal] 18/1/16, 3:45:15 PM SGT :       Basic = {
[cal] 18/1/16, 3:45:15 PM SGT :         Enabled = 1
[cal] 18/1/16, 3:45:15 PM SGT :         AllowedOverWireUnencrypted = 0
[cal] 18/1/16, 3:45:15 PM SGT :       }
[cal] 18/1/16, 3:45:15 PM SGT :     }
[cal] 18/1/16, 3:45:15 PM SGT :     EnableCardDAV = 0
[cal] 18/1/16, 3:45:15 PM SGT :     Scheduling = {
[cal] 18/1/16, 3:45:15 PM SGT :       iMIP = {
[cal] 18/1/16, 3:45:15 PM SGT :         Sending = {
[cal] 18/1/16, 3:45:15 PM SGT :           Server = mx.sapuraglobal.com
[cal] 18/1/16, 3:45:15 PM SGT :           UseSSL = 1
[cal] 18/1/16, 3:45:15 PM SGT :           Username = ical.service
[cal] 18/1/16, 3:45:15 PM SGT :           Address = ical.service@sapuraglobal.com
[cal] 18/1/16, 3:45:15 PM SGT :           Password = <hidden>
[cal] 18/1/16, 3:45:15 PM SGT :           Port = 465
[cal] 18/1/16, 3:45:15 PM SGT :         }
[cal] 18/1/16, 3:45:15 PM SGT :         Enabled = 1
[cal] 18/1/16, 3:45:15 PM SGT :         Receiving = {
[cal] 18/1/16, 3:45:15 PM SGT :           Server = mx.sapuraglobal.com
[cal] 18/1/16, 3:45:15 PM SGT :           UseSSL = 1
[cal] 18/1/16, 3:45:15 PM SGT :           Username = sam.aung
[cal] 18/1/16, 3:45:15 PM SGT :           Type = imap
[cal] 18/1/16, 3:45:15 PM SGT :           Password = <hidden>
[cal] 18/1/16, 3:45:15 PM SGT :           Port = 993
[cal] 18/1/16, 3:45:15 PM SGT :         }
[cal] 18/1/16, 3:45:15 PM SGT :       }
[cal] 18/1/16, 3:45:15 PM SGT :     }
[cal] 18/1/16, 3:45:15 PM SGT :     SSLPrivateKey = 
[cal] 18/1/16, 3:45:16 PM SGT :     LogLevels = {
[cal] 18/1/16, 3:45:16 PM SGT :     }
[cal] 18/1/16, 3:45:16 PM SGT :     DataRoot = /Library/Server/Calendar and Contacts/Data
[cal] 18/1/16, 3:45:16 PM SGT :     ServerRoot = /Library/Server/Calendar and Contacts
[cal] 18/1/16, 3:45:16 PM SGT :     SSLCertificate = 
[cal] 18/1/16, 3:45:16 PM SGT :     EnableCalDAV = 1
[cal] 18/1/16, 3:45:16 PM SGT :     Notifications = {
[cal] 18/1/16, 3:45:16 PM SGT :       Services = {
[cal] 18/1/16, 3:45:16 PM SGT :         APNS = {
[cal] 18/1/16, 3:45:16 PM SGT :           Enabled = 1
[cal] 18/1/16, 3:45:16 PM SGT :         }
[cal] 18/1/16, 3:45:16 PM SGT :       }
[cal] 18/1/16, 3:45:16 PM SGT :     }
[cal] 18/1/16, 3:45:16 PM SGT :     SSLPort = 8443
[cal] 18/1/16, 3:45:16 PM SGT :     RedirectHTTPToHTTPS = 1
[cal] 18/1/16, 3:45:16 PM SGT :     SSLAuthorityChain = 
[cal] 18/1/16, 3:45:16 PM SGT :     ServerHostName = dns1.sapuraglobal.com
[cal] 18/1/16, 3:45:16 PM SGT :   }
[cal] 18/1/16, 3:45:16 PM SGT :   readStatus = 0
[cal] 18/1/16, 3:45:16 PM SGT : Command readSettings duration 3.95 seconds
[cal] 18/1/16, 3:45:16 PM SGT : readSettings releasing request lock
[cal] 18/1/16, 3:45:16 PM SGT : Command getResourceList received
[cal] 18/1/16, 3:45:16 PM SGT : getResourceList attempting to acquire request lock...
[cal] 18/1/16, 3:45:16 PM SGT : getResourceList acquired request lock
[cal] 18/1/16, 3:45:16 PM SGT : calendarServerOperationWithRequest
[cal] 18/1/16, 3:45:16 PM SGT : Calling agent...
[cal] 18/1/16, 3:45:32 PM SGT : Agent failure: The request timed out.
[cal] 18/1/16, 3:45:32 PM SGT : Agent returned...
{
    error = "The request timed out.";
}
[cal] 18/1/16, 3:45:32 PM SGT : Command getResourceList duration 16.20 seconds
[cal] 18/1/16, 3:45:32 PM SGT : getResourceList releasing request lock
[cal] 18/1/16, 3:45:32 PM SGT : Command getLocationList received
[cal] 18/1/16, 3:45:32 PM SGT : getLocationList attempting to acquire request lock...
[cal] 18/1/16, 3:45:32 PM SGT : getLocationList acquired request lock
[cal] 18/1/16, 3:45:32 PM SGT : calendarServerOperationWithRequest
[cal] 18/1/16, 3:45:33 PM SGT : Calling agent...
[cal] 18/1/16, 3:45:49 PM SGT : Agent failure: The request timed out.
[cal] 18/1/16, 3:45:49 PM SGT : Agent returned...
{
    error = "The request timed out.";
}
[cal] 18/1/16, 3:45:49 PM SGT : Command getLocationList duration 16.10 seconds
[cal] 18/1/16, 3:45:49 PM SGT : getLocationList releasing request lock
[cal] 18/1/16, 3:45:49 PM SGT : Command getAddressList received
[cal] 18/1/16, 3:45:49 PM SGT : getAddressList attempting to acquire request lock...
[cal] 18/1/16, 3:45:49 PM SGT : getAddressList acquired request lock
[cal] 18/1/16, 3:45:49 PM SGT : calendarServerOperationWithRequest
[cal] 18/1/16, 3:45:49 PM SGT : Calling agent...
[cal] 18/1/16, 3:46:05 PM SGT : Agent failure: The request timed out.
[cal] 18/1/16, 3:46:05 PM SGT : Agent returned...
{
    error = "The request timed out.";
}
[cal] 18/1/16, 3:46:05 PM SGT : Command getAddressList duration 15.91 seconds
[cal] 18/1/16, 3:46:05 PM SGT : getAddressList releasing request lock
[cal] 18/1/16, 3:46:05 PM SGT : Command getState received




 

2 ) error.log (Note* The same line would keep repeating forever)

2016-01-18 15:34:53+0800 [-] [txdav.base.datastore.subpostgres.PostgresMonitor#info] .
2016-01-18 15:34:54+0800 [-] [txdav.base.datastore.subpostgres.PostgresMonitor#info] .
2016-01-18 15:34:55+0800 [-] [txdav.base.datastore.subpostgres.PostgresMonitor#info] .
2016-01-18 15:34:55+0800 [-] [twisted.internet.base#info] Received SIGTERM, shutting down.
2016-01-18 15:34:55+0800 [-] (UNIX Port '/var/run/caldavd/caldavd.sock' Closed)
2016-01-18 15:34:56+0800 [-] [txdav.base.datastore.subpostgres.PostgresMonitor#info] .
2016-01-18 15:34:57+0800 [-] [txdav.base.datastore.subpostgres.PostgresMonitor#info] .
2016-01-18 15:34:58+0800 [-] [txdav.base.datastore.subpostgres.PostgresMonitor#info] .
2016-01-18 15:34:59+0800 [-] [txdav.base.datastore.subpostgres.PostgresMonitor#info] .
2016-01-18 15:35:00+0800 [-] [txdav.base.datastore.subpostgres.PostgresMonitor#info] .
2016-01-18 15:43:11+0800 [-] Log opened.
2016-01-18 15:43:11+0800 [-] [twisted.application.app#info] twistd 15.2.1 (/System/Library/Frameworks/Python.framework/Versions/2.7/Resources/Python.app/Contents/MacOS/Python 2.7.10) starting up.
2016-01-18 15:43:11+0800 [-] [twisted.application.app#info] reactor class: twisted.internet.kqreactor.KQueueReactor.
2016-01-18 15:43:11+0800 [-] ControlSocket starting on '/var/run/caldavd/caldavd.sock'
2016-01-18 15:43:11+0800 [-] [txdav.base.datastore.subpostgres#info] Cluster already exists at /Library/Server/Calendar and Contacts/Data/Database.xpg/cluster.pg
2016-01-18 15:43:11+0800 [-] [txdav.base.datastore.subpostgres#info] Requesting postgres start via: ['/Applications/Server.app/Contents/ServerRoot/usr/bin/xpg_ctl', 'start', '--log=/Library/Server/Calendar and Contacts/Logs/xpg_ctl.log', '--timeout=86400', '-w', '-o', "-c listen_addresses='' -c unix_socket_directories=/var/run/caldavd/PostgresSocket -c shared_buffers=135 -c max_connections=90 -c standard_conforming_strings=on -c unix_socket_permissions=0770 -c log_lock_waits=TRUE -c deadlock_timeout=10 -c log_line_prefix='%m [%p] ' -c log_directory='/Library/Server/Calendar and Contacts/Logs' -c log_truncate_on_rotation=on -c log_filename=postgresql_%w.log -c log_rotation_age=1440 -c logging_collector=on -c log_line_prefix=%t"]
2016-01-18 15:43:13+0800 [-] [txdav.base.datastore.subpostgres.PostgresMonitor#info] 2016-01-18 15:43:13 XPG.48476:  Executing pg_ctl ['/Applications/Server.app/Contents/ServerRoot/usr/bin/pg_ctl', '-p', '/Applications/Server.app/Contents/ServerRoot/usr/bin/xpostgres', 'start', '--log=/Library/Server/Calendar and Contacts/Logs/xpg_ctl.log', '--timeout=86400', '-w', '-o', "-c listen_addresses='' -c unix_socket_directories=/var/run/caldavd/PostgresSocket -c shared_buffers=135 -c max_connections=90 -c standard_conforming_strings=on -c unix_socket_permissions=0770 -c log_lock_waits=TRUE -c deadlock_timeout=10 -c log_line_prefix='%m [%p] ' -c log_directory='/Library/Server/Calendar and Contacts/Logs' -c log_truncate_on_rotation=on -c log_filename=postgresql_%w.log -c log_rotation_age=1440 -c logging_collector=on -c log_line_prefix=%t"]
2016-01-18 15:43:13+0800 [-] [txdav.base.datastore.subpostgres.PostgresMonitor#info] 2016-01-18 15:43:13 XPG.48476:  Spawning... ['/Applications/Server.app/Contents/ServerRoot/usr/bin/pg_ctl', '-p', '/Applications/Server.app/Contents/ServerRoot/usr/bin/xpostgres', 'start', '--log=/Library/Server/Calendar and Contacts/Logs/xpg_ctl.log', '--timeout=86400', '-w', '-o', "-c listen_addresses='' -c unix_socket_directories=/var/run/caldavd/PostgresSocket -c shared_buffers=135 -c max_connections=90 -c standard_conforming_strings=on -c unix_socket_permissions=0770 -c log_lock_waits=TRUE -c deadlock_timeout=10 -c log_line_prefix='%m [%p] ' -c log_directory='/Library/Server/Calendar and Contacts/Logs' -c log_truncate_on_rotation=on -c log_filename=postgresql_%w.log -c log_rotation_age=1440 -c logging_collector=on -c log_line_prefix=%t"]
2016-01-18 15:43:13+0800 [-] [txdav.base.datastore.subpostgres.PostgresMonitor#info] waiting for server to start....
2016-01-18 15:43:14+0800 [-] [txdav.base.datastore.subpostgres.PostgresMonitor#info] .
2016-01-18 15:43:15+0800 [-] [txdav.base.datastore.subpostgres.PostgresMonitor#info] .
2016-01-18 15:43:16+0800 [-] [txdav.base.datastore.subpostgres.PostgresMonitor#info] .
2016-01-18 15:43:17+0800 [-] [txdav.base.datastore.subpostgres.PostgresMonitor#info] .
2016-01-18 15:43:18+0800 [-] [txdav.base.datastore.subpostgres.PostgresMonitor#info] .
2016-01-18 15:43:19+0800 [-] [txdav.base.datastore.subpostgres.PostgresMonitor#info] 




 

3 ) xpg_ctl.log

 

 

2016-01-18 15:43:15 XPG.48483:  Process parent is PID 1
2016-01-18 15:43:15 XPG.48483:  Excluding data directory.
2016-01-18 15:43:15 XPG.48483:  Turning on archive logging.
2016-01-18 15:43:15 XPG.48483:  Cleaning up any existing postmaster.pid file
2016-01-18 15:43:15 XPG.48483:  Cleaning up any existing socket lock file
2016-01-18 15:43:15 XPG.48483:  Replacing PID in socket lock file because we know it is not a postmaster.
2016-01-18 15:43:15 XPG.48483:  Starting postgres.
2016-01-18 15:43:15 XPG.48483:  Waiting for data directory: /Library/Server/Calendar and Contacts/Data/Database.xpg/cluster.pg
2016-01-18 15:43:15 XPG.48483:  Data directory exists.
2016-01-18 15:43:15 XPG.48483:  Spawning postgres now.
2016-01-18 15:43:15 XPG.48483:  Waiting for socket to appear in socket directory: /var/run/caldavd/PostgresSocket
2016-01-18 15:43:15 XPG.48483:  Socket available; starting should now be complete.
2016-01-18 15:43:15 XPG.48483:  Killing idle connections...
2016-01-18 15:43:15 XPG.48483:  Spawning... ('/Applications/Server.app/Contents/ServerRoot/usr/bin/psql', '-q', '-h', '/var/run/caldavd/PostgresSocket', '-d', 'postgres', '-c', "SELECT pid, (SELECT pg_terminate_backend(pid)) as killed from pg_stat_activity WHERE state LIKE 'idle';")
psql: could not connect to server: Connection refused
  Is the server running locally and accepting
  connections on Unix domain socket "/var/run/caldavd/PostgresSocket/.s.PGSQL.5432"?
2016-01-18 15:43:15 SGTFATAL:  data directory "/Library/Server/Calendar and Contacts/Data/Database.xpg/cluster.pg" has wrong ownership
2016-01-18 15:43:15 SGTHINT:  The server must be started by the user that owns the data directory.
2016-01-18 15:43:15 XPG.48483:  Postgres exited.

 

 

4 ) agent.log (*The same line from error.log)

2016-01-18 15:41:21+0800 [-] [txdav.base.datastore.subpostgres.PostgresMonitor#info] .
2016-01-18 15:41:22+0800 [-] [txdav.base.datastore.subpostgres.PostgresMonitor#info] .
2016-01-18 15:41:23+0800 [-] [txdav.base.datastore.subpostgres.PostgresMonitor#info] .
2016-01-18 15:41:24+0800 [-] [txdav.base.datastore.subpostgres.PostgresMonitor#info] .
2016-01-18 15:41:25+0800 [-] [txdav.base.datastore.subpostgres.PostgresMonitor#info] .
2016-01-18 15:41:26+0800 [-] [txdav.base.datastore.subpostgres.PostgresMonitor#info] .
2016-01-18 15:41:27+0800 [-] [txdav.base.datastore.subpostgres.PostgresMonitor#info] .
2016-01-18 15:41:28+0800 [-] [txdav.base.datastore.subpostgres.PostgresMonitor#info] .

 

What exactly is that agent? Is it an agent to connect the calendar service with database?

 

All help is appreciated. Thanks a lot!

Posted on Jan 18, 2016 12:07 AM

Close

Q: Calendar Server Error

  • All replies
  • Helpful answers