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

    Incident: Ignored broken message (SyncMail). Reason: '2'

    Z-Push when using Kopano
    z-push broken message
    2
    10
    3185
    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.
    • darootler
      darootler last edited by darootler

      Date Seen
      28.03.2016

      Versions
      Ubuntu 16.04.2 LTS
      Apache 2.4.18
      Z-Push 2.3.5

      Bug Description
      The problematic mails won’t sync to iPhones and are causing a loop.

      WBXML Log:

      20/04/2017 10:03:05 [18503] [DEBUG] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] -------- Start
      20/04/2017 10:03:05 [18503] [DEBUG] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] cmd='Sync' devType='iPhone' devId='e51i135rs54dl5ar3cu242hkjc' getUser='USERNAME' from='213.225.38.91' version='2.3.5+5' method='POST'
      20/04/2017 10:03:05 [18503] [DEBUG] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] Used timezone 'Europe/Vienna'
      20/04/2017 10:03:05 [18503] [DEBUG] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] ZPush::GetBackend(): trying autoload backend 'BackendKopano'
      20/04/2017 10:03:05 [18503] [DEBUG] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] BackendKopano using PHP-MAPI version: 8.4.0-344 - PHP version: 7.0.15-0ubuntu0.16.04.4
      20/04/2017 10:03:05 [18503] [DEBUG] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] Request::ProcessHeaders() ASVersion: 14.0
      20/04/2017 10:03:05 [18503] [DEBUG] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] ZPush::CommandNeedsAuthentication(0): true
      20/04/2017 10:03:05 [18503] [DEBUG] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] KopanoBackend->Logon(): Trying to authenticate user 'USERNAME'..
      20/04/2017 10:03:05 [18503] [DEBUG] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] FileStateMachine->GetState() read '5080' bytes from file: '/var/lib/z-push/c/j/e51i135rs54dl5ar3cu242hkjc-devicedata'
      20/04/2017 10:03:05 [18503] [DEBUG] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] ASDevice data loaded for user: 'USERNAME'
      20/04/2017 10:03:05 [18503] [DEBUG] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] TopCollector(): Initialized mutexid Resource id #18 and memid Resource id #19.
      20/04/2017 10:03:05 [18503] [DEBUG] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] TopCollector initialised with IPC provider 'IpcSharedMemoryProvider' with type '20'
      20/04/2017 10:03:05 [18503] [DEBUG] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] LoopDetection(): Initialized mutexid Resource id #22 and memid Resource id #23.
      20/04/2017 10:03:05 [18503] [DEBUG] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] LoopDetection initialised with IPC provider 'IpcSharedMemoryProvider' with type '1337'
      20/04/2017 10:03:05 [18503] [DEBUG] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] ZPush::HierarchyCommand(0): false
      20/04/2017 10:03:05 [18503] [DEBUG] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] KopanoBackend->openMessageStore('USERNAME'): Found 'DEFAULT' store: 'Resource id #29'
      20/04/2017 10:03:05 [18503] [DEBUG] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] KopanoBackend->Logon(): User 'USERNAME' is authenticated
      20/04/2017 10:03:05 [18503] [DEBUG] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] Store supports properties containing Unicode characters.
      20/04/2017 10:03:05 [18503] [DEBUG] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] ZPush::CommandNeedsPlainInput(0): false
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] I  <Synchronize>
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] I   <Folders>
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] I    <Folder>
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] I     <SyncKey>
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] I      {3cc25e55-00b9-42ca-82bd-ead0b2066526}1
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] I     </SyncKey>
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] I     <FolderId>
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] I      U5e81d
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] I     </FolderId>
      20/04/2017 10:03:05 [18503] [DEBUG] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] FileStateMachine->GetState() read '934' bytes from file: '/var/lib/z-push/c/j/e51i135rs54dl5ar3cu242hkjc-3cc25e55-00b9-42ca-82bd-ead0b2066526-fd'
      20/04/2017 10:03:05 [18503] [DEBUG] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] SyncParameters->UseCPO('DEFAULT')
      20/04/2017 10:03:05 [18503] [DEBUG] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] DeviceManager->GetBackendIdForFolderId(): folderid U5e81d => 786e8a1ff7ed45edad6b2f883fdfb6a0080000000000
      20/04/2017 10:03:05 [18503] [DEBUG] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] SyncCollections->AddCollection(): Folder id 'U5e81d' : ref. PolicyKey '267709328', ref. Lifetime '', last sync at '1492675384'
      20/04/2017 10:03:05 [18503] [DEBUG] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] SyncCollections->AddCollection(): Updated reference PolicyKey '267709328', reference Lifetime '', Last sync at '1492675384'
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] I     <GetChanges/>
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] I     <WindowSize>
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] I      25
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] I     </WindowSize>
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] I     <Options>
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] I      <MIMETruncation>
      20/04/2017 10:03:05 [18503] [DEBUG] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] SyncParameters->UseCPO('DEFAULT')
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] I       1
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] I      </MIMETruncation>
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] I      <MIMESupport>
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] I       0
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] I      </MIMESupport>
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] I      <AirSyncBase:BodyPreference>
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] I       <AirSyncBase:Type>
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] I        1
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] I       </AirSyncBase:Type>
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] I       <AirSyncBase:TruncationSize>
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] I        500
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] I       </AirSyncBase:TruncationSize>
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] I      </AirSyncBase:BodyPreference>
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] I     </Options>
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] I    </Folder>
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] I   </Folders>
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] I  </Synchronize>
      20/04/2017 10:03:05 [18503] [DEBUG] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] HandleSync(): Start Output
      20/04/2017 10:03:05 [18503] [DEBUG] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] ASDevice->GetFolderIdForBackendId(): no valid condition found for determining folderid for backendid '0'. Returning as is!
      20/04/2017 10:03:05 [18503] [DEBUG] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] ASDevice->GetFolderIdForBackendId(): no valid condition found for determining folderid for backendid '0'. Returning as is!
      20/04/2017 10:03:05 [18503] [DEBUG] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] ASDevice->GetFolderIdForBackendId(): no valid condition found for determining folderid for backendid '0'. Returning as is!
      20/04/2017 10:03:05 [18503] [DEBUG] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] ASDevice->GetFolderIdForBackendId(): no valid condition found for determining folderid for backendid '0'. Returning as is!
      20/04/2017 10:03:05 [18503] [DEBUG] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] ASDevice->GetFolderIdForBackendId(): no valid condition found for determining folderid for backendid '0'. Returning as is!
      20/04/2017 10:03:05 [18503] [DEBUG] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] ASDevice->GetFolderIdForBackendId(): no valid condition found for determining folderid for backendid '0'. Returning as is!
      20/04/2017 10:03:05 [18503] [DEBUG] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] ASDevice->GetFolderIdForBackendId(): no valid condition found for determining folderid for backendid '0'. Returning as is!
      20/04/2017 10:03:05 [18503] [DEBUG] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] ASDevice->GetFolderIdForBackendId(): no valid condition found for determining folderid for backendid '0'. Returning as is!
      20/04/2017 10:03:05 [18503] [DEBUG] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] ASDevice->GetFolderIdForBackendId(): no valid condition found for determining folderid for backendid '0'. Returning as is!
      20/04/2017 10:03:05 [18503] [DEBUG] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] ASDevice->GetFolderIdForBackendId(): no valid condition found for determining folderid for backendid '0'. Returning as is!
      20/04/2017 10:03:05 [18503] [DEBUG] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] ZPush::GetAdditionalSyncFolderStore('786e8a1ff7ed45edad6b2f883fdfb6a0080000000000'): 'false'
      20/04/2017 10:03:05 [18503] [DEBUG] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] KopanoBackend->GetFolderStat() fetched status information of 57 folders for store 'USERNAME'
      20/04/2017 10:03:05 [18503] [DEBUG] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] SyncParameters->IsExporterRunRequired(): true - current: 1492675381/1/0/2284 - saved: false - expiring: not set
      20/04/2017 10:03:05 [18503] [DEBUG] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] Sync->loadStates(): loading states for folder 'U5e81d'
      20/04/2017 10:03:05 [18503] [DEBUG] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] FileStateMachine->GetState() read '15' bytes from file: '/var/lib/z-push/c/j/e51i135rs54dl5ar3cu242hkjc-3cc25e55-00b9-42ca-82bd-ead0b2066526-1'
      20/04/2017 10:03:05 [18503] [DEBUG] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] ZPush::GetAdditionalSyncFolderStore('786e8a1ff7ed45edad6b2f883fdfb6a0080000000000'): 'false'
      20/04/2017 10:03:05 [18503] [DEBUG] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] ZPush::GetAdditionalSyncFolderStore('786e8a1ff7ed45edad6b2f883fdfb6a0080000000000'): 'false'
      20/04/2017 10:03:05 [18503] [DEBUG] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] ExportChangesICS->Config(): synching inital data
      20/04/2017 10:03:05 [18503] [DEBUG] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] ExportChangesICS->Config() initialized with state: 0x9916000000000000
      20/04/2017 10:03:05 [18503] [DEBUG] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] ExportChangesICS->InitializeExporter() successfully. 1 changes ready to sync for '786e8a1ff7ed45edad6b2f883fdfb6a0080000000000'.
      20/04/2017 10:03:05 [18503] [DEBUG] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] LoopDetection->ProcessLoopDetectionAddStatus: 'U5e81d' with status 1
      20/04/2017 10:03:05 [18503] [DEBUG] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] WBXMLEncoder->startWBXML() type: vnd.ms-sync.wbxml
      20/04/2017 10:03:05 [18503] [DEBUG] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] Folder type: Email
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] O  <Synchronize>
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] O   <Folders>
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] O    <Folder>
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] O     <SyncKey>
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] O     {3cc25e55-00b9-42ca-82bd-ead0b2066526}2
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] O     </SyncKey>
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] O     <FolderId>
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] O     U5e81d
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] O     </FolderId>
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] O     <Status>
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] O     1
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] O     </Status>
      20/04/2017 10:03:05 [18503] [DEBUG] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] LoopDetection->Detect(): folderid:'U5e81d' uuid:'3cc25e55-00b9-42ca-82bd-ead0b2066526' counter:'1' max:'25' queued:'1'
      20/04/2017 10:03:05 [18503] [DEBUG] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] LoopDetection->Detect(): UUID changed for folder
      20/04/2017 10:03:05 [18503] [DEBUG] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] LoopDetection->Detect(): UUID changed and while items where sent to device - forcing loop mode
      20/04/2017 10:03:05 [18503] [DEBUG] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] LoopDetection->Detect(): case 3.1 detected - loop detected, init loop mode
      20/04/2017 10:03:05 [18503] [DEBUG] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] LoopDetection->Detect(): loop data: loopcount(1), maxCount(2), queued(1), ignored(false)
      20/04/2017 10:03:05 [18503] [WARN] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] Mobile loop detected! Messages sent to the mobile will be restricted to 1 items in order to identify the conflict
      20/04/2017 10:03:05 [18503] [DEBUG] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] PHPWrapper->ImportMessageChange(): Getting message from MAPIProvider, sourcekey: '786e8a1ff7ed45edad6b2f883fdfb6a0bc6f01000000', parentsourcekey: '786e8a1ff7ed45edad6b2f883fdfb6a0080000000000', entryid: '00000000fffe07b9435e445f933d1a3a5df40c7b010000000500000076546eea4b77408d9a761f073320e82300000000'
      20/04/2017 10:03:05 [18503] [DEBUG] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] ZPush::GetAdditionalSyncFolderStore('786e8a1ff7ed45edad6b2f883fdfb6a0080000000000'): 'false'
      20/04/2017 10:03:05 [18503] [DEBUG] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] BodyPreference types: 1
      20/04/2017 10:03:05 [18503] [DEBUG] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] GetBodyPreferenceBestMatch: 1
      20/04/2017 10:03:05 [18503] [DEBUG] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] bpo: truncation size:'500', allornone:'0', preview:'0'
      20/04/2017 10:03:05 [18503] [DEBUG] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] MAPIStreamWrapper::stream_open(): initialized mapistream: Resource id #235 streamlength: 12031
      20/04/2017 10:03:05 [18503] [DEBUG] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] MAPIProvider->setMessageBody(): truncated plain-text body requested, stripping all links and images
      20/04/2017 10:03:05 [18503] [DEBUG] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] StringStreamWrapper::stream_open(): initialized stream length: 489
      20/04/2017 10:03:05 [18503] [DEBUG] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] LoopDetection->IgnoreNextMessage(): Loop mode, potential broken message id 'U5e81d:786e8a1ff7ed45edad6b2f883fdfb6a0bc6f01000000'
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] O     <Perform>
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] O      <Add>
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] O       <ServerEntryId>
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] O       U5e81d:786e8a1ff7ed45edad6b2f883fdfb6a0bc6f01000000
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] O       </ServerEntryId>
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] O       <Data>
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] O        <POOMMAIL:To>
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] O        "USERNAME SURNAME" <USERNAME@DOMAIN.ME>
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] O        </POOMMAIL:To>
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] O        <POOMMAIL:From>
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] O        "heise Security Summary" <newsletter@listserv.heise.de>
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] O        </POOMMAIL:From>
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] O        <POOMMAIL:Subject>
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] O        heise Security News 28.03.2016
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] O        </POOMMAIL:Subject>
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] O        <POOMMAIL:DateReceived>
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] O        2016-03-28T09:18:42.000Z
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] O        </POOMMAIL:DateReceived>
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] O        <POOMMAIL:DisplayTo>
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] O        USERNAME SURNAME
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] O        </POOMMAIL:DisplayTo>
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] O        <POOMMAIL:Importance>
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] O        1
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] O        </POOMMAIL:Importance>
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] O        <POOMMAIL:Read>
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] O        1
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] O        </POOMMAIL:Read>
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] O        <POOMMAIL:MessageClass>
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] O        IPM.Note
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] O        </POOMMAIL:MessageClass>
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] O        <POOMMAIL:InternetCPID>
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] O        65001
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] O        </POOMMAIL:InternetCPID>
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] O        <AirSyncBase:Body>
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] O         <AirSyncBase:Type>
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] O         1
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] O         </AirSyncBase:Type>
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] O         <AirSyncBase:EstimatedDataSize>
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] O         12031
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] O         </AirSyncBase:EstimatedDataSize>
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] O         <AirSyncBase:Truncated>
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] O         1
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] O         </AirSyncBase:Truncated>
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] O         <AirSyncBase:Data>
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] O         <<< written 489 of 489 bytes of plain data >>>
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] O         </AirSyncBase:Data>
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] O        </AirSyncBase:Body>
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] O        <POOMMAIL:ContentClass>
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] O        urn:content-classes:message
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] O        </POOMMAIL:ContentClass>
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] O        <POOMMAIL:Flag/>
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] O        <AirSyncBase:NativeBodyType>
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] O        2
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] O        </AirSyncBase:NativeBodyType>
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] O       </Data>
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] O      </Add>
      20/04/2017 10:03:05 [18503] [DEBUG] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] PHPWrapper->ImportMessageChange(): change for: 'U5e81d:786e8a1ff7ed45edad6b2f883fdfb6a0bc6f01000000'
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] O     </Perform>
      20/04/2017 10:03:05 [18503] [DEBUG] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] SetFolderSyncStatus(): completed for U5e81d
      20/04/2017 10:03:05 [18503] [DEBUG] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] ZPush::GetAdditionalSyncFolderStore('786e8a1ff7ed45edad6b2f883fdfb6a0080000000000'): 'false'
      20/04/2017 10:03:05 [18503] [DEBUG] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] Sync()->setFolderStat() on U5e81d: 1492675381/1/0/2284 expiring 2017-05-21 10:03:05
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] O    </Folder>
      20/04/2017 10:03:05 [18503] [DEBUG] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] FileStateMachine->SetState() written 15 bytes on file: '/var/lib/z-push/c/j/e51i135rs54dl5ar3cu242hkjc-3cc25e55-00b9-42ca-82bd-ead0b2066526-2'
      20/04/2017 10:03:05 [18503] [DEBUG] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] SyncCollections->SaveCollection(): Data of folder 'U5e81d' changed
      20/04/2017 10:03:05 [18503] [DEBUG] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] FileStateMachine->SetState() written 1045 bytes on file: '/var/lib/z-push/c/j/e51i135rs54dl5ar3cu242hkjc-3cc25e55-00b9-42ca-82bd-ead0b2066526-fd'
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] O   </Folders>
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] O  </Synchronize>
      20/04/2017 10:03:05 [18503] [DEBUG] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] WBXMLEncoder->endTag() WBXML output completed
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] WBXML-OUT: ...
      20/04/2017 10:03:05 [18503] [WBXML] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] WBXML-IN : ...
      20/04/2017 10:03:05 [18503] [DEBUG] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] DeviceManager->Save(): Device data changed
      20/04/2017 10:03:05 [18503] [DEBUG] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] FileStateMachine->SetState() written 5062 bytes on file: '/var/lib/z-push/c/j/e51i135rs54dl5ar3cu242hkjc-devicedata'
      20/04/2017 10:03:05 [18503] [DEBUG] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] DeviceManager->Save(): Device data saved
      20/04/2017 10:03:05 [18503] [DEBUG] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] LoopDetection->ProcessLoopDetectionTerminate()
      20/04/2017 10:03:05 [18503] [ INFO] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] cmd='Sync' memory='2.09 MiB/4.00 MiB' time='0.62s' devType='iPhone' devId='e51i135rs54dl5ar3cu242hkjc' getUser='USERNAME' from='213.225.38.91' version='2.3.5+5' method='POST' httpcode='200'
      20/04/2017 10:03:05 [18503] [DEBUG] [USERNAME] [e51i135rs54dl5ar3cu242hkjc] -------- End
      

      Severity
      Major

      Steps to Reproduce
      I just enabled the option “log_raw_message” in kopano-dagent. If i am receiving a mail causing this loop we are able to reproduce this error.

      Actual Behavior
      iPhones won’t sync the problematic mails and these are causing loops. The generated error message is “Ignored broken message (SyncMail). Reason: ‘2’”

      Expected Behavior
      iPhones are able to sync the mails.

      Troubleshooting/Testing Steps Attempted
      I searched through the internet and didn’t find a solution. I tried to compare two mails but didn’t find anything that points me in a direction.

      Workaround
      iPhones will continue to sync all other mails, the mails can be viewed via kopano-webapp.

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

        Thanks for opening a topic here. Much better than in the ticket. :slight_smile:

        The WBXML-OUT from your log actually gave away a hint about what is going on.

        I edited your post and removed that string as it contains lot of data you anonymized in your post.

        Anyway, I have a pretty good idea why the message is looping.
        It seems as the UTF-8 truncation we use is not working as it should (could be a php7 incompatibility).

        First, we should have a reproducible use case.
        Could you try to safe this message as EML via the WebApp (right-click on the message and select “download as file”).
        You can then try to deliver this eml file to your mailbox, using

        kopano-dagent -f <email.eml> <username> 
        

        It should show up as new (current date). Please check if you have the same kind of trouble with it (ignored by loop detection).
        If yes, please send me the eml file.
        If no, we try to export the original email via python.

        Cheers,
        Sebastian

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

          Hi Sebastian,

          thank you for anonymizing the logs.

          If i try to deliver the mail to my mailbox i am getting the following error:

          Apr 20 20:49:03 server kopano-dagent[23051]:   Python type: (null)
          Apr 20 20:49:03 server kopano-dagent[23051]:   Python error: 'module' object has no attribute 'DAgentPluginmanager'
          Apr 20 20:49:03 server kopano-dagent[23051]: K-1732: Unable to initialize the dagent plugin manager: Unknown error code (1).
          

          Any suggestions?

          Regards
          Richard

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

            I just disabled the plugin manager temporarily to deliver the mail manually. I am able to reproduce this error with the downloaded email and i will send it to you.

            Regards
            Richard

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

              WBXML log after your provided changes in utils.php and resyncing the problematic mail:

              Syncing went fine after changing utils.php with the provided code :thumbsup_tone1:

              20/04/2017 21:25:49 [18988] [DEBUG] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] -------- Start
              20/04/2017 21:25:49 [18988] [DEBUG] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] cmd='Sync' devType='iPhone' devId='e51i135rs54dl5ar3cu242hkjc' getUser='FIRSTNAME' from='IPADDRESS' version='2.3.5+5' method='POST'
              20/04/2017 21:25:49 [18988] [DEBUG] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] Used timezone 'Europe/Vienna'
              20/04/2017 21:25:49 [18988] [DEBUG] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] ZPush::GetBackend(): trying autoload backend 'BackendKopano'
              20/04/2017 21:25:49 [18988] [DEBUG] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] BackendKopano using PHP-MAPI version: 8.4.0-344 - PHP version: 7.0.15-0ubuntu0.16.04.4
              20/04/2017 21:25:49 [18988] [DEBUG] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] Request::ProcessHeaders() ASVersion: 14.0
              20/04/2017 21:25:49 [18988] [DEBUG] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] ZPush::CommandNeedsAuthentication(0): true
              20/04/2017 21:25:49 [18988] [DEBUG] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] KopanoBackend->Logon(): Trying to authenticate user 'FIRSTNAME'..
              20/04/2017 21:25:49 [18988] [DEBUG] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] FileStateMachine->GetState() read '5080' bytes from file: '/var/lib/z-push/c/j/e51i135rs54dl5ar3cu242hkjc-devicedata'
              20/04/2017 21:25:49 [18988] [DEBUG] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] ASDevice data loaded for user: 'FIRSTNAME'
              20/04/2017 21:25:49 [18988] [DEBUG] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] TopCollector(): Initialized mutexid Resource id #18 and memid Resource id #19.
              20/04/2017 21:25:49 [18988] [DEBUG] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] TopCollector initialised with IPC provider 'IpcSharedMemoryProvider' with type '20'
              20/04/2017 21:25:49 [18988] [DEBUG] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] LoopDetection(): Initialized mutexid Resource id #22 and memid Resource id #23.
              20/04/2017 21:25:49 [18988] [DEBUG] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] LoopDetection initialised with IPC provider 'IpcSharedMemoryProvider' with type '1337'
              20/04/2017 21:25:49 [18988] [DEBUG] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] ZPush::HierarchyCommand(0): false
              20/04/2017 21:25:49 [18988] [DEBUG] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] KopanoBackend->openMessageStore('FIRSTNAME'): Found 'DEFAULT' store: 'Resource id #29'
              20/04/2017 21:25:49 [18988] [DEBUG] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] KopanoBackend->Logon(): User 'FIRSTNAME' is authenticated
              20/04/2017 21:25:49 [18988] [DEBUG] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] Store supports properties containing Unicode characters.
              20/04/2017 21:25:49 [18988] [DEBUG] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] ZPush::CommandNeedsPlainInput(0): false
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] I  <Synchronize>
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] I   <Folders>
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] I    <Folder>
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] I     <SyncKey>
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] I      {3b545193-f74e-4cde-a0d9-66b9b0915edf}1
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] I     </SyncKey>
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] I     <FolderId>
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] I      U5e81d
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] I     </FolderId>
              20/04/2017 21:25:49 [18988] [DEBUG] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] FileStateMachine->GetState() read '934' bytes from file: '/var/lib/z-push/c/j/e51i135rs54dl5ar3cu242hkjc-3b545193-f74e-4cde-a0d9-66b9b0915edf-fd'
              20/04/2017 21:25:49 [18988] [DEBUG] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] SyncParameters->UseCPO('DEFAULT')
              20/04/2017 21:25:49 [18988] [DEBUG] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] DeviceManager->GetBackendIdForFolderId(): folderid U5e81d => 786e8a1ff7ed45edad6b2f883fdfb6a0080000000000
              20/04/2017 21:25:49 [18988] [DEBUG] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] SyncCollections->AddCollection(): Folder id 'U5e81d' : ref. PolicyKey '267709328', ref. Lifetime '', last sync at '1492716348'
              20/04/2017 21:25:49 [18988] [DEBUG] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] SyncCollections->AddCollection(): Updated reference PolicyKey '267709328', reference Lifetime '', Last sync at '1492716348'
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] I     <GetChanges/>
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] I     <WindowSize>
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] I      25
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] I     </WindowSize>
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] I     <Options>
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] I      <MIMETruncation>
              20/04/2017 21:25:49 [18988] [DEBUG] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] SyncParameters->UseCPO('DEFAULT')
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] I       1
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] I      </MIMETruncation>
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] I      <MIMESupport>
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] I       0
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] I      </MIMESupport>
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] I      <AirSyncBase:BodyPreference>
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] I       <AirSyncBase:Type>
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] I        1
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] I       </AirSyncBase:Type>
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] I       <AirSyncBase:TruncationSize>
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] I        500
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] I       </AirSyncBase:TruncationSize>
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] I      </AirSyncBase:BodyPreference>
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] I     </Options>
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] I    </Folder>
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] I   </Folders>
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] I  </Synchronize>
              20/04/2017 21:25:49 [18988] [DEBUG] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] HandleSync(): Start Output
              20/04/2017 21:25:49 [18988] [DEBUG] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] ASDevice->GetFolderIdForBackendId(): no valid condition found for determining folderid for backendid '0'. Returning as is!
              20/04/2017 21:25:49 [18988] [DEBUG] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] ASDevice->GetFolderIdForBackendId(): no valid condition found for determining folderid for backendid '0'. Returning as is!
              20/04/2017 21:25:49 [18988] [DEBUG] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] ASDevice->GetFolderIdForBackendId(): no valid condition found for determining folderid for backendid '0'. Returning as is!
              20/04/2017 21:25:49 [18988] [DEBUG] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] ASDevice->GetFolderIdForBackendId(): no valid condition found for determining folderid for backendid '0'. Returning as is!
              20/04/2017 21:25:49 [18988] [DEBUG] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] ASDevice->GetFolderIdForBackendId(): no valid condition found for determining folderid for backendid '0'. Returning as is!
              20/04/2017 21:25:49 [18988] [DEBUG] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] ASDevice->GetFolderIdForBackendId(): no valid condition found for determining folderid for backendid '0'. Returning as is!
              20/04/2017 21:25:49 [18988] [DEBUG] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] ASDevice->GetFolderIdForBackendId(): no valid condition found for determining folderid for backendid '0'. Returning as is!
              20/04/2017 21:25:49 [18988] [DEBUG] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] ASDevice->GetFolderIdForBackendId(): no valid condition found for determining folderid for backendid '0'. Returning as is!
              20/04/2017 21:25:49 [18988] [DEBUG] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] ASDevice->GetFolderIdForBackendId(): no valid condition found for determining folderid for backendid '0'. Returning as is!
              20/04/2017 21:25:49 [18988] [DEBUG] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] ASDevice->GetFolderIdForBackendId(): no valid condition found for determining folderid for backendid '0'. Returning as is!
              20/04/2017 21:25:49 [18988] [DEBUG] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] ZPush::GetAdditionalSyncFolderStore('786e8a1ff7ed45edad6b2f883fdfb6a0080000000000'): 'false'
              20/04/2017 21:25:49 [18988] [DEBUG] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] KopanoBackend->GetFolderStat() fetched status information of 58 folders for store 'FIRSTNAME'
              20/04/2017 21:25:49 [18988] [DEBUG] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] SyncParameters->IsExporterRunRequired(): true - current: 1492716295/1/0/2288 - saved: false - expiring: not set
              20/04/2017 21:25:49 [18988] [DEBUG] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] Sync->loadStates(): loading states for folder 'U5e81d'
              20/04/2017 21:25:49 [18988] [DEBUG] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] FileStateMachine->GetState() read '15' bytes from file: '/var/lib/z-push/c/j/e51i135rs54dl5ar3cu242hkjc-3b545193-f74e-4cde-a0d9-66b9b0915edf-1'
              20/04/2017 21:25:49 [18988] [DEBUG] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] ZPush::GetAdditionalSyncFolderStore('786e8a1ff7ed45edad6b2f883fdfb6a0080000000000'): 'false'
              20/04/2017 21:25:49 [18988] [DEBUG] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] ZPush::GetAdditionalSyncFolderStore('786e8a1ff7ed45edad6b2f883fdfb6a0080000000000'): 'false'
              20/04/2017 21:25:49 [18988] [DEBUG] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] ExportChangesICS->Config(): synching inital data
              20/04/2017 21:25:49 [18988] [DEBUG] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] ExportChangesICS->Config() initialized with state: 0x9f16000000000000
              20/04/2017 21:25:49 [18988] [DEBUG] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] ExportChangesICS->InitializeExporter() successfully. 1 changes ready to sync for '786e8a1ff7ed45edad6b2f883fdfb6a0080000000000'.
              20/04/2017 21:25:49 [18988] [DEBUG] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] LoopDetection->ProcessLoopDetectionAddStatus: 'U5e81d' with status 1
              20/04/2017 21:25:49 [18988] [DEBUG] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] WBXMLEncoder->startWBXML() type: vnd.ms-sync.wbxml
              20/04/2017 21:25:49 [18988] [DEBUG] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] Folder type: Email
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] O  <Synchronize>
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] O   <Folders>
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] O    <Folder>
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] O     <SyncKey>
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] O     {3b545193-f74e-4cde-a0d9-66b9b0915edf}2
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] O     </SyncKey>
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] O     <FolderId>
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] O     U5e81d
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] O     </FolderId>
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] O     <Status>
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] O     1
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] O     </Status>
              20/04/2017 21:25:49 [18988] [DEBUG] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] LoopDetection->Detect(): folderid:'U5e81d' uuid:'3b545193-f74e-4cde-a0d9-66b9b0915edf' counter:'1' max:'25' queued:'1'
              20/04/2017 21:25:49 [18988] [DEBUG] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] LoopDetection->Detect(): UUID changed for folder
              20/04/2017 21:25:49 [18988] [DEBUG] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] PHPWrapper->ImportMessageChange(): Getting message from MAPIProvider, sourcekey: '786e8a1ff7ed45edad6b2f883fdfb6a02e7001000000', parentsourcekey: '786e8a1ff7ed45edad6b2f883fdfb6a0080000000000', entryid: '00000000fffe07b9435e445f933d1a3a5df40c7b01000000050000004dc179be62f640f2a49293f9e1ed5fd100000000'
              20/04/2017 21:25:49 [18988] [DEBUG] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] ZPush::GetAdditionalSyncFolderStore('786e8a1ff7ed45edad6b2f883fdfb6a0080000000000'): 'false'
              20/04/2017 21:25:49 [18988] [DEBUG] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] BodyPreference types: 1
              20/04/2017 21:25:49 [18988] [DEBUG] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] GetBodyPreferenceBestMatch: 1
              20/04/2017 21:25:49 [18988] [DEBUG] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] bpo: truncation size:'500', allornone:'0', preview:'0'
              20/04/2017 21:25:49 [18988] [DEBUG] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] MAPIStreamWrapper::stream_open(): initialized mapistream: Resource id #227 streamlength: 12031
              20/04/2017 21:25:49 [18988] [DEBUG] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] MAPIProvider->setMessageBody(): truncated plain-text body requested, stripping all links and images
              20/04/2017 21:25:49 [18988] [DEBUG] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] StringStreamWrapper::stream_open(): initialized stream length: 489
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] O     <Perform>
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] O      <Add>
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] O       <ServerEntryId>
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] O       U5e81d:786e8a1ff7ed45edad6b2f883fdfb6a02e7001000000
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] O       </ServerEntryId>
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] O       <Data>
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] O        <POOMMAIL:To>
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] O        "FIRSTNAME LASTNAME" <FIRSTNAME@LASTNAME.biz>
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] O        </POOMMAIL:To>
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] O        <POOMMAIL:From>
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] O        "heise Security Summary" <newsletter@listserv.heise.de>
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] O        </POOMMAIL:From>
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] O        <POOMMAIL:Subject>
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] O        heise Security News 28.03.2016
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] O        </POOMMAIL:Subject>
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] O        <POOMMAIL:DateReceived>
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] O        2016-03-28T09:18:42.000Z
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] O        </POOMMAIL:DateReceived>
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] O        <POOMMAIL:DisplayTo>
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] O        FIRSTNAME LASTNAME
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] O        </POOMMAIL:DisplayTo>
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] O        <POOMMAIL:Importance>
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] O        1
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] O        </POOMMAIL:Importance>
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] O        <POOMMAIL:Read>
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] O        1
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] O        </POOMMAIL:Read>
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] O        <POOMMAIL:MessageClass>
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] O        IPM.Note
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] O        </POOMMAIL:MessageClass>
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] O        <POOMMAIL:InternetCPID>
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] O        65001
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] O        </POOMMAIL:InternetCPID>
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] O        <AirSyncBase:Body>
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] O         <AirSyncBase:Type>
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] O         1
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] O         </AirSyncBase:Type>
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] O         <AirSyncBase:EstimatedDataSize>
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] O         12031
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] O         </AirSyncBase:EstimatedDataSize>
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] O         <AirSyncBase:Truncated>
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] O         1
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] O         </AirSyncBase:Truncated>
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] O         <AirSyncBase:Data>
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] O         <<< written 489 of 489 bytes of plain data >>>
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] O         </AirSyncBase:Data>
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] O        </AirSyncBase:Body>
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] O        <POOMMAIL:ContentClass>
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] O        urn:content-classes:message
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] O        </POOMMAIL:ContentClass>
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] O        <POOMMAIL:Flag/>
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] O        <AirSyncBase:NativeBodyType>
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] O        2
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] O        </AirSyncBase:NativeBodyType>
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] O       </Data>
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] O      </Add>
              20/04/2017 21:25:49 [18988] [DEBUG] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] PHPWrapper->ImportMessageChange(): change for: 'U5e81d:786e8a1ff7ed45edad6b2f883fdfb6a02e7001000000'
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] O     </Perform>
              20/04/2017 21:25:49 [18988] [DEBUG] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] SetFolderSyncStatus(): completed for U5e81d
              20/04/2017 21:25:49 [18988] [DEBUG] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] ZPush::GetAdditionalSyncFolderStore('786e8a1ff7ed45edad6b2f883fdfb6a0080000000000'): 'false'
              20/04/2017 21:25:49 [18988] [DEBUG] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] Sync()->setFolderStat() on U5e81d: 1492716295/1/0/2288 expiring 2017-05-21 21:25:49
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] O    </Folder>
              20/04/2017 21:25:49 [18988] [DEBUG] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] FileStateMachine->SetState() written 15 bytes on file: '/var/lib/z-push/c/j/e51i135rs54dl5ar3cu242hkjc-3b545193-f74e-4cde-a0d9-66b9b0915edf-2'
              20/04/2017 21:25:49 [18988] [DEBUG] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] SyncCollections->SaveCollection(): Data of folder 'U5e81d' changed
              20/04/2017 21:25:49 [18988] [DEBUG] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] FileStateMachine->SetState() written 1045 bytes on file: '/var/lib/z-push/c/j/e51i135rs54dl5ar3cu242hkjc-3b545193-f74e-4cde-a0d9-66b9b0915edf-fd'
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] O   </Folders>
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] O  </Synchronize>
              20/04/2017 21:25:49 [18988] [DEBUG] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] WBXMLEncoder->endTag() WBXML output completed
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] WBXML-OUT: AwFqAEVcT0sDezNiNTQ1MTkzLWY3NGUtNGNkZS1hMGQ5LTY2YjliMDkxNWVkZn0yAAFSA1U1ZTgxZAABTgMxAAFWR00DVTVlODFkOjc4NmU4YTFmZjdlZDQ1ZWRhZDZiMmY4ODNmZGZiNmEwMmU3MDAxMDAwMDAwAAFdAAJWAyJSaWNoYXJkIE1hcnNjaGlrIiA8cmljaGFyZEBtYXJzY2hpay5iaXo+AAFYAyJoZWlzZSBTZWN1cml0eSBTdW1tYXJ5IiA8bmV3c2xldHRlckBsaXN0c2Vydi5oZWlzZS5kZT4AAVQDaGVpc2UgU2VjdXJpdHkgTmV3cyAyOC4wMy4yMDE2AAFPAzIwMTYtMDMtMjhUMDk6MTg6NDIuMDAwWgABUQNSaWNoYXJkIE1hcnNjaGlrAAFSAzEAAVUDMQABUwNJUE0uTm90ZQABeQM2NTAwMQABABFKRgMxAAFMAzEyMDMxAAFNAzEAAUsDIA0KICAJaGVpc2UgU2VjdXJpdHkgTmV3cyAyOC4wMy4yMDE2DQp3d3cuaGVpc2UuZGUvc2VjdXJpdHkgIAkgICAJICANCiAgDQogIA0KICAJTmFjaHJpY2h0ZW7DvGJlcmJsaWNrIGRlciB2ZXJnYW5nZW5lbiB2aWVyIFRhZ2UJICANCiAgDQogIA0KICAJDQogIA0KaGVpc2UgU2VjdXJpdHkgTmV3cw0KICANCk5ldWUgSW5mZWt0aW9ucy1NYXNjaGU6IEVycHJlc3N1bmdzLVRyb2phbmVyIG1pc3NicmF1Y2h0IFdpbmRvd3MgUG93ZXJTaGVsbCAgDQoNCkRpZSBuZXUgZW50ZGVja3RlIFJhbnNvbXdhcmUgUG93ZXJXYXJlIGJlbcOkY2h0aWd0IHNpY2ggZGVyIFdpbmRvd3MgUG93ZXJTaGVsbCwgdW0gQ29tcHV0ZXIgenUgaW5maXppZXJlbiB1bmQgRGF0ZW4genUgdmVyc2NobMO8c3NlbG4uIA0KDQrigLrCoEFydGlrZWwgbGVzZW4gIMKgDQoNCi0tLS0tLS0tLS0tLS0tLS0tLS0tLS0tLS0tLS0tLS0tDQoNCklyYW46IFVTQSBoYWJlbiBrZWluZSBCZXdlaXNlIGY/AAEBAAJ8A3Vybjpjb250ZW50LWNsYXNzZXM6bWVzc2FnZQABOgARVgMyAAEBAQEBAQE=
              20/04/2017 21:25:49 [18988] [WBXML] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] WBXML-IN : AwFqAEVcT0sDezNiNTQ1MTkzLWY3NGUtNGNkZS1hMGQ5LTY2YjliMDkxNWVkZn0xAAFSA1U1ZTgxZAABE1UDMjUAAVdjAzEAAWIDMAABABFFRgMxAAFHAzUwMAABAQEBAQE=
              20/04/2017 21:25:49 [18988] [DEBUG] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] DeviceManager->Save(): Device data changed
              20/04/2017 21:25:49 [18988] [DEBUG] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] FileStateMachine->SetState() written 5062 bytes on file: '/var/lib/z-push/c/j/e51i135rs54dl5ar3cu242hkjc-devicedata'
              20/04/2017 21:25:49 [18988] [DEBUG] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] DeviceManager->Save(): Device data saved
              20/04/2017 21:25:49 [18988] [DEBUG] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] LoopDetection->ProcessLoopDetectionTerminate()
              20/04/2017 21:25:49 [18988] [ INFO] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] cmd='Sync' memory='2.09 MiB/4.00 MiB' time='0.58s' devType='iPhone' devId='e51i135rs54dl5ar3cu242hkjc' getUser='FIRSTNAME' from='IPADDRESS' version='2.3.5+5' method='POST' httpcode='200'
              20/04/2017 21:25:49 [18988] [DEBUG] [FIRSTNAME] [e51i135rs54dl5ar3cu242hkjc] -------- End
              

              Regards
              Richard

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

                Hey Richard,
                can you please keep that fix running for a while? Just to see if you don’t run into this (another) issue.

                Cheers,
                Seb

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

                  Hi Sebastian,

                  i didn’t restore the original utils.php. So yes, i’ll keep it running and report if i am facing this issue again.

                  Regards
                  Richard

                  1 Reply Last reply Reply Quote 0
                  • darootler
                    darootler @Sebastian last edited by

                    @Sebastian

                    Hi Sebastian,

                    in the meantime i upgrade z-push to version 2.3.6 and your fix got overwritten. Today i received a “problematic” mail, reapplied your fix and was able to successfully resync the device.

                    Regards
                    Richard

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

                      Yes, the ticket is scheduled for 2.3.7.

                      Cheers,
                      Sebastian

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

                        The issue is fixed now, root cause identified.
                        The new fix is currently in develop and will be merged into release/2.3 soon to go into 2.3.7.

                        More information is in ticket ZP-1199.

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