Z-Push / KOE not syncing anymore

Hi,

i am running out of ideas in troubleshooting an issue which appeared abou 1 month ago after updating. Several iOS Device are synced without probs so far. Just one outlook 2016 makes trouble. I tried also on a outlook 2013 without success. Its getting the first 400 Mails and then stops… I already tried to delete, wipe, remove, clearloop and fixstates with z-push-admin. No difference. Further updating to the latest didn´t bring any changes to that.
How can i get the prob solved? I would be glad about tips.

Kopano Core 8.5.81.197
Webapp 3.4.6.1210
MDM 2.1.0.28
z-push 2.3.8.beta2

Thanks in advance.

Best regards,
Markus

Some logging would be nice. https://wiki.z-hub.io/display/ZP/Debugging

PS: are you also using KOE? Outlook has shown to request some folder over and over again even if they are long gone on the backend. The only thing to solve this is to get rid of the profile in Outlook (resyncing from z-push-admin is not enough here).

Hi,
Same problem with Outlook, I have create many profil in Outlook and test in other computer.
After 1 month I don’t have solution and Kopano too :(
If you have solution I’m happy to know it

Best regard

Hi,

thanks for answering. Yeah i indeed have already tried to delete the whole profile, removed all .pst files and added a new profile. Also i have tried by another machine. Today i recongnized that it seems to stuck at the calender…
What logs do you need and how should i post them?
Best regards
Markus

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

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

Hi,

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

Markus

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

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

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?

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

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

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

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

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

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

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

Hi Markus,

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

Manfred

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

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

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