Dovecot + Weakforced Policy server

alberto bersol alberto at bersol.info
Wed Jan 16 10:06:33 EET 2019


Hi,
I'm trying to set Weakforced with Dovecot and I cannot log in policy 
server. This is the config:

/root/weakforced/wforce/wforce.conf
-----------------------------------
...
webserver("0.0.0.0:8084", "super")
...

/etc/dovecot/conf.d/95-policy.conf
----------------------------------
auth_policy_server_url = http://localhost:8084/
#auth_policy_hash_nonce = wforce:super
auth_policy_hash_nonce = 
{SHA256-CRYPT}$5$Ue5UrToV.Bam02bQ$Bi9OJ62Mkgc20L2HnLVmD2OCHyXaKje6Hh7qNjnOkB9

I'm following the instructions of Dovecot's wiki:
https://wiki.dovecot.org/Authentication/Policy
...
"To generate the hash, you concatenate nonce, login name, nil byte, 
password and run it through the hash algorithm once. The hash is 
truncated when truncation is set to non-zero. The hash is truncated by 
first choosing bits from MSB to byte boundary (rounding up), then 
right-shifting the remainding bits.

hash = H(nonce||user||'\x00'||password)
bytes = round8(bits*8)
hash = HEX(hash[0:bytes] >> (bytes-bits*8))

And I set hash with password (super) in this way:

vm-weakforced:~# doveadm pw -p noncewforce\x00super -s SHA256-CRYPT
{SHA256-CRYPT}$5$ZWIX2dnU7NJvGHgC$hYFbeCCaHYZv0yPP80GHygxQMPmI5BjMx2ttRe9zti2 


But if I log in Dovecot Server:

vm-weakforced:~# doveadm auth login usuario
Password:
passdb: usuario auth succeeded
extra fields:
   user=usuario

userdb extra fields:
   usuario
   system_groups_user=usuario
   uid=1000
   gid=1000
   home=/home/usuario

Answer of Weakforced is always "...authentication failed":

WforceWebserver: HTTP Request "/" from 127.0.0.1:39720: Web 
Authentication failed

