Sorry to bump up an old thread. 2.3.11.3 already contains this patch and the error still gets generated.  Anything else we could try ? Scott On Wednesday, 19/08/2020 at 11:37 Josef 'Jeff' Sipek wrote: On Wed, Aug 19, 2020 at 17:03:57 +0200, Alessio Cecchi wrote:

Hi,

after the upgrade to Dovecot 2.3.11.3, from 2.3.10.1, I see frequently these errors from different users:

It looks like this has been around for a while and you just got unlucky and started seeing this now.  Here's a quick & dirty patch that should fix this. If you can try it, let us know how it went. Jeff. diff --git a/src/plugins/fts-solr/solr-connection.c b/src/plugins/fts-solr/solr-connection.c index ae720b5e2870a852c1b6c440939e3c7c0fa72b5c..9d364f93e2cd1b716b9ab61bd39656a6c5b1ea04 100644 --- a/src/plugins/fts-solr/solr-connection.c +++ b/src/plugins/fts-solr/solr-connection.c @@ -103,7 +103,7 @@ int solr_connection_init(const struct fts_solr_settings *solr_set, http_set.ssl = ssl_client_set; http_set.debug = solr_set->debug; http_set.rawlog_dir = solr_set->rawlog_dir; -solr_http_client = http_client_init(&http_set); +solr_http_client = http_client_init_private(&http_set); } *conn_r = conn; diff --git a/src/plugins/fts/fts-parser-tika.c b/src/plugins/fts/fts-parser-tika.c index a4b8b5c3034f57e22e77caa759c090da6b62f8ba..b8b57a350b9a710d101ac7ccbcc14560d415d905 100644 --- a/src/plugins/fts/fts-parser-tika.c +++ b/src/plugins/fts/fts-parser-tika.c @@ -77,7 +77,7 @@ tika_get_http_client_url(struct mail_user *user, struct http_url **http_url_r) http_set.request_timeout_msecs = 60*1000; http_set.ssl = &ssl_set; http_set.debug = user->mail_debug; -tika_http_client = http_client_init(&http_set); +tika_http_client = http_client_init_private(&http_set); } *http_url_r = tuser->http_url; return 0;

Sorry about that. My FreeBSD system automatically applied your patches and I assumed they were already part of the master. Unfortunately it still means the bug isn't resolved with these changes. On Wednesday, 02/09/2020 at 15:34 Josef 'Jeff' Sipek wrote: On Wed, Sep 02, 2020 at 15:07:37 -0400, Scott Q. wrote:

Sorry to bump up an old thread.

2.3.11.3 already contains this patch and the error still gets generated. 

I'm not sure where you are finding it.  The below patch isn't on the release-2.3.11 branch.  It isn't in the 2.3.11.3 tarball.  It isn't even on master.  Those two files haven't been touched since January. Jeff.

Anything else we could try ?

Scott

On Wednesday, 19/08/2020 at 11:37 Josef 'Jeff' Sipek wrote:

On Wed, Aug 19, 2020 at 17:03:57 +0200, Alessio Cecchi wrote:

...

Hi,

after the upgrade to Dovecot 2.3.11.3, from 2.3.10.1, I see frequently these errors from different users:

It looks like this has been around for a while and you just got unlucky and started seeing this now.  Here's a quick & dirty patch that should fix this. If you can try it, let us know how it went.

Jeff.

diff --git a/src/plugins/fts-solr/solr-connection.c b/src/plugins/fts-solr/solr-connection.c index

ae720b5e2870a852c1b6c440939e3c7c0fa72b5c..9d364f93e2cd1b716b9ab61bd39656a6c5b1ea04

100644 --- a/src/plugins/fts-solr/solr-connection.c +++ b/src/plugins/fts-solr/solr-connection.c @@ -103,7 +103,7 @@ int solr_connection_init(const struct fts_solr_settings *solr_set, http_set.ssl = ssl_client_set; http_set.debug = solr_set->debug; http_set.rawlog_dir = solr_set->rawlog_dir; -solr_http_client = http_client_init(&http_set); +solr_http_client = http_client_init_private(&http_set); }

*conn_r = conn; diff --git a/src/plugins/fts/fts-parser-tika.c b/src/plugins/fts/fts-parser-tika.c index

a4b8b5c3034f57e22e77caa759c090da6b62f8ba..b8b57a350b9a710d101ac7ccbcc14560d415d905

100644 --- a/src/plugins/fts/fts-parser-tika.c +++ b/src/plugins/fts/fts-parser-tika.c @@ -77,7 +77,7 @@ tika_get_http_client_url(struct mail_user *user, struct http_url **http_url_r) http_set.request_timeout_msecs = 60*1000; http_set.ssl = &ssl_set; http_set.debug = user->mail_debug; -tika_http_client = http_client_init(&http_set); +tika_http_client = http_client_init_private(&http_set); } *http_url_r = tuser->http_url; return 0;

-- Hegh QaQ law' quvHa'ghach QaQ puS

On 19/08/2020 17:37, Josef 'Jeff' Sipek wrote:

On Wed, Aug 19, 2020 at 17:03:57 +0200, Alessio Cecchi wrote:

...

Hi,

after the upgrade to Dovecot 2.3.11.3, from 2.3.10.1, I see frequently these errors from different users: It looks like this has been around for a while and you just got unlucky and started seeing this now. Here's a quick & dirty patch that should fix this. If you can try it, let us know how it went.

Jeff.

Well, maybe not. This patch is only useful when Solr and Tika are used at the same time. Otherwise, this is something else causing the same panic. Regards, Stephan.

diff --git a/src/plugins/fts-solr/solr-connection.c b/src/plugins/fts-solr/solr-connection.c index ae720b5e2870a852c1b6c440939e3c7c0fa72b5c..9d364f93e2cd1b716b9ab61bd39656a6c5b1ea04 100644 --- a/src/plugins/fts-solr/solr-connection.c +++ b/src/plugins/fts-solr/solr-connection.c @@ -103,7 +103,7 @@ int solr_connection_init(const struct fts_solr_settings *solr_set, http_set.ssl = ssl_client_set; http_set.debug = solr_set->debug; http_set.rawlog_dir = solr_set->rawlog_dir; - solr_http_client = http_client_init(&http_set); + solr_http_client = http_client_init_private(&http_set); }

*conn_r = conn; diff --git a/src/plugins/fts/fts-parser-tika.c b/src/plugins/fts/fts-parser-tika.c index a4b8b5c3034f57e22e77caa759c090da6b62f8ba..b8b57a350b9a710d101ac7ccbcc14560d415d905 100644 --- a/src/plugins/fts/fts-parser-tika.c +++ b/src/plugins/fts/fts-parser-tika.c @@ -77,7 +77,7 @@ tika_get_http_client_url(struct mail_user *user, struct http_url **http_url_r) http_set.request_timeout_msecs = 60*1000; http_set.ssl = &ssl_set; http_set.debug = user->mail_debug; - tika_http_client = http_client_init(&http_set); + tika_http_client = http_client_init_private(&http_set); } *http_url_r = tuser->http_url; return 0;

