May 2015 - dovecot - dovecot.org

[Dovecot] dsync replication errors
by Oli Schacher 09 Sep '15

09 Sep '15

Hi I'm trying to build a cluster of two servers with dsync replication (based on http://wiki2.dovecot.org/Replication) My test setup works fine for very simple tests, I can log in to both servers, copy a message to one of the servers and it successfully apperars in the other account. But, if I try to copy a large amount of messages at once to one of the accounts, my maillogs get flodded with errors(see below) and the mailboxes seem to get out of sync and messages are duplicated over and over again (I originally copied 100 messages and ended up with thousands in both mailboxes until I killed dovecot) I'd appreciate if someone could have a look at my config and tell me what I did wrong. dovecot.conf of both servers, they are identical except for the target ip in mail_replica: dovecot -n # 2.2.beta1 (070ca24e5846+): /etc/dovecot/dovecot.conf # OS: Linux 2.6.32-279.19.1.el6.x86_64 x86_64 CentOS release 6.3 (Final) disable_plaintext_auth = no mail_plugins = " notify replication" namespace { inbox = yes location = prefix = separator = / type = private } passdb { args = /etc/dovecot/dovecot-sql.conf driver = sql } plugin { mail_replica = remote:vmail@192.168.23.62 } protocols = pop3 imap service aggregator { fifo_listener replication-notify-fifo { user = vmail } unix_listener replication-notify { user = vmail } } service auth { unix_listener auth-master { group = vmail mode = 0660 user = vmail } user = root } service replicator { process_min_avail = 1 } ssl = no userdb { args = /etc/dovecot/dovecot-sql.conf driver = sql } Log on server1 after I copied 100 messages to an account on that server: Jan 31 10:41:04 doco1 dovecot: imap-login: Login: user=<user1>, method=PLAIN, rip=192.168.23.130, lip=192.168.23.61, mpid=1432, session=<OdjlbJLUmwDAqBeC> Jan 31 10:42:12 doco1 dovecot: doveadm: Error: dsync-remote(user1): Warning: Maildir /mailstore/user1/maildir: Expunged message reappeared, giving a new UID (old uid=72, file=1359625327.M621257P1432.doco1,S=2472,W=2547:2,) Jan 31 10:42:12 doco1 dovecot: dsync-local(user1): Error: Recent flags state corrupted for mailbox INBOX Jan 31 10:42:12 doco1 dovecot: doveadm: Error: dsync-remote(user1): Warning: Maildir /mailstore/user1/maildir: Expunged message reappeared, giving a new UID (old uid=73, file=1359625327.M740847P1432.doco1,S=2417,W=2492:2,) Jan 31 10:42:12 doco1 dovecot: doveadm: Error: dsync-remote(user1): Warning: Maildir /mailstore/user1/maildir: Expunged message reappeared, giving a new UID (old uid=74, file=1359625328.M206735P1432.doco1,S=2400,W=2474:2,) Jan 31 10:42:12 doco1 dovecot: doveadm: Error: dsync-remote(user1): Warning: Maildir /mailstore/user1/maildir: Expunged message reappeared, giving a new UID (old uid=75, file=1359625328.M668118P1432.doco1,S=2421,W=2496:2,) Jan 31 10:42:12 doco1 dovecot: doveadm: Error: dsync-remote(user1): Warning: Maildir /mailstore/user1/maildir: Expunged message reappeared, giving a new UID (old uid=76, file=1359625329.M167578P1432.doco1,S=2480,W=2559:2,) Jan 31 10:42:13 doco1 dovecot: doveadm: Error: dsync-remote(user1): Warning: Maildir /mailstore/user1/maildir: Expunged message reappeared, giving a new UID (old uid=77, file=1359625329.M520528P1432.doco1,S=2525,W=2604:2,) Jan 31 10:42:14 doco1 dovecot: doveadm(user1): Warning: /mailstore/user1/maildir/dovecot-uidlist: Duplicate file entry at line 132: 1359625329.M520528P1432.doco1,S=2525,W=2604 (uid 77 -> 133) Jan 31 10:42:14 doco1 dovecot: doveadm(user1): Warning: /mailstore/user1/maildir/dovecot-uidlist: Duplicate file entry at line 133: 1359625327.M621257P1432.doco1,S=2472,W=2547 (uid 72 -> 134) Jan 31 10:42:14 doco1 dovecot: doveadm(user1): Warning: /mailstore/user1/maildir/dovecot-uidlist: Duplicate file entry at line 134: 1359625327.M740847P1432.doco1,S=2417,W=2492 (uid 73 -> 135) Jan 31 10:42:14 doco1 dovecot: doveadm(user1): Warning: /mailstore/user1/maildir/dovecot-uidlist: Duplicate file entry at line 135: 1359625328.M206735P1432.doco1,S=2400,W=2474 (uid 74 -> 136) Jan 31 10:42:14 doco1 dovecot: doveadm(user1): Warning: /mailstore/user1/maildir/dovecot-uidlist: Duplicate file entry at line 136: 1359625328.M668118P1432.doco1,S=2421,W=2496 (uid 75 -> 137) Jan 31 10:42:14 doco1 dovecot: doveadm(user1): Warning: /mailstore/user1/maildir/dovecot-uidlist: Duplicate file entry at line 137: 1359625329.M167578P1432.doco1,S=2480,W=2559 (uid 76 -> 138) Jan 31 10:42:14 doco1 dovecot: doveadm(user1): Warning: /mailstore/user1/maildir/dovecot-uidlist: Duplicate file entry at line 139: 1359625329.M782065P1432.doco1,S=2461,W=2539 (uid 78 -> 140) Jan 31 10:42:14 doco1 dovecot: doveadm(user1): Warning: /mailstore/user1/maildir/dovecot-uidlist: Duplicate file entry at line 140: 1359625329.M973834P1432.doco1,S=2523,W=2602 (uid 79 -> 141) Jan 31 10:42:14 doco1 dovecot: doveadm(user1): Warning: /mailstore/user1/maildir/dovecot-uidlist: Duplicate file entry at line 141: 1359625330.M114922P1432.doco1,S=2546,W=2626 (uid 80 -> 142) Jan 31 10:42:14 doco1 dovecot: doveadm(user1): Warning: /mailstore/user1/maildir/dovecot-uidlist: Duplicate file entry at line 142: 1359625330.M255922P1432.doco1,S=2467,W=2546 (uid 81 -> 143) Jan 31 10:42:14 doco1 dovecot: doveadm(user1): Warning: /mailstore/user1/maildir/dovecot-uidlist: Duplicate file entry at line 143: 1359625330.M403257P1432.doco1,S=2534,W=2611 (uid 82 -> 144) Jan 31 10:42:14 doco1 dovecot: doveadm(user1): Warning: /mailstore/user1/maildir/dovecot-uidlist: Duplicate file entry at line 144: 1359625330.M486295P1432.doco1,S=2451,W=2529 (uid 83 -> 145) Jan 31 10:42:14 doco1 dovecot: doveadm: Error: dsync-remote(user1): Error: Mailbox INBOX: Unexpected GUID mismatch for UID=85: 1359625327.M740847P1432.doco1,S=2417,W=2492 != 2e1b1ee97994566870c02910ea929091 Jan 31 10:42:15 doco1 dovecot: doveadm: Error: dsync-remote(user1): Error: Mailbox INBOX: Remote didn't send mail GUID=1359625329.M167578P1432.doco1,S=2480,W=2559 (UID=175) Jan 31 10:42:15 doco1 dovecot: doveadm: Error: dsync-remote(user1): Error: Mailbox INBOX: Remote didn't send mail GUID=1359625329.M167578P1432.doco1,S=2480,W=2559 (UID=150) Jan 31 10:42:15 doco1 dovecot: doveadm: Error: dsync-remote(user1): Error: Mailbox INBOX: Remote didn't send mail GUID=1359625329.M520528P1432.doco1,S=2525,W=2604 (UID=176) Jan 31 10:42:15 doco1 dovecot: doveadm: Error: dsync-remote(user1): Error: Mailbox INBOX: Remote didn't send mail GUID=1359625329.M520528P1432.doco1,S=2525,W=2604 (UID=179) Jan 31 10:42:15 doco1 dovecot: doveadm: Error: dsync-remote(user1): Error: Mailbox INBOX: Remote didn't send mail GUID=1359625327.M740847P1432.doco1,S=2417,W=2492 (UID=123) Jan 31 10:42:15 doco1 dovecot: doveadm: Error: dsync-remote(user1): Error: Mailbox INBOX: Remote didn't send mail GUID=1359625327.M740847P1432.doco1,S=2417,W=2492 (UID=147) Jan 31 10:42:15 doco1 dovecot: doveadm: Error: dsync-remote(user1): Error: Mailbox INBOX: Remote didn't send mail GUID=1359625328.M668118P1432.doco1,S=2421,W=2496 (UID=174) Jan 31 10:42:15 doco1 dovecot: doveadm: Error: dsync-remote(user1): Error: Mailbox INBOX: Remote didn't send mail GUID=1359625328.M668118P1432.doco1,S=2421,W=2496 (UID=149) Jan 31 10:42:15 doco1 dovecot: doveadm: Error: dsync-remote(user1): Error: Mailbox INBOX: Remote didn't send mail GUID=1359625328.M206735P1432.doco1,S=2400,W=2474 (UID=173) Jan 31 10:42:15 doco1 dovecot: doveadm: Error: dsync-remote(user1): Error: Mailbox INBOX: Remote didn't send mail GUID=1359625328.M206735P1432.doco1,S=2400,W=2474 (UID=148) Jan 31 10:42:16 doco1 dovecot: doveadm: Error: dsync-remote(user1): Error: Importing mailbox INBOX failed Jan 31 10:42:16 doco1 dovecot: dsync-local(user1): Error: read(vmail(a)192.168.23.62) failed: EOF Jan 31 10:42:16 doco1 dovecot: dsync-local(user1): Error: Remote command returned error 75 Jan 31 10:42:20 doco1 dovecot: doveadm: Error: dsync-remote(user1): Error: Mailbox INBOX: Remote didn't send mail GUID=1359625329.M167578P1432.doco1,S=2480,W=2559 (UID=230) [...] Log on server2: Jan 31 10:42:14 doco2 dovecot: doveadm: Error: dsync-remote(user1): Warning: /mailstore/user1/maildir/dovecot-uidlist: Duplicate file entry at line 132: 1359625329.M520528P1432.doco1,S=2525,W=2604 (uid 77 -> 133) Jan 31 10:42:14 doco2 dovecot: doveadm: Error: dsync-remote(user1): Warning: /mailstore/user1/maildir/dovecot-uidlist: Duplicate file entry at line 133: 1359625327.M621257P1432.doco1,S=2472,W=2547 (uid 72 -> 134) Jan 31 10:42:14 doco2 dovecot: doveadm: Error: dsync-remote(user1): Warning: /mailstore/user1/maildir/dovecot-uidlist: Duplicate file entry at line 134: 1359625327.M740847P1432.doco1,S=2417,W=2492 (uid 73 -> 135) Jan 31 10:42:14 doco2 dovecot: doveadm: Error: dsync-remote(user1): Warning: /mailstore/user1/maildir/dovecot-uidlist: Duplicate file entry at line 135: 1359625328.M206735P1432.doco1,S=2400,W=2474 (uid 74 -> 136) Jan 31 10:42:14 doco2 dovecot: doveadm: Error: dsync-remote(user1): Warning: /mailstore/user1/maildir/dovecot-uidlist: Duplicate file entry at line 136: 1359625328.M668118P1432.doco1,S=2421,W=2496 (uid 75 -> 137) Jan 31 10:42:14 doco2 dovecot: doveadm: Error: dsync-remote(user1): Warning: /mailstore/user1/maildir/dovecot-uidlist: Duplicate file entry at line 137: 1359625329.M167578P1432.doco1,S=2480,W=2559 (uid 76 -> 138) Jan 31 10:42:14 doco2 dovecot: doveadm: Error: dsync-remote(user1): Warning: /mailstore/user1/maildir/dovecot-uidlist: Duplicate file entry at line 139: 1359625329.M782065P1432.doco1,S=2461,W=2539 (uid 78 -> 140) Jan 31 10:42:14 doco2 dovecot: doveadm: Error: dsync-remote(user1): Warning: /mailstore/user1/maildir/dovecot-uidlist: Duplicate file entry at line 140: 1359625329.M973834P1432.doco1,S=2523,W=2602 (uid 79 -> 141) Jan 31 10:42:14 doco2 dovecot: doveadm: Error: dsync-remote(user1): Warning: /mailstore/user1/maildir/dovecot-uidlist: Duplicate file entry at line 141: 1359625330.M114922P1432.doco1,S=2546,W=2626 (uid 80 -> 142) Jan 31 10:42:14 doco2 dovecot: doveadm: Error: dsync-remote(user1): Warning: /mailstore/user1/maildir/dovecot-uidlist: Duplicate file entry at line 142: 1359625330.M255922P1432.doco1,S=2467,W=2546 (uid 81 -> 143) Jan 31 10:42:14 doco2 dovecot: doveadm: Error: dsync-remote(user1): Warning: /mailstore/user1/maildir/dovecot-uidlist: Duplicate file entry at line 143: 1359625330.M403257P1432.doco1,S=2534,W=2611 (uid 82 -> 144) Jan 31 10:42:14 doco2 dovecot: doveadm: Error: dsync-remote(user1): Warning: /mailstore/user1/maildir/dovecot-uidlist: Duplicate file entry at line 144: 1359625330.M486295P1432.doco1,S=2451,W=2529 (uid 83 -> 145) Jan 31 10:42:15 doco2 dovecot: doveadm: Error: dsync-remote(user1): Warning: Maildir /mailstore/user1/maildir: Expunged message reappeared, giving a new UID (old uid=84, file=1359625330.M608391P1432.doco1,S=2480,W=2559:2,) Jan 31 10:42:15 doco2 dovecot: doveadm: Error: dsync-remote(user1): Warning: Maildir /mailstore/user1/maildir: Expunged message reappeared, giving a new UID (old uid=85, file=1359625330.M813949P1432.doco1,S=2427,W=2502:2,) Jan 31 10:42:15 doco2 dovecot: doveadm: Error: dsync-remote(user1): Warning: Maildir /mailstore/user1/maildir: Expunged message reappeared, giving a new UID (old uid=86, file=1359625331.M217320P1432.doco1,S=2547,W=2625:2,) Jan 31 10:42:15 doco2 dovecot: doveadm: Error: dsync-remote(user1): Warning: Maildir /mailstore/user1/maildir: Expunged message reappeared, giving a new UID (old uid=87, file=1359625331.M688431P1432.doco1,S=2529,W=2609:2,) [...] Thanks Oli -- message transmitted on 100% recycled electrons

