Panic on indexer-worker and Dovecot stop to search on Solr
Alessio Cecchi
alessio at skye.it
Thu Jun 3 09:39:35 EEST 2021
Il 31/05/21 21:00, Aki Tuomi ha scritto:
>> On 31/05/2021 21:58 Alessio Cecchi <alessio at skye.it> wrote:
>>
>>
>> Il 31/05/21 18:17, Aki Tuomi ha scritto:
>>
>>>> On 31/05/2021 19:09 Alessio Cecchi <alessio at skye.it> wrote:
>>>>
>>>>
>>>> Hi,
>>>> I have setup on a (little busy) Dovecot server FTS with Solr and Virtual folder to enable "search in all folders" for users.
>>>>
>>>> All works fine until for some users the indexer-worker process crash.
>>>> After this crash Dovecot stop to query Solr for new search in BODY, returning SERVERBUG, for all users on the server and only with a dovecot restart users can search in BODY again.
>>>> Before the dovecot restart I can see that on Solr server no query from dovecot arriving anymore (for SEARCH BODY because SEARCH in FROM/TO/SUBJECT still works fine)
>>>>
>>> Hi!
>>>
>>> It's a known bug and will be fixed in next release. It happens with tika and solr being used together.
>>>
>>> Aki
>> Good to know, I'm not using tika but decode2text, is the same?
>>
> Hm. Not necessarely. It could be something related to some other http connection though. The fix done should help in any case.
>
> Aki
Hi,
I'm not sure if can help but I have collect the core dump also for this
crash. I notice that happens only when indexing Virtual mailbox folder,
example:
- doveadm index -u user4 at email.com '*' works fine
- doveadm index -u user4 at email.com 'Virtual/All' crash
If I run first the index on '*' and after on 'Virtual/All' works fine
for both. But when users from webmail search in all folders via
Virtual/All always crash and after no more indexer-worker run until I
reload dovecot or kill "indexer" process.
Here the core dump:
Jun 03 05:05:34 Panic: indexer-worker(user4 at email.com)
session=<x0EZ2dPDiuW5Ydlx:pQBBH/tGuGDjBwAAxbYlJw>: file
http-client-request.c: line 1240 (http_client_request_send_more):
assertion failed: (req->payload_input != NULL)
Jun 03 05:05:34 Error: indexer-worker(user4 at email.com)
session=<x0EZ2dPDiuW5Ydlx:pQBBH/tGuGDjBwAAxbYlJw>: Raw backtrace:
/usr/lib64/dovecot/libdovecot.so.0(backtrace_append+0x42)
[0x7f5d132cbac2] ->
/usr/lib64/dovecot/libdovecot.so.0(backtrace_get+0x1e) [0x7f5d132cbbce]
-> /usr/lib64/dovecot/libdovecot.so.0(+0xf3cde) [0x7f5d132d8cde] ->
/usr/lib64/dovecot/libdovecot.so.0(+0xf3d81) [0x7f5d132d8d81] ->
/usr/lib64/dovecot/libdovecot.so.0(i_fatal+0) [0x7f5d1322a25a] ->
/usr/lib64/dovecot/libdovecot.so.0(http_client_request_send_more+0x3dd)
[0x7f5d132729ad] ->
/usr/lib64/dovecot/libdovecot.so.0(http_client_connection_output+0xf1)
[0x7f5d13277101] -> /usr/lib64/dovecot/libdovecot.so.0(+0x11d2b0)
[0x7f5d133022b0] ->
/usr/lib64/dovecot/libdovecot.so.0(io_loop_call_io+0x65)
[0x7f5d132f0f45] ->
/usr/lib64/dovecot/libdovecot.so.0(io_loop_handler_run_internal+0x12b)
[0x7f5d132f28fb] ->
/usr/lib64/dovecot/libdovecot.so.0(io_loop_handler_run+0x59)
[0x7f5d132f1049] -> /usr/lib64/dovecot/libdovecot.so.0(io_loop_run+0x38)
[0x7f5d132f1288] ->
/usr/lib64/dovecot/libdovecot.so.0(http_client_wait+0xcd)
[0x7f5d1328020d] ->
/usr/lib64/dovecot/lib21_fts_solr_plugin.so(solr_connection_select+0xe4)
[0x7f5d11440174] -> /usr/lib64/dovecot/lib21_fts_solr_plugin.so(+0x45d4)
[0x7f5d1143c5d4] ->
/usr/lib64/dovecot/lib20_fts_plugin.so(fts_backend_get_last_uid+0x6e)
[0x7f5d125af3fe] -> /usr/lib64/dovecot/lib20_fts_plugin.so(+0xf952)
[0x7f5d125b5952] -> /usr/lib64/dovecot/lib20_fts_plugin.so(+0x10ef6)
[0x7f5d125b6ef6] -> /usr/lib64/dovecot/lib20_virtual_plugin.so(+0x966a)
[0x7f5d1239b66a] -> /usr/lib64/dovecot/lib20_fts_plugin.so(+0x10ba6)
[0x7f5d125b6ba6] ->
/usr/lib64/dovecot/libdovecot-storage.so.0(mail_precache+0x2e)
[0x7f5d135dbb0e] -> dovecot/indexer-worker [user4 at email.com
Virtual/All](+0x2924) [0x561e504cb924] ->
/usr/lib64/dovecot/libdovecot.so.0(io_loop_call_io+0x65)
[0x7f5d132f0f45] ->
/usr/lib64/dovecot/libdovecot.so.0(io_loop_handler_run_internal+0x12b)
[0x7f5d132f28fb] ->
/usr/lib64/dovecot/libdovecot.so.0(io_loop_handler_run+0x59)
[0x7f5d132f1049] -> /usr/lib64/dovecot/libdovecot.so.0(io_loop_run+0x38)
[0x7f5d132f1288] ->
/usr/lib64/dovecot/libdovecot.so.0(master_service_run+0x13)
[0x7f5d1325bbb3] -> dovecot/indexer-worker [user4 at email.com
Virtual/All](main+0xd7) [0x561e504cb1f7] ->
/lib64/libc.so.6(__libc_start_main+0xf5) [0x7f5d12e39555] ->
dovecot/indexer-worker [user4 at email.com Virtual/All](+0x22ba)
[0x561e504cb2ba]
Jun 03 05:05:34 Fatal: indexer-worker(user4 at email.com)
session=<x0EZ2dPDiuW5Ydlx:pQBBH/tGuGDjBwAAxbYlJw>: master:
service(indexer-worker): child 2019 killed with signal 6 (core dumped)
[root at popimap ~]# gdb /usr/libexec/dovecot/indexer-worker
/var/core/core.indexer-worker.2019
GNU gdb (GDB) Red Hat Enterprise Linux 7.6.1-120.el7
Copyright (C) 2013 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later
<http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law. Type "show copying"
and "show warranty" for details.
This GDB was configured as "x86_64-redhat-linux-gnu".
For bug reporting instructions, please see:
<http://www.gnu.org/software/gdb/bugs/>...
Reading symbols from /usr/libexec/dovecot/indexer-worker...Reading
symbols from /usr/lib/debug/usr/libexec/dovecot/indexer-worker.debug...done.
done.
[New LWP 2019]
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib64/libthread_db.so.1".
Core was generated by `dovecot/indexer-worker'.
Program terminated with signal 6, Aborted.
#0 0x00007f5d12e4d387 in raise () from /lib64/libc.so.6
Missing separate debuginfos, use: debuginfo-install
bzip2-libs-1.0.6-13.el7.x86_64 expat-2.1.0-12.el7.x86_64
glibc-2.17-324.el7_9.x86_64 libgcc-4.8.5-44.el7.x86_64
libzstd-1.4.9-1.el7.x86_64 xz-libs-5.2.2-1.el7.x86_64
zlib-1.2.7-19.el7_9.x86_64
(gdb) bt full
#0 0x00007f5d12e4d387 in raise () from /lib64/libc.so.6
No symbol table info available.
#1 0x00007f5d12e4ea78 in abort () from /lib64/libc.so.6
No symbol table info available.
#2 0x00007f5d132d8c97 in default_fatal_finish (status=0,
type=<optimized out>) at failures.c:459
backtrace = 0x561e523ecab8
"/usr/lib64/dovecot/libdovecot.so.0(backtrace_append+0x42)
[0x7f5d132cbac2] ->
/usr/lib64/dovecot/libdovecot.so.0(backtrace_get+0x1e) [0x7f5d132cbbce]
-> /usr/lib64/dovecot/libdovecot.so.0(+0xf3cde) [0"...
recursed = 0
#3 fatal_handler_real (ctx=<optimized out>, format=<optimized out>,
args=<optimized out>) at failures.c:471
status = 0
#4 0x00007f5d132d8d81 in i_internal_fatal_handler (ctx=<optimized out>,
format=<optimized out>, args=<optimized out>)
at failures.c:866
No locals.
#5 0x00007f5d1322a25a in i_panic (format=format at entry=0x7f5d1331a730
"file %s: line %d (%s): assertion failed: (%s)")
at failures.c:523
ctx = {type = LOG_TYPE_PANIC, exit_status = 0, timestamp = 0x0,
timestamp_usecs = 0, log_prefix = 0x0,
log_prefix_type_pos = 0}
args = {{gp_offset = 40, fp_offset = 48, overflow_arg_area =
0x7ffdccb024d0, reg_save_area = 0x7ffdccb02410}}
#6 0x00007f5d132729ad in http_client_request_send_more
(req=req at entry=0x561e524c2a68, pipelined=pipelined at entry=false)
at http-client-request.c:1240
conn = 0x561e524aa5f0
cctx = 0x561e52427fa8
output = 0x561e524abf60
res = <optimized out>
error = <optimized out>
offset = <optimized out>
__func__ = "http_client_request_send_more"
#7 0x00007f5d13277101 in http_client_connection_continue_request
(conn=0x561e524aa5f0) at http-client-connection.c:1342
tmp_conn = 0x561e524aa5f0
count = 1
ret = <optimized out>
reqs = <optimized out>
req = 0x561e524c2a68
pipelined = false
#8 http_client_connection_output (conn=0x561e524aa5f0) at
http-client-connection.c:1374
output = <optimized out>
ret = <optimized out>
#9 0x00007f5d133022b0 in stream_send_io (fstream=0x561e524ab320) at
ostream-file.c:520
ostream = 0x561e524ab3c0
iostream = 0x561e524ab320
use_cork = true
ret = <optimized out>
---Type <return> to continue, or q <return> to quit---
#10 0x00007f5d132f0f45 in io_loop_call_io (io=0x561e524a4fb0) at
ioloop.c:714
ioloop = 0x561e524c2840
t_id = 6
__func__ = "io_loop_call_io"
#11 0x00007f5d132f28fb in io_loop_handler_run_internal
(ioloop=ioloop at entry=0x561e524c2840) at ioloop-epoll.c:222
ctx = 0x561e524a4f80
events = <optimized out>
list = 0x561e524ae350
io = <optimized out>
tv = {tv_sec = 0, tv_usec = 0}
events_count = <optimized out>
msecs = <optimized out>
ret = 1
i = 0
call = <optimized out>
__func__ = "io_loop_handler_run_internal"
#12 0x00007f5d132f1049 in io_loop_handler_run
(ioloop=ioloop at entry=0x561e524c2840) at ioloop.c:766
__func__ = "io_loop_handler_run"
#13 0x00007f5d132f1288 in io_loop_run (ioloop=0x561e524c2840) at
ioloop.c:739
__func__ = "io_loop_run"
#14 0x00007f5d1328020d in http_client_wait (client=0x561e52425f98) at
http-client.c:339
prev_ioloop = 0x561e523f0ff0
client_ioloop = 0x561e524c2840
prev_client_ioloop = 0x561e523f0ff0
__func__ = "http_client_wait"
#15 0x00007f5d11440174 in solr_connection_select (conn=0x561e52425ed0,
query=<optimized out>, pool=<optimized out>,
box_results_r=0x7ffdccb02780) at solr-connection.c:206
lctx = {result_pool = 0x561e5249dba0, payload = 0x0, io = 0x0,
request_status = 0, parser = 0x0, results = 0x0}
http_req = 0x561e5249dfd8
url = <optimized out>
#16 0x00007f5d1143c5d4 in fts_backend_solr_get_last_uid
(_backend=0x561e52425e10, box=0x561e52452538, last_uid_r=0x7ffdccb02824)
at fts-backend-solr.c:237
hdr = {last_indexed_uid = 0, settings_checksum = 0, unused = 0}
#17 0x00007f5d125af3fe in fts_backend_get_last_uid (backend=<optimized
out>, box=box at entry=0x561e52452538,
last_uid_r=last_uid_r at entry=0x7ffdccb02824) at fts-api.c:106
hdr = {last_indexed_uid = 3434097176, settings_checksum =
32765, unused = 325539906}
#18 0x00007f5d125b5952 in fts_mailbox_get_last_cached_seq
(box=box at entry=0x561e52452538, seq_r=seq_r at entry=0x7ffdccb02874)
at fts-storage.c:85
flist = <optimized out>
seq1 = 22046
seq2 = 1380210400
last_uid = 22046
---Type <return> to continue, or q <return> to quit---
#19 0x00007f5d125b6ef6 in fts_mail_precache_init (_mail=<optimized out>,
_mail=<optimized out>) at fts-storage.c:486
ft = 0x561e52499650
flist = 0x561e5241e928
last_seq = 22046
#20 fts_mail_index (_mail=0x561e524ad188) at fts-storage.c:507
ft = 0x561e52499650
flist = 0x561e5241e928
pmail = 0x561e524ad188
#21 fts_mail_precache (_mail=0x561e524ad188) at fts-storage.c:571
_data_stack_cur_id = 5
mail = 0x561e524ad188
fmail = <optimized out>
ft = 0x561e52499650
__func__ = "fts_mail_precache"
#22 0x00007f5d1239b66a in virtual_mail_precache (mail=<optimized out>)
at virtual-mail.c:265
vmail = <optimized out>
backend_mail = 0x561e524ad188
p = <optimized out>
#23 0x00007f5d125b6ba6 in fts_mail_precache (_mail=0x561e5248e0e8) at
fts-storage.c:564
mail = 0x561e5248e0e8
fmail = 0x561e5248e650
ft = 0x561e52458670
__func__ = "fts_mail_precache"
#24 0x00007f5d135dbb0e in mail_precache (mail=0x561e5248e0e8) at mail.c:453
_data_stack_cur_id = 4
p = 0x561e5248e0e8
#25 0x0000561e504cb924 in index_mailbox_precache (conn=<optimized out>,
box=0x561e52435a18) at master-connection.c:104
counter = 1
max = 172
percentage_sent = 0
storage = <optimized out>
status = {messages = 172, recent = 0, unseen = 0, uidvalidity =
1622689531, uidnext = 173, first_unseen_seq = 0,
first_recent_uid = 173, last_cached_seq = 0, highest_modseq =
0, highest_pvt_modseq = 0, keywords = 0x0,
permanent_flags = 0, flags = 0, permanent_keywords = false,
allow_new_keywords = false, nonpermanent_modseqs = false,
no_modseq_tracking = false, have_guids = true,
have_save_guids = true, have_only_guid128 = false}
uids = <optimized out>
username = 0x561e524158c8 "user4 at email.com"
first_uid = 1
percentage_str = "0\000\000"
percentage = <optimized out>
error = 1379909712
trans = 0x561e524641a0
---Type <return> to continue, or q <return> to quit---
ctx = 0x561e52434ee0
last_uid = 2
ret = 0
box_vname = 0x561e52435db0 "Virtual/All"
errstr = <optimized out>
search_args = 0x0
mail = 0x561e5248e0e8
metadata = {guid = '\000' <repeats 15 times>, virtual_size = 0,
physical_size = 0, first_save_date = 0,
cache_fields = 0x0,
precache_fields = (MAIL_FETCH_STREAM_HEADER |
MAIL_FETCH_STREAM_BODY | MAIL_FETCH_RECEIVED_DATE | MAIL_FETCH_SAVE_DATE
| MAIL_FETCH_PHYSICAL_SIZE | MAIL_FETCH_VIRTUAL_SIZE |
MAIL_FETCH_UIDL_BACKEND | MAIL_FETCH_GUID | MAIL_FETCH_POP3_ORDER),
backend_ns_prefix = 0x0, backend_ns_type = (unknown: 0)}
seq = <optimized out>
#26 index_mailbox (user=<optimized out>, user=<optimized out>,
what=<optimized out>, max_recent_msgs=<optimized out>,
mailbox=<optimized out>, conn=0x561e523fc070) at
master-connection.c:207
box = 0x561e52435a18
status = {messages = 0, recent = 0, unseen = 733118976,
uidvalidity = 3265295405, uidnext = 3434097280,
first_unseen_seq = 32765, first_recent_uid = 1,
last_cached_seq = 0, highest_modseq = 94688228871760,
highest_pvt_modseq = 140037729927678, keywords =
0x7ffdccb02a80, permanent_flags = 1379864144, flags = 22046,
permanent_keywords = false, allow_new_keywords = false,
nonpermanent_modseqs = false, no_modseq_tracking = false,
have_guids = true, have_save_guids = false, have_only_guid128
= true}
errstr = <optimized out>
ret = 0
ns = <optimized out>
path = 0x561e523eb6d0
"/home/vmail/nas10/domains/R/email.com/user4/Maildir/virtual/All"
error = 172
sync_flags = <optimized out>
#27 master_connection_input_line (line=<optimized out>,
conn=0x561e523fc070) at master-connection.c:249
str = <optimized out>
max_recent_msgs = 0
ret = <optimized out>
args = <optimized out>
input = {parent_event = 0x0, module = 0x561e504cbfff "mail",
service = 0x561e504cbff0 "indexer-worker",
username = 0x561e523e8038 "user4 at email.com", session_id = 0x0,
session_id_prefix = 0x561e523e805b "x0EZ2dPDiuW5Ydlx",
session_create_time = 0, local_ip = {family = 0, u = {ip6 = {
__in6_u = {__u6_addr8 = '\000' <repeats 15 times>,
__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' <repeats 15 times>, __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, forward_fields = 0x0,
flags_override_add = (unknown: 0), flags_override_remove =
(unknown: 0), no_userdb_lookup = false, debug = false,
conn_secured = false, conn_ssl_secured = false}
service_user = 0x561e523ffe30
---Type <return> to continue, or q <return> to quit---
user = 0x561e524157a8
error = 0x0
#28 master_connection_input (conn=0x561e523fc070) at master-connection.c:289
_data_stack_cur_id = 3
line = <optimized out>
#29 0x00007f5d132f0f45 in io_loop_call_io (io=0x561e523fc0b0) at
ioloop.c:714
ioloop = 0x561e523f0ff0
t_id = 2
__func__ = "io_loop_call_io"
#30 0x00007f5d132f28fb in io_loop_handler_run_internal
(ioloop=ioloop at entry=0x561e523f0ff0) at ioloop-epoll.c:222
ctx = 0x561e523f1c30
events = <optimized out>
list = 0x561e523fc110
io = <optimized out>
tv = {tv_sec = 2147483, tv_usec = 0}
events_count = <optimized out>
msecs = <optimized out>
ret = 1
i = 0
call = <optimized out>
__func__ = "io_loop_handler_run_internal"
#31 0x00007f5d132f1049 in io_loop_handler_run
(ioloop=ioloop at entry=0x561e523f0ff0) at ioloop.c:766
__func__ = "io_loop_handler_run"
#32 0x00007f5d132f1288 in io_loop_run (ioloop=0x561e523f0ff0) at
ioloop.c:739
__func__ = "io_loop_run"
#33 0x00007f5d1325bbb3 in master_service_run (service=0x561e523f0e50,
callback=callback at entry=0x561e504cb3b0 <client_connected>)
at master-service.c:853
No locals.
#34 0x0000561e504cb1f7 in main (argc=1, argv=0x561e523f0b90) at
indexer-worker.c:76
storage_service_flags =
(MAIL_STORAGE_SERVICE_FLAG_USERDB_LOOKUP |
MAIL_STORAGE_SERVICE_FLAG_TEMP_PRIV_DROP |
MAIL_STORAGE_SERVICE_FLAG_NO_IDLE_TIMEOUT)
c = <optimized out>
(gdb) exit
I hope can help to fix it.
Thanks
--
Alessio Cecchi
Postmaster @ http://www.qboxmail.it
https://www.linkedin.com/in/alessice
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://dovecot.org/pipermail/dovecot/attachments/20210603/36f980ce/attachment-0001.html>
More information about the dovecot
mailing list