mail-search backtrace

[Hugh Bragg]

On 27/06/16 16:35, Aki Tuomi wrote:
>
> On 25.06.2016 08:25, Hugh Bragg wrote:
>> On 22/05/16 05:17, Hugh Bragg wrote:
>>>
>>> On 13/04/16 06:41, Timo Sirainen wrote:
>>>> On 09 Apr 2016, at 21:48, Hugh Bragg <hughbragg at dodo.com.au> wrote:
>>>>> I'm repeatedly getting this error:
>>>>>
>>>>> Apr 07 04:37:27 imap(mymail at address): Panic: file mail-search.c:
>>>>> line 84 (mail_search_arg_init): assertion failed:
>>>>> (arg->initialized.keywords == NULL)
>>>>> Apr 07 04:37:27 imap(mymail at address): Error: Raw backtrace:
>>>>> /usr/lib64/dovecot/libdovecot.so.0(+0x827c2) [0x7fcb7f65e7c2] ->
>>>>> /usr/lib64/dovecot/libdovecot.so.0(+0x828ad) [0x7fcb7f65e8ad] ->
>>>>> /usr/lib64/dov
>>>>> ecot/libdovecot.so.0(i_fatal+0) [0x7fcb7f605b01] ->
>>>>> /usr/lib64/dovecot/libdovecot-storage.so.0(mail_search_arg_init+0x228)
>>>>> [0x7fcb7f91a328] ->
>>>>> /usr/lib64/dovecot/libdovecot-storage.so.0(index_search_result_updat
>>>>> e_flags+0x100) [0x7fcb7f98e470] ->
>>>>> /usr/lib64/dovecot/libdovecot-storage.so.0(index_sync_search_results_update+0x52)
>>>>> [0x7fcb7f9983e2] ->
>>>>> /usr/lib64/dovecot/libdovecot-storage.so.0(index_mailbox_sync_deinit+0x185
>>>>> ) [0x7fcb7f998bb5] ->
>>>>> /usr/lib64/dovecot/libdovecot-storage.so.0(mailbox_sync_deinit+0x32) [0x7fcb7f921222]
>>>>> ->
>>>>> /usr/lib64/dovecot/lib20_virtual_plugin.so(virtual_storage_sync_init+0xab3)
>>>>> [0x7fcb7e9f7313] -> /usr
>>>> It's coming from virtual mailboxes.
>>>>
>>>>> namespace virtual {
>>>>>    location = virtual:/var/mail/vhosts/%d/%n/virtual
>>>>>    prefix = virtual.
>>>>>    separator = .
>>>>> }
>>>> What do your dovecot-virtual files contain? I guess opening one of
>>>> those virtual mailboxes crashes always. Related to searching keywords.
>>> It still happens once in a while. It just won't expunge old messages
>>> from unseen. There is no other trace or log message.
>>> I was hoping to isolate the cause, but all I could only say for sure
>>> that it happens sometime after Dovecot first starts up and I have to
>>> restart to fix it.
>>> dovecot-virtual files look like this:
>>> # cat virtual/all/dovecot-virtual
>>> *
>>>    all
>>> # cat virtual/Unseen/dovecot-virtual
>>> virtual.all
>>>    inthread refs unseen
>>>
>>>
>>> A fresh trace:
>>>
>>> May 21 00:28:08 imap(x at y): Panic: file mail-search.c: line 84
>>> (mail_search_arg_init): assertion failed: (arg->initialized.keywords
>>> == NULL)
>>> May 21 00:28:08 imap(x at y): Error: Raw backtrace:
>>> /usr/lib64/dovecot/libdovecot.so.0(+0x85c62) [0x7f4fd8915c62] ->
>>> /usr/lib64/dovecot/libdovecot.so.0(+0x85d4d) [0x7f4fd8915d4d] ->
>>> /usr/lib64/dov
>>> ecot/libdovecot.so.0(i_fatal+0) [0x7f4fd88ba5c1] ->
>>> /usr/lib64/dovecot/libdovecot-storage.so.0(mail_search_arg_init+0x228) [0x7f4fd8bd4b78]
>>> -> /usr/lib64/dovecot/libdovecot-storage.so.0(index_search_result_updat
>>> e_flags+0x100) [0x7f4fd8c49d00] ->
>>> /usr/lib64/dovecot/libdovecot-storage.so.0(index_sync_search_results_update+0x52)
>>> [0x7f4fd8c53ce2] ->
>>> /usr/lib64/dovecot/libdovecot-storage.so.0(index_mailbox_sync_deinit+0x185
>>> ) [0x7f4fd8c544b5] ->
>>> /usr/lib64/dovecot/libdovecot-storage.so.0(mailbox_sync_deinit+0x32)
>>> [0x7f4fd8bdba82] ->
>>> /usr/lib64/dovecot/lib20_virtual_plugin.so(virtual_storage_sync_init+0x538)
>>> [0x7f4fd7caa428] -> /usr
>>> /lib64/dovecot/libdovecot-storage.so.0(mailbox_sync_init+0x3b)
>>> [0x7f4fd8bdb9fb] -> dovecot/imap(imap_sync_init+0x68)
>>> [0x56091d93b078] -> dovecot/imap(+0x1210e) [0x56091d92710e] ->
>>> dovecot/imap(+0x1234d) [0x56091
>>> d92734d] ->
>>> /usr/lib64/dovecot/libdovecot.so.0(io_loop_handle_timeouts+0xea)
>>> [0x7f4fd892984a] ->
>>> /usr/lib64/dovecot/libdovecot.so.0(io_loop_handler_run_internal+0xbb)
>>> [0x7f4fd892ae4b] -> /usr/lib64/dovecot/libdo
>>> vecot.so.0(io_loop_handler_run+0x25) [0x7f4fd8929a75] ->
>>> /usr/lib64/dovecot/libdovecot.so.0(io_loop_run+0x38) [0x7f4fd8929c18]
>>> -> /usr/lib64/dovecot/libdovecot.so.0(master_service_run+0x13)
>>> [0x7f4fd88c0123] -> d
>>> ovecot/imap(main+0x328) [0x56091d922a98] ->
>>> /lib64/libc.so.6(__libc_start_main+0xf0) [0x7f4fd84ef580] ->
>>> dovecot/imap(_start+0x29) [0x56091d922c19]
>> Still no clue on this even with debug set on. It's become so bad I
>> need to restart it or new mail is no longer reported after a few days
>> when the unseen has dozens of read mails.
>> I've no idea why it would need the keyword when I haven't done a
>> search but I suppose the virtual plugin works by using the
>> mail-search. Still, this shouldn't cause an error even if it is null.
>> I'm suppose it could be caused by the number of emails being so great.
>> Perhaps something is corrupt but as given, my dovecot-virtual files
>> are as recommended by the plugin doco and nothing else seems amiss. If
>> there is a corrupt mail or something then I don't know how to trace it.
>>
>> Anything anyone?
>>
>>
>> A fresh trace :
>> Jun 25 15:10:30 imap(x at y.z): Panic: file mail-search.c: line 84
>> (mail_search_arg_init): assertion failed: (arg->initialized.keywords
>> == NULL)
>> Jun 25 15:10:30 imap(x at y.z): Error: Raw backtrace:
>> /usr/lib64/dovecot/libdovecot.so.0(+0x87102) [0x7fcb73696102] ->
>> /usr/lib64/dovecot/libdovecot.so.0(+0x871ed) [0x7fcb736961ed] ->
>> /usr/lib64/dovecot/libdovecot.so.0(i_fatal+0) [0x7fcb736399e1] ->
>> /usr/lib64/dovecot/libdovecot-storage.so.0(mail_search_arg_init+0x228)
>> [0x7fcb73955cc8] ->
>> /usr/lib64/dovecot/libdovecot-storage.so.0(index_search_result_update_flags+0x100)
>> [0x7fcb739cb3f0] ->
>> /usr/lib64/dovecot/libdovecot-storage.so.0(index_sync_search_results_update+0x52)
>> [0x7fcb739d5392] ->
>> /usr/lib64/dovecot/libdovecot-storage.so.0(index_mailbox_sync_deinit+0x185)
>> [0x7fcb739d5b65] ->
>> /usr/lib64/dovecot/libdovecot-storage.so.0(mailbox_sync_deinit+0x32)
>> [0x7fcb7395cbd2] ->
>> /usr/lib64/dovecot/lib20_virtual_plugin.so(virtual_storage_sync_init+0x538)
>> [0x7fcb72e434f8] ->
>> /usr/lib64/dovecot/libdovecot-storage.so.0(mailbox_sync_init+0x3b)
>> [0x7fcb7395cb4b] -> dovecot/imap(imap_sync_init+0x68) [0x55cfd865d0f8]
>> -> dovecot/imap(+0x1217e) [0x55cfd864917e] -> dovecot/imap(+0x123bd)
>> [0x55cfd86493bd] ->
>> /usr/lib64/dovecot/libdovecot.so.0(io_loop_handle_timeouts+0xea)
>> [0x7fcb736a9dba] ->
>> /usr/lib64/dovecot/libdovecot.so.0(io_loop_handler_run_internal+0xbb)
>> [0x7fcb736ab3bb] ->
>> /usr/lib64/dovecot/libdovecot.so.0(io_loop_handler_run+0x25)
>> [0x7fcb736a9fe5] ->
>> /usr/lib64/dovecot/libdovecot.so.0(io_loop_run+0x38) [0x7fcb736aa188]
>> -> /usr/lib64/dovecot/libdovecot.so.0(master_service_run+0x13)
>> [0x7fcb7363fea3] -> dovecot/imap(main+0x328) [0x55cfd8644b08] ->
>> /lib64/libc.so.6(__libc_start_main+0xf0) [0x7fcb7326e580] ->
>> dovecot/imap(_start+0x29) [0x55cfd8644c89]
> Hi!
>
> Thank you for your report, we'll look into it.
>
> ---
> Aki Tuomi
> Dovecot oy
Some hopefully useful further debugging logs:

