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=<CYPX05QKj/tQyvF4> Nov 20 13:43:12 imap(francis@mydomain.com)<2822><+yVA1JQKj7wKCigB>: Info: Disconnected: Logged out in=218 out=2443 deleted=0 expunged=0 trashed=0 hdr_count=0 hdr_bytes=0 body_count=0 body_bytes=0 Nov 20 13:43:22 auth: Debug: http-client[1]: peer 10.10.20.100:443: Peer close Nov 20 13:43:22 auth: Debug: http-client[1]: peer 10.10.20.100:443: Peer disconnect Nov 20 13:43:22 auth: Debug: http-client: conn 10.10.20.100:443 [1]: Lost peer; already idle Nov 20 13:43:22 auth: Debug: http-client: conn 10.10.20.100:443 [1]: Detached peer Nov 20 13:43:22 auth: Debug: http-client[1]: peer 10.10.20.100:443: Peer destroy Nov 20 13:43:22 auth: Debug: http-client: host auth.mydomain.com: Host session destroy Nov 20 13:43:22 auth: Debug: http-client[1]: queue https://auth.mydomain.com:443: Destroy Nov 20 13:43:22 auth: Debug: http-client: host auth.mydomain.com: Host destroy Nov 20 13:43:22 auth: Debug: http-client: conn 10.10.20.100:443 [1]: Connection destroy Nov 20 13:43:22 auth: Debug: http-client: conn 10.10.20.100:443 [1]: Connection disconnect Nov 20 13:43:22 auth: Debug: http-client: conn 10.10.20.100:443 [1]: Disconnected: Connection closed (fd=24) Nov 20 13:43:22 auth: Debug: auth.mydomain.com: SSL alert: close notify Nov 20 13:43:22 auth: Debug: http-client: peer 10.10.20.100:443: Peer pool destroy Nov 20 13:43:22 auth: Debug: http-client: peer 10.10.20.100:443 (shared): Peer destroy
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