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

    Z-Push / KOE not syncing anymore

    Synchronising (mobile) devices via Z-Push
    7
    31
    4586
    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.
    • icey
      icey last edited by

      Hi,

      i got lots of errors in th ez-push.log like:

      10/02/2018 14:04:50 [ 4642] [ INFO] [gustav] HandlePing(): unknown collection 'U21301', triggering HierarchySync
10/02/2018 14:04:50 [ 4642] [ INFO] [gustav] NoHierarchyCacheAvailableException: Folderid 'U21f33' is not fully synchronized on the device - code: 0 - file: /usr/share/z-push/lib/core/devicemanager.php:448
10/02/2018 14:04:50 [ 1910] [ INFO] [gustav] StateNotFoundException: No hierarchy UUID linked to device. Requesting folder resync. - code: 0 - file: /usr/share/z-push/lib/core/statemanager.php:486
10/02/2018 14:04:50 [ 4642] [ INFO] [gustav] HandlePing(): unknown collection 'U21f33', triggering HierarchySync
10/02/2018 14:04:50 [ 4642] [ INFO] [gustav] NoHierarchyCacheAvailableException: Folderid 'U2276b' is not fully synchronized on the device - code: 0 - file: /usr/share/z-push/lib/core/devicemanager.php:448
10/02/2018 14:04:50 [ 4642] [ INFO] [gustav] HandlePing(): unknown collection 'U2276b', triggering HierarchySync
10/02/2018 14:04:50 [ 4642] [ INFO] [gustav] NoHierarchyCacheAvailableException: Folderid 'U22f50' is not fully synchronized on the device - code: 0 - file: /usr/share/z-push/lib/core/devicemanager.php:448
10/02/2018 14:04:50 [ 4642] [ INFO] [gustav] HandlePing(): unknown collection 'U22f50', triggering HierarchySync
10/02/2018 14:04:50 [ 4642] [ INFO] [gustav] NoHierarchyCacheAvailableException: Folderid 'U23b41' is not fully synchronized on the device - code: 0 - file: /usr/share/z-push/lib/core/devicemanager.php:448
10/02/2018 14:04:50 [ 4642] [ INFO] [gustav] HandlePing(): unknown collection 'U23b41', triggering HierarchySync

