Bug 23035 - kmail fails to authenticate imap connection to gmail
Summary: kmail fails to authenticate imap connection to gmail
Status: RESOLVED FIXED
Alias: None
Product: Mageia
Classification: Unclassified
Component: RPM Packages (show other bugs)
Version: 6
Hardware: All Linux
Priority: Normal normal
Target Milestone: ---
Assignee: QA Team
QA Contact:
URL:
Whiteboard: MGA6-64-OK
Keywords: advisory, validated_update
Depends on: 23627
Blocks:
  Show dependency treegraph
 
Reported: 2018-05-14 22:33 CEST by Ethan Merritt
Modified: 2019-02-14 09:40 CET (History)
9 users (show)

See Also:
Source RPM: lib64kdexoauth2_3-17.12.2-1.1.mga6
CVE:
Status comment:


Attachments

Description Ethan Merritt 2018-05-14 22:33:25 CEST
Description of problem:

After upgrade to kmail2 5.7.2 in the recent massive qt5 upgrade I can no longer access gmail accounts.  It is hard to get a reproducible error message. Sometimes it says "cannot authenticate", sometimes it reports a SASL error, sometimes it fails silently.   I believe that if it were possible to force the authentication method to PLAIN in the kmail account configuration widget this would work around the problem.  However as soon as I give imap.gmail.com as a server name the program automatically resets the authentication type to Gmail rather than PLAIN and greys out the widget so that I cannot change it back. 

Note that my kmail+gmail configuration was working fine before the upgrade.
Other imap servers continue to work OK; only the gmail authentication fails.


Version-Release number of selected component (if applicable):


How reproducible:
failure is 100% reproducible
the specific error message is not


Steps to Reproduce:
1.  configure a new or existing mail account in kmail to access imap.gmail.com
2.  try to access mail using this account
3.


I have the following installed

lib64sasl2_3-2.1.26-12.mga6
libsasl2_3-2.1.26-12.mga6
lib64sasl2-plug-plain-2.1.26-12.mga6
lib64sasl2-plug-login-2.1.26-12.mga6
lib64sasl2-plug-ntlm-2.1.26-12.mga6
lib64sasl2-plug-digestmd5-2.1.26-12.mga6


akonadi-kde-17.12.2-1.mga6
lib64kf5akonadicore5-17.12.2-1.mga6
lib64kf5mailtransportakonadi5-17.12.2-1.mga6
lib64akonadiprotocolinternals1-1.13.0-10.mga6
Marja Van Waes 2018-05-15 15:24:17 CEST

CC: (none) => marja11
Assignee: bugsquad => kde

Comment 1 Ethan Merritt 2018-05-15 18:29:42 CEST
More information:

libkgapi-17.12.2-1.mga6

error trace from journalctl
%%%%%%%%%%%%%%%%%%%
May 14 10:15:01 himeji akonadi_imap_resource[27732]: No worthy mechs found
May 14 10:15:01 himeji akonadi_imap_resource[27732]: org.kde.pim.kimap: sasl_client_start failed with: -4 "SASL(-4): no mechanism available: No worthy mechs found"
May 14 10:15:01 himeji akonadi_imap_resource[27732]: org.kde.kgapi.raw: Requesting token refresh:  "client_id=554041944266.apps.googleusercontent.com&client_secret=mdT1Dj
May 14 10:15:01 himeji akonadi_imap_resource[27732]: org.kde.kgapi: Queued QUrl("https://accounts.google.com/o/oauth2/token")
May 14 10:15:01 himeji akonadi_imap_resource[27732]: org.kde.kgapi: KGAPI2::AuthJob(0x1b8c5d0) Dispatching request to QUrl("https://accounts.google.com/o/oauth2/token")
May 14 10:15:01 himeji akonadi_imap_resource[27732]: org.kde.kgapi.raw: "client_id=554041944266.apps.googleusercontent.com&client_secret=mdT1DjzohxxxnpUUzkENT0gO&refresh_
May 14 10:15:03 himeji akonadi_vcard_resource[27808]: "No file selected."
May 14 10:15:03 himeji akonadi_vcard_resource[27819]: "No file selected."
May 14 10:15:03 himeji akonadi_vcard_resource[27818]: "No file selected."
May 14 10:15:05 himeji akonadi_imap_resource[27732]: org.kde.kgapi: Received reply from QUrl("https://accounts.google.com/o/oauth2/token")
May 14 10:15:05 himeji akonadi_imap_resource[27732]: org.kde.kgapi: Status code:  200
May 14 10:15:05 himeji akonadi_imap_resource[27732]: org.kde.kgapi.raw: "{\n  \"access_token\" : \"ya29.Gly7BRJTpBIKaP9EfIUNs6IyMLThrbFqDzlqNO8P1YbeexxgA8rDAEvtISiZaR-J2c
May 14 10:15:05 himeji akonadi_imap_resource[27732]: org.kde.kgapi: 
May 14 10:15:05 himeji akonadi_imap_resource[27732]: qt.network.ssl: QSslSocket::startClientEncryption: cannot start handshake on non-plain connection
%%%%%%%%%%%%%%%%%%%