7 45

Different behavior of ACLs in MUA and doveadm
by Thomas Leuxner 08 Sep '15

08 Sep '15

I have noticed a difference in the behavior of ACLs. When used in a MUA the following global ACL works fine and has the desired effect - new mailboxes can be created by a user being part of the 'PublicMailboxAdmins' group: [ global-acl: ] INBOX owner lrwstiekxap Public/* group=PublicMailboxAdmins lrwsipk Public/* anyone lr Public/* authenticated lrws Creating the same mailbox via doveadm however fails with a permission problem: doveadm(tlx(a)leuxner.net): Debug: acl vfile: Global ACL file: /var/vmail/conf.d/leuxner.net/global-acl doveadm(tlx(a)leuxner.net): Debug: Namespace : type=public, prefix=Public/, sep=/, inbox=no, hidden=no, list=yes, subscriptions=no location=mdbox:/var/vmail/public:INDEXPVT=~/mdbox/public doveadm(tlx(a)leuxner.net): Debug: fs: root=/var/vmail/public, index=, indexpvt=/var/vmail/domains/leuxner.net/tlx/mdbox/public, control=, inbox=, alt= doveadm(tlx(a)leuxner.net): Debug: acl: initializing backend with data: vfile:/var/vmail/conf.d/leuxner.net/global-acl:cache_secs=300 doveadm(tlx(a)leuxner.net): Debug: acl: acl username = tlx(a)leuxner.net doveadm(tlx(a)leuxner.net): Debug: acl: owner = 0 doveadm(tlx(a)leuxner.net): Debug: acl vfile: Global ACL file: /var/vmail/conf.d/leuxner.net/global-acl doveadm(tlx(a)leuxner.net): Debug: Namespace : type=private, prefix=Virtual/, sep=/, inbox=no, hidden=no, list=yes, subscriptions=yes location=virtual:~/mdbox/virtual doveadm(tlx(a)leuxner.net): Debug: fs: root=/var/vmail/domains/leuxner.net/tlx/mdbox/virtual, index=, indexpvt=, control=, inbox=, alt= doveadm(tlx(a)leuxner.net): Debug: acl: initializing backend with data: vfile:/var/vmail/conf.d/leuxner.net/global-acl:cache_secs=300 doveadm(tlx(a)leuxner.net): Debug: acl: acl username = tlx(a)leuxner.net doveadm(tlx(a)leuxner.net): Debug: acl: owner = 1 doveadm(tlx(a)leuxner.net): Debug: acl vfile: Global ACL file: /var/vmail/conf.d/leuxner.net/global-acl doveadm(tlx(a)leuxner.net): Debug: acl vfile: file /var/vmail/public/mailboxes/dovecot-acl not found doveadm(tlx(a)leuxner.net): Error: Can't create mailbox Public/Archive/Newsletters/heise-security/2014: Permission denied Interestingly, doveadm succeeds when dovecot-acl is present in the namespace root - which of course is not desirable in the light of the global ACL: [ dovecot-acl: ] group=PublicMailboxAdmins lrwsipk doveadm(tlx(a)leuxner.net): Debug: acl vfile: Global ACL file: /var/vmail/conf.d/leuxner.net/global-acl doveadm(tlx(a)leuxner.net): Debug: Namespace : type=public, prefix=Public/, sep=/, inbox=no, hidden=no, list=yes, subscriptions=no location=mdbox:/var/vmail/public:INDEXPVT=~/mdbox/public doveadm(tlx(a)leuxner.net): Debug: fs: root=/var/vmail/public, index=, indexpvt=/var/vmail/domains/leuxner.net/tlx/mdbox/public, control=, inbox=, alt= doveadm(tlx(a)leuxner.net): Debug: acl: initializing backend with data: vfile:/var/vmail/conf.d/leuxner.net/global-acl:cache_secs=300 doveadm(tlx(a)leuxner.net): Debug: acl: acl username = tlx(a)leuxner.net doveadm(tlx(a)leuxner.net): Debug: acl: owner = 0 doveadm(tlx(a)leuxner.net): Debug: acl vfile: Global ACL file: /var/vmail/conf.d/leuxner.net/global-acl doveadm(tlx(a)leuxner.net): Debug: Namespace : type=private, prefix=Virtual/, sep=/, inbox=no, hidden=no, list=yes, subscriptions=yes location=virtual:~/mdbox/virtual doveadm(tlx(a)leuxner.net): Debug: fs: root=/var/vmail/domains/leuxner.net/tlx/mdbox/virtual, index=, indexpvt=, control=, inbox=, alt= doveadm(tlx(a)leuxner.net): Debug: acl: initializing backend with data: vfile:/var/vmail/conf.d/leuxner.net/global-acl:cache_secs=300 doveadm(tlx(a)leuxner.net): Debug: acl: acl username = tlx(a)leuxner.net doveadm(tlx(a)leuxner.net): Debug: acl: owner = 1 doveadm(tlx(a)leuxner.net): Debug: acl vfile: Global ACL file: /var/vmail/conf.d/leuxner.net/global-acl doveadm(tlx(a)leuxner.net): Debug: acl vfile: reading file /var/vmail/public/mailboxes/dovecot-acl doveadm(tlx(a)leuxner.net): Debug: Namespace Public/: /var/vmail/public/mailboxes/Archive/Newsletters/heise-security/2014 doesn't exist yet, using default permissions doveadm(tlx(a)leuxner.net): Debug: Namespace Public/: Using permissions from /var/vmail/public: mode=0700 gid=default doveadm(tlx(a)leuxner.net): Debug: acl vfile: file /var/vmail/public/mailboxes/Archive/Newsletters/heise-security/dbox-Mails/dovecot-acl not found doveadm(tlx(a)leuxner.net): Debug: acl vfile: file /var/vmail/public/mailboxes/Archive/Newsletters/heise-security/2014/dbox-Mails/dovecot-acl not found doveadm(tlx(a)leuxner.net): Debug: acl vfile: file /var/vmail/public/mailboxes/Archive/Newsletters/heise-security/2014/dbox-Mails/dovecot-acl not found doveadm(tlx(a)leuxner.net): Debug: acl vfile: file /var/vmail/public/mailboxes/Archive/Newsletters/heise-security/2014/dbox-Mails/dovecot-acl not found # 2.2.15 (6078354e6238): /etc/dovecot/dovecot.conf I know there have been some changes in Mercurial as to how global ACLs are interpreted. Is doveadm probably behind on them? Regards Thomas

2 5

Patch for "doveadm -f table" nit (was Re: Dovecot current number of connections being used.)
by Joseph Tam 08 Sep '15

08 Sep '15

> doveadm who -1 2>/dev/null | wc -l You have to redirect stderr to /dev/null because that's where the first header line is written to. The default format style (table) is inconsistent with the other formats (flow,pager,tab) that write headers and data to stdout. The following patch will pick this nit. This patch will require modifications to scripts that rely on doveadm writing headers to stderr. For example, the above doveadm command could be modified to doveadm who -1 | grep -vc '^username' -------------------------------------------------------------------------------- --- a/dovecot-2.2.16.rc1/src/doveadm/doveadm-print-table.c Wed Mar 18 15:40:40 2015 +++ b/dovecot-2.2.16.rc1/src/doveadm/doveadm-print-table.c Wed Mar 18 15:41:18 2015 @@ -151,3 +151,3 @@ for (i = 0; i < count; i++) { - if (i > 0) fprintf(stderr, " "); + if (i > 0) printf(" "); @@ -155,3 +155,3 @@ DOVEADM_PRINT_HEADER_FLAG_RIGHT_JUSTIFY) == 0) { - fprintf(stderr, "%-*s", (int)headers[i].length, + printf("%-*s", (int)headers[i].length, headers[i].title); @@ -158,3 +158,3 @@ } else { - fprintf(stderr, "%*s", (int)headers[i].length, + printf("%*s", (int)headers[i].length, headers[i].title); @@ -162,3 +162,3 @@ } - fprintf(stderr, "\n"); + printf("\n"); } -------------------------------------------------------------------------------- Joseph Tam <jtam.home(a)gmail.com>

5 9

doveadm-server hangs with 100% cpu usage
by Dennis Kuhn 02 Sep '15

02 Sep '15

we have some replication issues. From time to time a doveadm-server process takes 100% cpu in the state recv_mailbox_tree_deletes on the replica. The process runs forever until it is manually killed. Strace on this process doesn't show anything. Sometimes we have several doveadm-server processes in this state, all for the same account, all with 100% CPU Load. The logfile on the master says: Error: Timeout during state=recv_mailbox_tree Error: dsync(dobby5.heinlein-support.de): I/O has stalled, no activity for 600 seconds My workaround is to delete the user directory on the replica so that the whole account is replicated again. This solves the problem for this specific account. The dovecot version is 2.2.15 on the master and 2.2.16 on the replica. Dennis Kuhn -- Heinlein Support GmbH Schwedter Str. 8/9b, 10119 Berlin http://www.heinlein-support.de Tel: 030 / 405051-57 Fax: 030 / 405051-19 Zwangsangaben lt. §35a GmbHG: HRB 93818 B / Amtsgericht Berlin-Charlottenburg, Geschäftsführer: Peer Heinlein -- Sitz: Berlin

3 4

mailbox deletion is not replicated correctly
by Dennis Kuhn 27 Aug '15

27 Aug '15

i can't delete several folders at once. I have a folder structure like folder1/folder2/folder3 (we use slash as hierarchy separator). When i delete folder1 server1 executes the command correctly Apr 16 13:44:28 server1 dovecot: imap(d.kuhn(a)heinlein-support.de): Mailbox deleted: INBOX/Trash/folder1/folder2/folder3 Apr 16 13:44:28 server1 dovecot: imap(d.kuhn(a)heinlein-support.de): Mailbox deleted: INBOX/Trash/folder1/folder2 Apr 16 13:44:28 server1 dovecot: imap(d.kuhn(a)heinlein-support.de): Mailbox deleted: INBOX/Trash/folder1 but the replica server2 reverses the order: Apr 16 13:44:29 server2 dovecot: dsync-server(d.kuhn(a)heinlein-support.de): Mailbox deleted: INBOX/Trash/folder1 Apr 16 13:44:29 server2 dovecot: dsync-server(d.kuhn(a)heinlein-support.de): Mailbox deleted: INBOX/Trash/folder1/folder2 Apr 16 13:44:29 server2 dovecot: dsync-server(d.kuhn(a)heinlein-support.de): Mailbox deleted: INBOX/Trash/folder1/folder2/folder3 This creates the folder INBOX/Trash/folder1/folder2 on server2 again which replicates back to server1. Regards, Dennis Kuhn -- Heinlein Support GmbH Schwedter Str. 8/9b, 10119 Berlin http://www.heinlein-support.de Tel: 030 / 405051-57 Fax: 030 / 405051-19 Zwangsangaben lt. §35a GmbHG: HRB 93818 B / Amtsgericht Berlin-Charlottenburg, Geschäftsführer: Peer Heinlein -- Sitz: Berlin

3 4

PROXY protocol
by Hoggins! 26 Aug '15

26 Aug '15

Hello folks, Any plans on implementing the PROXY protocol to allow Dovecot being behind a TCP proxy, and still logging the real IP address of the users ? See : http://blog.haproxy.com/haproxy/proxy-protocol/ Thanks !

6 15

[Dovecot] Dovecot FTS using ElasticSearch
by Darvin Denmian 21 Jul '15

21 Jul '15

Hi, I would like to know if is possible to use ElasticSearch instead of Solr for FTS. Regards, Erick Vitor de Barros.

6 6

Dovecot 2.2.16: disappearing messages, mismatched summaries, duplicated messages, excessive full re-downloads
by David Gessel 20 Jun '15

20 Jun '15

My Dovecot 2.2.16 server is interacting poorly with a variety of mail clients. The symptoms include disappearing messages, mismatched summaries, duplicated messages, and excessive full re-downloads. Dovecot 2.2.16 on FreeBSD 10.1-release r280247M ZFS is interacting suboptimally with various email clients. Output of "dovecot -n" further down. *Client Artifacts* Thunderbird 31.6 Win 7 Ultimate SP1: - messages disappear and reappear with checks somewhat randomly. - Sometimes full re-download of folders is triggered, also seems random - Copies of messages appear, sometimes multiplying with each mail check up to about 5-8 or so of each message. - The summary information in the list pane doesn't match the message headers in the preview pane - quit and restart always cleans it up. - sometimes changing folders cleans it up, but not always - sometimes instigating a manual mail check cleans it up but not always Mulberry 4.08 Win 7 Ultimate SP1: - messages disappear and reappear - full re-scans of entire folders triggered occasionally when changing folders, but not always - message list filled with semi-blank entries (message number, status flags, and dates are listed, but no sender, subject, or body is available). The time stamps do not appear to be correct "date received". - message list fills with duplicates - the last of the set of duplicates, which are not necessarily sequentially numbered, has load-able body text and headers, but the others do not. There may be 3-5 copies, only one of which is the real message. The inbox is sequentially numbered by "message number" (the "natural order of the mailbox") and duplicates have unique numbers. - If there's a deleted message left, the "expunge" button is enabled and this also restores normal mailbox view. - disconnecting and reconnecting usually fixes the issues - changing mailboxes while connected sometimes fixes the issues. Claws 3.10.1 Win 7 Ultimate SP1 - initial load is correct, but once claws tries to sync mail, it locks up and never releases (even after days). Claws is weird like that. Sylpheed 3.4.2 Win 7 Ultimate SP1 - mail list always looks fine, but sometimes clicking a message shows "can't display" in the preview pane - "get messages" restores access to messages. Thunderbird 31.5 Linux Mint 17 Qaina 3.13.0-24-generic - messages disappear and reappear with checks somewhat randomly. - Sometimes full redownload of folders is triggered, also seems random - Copies of messages appear, sometimes multiplying with each mail check - The summary information in the list pane doesn't match the message headers in the preview pane - wrong message total (every other client agrees on 2576 but TB-linux says 3242, perhaps counting dups) Claws 3.9.3 Linux Mint 17 Qaina 3.13.0-24-generic - Occasionally shows "this message can't be displayed" - executing a "get mail" fixes the error K-9 5.004 Android 4.3 - messages appear and then disappear on the next check - message body is occasionally blank (only subject and arrival time appear, no body preview line, clicking on the message shows "no text" *Server artifacts:* dovecot.log shows runs of this error: Apr 15 09:02:37 imap(user(a)domain.com): Warning: Maildir /mail/domain.com/user//.Sent: Expunged message reappeared, giving a new UID (old uid=306286, file=1429102024.M826331P1156.host,S=1678,W=1724:2,S) or this error: Apr 15 10:04:00 indexer-worker(user(a)domain.com): Warning: Maildir /mail/domain.com/user//.Sent: Expunged message reappeared, giving a new UID (old uid=306803, file=1428785463.M645546P27215.host,S=5389,W=5442:2,S) # grep -c "Expunged message reappeared" dovecot.log.0 8981 The first entry in dovecot.log.0 is at Apr 15 10:00:12, and the last entry at Apr 15 12:00:13; Dovecot is logging 4,490 expunged message reappeared messages per hour. Note the server has 4 accounts set up and very limited traffic, so 4,490 per hour would seem like a lot of anything to be logged. # doveadm dump -t mailboxlog /mail/domain.com/user #0: rename 000000803de108b60f00000000000000 (1969-12-31 16:00:00) #24: 00000000000000000000000000000000 (1969-12-31 16:00:00) #48: 000000000000000000000000c8272100 (1969-12-31 16:01:04) #72: 00002e61726368697665732e32303031 (2031-02-20 10:50:40) Fatal: rec read() 10 != 24 "Fatal" seems like an error. I do not see much argument with the assertion that 10 != 24. # doveadm dump -t fts-expunge-log /mail/domain.com/user Fatal: Invalid record_size=2147483648 at offset 0 dovecot-debug.log examples follow after # dovecot -n output, which follows "fixes tried:" *Fixes Tried* # doveadm purge -A # doveadm fts rescan -u user(a)domain.com # doveadm -Dv index -u user INBOX # doveadm force-resync -u user INBOX I've set mbox_dirty_syncs = no mbox_lazy_writes = no ...in an attempt to fix the problem, but none did. I tried removing most of my customizations one by one and testing, but the problem has not been improved. I strongly suspect that the index files are getting thrashed or otherwise abused. I have no idea what's triggering whatever event is resulting in the thousands of expunged messages reappearing, but the client artifacts suggest a mismatch between cache or index files and files on disk: UID, keywords, and set date appear as if from cache but the body of the message does not. It seems as if the UID doesn't match a message on disk any more, which soon gets automatically fixed and everything syncs again until something re-triggers - a false expunge perhaps? Or perhaps the transaction log is suffering some sort of ongoing abuse? *dovecot -n* # dovecot -n # 2.2.16: /usr/local/etc/dovecot/dovecot.conf # Pigeonhole version 0.4.7 # OS: FreeBSD 10.1-RELEASE amd64 auth_default_realm = blackrosetech.com auth_mechanisms = plain login auth_realms = blackrosetech.com eroticanarchy.org debug_log_path = /var/log/dovecot-debug.log deliver_log_format = msgid=%m: %f $p %$ disable_plaintext_auth = no first_valid_gid = 5000 first_valid_uid = 5000 hostname = blackrosetech.com info_log_path = /var/log/dovecot-info.log last_valid_gid = 5000 last_valid_uid = 5000 lda_mailbox_autocreate = yes listen = 10.3.69.135 log_path = /var/log/dovecot.log mail_debug = yes mail_gid = 5000 mail_location = maildir:~:CONTROL=/var/no-quota/%u mail_plugins = quota mail_log notify fts fts_lucene mail_temp_dir = /var/tmp mail_uid = 5000 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 index ihave duplicate spamtest spamtestplus editheader mbox_dirty_syncs = no mbox_lazy_writes = no namespace inbox { inbox = yes location = mailbox Drafts { 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 = } passdb { args = /usr/local/etc/dovecot/dovecot-sql.conf.ext driver = sql } plugin { expire = Trash fts = lucene fts_autoindex = yes fts_lucene = whitespace_chars=@. mime_parts mail_log_events = delete undelete expunge copy mailbox_delete mailbox_rename mail_log_fields = uid box msgid size quota = maildir:User quota quota_exceeded_message = Storage quota for this account has been exceeded, please try again later. quota_rule = *:storage=50G quota_rule2 = Trash:storage=+30%% quota_rule3 = Sent:storage=+30%% quota_warning = storage=90%% quota-warning 90 %u quota_warning2 = storage=75%% quota-warning 75 %u sieve = ~/.dovecot.sieve sieve_before = /usr/local/etc/dovecot/sieve/ sieve_dir = ~/sieve sieve_extensions = +spamtest +spamtestplus +relational +comparator-i;ascii-numeric +editheader sieve_global_dir = /usr/local/etc/dovecot/sieve } postmaster_address = gessel(a)blackrosetech.com protocols = imap lmtp sieve sieve sendmail_path = /usr/local/sbin/sendmail service auth { unix_listener /var/spool/postfix/private/auth { group = postfix mode = 0660 user = postfix } unix_listener auth-userdb { group = vmail mode = 0666 user = vmail } } service managesieve-login { inet_listener sieve { port = 4190 } service_count = 1 vsz_limit = 128 M } service quota-warning { executable = script /usr/local/bin/quota-warning.sh unix_listener quota-warning { user = vmail } user = vmail } ssl = required ssl_cert = </usr/local/etc/ca/shiofuki-cert.pem ssl_key = </usr/local/etc/ca/shiofuki-unencrypted-key.pem ssl_prefer_server_ciphers = yes userdb { driver = prefetch } userdb { args = /usr/local/etc/dovecot/dovecot-sql.conf.ext driver = sql } protocol lda { mail_plugins = quota mail_log notify fts fts_lucene sieve } protocol imap { mail_max_userip_connections = 20 mail_plugins = quota mail_log notify fts fts_lucene imap_quota } protocol lmtp { mail_plugins = quota mail_log notify fts fts_lucene sieve } I appreciate any assistance or insight, -David *dovecot-debug.log excerpts* Apr 15 13:17:26 indexer-worker(user(a)domain.com): user-lookup(user(a)domain.com)Debug: auth input: user(a)domain.com home=/mail/domain.com/user/ mail=maildir:~/ uid=5000 gid=5000 quota_rule=*:bytes=0 Apr 15 13:17:26 indexer-worker(user(a)domain.com): user-lookup(user(a)domain.com)Debug: Added userdb setting: mail=maildir:~/ Apr 15 13:17:26 indexer-worker(user(a)domain.com): user-lookup(user(a)domain.com)Debug: Added userdb setting: plugin/quota_rule=*:bytes=0 Apr 15 13:17:26 indexer-worker(user(a)domain.com): Debug: Effective uid=5000, gid=5000, home=/mail/domain.com/user/ Apr 15 13:17:26 indexer-worker(user(a)domain.com): Debug: Quota root: name=User quota backend=maildir args= Apr 15 13:17:26 indexer-worker(user(a)domain.com): Debug: Quota rule: root=User quota mailbox=* bytes=0 messages=0 Apr 15 13:17:26 indexer-worker(user(a)domain.com): Debug: Quota rule: root=User quota mailbox=Trash bytes=0 (30%) messages=0 Apr 15 13:17:26 indexer-worker(user(a)domain.com): Debug: Quota rule: root=User quota mailbox=Sent bytes=0 (30%) messages=0 Apr 15 13:17:26 indexer-worker(user(a)domain.com): Debug: Quota warning: bytes=0 (90%) messages=0 reverse=no command=quota-warning 90 user(a)domain.com Apr 15 13:17:26 indexer-worker(user(a)domain.com): Debug: Quota warning: bytes=0 (75%) messages=0 reverse=no command=quota-warning 75 user(a)domain.com Apr 15 13:17:26 indexer-worker(user(a)domain.com): Debug: Quota grace: root=User quota bytes=0 (10%) Apr 15 13:17:26 indexer-worker(user(a)domain.com): Debug: Namespace inbox: type=private, prefix=, sep=, inbox=yes, hidden=no, list=yes, subscriptions=yes location=maildir:~/ Apr 15 13:17:26 indexer-worker(user(a)domain.com): Debug: maildir++: root=/mail/domain.com/user/, index=, indexpvt=, control=, inbox=/mail/domain.com/user/, alt= Apr 15 13:17:27 indexer-worker(user(a)domain.com): Debug: Ignoring unknown cache field: pop3.order Apr 15 13:17:27 indexer-worker(user(a)domain.com): Debug: Ignoring unknown cache field: binary.parts Apr 15 13:17:27 indexer-worker(user(a)domain.com): Debug: Ignoring unknown cache field: body.snippet Apr 15 13:44:25 lda(user(a)domain.com): Debug: Quota root: name=User quota backend=maildir args= Apr 15 13:44:25 lda(user(a)domain.com): Debug: Quota rule: root=User quota mailbox=* bytes=53687091200 messages=0 Apr 15 13:44:25 lda(user(a)domain.com): Debug: Quota rule: root=User quota mailbox=Trash bytes=+16106127360 (30%) messages=0 Apr 15 13:44:25 lda(user(a)domain.com): Debug: Quota rule: root=User quota mailbox=Sent bytes=+16106127360 (30%) messages=0 Apr 15 13:44:25 lda(user(a)domain.com): Debug: Quota warning: bytes=48318382080 (90%) messages=0 reverse=no command=quota-warning 90 raw mail user Apr 15 13:44:25 lda(user(a)domain.com): Debug: Quota warning: bytes=40265318400 (75%) messages=0 reverse=no command=quota-warning 75 raw mail user Apr 15 13:44:25 lda(user(a)domain.com): Debug: Quota grace: root=User quota bytes=5368709120 (10%) Apr 15 13:44:25 lda(user(a)domain.com): Debug: none: root=, index=, indexpvt=, control=, inbox=, alt= Apr 15 13:49:32 lda(user(a)domain.com): Debug: Quota root: name=User quota backend=maildir args= Apr 15 13:49:32 lda(user(a)domain.com): Debug: Quota rule: root=User quota mailbox=* bytes=53687091200 messages=0 Apr 15 13:49:32 lda(user(a)domain.com): Debug: Quota rule: root=User quota mailbox=Trash bytes=+16106127360 (30%) messages=0 Apr 15 13:49:32 lda(user(a)domain.com): Debug: Quota rule: root=User quota mailbox=Sent bytes=+16106127360 (30%) messages=0 Apr 15 13:49:32 lda(user(a)domain.com): Debug: Quota warning: bytes=48318382080 (90%) messages=0 reverse=no command=quota-warning 90 raw mail user Apr 15 13:49:32 lda(user(a)domain.com): Debug: Quota warning: bytes=40265318400 (75%) messages=0 reverse=no command=quota-warning 75 raw mail user Apr 15 13:49:32 lda(user(a)domain.com): Debug: Quota grace: root=User quota bytes=5368709120 (10%) Apr 15 13:49:32 lda(user(a)domain.com): Debug: none: root=, index=, indexpvt=, control=, inbox=, alt= Apr 15 13:49:41 lda(user(a)domain.com): Debug: sieve: file storage: Using script storage path: /mail/domain.com/user//sieve Apr 15 13:49:41 lda(user(a)domain.com): Debug: sieve: file storage: Relative path to sieve storage in active link: sieve/ Apr 15 13:49:41 lda(user(a)domain.com): Debug: sieve: file script: Opened script `Forwards' from `/mail/domain.com/user/sieve/Forwards.sieve' Apr 15 13:49:41 lda(user(a)domain.com): Debug: sieve: file script: Opened script `File_Server_Msg' from `/mail/domain.com/user/sieve/File_Server_Msg.sieve' Apr 15 13:49:41 lda(user(a)domain.com): Debug: sieve: file script: Opened script `File_SRL' from `/mail/domain.com/user/sieve/File_SRL.sieve' Apr 15 13:49:41 lda(user(a)domain.com): Debug: sieve: file script: Opened script `File_BULK' from `/mail/domain.com/user/sieve/File_BULK.sieve' Apr 15 13:49:41 lda(user(a)domain.com): Debug: sieve: file script: Opened script `File_Commerce' from `/mail/domain.com/user/sieve/File_Commerce.sieve' Apr 15 13:49:41 lda(user(a)domain.com): Debug: sieve: file script: Opened script `File_Impersonal' from `/mail/domain.com/user/sieve/File_Impersonal.sieve' Apr 15 13:49:41 lda(user(a)domain.com): Debug: sieve: file script: Opened script `File_Travel' from `/mail/domain.com/user/sieve/File_Travel.sieve' Apr 15 13:49:41 lda(user(a)domain.com): Debug: sieve: file script: Opened script `File_Tribe' from `/mail/domain.com/user/sieve/File_Tribe.sieve' Apr 15 13:49:41 lda(user(a)domain.com): Debug: sieve: file script: Opened script `File_Info' from `/mail/domain.com/user/sieve/File_Info.sieve' Apr 15 13:49:41 lda(user(a)domain.com): Debug: sieve: file script: Opened script `File_Lists' from `/mail/domain.com/user/sieve/File_Lists.sieve' Apr 15 13:49:41 lda(user(a)domain.com): Debug: sieve: file script: Opened script `File_Trash' from `/mail/domain.com/user/sieve/File_Trash.sieve' Apr 15 13:49:41 lda(user(a)domain.com): Debug: sieve: file script: Opened script `File_Security' from `/mail/domain.com/user/sieve/File_Security.sieve' Apr 15 13:49:41 lda(user(a)domain.com): Debug: sieve: file script: Opened script `File_Notifications' from `/mail/domain.com/user/sieve/File_Notifications.sieve' Apr 15 13:49:41 lda(user(a)domain.com): Debug: sieve: file script: Opened script `File_Spam' from `/mail/domain.com/user/sieve/File_Spam.sieve' Apr 15 13:49:41 lda(user(a)domain.com): Debug: sieve: Script binary /mail/domain.com/user/.dovecot.svbin successfully loaded Apr 15 13:49:41 lda(user(a)domain.com): Debug: sieve: binary save: not saving binary /mail/domain.com/user/.dovecot.svbin, because it is already stored Apr 15 13:49:41 lda(user(a)domain.com): Debug: sieve: Executing script from `/mail/domain.com/user/.dovecot.svbin' Apr 15 13:49:41 lda(user(a)domain.com): Debug: Quota root: name=User quota backend=maildir args= Apr 15 13:49:41 lda(user(a)domain.com): Debug: Quota rule: root=User quota mailbox=* bytes=53687091200 messages=0 Apr 15 13:30:31 imap(user(a)domain.com): Debug: Loading modules from directory: /usr/local/lib/dovecot Apr 15 13:30:31 imap(user(a)domain.com): Debug: Module loaded: /usr/local/lib/dovecot/lib10_quota_plugin.so Apr 15 13:30:31 imap(user(a)domain.com): Debug: Module loaded: /usr/local/lib/dovecot/lib11_imap_quota_plugin.so Apr 15 13:30:31 imap(user(a)domain.com): Debug: Module loaded: /usr/local/lib/dovecot/lib15_notify_plugin.so Apr 15 13:30:31 imap(user(a)domain.com): Debug: Module loaded: /usr/local/lib/dovecot/lib20_fts_plugin.so Apr 15 13:30:31 imap(user(a)domain.com): Debug: Module loaded: /usr/local/lib/dovecot/lib20_mail_log_plugin.so Apr 15 13:30:31 imap(user(a)domain.com): Debug: Module loaded: /usr/local/lib/dovecot/lib21_fts_lucene_plugin.so Apr 15 13:30:31 imap(user(a)domain.com): Debug: Added userdb setting: plugin/quota_rule=*:bytes=0 Apr 15 13:30:31 imap(user(a)domain.com): Debug: Effective uid=5000, gid=5000, home=/mail/domain.com/user/ Apr 15 13:30:31 imap(user(a)domain.com): Debug: Quota root: name=User quota backend=maildir args= Apr 15 13:30:31 imap(user(a)domain.com): Debug: Quota rule: root=User quota mailbox=* bytes=0 messages=0 Apr 15 13:30:31 imap(user(a)domain.com): Debug: Quota rule: root=User quota mailbox=Trash bytes=0 (30%) messages=0 Apr 15 13:30:31 imap(user(a)domain.com): Debug: Quota rule: root=User quota mailbox=Sent bytes=0 (30%) messages=0 Apr 15 13:30:31 imap(user(a)domain.com): Debug: Quota warning: bytes=0 (90%) messages=0 reverse=no command=quota-warning 90 user(a)domain.com Apr 15 13:30:31 imap(user(a)domain.com): Debug: Quota warning: bytes=0 (75%) messages=0 reverse=no command=quota-warning 75 user(a)domain.com Apr 15 13:30:31 imap(user(a)domain.com): Debug: Quota grace: root=User quota bytes=0 (10%) Apr 15 13:30:31 imap(user(a)domain.com): Debug: Namespace inbox: type=private, prefix=, sep=, inbox=yes, hidden=no, list=yes, subscriptions=yes location=maildir:~:CONTROL=/var/no-quota/user@domain.com Apr 15 13:30:31 imap(user(a)domain.com): Debug: maildir++: root=/mail/domain.com/user/, index=, indexpvt=, control=/var/no-quota/user(a)domain.com, inbox=/mail/domain.com/user/, alt=

7 29

maildir, how to always add size tags to filename (,S=).
by Sergei Franco 19 Jun '15

19 Jun '15

Hi There, I have thoroughly read through documentation and wiki and I simply cannot find how to force dovecot to always add the size tag to the filename when using maildir format. We are using dovecot 2.2.9 (whatever comes from ubuntu 14.04 LTS). We are using dovecot in conjunction with exim with maidirsize file enabled and maildir quotas. For example exim has following configuration: maildir_tag = ,S=$message_size Which adds the size to the filename of the message. This has enormous (orders of magnitude) performance benefit as to calculate quota one does not need to stat every single file (only getents for each directory). I have wrote a script that adds the size tag retrospectively to files it didn't had it, and rebuild the dovecot index/cache if changes where made. This worked fine. Behaviour of dovecot is very peculiar: it generally adds the ,S= tag (along with ,W= tag) but occasionally it does not (I wander if it depends on the IMAP client). Is there anyway to force dovecot to add size tag to the files (like with exim example above)? Thank you very much. Sergei.

3 2

SOLR 5
by Robert Gierzinger 17 Jun '15

17 Jun '15

Hello, I just wanted to give SOLR 5 a try, however there probably have changed quite some bits in the config files, did not even manage to create a core with various solrconfig.xml and schema.xml files, but I am absolutely no expert in solr. Has anybody given it a try or are there some tips on how to get it running? regards, Robert

2 1