Bug 23035

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.

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

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

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.

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.

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

@ packager

Please add the symbolic link

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

Ulrich

Fixed in kdepim-runtime-17.12.2-1.1.mga6 in Core/Updates_testing repo!

CC: (none) => geiger.david68210

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

Fixed in next kdepim-runtime-17.12.2-1.2.mga6 update!

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

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

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)

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>

No regressions with it for the whole day so remarking it as OK for x86_64.

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

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