Cannot check Emails (internet works) / messageserver5 Eats 100% CPU of 1 Core (and battery)

ohnonot · 18 December 2023 16:49

REPRODUCIBILITY: 100%
OS VERSION: 4.5.0.24
HARDWARE: Xperia XA2 Ultra (single SIM)
UI LANGUAGE: English UK
REGRESSION: It used to work, so I guess yes.

DESCRIPTION:

I am not receiving new emails anymore though the email app starts normally.
The battery also goes down much quicker than usually. Superficial research shows that messageserver5 constantly eats 100% CPU of one core, see this screencast and this previous conversation.

PRECONDITIONS:

I have two email accounts, one is normal IMAP and has worked for years, the other is a recent addition - a Google account. I connect to the Internet through WLAN at home and mobile broadband when moving. Both connections are OK but not super.

STEPS TO REPRODUCE:

Have at least one email account I guess
(that’s all, email updating happens automatically in the background)
open email app, try to update

EXPECTED RESULT:

I get regularly notified of new emails or I can trigger a sync through the email app, and get to see new emails.

ACTUAL RESULT:

No notifications. A manual sync does nothing (not even a “please wait” pulsating top bar).
The email app works otherwise, I can see all (locally synced I guess) mails up to 9th of December.

MODIFICATIONS:

Create email accounts.
Saved WLAN connection.
Chum & openrepos apps.
Various manual hacks

Free Form Info, Logs

Gathering logs does not help much - messageserver itself only logs a little bit at start, then nothing (it is now 18:21, this is all it logged since 10:00 despite running at 100% all the time):

[7264] Dec 18 10:00:37 [Warning] void QCopClient::connectToServer() QLocalSocket::ConnectionRefusedError "QLocalSocket::connectToServer: Connection refused"
[7264] Dec 18 10:00:37 [Debug] Messaging :  MessageServer ctor begin
[7264] Dec 18 10:00:37 [Debug] Messaging :  opening database
[7264] Dec 18 10:00:37 [Debug] Messaging :  bool SSOSessionManager::createSsoIdentity(const QMailAccountId&, const QString&) Creating SSO identity for the service  "imap4"  from account  16  using authentication method  "oauth2"
[7264] Dec 18 10:00:37 [Debug] IMAP :  void ImapClient::setAccount(const QMailAccountId&) SSO identity is found for account id:  16
[7264] Dec 18 10:00:37 [Debug] Messaging :  Registering service: "imap4" for account: 16
[7264] Dec 18 10:00:37 [Debug] Messaging :  bool SSOSessionManager::createSsoIdentity(const QMailAccountId&, const QString&) Creating SSO identity for the service  "smtp"  from account  16  using authentication method  "oauth2"
[7264] Dec 18 10:00:37 [Debug] SMTP :  void SmtpClient::setAccount(const QMailAccountId&) SSO identity is found for account id:  16
[7264] Dec 18 10:00:37 [Debug] Messaging :  Registering service: "smtp" for account: 16
[7264] Dec 18 10:00:37 [Debug] Messaging :  bool SSOSessionManager::createSsoIdentity(const QMailAccountId&, const QString&) Creating SSO identity for the service  "imap4"  from account  11  using authentication method  "password"
[7264] Dec 18 10:00:37 [Debug] IMAP :  void ImapClient::setAccount(const QMailAccountId&) SSO identity is found for account id:  11
[7553] Dec 18 10:00:40 [Warning] void QCopClient::connectToServer() QLocalSocket::ConnectionRefusedError "QLocalSocket::connectToServer: Connection refused"
[7553] Dec 18 10:00:40 [Debug] Messaging :  MessageServer ctor begin
[7553] Dec 18 10:00:40 [Debug] Messaging :  opening database
[7553] Dec 18 10:00:40 [Debug] Messaging :  bool SSOSessionManager::createSsoIdentity(const QMailAccountId&, const QString&) Creating SSO identity for the service  "imap4"  from account  16  using authentication method  "oauth2"
[7553] Dec 18 10:00:40 [Debug] IMAP :  void ImapClient::setAccount(const QMailAccountId&) SSO identity is found for account id:  16
[7553] Dec 18 10:00:40 [Debug] Messaging :  Registering service: "imap4" for account: 16
[7553] Dec 18 10:00:40 [Debug] Messaging :  bool SSOSessionManager::createSsoIdentity(const QMailAccountId&, const QString&) Creating SSO identity for the service  "smtp"  from account  16  using authentication method  "oauth2"
[7553] Dec 18 10:00:40 [Debug] SMTP :  void SmtpClient::setAccount(const QMailAccountId&) SSO identity is found for account id:  16
[7553] Dec 18 10:00:40 [Debug] Messaging :  Registering service: "smtp" for account: 16
[7553] Dec 18 10:00:40 [Debug] Messaging :  bool SSOSessionManager::createSsoIdentity(const QMailAccountId&, const QString&) Creating SSO identity for the service  "imap4"  from account  11  using authentication method  "password"
[7553] Dec 18 10:00:40 [Debug] IMAP :  void ImapClient::setAccount(const QMailAccountId&) SSO identity is found for account id:  11