This reminds me, the way I was able to reproduce this consistently was by having large headers ( 100+ lines ). On Friday, 16/10/2020 at 11:49 Patrik Peng wrote: On 19.08.20 17:37, Josef 'Jeff' Sipek wrote: On Wed, Aug 19, 2020 at 17:03:57 +0200, Alessio Cecchi wrote: Hi, after the upgrade to Dovecot 2.3.11.3, from 2.3.10.1, I see frequently these errors from different users: It looks like this has been around for a while and you just got unlucky and started seeing this now. Here's a quick & dirty patch that should fix this. If you can try it, let us know how it went. Jeff. diff --git a/src/plugins/fts-solr/solr-connection.c b/src/plugins/fts-solr/solr-connection.c index ae720b5e2870a852c1b6c440939e3c7c0fa72b5c..9d364f93e2cd1b716b9ab61bd39656a6c5b1ea04 100644 --- a/src/plugins/fts-solr/solr-connection.c +++ b/src/plugins/fts-solr/solr-connection.c @@ -103,7 +103,7 @@ int solr_connection_init(const struct fts_solr_settings *solr_set, http_set.ssl = ssl_client_set; http_set.debug = solr_set->debug; http_set.rawlog_dir = solr_set->rawlog_dir; -solr_http_client = http_client_init(&http_set); +solr_http_client = http_client_init_private(&http_set); } *conn_r = conn; diff --git a/src/plugins/fts/fts-parser-tika.c b/src/plugins/fts/fts-parser-tika.c index a4b8b5c3034f57e22e77caa759c090da6b62f8ba..b8b57a350b9a710d101ac7ccbcc14560d415d905 100644 --- a/src/plugins/fts/fts-parser-tika.c +++ b/src/plugins/fts/fts-parser-tika.c @@ -77,7 +77,7 @@ tika_get_http_client_url(struct mail_user *user, struct http_url **http_url_r) http_set.request_timeout_msecs = 60*1000; http_set.ssl = &ssl_set; http_set.debug = user->mail_debug; -tika_http_client = http_client_init(&http_set); +tika_http_client = http_client_init_private(&http_set); } *http_url_r = tuser->http_url; return 0; Greetings I'm also experiencing these issues while running Dovecot 2.3.11.3 with Solr 8.6.3 on FreeBSD 11.4. As mentioned in a previous mail, the above patch is already applied to Dovecot's FreeBSD Port, confirmed by the patches being present in the portstree (https://svnweb.freebsd.org/ports/branches/2020Q3/mail/dovecot/files/). In a FreeBSD VM with the official image (https://download.freebsd.org/ftp/releases/VM-IMAGES/12.1-RELEASE/amd64/Lates...) I compiled dovecot from git and was able to reproduce the error with the patch mentioned above applied and also without any patches at all.

From these results i conclude, that neither the patches applied in FreeBSDs portstree or the patch above have any influence.

I also managed to reproduce the same results on a Debian 10 machine (also with and without the patch): doveadm(some.user@example.com [1]): Panic: file http-client-request.c: line 1232 (http_client_request_send_more): assertion failed: (req->payload_input != NULL) doveadm(some.user@example.com [1]): Error: Raw backtrace: /usr/local/lib/dovecot/libdovecot.so [2].0(backtrace_append+0x42) [0x7f093f7fc3c2] -> /usr/local/lib/dovecot/libdovecot.so [2].0(backtrace_get+0x1e) [0x7f093f7fc4ce] -> /usr/local/lib/dovecot/libdovecot.so [2].0(+0xea341) [0x7f093f807341] -> /usr/local/lib/dovecot/libdovecot.so [2].0(+0xea381) [0x7f093f807381] -> /usr/local/lib/dovecot/libdovecot.so [2].0(i_fatal+0) [0x7f093f75c074] -> /usr/local/lib/dovecot/libdovecot.so [2].0(http_client_request_send_more+0x378) [0x7f093f7a47a8] -> /usr/local/lib/dovecot/libdovecot.so [2].0(http_client_connection_output+0xe4) [0x7f093f7a90f4] -> /usr/local/lib/dovecot/libssl_iostream_openssl.so [3](+0x8bff) [0x7f093ec71bff] -> /usr/local/lib/dovecot/libdovecot.so [2].0(+0x1148b0) [0x7f093f8318b0] -> /usr/local/lib/dovecot/libdovecot.so [2].0(io_loop_call_io+0x69) [0x7f093f820259] -> /usr/local/lib/dovecot/libdovecot.so [2].0(io_loop_handler_run_internal+0x11b) [0x7f093f821b6b] -> /usr/local/lib/dovecot/libdovecot.so [2].0(io_loop_handler_run+0x59) [0x7f093f820369] -> /usr/local/lib/dovecot/libdovecot.so [2].0(io_loop_run+0x38) [0x7f093f820598] -> /usr/local/lib/dovecot/libdovecot.so [2].0(+0x86d1e) [0x7f093f7a3d1e] -> /usr/local/lib/dovecot/libdovecot.so [2].0(http_client_request_finish_payload+0x2e) [0x7f093f7a407e] -> /usr/local/lib/dovecot/lib21_fts_solr_plugin.so [4](solr_connection_post_end+0x32) [0x7f093b8492c2] -> /usr/local/lib/dovecot/lib21_fts_solr_plugin.so [4](+0x3a45) [0x7f093b844a45] -> /usr/local/lib/dovecot/lib20_fts_plugin.so [4](+0x94cc) [0x7f093e1104cc] -> /usr/local/lib/dovecot/lib20_fts_plugin.so [4](fts_backend_update_deinit+0x23) [0x7f093e110503] -> /usr/local/lib/dovecot/lib20_fts_plugin.so [4](+0x10a9b) [0x7f093e117a9b] -> /usr/local/lib/dovecot/lib20_fts_plugin.so [4](+0x119ca) [0x7f093e1189ca] -> /usr/local/lib/dovecot/libdovecot-storage.so [5].0(mailbox_transaction_commit_get_changes+0x56) [0x7f093fb16076] -> /usr/local/lib/dovecot/libdovecot-storage.so [5].0(mailbox_transaction_commit+0x1e) [0x7f093fb1615e] -> doveadm(+0x31370) [0x5607cfa1f370] -> doveadm(+0x2b2a8) [0x5607cfa192a8] -> doveadm(+0x2bfb2) [0x5607cfa19fb2] -> doveadm(doveadm_cmd_ver2_to_mail_cmd_wrapper+0x215) [0x5607cfa1ae05] -> doveadm(doveadm_cmd_run_ver2+0x57c) [0x5607cfa2bbec] -> doveadm(doveadm_cmd_try_run_ver2+0x37) [0x5607cfa2bc37] -> doveadm(main+0x1d2) [0x5607cfa09492] Aborted During my tests I also did notice, that the error appears more often depending of mail size and amount of mails in a folder: Tested with: doveadm -v fts rescan -u some.user@example.com && doveadm -v index -u some.user@example.com '*' 1 Mail in INBOX with 9KB -> Error appeared 0 out of 20 times 1 Mail in INBOX with 136KB -> Error appeared 17 out of 20 times 3 Mails in INBOX with 408KB -> Error appeared 12 out of 20 times 20 Mails in INBOX with ~2MB -> Error appeared 0 out of 20 times Maybe this info helps anyone. Patrik Links: ------ [1] mailto:some.user2@example.com [2] http://libdovecot.so [3] http://openssl.so [4] http://plugin.so [5] http://libdovecot-storage.so

On 16.10.20 18:34, Patrik Peng wrote:

On 16.10.20 18:00, Scott Q. wrote:

...

This reminds me, the way I was able to reproduce this consistently was by having large headers ( 100+ lines ).

On Friday, 16/10/2020 at 11:49 Patrik Peng wrote:

On 19.08.20 17:37, Josef 'Jeff' Sipek wrote:

...

On Wed, Aug 19, 2020 at 17:03:57 +0200, Alessio Cecchi wrote:

...

Hi, after the upgrade to Dovecot 2.3.11.3, from 2.3.10.1, I see frequently these errors from different users:

It looks like this has been around for a while and you just got unlucky and started seeing this now. Here's a quick & dirty patch that should fix this. If you can try it, let us know how it went. Jeff.

diff --git a/src/plugins/fts-solr/solr-connection.c b/src/plugins/fts-solr/solr-connection.c index ae720b5e2870a852c1b6c440939e3c7c0fa72b5c..9d364f93e2cd1b716b9ab61bd39656a6c5b1ea04 100644 --- a/src/plugins/fts-solr/solr-connection.c +++ b/src/plugins/fts-solr/solr-connection.c @@ -103,7 +103,7 @@ int solr_connection_init(const struct fts_solr_settings *solr_set, http_set.ssl = ssl_client_set; http_set.debug = solr_set->debug; http_set.rawlog_dir = solr_set->rawlog_dir; - solr_http_client = http_client_init(&http_set); + solr_http_client = http_client_init_private(&http_set); } *conn_r = conn; diff --git a/src/plugins/fts/fts-parser-tika.c b/src/plugins/fts/fts-parser-tika.c index a4b8b5c3034f57e22e77caa759c090da6b62f8ba..b8b57a350b9a710d101ac7ccbcc14560d415d905 100644 --- a/src/plugins/fts/fts-parser-tika.c +++ b/src/plugins/fts/fts-parser-tika.c @@ -77,7 +77,7 @@ tika_get_http_client_url(struct mail_user *user, struct http_url **http_url_r) http_set.request_timeout_msecs = 60*1000; http_set.ssl = &ssl_set; http_set.debug = user->mail_debug; - tika_http_client = http_client_init(&http_set); + tika_http_client = http_client_init_private(&http_set); } *http_url_r = tuser->http_url; return 0;