10/02/2018 14:04:53 [ 1910] [ INFO] [gustav] StateNotFoundException: FileStateMachine->GetState(): Could not locate state '/var/lib/z-push/3/4/f728750dbe95435594c1a85d4e01ef43-6579ee23-fd3c-4628-a034-ccf1da8775ee-1' - code: 0 - file: /usr/share/z-push/lib/default/filestatemachine.php:119
10/02/2018 14:04:53 [ 1910] [ INFO] [gustav] StateNotFoundException: FileStateMachine->GetState(): Could not locate state '/var/lib/z-push/3/4/f728750dbe95435594c1a85d4e01ef43-ec062ab5-b7c8-4d7a-8828-35c57e6c14f1-1' - code: 0 - file: /usr/share/z-push/lib/default/filestatemachine.php:119
10/02/2018 14:04:53 [ 1910] [ INFO] [gustav] StateNotFoundException: FileStateMachine->GetState(): Could not locate state '/var/lib/z-push/3/4/f728750dbe95435594c1a85d4e01ef43-411f31c2-77c1-4a90-81b4-d5a65afbcd06-1' - code: 0 - file: /usr/share/z-push/lib/default/filestatemachine.php:119
10/02/2018 14:04:53 [ 1910] [ INFO] [gustav] StateNotFoundException: FileStateMachine->GetState(): Could not locate state '/var/lib/z-push/3/4/f728750dbe95435594c1a85d4e01ef43-0f355a4b-0e25-44c1-acd2-1dab7fe6c6c5-1' - code: 0 - file: /usr/share/z-push/lib/default/filestatemachine.php:119
10/02/2018 14:04:53 [ 1910] [ INFO] [gustav] StateNotFoundException: FileStateMachine->GetState(): Could not locate state '/var/lib/z-push/3/4/f728750dbe95435594c1a85d4e01ef43-a5639e80-dcf0-4283-9178-bee66a5d7d86-1' - code: 0 - file: /usr/share/z-push/lib/default/filestatemachine.php:119
10/02/2018 14:04:53 [ 1910] [ INFO] [gustav] StateNotFoundException: FileStateMachine->GetState(): Could not locate state '/var/lib/z-push/3/4/f728750dbe95435594c1a85d4e01ef43-7d96c1f2-645e-481d-9b9e-9220d641772a-1' - code: 0 - file: /usr/share/z-push/lib/default/filestatemachine.php:119
10/02/2018 14:04:53 [ 1910] [ INFO] [gustav] StateNotFoundException: FileStateMachine->GetState(): Could not locate state '/var/lib/z-push/3/4/f728750dbe95435594c1a85d4e01ef43-bac7e561-53c9-477c-a6db-4b5e75456c00-1' - code: 0 - file: /usr/share/z-push/lib/default/filestatemachine.php:119
10/02/2018 14:04:53 [ 1910] [ INFO] [gustav] StateNotFoundException: FileStateMachine->GetState(): Could not locate state '/var/lib/z-push/3/4/f728750dbe95435594c1a85d4e01ef43-89eea5dd-a9d8-485c-8a1f-b33ac5094209-1' - code: 0 - file: /usr/share/z-push/lib/default/filestatemachine.php:119
10/02/2018 14:04:53 [ 1910] [ INFO] [gustav] StateNotFoundException: FileStateMachine->GetState(): Could not locate state '/var/lib/z-push/3/4/f728750dbe95435594c1a85d4e01ef43-591c3c39-39f0-46bd-a80b-f93dbbca1706-1' - code: 0 - file: /usr/share/z-push/lib/default/filestatemachine.php:119
10/02/2018 14:04:53 [ 1910] [ INFO] [gustav] StateNotFoundException: FileStateMachine->GetState(): Could not locate state '/var/lib/z-push/3/4/f728750dbe95435594c1a85d4e01ef43-7af91ccb-f18b-4d4b-b201-5af4e558c7c5-1' - code: 0 - file: /usr/share/z-push/lib/default/filestatemachine.php:119
10/02/2018 14:04:53 [ 1910] [ INFO] [gustav] cmd='Sync' memory='7.02 MiB/7.75 MiB' time='0.85s' devType='WindowsOutlook' devId='f728750dbe95435594c1a85d4e01ef43' getUser='gustav' from='193.159.133.181' idle='0s' version='2.3.9' method='POST' httpcode='200'
10/02/2018 14:04:56 [ 1910] [ INFO] [gustav] cmd='Sync' memory='12.95 MiB/13.75 MiB' time='2.93s' devType='WindowsOutlook' devId='f728750dbe95435594c1a85d4e01ef43' getUser='gustav' from='193.159.133.181' idle='0s' version='2.3.9' method='POST' httpcode='200'
10/02/2018 14:04:57 [30887] [ INFO] [gustav] SyncCollections->CheckForChanges(): Waiting for store changes... (lifetime 3540 seconds)
10/02/2018 14:04:57 [30887] [ INFO] [gustav] cmd='Ping' memory='8.06 MiB/8.50 MiB' time='0.48s' devType='WindowsOutlook' devId='f728750dbe95435594c1a85d4e01ef43' getUser='gustav' from='193.159.133.181' idle='0s' version='2.3.9' method='POST' httpcode='200'
10/02/2018 14:04:58 [ 1910] [WARN] [gustav] Mobile loop detected! Messages sent to the mobile will be restricted to 1 items in order to identify the conflict
10/02/2018 14:05:07 [ 1910] [ INFO] [gustav] cmd='Sync' memory='11.41 MiB/12.25 MiB' time='10.02s' devType='WindowsOutlook' devId='f728750dbe95435594c1a85d4e01ef43' getUser='gustav' from='193.159.133.181' idle='0s' version='2.3.9' method='POST' httpcode='200'
10/02/2018 14:05:18 [ 4642] [ INFO] [gustav] SyncCollections->CheckForChanges(): Waiting for store changes... (lifetime 3540 seconds)
10/02/2018 14:05:18 [ 4642] [ INFO] [gustav] cmd='Ping' memory='7.82 MiB/8.25 MiB' time='0.43s' devType='WindowsOutlook' devId='f728750dbe95435594c1a85d4e01ef43' getUser='gustav' from='193.159.133.181' idle='0s' version='2.3.9' method='POST' httpcode='200'
10/02/2018 14:05:36 [ 4642] [ INFO] [markus] cmd='Sync' memory='2.35 MiB/3.00 MiB' time='0.06s' devType='iPhone' devId='k56o6sg1kp4lt6jj6t55mfd4tk' getUser='markus' from='193.159.133.181' idle='0s' version='2.3.9' method='POST' httpcode='200'
10/02/2018 14:05:36 [30887] [ INFO] [icey] cmd='Sync' memory='2.34 MiB/3.00 MiB' time='0.04s' devType='iPhone' devId='k56o6sg1kp4lt6jj6t55mfd4tk' getUser='icey' from='193.159.133.181' idle='0s' version='2.3.9' method='POST' httpcode='200'
10/02/2018 14:05:36 [ 4642] [ INFO] [markus] cmd='Sync' memory='2.35 MiB/3.00 MiB' time='0.04s' devType='iPhone' devId='k56o6sg1kp4lt6jj6t55mfd4tk' getUser='markus' from='193.159.133.181' idle='0s' version='2.3.9' method='POST' httpcode='200'
10/02/2018 14:05:39 [30887] [ INFO] [icey] cmd='Sync' memory='2.34 MiB/3.00 MiB' time='0.04s' devType='iPhone' devId='k56o6sg1kp4lt6jj6t55mfd4tk' getUser='icey' from='193.159.133.181' idle='0s' version='2.3.9' method='POST' httpcode='200'
10/02/2018 14:05:54 [ 1910] [ INFO] [gustav] SyncCollections->CheckForChanges(): Waiting for store changes... (lifetime 900 seconds)
10/02/2018 14:06:11 [ 2155] [ INFO] [gustav] StatusException: SyncCollections->CheckForChanges(): Timeout forced after 360s from 900s due to other process - code: 3 - file: /usr/share/z-push/lib/core/synccollections.php:579
10/02/2018 14:06:11 [ 2155] [ INFO] [gustav] cmd='Ping' memory='7.98 MiB/8.25 MiB' time='360.39s' devType='iPhone' devId='c3kf4d2u4d4ed81gqj9d40uf74' getUser='gustav' from='80.187.111.129' idle='360s' version='2.3.9' method='POST' httpcode='200'

      The device id with the fault is f728750dbe95435594c1a85d4e01ef43

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

        What are the file/folder permissions on /var/lib/z-push ? they should be of the web server you’re using (eg www-data for apache)

        rg
        christian

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

          Hi,

          so they are. owner and group are www-data and it is 0755

          Markus

          1 Reply Last reply Reply Quote 0
          • fbartels
            fbartels Kopano @icey last edited by fbartels

            @icey said in Z-Push / KOE not syncing anymore:

            What logs do you need and how should i post them?

            I’ve already posted link for you that explains how to get debug logging. To have something meaningful in the log you should enable the logging and the create a new profile in outlook.

            Since the log is the likely to big for a single post you could put it on a public pastebin.

            If you have a kopano subscription you could also attach the log to a service case.

            Regards Felix

            Resources:
            https://kopano.com/blog/how-to-get-kopano/
            https://documentation.kopano.io/
            https://kb.kopano.io/

            Support overview:
            https://kopano.com/support/

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

              Hi fbartels,

              i hope i got the logs you want :) i putted them on the server to doenload. They are indeed to big. Because i tried to sync a new client they are very full.
              http://sapper-plus.de/kopano.rar

              Thanks so far for helping.
              Markus

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

                Just briefly scrolled through the wbxml of the Outlook account. on first look I could not find anything suspicious. Did the sync already stop when you copied the file?

                Regards Felix

                Resources:
                https://kopano.com/blog/how-to-get-kopano/
                https://documentation.kopano.io/
                https://kb.kopano.io/

                Support overview:
                https://kopano.com/support/

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

                  Hi Felix,
                  it is indeed very curious… The log ends on 12:06 but the outlook is still opened, with the status “Folder Calendar is being syncronized” and the timestamp of the log is 14:12…
                  Do you need any further informations or logs?

                  Kind regards
                  Markus

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

                    Hi Markus,

                    is there more of gustav.log? Because there are errors in z-push.log at 14:50 and gustav.log ends at 12:06.

                    Manfred

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

                      Hi Manfred,
                      i just deleted the old log and gave a new try. Now i got many errors in the gustav.log… Also the outlook is hanging with ‘Folder calender is beeing syncronised’

                      17/02/2018 08:43:59 [18744] [DEBUG] [gustav] [f728750dbe95435594c1a85d4e01ef43] Sync(): no exporter setup for 'Uebd3b' as GlobalWindowSize is full.
