[Dovecot] Problem with 1.2 and sieve: failed with unsuccessful implicit keep
Hi,
First, thanks for this awesome piece of software. I've just upgraded to latest dovecot, aka 1.2.
I've a problem. I've started using Sieve, and everything works fine, I already received a thousand of mails without any problem. However, there's one mail which is stuck in the postfix queue because of that:
Jul 8 18:47:51 prometheus dovecot: deliver(jd@danjou.info): mkdir_parents_chown(danjou.info/jd/) failed: Permission denied (euid=8(mail) egid=8(mail)) Jul 8 18:47:51 prometheus dovecot: deliver(jd@danjou.info): copy: i_stream_read() failed: No such file or directory Jul 8 18:47:51 prometheus dovecot: deliver(jd@danjou.info): sieve: msgid=? 1186f9b5-0529-4622-8f4a-58462f9a4bcb@svr-exchange.siege.ldlc.com: failed to store into mailbox 'INBOX': Internal error occurred. Refer to server log for more information. [2009-07-08 18:47:51] Jul 8 18:47:51 prometheus dovecot: deliver(jd@danjou.info): read(mail, uid=1) failed: Permission denied Jul 8 18:47:51 prometheus dovecot: deliver(jd@danjou.info): sieve: msgid=? 1186f9b5-0529-4622-8f4a-58462f9a4bcb@svr-exchange.siege.ldlc.com: failed to store into mailbox 'INBOX': BUG: Unknown internal error Jul 8 18:47:51 prometheus dovecot: deliver(jd@danjou.info): sieve: script /var/mail/sieve/jd@danjou.info.dovecot.sieve failed with unsuccessful implicit keep
IMHO, the bug is around the uid stuff. the read(mail, uid=1) seems very wrong. since this uid is not used at all in the configuration file.
I can provide more information if needed, just ask.
dovecot 1.2 Debian GNU/Linux 5.0 (lenny) CPU amd64 FS is ext3 # dovecot -n # 2007 pts/0 19:27:38 # 1.2.0: /etc/dovecot/dovecot.conf # OS: Linux 2.6.26-1-amd64 x86_64 Debian 5.0.2 ext3 log_timestamp: %Y-%m-%d %H:%M:%S protocols: imaps pop3s managesieve ssl_cert_file: /etc/ssl/private/ssl.naquadah.org.crt ssl_key_file: /etc/ssl/private/ssl.naquadah.org.key login_dir: /var/run/dovecot/login login_executable(default): /usr/lib/dovecot/imap-login login_executable(imap): /usr/lib/dovecot/imap-login login_executable(pop3): /usr/lib/dovecot/pop3-login login_executable(managesieve): /usr/lib/dovecot/managesieve-login first_valid_uid: 8 last_valid_uid: 8 mail_privileged_group: mail mail_location: maildir:/var/mail/vmail/%h mail_executable(default): /usr/lib/dovecot/imap mail_executable(imap): /usr/lib/dovecot/imap mail_executable(pop3): /usr/lib/dovecot/pop3 mail_executable(managesieve): /usr/lib/dovecot/managesieve mail_plugin_dir(default): /usr/lib/dovecot/modules/imap mail_plugin_dir(imap): /usr/lib/dovecot/modules/imap mail_plugin_dir(pop3): /usr/lib/dovecot/modules/pop3 mail_plugin_dir(managesieve): /usr/lib/dovecot/modules/managesieve auth default: user: mail passdb: driver: sql args: /etc/dovecot/dovecot-sql.conf userdb: driver: prefetch userdb: driver: sql args: /etc/dovecot/dovecot-sql.conf socket: type: listen client: path: /var/spool/postfix/private/auth mode: 432 user: postfix group: postfix master: path: /var/run/dovecot/auth-master mode: 384 user: mail group: mail plugin: sieve: /var/mail/sieve/%u.dovecot.sieve
Anonymized mail attached. The From line was manually added, mainly because I extracted the content from the Postfix queue.
(I'm not subscribed.)
Cheers,
Julien Danjou // ᐰ julien@danjou.info http://julien.danjou.info // 9A0D 5FD9 EB42 22F6 8974 C95C A462 B51E C2FE E5CD // Life is life. Lalalalala.
On Wed, 2009-07-08 at 19:37 +0200, Julien Danjou wrote:
Jul 8 18:47:51 prometheus dovecot: deliver(jd@danjou.info): mkdir_parents_chown(danjou.info/jd/) failed: Permission denied (euid=8(mail) egid=8(mail))
The problem is this. It tries to create a non-existing directory, but can't because of permission problems. Although this may be misleading, because you're not using absolute paths in the user's home (mail?) directory. I'd fix that first. Maybe this problem goes away after that too.
Jul 8 18:47:51 prometheus dovecot: deliver(jd@danjou.info): copy: i_stream_read() failed: No such file or directory Jul 8 18:47:51 prometheus dovecot: deliver(jd@danjou.info): sieve: msgid=? 1186f9b5-0529-4622-8f4a-58462f9a4bcb@svr-exchange.siege.ldlc.com: failed to store into mailbox 'INBOX': Internal error occurred. Refer to server log for more information. [2009-07-08 18:47:51] Jul 8 18:47:51 prometheus dovecot: deliver(jd@danjou.info): read(mail, uid=1) failed: Permission denied
All this is a result from the first error.
On Wed, 2009-07-08 at 13:46 -0400, Timo Sirainen wrote:
On Wed, 2009-07-08 at 19:37 +0200, Julien Danjou wrote:
Jul 8 18:47:51 prometheus dovecot: deliver(jd@danjou.info): mkdir_parents_chown(danjou.info/jd/) failed: Permission denied (euid=8(mail) egid=8(mail))
The problem is this. It tries to create a non-existing directory, but can't because of permission problems. Although this may be misleading, because you're not using absolute paths in the user's home (mail?) directory. I'd fix that first. Maybe this problem goes away after that too.
http://hg.dovecot.org/dovecot-1.2/rev/6d7f6ea02e17 makes it log the current directory in the above error message when the path is relative.
At 1247075539 time_t, Timo Sirainen wrote:
http://hg.dovecot.org/dovecot-1.2/rev/6d7f6ea02e17 makes it log the current directory in the above error message when the path is relative.
Ok, that helps to see what's wrong, thanks:
Jul 8 20:50:16 prometheus dovecot: deliver(jd@danjou.info): mkdir_parents_chown(danjou.info/jd/) in directory /var/spool/postfix failed: Permission denied (euid=8(mail) egid=8(mail)) Jul 8 20:50:16 prometheus dovecot: deliver(jd@danjou.info): copy: i_stream_read() failed: No such file or directory
Of course, that fails.
The thing is that danjou.info/jd/ is the homedir of the user (returned by SQL), and as you saw in my dovecot.conf, there's nothing like /var/spool/postfix for mail_location:
mail_location = maildir:/var/mail/vmail/%h /var/spool/postfix is probably the directory where postfix starts dovecot, since it's the home for postfix user.
I smell (did not dig into the code) that there's a chdir() to mail_location that is missing for a reason I don't know.
(FWIW, I know have 4 mails in Postfix queue on 4 differents account stuck, whereas I still receive others mail without any problems (since I read you ;-).
Cheers,
Julien Danjou // ᐰ julien@danjou.info http://julien.danjou.info // 9A0D 5FD9 EB42 22F6 8974 C95C A462 B51E C2FE E5CD // This is the end of my signature.
On Wed, 2009-07-08 at 21:03 +0200, Julien Danjou wrote:
At 1247075539 time_t, Timo Sirainen wrote:
http://hg.dovecot.org/dovecot-1.2/rev/6d7f6ea02e17 makes it log the current directory in the above error message when the path is relative.
Ok, that helps to see what's wrong, thanks:
Jul 8 20:50:16 prometheus dovecot: deliver(jd@danjou.info): mkdir_parents_chown(danjou.info/jd/) in directory /var/spool/postfix failed: Permission denied (euid=8(mail) egid=8(mail)) Jul 8 20:50:16 prometheus dovecot: deliver(jd@danjou.info): copy: i_stream_read() failed: No such file or directory
Of course, that fails.
The thing is that danjou.info/jd/ is the homedir of the user (returned by SQL),
Make your SQL query return absolute path for home dir.
I smell (did not dig into the code) that there's a chdir() to mail_location that is missing for a reason I don't know.
It's not supposed to chdir to mail_location. It's supposed to chdir to home dir.
At 1247080982 time_t, Timo Sirainen wrote:
The thing is that danjou.info/jd/ is the homedir of the user (returned by SQL),
Make your SQL query return absolute path for home dir.
Sigh. That sounds like you let the bug. Quite sad to read.
I smell (did not dig into the code) that there's a chdir() to mail_location that is missing for a reason I don't know.
It's not supposed to chdir to mail_location. It's supposed to chdir to home dir.
Ok. Saw that in deliver.c. That's weird since it runs as 'mail', and mail's home is /var/mail, where as mail_location is /var/mail/vmail/%h. And almost all the mails (except the couples of ones I mentionned) are delivered and still delivered currently.
Cheers,
Julien Danjou // ᐰ julien@danjou.info http://julien.danjou.info // 9A0D 5FD9 EB42 22F6 8974 C95C A462 B51E C2FE E5CD // When I get sad, I stop being sad and be awesome instead. True story.
On Wed, 2009-07-08 at 21:36 +0200, Julien Danjou wrote:
At 1247080982 time_t, Timo Sirainen wrote:
The thing is that danjou.info/jd/ is the homedir of the user (returned by SQL),
Make your SQL query return absolute path for home dir.
Sigh. That sounds like you let the bug. Quite sad to read.
"let the bug"? The idea is anyway that you return home=/var/mail/vmail/danjou.info/jd and set
mail_location = maildir:%h
That makes much more sense to me. I've considered making it an error to return relative home dirs from userdb, but that might break some setups that are actually working right..
I smell (did not dig into the code) that there's a chdir() to mail_location that is missing for a reason I don't know.
It's not supposed to chdir to mail_location. It's supposed to chdir to home dir.
Ok. Saw that in deliver.c. That's weird since it runs as 'mail', and mail's home is /var/mail,
Well, I guess there's some confusion about what a home dir is.. With Dovecot the home dir is always what userdb returns as the home dir. Dovecot doesn't care about /etc/passwd at all, unless your userdb is passwd. So Dovecot doesn't know/care that deliver is run as "mail" user, it doesn't care what /etc/passwd contains for the mail user.
where as mail_location is /var/mail/vmail/%h. And almost all the mails (except the couples of ones I mentionned) are delivered and still delivered currently.
It's probably the large mails that cause the problem. Dovecot writes them to a temporary file under home directory.
On Wed, 2009-07-08 at 15:46 -0400, Timo Sirainen wrote:
"let the bug"? The idea is anyway that you return home=/var/mail/vmail/danjou.info/jd and set
mail_location = maildir:%h
That makes much more sense to me. I've considered making it an error to return relative home dirs from userdb, but that might break some setups that are actually working right..
Maybe some day I should write a "Dovecot configuration sanity checker" that warns about everything that isn't set up in a recommended way, but can't really be failed with an error..
At 1247082407 time_t, Timo Sirainen wrote:
"let the bug"? The idea is anyway that you return home=/var/mail/vmail/danjou.info/jd and set
mail_location = maildir:%h
That makes much more sense to me. I've considered making it an error to return relative home dirs from userdb, but that might break some setups that are actually working right..
Like mine. I don't think this is *bad* since it's, AFAIK, Dovecot only use in homedir to expand %h. Or do I miss another point?
Well, I guess there's some confusion about what a home dir is.. With Dovecot the home dir is always what userdb returns as the home dir. Dovecot doesn't care about /etc/passwd at all, unless your userdb is passwd. So Dovecot doesn't know/care that deliver is run as "mail" user, it doesn't care what /etc/passwd contains for the mail user.
Okay, sorry for the confusion. I don't know why I though it was doing some chdir() in a part of mail_location, which has no sense.
where as mail_location is /var/mail/vmail/%h. And almost all the mails (except the couples of ones I mentionned) are delivered and still delivered currently.
It's probably the large mails that cause the problem. Dovecot writes them to a temporary file under home directory.
OK, that would explains everything actually, depending on what you call home directory. :-) If it's the user's home, it really has no sense since nowhere it returns something with /var/spool/postfix.
Well, anyway, I changed my setup to return absolute path and it seems to work, the mails got delivered.
I really suggest you[1] rather try to reproduce and fix the bug, or really disallow relative path in home directory since it's seems partly-broken, or maybe only for large file (your theory :).
[1] Yeah, I know, it's easy to say... :-)
Cheers,
Julien Danjou // ᐰ julien@danjou.info http://julien.danjou.info // 9A0D 5FD9 EB42 22F6 8974 C95C A462 B51E C2FE E5CD // I'm no superman.
On Wed, 2009-07-08 at 22:11 +0200, Julien Danjou wrote:
Like mine. I don't think this is *bad* since it's, AFAIK, Dovecot only use in homedir to expand %h. Or do I miss another point?
Home directory may also be used for other things, although mainly only when Sieve is enabled.
I really suggest you[1] rather try to reproduce and fix the bug, or really disallow relative path in home directory since it's seems partly-broken, or maybe only for large file (your theory :).
I don't really know what to do about this. I don't think Dovecot should waste time always checking that directories exist when it's not necessary. Checking and preventing relative paths might be a possibility, but I don't really want to break existing setups.
The improved error message will hopefully be enough for now. :)
participants (2)
-
Julien Danjou
-
Timo Sirainen