search

Z-Hub / Z-Push

Home of Z-Push
https://z-push.org
GNU Affero General Public License v3.0
97 stars 47 forks source link

Outlook 365 Version 2401 Build 17231.20194 breaks z-push / zimbra - [SOLVED] #52

Closed khoebling closed 7 months ago

khoebling commented 10 months ago

Describe the issue adding a new account in outlook results in looping entries and no mail is synced

04/02/2024 20:06:49 [12052] [ INFO] [xxxxx@xxxxx.at] ExportChangesDiff->InitializeExporter(): Found '13' changes for 'hierarchy'
04/02/2024 20:06:49 [12052] [ INFO] [xxxxx@xxxxx.at] cmd='FolderSync' memory='1.69 MiB/2.00 MiB' time='0.08s' devType='WindowsOutlook' devId='3112b02513224ccf9920e4e7075bbe27' 
getUser='xxxxx@xxxxx.at' from='0.0.0.0' idle='0s' version='2.7.1
' method='POST' httpcode='200'
04/02/2024 20:06:49 [12052] [ INFO] [xxxxx@xxxxx.at] ExportChangesDiff->InitializeExporter(): Found '13' changes for 'hierarchy'
04/02/2024 20:06:49 [12052] [ INFO] [xxxxx@xxxxx.at] cmd='FolderSync' memory='1.69 MiB/2.00 MiB' time='0.08s' devType='WindowsOutlook' devId='3112b02513224ccf9920e4e7075bbe27' 
getUser='xxxxx@xxxxx.at' from='0.0.0.0' idle='0s' version='2.7.1
' method='POST' httpcode='200'
04/02/2024 20:06:49 [12052] [ INFO] [xxxxx@xxxxx.at] ExportChangesDiff->InitializeExporter(): Found '13' changes for 'hierarchy'
04/02/2024 20:06:49 [12052] [ INFO] [xxxxx@xxxxx.at] cmd='FolderSync' memory='1.69 MiB/2.00 MiB' time='0.09s' devType='WindowsOutlook' devId='3112b02513224ccf9920e4e7075bbe27' 
getUser='xxxxx@xxxxx.at' from='0.0.0.0' idle='0s' version='2.7.1
' method='POST' httpcode='200'
04/02/2024 20:06:49 [12052] [ INFO] [xxxxx@xxxxx.at] ExportChangesDiff->InitializeExporter(): Found '13' changes for 'hierarchy'
04/02/2024 20:06:49 [12052] [ INFO] [xxxxx@xxxxx.at] cmd='FolderSync' memory='1.69 MiB/2.00 MiB' time='0.09s' devType='WindowsOutlook' devId='3112b02513224ccf9920e4e7075bbe27' 
getUser='xxxxx@xxxxx.at' from='0.0.0.0' idle='0s' version='2.7.1
' method='POST' httpcode='200'
04/02/2024 20:06:49 [12052] [ INFO] [xxxxx@xxxxx.at] ExportChangesDiff->InitializeExporter(): Found '13' changes for 'hierarchy'
04/02/2024 20:06:49 [12052] [ INFO] [xxxxx@xxxxx.at] cmd='FolderSync' memory='1.69 MiB/2.00 MiB' time='0.09s' devType='WindowsOutlook' devId='3112b02513224ccf9920e4e7075bbe27' 
getUser='xxxxx@xxxxx.at' from='0.0.0.0' idle='0s' version='2.7.1
' method='POST' httpcode='200'
04/02/2024 20:06:50 [12052] [ INFO] [xxxxx@xxxxx.at] ExportChangesDiff->InitializeExporter(): Found '13' changes for 'hierarchy'
04/02/2024 20:06:50 [12052] [ INFO] [xxxxx@xxxxx.at] cmd='FolderSync' memory='1.69 MiB/2.00 MiB' time='0.09s' devType='WindowsOutlook' devId='3112b02513224ccf9920e4e7075bbe27' 
getUser='xxxxx@xxxxx.at' from='0.0.0.0' idle='0s' version='2.7.1
' method='POST' httpcode='200'
04/02/2024 20:06:50 [12052] [ INFO] [xxxxx@xxxxx.at] ExportChangesDiff->InitializeExporter(): Found '13' changes for 'hierarchy'
04/02/2024 20:06:50 [12052] [ INFO] [xxxxx@xxxxx.at] cmd='FolderSync' memory='1.69 MiB/2.00 MiB' time='0.08s' devType='WindowsOutlook' devId='3112b02513224ccf9920e4e7075bbe27' 
getUser='xxxxx@xxxxx.at' from='0.0.0.0' idle='0s' version='2.7.1
' method='POST' httpcode='200'
04/02/2024 20:06:50 [12052] [ INFO] [xxxxx@xxxxx.at] ExportChangesDiff->InitializeExporter(): Found '13' changes for 'hierarchy'
04/02/2024 20:06:50 [12052] [ INFO] [xxxxx@xxxxx.at] cmd='FolderSync' memory='1.69 MiB/2.00 MiB' time='0.08s' devType='WindowsOutlook' devId='3112b02513224ccf9920e4e7075bbe27' 
getUser='xxxxx@xxxxx.at' from='0.0.0.0' idle='0s' version='2.7.1
' method='POST' httpcode='200'
04/02/2024 20:06:50 [12052] [ INFO] [xxxxx@xxxxx.at] ExportChangesDiff->InitializeExporter(): Found '13' changes for 'hierarchy'
04/02/2024 20:06:50 [12052] [ INFO] [xxxxx@xxxxx.at] cmd='FolderSync' memory='1.69 MiB/2.00 MiB' time='0.09s' devType='WindowsOutlook' devId='3112b02513224ccf9920e4e7075bbe27' 
getUser='xxxxx@xxxxx.at' from='0.0.0.0' idle='0s' version='2.7.1

