[Dovecot] dovecot 2 beta4 errors & core dumps

de Lafond Guillaume gdelafond+dovecot at aquaray.com
Sat Apr 3 11:53:07 EEST 2010


Hi,

While running imaptest with "clients=50 seed=123 msgs=100000000 random  
secs=600", I got errors : "Error: user at domain.com[55]: Unexpected BYE:  
* BYE IMAP session state is inconsistent, please relogin.".
dovecot.log :

Apr 03 10:23:47 imap(user at 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 at 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 at domain.com 10.0.0.5 APPEND]  
[0x804eab2] -> dovecot/imap [user at domain.com 10.0.0.5 APPEND]  
[0x804e8cb] -> dovecot/imap [user at domain.com 10.0.0.5 APPEND]  
[0x804ed02] -> dovecot/imap [user at domain.com 10.0.0.5 APPEND] 
(cmd_append+0x1d9) [0x804f069] -> dovecot/imap [user at domain.com  
10.0.0.5 APPEND] [0x80562dc] -> dovecot/imap [user at domain.com 10.0.0.5  
APPEND] [0x8056379] -> dovecot/imap [user at domain.com 10.0.0.5 APPEND] 
(client_handle_input+0x2d) [0x80564ed] -> dovecot/imap  
[user at 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 at 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 at 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 at 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 at 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 at 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 at 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 at domain.com): Warning: fscking index file / 
var/mail/dovecot_indexes/d/domain.com/user/.INBOX/dovecot.index
Apr 03 10:23:50 imap(user at 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 at domain.com): Warning: fscking index file / 
var/mail/dovecot_indexes/d/domain.com/user/.INBOX/dovecot.index
Apr 03 10:23:50 imap(user at 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 at 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 at 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 at 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




More information about the dovecot mailing list