Re: Dovecot & OAuth

5 Dec 2019


      Before declaring it not ready for prime time, did you try setting
tls_ca_cert_file = /etc/ssl/certs/ca-certificates.crt
In the oauth2 configuration file as documented in https://doc.dovecot.org/configuration_manual/authentication/oauth2 ?
Aki
...
On 05/12/2019 21:58 mizuki via dovecot <dovecot@dovecot.org> wrote:
Hi all,
We'd like to enable OAuth with Keycloak in Dovecot, after enabling 'OAUTHBEARER XOAUTH2' in Dovecot based on online document, I can confirm Dovecot is ready for OAuth using openssl command, however when the auth request comes in, it failed in establishing a SSL connection with Keycloak server on port 443, shown as following in debug logs. I can confirming using commands 'openssl s_client -connect <keycloak_server>:443' or 'curl -v https://<keycloak_server/' all returns normal and no errors. Altering some of the SSL options in dovecot such as 'ssl_ca = </etc/pki/CA/certs/root_ca.pem' or 'ssl_client_ca_file = </etc/pki/CA/certs/root_ca.pem' does not help either. The certificate are NOT self-signed but signed the legit authorities. So I'm not sure why dovecot could not establish the connections.
Debug logs:
Dec 5 14:32:07 mktst4 dovecot: auth: Debug: auth client connected (pid=16554)
Dec 5 14:32:22 mktst4 dovecot: auth: Debug: client in: AUTH#0111#011OAUTHBEARER#011service=imap#011secured#011session=QPwA/fmY+tqCx5Tr#011lip=130.199.148.187#011rip=10.0.2.1#011lport=993#011rport=56058#011resp=bixhPW1penVraQFob3N0PW1rdHN0NC5zZGNjLmJubC5nb3YBcG9ydD05OTMBYXV0aD1CZWFyZXIgZXlKaGJHY2lPaUpTVXpJMU5pSXNJblI1Y0NJZ09pQWlTbGRVSWl3aWEybGtJaUE2SUNKcmRHeE5TSFZtYkc1NFZUUmlSR1pLTm5kSGRteFBNVVYxWWxWd2FreEZVVmhIY25GTU5UYzNhSEJSSW4wLmV5SnFkR2tpT2lJNE5XSmxZV05tTkMxak1tTmxMVFJtTkRJdFltUTRNUzAxTnpWaU4yRmpZV05sT1RnaUxDSmxlSEFpT2pFMU56VTJNVEF5TURnc0ltNWlaaUk2TUN3aWFXRjBJam94TlRjMU5UYzBNakE0TENKcGMzTWlPaUpvZEhSd2N6b3ZMMnRsZVdOc2IyRnJNaTV6WkdOakxtSnViQzVuYjNZdllYVjBhQzl5WldGc2JYTXZiV0ZwYkNJc0ltRjFaQ0k2SW1GalkyOTFiblFpTENKemRXSWlPaUkyTmpWa05EVTNNeTA0WVdFMUxUUmtPRFl0WW1NelppMHlaVEpqTWpOaU16WTJORFVpTENKMGVYQWlPaUpDWldGeVpYSWlMQ0poZW5BaU9pSmtiM1psWTI5MElpd2lZWFYwYUY5MGFXMWxJam93TENKelpYTnphVzl1WDNOMFlYUmxJam9pT1RNNE5XRTVOakF0TUROa1pDMDBPR05sTFdFeU4yUXRZVFkzWkdZME5tUXhaRGcxSWl3aVlXTnlJam9pTVNJc0luSmxZV3h0WDJGalkyVnpjeUk2ZXlKeWIyeGxjeUk2V3lKdlptWnNhVzVsWDJGalkyVnpjeUlzSW5WdFlWOWhkWFJvYjNKcGVtRjBhVzl1SWwxOUxDSnlaWE52ZFhKalpWOWhZMk5sYzNNaU9uc2lZV05qYjNWdWRDSTZleUp5YjJ4bGN5STZXeUp0WVc1aFoyVXRZV05qYjNWdWRDSXNJbTFoYm1GblpTMWhZMk52ZFc1MExXeHBibXR6SWl3aWRtbGxkeTF3Y205bWFXeGxJbDE5ZlN3aWMyTnZjR1VpT2lKd2NtOW1hV3hsSUdWdFlXbHNJaXdpWlcxaGFXeGZkbVZ5YVdacFpXUWlPbVpoYkhObExDSnVZVzFsSWpvaVRXbDZkV3RwSUV0aGNtRnpZWGRoSWl3aWNISmxabVZ5Y21Wa1gzVnpaWEp1WVcxbElqb2liV2w2ZFd0cElpd2laMmwyWlc1ZmJtRnRaU0k2SWsxcGVuVnJhU0lzSW1aaGJXbHNlVjl1WVcxbElqb2lTMkZ5WVhOaGQyRWlMQ0psYldGcGJDSTZJbTFwZW5WcmFVQmlibXd1WjI5MkluMC5NZTRwNkl0dmx2T0VYRTIxM2pwSnJpa3FhZGNZb0ZsMnlMVlJzQTJvQTdmWDgteEtJYTR2ckZmamwwLXRwb2JodzIyRnBvVDZ2TWoxbXphLXBWWUxzNW1vM0w5Y0xKT2hVVnV2Tm9YSm5nZlRzLXk2TWxuTXVGV1NQemtidEhhOXJTUEVqZGFZQXBDQk52MG9CWEs2bmhIM0U5ZkNvTl9TQlUycWxaSWk2M1dWOUZXSjFrbHVGT2Iwc0xja2JfWGNGZzhUZ0dXOEdVUlRYTlg4bW1VM1dNLWJ5dnJuTkFyNmFjWW1ibXRaVzRhV0NwTk5FSHRZU29LSmgydHZuQjhHNnl5eWptWWJ5Q2ZhTmwwSnVZYU52VFEzTXhCX2FnLV9Pcy04VkwtTGFLdHBGYXBMNEVNWUJaXzFnZmNhSFdUSUV1VS0wSVdjTjlEa2xxcW1MN19jNlEBAQ== (previous base64 data may contain sensitive data)
Dec 5 14:32:22 mktst4 dovecot: auth: Debug: http-client: host example.com (http://example.com): Host created
Dec 5 14:32:22 mktst4 dovecot: auth: Debug: http-client: host example.com (http://example.com): Performing asynchronous DNS lookup
Dec 5 14:32:22 mktst4 dovecot: auth: Debug: http-client: request [Req1: GET https://example.com/auth/realms/mail/protocol/openid-connect/tokeneyJhbGciOi...]: Submitted
Dec 5 14:32:22 mktst4 dovecot: auth: Debug: http-client: host example.com (http://example.com): DNS lookup successful; got 1 IPs
Dec 5 14:32:22 mktst4 dovecot: auth: Debug: http-client: peer 10.0.2.2:443 (http://10.0.2.2:443): Peer created
Dec 5 14:32:22 mktst4 dovecot: auth: Debug: http-client: queue https://example.com"443: Setting up connection to 10.0.2.2:443 (http://10.0.2.2:443) (SSL=example.com (http://example.com)) (1 requests pending)
Dec 5 14:32:22 mktst4 dovecot: auth: Debug: http-client: peer 10.0.2.2:443 (http://10.0.2.2:443): Linked queue https://example.com:443 (1 queues linked)
Dec 5 14:32:22 mktst4 dovecot: auth: Debug: http-client: queue https://example.com:443: Started new connection to 10.0.2.2:443 (http://10.0.2.2:443) (SSL=example.com (http://example.com))
Dec 5 14:32:22 mktst4 dovecot: auth: Debug: http-client: peer 10.0.2.2:443 (http://10.0.2.2:443): Creating 1 new connections to handle requests (already 0 usable, connecting to 0, closing 0)
Dec 5 14:32:22 mktst4 dovecot: auth: Debug: http-client: peer 10.0.2.2:443 (http://10.0.2.2:443): Making new connection 1 of 1
Dec 5 14:32:22 mktst4 dovecot: auth: Debug: http-client: conn 10.0.2.2:443 (http://10.0.2.2:443) [0]: HTTPS connection created (1 parallel connections exist)
Dec 5 14:32:22 mktst4 dovecot: auth: Debug: http-client: conn 10.0.2.2:443 (http://10.0.2.2:443) [0]: Connected
Dec 5 14:32:22 mktst4 dovecot: auth: Debug: http-client: conn 10.0.2.2:443 (http://10.0.2.2:443) [0]: Starting SSL handshake
Dec 5 14:32:22 mktst4 dovecot: auth: Received invalid SSL certificate: unable to get issuer certificate: /C=US/ST=New Jersey/L=Jersey City/O=The USERTRUST Network/CN=USERTrust RSA Certification Authority
Dec 5 14:32:22 mktst4 dovecot: auth: Debug: http-client: peer 10.0.2.2:443 (http://10.0.2.2:443): Failed to make connection (connections=1, connecting=1)
Dec 5 14:32:22 mktst4 dovecot: auth: Debug: http-client: queue https://example.com:443: Failed to set up connection to 10.0.2.2:443 (http://10.0.2.2:443) (SSL=example.com (http://example.com)): SSL handshaking with 10.0.2.2:443 (http://10.0.2.2:443) failed: read(SSL 10.0.2.2:443 (http://10.0.2.2:443)) failed: Received invalid SSL certificate: unable to get issuer certificate: /C=US/ST=New Jersey/L=Jersey City/O=The USERTRUST Network/CN=USERTrust RSA Certification Authority (1 peers pending, 1 requests pending)
Dec 5 14:32:22 mktst4 dovecot: auth: Debug: http-client: queue https://example.com:443: Failed to set up any connection; failing all queued requests
Dec 5 14:32:22 mktst4 dovecot: auth: Debug: http-client: peer 10.0.2.2:443 (http://10.0.2.2:443): Unlinked queue https://example.com:443 (0 queues linked)
Dec 5 14:32:22 mktst4 dovecot: auth: Debug: http-client: queue https://example.com:443: Dropping request [Req1: GET https://example.com/auth/realms/mail/protocol/openid-connect/tokeneyJhbGciOi...]
Dec 5 14:32:22 mktst4 dovecot: auth: Debug: http-client: host example.com (http://example.com): Host is idle (timeout = 1799992 msecs)
Dec 5 14:32:22 mktst4 dovecot: auth: Error: oauth2(mizuki,10.0.2.1,<QPwA/fmY+tqCx5Tr>): oauth2 failed: SSL handshaking with 10.0.2.2:443 (http://10.0.2.2:443) failed: read(SSL 10.0.2.2:443 (http://10.0.2.2:443)) failed: Received invalid SSL certificate: unable to get issuer certificate: /C=US/ST=New Jersey/L=Jersey City/O=The USERTRUST Network/CN=USERTrust RSA Certification Authority
Dec 5 14:32:22 mktst4 dovecot: auth: Debug: http-client: request [Req1: GET https://example.com/auth/realms/mail/protocol/openid-connect/tokeneyJhbGciOi...]: Destroy (requests left=1)
Dec 5 14:32:22 mktst4 dovecot: auth: Debug: http-client: request [Req1: GET https://example.com/auth/realms/mail/protocol/openid-connect/tokeneyJhbGciOi...]: Free (requests left=0)
Dec 5 14:32:22 mktst4 dovecot: auth: Debug: http-client: conn 10.0.2.2:443 (http://10.0.2.2:443) [0]: SSL handshaking with 10.0.2.2:443 (http://10.0.2.2:443) failed: read(SSL 10.0.2.2:443 (http://10.0.2.2:443)) failed: Received invalid SSL certificate: unable to get issuer certificate: /C=US/ST=New Jersey/L=Jersey City/O=The USERTRUST Network/CN=USERTrust RSA Certification Authority
Dec 5 14:32:22 mktst4 dovecot: auth: Debug: http-client: conn 10.0.2.2:443 (http://10.0.2.2:443) [0]: Connection close
Dec 5 14:32:22 mktst4 dovecot: auth: Debug: http-client: conn 10.0.2.2:443 (http://10.0.2.2:443) [0]: Connection disconnect
Dec 5 14:32:22 mktst4 dovecot: auth: Debug: http-client: conn 10.0.2.2:443 (http://10.0.2.2:443) [0]: Connection destroy
#dovecot -n
# 2.2.36 (1f10bfa63): /etc/dovecot/dovecot.conf
# OS: Linux 3.10.0-1062.4.3.el7.x86_64 x86_64 Red Hat Enterprise Linux Server release 7.7 (Maipo)
# Hostname: mktst4.sdcc.bnl.gov (http://mktst4.sdcc.bnl.gov)
auth_debug = yes
auth_debug_passwords = yes
auth_mechanisms = oauthbearer xoauth2
auth_verbose = yes
auth_verbose_passwords = yes
first_valid_uid = 1000
mail_debug = yes
mail_location = maildir:~/Maildir
mbox_write_locks = fcntl
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-oauth2.conf.ext
driver = oauth2
mechanisms = oauthbearer xoauth2
}
protocols = imap
service auth {
unix_listener /var/spool/postfix/private/auth {
group = postfix
mode = 0666
user = postfix
}
}
ssl = required
ssl_ca = </etc/pki/CA/certs/2.pem
ssl_cert = </etc/pki/dovecot/certs/dovecot.pem
ssl_cipher_list = ECDH+AESGCM:ECDH+CHACHA20:DH+AESGCM:ECDH+AES256:DH+AES256:ECDH+AES128:DH+AES:!aNULL:!MD5:!DSS:!RSA
ssl_client_ca_file = </etc/pki/CA/certs/2.pem
ssl_key = # hidden, use -P to show it
ssl_prefer_server_ciphers = yes
ssl_require_crl = no
userdb {
args = uid=vmail gid=vmail home=/var/vmail/%u
driver = static
}
# cat /etc/dovecot/conf.d/auth-oauth2.conf.ext
passdb {
driver = oauth2
mechanisms = oauthbearer xoauth2
args = /etc/dovecot/dovecot-oauth2.conf.ext
}
userdb {
driver = static
args = uid=vmail gid=vmail home=/var/vmail/%u
}
I wonder if anyone has experienced this possibly know what's going on.
Thanks!
Mizuki

Re: Dovecot & OAuth

Aki Tuomi

Debug logs:

#dovecot -n

# cat /etc/dovecot/conf.d/auth-oauth2.conf.ext

userdb { driver = static args = uid=vmail gid=vmail home=/var/vmail/%u }