May 2010 - dovecot - dovecot.org

[Dovecot] dovecot 2 beta4 errors & core dumps
by de Lafond Guillaume 07 Jun '10

07 Jun '10

Hi, While running imaptest with "clients=50 seed=123 msgs=100000000 random secs=600", I got errors : "Error: user(a)domain.com[55]: Unexpected BYE: * BYE IMAP session state is inconsistent, please relogin.". dovecot.log : Apr 03 10:23:47 imap(user(a)domain.com): Panic: file index- transaction.c: line 145 (index_transaction_rollback): assertion failed: (box->transaction_count > 0 || box->view->transactions == 0) Apr 03 10:23:47 imap(user(a)domain.com): Error: Raw backtrace: /usr/ local/dovecot2/lib/dovecot/libdovecot.so.0 [0xb7e9adc1] -> /usr/local/ dovecot2/lib/dovecot/libdovecot.so.0 [0xb7e9ae3f] -> /usr/local/ dovecot2/lib/dovecot/libdovecot.so.0(i_error+0) [0xb7e9b0f8] -> /usr/ local/dovecot2/lib/dovecot/libdovecot-storage.so.0 [0xb7f3e9c2] -> / usr/local/dovecot2/lib/dovecot/lib10_quota_plugin.so [0xb7cdaaea] -> / usr/local/dovecot2/lib/dovecot/libdovecot-storage.so. 0(mailbox_transaction_rollback+0x20) [0xb7ef03f0] -> /usr/local/ dovecot2/lib/dovecot/lib10_quota_plugin.so [0xb7cda323] -> /usr/local/ dovecot2/lib/dovecot/lib10_quota_plugin.so [0xb7cda4df] -> /usr/local/ dovecot2/lib/dovecot/libdovecot-storage.so.0(maildir_sync_index+0x897) [0xb7f52bb7] -> /usr/local/dovecot2/lib/dovecot/libdovecot-storage.so. 0(maildir_transaction_save_commit_pre+0x710) [0xb7f50f70] -> /usr/ local/dovecot2/lib/dovecot/libdovecot-storage.so.0 [0xb7f3ee27] -> / usr/local/dovecot2/lib/dovecot/libdovecot-storage.so. 0(mail_index_transaction_commit_full+0x85) [0xb7f08ee5] -> /usr/local/ dovecot2/lib/dovecot/libdovecot-storage.so.0(index_transaction_commit +0x83) [0xb7f3ea53] -> /usr/local/dovecot2/lib/dovecot/ lib10_quota_plugin.so [0xb7cdab81] -> /usr/local/dovecot2/lib/dovecot/ libdovecot-storage.so.0(mailbox_transaction_commit_get_changes+0x42) [0xb7ef0c72] -> dovecot/imap [user(a)domain.com 10.0.0.5 APPEND] [0x804eab2] -> dovecot/imap [user(a)domain.com 10.0.0.5 APPEND] [0x804e8cb] -> dovecot/imap [user(a)domain.com 10.0.0.5 APPEND] [0x804ed02] -> dovecot/imap [user(a)domain.com 10.0.0.5 APPEND] (cmd_append+0x1d9) [0x804f069] -> dovecot/imap [user(a)domain.com 10.0.0.5 APPEND] [0x80562dc] -> dovecot/imap [user(a)domain.com 10.0.0.5 APPEND] [0x8056379] -> dovecot/imap [user(a)domain.com 10.0.0.5 APPEND] (client_handle_input+0x2d) [0x80564ed] -> dovecot/imap [user(a)domain.com 10.0.0.5 APPEND](client_input+0x5f) [0x8056f0f] -> / usr/local/dovecot2/lib/dovecot/libdovecot.so.0(io_loop_handler_run +0xf5) [0xb7ea7425] -> /usr/local/dovecot2/lib/dovecot/libdovecot.so. 0(io_loop_run+0x30) [0xb7ea6470] -> /usr/local/dovecot2/lib/dovecot/ libdovecot.so.0(master_service_run+0x2a) [0xb7e93eaa] -> dovecot/imap [user(a)domain.com 10.0.0.5 APPEND](main+0x2ad) [0x805f9ed] -> /lib/i686/cmov/libc.so. 6(__libc_start_main+0xe5) [0xb7d0f455] Apr 03 10:23:47 master: Error: service(imap): child 27371 killed with signal 6 (core dumped) Apr 03 10:23:50 imap(user(a)domain.com): Error: dotlock /var/mail/d/ domain.com/user/Maildir/dovecot-uidlist.lock was immediately deleted under us Apr 03 10:23:50 imap(user(a)domain.com): Error: dotlock /var/mail/d/ domain.com/user/Maildir/dovecot-uidlist.lock was immediately deleted under us Apr 03 10:23:50 imap(user(a)domain.com): Warning: Our dotlock file /var/ mail/d/domain.com/user/Maildir/dovecot-uidlist.lock was deleted (locked 0 secs ago, touched 0 secs ago) Apr 03 10:23:50 imap(user(a)domain.com): Warning: Our dotlock file /var/ mail/d/domain.com/user/Maildir/dovecot-uidlist.lock was deleted (locked 0 secs ago, touched 0 secs ago) Apr 03 10:23:50 imap(user(a)domain.com): Error: Log synchronization error at seq=2,offset=8188 for /var/mail/dovecot_indexes/d/domain.com/ user/.INBOX/dovecot.index: Append with UID 32, but next_uid = 33 Apr 03 10:23:50 imap(user(a)domain.com): Warning: fscking index file / var/mail/dovecot_indexes/d/domain.com/user/.INBOX/dovecot.index Apr 03 10:23:50 imap(user(a)domain.com): Error: Log synchronization error at seq=2,offset=8188 for /var/mail/dovecot_indexes/d/domain.com/ user/.INBOX/dovecot.index: Append with UID 32, but next_uid = 33 Apr 03 10:23:50 imap(user(a)domain.com): Warning: fscking index file / var/mail/dovecot_indexes/d/domain.com/user/.INBOX/dovecot.index Apr 03 10:23:50 imap(user(a)domain.com): Warning: Our dotlock file /var/ mail/d/domain.com/user/Maildir/dovecot-uidlist.lock was overridden (locked 0 secs ago, touched 0 secs ago) Apr 03 10:23:50 imap(user(a)domain.com): Error: dotlock /var/mail/d/ domain.com/user/Maildir/dovecot-uidlist.lock was immediately recreated under us Apr 03 10:23:50 imap(user(a)domain.com): Error: Log synchronization error at seq=2,offset=8188 for /var/mail/dovecot_indexes/d/domain.com/ user/.INBOX/dovecot.index: Append with UID 32, but next_uid = 33 Apr 03 10:23:50 imap(user(a)domain.com): Warning: fscking index file / var/mail/dovecot_indexes/d/domain.com/user/.INBOX/dovecot.index The backtrace : Core was generated by `dovecot/imap'. Program terminated with signal 6, Aborted. [New process 27371] #0 0xb7f85424 in __kernel_vsyscall () (gdb) bt full #0 0xb7f85424 in __kernel_vsyscall () No symbol table info available. #1 0xb7d24640 in raise () from /lib/i686/cmov/libc.so.6 No symbol table info available. #2 0xb7d26018 in abort () from /lib/i686/cmov/libc.so.6 No symbol table info available. #3 0xb7e9add5 in default_fatal_finish (type=<value optimized out>, status=0) at failures.c:164 backtrace = 0x80643d0 "/usr/local/dovecot2/lib/dovecot/libdovecot.so. 0 [0xb7e9adc1] -> /usr/local/dovecot2/lib/dovecot/libdovecot.so.0 [0xb7e9ae3f] -> /usr/local/dovecot2/lib/dovecot/libdovecot.so.0(i_error +0) [0xb7e9b0f8] "... #4 0xb7e9ae3f in i_internal_fatal_handler (type=LOG_TYPE_PANIC, status=0, fmt=0xb7f6f1c4 "file %s: line %d (%s): assertion failed: (%s)", args=0xbfffda44 "\2228??\221") at failures.c:592 No locals. #5 0xb7e9b0f8 in i_panic (format=0xb7f6f1c4 "file %s: line %d (%s): assertion failed: (%s)") at failures.c:230 No locals. #6 0xb7f3e9c2 in index_transaction_rollback (t=0x80b2a90) at index- transaction.c:144 box = (struct mailbox *) 0x808d340 itrans = (struct mail_index_transaction *) 0x0 __FUNCTION__ = "index_transaction_rollback" #7 0xb7cdaaea in quota_mailbox_transaction_rollback (ctx=0x80b2a90) at quota-storage.c:112 qt = (struct quota_transaction_context *) 0x80a9628 #8 0xb7ef03f0 in mailbox_transaction_rollback (_t=0x808d780) at mail- storage.c:1155 t = (struct mailbox_transaction_context *) 0x6aeb #9 0xb7cda323 in quota_mailbox_sync_cleanup (qbox=0x808d6c0) at quota- storage.c:246 No locals. #10 0xb7cda4df in quota_mailbox_sync_notify (box=0x808d340, uid=0, sync_type=<value optimized out>) at quota-storage.c:274 qbox = (struct quota_mailbox *) 0x808d6c0 i = <value optimized out> count = <value optimized out> size = <value optimized out> #11 0xb7f52bb7 in maildir_sync_index (ctx=0x80b45a0, partial=true) at maildir-sync-index.c:631 mbox = (struct maildir_mailbox *) 0x808d340 view = (struct mail_index_view *) 0x80a9270 view2 = (struct mail_index_view *) 0x0 iter = (struct maildir_uidlist_iter_ctx *) 0x0 trans = (struct mail_index_transaction *) 0x80b42c8 hdr = (const struct mail_index_header *) 0x80a85f8 empty_hdr = {major_version = 0 '\0', minor_version = 0 '\0', base_header_size = 0, header_size = 0, record_size = 576, compat_flags = 8 '\b', unused = "???", indexid = 3084301177, flags = 3085242720, uid_validity = 28, next_uid = 3085743644, messages_count = 134956776, unused_old_recent_messages_count = 576, seen_messages_count = 3221216296, deleted_messages_count = 3085530619, first_recent_uid = 3085747040, first_unseen_uid_lowwater = 0, first_deleted_uid_lowwater = 0, log_file_seq = 576, log_file_tail_offset = 28, log_file_head_offset = 1, sync_size = 13256344077235912704, sync_stamp = 3085747040, day_stamp = 134956776, day_first_uid = {3221216328, 3085530784, 3085747040, 3085781192, 3086502160, 3085743644, 4294967295, 3086618612}} rec = <value optimized out> seq = 0 seq2 = 0 uid = 29 prev_uid = 29 uflags = 0 filename = 0x80aee58 "1270283027.M108835P27367.test- mail,S=1837,W=1881:2," uid_validity = 1270283075 next_uid = <value optimized out> hdr_next_uid = 30 first_recent_uid = 30 first_uid = 1 changes = 4 ret = 0 time_before_sync = 1270283027 expunged_guid_128 = "?????o\216\bl\236?\000?8=\216" expunged = false full_rescan = false __FUNCTION__ = "maildir_sync_index" #12 0xb7f50f70 in maildir_transaction_save_commit_pre (_ctx=0x80ada00) at maildir-save.c:765 _t = (struct mailbox_transaction_context *) 0x80a9d38 last_mf = <value optimized out> sync_flags = <value optimized out> ret = <value optimized out> __FUNCTION__ = "maildir_transaction_save_commit_pre" #13 0xb7f3ee27 in index_transaction_index_commit (index_trans=0x80aa258, result_r=0xbfffddcc) at index-transaction.c:27 it = (struct index_transaction_context *) 0x80a9d38 ibox = (struct index_mailbox_context *) 0x808d558 ret = <value optimized out> __FUNCTION__ = "index_transaction_index_commit" #14 0xb7f08ee5 in mail_index_transaction_commit_full (_t=0xbfffdde8, result_r=0xbfffddcc) at mail-index-transaction.c:237 t = (struct mail_index_transaction *) 0x80aa258 index = (struct mail_index *) 0x806e708 index_undeleted = false #15 0xb7f3ea53 in index_transaction_commit (t=0x80a9d38, changes_r=0xbfffde8c) at index-transaction.c:123 box = (struct mailbox *) 0x808d340 itrans = (struct mail_index_transaction *) 0x0 result = {log_file_seq = 0, log_file_offset = 0, commit_size = 0, ignored_uid_changes = 0, ignored_modseq_changes = 0} ret = <value optimized out> __FUNCTION__ = "index_transaction_commit" #16 0xb7cdab81 in quota_mailbox_transaction_commit (ctx=0x80a9d38, changes_r=0xbfffde8c) at quota-storage.c:94 qt = (struct quota_transaction_context *) 0x80aa628 #17 0xb7ef0c72 in mailbox_transaction_commit_get_changes (_t=0x80893c8, changes_r=0xbfffde8c) at mail-storage.c:1143 _data_stack_cur_id = 4 t = (struct mailbox_transaction_context *) 0x80a9d38 ret = <value optimized out> #18 0x0804eab2 in cmd_append_continue_parsing (cmd=0x8089328) at cmd- append.c:265 sync_flags = <value optimized out> imap_flags = <value optimized out> changes = {pool = 0x80b3308, uid_validity = 0, saved_uids = {arr = {buffer = 0x80b3320, element_size = 8}, v = 0x80b3320, v_modifiable = 0x80b3320}, ignored_uid_changes = 0, ignored_modseq_changes = 0} msg = <value optimized out> client = (struct client *) 0x8084318 ctx = (struct cmd_append_context *) 0x80893b8 args = (const struct imap_arg *) 0x80ab218 flags_list = <value optimized out> flags = <value optimized out> keywords_list = <value optimized out> keywords = <value optimized out> internal_date_str = <value optimized out> internal_date = <value optimized out> ret = <value optimized out> timezone_offset = <value optimized out> save_count = <value optimized out> nonsync = <value optimized out> __FUNCTION__ = "cmd_append_continue_parsing" #19 0x0804e8cb in cmd_append_continue_message (cmd=0x8089328) at cmd- append.c:446 client = (struct client *) 0x8084318 ctx = (struct cmd_append_context *) 0x80893b8 size = 0 ret = <value optimized out> #20 0x0804ed02 in cmd_append_continue_parsing (cmd=0x8089328) at cmd- append.c:379 client = (struct client *) 0x8084318 ctx = (struct cmd_append_context *) 0x80893b8 args = (const struct imap_arg *) 0x80ab218 flags_list = (const struct imap_arg *) 0x0 flags = 0 keywords_list = (const char * const *) 0x80ab1e0 keywords = (struct mail_keywords *) 0x0 internal_date_str = 0x0 internal_date = -1 ret = 0 timezone_offset = 0 save_count = <value optimized out> nonsync = true __FUNCTION__ = "cmd_append_continue_parsing" #21 0x0804f069 in cmd_append (cmd=0x8089328) at cmd-append.c:540 client = (struct client *) 0x8084318 ctx = (struct cmd_append_context *) 0x80893b8 mailbox = 0x808abd8 "INBOX" #22 0x080562dc in client_command_input (cmd=0x8089328) at imap- client.c:647 client = (struct client *) 0x8084318 command = <value optimized out> __FUNCTION__ = "client_command_input" #23 0x08056379 in client_command_input (cmd=0x8089328) at imap- client.c:697 client = (struct client *) 0x8084318 command = <value optimized out> __FUNCTION__ = "client_command_input" #24 0x080564ed in client_handle_input (client=0x8084318) at imap- client.c:738 _data_stack_cur_id = 3 ret = false remove_io = <value optimized out> handled_commands = false __FUNCTION__ = "client_handle_input" #25 0x08056f0f in client_input (client=0x8084318) at imap-client.c:789 cmd = <value optimized out> output = (struct ostream *) 0x8083054 bytes = <value optimized out> __FUNCTION__ = "client_input" #26 0xb7ea7425 in io_loop_handler_run (ioloop=0x806c358) at ioloop- epoll.c:208 ctx = (struct ioloop_handler_context *) 0x806c478 event = (const struct epoll_event *) 0x806c4b8 list = (struct io_list *) 0x80830d8 io = (struct io_file *) 0x80830b0 tv = {tv_sec = 1799, tv_usec = 999126} t_id = 2 msecs = <value optimized out> ret = 1 i = 0 j = 0 call = <value optimized out> #27 0xb7ea6470 in io_loop_run (ioloop=0x806c358) at ioloop.c:350 No locals. #28 0xb7e93eaa in master_service_run (service=0x806c2a8, callback=0x805faa0 <client_connected>) at master-service.c:486 No locals. #29 0x0805f9ed in main (argc=Cannot access memory at address 0x0 ) at main.c:323 service_flags = <value optimized out> storage_service_flags = <value optimized out> postlogin_socket_path = 0x0 username = 0x0 c = <value optimized out> set_roots = {0x8062760, 0x0} (gdb) I don't have errors with clients=1 seed=123 msgs=100000000 random secs=600. -- Guillaume de Lafond Aqua Ray

2 1

[Dovecot] Ignoring the quota by the LDA?
by Holger Richter 07 Jun '10

07 Jun '10

Is it possible to configure dovecot in a manner that only the imap process respects the quota, and the local delivery ignores completely the quota? I think it should happen if I don't activate the quota plugin in the lda section but only in the imap section. protocol lda { ... # mail_plugins = ... } protocol imap { ... mail_plugins = quota imap_quota ... } Will it work or will it result in a big mess? I've the aim that a mail will never be rejected because the recipient is over his/her quota. Regards, Holger

3 4

[Dovecot] Problems with the IMAP proxy after upgrading from dovecot 1.1.16 to 1.211
by Holger Richter 07 Jun '10

07 Jun '10

We have frequent timeout problems after upgrading our imap servers from dovecot 1.1.16 to dovecot 1.2.11. One server acts as proxy only, and the other one is the "real" imap server". The credentials for the proxy service are stored in a remote MYSQL database. There were no trouble with dovecot 1.1.16. But now, with the most recent version, we get frequent login failures. It seems dovecot reconnects too late to the MySQL database after a timeout, after sending the SQL query. Here's a piece of my log file: May 7 14:46:32 ttt dovecot: auth(default): new auth connection: pid=5136 May 7 14:46:42 ttt dovecot: auth(default): client in: AUTH^I1^IPLAIN^Iservice=imap^Isecured^Ilip=xxx.xxx.xxx.xxx^Irip=yyy.yyy.yyy.yyy^Ilport=sss^Irport=26480^Iresp=<hidden> May 7 14:46:42 ttt dovecot: auth-worker(default): sql(uid,yyy.yyy.yyy.yyy): query: SELECT NULL as password, destuser, host, 'zzz' as port, 'Y' as proxy, '0' as proxy_timeout, 'Y' as nopassword, 'Y' as nodelay from accounts where user ='uid'; May 7 14:47:42 ttt dovecot: auth(default): worker-server(uid,yyy.yyy.yyy.yyy): Aborted: Lookup timed out May 7 14:47:42 ttt dovecot: auth-worker(default): mysql: Connected to lll.lll.lll.lll (imapauth) May 7 14:47:44 ttt dovecot: auth(default): client out: FAIL^I1^Iuser=uid^Itemp May 7 14:47:49 ttt dovecot: imap-login: Disconnected (auth failed, 1 attempts): user=<uid>, method=PLAIN, rip=yyy.yyy.yyy.yyy, lip=xxx.xxx.xxx.xxx, TLS May 7 14:48:26 ttt dovecot: auth(default): new auth connection: pid=5159 May 7 14:48:47 ttt dovecot: auth(default): client in: AUTH^I1^IPLAIN^Iservice=imap^Isecured^Ilip=xxx.xxx.xxx.xxx^Irip=yyy.yyy.yyy.yyy^Ilport=sss^Irport=6243^Iresp=<hidden> May 7 14:48:47 ttt dovecot: auth-worker(default): sql(uid,yyy.yyy.yyy.yyy): query: SELECT NULL as password, destuser, host, 'zzz' as port, 'Y' as proxy, '0' as proxy_timeout, 'Y' as nopassword, 'Y' as nodelay from accounts where user ='uid'; May 7 14:48:47 ttt dovecot: auth(default): client out: OK^I1^Iuser=uid^Idestuser=luid^Ihost=mmm.mmm.mmm.mmm^Iport=zzz^Iproxy^Iproxy_timeout=0^Ipass=<hidden> May 7 14:48:47 ttt dovecot: imap-login: proxy(uid): started proxying to mmm.mmm.mmm.mmm:zzz/luid: user=<uid>, method=PLAIN, rip=yyy.yyy.yyy.yyy, lip=xxx.xxx.xxx.xxx, TLS May 7 14:48:48 ttt dovecot: imap-login: proxy(uid): disconnecting yyy.yyy.yyy.yyy As you can see, the second login attempt is always successful. Of course I've tried out various values (0, 60, 90, 300) for the proxy_timeout parameter - but without any success.

2 2

[Dovecot] authentification failure: double quotes in password
by Martin Ott 07 Jun '10

07 Jun '10

we use Passdb LDAP with authentication binds against an Active Directory Server. The problem with one of our users seems to be the usage of double quotes in his password, as the windows-login works: /var/log/dovecot-info.log auth(default): Info: ldap(testuser 77.22.xx.xxx): invalid credentials (given password: xxxxx"xxxxxxx) Which chars in passwords does the dovecot auth process not like? Is there something similar to auth_username_chars for passwords? thanks, martin

2 2

[Dovecot] raw backtrace in masses
by John Adams 06 Jun '10

06 Jun '10

Hi I've got huge amounts of May 3 15:47:37 host dovecot: [ID 583609 mail.error] IMAP(user): close(/home/user/Mail/R-Help.lock) failed: Disc quota exceeded May 3 15:47:37 host dovecot: [ID 583609 mail.error] IMAP(user): Raw backtrace: 0xb0e58 -> 0xb0894 -> 0x552b4 -> 0x55508 -> 0x55774 -> 0x55d9c -> 0x5759c -> 0x57ad0 -> 0x713cc -> 0x64284 -> 0x57be0 -> 0x71178 -> 0x6841c -> 0x76a38 -> 0x76a6c -> 0x25a08 -> 0x2afd4 -> 0x2bee4 -> 0x2bea0 -> 0x2c1f8 -> 0x2cb4c -> 0xb9450 -> 0xb8d00 -> 0x35294 -> 0x246e8 May 3 15:47:37 host dovecot: [ID 583609 mail.error] dovecot: child 3892 (imap) killed with signal 6 (core dumps disabled) May 3 15:47:49 host dovecot: [ID 583609 mail.error] IMAP(user): Raw backtrace: 0xb0e58 -> 0xb0894 -> 0x552b4 -> 0x55508 -> 0x55774 -> 0x55d9c -> 0x5759c -> 0x57ad0 -> 0x713cc -> 0x64284 -> 0x57be0 -> 0x71178 -> 0x6841c -> 0x76a38 -> 0x76a6c -> 0x25a08 -> 0x2afd4 -> 0x2bee4 -> 0x2bea0 -> 0x2c1f8 -> 0x2cb4c -> 0xb9450 -> 0xb8d00 -> 0x35294 -> 0x246e8 May 3 15:47:49 host dovecot: [ID 583609 mail.error] dovecot: child 4277 (imap) killed with signal 6 (core dumps disabled) The backtrace is always the same content. is this a disc quota problem? Dovecot is 1.2.11, managesieve patched. Thanks

3 9

[Dovecot] mdbox error with 2.0.beta5
by Mike Abbott 05 Jun '10

05 Jun '10

Running 2.0.beta5 on Mac OS X with HFS+J, I often see this error in the log: Fri May 14 12:25:59 gromit dovecot[5466]: imap(pid 8101 user joe): Error: mdbox /var/spool/imap/dovecot/mail/mailboxes/INBOX/Foobar/dbox-Mails: map uidvalidity mismatch (1273852899 vs 1273853949) Fri May 14 12:25:59 gromit dovecot[5466]: imap(pid 8101 user joe): Disconnected: Internal error occurred. Refer to server log for more information. [2010-05-14 12:25:59] bytes=1337/4443 Fri May 14 12:25:59 gromit dovecot[5466]: imap(pid 8101 user joe): Warning: mdbox /var/spool/imap/dovecot/mail/storage: rebuilding indexes The logs also reveal that this user was logged in twice at the time. There appear to be two issues here: the uidvalidity mismatch, and the path in the "rebuilding indexes" message does not match the path in the "uidvalidity mismatch" error.

2 6

[Dovecot] Dovecot 2.0beta3: mdbox crash on corrupted mail (backtrace included)
by Thomas Leuxner 04 Jun '10

04 Jun '10

Hi, captured a crash on mdbox with latest mercurial: Mar 9 13:56:28 spectre dovecot: imap(tlx(a)leuxner.net): Corrupted dbox file /var/vmail/leuxner.net/tlx/mdbox/storage/m.59 (around offset=1438073): msg header has bad magic value Mar 9 13:56:28 spectre dovecot: imap(tlx(a)leuxner.net): Corrupted dbox file /var/vmail/leuxner.net/tlx/mdbox/storage/m.59 (around offset=1438073): uid=4831 points to broken data at offset=1438073 Mar 9 13:56:28 spectre dovecot: imap(tlx(a)leuxner.net): Corrupted dbox file /var/vmail/leuxner.net/tlx/mdbox/storage/m.59 (around offset=1438073): msg header has bad magic value Mar 9 13:56:28 spectre dovecot: imap(tlx(a)leuxner.net): Corrupted dbox file /var/vmail/leuxner.net/tlx/mdbox/storage/m.59 (around offset=1438073): uid=4831 points to broken data at offset=1438073 Mar 9 13:56:28 spectre dovecot: imap(tlx(a)leuxner.net): Disconnected: Internal error occurred. Refer to server log for more information. [2010-03-09 13:56:28] bytes=74358/28147042 Mar 9 13:56:28 spectre dovecot: imap(tlx(a)leuxner.net): dbox /var/vmail/leuxner.net/tlx/mdbox/storage: rebuilding indexes Mar 9 13:56:28 spectre dovecot: imap(tlx(a)leuxner.net): Corrupted dbox file /var/vmail/leuxner.net/tlx/mdbox/storage/m.59 (around offset=2075210): msg header has bad magic value Mar 9 13:56:28 spectre dovecot: imap(tlx(a)leuxner.net): dbox: Copy of the broken file saved to /var/vmail/leuxner.net/tlx/mdbox/storage/m.59.broken Mar 9 13:56:29 spectre dovecot: imap(tlx(a)leuxner.net): Panic: file index-sync.c: line 40 (index_mailbox_set_recent_uid): assertion failed: (seq_range_exists(&ibox->recent_flags, uid)) Mar 9 13:56:29 spectre dovecot: imap(tlx(a)leuxner.net): Raw backtrace: /usr/lib/dovecot/libdovecot.so.0 [0x7f184c7d92b2] -> /usr/lib/dovecot/libdovecot.so.0 [0x7f184c7d931a] -> /usr/lib/dovecot/libdovecot.so.0(i_error+0) [0x7f184c7d96c3] -> /usr/lib/dovecot/libdovecot-storage.so.0(index_mailbox_set_recent_seq+0) [0x7f184ca84010] -> /usr/lib/dovecot/libdovecot-storage.so.0(index_mailbox_set_recent_seq+0x3c) [0x7f184ca8404c] -> /usr/lib/dovecot/libdovecot-storage.so.0(mdbox_sync_begin+0x37b) [0x7f184caafddb] -> /usr/lib/dovecot/libdovecot-storage.so.0(mdbox_sync+0x12) [0x7f184cab00c2] -> /usr/lib/dovecot/libdovecot-storage.so.0(mdbox_storage_sync_init+0x43) [0x7f184cab0133] -> /usr/lib/dovecot/libdovecot-storage.so.0(mailbox_sync_init+0x31) [0x7f184ca414e1] -> dovecot/imap [tlx(a)leuxner.net 80.187.100.24 IDLE](imap_sync_init+0x68) [0x417db8] -> dovecot/imap [tlx(a)leuxner.net 80.187.100.24 IDLE] [0x40ab5e] -> /usr/lib/dovecot/libdovecot.so.0(io_loop_handle_timeouts+0x9b) [0x7f184c7e342b] -> /usr/lib/dovecot/libdovecot.so.0(io_loop_handler_run+0x6f) [0x7f184c7e3f8f] -> /usr/lib/dovecot/libdovecot.so.0(io_loop_run+0x18) [0x7f184c7e3168] -> /usr/lib/dovecot/libdovecot.so.0(master_service_run+0x13) [0x7f184c7d3143] -> dovecot/imap [tlx(a)leuxner.net 80.187.100.24 IDLE](main+0x191) [0x418681] -> /lib/libc.so.6(__libc_start_main+0xe6) [0x7f184c0601a6] -> dovecot/imap [tlx(a)leuxner.net 80.187.100.24 IDLE] [0x4084e9] Mar 9 13:56:29 spectre dovecot: master: service(imap): child 32643 killed with signal 6 (core dumped) [14:02] root spectre:/# gdb /usr/lib/dovecot/imap /var/vmail/leuxner.net/tlx/core GNU gdb 6.8-debian Copyright (C) 2008 Free Software Foundation, Inc. License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html> This is free software: you are free to change and redistribute it. There is NO WARRANTY, to the extent permitted by law. Type "show copying" and "show warranty" for details. This GDB was configured as "x86_64-linux-gnu"... warning: Can't read pathname for load map: Input/output error. Reading symbols from /usr/lib/dovecot/libdovecot-storage.so.0...Reading symbols from /usr/lib/debug/usr/lib/dovecot/libdovecot-storage.so.0.0.0...done. done. Loaded symbols for /usr/lib/dovecot/libdovecot-storage.so.0 Reading symbols from /usr/lib/dovecot/libdovecot.so.0...Reading symbols from /usr/lib/debug/usr/lib/dovecot/libdovecot.so.0.0.0...done. done. Loaded symbols for /usr/lib/dovecot/libdovecot.so.0 Reading symbols from /lib/libdl.so.2...done. Loaded symbols for /lib/libdl.so.2 Reading symbols from /lib/librt.so.1...done. Loaded symbols for /lib/librt.so.1 Reading symbols from /lib/libc.so.6...done. Loaded symbols for /lib/libc.so.6 Reading symbols from /lib/ld-linux-x86-64.so.2...done. Loaded symbols for /lib64/ld-linux-x86-64.so.2 Reading symbols from /lib/libpthread.so.0...done. Loaded symbols for /lib/libpthread.so.0 Reading symbols from /usr/lib/dovecot/modules/lib01_acl_plugin.so...Reading symbols from /usr/lib/debug/usr/lib/dovecot/modules/lib01_acl_plugin.so...done. done. Loaded symbols for /usr/lib/dovecot/modules/lib01_acl_plugin.so Reading symbols from /usr/lib/dovecot/modules/lib02_imap_acl_plugin.so...Reading symbols from /usr/lib/debug/usr/lib/dovecot/modules/lib02_imap_acl_plugin.so...done. done. Loaded symbols for /usr/lib/dovecot/modules/lib02_imap_acl_plugin.so Reading symbols from /usr/lib/dovecot/modules/lib10_quota_plugin.so...Reading symbols from /usr/lib/debug/usr/lib/dovecot/modules/lib10_quota_plugin.so...done. done. Loaded symbols for /usr/lib/dovecot/modules/lib10_quota_plugin.so Reading symbols from /usr/lib/dovecot/modules/lib11_imap_quota_plugin.so...Reading symbols from /usr/lib/debug/usr/lib/dovecot/modules/lib11_imap_quota_plugin.so...done. done. Loaded symbols for /usr/lib/dovecot/modules/lib11_imap_quota_plugin.so Reading symbols from /lib/libgcc_s.so.1...done. Loaded symbols for /lib/libgcc_s.so.1 Core was generated by `dovecot/imap'. Program terminated with signal 6, Aborted. [New process 32643] #0 0x00007f184c073ed5 in raise () from /lib/libc.so.6 (gdb) bt full #0 0x00007f184c073ed5 in raise () from /lib/libc.so.6 No symbol table info available. #1 0x00007f184c0753f3 in abort () from /lib/libc.so.6 No symbol table info available. #2 0x00007f184c7d92c5 in default_fatal_finish (type=<value optimized out>, status=0) at failures.c:164 backtrace = 0x61f0e8 "/usr/lib/dovecot/libdovecot.so.0 [0x7f184c7d92b2] -> /usr/lib/dovecot/libdovecot.so.0 [0x7f184c7d931a] -> /usr/lib/dovecot/libdovecot.so.0(i_error+0) [0x7f184c7d96c3] -> /usr/lib/dovecot/libdovecot-st"... #3 0x00007f184c7d931a in i_internal_fatal_handler (type=LOG_TYPE_PANIC, status=0, fmt=<value optimized out>, args=<value optimized out>) at failures.c:592 No locals. #4 0x00007f184c7d96c3 in i_panic (format=<value optimized out>) at failures.c:230 args = {{gp_offset = 40, fp_offset = 48, overflow_arg_area = 0x7fffffffcd00, reg_save_area = 0x7fffffffcc40}} #5 0x00007f184ca84010 in index_mailbox_set_recent_uid (box=<value optimized out>, uid=4722) at index-sync.c:40 ibox = (struct index_mailbox_context *) 0x654890 __PRETTY_FUNCTION__ = "index_mailbox_set_recent_uid" #6 0x00007f184ca8404c in index_mailbox_set_recent_seq (box=0x654508, view=0x665040, seq1=2, seq2=44) at index-sync.c:57 uid = 4722 #7 0x00007f184caafddb in mdbox_sync_begin (mbox=0x654508, flags=<value optimized out>, ctx_r=0x7fffffffcea8) at mdbox-sync.c:141 storage = (struct mail_storage *) 0x648c78 ctx = (struct mdbox_sync_context *) 0x657260 sync_flags = <value optimized out> ret = 1 storage_rebuilt = false #8 0x00007f184cab00c2 in mdbox_sync (mbox=0x7f83, flags=32643) at mdbox-sync.c:286 sync_ctx = (struct mdbox_sync_context *) 0x654508 #9 0x00007f184cab0133 in mdbox_storage_sync_init (box=0x654508, flags=0) at mdbox-sync.c:310 mdbox_sync_flags = 32643 #10 0x00007f184ca414e1 in mailbox_sync_init (box=0x654508, flags=0) at mail-storage.c:848 _data_stack_cur_id = 0 ctx = <value optimized out> #11 0x0000000000417db8 in imap_sync_init (client=0x64f9d8, box=<value optimized out>, imap_flags=0, flags=0) at imap-sync.c:142 ctx = <value optimized out> __PRETTY_FUNCTION__ = "imap_sync_init" #12 0x000000000040ab5e in idle_sync_now (box=<value optimized out>, ctx=0x650228) at cmd-idle.c:122 __PRETTY_FUNCTION__ = "idle_sync_now" #13 0x00007f184c7e342b in io_loop_handle_timeouts (ioloop=0x6275c0) at ioloop.c:328 _data_stack_cur_id = 2 #14 0x00007f184c7e3f8f in io_loop_handler_run (ioloop=0x6275c0) at ioloop-epoll.c:180 ctx = (struct ioloop_handler_context *) 0x6277d0 event = <value optimized out> list = <value optimized out> io = <value optimized out> tv = {tv_sec = 0, tv_usec = 499327} t_id = <value optimized out> msecs = 500 ret = 0 call = <value optimized out> #15 0x00007f184c7e3168 in io_loop_run (ioloop=0x6275c0) at ioloop.c:350 No locals. #16 0x00007f184c7d3143 in master_service_run (service=0x627490, callback=0x7f83) at master-service.c:478 No locals. #17 0x0000000000418681 in main (argc=1, argv=0x627370) at main.c:313 service_flags = <value optimized out> storage_service_flags = <value optimized out> postlogin_socket_path = 0x0 set_roots = {0x41b980, 0x0} (gdb) Regards Thomas

