Hello,
i use a proxy only configuration with version 2.2.22 (Ubuntu 16.04) and have
now transferred it to version 2.3.10. This works as before.
But as soon as i use "auth_cache_verify_password_with_worker = yes", it does
not work anymore.
The first login still works, but from the second one, where the answer comes
from the cache, there is an error. The login is still accepted but dovecot
searches the mailbox locally.
The configuration for cache and proxy (from dovecot -n):
auth_cache_verify_password_with_worker = yes
auth_cache_negative_ttl = 0
auth_cache_size = 64 M
passdb {
args = /etc/dovecot/dovecot-sql.conf.ext
driver = sql
}
The sql from /etc/dovecot/dovecot-sql.conf.ext:
password_query = SELECT pwdCrypt AS password, \
NULL AS nopassword, \
'MyMasterUser' AS master, \
'MyMasterPass' AS pass, \
ipv4address AS host, \
'%u' AS destuser, \
'Y' AS proxy \
FROM mailbox \
WHERE user = '%u' AND activeFlg = '1' LIMIT 1
The logfile extracts with "auth_cache_verify_password_with_worker = yes":
- First Login from mail.log (work's)
Apr 2 12:27:11 mf-19 dovecot: auth: Debug: client in:
AUTH#0111#011PLAIN#011service=imap#011secured=tls#011session=6fZiPkyiWHJSZMhl#011lip=178.254.4.122#011rip=93.200.174.28#011lport=143#011rport=29272#011local_name=mf-19.1blu.de#011ssl_cipher=TLS_AES_128_GCM_SHA256#011ssl_cipher_bits=128#011ssl_pfs=KxANY#011ssl_protocol=TLSv1.3
Apr 2 12:27:11 mf-19 dovecot: auth: Debug: client passdb out: CONT#0111
Apr 2 12:27:11 mf-19 dovecot: auth: Debug: client in: CONT
Apr 2 12:27:11 mf-19 dovecot: auth: Debug:
sql(testuser,93.200.174.28,<6fZiPkyiWHJSZMhl>): Performing passdb lookup
Apr 2 12:27:11 mf-19 dovecot: auth: Debug:
sql(testuser,93.200.174.28,<6fZiPkyiWHJSZMhl>): cache miss
Apr 2 12:27:11 mf-19 dovecot: auth-worker(18978): Debug: Loading modules from
directory: /usr/lib/dovecot/modules/auth
Apr 2 12:27:11 mf-19 dovecot: auth-worker(18978): Debug: Module loaded:
/usr/lib/dovecot/modules/auth/lib20_auth_var_expand_crypt.so
Apr 2 12:27:11 mf-19 dovecot: auth-worker(18978): Debug: Module loaded:
/usr/lib/dovecot/modules/auth/libdriver_mysql.so
Apr 2 12:27:11 mf-19 dovecot: auth-worker(18978): Debug: conn unix:auth-worker
(pid=18976,uid=109): Server accepted connection (fd=16)
Apr 2 12:27:11 mf-19 dovecot: auth-worker(18978): Debug: conn unix:auth-worker
(pid=18976,uid=109): Sending version handshake
Apr 2 12:27:11 mf-19 dovecot: auth-worker(18978): Debug: conn unix:auth-worker
(pid=18976,uid=109): auth-worker<1>: Handling PASSV request
Apr 2 12:27:11 mf-19 dovecot: auth-worker(18978): Debug:
sql(testuser,93.200.174.28,<6fZiPkyiWHJSZMhl>): Performing passdb lookup
Apr 2 12:27:11 mf-19 dovecot: auth-worker(18978): Debug:
sql(testuser,93.200.174.28,<6fZiPkyiWHJSZMhl>): query: SELECT pwdCrypt AS
password, NULL AS nopassword, 'MyMasterUser' AS master, 'MyMasterPass' AS pass,
ipv4address AS host, 'testuser' AS destuser, 'Y' AS proxy FROMmailbox WHERE
user = 'testuser' AND activeFlg = '1' LIMIT 1
Apr 2 12:27:11 mf-19 dovecot: auth-worker(18978): Debug:
sql(testuser,93.200.174.28,<6fZiPkyiWHJSZMhl>): Finished passdb lookup
Apr 2 12:27:11 mf-19 dovecot: auth-worker(18978): Debug: conn unix:auth-worker
(pid=18976,uid=109): auth-worker<1>: Finished
Apr 2 12:27:11 mf-19 dovecot: auth: Debug:
sql(testuser,93.200.174.28,<6fZiPkyiWHJSZMhl>): Finished passdb lookup
Apr 2 12:27:11 mf-19 dovecot: auth: Debug:
auth(testuser,93.200.174.28,<6fZiPkyiWHJSZMhl>): Auth request finished
Apr 2 12:27:11 mf-19 dovecot: auth: Debug: client passdb out:
OK#0111#011user=testuser#011master=MyMasterUser#011pass=#011host=10.1.2.3#011destuser=testuser#011proxy
Apr 2 12:27:11 mf-19 dovecot: imap-login: proxy(testuser): started proxying to
10.1.2.3:143 (master MyMasterUser): user=, method=PLAIN,
rip=93.200.174.28, lip=178.254.4.122, TLS, session=<6fZiPkyiWHJSZMhl>
- Further logins from mail.log (searches locally):
Apr 2 12:27:18 mf-19 dovecot: auth: Debug: client in:
AUTH#0111#011PLAIN#011service=imap#011secured=tls#011session=L4PQPkyi7plSZMhl#011lip=178.254.4.122#011rip=93.200.174.28#011lport=143#011rport=39406#011local_name=mf-19.1blu.de#011ssl_cipher=TLS_AES_128_GCM_SHA256#011ssl_cipher_bits=128#011ssl_pfs=KxANY#011ssl_protocol=TLSv1.3
Apr 2 12:27:18 mf-19 dovecot: auth: Debug: client passdb out: CONT#0111
Apr 2 12:27:18 mf-19 dovecot: auth: Debug: client in: CONT
Apr 2 12:27:18 mf-19 dovecot: auth: Debug:
sql(testuser,93.200.174.28,): Performing passdb lookup
Apr 2 12:27:18 mf-19 dovecot: auth: Debug:
sql(testuser,93.200.174.28,): cache hit:
#011master=MyMasterUser#011pass=MyMasterPass#011host=10.1.2.3#011destuser=testuser#011proxy=Y
Apr 2 12:27:18 mf-19 dovecot: auth: Debug:
sql(testuser,93.200.174.28,): cache: validating password on
worker
Apr 2 12:27:18 mf-19 dovecot:
