[Dovecot] Dovecot 2.2.1 LDA and sieve (lack of) errors

Jim McNamara jim at packetalk.net
Sat May 18 17:56:10 EEST 2013


Hello again, all. Of course after posting yesterday that all was well 
with my setup, turns out all is not well. The problem I'm having is with 
dovecot-lda functioning and making deliveries to my mailbox, but the 
sieve scripts don't seem to have any effect. Attempts at logging what 
is/isn't happening have been total failures.

Managesieve seems to work fine, port 4190 is open on the server and it 
allows the tunderbird plugin to function, I can create and edit scripts 
with the plugin. For some reason it doesn't seem to auto-compile the 
scripts to binary form, but if I just need to do that manually I can 
live with it. I only mention the lack of auto-compiling in case that 
sheds light on what is wrong with the LDA or sieve.

I'm running the current dovecot, 2.2.1 along with pigeonhole 0.4.0. Here 
is the config:

root at hostname:/usr/local/dovecot-2.2.1# doveconf -n
# 2.2.1: /usr/local/etc/dovecot/dovecot.conf
# OS: Linux 3.2.0-4-amd64 x86_64 Debian 7.0
auth_cache_size = 10 M
auth_default_realm = mail.domain.com
auth_mechanisms = plain login
auth_socket_path = /usr/local/var/run/dovecot/auth-userdb
debug_log_path = /dev/stderr
default_internal_user = vpopmail
default_login_user = vpopmail
first_valid_gid = 89
first_valid_uid = 89
hostname = mail.domain.com
last_valid_gid = 89
last_valid_uid = 89
lda_mailbox_autocreate = yes
lda_mailbox_autosubscribe = yes
log_path = /dev/stderr
mail_access_groups = 89
mail_debug = yes
mail_gid = 89
mail_location = maildir:%h/Maildir
mail_plugins = " quota"
mail_privileged_group = 89
mail_uid = 89
managesieve_notify_capability = mailto
managesieve_sieve_capability = fileinto reject envelope 
encoded-character vacation subaddress comparator-i;ascii-numeric 
relational regex imap4flags copy include variables body enotify 
environment mailbox date ihave spamtest spamtestplus vnd.dovecot.debug
namespace inbox {
   inbox = yes
   location =
   prefix =
   separator = .
}
passdb {
   driver = vpopmail
}
plugin {
   quota = maildir:User quota
   quota_rule = *:storage=2G
   quota_warning = storage=95%% quota-warning 95 %u
   sieve = ~/.sieve/dovecot.sieve
   sieve_dir = ~/.sieve
   sieve_extensions = +spamtest +spamtestplus +relational 
+comparator-i;ascii-numeric +vnd.dovecot.debug
}
postmaster_address = postmaster at mail.domain.com
protocols = imap pop3 lmtp sieve
sendmail_path = /var/qmail/bin/sendmail
service auth-worker {
   user = $default_internal_user
}
service auth {
   unix_listener auth-userdb {
     group = vchkpw
     mode = 0600
     user = vpopmail
   }
   user = $default_internal_user
}
service managesieve-login {
   inet_listener sieve {
     port = 4190
   }
   service_count = 1
   vsz_limit = 64 M
}
ssl = required
ssl_cert = </var/qmail/control/servercert.pem
ssl_key = </var/qmail/control/servercert.priv
userdb {
   args = quota_template=quota_rule=*:backend=%q
   driver = vpopmail
}
protocol lda {
   info_log_path = /dev/stderr
   log_path = /dev/stderr
   mail_plugins = " quota sieve"
}
protocol imap {
   mail_plugins = " quota imap_quota"
}
protocol pop3 {
   mail_plugins = " quota quota"
}


I've set the lda specific logs to /dev/stderr because I'm running 
dovecot through daemontools, and that is what it logs. Daemontools 
redirects /dev/stderr to /var/log/qmail/qmail-dovecot/current. I had 
tried logging to /var/log/dovecot/lda.log, that file exists, the 
directory is 775 dovecot:dovecot, but the file size remained 0. Very 
little appears in the dovecot logs with lda -

root at hostname:/home/vpopmail/domains/domain.com/jim/.sieve# grep lda 
/var/log/qmail/qmail-dovecot/current |tai64nlocal
2013-05-16 11:05:49.432026500 May 16 11:05:49 auth: Debug: master in: 
USER    1jim at domain.com    service=lda
2013-05-16 11:29:32.386361500 May 16 11:29:32 auth: Debug: master in: 
USER    1jim at domain.com    service=lda
2013-05-16 11:54:03.145741500 May 16 11:54:03 auth: Debug: master in: 
USER    1jim at domain.com    service=lda
2013-05-16 12:33:40.274543500 May 16 12:33:40 auth: Debug: master in: 
USER    1jim at domain.com    service=lda
2013-05-16 12:47:07.202036500 May 16 12:47:07 auth: Debug: master in: 
USER    1jim at domain.com    service=lda
2013-05-16 13:40:44.548948500 May 16 13:40:44 auth: Debug: master in: 
USER    1jim at domain.com    service=lda
2013-05-17 11:50:31.073410500 May 17 11:50:31 auth: Debug: master in: 
USER    1jim at domain.com    service=lda

The sieve issue is as follows: I have a very simple sieve script. the 
managaesieve utility accepts the script, here is the contents of the 
$HOME/.sieve directory:

