Navigation

    Kopano
    • Register
    • Login
    • Search
    • Categories
    • Get Official Kopano Support
    • Recent
    Statement regarding the closure of the Kopano community forum and the end of the community edition

    CalDAV sync trouble against Apple CCS

    Z-Push when using other backends
    1
    1
    596
    Loading More Posts
    • Oldest to Newest
    • Newest to Oldest
    • Most Votes
    Reply
    • Reply as topic
    Log in to reply
    This topic has been deleted. Only users with topic management privileges can see it.
    • dfberger
      dfberger last edited by dfberger

      I’ve been trying to get z-push working against a local instance of Apple’s CalendarServer. Contacts (CardDAV) work fine, calendars are a different issue.

      I’m running CalendarServer 9.1 from debian testing, and testing with a macOS desktop CalDav client (macOS Calendar) and iOS Active Sync client (iOS 11.0.3).

      The symptoms are:

      1. events created via desktop client never appear on the mobile device
      2. events created on the mobile device appear momentarily on the device, then vanish, but persist as expected in the CalDAV server and appear on the desktop client. [Edit: I’ve added a CalDav account on the iOS device, and both the desktop-created and mobile-created events appear as expected.]

      I’ve turned on WBXML logging for my user while creating an event on the iOS device and have a log file which I don’t pretend to grok.

      29/10/2017 16:12:50 [23814] [DEBUG] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] -------- Start
