Michael Kliewe
2014-Apr-01 18:34 UTC
[Dovecot] imap process and indexer-worker crash while creating folders
Hi,
our dovecot processes sometimes crash when we create new folders. The
"imap" process and the "indexer worker" process is crashing.
We can reproduce this, we have a java program with multiple threads, and
sometimes 2 threads try to create the same folder for the same user, and if both
collide, dovecot processes crash.
We don't see this happening in the real world if "normal" imap
clients are connected, but our special java program trying to create folders in
parallel is producing these crashes.
Below you can see the log entries and gdb "bt full" output, one for an
"imap" process and one for an "indexer worker" process.
We are using dovecot 2.2.9, and I did not find anything in the changelog
regarding this problem. Does ist make sense to try the newest version 2.2.12?
Thanks
Michael
=================Apr 1 19:58:28 dovecot01 dovecot: imap(user at domain.de):
Panic: file mail-index-transaction-export.c: line 117 (log_append_ext_intro):
assertion failed: (intro->ext_id == idx || idx == (uint32_t)-1)
Apr 1 19:58:28 dovecot01 dovecot: imap(user at domain.de): Error: Raw backtrace:
/usr/local/lib/dovecot/libdovecot.so.0(+0x66ab1) [0x7f0028259ab1] ->
/usr/local/lib/dovecot/libdovecot.so.0(+0x66b8e) [0x7f0028259b8e] ->
/usr/local/lib/dovecot/libdovecot.so.0(i_fatal+0) [0x7f00282153ce] ->
/usr/local/lib/dovecot/libdovecot-storage.so.0(+0xb9c72) [0x7f002857ec72] ->
/usr/local/lib/dovecot/libdovecot-storage.so.0(mail_index_transaction_export+0x200)
[0x7f002857f140] -> /usr/local/lib/dovecot/libdovecot-storage.so.0(+0xb932f)
[0x7f002857e32f] ->
/usr/local/lib/dovecot/libdovecot-storage.so.0(mail_index_transaction_commit_full+0x9d)
[0x7f002857e78d] ->
/usr/local/lib/dovecot/libdovecot-storage.so.0(mail_index_transaction_commit+0xc)
[0x7f002857e82c] -> /usr/local/lib/dovecot/libdovecot-storage.so.0(+0x3e1ea)
[0x7f00285031ea] -> /usr/local/lib/dovecot/libdovecot-storage.so.0(+0x3e44c)
[0x7f002850344c] -> /usr/local/lib/dovecot/libdovecot-storage.so.0(+0x90a15)
[0x7f0028555a15] ->
/usr/local/lib/dovecot/libdovecot-storage.so.0(mailbox_get_metadata+0x95)
[0x7f0028542345] ->
/usr/local/lib/dovecot/libdovecot-storage.so.0(mailbox_list_index_sync_name+0x2a4)
[0x7f0028556324] ->
/usr/local/lib/dovecot/libdovecot-storage.so.0(mailbox_list_index_sync+0x10a)
[0x7f002855694a] ->
/usr/local/lib/dovecot/libdovecot-storage.so.0(mailbox_list_index_refresh+0x9e)
[0x7f002855184e] ->
/usr/local/lib/dovecot/libdovecot-storage.so.0(mailbox_list_index_iter_init+0x129)
[0x7f0028553169] ->
/usr/local/lib/dovecot/libdovecot-storage.so.0(mailbox_list_iter_init_multiple+0x29)
[0x7f0028556ec9] -> /usr/local/lib/dovecot/libdovecot-storage.so.0(+0x93179)
[0x7f0028558179] -> /usr/local/lib/dovecot/libdovecot-storage.so.0(+0x91baf)
[0x7f0028556baf] ->
/usr/local/lib/dovecot/libdovecot-storage.so.0(mailbox_list_iter_next+0x334)
[0x7f00285577c4] -> dovecot/imap [user at domain.de 10.0.121.43 LIST]()
[0x40f089] -> dovecot/imap [user at domain.de 10.0.121.43
LIST](cmd_list_full+0x4de) [0x40f8ce] -> dovecot/imap [user at domain.de
10.0.121.43 LIST](command_exec+0x3c) [0x416adc] -> dovecot/imap [user at
domain.de 10.0.121.43 LIST]() [0x415b3f] -> dovecot/imap [user at domain.de
10.0.121.43 LIST]() [0x415bf5] -> dovecot/imap [user at domain.de 10.0.121.43
LIST](client_handle_input+0x115) [0x415ef5] -> dovecot/imap [user at
domain.de 10.0.121.43 LIST](client_input+0x72) [0x416282] ->
/usr/local/lib/dovecot/libdovecot.so.0(io_loop_call_io+0x27) [0x7f0028269a87]
Apr 1 19:58:28 dovecot01 dovecot: imap(user at domain.de): Fatal: master:
service(imap): child 3928 killed with signal 6 (core dumped)
=================Core was generated by `dovecot/imap'.
Program terminated with signal 6, Aborted.
#0 0x00007f0027e61f77 in __GI_raise (sig=sig at entry=6) at
../nptl/sysdeps/unix/sysv/linux/raise.c:56
56 ../nptl/sysdeps/unix/sysv/linux/raise.c: No such file or directory.
(gdb) bt full
#0 0x00007f0027e61f77 in __GI_raise (sig=sig at entry=6) at
../nptl/sysdeps/unix/sysv/linux/raise.c:56
resultvar = 0
pid = 3928
selftid = 3928
#1 0x00007f0027e655e8 in __GI_abort () at abort.c:90
save_stage = 2
act = {__sigaction_handler = {sa_handler = 0x0, sa_sigaction = 0x0}, sa_mask =
{__val = {11509168, 0, 139638656126069, 1, 0, 4283381, 139638645923048,
140736983670273, 0,
11764224, 139638656153381, 0, 139638646863616, 139638652804256, 11513608,
140736983669916}}, sa_flags = 4096,
sa_restorer = 0x7f0027e79134 }
sigs = {__val = {32, 0 }}
#2 0x00007f0028259ad8 in default_fatal_finish (type=, status=status at entry=0)
at failures.c:192
backtrace = 0xaf9eb8 "/usr/local/lib/dovecot/libdovecot.so.0(+0x66ab1)
[0x7f0028259ab1] -> /usr/local/lib/dovecot/libdovecot.so.0(+0x66b8e)
[0x7f0028259b8e] -> /usr/local/lib/dovecot/libdovecot.so.0(i_fatal+0)
[0x7f0028215"...
#3 0x00007f0028259b8e in i_internal_fatal_handler (ctx=0x7fffe1eb1e30, format=,
args=) at failures.c:653
status = 0
#4 0x00007f00282153ce in i_panic (format=format at entry=0x7f0028597088
"file %s: line %d (%s): assertion failed: (%s)") at failures.c:264
ctx = {type = LOG_TYPE_PANIC, exit_status = 0, timestamp = 0x0}
args = {{gp_offset = 40, fp_offset = 48, overflow_arg_area = 0x7fffe1eb1f20,
reg_save_area = 0x7fffe1eb1e60}}
#5 0x00007f002857ec72 in log_append_ext_intro (ctx=ctx at entry=0x7fffe1eb2040,
ext_id=ext_id at entry=5, reset_id=0, hdr_size_r=hdr_size_r at
entry=0x7fffe1eb2018)
at mail-index-transaction-export.c:117
t = 0xb3dd30
intro = 0xb3cd04
resizes = 0xb3cca0
buf = 0xaf9db0
idx = 0
count = 6
__FUNCTION__ = "log_append_ext_intro"
#6 0x00007f002857f140 in mail_transaction_log_append_ext_intros
(ctx=0x7fffe1eb2040) at mail-index-transaction-export.c:283
resize =
ext_reset = {new_reset_id = 0, preserve_data = 0 '\000', unused_padding
= "\000\000"}
resize_count =
ext_count = 6
hdrs =
hdrs_count = 6
ext_id = 5
reset_count = 0
hdr_size = 0
reset = 0x0
reset_buf = {data = 0x7fffe1eb2020, used = 8, priv = {0x7fffe1eb2020, 0x0, 0x8,
0x0, 0x0}}
t =
reset_id_count = 0
reset_id =
reset_ids = 0x0
#7 mail_index_transaction_export (t=t at entry=0xb3dd30, append_ctx=0xb43570) at
mail-index-transaction-export.c:409
null4 = "\000\000\000"
change_mask = (unknown: 0)
ctx = {trans = 0xb3dd30, append_ctx = 0xb43570}
__FUNCTION__ = "mail_index_transaction_export"
#8 0x00007f002857e32f in mail_index_transaction_commit_real
(commit_size_r=0x7fffe1eb2180, t=0xb3dd30) at mail-index-transaction.c:165
_data_stack_cur_id = 7
ctx = 0xb43570
log_seq2 = 0
log_offset1 = 0
log = 0xb38e00
trans_flags =
---Type to continue, or q to quit---
log_seq1 = 11763008
log_offset2 = 7
#9 mail_index_transaction_commit_v (t=0xb3dd30, result_r=0x7fffe1eb2170) at
mail-index-transaction.c:203
index = 0xb37d40
changed = true
ret =
__FUNCTION__ = "mail_index_transaction_commit_v"
#10 0x00007f002857e78d in mail_index_transaction_commit_full (_t=_t at
entry=0x7fffe1eb21b0, result_r=result_r at entry=0x7fffe1eb2170) at
mail-index-transaction.c:262
t = 0xb3dd30
index = 0xb37d40
index_undeleted = false
#11 0x00007f002857e82c in mail_index_transaction_commit (t=t at
entry=0x7fffe1eb21b0) at mail-index-transaction.c:236
result = {log_file_seq = 0, log_file_offset = 0, commit_size = 0,
ignored_modseq_changes = 0}
#12 0x00007f00285031ea in mdbox_write_index_header (box=box at entry=0xb37170,
update=update at entry=0x0, trans=0xb3dd30, trans at entry=0x0) at
mdbox-storage.c:312
mbox = 0xb37170
new_trans = 0x0
view = 0x0
hdr = 0xb39350
uid_validity = 1306175967
uid_next = 0
#13 0x00007f002850344c in mdbox_mailbox_get_guid (guid_r=0x7fffe1eb2370
"", mbox=0xb37170) at mdbox-storage.c:391
need_resize = true
ret = 0
idx_hdr =
hdr = {map_uid_validity = 0, mailbox_guid = '\000' , flags = 0
'\000', unused = "\000\000"}
#14 mdbox_mailbox_get_metadata (box=0xb37170, items=, metadata_r=0x7fffe1eb2370)
at mdbox-storage.c:411
items =
metadata_r = 0x7fffe1eb2370
box = 0xb37170
mbox = 0xb37170
#15 0x00007f0028555a15 in index_list_get_metadata (box=0xb37170,
items=MAILBOX_METADATA_GUID, metadata_r=0x7fffe1eb2370) at
mailbox-list-index-status.c:202
ibox = 0xb37a70
#16 0x00007f0028542345 in mailbox_get_metadata (box=0xb37170, items=items at
entry=MAILBOX_METADATA_GUID, metadata_r=metadata_r at entry=0x7fffe1eb2370) at
mail-storage.c:1544
__FUNCTION__ = "mailbox_get_metadata"
#17 0x00007f0028556324 in node_lookup_guid (ctx=, guid_r=0x7fffe1eb2358
"", node=0xb22780) at mailbox-list-index-sync.c:25
box = 0xb37170
vname =
str = 0xaf9920
ns_sep =
metadata = {guid = '\000' , virtual_size = 0, cache_fields = 0x0,
precache_fields = (unknown: 0), backend_ns_prefix = 0x0, backend_ns_type =
(unknown: 0)}
#18 node_add_to_index (seq_r=0x7fffe1eb2330, node=0xb22780, ctx=0xb34ef0) at
mailbox-list-index-sync.c:45
_data_stack_cur_id = 6
irec = {name_id = 65, parent_uid = 0, guid = '\000' , uid_validity = 0}
seq = 11759984
#19 mailbox_list_index_node_add (seq_r=0x7fffe1eb2330, name=, parent=,
ctx=0xb34ef0) at mailbox-list-index-sync.c:87
node = 0xb22780
dup_name = 0xb227b0 "GoogleMail 01.04.2014 19:58"
#20 mailbox_list_index_sync_name (ctx=ctx at entry=0xb34ef0, name=,
node_r=node_r at entry=0x7fffe1eb2418, created_r=created_r at
entry=0x7fffe1eb240b)
at mailbox-list-index-sync.c:125
path = 0xaf9808
empty_path = {0x7f00285982ff "", 0x0}
node =
parent =
i = 0
seq = 0
---Type to continue, or q to quit---
__FUNCTION__ = "mailbox_list_index_sync_name"
#21 0x00007f002855694a in mailbox_list_index_sync_list (sync_ctx=0xb34ef0) at
mailbox-list-index-sync.c:318
name =
_data_stack_cur_id = 5
iter = 0xb352c0
info = 0xb35340
flags = (unknown: 0)
node = 0xb21c40
seq =
patterns = {0x7f00285a55d3 "*", 0x0}
created = false
#22 mailbox_list_index_sync (list=list at entry=0xb15df0) at
mailbox-list-index-sync.c:390
sync_ctx = 0xb34ef0
ret = 0
#23 0x00007f002855184e in mailbox_list_index_refresh (list=0xb15df0) at
mailbox-list-index.c:380
ilist = 0xb16288
view = 0xb27890
ret =
#24 0x00007f0028553169 in iter_use_index (ctx=0xb26dc0, ctx=0xb26dc0) at
mailbox-list-index-iter.c:25
ilist = 0xb16288
#25 mailbox_list_index_iter_init (list=0xb15df0, patterns=0xb26c88,
flags=(MAILBOX_LIST_ITER_RETURN_CHILDREN | MAILBOX_LIST_ITER_RETURN_SPECIALUSE))
at mailbox-list-index-iter.c:52
ilist = 0xb16288
ctx = 0xb26dc0
pool = 0xb26da0
ns_sep =
#26 0x00007f0028556ec9 in mailbox_list_iter_init_multiple (list=0xb15df0,
patterns=, flags=(MAILBOX_LIST_ITER_RETURN_CHILDREN |
MAILBOX_LIST_ITER_RETURN_SPECIALUSE))
at mailbox-list-iter.c:173
ctx =
ret = 0
#27 0x00007f0028558179 in mailbox_list_ns_iter_try_next (info_r=, _ctx=0xb269b0)
at mailbox-list-iter.c:574
ctx = 0xb269b0
info =
errstr =
has_children =
ns =
error = MAIL_ERROR_NONE
#28 mailbox_list_ns_iter_next (_ctx=0xb269b0) at mailbox-list-iter.c:645
info =
#29 0x00007f0028556baf in mailbox_list_iter_next_call (ctx=ctx at
entry=0xb269b0) at mailbox-list-iter.c:941
info =
set =
#30 0x00007f00285577c4 in mailbox_list_iter_next (ctx=0xb269b0) at
mailbox-list-iter.c:1012
_data_stack_cur_id = 4
info =
#31 0x000000000040f089 in cmd_list_continue (cmd=cmd at entry=0xb24190) at
cmd-list.c:229
ctx = 0xb242a8
info =
flags =
str = 0xaf93a0
mutf7_name = 0xaf94f0
name =
ret =
#32 0x000000000040f8ce in cmd_list_full (cmd=0xb24190, lsub=) at cmd-list.c:463
client =
args = 0xb04a98
---Type to continue, or q to quit---
list_args = 0x0
arg_count = 32512
ctx = 0xb242a8
patterns = {arr = {buffer = 0xb24300, element_size = 8}, v = 0xb24300,
v_modifiable = 0xb24300}
ref = 0xb242d8 ""
pattern = 0xb242e0 "GoogleMail 01.04.2014 19:58"
str =
#33 0x0000000000416adc in command_exec (cmd=0xb24190) at imap-commands.c:158
hook = 0xb020f0
ret =
#34 0x0000000000415b3f in client_command_input (cmd=0xb24190) at
imap-client.c:780
client = 0xb235b0
command =
__FUNCTION__ = "client_command_input"
#35 0x0000000000415bf5 in client_command_input (cmd=0xb24190) at
imap-client.c:841
client = 0xb235b0
command =
__FUNCTION__ = "client_command_input"
#36 0x0000000000415ef5 in client_handle_next_command (remove_io_r=,
client=0xb235b0) at imap-client.c:879
No locals.
#37 client_handle_input (client=client at entry=0xb235b0) at imap-client.c:891
_data_stack_cur_id = 3
remove_io = false
handled_commands = false
__FUNCTION__ = "client_handle_input"
#38 0x0000000000416282 in client_input (client=0xb235b0) at imap-client.c:933
cmd = 0xb16a70
output = 0xb23fe0
bytes = 42
__FUNCTION__ = "client_input"
#39 0x00007f0028269a87 in io_loop_call_io (io=0xb240b0) at ioloop.c:388
ioloop = 0xb01730
t_id = 2
#40 0x00007f002826a817 in io_loop_handler_run (ioloop=ioloop at entry=0xb01730)
at ioloop-epoll.c:220
ctx = 0xb023d0
list = 0xb03e00
io =
tv = {tv_sec = 1799, tv_usec = 999837}
events_count =
msecs =
ret = 1
i = 0
call =
__FUNCTION__ = "io_loop_handler_run"
#41 0x00007f0028269628 in io_loop_run (ioloop=0xb01730) at ioloop.c:412
__FUNCTION__ = "io_loop_run"
#42 0x00007f002821a5c3 in master_service_run (service=0xb015c0,
callback=callback at entry=0x41ec00 ) at master-service.c:566
No locals.
#43 0x000000000040b03f in main (argc=1, argv=0xb01390) at main.c:400
set_roots = {0x4269a0 , 0x0}
login_set = {auth_socket_path = 0xaf9058 "(", postlogin_socket_path =
0x0, postlogin_timeout_secs = 60, callback = 0x41efb0 ,
failure_callback = 0x41ece0 , request_auth_token = 1}
service_flags =
storage_service_flags =
username = 0x0
---Type to continue, or q to quit---
c =
=================Apr 1 20:19:42 dovecot01 dovecot: indexer-worker(user at
domain.de): Panic: file mail-index-transaction-export.c: line 117
(log_append_ext_intro): assertion failed: (intro->ext_id == idx || idx ==
(uint32_t)-1)
Apr 1 20:19:42 dovecot01 dovecot: indexer-worker(user at domain.de): Error: Raw
backtrace: /usr/local/lib/dovecot/libdovecot.so.0(+0x66ab1) [0x7f77b4f2aab1]
-> /usr/local/lib/dovecot/libdovecot.so.0(+0x66b8e) [0x7f77b4f2ab8e] ->
/usr/local/lib/dovecot/libdovecot.so.0(i_fatal+0) [0x7f77b4ee63ce] ->
/usr/local/lib/dovecot/libdovecot-storage.so.0(+0xb9c72) [0x7f77b524fc72] ->
/usr/local/lib/dovecot/libdovecot-storage.so.0(mail_index_transaction_export+0x200)
[0x7f77b5250140] -> /usr/local/lib/dovecot/libdovecot-storage.so.0(+0xb932f)
[0x7f77b524f32f] ->
/usr/local/lib/dovecot/libdovecot-storage.so.0(mail_index_transaction_commit_full+0x9d)
[0x7f77b524f78d] ->
/usr/local/lib/dovecot/libdovecot-storage.so.0(mail_index_transaction_commit+0xc)
[0x7f77b524f82c] -> /usr/local/lib/dovecot/libdovecot-storage.so.0(+0x3e1ea)
[0x7f77b51d41ea] -> /usr/local/lib/dovecot/libdovecot-storage.so.0(+0x3e44c)
[0x7f77b51d444c] -> /usr/local/lib/dovecot/libdovecot-storage.so.0(+0x90a15)
[0x7f77b5226a15] ->
/usr/local/lib/dovecot/libdovecot-storage.so.0(mailbox_get_metadata+0x95)
[0x7f77b5213345] ->
/usr/local/lib/dovecot/libdovecot-storage.so.0(mailbox_list_index_sync_name+0x2a4)
[0x7f77b5227324] ->
/usr/local/lib/dovecot/libdovecot-storage.so.0(mailbox_list_index_sync+0x10a)
[0x7f77b522794a] ->
/usr/local/lib/dovecot/libdovecot-storage.so.0(mailbox_list_index_refresh+0x9e)
[0x7f77b522284e] -> /usr/local/lib/dovecot/libdovecot-storage.so.0(+0x9072e)
[0x7f77b522672e] -> /usr/local/lib/dovecot/libdovecot-storage.so.0(+0x909a3)
[0x7f77b52269a3] ->
/usr/local/lib/dovecot/libdovecot-storage.so.0(mailbox_sync_deinit+0x22)
[0x7f77b5211ef2] ->
/usr/local/lib/dovecot/libdovecot-storage.so.0(mailbox_sync+0x39)
[0x7f77b5211fa9] -> dovecot/indexer-worker [user at domain.de INBOX]()
[0x4022f7] -> /usr/local/lib/dovecot/libdovecot.so.0(io_loop_call_io+0x27)
[0x7f77b4f3aa87] ->
/usr/local/lib/dovecot/libdovecot.so.0(io_loop_handler_run+0xd7)
[0x7f77b4f3b817] -> /usr/local/lib/dovecot/libdovecot.so.0(io_loop_run+0x38)
[0x7f77b4f3a628] ->
/usr/local/lib/dovecot/libdovecot.so.0(master_service_run+0x13) [0x7f77b4eeb5c3]
-> dovecot/indexer-worker [user at domain.de INBOX](main+0xe3) [0x401f03]
-> /lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0xf5) [0x7f77b4b1dde5]
-> dovecot/indexer-worker [user at domain.de INBOX]() [0x401fc2]
Apr 1 20:19:42 dovecot01 dovecot: indexer: Error: Indexer worker disconnected,
discarding 1 requests for user at domain.de
Apr 1 20:19:42 dovecot01 dovecot: indexer-worker(user at domain.de): Fatal:
master: service(indexer-worker): child 8806 killed with signal 6 (core dumped)
=================Core was generated by `dovecot/indexer-worker'.
Program terminated with signal 6, Aborted.
#0 0x00007f77b4b32f77 in __GI_raise (sig=sig at entry=6) at
../nptl/sysdeps/unix/sysv/linux/raise.c:56
56 ../nptl/sysdeps/unix/sysv/linux/raise.c: No such file or directory.
(gdb) bt full
#0 0x00007f77b4b32f77 in __GI_raise (sig=sig at entry=6) at
../nptl/sysdeps/unix/sysv/linux/raise.c:56
resultvar = 0
pid = 8806
selftid = 8806
#1 0x00007f77b4b365e8 in __GI_abort () at abort.c:90
save_stage = 2
act = {__sigaction_handler = {sa_handler = 0x0, sa_sigaction = 0x0}, sa_mask =
{__val = {12654816, 0, 140152119483509, 140149077835777, 0, 4202243,
140152109280488,
140733744696321, 0, 12801792, 140152119510821, 0, 140152110221056,
140152116161696, 12659256, 140733744696092}}, sa_flags = 4096,
sa_restorer = 0x7f77b4b4a134 }
sigs = {__val = {32, 0 }}
#2 0x00007f77b4f2aad8 in default_fatal_finish (type=, status=status at entry=0)
at failures.c:192
backtrace = 0xc119e8 "/usr/local/lib/dovecot/libdovecot.so.0(+0x66ab1)
[0x7f77b4f2aab1] -> /usr/local/lib/dovecot/libdovecot.so.0(+0x66b8e)
[0x7f77b4f2ab8e] -> /usr/local/lib/dovecot/libdovecot.so.0(i_fatal+0)
[0x7f77b4ee6"...
#3 0x00007f77b4f2ab8e in i_internal_fatal_handler (ctx=0x7fff20dc4cb0, format=,
args=) at failures.c:653
status = 0
#4 0x00007f77b4ee63ce in i_panic (format=format at entry=0x7f77b5268088
"file %s: line %d (%s): assertion failed: (%s)") at failures.c:264
ctx = {type = LOG_TYPE_PANIC, exit_status = 0, timestamp = 0x0}
args = {{gp_offset = 40, fp_offset = 48, overflow_arg_area = 0x7fff20dc4da0,
reg_save_area = 0x7fff20dc4ce0}}
#5 0x00007f77b524fc72 in log_append_ext_intro (ctx=ctx at entry=0x7fff20dc4ec0,
ext_id=ext_id at entry=5, reset_id=0, hdr_size_r=hdr_size_r at
entry=0x7fff20dc4e98)
at mail-index-transaction-export.c:117
t = 0xc6d700
intro = 0xc6dac4
resizes = 0xc6da60
buf = 0xc118e0
idx = 0
count = 6
__FUNCTION__ = "log_append_ext_intro"
#6 0x00007f77b5250140 in mail_transaction_log_append_ext_intros
(ctx=0x7fff20dc4ec0) at mail-index-transaction-export.c:283
resize =
ext_reset = {new_reset_id = 0, preserve_data = 0 '\000', unused_padding
= "\000\000"}
resize_count =
ext_count = 6
hdrs =
hdrs_count = 6
ext_id = 5
reset_count = 0
hdr_size = 0
reset = 0x0
reset_buf = {data = 0x7fff20dc4ea0, used = 8, priv = {0x7fff20dc4ea0, 0x0, 0x8,
0x0, 0x0}}
t =
reset_id_count = 0
reset_id =
reset_ids = 0x0
#7 mail_index_transaction_export (t=t at entry=0xc6d700, append_ctx=0xc6dcd0) at
mail-index-transaction-export.c:409
null4 = "\000\000\000"
change_mask = (unknown: 0)
ctx = {trans = 0xc6d700, append_ctx = 0xc6dcd0}
__FUNCTION__ = "mail_index_transaction_export"
#8 0x00007f77b524f32f in mail_index_transaction_commit_real
(commit_size_r=0x7fff20dc5000, t=0xc6d700) at mail-index-transaction.c:165
_data_stack_cur_id = 6
ctx = 0xc6dcd0
log_seq2 = 0
log_offset1 = 140733744697296
log = 0xc35bb0
trans_flags =
---Type to continue, or q to quit---
log_seq1 = 24
log_offset2 = 140733193388038
#9 mail_index_transaction_commit_v (t=0xc6d700, result_r=0x7fff20dc4ff0) at
mail-index-transaction.c:203
index = 0xc35190
changed = true
ret =
__FUNCTION__ = "mail_index_transaction_commit_v"
#10 0x00007f77b524f78d in mail_index_transaction_commit_full (_t=_t at
entry=0x7fff20dc5030, result_r=result_r at entry=0x7fff20dc4ff0) at
mail-index-transaction.c:262
t = 0xc6d700
index = 0xc35190
index_undeleted = false
#11 0x00007f77b524f82c in mail_index_transaction_commit (t=t at
entry=0x7fff20dc5030) at mail-index-transaction.c:236
result = {log_file_seq = 0, log_file_offset = 0, commit_size = 0,
ignored_modseq_changes = 0}
#12 0x00007f77b51d41ea in mdbox_write_index_header (box=box at entry=0xc345c0,
update=update at entry=0x0, trans=0xc6d700, trans at entry=0x0) at
mdbox-storage.c:312
mbox = 0xc345c0
new_trans = 0x0
view = 0x0
hdr = 0xc45e00
uid_validity = 1306175995
uid_next = 3038592790
#13 0x00007f77b51d444c in mdbox_mailbox_get_guid (guid_r=0x7fff20dc51f0
"", mbox=0xc345c0) at mdbox-storage.c:391
need_resize = true
ret = 0
idx_hdr =
hdr = {map_uid_validity = 0, mailbox_guid = '\000' , flags = 0
'\000', unused = "\000\000"}
#14 mdbox_mailbox_get_metadata (box=0xc345c0, items=, metadata_r=0x7fff20dc51f0)
at mdbox-storage.c:411
items =
metadata_r = 0x7fff20dc51f0
box = 0xc345c0
mbox = 0xc345c0
#15 0x00007f77b5226a15 in index_list_get_metadata (box=0xc345c0,
items=MAILBOX_METADATA_GUID, metadata_r=0x7fff20dc51f0) at
mailbox-list-index-status.c:202
ibox = 0xc34ed0
#16 0x00007f77b5213345 in mailbox_get_metadata (box=0xc345c0, items=items at
entry=MAILBOX_METADATA_GUID, metadata_r=metadata_r at entry=0x7fff20dc51f0) at
mail-storage.c:1544
__FUNCTION__ = "mailbox_get_metadata"
#17 0x00007f77b5227324 in node_lookup_guid (ctx=, guid_r=0x7fff20dc51d8
"", node=0xc30110) at mailbox-list-index-sync.c:25
box = 0xc345c0
vname =
str = 0xc11428
ns_sep =
metadata = {guid = '\000' , virtual_size = 0, cache_fields = 0x0,
precache_fields = (unknown: 0), backend_ns_prefix = 0x0, backend_ns_type =
(unknown: 0)}
#18 node_add_to_index (seq_r=0x7fff20dc51b0, node=0xc30110, ctx=0xc25bb0) at
mailbox-list-index-sync.c:45
_data_stack_cur_id = 5
irec = {name_id = 86, parent_uid = 76, guid = '\000' , uid_validity =
0}
seq = 12797376
#19 mailbox_list_index_node_add (seq_r=0x7fff20dc51b0, name=, parent=,
ctx=0xc25bb0) at mailbox-list-index-sync.c:87
node = 0xc30110
dup_name = 0xc30140 "Drafts"
#20 mailbox_list_index_sync_name (ctx=ctx at entry=0xc25bb0, name=,
node_r=node_r at entry=0x7fff20dc5298, created_r=created_r at
entry=0x7fff20dc528b)
at mailbox-list-index-sync.c:125
path = 0xc11310
empty_path = {0x7f77b52692ff "", 0x0}
node =
parent =
i = 1
seq = 0
---Type to continue, or q to quit---
__FUNCTION__ = "mailbox_list_index_sync_name"
#21 0x00007f77b522794a in mailbox_list_index_sync_list (sync_ctx=0xc25bb0) at
mailbox-list-index-sync.c:318
name =
_data_stack_cur_id = 4
iter = 0xc31b30
info = 0xc31bb0
flags = (unknown: 0)
node = 0xc2ff18
seq =
patterns = {0x7f77b52765d3 "*", 0x0}
created = false
#22 mailbox_list_index_sync (list=list at entry=0xc49360) at
mailbox-list-index-sync.c:390
sync_ctx = 0xc25bb0
ret = 0
#23 0x00007f77b522284e in mailbox_list_index_refresh (list=0xc49360) at
mailbox-list-index.c:380
ilist = 0xc497f8
view = 0xc275a0
ret =
#24 0x00007f77b522672e in index_list_update_mailbox (box=box at entry=0xc4a1a0)
at mailbox-list-index-status.c:363
ilist = 0xc497f8
list_sync_ctx = 0xc27270
list_view = 0xc48c20
list_trans = 0x7f77b5213a75
changes = {status = {messages = 256, recent = 0, unseen = 12890576, uidvalidity
= 0, uidnext = 65, first_unseen_seq = 0, first_recent_uid = 12886432,
last_cached_seq = 0,
highest_modseq = 140733744698432, highest_pvt_modseq = 12888328, keywords =
0xc49718, permanent_flags = 3025012879, permanent_keywords = 1,
allow_new_keywords = 1,
nonpermanent_modseqs = 1, have_guids = 0, have_save_guids = 1,
have_only_guid128 = 1}, guid =
"\360\261\304\000\000\000\000\000p\247\304\000\000\000\000",
seq = 12890576, rec_changed = false, msgs_changed = false, hmodseq_changed =
false}
ret =
__FUNCTION__ = "index_list_update_mailbox"
#25 0x00007f77b52269a3 in index_list_sync_deinit (ctx=0x0,
status_r=0x7fff20dc5440) at mailbox-list-index-status.c:470
box = 0xc4a1a0
ibox =
#26 0x00007f77b5211ef2 in mailbox_sync_deinit (_ctx=_ctx at
entry=0x7fff20dc5448, status_r=status_r at entry=0x7fff20dc5440) at
mail-storage.c:1691
ctx =
box = 0xc4a1a0
errormsg =
error = MAIL_ERROR_NONE
ret =
#27 0x00007f77b5211fa9 in mailbox_sync (box=, flags=) at mail-storage.c:1717
ctx = 0x0
status = {sync_delayed_expunges = 0}
#28 0x00000000004022f7 in index_mailbox (what=0xc0f07e "i",
max_recent_msgs=0, mailbox=0xc0f076 "INBOX", user=0xc52f00,
conn=0xc1bfb0) at master-connection.c:161
box = 0xc4a1a0
status = {messages = 5000, recent = 0, unseen = 3035915435, uidvalidity =
32631, uidnext = 64, first_unseen_seq = 0, first_recent_uid = 12679056,
last_cached_seq = 0,
highest_modseq = 5000, highest_pvt_modseq = 213, keywords = 0x7f77b4f01ac0 ,
permanent_flags = 12838464, permanent_keywords = 0,
allow_new_keywords = 0, nonpermanent_modseqs = 0, have_guids = 0,
have_save_guids = 0, have_only_guid128 = 0}
errstr =
ret = 0
ns =
path = 0xc11048
"/mnt/filestorage01/team.mail.de/m.kliewe/maildir/mailboxes/INBOX/dbox-Mails"
error = MAIL_ERROR_NONE
sync_flags =
#29 master_connection_input_line (line=, conn=0xc1bfb0) at
master-connection.c:208
str =
max_recent_msgs = 0
---Type to continue, or q to quit---
ret =
args =
input = {module = 0x4029ff "mail", service = 0x4029f0
"indexer-worker", username = 0xc0f060 "m.kliewe at
team.mail.de", session_id = 0x0, local_ip = {family = 0, u = {ip6 = {
__in6_u = {__u6_addr8 = '\000' , __u6_addr16 = {0, 0, 0, 0, 0, 0, 0,
0}, __u6_addr32 = {0, 0, 0, 0}}}, ip4 = {s_addr = 0}}}, remote_ip = {
family = 0, u = {ip6 = {__in6_u = {__u6_addr8 = '\000' , __u6_addr16 =
{0, 0, 0, 0, 0, 0, 0, 0}, __u6_addr32 = {0, 0, 0, 0}}}, ip4 = {s_addr = 0}}},
local_port = 0, remote_port = 0, userdb_fields = 0x0, flags_override_add =
(unknown: 0), flags_override_remove = (unknown: 0), no_userdb_lookup = 0}
service_user = 0xc1f098
user = 0xc52f00
error = 0x7fff20dc5620 "\002"
#30 master_connection_input (conn=0xc1bfb0) at master-connection.c:245
_data_stack_cur_id = 3
line =
#31 0x00007f77b4f3aa87 in io_loop_call_io (io=0xc1bff0) at ioloop.c:388
ioloop = 0xc17730
t_id = 2
#32 0x00007f77b4f3b817 in io_loop_handler_run (ioloop=ioloop at entry=0xc17730)
at ioloop-epoll.c:220
ctx = 0xc1a560
list = 0xc1c040
io =
tv = {tv_sec = 0, tv_usec = 0}
events_count =
msecs =
ret = 1
i = 0
call =
__FUNCTION__ = "io_loop_handler_run"
#33 0x00007f77b4f3a628 in io_loop_run (ioloop=0xc17730) at ioloop.c:412
__FUNCTION__ = "io_loop_run"
#34 0x00007f77b4eeb5c3 in master_service_run (service=0xc175c0,
callback=callback at entry=0x402090 ) at master-service.c:566
No locals.
#35 0x0000000000401f03 in main (argc=1, argv=0xc17390) at indexer-worker.c:78
storage_service_flags = (MAIL_STORAGE_SERVICE_FLAG_DISALLOW_ROOT |
MAIL_STORAGE_SERVICE_FLAG_USERDB_LOOKUP |
MAIL_STORAGE_SERVICE_FLAG_TEMP_PRIV_DROP |
MAIL_STORAGE_SERVICE_FLAG_NO_IDLE_TIMEOUT)
c =
==================
Florian Pritz
2014-Apr-14 17:49 UTC
[Dovecot] imap process and indexer-worker crash while creating folders
Hi, I just noticed a similar crash (well same assertion at least) on my production server. No idea what the user did, but I know it's a normal client, not some kind of script. Since I don't know what the user did I can't reproduce the problem, but I figured dropping a note won't hurt. I'm running dovecot 2.2.11 on Arch Linux with ext4, config and backtraces below. PS: I'm not subscribed to the list, please make sure to CC me on replies. Thanks, Florian ###> Apr 14 09:49:29 karif dovecot: imap(user): Panic: file mail-index-transaction-export.c: line 117 (log_append_ext_intro): assertion failed: (intro->ext_id == idx || idx == (uint32_t)-1) > Apr 14 09:49:29 karif dovecot: imap(user): Error: Raw backtrace: /usr/lib/dovecot/libdovecot.so.0(+0x67450) [0x7f842e6c2450] -> /usr/lib/dovecot/libdovecot.so.0(+0x6752e) [0x7f842e6c252e] -> /usr/lib/dovecot/libdovecot.so.0(i_fatal+0) [0x7f842e67d47e] -> /usr/lib/dovecot/libdovecot-storage.so.0(+0xba112) [0x7f842e9e8112] -> /usr/lib/dovecot/libdovecot-storage.so.0(mail_index_transaction_export+0x200) [0x7f842e9e85e0] -> /usr/lib/dovecot/libdovecot-storage.so.0(+0xb979f) [0x7f842e9e779f] -> /usr/lib/dovecot/libdovecot-storage.so.0(mail_index_transaction_commit_full+0x9d) [0x7f842e9e7bfd] -> /usr/lib/dovecot/libdovecot-storage.so.0(mail_index_transaction_commit+0xc) [0x7f842e9e7c9c] -> /usr/lib/dovecot/libdovecot-storage.so.0(+0x3e25a) [0x7f842e96c25a] -> /usr/lib/dovecot/libdovecot-storage.so.0(+0x3e4bc) [0x7f842e96c4bc] -> /usr/lib/dovecot/libdovecot-storage.so.0(+0x90e45) [0x7f842e9bee45] -> /usr/lib/dovecot/libdovecot-storage.so.0(mailbox_get_metadata+0x95) [0x7f842e9ab595] -> /usr/lib/dovecot/libdovecot-storage.so.0(mailbox_list_index_sync_name+0x2a4) [0x7f842e9bf754] -> /usr/lib/dovecot/libdovecot-storage.so.0(mailbox_list_index_sync+0x10a) [0x7f842e9bfd7a] -> /usr/lib/dovecot/libdovecot-storage.so.0(mailbox_list_index_refresh+0x9e) [0x7f842e9bac8e] -> /usr/lib/dovecot/libdovecot-storage.so.0(+0x90292) [0x7f842e9be292] -> /usr/lib/dovecot/libdovecot-storage.so.0(+0x90f9b) [0x7f842e9bef9b] -> /usr/lib/dovecot/libdovecot-storage.so.0(mailbox_get_status+0x31) [0x7f842e9ab4b1] -> dovecot/imap(imap_status_get+0x67) [0x41d5d7] -> dovecot/imap(cmd_status+0x123) [0x413133] -> dovecot/imap(command_exec+0x3c) [0x4170ec] -> dovecot/imap() [0x41614f] -> dovecot/imap() [0x416205] -> dovecot/imap(client_handle_input+0x115) [0x416505] -> dovecot/imap(client_input+0x72) [0x416892] -> /usr/lib/dovecot/libdovecot.so.0(io_loop_call_io+0x27) [0x7f842e6d2527] -> /usr/lib/dovecot/libdovecot.so.0(io_loop_handler_run+0xd7) [0x7f842e6d32b7] -> /usr/lib/dovecot/libdovecot.so.0(io_loo p_run+0x38) [0x7f842e6d20c8]> Apr 14 09:49:29 karif dovecot: imap(user): Fatal: master: service(imap): child 20156 killed with signal 6 (core dumped)backtrace from a core dump below, sadly it doesn't contain much information since the dovecot build I'm running stripped.> #0 0x00007f842e2e8389 in raise () from /usr/lib/libc.so.6 > #1 0x00007f842e2e9788 in abort () from /usr/lib/libc.so.6 > #2 0x00007f842e6c2446 in ?? () from /usr/lib/dovecot/libdovecot.so.0 > #3 0x00007f842e6c252e in ?? () from /usr/lib/dovecot/libdovecot.so.0 > #4 0x00007f842e67d47e in i_panic () from /usr/lib/dovecot/libdovecot.so.0 > #5 0x00007f842e9e8112 in ?? () from /usr/lib/dovecot/libdovecot-storage.so.0 > #6 0x00007f842e9e85e0 in mail_index_transaction_export () from /usr/lib/dovecot/libdovecot-storage.so.0 > #7 0x00007f842e9e779f in ?? () from /usr/lib/dovecot/libdovecot-storage.so.0 > #8 0x00007f842e9e7bfd in mail_index_transaction_commit_full () from /usr/lib/dovecot/libdovecot-storage.so.0 > #9 0x00007f842e9e7c9c in mail_index_transaction_commit () from /usr/lib/dovecot/libdovecot-storage.so.0 > #10 0x00007f842e96c25a in ?? () from /usr/lib/dovecot/libdovecot-storage.so.0 > #11 0x00007f842e96c4bc in ?? () from /usr/lib/dovecot/libdovecot-storage.so.0 > #12 0x00007f842e9bee45 in ?? () from /usr/lib/dovecot/libdovecot-storage.so.0 > #13 0x00007f842e9ab595 in mailbox_get_metadata () from /usr/lib/dovecot/libdovecot-storage.so.0 > #14 0x00007f842e9bf754 in mailbox_list_index_sync_name () from /usr/lib/dovecot/libdovecot-storage.so.0 > #15 0x00007f842e9bfd7a in mailbox_list_index_sync () from /usr/lib/dovecot/libdovecot-storage.so.0 > #16 0x00007f842e9bac8e in mailbox_list_index_refresh () from /usr/lib/dovecot/libdovecot-storage.so.0 > #17 0x00007f842e9be292 in ?? () from /usr/lib/dovecot/libdovecot-storage.so.0 > #18 0x00007f842e9bef9b in ?? () from /usr/lib/dovecot/libdovecot-storage.so.0 > #19 0x00007f842e9ab4b1 in mailbox_get_status () from /usr/lib/dovecot/libdovecot-storage.so.0 > #20 0x000000000041d5d7 in imap_status_get () > #21 0x0000000000413133 in cmd_status () > #22 0x00000000004170ec in command_exec () > #23 0x000000000041614f in ?? () > #24 0x0000000000416205 in ?? () > #25 0x0000000000416505 in client_handle_input () > #26 0x0000000000416892 in client_input () > #27 0x00007f842e6d2527 in io_loop_call_io () from /usr/lib/dovecot/libdovecot.so.0 > #28 0x00007f842e6d32b7 in io_loop_handler_run () from /usr/lib/dovecot/libdovecot.so.0 > #29 0x00007f842e6d20c8 in io_loop_run () from /usr/lib/dovecot/libdovecot.so.0 > #30 0x00007f842e682683 in master_service_run () from /usr/lib/dovecot/libdovecot.so.0 > #31 0x000000000040b44f in main ()config:> # 2.2.11: /etc/dovecot/dovecot.conf > # OS: Linux 3.13.8-1-ARCH x86_64 Arch Linux > auth_mechanisms = plain login > auth_username_format = %Ln > login_log_format_elements = user=<%u> method=%m rip=%r lip=%l mpid=%e %c %k > mail_location = mdbox:~/.mdbox > mail_plugins = " zlib notify mail_log" > mailbox_list_index = yes > 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 > namespace inbox { > hidden = no > inbox = yes > list = yes > location = > mailbox Drafts { > auto = subscribe > special_use = \Drafts > } > mailbox Junk { > auto = subscribe > special_use = \Junk > } > mailbox Sent { > auto = subscribe > special_use = \Sent > } > mailbox Trash { > auto = subscribe > special_use = \Trash > } > prefix = > separator = . > type = private > } > passdb { > driver = pam > } > plugin { > mail_log_events = delete undelete expunge copy mailbox_delete mailbox_rename > mail_log_fields = uid box msgid size > sieve = ~/.dovecot.sieve > sieve_dir = ~/.sieve > sieve_global_dir = /etc/dovecot/sieve/global/ > sieve_global_path = /etc/dovecot/sieve/default.sieve > zlib_save = gz > zlib_save_level = 6 > } > protocols = imap pop3 sieve lmtp > service auth { > unix_listener auth-client { > group = postfix > mode = 0660 > user = postfix > } > user = root > } > service imap-login { > process_limit = 400 > process_min_avail = 5 > } > service lmtp { > unix_listener /var/spool/postfix/private/dovecot-lmtp { > group = postfix > mode = 0660 > user = postfix > } > } > service managesieve-login { > inet_listener sieve-obsolete { > port = 2000 > } > } > ssl_cert = </etc/ssl/my-certs/mail.pem > ssl_cipher_list = DHE-ECDSA-AES256-GCM-SHA384:DHE-RSA-AES256-GCM-SHA384:ECDHE-ECDSA-AES256-GCM-SHA384:ECDHE-RSA-AES256-GCM-SHA384:DHE-ECDSA-AES256-SHA384:DHE-RSA-AES256-SHA384:ECDHE-ECDSA-AES256-SHA384:ECDHE-RSA-AES256-SHA384:DHE-ECDSA-AES128-GCM-SHA256:DHE-RSA-AES128-GCM-SHA256:ECDHE-ECDSA-AES128-GCM-SHA256:ECDHE-RSA-AES128-GCM-SHA256:DHE-RSA-AES256-SHA256:ECDHE-RSA-AES256-SHA256:DHE-ECDSA-AES128-SHA256:DHE-RSA-AES128-SHA256:ECDHE-ECDSA-AES128-SHA256:ECDHE-RSA-AES128-SHA256:DHE-RSA-AES256-SHA:ECDHE-RSA-AES256-SHA:DHE-RSA-AES128-SHA:EDH-RSA-DES-CBC3-SHA:DHE-RSA-AES256-SHA:DHE-RSA-AES128-SHA:ALL:!LOW:!SSLv2:!EXP:!aNULL > ssl_key = </etc/ssl/private/server.key > userdb { > driver = passwd > } > protocol imap { > imap_client_workarounds = tb-extra-mailbox-sep > mail_max_userip_connections = 30 > mail_plugins = " zlib notify mail_log" > } > protocol lda { > mail_plugins = " zlib notify mail_log sieve" > postmaster_address = postmaster at server-speed.net > } > protocol lmtp { > mail_plugins = " zlib notify mail_log sieve" > postmaster_address = postmaster at server-speed.net > } > protocol sieve { > managesieve_logout_format = bytes ( in=%i : out=%o ) > }-------------- next part -------------- A non-text attachment was scrubbed... Name: signature.asc Type: application/pgp-signature Size: 836 bytes Desc: OpenPGP digital signature URL: <http://dovecot.org/pipermail/dovecot/attachments/20140414/61b39bf7/attachment-0001.sig>
Timo Sirainen
2014-May-07 13:37 UTC
[Dovecot] imap process and indexer-worker crash while creating folders
On 1.4.2014, at 21.34, Michael Kliewe <mkliewe at gmx.de> wrote:> our dovecot processes sometimes crash when we create new folders. The "imap" process and the "indexer worker" process is crashing. We can reproduce this, we have a java program with multiple threads, and sometimes 2 threads try to create the same folder for the same user, and if both collide, dovecot processes crash. > > We don't see this happening in the real world if "normal" imap clients are connected, but our special java program trying to create folders in parallel is producing these crashes...> Apr 1 19:58:28 dovecot01 dovecot: imap(user at domain.de): Panic: file mail-index-transaction-export.c: line 117 (log_append_ext_intro): assertion failed: (intro->ext_id == idx || idx == (uint32_t)-1)Fixed: http://hg.dovecot.org/dovecot-2.2/rev/ed6e472cab0e