January 2014 - dovecot

[Dovecot] Dovecot quoting problem?
by Gerhard Wiesinger 07 May '14

07 May '14

Hello Timo, I think the following commit makes problems: http://hg.dovecot.org/dovecot-2.2/rev/68a8b650578e # Doesn't work A01 LIST "" ~/Mail/Gesendet # OK with quoted mailbox A02 LIST "" "~/Mail/Gesendet" Details: imap * PREAUTH [CAPABILITY IMAP4rev1 LITERAL+ SASL-IR LOGIN-REFERRALS ID ENABLE IDLE SORT SORT=DISPLAY THREAD=REFERENCES THREAD=REFS THREAD=ORDEREDSUBJECT MULTIAPPEND URL-PARTIAL CATENATE UNSELECT CHILDREN NAMESPACE UIDPLUS LIST-EXTENDED I18NLEVEL=1 CONDSTORE QRESYNC ESEARCH ESORT SEARCHRES WITHIN CONTEXT=SEARCH LIST-STATUS SPECIAL-USE BINARY MOVE] Logged in as user A01 LIST "" ~/Mail/Gesendet A01 BAD Error in IMAP command LIST: literal8 not allowed here A02 LIST "" "~/Mail/Gesendet" * LIST (\NoInferiors \UnMarked) "/" ~/Mail/Gesendet A02 OK List completed. A03 STATUS ~/Mail/Gesendet (MESSAGES UNSEEN RECENT) A03 BAD Error in IMAP command STATUS: literal8 not allowed here A04 STATUS "~/Mail/Gesendet" (MESSAGES UNSEEN RECENT) * STATUS ~/Mail/Gesendet (MESSAGES 0 RECENT 0 UNSEEN 0) A04 OK Status completed. Is this a bug of dovecot or a bug of the IMAP client (roundcube mail)? Thank you Ciao, Gerhard

2 2

[Dovecot] BUG report: doveadm HEADER <field> <pattern> when concatenating with another Search key
by megodin＠inboxalias.com 07 May '14

07 May '14

Hey there, I'm pretty sure I've found a bug with doveadm when concatenating with another search key. While doveadm HEADER <field pattern> works fine when not using additional search keys, it doesn't work properly when concatenating with other serarch keys - it then simply seems to ignore the additional HEADER <field pattern> search key. It's reproduceable, also with different user accounts on 2 different productive systems. Testing it on latest dovecot-ee 2.2.9.2 and 2.2.5.5. I think it's best explained with showing some examples: doveadm search -u exampleuser SUBJECT Silvester (outputs correctly 10 matches) 5a09f50926daef51b50e000025ab05f8 1106 5a09f50926daef51b50e000025ab05f8 1107 5a09f50926daef51b50e000025ab05f8 1579 5a09f50926daef51b50e000025ab05f8 4092 5a09f50926daef51b50e000025ab05f8 5330 5a09f50926daef51b50e000025ab05f8 9773 5a09f50926daef51b50e000025ab05f8 11460 5a09f50926daef51b50e000025ab05f8 12718 5a09f50926daef51b50e000025ab05f8 15653 5a09f50926daef51b50e000025ab05f8 15697 doveadm search -u exampleuser SUBJECT Silvester HEADER Return-Path someuser(a)example.com (gives exactly the same output - but this is WRONG, as the given Subject AND Return-Path is really only found in 1 Message - uid 15697) 5a09f50926daef51b50e000025ab05f8 1106 5a09f50926daef51b50e000025ab05f8 1107 5a09f50926daef51b50e000025ab05f8 1579 5a09f50926daef51b50e000025ab05f8 4092 5a09f50926daef51b50e000025ab05f8 5330 5a09f50926daef51b50e000025ab05f8 9773 5a09f50926daef51b50e000025ab05f8 11460 5a09f50926daef51b50e000025ab05f8 12718 5a09f50926daef51b50e000025ab05f8 15653 5a09f50926daef51b50e000025ab05f8 15697 doveadm search -u exampleuser HEADER Return-Path someuser(a)example.com (showing that Return-Path as standalone search key is working fine - note that message uid 15697 with subject "Silvester" is also found of course. I manually checked all Mails showing up here, they all contained the Return-Path "someuser(a)example.com" as they should): 5a09f50926daef51b50e000025ab05f8 14080 5a09f50926daef51b50e000025ab05f8 14814 5a09f50926daef51b50e000025ab05f8 14815 5a09f50926daef51b50e000025ab05f8 14820 5a09f50926daef51b50e000025ab05f8 14825 5a09f50926daef51b50e000025ab05f8 14830 5a09f50926daef51b50e000025ab05f8 14832 5a09f50926daef51b50e000025ab05f8 14833 5a09f50926daef51b50e000025ab05f8 15427 5a09f50926daef51b50e000025ab05f8 15428 5a09f50926daef51b50e000025ab05f8 15430 5a09f50926daef51b50e000025ab05f8 15431 5a09f50926daef51b50e000025ab05f8 15697 Further testing with: doveadm search -u exampleuser HEADER Return-Path completegarbageforsurenotinheaders (Correctly no output was given.) doveadm search -u exampleuser SUBJECT Silvester HEADER Return-Path completegarbageforsurenotinheaders (again ignoring the additional HEADER and showing all uids which just match the SUBJECT) 5a09f50926daef51b50e000025ab05f8 1106 5a09f50926daef51b50e000025ab05f8 1107 5a09f50926daef51b50e000025ab05f8 1579 5a09f50926daef51b50e000025ab05f8 4092 5a09f50926daef51b50e000025ab05f8 5330 5a09f50926daef51b50e000025ab05f8 9773 5a09f50926daef51b50e000025ab05f8 11460 5a09f50926daef51b50e000025ab05f8 12718 5a09f50926daef51b50e000025ab05f8 15653 5a09f50926daef51b50e000025ab05f8 15697 Moreove, when playing with HEADER Reply-To it shows some strange behaviour, note the differences with the ":" : doveadm search -u exampleuser SUBJECT blubbs HEADER Reply-to kacke(a)example.com f64cf50926daef51b50e000025ab05f8 2231 f64cf50926daef51b50e000025ab05f8 2781 5a09f50926daef51b50e000025ab05f8 13620 5a09f50926daef51b50e000025ab05f8 15763 doveadm search -u exampleuser SUBJECT blubbs HEADER Reply-to: kacke(a)example.com f64cf50926daef51b50e000025ab05f8 2231 5a09f50926daef51b50e000025ab05f8 13620 Can you please have a look at this and fix it? Thanks in advance, Megodin -- mailstorage @ NFS with nfsvers=3 (NetApp) # 2.2.5.5 (e5350245ad9b): /etc/dovecot/dovecot.conf # OS: Linux 2.6.32-358.23.2.el6.x86_64 x86_64 Red Hat Enterprise Linux Server release 6.4 (Santiago) nfs import_environment = TZ DEBUG_OUTOFMEM DOVECOT_HOSTDOMAIN # 2.2.9.2 (8d71ef248a6e): /etc/dovecot/dovecot.conf # OS: Linux 2.6.32-358.23.2.el6.x86_64 x86_64 CentOS release 6.5 (Final) nfs _________________________________________________________________ Send and receive anonymous emails to your inbox with InboxAlias. http://www.inboxalias.com

