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