| Summary: | Get a lot of `Failed to process EWS request: ` with empty details | ||
|---|---|---|---|
| Product: | [Frameworks and Libraries] Akonadi | Reporter: | arcticlampyrid |
| Component: | EWS Resource | Assignee: | kdepim bugs <kdepim-bugs> |
| Status: | RESOLVED FIXED | ||
| Severity: | normal | CC: | carl, krissn, lbeltrame, michel.munnix |
| Priority: | NOR | ||
| Version: | unspecified | ||
| Target Milestone: | --- | ||
| Platform: | Arch Linux | ||
| OS: | Linux | ||
| Latest Commit: | https://invent.kde.org/pim/kdepim-runtime/-/commit/13bda2e41f84df8ba04df0e32be6c213a56be121 | Version Fixed In: | |
| Sentry Crash Report: | |||
| Attachments: | log from akonadiconsole | ||
|
Description
arcticlampyrid
2024-04-19 16:26:01 UTC
Created attachment 169010 [details]
log from akonadiconsole
I have the same messages repeated in journalctl.
There is also a memory leak that makes the akonadi_ews_res process grow:
top with interval: 10 sec
continuous increase of akonadi_ews_res RES size:
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
4317 mm 20 0 2545384 580612 11784 S 5.389 15.28 0:41.93 akonadi_ews_res
4317 mm 20 0 2553160 587140 11656 S 5.389 15.45 0:42.47 akonadi_ews_res
4317 mm 20 0 2562660 594564 11656 S 5.694 15.65 0:43.04 akonadi_ews_res
opensuse tumbleweed
kdepim-runtime-24.02.2-1.1.x86_64
This is because malformed data is sent, this is the reply from the server (you should set QT_LOGGING_RULES="*org.kde.pim.ews.client.proto*.debug=true" to have it dumped somewhere): <?xml version="1.0" encoding="utf-8"?><s:Envelope xmlns:s="http://schemas.xmlsoap.org/soap/envelope/"><s:Body><s:Fault><faultcode xmlns:a="http://schemas.microsoft.com/exchange/services/2006/types">a:ErrorInvalidOperation</faultcode><faultstring xml:lang="en-US">Id is malformed.</faultstring><detail><e:ResponseCode xmlns:e="http://schemas.microsoft.com/exchange/services/2006/errors">ErrorInvalidOperation</e:ResponseCode><e:Message xmlns:e="http://schemas.microsoft.com/exchange/services/2006/errors">Id is malformed.</e:Message></detail></s:Fault></s:Body></s:Envelope> I haven't found a way to debug *why* it's invalid. (In reply to Luca Beltrame from comment #2) > I haven't found a way to debug *why* it's invalid. dd785b95af83fd74618b5e4ce2904fa86db771e3 in kdepim-runtime might be suspect, but I have no way of confirming it. The memory leak at least should be fixed (doesn't leak anymore in my tests) by https://invent.kde.org/pim/kdepim-runtime/-/commit/aacd0807f13d0694b2bde515964b5f081973da5f. The spam in the log is a different issue. Do you maybe have a the body of one of the EWS request with an invalid ID? Locally I get: org.kde.pim.ews.client.proto: "<?xml version=\"1.0\"?><soap:Envelope xmlns:soap=\"http://schemas.xmlsoap.org/soap/envelope/\" xmlns:m=\"http://schemas.microsoft.com/exchange/services/2006/messages\" xmlns:t=\"http://schemas.microsoft.com/exchange/services/2006/types\"><soap:Header><t:RequestServerVersion Version=\"Exchange2007_SP1\"/></soap:Header><soap:Body><m:GetItem><m:ItemShape><t:BaseShape>IdOnly</t:BaseShape><t:AdditionalProperties><t:FieldURI FieldURI=\"item:MimeContent\"/></t:AdditionalProperties></m:ItemShape><m:ItemIds><t:ItemId Id=\"AAMkADgzNzkyOTg1LWZmYzgtNDY3Zi1hMjU2LTFlODNlZGIxNTVlNgBGAAAAAACGij6e2qxSSoxGqEgp0YQIBwAQB6nxUL4fQLR2Ugu0H+JMAAAAAAEMAAAQB6nxUL4fQLR2Ugu0H+JMAATIyE6cAAA=\" ChangeKey=\"CQAAABYAAAAQB6nxUL4fQLR2Ugu0H+JMAATLClcH\"/></m:ItemIds></m:GetItem></soap:Body></soap:Envelope>\n" and this is valid according to Outlook/Office365. A possibly relevant merge request was started @ https://invent.kde.org/pim/kdepim-runtime/-/merge_requests/170 Git commit 46ad0976a178a0189fe9fea6ec99f4a8a15b5af3 by Louis Moureaux. Committed on 26/06/2024 at 18:37. Pushed by carlschwan into branch 'master'. Do not try to subscribe to an empty list of folders The server refuses to watch when the list of folders is empty, which caused EwsSubscribedFoldersJob to try and subscribe in a loop. Just subscribe to the default folder list when this happens so we avoid the error. Subscribing still fails with a timeout, but at least we're not trying to do something invalid. M +2 -2 resources/ews/ewssubscribedfoldersjob.cpp https://invent.kde.org/pim/kdepim-runtime/-/commit/46ad0976a178a0189fe9fea6ec99f4a8a15b5af3 Git commit 05864950c3d0956bb9cb3148acc1245825cdde77 by Carl Schwan. Committed on 26/06/2024 at 22:45. Pushed by carlschwan into branch 'release/24.05'. Do not try to subscribe to an empty list of folders The server refuses to watch when the list of folders is empty, which caused EwsSubscribedFoldersJob to try and subscribe in a loop. Just subscribe to the default folder list when this happens so we avoid the error. Subscribing still fails with a timeout, but at least we're not trying to do something invalid. (cherry picked from commit 46ad0976a178a0189fe9fea6ec99f4a8a15b5af3) Co-authored-by: Louis Moureaux <m_louis30@yahoo.com> M +2 -2 resources/ews/ewssubscribedfoldersjob.cpp https://invent.kde.org/pim/kdepim-runtime/-/commit/05864950c3d0956bb9cb3148acc1245825cdde77 A possibly relevant merge request was started @ https://invent.kde.org/pim/kdepim-runtime/-/merge_requests/174 Git commit 586bbacf6990e5d8264a4a0c5884f03458a8d969 by Carl Schwan. Committed on 06/09/2024 at 13:50. Pushed by carlschwan into branch 'master'. Forward network error to the resouce job->error and job->errorString are always empty and so the error was not forwarded. Due to it not being forwarded, this made the EWS request believe it was successful, which then crashed due to the response data being empty. Related: bug 484579 Fixed-In: 24.08.0 M +1 -1 resources/ews/ewsclient/ewsrequest.cpp https://invent.kde.org/pim/kdepim-runtime/-/commit/586bbacf6990e5d8264a4a0c5884f03458a8d969 Git commit 13bda2e41f84df8ba04df0e32be6c213a56be121 by Carl Schwan. Committed on 06/09/2024 at 13:52. Pushed by carlschwan into branch 'release/24.08'. Forward network error to the resouce job->error and job->errorString are always empty and so the error was not forwarded. Due to it not being forwarded, this made the EWS request believe it was successful, which then crashed due to the response data being empty. Related: bug 484579 Fixed-In: 24.08.0 (cherry picked from commit 586bbacf6990e5d8264a4a0c5884f03458a8d969) Co-authored-by: Carl Schwan <carl@carlschwan.eu> M +1 -1 resources/ews/ewsclient/ewsrequest.cpp https://invent.kde.org/pim/kdepim-runtime/-/commit/13bda2e41f84df8ba04df0e32be6c213a56be121 |