I have shifted from a system-based email system to virtual for a website I manage. The MTA is exim4, and user data are in a MySQL database.
It will receive email, but with one exception the userdb is empty and emails go out with no username in the email address. Sample error message from exim:
2024-08-05 05:21:43 1sawid-00065N-0R Error while reading message with no usable sender address (R=1sawiX-00065C-1a): at least one malformed recipient address: @scasl.ca - no local part
Here is the output of doveconf -n:
# 2.3.19.1 (9b53102964): /etc/dovecot/dovecot.conf # Pigeonhole version 0.5.19 (4eae2f79) # OS: Linux 6.1.0-20-rt-686-pae i686 Debian 12.6 ext4 # Hostname: football.scasl.ca auth_debug = yes auth_default_realm = scasl.ca auth_mechanisms = plain login auth_username_format = %Ln auth_verbose = yes base_dir = /var/run/dovecot/ hostname = scasl.ca login_trusted_networks = 209.121.143.10/32 mail_debug = yes mail_gid = vmail mail_home = /var/vmail/%n mail_location = maildir:/var/vmail/%n/Maildir:INBOX=/var/vmail/%n/Maildir/INBOX mail_privileged_group = vmail mail_uid = vmail namespace inbox { inbox = yes location = mailbox Drafts { auto = subscribe special_use = \Drafts } mailbox Junk { special_use = \Junk } mailbox Sent { special_use = \Sent } mailbox "Sent Messages" { special_use = \Sent } mailbox Trash { special_use = \Trash } prefix = separator = / } passdb { args = /etc/dovecot/dovecot-sql.conf.ext driver = sql } passdb { args = /etc/dovecot/dovecot-sql.conf.ext driver = sql } postmaster_address = postmaster@scasl.ca protocols = " imap" service auth { unix_listener auth-client { mode = 0666 } unix_listener auth-userdb { mode = 0666 } } service imap-login { service_count = 1 } service stats { unix_listener stats-reader { group = vmail mode = 0666 } unix_listener stats-writer { group = vmail mode = 0666 } } ssl_cert =
There are two userdb entries, since one of the users is a system user. It is also the only one that appears in userdb.
The relevant commands from dovecot-sql.conf.ext are here:
password_query = SELECT email_username AS username, domain, email_password AS password FROM league WHERE email_username = '%n' user_query = SELECT CONCAT('/var/vmail/',email_username) AS home, 5000 AS uid, 5000 AS gid FROM league WHERE email_username = '%n' AND domain = '%d' iterate_query = SELECT email_username AS username, domain FROM league
The vmail uid:gid is 5000:5000
As a side issue, it cannot open (/proc/self/io) - I'm not sure whether that means anything.
Here is debugging output:
2024-08-05T06:33:18.777211-07:00 football dovecot: auth-worker(24847): Debug: Loading modules from directory: /usr/lib/dovecot/modules/auth 2024-08-05T06:33:18.777456-07:00 football dovecot: auth-worker(24847): Debug: Module loaded: /usr/lib/dovecot/modules/auth/lib20_auth_var_expand_crypt.so 2024-08-05T06:33:18.782112-07:00 football dovecot: auth-worker(24847): Debug: Module loaded: /usr/lib/dovecot/modules/auth/libdriver_mysql.so 2024-08-05T06:33:18.782392-07:00 football dovecot: auth-worker(24847): Debug: sqlpool(mysql): Creating new connection 2024-08-05T06:33:18.784671-07:00 football dovecot: auth-worker(24847): Debug: mysql(localhost): Connecting 2024-08-05T06:33:18.785532-07:00 football dovecot: auth-worker(24847): Debug: conn unix:auth-worker (pid=24845,uid=121): Server accepted connection (fd=14) 2024-08-05T06:33:18.785703-07:00 football dovecot: auth-worker(24847): Debug: conn unix:auth-worker (pid=24845,uid=121): Sending version handshake 2024-08-05T06:33:18.785850-07:00 football dovecot: auth-worker(24847): Debug: conn unix:auth-worker (pid=24845,uid=121): auth-worker<1>: Handling PASSV request 2024-08-05T06:33:18.785986-07:00 football dovecot: auth-worker(24847): Debug: conn unix:auth-worker (pid=24845,uid=121): auth-worker<1>: sql(scasl,209.121.143.14,<Z41TuO8eENjReY8O>): Performing passdb lookup 2024-08-05T06:33:18.786124-07:00 football dovecot: auth-worker(24847): Debug: conn unix:auth-worker (pid=24845,uid=121): auth-worker<1>: sql(scasl,209.121.143.14,<Z41TuO8eENjReY8O>): query: SELECT email_username AS username, domain, emai l_password AS password FROM league WHERE email_username = 'scasl' 2024-08-05T06:33:18.786347-07:00 football dovecot: auth-worker(24847): Debug: mysql(localhost): Finished query 'SELECT email_username AS username, domain, email_password AS password FROM league WHERE email_username = 'scasl'' in 0 msecs 2024-08-05T06:33:18.786524-07:00 football dovecot: auth-worker(24847): Debug: conn unix:auth-worker (pid=24845,uid=121): auth-worker<1>: sql(scasl,209.121.143.14,<Z41TuO8eENjReY8O>): username changed scasl -> scasl@scasl.ca 2024-08-05T06:33:18.786672-07:00 football dovecot: auth-worker(24847): Debug: conn unix:auth-worker (pid=24845,uid=121): auth-worker<1>: sql(scasl@scasl.ca,209.121.143.14,<Z41TuO8eENjReY8O>): Finished passdb lookup 2024-08-05T06:33:18.786791-07:00 football dovecot: auth-worker(24847): Debug: conn unix:auth-worker (pid=24845,uid=121): auth-worker<1>: Finished 2024-08-05T06:33:18.786940-07:00 football dovecot: auth: Debug: sql(scasl,209.121.143.14,<Z41TuO8eENjReY8O>): username changed scasl -> scasl@scasl.ca 2024-08-05T06:33:18.787098-07:00 football dovecot: auth: Debug: sql(scasl@scasl.ca,209.121.143.14,<Z41TuO8eENjReY8O>): Finished passdb lookup 2024-08-05T06:33:18.787239-07:00 football dovecot: auth: Debug: auth(scasl@scasl.ca,209.121.143.14,<Z41TuO8eENjReY8O>): Auth request finished 2024-08-05T06:33:18.787379-07:00 football dovecot: auth: Debug: client passdb out: OK#0111#011user=scasl@scasl.ca#011#011original_user=scasl 2024-08-05T06:33:18.794297-07:00 football dovecot: auth: Debug: master in: REQUEST#011600309761#01124843#0111#0115343bacecb1c0282e3e40282e4ebd64d#011session_pid=24849#011request_auth_token 2024-08-05T06:33:18.794568-07:00 football dovecot: auth: Debug: sql(scasl@scasl.ca,209.121.143.14,<Z41TuO8eENjReY8O>): Performing userdb lookup 2024-08-05T06:33:18.794712-07:00 football dovecot: auth-worker(24847): Debug: conn unix:auth-worker (pid=24845,uid=121): auth-worker<2>: Handling USER request 2024-08-05T06:33:18.794859-07:00 football dovecot: auth-worker(24847): Debug: conn unix:auth-worker (pid=24845,uid=121): auth-worker<2>: sql(scasl@scasl.ca,209.121.143.14,<Z41TuO8eENjReY8O>): Performing userdb lookup 2024-08-05T06:33:18.795004-07:00 football dovecot: auth-worker(24847): Debug: conn unix:auth-worker (pid=24845,uid=121): auth-worker<2>: sql(scasl@scasl.ca,209.121.143.14,<Z41TuO8eENjReY8O>): SELECT CONCAT('/var/vmail/',email_username) A S home, 5000 AS uid, 5000 AS gid FROM league WHERE email_username = 'scasl' AND domain = 'scasl.ca' 2024-08-05T06:33:18.795222-07:00 football dovecot: auth-worker(24847): Debug: mysql(localhost): Finished query 'SELECT CONCAT('/var/vmail/',email_username) AS home, 5000 AS uid, 5000 AS gid FROM league WHERE email_username = 'scasl' AND domain = 'scasl.ca'' in 0 msecs 2024-08-05T06:33:18.795387-07:00 football dovecot: auth-worker(24847): Debug: conn unix:auth-worker (pid=24845,uid=121): auth-worker<2>: sql(scasl@scasl.ca,209.121.143.14,<Z41TuO8eENjReY8O>): Finished userdb lookup 2024-08-05T06:33:18.795526-07:00 football dovecot: auth-worker(24847): Debug: conn unix:auth-worker (pid=24845,uid=121): auth-worker<2>: Finished 2024-08-05T06:33:18.795660-07:00 football dovecot: auth: Debug: sql(scasl@scasl.ca,209.121.143.14,<Z41TuO8eENjReY8O>): Finished userdb lookup 2024-08-05T06:33:18.795899-07:00 football dovecot: auth: Debug: master userdb out: USER#011600309761#011scasl@scasl.ca#011home=/var/vmail/scasl#011uid=5000#011gid=5000#011auth_mech=PLAIN#011auth_token=e9d7425913886e014c83af029551e70f8db2 98f9#011auth_user=scasl 2024-08-05T06:33:18.796199-07:00 football dovecot: imap-login: Login: user=scasl@scasl.ca, method=PLAIN, rip=209.121.143.14, lip=209.121.143.10, mpid=24849, TLS, session=<Z41TuO8eENjReY8O> 2024-08-05T06:33:18.797562-07:00 football dovecot: imap(scasl@scasl.ca)<24849><Z41TuO8eENjReY8O>: Debug: Effective uid=5000, gid=5000, home=/var/vmail/scasl 2024-08-05T06:33:18.797718-07:00 football dovecot: imap(scasl@scasl.ca)<24849><Z41TuO8eENjReY8O>: Debug: open(/proc/self/io) failed: Permission denied 2024-08-05T06:33:18.798021-07:00 football dovecot: imap(scasl@scasl.ca)<24849><Z41TuO8eENjReY8O>: Debug: Namespace inbox: type=private, prefix=, sep=/, inbox=yes, hidden=no, list=yes, subscriptions=yes location=maildir:/var/vmail/scasl/M aildir:INBOX=/var/vmail/scasl/Maildir/INBOX 2024-08-05T06:33:18.798286-07:00 football dovecot: imap(scasl@scasl.ca)<24849><Z41TuO8eENjReY8O>: Debug: maildir++: root=/var/vmail/scasl/Maildir, index=, indexpvt=, control=, inbox=/var/vmail/scasl/Maildir/INBOX, alt= 2024-08-05T06:33:18.799780-07:00 football dovecot: imap(scasl@scasl.ca)<24849><Z41TuO8eENjReY8O>: Debug: Mailbox INBOX: Mailbox opened 2024-08-05T06:34:18.830024-07:00 football dovecot: auth-worker(24847): Debug: conn unix:auth-worker (pid=24845,uid=121): Disconnected: Connection closed (fd=-1) 2024-08-05T06:34:18.882117-07:00 football dovecot: auth-worker(24847): Debug: mysql(localhost): Connection finished (queries=2, slow queries=0) 2024-08-05T06:34:19.349925-07:00 football dovecot: auth: Debug: mysql(localhost): Connection finished (queries=0, slow queries=0)
Sorry this is so long.
What am I doing wrong here?
Thank you in advance
Cam
On 05/08/2024 16:02, Cam Ellison via dovecot wrote:
I have shifted from a system-based email system to virtual for a website I manage. The MTA is exim4, and user data are in a MySQL database.
It will receive email, but with one exception the userdb is empty and emails go out with no username in the email address. Sample error message from exim:
2024-08-05 05:21:43 1sawid-00065N-0R Error while reading message with no usable sender address (R=1sawiX-00065C-1a): at least one malformed recipient address: @scasl.ca - no local part
Hi Cam
if your issue is about sending emails and you are using dovecot only as an imap server and using exim to send emails, what is the relation between your problem and the dovecot configuration? I didn't see one, but maybe I'm misunderstanding something about the problem you are seeing.
John
On 2024-08-08 10:25, John Fawcett via dovecot wrote:
On 05/08/2024 16:02, Cam Ellison via dovecot wrote:
I have shifted from a system-based email system to virtual for a website I manage. The MTA is exim4, and user data are in a MySQL database.
It will receive email, but with one exception the userdb is empty and emails go out with no username in the email address. Sample error message from exim:
2024-08-05 05:21:43 1sawid-00065N-0R Error while reading message with no usable sender address (R=1sawiX-00065C-1a): at least one malformed recipient address: @scasl.ca - no local part
Hi Cam
if your issue is about sending emails and you are using dovecot only as an imap server and using exim to send emails, what is the relation between your problem and the dovecot configuration? I didn't see one, but maybe I'm misunderstanding something about the problem you are seeing.
It turns out that the problem was in exim4.conf, particularly since shifting to virtual users raised the issue of tainted email addresses. It was not clear to me for a while (2 or 3 days) where the problem lay, since the userdb was empty. And I can get confused...
Thank you for responding.
The original email can safely be ignored.
Cheers
Cam
participants (2)
-
Cam Ellison
-
John Fawcett