dovecot lmtp delivery fails with compression enabled and mailbox stored under different os users
# dovecot --version 2.3.21.1 (d492236fa0)
Error itself(I've replaced some data like original domains/and usernames):
Sep 20 14:24:08 lmtp(lxc@forwardusr.org)<486449><+IvZKVhb7WYxbAcAZOUKzw>: Debug: auth-master: userdb lookup(lxc@forwardusr.org): Started userdb lookup
Sep 20 14:24:08 lmtp(lxc@forwardusr.org)<486449><+IvZKVhb7WYxbAcAZOUKzw>: Debug: auth-master: userdb lookup(lxc@forwardusr.org): auth USER input: lxc@forwardusr.org uid=1006 gid=12 home=/home/forwardusr/imap/forwardusr.org/lxc quota_rule=*:bytes=50M
Sep 20 14:24:08 lmtp(lxc@forwardusr.org)<486449><+IvZKVhb7WYxbAcAZOUKzw>: Debug: auth-master: userdb lookup(lxc@forwardusr.org): Finished userdb lookup (username=lxc@forwardusr.org uid=1006 gid=12 home=/home/forwardusr/imap/forwardusr.org/lxc quota_rule=*:bytes=50M)
Sep 20 14:24:08 lmtp(lxc@forwardusr.org)<486449><+IvZKVhb7WYxbAcAZOUKzw>: Debug: lmtp-server: conn unix:pid=492384,uid=8 [4]: rcpt lxc@forwardusr.org: Added userdb setting: plugin/quota_rule=*:bytes=50M
Sep 20 14:24:08 lmtp(lxc@forwardusr.org)<486449><+IvZKVhb7WYxbAcAZOUKzw>: Debug: Effective uid=1006, gid=12, home=/home/forwardusr/imap/forwardusr.org/lxc
Sep 20 14:24:08 lmtp(lxc@forwardusr.org)<486449><+IvZKVhb7WYxbAcAZOUKzw>: Debug: Quota root: name= backend=maildir args=
Sep 20 14:24:08 lmtp(lxc@forwardusr.org)<486449><+IvZKVhb7WYxbAcAZOUKzw>: Debug: Quota rule: root= mailbox=* bytes=52428800 messages=0
Sep 20 14:24:08 lmtp(lxc@forwardusr.org)<486449><+IvZKVhb7WYxbAcAZOUKzw>: Debug: Quota grace: root= bytes=5242880 (10%)
Sep 20 14:24:08 lmtp(lxc@forwardusr.org)<486449><+IvZKVhb7WYxbAcAZOUKzw>: Debug: Namespace inbox: type=private, prefix=, sep=., inbox=yes, hidden=no, list=yes, subscriptions=yes location=maildir:~/Maildir
Sep 20 14:24:08 lmtp(lxc@forwardusr.org)<486449><+IvZKVhb7WYxbAcAZOUKzw>: Debug: maildir++: root=/home/forwardusr/imap/forwardusr.org/lxc/Maildir, index=, indexpvt=, control=, inbox=/home/forwardusr/imap/forwardusr.org/lxc/Maildir, alt=
Sep 20 14:24:08 lmtp(lxc@forwardusr.org)<486449><+IvZKVhb7WYxbAcAZOUKzw>: Debug: quota: quota_over_flag check: quota_over_script unset - skipping
Sep 20 14:24:08 lmtp(lxc@forwardusr.org)<486449><+IvZKVhb7WYxbAcAZOUKzw>: Debug: User session is finished
Sep 20 14:24:08 lmtp(lxc@site.edu)<486449><+IvZKVhb7WYxbAcAZOUKzw:R2>: Debug: auth-master: userdb lookup(lxc@site.edu): Started userdb lookup
Sep 20 14:24:08 lmtp(lxc@site.edu)<486449><+IvZKVhb7WYxbAcAZOUKzw:R2>: Debug: auth-master: userdb lookup(lxc@site.edu): auth USER input: lxc@site.edu uid=1002 gid=12 home=/home/siteowner/imap/site.edu/lxc quota_rule=*:bytes=50M
Sep 20 14:24:08 lmtp(lxc@site.edu)<486449><+IvZKVhb7WYxbAcAZOUKzw:R2>: Debug: auth-master: userdb lookup(lxc@site.edu): Finished userdb lookup (username=lxc@site.edu uid=1002 gid=12 home=/home/siteowner/imap/site.edu/lxc quota_rule=*:bytes=50M)
Sep 20 14:24:08 lmtp(lxc@site.edu)<486449><+IvZKVhb7WYxbAcAZOUKzw:R2>: Debug: lmtp-server: conn unix:pid=492384,uid=8 [4]: rcpt lxc@site.edu: Added userdb setting: plugin/quota_rule=*:bytes=50M
Sep 20 14:24:08 lmtp(lxc@site.edu)<486449><+IvZKVhb7WYxbAcAZOUKzw:R2>: Debug: Effective uid=1002, gid=12, home=/home/siteowner/imap/site.edu/lxc
Sep 20 14:24:08 lmtp(lxc@site.edu)<486449><+IvZKVhb7WYxbAcAZOUKzw:R2>: Debug: Quota root: name= backend=maildir args=
Sep 20 14:24:08 lmtp(lxc@site.edu)<486449><+IvZKVhb7WYxbAcAZOUKzw:R2>: Debug: Quota rule: root= mailbox=* bytes=52428800 messages=0
Sep 20 14:24:08 lmtp(lxc@site.edu)<486449><+IvZKVhb7WYxbAcAZOUKzw:R2>: Debug: Quota grace: root= bytes=5242880 (10%)
Sep 20 14:24:08 lmtp(lxc@site.edu)<486449><+IvZKVhb7WYxbAcAZOUKzw:R2>: Debug: Namespace inbox: type=private, prefix=, sep=., inbox=yes, hidden=no, list=yes, subscriptions=yes location=maildir:~/Maildir
Sep 20 14:24:08 lmtp(lxc@site.edu)<486449><+IvZKVhb7WYxbAcAZOUKzw:R2>: Debug: maildir++: root=/home/siteowner/imap/site.edu/lxc/Maildir, index=, indexpvt=, control=, inbox=/home/siteowner/imap/site.edu/lxc/Maildir, alt=
Sep 20 14:24:08 lmtp(lxc@site.edu)<486449><+IvZKVhb7WYxbAcAZOUKzw:R2>: Debug: quota: quota_over_flag check: quota_over_script unset - skipping
Sep 20 14:24:08 lmtp(lxc@site.edu)<486449><+IvZKVhb7WYxbAcAZOUKzw:R2>: Debug: User session is finished
Sep 20 14:24:08 lmtp(lxc@forwardusr.org)<486449><+IvZKVhb7WYxbAcAZOUKzw>: Debug: Effective uid=1006, gid=12, home=/home/forwardusr/imap/forwardusr.org/lxc
Sep 20 14:24:08 lmtp(lxc@forwardusr.org)<486449><+IvZKVhb7WYxbAcAZOUKzw>: Debug: Quota root: name= backend=maildir args=
Sep 20 14:24:08 lmtp(lxc@forwardusr.org)<486449><+IvZKVhb7WYxbAcAZOUKzw>: Debug: Quota rule: root= mailbox=* bytes=52428800 messages=0
Sep 20 14:24:08 lmtp(lxc@forwardusr.org)<486449><+IvZKVhb7WYxbAcAZOUKzw>: Debug: Quota grace: root= bytes=5242880 (10%)
Sep 20 14:24:08 lmtp(lxc@forwardusr.org)<486449><+IvZKVhb7WYxbAcAZOUKzw>: Debug: Namespace inbox: type=private, prefix=, sep=., inbox=yes, hidden=no, list=yes, subscriptions=yes location=maildir:~/Maildir
Sep 20 14:24:08 lmtp(lxc@forwardusr.org)<486449><+IvZKVhb7WYxbAcAZOUKzw>: Debug: maildir++: root=/home/forwardusr/imap/forwardusr.org/lxc/Maildir, index=, indexpvt=, control=, inbox=/home/forwardusr/imap/forwardusr.org/lxc/Maildir, alt=
Sep 20 14:24:08 lmtp(lxc@forwardusr.org)<486449><+IvZKVhb7WYxbAcAZOUKzw>: Debug: quota: quota_over_flag check: quota_over_script unset - skipping
Sep 20 14:24:08 lmtp(lxc@forwardusr.org)<486449><+IvZKVhb7WYxbAcAZOUKzw>: Debug: duplicate db: Initialize
Sep 20 14:24:08 lmtp(lxc@forwardusr.org)<486449><+IvZKVhb7WYxbAcAZOUKzw>: Debug: sieve: Pigeonhole version 0.5.21.1 (49005e73) initializing
Sep 20 14:24:08 lmtp(lxc@forwardusr.org)<486449><+IvZKVhb7WYxbAcAZOUKzw>: Debug: sieve: include: sieve_global is not set; it is currently not possible to include :global' scripts. Sep 20 14:24:08 lmtp(lxc@forwardusr.org)<486449><+IvZKVhb7WYxbAcAZOUKzw>: Debug: sieve: file storage: Storage path /home/forwardusr/imap/forwardusr.org/lxc/sieve' not found
Sep 20 14:24:08 lmtp(lxc@forwardusr.org)<486449><+IvZKVhb7WYxbAcAZOUKzw>: Debug: sieve: file storage: Storage path /home/forwardusr/imap/forwardusr.org/lxc/.dovecot.sieve' not found Sep 20 14:24:08 lmtp(lxc@forwardusr.org)<486449><+IvZKVhb7WYxbAcAZOUKzw>: Debug: sieve: storage: No default script location configured Sep 20 14:24:08 lmtp(lxc@forwardusr.org)<486449><+IvZKVhb7WYxbAcAZOUKzw>: Debug: sieve: User has no personal script Sep 20 14:24:08 lmtp(lxc@forwardusr.org)<486449><+IvZKVhb7WYxbAcAZOUKzw>: Debug: sieve: No scripts to execute: reverting to default delivery. Sep 20 14:24:08 lmtp(lxc@forwardusr.org)<486449><+IvZKVhb7WYxbAcAZOUKzw>: Debug: duplicate db: Cleanup Sep 20 14:24:08 lmtp(lxc@forwardusr.org)<486449><+IvZKVhb7WYxbAcAZOUKzw>: Debug: Mailbox INBOX: Mailbox opened Sep 20 14:24:08 lmtp(lxc@forwardusr.org)<486449><+IvZKVhb7WYxbAcAZOUKzw>: Debug: Mailbox INBOX: UID 10: Opened mail because: access Sep 20 14:24:08 lmtp(lxc@forwardusr.org)<486449><+IvZKVhb7WYxbAcAZOUKzw>: Info: msgid=<F386DD43-FE57-4CDE-A48B-3D0945ACC98C@sender.domain>: saved mail to INBOX Sep 20 14:24:08 lmtp(lxc@site.edu)<486449><+IvZKVhb7WYxbAcAZOUKzw:R2>: Debug: Effective uid=1002, gid=12, home=/home/siteowner/imap/site.edu/lxc Sep 20 14:24:08 lmtp(lxc@site.edu)<486449><+IvZKVhb7WYxbAcAZOUKzw:R2>: Debug: Quota root: name= backend=maildir args= Sep 20 14:24:08 lmtp(lxc@site.edu)<486449><+IvZKVhb7WYxbAcAZOUKzw:R2>: Debug: Quota rule: root= mailbox=* bytes=52428800 messages=0 Sep 20 14:24:08 lmtp(lxc@site.edu)<486449><+IvZKVhb7WYxbAcAZOUKzw:R2>: Debug: Quota grace: root= bytes=5242880 (10%) Sep 20 14:24:08 lmtp(lxc@site.edu)<486449><+IvZKVhb7WYxbAcAZOUKzw:R2>: Debug: Namespace inbox: type=private, prefix=, sep=., inbox=yes, hidden=no, list=yes, subscriptions=yes location=maildir:~/Maildir Sep 20 14:24:08 lmtp(lxc@site.edu)<486449><+IvZKVhb7WYxbAcAZOUKzw:R2>: Debug: maildir++: root=/home/siteowner/imap/site.edu/lxc/Maildir, index=, indexpvt=, control=, inbox=/home/siteowner/imap/site.edu/lxc/Maildir, alt= Sep 20 14:24:08 lmtp(lxc@site.edu)<486449><+IvZKVhb7WYxbAcAZOUKzw:R2>: Debug: quota: quota_over_flag check: quota_over_script unset - skipping Sep 20 14:24:08 lmtp(lxc@site.edu)<486449><+IvZKVhb7WYxbAcAZOUKzw:R2>: Debug: duplicate db: Initialize Sep 20 14:24:08 lmtp(lxc@site.edu)<486449><+IvZKVhb7WYxbAcAZOUKzw:R2>: Debug: sieve: Pigeonhole version 0.5.21.1 (49005e73) initializing Sep 20 14:24:08 lmtp(lxc@site.edu)<486449><+IvZKVhb7WYxbAcAZOUKzw:R2>: Debug: sieve: include: sieve_global is not set; it is currently not possible to include :global' scripts.
Sep 20 14:24:08 lmtp(lxc@site.edu)<486449><+IvZKVhb7WYxbAcAZOUKzw:R2>: Debug: sieve: file storage: Storage path /home/siteowner/imap/site.edu/lxc/sieve' not found Sep 20 14:24:08 lmtp(lxc@site.edu)<486449><+IvZKVhb7WYxbAcAZOUKzw:R2>: Debug: sieve: file storage: Storage path /home/siteowner/imap/site.edu/lxc/.dovecot.sieve' not found
Sep 20 14:24:08 lmtp(lxc@site.edu)<486449><+IvZKVhb7WYxbAcAZOUKzw:R2>: Debug: sieve: storage: No default script location configured
Sep 20 14:24:08 lmtp(lxc@site.edu)<486449><+IvZKVhb7WYxbAcAZOUKzw:R2>: Debug: sieve: User has no personal script
Sep 20 14:24:08 lmtp(lxc@site.edu)<486449><+IvZKVhb7WYxbAcAZOUKzw:R2>: Debug: sieve: No scripts to execute: reverting to default delivery.
Sep 20 14:24:08 lmtp(lxc@site.edu)<486449><+IvZKVhb7WYxbAcAZOUKzw:R2>: Debug: duplicate db: Cleanup
Sep 20 14:24:08 lmtp(lxc@site.edu)<486449><+IvZKVhb7WYxbAcAZOUKzw:R2>: Debug: Mailbox INBOX: Mailbox opened
Sep 20 14:24:08 lmtp(lxc@site.edu)<486449><+IvZKVhb7WYxbAcAZOUKzw:R2>: Info: msgid=<F386DD43-FE57-4CDE-A48B-3D0945ACC98C@sender.domain>: save failed to INBOX: Internal error occurred. Refer to server log for more information. [2024-09-20 14:24:08] (received-date)
Sep 20 14:24:08 lmtp(lxc@site.edu)<486449><+IvZKVhb7WYxbAcAZOUKzw:R2>: Debug: User session is finished
Sep 20 14:24:08 lmtp(lxc@forwardusr.org)<486449><+IvZKVhb7WYxbAcAZOUKzw>: Debug: User session is finished
With error itself. Sep 20 14:24:08 lmtp(lxc@forwardusr.org)<486449><+IvZKVhb7WYxbAcAZOUKzw>: Error: Mailbox INBOX: stat(/home/forwardusr/imap/forwardusr.org/lxc/Maildir/new/1726831448.M709209P486449.testhost.dev,S=2068,W=2116) failed: Permission denied (euid=1002(quakeowner) egid=12(mail) missing +x perm: /home/forwardusr, dir owned by 1006:1003 mode=0710)
Basically there's etc. domainA and domainB stored under different OS users. In case etc. there's alias from domainA to domainB which results in lmtp delivery with both recipients submitted in the same "lmtp session" as "batch", it seems that only one delivery happens, as by the time zlib plugin kicks in - effective user id for the process is already set to second delivery user which fails zlib(at least disabling that/removing it from mail plugins delivery/save is successful).
I know that it can mitigate by modifying (in this case exim's) conf and setting batch_max to 1, which results in single submit(single RCPT TO), though still curious if that's by design? What I guess is asynchronous compression ? Or that would be considered a bug?
Best Regards
participants (1)
-
jonas＠mc2.dev