To Reproduce Steps to reproduce the behavior:

first observed with z-push v2.5.1, zimbra connector V68, zimbra version 8.8.10

installed a new z-push instance with z-push v2.7.1, zimbra connector V72, zimbra version 8.8.10 - same behaviour

after downgrading to outlook to version 2312 build 17126.20132 everything works out as it should

Additional context There seems to be a major change in outlook 365 Version 2401 Build 17231.20194

bastien30 commented 9 months ago

Hello,

I confirm the problem with Outlook version 2401 Build 17231.20194.

Already configured accounts are not syncing properly (only INBOX folder is synced, and very slow).

All our user's Outlook are affected.

phvogt commented 9 months ago

Same problem here.

What I tried:

Software versions:

04/02/2024 17:36:09 [15244] [DEBUG] [xxx@example.com] -------- Start
04/02/2024 17:36:09 [15244] [DEBUG] [xxx@example.com] cmd='FolderSync' devType='WindowsOutlook' devId='ad2541a60b0c4e858919c8e0d729a81f' getUser='xxx@example.com' from='<ipv6>' version='2.5.1-1' method='POST'
04/02/2024 17:36:09 [15244] [DEBUG] [xxx@example.com] Used timezone 'Europe/Vienna'
04/02/2024 17:36:09 [15244] [DEBUG] [xxx@example.com] ZPush::GetBackend(): trying autoload backend 'BackendKopano'
04/02/2024 17:36:09 [15244] [DEBUG] [xxx@example.com] BackendKopano using PHP-MAPI version: 8.7.0 - PHP version: 7.3.31-1~deb10u5
04/02/2024 17:36:09 [15244] [DEBUG] [xxx@example.com] Request::ProcessHeaders() ASVersion: 14.0
04/02/2024 17:36:09 [15244] [DEBUG] [xxx@example.com] ZPush::CommandNeedsProvisioning(9): true
04/02/2024 17:36:09 [15244] [DEBUG] [xxx@example.com] FileStateMachine->GetState() read '8650' bytes from file: '/var/lib/z-push/f/1/ad2541a60b0c4e858919c8e0d729a81f-devicedata'
04/02/2024 17:36:09 [15244] [DEBUG] [xxx@example.com] ASDevice data loaded for user: 'xxx@example.com'
04/02/2024 17:36:09 [15244] [DEBUG] [xxx@example.com] InterProcessData:__construct type: 'ad2541a60b0c4e858919c8e0d729a81f'
04/02/2024 17:36:09 [15244] [DEBUG] [xxx@example.com] TopCollector(): Initialized mutexid Resource id #20 and memid Resource id #21.
04/02/2024 17:36:09 [15244] [DEBUG] [xxx@example.com] TopCollector initialised with IPC provider 'IpcSharedMemoryProvider' with type '20'
04/02/2024 17:36:09 [15244] [DEBUG] [xxx@example.com] InterProcessData:__construct type: 'ad2541a60b0c4e858919c8e0d729a81f'
04/02/2024 17:36:09 [15244] [DEBUG] [xxx@example.com] LoopDetection(): Initialized mutexid Resource id #25 and memid Resource id #26.
04/02/2024 17:36:09 [15244] [DEBUG] [xxx@example.com] LoopDetection initialised with IPC provider 'IpcSharedMemoryProvider' with type '1337'
04/02/2024 17:36:09 [15244] [DEBUG] [xxx@example.com] ZPush::HierarchyCommand(9): true
04/02/2024 17:36:09 [15244] [DEBUG] [xxx@example.com] DeviceManager->ProvisioningRequired('0') saved device key '-1': false
04/02/2024 17:36:09 [15244] [DEBUG] [xxx@example.com] DeviceManager->getPolicyName(): determined policy name: 'default'
04/02/2024 17:36:09 [15244] [DEBUG] [xxx@example.com] DeviceManager->getProvisioningPolicies(): loaded 'default' policy.
04/02/2024 17:36:09 [15244] [DEBUG] [xxx@example.com] ZPush::CommandNeedsAuthentication(9): true
04/02/2024 17:36:09 [15244] [DEBUG] [xxx@example.com] KopanoBackend->Logon(): Trying to authenticate user 'xxx@example.com'..
04/02/2024 17:36:09 [15244] [DEBUG] [xxx@example.com] KopanoBackend->openMessageStore('xxx@example.com'): Found 'DEFAULT' store: 'Resource id #37'
04/02/2024 17:36:09 [15244] [DEBUG] [xxx@example.com] KopanoBackend->Logon(): User 'xxx@example.com' is authenticated
04/02/2024 17:36:09 [15244] [DEBUG] [xxx@example.com] Store supports properties containing Unicode characters.
04/02/2024 17:36:09 [15244] [DEBUG] [xxx@example.com] ZPush::CommandNeedsPlainInput(9): false
04/02/2024 17:36:09 [15244] [DEBUG] [xxx@example.com] ZPush::GetSupportedProtocolVersions(): 12.0,12.1,14.0,14.1
04/02/2024 17:36:09 [15244] [DEBUG] [xxx@example.com] ZPush::GetSupportedCommands(): Sync,SendMail,SmartForward,SmartReply,GetAttachment,GetHierarchy,CreateCollection,DeleteCollection,MoveCollection,FolderSync,FolderCreate,FolderDelete,FolderUpdate,MoveItems,GetItemEstimate,MeetingResponse,ResolveRecipients,ValidateCert,Provision,Search,Ping,Notify,ItemOperations,Settings
04/02/2024 17:36:09 [15244] [DEBUG] [xxx@example.com] FileStateMachine->GetState() read '372' bytes from file: '/var/lib/z-push/f/1/ad2541a60b0c4e858919c8e0d729a81f-89421b8c-1b23-4f3f-a1ec-6f547e7ee3a9-fd'
04/02/2024 17:36:09 [15244] [DEBUG] [xxx@example.com] SyncParameters->UseCPO('DEFAULT')
04/02/2024 17:36:09 [15244] [DEBUG] [xxx@example.com] ASDevice->GetHierarchyCache(): HierarchyCache is up - Cached objects: 0
04/02/2024 17:36:09 [15244] [DEBUG] [xxx@example.com] WBXMLEncoder->startWBXML() type: vnd.ms-sync.wbxml
04/02/2024 17:36:09 [15244] [DEBUG] [xxx@example.com] ExportChangesICS->Config() initialized with state: 0x0000000000000000
04/02/2024 17:36:09 [15244] [DEBUG] [xxx@example.com] ExportChangesICS->InitializeExporter() successfully. 100 changes ready to sync for 'hierarchy'.
04/02/2024 17:36:09 [15244] [DEBUG] [xxx@example.com] MAPIProvider->GetStoreProps(): Getting store properties.
04/02/2024 17:36:09 [15244] [DEBUG] [xxx@example.com] MAPIProvider->getInboxProps(): Getting inbox properties.
04/02/2024 17:36:09 [15244] [DEBUG] [xxx@example.com] HierarchyCache: AddFolder() serverid: U12869 displayname: Inbox
04/02/2024 17:36:09 [15244] [DEBUG] [xxx@example.com] HierarchyCache: AddFolder() serverid: U8b64f displayname: Outbox
04/02/2024 17:36:09 [15244] [DEBUG] [xxx@example.com] HierarchyCache: AddFolder() serverid: U4aea2 displayname: Deleted Items
04/02/2024 17:36:09 [15244] [DEBUG] [xxx@example.com] HierarchyCache: AddFolder() serverid: U63d13 displayname: Sent Items
04/02/2024 17:36:09 [15244] [DEBUG] [xxx@example.com] HierarchyCache: AddFolder() serverid: Ua25fe displayname: Contacts
04/02/2024 17:36:09 [15244] [DEBUG] [xxx@example.com] HierarchyCache: AddFolder() serverid: U3bbd8 displayname: Calendar
04/02/2024 17:36:09 [15244] [DEBUG] [xxx@example.com] HierarchyCache: AddFolder() serverid: U3013d displayname: Drafts
04/02/2024 17:36:09 [15244] [DEBUG] [xxx@example.com] HierarchyCache: AddFolder() serverid: Uf19d0 displayname: Journal
04/02/2024 17:36:09 [15244] [DEBUG] [xxx@example.com] HierarchyCache: AddFolder() serverid: U80caa displayname: Junk E-mail
04/02/2024 17:36:09 [15244] [DEBUG] [xxx@example.com] MAPIProvider->GetFolder(): folder 'RSS Feeds' should not be synchronized
04/02/2024 17:36:09 [15244] [DEBUG] [xxx@example.com] MAPIProvider->GetFolder(): invalid folder 'Conversation Action Settings' as it is a hidden folder (PR_ATTR_HIDDEN)
04/02/2024 17:36:09 [15244] [DEBUG] [xxx@example.com] MAPIProvider->GetFolder(): invalid folder 'Quick Step Settings' as it is a hidden folder (PR_ATTR_HIDDEN)
04/02/2024 17:36:09 [15244] [DEBUG] [xxx@example.com] MAPIProvider->GetFolder(): folder 'Suggested Contacts' should not be synchronized
04/02/2024 17:36:09 [15244] [DEBUG] [xxx@example.com] HierarchyCache: AddFolder() serverid: U6de9a displayname: Einstellungen für QuickSteps
04/02/2024 17:36:09 [15244] [DEBUG] [xxx@example.com] HierarchyCache: AddFolder() serverid: Uaf949 displayname: Einstellungen für Unterhaltungsaktionen
04/02/2024 17:36:09 [15244] [DEBUG] [xxx@example.com] HierarchyCache: AddFolder() serverid: Uaa99f displayname: Newsfeed
04/02/2024 17:36:09 [15244] [DEBUG] [xxx@example.com] HierarchyCache: AddFolder() serverid: U84107 displayname: Vorgeschlagene Kontakte
04/02/2024 17:36:09 [15244] [DEBUG] [xxx@example.com] HierarchyCache: AddFolder() serverid: Ud2e50 displayname: xxx
<more folders>
04/02/2024 17:36:09 [15244] [DEBUG] [xxx@example.com] StateManager::UnLinkState(''): saved state '89421b8c-1b23-4f3f-a1ec-6f547e7ee3a9' will be deleted.
04/02/2024 17:36:09 [15244] [DEBUG] [xxx@example.com] FileStateMachine->CleanStates(): Deleting file: '/var/lib/z-push/f/1/ad2541a60b0c4e858919c8e0d729a81f-89421b8c-1b23-4f3f-a1ec-6f547e7ee3a9-1'
04/02/2024 17:36:09 [15244] [DEBUG] [xxx@example.com] FileStateMachine->CleanStates(): Deleting file: '/var/lib/z-push/f/1/ad2541a60b0c4e858919c8e0d729a81f-89421b8c-1b23-4f3f-a1ec-6f547e7ee3a9-fd'
04/02/2024 17:36:09 [15244] [DEBUG] [xxx@example.com] FileStateMachine->CleanStates(): Deleting file: '/var/lib/z-push/f/1/ad2541a60b0c4e858919c8e0d729a81f-89421b8c-1b23-4f3f-a1ec-6f547e7ee3a9-hc-1'
04/02/2024 17:36:09 [15244] [DEBUG] [xxx@example.com] StateManager::linkState(#ASDevice, 'a833220e-a0a6-4e04-9613-dde8fcce33fb','HierarchyCache'): linked to uuid 'a833220e-a0a6-4e04-9613-dde8fcce33fb'.
04/02/2024 17:36:09 [15244] [DEBUG] [xxx@example.com] ASDevice->GetHierarchyCache(): HierarchyCache is up - Cached objects: 96
04/02/2024 17:36:09 [15244] [DEBUG] [xxx@example.com] FileStateMachine->SetState() written 25477 bytes on file: '/var/lib/z-push/f/1/ad2541a60b0c4e858919c8e0d729a81f-a833220e-a0a6-4e04-9613-dde8fcce33fb-hc-1'
04/02/2024 17:36:09 [15244] [DEBUG] [xxx@example.com] FileStateMachine->SetState() written 15 bytes on file: '/var/lib/z-push/f/1/ad2541a60b0c4e858919c8e0d729a81f-a833220e-a0a6-4e04-9613-dde8fcce33fb-1'
04/02/2024 17:36:09 [15244] [DEBUG] [xxx@example.com] SyncCollections::InvalidatePingableFlags(): Invalidating now
04/02/2024 17:36:09 [15244] [DEBUG] [xxx@example.com] FileStateMachine->SetState() written 372 bytes on file: '/var/lib/z-push/f/1/ad2541a60b0c4e858919c8e0d729a81f-a833220e-a0a6-4e04-9613-dde8fcce33fb-fd'
04/02/2024 17:36:09 [15244] [DEBUG] [xxx@example.com] WBXMLEncoder->endTag() WBXML output completed
04/02/2024 17:36:09 [15244] [DEBUG] [xxx@example.com] Special header: MS-ASProtocolVersions: 12.0,12.1,14.0,14.1
04/02/2024 17:36:09 [15244] [DEBUG] [xxx@example.com] Special header: MS-ASProtocolCommands: Sync,SendMail,SmartForward,SmartReply,GetAttachment,GetHierarchy,CreateCollection,DeleteCollection,MoveCollection,FolderSync,FolderCreate,FolderDelete,FolderUpdate,MoveItems,GetItemEstimate,MeetingResponse,ResolveRecipients,ValidateCert,Provision,Search,Ping,Notify,ItemOperations,Settings
04/02/2024 17:36:09 [15244] [DEBUG] [xxx@example.com] DeviceManager->Save(): Device data changed
04/02/2024 17:36:09 [15244] [DEBUG] [xxx@example.com] FileStateMachine->SetState() written 8650 bytes on file: '/var/lib/z-push/f/1/ad2541a60b0c4e858919c8e0d729a81f-devicedata'
04/02/2024 17:36:09 [15244] [DEBUG] [xxx@example.com] DeviceManager->Save(): Device data saved
04/02/2024 17:36:09 [15244] [DEBUG] [xxx@example.com] LoopDetection->ProcessLoopDetectionTerminate()
04/02/2024 17:36:09 [15244] [ INFO] [xxx@example.com] cmd='FolderSync' memory='2.73 MiB/2.00 MiB' time='0.26s' devType='WindowsOutlook' devId='ad2541a60b0c4e858919c8e0d729a81f' getUser='xxx@example.com' from='2001:871:265:392a:c24a:ff:fe03:fc7a' idle='0s' version='2.5.1-1' method='POST' httpcode='200'
04/02/2024 17:36:09 [15244] [DEBUG] [xxx@example.com] -------- End
bastien30 commented 9 months ago

Hello,

For information, the problem does not seems to be related to Z-Push.

I've same problem with Zimbra native EAS, and internet users starting to reports same problem for differents products too.

Looks like Microsoft has broke EAS for everyone.

Links :

khoebling commented 9 months ago

So it seems like M$ broke EAS with the latest update, so it is no bug in z-push and i will close this.

Solution in the meantime:

Deactivate Outlook Auto Update

Open CMD as admin

Paste this command:

"C:\Program Files\Common Files\microsoft shared\ClickToRun\officec2rclient.exe" /update user updatetoversion=16.0.17126.20132

Press enter and wait till the downgrade is done.

matidau commented 9 months ago

Might be better to keep this open until Outlook gets fixed, so others can find it easily.

igita commented 9 months ago

Thank you very much! the downgrade fixed it temporarily

akbypajoma commented 9 months ago

Hello,

For information, the problem does not seems to be related to Z-Push.

I've same problem with Zimbra native EAS, and internet users starting to reports same problem for differents products too.

Looks like Microsoft has broke EAS for everyone.

Links :

Thanks 👌, this workaround worked well by my clients, I hope Microsoft will provide an update quickly

bastien30 commented 9 months ago

Hello,

FYI Microsoft has fixed the bug in latest Outlook release, see https://support.microsoft.com/en-us/office/outlook-desktop-exchange-activesync-connections-stopped-working-in-version-2401-da2dc0dd-297e-48ba-b6d9-ab18f5d522fc.