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

    Exception: (WBXMLException) - Unknown error in Sync->Handle()

    General usage of Z-Push
    3
    12
    2749
    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.
    • romeor
      romeor last edited by fbartels

      Hi, getting these errors with my latest stable Z-push and Huawei P10 Lite

      07/10/2017 20:34:24 [  348] [FATAL] [roman] Exception: (WBXMLException) - Unknown error in Sync->Handle()
07/10/2017 20:34:24 [  348] [FATAL] [roman] Request could not be processed correctly due to a WBXMLException. Please report this including the 'WBXML debug data' logged. Be aware that the debug data could contain confidential information.
07/10/2017 20:35:27 [11598] [ERROR] [roman] WBXMLDecoder->getElementEndTag(): could not read end tag in '/usr/share/z-push/lib/request/sync.php:492'. Please enable the LOGLEVEL_WBXML and send the log to the Z-Push dev team.
07/10/2017 20:35:27 [11598] [FATAL] [roman] WBXMLException: Unknown error in Sync->Handle() - code: 0 - file: /usr/share/z-push/lib/request/requestprocessor.php:113
07/10/2017 20:35:27 [11598] [FATAL] [roman] WBXML 10K debug data: AwFqAEVcT0sDezkzNDczYTNlLTE0MWItNDU5Mi1hMjZiLWNkMDAyNTFiZjdlNX0yNDcAAVIDVWNlMmFhAAFeAzEAAVMDMAABVkhNA1U5NjQ2MTowNDJmN2ZjMzNiZTA0MWJiOWE2MzgyYzYxNmIzMWNhMjhkNGEwMDAwMDAwMAABXQACVQMxAAEBAQEBAQE=
      1 Reply Last reply Reply Quote 0
      • romeor
        romeor last edited by

        And here is the debug

        08/10/2017 02:03:31 [ 1875] [DEBUG] [roman] [androidc1650660868] -------- Start
