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

    CardDAV backend to NextCloud not working

    Z-Push when using other backends
    1
    1
    895
    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.
    • elodg
      elodg last edited by elodg

      I have a recently installed NextCloud instance with Calendar & Contacts app. I can connect to it with a CardDAV client (iPhone) and sync my contacts. However, I am trying to merge e-mail, contact and calendar accounts into one using EAS, hence Z-Push.
      I am using the combined backend with IMAP and CardDAV.
      E-mail sync works, contacts do not. The contact list is empty and when I add a new contact the following is logged.

      31/12/2017 15:32:10 [12817] [DEBUG] [<EMAIL>] -------- Start
31/12/2017 15:32:10 [12817] [DEBUG] [<EMAIL>] cmd='Sync' devType='iPhone' devId='l6ks0va0ip4d7eq44vk20f3688' getUser='<EMAIL>' from='109.102.78.245' version='2.3.8' method='POST'
31/12/2017 15:32:10 [12817] [DEBUG] [<EMAIL>] Used timezone 'Europe/London'
31/12/2017 15:32:10 [12817] [DEBUG] [<EMAIL>] Including backend file: '/srv/www/roundcube/z-push/backend/imap/imap.php'
31/12/2017 15:32:10 [12817] [DEBUG] [<EMAIL>] Including backend file: '/srv/www/roundcube/z-push/backend/carddav/carddav.php'
31/12/2017 15:32:10 [12817] [DEBUG] [<EMAIL>] Combined 2 backends loaded.
31/12/2017 15:32:10 [12817] [DEBUG] [<EMAIL>] Request::ProcessHeaders() ASVersion: 14.0
31/12/2017 15:32:10 [12817] [DEBUG] [<EMAIL>] ZPush::CommandNeedsProvisioning(0): true
31/12/2017 15:32:10 [12817] [DEBUG] [<EMAIL>] FileStateMachine->GetState() read '2177' bytes from file: '/srv/www/roundcube/z-push//state/8/8/l6ks0va0ip4d7eq44vk20f3688-devicedata'
31/12/2017 15:32:10 [12817] [DEBUG] [<EMAIL>] ASDevice data loaded for user: '<EMAIL>'
31/12/2017 15:32:10 [12817] [DEBUG] [<EMAIL>] TopCollector(): Initialized mutexid Resource id #18 and memid Resource id #19.
31/12/2017 15:32:10 [12817] [DEBUG] [<EMAIL>] TopCollector initialised with IPC provider 'IpcSharedMemoryProvider' with type '20'
31/12/2017 15:32:10 [12817] [DEBUG] [<EMAIL>] LoopDetection(): Initialized mutexid Resource id #22 and memid Resource id #23.
31/12/2017 15:32:10 [12817] [DEBUG] [<EMAIL>] LoopDetection initialised with IPC provider 'IpcSharedMemoryProvider' with type '1337'
31/12/2017 15:32:10 [12817] [DEBUG] [<EMAIL>] ZPush::HierarchyCommand(0): false
31/12/2017 15:32:10 [12817] [DEBUG] [<EMAIL>] DeviceManager->ProvisioningRequired('833756154') saved device key '833756154': false
31/12/2017 15:32:10 [12817] [DEBUG] [<EMAIL>] DeviceManager->getPolicyName(): determined policy name: 'default'
31/12/2017 15:32:10 [12817] [DEBUG] [<EMAIL>] DeviceManager->getProvisioningPolicies(): loaded 'default' policy.
31/12/2017 15:32:10 [12817] [DEBUG] [<EMAIL>] ZPush::CommandNeedsAuthentication(0): true
31/12/2017 15:32:10 [12817] [DEBUG] [<EMAIL>] Combined->Logon('<EMAIL>', '',***))
31/12/2017 15:32:10 [12817] [DEBUG] [<EMAIL>] BackendIMAP->Logon(): User '<EMAIL>' is authenticated on '{localhost:143/imap/notls/norsh}'
31/12/2017 15:32:10 [12817] [DEBUG] [<EMAIL>] BackendCardDAV->Logon(): User '<EMAIL>' is authenticated on 'https://<HOST>:443/remote.php/dav/principals/users/<EMAIL>/'
31/12/2017 15:32:10 [12817] [DEBUG] [<EMAIL>] Combined->Logon() success
31/12/2017 15:32:10 [12817] [DEBUG] [<EMAIL>] ZPush::CommandNeedsPlainInput(0): false
31/12/2017 15:32:10 [12817] [WBXML] [<EMAIL>] I  <Synchronize>
31/12/2017 15:32:10 [12817] [WBXML] [<EMAIL>] I   <Folders>
31/12/2017 15:32:10 [12817] [WBXML] [<EMAIL>] I    <Folder>
31/12/2017 15:32:10 [12817] [WBXML] [<EMAIL>] I     <SyncKey>
31/12/2017 15:32:10 [12817] [WBXML] [<EMAIL>] I      {56c72c6d-e226-4db1-860f-e345dfdcfe3e}1
31/12/2017 15:32:10 [12817] [WBXML] [<EMAIL>] I     </SyncKey>
31/12/2017 15:32:10 [12817] [WBXML] [<EMAIL>] I     <FolderId>
31/12/2017 15:32:10 [12817] [WBXML] [<EMAIL>] I      d/contacts
31/12/2017 15:32:10 [12817] [WBXML] [<EMAIL>] I     </FolderId>
31/12/2017 15:32:10 [12817] [DEBUG] [<EMAIL>] FileStateMachine->GetState() read '857' bytes from file: '/srv/www/roundcube/z-push//state/8/8/l6ks0va0ip4d7eq44vk20f3688-56c72c6d-e226-4db1-860f-e345dfdcfe3e-fd'
31/12/2017 15:32:10 [12817] [DEBUG] [<EMAIL>] SyncParameters->UseCPO('DEFAULT')
31/12/2017 15:32:10 [12817] [DEBUG] [<EMAIL>] DeviceManager->GetBackendIdForFolderId(): no backend-folderid available for 'd/contacts', returning as is.
31/12/2017 15:32:10 [12817] [DEBUG] [<EMAIL>] SyncCollections->AddCollection(): Folder id 'd/contacts' : ref. PolicyKey '833756154', ref. Lifetime '', last sync at '1514731461'
31/12/2017 15:32:10 [12817] [DEBUG] [<EMAIL>] SyncCollections->AddCollection(): Updated reference PolicyKey '833756154', reference Lifetime '', Last sync at '1514731461'
31/12/2017 15:32:10 [12817] [WBXML] [<EMAIL>] I     <GetChanges/>
31/12/2017 15:32:10 [12817] [WBXML] [<EMAIL>] I     <WindowSize>
31/12/2017 15:32:10 [12817] [WBXML] [<EMAIL>] I      25
31/12/2017 15:32:10 [12817] [WBXML] [<EMAIL>] I     </WindowSize>
31/12/2017 15:32:10 [12817] [WBXML] [<EMAIL>] I     <Options>
31/12/2017 15:32:10 [12817] [WBXML] [<EMAIL>] I      <AirSyncBase:BodyPreference>
31/12/2017 15:32:10 [12817] [DEBUG] [<EMAIL>] SyncParameters->UseCPO('DEFAULT')
31/12/2017 15:32:10 [12817] [WBXML] [<EMAIL>] I       <AirSyncBase:Type>
31/12/2017 15:32:10 [12817] [WBXML] [<EMAIL>] I        1
31/12/2017 15:32:10 [12817] [WBXML] [<EMAIL>] I       </AirSyncBase:Type>
31/12/2017 15:32:10 [12817] [WBXML] [<EMAIL>] I       <AirSyncBase:TruncationSize>
31/12/2017 15:32:10 [12817] [WBXML] [<EMAIL>] I        32768
31/12/2017 15:32:10 [12817] [WBXML] [<EMAIL>] I       </AirSyncBase:TruncationSize>
31/12/2017 15:32:10 [12817] [WBXML] [<EMAIL>] I      </AirSyncBase:BodyPreference>
31/12/2017 15:32:10 [12817] [WBXML] [<EMAIL>] I     </Options>
31/12/2017 15:32:10 [12817] [WBXML] [<EMAIL>] I     <Perform>
31/12/2017 15:32:10 [12817] [WBXML] [<EMAIL>] I      <Add>
31/12/2017 15:32:10 [12817] [WBXML] [<EMAIL>] I       <ClientEntryId>
31/12/2017 15:32:10 [12817] [WBXML] [<EMAIL>] I        274
31/12/2017 15:32:10 [12817] [WBXML] [<EMAIL>] I       </ClientEntryId>
31/12/2017 15:32:10 [12817] [WBXML] [<EMAIL>] I       <Data>
31/12/2017 15:32:10 [12817] [WBXML] [<EMAIL>] I        <AirSyncBase:Body>
31/12/2017 15:32:10 [12817] [WBXML] [<EMAIL>] I         <AirSyncBase:Type>
31/12/2017 15:32:10 [12817] [WBXML] [<EMAIL>] I          1
31/12/2017 15:32:10 [12817] [WBXML] [<EMAIL>] I         </AirSyncBase:Type>
31/12/2017 15:32:10 [12817] [WBXML] [<EMAIL>] I         <AirSyncBase:Data/>
31/12/2017 15:32:10 [12817] [WBXML] [<EMAIL>] I        </AirSyncBase:Body>
31/12/2017 15:32:10 [12817] [WBXML] [<EMAIL>] I        <POOMCONTACTS:FileAs>
31/12/2017 15:32:10 [12817] [WBXML] [<EMAIL>] I         Testing
31/12/2017 15:32:10 [12817] [WBXML] [<EMAIL>] I        </POOMCONTACTS:FileAs>
31/12/2017 15:32:10 [12817] [WBXML] [<EMAIL>] I        <POOMCONTACTS:FirstName>
31/12/2017 15:32:10 [12817] [WBXML] [<EMAIL>] I         Testing
31/12/2017 15:32:10 [12817] [WBXML] [<EMAIL>] I        </POOMCONTACTS:FirstName>
31/12/2017 15:32:10 [12817] [WBXML] [<EMAIL>] I        <POOMCONTACTS:HomePhoneNumber>
31/12/2017 15:32:10 [12817] [WBXML] [<EMAIL>] I         54235
31/12/2017 15:32:10 [12817] [WBXML] [<EMAIL>] I        </POOMCONTACTS:HomePhoneNumber>
31/12/2017 15:32:10 [12817] [WBXML] [<EMAIL>] I        <POOMCONTACTS:Picture/>
31/12/2017 15:32:10 [12817] [WBXML] [<EMAIL>] I       </Data>
31/12/2017 15:32:10 [12817] [DEBUG] [<EMAIL>] Sync->getImporter(): initialize importer
31/12/2017 15:32:10 [12817] [DEBUG] [<EMAIL>] Sync->loadStates(): loading states for folder 'd/contacts'
31/12/2017 15:32:10 [12817] [DEBUG] [<EMAIL>] FileStateMachine->GetState() read '6' bytes from file: '/srv/www/roundcube/z-push//state/8/8/l6ks0va0ip4d7eq44vk20f3688-56c72c6d-e226-4db1-860f-e345dfdcfe3e-1'
31/12/2017 15:32:10 [12817] [DEBUG] [<EMAIL>] ZPush::GetAdditionalSyncFolderStore('d/contacts'): 'false'
31/12/2017 15:32:10 [12817] [DEBUG] [<EMAIL>] Combined->Setup('', 'false', '', 'false')
31/12/2017 15:32:10 [12817] [DEBUG] [<EMAIL>] Combined->Setup() success
31/12/2017 15:32:10 [12817] [DEBUG] [<EMAIL>] Combined->GetImporter() Content: ImportChangesCombined:('d/contacts')
31/12/2017 15:32:10 [12817] [DEBUG] [<EMAIL>] ImportChangesCombined->SetMoveStates()
31/12/2017 15:32:10 [12817] [DEBUG] [<EMAIL>] ImportChangesCombined->SetMoveStates() success
31/12/2017 15:32:10 [12817] [DEBUG] [<EMAIL>] ImportChangesCombined->Config(...)
31/12/2017 15:32:10 [12817] [DEBUG] [<EMAIL>] ImportChangesCombined->Config() success
31/12/2017 15:32:10 [12817] [DEBUG] [<EMAIL>] ImportChangesCombined->ConfigContentParameters()
31/12/2017 15:32:10 [12817] [DEBUG] [<EMAIL>] ImportChangesCombined->ConfigContentParameters() success
31/12/2017 15:32:10 [12817] [DEBUG] [<EMAIL>] LoopDetection->SetSyncStateUsage(): uuid: 56c72c6d-e226-4db1-860f-e345dfdcfe3e  counter: 1
31/12/2017 15:32:10 [12817] [DEBUG] [<EMAIL>] BackendCardDAV->ChangeMessage('contacts', '')
31/12/2017 15:32:10 [12817] [WARN] [<EMAIL>] /data/www/roundcube/z-push/backend/carddav/carddav.php:1265 stream_get_contents() expects parameter 1 to be resource, null given (2)
31/12/2017 15:32:10 [12817] [WBXML] [<EMAIL>] BackendCardDAV->ChangeMessage - vCard
BEGIN:VCARD
VERSION:3.0
PRODID:Z-Push
FN:Testing
N:;Testing;;;
TEL;TYPE=HOME,VOICE:54235
END:VCARD

