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

    Mobile loop detected!

    Z-Push when using Kopano
    2
    8
    1862
    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.
    • madpatrick
      madpatrick last edited by madpatrick

      Hi,

      I/m having with 1 user the following error messages in z-push-error.log
      What is this and how to resolve this.
      Kopano Core: 8.5.8.2
      Z-Push: 2.5.1+0

      Appreciate the support

      30/09/2019 11:50:51 [41997] [WARN] [xxxxxxx] Mobile loop detected! Messages sent to the mobile will be restricted to 1 items in order to identify the conflict
      30/09/2019 11:50:52 [63107] [WARN] [xxxxxxx] Mobile loop detected! Messages sent to the mobile will be restricted to 2 items in order to identify the conflict
      30/09/2019 11:50:52 [63107] [ERROR] [xxxxxxx] Ignored broken message (SyncAppointment). Reason: '2' Folderid: 'Ud42b6' message id 'Ud42b6:39f4b04e30b74bcd8c5378fcdb847d4d4e2201000000'
      30/09/2019 11:50:52 [53121] [WARN] [xxxxxxx] Mobile loop detected! Messages sent to the mobile will be restricted to 2 items in order to identify the conflict
      30/09/2019 11:50:52 [53121] [ERROR] [xxxxxxx] Ignored broken message (SyncAppointment). Reason: '2' Folderid: 'Ud42b6' message id 'Ud42b6:39f4b04e30b74bcd8c5378fcdb847d4d472201000000'
      30/09/2019 11:50:53 [57551] [WARN] [xxxxxxx] /usr/share/z-push/backend/kopano/mapiprovider.php:274 mapi_zarafa_getuser_by_name(): Unable to resolve the user: 8004010F (2)
      30/09/2019 11:50:54 [53122] [WARN] [xxxxxxx] Mobile loop detected! Messages sent to the mobile will be restricted to 1 items in order to identify the conflict
      30/09/2019 11:50:55 [41999] [WARN] [xxxxxxx] Mobile loop detected! Messages sent to the mobile will be restricted to 1 items in order to identify the conflict
      30/09/2019 11:50:55 [57549] [WARN] [xxxxxxx] Mobile loop detected! Messages sent to the mobile will be restricted to 1 items in order to identify the conflict
      30/09/2019 11:50:56 [65515] [WARN] [xxxxxxx] Mobile loop detected! Messages sent to the mobile will be restricted to 1 items in order to identify the conflict
      30/09/2019 11:50:59 [53121] [WARN] [xxxxxxx] /usr/share/z-push/backend/kopano/mapiprovider.php:274 mapi_zarafa_getuser_by_name(): Unable to resolve the user: 8004010F (2)
      30/09/2019 11:51:05 [41997] [WARN] [xxxxxxx] /usr/share/z-push/backend/kopano/mapiprovider.php:274 mapi_zarafa_getuser_by_name(): Unable to resolve the user: 8004010F (2)
      30/09/2019 11:51:06 [63107] [WARN] [xxxxxxx] Mobile loop detected! Messages sent to the mobile will be restricted to 1 items in order to identify the conflict
      30/09/2019 11:51:07 [57551] [WARN] [xxxxxxx] Mobile loop detected! Messages sent to the mobile will be restricted to 1 items in order to identify the conflict
      30/09/2019 11:51:08 [30327] [WARN] [xxxxxxx] Mobile loop detected! Messages sent to the mobile will be restricted to 1 items in order to identify the conflict```
      
      z-push-admin -a list -d xxxxxx
      
      
      DeviceId:               xxxxxxxx
      Device type:            iPhone
      UserAgent:              Apple-iPhone9C3/1701.854
      Device Model:           iPhone9C3
      Device friendly name:   iPhone 7
      Device OS:              iOS 13.1.1 17A854
      Device OS Language:     nl
      ActiveSync version:     14.1
      First sync:             2018-10-21 16:32
      Last sync:              2019-09-30 12:31
      Sync Period:            unlimited (0)
      Total folders:          15
      Short folder Ids:       Yes
      Synchronized folders:   13 (1 in progress)
      Synchronized data:      Emails(9) Contacts Calendars Notes Tasks
      Synchronization progress:
              Folder: Agenda               Sync: Synchronizing Status:  0% (0/275)
      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
      

      Looks like the agenda is not synchronizing
      Folder: Agenda Sync: Synchronizing Status: 0% (0/275)

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

        Hi @madpatrick,

        more information on loop detection is available in Z-Push wiki: https://wiki.z-hub.io/display/ZP/Loop+detection.

        It looks like you have some broken appointments. Did you run kopano-fsck on the user’s calendar?

        Manfred

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

          I’ve deleted a lot of old appointment which solved the synchronization.
          Unfortunately still error in the log

          kopano-fsk

          Statistics:
          IPF.Appointment
                  Folders:        1
                  Entries:        24
                  Problems:       0
                  Fixed:          0
                  Deleted:        0
          IPF.Contact
                  Folders:        1
                  Entries:        94
                  Problems:       0
                  Fixed:          0
                  Deleted:        0
          IPF.Task
                  Folders:        1
                  Entries:        2
                  Problems:       0
                  Fixed:          0
                  Deleted:        0
          
          

          The information on the wiki is not completely clear for me what to do.
          Therefor some assistance is appreciated

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

            Hi @madpatrick,

            what error is still in the log? Please provide WBXML level log for the request with the error.

            Did you run z-push-admin -a clearloop -u user -d deviceid after you deleted those old appointments?

            Manfred

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

              @Manfred

              I’ve run the clearloop command and also fixstates.
              Still getting the erros in the log.

              here my output of the WBXML log. I hope this helps to find the problem.

              02/10/2019 12:12:32 [60067] [WBXML] [linda] WBXML-IN : AwFqAEVcT0sDezk0N2YxYzNjLWRjZGYtNGM0MS1iYjYyLWM1OWVkNmQ3MDBhM30xAAFSA1VkNDJiNgABE1UDMjUAAVcAEUVGAzEAAUcDMzI3NjgAAQEBAQEB
              02/10/2019 12:12:32 [60067] [DEBUG] [linda] DeviceManager->Save(): Device data changed
              02/10/2019 12:12:32 [60067] [DEBUG] [linda] FileStateMachine->SetState() written 5006 bytes on file: '/var/lib/z-push/0/l/889d6c4jrd5f5e2lejtl6t1pl0-devicedata'
              02/10/2019 12:12:32 [60067] [DEBUG] [linda] DeviceManager->Save(): Device data saved
              02/10/2019 12:12:32 [60067] [DEBUG] [linda] LoopDetection->ProcessLoopDetectionTerminate()
              02/10/2019 12:12:32 [60067] [ INFO] [linda] cmd='Sync' memory='7.77 MiB/8.25 MiB' time='0.18s' devType='iPhone' devId='889d6c4jrd5f5e2lejtl6t1pl0' getUser='linda' from='192.168.1.195' idle='0s' version='2.5.1+0' method='POST' httpcode='200'
              02/10/2019 12:12:32 [60067] [DEBUG] [linda] -------- End
              02/10/2019 12:12:32 [45978] [DEBUG] [linda] -------- Start
              02/10/2019 12:12:32 [45978] [DEBUG] [linda] cmd='Sync' devType='iPhone' devId='889d6c4jrd5f5e2lejtl6t1pl0' getUser='linda' from='192.168.1.195' version='2.5.1+0' method='POST'
              02/10/2019 12:12:32 [45978] [DEBUG] [linda] Used timezone 'Europe/Amsterdam'
              02/10/2019 12:12:32 [45978] [DEBUG] [linda] ZPush::GetBackend(): trying autoload backend 'BackendKopano'
              02/10/2019 12:12:32 [45978] [DEBUG] [linda] BackendKopano using PHP-MAPI version: 8.5.8.2 - PHP version: 5.4.16
              02/10/2019 12:12:32 [45978] [DEBUG] [linda] Request::ProcessHeaders() ASVersion: 14.1
              02/10/2019 12:12:32 [45978] [DEBUG] [linda] ZPush::CommandNeedsProvisioning(0): true
              02/10/2019 12:12:32 [45978] [DEBUG] [linda] FileStateMachine->GetState() read '5006' bytes from file: '/var/lib/z-push/0/l/889d6c4jrd5f5e2lejtl6t1pl0-devicedata'
              02/10/2019 12:12:32 [45978] [DEBUG] [linda] ASDevice data loaded for user: 'linda'
              02/10/2019 12:12:32 [45978] [DEBUG] [linda] InterProcessData:__construct type: '889d6c4jrd5f5e2lejtl6t1pl0'
              02/10/2019 12:12:32 [45978] [DEBUG] [linda] TopCollector(): Initialized mutexid Resource id #58 and memid Resource id #59.
              02/10/2019 12:12:32 [45978] [DEBUG] [linda] TopCollector initialised with IPC provider 'IpcSharedMemoryProvider' with type '20'
              02/10/2019 12:12:33 [45978] [DEBUG] [linda] InterProcessData:__construct type: '889d6c4jrd5f5e2lejtl6t1pl0'
              02/10/2019 12:12:33 [45978] [DEBUG] [linda] LoopDetection(): Initialized mutexid Resource id #64 and memid Resource id #65.
              02/10/2019 12:12:33 [45978] [DEBUG] [linda] LoopDetection initialised with IPC provider 'IpcSharedMemoryProvider' with type '1337'
              02/10/2019 12:12:33 [45978] [DEBUG] [linda] ZPush::HierarchyCommand(0): false
              02/10/2019 12:12:33 [45978] [DEBUG] [linda] DeviceManager->ProvisioningRequired('811893419') saved device key '811893419': false
              02/10/2019 12:12:33 [45978] [DEBUG] [linda] DeviceManager->getPolicyName(): determined policy name: 'default'
              02/10/2019 12:12:33 [45978] [DEBUG] [linda] DeviceManager->getProvisioningPolicies(): loaded 'default' policy.
              02/10/2019 12:12:33 [45978] [DEBUG] [linda] ZPush::CommandNeedsAuthentication(0): true
              02/10/2019 12:12:33 [45978] [DEBUG] [linda] KopanoBackend->Logon(): Trying to authenticate user 'linda'..
              02/10/2019 12:12:33 [45978] [DEBUG] [linda] KopanoBackend->openMessageStore('linda'): Found 'DEFAULT' store: 'Resource id #80'
              02/10/2019 12:12:33 [45978] [DEBUG] [linda] KopanoBackend->Logon(): User 'linda' is authenticated
              02/10/2019 12:12:33 [45978] [DEBUG] [linda] Store supports properties containing Unicode characters.
              02/10/2019 12:12:33 [45978] [DEBUG] [linda] ZPush::CommandNeedsPlainInput(0): false
              02/10/2019 12:12:33 [45978] [WBXML] [linda] I  <Synchronize>
              02/10/2019 12:12:33 [45978] [WBXML] [linda] I   <Folders>
              02/10/2019 12:12:33 [45978] [WBXML] [linda] I    <Folder>
              02/10/2019 12:12:33 [45978] [WBXML] [linda] I     <SyncKey>
              02/10/2019 12:12:33 [45978] [WBXML] [linda] I      {3c3dfb1e-a426-4104-b576-3273433ca835}2
              02/10/2019 12:12:33 [45978] [WBXML] [linda] I     </SyncKey>
              02/10/2019 12:12:33 [45978] [WBXML] [linda] I     <FolderId>
              02/10/2019 12:12:33 [45978] [WBXML] [linda] I      Ud42b6
              02/10/2019 12:12:33 [45978] [WBXML] [linda] I     </FolderId>
              02/10/2019 12:12:33 [45978] [DEBUG] [linda] FileStateMachine->GetState() read '982' bytes from file: '/var/lib/z-push/0/l/889d6c4jrd5f5e2lejtl6t1pl0-947f1c3c-dcdf-4c41-bb62-c59ed6d700a3-fd'
              02/10/2019 12:12:33 [45978] [DEBUG] [linda] SyncParameters->UseCPO('DEFAULT')
              02/10/2019 12:12:33 [45978] [DEBUG] [linda] HandleSync(): Synckey does not match latest saved for this folder or there is a move state, removing folderstat to force Exporter setup
              02/10/2019 12:12:33 [45978] [DEBUG] [linda] DeviceManager->GetBackendIdForFolderId(): folderid Ud42b6 => 39f4b04e30b74bcd8c5378fcdb847d4d580000000000
              02/10/2019 12:12:33 [45978] [DEBUG] [linda] SyncCollections->AddCollection(): Folder id 'Ud42b6' : ref. PolicyKey '811893419', ref. Lifetime '889', last sync at '1570011152'
              02/10/2019 12:12:33 [45978] [DEBUG] [linda] SyncCollections->AddCollection(): Updated reference PolicyKey '811893419', reference Lifetime '889', Last sync at '1570011152'
              02/10/2019 12:12:33 [45978] [WBXML] [linda] I     <GetChanges/>
              02/10/2019 12:12:33 [45978] [WBXML] [linda] I     <WindowSize>
              02/10/2019 12:12:33 [45978] [WBXML] [linda] I      25
              02/10/2019 12:12:33 [45978] [WBXML] [linda] I     </WindowSize>
              02/10/2019 12:12:33 [45978] [WBXML] [linda] I     <Options>
              02/10/2019 12:12:33 [45978] [WBXML] [linda] I      <AirSyncBase:BodyPreference>
              02/10/2019 12:12:33 [45978] [DEBUG] [linda] SyncParameters->UseCPO('DEFAULT')
              02/10/2019 12:12:33 [45978] [WBXML] [linda] I       <AirSyncBase:Type>
              02/10/2019 12:12:33 [45978] [WBXML] [linda] I        1
              02/10/2019 12:12:33 [45978] [WBXML] [linda] I       </AirSyncBase:Type>
              02/10/2019 12:12:33 [45978] [WBXML] [linda] I       <AirSyncBase:TruncationSize>
              02/10/2019 12:12:33 [45978] [WBXML] [linda] I        32768
              02/10/2019 12:12:33 [45978] [WBXML] [linda] I       </AirSyncBase:TruncationSize>
              02/10/2019 12:12:33 [45978] [WBXML] [linda] I      </AirSyncBase:BodyPreference>
              02/10/2019 12:12:33 [45978] [WBXML] [linda] I     </Options>
              02/10/2019 12:12:33 [45978] [WBXML] [linda] I    </Folder>
              02/10/2019 12:12:33 [45978] [WBXML] [linda] I   </Folders>
              02/10/2019 12:12:33 [45978] [WBXML] [linda] I  </Synchronize>
              02/10/2019 12:12:33 [45978] [DEBUG] [linda] HandleSync(): Start Output
              02/10/2019 12:12:33 [45978] [DEBUG] [linda] HasFolderSyncStatus(): saved folder status for Ud42b6: 2
              02/10/2019 12:12:33 [45978] [DEBUG] [linda] Sync(): forcing exporter setup for 'Ud42b6' as a sync status is saved - ignoring backend folder stats
              02/10/2019 12:12:33 [45978] [DEBUG] [linda] Sync->loadStates(): loading states for folder 'Ud42b6'
              02/10/2019 12:12:33 [45978] [ INFO] [linda] StateNotFoundException: FileStateMachine->GetState(): Could not locate state '/var/lib/z-push/0/l/889d6c4jrd5f5e2lejtl6t1pl0-3c3dfb1e-a426-4104-b576-3273433ca835-2' - code: 0 - file: /usr/share/z-push/lib/default/filestatemachine.php:126
              02/10/2019 12:12:33 [45978] [DEBUG] [linda] WBXMLEncoder->startWBXML() type: vnd.ms-sync.wbxml
              02/10/2019 12:12:33 [45978] [DEBUG] [linda] Folder type: Calendar
              02/10/2019 12:12:33 [45978] [WBXML] [linda] O  <Synchronize>
              02/10/2019 12:12:33 [45978] [WBXML] [linda] O   <Folders>
              02/10/2019 12:12:33 [45978] [WBXML] [linda] O    <Folder>
              02/10/2019 12:12:33 [45978] [WBXML] [linda] O     <SyncKey>
              02/10/2019 12:12:33 [45978] [WBXML] [linda] O     {3c3dfb1e-a426-4104-b576-3273433ca835}2
              02/10/2019 12:12:33 [45978] [WBXML] [linda] O     </SyncKey>
              02/10/2019 12:12:33 [45978] [WBXML] [linda] O     <FolderId>
              02/10/2019 12:12:33 [45978] [WBXML] [linda] O     Ud42b6
              02/10/2019 12:12:33 [45978] [WBXML] [linda] O     </FolderId>
              02/10/2019 12:12:33 [45978] [WBXML] [linda] O     <Status>
              02/10/2019 12:12:33 [45978] [WBXML] [linda] O     3
              02/10/2019 12:12:33 [45978] [WBXML] [linda] O     </Status>
              02/10/2019 12:12:33 [45978] [DEBUG] [linda] LoopDetection->ProcessLoopDetectionAddStatus: 'Ud42b6' with status 3
              02/10/2019 12:12:33 [45978] [DEBUG] [linda] LoopDetection->Detect(): folderid:'Ud42b6' uuid:'3c3dfb1e-a426-4104-b576-3273433ca835' counter:'2' max:'25' queued:''
              02/10/2019 12:12:33 [45978] [DEBUG] [linda] LoopDetection->Detect(): UUID changed for folder
              02/10/2019 12:12:33 [45978] [DEBUG] [linda] LoopDetection->Detect(): UUID changed and while items where sent to device - forcing loop mode
              02/10/2019 12:12:33 [45978] [WARN] [linda] Mobile loop detected! Messages sent to the mobile will be restricted to 1 items in order to identify the conflict
              02/10/2019 12:12:33 [45978] [WBXML] [linda] O    </Folder>
              02/10/2019 12:12:33 [45978] [WBXML] [linda] O   </Folders>
              02/10/2019 12:12:33 [45978] [WBXML] [linda] O  </Synchronize>
              02/10/2019 12:12:33 [45978] [DEBUG] [linda] WBXMLEncoder->endTag() WBXML output completed
              
              1 Reply Last reply Reply Quote 0
              • Manfred
                Manfred Kopano last edited by

                Hi @madpatrick,

                the Z-Push states and the device states don’t match at least for calendar. Run z-push-admin -a resync -t calendar -u linda to resync the calendar only.

                If that doesn’t help, remove the account from the device, remove device from the list with z-push-admin -a remove -u linda -d 889d6c4jrd5f5e2lejtl6t1pl0, configure the account on the device again.

                Manfred

                madpatrick 2 Replies Last reply Reply Quote 1
                • madpatrick
                  madpatrick @Manfred last edited by

                  Hi @Manfred

                  I’ve removed the account and device as described.
                  Currently (approx. 2 hours) no errors in the log

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

                    @Manfred
                    The errors do not come back.
                    It looks like it appeared after an IOS13 upgrade.
                    With another user i had the same errors in the log after an updae to IOS13

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