08/10/2017 02:03:31 [ 1875] [DEBUG] [roman] [androidc1650660868] cmd='Ping' devType='Android' devId='androidc1650660868' getUser='roman' from='185.158.178.166' version='2.3.8+0-0' method='POST'
08/10/2017 02:03:31 [ 1875] [DEBUG] [roman] [androidc1650660868] Used timezone 'Europe/Tallinn'
08/10/2017 02:03:31 [ 1875] [DEBUG] [roman] [androidc1650660868] BackendKopano using PHP-MAPI version: 7.2.5-109 - PHP version: 5.6.30-0+deb8u1
08/10/2017 02:03:31 [ 1875] [DEBUG] [roman] [androidc1650660868] Request::ProcessHeaders() ASVersion: 14.0
08/10/2017 02:03:31 [ 1875] [DEBUG] [roman] [androidc1650660868] ZPush::CommandNeedsProvisioning(18): false
08/10/2017 02:03:31 [ 1875] [DEBUG] [roman] [androidc1650660868] ZPush::CommandNeedsAuthentication(18): true
08/10/2017 02:03:31 [ 1875] [DEBUG] [roman] [androidc1650660868] KopanoBackend->Logon(): Trying to authenticate user 'roman'..
08/10/2017 02:03:31 [ 1875] [DEBUG] [roman] [androidc1650660868] FileStateMachine->GetState() read '6160' bytes from file: '/var/lib/z-push/8/6/androidc1650660868-devicedata'
08/10/2017 02:03:31 [ 1875] [DEBUG] [roman] [androidc1650660868] ASDevice data loaded for user: 'roman'
08/10/2017 02:03:31 [ 1875] [DEBUG] [roman] [androidc1650660868] TopCollector(): Initialized mutexid Resource id #19 and memid Resource id #20.
08/10/2017 02:03:31 [ 1875] [DEBUG] [roman] [androidc1650660868] TopCollector initialised with IPC provider 'IpcSharedMemoryProvider' with type '20'
08/10/2017 02:03:31 [ 1875] [DEBUG] [roman] [androidc1650660868] LoopDetection(): Initialized mutexid Resource id #23 and memid Resource id #24.
08/10/2017 02:03:31 [ 1875] [DEBUG] [roman] [androidc1650660868] LoopDetection initialised with IPC provider 'IpcSharedMemoryProvider' with type '1337'
08/10/2017 02:03:31 [ 1875] [DEBUG] [roman] [androidc1650660868] ZPush::HierarchyCommand(18): false
08/10/2017 02:03:31 [ 1875] [DEBUG] [roman] [androidc1650660868] KopanoBackend->openMessageStore('roman'): Found 'DEFAULT' store: 'Resource id #30'
08/10/2017 02:03:31 [ 1875] [DEBUG] [roman] [androidc1650660868] KopanoBackend->Logon(): User 'roman' is authenticated
08/10/2017 02:03:31 [ 1875] [DEBUG] [roman] [androidc1650660868] Store supports properties containing Unicode characters.
08/10/2017 02:03:31 [ 1875] [DEBUG] [roman] [androidc1650660868] ZPush::CommandNeedsPlainInput(18): false
08/10/2017 02:03:31 [ 1875] [WBXML] [roman] [androidc1650660868] I  <Ping:Ping>
08/10/2017 02:03:31 [ 1875] [DEBUG] [roman] [androidc1650660868] FileStateMachine->GetState() read '1048' bytes from file: '/var/lib/z-push/8/6/androidc1650660868-f2d48d89-e29b-45b9-aa2a-06cc07ea5135-fd'
08/10/2017 02:03:31 [ 1875] [DEBUG] [roman] [androidc1650660868] SyncParameters->UseCPO('DEFAULT')
08/10/2017 02:03:31 [ 1875] [DEBUG] [roman] [androidc1650660868] ZPush::GetAdditionalSyncFolderStore('042f7fc33be041bb9a6382c616b31ca2c40200000000'): 'false'
08/10/2017 02:03:31 [ 1875] [DEBUG] [roman] [androidc1650660868] SyncCollections->AddCollection(): Folder id 'U96461' : ref. PolicyKey '608877122', ref. Lifetime '1080', last sync at '1507092233'
08/10/2017 02:03:31 [ 1875] [DEBUG] [roman] [androidc1650660868] SyncCollections->AddCollection(): Updated reference PolicyKey '608877122', reference Lifetime '1080', Last sync at '1507092233'
08/10/2017 02:03:31 [ 1875] [DEBUG] [roman] [androidc1650660868] SyncParameters->GetLatestSyncKey(): '{f2d48d89-e29b-45b9-aa2a-06cc07ea5135}262'
08/10/2017 02:03:31 [ 1875] [DEBUG] [roman] [androidc1650660868] FileStateMachine->GetState() read '15' bytes from file: '/var/lib/z-push/8/6/androidc1650660868-f2d48d89-e29b-45b9-aa2a-06cc07ea5135-262'
08/10/2017 02:03:31 [ 1875] [DEBUG] [roman] [androidc1650660868] FileStateMachine->GetState() read '1092' bytes from file: '/var/lib/z-push/8/6/androidc1650660868-93473a3e-141b-4592-a26b-cd00251bf7e5-fd'
08/10/2017 02:03:31 [ 1875] [DEBUG] [roman] [androidc1650660868] SyncParameters->UseCPO('DEFAULT')
08/10/2017 02:03:31 [ 1875] [DEBUG] [roman] [androidc1650660868] ZPush::GetAdditionalSyncFolderStore('042f7fc33be041bb9a6382c616b31ca2c60200000000'): 'false'
08/10/2017 02:03:31 [ 1875] [DEBUG] [roman] [androidc1650660868] SyncCollections->AddCollection(): Folder id 'Uce2aa' : ref. PolicyKey '608877122', ref. Lifetime '1680', last sync at '1507092232'
08/10/2017 02:03:31 [ 1875] [DEBUG] [roman] [androidc1650660868] SyncParameters->GetLatestSyncKey(): '{93473a3e-141b-4592-a26b-cd00251bf7e5}247'
08/10/2017 02:03:31 [ 1875] [DEBUG] [roman] [androidc1650660868] FileStateMachine->GetState() read '15' bytes from file: '/var/lib/z-push/8/6/androidc1650660868-93473a3e-141b-4592-a26b-cd00251bf7e5-247'
08/10/2017 02:03:31 [ 1875] [DEBUG] [roman] [androidc1650660868] FileStateMachine->GetState() read '1049' bytes from file: '/var/lib/z-push/8/6/androidc1650660868-8b411180-16bd-40c9-a171-8a06ba97f3e9-fd'
08/10/2017 02:03:31 [ 1875] [DEBUG] [roman] [androidc1650660868] SyncParameters->UseCPO('DEFAULT')
08/10/2017 02:03:31 [ 1875] [DEBUG] [roman] [androidc1650660868] ZPush::GetAdditionalSyncFolderStore('042f7fc33be041bb9a6382c616b31ca2c70200000000'): 'false'
08/10/2017 02:03:31 [ 1875] [DEBUG] [roman] [androidc1650660868] SyncCollections->AddCollection(): Folder id 'Ufa47f' : ref. PolicyKey '608877122', ref. Lifetime '1080', last sync at '1506813002'
08/10/2017 02:03:31 [ 1875] [DEBUG] [roman] [androidc1650660868] SyncParameters->GetLatestSyncKey(): '{8b411180-16bd-40c9-a171-8a06ba97f3e9}62'
08/10/2017 02:03:31 [ 1875] [DEBUG] [roman] [androidc1650660868] FileStateMachine->GetState() read '15' bytes from file: '/var/lib/z-push/8/6/androidc1650660868-8b411180-16bd-40c9-a171-8a06ba97f3e9-62'
08/10/2017 02:03:31 [ 1875] [DEBUG] [roman] [androidc1650660868] FileStateMachine->GetState() read '1031' bytes from file: '/var/lib/z-push/8/6/androidc1650660868-36631614-2cda-4724-8f28-b2c49410e4af-fd'
08/10/2017 02:03:31 [ 1875] [DEBUG] [roman] [androidc1650660868] SyncParameters->UseCPO('DEFAULT')
08/10/2017 02:03:31 [ 1875] [DEBUG] [roman] [androidc1650660868] ZPush::GetAdditionalSyncFolderStore('042f7fc33be041bb9a6382c616b31ca2c80200000000'): 'false'
08/10/2017 02:03:31 [ 1875] [DEBUG] [roman] [androidc1650660868] SyncCollections->AddCollection(): Folder id 'U9c5c8' : ref. PolicyKey '608877122', ref. Lifetime '1080', last sync at '1507390471'
08/10/2017 02:03:31 [ 1875] [DEBUG] [roman] [androidc1650660868] SyncCollections->AddCollection(): Updated reference PolicyKey '608877122', reference Lifetime '1080', Last sync at '1507390471'
08/10/2017 02:03:31 [ 1875] [DEBUG] [roman] [androidc1650660868] SyncParameters->GetLatestSyncKey(): '{36631614-2cda-4724-8f28-b2c49410e4af}129'
08/10/2017 02:03:31 [ 1875] [DEBUG] [roman] [androidc1650660868] FileStateMachine->GetState() read '15' bytes from file: '/var/lib/z-push/8/6/androidc1650660868-36631614-2cda-4724-8f28-b2c49410e4af-129'
08/10/2017 02:03:31 [ 1875] [DEBUG] [roman] [androidc1650660868] FileStateMachine->GetState() read '1030' bytes from file: '/var/lib/z-push/8/6/androidc1650660868-0d98bea4-d4d1-473b-b93b-8a2ace94fa71-fd'
08/10/2017 02:03:31 [ 1875] [DEBUG] [roman] [androidc1650660868] SyncParameters->UseCPO('DEFAULT')
08/10/2017 02:03:31 [ 1875] [DEBUG] [roman] [androidc1650660868] ZPush::GetAdditionalSyncFolderStore('042f7fc33be041bb9a6382c616b31ca2c90200000000'): 'false'
08/10/2017 02:03:31 [ 1875] [DEBUG] [roman] [androidc1650660868] SyncCollections->AddCollection(): Folder id 'U5dd25' : ref. PolicyKey '608877122', ref. Lifetime '1080', last sync at '1505611035'
08/10/2017 02:03:31 [ 1875] [DEBUG] [roman] [androidc1650660868] SyncParameters->GetLatestSyncKey(): '{0d98bea4-d4d1-473b-b93b-8a2ace94fa71}9'
08/10/2017 02:03:31 [ 1875] [DEBUG] [roman] [androidc1650660868] FileStateMachine->GetState() read '15' bytes from file: '/var/lib/z-push/8/6/androidc1650660868-0d98bea4-d4d1-473b-b93b-8a2ace94fa71-9'
08/10/2017 02:03:31 [ 1875] [DEBUG] [roman] [androidc1650660868] FileStateMachine->GetState() read '1013' bytes from file: '/var/lib/z-push/8/6/androidc1650660868-533a624a-7509-4e25-8a92-c293a2ff4047-fd'
08/10/2017 02:03:31 [ 1875] [DEBUG] [roman] [androidc1650660868] SyncParameters->UseCPO('DEFAULT')
08/10/2017 02:03:31 [ 1875] [DEBUG] [roman] [androidc1650660868] ZPush::GetAdditionalSyncFolderStore('042f7fc33be041bb9a6382c616b31ca2f20400000000'): 'false'
08/10/2017 02:03:31 [ 1875] [DEBUG] [roman] [androidc1650660868] SyncCollections->AddCollection(): Folder id 'U954ad' : ref. PolicyKey '608877122', ref. Lifetime '', last sync at '1506955812'
08/10/2017 02:03:31 [ 1875] [DEBUG] [roman] [androidc1650660868] SyncParameters->GetLatestSyncKey(): '{533a624a-7509-4e25-8a92-c293a2ff4047}1'
08/10/2017 02:03:31 [ 1875] [DEBUG] [roman] [androidc1650660868] FileStateMachine->GetState() read '15' bytes from file: '/var/lib/z-push/8/6/androidc1650660868-533a624a-7509-4e25-8a92-c293a2ff4047-1'
08/10/2017 02:03:31 [ 1875] [DEBUG] [roman] [androidc1650660868] FileStateMachine->GetState() read '1020' bytes from file: '/var/lib/z-push/8/6/androidc1650660868-a49b2115-4bbd-49cf-9676-155043942453-fd'
08/10/2017 02:03:31 [ 1875] [DEBUG] [roman] [androidc1650660868] SyncParameters->UseCPO('DEFAULT')
08/10/2017 02:03:31 [ 1875] [DEBUG] [roman] [androidc1650660868] ZPush::GetAdditionalSyncFolderStore('042f7fc33be041bb9a6382c616b31ca2584300000000'): 'false'
08/10/2017 02:03:31 [ 1875] [DEBUG] [roman] [androidc1650660868] SyncCollections->AddCollection(): Folder id 'U518ac' : ref. PolicyKey '608877122', ref. Lifetime '1680', last sync at '1501516454'
08/10/2017 02:03:31 [ 1875] [DEBUG] [roman] [androidc1650660868] SyncParameters->GetLatestSyncKey(): '{a49b2115-4bbd-49cf-9676-155043942453}3'
08/10/2017 02:03:31 [ 1875] [DEBUG] [roman] [androidc1650660868] FileStateMachine->GetState() read '15' bytes from file: '/var/lib/z-push/8/6/androidc1650660868-a49b2115-4bbd-49cf-9676-155043942453-3'
08/10/2017 02:03:31 [ 1875] [DEBUG] [roman] [androidc1650660868] FileStateMachine->GetState() read '379' bytes from file: '/var/lib/z-push/8/6/androidc1650660868-6b7a58e3-41d6-4b5e-a2b4-558fc101f86a-fd'
08/10/2017 02:03:31 [ 1875] [DEBUG] [roman] [androidc1650660868] SyncParameters->UseCPO('DEFAULT')
08/10/2017 02:03:31 [ 1875] [DEBUG] [roman] [androidc1650660868] SyncCollections->AddCollection(): Folder id '' : ref. PolicyKey '608877122', ref. Lifetime '10', last sync at '1507011143'
08/10/2017 02:03:31 [ 1875] [DEBUG] [roman] [androidc1650660868] SyncParameters->GetLatestSyncKey(): '{6b7a58e3-41d6-4b5e-a2b4-558fc101f86a}3'
08/10/2017 02:03:31 [ 1875] [DEBUG] [roman] [androidc1650660868] StateManager->loadHierarchyCache(): 'androidc1650660868-6b7a58e3-41d6-4b5e-a2b4-558fc101f86a-hc-3'
08/10/2017 02:03:31 [ 1875] [DEBUG] [roman] [androidc1650660868] FileStateMachine->GetState() read '9708' bytes from file: '/var/lib/z-push/8/6/androidc1650660868-6b7a58e3-41d6-4b5e-a2b4-558fc101f86a-hc-3'
08/10/2017 02:03:31 [ 1875] [DEBUG] [roman] [androidc1650660868] FileStateMachine->GetState() read '15' bytes from file: '/var/lib/z-push/8/6/androidc1650660868-6b7a58e3-41d6-4b5e-a2b4-558fc101f86a-3'
08/10/2017 02:03:31 [ 1875] [DEBUG] [roman] [androidc1650660868] HandlePing(): reference PolicyKey for PING: 608877122
08/10/2017 02:03:31 [ 1875] [DEBUG] [roman] [androidc1650660868] HandlePing(): initialization data received
08/10/2017 02:03:31 [ 1875] [WBXML] [roman] [androidc1650660868] I   <Ping:LifeTime>
08/10/2017 02:03:31 [ 1875] [WBXML] [roman] [androidc1650660868] I    480
08/10/2017 02:03:31 [ 1875] [WBXML] [roman] [androidc1650660868] I   </Ping:LifeTime>
08/10/2017 02:03:31 [ 1875] [WBXML] [roman] [androidc1650660868] I   <Ping:Folders>
08/10/2017 02:03:31 [ 1875] [WBXML] [roman] [androidc1650660868] I    <Ping:Folder>
08/10/2017 02:03:31 [ 1875] [WBXML] [roman] [androidc1650660868] I     <Ping:ServerEntryId>
08/10/2017 02:03:31 [ 1875] [WBXML] [roman] [androidc1650660868] I      U96461
08/10/2017 02:03:31 [ 1875] [WBXML] [roman] [androidc1650660868] I     </Ping:ServerEntryId>
08/10/2017 02:03:31 [ 1875] [WBXML] [roman] [androidc1650660868] I     <Ping:FolderType>
08/10/2017 02:03:31 [ 1875] [WBXML] [roman] [androidc1650660868] I      Email
08/10/2017 02:03:31 [ 1875] [WBXML] [roman] [androidc1650660868] I     </Ping:FolderType>
08/10/2017 02:03:31 [ 1875] [WBXML] [roman] [androidc1650660868] I    </Ping:Folder>
08/10/2017 02:03:31 [ 1875] [DEBUG] [roman] [androidc1650660868] HandlePing(): using saved sync state for 'Email' id 'U96461'
08/10/2017 02:03:31 [ 1875] [WBXML] [roman] [androidc1650660868] I    <Ping:Folder>
08/10/2017 02:03:31 [ 1875] [WBXML] [roman] [androidc1650660868] I     <Ping:ServerEntryId>
08/10/2017 02:03:31 [ 1875] [WBXML] [roman] [androidc1650660868] I      Ufa47f
08/10/2017 02:03:31 [ 1875] [WBXML] [roman] [androidc1650660868] I     </Ping:ServerEntryId>
08/10/2017 02:03:31 [ 1875] [WBXML] [roman] [androidc1650660868] I     <Ping:FolderType>
08/10/2017 02:03:31 [ 1875] [WBXML] [roman] [androidc1650660868] I      Email
08/10/2017 02:03:31 [ 1875] [WBXML] [roman] [androidc1650660868] I     </Ping:FolderType>
08/10/2017 02:03:31 [ 1875] [WBXML] [roman] [androidc1650660868] I    </Ping:Folder>
08/10/2017 02:03:31 [ 1875] [DEBUG] [roman] [androidc1650660868] HandlePing(): using saved sync state for 'Email' id 'Ufa47f'
08/10/2017 02:03:31 [ 1875] [WBXML] [roman] [androidc1650660868] I    <Ping:Folder>
08/10/2017 02:03:31 [ 1875] [WBXML] [roman] [androidc1650660868] I     <Ping:ServerEntryId>
08/10/2017 02:03:31 [ 1875] [WBXML] [roman] [androidc1650660868] I      U9c5c8
08/10/2017 02:03:31 [ 1875] [WBXML] [roman] [androidc1650660868] I     </Ping:ServerEntryId>
08/10/2017 02:03:31 [ 1875] [WBXML] [roman] [androidc1650660868] I     <Ping:FolderType>
08/10/2017 02:03:31 [ 1875] [WBXML] [roman] [androidc1650660868] I      Contacts
08/10/2017 02:03:31 [ 1875] [WBXML] [roman] [androidc1650660868] I     </Ping:FolderType>
08/10/2017 02:03:31 [ 1875] [WBXML] [roman] [androidc1650660868] I    </Ping:Folder>
08/10/2017 02:03:31 [ 1875] [DEBUG] [roman] [androidc1650660868] HandlePing(): using saved sync state for 'Contacts' id 'U9c5c8'
08/10/2017 02:03:31 [ 1875] [WBXML] [roman] [androidc1650660868] I    <Ping:Folder>
08/10/2017 02:03:31 [ 1875] [WBXML] [roman] [androidc1650660868] I     <Ping:ServerEntryId>
08/10/2017 02:03:31 [ 1875] [WBXML] [roman] [androidc1650660868] I      U5dd25
08/10/2017 02:03:31 [ 1875] [WBXML] [roman] [androidc1650660868] I     </Ping:ServerEntryId>
08/10/2017 02:03:31 [ 1875] [WBXML] [roman] [androidc1650660868] I     <Ping:FolderType>
08/10/2017 02:03:31 [ 1875] [WBXML] [roman] [androidc1650660868] I      Calendar
08/10/2017 02:03:31 [ 1875] [WBXML] [roman] [androidc1650660868] I     </Ping:FolderType>
08/10/2017 02:03:31 [ 1875] [WBXML] [roman] [androidc1650660868] I    </Ping:Folder>
08/10/2017 02:03:31 [ 1875] [DEBUG] [roman] [androidc1650660868] HandlePing(): using saved sync state for 'Calendar' id 'U5dd25'
08/10/2017 02:03:31 [ 1875] [WBXML] [roman] [androidc1650660868] I   </Ping:Folders>
08/10/2017 02:03:31 [ 1875] [WBXMLSTACK] [roman] [androidc1650660868] WBXMLDecoder->getElementStartTag(): unmatched WBXML tag: 'Ping:Folder' matching '' type '2' flags ''
08/10/2017 02:03:31 [ 1875] [WBXML] [roman] [androidc1650660868] I  </Ping:Ping>
08/10/2017 02:03:31 [ 1875] [DEBUG] [roman] [androidc1650660868] DeviceManager->DoAutomaticASDeviceSaving(): save automatically: false
08/10/2017 02:03:31 [ 1875] [DEBUG] [roman] [androidc1650660868] PingTracking(): Initialized mutexid Resource id #152 and memid Resource id #153.
08/10/2017 02:03:31 [ 1875] [DEBUG] [roman] [androidc1650660868] PingTracking initialised with IPC provider 'IpcSharedMemoryProvider' with type '2'
08/10/2017 02:03:31 [ 1875] [DEBUG] [roman] [androidc1650660868] Announce process as PUSH connection
08/10/2017 02:03:31 [ 1875] [ INFO] [roman] [androidc1650660868] SyncCollections->CheckForChanges(): Waiting for store changes... (lifetime 480 seconds)
08/10/2017 02:03:31 [ 1875] [DEBUG] [roman] [androidc1650660868] KopanoBackend->HasChangesSink(): created - HierarchyHash: 8fe2e012f80673fcb30f4a2174c791b5
08/10/2017 02:03:31 [ 1875] [DEBUG] [roman] [androidc1650660868] KopanoBackend->adviseStoreToSink(): advised store 'Resource id #30'
08/10/2017 02:03:31 [ 1875] [DEBUG] [roman] [androidc1650660868] ZPush::GetAdditionalSyncFolderStore('042f7fc33be041bb9a6382c616b31ca2c40200000000'): 'false'
08/10/2017 02:03:31 [ 1875] [DEBUG] [roman] [androidc1650660868] KopanoBackend->ChangesSinkInitialize(): folderid '042f7fc33be041bb9a6382c616b31ca2c40200000000'
08/10/2017 02:03:31 [ 1875] [DEBUG] [roman] [androidc1650660868] KopanoBackend->GetFolderStat() fetched status information of 51 folders for store 'roman'
08/10/2017 02:03:31 [ 1875] [DEBUG] [roman] [androidc1650660868] SyncParameters->IsExporterRunRequired(): true - current: 1507397716/117/0/28 - saved: 1507092231/113/1/26 - expiring: 2017-10-10 21:17:52
08/10/2017 02:03:31 [ 1875] [DEBUG] [roman] [androidc1650660868] ZPush::GetAdditionalSyncFolderStore('042f7fc33be041bb9a6382c616b31ca2c70200000000'): 'false'
08/10/2017 02:03:31 [ 1875] [DEBUG] [roman] [androidc1650660868] SyncParameters->IsExporterRunRequired(): true - current: 1507283887/1041/0/0 - saved: 1506813000/1037/0/0 - expiring: 2017-10-07 18:20:39
08/10/2017 02:03:31 [ 1875] [DEBUG] [roman] [androidc1650660868] ZPush::GetAdditionalSyncFolderStore('042f7fc33be041bb9a6382c616b31ca2c80200000000'): 'false'
08/10/2017 02:03:31 [ 1875] [DEBUG] [roman] [androidc1650660868] SyncParameters->IsExporterRunRequired(): false - current: 1507390470/217/0/0 - saved: 1507390470/217/0/0 - expiring: 2017-11-07 14:05:49
08/10/2017 02:03:31 [ 1875] [DEBUG] [roman] [androidc1650660868] ZPush::GetAdditionalSyncFolderStore('042f7fc33be041bb9a6382c616b31ca2c90200000000'): 'false'
08/10/2017 02:03:31 [ 1875] [DEBUG] [roman] [androidc1650660868] SyncParameters->IsExporterRunRequired(): false - current: 1505611034/45/0/0 - saved: 1505611034/45/0/0 - expiring: 2017-10-15 21:12:39
08/10/2017 02:03:31 [ 1875] [DEBUG] [roman] [androidc1650660868] SyncCollections->CheckForChanges(): Using ChangesSink but found changes verifying the folder stats
08/10/2017 02:03:31 [ 1875] [DEBUG] [roman] [androidc1650660868] WBXMLEncoder->startWBXML() type: vnd.ms-sync.wbxml
08/10/2017 02:03:31 [ 1875] [WBXML] [roman] [androidc1650660868] O  <Ping:Ping>
08/10/2017 02:03:31 [ 1875] [WBXML] [roman] [androidc1650660868] O   <Ping:Status>
08/10/2017 02:03:31 [ 1875] [WBXML] [roman] [androidc1650660868] O   2
08/10/2017 02:03:31 [ 1875] [WBXML] [roman] [androidc1650660868] O   </Ping:Status>
08/10/2017 02:03:31 [ 1875] [WBXML] [roman] [androidc1650660868] O   <Ping:Folders>
08/10/2017 02:03:31 [ 1875] [WBXML] [roman] [androidc1650660868] O    <Ping:Folder>
08/10/2017 02:03:31 [ 1875] [WBXML] [roman] [androidc1650660868] O    U96461
08/10/2017 02:03:31 [ 1875] [WBXML] [roman] [androidc1650660868] O    </Ping:Folder>
08/10/2017 02:03:31 [ 1875] [DEBUG] [roman] [androidc1650660868] LoopDetection->ProcessLoopDetectionAddStatus: 'U96461' with status 2
08/10/2017 02:03:31 [ 1875] [WBXML] [roman] [androidc1650660868] O    <Ping:Folder>
08/10/2017 02:03:31 [ 1875] [WBXML] [roman] [androidc1650660868] O    Ufa47f
08/10/2017 02:03:31 [ 1875] [WBXML] [roman] [androidc1650660868] O    </Ping:Folder>
08/10/2017 02:03:31 [ 1875] [DEBUG] [roman] [androidc1650660868] LoopDetection->ProcessLoopDetectionAddStatus: 'Ufa47f' with status 2
08/10/2017 02:03:31 [ 1875] [WBXML] [roman] [androidc1650660868] O   </Ping:Folders>
08/10/2017 02:03:31 [ 1875] [WBXML] [roman] [androidc1650660868] O  </Ping:Ping>
08/10/2017 02:03:31 [ 1875] [DEBUG] [roman] [androidc1650660868] WBXMLEncoder->endTag() WBXML output completed
08/10/2017 02:03:31 [ 1875] [WBXML] [roman] [androidc1650660868] WBXML-OUT: AwFqAAANRUcDMgABSUoDVTk2NDYxAAFKA1VmYTQ3ZgABAQE=
08/10/2017 02:03:31 [ 1875] [WBXML] [roman] [androidc1650660868] WBXML-IN : AwFqAAANRUgDNDgwAAFJSksDVTk2NDYxAAFMA0VtYWlsAAEBSksDVWZhNDdmAAFMA0VtYWlsAAEBSksDVTljNWM4AAFMA0NvbnRhY3RzAAEBSksDVTVkZDI1AAFMA0NhbGVuZGFyAAEBAQE=
08/10/2017 02:03:31 [ 1875] [DEBUG] [roman] [androidc1650660868] LoopDetection->ProcessLoopDetectionTerminate()
08/10/2017 02:03:31 [ 1875] [ INFO] [roman] [androidc1650660868] cmd='Ping' memory='2.77 MiB/3.25 MiB' time='0.23s' devType='Android' devId='androidc1650660868' getUser='roman' from='185.158.178.166' idle='0s' version='2.3.8+0-0' method='POST' httpcode='200'
08/10/2017 02:03:31 [ 1875] [DEBUG] [roman] [androidc1650660868] -------- End
        1 Reply Last reply Reply Quote 0
        • romeor
          romeor last edited by

          And should I change my password after I’ve published my debug?

          1 Reply Last reply Reply Quote 0
          • Manfred
            Manfred Kopano last edited by

            Hi romeor,

            I don’t see anything wrong in WBXML debug data you posted in the initial post. There are two different requests (pid 348 and 11598). Is this the complete error log?

            The 2nd post is not helpful for us because it’s for a ‘Ping’ command and not for a ‘Sync’ command which was causing the issues.

            Is it a new installation or an update? Have you installed using the repositories or the tar archive?

            @romeor said in Exception: (WBXMLException) - Unknown error in Sync->Handle():

            And should I change my password after I’ve published my debug?

            Z-Push doesn’t output the password to the logs.

            Manfred

            1 Reply Last reply Reply Quote 0
            • romeor
              romeor last edited by romeor

              Thanks for the answer. It suddenly started to work again. I will come back, when I see same problem again. When this happens my phone is unable to sync.

              1 Reply Last reply Reply Quote 0
              • romeor
                romeor last edited by romeor

                Well, here it comes again:

                10/10/2017 11:42:31 [27691] [DEBUG] [roman] [androidc1650660868] -------- Start