partial work-around:

In the kmail account configuration widget if I provide a single IP address from the imap.gmail.com block then it allows me to set PLAIN authentication rather than GMAIL authentication.  This works and I can access my mail.  But it is obviously fragile compared to giving the generic name for DNS resolution.

proposed fix:

It's fine that kmail sets the default authentication method to GMAIL if it recognizes the server as a gmail server.  But it should not disable manual selection of the authentiation mode.  That way if the special-case authentication fails, the user can back off to PLAIN authentication.
Ulrich Beckmann 2018-05-15 21:29:24 CEST

See Also: (none) => https://bugs.mageia.org/show_bug.cgi?id=22655
CC: (none) => bequimao.de

Comment 2 Arne Spiegelhauer 2018-05-18 16:06:42 CEST
I got the same journal logs.
Found this: https://bugs.kde.org/show_bug.cgi?id=375410
Adding libkdexoauth2.so as a symbolic link to libkdexoauth2.so.3.0.0 as suggested in comment 3 solved the problem.

CC: (none) => gm2.asp

Comment 3 Ethan Merritt 2018-05-18 19:38:47 CEST
Adding the symlink produces a different failure mode, but it still does not complete the authentication process. I added the symlink in both /usr/lib/sasl2 and /usr/lib64/sasl2.

New log:

