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 argssievec(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 argssieve-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 argssieve-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=, altdovecot: 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.
Stephan Bosch
2013-May-18 21:35 UTC
[Dovecot] Dovecot 2.2.1 LDA and sieve (lack of) errors
On 5/18/2013 4:56 PM, Jim McNamara wrote:> 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 > > mail_debug = yesSo, mail_debug is enabled.> 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.Are you sure this is actually being executed? What happens if you execute dovecot-lda manually? This is an example of what you're supposed to see in the logs with mail_debug=yes: May 18 23:28:02 klara dovecot: lda: Debug: Loading modules from directory: /usr/lib/dovecot/modules May 18 23:28:02 klara dovecot: lda: Debug: Module loaded: /usr/lib/dovecot/modules/lib90_sieve_plugin.so May 18 23:28:02 klara dovecot: lda(stephan): Debug: Effective uid=1000, gid=1000, home=/home/stephan May 18 23:28:02 klara dovecot: lda(stephan): Debug: Namespace inbox: type=private, prefix=, sep=, inbox=yes, hidden=no, list=yes, subscriptions=yes location=maildir:~/Maildir May 18 23:28:02 klara dovecot: lda(stephan): Debug: maildir++: root=/home/stephan/Maildir, index=, indexpvt=, control=, inbox=/home/stephan/Maildir, altMay 18 23:28:02 klara dovecot: lda(stephan): Debug: userdb lookup skipped, username taken from USER environment May 18 23:28:02 klara dovecot: lda(stephan): Debug: none: root=, index=, indexpvt=, control=, inbox=, altMay 18 23:28:02 klara dovecot: lda(stephan): Debug: Destination address: stephan at klara (source: user at hostname) May 18 23:28:02 klara dovecot: lda(stephan): Debug: sieve: Pigeonhole version 0.4.0 initializing Regards, Stephan.