Hi,
well I fear there is still something wrong.
Am 04.10.2023 um 15:05 schrieb Aki Tuomi via dovecot dovecot@dovecot.org:
On 04/10/2023 16:02 EEST Christian Rößner lists@mlserv.org wrote:
Hi,
Am 04.10.2023 um 14:31 schrieb Aki Tuomi aki.tuomi@open-xchange.com:
On 04/10/2023 15:13 EEST Christian Rößner via dovecot dovecot@dovecot.org wrote:
Hi,
Am 04.10.2023 um 12:56 schrieb Arjen de Korte build+dovecot@de-korte.org:
Citeren Christian Rößner via dovecot dovecot@dovecot.org:
Hi,
I use Roundcube with OIDC. Everything works fine in Dovecot 2.3.20, but broke in 2.3.21. Downgrading to 2.3.20 makes it work again, so it is introduced in the newer release.
Error (2.3.21):
Oct 4 11:03:57 mx dovecot[558531]: imap-login: Disconnected: Connection closed (client didn't finish SASL auth, waited 1 secs): user=<christian@roessner.email>, orig_user=<christian@roessner.email>, method=XOAUTH2, rip=192.168.0.4, lip=192.168.0.2, TLS, TLSv1.3 with cipher TLS_AES_256_GCM_SHA384 (256/256 bits)Here is an example with 2.3.20:
Success (2.3.20):
Oct 4 11:17:21 mx dovecot[889914]: imap-login: Login: user=<christian@roessner.email>, orig_user=<christian@roessner.email>, method=XOAUTH2, rip=192.168.0.4, lip=192.168.0.2, mpid=891874, TLS, TLSv1.3 with cipher TLS_AES_256_GCM_SHA384 (256/256 bits)Searching the archives might give a lead to what's going on (and a possible workaround):
https://dovecot.org/mailman3/archives/list/dovecot@dovecot.org/thread/RR2GXL...
I get a different error from RC:
Oct 04 12:08:48 node1 8868c38d7990[158494]: errors: <48ea0f68> IMAP Error: Login failed for christian@roessner.email against mail.roessner-net.de from 192.168.32.1 (X-Real-IP: 2003:a:a05:a600:858:7851:547f:8aed,X-Forwarded-For: 2003:a:a05:a600:858:7851:547f:8aed). AUTHENTICATE XOAUTH2: A0001 NO [AUTHENTICATIONFAILED] Authentication failed. in /var/www/html/program/lib/Roundcube/rcube_imap.php on line 211 (GET /index.php/login/oauth?code=ory_ac_L5_NrO7EjgIccmV-_Tq1Y1_vls6i9NS8lbO7mHYwVeQ.maAkpsqdG95hkLutiDi4aB2KDPvj_pQ65qD-tuY9zBI&scope=openid+offline_access+profile+email+dovecot&state=J3WpRsBcOrnw)And changing the introspection_url parameter did not change anything.
Thanks in advance
Christian Rößner
Can you provide auth_debug=yes logs?
Turning n debug showed the problem:
Oct 4 14:50:31 mx dovecot[1302421]: auth: Debug: oauth2(christian@roessner.email,192.168.0.4,<3kfgc+MGeuXAqAAE>): oauth2 active_attribute "active" is not present in the oauth2 server's responseIn earlier configuration tests I had an 'active' claim. Dovecot prior 2.3.21 seems to had ignored a missing field, while newer version expect it to be present if configured.
Thanks.
Christian Rößner
Yes, this was a bug that was fixed, that the active attribute is now actually checked.
I thought I had mistakenly removed the active field, but I did not:
curl -X POST -d 'scope=email&token=****HIDDEN***' https://oauth.authserv.me:4445/admin/oauth2/introspect
{"active":true,"scope":"openid profile email groups dovecot offline offline_access","client_id":"718f4a52-e1a8-431d-9146-15809cfe3240","sub":"977c6572-d017-103b-836b-b5fc6e126160","exp":1696442299,"iat":1696438699,"nbf":1696438699,"aud":[],"iss":"https://oauth.authserv.me:4444","token_type":"Bearer","token_use":"access_token"}
As you can see, the 'active' field exists, but Dovecot expects it to be a claim, which it is not.
From auth_debug:
Oct 4 14:50:31 mx dovecot[1302421]: auth: Debug: oauth2(christian@roessner.email,192.168.0.4,<3kfgc+MGeuXAqAAE>): Making token validation lookup to https://oauth.authserv.me:4444/userinfo?access_token=
Oct 4 14:50:31 mx dovecot[1302421]: auth: Debug: oauth2(christian@roessner.email,192.168.0.4,<3kfgc+MGeuXAqAAE>): Token validation succeeded
Oct 4 14:50:31 mx dovecot[1302421]: auth: Debug: oauth2(christian@roessner.email,192.168.0.4,<3kfgc+MGeuXAqAAE>): Processing field auth_time
Oct 4 14:50:31 mx dovecot[1302421]: auth: Debug: oauth2(christian@roessner.email,192.168.0.4,<3kfgc+MGeuXAqAAE>): Processing field dovecot_mailbox_path
Oct 4 14:50:31 mx dovecot[1302421]: auth: Debug: oauth2(christian@roessner.email,192.168.0.4,<3kfgc+MGeuXAqAAE>): Processing field dovecot_user
Oct 4 14:50:31 mx dovecot[1302421]: auth: Debug: oauth2(christian@roessner.email,192.168.0.4,<3kfgc+MGeuXAqAAE>): Processing field email
Oct 4 14:50:31 mx dovecot[1302421]: auth: Debug: oauth2(christian@roessner.email,192.168.0.4,<3kfgc+MGeuXAqAAE>): Processing field family_name
Oct 4 14:50:31 mx dovecot[1302421]: auth: Debug: oauth2(christian@roessner.email,192.168.0.4,<3kfgc+MGeuXAqAAE>): Processing field given_name
Oct 4 14:50:31 mx dovecot[1302421]: auth: Debug: oauth2(christian@roessner.email,192.168.0.4,<3kfgc+MGeuXAqAAE>): Processing field iat
Oct 4 14:50:31 mx dovecot[1302421]: auth: Debug: oauth2(christian@roessner.email,192.168.0.4,<3kfgc+MGeuXAqAAE>): Processing field iss
Oct 4 14:50:31 mx dovecot[1302421]: auth: Debug: oauth2(christian@roessner.email,192.168.0.4,<3kfgc+MGeuXAqAAE>): Processing field name
Oct 4 14:50:31 mx dovecot[1302421]: auth: Debug: oauth2(christian@roessner.email,192.168.0.4,<3kfgc+MGeuXAqAAE>): Processing field nickname
Oct 4 14:50:31 mx dovecot[1302421]: auth: Debug: oauth2(christian@roessner.email,192.168.0.4,<3kfgc+MGeuXAqAAE>): Processing field preferred_username
Oct 4 14:50:31 mx dovecot[1302421]: auth: Debug: oauth2(christian@roessner.email,192.168.0.4,<3kfgc+MGeuXAqAAE>): Processing field rat
Oct 4 14:50:31 mx dovecot[1302421]: auth: Debug: oauth2(christian@roessner.email,192.168.0.4,<3kfgc+MGeuXAqAAE>): Processing field sub
Oct 4 14:50:31 mx dovecot[1302421]: auth: Debug: oauth2(christian@roessner.email,192.168.0.4,<3kfgc+MGeuXAqAAE>): oauth2 active_attribute "active" is not present in the oauth2 server's response
Oct 4 14:50:31 mx dovecot[1302421]: auth: oauth2(christian@roessner.email,192.168.0.4,<3kfgc+MGeuXAqAAE>): oauth2 failed: Token is not valid: Missing active_attribute from token
Is this a bug or does the active field shown above nothing have to do with the active field in the dovecot configuration?
I would expect the field shown above.
Thanks in advance
Christian Rößner
Rößner-Network-Solutions Zertifizierter ITSiBe / CISO Karl-Bröger-Str. 10, 36304 Alsfeld Fax: +49 6631 78823409, Mobil: +49 171 9905345 USt-IdNr.: DE225643613, https://roessner.website PGP fingerprint: 658D 1342 B762 F484 2DDF 1E88 38A5 4346 D727 94E5