17/02/2018 08:43:59 [18744] [DEBUG] [gustav] [f728750dbe95435594c1a85d4e01ef43] Global WindowSize for amount of exported changes reached, omitting output for collection.
17/02/2018 08:43:59 [18744] [DEBUG] [gustav] [f728750dbe95435594c1a85d4e01ef43] Sync(): no exporter setup for 'Uef5de' as GlobalWindowSize is full.
17/02/2018 08:43:59 [18744] [DEBUG] [gustav] [f728750dbe95435594c1a85d4e01ef43] Global WindowSize for amount of exported changes reached, omitting output for collection.
17/02/2018 08:43:59 [18744] [DEBUG] [gustav] [f728750dbe95435594c1a85d4e01ef43] Sync(): no exporter setup for 'Uf0896' as GlobalWindowSize is full.
17/02/2018 08:43:59 [18744] [DEBUG] [gustav] [f728750dbe95435594c1a85d4e01ef43] Global WindowSize for amount of exported changes reached, omitting output for collection.
17/02/2018 08:43:59 [18744] [DEBUG] [gustav] [f728750dbe95435594c1a85d4e01ef43] Sync(): no exporter setup for 'U1165b' as GlobalWindowSize is full.
17/02/2018 08:43:59 [18744] [DEBUG] [gustav] [f728750dbe95435594c1a85d4e01ef43] Global WindowSize for amount of exported changes reached, omitting output for collection.
17/02/2018 08:43:59 [18744] [DEBUG] [gustav] [f728750dbe95435594c1a85d4e01ef43] Sync(): no exporter setup for 'Uf3beb' as GlobalWindowSize is full.
17/02/2018 08:43:59 [18744] [DEBUG] [gustav] [f728750dbe95435594c1a85d4e01ef43] Global WindowSize for amount of exported changes reached, omitting output for collection.
17/02/2018 08:43:59 [18744] [DEBUG] [gustav] [f728750dbe95435594c1a85d4e01ef43] Sync(): no exporter setup for 'Uf9dfa' as GlobalWindowSize is full.
17/02/2018 08:43:59 [18744] [DEBUG] [gustav] [f728750dbe95435594c1a85d4e01ef43] Global WindowSize for amount of exported changes reached, omitting output for collection.
17/02/2018 08:43:59 [18744] [DEBUG] [gustav] [f728750dbe95435594c1a85d4e01ef43] Sync(): no exporter setup for 'Ufa01c' as GlobalWindowSize is full.
17/02/2018 08:43:59 [18744] [DEBUG] [gustav] [f728750dbe95435594c1a85d4e01ef43] Global WindowSize for amount of exported changes reached, omitting output for collection.
17/02/2018 08:43:59 [18744] [DEBUG] [gustav] [f728750dbe95435594c1a85d4e01ef43] Sync(): no exporter setup for 'Ufe2c4' as GlobalWindowSize is full.
17/02/2018 08:43:59 [18744] [DEBUG] [gustav] [f728750dbe95435594c1a85d4e01ef43] Global WindowSize for amount of exported changes reached, omitting output for collection.
17/02/2018 08:43:59 [18744] [DEBUG] [gustav] [f728750dbe95435594c1a85d4e01ef43] Sync(): no exporter setup for 'U96306' as GlobalWindowSize is full.
17/02/2018 08:43:59 [18744] [DEBUG] [gustav] [f728750dbe95435594c1a85d4e01ef43] Global WindowSize for amount of exported changes reached, omitting output for collection.
17/02/2018 08:43:59 [18744] [DEBUG] [gustav] [f728750dbe95435594c1a85d4e01ef43] Sync(): no exporter setup for 'U75bef' as GlobalWindowSize is full.
17/02/2018 08:43:59 [18744] [DEBUG] [gustav] [f728750dbe95435594c1a85d4e01ef43] Global WindowSize for amount of exported changes reached, omitting output for collection.
17/02/2018 08:43:59 [18744] [WBXML] [gustav] [f728750dbe95435594c1a85d4e01ef43] O   </Folders>
17/02/2018 08:43:59 [18744] [WBXML] [gustav] [f728750dbe95435594c1a85d4e01ef43] O  </Synchronize>
17/02/2018 08:43:59 [18744] [DEBUG] [gustav] [f728750dbe95435594c1a85d4e01ef43] WBXMLEncoder->endTag() WBXML output completed
17/02/2018 08:43:59 [18744] [WBXML] [gustav] [f728750dbe95435594c1a85d4e01ef43] WBXML-OUT: more than 512K of data
17/02/2018 08:43:59 [18744] [DEBUG] [gustav] [f728750dbe95435594c1a85d4e01ef43] HandleSync: Processed 163 folders
17/02/2018 08:43:59 [18744] [WBXML] [gustav] [f728750dbe95435594c1a85d4e01ef43] WBXML-IN : Aw(.....)AzUxMgABV1gDMAABYgMyAAFjAzgAAQARRUYDNAABSAMxAAEBAQEAAE9LA3tjZWQ4MzMzYy0wNjBmLQ==
17/02/2018 08:43:59 [18744] [DEBUG] [gustav] [f728750dbe95435594c1a85d4e01ef43] LoopDetection->ProcessLoopDetectionTerminate()
17/02/2018 08:43:59 [18744] [ INFO] [gustav] [f728750dbe95435594c1a85d4e01ef43] cmd='Sync' memory='7.07 MiB/7.75 MiB' time='1.82s' devType='WindowsOutlook' devId='f728750dbe95435594c1a85d4e01ef43' getUser='gustav' from='193.159.136.15' idle='0s' version='2.3.9' method='POST' httpcode='200'
17/02/2018 08:43:59 [18744] [DEBUG] [gustav] [f728750dbe95435594c1a85d4e01ef43] -------- End

                      z-push-error.log:

                      17/02/2018 08:03:46 [17207] [ERROR] [gustav] Ignored broken message (SyncMail). Reason: '2' Folderid: 'U81c68' message id 'U81c68:a898e84976e34829848f9b0e374f6630a69202000000'
