Panic on indexer-worker and Dovecot stop to search on Solr

[Alessio Cecchi]

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)

Dovecot version is 2.3.14 (from RPM) and Apache Solr si 7.7.3. Here is 
the error found in the log:

May 31 14:58:13 Panic: indexer-worker(user at email.com) 
session=<VA0oxZ/DXtG5Ydlx:0KzOIkLdtGDSawAAxbYlJw>: file 
http-client-request.c: line 1240 (http_client_request_send_more): 
assertion failed: (req->payload_input != NULL)
May 31 14:58:13 Error: indexer-worker(user at email.com) 
session=<VA0oxZ/DXtG5Ydlx:0KzOIkLdtGDSawAAxbYlJw>: Raw backtrace: 
/usr/lib64/dovecot/libdovecot.so.0(backtrace_append+0x42) 
[0x7f3d91b2cac2] -> 
/usr/lib64/dovecot/libdovecot.so.0(backtrace_get+0x1e) [0x7f3d91b2cbce] 
-> /usr/lib64/dovecot/libdovecot.so.0(+0xf3cde) [0x7f3d91b39cde] -> 
/usr/lib64/dovecot/libdovecot.so.0(+0xf3d81) [0x7f3d91b39d81] -> 
/usr/lib64/dovecot/libdovecot.so.0(i_fatal+0) [0x7f3d91a8b25a] -> 
/usr/lib64/dovecot/libdovecot.so.0(http_client_request_send_more+0x3dd) 
[0x7f3d91ad39ad] -> 
/usr/lib64/dovecot/libdovecot.so.0(http_client_connection_output+0xf1) 
[0x7f3d91ad8101] -> /usr/lib64/dovecot/libdovecot.so.0(+0x11d2b0) 
[0x7f3d91b632b0] -> 
/usr/lib64/dovecot/libdovecot.so.0(io_loop_call_io+0x65) 
[0x7f3d91b51f45] -> 
/usr/lib64/dovecot/libdovecot.so.0(io_loop_handler_run_internal+0x12b) 
[0x7f3d91b538fb] -> 
/usr/lib64/dovecot/libdovecot.so.0(io_loop_handler_run+0x59) 
[0x7f3d91b52049] -> /usr/lib64/dovecot/libdovecot.so.0(io_loop_run+0x38) 
[0x7f3d91b52288] -> 
/usr/lib64/dovecot/libdovecot.so.0(http_client_wait+0xcd) 
[0x7f3d91ae120d] -> 
/usr/lib64/dovecot/lib21_fts_solr_plugin.so(solr_connection_select+0xe4) 
[0x7f3d8fca1174] -> /usr/lib64/dovecot/lib21_fts_solr_plugin.so(+0x45d4) 
[0x7f3d8fc9d5d4] -> 
/usr/lib64/dovecot/lib20_fts_plugin.so(fts_backend_get_last_uid+0x6e) 
[0x7f3d90e103fe] -> /usr/lib64/dovecot/lib20_fts_plugin.so(+0xf952) 
[0x7f3d90e16952] -> /usr/lib64/dovecot/lib20_fts_plugin.so(+0x10ef6) 
[0x7f3d90e17ef6] -> /usr/lib64/dovecot/lib20_virtual_plugin.so(+0x966a) 
[0x7f3d90bfc66a] -> /usr/lib64/dovecot/lib20_fts_plugin.so(+0x10ba6) 
[0x7f3d90e17ba6] -> 
/usr/lib64/dovecot/libdovecot-storage.so.0(mail_precache+0x2e) 
[0x7f3d91e3cb0e] -> dovecot/indexer-worker [user at email.com Virtual/All - 
5300/20832](+0x2924) [0x5648464be924] -> 
/usr/lib64/dovecot/libdovecot.so.0(io_loop_call_io+0x65) 
[0x7f3d91b51f45] -> 
/usr/lib64/dovecot/libdovecot.so.0(io_loop_handler_run_internal+0x12b) 
[0x7f3d91b538fb] -> 
/usr/lib64/dovecot/libdovecot.so.0(io_loop_handler_run+0x59) 
[0x7f3d91b52049] -> /usr/lib64/dovecot/libdovecot.so.0(io_loop_run+0x38) 
[0x7f3d91b52288] -> 
/usr/lib64/dovecot/libdovecot.so.0(master_service_run+0x13) 
[0x7f3d91abcbb3] -> dovecot/indexer-worker [user at email.com Virtual/All - 
5300/20832](main+0xd7) [0x5648464be1f7] -> 
/lib64/libc.so.6(__libc_start_main+0xf5) [0x7f3d9169a555] -> 
dovecot/indexer-worker [user at email.com Virtual/All - 
5300/20832](+0x22ba) [0x5648464be2ba]
May 31 14:58:13 Fatal: indexer-worker(user at email.com) 
session=<VA0oxZ/DXtG5Ydlx:0KzOIkLdtGDSawAAxbYlJw>: master: 
service(indexer-worker): child 27602 killed with signal 6 (core dumps 
disabled - https://dovecot.org/bugreport.html#coredumps)

on Solr side I found this error log:

org.apache.solr.common.SolrException: Early EOF
     at org.apache.solr.handler.loader.XMLLoader.load(XMLLoader.java:190)
     at 
org.apache.solr.handler.UpdateRequestHandler$1.load(UpdateRequestHandler.java:97)
     at 
org.apache.solr.handler.ContentStreamHandlerBase.handleRequestBody(ContentStreamHandlerBase.java:68)
     at 
org.apache.solr.handler.RequestHandlerBase.handleRequest(RequestHandlerBase.java:199)
     at org.apache.solr.core.SolrCore.execute(SolrCore.java:2551)
     at org.apache.solr.servlet.HttpSolrCall.execute(HttpSolrCall.java:733)
     at org.apache.solr.servlet.HttpSolrCall.call(HttpSolrCall.java:531)
     at 
org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:395)
     [...]

and

[com.ctc.wstx.exc.WstxLazyException] com.ctc.wstx.exc.WstxIOException: 
Early EOF
     at 
com.ctc.wstx.exc.WstxLazyException.throwLazily(WstxLazyException.java:45)
     at com.ctc.wstx.sr.StreamScanner.throwLazyError(StreamScanner.java:728)
     at 
com.ctc.wstx.sr.BasicStreamReader.safeFinishToken(BasicStreamReader.java:3678)
     at 
com.ctc.wstx.sr.BasicStreamReader.getText(BasicStreamReader.java:860)
     at org.apache.solr.handler.loader.XMLLoader.readDoc(XMLLoader.java:419)
     at 
org.apache.solr.handler.loader.XMLLoader.processUpdate(XMLLoader.java:260)
     at org.apache.solr.handler.loader.XMLLoader.load(XMLLoader.java:188)
     at 
org.apache.solr.handler.UpdateRequestHandler$1.load(UpdateRequestHandler.java:97)

This is the relevant part of dovecot configuration:
plugin {
   fts = solr
   fts_autoindex = yes
   fts_decoder = decode2text
   fts_enforced = body
   fts_index_timeout = 5s
   fts_solr = url=http://10.0.1.3:8983/solr/dovecot/
   [...]
}

Is this an already know bug? Any workaround?
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/20210531/3d30b95e/attachment.html>