29/10/2017 16:12:50 [23814] [DEBUG] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] cmd='Sync' devType='iPad' devId='jll4a0h7ul4hv4vhmjr3ai8urg' getUser='dberger' from='192.168.0.2' version='2.3.8+0-0' method='POST'
29/10/2017 16:12:50 [23814] [DEBUG] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] Used timezone 'America/Los_Angeles'
29/10/2017 16:12:50 [23814] [DEBUG] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] Including backend file: '/usr/share/z-push/backend/imap/imap.php'
29/10/2017 16:12:50 [23814] [DEBUG] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] Including backend file: '/usr/share/z-push/backend/caldav/caldav.php'
29/10/2017 16:12:50 [23814] [DEBUG] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] Including backend file: '/usr/share/z-push/backend/carddav/carddav.php'
29/10/2017 16:12:50 [23814] [DEBUG] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] Combined 3 backends loaded.
29/10/2017 16:12:50 [23814] [DEBUG] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] Request::ProcessHeaders() ASVersion: 14.0
29/10/2017 16:12:50 [23814] [DEBUG] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] ZPush::CommandNeedsProvisioning(0): true
29/10/2017 16:12:50 [23814] [DEBUG] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] FileStateMachine->GetState() read '3517' bytes from file: '/var/lib/z-push/g/r/jll4a0h7ul4hv4vhmjr3ai8urg-devicedata'
29/10/2017 16:12:50 [23814] [DEBUG] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] ASDevice data loaded for user: 'dberger'
29/10/2017 16:12:50 [23814] [DEBUG] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] TopCollector(): Initialized mutexid Resource id #10 and memid Resource id #11.
29/10/2017 16:12:50 [23814] [DEBUG] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] TopCollector initialised with IPC provider 'IpcSharedMemoryProvider' with type '20'
29/10/2017 16:12:50 [23814] [DEBUG] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] LoopDetection(): Initialized mutexid Resource id #12 and memid Resource id #13.
29/10/2017 16:12:50 [23814] [DEBUG] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] LoopDetection initialised with IPC provider 'IpcSharedMemoryProvider' with type '1337'
29/10/2017 16:12:50 [23814] [DEBUG] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] ZPush::HierarchyCommand(0): false
29/10/2017 16:12:50 [23814] [DEBUG] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] DeviceManager->ProvisioningRequired('890874710') saved device key '890874710': false
29/10/2017 16:12:50 [23814] [DEBUG] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] DeviceManager->getPolicyName(): determined policy name: 'default'
29/10/2017 16:12:50 [23814] [DEBUG] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] DeviceManager->getProvisioningPolicies(): loaded 'default' policy.
29/10/2017 16:12:50 [23814] [DEBUG] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] ZPush::CommandNeedsAuthentication(0): true
29/10/2017 16:12:50 [23814] [DEBUG] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] Combined->Logon('dberger', '',***))
29/10/2017 16:12:50 [23814] [DEBUG] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] BackendIMAP->Logon(): User 'dberger' is authenticated on '{mail.oubliette.org:993/imap/ssl/norsh}'
29/10/2017 16:12:50 [23814] [DEBUG] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] BackendCalDAV->Logon(): User 'dberger' is authenticated on CalDAV 'https://ccs.lan:8443/calendars/users/dberger/'
29/10/2017 16:12:50 [23814] [DEBUG] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] BackendCardDAV->Logon(): User 'dberger' is authenticated on 'https://ccs.lan:8443/addressbooks/users/dberger/'
29/10/2017 16:12:50 [23814] [DEBUG] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] BackendCardDAV::discoverAddressbooks() Found addressbook 'https://ccs.lan:8443/addressbooks/users/dberger/addressbook/'
29/10/2017 16:12:50 [23814] [DEBUG] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] Combined->Logon() success
29/10/2017 16:12:50 [23814] [DEBUG] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] ZPush::CommandNeedsPlainInput(0): false
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] I  <Synchronize>
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] I   <Folders>
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] I    <Folder>
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] I     <SyncKey>
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] I      {781a10c6-04f4-4e1c-9f8e-f51b0366a3bc}1
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] I     </SyncKey>
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] I     <FolderId>
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] I      c/Ccalendar
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] I     </FolderId>
29/10/2017 16:12:50 [23814] [DEBUG] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] FileStateMachine->GetState() read '893' bytes from file: '/var/lib/z-push/g/r/jll4a0h7ul4hv4vhmjr3ai8urg-781a10c6-04f4-4e1c-9f8e-f51b0366a3bc-fd'
29/10/2017 16:12:50 [23814] [DEBUG] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] SyncParameters->UseCPO('DEFAULT')
29/10/2017 16:12:50 [23814] [DEBUG] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] DeviceManager->GetBackendIdForFolderId(): no backend-folderid available for 'c/Ccalendar', returning as is.
29/10/2017 16:12:50 [23814] [DEBUG] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] SyncCollections->AddCollection(): Folder id 'c/Ccalendar' : ref. PolicyKey '890874710', ref. Lifetime '900', last sync at '1509318656'
29/10/2017 16:12:50 [23814] [DEBUG] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] SyncCollections->AddCollection(): Updated reference PolicyKey '890874710', reference Lifetime '900', Last sync at '1509318656'
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] I     <GetChanges/>
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] I     <WindowSize>
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] I      25
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] I     </WindowSize>
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] I     <Options>
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] I      <FilterType>
29/10/2017 16:12:50 [23814] [DEBUG] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] SyncParameters->UseCPO('DEFAULT')
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] I       5
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] I      </FilterType>
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] I      <AirSyncBase:BodyPreference>
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] I       <AirSyncBase:Type>
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] I        1
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] I       </AirSyncBase:Type>
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] I       <AirSyncBase:TruncationSize>
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] I        32768
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] I       </AirSyncBase:TruncationSize>
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] I      </AirSyncBase:BodyPreference>
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] I     </Options>
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] I     <Perform>
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] I      <Add>
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] I       <ClientEntryId>
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] I        2519
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] I       </ClientEntryId>
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] I       <Data>
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] I        <AirSyncBase:Body>
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] I         <AirSyncBase:Type>
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] I          1
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] I         </AirSyncBase:Type>
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] I         <AirSyncBase:Data/>
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] I        </AirSyncBase:Body>
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] I        <POOMCAL:Timezone>
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] I         4AEAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAsAAAABAAIAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAMAAAACAAIAAAAAAAAAxP///w==
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] I        </POOMCAL:Timezone>
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] I        <POOMCAL:AllDayEvent>
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] I         0
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] I        </POOMCAL:AllDayEvent>
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] I        <POOMCAL:BusyStatus>
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] I         2
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] I        </POOMCAL:BusyStatus>
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] I        <POOMCAL:DtStamp>
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] I         20171029T231249Z
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] I        </POOMCAL:DtStamp>
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] I        <POOMCAL:EndTime>
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] I         20171030T000000Z
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] I        </POOMCAL:EndTime>
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] I        <POOMCAL:Sensitivity>
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] I         0
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] I        </POOMCAL:Sensitivity>
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] I        <POOMCAL:Subject>
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] I         Created on ipad
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] I        </POOMCAL:Subject>
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] I        <POOMCAL:StartTime>
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] I         20171029T230000Z
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] I        </POOMCAL:StartTime>
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] I        <POOMCAL:UID>
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] I         26496597317F40E0A32659BDFECCC5710
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] I        </POOMCAL:UID>
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] I        <POOMCAL:MeetingStatus>
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] I         0
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] I        </POOMCAL:MeetingStatus>
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] I       </Data>
29/10/2017 16:12:50 [23814] [DEBUG] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] Sync->getImporter(): initialize importer
29/10/2017 16:12:50 [23814] [DEBUG] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] Sync->loadStates(): loading states for folder 'c/Ccalendar'
29/10/2017 16:12:50 [23814] [DEBUG] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] FileStateMachine->GetState() read '6' bytes from file: '/var/lib/z-push/g/r/jll4a0h7ul4hv4vhmjr3ai8urg-781a10c6-04f4-4e1c-9f8e-f51b0366a3bc-1'
29/10/2017 16:12:50 [23814] [DEBUG] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] ZPush::GetAdditionalSyncFolderStore('c/Ccalendar'): 'false'
29/10/2017 16:12:50 [23814] [DEBUG] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] Combined->Setup('', 'false', '', 'false')
29/10/2017 16:12:50 [23814] [DEBUG] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] Combined->Setup() success
29/10/2017 16:12:50 [23814] [DEBUG] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] Combined->GetImporter() Content: ImportChangesCombined:('c/Ccalendar')
29/10/2017 16:12:50 [23814] [DEBUG] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] ImportChangesCombined->SetMoveStates()
29/10/2017 16:12:50 [23814] [DEBUG] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] ImportChangesCombined->SetMoveStates() success
29/10/2017 16:12:50 [23814] [DEBUG] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] ImportChangesCombined->Config(...)
29/10/2017 16:12:50 [23814] [DEBUG] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] ImportChangesCombined->Config() success
29/10/2017 16:12:50 [23814] [DEBUG] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] ImportChangesCombined->ConfigContentParameters()
29/10/2017 16:12:50 [23814] [DEBUG] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] ImportChangesCombined->ConfigContentParameters() success
29/10/2017 16:12:50 [23814] [DEBUG] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] LoopDetection->SetSyncStateUsage(): uuid: 781a10c6-04f4-4e1c-9f8e-f51b0366a3bc  counter: 1
29/10/2017 16:12:50 [23814] [DEBUG] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] BackendCalDAV->ChangeMessage('Ccalendar','')
29/10/2017 16:12:50 [23814] [DEBUG] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] BackendCalDAV->StatMessage('Ccalendar','20171029T231250Z-67eb723bca9091d11b80980b274723be.ics')
29/10/2017 16:12:50 [23814] [DEBUG] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] Sync->importMessage(): message imported
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] I      </Add>
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] I     </Perform>
29/10/2017 16:12:50 [23814] [ INFO] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] Processed '1' incoming changes
29/10/2017 16:12:50 [23814] [DEBUG] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] FileStateMachine->SetState() written 393 bytes on file: '/var/lib/z-push/g/r/jll4a0h7ul4hv4vhmjr3ai8urg-781a10c6-04f4-4e1c-9f8e-f51b0366a3bc-fs-1'
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] I    </Folder>
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] I   </Folders>
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] I  </Synchronize>
29/10/2017 16:12:50 [23814] [DEBUG] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] HandleSync(): Start Output
29/10/2017 16:12:50 [23814] [DEBUG] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] ZPush::GetAdditionalSyncFolderStore('c/Ccalendar'): 'false'
29/10/2017 16:12:50 [23814] [DEBUG] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] Combined->Setup('', 'false', '', 'false')
29/10/2017 16:12:50 [23814] [DEBUG] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] Combined->Setup() success
29/10/2017 16:12:50 [23814] [DEBUG] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] Combined->GetExporter('c/Ccalendar')
29/10/2017 16:12:50 [23814] [DEBUG] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] ExportChangesDiff->InitializeExporter(): Initializing message diff engine. '1' messages in state
29/10/2017 16:12:50 [23814] [DEBUG] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] BackendCalDAV->GetMessageList('Ccalendar','1506640370')
29/10/2017 16:12:50 [23814] [ INFO] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] ExportChangesDiff->InitializeExporter(): Found '1' changes for 'Ccalendar'
29/10/2017 16:12:50 [23814] [DEBUG] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] LoopDetection->ProcessLoopDetectionAddStatus: 'c/Ccalendar' with status 1
29/10/2017 16:12:50 [23814] [DEBUG] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] WBXMLEncoder->startWBXML() type: vnd.ms-sync.wbxml
29/10/2017 16:12:50 [23814] [DEBUG] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] Folder type: Calendar
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] O  <Synchronize>
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] O   <Folders>
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] O    <Folder>
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] O     <SyncKey>
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] O     {781a10c6-04f4-4e1c-9f8e-f51b0366a3bc}2
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] O     </SyncKey>
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] O     <FolderId>
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] O     c/Ccalendar
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] O     </FolderId>
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] O     <Status>
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] O     1
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] O     </Status>
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] O     <Replies>
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] O      <Add>
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] O       <ClientEntryId>
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] O       2519
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] O       </ClientEntryId>
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] O       <ServerEntryId>
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] O       20171029T231250Z-67eb723bca9091d11b80980b274723be.ics
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] O       </ServerEntryId>
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] O       <Status>
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] O       1
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] O       </Status>
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] O      </Add>
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] O     </Replies>
29/10/2017 16:12:50 [23814] [DEBUG] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] LoopDetection->Detect(): folderid:'c/Ccalendar' uuid:'781a10c6-04f4-4e1c-9f8e-f51b0366a3bc' counter:'1' max:'25' queued:'1'
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] O     <Perform>
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] O      <Remove>
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] O       <ServerEntryId>
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] O       20171029T231250Z-67eb723bca9091d11b80980b274723be.ics
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] O       </ServerEntryId>
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] O      </Remove>
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] O     </Perform>
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] O    </Folder>
29/10/2017 16:12:50 [23814] [DEBUG] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] FileStateMachine->SetState() written 6 bytes on file: '/var/lib/z-push/g/r/jll4a0h7ul4hv4vhmjr3ai8urg-781a10c6-04f4-4e1c-9f8e-f51b0366a3bc-2'
29/10/2017 16:12:50 [23814] [DEBUG] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] SyncCollections->SaveCollection(): Data of folder 'c/Ccalendar' changed
29/10/2017 16:12:50 [23814] [DEBUG] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] FileStateMachine->SetState() written 919 bytes on file: '/var/lib/z-push/g/r/jll4a0h7ul4hv4vhmjr3ai8urg-781a10c6-04f4-4e1c-9f8e-f51b0366a3bc-fd'
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] O   </Folders>
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] O  </Synchronize>
29/10/2017 16:12:50 [23814] [DEBUG] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] WBXMLEncoder->endTag() WBXML output completed
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] WBXML-OUT: AwFqAEVcT0sDezc4MWExMGM2LTA0ZjQtNGUxYy05ZjhlLWY1MWIwMzY2YTNiY30yAAFSA2MvQ2NhbGVuZGFyAAFOAzEAAUZHTAMyNTE5AAFNAzIwMTcxMDI5VDIzMTI1MFotNjdlYjcyM2JjYTkwOTFkMTFiODA5ODBiMjc0NzIzYmUuaWNzAAFOAzEAAQEBVklNAzIwMTcxMDI5VDIzMTI1MFotNjdlYjcyM2JjYTkwOTFkMTFiODA5ODBiMjc0NzIzYmUuaWNzAAEBAQEBAQ==
29/10/2017 16:12:50 [23814] [WBXML] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] WBXML-IN : AwFqAEVcT0sDezc4MWExMGM2LTA0ZjQtNGUxYy05ZjhlLWY1MWIwMzY2YTNiY30xAAFSA2MvQ2NhbGVuZGFyAAETVQMyNQABV1gDNQABABFFRgMxAAFHAzMyNzY4AAEBAQAAVkdMAzI1MTkAAV0AEUpGAzEAAQsBAARFAzRBRUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFzQUFBQUJBQUlBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBTUFBQUFDQUFJQUFBQUFBQUFBeFAvLy93PT0AAUYDMAABTQMyAAFRAzIwMTcxMDI5VDIzMTI0OVoAAVIDMjAxNzEwMzBUMDAwMDAwWgABZQMwAAFmA0NyZWF0ZWQgb24gaXBhZAABZwMyMDE3MTAyOVQyMzAwMDBaAAFoAzI2NDk2NTk3MzE3RjQwRTBBMzI2NTlCREZFQ0NDNTcxMAABWAMwAAEBAQEBAQE=
29/10/2017 16:12:50 [23814] [DEBUG] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] Combined->Logoff()
29/10/2017 16:12:50 [23814] [DEBUG] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] BackendIMAP->close_connection(): disconnected from IMAP server
29/10/2017 16:12:50 [23814] [DEBUG] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] BackendCalDAV->Logoff(): disconnected from CALDAV server
29/10/2017 16:12:50 [23814] [DEBUG] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] BackendCardDAV->Logoff(): disconnected from CARDDAV server
29/10/2017 16:12:50 [23814] [DEBUG] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] Combined->Logoff() success
29/10/2017 16:12:50 [23814] [DEBUG] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] LoopDetection->ProcessLoopDetectionTerminate()
29/10/2017 16:12:50 [23814] [ INFO] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] cmd='Sync' memory='2.17 MiB/4.00 MiB' time='0.40s' devType='iPad' devId='jll4a0h7ul4hv4vhmjr3ai8urg' getUser='dberger' from='192.168.0.2' idle='0s' version='2.3.8+0-0' method='POST' httpcode='200'
29/10/2017 16:12:50 [23814] [DEBUG] [dberger] [jll4a0h7ul4hv4vhmjr3ai8urg] -------- End
      1 Reply Last reply Reply Quote 0
      • First post
        Last post