31/12/2017 15:32:10 [12817] [DEBUG] [<EMAIL>] FileStateMachine->GetState() read '1342' bytes from file: '/srv/www/roundcube/z-push//state/8/8/l6ks0va0ip4d7eq44vk20f3688-bs-1514540826'
31/12/2017 15:32:10 [12817] [DEBUG] [<EMAIL>] BackendCardDAV::getAddressbookFromUrl('https://<HOST>:443/remote.php/dav/principals/users/<EMAIL>/') = not initialized!
31/12/2017 15:32:10 [12817] [WARN] [<EMAIL>] /data/www/roundcube/z-push/backend/carddav/carddav.php:569 Undefined offset: 0 (8)
31/12/2017 15:32:10 [12817] [DEBUG] [<EMAIL>] BackendCardDAV::getAddressbookFromUrl('') = not initialized!
31/12/2017 15:32:10 [12817] [WARN] [<EMAIL>] /data/www/roundcube/z-push/backend/carddav/carddav.php:570 Undefined offset: 0 (8)
31/12/2017 15:32:12 [ 4260] [DEBUG] [<EMAIL>] BackendCombined->ChangesSink(30)
31/12/2017 15:32:12 [ 4260] [DEBUG] [<EMAIL>] BackendCombined->ChangesSink - Calling in 'BackendIMAP' with 15
31/12/2017 15:32:13 [ 4260] [DEBUG] [<EMAIL>] BackendIMAP->close_connection(): IMAP said: SECURITY PROBLEM: insecure server advertised AUTH=PLAIN
31/12/2017 15:32:13 [ 4260] [DEBUG] [<EMAIL>] BackendIMAP->close_connection(): disconnected from IMAP server

      The issue is related to out-of-memory issues. During the last three events instances of php5-fpm were killed using around 300000 rss with PIDs: 802, 15671, 15732.
      The last two segfaulted:

      kernel: [387753.727033] php5-fpm[15671]: segfault at 7ffe6f94efe8 ip 00007f01983f52a8 sp 00007ffe6f94ef90 error 6 in libcurl.so.4.3.0[7f01983d1000+64000]
