Hello,
I'm trying to configure roundcube / dovecot to work with keycloak. I activated xoauth2 oauthbearer in dovecot. But a problem occurs when dovecot tries to contact the keycloak server (logs are below).
My problem looks like this one: https://dovecot.org/pipermail/dovecot/2019-December/117768.html The response to this problem was about a bug in oauth driver (https://dovecot.org/pipermail/dovecot/2019-December/117787.html).
Mizuki was using Dovecot v2.2.36 (1f10bfa63) I have Dovecot Dovecot v2.3.4.1 (f79e8e7e4)
I'm wondering if this bug is still present in my version or if I have another problem.
Both my servers (dovecot and keycloak) are using let's encrypt certificates. I tried to configure Keycloak with nginx proxy and without it (access via port 8443) (in case the problem came from the ssl config on the keycloak server), but still the same error.
If the bug is fixed, then could someone tell me what do I have to put in the option tls_ca_cert_file?
I tried with /etc/letsencrypt/live/my.host/chain.pem and also certs I got from let's encrypt website (https://letsencrypt.org/certificates/ / tried ISRG Root X1 (self-signed) & Let’s Encrypt Authority X3 (IdenTrust cross-signed) & Let’s Encrypt Authority X3 (Signed by ISRG Root X1)) But I always have the same error.
Thanks, Kenny
My configs:
- I'm on a Debian Buster with Dovecot / postfix / roundcube
- dovecot -n :
# 2.3.4.1 (f79e8e7e4): /etc/dovecot/dovecot.conf # Pigeonhole version 0.5.4 () # OS: Linux 4.19.0-5-cloud-amd64 x86_64 Debian 10.4 auth_debug = yes auth_mechanisms = xoauth2 oauthbearer login auth_verbose = yes debug_log_path = /var/log/dovecot-debug.log first_valid_gid = 10000 first_valid_uid = 10000 info_log_path = /var/log/dovecot.log last_valid_gid = 20000 last_valid_uid = 20000 lda_mailbox_autocreate = yes log_path = /var/log/dovecot.log mail_debug = yes mail_gid = mail mail_location = maildir:~/Maildir mail_privileged_group = mail namespace inbox { inbox = yes location = mailbox Drafts { special_use = \Drafts } mailbox Junk { special_use = \Junk } mailbox Sent { special_use = \Sent } mailbox "Sent Messages" { special_use = \Sent } mailbox Trash { special_use = \Trash } prefix = } passdb { args = /etc/dovecot/dovecot-ldap.conf.ext driver = ldap } passdb { args = /etc/dovecot/dovecot-oauth2.conf.ext driver = oauth2 mechanisms = xoauth2 oauthbearer } plugin { sieve = file:~/sieve;active=~/.dovecot.sieve } protocols = " imap" service auth { unix_listener /var/spool/postfix/private/auth { mode = 0600 user = postfix } unix_listener auth-master { mode = 0600 user = mail } unix_listener auth-userdb { mode = 0600 user = mail } } service stats { unix_listener stats-reader { mode = 0600 user = mail } unix_listener stats-writer { mode = 0600 user = mail } } ssl_cert = </etc/letsencrypt/live/my.host/fullchain.pem ssl_client_ca_dir = /etc/ssl/certs ssl_dh = # hidden, use -P to show it ssl_key = # hidden, use -P to show it ssl_prefer_server_ciphers = yes ssl_require_crl = no userdb { args = /etc/dovecot/dovecot-ldap.conf.ext driver = ldap } userdb { args = gid=mail home=/var/mail/%u driver = static } verbose_ssl = yes protocol lda { info_log_path = /var/log/dovecot-deliver.log log_path = /var/log/dovecot-deliver-errors.log }
- dovecot-oauth2.conf.ext
tokeninfo_url = https://my.keycloak.host/auth/realms/test_saml/protocol/openid-connect/token introspection_mode = post introspection_url = https://my.keycloak.host/auth/realms/test_saml/protocol/openid-connect/token... username_attribute = email tls_ca_cert_file = /etc/letsencrypt/live/my.host/chain.pem #tls_ca_cert_file = /etc/ssl/certs/letsencrypt.pem #active_attribute = enableMail #active_value = TRUE debug = yes rawlog_dir = /tmp/oauth2
- Logs:
Jul 04 17:00:12 auth: Debug: oauth2(my.mail@whatever,::1,<fG8uk6CpBJ0AAAAAAAAAAAAAAAAAAAAB>): oauth2: Making token validation lookup to https://my.keycloak.host/auth/realms/test_saml/protocol/openid-connect/token Jul 04 17:00:12 auth: Debug: http-client: host my.keycloak.host: Host created Jul 04 17:00:12 auth: Debug: http-client: host my.keycloak.host: Host session created Jul 04 17:00:12 auth: Debug: http-client: host my.keycloak.host: IPs have expired; need to refresh DNS lookup Jul 04 17:00:12 auth: Debug: http-client: host my.keycloak.host: Performing asynchronous DNS lookup Jul 04 17:00:12 auth: Debug: http-client[1]: request [Req1: GET https://my.keycloak.host/auth/realms/test_saml/protocol/openid-connect/token...... (long token)]: Submitted (requests left=1) Jul 04 17:00:12 auth: Debug: http-client: host my.keycloak.host: DNS lookup successful; got 1 IPs Jul 04 17:00:12 auth: Debug: http-client: peer 151.62.56.14 (shared): Peer created Jul 04 17:00:12 auth: Debug: http-client: peer 151.62.56.14: Peer pool created Jul 04 17:00:12 auth: Debug: http-client[1]: peer 151.62.56.14: Peer created Jul 04 17:00:12 auth: Debug: http-client[1]: queue https://my.keycloak.host: Setting up connection to 151.62.56.14 (SSL=my.keycloak.host) (1 requests pending) Jul 04 17:00:12 auth: Debug: http-client[1]: peer 151.62.56.14: Linked queue https://my.keycloak.host (1 queues linked) Jul 04 17:00:12 auth: Debug: http-client[1]: queue https://my.keycloak.host: Started new connection to 151.62.56.14 (SSL=my.keycloak.host) Jul 04 17:00:12 auth: Debug: http-client[1]: peer 151.62.56.14: Creating 1 new connections to handle requests (already 0 usable, connecting to 0, closing 0) Jul 04 17:00:12 auth: Debug: http-client[1]: peer 151.62.56.14: Making new connection 1 of 1 (0 connections exist, 0 pending) Jul 04 17:00:12 auth: Debug: http-client[1]: conn 151.62.56.14 [0]: (151.62.56.14): Connecting Jul 04 17:00:12 auth: Debug: http-client[1]: conn 151.62.56.14 [0]: (151.62.56.14): Waiting for connect (fd=22) to finish for max 0 msecs Jul 04 17:00:12 auth: Debug: http-client[1]: conn 151.62.56.14 [0]: HTTPS connection created (1 parallel connections exist) Jul 04 17:00:12 auth: Debug: http-client[1]: conn 151.62.56.14 [0]: (151.62.56.14): Client connected (fd=22) Jul 04 17:00:12 auth: Debug: http-client[1]: conn 151.62.56.14 [0]: Connected Jul 04 17:00:12 auth: Debug: http-client[1]: conn 151.62.56.14 [0]: Starting SSL handshake Jul 04 17:00:12 auth: Debug: my.keycloak.host: SSL: where=0x10, ret=1: before SSL initialization Jul 04 17:00:12 auth: Debug: my.keycloak.host: SSL: where=0x1001, ret=1: before SSL initialization Jul 04 17:00:12 auth: Debug: my.keycloak.host: SSL: where=0x1001, ret=1: SSLv3/TLS write client hello Jul 04 17:00:12 auth: Debug: my.keycloak.host: SSL: where=0x1002, ret=-1: SSLv3/TLS write client hello Jul 04 17:00:12 auth: Debug: my.keycloak.host: SSL: where=0x1002, ret=-1: SSLv3/TLS write client hello Jul 04 17:00:12 auth: Debug: my.keycloak.host: SSL: where=0x1001, ret=1: SSLv3/TLS write client hello Jul 04 17:00:12 auth: Debug: my.keycloak.host: SSL: where=0x1001, ret=1: SSLv3/TLS read server hello Jul 04 17:00:12 auth: Debug: my.keycloak.host: SSL error: Received invalid SSL certificate: unable to get issuer certificate: /C=US/O=Let's Encrypt/CN=Let's Encrypt Authority X3 Jul 04 17:00:12 auth: Debug: my.keycloak.host: SSL: where=0x1001, ret=1: SSLv3/TLS read server certificate Jul 04 17:00:12 auth: Debug: my.keycloak.host: SSL: where=0x1001, ret=1: SSLv3/TLS read server key exchange Jul 04 17:00:12 auth: Debug: my.keycloak.host: SSL: where=0x1001, ret=1: SSLv3/TLS read server done Jul 04 17:00:12 auth: Debug: my.keycloak.host: SSL: where=0x1001, ret=1: SSLv3/TLS write client key exchange Jul 04 17:00:12 auth: Debug: my.keycloak.host: SSL: where=0x1001, ret=1: SSLv3/TLS write change cipher spec Jul 04 17:00:12 auth: Debug: my.keycloak.host: SSL: where=0x1001, ret=1: SSLv3/TLS write finished Jul 04 17:00:12 auth: Debug: my.keycloak.host: SSL: where=0x1002, ret=-1: SSLv3/TLS write finished Jul 04 17:00:12 auth: Debug: my.keycloak.host: SSL: where=0x1002, ret=-1: SSLv3/TLS write finished
==> dovecot.log <== Jul 04 17:00:12 auth: Info: Received invalid SSL certificate: unable to get issuer certificate: /C=US/O=Let's Encrypt/CN=Let's Encrypt Authority X3
==> dovecot-debug.log <== Jul 04 17:00:12 auth: Debug: my.keycloak.host: SSL: where=0x1002, ret=-1: SSLv3/TLS write finished Jul 04 17:00:12 auth: Debug: my.keycloak.host: SSL: where=0x1001, ret=1: SSLv3/TLS write finished Jul 04 17:00:12 auth: Debug: my.keycloak.host: SSL: where=0x1001, ret=1: SSLv3/TLS read change cipher spec Jul 04 17:00:12 auth: Debug: my.keycloak.host: SSL: where=0x1001, ret=1: SSLv3/TLS read finished Jul 04 17:00:12 auth: Debug: my.keycloak.host: SSL: where=0x20, ret=1: SSL negotiation finished successfully Jul 04 17:00:12 auth: Debug: my.keycloak.host: SSL: where=0x1002, ret=1: SSL negotiation finished successfully Jul 04 17:00:12 auth: Debug: my.keycloak.host: SSL error: Received invalid SSL certificate: unable to get issuer certificate: /C=US/O=Let's Encrypt/CN=Let's Encrypt Authority X3 Jul 04 17:00:12 auth: Debug: http-client[1]: peer 151.62.56.14: Connection failed (1 connections exist, 0 pending) Jul 04 17:00:12 auth: Debug: http-client: peer 151.62.56.14: Failed to make connection (1 connections exist, 0 pending) Jul 04 17:00:12 auth: Debug: http-client[1]: peer 151.62.56.14: Failed to establish any connection within our peer pool: SSL handshaking with 151.62.56.14 failed: read(SSL 151.62.56.14) failed: Received invalid SSL certificate: unable to get issuer certificate: /C=US/O=Let's Encrypt/CN=Let's Encrypt Authority X3 (1 connections exist, 0 pending) Jul 04 17:00:12 auth: Debug: http-client[1]: queue https://my.keycloak.host: Failed to set up connection to 151.62.56.14 (SSL=my.keycloak.host): SSL handshaking with 151.62.56.14 failed: read(SSL 151.62.56.14) failed: Received invalid SSL certificate: unable to get issuer certificate: /C=US/O=Let's Encrypt/CN=Let's Encrypt Authority X3 (1 peers pending, 1 requests pending) Jul 04 17:00:12 auth: Debug: http-client[1]: queue https://my.keycloak.host: Failed to set up any connection; failing all queued requests Jul 04 17:00:12 auth: Debug: http-client[1]: peer 151.62.56.14: Unlinked queue https://my.keycloak.host (0 queues linked) Jul 04 17:00:12 auth: Debug: http-client[1]: request [Req1: GET https://my.keycloak.host/auth/realms/test_saml/protocol/openid-connect/token...... (long token)]: Error: 9003 SSL handshaking with 151.62.56.14 failed: read(SSL 151.62.56.14) failed: Received invalid SSL certificate: unable to get issuer certificate: /C=US/O=Let's Encrypt/CN=Let's Encrypt Authority X3 Jul 04 17:00:12 auth: Debug: http-client[1]: queue https://my.keycloak.host: Dropping request [Req1: GET https://my.keycloak.host/auth/realms/test_saml/protocol/openid-connect/token...... (long token)] Jul 04 17:00:12 auth: Debug: oauth2(my.mail@whatever,::1,<fG8uk6CpBJ0AAAAAAAAAAAAAAAAAAAAB>): oauth2: callback(-1, SSL handshaking with 151.62.56.14 failed: read(SSL 151.62.56.14) failed: Received invalid SSL certificate: unable to get issuer certificate: /C=US/O=Let's Encrypt/CN=Let's Encrypt Authority X3)
==> dovecot.log <== Jul 04 17:00:12 auth: Error: oauth2(my.mail@whatever,::1,<fG8uk6CpBJ0AAAAAAAAAAAAAAAAAAAAB>): oauth2 failed: SSL handshaking with 151.62.56.14 failed: read(SSL 151.62.56.14) failed: Received invalid SSL certificate: unable to get issuer certificate: /C=US/O=Let's Encrypt/CN=Let's Encrypt Authority X3