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 passdb {
driver = oauth2
mechanisms = oauthbearer xoauth2
args = /etc/dovecot/dovecot-oauth2.conf.ext
} I wonder if anyone has experienced this possibly know what's going on.
Thanks!
Mizuki*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:
Host created
Dec 5 14:32:22 mktst4 dovecot: auth: Debug: http-client: host 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:
DNS lookup successful; got 1 IPs
Dec 5 14:32:22 mktst4 dovecot: auth: Debug: http-client: peer 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 (SSL=
example.com) (1 requests pending)
Dec 5 14:32:22 mktst4 dovecot: auth: Debug: http-client: peer 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 (SSL=
example.com)
Dec 5 14:32:22 mktst4 dovecot: auth: Debug: http-client: peer 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:
Making new connection 1 of 1
Dec 5 14:32:22 mktst4 dovecot: auth: Debug: http-client: conn 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
[0]: Connected
Dec 5 14:32:22 mktst4 dovecot: auth: Debug: http-client: conn 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:
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 (SSL=
example.com): SSL handshaking with 10.0.2.2:443 failed: read(SSL
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:
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:
Host is idle (timeout = 1799992 msecs)
Dec 5 14:32:22 mktst4 dovecot: auth: Error:
oauth2(mizuki,10.0.2.1,
*#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
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 =
*# cat /etc/dovecot/conf.d/auth-oauth2.conf.ext*
userdb {
driver = static
args = uid=vmail gid=vmail home=/var/vmail/%u
}
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
:443' or 'curl -v https:// 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,
): 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 =
# 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
I changed some of the tls options following the document, now config is following:
tokeninfo_url = https://keycloak.com/auth/realms/mail/protocol/openid-connect/token introspection_url = https://dovecot:7598e21b-ec34-481f-80d0-059bddae0923@keycloak.com/auth/realm... introspection_mode = post debug = yes rawlog_dir = /tmp/oauth2 #force_introspection = yes username_attribute = username #active_attribute = active #active_value = true tls_ca_cert_file = /etc/pki/CA/certs/incommon-rsa-server-ca.crt tls_cert_file = /etc/pki/dovecot/certs/dovecot.pem tls_key_file = /etc/pki/dovecot/private/dovecot.pem
The debug log is showing now slightly different msg ex: Dec 5 21:09:59 mktst4 dovecot: auth: Error: oauth2(mizuki,10.0.2.1,<29b4iv+YKuuCx5Tr>): oauth2 failed: Couldn't initialize SSL context: Can't load SSL certificate: There is no valid PEM certificate.
Still not able to connect to the keyclaok server. :(
PS: Dovecot & Keycloak severs are both using the same legit cert/key pair with CA file configured.
Thanks! Mizuki
On Thu, Dec 5, 2019 at 3:06 PM Aki Tuomi aki.tuomi@open-xchange.com wrote:
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
:443' or 'curl -v https:// 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,
): 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 =
# 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
participants (2)
-
Aki Tuomi
-
mizuki