2 1

[Dovecot] New global ACL mailbox pattern feature in HG
by Thomas Leuxner 07 May '14

07 May '14

Hi, I played around with changeset 9376bf098692 a bit. Right now I'm unsure how to describe a namespace using this feature. Using something like 'Public/*" doesn't seem to work while 'Public*" does, but would also potentially alter non-related mailboxes elsewhere: $ cat global-acl INBOX owner lrwstiekxap Public* group=PublicMailboxAdmins lrwsik Regards Thomas

2 8

[Dovecot] SSL/TLS handshake stays forever without timeout
by morrison 07 May '14

07 May '14

Hi, I am a system admin and I am evaluating using dovecot as our email server. In my test, I found that if I telneted to 993 port and did not do anything or I telneted to 143 port, sent starttls command and then did not do anything, the connection stayed forever without timeout. This will make our mail server vulnerable to DOS attack. I dig into dovecot Wiki and did not find any solution. This seems to me that dovecot does not handle SSL/TLS handshake timeout. I am wondering if this is a known issue and will be fixed in near future. Thanks,

6 5

[Dovecot] nfs flush/fsync config settings problem
by Troton_admin 03 Apr '14

03 Apr '14

Hi, I need to place a maildir storage on a NFS filesystem, so I set up the config like this: mmap_disable = yes mail_nfs_storage = yes mail_nfs_index = yes mail_fsync = always lock_method = dotlock (also tried fcntl - local lockd is running, no success, now using dotlock, to be sure while debugging) The problem is that Dovecot (2.2.9/2.2.10 - the relevant code in mail-index.c is the same) logs a fatal error and quits the session (no daemon crash/coredump). Jan 07 14:13:31 auth: Debug: client in: AUTH 1 PLAIN service=pop3 session=fRCRJGHvbADDUKU9 lip=192.168.100.102 rip=IP_ADDR lport=1110 rport=48236 resp=AHRyb3RvbjEAdHJvdG9uMQ== (previous base64 data may contain sensitive data) Jan 07 14:13:31 auth: Debug: passwd-file(troton1,IP_ADDR,<fRCRJGHvbADDUKU9>): lookup: user=troton1 file=/usr/local/etc/dovecot/passwd-file Jan 07 14:13:31 auth: Debug: client passdb out: OK 1 user=troton1 Jan 07 14:13:31 auth: Debug: master in: REQUEST 1289355265 29049 1 4f9fdd9e4069fa503e8e6bcc09d4cf30 session_pid=29089 Jan 07 14:13:31 auth: Debug: passwd-file(troton1,IP_ADDR,<fRCRJGHvbADDUKU9>): lookup: user=troton1 file=/usr/local/etc/dovecot/passwd-file Jan 07 14:13:31 auth: Debug: master userdb out: USER 1289355265 troton1 uid=81 gid=81 home=/home/troton1 mail=maildir:~/Maildir Jan 07 14:13:31 pop3-login: Info: Login: user=<troton1>, method=PLAIN, rip=IP_ADDR, lip=192.168.100.102, mpid=29089, session=<fRCRJGHvbADDUKU9> Jan 07 14:13:31 pop3: Debug: Added userdb setting: mail=maildir:~/Maildir Jan 07 14:13:31 pop3(troton1): Debug: Effective uid=81, gid=81, home=/home/troton1 Jan 07 14:13:31 pop3(troton1): Debug: Namespace inbox: type=private, prefix=, sep=., inbox=yes, hidden=no, list=yes, subscriptions=yes location=maildir:~/Maildir Jan 07 14:13:31 pop3(troton1): Debug: maildir++: root=/home/troton1/Maildir, index=, indexpvt=, control=, inbox=/home/troton1/Maildir, alt= Jan 07 14:13:31 pop3(troton1): Info: DEBUG1: fsync_mode=2 , mask=0 Jan 07 14:13:31 pop3(troton1): Info: DEBUG2: fsync_mode=2 flags=85 Jan 07 14:13:31 pop3(troton1): Debug: Namespace : Using permissions from /home/troton1/Maildir: mode=0700 gid=default Jan 07 14:13:31 pop3(troton1): Info: DEBUG2: fsync_mode=0 flags=85 The user/passdb is just a plaintext file, for debugging purposes. But what is strange, the messages system log shows: Jan 7 14:13:31 mailhub2 dovecot: pop3(troton1): Fatal: nfs flush requires mail_fsync=always That is obviously wrong, even its own doveconf -n utility shows the correct value. # doveconf -n | grep -E 'sync|nfs' mail_fsync = always mail_nfs_index = yes mail_nfs_storage = yes maildir_very_dirty_syncs = yes Affected code seems to be in the lib-index/mail-index.c file, mail_index_file function - around line 585 : // my custom debug line i_info("DEBUG2: fsync_mode=%u flags=%u", (unsigned int)(index->fsync_mode),(unsigned int)flags); if ((flags & MAIL_INDEX_OPEN_FLAG_NFS_FLUSH) != 0 && index->fsync_mode != FSYNC_MODE_ALWAYS) i_fatal("nfs flush requires mail_fsync=always"); The first time it sees fsync_mode=2 (which is correct value of FSYNC_MODE_ALWAYS), but next function call is with index->fsync_mode=0 and an error is raised, see the logfile above. Dovecot correctly creates its working files in user's home directory - dovecot-uidlist, dovecot-uidvalidity, dovecot-uidvalidity.52cbfd7b, dovecot.index.log . The complete (testing, not production) doveconf -n is: == # 2.2.10: /usr/local/etc/dovecot/dovecot.conf # OS: FreeBSD 7.3-RELEASE-p3 amd64 auth_debug = yes auth_debug_passwords = yes auth_mechanisms = plain login auth_verbose = yes auth_verbose_passwords = sha1 default_process_limit = 200 disable_plaintext_auth = no first_valid_uid = 81 imap_client_workarounds = delay-newmail tb-extra-mailbox-sep info_log_path = /var/log/dovecot.log last_valid_uid = 81 listen = 192.168.100.102 lock_method = dotlock mail_debug = yes mail_fsync = always mail_gid = 81 mail_location = maildir:%h/Maildir mail_nfs_index = yes mail_nfs_storage = yes mail_prefetch_count = 5 mail_uid = 81 mailbox_list_index = yes maildir_stat_dirs = yes maildir_very_dirty_syncs = yes mmap_disable = yes namespace inbox { inbox = yes location = mailbox Sent { special_use = \Sent } mailbox "Sent Messages" { special_use = \Sent } mailbox Trash { special_use = \Trash } prefix = separator = . type = private } passdb { args = scheme=plain username_format=%n /usr/local/etc/dovecot/passwd-file driver = passwd-file } plugin { mail_log_events = delete undelete expunge copy mailbox_delete mailbox_rename mail_log_fields = uid box msgid subject size } pop3_enable_last = yes pop3_save_uidl = yes protocols = imap pop3 service doveadm { inet_listener { port = 9292 } } service imap-login { inet_listener imap { port = 1143 } } service imap { process_limit = 250 } service pop3-login { inet_listener pop3 { port = 1110 } } service pop3 { process_limit = 200 } ssl = no userdb { args = username_format=%n /usr/local/etc/dovecot/passwd-file default_fields = uid=81 gid=0 home=/home/%n driver = passwd-file } protocol imap { mail_max_userip_connections = 5 } protocol pop3 { mail_max_userip_connections = 5 } == OS: 7.3-RELEASE-p3 FreeBSD 7.3-RELEASE-p3 #1 amd64 Affected Dovecot version: 2.2.9, 2.2.10 How to repeat: Anytime I enter the correct username/pass pair And I tried to place the homedir on a local disk too, and I got the same error as on NFS. Any ideas, what could possibly be wrong ? Is it a feature or a bug ? Thanks for your help. Regards, Troton

3 2

[Dovecot] Is replication broken?
by IT geek 31 03 Apr '14

03 Apr '14

Hi, Apologies for this being my 248th post about replication... The current error I'm getting is: Jan 30 12:10:54 Server1 dovecot: dsync-local(MailUser1): Error: dsync( Server2.test.com) read() failed: read((fd)) failed: Connection reset by peer Subsequent errors are: Jan 30 12:15:47 Server1 dovecot: dsync-local(MailUser1): Error: read( Server2.test.com) failed: EOF The above error is seen on Server1, after the initial sync completes of the first mailbox (Sent folder to be precise). Does anyone have an ideas as to what might be causing it? These are brand new rebuilds, running the latest build - I just can't seem to get this working. Bug maybe? Configs are as follows: Server1: # 2.2.10: /usr/pkg/etc/dovecot/dovecot.conf # OS: NetBSD 5.2 cobalt auth_mechanisms = plain login doveadm_password = secret doveadm_port = 12345 first_valid_uid = 1003 last_valid_uid = 1020 listen = 192.168.1.1 login_greeting = test.com mail_location = mbox:~/mail:INBOX=/var/mail/%u mail_plugins = " notify replication" passdb { driver = passwd } plugin { mail_replica = tcp:Server2.test.com } protocols = imap service aggregator { fifo_listener replication-notify-fifo { mode = 0666 } unix_listener replication-notify { mode = 0600 } } service auth { unix_listener /var/spool/postfix/private/auth { group = postfix mode = 0660 user = postfix } user = root } service imap-login { inet_listener imap { port = 0 } } service replicator { process_min_avail = 1 unix_listener replicator-doveadm { mode = 0600 } } ssl_cert = </etc/openssl/certs/Server1.test.crt ssl_key = </etc/openssl/private/Server1.test.key userdb { driver = passwd } protocol lda { postmaster_address = postmaster(a)test.com } ServerB: # 2.2.10: /usr/pkg/etc/dovecot/dovecot.conf # OS: NetBSD 5.1 cobalt auth_mechanisms = plain login doveadm_password = secret doveadm_port = 12345 listen = 192.168.1.2 login_greeting = test.com mail_location = mbox:~/mail:INBOX=/var/mail/%u passdb { driver = passwd } protocols = imap service aggregator { fifo_listener replication-notify-fifo { mode = 0666 } unix_listener replication-notify { mode = 0600 } } service auth { unix_listener /var/spool/postfix/private/auth { group = postfix mode = 0660 user = postfix } user = root } service doveadm { inet_listener { port = 12345 } } service imap-login { inet_listener imap { port = 0 } } service replicator { process_min_avail = 1 unix_listener replicator-doveadm { mode = 0600 } } ssl_cert = </etc/openssl/certs/Server2.test.com.crt ssl_key = </etc/openssl/private/Server2.test.com.key userdb { driver = passwd } protocol lda { postmaster_address = postmaster(a)test.com }

4 15

[Dovecot] possible quota bug ?
by fernando.figaro＠uol.com.br 31 Mar '14

31 Mar '14

Hi, I'm using dovecot 2.2.5 with quota (maildir backend), zlib and expunge plugins. When I list maildirsize file, I get: 1073741824S 17952 16 If I receive a new message (example: 1204 bytes compressed and 2524 bytes plain text), the quota file is write correctly (2524 1 entry). When I move the message to trash folder (or between user custom folders) the file have wrong entries: 1073741824S 17952 16 2524 1 1204 1 (this is the size of the compressed message) -2524 -1 I coudn't find any relation with the config settings causing this problem and checked the changelog since 2.2.5. Had someone had this same problem? Thanks, Fernando

4 6

[Dovecot] dsync Error: Mailbox INBOX: Save commit failed: Mailbox was deleted under us
by Alan McGinlay - SICS 17 Mar '14

17 Mar '14

Hi, I am doing a mass migration of users from Cyrus imap on a solaris server to dovecot 1:2.2.9-1ubuntu1 and am getting this weird issue with dsync if I try to do a "full" sync. Debug output below: dsync(user(a)example.com): Error: Mailbox INBOX: Save commit failed: Mailbox was deleted under us dsync(user(a)example.com): Debug: brain M: out box 'INBOX' recv_state=recv_last_common send_state=done changed=1 dsync(user(a)example.com): Debug: brain M: out state=sync_mails changed=1 dsync(user(a)example.com): Debug: brain S: in state=sync_mails dsync(user(a)example.com): Debug: brain S: in box 'INBOX' recv_state=recv_last_common send_state=done dsync(user(a)example.com): Debug: brain S: out box 'INBOX' recv_state=recv_last_common send_state=done changed=0 dsync(user(a)example.com): Debug: brain S: out state=sync_mails changed=0 dsync(user(a)example.com): Debug: imapc(10.10.10.10:143): Disconnected [2]+ Killed /usr/bin/dsync -v -o mail_fsync=never backup -R -f -u user(a)example.com imapc: (I changed the domain / ip here of course) I notice that it does the IMAP sync for a while and then shows connecting info for pop3 (I have configuration for both imap and pop). The user in question has never connected with POP. imap migration config: imapc_host = 10.10.10.10 imapc_user = %u imapc_master_user = cyrusadmin imapc_password = blahblahblahpasswordhere imapc_features = rfc822.size imapc_features = $imapc_features #fetch-headers mail_prefetch_count = 20 pop configuration: pop3c_host = pop.example.com pop3c_user = %u pop3c_master_user = cyrusadmin pop3c_password = blahblahblahpasswordhere namespace { prefix = POP3-MIGRATION-NS/ location = pop3c: list = no hidden = yes } protocol doveadm { mail_plugins = $mail_plugins pop3_migration } plugin { pop3_migration_mailbox = POP3-MIGRATION-NS/INBOX } Thanks in advance for any pointers on this! /Alan

2 1

[Dovecot] panic with 2.2.10 and GETMETADATA
by Michael Cramer 16 Mar '14

16 Mar '14

i have in my configs the following lines: 10-mail.conf:mail_attribute_dict = file:/srv/vmail/dovecot/metadata/%d/%n/attributes 20-imap.conf:imap_metadata = yes when i test GETMETADATA with telnet i got a pannic in my error.log file and no attributes file in the given location is created root@i920:/etc/dovecot/conf.d# telnet localhost imap Trying 127.0.0.1... Connected to localhost. Escape character is '^]'. * OK [CAPABILITY IMAP4rev1 LITERAL+ SASL-IR LOGIN-REFERRALS ID ENABLE IDLE STARTTLS AUTH=PLAIN AUTH=LOGIN] Dovecot ready. 01 LOGIN tester(a)domain.com ********* 01 OK [CAPABILITY IMAP4rev1 LITERAL+ SASL-IR LOGIN-REFERRALS ID ENABLE IDLE SORT SORT=DISPLAY THREAD=REFERENCES THREAD=REFS THREAD=ORDEREDSUBJECT MULTIAPPEND URL-PARTIA L CATENATE UNSELECT CHILDREN NAMESPACE UIDPLUS LIST-EXTENDED I18NLEVEL=1 CONDSTORE QRESYNC ESEARCH ESORT SEARCHRES WITHIN CONTEXT=SEARCH LIST-STATUS SPECIAL-USE BINARY MOVE SEARCH=FUZZY NOTIFY METADATA COMPRESS=DEFLATE QUOTA ACL RIGHTS=texk] Logged in 02 GETMETADATA "*" (/shared/test) Connection closed by foreign host. in error.log i have these lines: Dec 23 17:20:00 imap(tester(a)domain.com): Panic: file imap-client.c: line 634 (client_command_free): assertion failed: (client->output_cmd_lock == NULL) Dec 23 17:20:00 imap(tester(a)domain.com): Error: Raw backtrace: /usr/lib/dovecot/libdovecot.so.0(+0x5e900) [0x7fb053bea900] -> /usr/lib/dovecot/libdovecot.so.0(+0x5e9de) [0x7fb053bea9de] -> /usr/lib/dovecot/libdovecot.so.0(i_fatal+0) [0x7fb053ba5bfe] -> dovecot/imap() [0x415c17] -> dovecot/imap() [0x415d8a] -> dovecot/imap() [0x415e15] -> dovecot/imap(client_handle_input+0x115) [0x416115] -> dovecot/imap(client_input+0x72) [0x4164a2] -> /usr/lib/dovecot/libdovecot.so.0(io_loop_call_io+0x27) [0x7fb053bfa8f7] -> /usr/lib/dovecot/libdovecot.so.0(io_loop_handler_run+0xd7) [0x7fb053bfb687] -> /usr/lib/dovecot/libdovecot.so.0(io_loop_run+0x38) [0x7fb053bfa498] -> /usr/lib/dovecot/libdovecot.so.0(master_service_run+0x13) [0x7fb053baadf3] -> dovecot/imap(main+0x2af) [0x40b06f] -> /lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0xf5) [0x7fb0537e5de5] -> dovecot/imap() [0x40b1cc] gdb with bt full gives: #0 0x00007f174b6bdf77 in raise () from /lib/x86_64-linux-gnu/libc.so.6 No symbol table info available. #1 0x00007f174b6c15e8 in abort () from /lib/x86_64-linux-gnu/libc.so.6 No symbol table info available. #2 0x00007f174baad8f6 in default_fatal_finish (type=<optimized out>, status=status@entry=0) at failures.c:193 backtrace = 0x1801040 "/usr/lib/dovecot/libdovecot.so.0(+0x5e900) [0x7f174baad900] -> /usr/lib/dovecot/libdovecot.so.0(+0x5e9de) [0x7f174baad9de] -> /usr/lib/dovecot/libdovecot.so.0(i_fatal+0) [0x7f174ba68bfe] -> dovecot/im"... #3 0x00007f174baad9de in i_internal_fatal_handler (ctx=0x7fffe2002eb0, format=<optimized out>, args=<optimized out>) at failures.c:657 status = 0 #4 0x00007f174ba68bfe in i_panic (format=format@entry=0x423040 "file %s: line %d (%s): assertion failed: (%s)") at failures.c:267 ctx = {type = LOG_TYPE_PANIC, exit_status = 0, timestamp = 0x0} args = {{gp_offset = 40, fp_offset = 48, overflow_arg_area = 0x7fffe2002fa0, reg_save_area = 0x7fffe2002ee0}} #5 0x0000000000415c17 in client_command_free (_cmd=_cmd@entry=0x7fffe2002fc8) at imap-client.c:634 cmd = 0x183a2d0 client = 0x18396f0 state = CLIENT_COMMAND_STATE_WAIT_INPUT __FUNCTION__ = "client_command_free" #6 0x0000000000415d8a in client_command_input (cmd=0x0) at imap-client.c:783 client = 0x18396f0 command = <optimized out> __FUNCTION__ = "client_command_input" #7 0x0000000000415e15 in client_command_input (cmd=0x183a2d0) at imap-client.c:841 client = 0x18396f0 command = <optimized out> __FUNCTION__ = "client_command_input" #8 0x0000000000416115 in client_handle_next_command (remove_io_r=<synthetischer Zeiger>, client=0x18396f0) at imap-client.c:879 No locals. #9 client_handle_input (client=client@entry=0x18396f0) at imap-client.c:891 _data_stack_cur_id = 3 remove_io = false handled_commands = false __FUNCTION__ = "client_handle_input" #10 0x00000000004164a2 in client_input (client=0x18396f0) at imap-client.c:933 cmd = 0x181db70 output = 0x183a120 bytes = 35 __FUNCTION__ = "client_input" #11 0x00007f174babd8f7 in io_loop_call_io (io=0x183a1f0) at ioloop.c:388 ioloop = 0x1808730 t_id = 2 #12 0x00007f174babe687 in io_loop_handler_run (ioloop=ioloop@entry=0x1808730) at ioloop-epoll.c:220 ctx = 0x18093c0 list = 0x180adf0 io = <optimized out> tv = {tv_sec = 1799, tv_usec = 999100} events_count = <optimized out> msecs = <optimized out> ret = 1 i = 0 call = <optimized out> __FUNCTION__ = "io_loop_handler_run" #13 0x00007f174babd498 in io_loop_run (ioloop=0x1808730) at ioloop.c:412 __FUNCTION__ = "io_loop_run" #14 0x00007f174ba6ddf3 in master_service_run (service=0x18085c0, callback=callback@entry=0x41eea0 <client_connected>) at master-service.c:566 No locals. #15 0x000000000040b06f in main (argc=1, argv=0x1808390) at main.c:400 set_roots = {0x426d00 <imap_setting_parser_info>, 0x0} login_set = {auth_socket_path = 0x1800048 "\001", postlogin_socket_path = 0x0, postlogin_timeout_secs = 60, callback = 0x41f250 <login_client_connected>, failure_callback = 0x41ef80 <login_client_failed>, request_auth_token = 1} service_flags = <optimized out> storage_service_flags = <optimized out> username = 0x0 c = <optimized out>

2 2

[Dovecot] Mbox corruption - Inbox beginning with 'FFrom' or 'FrFrom'
by Dimos Alevizos 08 Mar '14

08 Mar '14

Hello, we're having some problems with our dovecot setup. I've seen similar problems in the mailing list some years ago but alas wasn't able to find a solution. Our setup is as follows : An MX farm (postfix) sends mails via LMTP to a director farm (dovecot 2.1.12) which proxies pop3/imap/lmtp traffic to a dovecot farm (dovecot 2.1.16). All mailboxes and indexes are on NFS and all servers are Centos. The problem is that at times we see mailboxes (all of them are in mbox format) beginning with FFrom or FrFrom and of course dovecot says it's not a valid mbox file. If we manually remove the offending extra characters from the beginning of the file everything is working again, but often the same user will show the problem again tomorrow. However it's very rare and so far we haven't been able to reproduce the problem. After activating the mail_log plugin hoping it'll help us locate the problem we run across this case : The user (let's call him user(a)domain.gr) logs in via pop3 and deletes some mails but one of them fails: Jun 19 11:09:18 pop01 dovecot: pop3-login: Login: user=<user(a)domain.gr>, method=PLAIN, rip=83.235.173.26, lip=83.235.66.40, mpid=1389, secured, session=<Ao+rWH3fHgBT660a> Jun 19 11:09:18 director5 dovecot: pop3-login: proxy(user(a)domain.gr): started proxying to 83.235.66.40:110: user=<user(a)domain.gr>, method=PLAIN, rip=83.235.173.26, lip=83.235.66.65, session=<Ao+rWH3fHgBT660a> Jun 19 11:09:24 pop01 dovecot: pop3(user(a)domain.gr): expunge: box=INBOX, uid=20670, msgid=<9f5b1a20a9428ed31a9e7e42ce4411f08d0.20130612070424(a)mail84.us2.rsgsv.net>, size=36526 Jun 19 11:09:24 pop01 dovecot: pop3(user(a)domain.gr): expunge: box=INBOX, uid=20671, msgid=<b27d72dc5a47a3235a232494c6fe8aa0(a)newsletter.stockout.gr>, size=4637 Jun 19 11:09:24 pop01 dovecot: pop3(user(a)domain.gr): expunge: box=INBOX, uid=20672, msgid=<1113670779560.1111910791405.1470.2.32032003(a)scheduler.constantcontact.com>, size=38655 Jun 19 11:09:24 pop01 dovecot: pop3(user(a)domain.gr): expunge: box=INBOX, uid=20673, msgid=<83600a274c1407c5aa4c263e2592cb54(a)debop.gr>, size=1181688 Jun 19 11:09:24 pop01 dovecot: pop3(user(a)domain.gr): expunge: box=INBOX, uid=20674, msgid=<F2A59BE7-007A-4567-9BA5-803446C3D7F8(a)bernier-eliades.gr>, size=61116 Jun 19 11:09:26 pop01 dovecot: pop3(user(a)domain.gr): Error: Next message unexpectedly corrupted in mbox file /var/mail/K/Y/V/domain_gr_user_007 at 1 Jun 19 11:09:26 pop01 dovecot: pop3(user(a)domain.gr): Error: Cached message offset 1 is invalid for mbox file /var/mail/K/Y/V/domain_gr_user_007 Jun 19 11:09:27 pop01 dovecot: pop3(user(a)domain.gr): Disconnected: Logged out top=0/0, retr=2/1502843, del=122/359, size=137448432 Jun 19 11:09:27 pop01 dovecot: pop3(user(a)domain.gr): Warning: Our dotlock file /var/mail/K/Y/V/domain_gr_user_007.lock was deleted (locked 9 secs ago, touched 9 secs ago) Jun 19 11:09:27 pop01 dovecot: pop3(user(a)domain.gr): Error: file_dotlock_delete() failed with mbox file /var/mail/K/Y/V/domain_gr_user_007: No such file or directory Jun 19 11:09:27 director5 dovecot: pop3-login: proxy(user(a)domain.gr): disconnecting 83.235.173.26 (Disconnected by server): user=<user(a)domain.gr>, method=PLAIN, rip=83.235.173.26, lip=83.235.66.65, session=<Ao+rWH3fHgBT660a> However he's still able to log in again : Jun 19 11:11:36 pop01 dovecot: pop3-login: Login: user=<user(a)domain.gr>, method=PLAIN, rip=85.74.231.10, lip=83.235.66.40, mpid=10094, secured, session=<QDLrYH3f7ABVSucK> Jun 19 11:11:36 director3 dovecot: pop3-login: proxy(user(a)domain.gr): started proxying to 83.235.66.40:110: user=<user(a)domain.gr>, method=PLAIN, rip=85.74.231.10, lip=83.235.66.63, session=<QDLrYH3f7ABVSucK> Jun 19 11:11:51 pop01 dovecot: pop3(user(a)domain.gr): Disconnected: Logged out top=0/0, retr=0/0, del=0/237, size=75036938 Jun 19 11:11:51 director3 dovecot: pop3-login: proxy(user(a)domain.gr): disconnecting 85.74.231.10 (Disconnected by server): user=<user(a)domain.gr>, method=PLAIN, rip=85.74.231.10, lip=83.235.66.63, session=<QDLrYH3f7ABVSucK> A few minutes later he receives another mail which is delivered with no problem : Jun 19 11:30:39 corvus amavis[546]: (00546-22) Passed CLEAN, [91.190.168.40] [91.190.168.40] <tk-14439(a)free.splio.com> -> <user(a)domain.gr>, Message-ID: <58175-bWFyaW5hQGJlcm5pZXItZWxpYWR lcy5ncg==(a)free.splio.com>, mail_id: J1P-0WpmQksJ, Hits: 1.412, size: 9025, queued_as: 02BA4AE00414, Tests: [DKIM_VALID=-0.1,DKIM_VERIFIED=-0.1,FREEMAIL_FROM=0.001,HTML_IMAGE_RATIO_04=0.61,INVALID_MSGID=1,URIBL_BLOCKED=0.001], autolearn=disabled, 1533 ms Jun 19 11:30:39 corvus smtp/smtpd[1283]: proxy-accept: END-OF-MESSAGE: 250 2.0.0 from MTA(smtp:[127.0.0.1]:10025): 250 2.0.0 Ok: queued as 02BA4AE00414; from=<tk-14439(a)free.splio.com> to=<marina(a)bernier-eliades.gr> proto=ESMTP helo=<poc-pbcs2.splio.com> Jun 19 11:30:39 pop01 dovecot: lmtp(4099, user(a)domain.gr) 77O4IHlGwVEDEAAAYg/qxw: msgid=58175-bWFyaW5hQGJlcm5pZXItZWxpYWRlcy5ncg==(a)free.splio.com: from=residence.suddenly(a)gmx.com size=9610 saved mail to INBOX Jun 19 11:30:39 corvus postfix/lmtp[1350]: 02BA4AE00414: to=<user(a)domain.gr>, relay=lmtp.otenet.gr[62.103.147.209]:24, delay=0.12, delays=0.01/0/0/0.11, dsn=2.0.0, status=sent (250 2.0.0 <user(a)domain.gr> 77O4IHlGwVEDEAAAYg/qxw Saved) And then RIGHT after the successful delivery, the mbox somehow ends up corrupted with an FFrom in the beginning : Jun 19 11:31:27 pop01 dovecot: pop3-login: Login: user=<user(a)domain.gr>, method=PLAIN, rip=83.235.173.26, lip=83.235.66.40, mpid=14630, secured, session=<eBLjp33fUwBT660a> Jun 19 11:31:27 pop01 dovecot: pop3(user(a)domain.gr): Error: Syncing INBOX failed: Mailbox isn't a valid mbox file Jun 19 11:31:27 pop01 dovecot: pop3(user(a)domain.gr): Error: Couldn't init INBOX: Mailbox isn't a valid mbox file Jun 19 11:31:27 pop01 dovecot: pop3(user(a)domain.gr): Mailbox init failed top=0/0, retr=0/0, del=0/0, size=0 Jun 19 11:31:27 director5 dovecot: pop3-login: proxy(user(a)domain.gr): Login failed to 83.235.66.40:110: Mailbox isn't a valid mbox file Jun 19 11:31:27 pop01 dovecot: pop3-login: Login: user=<user(a)domain.gr>, method=PLAIN, rip=83.235.173.26, lip=83.235.66.40, mpid=14642, secured, session=<eBLjp33fUwBT660a> Jun 19 11:31:27 pop01 dovecot: pop3(user(a)domain.gr): Error: Syncing INBOX failed: Mailbox isn't a valid mbox file Jun 19 11:31:27 pop01 dovecot: pop3(user(a)domain.gr): Error: Couldn't init INBOX: Mailbox isn't a valid mbox file Jun 19 11:31:27 pop01 dovecot: pop3(user(a)domain.gr): Mailbox init failed top=0/0, retr=0/0, del=0/0, size=0 Jun 19 11:31:27 director5 dovecot: pop3-login: proxy(user(a)domain.gr): Login failed to 83.235.66.40:110: Mailbox isn't a valid mbox file Jun 19 11:31:27 director5 dovecot: pop3-login: Aborted login (proxy dest auth failed): user=<user(a)domain.gr>, method=PLAIN, rip=83.235.173.26, lip=83.235.66.65, session=<eBLjp33fUwBT660a Our config : # 2.1.16: /opt/dovecot-2.1.16/etc/dovecot/dovecot.conf # OS: Linux 2.6.18-92.1.22.el5 x86_64 CentOS release 5.9 (Final) auth_cache_negative_ttl = 10 mins auth_cache_size = 5 M auth_cache_ttl = 10 mins auth_verbose = yes default_client_limit = 5000 default_process_limit = 500 deliver_log_format = msgid=%m: from=%f size=%p %$ dict { sqlquota = mysql:/opt/dovecot/etc/dovecot/dovecot-dict-sql.conf.ext } disable_plaintext_auth = no first_valid_uid = 20 lda_mailbox_autocreate = yes lda_mailbox_autosubscribe = yes listen = * log_timestamp = "%Y-%m-%d %H:%M:%S " login_greeting = ready login_trusted_networks = 83.235.66.0/24 mail_access_groups = mail disk root mail_fsync = always mail_nfs_index = yes mail_nfs_storage = yes mail_plugins = quota 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 imapflags notify mbox_lock_timeout = 3 secs mbox_read_locks = dotlock fcntl mmap_disable = yes passdb { args = /opt/dovecot/etc/dovecot/dovecot-ldap.conf.ext driver = ldap } plugin { mail_log_events = delete undelete expunge copy mailbox_delete mailbox_rename flag_change append mail_log_fields = uid box msgid size quota = dict:User quota::noenforcing:proxy::sqlquota sieve = ~/.sieve sieve_dir = ~/sieve sieve_extensions = +notify +imapflags } postmaster_address = postmaster(a)otenet.gr quota_full_tempfail = yes service auth-worker { user = dovenull } service dict { unix_listener dict { group = mail mode = 0666 } } service imap-login { inet_listener imap { port = 143 } inet_listener imaps { port = 993 ssl = yes } } service lmtp { client_limit = 1 inet_listener lmtp { port = 24 } } service pop3-login { inet_listener pop3 { port = 110 } inet_listener pop3s { port = 995 ssl = yes } } service quota-warning { executable = script /opt/dovecot/etc/dovecot/quota-warning.sh user = dovecot } ssl = no userdb { args = /opt/dovecot/etc/dovecot/dovecot-ldap.conf.ext driver = ldap } verbose_proctitle = yes protocol lmtp { mail_plugins = quota sieve quota } protocol lda { mail_plugins = quota sieve quota } protocol imap { imap_client_workarounds = delay-newmail tb-extra-mailbox-sep mail_max_userip_connections = 100 mail_plugins = quota imap_quota quota notify mail_log } protocol pop3 { mail_max_userip_connections = 100 mail_plugins = quota quota mail_log notify pop3_client_workarounds = outlook-no-nuls oe-ns-eoh pop3_fast_size_lookups = yes pop3_lock_session = yes pop3_reuse_xuidl = yes pop3_uidl_format = %08Xu%08Xv } Thank you for your time. Dimos Alevizos

4 10