10/10/2017 11:42:31 [27691] [DEBUG] [roman] [androidc1650660868] cmd='Sync' devType='Android' devId='androidc1650660868' getUser='roman' from='37.157.96.39' version='2.3.8+0-0' method='POST'
10/10/2017 11:42:31 [27691] [DEBUG] [roman] [androidc1650660868] Used timezone 'Europe/Tallinn'
10/10/2017 11:42:31 [27691] [DEBUG] [roman] [androidc1650660868] BackendKopano using PHP-MAPI version: 7.2.5-109 - PHP version: 5.6.30-0+deb8u1
10/10/2017 11:42:31 [27691] [DEBUG] [roman] [androidc1650660868] Request::ProcessHeaders() ASVersion: 14.0
10/10/2017 11:42:31 [27691] [DEBUG] [roman] [androidc1650660868] ZPush::CommandNeedsProvisioning(0): true
10/10/2017 11:42:31 [27691] [DEBUG] [roman] [androidc1650660868] FileStateMachine->GetState() read '6160' bytes from file: '/var/lib/z-push/8/6/androidc1650660868-devicedata'
10/10/2017 11:42:31 [27691] [DEBUG] [roman] [androidc1650660868] ASDevice data loaded for user: 'roman'
10/10/2017 11:42:31 [27691] [DEBUG] [roman] [androidc1650660868] TopCollector(): Initialized mutexid Resource id #55 and memid Resource id #56.
10/10/2017 11:42:31 [27691] [DEBUG] [roman] [androidc1650660868] TopCollector initialised with IPC provider 'IpcSharedMemoryProvider' with type '20'
10/10/2017 11:42:31 [27691] [DEBUG] [roman] [androidc1650660868] LoopDetection(): Initialized mutexid Resource id #60 and memid Resource id #61.
10/10/2017 11:42:31 [27691] [DEBUG] [roman] [androidc1650660868] LoopDetection initialised with IPC provider 'IpcSharedMemoryProvider' with type '1337'
10/10/2017 11:42:31 [27691] [DEBUG] [roman] [androidc1650660868] ZPush::HierarchyCommand(0): false
10/10/2017 11:42:31 [27691] [DEBUG] [roman] [androidc1650660868] DeviceManager->ProvisioningRequired('608877122') saved device key '608877122': false
10/10/2017 11:42:31 [27691] [DEBUG] [roman] [androidc1650660868] DeviceManager->getPolicyName(): determined policy name: 'default'
10/10/2017 11:42:31 [27691] [DEBUG] [roman] [androidc1650660868] DeviceManager->getProvisioningPolicies(): loaded 'default' policy.
10/10/2017 11:42:31 [27691] [DEBUG] [roman] [androidc1650660868] ZPush::CommandNeedsAuthentication(0): true
10/10/2017 11:42:31 [27691] [DEBUG] [roman] [androidc1650660868] KopanoBackend->Logon(): Trying to authenticate user 'roman'..
10/10/2017 11:42:31 [27691] [DEBUG] [roman] [androidc1650660868] KopanoBackend->openMessageStore('roman'): Found 'DEFAULT' store: 'Resource id #76'
10/10/2017 11:42:31 [27691] [DEBUG] [roman] [androidc1650660868] KopanoBackend->Logon(): User 'roman' is authenticated
10/10/2017 11:42:31 [27691] [DEBUG] [roman] [androidc1650660868] Store supports properties containing Unicode characters.
10/10/2017 11:42:31 [27691] [DEBUG] [roman] [androidc1650660868] ZPush::CommandNeedsPlainInput(0): false
10/10/2017 11:42:31 [27691] [WBXML] [roman] [androidc1650660868] I  <Synchronize>
10/10/2017 11:42:31 [27691] [WBXML] [roman] [androidc1650660868] I   <Folders>
10/10/2017 11:42:31 [27691] [WBXMLSTACK] [roman] [androidc1650660868] WBXMLDecoder->getElementStartTag(): unmatched WBXML tag: 'Version' matching 'Folders' type '1' flags '1'
10/10/2017 11:42:31 [27691] [WBXML] [roman] [androidc1650660868] I    <Folder>
10/10/2017 11:42:31 [27691] [WBXML] [roman] [androidc1650660868] I     <SyncKey>
10/10/2017 11:42:31 [27691] [WBXMLSTACK] [roman] [androidc1650660868] WBXMLDecoder->getElementStartTag(): unmatched WBXML tag: 'FolderType' matching 'SyncKey' type '1' flags '1'
10/10/2017 11:42:31 [27691] [WBXML] [roman] [androidc1650660868] I      {93473a3e-141b-4592-a26b-cd00251bf7e5}363
10/10/2017 11:42:31 [27691] [WBXML] [roman] [androidc1650660868] I     </SyncKey>
10/10/2017 11:42:31 [27691] [WBXML] [roman] [androidc1650660868] I     <FolderId>
10/10/2017 11:42:31 [27691] [WBXML] [roman] [androidc1650660868] I      Uce2aa
10/10/2017 11:42:31 [27691] [WBXML] [roman] [androidc1650660868] I     </FolderId>
10/10/2017 11:42:31 [27691] [DEBUG] [roman] [androidc1650660868] FileStateMachine->GetState() read '1092' bytes from file: '/var/lib/z-push/8/6/androidc1650660868-93473a3e-141b-4592-a26b-cd00251bf7e5-fd'
10/10/2017 11:42:31 [27691] [DEBUG] [roman] [androidc1650660868] SyncParameters->UseCPO('DEFAULT')
10/10/2017 11:42:31 [27691] [DEBUG] [roman] [androidc1650660868] DeviceManager->GetBackendIdForFolderId(): folderid Uce2aa => 042f7fc33be041bb9a6382c616b31ca2c60200000000
10/10/2017 11:42:31 [27691] [DEBUG] [roman] [androidc1650660868] SyncCollections->AddCollection(): Folder id 'Uce2aa' : ref. PolicyKey '608877122', ref. Lifetime '1380', last sync at '1507624065'
10/10/2017 11:42:31 [27691] [DEBUG] [roman] [androidc1650660868] SyncCollections->AddCollection(): Updated reference PolicyKey '608877122', reference Lifetime '1380', Last sync at '1507624065'
10/10/2017 11:42:31 [27691] [WBXML] [roman] [androidc1650660868] I     <DeletesAsMoves>
10/10/2017 11:42:31 [27691] [WBXMLSTACK] [roman] [androidc1650660868] WBXMLDecoder->getElementStartTag(): unmatched WBXML tag: 'Supported' matching 'DeletesAsMoves' type '1' flags '1'
10/10/2017 11:42:31 [27691] [WBXML] [roman] [androidc1650660868] I      1
10/10/2017 11:42:31 [27691] [WBXML] [roman] [androidc1650660868] I     </DeletesAsMoves>
10/10/2017 11:42:31 [27691] [WBXML] [roman] [androidc1650660868] I     <GetChanges>
10/10/2017 11:42:31 [27691] [WBXML] [roman] [androidc1650660868] I      0
10/10/2017 11:42:31 [27691] [WBXML] [roman] [androidc1650660868] I     </GetChanges>
10/10/2017 11:42:31 [27691] [WBXML] [roman] [androidc1650660868] I     <Perform>
10/10/2017 11:42:31 [27691] [WBXMLSTACK] [roman] [androidc1650660868] WBXMLDecoder->getElementStartTag(): unmatched WBXML tag: 'WindowSize' matching 'Perform' type '1' flags '1'
10/10/2017 11:42:31 [27691] [WBXMLSTACK] [roman] [androidc1650660868] WBXMLDecoder->getElementStartTag(): unmatched WBXML tag: 'ConversationMode' matching 'Perform' type '1' flags '1'
10/10/2017 11:42:31 [27691] [WBXMLSTACK] [roman] [androidc1650660868] WBXMLDecoder->getElementStartTag(): unmatched WBXML tag: 'Options' matching 'Perform' type '1' flags '1'
10/10/2017 11:42:31 [27691] [WBXML] [roman] [androidc1650660868] I      <Modify>
10/10/2017 11:42:31 [27691] [WBXML] [roman] [androidc1650660868] I       <ServerEntryId>
10/10/2017 11:42:31 [27691] [WBXMLSTACK] [roman] [androidc1650660868] WBXMLDecoder->getElementStartTag(): unmatched WBXML tag: 'FolderType' matching 'ServerEntryId' type '1' flags '1'
10/10/2017 11:42:31 [27691] [WBXML] [roman] [androidc1650660868] I        U96461:042f7fc33be041bb9a6382c616b31ca2ff4a00000000
10/10/2017 11:42:31 [27691] [WBXML] [roman] [androidc1650660868] I       </ServerEntryId>
10/10/2017 11:42:31 [27691] [WBXML] [roman] [androidc1650660868] I       <Data>
10/10/2017 11:42:31 [27691] [WBXMLSTACK] [roman] [androidc1650660868] WBXMLDecoder->getElementStartTag(): unmatched WBXML tag: 'ClientEntryId' matching 'Data' type '1' flags '1'
10/10/2017 11:42:31 [27691] [WBXML] [roman] [androidc1650660868] I        <POOMMAIL:Read>
10/10/2017 11:42:31 [27691] [WBXMLSTACK] [roman] [androidc1650660868] Tag 'POOMMAIL:Read' unexpected in type XML type 'SyncContact'
10/10/2017 11:42:31 [27691] [WBXML] [roman] [androidc1650660868] I         1
10/10/2017 11:42:31 [27691] [WBXMLSTACK] [roman] [androidc1650660868] WBXMLDecoder->getElementEndTag(): unmatched WBXML tag: '' type '3' flags ''
10/10/2017 11:42:31 [27691] [ERROR] [roman] [androidc1650660868] WBXMLDecoder->getElementEndTag(): could not read end tag in '/usr/share/z-push/lib/request/sync.php:492'. Please enable the LOGLEVEL_WBXML and send the log to the Z-Push dev team.
10/10/2017 11:42:31 [27691] [WBXML] [roman] [androidc1650660868] I        </POOMMAIL:Read>
10/10/2017 11:42:31 [27691] [WBXML] [roman] [androidc1650660868] I       </Data>
10/10/2017 11:42:31 [27691] [WBXML] [roman] [androidc1650660868] I      </Modify>
10/10/2017 11:42:31 [27691] [WBXML] [roman] [androidc1650660868] I     </Perform>
10/10/2017 11:42:31 [27691] [WBXML] [roman] [androidc1650660868] I    </Folder>
10/10/2017 11:42:31 [27691] [WBXML] [roman] [androidc1650660868] I   </Folders>
10/10/2017 11:42:31 [27691] [WBXML] [roman] [androidc1650660868] I  </Synchronize>
10/10/2017 11:42:31 [27691] [FATAL] [roman] [androidc1650660868] WBXMLException: Unknown error in Sync->Handle() - code: 0 - file: /usr/share/z-push/lib/request/requestprocessor.php:113
10/10/2017 11:42:31 [27691] [FATAL] [roman] [androidc1650660868] WBXML 10K debug data: AwFqAEVcT0sDezkzNDczYTNlLTE0MWItNDU5Mi1hMjZiLWNkMDAyNTFiZjdlNX0zNjMAAVIDVWNlMmFhAAFeAzEAAVMDMAABVkhNA1U5NjQ2MTowNDJmN2ZjMzNiZTA0MWJiOWE2MzgyYzYxNmIzMWNhMmZmNGEwMDAwMDAwMAABXQACVQMxAAEBAQEBAQE=
10/10/2017 11:42:31 [27691] [ INFO] [roman] [androidc1650660868] User-agent: 'Android/7.0-EAS-2.0'
10/10/2017 11:42:31 [27691] [FATAL] [roman] [androidc1650660868] Exception: (WBXMLException) - Unknown error in Sync->Handle()
10/10/2017 11:42:31 [27691] [FATAL] [roman] [androidc1650660868] Request could not be processed correctly due to a WBXMLException. Please report this including the 'WBXML debug data' logged. Be aware that the debug data could contain confidential information.
10/10/2017 11:42:31 [27691] [DEBUG] [roman] [androidc1650660868] LoopDetection->ProcessLoopDetectionTerminate()
10/10/2017 11:42:31 [27691] [ INFO] [roman] [androidc1650660868] cmd='Sync' memory='3.14 MiB/4.50 MiB' time='0.26s' devType='Android' devId='androidc1650660868' getUser='roman' from='37.157.96.39' idle='0s' version='2.3.8+0-0' method='POST' httpcode='500'
10/10/2017 11:42:31 [27691] [DEBUG] [roman] [androidc1650660868] -------- End
10/10/2017 11:42:32 [27692] [DEBUG] [roman] [androidc1650660868] -------- Start
10/10/2017 11:42:32 [27692] [DEBUG] [roman] [androidc1650660868] cmd='Sync' devType='Android' devId='androidc1650660868' getUser='roman' from='37.157.96.39' version='2.3.8+0-0' method='POST'
10/10/2017 11:42:32 [27692] [DEBUG] [roman] [androidc1650660868] Used timezone 'Europe/Tallinn'
10/10/2017 11:42:32 [27692] [DEBUG] [roman] [androidc1650660868] BackendKopano using PHP-MAPI version: 7.2.5-109 - PHP version: 5.6.30-0+deb8u1
10/10/2017 11:42:32 [27692] [DEBUG] [roman] [androidc1650660868] Request::ProcessHeaders() ASVersion: 14.0
10/10/2017 11:42:32 [27692] [DEBUG] [roman] [androidc1650660868] ZPush::CommandNeedsProvisioning(0): true
10/10/2017 11:42:32 [27692] [DEBUG] [roman] [androidc1650660868] FileStateMachine->GetState() read '6160' bytes from file: '/var/lib/z-push/8/6/androidc1650660868-devicedata'
10/10/2017 11:42:32 [27692] [DEBUG] [roman] [androidc1650660868] ASDevice data loaded for user: 'roman'
10/10/2017 11:42:32 [27692] [DEBUG] [roman] [androidc1650660868] TopCollector(): Initialized mutexid Resource id #17 and memid Resource id #18.
10/10/2017 11:42:32 [27692] [DEBUG] [roman] [androidc1650660868] TopCollector initialised with IPC provider 'IpcSharedMemoryProvider' with type '20'
10/10/2017 11:42:32 [27692] [DEBUG] [roman] [androidc1650660868] LoopDetection(): Initialized mutexid Resource id #21 and memid Resource id #22.
10/10/2017 11:42:32 [27692] [DEBUG] [roman] [androidc1650660868] LoopDetection initialised with IPC provider 'IpcSharedMemoryProvider' with type '1337'
10/10/2017 11:42:32 [27692] [DEBUG] [roman] [androidc1650660868] ZPush::HierarchyCommand(0): false
10/10/2017 11:42:32 [27692] [DEBUG] [roman] [androidc1650660868] DeviceManager->ProvisioningRequired('608877122') saved device key '608877122': false
10/10/2017 11:42:32 [27692] [DEBUG] [roman] [androidc1650660868] DeviceManager->getPolicyName(): determined policy name: 'default'
10/10/2017 11:42:32 [27692] [DEBUG] [roman] [androidc1650660868] DeviceManager->getProvisioningPolicies(): loaded 'default' policy.
10/10/2017 11:42:32 [27692] [DEBUG] [roman] [androidc1650660868] ZPush::CommandNeedsAuthentication(0): true
10/10/2017 11:42:32 [27692] [DEBUG] [roman] [androidc1650660868] KopanoBackend->Logon(): Trying to authenticate user 'roman'..
10/10/2017 11:42:32 [27692] [DEBUG] [roman] [androidc1650660868] KopanoBackend->openMessageStore('roman'): Found 'DEFAULT' store: 'Resource id #33'
10/10/2017 11:42:32 [27692] [DEBUG] [roman] [androidc1650660868] KopanoBackend->Logon(): User 'roman' is authenticated
10/10/2017 11:42:32 [27692] [DEBUG] [roman] [androidc1650660868] Store supports properties containing Unicode characters.
10/10/2017 11:42:32 [27692] [DEBUG] [roman] [androidc1650660868] ZPush::CommandNeedsPlainInput(0): false
10/10/2017 11:42:32 [27692] [WBXML] [roman] [androidc1650660868] I  <Synchronize>
10/10/2017 11:42:32 [27692] [WBXML] [roman] [androidc1650660868] I   <Folders>
10/10/2017 11:42:32 [27692] [WBXMLSTACK] [roman] [androidc1650660868] WBXMLDecoder->getElementStartTag(): unmatched WBXML tag: 'Version' matching 'Folders' type '1' flags '1'
10/10/2017 11:42:32 [27692] [WBXML] [roman] [androidc1650660868] I    <Folder>
10/10/2017 11:42:32 [27692] [WBXML] [roman] [androidc1650660868] I     <SyncKey>
10/10/2017 11:42:32 [27692] [WBXMLSTACK] [roman] [androidc1650660868] WBXMLDecoder->getElementStartTag(): unmatched WBXML tag: 'FolderType' matching 'SyncKey' type '1' flags '1'
10/10/2017 11:42:32 [27692] [WBXML] [roman] [androidc1650660868] I      {0d98bea4-d4d1-473b-b93b-8a2ace94fa71}9
10/10/2017 11:42:32 [27692] [WBXML] [roman] [androidc1650660868] I     </SyncKey>
10/10/2017 11:42:32 [27692] [WBXML] [roman] [androidc1650660868] I     <FolderId>
10/10/2017 11:42:32 [27692] [WBXML] [roman] [androidc1650660868] I      U5dd25
10/10/2017 11:42:32 [27692] [WBXML] [roman] [androidc1650660868] I     </FolderId>
10/10/2017 11:42:32 [27692] [DEBUG] [roman] [androidc1650660868] FileStateMachine->GetState() read '1030' bytes from file: '/var/lib/z-push/8/6/androidc1650660868-0d98bea4-d4d1-473b-b93b-8a2ace94fa71-fd'
10/10/2017 11:42:32 [27692] [DEBUG] [roman] [androidc1650660868] SyncParameters->UseCPO('DEFAULT')
10/10/2017 11:42:32 [27692] [DEBUG] [roman] [androidc1650660868] DeviceManager->GetBackendIdForFolderId(): folderid U5dd25 => 042f7fc33be041bb9a6382c616b31ca2c90200000000
10/10/2017 11:42:32 [27692] [DEBUG] [roman] [androidc1650660868] SyncCollections->AddCollection(): Folder id 'U5dd25' : ref. PolicyKey '608877122', ref. Lifetime '1080', last sync at '1505611035'
10/10/2017 11:42:32 [27692] [DEBUG] [roman] [androidc1650660868] SyncCollections->AddCollection(): Updated reference PolicyKey '608877122', reference Lifetime '1080', Last sync at '1505611035'
10/10/2017 11:42:32 [27692] [WBXML] [roman] [androidc1650660868] I     <DeletesAsMoves/>
10/10/2017 11:42:32 [27692] [WBXMLSTACK] [roman] [androidc1650660868] WBXMLDecoder->getElementStartTag(): unmatched WBXML tag: 'Supported' matching 'DeletesAsMoves' type '1' flags '0'
10/10/2017 11:42:32 [27692] [WBXML] [roman] [androidc1650660868] I     <GetChanges/>
10/10/2017 11:42:32 [27692] [WBXMLSTACK] [roman] [androidc1650660868] WBXMLDecoder->getElementContent(): unmatched WBXML content: 'GetChanges' type '1' flags '0'
10/10/2017 11:42:32 [27692] [WBXML] [roman] [androidc1650660868] I     <WindowSize>
10/10/2017 11:42:32 [27692] [WBXMLSTACK] [roman] [androidc1650660868] WBXMLDecoder->getElementContent(): unmatched WBXML content: 'WindowSize' type '1' flags '1'
10/10/2017 11:42:32 [27692] [WBXML] [roman] [androidc1650660868] I      10
10/10/2017 11:42:32 [27692] [WBXML] [roman] [androidc1650660868] I     </WindowSize>
10/10/2017 11:42:32 [27692] [WBXML] [roman] [androidc1650660868] I     <Options>
10/10/2017 11:42:32 [27692] [WBXMLSTACK] [roman] [androidc1650660868] WBXMLDecoder->getElementStartTag(): unmatched WBXML tag: 'ConversationMode' matching 'Options' type '1' flags '1'
10/10/2017 11:42:32 [27692] [WBXML] [roman] [androidc1650660868] I      <FilterType>
10/10/2017 11:42:32 [27692] [WBXMLSTACK] [roman] [androidc1650660868] WBXMLDecoder->getElementStartTag(): unmatched WBXML tag: 'FolderType' matching 'FilterType' type '1' flags '1'
10/10/2017 11:42:32 [27692] [DEBUG] [roman] [androidc1650660868] SyncParameters->UseCPO('DEFAULT')
10/10/2017 11:42:32 [27692] [WBXML] [roman] [androidc1650660868] I       4
10/10/2017 11:42:32 [27692] [WBXML] [roman] [androidc1650660868] I      </FilterType>
10/10/2017 11:42:32 [27692] [WBXML] [roman] [androidc1650660868] I      <AirSyncBase:BodyPreference>
10/10/2017 11:42:32 [27692] [WBXMLSTACK] [roman] [androidc1650660868] WBXMLDecoder->getElementStartTag(): unmatched WBXML tag: 'Truncation' matching 'AirSyncBase:BodyPreference' type '1' flags '1'
10/10/2017 11:42:32 [27692] [WBXMLSTACK] [roman] [androidc1650660868] WBXMLDecoder->getElementStartTag(): unmatched WBXML tag: 'RtfTruncation' matching 'AirSyncBase:BodyPreference' type '1' flags '1'
10/10/2017 11:42:32 [27692] [WBXMLSTACK] [roman] [androidc1650660868] WBXMLDecoder->getElementStartTag(): unmatched WBXML tag: 'MIMESupport' matching 'AirSyncBase:BodyPreference' type '1' flags '1'
10/10/2017 11:42:32 [27692] [WBXMLSTACK] [roman] [androidc1650660868] WBXMLDecoder->getElementStartTag(): unmatched WBXML tag: 'MIMETruncation' matching 'AirSyncBase:BodyPreference' type '1' flags '1'
10/10/2017 11:42:32 [27692] [WBXMLSTACK] [roman] [androidc1650660868] WBXMLDecoder->getElementStartTag(): unmatched WBXML tag: 'Conflict' matching 'AirSyncBase:BodyPreference' type '1' flags '1'
10/10/2017 11:42:32 [27692] [WBXML] [roman] [androidc1650660868] I       <AirSyncBase:Type>
10/10/2017 11:42:32 [27692] [WBXML] [roman] [androidc1650660868] I        1
10/10/2017 11:42:32 [27692] [WBXML] [roman] [androidc1650660868] I       </AirSyncBase:Type>
10/10/2017 11:42:32 [27692] [WBXML] [roman] [androidc1650660868] I       <AirSyncBase:TruncationSize>
10/10/2017 11:42:32 [27692] [WBXML] [roman] [androidc1650660868] I        200000
10/10/2017 11:42:32 [27692] [WBXML] [roman] [androidc1650660868] I       </AirSyncBase:TruncationSize>
10/10/2017 11:42:32 [27692] [WBXML] [roman] [androidc1650660868] I      </AirSyncBase:BodyPreference>
10/10/2017 11:42:32 [27692] [WBXMLSTACK] [roman] [androidc1650660868] WBXMLDecoder->getElementStartTag(): unmatched WBXML tag: 'AirSyncBase:AllOrNone' matching '' type '2' flags ''
10/10/2017 11:42:32 [27692] [WBXMLSTACK] [roman] [androidc1650660868] WBXMLDecoder->getElementStartTag(): unmatched WBXML tag: 'AirSyncBase:Preview' matching '' type '2' flags ''
10/10/2017 11:42:32 [27692] [WBXML] [roman] [androidc1650660868] I     </Options>
10/10/2017 11:42:32 [27692] [WBXMLSTACK] [roman] [androidc1650660868] WBXMLDecoder->getElementStartTag(): unmatched WBXML tag: 'AirSyncBase:BodyPreference' matching '' type '2' flags ''
10/10/2017 11:42:32 [27692] [WBXML] [roman] [androidc1650660868] I    </Folder>
10/10/2017 11:42:32 [27692] [WBXMLSTACK] [roman] [androidc1650660868] WBXMLDecoder->getElementStartTag(): unmatched WBXML tag: 'Options' matching '' type '2' flags ''
10/10/2017 11:42:32 [27692] [WBXMLSTACK] [roman] [androidc1650660868] WBXMLDecoder->getElementStartTag(): unmatched WBXML tag: 'Perform' matching '' type '2' flags ''
10/10/2017 11:42:32 [27692] [WBXML] [roman] [androidc1650660868] I   </Folders>
10/10/2017 11:42:32 [27692] [WBXMLSTACK] [roman] [androidc1650660868] WBXMLDecoder->getElementStartTag(): unmatched WBXML tag: 'Folder' matching '' type '2' flags ''
10/10/2017 11:42:32 [27692] [WBXML] [roman] [androidc1650660868] I  </Synchronize>
10/10/2017 11:42:32 [27692] [WBXMLSTACK] [roman] [androidc1650660868] WBXMLDecoder->getElementStartTag(): unmatched WBXML tag: 'HeartbeatInterval' matching '' type '2' flags ''
10/10/2017 11:42:32 [27692] [WBXMLSTACK] [roman] [androidc1650660868] WBXMLDecoder->getElementStartTag(): unmatched WBXML tag: 'Wait' matching '' type '2' flags ''
10/10/2017 11:42:32 [27692] [WBXMLSTACK] [roman] [androidc1650660868] WBXMLDecoder->getElementStartTag(): unmatched WBXML tag: 'WindowSize' matching '' type '2' flags ''
10/10/2017 11:42:32 [27692] [WBXMLSTACK] [roman] [androidc1650660868] WBXMLDecoder->getElementStartTag(): unmatched WBXML tag: 'Partial' matching '' type '2' flags ''
10/10/2017 11:42:32 [27692] [DEBUG] [roman] [androidc1650660868] HandleSync(): Start Output
10/10/2017 11:42:32 [27692] [DEBUG] [roman] [androidc1650660868] ZPush::GetAdditionalSyncFolderStore('042f7fc33be041bb9a6382c616b31ca2c90200000000'): 'false'
10/10/2017 11:42:32 [27692] [DEBUG] [roman] [androidc1650660868] KopanoBackend->GetFolderStat() fetched status information of 52 folders for store 'roman'
10/10/2017 11:42:32 [27692] [DEBUG] [roman] [androidc1650660868] SyncParameters->IsExporterRunRequired(): false - current: 1505611034/45/0/0 - saved: 1505611034/45/0/0 - expiring: 2017-10-15 21:12:39
10/10/2017 11:42:32 [27692] [DEBUG] [roman] [androidc1650660868] HandleSync: No changes found for Calendar folder id 'U5dd25'. Omitting output.
10/10/2017 11:42:32 [27692] [WBXML] [roman] [androidc1650660868] WBXML-IN : AwFqAEVcT0sDezBkOThiZWE0LWQ0ZDEtNDczYi1iOTNiLThhMmFjZTk0ZmE3MX05AAFSA1U1ZGQyNQABHhNVAzEwAAFXWAM0AAEAEUVGAzEAAUcDMjAwMDAwAAEBAQEBAQ==
10/10/2017 11:42:32 [27692] [DEBUG] [roman] [androidc1650660868] LoopDetection->ProcessLoopDetectionTerminate()
10/10/2017 11:42:32 [27692] [ INFO] [roman] [androidc1650660868] cmd='Sync' memory='2.36 MiB/2.75 MiB' time='0.22s' devType='Android' devId='androidc1650660868' getUser='roman' from='37.157.96.39' idle='0s' version='2.3.8+0-0' method='POST' httpcode='200'
10/10/2017 11:42:32 [27692] [DEBUG] [roman] [androidc1650660868] -------- End

                z-push is installed from repository

                1 Reply Last reply Reply Quote 0
                • romeor
                  romeor last edited by

                  Any thoughts?

                  1 Reply Last reply Reply Quote 0
                  • Manfred
                    Manfred Kopano last edited by

                    Hi romeor,

                    there’s something strange going on with your profile on the device. It syncs the folder with the id ‘Uce2aa’ but tries to modify the item ‘U96461:042f7fc33be041bb9a6382c616b31ca2ff4a00000000’ which is in another folder (the FolderId and ServerEntryId part before ‘:’ must be equal).

                    Could you post the output of

                    z-push-admin -a list -u roman -d androidc1650660868

                    ?

                    Do you have multiple ActiveSync accounts on your device?

                    For now I don’t have any idea you could try other than to remove profile from the device, remove the device with z-push-admin, create the profile on the mobile again.

                    Manfred

                    romeor 1 Reply Last reply Reply Quote 0
                    • romeor
                      romeor @Manfred last edited by romeor

                      @manfred
                      Hi, thanks for an answer.
                      Actually, as soon as I get these errors I have remove the account from phone and add it again to get things going. This happens pretty often, so I decided to ask for a help and help myself to debug the issue.

                      There are two accounts on the phone: one syncs calendar, contacts and e-mail.
                      Another one is so named shared calendar used among multiple users. The problem occurs only with first one and it seems like only on my phone.

                      The output is here:

                      Synchronized by user: roman
