I'm setting up an email server using postfix+dovecot+mysql in ubuntu 20.04
I am stuck trying to authenticate users. It doesn't receive the domain information in the %d config variable (https://doc.dovecot.org/configuration_manual/config_file/config_variables/)
This is my /etc/dovecot/dovecot-sql.conf.ext file:
driver = mysql
connect = host=127.0.0.1 dbname=mail user=mail password=**********
default_pass_scheme = SHA512-CRYPT
user_query = select '/home/' home, 5000 id, 5000 from virtual_users u join virtual_domains d on u.domain_id=d.id WHERE u.email='%n' and d.name='%d'
password_query = select u.email as user, d.name as domain, password from virtual_users u join virtual_domains d on u.domain_id=d.id WHERE u.email='%n' and d.name='%d'
iterate_query = select u.email as user, d.name as domain, password from virtual_users u join virtual_domains d on u.domain_id=d.id
This is what I see in the logs:
Sep 05 15:00:20 master: Info: Dovecot v2.3.7.2 (3c910f64b) starting up for pop3, imap, lmtp, imap, lmtp, pop3 (core dumps disabled)
Sep 05 15:01:07 auth: Debug: Loading modules from directory: /usr/lib/dovecot/modules/auth
Sep 05 15:01:07 auth: Debug: Module loaded: /usr/lib/dovecot/modules/auth/lib20_auth_var_expand_crypt.so
Sep 05 15:01:07 auth: Debug: Module loaded: /usr/lib/dovecot/modules/auth/libdriver_mysql.so
Sep 05 15:01:07 auth: Debug: Read auth token secret from /var/run/dovecot/auth-token-secret.dat
Sep 05 15:01:07 auth: Debug: auth client connected (pid=0)
Sep 05 15:01:07 auth: Debug: client in: AUTH 3 PLAIN service=smtp nologin lip=10.0.0.4 rip=209.85.218.43 secured resp=<hidden>
Sep 05 15:01:07 auth: Debug: sql(yvan,209.***.***.***): Performing passdb lookup
Sep 05 15:01:07 auth-worker(7518): Debug: Loading modules from directory: /usr/lib/dovecot/modules/auth
Sep 05 15:01:07 auth-worker(7518): Debug: Module loaded: /usr/lib/dovecot/modules/auth/lib20_auth_var_expand_crypt.so
Sep 05 15:01:07 auth-worker(7518): Debug: Module loaded: /usr/lib/dovecot/modules/auth/libdriver_mysql.so
Sep 05 15:01:07 auth-worker(7518): Debug: conn unix:auth-worker (pid=7516,uid=115): Server accepted connection (fd=14)
Sep 05 15:01:07 auth-worker(7518): Debug: conn unix:auth-worker (pid=7516,uid=115): Sending version handshake
Sep 05 15:01:07 auth-worker(7518): Debug: conn unix:auth-worker (pid=7516,uid=115): auth-worker<1>: Handling PASSV request
Sep 05 15:01:07 auth-worker(7518): Debug: sql(yvan,209.***.***.***): Performing passdb lookup
Sep 05 15:01:07 auth-worker(7518): Debug: sql(yvan,209.***.***.***): query: select u.email as user, d.name as domain, password from virtual_users u join virtual_domains d on u.domain_id=d.id WHERE u.email='yvan' and d.name=''
Sep 05 15:01:07 auth-worker(7518): Info: sql(yvan,209.***.***.***): unknown user
Sep 05 15:01:07 auth: Debug: sql(yvan,209.***.***.***): Finished passdb lookup
Sep 05 15:01:07 auth: Debug: auth(yvan,209.***.***.***): Auth request finished
Sep 05 15:01:07 auth-worker(7518): Debug: sql(yvan,209.***.***.***): Finished passdb lookup
Sep 05 15:01:07 auth-worker(7518): Debug: conn unix:auth-worker (pid=7516,uid=115): auth-worker<1>: Finished
Sep 05 15:01:09 auth: Debug: client passdb out: FAIL 3 user=yvan [email protected]
Sep 05 15:02:07 auth-worker(7518): Debug: conn unix:auth-worker (pid=7516,uid=115): Disconnected: Connection closed (fd=-1)
Sep 05 15:02:59 auth: Debug: auth client connected (pid=7535)
Sep 05 15:02:59 pop3-login: Debug: SSL: where=0x10, ret=1: before SSL initialization
Sep 05 15:02:59 pop3-login: Debug: SSL: where=0x2001, ret=1: before SSL initialization
Sep 05 15:02:59 pop3-login: Debug: SSL: where=0x2002, ret=-1: before SSL initialization
Sep 05 15:02:59 pop3-login: Debug: SSL: where=0x2001, ret=1: before SSL initialization
Sep 05 15:02:59 pop3-login: Debug: SSL: where=0x2001, ret=1: SSLv3/TLS read client hello
Sep 05 15:02:59 pop3-login: Debug: SSL: where=0x2001, ret=1: SSLv3/TLS write server hello
Sep 05 15:02:59 pop3-login: Debug: SSL: where=0x2001, ret=1: SSLv3/TLS write certificate
Sep 05 15:02:59 pop3-login: Debug: SSL: where=0x2001, ret=1: SSLv3/TLS write key exchange
Sep 05 15:02:59 pop3-login: Debug: SSL: where=0x2001, ret=1: SSLv3/TLS write server done
Sep 05 15:02:59 pop3-login: Debug: SSL: where=0x2002, ret=-1: SSLv3/TLS write server done
Sep 05 15:02:59 pop3-login: Debug: SSL: where=0x2002, ret=-1: SSLv3/TLS write server done
Sep 05 15:02:59 pop3-login: Debug: SSL: where=0x2002, ret=-1: SSLv3/TLS write server done
Sep 05 15:02:59 pop3-login: Debug: SSL: where=0x2002, ret=-1: SSLv3/TLS write server done
Sep 05 15:02:59 pop3-login: Debug: SSL: where=0x2001, ret=1: SSLv3/TLS write server done
Sep 05 15:02:59 pop3-login: Debug: SSL: where=0x2001, ret=1: SSLv3/TLS read client key exchange
Sep 05 15:02:59 pop3-login: Debug: SSL: where=0x2001, ret=1: SSLv3/TLS read change cipher spec
Sep 05 15:02:59 pop3-login: Debug: SSL: where=0x2001, ret=1: SSLv3/TLS read finished
Sep 05 15:02:59 pop3-login: Debug: SSL: where=0x2001, ret=1: SSLv3/TLS write session ticket
Sep 05 15:02:59 pop3-login: Debug: SSL: where=0x2001, ret=1: SSLv3/TLS write change cipher spec
Sep 05 15:02:59 pop3-login: Debug: SSL: where=0x2001, ret=1: SSLv3/TLS write finished
Sep 05 15:02:59 pop3-login: Debug: SSL: where=0x20, ret=1: SSL negotiation finished successfully
Sep 05 15:02:59 pop3-login: Debug: SSL: where=0x2002, ret=1: SSL negotiation finished successfully
Sep 05 15:02:59 auth: Debug: client in: AUTH 1 PLAIN service=pop3 secured=tls session=IHYO1EDLFNpPmIbe lip=10.0.0.4 rip=79.***.***.*** lport=995 rport=55828 local_name=mail.test-domain.com ssl_cipher=ECDHE-RSA-AES256-GCM-SHA384 ssl_cipher_bits=256 ssl_pfs=KxECDHE ssl_protocol=TLSv1.2 resp=<hidden>
Sep 05 15:02:59 auth: Debug: sql(yvan,79.***.***.***,<IHYO1EDLFNpPmIbe>): Performing passdb lookup
Sep 05 15:02:59 auth-worker(7536): Debug: Loading modules from directory: /usr/lib/dovecot/modules/auth
Sep 05 15:02:59 auth-worker(7536): Debug: Module loaded: /usr/lib/dovecot/modules/auth/lib20_auth_var_expand_crypt.so
Sep 05 15:02:59 auth-worker(7536): Debug: Module loaded: /usr/lib/dovecot/modules/auth/libdriver_mysql.so
Sep 05 15:02:59 auth-worker(7536): Debug: conn unix:auth-worker (pid=7516,uid=115): Server accepted connection (fd=14)
Sep 05 15:02:59 auth-worker(7536): Debug: conn unix:auth-worker (pid=7516,uid=115): Sending version handshake
Sep 05 15:02:59 auth-worker(7536): Debug: conn unix:auth-worker (pid=7516,uid=115): auth-worker<1>: Handling PASSV request
Sep 05 15:02:59 auth-worker(7536): Debug: sql(yvan,79.***.***.***,<IHYO1EDLFNpPmIbe>): Performing passdb lookup
Sep 05 15:02:59 auth-worker(7536): Debug: sql(yvan,79.***.***.***,<IHYO1EDLFNpPmIbe>): query: select u.email as user, d.name as domain, password from virtual_users u join virtual_domains d on u.domain_id=d.id WHERE u.email='yvan' and d.name=''
Sep 05 15:02:59 auth-worker(7536): Info: sql(yvan,79.***.***.***,<IHYO1EDLFNpPmIbe>): unknown user
Sep 05 15:02:59 auth: Debug: sql(yvan,79.***.***.***,<IHYO1EDLFNpPmIbe>): Finished passdb lookup
Sep 05 15:02:59 auth: Debug: auth(yvan,79.***.***.***,<IHYO1EDLFNpPmIbe>): Auth request finished
Sep 05 15:02:59 auth-worker(7536): Debug: sql(yvan,79.***.***.***,<IHYO1EDLFNpPmIbe>): Finished passdb lookup
Sep 05 15:02:59 auth-worker(7536): Debug: conn unix:auth-worker (pid=7516,uid=115): auth-worker<1>: Finished
Sep 05 15:03:01 auth: Debug: client passdb out: FAIL 1 user=yvan [email protected]
Sep 05 15:03:01 pop3-login: Debug: Ignoring unknown passdb extra field: original_user
Sep 05 15:03:01 pop3-login: Debug: SSL error: Connection closed
Sep 05 15:03:01 pop3-login: Info: Disconnected (auth failed, 1 attempts in 2 secs): user=<yvan>, method=PLAIN, rip=79.***.***.***, lip=10.0.0.4, TLS: Connection closed, session=<IHYO1EDLFNpPmIbe>
Sep 05 15:03:01 pop3-login: Debug: SSL alert: close notify
Am I missing something in another configuration file? What am I doing wrong?
