January 2013 - dovecot

[Dovecot] dovecot index errors since 2.1.12
by Morten Stevens 18 Apr '13

18 Apr '13

Hi, After upgrading to dovecot 2.1.12, I see a lot of these errors: # 2.1.12: /etc/dovecot/dovecot.conf # OS: Linux 2.6.32-279.14.1.el6.x86_64 x86_64 CentOS release 6.3 (Final) # Filesystem: ext4 with mdbox storage Dec 10 15:21:04 mail dovecot: imap(user(a)example.org): Error: Cached message size smaller than expected (5010 < 8192) Dec 10 15:21:04 mail dovecot: imap(user(a)example.org): Error: Corrupted index cache file /var/vmail/example.org/user//mdbox/mailboxes/INBOX/Ubuntu/dbox-Mails/dovecot.index.cache: Broken physical size for mail UID 27517 Dec 10 15:21:04 mail dovecot: imap(user(a)example.org): Error: read(/var/vmail/example.org/user//mdbox/storage/m.7123) failed: Input/output error (FETCH for mailbox INBOX/Ubuntu UID 27517) Dec 10 15:21:04 mail dovecot: imap(user(a)example.org): Disconnected: Internal error occurred. Refer to server log for more information. [2012-12-10 15:21:04] in=3391 out=1383967 Dec 17 21:38:34 mail dovecot: imap(user2(a)example.org): Error: Cached message size larger than expected (12222 > 12085) Dec 17 21:38:34 mail dovecot: imap(user2(a)example.org): Error: Corrupted index cache file /var/vmail/example.org/user2//mdbox/mailboxes/LKML/dbox-Mails/dovecot.index.cache: Broken physical size for mail UID 216231 Dec 17 21:38:34 mail dovecot: imap(user2(a)example.org): Error: read(/var/vmail/example.org/user2//mdbox/storage/m.15569) failed: Input/output error (FETCH for mailbox LKML UID 216231) Dec 17 21:38:34 mail dovecot: imap(user2(a)example.org): Disconnected: Internal error occurred. Refer to server log for more information. [2012-12-17 21:38:34] in=4079 out=61996358 Dec 17 21:40:34 mail dovecot: imap(user2(a)example.org): Error: Cached message size larger than expected (6726 > 5302) Dec 17 21:40:34 mail dovecot: imap(user2(a)example.org): Error: Corrupted index cache file /var/vmail/example.org/user2//mdbox/mailboxes/Google/dbox-Mails/dovecot.index.cache: Broken physical size for mail UID 930834 Dec 17 21:40:34 mail dovecot: imap(user2(a)example.org): Error: read(/var/vmail/example.org/user2//mdbox/storage/m.15544) failed: Input/output error (FETCH for mailbox Google UID 930834) Dec 17 21:40:34 mail dovecot: imap(user2(a)example.org): Disconnected: Internal error occurred. Refer to server log for more information. [2012-12-17 21:40:34] in=27666 out=29738162 Since the release of dovecot 2.1.x, I have never seen this error message. After downgrading to 2.1.10 the error is gone. Andy ideas? Best regards, Morten

3 18

[Dovecot] v2.1.11 soon
by Timo Sirainen 17 Apr '13

17 Apr '13

Just to let you know: I'm planning on releasing v2.1.11 today/tomorrow. If you wish to get something fixed for it, ask quickly. :)

8 15

[Dovecot] Released Pigeonhole v0.2.4 for Dovecot v2.0.14
by Stephan Bosch 26 Mar '13

26 Mar '13

