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



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


  • Kopano

    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



  • 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.



  • 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



  • Any thoughts?


  • Kopano

    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



  • @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?


  • Kopano

    @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


  • Kopano

    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?



  • 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.


Log in to reply
 

Looks like your connection to Kopano Community Forum was lost, please wait while we try to reconnect.