Here is the output of journalctl for the same timespan (I removed some personal info, hopefully I haven’t overlooked anything).

The log does not tell me that only one of the 2 accounts (11 and 16) causes problems.
I can see the QLocalSocket::ConnectionRefusedError at the beginning, but it is logged as a warning and seems to be account-independent. Frankly I have no idea what it means.

Here is a screencast for htop just to clarify what “100% of 1 core” means. Halfway through the cast I checked my email with the ui, which did nothing and seems to have no effect on messageserver5 either way.

This has been goingon for over a week now.

I can kill the process, stop the messageserver5.service, mask the service, and one battery charge lasts twice as long. But no fresh emails of course.

jwalden · 19 December 2023 07:34

Thanks for the good bug report!
You wrote: “I have two email accounts, one is normal IMAP and has worked for years, the other is a recent addition - a Google account.”
Couple of questions still:
Was the email sync working with 4.5.0.24 before you added the Google account?
Was the sync working for some time with Google account before it started to fail? Have you tried to remove and add the Google account to see if that has any impact?

ohnonot · 24 December 2023 12:13

Yes, definitely

Was the sync working for some time with Google account before it started to fail?

I think so but I can’t be 100% sure.

Have you tried to remove and add the Google account to see if that has any impact?

I had disabled it before, that didn’t help.

Now I removed it completely, then uninstalled Microsoft Exchange support (I know it has nothing to do with Google, just something unneeded I remembered - there are no longer Exchange accounts on my phone).

After a reboot all is good.

Re-adding the account and rebooting again => back to the problem as described in OP.

The other person having problems with messageserver5 said something about Wlan vs. Mobile Broadband iirc, so I tried enabling mobile bradband, disabling wlan, and rebooting. This does not seem to have any effect on my problem.

On my desktop I use evolution to access the same account. It doesn’t have 2FA enabled, and constantly asks me to confirm new logins from different devices, and re-enter my password. I don’t want it to ping my phone each time I log in. I think I’ll just set it to forward all incoming mail to a different account & fuck Google.

ohnonot · 26 December 2023 16:00

PS: I’d be happy to recreate the account for further troubleshooting.

martinh · 26 December 2023 21:48

I’m using three Google Accounts and one IMAP (Dovecot) account on my Jolla, all configured with IMAP IDLE. That works flawlessly, even better than with the desktop client (evolution). So I guess it’s a misconfiguration on your side. Anyhow eating a CPU core due to a misconfiguration is a bug that needs to be squashed.

“netstat -ant” should give some hint. Connections in state ESTABLISHED simply work, the account causing the problem won’t show up or with another state.

“ConnectionRefused” from the log usually indicates, that the client received a TCP RESET, i.e. the addressed port is not listening or blocked. “tcpdump -ni eno1 ‘tcp[tcpflags] & (tcp-rst) != 0’” might help here.

ohnonot · 20 January 2024 04:15

Here’s one thing I only thought of afterwards:

Since I wasn’t using 2FA, maybe I should’ve added the account as a normal email account, not as a Google account. IDK. The whole account is gone now (thankfully my employer was happy to do that & provide an alternative solution).