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 <li...@mlserv.org> wrote:
>> 
>> 
>> Hi,
>> 
>>> Am 04.10.2023 um 14:31 schrieb Aki Tuomi <aki.tu...@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+dove...@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/RR2GXLOAS6U3MZCQCA4T4S6QXCRV5GST
>>>> 
>>>> 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 response
>> ```
>> 
>> In 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 

_______________________________________________
dovecot mailing list -- dovecot@dovecot.org
To unsubscribe send an email to dovecot-le...@dovecot.org

Reply via email to