root at hostname:/home/vpopmail/domains/domain.com/jim/.sieve# ls -al
total 20
drwx------ 3 vpopmail vchkpw 4096 May 18 02:24 .
drwx------ 5 vpopmail vchkpw 4096 May 18 09:39 ..
lrwxrwxrwx 1 vpopmail vchkpw   16 May 18 02:22 dovecot.sieve -> 
night-test.sieve
-rw------- 1 vpopmail vchkpw  303 May 18 02:22 dovecot.svbin
-rw------- 1 vpopmail vchkpw  315 May 18 02:24 night-test.sieve
drwx------ 2 vpopmail vchkpw 4096 May 18 02:24 tmp

The contents of dovecot.sieve itself are:

root at hostname:/home/vpopmail/domains/domain.com/jim/.sieve# cat 
dovecot.sieve
#
# 2013-5-17
#
require ["fileinto", "envelope", "vnd.dovecot.debug"];
if header :contains ["from"] "sub1.domain.com" {
     debug_log "match happened and syntax changed for testing purposes";
       fileinto
   "INBOX.folder2";
} else {
     debug_log "can't catch a cold when wet snowy and cold";
   keep;
}

The compile of the script works fine as user vpopmail:

vpopmail at hostname:~/domains/domain.com/jim/.sieve$ sievec dovecot.sieve 
/tmp/dovecot.svbin
sievec(vpopmail): Debug: Loading modules from directory: 
/usr/local/lib/dovecot
sievec(vpopmail): Debug: Module loaded: 
/usr/local/lib/dovecot/lib10_quota_plugin.so
sievec(vpopmail): Debug: Effective uid=89, gid=89, home=/home/vpopmail
sievec(vpopmail): Debug: Quota root: name=User quota backend=maildir args=
sievec(vpopmail): Debug: Quota rule: root=User quota mailbox=* 
bytes=2147483648 messages=0
sievec(vpopmail): Debug: Quota warning: bytes=2040109465 (95%) 
messages=0 reverse=no command=quota-warning 95 vpopmail
sievec(vpopmail): Debug: Quota grace: root=User quota bytes=214748364 (10%)

A diff between dovecot.svbin and /tmp/dovecot.svbin shows no difference. 
Neither of the debug lines show up anywhere in the logs.

When I send an email from sub1.domain.com to this server, it ends up in 
the main inbox rather than INBOX.folder2. Interestingly, if I run 
sieve-test on the mail, it tells me it should have been moved to 
INBOX.folder2:

vpopmail at hostname:~/domains/domain.com/jim/Maildir/cur$ sieve-test 
../../.sieve/dovecot.sieve 1368888104.11471.hostname\,S\=1235\:2\,a
sieve-test(vpopmail): Debug: Loading modules from directory: 
/usr/local/lib/dovecot
sieve-test(vpopmail): Debug: Module loaded: 
/usr/local/lib/dovecot/lib10_quota_plugin.so
sieve-test(vpopmail): Debug: Effective uid=89, gid=89, home=/home/vpopmail
sieve-test(vpopmail): Debug: Quota root: name=User quota backend=maildir 
args=
sieve-test(vpopmail): Debug: Quota rule: root=User quota mailbox=* 
bytes=2147483648 messages=0
sieve-test(vpopmail): Debug: Quota warning: bytes=2040109465 (95%) 
messages=0 reverse=no command=quota-warning 95 vpopmail
sieve-test(vpopmail): Debug: Quota grace: root=User quota 
bytes=214748364 (10%)
sieve-test(vpopmail): Debug: Quota root: name=User quota backend=maildir 
args=
sieve-test(vpopmail): Debug: Quota rule: root=User quota mailbox=* 
bytes=2147483648 messages=0
sieve-test(vpopmail): Debug: Quota warning: bytes=2040109465 (95%) 
messages=0 reverse=no command=quota-warning 95 raw mail user
sieve-test(vpopmail): Debug: Quota grace: root=User quota 
bytes=214748364 (10%)
sieve-test(vpopmail): Debug: none: root=, index=, indexpvt=, control=, 
inbox=, alt=
dovecot: line 6: info: DEBUG: match happened and syntax changed for 
testing purposes.

Performed actions:

  * store message in folder: INBOX.folder2

Implicit keep:

   (none)

sieve-test(vpopmail): Info: final result: success


And yes, INBOX.folder exists:

vpopmail at hostname:~/domains/domain.com/jim/Maildir/cur$ ls -al 
../.INBOX.folder2/
total 28
drwx------  5 vpopmail vchkpw 4096 May 14 10:33 .
drwx------ 15 vpopmail vchkpw 4096 May 18 10:42 ..
drwx------  2 vpopmail vchkpw 4096 May 14 10:20 cur
-rw-------  1 vpopmail vchkpw  232 May 17 08:07 dovecot.index.log
-rw-------  1 vpopmail vchkpw   17 May 14 10:33 dovecot-uidlist
-rw-------  1 vpopmail vchkpw    0 May 14 10:20 maildirfolder
drwx------  2 vpopmail vchkpw 4096 May 14 10:20 new
drwx------  2 vpopmail vchkpw 4096 May 14 10:20 tmp


Here's the file that calls dovecot-lda for user jim:

vpopmail at hostname:~/domains/domain.com/jim$ cat .qmail-default
|/var/qmail/bin/preline -f /usr/local/libexec/dovecot/dovecot-lda -d 
$EXT@$USER

Both /var/qmail/bin/preline and /usr/local/libexec/dovecot/dovecot-lda 
exist.

Any idea why my sieve doesn't seem to take effect?

Thanks for reading.





More information about the dovecot mailing list