Alessio Cecchi
2021-May-31 18:58 UTC
Panic on indexer-worker and Dovecot stop to search on Solr
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. > > AkiGood to know, I'm not using tika but decode2text, is the same? -- Alessio Cecchi Postmaster @ http://www.qboxmail.it https://www.linkedin.com/in/alessice
Aki Tuomi
2021-May-31 19:00 UTC
Panic on indexer-worker and Dovecot stop to search on Solr
> 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
Alessio Cecchi
2021-Jun-03 06:39 UTC
Panic on indexer-worker and Dovecot stop to search on Solr
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. > > AkiHi, 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>