2 11

[Dovecot] dsync panic in dsync-worker-local.c - 2.0.beta4
by Frode Nordahl 04 Jun '10

04 Jun '10

Hello, While testing mailbox conversion I encountered a Panic in dsync on a few users mailboxes. Running dovecot 2.0.beta4 on RedHat Enterprise Linux 5 (x86_64). I tried to compile the code with -ggdb and debug some more before posting this, but I was unsuccessful. Running dsync from a source tree is hard because of all the dependencies on shares libraries. Is it possbile to build static binaries? Panic message and backtrace included below (anonymized): dsync(user): Error: o_stream_send_istream(/home/user/mdbox/storage/temp.1271871137.P25074Q1M330350.localhost.localdomain) failed: Bad file descriptor dsync(user): Panic: file dsync-worker-local.c: line 1460 (local_worker_save_msg_continue): assertion failed: (ret == -1) dsync(user): Error: Raw backtrace: /usr/lib64/dovecot/libdovecot.so.0 [0x3da92343a0] -> /usr/lib64/dovecot/libdovecot.so.0(default_fatal_handler+0x37) [0x3da9234487] -> /usr/lib64/dovecot/libdovecot.so.0 [0x3da92338c8] -> /usr/bin/dsync [0x40db83] -> /usr/bin/dsync [0x40dc5e] -> /usr/bin/dsync(dsync_worker_msg_save+0x79) [0x40d429] -> /usr/bin/dsync [0x408b4c] -> /usr/bin/dsync [0x40d88d] -> /usr/bin/dsync(dsync_worker_msg_get+0x81) [0x40d061] -> /usr/bin/dsync [0x4085fe] -> /usr/bin/dsync [0x40868d] -> /usr/bin/dsync [0x4087d5] -> /usr/bin/dsync(dsync_brain_msg_sync_more+0x3f5) [0x408395] -> /usr/bin/dsync(dsync_brain_sync+0x93f) [0x40720f] -> /usr/bin/dsync [0x4078e0] -> /usr/bin/dsync(dsync_brain_sync+0x42e) [0x406cfe] -> /usr/bin/dsync [0x4079e1] -> /usr/bin/dsync(dsync_brain_sync+0x3f0) [0x406cc0] -> /usr/bin/dsync(dsync_brain_sync_all+0x18) [0x407728] -> /usr/bin/dsync(main+0x436) [0x406156] -> /lib64/libc.so.6(__libc_start_main+0xf4) [0x3d18a1d994] -> /usr/bin/dsync [0x405c29] -- Frode Nordahl