Greetings

I'm also experiencing these issues while running Dovecot 2.3.11.3 with Solr 8.6.3 on FreeBSD 11.4. As mentioned in a previous mail, the above patch is already applied to Dovecot's FreeBSD Port, confirmed by the patches being present in the portstree (https://svnweb.freebsd.org/ports/branches/2020Q3/mail/dovecot/files/).

In a FreeBSD VM with the official image (https://download.freebsd.org/ftp/releases/VM-IMAGES/12.1-RELEASE/amd64/Lates...) I compiled dovecot from git and was able to reproduce the error with the patch mentioned above applied and also without any patches at all. From these results i conclude, that neither the patches applied in FreeBSDs portstree or the patch above have any influence.

I also managed to reproduce the same results on a Debian 10 machine (also with and without the patch):

doveadm(some.user@example.com): Panic: file http-client-request.c: line 1232 (http_client_request_send_more): assertion failed: (req->payload_input != NULL) doveadm(some.user@example.com): Error: Raw backtrace: /usr/local/lib/dovecot/libdovecot.so http://libdovecot.so.0(backtrace_append+0x42) [0x7f093f7fc3c2] -> /usr/local/lib/dovecot/libdovecot.so http://libdovecot.so.0(backtrace_get+0x1e) [0x7f093f7fc4ce] -> /usr/local/lib/dovecot/libdovecot.so http://libdovecot.so.0(+0xea341) [0x7f093f807341] -> /usr/local/lib/dovecot/libdovecot.so http://libdovecot.so.0(+0xea381) [0x7f093f807381] -> /usr/local/lib/dovecot/libdovecot.so http://libdovecot.so.0(i_fatal+0) [0x7f093f75c074] -> /usr/local/lib/dovecot/libdovecot.so http://libdovecot.so.0(http_client_request_send_more+0x378) [0x7f093f7a47a8] -> /usr/local/lib/dovecot/libdovecot.so http://libdovecot.so.0(http_client_connection_output+0xe4) [0x7f093f7a90f4] -> /usr/local/lib/dovecot/libssl_iostream_openssl.so http://openssl.so(+0x8bff) [0x7f093ec71bff] -> /usr/local/lib/dovecot/libdovecot.so http://libdovecot.so.0(+0x1148b0) [0x7f093f8318b0] -> /usr/local/lib/dovecot/libdovecot.so http://libdovecot.so.0(io_loop_call_io+0x69) [0x7f093f820259] -> /usr/local/lib/dovecot/libdovecot.so http://libdovecot.so.0(io_loop_handler_run_internal+0x11b) [0x7f093f821b6b] -> /usr/local/lib/dovecot/libdovecot.so http://libdovecot.so.0(io_loop_handler_run+0x59) [0x7f093f820369] -> /usr/local/lib/dovecot/libdovecot.so http://libdovecot.so.0(io_loop_run+0x38) [0x7f093f820598] -> /usr/local/lib/dovecot/libdovecot.so http://libdovecot.so.0(+0x86d1e) [0x7f093f7a3d1e] -> /usr/local/lib/dovecot/libdovecot.so http://libdovecot.so.0(http_client_request_finish_payload+0x2e) [0x7f093f7a407e] -> /usr/local/lib/dovecot/lib21_fts_solr_plugin.so http://plugin.so(solr_connection_post_end+0x32) [0x7f093b8492c2] -> /usr/local/lib/dovecot/lib21_fts_solr_plugin.so http://plugin.so(+0x3a45) [0x7f093b844a45] -> /usr/local/lib/dovecot/lib20_fts_plugin.so http://plugin.so(+0x94cc) [0x7f093e1104cc] -> /usr/local/lib/dovecot/lib20_fts_plugin.so http://plugin.so(fts_backend_update_deinit+0x23) [0x7f093e110503] -> /usr/local/lib/dovecot/lib20_fts_plugin.so http://plugin.so(+0x10a9b) [0x7f093e117a9b] -> /usr/local/lib/dovecot/lib20_fts_plugin.so http://plugin.so(+0x119ca) [0x7f093e1189ca] -> /usr/local/lib/dovecot/libdovecot-storage.so http://libdovecot-storage.so.0(mailbox_transaction_commit_get_changes+0x56) [0x7f093fb16076] -> /usr/local/lib/dovecot/libdovecot-storage.so http://libdovecot-storage.so.0(mailbox_transaction_commit+0x1e) [0x7f093fb1615e] -> doveadm(+0x31370) [0x5607cfa1f370] -> doveadm(+0x2b2a8) [0x5607cfa192a8] -> doveadm(+0x2bfb2) [0x5607cfa19fb2] -> doveadm(doveadm_cmd_ver2_to_mail_cmd_wrapper+0x215) [0x5607cfa1ae05] -> doveadm(doveadm_cmd_run_ver2+0x57c) [0x5607cfa2bbec] -> doveadm(doveadm_cmd_try_run_ver2+0x37) [0x5607cfa2bc37] -> doveadm(main+0x1d2) [0x5607cfa09492] Aborted

During my tests I also did notice, that the error appears more often depending of mail size and amount of mails in a folder:

Tested with: doveadm -v fts rescan -usome.user@example.com && doveadm -v index -usome.user@example.com '*' 1 Mail in INBOX with 9KB -> Error appeared 0 out of 20 times 1 Mail in INBOX with 136KB -> Error appeared 17 out of 20 times 3 Mails in INBOX with 408KB -> Error appeared 12 out of 20 times 20 Mails in INBOX with ~2MB -> Error appeared 0 out of 20 times

Maybe this info helps anyone.

Patrik

Yeah, I read your mail and that's why I tested with different mail sizes. I did some more tests, one with large headers (around 700 lines of a long header line) but small body:

1 Mail in INBOX with 583KB -> Error appeared 5 out of 20 times

and another with a large mail body but normal headers:

1 Mail in INBOX with 585KB -> Error appeared 0 out of 20 times I guess this kinda confirms your guess, but interestingly shows less errors than my previous test with a large header 136KB Mail.

Patrik

I did notice that changing the batch_size in fts_solr = url=http://solr.example.org:8983/solr/ soft_commit=yes batch_size=1000 does have an influence in how often the error occurs. Setting it to 1 or some huge number like 10000 reduces the chances quite a bit but not completely and also causes lots of small , or few but quite large requests to Solr, so its not a practical workaround. Whats the current state of this bug? A fix for it would be very welcome, as it causes some trouble in our setup. Regards

On 21/10/2020 19:00, John Fawcett wrote:

On 21/10/2020 16:44, Patrik Peng wrote:

...

On 16.10.20 18:34, Patrik Peng wrote:

...

On 16.10.20 18:00, Scott Q. wrote:

...

This reminds me, the way I was able to reproduce this consistently was by having large headers ( 100+ lines ).

On Friday, 16/10/2020 at 11:49 Patrik Peng wrote:

On 19.08.20 17:37, Josef 'Jeff' Sipek wrote:

...

On Wed, Aug 19, 2020 at 17:03:57 +0200, Alessio Cecchi wrote:

...

Hi, after the upgrade to Dovecot 2.3.11.3, from 2.3.10.1, I see frequently these errors from different users:

It looks like this has been around for a while and you just got unlucky and started seeing this now. Here's a quick & dirty patch that should fix this. If you can try it, let us know how it went. Jeff.

diff --git a/src/plugins/fts-solr/solr-connection.c b/src/plugins/fts-solr/solr-connection.c index ae720b5e2870a852c1b6c440939e3c7c0fa72b5c..9d364f93e2cd1b716b9ab61bd39656a6c5b1ea04 100644 --- a/src/plugins/fts-solr/solr-connection.c +++ b/src/plugins/fts-solr/solr-connection.c @@ -103,7 +103,7 @@ int solr_connection_init(const struct fts_solr_settings *solr_set, http_set.ssl = ssl_client_set; http_set.debug = solr_set->debug; http_set.rawlog_dir = solr_set->rawlog_dir; - solr_http_client = http_client_init(&http_set); + solr_http_client = http_client_init_private(&http_set); } *conn_r = conn; diff --git a/src/plugins/fts/fts-parser-tika.c b/src/plugins/fts/fts-parser-tika.c index a4b8b5c3034f57e22e77caa759c090da6b62f8ba..b8b57a350b9a710d101ac7ccbcc14560d415d905 100644 --- a/src/plugins/fts/fts-parser-tika.c +++ b/src/plugins/fts/fts-parser-tika.c @@ -77,7 +77,7 @@ tika_get_http_client_url(struct mail_user *user, struct http_url **http_url_r) http_set.request_timeout_msecs = 60*1000; http_set.ssl = &ssl_set; http_set.debug = user->mail_debug; - tika_http_client = http_client_init(&http_set); + tika_http_client = http_client_init_private(&http_set); } *http_url_r = tuser->http_url; return 0;

Greetings

I'm also experiencing these issues while running Dovecot 2.3.11.3 with Solr 8.6.3 on FreeBSD 11.4. As mentioned in a previous mail, the above patch is already applied to Dovecot's FreeBSD Port, confirmed by the patches being present in the portstree (https://svnweb.freebsd.org/ports/branches/2020Q3/mail/dovecot/files/).

In a FreeBSD VM with the official image (https://download.freebsd.org/ftp/releases/VM-IMAGES/12.1-RELEASE/amd64/Lates...) I compiled dovecot from git and was able to reproduce the error with the patch mentioned above applied and also without any patches at all. From these results i conclude, that neither the patches applied in FreeBSDs portstree or the patch above have any influence.

I also managed to reproduce the same results on a Debian 10 machine (also with and without the patch):

doveadm(some.user@example.com): Panic: file http-client-request.c: line 1232 (http_client_request_send_more): assertion failed: (req->payload_input != NULL) doveadm(some.user@example.com): Error: Raw backtrace: /usr/local/lib/dovecot/libdovecot.so http://libdovecot.so.0(backtrace_append+0x42) [0x7f093f7fc3c2] -> /usr/local/lib/dovecot/libdovecot.so http://libdovecot.so.0(backtrace_get+0x1e) [0x7f093f7fc4ce] -> /usr/local/lib/dovecot/libdovecot.so http://libdovecot.so.0(+0xea341) [0x7f093f807341] -> /usr/local/lib/dovecot/libdovecot.so http://libdovecot.so.0(+0xea381) [0x7f093f807381] -> /usr/local/lib/dovecot/libdovecot.so http://libdovecot.so.0(i_fatal+0) [0x7f093f75c074] -> /usr/local/lib/dovecot/libdovecot.so http://libdovecot.so.0(http_client_request_send_more+0x378) [0x7f093f7a47a8] -> /usr/local/lib/dovecot/libdovecot.so http://libdovecot.so.0(http_client_connection_output+0xe4) [0x7f093f7a90f4] -> /usr/local/lib/dovecot/libssl_iostream_openssl.so http://openssl.so(+0x8bff) [0x7f093ec71bff] -> /usr/local/lib/dovecot/libdovecot.so http://libdovecot.so.0(+0x1148b0) [0x7f093f8318b0] -> /usr/local/lib/dovecot/libdovecot.so http://libdovecot.so.0(io_loop_call_io+0x69) [0x7f093f820259] -> /usr/local/lib/dovecot/libdovecot.so http://libdovecot.so.0(io_loop_handler_run_internal+0x11b) [0x7f093f821b6b] -> /usr/local/lib/dovecot/libdovecot.so http://libdovecot.so.0(io_loop_handler_run+0x59) [0x7f093f820369] -> /usr/local/lib/dovecot/libdovecot.so http://libdovecot.so.0(io_loop_run+0x38) [0x7f093f820598] -> /usr/local/lib/dovecot/libdovecot.so http://libdovecot.so.0(+0x86d1e) [0x7f093f7a3d1e] -> /usr/local/lib/dovecot/libdovecot.so http://libdovecot.so.0(http_client_request_finish_payload+0x2e) [0x7f093f7a407e] -> /usr/local/lib/dovecot/lib21_fts_solr_plugin.so http://plugin.so(solr_connection_post_end+0x32) [0x7f093b8492c2] -> /usr/local/lib/dovecot/lib21_fts_solr_plugin.so http://plugin.so(+0x3a45) [0x7f093b844a45] -> /usr/local/lib/dovecot/lib20_fts_plugin.so http://plugin.so(+0x94cc) [0x7f093e1104cc] -> /usr/local/lib/dovecot/lib20_fts_plugin.so http://plugin.so(fts_backend_update_deinit+0x23) [0x7f093e110503] -> /usr/local/lib/dovecot/lib20_fts_plugin.so http://plugin.so(+0x10a9b) [0x7f093e117a9b] -> /usr/local/lib/dovecot/lib20_fts_plugin.so http://plugin.so(+0x119ca) [0x7f093e1189ca] -> /usr/local/lib/dovecot/libdovecot-storage.so http://libdovecot-storage.so.0(mailbox_transaction_commit_get_changes+0x56) [0x7f093fb16076] -> /usr/local/lib/dovecot/libdovecot-storage.so http://libdovecot-storage.so.0(mailbox_transaction_commit+0x1e) [0x7f093fb1615e] -> doveadm(+0x31370) [0x5607cfa1f370] -> doveadm(+0x2b2a8) [0x5607cfa192a8] -> doveadm(+0x2bfb2) [0x5607cfa19fb2] -> doveadm(doveadm_cmd_ver2_to_mail_cmd_wrapper+0x215) [0x5607cfa1ae05] -> doveadm(doveadm_cmd_run_ver2+0x57c) [0x5607cfa2bbec] -> doveadm(doveadm_cmd_try_run_ver2+0x37) [0x5607cfa2bc37] -> doveadm(main+0x1d2) [0x5607cfa09492] Aborted

During my tests I also did notice, that the error appears more often depending of mail size and amount of mails in a folder:

Tested with: doveadm -v fts rescan -u some.user@example.com && doveadm -v index -u some.user@example.com '*' 1 Mail in INBOX with 9KB -> Error appeared 0 out of 20 times 1 Mail in INBOX with 136KB -> Error appeared 17 out of 20 times 3 Mails in INBOX with 408KB -> Error appeared 12 out of 20 times 20 Mails in INBOX with ~2MB -> Error appeared 0 out of 20 times

Maybe this info helps anyone.

Patrik

Yeah, I read your mail and that's why I tested with different mail sizes. I did some more tests, one with large headers (around 700 lines of a long header line) but small body:

1 Mail in INBOX with 583KB -> Error appeared 5 out of 20 times

and another with a large mail body but normal headers:

1 Mail in INBOX with 585KB -> Error appeared 0 out of 20 times I guess this kinda confirms your guess, but interestingly shows less errors than my previous test with a large header 136KB Mail.

Patrik

I did notice that changing the batch_size in

fts_solr = url=http://solr.example.org:8983/solr/ soft_commit=yes batch_size=1000

does have an influence in how often the error occurs. Setting it to 1 or some huge number like 10000 reduces the chances quite a bit but not completely and also causes lots of small , or few but quite large requests to Solr, so its not a practical workaround.

Whats the current state of this bug? A fix for it would be very welcome, as it causes some trouble in our setup.

Regards

Hi

would someone care to post (preferably a link) to a test email with which the problem can be reproduced?

thanks

Joh

I can confirm that this is an error that was introduced in 2.3.11.3. It did not happen on 2.3.10. I see it occurring on a Centos 7 installation compiled from source. Between these two releases I didn't see changes on the fts-solr code, but I do see some changes on the lib-http code. I suspect that the changes done on lib-http have introduced this issue. One temporary solution might be to roll back the relevant commits that impacted lib-http and see if the problem resolves. Given the info in this thread about the records arriving on solr, I'm wondering if this is just a problem where the data has been split into more than one request, but the last one has no data left in it. John

I have implemented this change and the core dumps went away. It appears so far that it's indeed the right fix. Has this change been introduced in 2.3.11.3 ?  Thanks! On Tuesday, 27/10/2020 at 08:20 John Fawcett wrote: On 22/10/2020 10:23, John Fawcett wrote: On 21/10/2020 19:00, John Fawcett wrote: On 21/10/2020 16:44, Patrik Peng wrote: On 16.10.20 18:34, Patrik Peng wrote: On 16.10.20 18:00, Scott Q. wrote: This reminds me, the way I was able to reproduce this consistently was by having large headers ( 100+ lines ). On Friday, 16/10/2020 at 11:49 Patrik Peng wrote: On 19.08.20 17:37, Josef 'Jeff' Sipek wrote: On Wed, Aug 19, 2020 at 17:03:57 +0200, Alessio Cecchi wrote: Hi, after the upgrade to Dovecot 2.3.11.3, from 2.3.10.1, I see frequently these errors from different users: It looks like this has been around for a while and you just got unlucky and started seeing this now. Here's a quick & dirty patch that should fix this. If you can try it, let us know how it went. Jeff. diff --git a/src/plugins/fts-solr/solr-connection.c b/src/plugins/fts-solr/solr-connection.c index ae720b5e2870a852c1b6c440939e3c7c0fa72b5c..9d364f93e2cd1b716b9ab61bd39656a6c5b1ea04 100644 --- a/src/plugins/fts-solr/solr-connection.c +++ b/src/plugins/fts-solr/solr-connection.c @@ -103,7 +103,7 @@ int solr_connection_init(const struct fts_solr_settings *solr_set, http_set.ssl = ssl_client_set; http_set.debug = solr_set->debug; http_set.rawlog_dir = solr_set->rawlog_dir; -solr_http_client = http_client_init(&http_set); +solr_http_client = http_client_init_private(&http_set); } *conn_r = conn; diff --git a/src/plugins/fts/fts-parser-tika.c b/src/plugins/fts/fts-parser-tika.c index a4b8b5c3034f57e22e77caa759c090da6b62f8ba..b8b57a350b9a710d101ac7ccbcc14560d415d905 100644 --- a/src/plugins/fts/fts-parser-tika.c +++ b/src/plugins/fts/fts-parser-tika.c @@ -77,7 +77,7 @@ tika_get_http_client_url(struct mail_user *user, struct http_url **http_url_r) http_set.request_timeout_msecs = 60*1000; http_set.ssl = &ssl_set; http_set.debug = user->mail_debug; -tika_http_client = http_client_init(&http_set); +tika_http_client = http_client_init_private(&http_set); } *http_url_r = tuser->http_url; return 0; Greetings I'm also experiencing these issues while running Dovecot 2.3.11.3 with Solr 8.6.3 on FreeBSD 11.4. As mentioned in a previous mail, the above patch is already applied to Dovecot's FreeBSD Port, confirmed by the patches being present in the portstree (https://svnweb.freebsd.org/ports/branches/2020Q3/mail/dovecot/files/). In a FreeBSD VM with the official image (https://download.freebsd.org/ftp/releases/VM-IMAGES/12.1-RELEASE/amd64/Lates...) I compiled dovecot from git and was able to reproduce the error with the patch mentioned above applied and also without any patches at all.

From these results i conclude, that neither the patches applied in FreeBSDs portstree or the patch above have any influence.

I also managed to reproduce the same results on a Debian 10 machine (also with and without the patch): doveadm(some.user@example.com [1]): Panic: file http-client-request.c: line 1232 (http_client_request_send_more): assertion failed: (req->payload_input != NULL) doveadm(some.user@example.com [1]): Error: Raw backtrace: /usr/local/lib/dovecot/libdovecot.so [2].0(backtrace_append+0x42) [0x7f093f7fc3c2] -> /usr/local/lib/dovecot/libdovecot.so [2].0(backtrace_get+0x1e) [0x7f093f7fc4ce] -> /usr/local/lib/dovecot/libdovecot.so [2].0(+0xea341) [0x7f093f807341] -> /usr/local/lib/dovecot/libdovecot.so [2].0(+0xea381) [0x7f093f807381] -> /usr/local/lib/dovecot/libdovecot.so [2].0(i_fatal+0) [0x7f093f75c074] -> /usr/local/lib/dovecot/libdovecot.so [2].0(http_client_request_send_more+0x378) [0x7f093f7a47a8] -> /usr/local/lib/dovecot/libdovecot.so [2].0(http_client_connection_output+0xe4) [0x7f093f7a90f4] -> /usr/local/lib/dovecot/libssl_iostream_openssl.so [3](+0x8bff) [0x7f093ec71bff] -> /usr/local/lib/dovecot/libdovecot.so [2].0(+0x1148b0) [0x7f093f8318b0] -> /usr/local/lib/dovecot/libdovecot.so [2].0(io_loop_call_io+0x69) [0x7f093f820259] -> /usr/local/lib/dovecot/libdovecot.so [2].0(io_loop_handler_run_internal+0x11b) [0x7f093f821b6b] -> /usr/local/lib/dovecot/libdovecot.so [2].0(io_loop_handler_run+0x59) [0x7f093f820369] -> /usr/local/lib/dovecot/libdovecot.so [2].0(io_loop_run+0x38) [0x7f093f820598] -> /usr/local/lib/dovecot/libdovecot.so [2].0(+0x86d1e) [0x7f093f7a3d1e] -> /usr/local/lib/dovecot/libdovecot.so [2].0(http_client_request_finish_payload+0x2e) [0x7f093f7a407e] -> /usr/local/lib/dovecot/lib21_fts_solr_plugin.so [4](solr_connection_post_end+0x32) [0x7f093b8492c2] -> /usr/local/lib/dovecot/lib21_fts_solr_plugin.so [4](+0x3a45) [0x7f093b844a45] -> /usr/local/lib/dovecot/lib20_fts_plugin.so [4](+0x94cc) [0x7f093e1104cc] -> /usr/local/lib/dovecot/lib20_fts_plugin.so [4](fts_backend_update_deinit+0x23) [0x7f093e110503] -> /usr/local/lib/dovecot/lib20_fts_plugin.so [4](+0x10a9b) [0x7f093e117a9b] -> /usr/local/lib/dovecot/lib20_fts_plugin.so [4](+0x119ca) [0x7f093e1189ca] -> /usr/local/lib/dovecot/libdovecot-storage.so [5].0(mailbox_transaction_commit_get_changes+0x56) [0x7f093fb16076] -> /usr/local/lib/dovecot/libdovecot-storage.so [5].0(mailbox_transaction_commit+0x1e) [0x7f093fb1615e] -> doveadm(+0x31370) [0x5607cfa1f370] -> doveadm(+0x2b2a8) [0x5607cfa192a8] -> doveadm(+0x2bfb2) [0x5607cfa19fb2] -> doveadm(doveadm_cmd_ver2_to_mail_cmd_wrapper+0x215) [0x5607cfa1ae05] -> doveadm(doveadm_cmd_run_ver2+0x57c) [0x5607cfa2bbec] -> doveadm(doveadm_cmd_try_run_ver2+0x37) [0x5607cfa2bc37] -> doveadm(main+0x1d2) [0x5607cfa09492] Aborted During my tests I also did notice, that the error appears more often depending of mail size and amount of mails in a folder: Tested with: doveadm -v fts rescan -u some.user@example.com && doveadm -v index -u some.user@example.com '*' 1 Mail in INBOX with 9KB -> Error appeared 0 out of 20 times 1 Mail in INBOX with 136KB -> Error appeared 17 out of 20 times 3 Mails in INBOX with 408KB -> Error appeared 12 out of 20 times 20 Mails in INBOX with ~2MB -> Error appeared 0 out of 20 times Maybe this info helps anyone. Patrik Yeah, I read your mail and that's why I tested with different mail sizes. I did some more tests, one with large headers (around 700 lines of a long header line) but small body: 1 Mail in INBOX with 583KB -> Error appeared 5 out of 20 times and another with a large mail body but normal headers: 1 Mail in INBOX with 585KB -> Error appeared 0 out of 20 times I guess this kinda confirms your guess, but interestingly shows less errors than my previous test with a large header 136KB Mail. Patrik I did notice that changing the batch_size in fts_solr = url=http://solr.example.org:8983/solr/ soft_commit=yes batch_size=1000 does have an influence in how often the error occurs. Setting it to 1 or some huge number like 10000 reduces the chances quite a bit but not completely and also causes lots of small , or few but quite large requests to Solr, so its not a practical workaround. Whats the current state of this bug? A fix for it would be very welcome, as it causes some trouble in our setup. Regards Hi would someone care to post (preferably a link) to a test email with which the problem can be reproduced? thanks Joh I can confirm that this is an error that was introduced in 2.3.11.3. It did not happen on 2.3.10. I see it occurring on a Centos 7 installation compiled from source. Between these two releases I didn't see changes on the fts-solr code, but I do see some changes on the lib-http code. I suspect that the changes done on lib-http have introduced this issue. One temporary solution might be to roll back the relevant commits that impacted lib-http and see if the problem resolves. Given the info in this thread about the records arriving on solr, I'm wondering if this is just a problem where the data has been split into more than one request, but the last one has no data left in it. John Hi I did a bit of tracing. From the albeit limited examples that I saw the panic and assert segfault always happens when  req->payload_finished is true. If that observation is correct in general, then the patch is simple, just put the test for payload_finished before the assert for payload_input and payload_output. Would anyone with the problem care to try it and give feedback? diff -ur dovecot-2.3.11.3-orig/src/lib-http/http-client-request.c dovecot-2.3.11.3/src/lib-http/http-client-request.c --- dovecot-2.3.11.3-orig/src/lib-http/http-client-request.c    2020-08-12 14:20:41.000000000 +0200 +++ dovecot-2.3.11.3/src/lib-http/http-client-request.c 2020-10-27 13:06:09.352973130 +0100 @@ -1229,12 +1229,12 @@         const char *error;         uoff_t offset; -       i_assert(req->payload_input != NULL); -       i_assert(req->payload_output != NULL); -         if (req->payload_finished)                 return http_client_request_finish_payload_out(req); +       i_assert(req->payload_input != NULL); +       i_assert(req->payload_output != NULL); +         io_remove(&conn->io_req_payload);         /* chunked ostream needs to write to the parent stream's buffer */ Links: ------ [1] mailto:some.user2@example.com [2] http://libdovecot.so [3] http://openssl.so [4] http://plugin.so [5] http://libdovecot-storage.so

But do you know how this bug was introduced ? I checked the history of that file and don't see anything introduced recently that might cause this: https://github.com/dovecot/core/commits/master/src/lib-http/http-client-requ... The only one that might be somewhat related is this one from Apr 27 by Stephan Bosch https://github.com/dovecot/core/commit/799b52accf71e86756dde738d22c1c6a500a7... On Saturday, 31/10/2020 at 08:40 John Fawcett wrote: On 31/10/2020 00:18, Scott Q. wrote: I have implemented this change and the core dumps went away. It appears so far that it's indeed the right fix. Has this change been introduced in 2.3.11.3 ?  Thanks! I've also been running it for 4 days without any further panics / segfaults and no noticed adverse effects. I'd recommend the dovecot team to consider including the patch in the next update. John diff -ur dovecot-2.3.11.3-orig/src/lib-http/http-client-request.c dovecot-2.3.11.3/src/lib-http/http-client-request.c --- dovecot-2.3.11.3-orig/src/lib-http/http-client-request.c    2020-08-12 14:20:41.000000000 +0200 +++ dovecot-2.3.11.3/src/lib-http/http-client-request.c 2020-10-27 13:06:09.352973130 +0100 @@ -1229,12 +1229,12 @@         const char *error;         uoff_t offset; -       i_assert(req->payload_input != NULL); -       i_assert(req->payload_output != NULL); -         if (req->payload_finished)                 return http_client_request_finish_payload_out(req); +       i_assert(req->payload_input != NULL); +       i_assert(req->payload_output != NULL); +         io_remove(&conn->io_req_payload);         /* chunked ostream needs to write to the parent stream's buffer */

On 31.10.20 00:18, Scott Q. wrote:

I have implemented this change and the core dumps went away.

It appears so far that it's indeed the right fix.

Has this change been introduced in 2.3.11.3 ?

Thanks!

On Tuesday, 27/10/2020 at 08:20 John Fawcett wrote:

On 22/10/2020 10:23, John Fawcett wrote:

...

On 21/10/2020 19:00, John Fawcett wrote:

...

On 21/10/2020 16:44, Patrik Peng wrote:

...

On 16.10.20 18:34, Patrik Peng wrote:

...

On 16.10.20 18:00, Scott Q. wrote:

...

This reminds me, the way I was able to reproduce this consistently was by having large headers ( 100+ lines ).

On Friday, 16/10/2020 at 11:49 Patrik Peng wrote:

On 19.08.20 17:37, Josef 'Jeff' Sipek wrote:

> On Wed, Aug 19, 2020 at 17:03:57 +0200, Alessio Cecchi wrote: >> Hi, >> after the upgrade to Dovecot 2.3.11.3, from 2.3.10.1, I see frequently >> these errors from different users: > It looks like this has been around for a while and you just got unlucky and > started seeing this now. Here's a quick & dirty patch that should fix this. > If you can try it, let us know how it went. > Jeff. > diff --git a/src/plugins/fts-solr/solr-connection.c b/src/plugins/fts-solr/solr-connection.c > index ae720b5e2870a852c1b6c440939e3c7c0fa72b5c..9d364f93e2cd1b716b9ab61bd39656a6c5b1ea04 100644 > --- a/src/plugins/fts-solr/solr-connection.c > +++ b/src/plugins/fts-solr/solr-connection.c > @@ -103,7 +103,7 @@ int solr_connection_init(const struct fts_solr_settings *solr_set, > http_set.ssl = ssl_client_set; > http_set.debug = solr_set->debug; > http_set.rawlog_dir = solr_set->rawlog_dir; > - solr_http_client = http_client_init(&http_set); > + solr_http_client = http_client_init_private(&http_set); > } > *conn_r = conn; > diff --git a/src/plugins/fts/fts-parser-tika.c b/src/plugins/fts/fts-parser-tika.c > index a4b8b5c3034f57e22e77caa759c090da6b62f8ba..b8b57a350b9a710d101ac7ccbcc14560d415d905 100644 > --- a/src/plugins/fts/fts-parser-tika.c > +++ b/src/plugins/fts/fts-parser-tika.c > @@ -77,7 +77,7 @@ tika_get_http_client_url(struct mail_user *user, struct http_url **http_url_r) > http_set.request_timeout_msecs = 60*1000; > http_set.ssl = &ssl_set; > http_set.debug = user->mail_debug; > - tika_http_client = http_client_init(&http_set); > + tika_http_client = http_client_init_private(&http_set); > } > *http_url_r = tuser->http_url; > return 0;

Greetings

I'm also experiencing these issues while running Dovecot 2.3.11.3 with Solr 8.6.3 on FreeBSD 11.4. As mentioned in a previous mail, the above patch is already applied to Dovecot's FreeBSD Port, confirmed by the patches being present in the portstree (https://svnweb.freebsd.org/ports/branches/2020Q3/mail/dovecot/files/).

In a FreeBSD VM with the official image (https://download.freebsd.org/ftp/releases/VM-IMAGES/12.1-RELEASE/amd64/Lates...) I compiled dovecot from git and was able to reproduce the error with the patch mentioned above applied and also without any patches at all. From these results i conclude, that neither the patches applied in FreeBSDs portstree or the patch above have any influence.

I also managed to reproduce the same results on a Debian 10 machine (also with and without the patch):

doveadm(some.user@example.com): Panic: file http-client-request.c: line 1232 (http_client_request_send_more): assertion failed: (req->payload_input != NULL) doveadm(some.user@example.com): Error: Raw backtrace: /usr/local/lib/dovecot/libdovecot.so http://libdovecot.so.0(backtrace_append+0x42) [0x7f093f7fc3c2] -> /usr/local/lib/dovecot/libdovecot.so http://libdovecot.so.0(backtrace_get+0x1e) [0x7f093f7fc4ce] -> /usr/local/lib/dovecot/libdovecot.so http://libdovecot.so.0(+0xea341) [0x7f093f807341] -> /usr/local/lib/dovecot/libdovecot.so http://libdovecot.so.0(+0xea381) [0x7f093f807381] -> /usr/local/lib/dovecot/libdovecot.so http://libdovecot.so.0(i_fatal+0) [0x7f093f75c074] -> /usr/local/lib/dovecot/libdovecot.so http://libdovecot.so.0(http_client_request_send_more+0x378) [0x7f093f7a47a8] -> /usr/local/lib/dovecot/libdovecot.so http://libdovecot.so.0(http_client_connection_output+0xe4) [0x7f093f7a90f4] -> /usr/local/lib/dovecot/libssl_iostream_openssl.so http://openssl.so(+0x8bff) [0x7f093ec71bff] -> /usr/local/lib/dovecot/libdovecot.so http://libdovecot.so.0(+0x1148b0) [0x7f093f8318b0] -> /usr/local/lib/dovecot/libdovecot.so http://libdovecot.so.0(io_loop_call_io+0x69) [0x7f093f820259] -> /usr/local/lib/dovecot/libdovecot.so http://libdovecot.so.0(io_loop_handler_run_internal+0x11b) [0x7f093f821b6b] -> /usr/local/lib/dovecot/libdovecot.so http://libdovecot.so.0(io_loop_handler_run+0x59) [0x7f093f820369] -> /usr/local/lib/dovecot/libdovecot.so http://libdovecot.so.0(io_loop_run+0x38) [0x7f093f820598] -> /usr/local/lib/dovecot/libdovecot.so http://libdovecot.so.0(+0x86d1e) [0x7f093f7a3d1e] -> /usr/local/lib/dovecot/libdovecot.so http://libdovecot.so.0(http_client_request_finish_payload+0x2e) [0x7f093f7a407e] -> /usr/local/lib/dovecot/lib21_fts_solr_plugin.so http://plugin.so(solr_connection_post_end+0x32) [0x7f093b8492c2] -> /usr/local/lib/dovecot/lib21_fts_solr_plugin.so http://plugin.so(+0x3a45) [0x7f093b844a45] -> /usr/local/lib/dovecot/lib20_fts_plugin.so http://plugin.so(+0x94cc) [0x7f093e1104cc] -> /usr/local/lib/dovecot/lib20_fts_plugin.so http://plugin.so(fts_backend_update_deinit+0x23) [0x7f093e110503] -> /usr/local/lib/dovecot/lib20_fts_plugin.so http://plugin.so(+0x10a9b) [0x7f093e117a9b] -> /usr/local/lib/dovecot/lib20_fts_plugin.so http://plugin.so(+0x119ca) [0x7f093e1189ca] -> /usr/local/lib/dovecot/libdovecot-storage.so http://libdovecot-storage.so.0(mailbox_transaction_commit_get_changes+0x56) [0x7f093fb16076] -> /usr/local/lib/dovecot/libdovecot-storage.so http://libdovecot-storage.so.0(mailbox_transaction_commit+0x1e) [0x7f093fb1615e] -> doveadm(+0x31370) [0x5607cfa1f370] -> doveadm(+0x2b2a8) [0x5607cfa192a8] -> doveadm(+0x2bfb2) [0x5607cfa19fb2] -> doveadm(doveadm_cmd_ver2_to_mail_cmd_wrapper+0x215) [0x5607cfa1ae05] -> doveadm(doveadm_cmd_run_ver2+0x57c) [0x5607cfa2bbec] -> doveadm(doveadm_cmd_try_run_ver2+0x37) [0x5607cfa2bc37] -> doveadm(main+0x1d2) [0x5607cfa09492] Aborted

During my tests I also did notice, that the error appears more often depending of mail size and amount of mails in a folder:

Tested with: doveadm -v fts rescan -usome.user@example.com && doveadm -v index -usome.user@example.com '*' 1 Mail in INBOX with 9KB -> Error appeared 0 out of 20 times 1 Mail in INBOX with 136KB -> Error appeared 17 out of 20 times 3 Mails in INBOX with 408KB -> Error appeared 12 out of 20 times 20 Mails in INBOX with ~2MB -> Error appeared 0 out of 20 times

Maybe this info helps anyone.

Patrik

Yeah, I read your mail and that's why I tested with different mail sizes. I did some more tests, one with large headers (around 700 lines of a long header line) but small body:

1 Mail in INBOX with 583KB -> Error appeared 5 out of 20 times

and another with a large mail body but normal headers:

1 Mail in INBOX with 585KB -> Error appeared 0 out of 20 times I guess this kinda confirms your guess, but interestingly shows less errors than my previous test with a large header 136KB Mail.

Patrik

I did notice that changing the batch_size in

fts_solr = url=http://solr.example.org:8983/solr/ soft_commit=yes batch_size=1000

does have an influence in how often the error occurs. Setting it to 1 or some huge number like 10000 reduces the chances quite a bit but not completely and also causes lots of small , or few but quite large requests to Solr, so its not a practical workaround.

Whats the current state of this bug? A fix for it would be very welcome, as it causes some trouble in our setup.

Regards

Hi

would someone care to post (preferably a link) to a test email with which the problem can be reproduced?

thanks

Joh

I can confirm that this is an error that was introduced in 2.3.11.3. It did not happen on 2.3.10. I see it occurring on a Centos 7 installation compiled from source. Between these two releases I didn't see changes on the fts-solr code, but I do see some changes on the lib-http code. I suspect that the changes done on lib-http have introduced this issue.

One temporary solution might be to roll back the relevant commits that impacted lib-http and see if the problem resolves. Given the info in this thread about the records arriving on solr, I'm wondering if this is just a problem where the data has been split into more than one request, but the last one has no data left in it.

John

Hi

I did a bit of tracing. From the albeit limited examples that I saw the panic and assert segfault always happens when  req->payload_finished is true. If that observation is correct in general, then the patch is simple, just put the test for payload_finished before the assert for payload_input and payload_output. Would anyone with the problem care to try it and give feedback?

diff -ur dovecot-2.3.11.3-orig/src/lib-http/http-client-request.c dovecot-2.3.11.3/src/lib-http/http-client-request.c --- dovecot-2.3.11.3-orig/src/lib-http/http-client-request.c 2020-08-12 14:20:41.000000000 +0200 +++ dovecot-2.3.11.3/src/lib-http/http-client-request.c 2020-10-27 13:06:09.352973130 +0100 @@ -1229,12 +1229,12 @@         const char *error;         uoff_t offset;

-       i_assert(req->payload_input != NULL); -       i_assert(req->payload_output != NULL); -         if (req->payload_finished)                 return http_client_request_finish_payload_out(req);

+       i_assert(req->payload_input != NULL); +       i_assert(req->payload_output != NULL); +         io_remove(&conn->io_req_payload);

        /* chunked ostream needs to write to the parent stream's buffer */

I can confirm the same behavior after applying these changes. No more core dumps so far. Thanks as well :)

Not sure if I mentioned it but I'm on FreeBSD too. I wonder if any of the patches FreeBSD applies automatically is causing this. I looked through them but couldn't find anything obvious that might cause this --- configure.orig      2020-08-12 12:20:51 UTC +++ configure @@ -28901,13 +28901,13 @@ fi    if test $want_stemmer != no; then -    { $as_echo "$as_me:${as_lineno-$LINENO}: checking for sb_stemmer_new in -lstemmer" >&5 -$as_echo_n "checking for sb_stemmer_new in -lstemmer... " >&6; } +    { $as_echo "$as_me:${as_lineno-$LINENO}: checking for sb_stemmer_new in -lclucene-contribs-lib" >&5 +$as_echo_n "checking for sb_stemmer_new in -lclucene-contribs-lib... " >&6; }  if ${ac_cv_lib_stemmer_sb_stemmer_new+:} false; then :    $as_echo_n "(cached) " >&6  else    ac_check_lib_save_LIBS=$LIBS -LIBS="-lstemmer  $LIBS" +LIBS="-lclucene-contribs-lib  $LIBS"  cat confdefs.h - base_dir, "/"MASTER_PID_FILE_NAME, NULL); --- src/plugins/fts-lucene/SnowballFilter.h.orig        2020-08-12 12:20:41 UTC +++ src/plugins/fts-lucene/SnowballFilter.h @@ -8,7 +8,7 @@  #define _lucene_analysis_snowball_filter_  #include "CLucene/analysis/AnalysisHeader.h" -#include "libstemmer.h" +#include "CLucene/snowball/libstemmer.h"  CL_NS_DEF2(analysis,snowball) --- src/plugins/fts-solr/solr-connection.c.orig 2020-08-12 12:20:41 UTC +++ src/plugins/fts-solr/solr-connection.c @@ -103,7 +103,7 @@ int solr_connection_init(const struct fts_solr_setting                 http_set.ssl = ssl_client_set;                 http_set.debug = solr_set->debug;                 http_set.rawlog_dir = solr_set->rawlog_dir; -               solr_http_client = http_client_init(&http_set); +               solr_http_client = http_client_init_private(&http_set);         }         *conn_r = conn; /usr gets changed to ${LOCALBASE} in post-patch:, so we cheat and set xpdf's path to /usr/lib. --- src/plugins/fts/decode2text.sh.orig 2017-10-28 12:21:20 UTC +++ src/plugins/fts/decode2text.sh @@ -79,16 +79,20 @@ wait_timeout() {  LANG=en_US.UTF-8  export LANG  if [ $fmt = "pdf" ]; then -  /usr/bin/pdftotext $path - 2>/dev/null& +  if [ -x /usr/lib/xpdf/pdftotext ]; then +    /usr/lib/xpdf/pdftotext $path - 2>/dev/null& +  else +    /usr/local/bin/pdftotext $path - 2>/dev/null& +  fi    wait_timeout 2>/dev/null  elif [ $fmt = "doc" ]; then -  (/usr/bin/catdoc $path; true) 2>/dev/null& +  (/usr/local/bin/catdoc $path; true) 2>/dev/null&    wait_timeout 2>/dev/null  elif [ $fmt = "ppt" ]; then -  (/usr/bin/catppt $path; true) 2>/dev/null& +  (/usr/local/bin/catppt $path; true) 2>/dev/null&    wait_timeout 2>/dev/null  elif [ $fmt = "xls" ]; then -  (/usr/bin/xls2csv $path; true) 2>/dev/null& +  (/usr/local/bin/xls2csv $path; true) 2>/dev/null&    wait_timeout 2>/dev/null  elif [ $fmt = "odt" -o $fmt = "ods" -o $fmt = "odp" ]; then    xmlunzip "content.xml" --- src/plugins/fts/fts-parser-tika.c.orig      2019-01-02 22:11:26 UTC +++ src/plugins/fts/fts-parser-tika.c @@ -77,7 +77,7 @@ tika_get_http_client_url(struct mail_user *user, struc                 http_set.request_timeout_msecs = 60*1000;                 http_set.ssl = &ssl_set;                 http_set.debug = user->mail_debug; -               tika_http_client = http_client_init(&http_set); +               tika_http_client = http_client_init_private(&http_set);         }         *http_url_r = tuser->http_url;         return 0; On Sunday, 06/09/2020 at 10:14 Bane Ivosev wrote: Just to confirm, same problem, FreeBSD, after update from 2.3.10.1 to 2.3.11.3 with Solr 7.7. On 8/19/20 5:03 PM, Alessio Cecchi wrote:

Hi,

after the upgrade to Dovecot 2.3.11.3, from 2.3.10.1, I see frequently these errors from different users:

Aug 18 11:02:35 Panic: indexer-worker(info@domain.com) session=: file http-client-request.c: line 1232 (http_client_request_send_more): assertion failed: (req->payload_input != NULL) Aug 18 11:02:35 Error: indexer-worker(info@domain.com) session=: Raw backtrace: /usr/lib64/dovecot/libdovecot.so [1].0(backtrace_append+0x2f) [0x7f0ee3c828bf] -> /usr/lib64/dovecot/libdovecot.so [1].0(backtrace_get+0x26) [0x7f0ee3c829d6] -> /usr/lib64/dovecot/libdovecot.so [1].0(+0xeb7ba) [0x7f0ee3c8d7ba] -> /usr/lib64/dovecot/libdovecot.so [1].0(+0xeb801) [0x7f0ee3c8d801] -> /usr/lib64/dovecot/libdovecot.so [1].0(+0x42ff1) [0x7f0ee3be4ff1] -> /usr/lib64/dovecot/libdovecot.so [1].0(http_client_request_send_more+0x415) [0x7f0ee3c2ba25] -> /usr/lib64/dovecot/libdovecot.so [1].0(http_client_connection_output+0x114) [0x7f0ee3c30994] -> /usr/lib64/dovecot/libdovecot.so [1].0(+0x115470) [0x7f0ee3cb7470] -> /usr/lib64/dovecot/libdovecot.so [1].0(io_loop_call_io+0x55) [0x7f0ee3ca4eb5] -> /usr/lib64/dovecot/libdovecot.so [1].0(io_loop_handler_run_internal+0xdc) [0x7f0ee3ca6ebc] -> /usr/lib64/dovecot/libdovecot.so [1].0(io_loop_handler_run+0x5c) [0x7f0ee3ca4fac] -> /usr/lib64/dovecot/libdovecot.so [1].0(io_loop_run+0x38) [0x7f0ee3ca51f8] -> /usr/lib64/dovecot/libdovecot.so [1].0(+0x8a955) [0x7f0ee3c2c955] -> /usr/lib64/dovecot/libdovecot.so [1].0(http_client_request_finish_payload+0x21) [0x7f0ee3c2cbd1] -> /usr/lib64/dovecot/lib21_fts_solr_plugin.so [2](solr_connection_post_end+0x45) [0x7f0ee1c85d15] -> /usr/lib64/dovecot/lib21_fts_solr_plugin.so [2](+0x3fa0) [0x7f0ee1c81fa0] -> /usr/lib64/dovecot/lib20_fts_plugin.so [2](+0x86cc) [0x7f0ee297f6cc] -> /usr/lib64/dovecot/lib20_fts_plugin.so [2](fts_backend_update_deinit+0x2c) [0x7f0ee297f74c] -> /usr/lib64/dovecot/lib20_fts_plugin.so [2](+0xfd04) [0x7f0ee2986d04] -> /usr/lib64/dovecot/lib20_fts_plugin.so [2](+0xff3f) [0x7f0ee2986f3f] -> /usr/lib64/dovecot/lib10_quota_plugin.so [2](+0xf64b) [0x7f0ee2dc764b] -> /usr/lib64/dovecot/lib01_acl_plugin.so [2](+0xde43) [0x7f0ee2fdce43] -> /usr/lib64/dovecot/libdovecot-storage.so [3].0(mailbox_transaction_commit_get_changes+0x54) [0x7f0ee3f91db4] -> /usr/lib64/dovecot/libdovecot-storage.so [3].0(mailbox_transaction_commit+0x16) [0x7f0ee3f91e76] -> dovecot/indexer-worker [info@domain.com INBOX](+0x291c) [0x557584acb91c] -> dovecot/indexer-worker [info@domain.com INBOX](+0x2e54) [0x557584acbe54] -> /usr/lib64/dovecot/libdovecot.so [1].0(io_loop_call_io+0x55) [0x7f0ee3ca4eb5] -> /usr/lib64/dovecot/libdovecot.so [1].0(io_loop_handler_run_internal+0xdc) [0x7f0ee3ca6ebc] -> /usr/lib64/dovecot/libdovecot.so [1].0(io_loop_handler_run+0x5c) [0x7f0ee3ca4fac] -> /usr/lib64/dovecot/libdovecot.so [1].0(io_loop_run+0x38) [0x7f0ee3ca51f8] Aug 18 11:02:35 Error: indexer: Indexer worker disconnected, discarding 1 requests for info@domain.com Aug 18 11:02:35 Error: imap(info@domain.com) session=: indexer failed to index mailbox INBOX Aug 18 11:02:35 Fatal: indexer-worker(info@domain.com) session=: master: service(indexer-worker): child 24604 killed with signal 6 (core dumps disabled - https://dovecot.org/bugreport.html#coredumps)

I'm using FTS with Solr 6.6.5. What is it?

Thanks

-- Alessio Cecchi Postmaster @ http://www.qboxmail.it https://www.linkedin.com/in/alessice

Links: ------ [1] http://libdovecot.so [2] http://plugin.so [3] http://libdovecot-storage.so