May 18 10:31:52 himeji akonadi_imap_resource[10018]: attempting client step after doneflag
May 18 10:31:52 himeji akonadi_imap_resource[10018]: org.kde.pim.kimap: sasl_client_step failed with: -1 "SASL(0): successful result: "
May 18 10:31:52 himeji akonadi_imap_resource[10018]: org.kde.kgapi.raw: Requesting token refresh:  "client_id=554041944266.apps.googleusercontent.com&client_secret=mdT1DjzohxN3npUUzkENT0gO&refresh_token=1/Ikby5iK7FBbK_G3x1r32KsYpwuVyp1QjAhM8Eu5GpxxNCp5T_yyFFpxcn2iMa1xb&grant_type=refresh_token"
May 18 10:31:52 himeji akonadi_imap_resource[10018]: org.kde.kgapi: Queued QUrl("https://accounts.google.com/o/oauth2/token")
May 18 10:31:52 himeji akonadi_imap_resource[10018]: org.kde.kgapi: KGAPI2::AuthJob(0x1738ee0) Dispatching request to QUrl("https://accounts.google.com/o/oauth2/token")
May 18 10:31:52 himeji akonadi_imap_resource[10018]: org.kde.kgapi.raw: "client_id=554041944266.apps.googleusercontent.com&client_secret=mdT1DjzohxN3npUUzkENT0gO&refresh_token=1/Ikby5iK7FBbK_G3x1r32KsYpwuVyp1QjAhM8Eu5Gp8BNCp5T_yyFFpxcn2iMa1xb&grant_type=refresh_token"
May 18 10:31:52 himeji akonadi_imap_resource[10018]: org.kde.kgapi: Received reply from QUrl("https://accounts.google.com/o/oauth2/token")
May 18 10:31:52 himeji akonadi_imap_resource[10018]: org.kde.kgapi: Status code:  200
May 18 10:31:52 himeji akonadi_imap_resource[10018]: org.kde.kgapi.raw: "{\n  \"access_token\" : \"ya29.Glu_BTgc-OIIaooajDd1YEsFVeXyVECWxhZ2rrQZhQl4CHTXWrIRhXOn3ycU0_f3soA4KXzOG9zb-_ko54cTJuq3mpI0SMzYSbxJ9YblIlPrZRZFshzYbtRAgHo9\",\n  \"expires_in\" : 3600,\n  \"id_token\" : \"eyJhbGciOiJSUzI1NiIsImtpZCI6IjAyOWYyNjlmM2YwNmFmMWU5M2RhYzY3MDYzOTc3ZjcxM2E3N2YxOWUifQ.eyJhenAiOiI1NTQwNDE5NDQyNjYuYXBwcy5nb29nbGV1c2VyY29udGVudC5jb20iLCJhdWQiOiI1NTQwNDE5NDQyNjYuYXBwcy5nb29nbGV1c2VyY29udGVudC5jb20iLCJzdWIiOiIxMDYzMzEwMDM2NDAxNTcyOTU5OTAiLCJoZCI6InV3LmVkdSIsImVtYWlsIjoibWVycml0dEB1dy5lZHUiLCJlbWFpbF92ZXJpZmllZCI6dHJ1ZSwiYXRfaGFzaCI6ImhCV3VOU0NIR1NHNHBCeVNMS3E1QmciLCJleHAiOjE1MjY2NjgzMTMsImlzcyI6ImFjY291bnRzLmdvb2dsZS5jb20iLCJpYXQiOjE1MjY2NjQ3MTN9.KH43YBccAEV1taxcRr_8qIzivcHQoaG1o4KMgtBhFc-51324-sSYzR_KCNmsjgF6rvU8-ButqDiiDu6SJnsw9KskQBwXTDZNrG0d1HwUkH_IEu4MtgYbZN37FBzcyYYk71gpuNSgr-sh0eK_H8Z3asj5XNVf4FEiNvGtInuBWc5zBfMHSgevSBR2Luv4Vu3jC_IjMcmM4z4934z_ahK-4gyiUDoVHz7k07TUZYtHGXMrmtiA3WGOx6lqoTPuruKwffkpzQU_wJxuZoe_YKzqCV1UOxKPYMAl2WxQ94MZSvLzNsEJxhkYPu7HURG8sRdVdY5D_QZXqyk70mRkAfkD8A\",\n  \"token_type\" : \"Bearer\"\n}"
May 18 10:31:52 himeji akonadi_imap_resource[10018]: org.kde.kgapi: 
May 18 10:31:52 himeji akonadi_imap_resource[10018]: qt.network.ssl: QSslSocket::startClientEncryption: cannot start handshake on non-plain connection


FWIW the same problem is present in Cauldron
Comment 4 Arne Spiegelhauer 2018-05-18 20:39:25 CEST
I have also got this log sequence 3 times in the journal since I added the symlink. Nevertheless kmail seems to work fine with my gmail account.
Maybe it is just a normal token renewal.
Comment 5 Arne Spiegelhauer 2018-05-19 14:27:52 CEST
Just updated another mga6 system and discovered that the package containing libkdexoauth2.so.3.0.0 (lib64kdexoauth2_3-2:17.12.2-1.mga6.x86_64) wasn't installed, so apparently in addition to the missing symlink, there is a dependency problem.
Comment 6 Ulrich Beckmann 2018-05-19 15:04:01 CEST
Thanks, Arne!

I identified that missing package (lib64kdexoauth2_3), too. The journal is flooded with warnings, while the database is rebuild. It works now, everything is  ok.