Jun 29 04:50:02 imap(username at nodo.com.au): Debug: Loading modules from 
directory: /usr/lib64/dovecot
Jun 29 04:50:02 imap(username at nodo.com.au): Debug: Module loaded: 
/usr/lib64/dovecot/lib20_virtual_plugin.so
Jun 29 04:50:02 imap(username at nodo.com.au): Debug: Effective uid=5000, 
gid=5000, home=/var/mail/vhosts/nodo.com.au/username
Jun 29 04:50:02 imap(username at nodo.com.au): Debug: Namespace inbox: 
type=private, prefix=, sep=, inbox=yes, hidden=no, list=yes, 
subscriptions=yes location=maildir:~/mail
Jun 29 04:50:02 imap(username at nodo.com.au): Debug: maildir++: 
root=/var/mail/vhosts/nodo.com.au/username/mail, index=, indexpvt=, 
control=, inbox=/var/mail/vhosts/nodo.com.au/username/mail, alt=
Jun 29 04:50:02 imap(username at nodo.com.au): Debug: Namespace virtual: 
type=private, prefix=virtual., sep=., inbox=no, hidden=no, list=yes, 
subscriptions=yes location=virtual:/var/mail/vhosts/nodo.com.au/hughbra
gg/virtual
Jun 29 04:50:02 imap(username at nodo.com.au): Debug: fs: 
root=/var/mail/vhosts/nodo.com.au/username/virtual, index=, indexpvt=, 
control=, inbox=, alt=
Jun 29 04:50:06 imap(username at nodo.com.au): Panic: file mail-search.c: 
line 84 (mail_search_arg_init): assertion failed: 
(arg->initialized.keywords == NULL)
Jun 29 04:50:06 imap(username at nodo.com.au): Error: Raw backtrace: 
/usr/lib64/dovecot/libdovecot.so.0(+0x87102) [0x7f68355e1102] -> 
/usr/lib64/dovecot/libdovecot.so.0(+0x871ed) [0x7f68355e11ed] -> 
/usr/lib64/dov
ecot/libdovecot.so.0(i_fatal+0) [0x7f68355849e1] -> 
/usr/lib64/dovecot/libdovecot-storage.so.0(mail_search_arg_init+0x228) 
[0x7f68358a0cc8] -> 
/usr/lib64/dovecot/libdovecot-storage.so.0(index_search_result_updat
e_flags+0x100) [0x7f68359163f0] -> 
/usr/lib64/dovecot/libdovecot-storage.so.0(index_sync_search_results_update+0x52) 
[0x7f6835920392] -> 
/usr/lib64/dovecot/libdovecot-storage.so.0(index_mailbox_sync_deinit+0x185
) [0x7f6835920b65] -> 
/usr/lib64/dovecot/libdovecot-storage.so.0(mailbox_sync_deinit+0x32) 
[0x7f68358a7bd2] -> 
/usr/lib64/dovecot/lib20_virtual_plugin.so(virtual_storage_sync_init+0x538) 
[0x7f6834d8e4f8] -> /usr
/lib64/dovecot/libdovecot-storage.so.0(mailbox_sync_init+0x3b) 
[0x7f68358a7b4b] -> dovecot/imap(imap_sync_init+0x68) [0x55fa42fc70f8] 
-> dovecot/imap(+0x1217e) [0x55fa42fb317e] -> dovecot/imap(+0x123bd) 
[0x55fa4
2fb33bd] -> 
/usr/lib64/dovecot/libdovecot.so.0(io_loop_handle_timeouts+0xea) 
[0x7f68355f4dba] -> 
/usr/lib64/dovecot/libdovecot.so.0(io_loop_handler_run_internal+0xbb) 
[0x7f68355f63bb] -> /usr/lib64/dovecot/libdo
vecot.so.0(io_loop_handler_run+0x25) [0x7f68355f4fe5] -> 
/usr/lib64/dovecot/libdovecot.so.0(io_loop_run+0x38) [0x7f68355f5188] -> 
/usr/lib64/dovecot/libdovecot.so.0(master_service_run+0x13) 
[0x7f683558aea3] -> dovecot/imap(main+0x328) [0x55fa42faeb08] -> 
/lib64/libc.so.6(__libc_start_main+0xf0) [0x7f68351b9580] -> 
dovecot/imap(_start+0x29) [0x55fa42faec89]
Jun 29 04:50:07 imap(username at nodo.com.au): Fatal: master: 
service(imap): child 22020 killed with signal 6 (core dumped)