2 1

[Dovecot] 2.0.beta4, Panic: stream doesn't support seeking backwards
by Juergen Daubert 04 Jun '10

04 Jun '10

Hi, got the following with beta4 while uploading messages from a local mbox to the dovecot server in my LAN, tested with mutt and sylpheed, the same action works with 1.2.11: Mar 29 13:42:46 [dovecot] imap(juergen): Panic: stream doesn't support seeking backwards Mar 29 13:42:46 [dovecot] imap(juergen): Raw backtrace: /usr/lib/dovecot/libdovecot.so.0 [0xb76b7ec4] -> /usr/lib/dovecot/libdovecot.so.0 [0xb76b7f2c] -> /usr/lib/dovecot/libdovecot.so.0(i_error+0) [0xb76b8193] -> /usr/lib/dovecot/libdovecot.so.0 [0xb76c02cd] -> /usr/lib/dovecot/libdovecot.so.0(i_stream_seek+0xbb) [0xb76be1db] -> /usr/lib/dovecot/libdovecot.so.0 [0xb76c08a9] -> /usr/lib/dovecot/libdovecot.so.0(i_stream_read+0x6e) [0xb76be27e] -> /usr/lib/dovecot/libdovecot.so.0(i_stream_read_data+0x40) [0xb76be570] -> /usr/lib/dovecot/libdovecot.so.0(message_parse_header_next+0x6d) [0xb76a7b6d] -> /usr/lib/dovecot/libdovecot.so.0 [0xb76a4302] -> /usr/lib/dovecot/libdovecot.so.0 [0xb76a498f] -> /usr/lib/dovecot/libdovecot.so.0(i_stream_read+0x6e) [0xb76be27e] -> /usr/lib/dovecot/libdovecot.so.0 [0xb76a3f61] -> /usr/lib/dovecot/libdovecot.so.0 [0xb76a4072] -> /usr/lib/dovecot/libdovecot.so.0(i_stream_seek+0xbb) [0xb76be1db] -> /usr/lib/dovecot/libdovecot.so.0(i_stream_read+0x52) [0xb76be262] -> /usr/lib/dovecot/libdovecot.so.0 [0xb76c246d] -> /usr/lib/dovecot/libdovecot.so.0(i_stream_read+0x6e) [0xb76be27e] -> /usr/lib/dovecot/libdovecot-storage.so.0(mbox_save_continue+0x4c) [0xb776ca6c] -> /usr/lib/dovecot/libdovecot-storage.so.0(mailbox_save_continue+0x14) [0xb7708964] -> dovecot/imap [0x804e32f] -> dovecot/imap [0x804ed31] -> /usr/lib/dovecot/libdovecot.so.0(io_loop_handler_run+0xd1) [0xb76c38f1] -> /usr/lib/dovecot/libdovecot.so.0(io_loop_run+0x29) [0xb76c29f9] -> /usr/lib/dovecot/libdovecot.so.0(master_service_run+0x25) [0xb76b1c45] -> dovecot/imap(main+0x1b3) [0x805da13] -> /lib/libc.so.6(__libc_start_main+0xdb) [0xb7559a3b] -> dovecot/imap [0x804e161] Mar 29 13:42:46 [dovecot] master: service(imap): child 21107 killed with signal 6 (core dumps disabled) # dovecot -n # 2.0.beta4: /etc/dovecot/dovecot.conf # OS: Linux 2.6.32.10 i686 listen = * login_access_sockets = tcpwrap passdb { driver = shadow } service tcpwrap { unix_listener login/tcpwrap { mode = 0666 } } ssl_cert = </etc/ssl/certs/dovecot.crt ssl_key = </etc/ssl/keys/dovecot.key userdb { driver = passwd } Greetings Juergen -- Juergen Daubert | mailto:jue@jue.li Korb, Germany | http://jue.li/crux

3 16

[Dovecot] userdb prefetch not compatible with ssl_require_client_cert
by zhong ming wu 04 Jun '10

04 Jun '10

Dear List I looked into docs but couldn't see any where that says of this incompatibility. Anywhere this is confirmed in the doc? Thanks mr.wu

2 3