# ls -l /usr/lib64/sasl2/libkdexoauth2.so*
lrwxrwxrwx 1 root root    18 May 19 09:53 /usr/lib64/sasl2/libkdexoauth2.so -> libkdexoauth2.so.3*
lrwxrwxrwx 1 root root    22 Feb 21 19:49 /usr/lib64/sasl2/libkdexoauth2.so.3 -> libkdexoauth2.so.3.0.0*
-rwxr-xr-x 1 root root 19808 Feb 21 19:50 /usr/lib64/sasl2/libkdexoauth2.so.3.0.0*

Ulrich
Comment 7 Ulrich Beckmann 2018-05-21 17:26:17 CEST
@ packager

Please add the symbolic link

# ln -s /usr/lib64/sasl2/libkdexoauth2.so.3 /usr/lib64/sasl2/libkdexoauth2.so

Ulrich
Vincent D 2018-06-02 13:06:39 CEST

CC: (none) => vincent.dema+mageia

Stéphane Pontier 2018-07-11 19:59:51 CEST

CC: (none) => stephane.pontier

Comment 8 David GEIGER 2019-01-07 14:06:04 CET
Fixed in kdepim-runtime-17.12.2-1.1.mga6 in Core/Updates_testing repo!

CC: (none) => geiger.david68210

Ulrich Beckmann 2019-01-10 23:02:09 CET

Assignee: kde => qa-bugs

Comment 9 Ulrich Beckmann 2019-01-10 23:21:02 CET
No match for kdepim-runtime here.

lib64kdexoauth2_3 was upgraded, but I had installed it manually before.

Ulrich

Source RPM: (none) => lib64kdexoauth2_3-17.12.2-1.1.mga6

Comment 10 David GEIGER 2019-01-11 14:17:29 CET
Fixed in next kdepim-runtime-17.12.2-1.2.mga6 update!
Ulrich Beckmann 2019-01-11 20:11:54 CET

Assignee: qa-bugs => geiger.david68210

Comment 11 David GEIGER 2019-02-08 08:27:33 CET
Assigning to QA,

Advisory:
========================

Some users reported that kmail fails to authenticate imap connection to gmail since big kde application update (17.12.2). This come from a packaging issue and from some missing required dependencies.
So this update fixes those issues.

- libkdexoauth2.so should be installed as it is a plugin.
- akonadi-kde require libkgapi and recommend sasl2-plugin-kdexoauth2.

========================

Packages in 6/core/updates_testing:
========================
kdepim-runtime-handbook-17.12.2-1.2.mga6.noarch.rpm
akonadi-kde-17.12.2-1.2.mga6.x86_64.rpm
lib64akonadi-singlefileresource5-17.12.2-1.2.mga6.x86_64.rpm
lib64maildir5-17.12.2-1.2.mga6.x86_64.rpm
lib64akonadi-filestore5-17.12.2-1.2.mga6.x86_64.rpm
lib64kmindexreader5-17.12.2-1.2.mga6.x86_64.rpm
lib64folderarchivesettings5-17.12.2-1.2.mga6.x86_64.rpm
lib64kdexoauth2_3-17.12.2-1.2.mga6.x86_64.rpm

akonadi-kde-17.12.2-1.2.mga6.i586.rpm
libakonadi-singlefileresource5-17.12.2-1.2.mga6.i586.rpm
libmaildir5-17.12.2-1.2.mga6.i586.rpm
libakonadi-filestore5-17.12.2-1.2.mga6.i586.rpm
libkmindexreader5-17.12.2-1.2.mga6.i586.rpm
libfolderarchivesettings5-17.12.2-1.2.mga6.i586.rpm
libkdexoauth2_3-17.12.2-1.2.mga6.i586.rpm


Source RPM: 
========================
kdepim-runtime-17.12.2-1.2.mga6.src.rpm

Assignee: geiger.david68210 => qa-bugs

Comment 12 Ulrich Beckmann 2019-02-10 19:46:10 CET
Tested in a VM, where I never invoked Kontact/KMail before.

