Problem mit P9 Lite Android 7 default mail-app and z-push
-
Hallo there.
We get the following error message with Z-push
If we use a Huawei P9 Lite under Android7 using the default mail appBetreff: Z-Push: Writing operation not permitted - data reset
Von: n**********
An: n*********
Cc:Dear n********
on 02.06.2017 at 10:50:27 you’ve tried to save a data in the folder ‘L***’ on your device ‘Android’ ID: ‘androidc348723896’.
This operation was not successful, as you lack write access to this folder.
Your data has been dropped and replaced with the original data on your device to ensure data integrity.with the Gmail app, there is no problem
With P9-Lite and Android6 and the standard mail there is no problem
We also use A Sony Expiria Z5 with Android7 and the standard mail app with this mobile phone there are no problems
Any ideas What I can adjust the P9-Lite with Android7 and the default mail app so this Z-Push error does not occur
regards Christian Hartmann
-
You should get this only if you try to edit in object in a read-only folder.
Which folder is this happening on? One of yours?Can you create a wbxml log, repeat the procedure and post/send the logs?
Cheers,
Sebastian -
02/06/2017 13:32:20 [ 4381] [DEBUG] [mcs] TopCollector(): Initialized mutexid Resource id #20 and memid Resource id #21. 02/06/2017 13:32:20 [ 4381] [DEBUG] [mcs] TopCollector initialised with IPC provider 'IpcSharedMemoryProvider' with type '20' 02/06/2017 13:32:20 [ 4381] [DEBUG] [mcs] LoopDetection(): Initialized mutexid Resource id #24 and memid Resource id #25. 02/06/2017 13:32:20 [ 4381] [DEBUG] [mcs] LoopDetection initialised with IPC provider 'IpcSharedMemoryProvider' with type '1337' 02/06/2017 13:32:20 [ 4381] [DEBUG] [mcs] ZPush::HierarchyCommand(18): false 02/06/2017 13:32:20 [ 4381] [DEBUG] [mcs] KopanoBackend->openMessageStore('mcs'): Found 'DEFAULT' store: 'Resource id #31' 02/06/2017 13:32:20 [ 4381] [DEBUG] [mcs] KopanoBackend->Logon(): User 'mcs' is authenticated 02/06/2017 13:32:20 [ 4381] [DEBUG] [mcs] Store supports properties containing Unicode characters. 02/06/2017 13:32:20 [ 4381] [DEBUG] [mcs] ZPush::CommandNeedsPlainInput(18): false 02/06/2017 13:32:20 [ 4381] [WBXML] [mcs] I <Ping:Ping> 02/06/2017 13:32:20 [ 4381] [DEBUG] [mcs] FileStateMachine->GetState() read '1027' bytes from file: '/var/lib/z-push/7/6/androidc1233927167-55e20ba6-a036-4c96-9d10-b2b17189df6a-fd' 02/06/2017 13:32:20 [ 4381] [DEBUG] [mcs] SyncParameters->UseCPO('DEFAULT') 02/06/2017 13:32:20 [ 4381] [DEBUG] [mcs] ASDevice->GetFolderIdForBackendId(): no valid condition found for determining folderid for backendid '0'. Returning as is! 02/06/2017 13:32:20 [ 4381] [DEBUG] [mcs] ZPush::GetAdditionalSyncFolderStore('83d0690bd687476995200a6b9c27b8e7a70700000000'): 'SYSTEM' 02/06/2017 13:32:20 [ 4381] [DEBUG] [mcs] KopanoBackend->openMessageStore('SYSTEM'): Found 'PUBLIC' store: 'Resource id #45' 02/06/2017 13:32:20 [ 4381] [DEBUG] [mcs] SyncCollections->AddCollection(): Folder id 'Ce5a84' : ref. PolicyKey '292307370', ref. Lifetime '1080', last sync at '1496403137' 02/06/2017 13:32:20 [ 4381] [DEBUG] [mcs] SyncCollections->AddCollection(): Updated reference PolicyKey '292307370', reference Lifetime '1080', Last sync at '1496403137' 02/06/2017 13:32:20 [ 4381] [DEBUG] [mcs] SyncParameters->GetLatestSyncKey(): '{55e20ba6-a036-4c96-9d10-b2b17189df6a}13' 02/06/2017 13:32:20 [ 4381] [DEBUG] [mcs] FileStateMachine->GetState() read '15' bytes from file: '/var/lib/z-push/7/6/androidc1233927167-55e20ba6-a036-4c96-9d10-b2b17189df6a-13' 02/06/2017 13:32:20 [ 4381] [DEBUG] [mcs] FileStateMachine->GetState() read '1071' bytes from file: '/var/lib/z-push/7/6/androidc1233927167-8259db08-ead9-496c-97bf-aba4a998d943-fd' 02/06/2017 13:32:20 [ 4381] [DEBUG] [mcs] SyncParameters->UseCPO('DEFAULT') 02/06/2017 13:32:20 [ 4381] [DEBUG] [mcs] ZPush::GetAdditionalSyncFolderStore('83d0690bd687476995200a6b9c27b8e70d1900000000'): 'false' 02/06/2017 13:32:20 [ 4381] [DEBUG] [mcs] SyncCollections->AddCollection(): Folder id 'U842a5' : ref. PolicyKey '292307370', ref. Lifetime '1080', last sync at '1496403139' 02/06/2017 13:32:20 [ 4381] [DEBUG] [mcs] SyncCollections->AddCollection(): Updated reference PolicyKey '292307370', reference Lifetime '1080', Last sync at '1496403139' 02/06/2017 13:32:20 [ 4381] [DEBUG] [mcs] SyncParameters->GetLatestSyncKey(): '{8259db08-ead9-496c-97bf-aba4a998d943}3' 02/06/2017 13:32:20 [ 4381] [DEBUG] [mcs] FileStateMachine->GetState() read '15' bytes from file: '/var/lib/z-push/7/6/androidc1233927167-8259db08-ead9-496c-97bf-aba4a998d943-3' 02/06/2017 13:32:20 [ 4381] [DEBUG] [mcs] FileStateMachine->GetState() read '1071' bytes from file: '/var/lib/z-push/7/6/androidc1233927167-eb474a16-8535-4c9a-af3b-2d7d9679249a-fd' 02/06/2017 13:32:20 [ 4381] [DEBUG] [mcs] SyncParameters->UseCPO('DEFAULT') 02/06/2017 13:32:20 [ 4381] [DEBUG] [mcs] ZPush::GetAdditionalSyncFolderStore('83d0690bd687476995200a6b9c27b8e7101900000000'): 'false' 02/06/2017 13:32:20 [ 4381] [DEBUG] [mcs] SyncCollections->AddCollection(): Folder id 'Ud7e8b' : ref. PolicyKey '292307370', ref. Lifetime '1080', last sync at '1496403139' 02/06/2017 13:32:20 [ 4381] [DEBUG] [mcs] SyncParameters->GetLatestSyncKey(): '{eb474a16-8535-4c9a-af3b-2d7d9679249a}5' 02/06/2017 13:32:20 [ 4381] [DEBUG] [mcs] FileStateMachine->GetState() read '15' bytes from file: '/var/lib/z-push/7/6/androidc1233927167-eb474a16-8535-4c9a-af3b-2d7d9679249a-5' 02/06/2017 13:32:20 [ 4381] [DEBUG] [mcs] FileStateMachine->GetState() read '1023' bytes from file: '/var/lib/z-push/7/6/androidc1233927167-e2f40e93-1b65-4a5d-b094-207930cf582d-fd' 02/06/2017 13:32:20 [ 4381] [DEBUG] [mcs] SyncParameters->UseCPO('DEFAULT') 02/06/2017 13:32:20 [ 4381] [DEBUG] [mcs] ZPush::GetAdditionalSyncFolderStore('83d0690bd687476995200a6b9c27b8e7111900000000'): 'false' 02/06/2017 13:32:20 [ 4381] [DEBUG] [mcs] SyncCollections->AddCollection(): Folder id 'U16666' : ref. PolicyKey '292307370', ref. Lifetime '480', last sync at '1496219518' 02/06/2017 13:32:20 [ 4381] [DEBUG] [mcs] SyncParameters->GetLatestSyncKey(): '{e2f40e93-1b65-4a5d-b094-207930cf582d}1' 02/06/2017 13:32:20 [ 4381] [DEBUG] [mcs] FileStateMachine->GetState() read '15' bytes from file: '/var/lib/z-push/7/6/androidc1233927167-e2f40e93-1b65-4a5d-b094-207930cf582d-1' 02/06/2017 13:32:20 [ 4381] [DEBUG] [mcs] FileStateMachine->GetState() read '1027' bytes from file: '/var/lib/z-push/7/6/androidc1233927167-9f21a772-192f-4dda-80d0-76ae7f58eec4-fd' 02/06/2017 13:32:20 [ 4381] [DEBUG] [mcs] SyncParameters->UseCPO('DEFAULT') 02/06/2017 13:32:20 [ 4381] [DEBUG] [mcs] ZPush::GetAdditionalSyncFolderStore('83d0690bd687476995200a6b9c27b8e7121900000000'): 'false' 02/06/2017 13:32:20 [ 4381] [DEBUG] [mcs] SyncCollections->AddCollection(): Folder id 'U8f840' : ref. PolicyKey '292307370', ref. Lifetime '480', last sync at '1496219519' 02/06/2017 13:32:20 [ 4381] [DEBUG] [mcs] SyncParameters->GetLatestSyncKey(): '{9f21a772-192f-4dda-80d0-76ae7f58eec4}1' 02/06/2017 13:32:20 [ 4381] [DEBUG] [mcs] FileStateMachine->GetState() read '15' bytes from file: '/var/lib/z-push/7/6/androidc1233927167-9f21a772-192f-4dda-80d0-76ae7f58eec4-1' 02/06/2017 13:32:20 [ 4381] [DEBUG] [mcs] FileStateMachine->GetState() read '379' bytes from file: '/var/lib/z-push/7/6/androidc1233927167-24c2261f-db0b-4406-bc71-9ff71bc4f765-fd' 02/06/2017 13:32:20 [ 4381] [DEBUG] [mcs] SyncParameters->UseCPO('DEFAULT') 02/06/2017 13:32:20 [ 4381] [DEBUG] [mcs] SyncCollections->AddCollection(): Folder id '' : ref. PolicyKey '292307370', ref. Lifetime '10', last sync at '1496219509' 02/06/2017 13:32:20 [ 4381] [DEBUG] [mcs] SyncParameters->GetLatestSyncKey(): '{24c2261f-db0b-4406-bc71-9ff71bc4f765}1' 02/06/2017 13:32:20 [ 4381] [DEBUG] [mcs] StateManager->loadHierarchyCache(): 'androidc1233927167-24c2261f-db0b-4406-bc71-9ff71bc4f765-hc-1' 02/06/2017 13:32:20 [ 4381] [DEBUG] [mcs] FileStateMachine->GetState() read '3169' bytes from file: '/var/lib/z-push/7/6/androidc1233927167-24c2261f-db0b-4406-bc71-9ff71bc4f765-hc-1' 02/06/2017 13:32:20 [ 4381] [DEBUG] [mcs] FileStateMachine->GetState() read '15' bytes from file: '/var/lib/z-push/7/6/androidc1233927167-24c2261f-db0b-4406-bc71-9ff71bc4f765-1' 02/06/2017 13:32:20 [ 4381] [DEBUG] [mcs] HandlePing(): reference PolicyKey for PING: 292307370 02/06/2017 13:32:20 [ 4381] [DEBUG] [mcs] HandlePing(): initialization data received 02/06/2017 13:32:20 [ 4381] [WBXML] [mcs] I <Ping:LifeTime> 02/06/2017 13:32:20 [ 4381] [WBXML] [mcs] I 1080 02/06/2017 13:32:20 [ 4381] [WBXML] [mcs] I </Ping:LifeTime> 02/06/2017 13:32:20 [ 4381] [WBXML] [mcs] I <Ping:Folders> 02/06/2017 13:32:20 [ 4381] [WBXML] [mcs] I <Ping:Folder> 02/06/2017 13:32:20 [ 4381] [WBXML] [mcs] I <Ping:ServerEntryId> 02/06/2017 13:32:20 [ 4381] [WBXML] [mcs] I Ce5a84 02/06/2017 13:32:20 [ 4381] [WBXML] [mcs] I </Ping:ServerEntryId> 02/06/2017 13:32:20 [ 4381] [WBXML] [mcs] I <Ping:FolderType> 02/06/2017 13:32:20 [ 4381] [WBXML] [mcs] I Contacts 02/06/2017 13:32:20 [ 4381] [WBXML] [mcs] I </Ping:FolderType> 02/06/2017 13:32:20 [ 4381] [WBXML] [mcs] I </Ping:Folder> 02/06/2017 13:32:20 [ 4381] [DEBUG] [mcs] HandlePing(): using saved sync state for 'Contacts' id 'Ce5a84' 02/06/2017 13:32:20 [ 4381] [WBXML] [mcs] I <Ping:Folder> 02/06/2017 13:32:20 [ 4381] [WBXML] [mcs] I <Ping:ServerEntryId> 02/06/2017 13:32:20 [ 4381] [WBXML] [mcs] I U842a5 02/06/2017 13:32:20 [ 4381] [WBXML] [mcs] I </Ping:ServerEntryId> 02/06/2017 13:32:20 [ 4381] [WBXML] [mcs] I <Ping:FolderType> 02/06/2017 13:32:20 [ 4381] [WBXML] [mcs] I Email 02/06/2017 13:32:20 [ 4381] [WBXML] [mcs] I </Ping:FolderType> 02/06/2017 13:32:20 [ 4381] [WBXML] [mcs] I </Ping:Folder> 02/06/2017 13:32:20 [ 4381] [DEBUG] [mcs] HandlePing(): using saved sync state for 'Email' id 'U842a5' 02/06/2017 13:32:20 [ 4381] [WBXML] [mcs] I <Ping:Folder> 02/06/2017 13:32:20 [ 4381] [WBXML] [mcs] I <Ping:ServerEntryId> 02/06/2017 13:32:20 [ 4381] [WBXML] [mcs] I Ud7e8b 02/06/2017 13:32:20 [ 4381] [WBXML] [mcs] I </Ping:ServerEntryId> 02/06/2017 13:32:20 [ 4381] [WBXML] [mcs] I <Ping:FolderType> 02/06/2017 13:32:20 [ 4381] [WBXML] [mcs] I Email 02/06/2017 13:32:20 [ 4381] [WBXML] [mcs] I </Ping:FolderType> 02/06/2017 13:32:20 [ 4381] [WBXML] [mcs] I </Ping:Folder> 02/06/2017 13:32:20 [ 4381] [DEBUG] [mcs] HandlePing(): using saved sync state for 'Email' id 'Ud7e8b' 02/06/2017 13:32:20 [ 4381] [WBXML] [mcs] I <Ping:Folder> 02/06/2017 13:32:20 [ 4381] [WBXML] [mcs] I <Ping:ServerEntryId> 02/06/2017 13:32:20 [ 4381] [WBXML] [mcs] I U16666 02/06/2017 13:32:20 [ 4381] [WBXML] [mcs] I </Ping:ServerEntryId> 02/06/2017 13:32:20 [ 4381] [WBXML] [mcs] I <Ping:FolderType> 02/06/2017 13:32:20 [ 4381] [WBXML] [mcs] I Contacts 02/06/2017 13:32:20 [ 4381] [WBXML] [mcs] I </Ping:FolderType> 02/06/2017 13:32:20 [ 4381] [WBXML] [mcs] I </Ping:Folder> 02/06/2017 13:32:20 [ 4381] [DEBUG] [mcs] HandlePing(): using saved sync state for 'Contacts' id 'U16666' 02/06/2017 13:32:20 [ 4381] [WBXML] [mcs] I <Ping:Folder> 02/06/2017 13:32:20 [ 4381] [WBXML] [mcs] I <Ping:ServerEntryId> 02/06/2017 13:32:20 [ 4381] [WBXML] [mcs] I U8f840 02/06/2017 13:32:20 [ 4381] [WBXML] [mcs] I </Ping:ServerEntryId> 02/06/2017 13:32:20 [ 4381] [WBXML] [mcs] I <Ping:FolderType> 02/06/2017 13:32:20 [ 4381] [WBXML] [mcs] I Calendar 02/06/2017 13:32:20 [ 4381] [WBXML] [mcs] I </Ping:FolderType> 02/06/2017 13:32:20 [ 4381] [WBXML] [mcs] I </Ping:Folder> 02/06/2017 13:32:20 [ 4381] [DEBUG] [mcs] HandlePing(): using saved sync state for 'Calendar' id 'U8f840' 02/06/2017 13:32:20 [ 4381] [WBXML] [mcs] I </Ping:Folders> 02/06/2017 13:32:20 [ 4381] [WBXML] [mcs] I </Ping:Ping> 02/06/2017 13:32:20 [ 4381] [DEBUG] [mcs] SyncCollections->SaveCollection(): Data of folder 'U842a5' changed 02/06/2017 13:32:20 [ 4381] [DEBUG] [mcs] FileStateMachine->SetState() written 1045 bytes on file: '/var/lib/z-push/7/6/androidc1233927167-8259db08-ead9-496c-97bf-aba4a998d943-fd' 02/06/2017 13:32:20 [ 4381] [DEBUG] [mcs] SyncCollections->SaveCollection(): Data of folder 'Ud7e8b' changed 02/06/2017 13:32:20 [ 4381] [DEBUG] [mcs] FileStateMachine->SetState() written 1045 bytes on file: '/var/lib/z-push/7/6/androidc1233927167-eb474a16-8535-4c9a-af3b-2d7d9679249a-fd' 02/06/2017 13:32:20 [ 4381] [DEBUG] [mcs] DeviceManager->DoAutomaticASDeviceSaving(): save automatically: false 02/06/2017 13:32:20 [ 4381] [DEBUG] [mcs] PingTracking(): Initialized mutexid Resource id #155 and memid Resource id #156. 02/06/2017 13:32:20 [ 4381] [DEBUG] [mcs] PingTracking initialised with IPC provider 'IpcSharedMemoryProvider' with type '2' 02/06/2017 13:32:20 [ 4381] [DEBUG] [mcs] Announce process as PUSH connection 02/06/2017 13:32:20 [ 4381] [ INFO] [mcs] SyncCollections->CheckForChanges(): Waiting for store changes... (lifetime 1080 seconds) 02/06/2017 13:32:20 [ 4381] [DEBUG] [mcs] KopanoBackend->HasChangesSink(): created - HierarchyHash: 55f1012ab6e750749e116a68fb4045d1 02/06/2017 13:32:20 [ 4381] [DEBUG] [mcs] KopanoBackend->adviseStoreToSink(): advised store 'Resource id #31' 02/06/2017 13:32:20 [ 4381] [DEBUG] [mcs] ZPush::GetAdditionalSyncFolderStore('83d0690bd687476995200a6b9c27b8e7a70700000000'): 'SYSTEM' 02/06/2017 13:32:20 [ 4381] [DEBUG] [mcs] KopanoBackend->ChangesSinkInitialize(): folderid '83d0690bd687476995200a6b9c27b8e7a70700000000' 02/06/2017 13:32:20 [ 4381] [DEBUG] [mcs] KopanoBackend->adviseStoreToSink(): advised store 'Resource id #45' 02/06/2017 13:32:20 [ 4381] [DEBUG] [mcs] KopanoBackend->GetFolderStat() fetched status information of 6 folders for store 'SYSTEM' 02/06/2017 13:32:20 [ 4381] [DEBUG] [mcs] SyncParameters->IsExporterRunRequired(): false - current: 1496391927/75/0/0 - saved: 1496391927/75/0/0 - expiring: 2017-07-03 13:32:18 02/06/2017 13:32:20 [ 4381] [DEBUG] [mcs] ZPush::GetAdditionalSyncFolderStore('83d0690bd687476995200a6b9c27b8e70d1900000000'): 'false' 02/06/2017 13:32:20 [ 4381] [DEBUG] [mcs] KopanoBackend->ChangesSinkInitialize(): folderid '83d0690bd687476995200a6b9c27b8e70d1900000000' 02/06/2017 13:32:20 [ 4381] [DEBUG] [mcs] KopanoBackend->GetFolderStat() fetched status information of 23 folders for store 'mcs' 02/06/2017 13:32:20 [ 4381] [DEBUG] [mcs] SyncParameters->IsExporterRunRequired(): false - current: 1496403138/3/3/0 - saved: 1496403138/3/3/0 - expiring: 2017-06-09 13:32:19 02/06/2017 13:32:20 [ 4381] [DEBUG] [mcs] ZPush::GetAdditionalSyncFolderStore('83d0690bd687476995200a6b9c27b8e7101900000000'): 'false' 02/06/2017 13:32:20 [ 4381] [DEBUG] [mcs] KopanoBackend->ChangesSinkInitialize(): folderid '83d0690bd687476995200a6b9c27b8e7101900000000' 02/06/2017 13:32:20 [ 4381] [DEBUG] [mcs] SyncParameters->IsExporterRunRequired(): false - current: 0000000000/6/0/0 - saved: 0000000000/6/0/0 - expiring: 2017-06-09 13:32:19 02/06/2017 13:32:20 [ 4381] [DEBUG] [mcs] ZPush::GetAdditionalSyncFolderStore('83d0690bd687476995200a6b9c27b8e7111900000000'): 'false' 02/06/2017 13:32:20 [ 4381] [DEBUG] [mcs] KopanoBackend->ChangesSinkInitialize(): folderid '83d0690bd687476995200a6b9c27b8e7111900000000' 02/06/2017 13:32:20 [ 4381] [DEBUG] [mcs] SyncParameters->IsExporterRunRequired(): false - current: 0000000000/0/0/0 - saved: 0000000000/0/0/0 - expiring: 2017-07-01 10:31:58 02/06/2017 13:32:20 [ 4381] [DEBUG] [mcs] ZPush::GetAdditionalSyncFolderStore('83d0690bd687476995200a6b9c27b8e7121900000000'): 'false' 02/06/2017 13:32:20 [ 4381] [DEBUG] [mcs] KopanoBackend->ChangesSinkInitialize(): folderid '83d0690bd687476995200a6b9c27b8e7121900000000' 02/06/2017 13:32:20 [ 4381] [DEBUG] [mcs] SyncParameters->IsExporterRunRequired(): false - current: 1495612447/0/0/0 - saved: 1495612447/0/0/0 - expiring: 2017-06-14 10:31:59 02/06/2017 13:32:20 [ 4381] [DEBUG] [mcs] ASDevice->GetHierarchyCache(): HierarchyCache is up - Cached objects: 12 02/06/2017 13:32:20 [ 4381] [DEBUG] [mcs] ZPush::GetAdditionalSyncFolders(): Requested AS folderids as keys for additional folders array, converting 02/06/2017 13:32:20 [ 4381] [DEBUG] [mcs] ChangesMemoryWrapper->Config(AdditionalFolders) : process folder 'Lohr' 02/06/2017 13:32:20 [ 4381] [DEBUG] [mcs] KopanoBackend->Setup(): Checking for 'read' ACLs on '83d0690bd687476995200a6b9c27b8e7a70700000000' of store 'SYSTEM': 'true' 02/06/2017 13:32:20 [ 4381] [DEBUG] [mcs] ChangesMemoryWrapper->ImportFolderChange(): Change for folder 'Lohr' will not be sent as modification is not relevant. 02/06/2017 13:32:20 [ 4381] [DEBUG] [mcs] ExportChangesICS->Config() initialized with state: 0xcb020000e1400000 02/06/2017 13:32:20 [ 4381] [DEBUG] [mcs] ExportChangesICS->InitializeExporter() successfully. 0 changes ready to sync for 'hierarchy'. 02/06/2017 13:32:21 [ 4356] [ INFO] [bcr] StatusException: SyncCollections->CheckForChanges(): Timeout forced after 631s from 1514s due to other process - code: 3 - file: /usr/share/z-push/lib/core/synccollections.php:572 02/06/2017 13:32:21 [ 4356] [ INFO] [bcr] cmd='Ping' memory='3.92 MiB/4.50 MiB' time='630.26s' devType='iPhone' devId='5b65apcn617u5et47v60rlprvs' getUser='bcr' from='213.225.10.242' idle='631s' version='2.3.6+0' method='POST' httpcode='200' 02/06/2017 13:32:24 [ 4356] [DEBUG] [mcs] -------- Start 02/06/2017 13:32:24 [ 4356] [DEBUG] [mcs] cmd='Ping' devType='Android' devId='androidc1233927167' getUser='mcs' from='62.218.146.171' version='2.3.6+0' method='POST' 02/06/2017 13:32:24 [ 4356] [DEBUG] [mcs] Used timezone 'Europe/Vienna' 02/06/2017 13:32:24 [ 4356] [DEBUG] [mcs] ZPush::GetBackend(): trying autoload backend 'BackendKopano' 02/06/2017 13:32:24 [ 4356] [DEBUG] [mcs] BackendKopano using PHP-MAPI version: 8.3.0-1042 - PHP version: 5.6.30-0+deb8u1 02/06/2017 13:32:24 [ 4356] [DEBUG] [mcs] Request::ProcessHeaders() ASVersion: 14.0 02/06/2017 13:32:24 [ 4356] [DEBUG] [mcs] ZPush::CommandNeedsProvisioning(18): false 02/06/2017 13:32:24 [ 4356] [DEBUG] [mcs] ZPush::CommandNeedsAuthentication(18): true 02/06/2017 13:32:24 [ 4356] [DEBUG] [mcs] KopanoBackend->Logon(): Trying to authenticate user 'mcs'.. 02/06/2017 13:32:24 [ 4356] [DEBUG] [mcs] FileStateMachine->GetState() read '2225' bytes from file: '/var/lib/z-push/7/6/androidc1233927167-devicedata' 02/06/2017 13:32:24 [ 4356] [DEBUG] [mcs] ASDevice data loaded for user: 'mcs' 02/06/2017 13:32:24 [ 4356] [DEBUG] [mcs] TopCollector(): Initialized mutexid Resource id #20 and memid Resource id #21. 02/06/2017 13:32:24 [ 4356] [DEBUG] [mcs] TopCollector initialised with IPC provider 'IpcSharedMemoryProvider' with type '20' 02/06/2017 13:32:24 [ 4356] [DEBUG] [mcs] LoopDetection(): Initialized mutexid Resource id #24 and memid Resource id #25. 02/06/2017 13:32:24 [ 4356] [DEBUG] [mcs] LoopDetection initialised with IPC provider 'IpcSharedMemoryProvider' with type '1337' 02/06/2017 13:32:24 [ 4356] [DEBUG] [mcs] ZPush::HierarchyCommand(18): false 02/06/2017 13:32:24 [ 4356] [DEBUG] [mcs] KopanoBackend->openMessageStore('mcs'): Found 'DEFAULT' store: 'Resource id #31' 02/06/2017 13:32:24 [ 4356] [DEBUG] [mcs] KopanoBackend->Logon(): User 'mcs' is authenticated 02/06/2017 13:32:24 [ 4356] [DEBUG] [mcs] Store supports properties containing Unicode characters. 02/06/2017 13:32:24 [ 4356] [DEBUG] [mcs] ZPush::CommandNeedsPlainInput(18): false 02/06/2017 13:32:24 [ 4356] [WBXML] [mcs] I <Ping:Ping> 02/06/2017 13:32:24 [ 4356] [DEBUG] [mcs] FileStateMachine->GetState() read '1027' bytes from file: '/var/lib/z-push/7/6/androidc1233927167-55e20ba6-a036-4c96-9d10-b2b17189df6a-fd' 02/06/2017 13:32:24 [ 4356] [DEBUG] [mcs] SyncParameters->UseCPO('DEFAULT') 02/06/2017 13:32:24 [ 4356] [DEBUG] [mcs] ASDevice->GetFolderIdForBackendId(): no valid condition found for determining folderid for backendid '0'. Returning as is! 02/06/2017 13:32:24 [ 4356] [DEBUG] [mcs] ZPush::GetAdditionalSyncFolderStore('83d0690bd687476995200a6b9c27b8e7a70700000000'): 'SYSTEM' 02/06/2017 13:32:24 [ 4356] [DEBUG] [mcs] KopanoBackend->openMessageStore('SYSTEM'): Found 'PUBLIC' store: 'Resource id #45' 02/06/2017 13:32:24 [ 4356] [DEBUG] [mcs] SyncCollections->AddCollection(): Folder id 'Ce5a84' : ref. PolicyKey '292307370', ref. Lifetime '1080', last sync at '1496403137' 02/06/2017 13:32:24 [ 4356] [DEBUG] [mcs] SyncCollections->AddCollection(): Updated reference PolicyKey '292307370', reference Lifetime '1080', Last sync at '1496403137' 02/06/2017 13:32:24 [ 4356] [DEBUG] [mcs] SyncParameters->GetLatestSyncKey(): '{55e20ba6-a036-4c96-9d10-b2b17189df6a}13' 02/06/2017 13:32:24 [ 4356] [DEBUG] [mcs] FileStateMachine->GetState() read '15' bytes from file: '/var/lib/z-push/7/6/androidc1233927167-55e20ba6-a036-4c96-9d10-b2b17189df6a-13' 02/06/2017 13:32:24 [ 4356] [DEBUG] [mcs] FileStateMachine->GetState() read '1045' bytes from file: '/var/lib/z-push/7/6/androidc1233927167-8259db08-ead9-496c-97bf-aba4a998d943-fd' 02/06/2017 13:32:24 [ 4356] [DEBUG] [mcs] SyncParameters->UseCPO('DEFAULT') 02/06/2017 13:32:24 [ 4356] [DEBUG] [mcs] ZPush::GetAdditionalSyncFolderStore('83d0690bd687476995200a6b9c27b8e70d1900000000'): 'false' 02/06/2017 13:32:24 [ 4356] [DEBUG] [mcs] SyncCollections->AddCollection(): Folder id 'U842a5' : ref. PolicyKey '292307370', ref. Lifetime '1080', last sync at '1496403139' 02/06/2017 13:32:24 [ 4356] [DEBUG] [mcs] SyncCollections->AddCollection(): Updated reference PolicyKey '292307370', reference Lifetime '1080', Last sync at '1496403139' 02/06/2017 13:32:24 [ 4356] [DEBUG] [mcs] SyncParameters->GetLatestSyncKey(): '{8259db08-ead9-496c-97bf-aba4a998d943}3' 02/06/2017 13:32:24 [ 4356] [DEBUG] [mcs] FileStateMachine->GetState() read '15' bytes from file: '/var/lib/z-push/7/6/androidc1233927167-8259db08-ead9-496c-97bf-aba4a998d943-3' 02/06/2017 13:32:24 [ 4356] [DEBUG] [mcs] FileStateMachine->GetState() read '1045' bytes from file: '/var/lib/z-push/7/6/androidc1233927167-eb474a16-8535-4c9a-af3b-2d7d9679249a-fd' 02/06/2017 13:32:24 [ 4356] [DEBUG] [mcs] SyncParameters->UseCPO('DEFAULT') 02/06/2017 13:32:24 [ 4356] [DEBUG] [mcs] ZPush::GetAdditionalSyncFolderStore('83d0690bd687476995200a6b9c27b8e7101900000000'): 'false' 02/06/2017 13:32:24 [ 4356] [DEBUG] [mcs] SyncCollections->AddCollection(): Folder id 'Ud7e8b' : ref. PolicyKey '292307370', ref. Lifetime '1080', last sync at '1496403139' 02/06/2017 13:32:24 [ 4356] [DEBUG] [mcs] SyncParameters->GetLatestSyncKey(): '{eb474a16-8535-4c9a-af3b-2d7d9679249a}5' 02/06/2017 13:32:24 [ 4356] [DEBUG] [mcs] FileStateMachine->GetState() read '15' bytes from file: '/var/lib/z-push/7/6/androidc1233927167-eb474a16-8535-4c9a-af3b-2d7d9679249a-5' 02/06/2017 13:32:24 [ 4356] [DEBUG] [mcs] FileStateMachine->GetState() read '1023' bytes from file: '/var/lib/z-push/7/6/androidc1233927167-e2f40e93-1b65-4a5d-b094-207930cf582d-fd' 02/06/2017 13:32:24 [ 4356] [DEBUG] [mcs] SyncParameters->UseCPO('DEFAULT') 02/06/2017 13:32:24 [ 4356] [DEBUG] [mcs] ZPush::GetAdditionalSyncFolderStore('83d0690bd687476995200a6b9c27b8e7111900000000'): 'false' 02/06/2017 13:32:24 [ 4356] [DEBUG] [mcs] SyncCollections->AddCollection(): Folder id 'U16666' : ref. PolicyKey '292307370', ref. Lifetime '480', last sync at '1496219518' 02/06/2017 13:32:24 [ 4356] [DEBUG] [mcs] SyncParameters->GetLatestSyncKey(): '{e2f40e93-1b65-4a5d-b094-207930cf582d}1' 02/06/2017 13:32:24 [ 4356] [DEBUG] [mcs] FileStateMachine->GetState() read '15' bytes from file: '/var/lib/z-push/7/6/androidc1233927167-e2f40e93-1b65-4a5d-b094-207930cf582d-1' 02/06/2017 13:32:24 [ 4356] [DEBUG] [mcs] FileStateMachine->GetState() read '1027' bytes from file: '/var/lib/z-push/7/6/androidc1233927167-9f21a772-192f-4dda-80d0-76ae7f58eec4-fd' 02/06/2017 13:32:24 [ 4356] [DEBUG] [mcs] SyncParameters->UseCPO('DEFAULT') 02/06/2017 13:32:24 [ 4356] [DEBUG] [mcs] ZPush::GetAdditionalSyncFolderStore('83d0690bd687476995200a6b9c27b8e7121900000000'): 'false' 02/06/2017 13:32:24 [ 4356] [DEBUG] [mcs] SyncCollections->AddCollection(): Folder id 'U8f840' : ref. PolicyKey '292307370', ref. Lifetime '480', last sync at '1496219519' 02/06/2017 13:32:24 [ 4356] [DEBUG] [mcs] SyncParameters->GetLatestSyncKey(): '{9f21a772-192f-4dda-80d0-76ae7f58eec4}1' 02/06/2017 13:32:24 [ 4356] [DEBUG] [mcs] FileStateMachine->GetState() read '15' bytes from file: '/var/lib/z-push/7/6/androidc1233927167-9f21a772-192f-4dda-80d0-76ae7f58eec4-1' 02/06/2017 13:32:24 [ 4356] [DEBUG] [mcs] FileStateMachine->GetState() read '379' bytes from file: '/var/lib/z-push/7/6/androidc1233927167-24c2261f-db0b-4406-bc71-9ff71bc4f765-fd' 02/06/2017 13:32:24 [ 4356] [DEBUG] [mcs] SyncParameters->UseCPO('DEFAULT') 02/06/2017 13:32:24 [ 4356] [DEBUG] [mcs] SyncCollections->AddCollection(): Folder id '' : ref. PolicyKey '292307370', ref. Lifetime '10', last sync at '1496219509' 02/06/2017 13:32:24 [ 4356] [DEBUG] [mcs] SyncParameters->GetLatestSyncKey(): '{24c2261f-db0b-4406-bc71-9ff71bc4f765}1' 02/06/2017 13:32:24 [ 4356] [DEBUG] [mcs] StateManager->loadHierarchyCache(): 'androidc1233927167-24c2261f-db0b-4406-bc71-9ff71bc4f765-hc-1' 02/06/2017 13:32:24 [ 4356] [DEBUG] [mcs] FileStateMachine->GetState() read '3169' bytes from file: '/var/lib/z-push/7/6/androidc1233927167-24c2261f-db0b-4406-bc71-9ff71bc4f765-hc-1' 02/06/2017 13:32:24 [ 4356] [DEBUG] [mcs] FileStateMachine->GetState() read '15' bytes from file: '/var/lib/z-push/7/6/androidc1233927167-24c2261f-db0b-4406-bc71-9ff71bc4f765-1' 02/06/2017 13:32:24 [ 4356] [DEBUG] [mcs] HandlePing(): reference PolicyKey for PING: 292307370 02/06/2017 13:32:24 [ 4356] [DEBUG] [mcs] HandlePing(): initialization data received 02/06/2017 13:32:24 [ 4356] [WBXML] [mcs] I <Ping:LifeTime> 02/06/2017 13:32:24 [ 4356] [WBXML] [mcs] I 1080 02/06/2017 13:32:24 [ 4356] [WBXML] [mcs] I </Ping:LifeTime> 02/06/2017 13:32:24 [ 4356] [WBXML] [mcs] I <Ping:Folders> 02/06/2017 13:32:24 [ 4356] [WBXML] [mcs] I <Ping:Folder> 02/06/2017 13:32:24 [ 4356] [WBXML] [mcs] I <Ping:ServerEntryId> 02/06/2017 13:32:24 [ 4356] [WBXML] [mcs] I Ce5a84 02/06/2017 13:32:24 [ 4356] [WBXML] [mcs] I </Ping:ServerEntryId> 02/06/2017 13:32:24 [ 4356] [WBXML] [mcs] I <Ping:FolderType> 02/06/2017 13:32:24 [ 4356] [WBXML] [mcs] I Contacts 02/06/2017 13:32:24 [ 4356] [WBXML] [mcs] I </Ping:FolderType> 02/06/2017 13:32:24 [ 4356] [WBXML] [mcs] I </Ping:Folder> 02/06/2017 13:32:24 [ 4356] [DEBUG] [mcs] HandlePing(): using saved sync state for 'Contacts' id 'Ce5a84' 02/06/2017 13:32:24 [ 4356] [WBXML] [mcs] I <Ping:Folder> 02/06/2017 13:32:24 [ 4356] [WBXML] [mcs] I <Ping:ServerEntryId> 02/06/2017 13:32:24 [ 4356] [WBXML] [mcs] I U842a5 02/06/2017 13:32:24 [ 4356] [WBXML] [mcs] I </Ping:ServerEntryId> 02/06/2017 13:32:24 [ 4356] [WBXML] [mcs] I <Ping:FolderType> 02/06/2017 13:32:24 [ 4356] [WBXML] [mcs] I Email 02/06/2017 13:32:24 [ 4356] [WBXML] [mcs] I </Ping:FolderType> 02/06/2017 13:32:24 [ 4356] [WBXML] [mcs] I </Ping:Folder> 02/06/2017 13:32:24 [ 4356] [DEBUG] [mcs] HandlePing(): using saved sync state for 'Email' id 'U842a5' 02/06/2017 13:32:24 [ 4356] [WBXML] [mcs] I <Ping:Folder> 02/06/2017 13:32:24 [ 4356] [WBXML] [mcs] I <Ping:ServerEntryId> 02/06/2017 13:32:24 [ 4356] [WBXML] [mcs] I Ud7e8b 02/06/2017 13:32:24 [ 4356] [WBXML] [mcs] I </Ping:ServerEntryId> 02/06/2017 13:32:24 [ 4356] [WBXML] [mcs] I <Ping:FolderType> 02/06/2017 13:32:24 [ 4356] [WBXML] [mcs] I Email 02/06/2017 13:32:24 [ 4356] [WBXML] [mcs] I </Ping:FolderType> 02/06/2017 13:32:24 [ 4356] [WBXML] [mcs] I </Ping:Folder> 02/06/2017 13:32:24 [ 4356] [DEBUG] [mcs] HandlePing(): using saved sync state for 'Email' id 'Ud7e8b' 02/06/2017 13:32:24 [ 4356] [WBXML] [mcs] I <Ping:Folder> 02/06/2017 13:32:24 [ 4356] [WBXML] [mcs] I <Ping:ServerEntryId> 02/06/2017 13:32:24 [ 4356] [WBXML] [mcs] I U16666 02/06/2017 13:32:24 [ 4356] [WBXML] [mcs] I </Ping:ServerEntryId> 02/06/2017 13:32:24 [ 4356] [WBXML] [mcs] I <Ping:FolderType> 02/06/2017 13:32:24 [ 4356] [WBXML] [mcs] I Contacts 02/06/2017 13:32:24 [ 4356] [WBXML] [mcs] I </Ping:FolderType> 02/06/2017 13:32:24 [ 4356] [WBXML] [mcs] I </Ping:Folder> 02/06/2017 13:32:24 [ 4356] [DEBUG] [mcs] HandlePing(): using saved sync state for 'Contacts' id 'U16666' 02/06/2017 13:32:24 [ 4356] [WBXML] [mcs] I <Ping:Folder> 02/06/2017 13:32:24 [ 4356] [WBXML] [mcs] I <Ping:ServerEntryId> 02/06/2017 13:32:24 [ 4356] [WBXML] [mcs] I U8f840 02/06/2017 13:32:24 [ 4356] [WBXML] [mcs] I </Ping:ServerEntryId> 02/06/2017 13:32:24 [ 4356] [WBXML] [mcs] I <Ping:FolderType> 02/06/2017 13:32:24 [ 4356] [WBXML] [mcs] I Calendar 02/06/2017 13:32:24 [ 4356] [WBXML] [mcs] I </Ping:FolderType> 02/06/2017 13:32:24 [ 4356] [WBXML] [mcs] I </Ping:Folder> 02/06/2017 13:32:24 [ 4356] [DEBUG] [mcs] HandlePing(): using saved sync state for 'Calendar' id 'U8f840' 02/06/2017 13:32:24 [ 4356] [WBXML] [mcs] I </Ping:Folders> 02/06/2017 13:32:24 [ 4356] [WBXML] [mcs] I </Ping:Ping> 02/06/2017 13:32:24 [ 4356] [DEBUG] [mcs] DeviceManager->DoAutomaticASDeviceSaving(): save automatically: false 02/06/2017 13:32:24 [ 4356] [DEBUG] [mcs] PingTracking(): Initialized mutexid Resource id #149 and memid Resource id #150. 02/06/2017 13:32:24 [ 4356] [DEBUG] [mcs] PingTracking initialised with IPC provider 'IpcSharedMemoryProvider' with type '2' 02/06/2017 13:32:24 [ 4356] [DEBUG] [mcs] Announce process as PUSH connection 02/06/2017 13:32:24 [ 4356] [ INFO] [mcs] SyncCollections->CheckForChanges(): Waiting for store changes... (lifetime 1080 seconds) 02/06/2017 13:32:24 [ 4356] [DEBUG] [mcs] KopanoBackend->HasChangesSink(): created - HierarchyHash: 55f1012ab6e750749e116a68fb4045d1 02/06/2017 13:32:24 [ 4356] [DEBUG] [mcs] KopanoBackend->adviseStoreToSink(): advised store 'Resource id #31' 02/06/2017 13:32:24 [ 4356] [DEBUG] [mcs] ZPush::GetAdditionalSyncFolderStore('83d0690bd687476995200a6b9c27b8e7a70700000000'): 'SYSTEM' 02/06/2017 13:32:24 [ 4356] [DEBUG] [mcs] KopanoBackend->ChangesSinkInitialize(): folderid '83d0690bd687476995200a6b9c27b8e7a70700000000' 02/06/2017 13:32:24 [ 4356] [DEBUG] [mcs] KopanoBackend->adviseStoreToSink(): advised store 'Resource id #45' 02/06/2017 13:32:24 [ 4356] [DEBUG] [mcs] KopanoBackend->GetFolderStat() fetched status information of 6 folders for store 'SYSTEM' 02/06/2017 13:32:24 [ 4356] [DEBUG] [mcs] SyncParameters->IsExporterRunRequired(): false - current: 1496391927/75/0/0 - saved: 1496391927/75/0/0 - expiring: 2017-07-03 13:32:18 02/06/2017 13:32:24 [ 4356] [DEBUG] [mcs] ZPush::GetAdditionalSyncFolderStore('83d0690bd687476995200a6b9c27b8e70d1900000000'): 'false' 02/06/2017 13:32:24 [ 4356] [DEBUG] [mcs] KopanoBackend->ChangesSinkInitialize(): folderid '83d0690bd687476995200a6b9c27b8e70d1900000000' 02/06/2017 13:32:24 [ 4356] [DEBUG] [mcs] KopanoBackend->GetFolderStat() fetched status information of 23 folders for store 'mcs' 02/06/2017 13:32:24 [ 4356] [DEBUG] [mcs] SyncParameters->IsExporterRunRequired(): false - current: 1496403138/3/3/0 - saved: 1496403138/3/3/0 - expiring: 2017-06-09 13:32:19 02/06/2017 13:32:24 [ 4356] [DEBUG] [mcs] ZPush::GetAdditionalSyncFolderStore('83d0690bd687476995200a6b9c27b8e7101900000000'): 'false' 02/06/2017 13:32:24 [ 4356] [DEBUG] [mcs] KopanoBackend->ChangesSinkInitialize(): folderid '83d0690bd687476995200a6b9c27b8e7101900000000' 02/06/2017 13:32:24 [ 4356] [DEBUG] [mcs] SyncParameters->IsExporterRunRequired(): false - current: 0000000000/6/0/0 - saved: 0000000000/6/0/0 - expiring: 2017-06-09 13:32:19 02/06/2017 13:32:24 [ 4356] [DEBUG] [mcs] ZPush::GetAdditionalSyncFolderStore('83d0690bd687476995200a6b9c27b8e7111900000000'): 'false' 02/06/2017 13:32:24 [ 4356] [DEBUG] [mcs] KopanoBackend->ChangesSinkInitialize(): folderid '83d0690bd687476995200a6b9c27b8e7111900000000' 02/06/2017 13:32:24 [ 4356] [DEBUG] [mcs] SyncParameters->IsExporterRunRequired(): false - current: 0000000000/0/0/0 - saved: 0000000000/0/0/0 - expiring: 2017-07-01 10:31:58 02/06/2017 13:32:24 [ 4356] [DEBUG] [mcs] ZPush::GetAdditionalSyncFolderStore('83d0690bd687476995200a6b9c27b8e7121900000000'): 'false' 02/06/2017 13:32:24 [ 4356] [DEBUG] [mcs] KopanoBackend->ChangesSinkInitialize(): folderid '83d0690bd687476995200a6b9c27b8e7121900000000' 02/06/2017 13:32:24 [ 4356] [DEBUG] [mcs] SyncParameters->IsExporterRunRequired(): false - current: 1495612447/0/0/0 - saved: 1495612447/0/0/0 - expiring: 2017-06-14 10:31:59 02/06/2017 13:32:24 [ 4356] [DEBUG] [mcs] ASDevice->GetHierarchyCache(): HierarchyCache is up - Cached objects: 12 02/06/2017 13:32:24 [ 4356] [DEBUG] [mcs] ZPush::GetAdditionalSyncFolders(): Requested AS folderids as keys for additional folders array, converting 02/06/2017 13:32:24 [ 4356] [DEBUG] [mcs] ChangesMemoryWrapper->Config(AdditionalFolders) : process folder 'Lohr' 02/06/2017 13:32:24 [ 4356] [DEBUG] [mcs] KopanoBackend->Setup(): Checking for 'read' ACLs on '83d0690bd687476995200a6b9c27b8e7a70700000000' of store 'SYSTEM': 'true' 02/06/2017 13:32:24 [ 4356] [DEBUG] [mcs] ChangesMemoryWrapper->ImportFolderChange(): Change for folder 'Lohr' will not be sent as modification is not relevant. 02/06/2017 13:32:24 [ 4356] [DEBUG] [mcs] ExportChangesICS->Config() initialized with state: 0xcb020000e1400000 02/06/2017 13:32:24 [ 4356] [DEBUG] [mcs] ExportChangesICS->InitializeExporter() successfully. 0 changes ready to sync for 'hierarchy'.
Edit Sebastian: put log in code block
-
The log does show no sync request nor the sending of the email, but it gave away that the folder “Lohr” is a shared folder (probably via the static configuration, right?).
Then the short answer is: please double check if the user no write permissions on this folder. If he doesn’t the folder is treated as “read-only” and any action the user performs there will be suppressed and the user will get these emails.
You can get more information about read-only folders here: https://wiki.z-hub.io/pages/viewpage.action?pageId=1737238
-
i check this
-
system worked with Android 6 without any issues, but after upgradng to Android 7 customer sees this errors.
Any ideas why we see this errors since upgrading to Android 7?
Walter
-
First of all, these are not errors. An error indicates that there is something wrong. This is not really the case here.
The only explanation I could imagine is that Android 7 tries to edit (sync?) e.g. contacts with some external source automatically in a read-only folder.
-
@Sebastian
would be helpful, to have a switch, to silently ignore any changes in this folder. The folder is a RO address book, no one can change the content, Unfortunately Android 7 seems to modify data in this folder and we see no possibility to stop Android 7 to do so.Please add an folder based switch to silently discard changes in this folder.
Walter
-
I’ve created a ticket to exclude a list of folders from the notifications: https://jira.z-hub.io/browse/ZP-1232
It’s still undecided when this is going to be implemented.Cheers,
Sebastian -
@Sebastian
thank you.