---
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...@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(fran...@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(fran...@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?token=eyJhbGciOi..redacted...3MDA0ODQ0ODMsImlhdCI6MTcwMDQ4NDE4MywiYXV0aF...:
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?token=eyJhbGciOiJSUzI1NiIsInR5cCIgOiAiSldUIiwia2lkIiA6ICJaYTFXcXhxb0RULXBSc2o1WXZFdUJfLUxBVUtGNk5SeFFrUS1mNmdTUGs4In0.eyJleHA..redacted...IteRg0Yvoo-2E_-NlvfaUV2E_CjyedmiS83FJ0SZ3MQ8WxaCo2ja6BhupTV1HoQ2LVy-F5kGSC5qpdCbUqr931ffd8VrVwhBgQ4TA-9ooLbIMYpbduJWHBt26lEjUbL-jKwjBHM-XvVq1f58fZNruDzKxBt3UPJGnniOssCbFomOkL8WEWj2m0-1xaD1NfONs2iRzu4YHbwqHKfS-Afn9yzB6l6ArXFGpUkrtIwu3sF06oYM60NQZsYMPFAwvysmIruXNrItuxbq-8j_y20g]
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?token=eyJhbGciOiJSUzI1NiIsInR5cCIgOiAiSldUIiwia2lkIiA6ICJaYTFXcXhxb0RULXBSc2o1WXZFdUJfLUxBVUtGNk5SeFFrUS1mNmdTUGs4In0.eyJWVkLWxvLmV1L3Jl...redactedlvfaUV2E_CjyedmiS83FJ0SZ3MQ8WxaCo2ja6BhupTV1HoQ2LVy-F5kGSC5qpdCbUqr931ffd8VrVwhBgQ4TA-9ooLbIMYpbduJWHBt26lEjUbL-jKwjBHM-XvVq1f58fZNruDzKxBt3UPJGnniOssCbFomOkL8WEWj2m0-1xaD1NfONs2iRzu4YHbwqHKfS-Afn9yzB6l6ArXFGpUkrtIwu3sF06oYM60NQZsYMPFAwvysmIruXNrItuxbq-8j_y20g]
Nov 20 13:43:03 auth: Debug: http-client[1]: request [Req1: GET
https://auth.mydomain.com/realms/myrealm/protocol/openid-connect/userinfo?token=eyJhbGciOiJSUzI1N...redacted...hdCI6MTcwMDQ4NDE4MywiYXV0aF...:
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...redacted...faUV2E_CjyedmiS83FJ0SZ3MQ8WxaCo2ja6BhupTV1HoQ2LVy-F5kGSC5qpdCbUqr931ffd8VrVwhBgQ4TA-9ooLbIMYpbduJWHBt26lEjUbL-jKwjBHM-XvVq1f58fZNruDzKxBt3UPJGnniOssCbFomOkL8WEWj2m0-1xaD1NfONs2iRzu4YHbwqHKfS-Afn9yzB6l6ArXFGpUkrtIwu3sF06oYM60NQZsYMPFAwvysmIruXNrItuxbq-8j_y20g]:
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?token=eyJhbGciOiJSUzI1NiIsInR5cCIgOiAiSldUIiwia2lkIiA6ICJaYTFXcXhxb0RULXBSc2o1WXZFdUJfLUxBVUtGNk5SeFFrUS1mNmdTUGs4In0.eyJleHAiOjE3MDA0ODQ0ODMsImlhdCI6MTcwMDQ4NDE4MywiYXV0aF...:
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?token=eyJhbGciOiJSUzI1NiIsInR5cCIgOiAiSldUIiwia2lkIiA6ICJaYTFXcXhxb0RULXBSc2o1WXZFdUJfLUxBVUtGNk5SeFFrUS1mNmdTUGs4In0.eyJleHAiOjE3M2Vzc2lvbl9zdGF0Z...redacted...yedmiS83FJ0SomOkL8WEWj2m0-1xaD1NfONs2iRzu4YHbwqHKfS-Afn9yzB6l6ArXFGpUkrtIwu3sF06oYM60NQZsYMPFAwvysmIruXNrItuxbq-8j_y20g]
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?token=eyJhbGciOiJ...redacted..hdCI6MTcwMDQ4NDE4MywiYXV0aF...:
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=<fran...@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=<fran...@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(fran...@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
_______________________________________________
dovecot mailing list -- dovecot@dovecot.org
To unsubscribe send an email to dovecot-le...@dovecot.org