And Dovecot logs don't show anything else:
...
Jan 15 16:50:50 vm-weakforced dovecot: auth: Debug: auth client 
connected (pid=967)
Jan 15 16:50:50 vm-weakforced dovecot: auth: Debug: client in: 
AUTH#0111#011PLAIN#011service=doveadm#011resp=dXN1YXJpbwB1c3VhcmlvAHVzdWFyaW8= 
(previous base64 data may contain sensitive data)
Jan 15 16:50:50 vm-weakforced dovecot: auth: Debug: policy(usuario): 
Policy request http://localhost:8084/?command=allow
Jan 15 16:50:50 vm-weakforced dovecot: auth: Debug: policy(usuario): 
Policy server request JSON: 
{"device_id":"","login":"usuario","protocol":"doveadm","pwhash":"0a00","remote":"","tls":false}
Jan 15 16:50:50 vm-weakforced dovecot: auth: Debug: http-client[1]: 
queue http://localhost:8084: Set request timeout to 2019-01-15 
16:50:52.236 (now: 2019-01-15 16:50:50.236)
Jan 15 16:50:50 vm-weakforced dovecot: auth: Debug: http-client: peer 
127.0.0.1:8084 (shared): Peer created
Jan 15 16:50:50 vm-weakforced dovecot: auth: Debug: http-client: peer 
127.0.0.1:8084: Peer pool created
Jan 15 16:50:50 vm-weakforced dovecot: auth: Debug: http-client[1]: peer 
127.0.0.1:8084: Peer created
Jan 15 16:50:50 vm-weakforced dovecot: auth: Debug: http-client[1]: 
queue http://localhost:8084: Setting up connection to 127.0.0.1:8084 (1 
requests pending)
Jan 15 16:50:50 vm-weakforced dovecot: auth: Debug: http-client[1]: peer 
127.0.0.1:8084: Linked queue http://localhost:8084 (1 queues linked)
Jan 15 16:50:50 vm-weakforced dovecot: auth: Debug: http-client[1]: 
queue http://localhost:8084: Started new connection to 127.0.0.1:8084
Jan 15 16:50:50 vm-weakforced dovecot: auth: Debug: http-client[1]: 
request [Req4: POST http://localhost:8084/?command=allow]: Submitted 
(requests left=1)
Jan 15 16:50:50 vm-weakforced dovecot: auth: Debug: http-client[1]: peer 
127.0.0.1:8084: Creating 1 new connections to handle requests (already 0 
usable, connecting to 0, closing 0)
Jan 15 16:50:50 vm-weakforced dovecot: auth: Debug: http-client[1]: peer 
127.0.0.1:8084: Making new connection 1 of 1 (0 connections exist, 0 
pending)
Jan 15 16:50:50 vm-weakforced dovecot: auth: Debug: http-client[1]: conn 
127.0.0.1:8084 [2]: (127.0.0.1:8084): Connecting
Jan 15 16:50:50 vm-weakforced dovecot: auth: Debug: http-client[1]: conn 
127.0.0.1:8084 [2]: (127.0.0.1:8084): Waiting for connect (fd=20) to 
finish for max 0 msecs
Jan 15 16:50:50 vm-weakforced dovecot: auth: Debug: http-client[1]: conn 
127.0.0.1:8084 [2]: HTTP connection created (1 parallel connections exist)
Jan 15 16:50:50 vm-weakforced dovecot: auth: Debug: http-client[1]: conn 
127.0.0.1:8084 [2]: (127.0.0.1:8084): Client connected (fd=20)
Jan 15 16:50:50 vm-weakforced dovecot: auth: Debug: http-client[1]: conn 
127.0.0.1:8084 [2]: Connected
Jan 15 16:50:50 vm-weakforced dovecot: auth: Debug: http-client[1]: conn 
127.0.0.1:8084 [2]: Ready for requests
Jan 15 16:50:50 vm-weakforced dovecot: auth: Debug: http-client[1]: peer 
127.0.0.1:8084: Successfully connected (1 connections exist, 0 pending)
Jan 15 16:50:50 vm-weakforced dovecot: auth: Debug: http-client: peer 
127.0.0.1:8084: Successfully connected (1 connections exist, 0 pending)
Jan 15 16:50:50 vm-weakforced dovecot: auth: Debug: http-client[1]: peer 
127.0.0.1:8084: Using 1 idle connections to handle 1 requests (1 total 
connections ready)
Jan 15 16:50:50 vm-weakforced dovecot: auth: Debug: http-client[1]: 
queue http://localhost:8084: Connection to peer 127.0.0.1:8084 claimed 
request [Req4: POST http://localhost:8084/?command=allow]
Jan 15 16:50:50 vm-weakforced dovecot: auth: Debug: http-client[1]: conn 
127.0.0.1:8084 [2]: Claimed request [Req4: POST 
http://localhost:8084/?command=allow]
Jan 15 16:50:50 vm-weakforced dovecot: auth: Debug: http-client[1]: 
request [Req4: POST http://localhost:8084/?command=allow]: Sent header
Jan 15 16:50:50 vm-weakforced dovecot: auth: Debug: http-client[1]: 
request [Req4: POST http://localhost:8084/?command=allow]: Send more 
(sent 95, buffered=303)
Jan 15 16:50:50 vm-weakforced dovecot: auth: Debug: http-client[1]: 
request [Req4: POST http://localhost:8084/?command=allow]: Finished 
sending payload
Jan 15 16:50:50 vm-weakforced dovecot: auth: Debug: http-client[1]: peer 
127.0.0.1:8084: No more requests to service for this peer (1 connections 
exist, 0 pending)
Jan 15 16:50:50 vm-weakforced dovecot: auth: Debug: http-client[1]: conn 
127.0.0.1:8084 [2]: Got 401 response for request [Req4: POST 
http://localhost:8084/?command=allow] (took 4 ms + 3 ms in queue)
Jan 15 16:50:50 vm-weakforced dovecot: auth: Error: policy(usuario): 
Policy server HTTP error: 401 Unauthorized
Jan 15 16:50:50 vm-weakforced dovecot: auth: Debug: http-client[1]: conn 
127.0.0.1:8084 [2]: Response payload stream destroyed (0 ms after 
initial response)
Jan 15 16:50:50 vm-weakforced dovecot: auth: Debug: http-client[1]: 
request [Req4: POST http://localhost:8084/?command=allow]: Finished
Jan 15 16:50:50 vm-weakforced dovecot: auth: Debug: http-client[1]: 
queue http://localhost:8084: Dropping request [Req4: POST 
http://localhost:8084/?command=allow]
Jan 15 16:50:50 vm-weakforced dovecot: auth: Debug: http-client[1]: 
request [Req4: POST http://localhost:8084/?command=allow]: Free 
(requests left=1)
Jan 15 16:50:50 vm-weakforced dovecot: auth: Debug: http-client[1]: peer 
127.0.0.1:8084: No requests to service for this peer (1 connections 
exist, 0 pending)
Jan 15 16:50:50 vm-weakforced dovecot: auth: Debug: http-client[1]: conn 
127.0.0.1:8084 [2]: No more requests queued; going idle (timeout = 10000 
msecs)
...

Any idea?

Thank you so much
Regards,



More information about the dovecot mailing list