...
kernel: [387838.685031] php5-fpm[15732]: segfault at 7ffe6f94dfe0 ip 00007f01983f52ad sp 00007ffe6f94dfc0 error 6 in libcurl.so.4.3.0[7f01983d1000+64000]

      And the z-push log:

      01/01/2018 08:38:53 [  802] [WARN] [<EMAIL>] /data/www/roundcube/z-push/backend/carddav/carddav.php:1265 stream_get_contents() expects parameter 1 to be resource, null given (2)
01/01/2018 08:38:53 [  802] [WARN] [<EMAIL>] /data/www/roundcube/z-push/backend/carddav/carddav.php:569 Undefined offset: 0 (8)
01/01/2018 08:38:53 [  802] [WARN] [<EMAIL>] /data/www/roundcube/z-push/backend/carddav/carddav.php:570 Undefined offset: 0 (8)
01/01/2018 08:39:08 [15671] [WARN] [<EMAIL>] /data/www/roundcube/z-push/backend/carddav/carddav.php:1265 stream_get_contents() expects parameter 1 to be resource, null given (2)
01/01/2018 08:39:08 [15671] [WARN] [<EMAIL>] /data/www/roundcube/z-push/backend/carddav/carddav.php:569 Undefined offset: 0 (8)
01/01/2018 08:39:08 [15671] [WARN] [<EMAIL>] /data/www/roundcube/z-push/backend/carddav/carddav.php:570 Undefined offset: 0 (8)
01/01/2018 08:40:33 [15732] [WARN] [<EMAIL>] /data/www/roundcube/z-push/backend/carddav/carddav.php:1265 stream_get_contents() expects parameter 1 to be resource, null given (2)
01/01/2018 08:40:33 [15732] [WARN] [<EMAIL>] /data/www/roundcube/z-push/backend/carddav/carddav.php:569 Undefined offset: 0 (8)
01/01/2018 08:40:33 [15732] [WARN] [<EMAIL>] /data/www/roundcube/z-push/backend/carddav/carddav.php:570 Undefined offset: 0 (8)

      Running:
      PHP 5.5.9-1ubuntu4.22 (fpm-fcgi) (built: Aug 4 2017 19:44:16)
      Z-Push 2.3.8

      How to debug this further?

      1 Reply Last reply Reply Quote 0
      • First post
        Last post