17/02/2018 08:03:46 [17207] [WARN] [gustav] Mobile loop detected! Messages sent to the mobile will be restricted to 1 items in order to identify the conflict
17/02/2018 08:03:46 [17207] [WARN] [gustav] Mobile loop detected! Messages sent to the mobile will be restricted to 2 items in order to identify the conflict
17/02/2018 08:03:46 [17207] [ERROR] [gustav] Ignored broken message (SyncTask). Reason: '2' Folderid: 'U62dd1' message id 'U62dd1:a898e84976e34829848f9b0e374f66302c3d02000000'
17/02/2018 08:03:46 [17207] [WARN] [gustav] Mobile loop detected! Messages sent to the mobile will be restricted to 2 items in order to identify the conflict
17/02/2018 08:03:47 [17207] [ERROR] [gustav] Ignored broken message (SyncMail). Reason: '2' Folderid: 'U1165b' message id 'U1165b:a898e84976e34829848f9b0e374f6630c23e02000000'
17/02/2018 08:03:47 [17207] [WARN] [gustav] Mobile loop detected! Messages sent to the mobile will be restricted to 2 items in order to identify the conflict
17/02/2018 08:03:48 [17207] [ERROR] [gustav] Ignored broken message (SyncMail). Reason: '2' Folderid: 'U12150' message id 'U12150:a898e84976e34829848f9b0e374f6630277b02000000'
17/02/2018 08:42:04 [17207] [WARN] [gustav] Mobile loop detected! Messages sent to the mobile will be restricted to 1 items in order to identify the conflict
17/02/2018 08:42:04 [17207] [WARN] [gustav] Mobile loop detected! Messages sent to the mobile will be restricted to 1 items in order to identify the conflict
17/02/2018 08:43:58 [18744] [WARN] [gustav] [f728750dbe95435594c1a85d4e01ef43] Mobile loop detected! Messages sent to the mobile will be restricted to 1 items in order to identify the conflict
17/02/2018 08:43:58 [18744] [WARN] [gustav] [f728750dbe95435594c1a85d4e01ef43] Mobile loop detected! Messages sent to the mobile will be restricted to 1 items in order to identify the conflict
17/02/2018 08:43:58 [18744] [WARN] [gustav] [f728750dbe95435594c1a85d4e01ef43] Mobile loop detected! Messages sent to the mobile will be restricted to 1 items in order to identify the conflict
17/02/2018 08:43:59 [18744] [WARN] [gustav] [f728750dbe95435594c1a85d4e01ef43] SyncObject->Check(): object from type SyncMail: parameter 'from' contains an invalid email address '"" <>'. Address is removed.
17/02/2018 08:43:59 [18744] [WARN] [gustav] [f728750dbe95435594c1a85d4e01ef43] SyncObject->Check(): object from type SyncMail: parameter 'from' contains an invalid email address '"" <>'. Address is removed.
17/02/2018 08:43:59 [18744] [WARN] [gustav] [f728750dbe95435594c1a85d4e01ef43] SyncObject->Check(): object from type SyncMail: parameter 'from' contains an invalid email address '"" <>'. Address is removed.
17/02/2018 08:43:59 [18744] [WARN] [gustav] [f728750dbe95435594c1a85d4e01ef43] SyncObject->Check(): object from type SyncMail: parameter 'from' contains an invalid email address '"" <>'. Address is removed.
17/02/2018 08:43:59 [18744] [WARN] [gustav] [f728750dbe95435594c1a85d4e01ef43] SyncObject->Check(): object from type SyncMail: parameter 'from' contains an invalid email address '"" <>'. Address is removed.```

                      z-push.log

                      17/02/2018 08:43:57 [18744] [ INFO] [gustav] [] Options request
17/02/2018 08:43:57 [18744] [ INFO] [gustav] [] cmd='' memory='1.59 MiB/2.00 MiB' time='0.02s' devType='' devId='' getUser='gustav' from='193.159.136.15' idle='0s' version='2.3.9' method='OPTIONS' httpcode='200'
17/02/2018 08:43:57 [18744] [ INFO] [gustav] [f728750dbe95435594c1a85d4e01ef43] cmd='FolderSync' memory='4.40 MiB/4.75 MiB' time='0.08s' devType='WindowsOutlook' devId='f728750dbe95435594c1a85d4e01ef43' getUser='gustav' from='193.159.136.15' idle='0s' version='2.3.9' method='POST' httpcode='200'
17/02/2018 08:43:58 [18744] [WARN] [gustav] [f728750dbe95435594c1a85d4e01ef43] Mobile loop detected! Messages sent to the mobile will be restricted to 1 items in order to identify the conflict
17/02/2018 08:43:58 [18744] [WARN] [gustav] [f728750dbe95435594c1a85d4e01ef43] Mobile loop detected! Messages sent to the mobile will be restricted to 1 items in order to identify the conflict
17/02/2018 08:43:58 [18744] [WARN] [gustav] [f728750dbe95435594c1a85d4e01ef43] Mobile loop detected! Messages sent to the mobile will be restricted to 1 items in order to identify the conflict
17/02/2018 08:43:59 [18744] [WARN] [gustav] [f728750dbe95435594c1a85d4e01ef43] SyncObject->Check(): object from type SyncMail: parameter 'from' contains an invalid email address '"" <>'. Address is removed.
17/02/2018 08:43:59 [18744] [WARN] [gustav] [f728750dbe95435594c1a85d4e01ef43] SyncObject->Check(): object from type SyncMail: parameter 'from' contains an invalid email address '"" <>'. Address is removed.
17/02/2018 08:43:59 [18744] [WARN] [gustav] [f728750dbe95435594c1a85d4e01ef43] SyncObject->Check(): object from type SyncMail: parameter 'from' contains an invalid email address '"" <>'. Address is removed.
17/02/2018 08:43:59 [18744] [WARN] [gustav] [f728750dbe95435594c1a85d4e01ef43] SyncObject->Check(): object from type SyncMail: parameter 'from' contains an invalid email address '"" <>'. Address is removed.
17/02/2018 08:43:59 [18744] [WARN] [gustav] [f728750dbe95435594c1a85d4e01ef43] SyncObject->Check(): object from type SyncMail: parameter 'from' contains an invalid email address '"" <>'. Address is removed.
17/02/2018 08:43:59 [18744] [ INFO] [gustav] [f728750dbe95435594c1a85d4e01ef43] cmd='Sync' memory='7.07 MiB/7.75 MiB' time='1.82s' devType='WindowsOutlook' devId='f728750dbe95435594c1a85d4e01ef43' getUser='gustav' from='193.159.136.15' idle='0s' version='2.3.9' method='POST' httpcode='200'
17/02/2018 08:44:37 [17207] [ INFO] [gustav] [webservice] Announcing latest AS version to device: 12.0,12.1,14.0
17/02/2018 08:44:37 [17207] [ INFO] [gustav] [webservice] WebserviceDevice::GetDeviceDetails('6980e5336cb54957b08d23cb45e3e817'): getting device details from state of user 'gustav'
17/02/2018 08:44:37 [17207] [ INFO] [gustav] [webservice] cmd='WebserviceDevice' memory='5.65 MiB/6.25 MiB' time='0.21s' devType='webservice' devId='webservice' getUser='gustav' from='93.213.48.228' idle='0s' version='2.3.9' method='POST' httpcode='200'
17/02/2018 08:45:37 [17095] [ INFO] [gustav] [webservice] Announcing latest AS version to device: 12.0,12.1,14.0
17/02/2018 08:45:37 [17095] [ INFO] [gustav] [webservice] WebserviceDevice::GetDeviceDetails('6980e5336cb54957b08d23cb45e3e817'): getting device details from state of user 'gustav'
17/02/2018 08:45:37 [17095] [ INFO] [gustav] [webservice] cmd='WebserviceDevice' memory='5.65 MiB/6.25 MiB' time='0.20s' devType='webservice' devId='webservice' getUser='gustav' from='93.213.48.228' idle='0s' version='2.3.9' method='POST' httpcode='200'
17/02/2018 08:46:37 [18744] [ INFO] [gustav] [webservice] Announcing latest AS version to device: 12.0,12.1,14.0
17/02/2018 08:46:37 [18744] [ INFO] [gustav] [webservice] WebserviceDevice::GetDeviceDetails('6980e5336cb54957b08d23cb45e3e817'): getting device details from state of user 'gustav'
17/02/2018 08:46:37 [18744] [ INFO] [gustav] [webservice] cmd='WebserviceDevice' memory='5.65 MiB/6.25 MiB' time='0.22s' devType='webservice' devId='webservice' getUser='gustav' from='93.213.48.228' idle='0s' version='2.3.9' method='POST' httpcode='200'
17/02/2018 08:47:37 [18744] [ INFO] [gustav] [webservice] Announcing latest AS version to device: 12.0,12.1,14.0
17/02/2018 08:47:37 [18744] [ INFO] [gustav] [webservice] WebserviceDevice::GetDeviceDetails('6980e5336cb54957b08d23cb45e3e817'): getting device details from state of user 'gustav'
17/02/2018 08:47:37 [18744] [ INFO] [gustav] [webservice] cmd='WebserviceDevice' memory='5.65 MiB/6.25 MiB' time='0.21s' devType='webservice' devId='webservice' getUser='gustav' from='93.213.48.228' idle='0s' version='2.3.9' method='POST' httpcode='200'

                      Markus

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

                        These are no errors, but INFO and DEBUG messages! Errors would be FATAL, ERROR or even WARN.

                        You are in loop detection. Why is another question, but it’s per se no error.
                        You could try to force loop detection to terminate via z-push-admin. But if you have broken items in your store it will just kick in again.
                        Read more about loop detection here: https://wiki.z-hub.io/display/ZP/Loop+detection

                        Cheers,
                        Sebastian

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

                          H i Sebastian,
                          ok so far. When i delete the system wide loop detection data it syncs a few more mails and stops again… so how can i get closer to the prob. it is an outlook and i got a good network/inet connection…

                          Markus

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

                            Beto a WBXML log. The wiki has more details (debugging).

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

                              Hi Manfred and Sebastian,

                              i would like to provide you the wbxml.log. i am not getting an idea out of it :(
                              Hopefully you can find an error where i can solve the problem.

                              Thanks in advance

                              Markus

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

                                Hi Markus,

                                yes, you can post the link to the WBXML log and we will take a look at it.

                                Manfred

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

                                  Great, thanks! There you go: https://sapper-plus.de/log/gustav.rar

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

                                    Hi Markus,

                                    I’ve looked through the log and didn’t find anything obviously wrong. I have some questions though.

                                    There are quite some folders and messages you’re syncing. Have you tried synchronising 1 month instead of all items?

                                    What is the size of the .ost file associated to this Outlook profile?

                                    The both broken appointments, “Internorga 2013” and “Sapper Göppingen” have a quite unusual UID. Are they invitations from external system?

                                    Have you tried running kopano-fsck?

                                    Manfred

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

                                      Hi Manfred,
                                      thanks a lot so far. These two appointments had as date 01.01.1753. Why? I don’t know… May you tell how you found these? How did you search? I now get it synct up to 33% and it gets stucked again… So i would like to give it a try to find it by myself.
                                      You talked about kopano-fsck. don’t know this tool yet. when i make a --checkonly i get the following results:
                                      Statistics:

                                      IPF.Appointment
        Folders:        1
        Entries:        541
        Problems:       38
        Fixed:          0
        Deleted:        0
IPF.Contact
        Folders:        13
        Entries:        3387
        Problems:       293
        Fixed:          0
        Deleted:        0
IPF.Task
        Folders:        1
        Entries:        13
        Problems:       0
        Fixed:          0
        Deleted:        0

                                      Should i try a --autofix or what would you suggest? I can’t just delete all the contacts and so on…

                                      Thanks in advance
                                      Markus

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

                                        Hi Markus,

                                        I was looking for “potential broken message id” in the log and noticed the unusual uid. Now that you say the timestamp is pretty strange indeed as well.

                                        I would suggest you run kopano-fsck for calendar only without --autofix. If I remember correctly it will show you what it would fix, so that you can decide if you want to accept it or not.
                                        There are quite some contacts with problems, so running without --autofix might be quite tedious.
                                        Anyway, I think kopano-fsck should get you further in sync.

                                        Is it actually an older installation with some updates of Zarafa/Kopano or have you migrated from some other solution?

                                        Manfred

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

                                          Hi Manfred,
                                          no it is a running installation since years now. Originally it was Zarafa, then migrated to kopano, and since a few reinstallation and server movings it runs on that server since 2 years i think. without any probs so far. just i think after the last upate the probs began…
                                          So what is the indication for an unusual id? when it ends with “2000000” so then there would be many…
                                          kopano-fsck without an option asks if it should delete the item or not… a bit annoying to type 38 times “yes” \o/ ^^

                                          Regards
                                          Markus

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

                                            Hi Markus,

                                            the usual uids start with 0400000082… (e.g. 040000008200E00074C5B7101A82E0080000000000734468419CD301000000000000000010000000F59DB9B0B89CD0B831193088D7E52010).

                                            But it might be also other issues with the items, not uid only (like end before start or property value out of range defined in ActiveSync). It’s not easy to spot such issues.

                                            I didn’t remember that kopano-fsck was deleting items. But if you don’t need them anymore, that’s probably the way to go.

                                            Manfred

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