dovecot and oauth2 (with keycloak) not working
Hi,
I successfully configured Roundcube to use keycloak for oauth2.
However, I am having trouble to make it work with dovecot. My configuration is this:
cat dovecot-oauth2.conf.ext tokeninfo_url = https://auth.mydomain.com/realms/myrealm/protocol/openid-connect/userinfo introspection_url = https://auth.mydomain.com/realms/myrealm/protocol/openid-connect/token/intro... introspection_mode = post username_attribute = postfixMailAddress debug = yes scope = openid Roundcube_email
This is what I am getting from the logs:
Nov 20 08:20:30 auth: Error: ldap(francis@mydomain.com,10.10.40.30,<yskzUpAKb9EKCige>): ldap_bind() failed: Constraint violation Nov 20 08:20:30 auth: Debug: http-client: host auth.mydomain.com: Host created Nov 20 08:20:30 auth: Debug: http-client: host auth.mydomain.com: Host session created Nov 20 08:20:30 auth: Debug: http-client: host auth.mydomain.com: IPs have expired; need to refresh DNS lookup Nov 20 08:20:30 auth: Debug: http-client: host auth.mydomain.com: Performing asynchronous DNS lookup Nov 20 08:20:30 auth: Debug: http-client[1]: request [Req1: GET https://auth.mydomain.com/realms/med-lo/protocol/openid-connect/userinfoeyJh...]: Submitted (requests left=1) Nov 20 08:20:30 auth: Debug: http-client: host auth.mydomain.com: DNS lookup successful; got 1 IPs Nov 20 08:20:30 auth: Debug: http-client: peer 10.10.100.10:443 (shared): Peer created Nov 20 08:20:30 auth: Debug: http-client: peer 10.10.100.10:443: Peer pool created Nov 20 08:20:30 auth: Debug: http-client[1]: peer 10.10.100.10:443: Peer created Nov 20 08:20:30 auth: Debug: http-client[1]: queue https://auth.mydomain.com:443: Setting up connection to 10.10.100.10:443 (SSL=auth.mydomain.com) (1 requests pending) Nov 20 08:20:30 auth: Debug: http-client[1]: peer 10.10.100.10:443: Linked queue https://auth.mydomain.com:443 (1 queues linked) Nov 20 08:20:30 auth: Debug: http-client[1]: queue https://auth.mydomain.com:443: Started new connection to 10.10.100.10:443 (SSL=auth.mydomain.com) Nov 20 08:20:30 auth: Debug: http-client[1]: peer 10.10.100.10:443: Creating 1 new connections to handle requests (already 0 usable, connecting to 0, closing 0) Nov 20 08:20:30 auth: Debug: http-client[1]: peer 10.10.100.10:443: Making new connection 1 of 1 (0 connections exist, 0 pending) Nov 20 08:20:30 auth: Debug: http-client: conn 10.10.100.10:443 [1]: Connecting Nov 20 08:20:30 auth: Debug: http-client: conn 10.10.100.10:443 [1]: Waiting for connect (fd=23) to finish for max 0 msecs Nov 20 08:20:30 auth: Debug: http-client: conn 10.10.100.10:443 [1]: HTTPS connection created (1 parallel connections exist) Nov 20 08:20:30 auth: Debug: http-client: conn 10.10.100.10:443 [1]: Client connection failed (fd=23) Nov 20 08:20:30 auth: Debug: http-client[1]: peer 10.10.100.10:443: Connection failed (1 connections exist, 0 pending) Nov 20 08:20:30 auth: Debug: http-client: peer 10.10.100.10:443: Failed to make connection (1 connections exist, 0 pending) Nov 20 08:20:30 auth: Debug: http-client[1]: peer 10.10.100.10:443: Failed to establish any connection within our peer pool: connect(10.10.100.10:443) failed: Connection refused (1 connections exist, 0 pending) Nov 20 08:20:30 auth: Debug: http-client[1]: queue https://auth.mydomain.com:443: Failed to set up connection to 10.10.100.10:443 (SSL=auth.mydomain.com): connect(10.10.100.10:443) failed: Connection refused (1 peers pending, 1 requests pending) Nov 20 08:20:30 auth: Debug: http-client[1]: peer 10.10.100.10:443: Unlinked queue https://auth.mydomain.com:443 (0 queues linked) Nov 20 08:20:30 auth: Debug: http-client[1]: queue https://auth.mydomain.com:443: Failed to set up any connection; failing all queued requests Nov 20 08:20:30 auth: Debug: http-client[1]: request [Req1: GET https://auth.mydomain.com/realms/med-lo/protocol/openid-connect/userinfoeyJh...]: Error: 9003 connect(10.10.100.10:443) failed: Connection refused Nov 20 08:20:30 auth: Debug: http-client[1]: queue https://auth.mydomain.com:443: Dropping request [Req1: GET https://auth.mydomain.com/realms/med-lo/protocol/openid-connect/userinfoeyJh...] Nov 20 08:20:30 auth: Error: oauth2(francis@mydomain.com,10.10.40.30,<yskzUpAKb9EKCige>): oauth2 failed: connect(10.10.100.10:443) failed: Connection refused Nov 20 08:20:30 auth: Debug: http-client[1]: request [Req1: GET https://auth.mydomain.com/realms/med-lo/protocol/openid-connect/userinfoeyJh...]: Destroy (requests left=1) Nov 20 08:20:30 auth: Debug: http-client[1]: request [Req1: GET https://auth.mydomain.com/realms/med-lo/protocol/openid-connect/userinfoeyJh...]: Free (requests left=0) Nov 20 08:20:30 auth: Debug: http-client: conn 10.10.100.10:443 [1]: Connection close Nov 20 08:20:30 auth: Debug: http-client: conn 10.10.100.10:443 [1]: Connection disconnect Nov 20 08:20:30 auth: Debug: http-client: conn 10.10.100.10:443 [1]: Disconnected: connect() failed: Connection refused (fd=23) Nov 20 08:20:30 auth: Debug: http-client: conn 10.10.100.10:443 [1]: Detached peer Nov 20 08:20:30 auth: Debug: http-client: conn 10.10.100.10:443 [1]: Connection destroy Nov 20 08:20:32 imap-login: Info: Disconnected (auth service reported temporary failure): user=francis@mydomain.com, method=XOAUTH2, rip=10.10.40.30, lip=172.18.0.10, TLS, session=<yskzUpAKb9EKCige>
My dovecot version is 2.3.7.2 (3c910f64b).
I find it odd that it is sending the token as a parameter, when I chose “post” as the introspection mode. But I don’t know if that is the problem.
best,
Francis
On 20/11/2023 09:29 EET Francis Augusto Medeiros-Logeay via dovecot dovecot@dovecot.org wrote:
Hi,
I successfully configured Roundcube to use keycloak for oauth2.
However, I am having trouble to make it work with dovecot. My configuration is this:
cat dovecot-oauth2.conf.ext tokeninfo_url = https://auth.mydomain.com/realms/myrealm/protocol/openid-connect/userinfo introspection_url = https://auth.mydomain.com/realms/myrealm/protocol/openid-connect/token/intro... introspection_mode = post username_attribute = postfixMailAddress debug = yes scope = openid Roundcube_email
This is what I am getting from the logs:
Nov 20 08:20:30 auth: Error: ldap(francis@mydomain.com,10.10.40.30,<yskzUpAKb9EKCige>): ldap_bind() failed: Constraint violation Nov 20 08:20:30 auth: Debug: http-client: host auth.mydomain.com: Host created Nov 20 08:20:30 auth: Debug: http-client: host auth.mydomain.com: Host session created Nov 20 08:20:30 auth: Debug: http-client: host auth.mydomain.com: IPs have expired; need to refresh DNS lookup Nov 20 08:20:30 auth: Debug: http-client: host auth.mydomain.com:
...
My dovecot version is 2.3.7.2 (3c910f64b).
I find it odd that it is sending the token as a parameter, when I chose “post” as the introspection mode. But I don’t know if that is the problem.
best,
Francis
dovecot mailing list -- dovecot@dovecot.org To unsubscribe send an email to dovecot-leave@dovecot.org
Try adding /?token= to tokeninfo_url. Dovecot 2.3.7.2 will simply concatenate tokeninfo_url and token, so you need to provide the URL in that fashion.
Aki
Try adding /?token= to tokeninfo_url. Dovecot 2.3.7.2 will simply concatenate tokeninfo_url and token, so you need to provide the URL in that fashion.
Aki
Thanks Aki.
Still no go:
Nov 20 08:59:19 auth: Debug: http-client: host auth.mydomain.com: Host created Nov 20 08:59:19 auth: Debug: http-client: host auth.mydomain.com: Host session created Nov 20 08:59:19 auth: Debug: http-client: host auth.mydomain.com: Need to perform DNS lookup Nov 20 08:59:19 auth: Debug: http-client: host auth.mydomain.com: Performing asynchronous DNS lookup Nov 20 08:59:19 auth: Debug: http-client: host auth.mydomain.com: conn unix:dns-client: dns(auth.mydomain.com): Lookup started Nov 20 08:59:19 auth: Debug: http-client: host auth.mydomain.com: conn unix:dns-client: Connecting Nov 20 08:59:19 auth: Debug: http-client: host auth.mydomain.com: conn unix:dns-client (pid=506,uid=0): Client connected (fd=24) Nov 20 08:59:19 auth: Debug: http-client: host auth.mydomain.com: conn unix:dns-client (pid=506,uid=0): Sending version handshake Nov 20 08:59:19 auth: Debug: http-client[1]: request [Req1: GET https://auth.mydomain.com/realms/myrealm/protocol/openid-connect/userinfo/to......: Submitted (requests left=1) Nov 20 08:59:19 auth: Debug: http-client: host auth.mydomain.com: conn unix:dns-client (pid=506,uid=0): dns(auth.mydomain.com): Lookup successful after 4 msecs Nov 20 08:59:19 auth: Debug: http-client: host auth.mydomain.com: DNS lookup successful; got 1 IPs Nov 20 08:59:19 auth: Debug: http-client: peer 10.10.200.10:443 (shared): Peer created Nov 20 08:59:19 auth: Debug: http-client: peer 10.10.200.10:443: Peer pool created Nov 20 08:59:19 auth: Debug: http-client[1]: peer 10.10.200.10:443: Peer created Nov 20 08:59:19 auth: Debug: http-client[1]: queue https://auth.mydomain.com:443: Setting up connection to 10.10.200.10:443 (SSL=auth.mydomain.com) (1 requests pending) Nov 20 08:59:19 auth: Debug: http-client[1]: peer 10.10.200.10:443: Linked queue https://auth.mydomain.com:443 (1 queues linked) Nov 20 08:59:19 auth: Debug: http-client[1]: queue https://auth.mydomain.com:443: Started new connection to 10.10.200.10:443 (SSL=auth.mydomain.com) Nov 20 08:59:19 auth: Debug: http-client: host auth.mydomain.com: conn unix:dns-client (pid=506,uid=0): Disconnected: Connection closed (fd=24) Nov 20 08:59:19 auth: Debug: http-client: host auth.mydomain.com: conn unix:dns-client (pid=506,uid=0): Disconnect: deinit Nov 20 08:59:19 auth: Debug: http-client[1]: peer 10.10.200.10:443: Creating 1 new connections to handle requests (already 0 usable, connecting to 0, closing 0) Nov 20 08:59:19 auth: Debug: http-client[1]: peer 10.10.200.10:443: Making new connection 1 of 1 (0 connections exist, 0 pending) Nov 20 08:59:19 auth: Debug: http-client: conn 10.10.200.10:443 [1]: Connecting Nov 20 08:59:19 auth: Debug: http-client: conn 10.10.200.10:443 [1]: Waiting for connect (fd=24) to finish for max 0 msecs Nov 20 08:59:19 auth: Debug: http-client: conn 10.10.200.10:443 [1]: HTTPS connection created (1 parallel connections exist) Nov 20 08:59:19 auth: Debug: http-client: conn 10.10.200.10:443 [1]: Client connection failed (fd=24) Nov 20 08:59:19 auth: Debug: http-client[1]: peer 10.10.200.10:443: Connection failed (1 connections exist, 0 pending) Nov 20 08:59:19 auth: Debug: http-client: peer 10.10.200.10:443: Failed to make connection (1 connections exist, 0 pending) Nov 20 08:59:19 auth: Debug: http-client[1]: peer 10.10.200.10:443: Failed to establish any connection within our peer pool: connect(10.10.200.10:443) failed: Connection refused (1 connections exist, 0 pending) Nov 20 08:59:19 auth: Debug: http-client[1]: queue https://auth.mydomain.com:443: Failed to set up connection to 10.10.200.10:443 (SSL=auth.mydomain.com): connect(10.10.200.10:443) failed: Connection refused (1 peers pending, 1 requests pending) Nov 20 08:59:19 auth: Debug: http-client[1]: peer 10.10.200.10:443: Unlinked queue https://auth.mydomain.com:443 (0 queues linked) Nov 20 08:59:19 auth: Debug: http-client[1]: queue https://auth.mydomain.com:443: Failed to set up any connection; failing all queued requests Nov 20 08:59:19 auth: Debug: http-client[1]: request [Req1: GET https://auth.mydomain.com/realms/myrealm/protocol/openid-connect/userinfo/to......: Error: 9003 connect(10.10.200.10:443) failed: Connection refused Nov 20 08:59:19 auth: Debug: http-client[1]: queue https://auth.mydomain.com:443: Dropping request [Req1: GET https://auth.mydomain.com/realms/myrealm/protocol/openid-connect/userinfo/to...] Nov 20 08:59:19 auth: Debug: http-client: host auth.mydomain.com: Host is idle (timeout = 1799998 msecs) Nov 20 08:59:19 auth: Error: oauth2(francis@mydomain.com,10.10.40.30,<4Gv83JAKyOcKCige>): oauth2 failed: Token validation failed: connect(10.10.200.10:443) failed: Connection refused Nov 20 08:59:19 auth: Debug: http-client[1]: request [Req1: GET https://auth.mydomain.com/realms/myrealm/protocol/openid-connect/userinfo/to......: Destroy (requests left=1) Nov 20 08:59:19 auth: Debug: http-client[1]: request [Req1: GET https://auth.mydomain.com/realms/myrealm/protocol/openid-connect/userinfo/to......: Free (requests left=0) Nov 20 08:59:19 auth: Debug: http-client: conn 10.10.200.10:443 [1]: Connection close Nov 20 08:59:19 auth: Debug: http-client: conn 10.10.200.10:443 [1]: Connection disconnect Nov 20 08:59:19 auth: Debug: http-client: conn 10.10.200.10:443 [1]: Disconnected: connect() failed: Connection refused (fd=24) Nov 20 08:59:19 auth: Debug: http-client: conn 10.10.200.10:443 [1]: Detached peer Nov 20 08:59:19 auth: Debug: http-client: conn 10.10.200.10:443 [1]: Connection destroy Nov 20 08:59:21 imap-login: Info: Disconnected: Connection closed (auth service reported temporary failure): user=francis@mydomain.com, method=XOAUTH2, rip=10.10.40.30, lip=172.18.0.10, TLS, session=<4Gv83JAKyOcKCige> Nov 20 08:59:35 auth: Debug: http-client[1]: peer 10.10.200.10:443: Peer close Nov 20 08:59:35 auth: Debug: http-client[1]: peer 10.10.200.10:443: Peer disconnect Nov 20 08:59:35 auth: Debug: http-client[1]: peer 10.10.200.10:443: Peer destroy Nov 20 08:59:35 auth: Debug: http-client: peer 10.10.200.10:443: Peer pool destroy Nov 20 08:59:35 auth: Debug: http-client: peer 10.10.200.10:443 (shared): Peer destroy Nov 20 08:59:35 auth: Debug: http-client: host auth.mydomain.com: Host session destroy Nov 20 08:59:35 auth: Debug: http-client[1]: queue https://auth.mydomain.com:443: Destroy Nov 20 08:59:35 auth: Debug: http-client: host auth.mydomain.com: Host destroy
On 20/11/2023 10:03 EET Francis Augusto Medeiros-Logeay r_f@med-lo.eu wrote:
Try adding /?token= to tokeninfo_url. Dovecot 2.3.7.2 will simply concatenate tokeninfo_url and token, so you need to provide the URL in that fashion.
Aki
Thanks Aki.
Still no go:
Nov 20 08:59:19 auth: Debug: http-client: host auth.mydomain.com: Host created
<snip/>
oauth2(francis@mydomain.com,10.10.40.30,<4Gv83JAKyOcKCige>): oauth2 failed: Token validation failed: connect(10.10.200.10:443) failed: Connection refused
Aki
Francis Augusto Medeiros-Logeay Oslo, Norway
On 2023-11-20 09:04, Aki Tuomi wrote:
On 20/11/2023 10:03 EET Francis Augusto Medeiros-Logeay r_f@med-lo.eu wrote:
Try adding /?token= to tokeninfo_url. Dovecot 2.3.7.2 will simply concatenate tokeninfo_url and token, so you need to provide the URL in that fashion.
Aki
Thanks Aki.
Still no go:
Nov 20 08:59:19 auth: Debug: http-client: host auth.mydomain.com: Host created
<snip/>
oauth2(francis@mydomain.com,10.10.40.30,<4Gv83JAKyOcKCige>): oauth2 failed: Token validation failed: connect(10.10.200.10:443) failed: Connection refused
It still doesn't work after I fixed that "connection refused" problem. I had a NAT reflector problem. But with that out of the way, I still don't get it to work:
Nov 20 13:43:03 auth: Error:
ldap(francis@mydomain.com,10.10.40.30,<joax05QKsSAKCige>): ldap_bind()
failed: Constraint violation
Nov 20 13:43:03 auth: Debug: http-client: host auth.mydomain.com: Host
created
Nov 20 13:43:03 auth: Debug: http-client: host auth.mydomain.com: Host
session created
Nov 20 13:43:03 auth: Debug: http-client: host auth.mydomain.com: Need
to perform DNS lookup
Nov 20 13:43:03 auth: Debug: http-client: host auth.mydomain.com:
Performing asynchronous DNS lookup
Nov 20 13:43:03 auth: Debug: http-client: host auth.mydomain.com: conn
unix:dns-client: dns(auth.mydomain.com): Lookup started
Nov 20 13:43:03 auth: Debug: http-client: host auth.mydomain.com: conn
unix:dns-client: Connecting
Nov 20 13:43:03 auth: Debug: http-client: host auth.mydomain.com: conn
unix:dns-client (pid=2800,uid=0): Client connected (fd=23)
Nov 20 13:43:03 auth: Debug: http-client: host auth.mydomain.com: conn
unix:dns-client (pid=2800,uid=0): Sending version handshake
Nov 20 13:43:03 auth: Debug: http-client[1]: request [Req1: GET
https://auth.mydomain.com/realms/myrealm/protocol/openid-connect/userinfo?to......:
Submitted (requests left=1)
Nov 20 13:43:03 auth: Debug: http-client: host auth.mydomain.com: conn
unix:dns-client (pid=2800,uid=0): dns(auth.mydomain.com): Lookup
successful after 5 msecs
Nov 20 13:43:03 auth: Debug: http-client: host auth.mydomain.com: DNS
lookup successful; got 1 IPs
Nov 20 13:43:03 auth: Debug: http-client: peer 10.10.20.100:443
(shared): Peer created
Nov 20 13:43:03 auth: Debug: http-client: peer 10.10.20.100:443: Peer
pool created
Nov 20 13:43:03 auth: Debug: http-client[1]: peer 10.10.20.100:443: Peer
created
Nov 20 13:43:03 auth: Debug: http-client[1]: queue
https://auth.mydomain.com:443: Setting up connection to 10.10.20.100:443
(SSL=auth.mydomain.com) (1 requests pending)
Nov 20 13:43:03 auth: Debug: http-client[1]: peer 10.10.20.100:443:
Linked queue https://auth.mydomain.com:443 (1 queues linked)
Nov 20 13:43:03 auth: Debug: http-client[1]: queue
https://auth.mydomain.com:443: Started new connection to
10.10.20.100:443 (SSL=auth.mydomain.com)
Nov 20 13:43:03 auth: Debug: http-client: host auth.mydomain.com: conn
unix:dns-client (pid=2800,uid=0): Disconnected: Connection closed
(fd=23)
Nov 20 13:43:03 auth: Debug: http-client: host auth.mydomain.com: conn
unix:dns-client (pid=2800,uid=0): Disconnect: deinit
Nov 20 13:43:03 auth: Debug: http-client[1]: peer 10.10.20.100:443:
Creating 1 new connections to handle requests (already 0 usable,
connecting to 0, closing 0)
Nov 20 13:43:03 auth: Debug: http-client[1]: peer 10.10.20.100:443:
Making new connection 1 of 1 (0 connections exist, 0 pending)
Nov 20 13:43:03 auth: Debug: http-client: conn 10.10.20.100:443 [1]:
Connecting
Nov 20 13:43:03 auth: Debug: http-client: conn 10.10.20.100:443 [1]:
Waiting for connect (fd=23) to finish for max 0 msecs
Nov 20 13:43:03 auth: Debug: http-client: conn 10.10.20.100:443 [1]:
HTTPS connection created (1 parallel connections exist)
Nov 20 13:43:03 auth: Debug: http-client: conn 10.10.20.100:443 [1]:
Client connected (fd=23)
Nov 20 13:43:03 auth: Debug: http-client: conn 10.10.20.100:443 [1]:
Connected
Nov 20 13:43:03 auth: Debug: http-client: conn 10.10.20.100:443 [1]:
Starting SSL handshake
Nov 20 13:43:03 auth: Debug: auth.mydomain.com: SSL: where=0x10, ret=1:
before SSL initialization
Nov 20 13:43:03 auth: Debug: auth.mydomain.com: SSL: where=0x1001,
ret=1: before SSL initialization
Nov 20 13:43:03 auth: Debug: auth.mydomain.com: SSL: where=0x1001,
ret=1: SSLv3/TLS write client hello
Nov 20 13:43:03 auth: Debug: auth.mydomain.com: SSL: where=0x1002,
ret=-1: SSLv3/TLS write client hello
Nov 20 13:43:03 auth: Debug: auth.mydomain.com: SSL: where=0x1002,
ret=-1: SSLv3/TLS write client hello
Nov 20 13:43:03 auth: Debug: auth.mydomain.com: SSL: where=0x1002,
ret=-1: SSLv3/TLS write client hello
Nov 20 13:43:03 auth: Debug: auth.mydomain.com: SSL: where=0x1001,
ret=1: SSLv3/TLS write client hello
Nov 20 13:43:03 auth: Debug: auth.mydomain.com: SSL: where=0x1001,
ret=1: SSLv3/TLS read server hello
Nov 20 13:43:03 auth: Debug: auth.mydomain.com: SSL: where=0x1002,
ret=-1: TLSv1.3 read encrypted extensions
Nov 20 13:43:03 auth: Debug: auth.mydomain.com: SSL: where=0x1002,
ret=-1: TLSv1.3 read encrypted extensions
Nov 20 13:43:03 auth: Debug: auth.mydomain.com: SSL: where=0x1002,
ret=-1: TLSv1.3 read encrypted extensions
Nov 20 13:43:03 auth: Debug: auth.mydomain.com: SSL: where=0x1001,
ret=1: TLSv1.3 read encrypted extensions
Nov 20 13:43:03 auth: Info: Received valid SSL certificate:
/C=US/O=Internet Security Research Group/CN=ISRG Root X1
Nov 20 13:43:03 auth: Info: Received valid SSL certificate:
/C=US/O=Let's Encrypt/CN=R3
Nov 20 13:43:03 auth: Info: Received valid SSL certificate:
/CN=auth.mydomain.com
Nov 20 13:43:03 auth: Debug: auth.mydomain.com: SSL: where=0x1001,
ret=1: SSLv3/TLS read server certificate
Nov 20 13:43:03 auth: Debug: auth.mydomain.com: SSL: where=0x1001,
ret=1: TLSv1.3 read server certificate verify
Nov 20 13:43:03 auth: Debug: auth.mydomain.com: SSL: where=0x1001,
ret=1: SSLv3/TLS read finished
Nov 20 13:43:03 auth: Debug: auth.mydomain.com: SSL: where=0x1001,
ret=1: SSLv3/TLS write change cipher spec
Nov 20 13:43:03 auth: Debug: auth.mydomain.com: SSL: where=0x1001,
ret=1: SSLv3/TLS write finished
Nov 20 13:43:03 auth: Debug: auth.mydomain.com: SSL: where=0x20, ret=1:
SSL negotiation finished successfully
Nov 20 13:43:03 auth: Debug: auth.mydomain.com: SSL: where=0x1002,
ret=1: SSL negotiation finished successfully
Nov 20 13:43:03 auth: Debug: http-client: conn 10.10.20.100:443 [1]: SSL
handshake successful
Nov 20 13:43:03 auth: Debug: http-client: conn 10.10.20.100:443 [1]:
Ready for requests
Nov 20 13:43:03 auth: Debug: http-client[1]: peer 10.10.20.100:443:
Successfully connected (1 connections exist, 0 pending)
Nov 20 13:43:03 auth: Debug: http-client: peer 10.10.20.100:443:
Successfully connected (1 connections exist, 0 pending)
Nov 20 13:43:03 auth: Debug: http-client[1]: peer 10.10.20.100:443:
Using 1 idle connections to handle 1 requests (1 total connections
ready)
Nov 20 13:43:03 auth: Debug: http-client[1]: queue
https://auth.mydomain.com:443: Connection to peer 10.10.20.100:443
claimed request [Req1: GET
https://auth.mydomain.com/realms/myrealm/protocol/openid-connect/userinfo?to...]
Nov 20 13:43:03 auth: Debug: http-client: conn 10.10.20.100:443 [1]:
Claimed request [Req1: GET
https://auth.mydomain.com/realms/myrealm/protocol/openid-connect/userinfo?to...]
Nov 20 13:43:03 auth: Debug: http-client[1]: request [Req1: GET
https://auth.mydomain.com/realms/myrealm/protocol/openid-connect/userinfo?to......:
Sent header
Nov 20 13:43:03 auth: Debug: http-client[1]: peer 10.10.20.100:443: No
more requests to service for this peer (1 connections exist, 0 pending)
Nov 20 13:43:03 auth: Debug: auth.mydomain.com: SSL: where=0x1001,
ret=1: SSL negotiation finished successfully
Nov 20 13:43:03 auth: Debug: auth.mydomain.com: SSL: where=0x1001,
ret=1: SSL negotiation finished successfully
Nov 20 13:43:03 auth: Debug: auth.mydomain.com: SSL: where=0x1001,
ret=1: SSLv3/TLS read server session ticket
Nov 20 13:43:03 auth: Debug: auth.mydomain.com: SSL: where=0x1002,
ret=1: SSL negotiation finished successfully
Nov 20 13:43:03 auth: Debug: auth.mydomain.com: SSL: where=0x1001,
ret=1: SSL negotiation finished successfully
Nov 20 13:43:03 auth: Debug: auth.mydomain.com: SSL: where=0x1001,
ret=1: SSL negotiation finished successfully
Nov 20 13:43:03 auth: Debug: auth.mydomain.com: SSL: where=0x1001,
ret=1: SSLv3/TLS read server session ticket
Nov 20 13:43:03 auth: Debug: auth.mydomain.com: SSL: where=0x1002,
ret=1: SSL negotiation finished successfully
Nov 20 13:43:03 auth: Debug: http-client: conn 10.10.20.100:443 [1]: Got
401 response for request [Req1: GET
https://auth.mydomain.com/realms/myrealm/protocol/openid-connecc2lvbl9z...re...]:
Unauthorized (took 7 ms + 20 ms in queue)
Nov 20 13:43:03 auth: Debug: http-client[1]: request [Req1: GET
https://auth.mydomain.com/realms/myrealm/protocol/openid-connect/userinfo?to......:
Finished
Nov 20 13:43:03 auth: Debug: http-client[1]: queue
https://auth.mydomain.com:443: Dropping request [Req1: GET
https://auth.mydomain.com/realms/myrealm/protocol/openid-connect/userinfo?to...]
Nov 20 13:43:03 auth: Debug: http-client: host auth.mydomain.com: Host
is idle (timeout = 1799981 msecs)
Nov 20 13:43:03 auth: Debug: http-client[1]: request [Req1: GET
https://auth.mydomain.com/realms/myrealm/protocol/openid-connect/userinfo?to......:
Free (requests left=1)
Nov 20 13:43:03 auth: Debug: http-client[1]: peer 10.10.20.100:443: No
requests to service for this peer (1 connections exist, 0 pending)
Nov 20 13:43:03 auth: Debug: http-client: conn 10.10.20.100:443 [1]: No
more requests queued; going idle (timeout = 60000 msecs)
Nov 20 13:43:05 imap-login: Info: Disconnected: Connection closed (auth
service reported temporary failure): user=francis@mydomain.com,
method=XOAUTH2, rip=10.10.40.30, lip=172.18.0.10, TLS,
session=<joax05QKsSAKCige>
Nov 20 13:43:05 imap-login: Info: Login: user=francis@mydomain.com,
method=PLAIN, rip=80.202.241.120, lip=172.18.0.10, mpid=2815, TLS,
session=
Any clue?
Best, Francis
It seems that it works on the dovecot side. When Roundcube sends the token, I get the user authenticated via IMAP/oauth2 in dovecot.
What worked for me was:
- adding client_id and client_secret
- removing the tokeninfo_url, using just the introspect_url and introspect_mode=token.
Now gotta fix Roundcube...
Best, Francis
On 2023-11-20 13:48, Francis Augusto Medeiros-Logeay wrote:
Francis Augusto Medeiros-Logeay Oslo, Norway
On 2023-11-20 09:04, Aki Tuomi wrote:
On 20/11/2023 10:03 EET Francis Augusto Medeiros-Logeay r_f@med-lo.eu wrote:
Try adding /?token= to tokeninfo_url. Dovecot 2.3.7.2 will simply concatenate tokeninfo_url and token, so you need to provide the URL in that fashion.
Aki
Thanks Aki.
Still no go:
Nov 20 08:59:19 auth: Debug: http-client: host auth.mydomain.com: Host created
<snip/>
oauth2(francis@mydomain.com,10.10.40.30,<4Gv83JAKyOcKCige>): oauth2 failed: Token validation failed: connect(10.10.200.10:443) failed: Connection refused
Hi,
I'm running dovecot with keycloak without problems since 1 month.
Nov 20 08:20:30 auth: Error: oauth2(francis@mydomain.com,10.10.40.30,<yskzUpAKb9EKCige>): oauth2 failed: connect(10.10.100.10:443) failed: Connection refused
It seem's that your keycloak is not responding to connection requests on port 443. You can try "telnet 10.10.100.10 443" from your dovecot server?
Regards Urban
Am 20.11.23 um 08:29 schrieb Francis Augusto Medeiros-Logeay via dovecot:
Hi,
I successfully configured Roundcube to use keycloak for oauth2.
However, I am having trouble to make it work with dovecot. My configuration is this:
cat dovecot-oauth2.conf.ext tokeninfo_url = https://auth.mydomain.com/realms/myrealm/protocol/openid-connect/userinfo introspection_url = https://auth.mydomain.com/realms/myrealm/protocol/openid-connect/token/intro... introspection_mode = post username_attribute = postfixMailAddress debug = yes scope = openid Roundcube_email
This is what I am getting from the logs:
Nov 20 08:20:30 auth: Error: ldap(francis@mydomain.com,10.10.40.30,<yskzUpAKb9EKCige>): ldap_bind() failed: Constraint violation Nov 20 08:20:30 auth: Debug: http-client: host auth.mydomain.com: Host created Nov 20 08:20:30 auth: Debug: http-client: host auth.mydomain.com: Host session created Nov 20 08:20:30 auth: Debug: http-client: host auth.mydomain.com: IPs have expired; need to refresh DNS lookup Nov 20 08:20:30 auth: Debug: http-client: host auth.mydomain.com: Performing asynchronous DNS lookup Nov 20 08:20:30 auth: Debug: http-client[1]: request [Req1: GET https://auth.mydomain.com/realms/med-lo/protocol/openid-connect/userinfoeyJh...]: Submitted (requests left=1) Nov 20 08:20:30 auth: Debug: http-client: host auth.mydomain.com: DNS lookup successful; got 1 IPs Nov 20 08:20:30 auth: Debug: http-client: peer 10.10.100.10:443 (shared): Peer created Nov 20 08:20:30 auth: Debug: http-client: peer 10.10.100.10:443: Peer pool created Nov 20 08:20:30 auth: Debug: http-client[1]: peer 10.10.100.10:443: Peer created Nov 20 08:20:30 auth: Debug: http-client[1]: queue https://auth.mydomain.com:443: Setting up connection to 10.10.100.10:443 (SSL=auth.mydomain.com) (1 requests pending) Nov 20 08:20:30 auth: Debug: http-client[1]: peer 10.10.100.10:443: Linked queue https://auth.mydomain.com:443 (1 queues linked) Nov 20 08:20:30 auth: Debug: http-client[1]: queue https://auth.mydomain.com:443: Started new connection to 10.10.100.10:443 (SSL=auth.mydomain.com) Nov 20 08:20:30 auth: Debug: http-client[1]: peer 10.10.100.10:443: Creating 1 new connections to handle requests (already 0 usable, connecting to 0, closing 0) Nov 20 08:20:30 auth: Debug: http-client[1]: peer 10.10.100.10:443: Making new connection 1 of 1 (0 connections exist, 0 pending) Nov 20 08:20:30 auth: Debug: http-client: conn 10.10.100.10:443 [1]: Connecting Nov 20 08:20:30 auth: Debug: http-client: conn 10.10.100.10:443 [1]: Waiting for connect (fd=23) to finish for max 0 msecs Nov 20 08:20:30 auth: Debug: http-client: conn 10.10.100.10:443 [1]: HTTPS connection created (1 parallel connections exist) Nov 20 08:20:30 auth: Debug: http-client: conn 10.10.100.10:443 [1]: Client connection failed (fd=23) Nov 20 08:20:30 auth: Debug: http-client[1]: peer 10.10.100.10:443: Connection failed (1 connections exist, 0 pending) Nov 20 08:20:30 auth: Debug: http-client: peer 10.10.100.10:443: Failed to make connection (1 connections exist, 0 pending) Nov 20 08:20:30 auth: Debug: http-client[1]: peer 10.10.100.10:443: Failed to establish any connection within our peer pool: connect(10.10.100.10:443) failed: Connection refused (1 connections exist, 0 pending) Nov 20 08:20:30 auth: Debug: http-client[1]: queue https://auth.mydomain.com:443: Failed to set up connection to 10.10.100.10:443 (SSL=auth.mydomain.com): connect(10.10.100.10:443) failed: Connection refused (1 peers pending, 1 requests pending) Nov 20 08:20:30 auth: Debug: http-client[1]: peer 10.10.100.10:443: Unlinked queue https://auth.mydomain.com:443 (0 queues linked) Nov 20 08:20:30 auth: Debug: http-client[1]: queue https://auth.mydomain.com:443: Failed to set up any connection; failing all queued requests Nov 20 08:20:30 auth: Debug: http-client[1]: request [Req1: GET https://auth.mydomain.com/realms/med-lo/protocol/openid-connect/userinfoeyJh...]: Error: 9003 connect(10.10.100.10:443) failed: Connection refused Nov 20 08:20:30 auth: Debug: http-client[1]: queue https://auth.mydomain.com:443: Dropping request [Req1: GET https://auth.mydomain.com/realms/med-lo/protocol/openid-connect/userinfoeyJh...] Nov 20 08:20:30 auth: Error: oauth2(francis@mydomain.com,10.10.40.30,<yskzUpAKb9EKCige>): oauth2 failed: connect(10.10.100.10:443) failed: Connection refused Nov 20 08:20:30 auth: Debug: http-client[1]: request [Req1: GET https://auth.mydomain.com/realms/med-lo/protocol/openid-connect/userinfoeyJh...]: Destroy (requests left=1) Nov 20 08:20:30 auth: Debug: http-client[1]: request [Req1: GET https://auth.mydomain.com/realms/med-lo/protocol/openid-connect/userinfoeyJh...]: Free (requests left=0) Nov 20 08:20:30 auth: Debug: http-client: conn 10.10.100.10:443 [1]: Connection close Nov 20 08:20:30 auth: Debug: http-client: conn 10.10.100.10:443 [1]: Connection disconnect Nov 20 08:20:30 auth: Debug: http-client: conn 10.10.100.10:443 [1]: Disconnected: connect() failed: Connection refused (fd=23) Nov 20 08:20:30 auth: Debug: http-client: conn 10.10.100.10:443 [1]: Detached peer Nov 20 08:20:30 auth: Debug: http-client: conn 10.10.100.10:443 [1]: Connection destroy Nov 20 08:20:32 imap-login: Info: Disconnected (auth service reported temporary failure): user=francis@mydomain.com, method=XOAUTH2, rip=10.10.40.30, lip=172.18.0.10, TLS, session=<yskzUpAKb9EKCige>
My dovecot version is 2.3.7.2 (3c910f64b).
I find it odd that it is sending the token as a parameter, when I chose “post” as the introspection mode. But I don’t know if that is the problem.
best,
Francis
dovecot mailing list -- dovecot@dovecot.org To unsubscribe send an email to dovecot-leave@dovecot.org
participants (3)
-
Aki Tuomi
-
Francis Augusto Medeiros-Logeay
-
Urban Loesch