configuring Dovecot with wforced and auth_policy_server_url with https results in assertion failed

Thu Mar 28 22:34:52 EET 2019

>>>> Set
>>>> 
>>>> ssl_client_ca_file=/path/to/cacert.pem to validate the certificate 
>>> 
>>> Can this be the Lets Encrypt cert that we already have? In other words we have:
>>> ssl_cert = </etc/pki/dovecot/certs/dovecot.pem
>>> ssl_key = </etc/pki/dovecot/private/dovecot.pem
>>> 
>>> Can those be used?
>> 
>> Set it to *CA* cert. You can also use
>> 
>> ssl_client_ca_file=/etc/pki/tls/ca-bundle crt (on centos) 

OK did that.

>> ssl_client_ca_dir=/etc/ssl/certs (on debian based)
>>>> Are you using haproxy or something in front of dovecot?
>>> 
>>> No. Just Squirrelmail webmail with sendmail.
>>> 
>> Maybe squirrelmail supports forwarding original client ip with ID command. Otherwise dovecot cannot know it. Or you could configure squirrelmail to use weakforced ?

I see some options in http://squirrelmail.org/docs/admin/admin-5.html#ss5.3 <http://squirrelmail.org/docs/admin/admin-5.html#ss5.3>. Would it be a plugin?

> Also check that auth_policy_request_attributes use %{rip} and not %{real_rip}. You can see this with 
> 
> `doveconf auth_policy_request_attributes`

Yes I’ve confirmed it matches. Still getting the URL or IP of the webmail address as well as errors like SSL handshake to ex.ter.na.lip:8084 failed: Connection closed