Installed packages:
akonadi-kde-17.12.2-1.2.mga6
lib64akonadi-filestore5-17.12.2-1.2.mga6
lib64akonadi-singlefileresource5-17.12.2-1.2.mga6
lib64folderarchivesettings5-17.12.2-1.2.mga6
lib64kdexoauth2_3-17.12.2-1.2.mga6
lib64kmindexreader5-17.12.2-1.2.mga6
lib64maildir5-17.12.2-1.2.mga6

I created a Gmail receiving IMAP account, and ran through the GMail authorisation workflow sucessfully.

Thanks David for fixing a long standing issue!

Ulrich

Whiteboard: (none) => MGA6-64-OK

Ulrich Beckmann 2019-02-11 00:10:31 CET

Depends on: (none) => 23627

Comment 13 PC LX 2019-02-12 02:45:24 CET
There is a regression with these updates.

Before this update kmail started in one or two seconds. After the update it takes over 50 seconds and the culprits are two futex calls.

Following lines are a part of the output of "strace -r kmail". As can be seen, two futex take some 25 seconds each to complete.

$ strace -r kmail
<SNIP>
     0.000117 open("/usr/lib64/qt5/plugins/kf5/org.kde.kwindowsystem.platforms/KF5WindowSystemX11Plugin.so", O_RDONLY|O_CLOEXEC) = 27
     0.000046 read(27, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\220\207\0\0\0\0\0\0"..., 832) = 832
     0.000043 fstat(27, {st_mode=S_IFREG|0755, st_size=123288, ...}) = 0
     0.000049 mmap(NULL, 2214136, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 27, 0) = 0x7f128c220000
     0.000041 mprotect(0x7f128c23b000, 2097152, PROT_NONE) = 0
     0.000042 mmap(0x7f128c43b000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 27, 0x1b000) = 0x7f128c43b000
     0.000056 close(27)                 = 0
     0.000734 mprotect(0x7f128c43b000, 4096, PROT_READ) = 0
     0.000115 write(25, "\1\0\0\0\0\0\0\0", 8) = 8
     0.000118 futex(0x1ec2a3c, FUTEX_WAIT_PRIVATE, 1, NULL) = 0
    24.966272 futex(0x1ec2a10, FUTEX_WAKE_PRIVATE, 1) = 0
     0.000132 write(25, "\1\0\0\0\0\0\0\0", 8) = 8
     0.000080 futex(0x7f12bea5e358, FUTEX_WAKE_PRIVATE, 1) = 1
     0.000115 futex(0x1ec29cc, FUTEX_WAIT_PRIVATE, 1, NULL) = -1 EAGAIN (Resource temporarily unavailable)
     0.000055 futex(0x1ec29a0, FUTEX_WAKE_PRIVATE, 1) = 0
     0.000081 write(25, "\1\0\0\0\0\0\0\0", 8) = 8
     0.000101 futex(0x1ec23cc, FUTEX_WAIT_PRIVATE, 1, NULL) = 0
     0.000135 futex(0x1ec23a0, FUTEX_WAKE_PRIVATE, 1) = 0
     0.000057 getcwd("/home/pclx", 4096) = 12
     0.000203 write(25, "\1\0\0\0\0\0\0\0", 8) = 8
     0.000106 futex(0x1ec23cc, FUTEX_WAIT_PRIVATE, 1, NULL) = 0
    25.015091 futex(0x1ec23a0, FUTEX_WAKE_PRIVATE, 1) = 0
     0.000101 write(25, "\1\0\0\0\0\0\0\0", 8) = 8
     0.000178 futex(0x7f12bea5e4c8, FUTEX_WAKE_PRIVATE, 1) = 1
     0.000109 write(25, "\1\0\0\0\0\0\0\0", 8) = 8
     0.000094 futex(0x7f12bea5e358, FUTEX_WAKE_PRIVATE, 1) = 1
<SNIP>

Installed/updated packages:
- akonadi-kde-17.12.2-1.2.mga6.x86_64
- kdepim-runtime-handbook-17.12.2-1.2.mga6.noarch
- lib64akonadi-filestore5-17.12.2-1.2.mga6.x86_64
- lib64akonadi-singlefileresource5-17.12.2-1.2.mga6.x86_64
- lib64folderarchivesettings5-17.12.2-1.2.mga6.x86_64
- lib64kdexoauth2_3-17.12.2-1.2.mga6.x86_64
- lib64kmindexreader5-17.12.2-1.2.mga6.x86_64
- lib64maildir5-17.12.2-1.2.mga6.x86_64
- libkgapi-17.12.2-1.mga6.x86_64

System: Mageia 6, x86_64, Plasma DE, Intel CPU, nVidia GPU using nvidia340 proprietary dr

CC: (none) => mageia
Whiteboard: MGA6-64-OK => (none)

Comment 14 PC LX 2019-02-12 11:21:30 CET
Don't know what was causing the futex to block for 25 seconds but this morning kmail is starting like before the update, taking one or two seconds to start.

I usually only restart the user session (and don't reboot) to test updates that should only involve user level stuff, like this kmail/akonadi update, but it seems a reboot this time was needed. Maybe there was some temp files causing issues.

For now, this update seems to be working. By the end of the day, I will give it an OK for x86_64 if no more issues show up and no one else does it before me.

$ strace -r kmail
<SNIP>
     0.000107 open("/usr/lib64/qt5/plugins/kf5/org.kde.kwindowsystem.platforms/KF5WindowSystemX11Plugin.so", O_RDONLY|O_CLOEXEC) = 34
     0.000042 read(34, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\220\207\0\0\0\0\0\0"..., 832) = 832
     0.000039 fstat(34, {st_mode=S_IFREG|0755, st_size=123288, ...}) = 0
     0.000045 mmap(NULL, 2214136, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 34, 0) = 0x7ffabd386000
     0.000038 mprotect(0x7ffabd3a1000, 2097152, PROT_NONE) = 0
     0.000040 mmap(0x7ffabd5a1000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 34, 0x1b000) = 0x7ffabd5a1000
     0.000052 close(34)                 = 0
     0.000735 mprotect(0x7ffabd5a1000, 4096, PROT_READ) = 0
     0.000096 write(25, "\1\0\0\0\0\0\0\0", 8) = 8
     0.000040 futex(0x10ff5ac, FUTEX_WAIT_PRIVATE, 1, NULL) = 0
     0.000128 futex(0x10ff580, FUTEX_WAKE_PRIVATE, 1) = 0
     0.000106 write(25, "\1\0\0\0\0\0\0\0", 8) = 8
     0.000052 futex(0x10ff5ac, FUTEX_WAIT_PRIVATE, 1, NULL) = 0
     0.000721 futex(0x10ff580, FUTEX_WAKE_PRIVATE, 1) = 0
     0.000089 write(25, "\1\0\0\0\0\0\0\0", 8) = 8
     0.000039 futex(0x7ffaf6829120, FUTEX_WAKE_PRIVATE, 1) = 1
     0.000034 futex(0x10ff9fc, FUTEX_WAIT_PRIVATE, 1, NULL) = 0
     0.000039 futex(0x10ff9d0, FUTEX_WAKE_PRIVATE, 1) = 0
<SNIP>
Comment 15 PC LX 2019-02-13 00:59:07 CET
No regressions with it for the whole day so remarking it as OK for x86_64.

Whiteboard: (none) => MGA6-64-OK

Dave Hodgins 2019-02-14 08:15:03 CET

Keywords: (none) => advisory, validated_update
CC: (none) => davidwhodgins, sysadmin-bugs

Comment 16 Mageia Robot 2019-02-14 09:40:07 CET
An update for this issue has been pushed to the Mageia Updates repository.

https://advisories.mageia.org/MGAA-2019-0011.html

Resolution: (none) => FIXED
Status: NEW => RESOLVED


Note You need to log in before you can comment on or make changes to this bug.