Hello Dovecot users, I release a new version of Pigeonhole tonight. This release extends the configuration capabilities of the include and vacation extensions, adds the ihave extension (RFC 5463), and fixes a few small other things. Judging by Timo's plans, this will be one of the last feature releases for Dovecot v2.0, since I'll be switching active development to Dovecot v2.1 once that matures a little more. Changelog v0.2.4: + Vacation extension: finally added support for using the original recipient in vacation address check. It is also possible to disable the recipient address check entirely. Check doc/vacation.txt for configuration information. + Include extension: made limits on the include depth and the total number of included scripts configurable. Check doc/include.txt for configuration information. + Implemented ihave extension. This allows checking for the availability of Sieve language extensions at 'runtime'. Actually, this is checked at compile time. At runtime the interpreter checks whether extensions that were not previously available are still unavailable. If the situation changed, the script is re-compiled and the ihave tests are evaluated again. + Sieve: optimized compilation of tests that yield constant results (i.e. known at compile tme), such as 'true' and 'false'. No code is produced anymore for script sections that are never executed. Also, semantics are not verified anymore in uncompiled script sections. + Made vnd.dovecot.debug extension available to the LDA plugin instead of only the command line tools. + Sieve: redirect action now adds X-Sieve-Redirected-From header (mainly for people using SPF/SRS). - Sieve: fixed bug in handling flags and keywords; in case of error an assertion was triggered. - Script storage: improved handling of unconfigured user home directory. Originally this would produce an unhelpful error message. - Imap4flags extension: prevent forcibly enabling imap4flags when imapflags is enabled. - Fixed various -Wunused-but-set-variable compiler warnings. - Include extension: forgot to check variable identifier syntax for 'global' command. - Sieve: fixed debug mode; no messages were logged in some situations. - sievec tool: forgot to enable -D (debug) parameter. The release is available as follows: http://www.rename-it.nl/dovecot/2.0/dovecot-2.0-pigeonhole-0.2.4.tar.gz http://www.rename-it.nl/dovecot/2.0/dovecot-2.0-pigeonhole-0.2.4.tar.gz.sig Refer to http://pigeonhole.dovecot.org and the Dovecot v2.0 wiki for more information. Have fun testing this new release and don't hesitate to notify me when there are any problems. Regards, -- Stephan Bosch stephan(a)rename-it.nl

2 1

[Dovecot] doveadm with multiple commands
by Timo Sirainen 25 Mar '13

25 Mar '13