-----------------------------------------------------
DeviceId:               androidc1650660868
Device type:            Android
UserAgent:              Android/7.0-EAS-2.0
Device Model:           WAS-LX1
Device IMEI:            IMEI-HERE
Device friendly name:   WAS-LX1
Device OS:              Android 7.0
ActiveSync version:     14.0
First sync:             2017-06-05 12:02
Last sync:              2017-10-23 16:17
Total folders:          39
Short folder Ids:       Yes
Synchronized folders:   7
Synchronized data:      Emails(5) Contacts Calendars
Additional Folders:     none
Status:                 OK
WipeRequest on:         not set
WipeRequest by:         not set
Wiped on:               not set
Policy name:            default
Attention needed:       No errors known

                      But I’ve already recreated the account so there is no issue for some time. Should I post the output, when I’ll have the same issue?

                      Manfred 1 Reply Last reply Reply Quote 0
                      • Manfred
                        Manfred Kopano @romeor last edited by

                        @romeor said in Exception: (WBXMLException) - Unknown error in Sync->Handle():

                        But I’ve already recreated the account so there is no issue for some time. Should I post the output, when I’ll have the same issue?

                        Yes, please. If possible you could also add the debug from the device (e.g. via adb).

                        Manfred

                        1 Reply Last reply Reply Quote 0
                        • Sebastian
                          Sebastian Kopano last edited by

                          Perhaps it would be helpful to get a WBXML log from before this issue happens. In the log snipped you’ve posted the device tries to mark an email as read. The only explanation I can find is that this email is located in a Contact folder.

                          Could you resync your device and attach the WBXML output? Btw, WBXML log level is enough (no need for WBXMLSTACK).
                          Especially interesting would be the log of the FolderSync command (on of the first commands to be triggered after resync).

                          Just confirming: is this a Huawei P10 lite?

                          1 Reply Last reply Reply Quote 0
                          • romeor
                            romeor last edited by

                            Hello,

                            I’m sorry. I’m not able to follow this issue any more. I’ve dropped my phone and it’s glass cracked so I can’t use it anymore. As glass change costs as same as almost new xiaomi phone I’ve decided to just buy new phone.

                            I will try to get back if I’ll get same problems with my new phone.

                            And yes, it was Huawei P10 Lite.

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