Mar 28 16:13:36 auth: Debug: http-client[1]: queue https://ourdomain:8084: Timeout (now: 2019-03-28 16:13:36.300)
Mar 28 16:13:36 auth: Debug: http-client[1]: queue https://ourdomain:8084: Absolute timeout expired for request [Req10: POST https://ourdomain:8084/?command=allow] (Request queued 2.002 secs ago, not yet sent, 0.000 in other ioloops)
Mar 28 16:13:36 auth: Debug: http-client[1]: request [Req10: POST https://ourdomain:8084/?command=allow]: Error: 9008 Absolute request timeout expired (Request queued 2.002 secs ago, not yet sent, 0.000 in other ioloops)
Mar 28 16:13:36 auth: Debug: http-client[1]: queue https://ourdomain:8084: Dropping request [Req10: POST https://ourdomain:8084/?command=allow]
Mar 28 16:13:36 auth: Error: policy(abc,127.0.0.1,<5aBSMC2FROF/AAAB>): Policy server HTTP error: Absolute request timeout expired (Request queued 2.002 secs ago, not yet sent, 0.000 in other ioloops)
Mar 28 16:13:36 auth: Debug: http-client[1]: request [Req10: POST https://ourdomain:8084/?command=allow]: Destroy (requests left=1)
Mar 28 16:13:36 auth: Debug: http-client[1]: request [Req10: POST https://ourdomain:8084/?command=allow]: Free (requests left=0)
Mar 28 16:13:36 auth-worker(32249): Debug: pam(abc,127.0.0.1,<5aBSMC2FROF/AAAB>): lookup service=dovecot
Mar 28 16:13:36 auth-worker(32249): Debug: pam(abc,127.0.0.1,<5aBSMC2FROF/AAAB>): #1/1 style=1 msg=Password: 
Mar 28 16:13:38 auth-worker(32249): Info: pam(abc,127.0.0.1,<5aBSMC2FROF/AAAB>): unknown user
Mar 28 16:13:38 auth: Debug: policy(abc,127.0.0.1,<5aBSMC2FROF/AAAB>): Policy request https://ourdomain:8084/?command=report
Mar 28 16:13:38 auth: Debug: policy(abc,127.0.0.1,<5aBSMC2FROF/AAAB>): Policy server request JSON: {"device_id":"","login":"abc","protocol":"imap","pwhash":"00","remote":"127.0.0.1","success":false,"policy_reject":false,"tls":false}
Mar 28 16:13:38 auth: Debug: http-client[1]: queue https://ourdomain:8084: Set request timeout to 2019-03-28 16:13:40.625 (now: 2019-03-28 16:13:38.625)
Mar 28 16:13:38 auth: Debug: http-client: peer ex.ter.na.lip:8084 (shared): Peer reused
Mar 28 16:13:38 auth: Debug: http-client[1]: queue https://ourdomain:8084: Setting up connection to ex.ter.na.lip:8084 (SSL=ourdomain) (1 requests pending)
Mar 28 16:13:38 auth: Debug: http-client[1]: request [Req11: POST https://ourdomain:8084/?command=report]: Submitted (requests left=1)
Mar 28 16:13:38 auth: Debug: http-client[1]: peer ex.ter.na.lip:8084: Creating 1 new connections to handle requests (already 0 usable, connecting to 0, closing 0)
Mar 28 16:13:40 auth: Debug: client passdb out: FAIL	1	user=abc
Mar 28 16:13:40 imap-login: Info: Aborted login (auth failed, 1 attempts in 6 secs): user=<abc>, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, secured, session=<5aBSMC2FROF/AAAB>
Mar 28 16:13:40 auth: Debug: http-client[1]: queue https://ourdomain:8084: Timeout (now: 2019-03-28 16:13:40.626)
Mar 28 16:13:40 auth: Debug: http-client[1]: queue https://ourdomain:8084: Absolute timeout expired for request [Req11: POST https://ourdomain:8084/?command=report] (Request queued 2.000 secs ago, not yet sent, 0.000 in other ioloops)
Mar 28 16:13:40 auth: Debug: http-client[1]: request [Req11: POST https://ourdomain:8084/?command=report]: Error: 9008 Absolute request timeout expired (Request queued 2.000 secs ago, not yet sent, 0.000 in other ioloops)
Mar 28 16:13:40 auth: Debug: http-client[1]: queue https://ourdomain:8084: Dropping request [Req11: POST https://ourdomain:8084/?command=report]
Mar 28 16:13:40 auth: Error: policy(abc,127.0.0.1,<5aBSMC2FROF/AAAB>): Policy server HTTP error: Absolute request timeout expired (Request queued 2.000 secs ago, not yet sent, 0.000 in other ioloops)
Mar 28 16:13:40 auth: Debug: http-client[1]: request [Req11: POST https://ourdomain:8084/?command=report]: Destroy (requests left=1)
Mar 28 16:13:40 auth: Debug: http-client[1]: request [Req11: POST https://ourdomain:8084/?command=report]: Free (requests left=0)

Mar 28 16:13:59 auth: Debug: http-client: peer ex.ter.na.lip:8084 (shared): Backoff timer expired
Mar 28 16:13:59 auth: Debug: http-client[1]: peer ex.ter.na.lip:8084: Making new connection 1 of 1 (0 connections exist, 0 pending)
Mar 28 16:13:59 auth: Debug: http-client[1]: conn ex.ter.na.lip:8084 [9]: HTTPS connection created (1 parallel connections exist)
Mar 28 16:13:59 auth: Debug: http-client[1]: conn ex.ter.na.lip:8084 [9]: Connected
Mar 28 16:13:59 auth: Debug: http-client[1]: conn ex.ter.na.lip:8084 [9]: Starting SSL handshake
Mar 28 16:13:59 auth: Debug: http-client[1]: conn ex.ter.na.lip:8084 [9]: SSL handshake to ex.ter.na.lip:8084 failed: Connection closed
Mar 28 16:13:59 auth: Debug: http-client[1]: peer ex.ter.na.lip:8084: Connection failed (1 connections exist, 0 pending)
Mar 28 16:13:59 auth: Debug: http-client: peer ex.ter.na.lip:8084: Failed to make connection (1 connections exist, 0 pending)
Mar 28 16:13:59 auth: Debug: http-client[1]: peer ex.ter.na.lip:8084: Failed to establish any connection within our peer pool: SSL handshake to ex.ter.na.lip:8084 failed: Connection closed (1 connections exist, 0 pending)
Mar 28 16:13:59 auth: Debug: http-client[1]: queue https://ourdomain:8084: Failed to set up connection to ex.ter.na.lip:8084 (SSL=ourdomain): SSL handshake to ex.ter.na.lip:8084 failed: Connection closed (1 peers pending, 0 requests pending)
Mar 28 16:13:59 auth: Debug: http-client[1]: queue https://ourdomain:8084: Failed to set up any connection; failing all queued requests
Mar 28 16:13:59 auth: Debug: http-client[1]: peer ex.ter.na.lip:8084: Unlinked queue https://ourdomain:8084 (0 queues linked)
Mar 28 16:13:59 auth: Debug: http-client[1]: conn ex.ter.na.lip:8084 [9]: Connection close
Mar 28 16:13:59 auth: Debug: http-client[1]: conn ex.ter.na.lip:8084 [9]: Connection disconnect
Mar 28 16:13:59 auth: Debug: http-client[1]: conn ex.ter.na.lip:8084 [9]: Detached peer
Mar 28 16:13:59 auth: Debug: http-client[1]: conn ex.ter.na.lip:8084 [9]: Connection destroy

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://dovecot.org/pipermail/dovecot/attachments/20190328/3c8ef892/attachment-0001.html>