This has been in my TODO for a while and today I implemented it (but didn't dare to test it yet :) So the problem has been that you want to run for example: doveadm expunge -A mailbox Trash savedbefore 7d doveadm purge -A This is annoying because it scans through the users' mailboxes twice, wasting disk IO and CPU. So how to make it do the scan only once? The syntax I thought of today would be: doveadm multi [-A | -u wildcards] <separator string> <comand 1> [<separator string> <command 2> [...]] So the first two commands could be for example: doveadm multi -A : expunge mailbox Trash savedbefore 7d : purge The ':' character is the separator. Any other string could be used as well, for example "?SEP?" or whatever. Thoughts? Any better name for the command than "multi"?

6 13

[Dovecot] virtual folder - crash while searching
by Matthias Rieber 10 Mar '13

10 Mar '13

Hi, I've upgraded from dovecot 2.0 to 2.1. When I perform a header search in a virtual folder dovecot crashes. Here's the stacktrace: http://pastebin.com/urSDDzku Regards, Matthias

4 11

[Dovecot] Broken physical size caching in Dovecot 2.1.10
by Rob Redpath 06 Mar '13

06 Mar '13

Hi, I'm encountering two, probably related, errors in my Dovecot 2.1.10 install. The issue relates to compressed email stored in Maildir format directories. In some cases, a mailbox will become inaccessible, and the following will be logged from a doveadm fetch:- doveadm(info(a)example.com): Error: Corrupted index cache file /var/spool/virtual_mail/info_example.com_d/dovecot.index.cache: Broken physical size for mail UID 2777 doveadm(info(a)example.com): Error: Cached message size smaller than expected (18996 < 64624) doveadm(info(a)example.com): Error: Maildir filename has wrong S value, renamed the file from /var/spool/virtual_mail/info_example.com_d/cur/1277451630.H877760P14612.mailserver.example.com,S=18996:2,Z to /var/spool/virtual_mail/info_example.com_d/cur/1277451630.H877760P14612.mailserver.example.com,S=18996:2,Z Interestingly, the file mentioned in the error ( /var/spool/virtual_mail/info_example.com_d/dovecot.index.cache ) doesn't exist. The uncompressed size of the file is 64624 bytes, the compressed size is 18996. My attempts to debug the issue myself didn't get very far - the function that appears to return the wrong value is in /src/lib-storage/index/maildir/maildir-mail.c in the 2.1.13 source; it's do_fix_size() and appears to not consider whether a file is compressed or not when reporting it's size for S= value purposes. Can anyone help? I'm happy to provide parts of dovecot -n output if required, but I'd rather not post configuration in a public forum if it's not required. -- Rob Redpath Systems Administrator Heart Internet Ltd E: rob.redpath(a)heartinternet.co.uk DDI: 0115 845 6643 www.heartinternet.co.uk<http://www.heartinternet.co.uk> ****************************************************************** This email and any files transmitted with it are confidential and intended solely for the use of the individual or entity to whom they are addressed. If you are not the intended recipient you are not authorised to and must not disclose, copy, distribute, or retain this message or any part of it. Heart Internet Ltd accepts no responsibility for information, errors or omissions in this email. ******************************************************************

3 13

[Dovecot] 2.1.12: Panic: file solr-connection.c: line 547 (solr_connection_post_more)
by Marc Schiffbauer 26 Feb '13

26 Feb '13

Hi all, I am having a problem indexing one of my mailboxes using the solr fts backend in dovecot 2.1.12 For many mailboxes it works just fine, but on one mailbox I currently always get a panic. solr setup: Java: icedtea 6.1.11.5 Solr: 3.6.2 running in tomcat 7.0.32 Command to reproduce error: doveadm index -u my@user badmailbox I already noticed that there have been some solr backend fixes just before 2.1.21 release... Is this another bug in the backend? Any idea? IMO relevant logs line parts: java.io.CharConversionException: Invalid UTF-8 start byte 0xf8 (at char #483989, byte #532382) complete dovecot log: doveadm(my@user): Error: fts_solr: Invalid XML input at 85:198: mismatched tag (near: <html><head><title>Apache Tomcat/7.0.32-gentoo - Error report</title><style><!--H1 {font-family:Tahoma,Arial,sans-serif;color:wh) doveadm(my@user): Panic: file solr-connection.c: line 547 (solr_connection_post_more): assertion failed: (maxfd >= 0) doveadm(my@user): Error: Raw backtrace: /usr/lib64/dovecot/libdovecot.so.0(+0x4bcdb) [0x34fbd53ecdb] -> /usr/lib64/dovecot/libdovecot.so.0(default_fatal_handler+0x3a) [0x34fbd53edb8] -> /usr/lib64/dovecot/libdovecot.so.0(i_fatal+0) [0x34fbd50eeac] -> /usr/lib64/dovecot/lib21_fts_solr_plugin.so(solr_connection_post_more+0x2a4) [0x34fbba81072] -> /usr/lib64/dovecot/lib21_fts_solr_plugin.so(+0x40a5) [0x34fbba7d0a5] -> /usr/lib64/dovecot/lib20_fts_plugin.so(fts_build_mail+0x462) [0x34fbbc8d6dc] -> /usr/lib64/dovecot/lib20_fts_plugin.so(+0xd8c2) [0x34fbbc928c2] -> doveadm(+0x17a30) [0x264ecb7a30] -> doveadm(+0x13a45) [0x264ecb3a45] -> doveadm(+0x14762) [0x264ecb4762] -> doveadm(doveadm_mail_try_run+0x173) [0x264ecb4cfd] -> doveadm(main+0x3e9) [0x264ecbd0d5] -> /lib64/libc.so.6(__libc_start_main+0xfd) [0x34fbd16a48d] -> doveadm(+0x13809) [0x264ecb3809] Aborted complete java exception: Dec 31, 2012 4:12:58 AM org.apache.solr.core.SolrCore execute INFO: [] webapp=/solr-web path=/update params={} status=500 QTime=118 Dec 31, 2012 4:12:58 AM org.apache.solr.common.SolrException log SEVERE: java.lang.RuntimeException: [was class java.io.CharConversionException] Invalid UTF-8 start byte 0xf8 (at char #483989, byte #532382) at com.ctc.wstx.util.ExceptionUtil.throwRuntimeException(ExceptionUtil.java:18) at com.ctc.wstx.sr.StreamScanner.throwLazyError(StreamScanner.java:731) at com.ctc.wstx.sr.BasicStreamReader.safeFinishToken(BasicStreamReader.java:3657) at com.ctc.wstx.sr.BasicStreamReader.getText(BasicStreamReader.java:809) at org.apache.solr.handler.XMLLoader.readDoc(XMLLoader.java:315) at org.apache.solr.handler.XMLLoader.processUpdate(XMLLoader.java:156) at org.apache.solr.handler.XMLLoader.load(XMLLoader.java:79) at org.apache.solr.handler.ContentStreamHandlerBase.handleRequestBody(ContentStreamHandlerBase.java:58) at org.apache.solr.handler.RequestHandlerBase.handleRequest(RequestHandlerBase.java:129) at org.apache.solr.core.SolrCore.execute(SolrCore.java:1376) at org.apache.solr.servlet.SolrDispatchFilter.execute(SolrDispatchFilter.java:365) at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:260) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(Unknown Source) at org.apache.catalina.core.ApplicationFilterChain.doFilter(Unknown Source) at org.apache.catalina.core.StandardWrapperValve.invoke(Unknown Source) at org.apache.catalina.core.StandardContextValve.invoke(Unknown Source) at org.apache.catalina.authenticator.AuthenticatorBase.invoke(Unknown Source) at org.apache.catalina.core.StandardHostValve.invoke(Unknown Source) at org.apache.catalina.valves.ErrorReportValve.invoke(Unknown Source) at org.apache.catalina.valves.AccessLogValve.invoke(Unknown Source) at org.apache.catalina.core.StandardEngineValve.invoke(Unknown Source) at org.apache.catalina.connector.CoyoteAdapter.service(Unknown Source) at org.apache.coyote.http11.AbstractHttp11Processor.process(Unknown Source) at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(Unknown Source) at org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(Unknown Source) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603) at java.lang.Thread.run(Thread.java:679) Caused by: java.io.CharConversionException: Invalid UTF-8 start byte 0xf8 (at char #483989, byte #532382) at com.ctc.wstx.io.UTF8Reader.reportInvalidInitial(UTF8Reader.java:302) at com.ctc.wstx.io.UTF8Reader.read(UTF8Reader.java:188) at com.ctc.wstx.io.ReaderSource.readInto(ReaderSource.java:84) at com.ctc.wstx.io.BranchingReaderSource.readInto(BranchingReaderSource.java:57) at com.ctc.wstx.sr.StreamScanner.loadMore(StreamScanner.java:992) at com.ctc.wstx.sr.BasicStreamReader.readTextSecondary(BasicStreamReader.java:4628) at com.ctc.wstx.sr.BasicStreamReader.readCoalescedText(BasicStreamReader.java:4126) at com.ctc.wstx.sr.BasicStreamReader.finishToken(BasicStreamReader.java:3701) at com.ctc.wstx.sr.BasicStreamReader.safeFinishToken(BasicStreamReader.java:3649) ... 25 more TIA -Marc -- [*] sys4 AG http://sys4.de, +49 (89) 30 90 46 64 Franziskanerstraße 15, 81669 München Sitz der Gesellschaft: München, Amtsgericht München: HRB 199263 Vorstand: Patrick Ben Koetter, Axel von der Ohe, Marc Schiffbauer Aufsichtsratsvorsitzender: Joerg Heidrich

4 9

[Dovecot] doveadm user error messages
by Thomas Leuxner 22 Feb '13

22 Feb '13

I use 'doveadm user' in some scripts and the exit codes are fine for my purposes. During tests it transpired that Dovecot 2.1 would give an error message when querying for non-existent users. Dovecot 2.2 just exits without a word. Not sure this is intended behaviour: $ doveadm user foo $ echo $? 67 $ id foo id: foo: No such user Regards Thomas

2 2

[Dovecot] assert in mail-transaction-log-file.c
by Anton Yuzhaninov 22 Feb '13

22 Feb '13

I setup new server with dovecot 2.1.12 and mboxes from backup (moboxes was used with dovecot 1.1.6). OS: FreeBSD 8.3-STABLE, amd64. All index files from dovecot 1.1.6 has been deleted. Some times dovecot processes aborted. E. g. Jan 25 03:01:52 ost dovecot: lda(user(a)example.ru): Panic: file mail-transaction-log-file.c: line 1694 (mail_transaction_log_file_map): assertion failed: (file->buffer != NULL) (gdb) bt #0 0x0000000800bd610c in kill () from /lib/libc.so.7 #1 0x0000000800bd4f0b in abort () from /lib/libc.so.7 #2 0x000000080099b339 in default_fatal_finish (type=72898, status=0) at failures.c:191 #3 0x000000080099b3be in i_syslog_fatal_handler (ctx=<value optimized out>, format=<value optimized out>, args=<value optimized out>) at failures.c:413 #4 0x000000080099a8a3 in i_panic (format=<value optimized out>) at failures.c:263 #5 0x000000080081bdb6 in mail_transaction_log_file_map (file=0x801670e00, start_offset=40, end_offset=18446744073709551615) at mail-transaction-log-file.c:1694 #6 0x000000080081da41 in mail_transaction_log_view_set (view=0x801654a80, min_file_seq=1, min_file_offset=40, max_file_seq=2, max_file_offset=18446744073709551615, reset_r=0x7fffffffbedf) at mail-transaction-log-view.c:228 #7 0x000000080081519d in mail_index_sync_map (_map=0x801670b08, type=MAIL_INDEX_SYNC_HANDLER_HEAD, force=false) at mail-index-sync-update.c:950 #8 0x0000000800805be0 in mail_index_map (index=0x801670a80, type=MAIL_INDEX_SYNC_HANDLER_HEAD) at mail-index-map-read.c:415 #9 0x0000000800800bde in mail_index_refresh (index=<value optimized out>) at mail-index.c:735 #10 0x00000008007b2344 in mbox_sync_header_refresh (mbox=0x801680840) at mbox-sync.c:1652 #11 0x00000008007b24e2 in mbox_sync_has_changed_full (mbox=0x801680840, leave_dirty=true, empty_r=0x7fffffffe2e8) at mbox-sync.c:1729 #12 0x00000008007ae1a7 in mbox_save_begin (_ctx=0x80161a500, input=0x801669660) at mbox-save.c:296 #13 0x00000008018025ae in notify_save_begin (ctx=0x80161a500, input=0x801669660) at notify-storage.c:130 #14 0x00000008014261fd in quota_save_begin (ctx=0x80161a500, input=0x801669660) at quota-storage.c:251 #15 0x00000008007cfecc in mailbox_save_begin (ctx=0x7fffffffe3d0, input=0x801669660) at mail-storage.c:1652 #16 0x00000008007ca48d in mail_storage_copy (ctx=0x80161a500, mail=0x801637040) at mail-copy.c:68 #17 0x000000080180269d in notify_copy (ctx=0x80161a500, mail=0x801637040) at notify-storage.c:105 #18 0x00000008014262f6 in quota_copy (ctx=0x80161a500, mail=0x801637040) at quota-storage.c:200 #19 0x00000008007cfe04 in mailbox_copy (_ctx=<value optimized out>, mail=0x801637040) at mail-storage.c:1721 #20 0x0000000801b4b706 in act_store_execute (action=<value optimized out>, aenv=0x8016a3070, tr_context=<value optimized out>) at sieve-actions.c:551 #21 0x0000000801b428de in sieve_result_execute (result=0x8016a3040, keep=0x0) at sieve-result.c:1117 #22 0x0000000801b52d5a in sieve_execute (sbin=<value optimized out>, msgdata=<value optimized out>, senv=<value optimized out>, ehandler=<value optimized out>, flags=<value optimized out>, keep=0x0) at sieve.c:508 #23 0x0000000801a0aec6 in lda_sieve_deliver_mail (mdctx=0x7fffffffe970, storage_r=0x7fffffffe8e8) at lda-sieve-plugin.c:424 #24 0x0000000800651735 in mail_deliver (ctx=0x7fffffffe970, storage_r=0x7fffffffe8e8) at mail-deliver.c:390 #25 0x0000000000402ffa in main (argc=6, argv=0x7fffffffea78) at main.c:434 (gdb) f 5 (gdb) p *file $1 = {log = 0x8016463d0, next = 0x0, refcount = 5, filepath = 0x801620420 "(in-memory index).log", fd = -1, st_ino = 13919248, st_dev = 109, last_mtime = 1359082912, last_size = 0, hdr = {major_version = 1 '\001', minor_version = 2 '\002', hdr_size = 40, indexid = 1359082912, file_seq = 2, prev_file_seq = 0, prev_file_offset = 0, create_stamp = 1359082912, initial_modseq = 0, compat_flags = 1 '\001', unused = "\000\000", unused2 = 0}, mmap_buffer = {data = 0x0, used = 0, priv = {0x0, 0x0, 0x0, 0x0, 0x0}}, buffer = 0x0, buffer_offset = 0, mmap_base = 0x0, mmap_size = 0, sync_offset = 40, sync_highest_modseq = 0, saved_tail_offset = 0, max_tail_offset = 0, saved_tail_sync_offset = 0, index_deleted_offset = 0, index_undeleted_offset = 0, modseq_cache = {{offset = 0, highest_modseq = 0}, {offset = 0, highest_modseq = 0}, { offset = 0, highest_modseq = 0}, {offset = 0, highest_modseq = 0}, {offset = 0, highest_modseq = 0}, {offset = 0, highest_modseq = 0}, {offset = 0, highest_modseq = 0}, { offset = 0, highest_modseq = 0}, {offset = 0, highest_modseq = 0}, {offset = 0, highest_modseq = 0}}, file_lock = 0x0, lock_created = 0, locked = 0, locked_sync_offset_updated = 0, corrupted = 0} Also same aborts can happen in imap processes: Jan 24 16:35:04 ost dovecot: imap(user(a)example.ru): Panic: file mail-transaction-log-file.c: line 1694 (mail_transaction_log_file_map): assertion failed: (file->buffer != NULL) -- Anton Yuzhaninov

2 2

[Dovecot] pop3_lock_session and mdbox format
by Ewald Dieterich 22 Feb '13

22 Feb '13

Setting "pop3_lock_session = yes" in the configuration has no effect when I use Dovecot 2.1.13 with the mdbox format. A second POP3 connection to the same mailbox is still allowed. Grepping for MAILBOX_FLAG_KEEP_LOCKED in the source code shows that POP3 session locking only works for the Maildir and mbox formats. Is it possible to enable it for the mdbox format, as well? Ewald

2 1