Hi all,
I have a Dovecot core that I am trying to track down, in an attempt to
replicate so I can log a bug report, and am hoping others might be able to
help me as I?m reaching my limit.
My working theory is that two user sessions are active at the same time,
one of the sessions is ?mid-search? (or perhaps in idle state) on a virtual
folder where the number of results is zero (due to a null results array),
when another session either performs an append or perhaps a new message
arrives in the virtual view and qualifies for the search.
It seems that the current list of UID?s in the search results is zero
(null), and new messages are being appended to the search results, which
results in a divide by zero.
But I have not been able to create a scenario to replicate this on my test
box, but is occurring regularly (every hour or so) on my mail server. I
have been able to replicate on my test box using a single account by
performing many random operations over and over again, with multiple
sessions, but took over 24 hours and I can?t isolate the action that caused
it.
Dovecot version is 2.2.36 (1f10bfa63) as shipped with Centos 7 (latest
update). If I can reproduce, I can then test the latest 2.3 and see if
this is still a problem in that version.
Here is the full back trace:
#0 0x00007f8d40636e58 in array_count_i (array=0x557be80cc168) at
array.h:155
No locals.
#1 array_get_i (count_r=<synthetic pointer>, array=0x557be80cc168) at
array.h:209
No locals.
#2 seq_range_lookup (array=0x557be80cc168, seq=2222, idx_r=0x7ffead4141d4)
at seq-range-array.c:14
data = <optimized out>
idx = <optimized out>
left_idx = <optimized out>
right_idx = <optimized out>
count = <optimized out>
#3 0x00007f8d406379ae in seq_range_exists (array=array at entry=0x557be80cc168,
seq=seq at entry=2222) at seq-range-array.c:391
idx = 32766
#4 0x00007f8d408fd3d9 in mailbox_search_result_add
(result=result at entry=0x557be80cc150,
uid=2222) at mailbox-search-result.c:121
__FUNCTION__ = "mailbox_search_result_add"
#5 0x00007f8d40962f30 in index_search_result_update_appends
(result=result at entry=0x557be80cc150, old_messages_count=<optimized
out>)
at index-search-result.c:168
t = 0x557be7fb1820
search_ctx = 0x557be7fef860
mail = 0x557be8100198
search_arg = {next = 0x557be7fab460, type = SEARCH_SEQSET, value
{subargs = 0x0, seqset = {arr = {buffer = 0x557be7f69208,
element_size = 8}, v = 0x557be7f69208, v_modifiable
0x557be7f69208}, str = 0x0, time = 0, size = 0, flags = 0,
search_flags = (unknown: 0), date_type = 0, thread_type
MAIL_THREAD_NONE, modseq = 0x0, search_result = 0x0,
mime_part = 0x0}, initialized = {search_args = 0x0, keywords 0x0,
mailbox_glob = 0x0}, context = 0x0, hdr_field_name = 0x0,
match_not = 0, match_always = 0, nonmatch_always = 0, fuzzy = 0,
no_fts = 0, result = -1}
message_count = 2008
ret = <optimized out>
__FUNCTION__ = "index_search_result_update_appends"
#6 0x00007f8d4096dc37 in search_result_update (result=0x557be80cc150,
ctx=0x557be7ff8950) at index-sync-search.c:78
No locals.
#7 index_sync_search_results_update (ctx=ctx at entry=0x557be7ff8950) at
index-sync-search.c:88
results = 0x557be7f9d480
i = <optimized out>
count = <optimized out>
#8 0x00007f8d4096e4b4 in index_mailbox_sync_deinit (_ctx=0x557be7ff8950,
status_r=0x557be7ff0108) at index-sync.c:353
ctx = 0x557be7ff8950
sync_rec = {seq1 = 0, seq2 = 0, type = MAILBOX_SYNC_TYPE_EXPUNGE}
delayed_expunges = false
ret = <optimized out>
#9 0x00007f8d40950400 in mailbox_list_index_sync_deinit
(ctx=0x557be7ff8950, status_r=0x557be7ff0108) at mailbox-list-index.c:976
---Type <return> to continue, or q <return> to quit---
ibox = 0x557be7fd0bf0
box = 0x557be7f9d078
#10 0x00007f8d408ed568 in mailbox_sync_deinit (_ctx=<optimized out>,
status_r=<optimized out>) at mail-storage.c:1953
ctx = <optimized out>
box = <optimized out>
errormsg = <optimized out>
error = MAIL_ERROR_NONE
ret = <optimized out>
#11 0x0000557be6613431 in imap_sync_finish (ctx=ctx at entry=0x557be7ff0090,
aborting=aborting at entry=false) at imap-sync.c:279
client = 0x557be7f8a6d8
ret = 0
#12 0x0000557be6613fed in imap_sync_more (ctx=0x557be7ff0090) at
imap-sync.c:594
str = <optimized out>
ret = 1
__FUNCTION__ = "imap_sync_more"
#13 0x0000557be6614676 in cmd_sync_continue (sync_cmd=0x557be7f8be88) at
imap-sync.c:629
cmd = 0x557be7f75e40
prev = <optimized out>
client = 0x557be7f8a6d8
ctx = 0x557be7ff0090
ret = <optimized out>
__FUNCTION__ = "cmd_sync_continue"
#14 0x0000557be6614b34 in cmd_sync_client (sync_cmd=0x557be7f8be88) at
imap-sync.c:720
ctx = <optimized out>
flags = <optimized out>
client = 0x557be7f8a6d8
imap_flags = <optimized out>
no_newmail = <optimized out>
#15 cmd_sync_delayed_real (client=0x557be7f8a6d8) at imap-sync.c:833
cmd = <optimized out>
first_expunge = <optimized out>
first_nonexpunge = <optimized out>
#16 cmd_sync_delayed (client=client at entry=0x557be7f8a6d8) at imap-sync.c:841
_data_stack_cur_id = 3
#17 0x0000557be6607a18 in client_handle_input
(client=client at entry=0x557be7f8a6d8)
at imap-client.c:1233
remove_io = <optimized out>
handled_commands = <optimized out>
__FUNCTION__ = "client_handle_input"
#18 0x0000557be6607eb5 in client_input (client=0x557be7f8a6d8) at
imap-client.c:1264
---Type <return> to continue, or q <return> to quit---
cmd = 0xcfee4
output = 0x557be7f8bd90
bytes = 2052
__FUNCTION__ = "client_input"
#19 0x00007f8d40624be2 in io_loop_call_io (io=0x557be7f84cb0) at
ioloop.c:600
ioloop = 0x557be7f719c0
t_id = 2
__FUNCTION__ = "io_loop_call_io"
#20 0x00007f8d406262cf in io_loop_handler_run_internal
(ioloop=ioloop at entry=0x557be7f719c0)
at ioloop-epoll.c:223
ctx = 0x557be7f734e0
events = <optimized out>
list = 0x557be7f74f40
io = <optimized out>
tv = {tv_sec = 1795, tv_usec = 114881}
events_count = <optimized out>
msecs = <optimized out>
ret = 1
i = 0
call = <optimized out>
__FUNCTION__ = "io_loop_handler_run_internal"
#21 0x00007f8d40624c7c in io_loop_handler_run
(ioloop=ioloop at entry=0x557be7f719c0)
at ioloop.c:649
No locals.
#22 0x00007f8d40624e38 in io_loop_run (ioloop=0x557be7f719c0) at
ioloop.c:624
__FUNCTION__ = "io_loop_run"
#23 0x00007f8d405a9c03 in master_service_run (service=0x557be7f71860,
callback=callback at entry=0x557be6614e30 <client_connected>)
at master-service.c:724
No locals.
#24 0x0000557be65fa262 in main (argc=1, argv=0x557be7f715f0) at main.c:484
set_roots = {0x557be6825700 <imap_setting_parser_info>,
0x7f8d40df95a0, 0x0}
login_set = {auth_socket_path = 0x557be7f69048 "\001",
postlogin_socket_path = 0x0, postlogin_timeout_secs = 60,
callback = 0x557be6615600 <login_client_connected>,
failure_callback = 0x557be6614f40 <login_client_failed>,
request_auth_token = 1}
service_flags = <optimized out>
storage_service_flags = <optimized out>
username = 0x0
auth_socket_path = <optimized out>
c = <optimized out>
And the output of array in frame #0:
(gdb) f 0
#0 0x00007f8d40636e58 in array_count_i (array=0x557be80cc168) at
array.h:155
155 return array->buffer->used / array->element_size;
(gdb) p *array
$2 = {buffer = 0x0, element_size = 0}
Here is the virtual folder config in use:
# cat /etc/dovecot/virtual/combined/dovecot-virtual
!INBOX
INBOX/Sent
INBOX/Drafts
all
Any help would be greatly appreciated in diagnosing the cause here.
Thanks,
Dave
-------------- next part --------------
An HTML attachment was scrubbed...
URL:
<https://dovecot.org/pipermail/dovecot/attachments/20191009/370ce0ce/attachment-0001.html>
