5 Dec
2019
5 Dec
'19
9:58 p.m.
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: 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,<QPwA/fmY+tqCx5Tr>): oauth2 failed: 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 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 [0]: 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 Dec 5 14:32:22 mktst4 dovecot: auth: Debug: http-client: conn 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 [0]: Connection disconnect Dec 5 14:32:22 mktst4 dovecot: auth: Debug: http-client: conn 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 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
5 Dec
5 Dec
10:06 p.m.
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
6 Dec
6 Dec
4:16 a.m.
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 <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
1849
Age (days ago)
1850
Last active (days ago)
3 comments
2 participants
participants (2)
-
Aki Tuomi
-
mizuki