dovecot - Apr 2016 - fts_solr: Lookup failed: 400 Bad Request / GET null null

Hi,

the log file shows suspicious entries as follows:

Apr  3 09:14:49 xxx dovecot: imap(user at domain): Error: fts_solr:
Lookup failed: 400 Bad Request

The tomcat7 log shows for this request:

10.0.0.234 - - [03/Apr/2016:09:14:49 +0200] "GET null null" 400 -

Dovecot is latest 2.2.23 with a pretty standard FTS config copied from the wiki:

mail_plugins = " acl fts fts_solr"
fts = solr
fts_solr = break-imap-search url=http://10.0.0.123:8080/solr/

Unfortunately I do not know (yet) which client action produces these
log lines. "GET null null" seems not to be a sensible request in any
case.

Anyone seeing the same effect?

Chris

Op 3-4-2016 om 14:39 schreef Chris Laif:
> Hi,
>
> the log file shows suspicious entries as follows:
>
> Apr  3 09:14:49 xxx dovecot: imap(user at domain): Error: fts_solr:
> Lookup failed: 400 Bad Request
>
> The tomcat7 log shows for this request:
>
> 10.0.0.234 - - [03/Apr/2016:09:14:49 +0200] "GET null null" 400 -
>
> Dovecot is latest 2.2.23 with a pretty standard FTS config copied from the
wiki:
>
> mail_plugins = " acl fts fts_solr"
> fts = solr
> fts_solr = break-imap-search url=http://10.0.0.123:8080/solr/
>
> Unfortunately I do not know (yet) which client action produces these
> log lines. "GET null null" seems not to be a sensible request in
any
> case.
>
> Anyone seeing the same effect?
Did this happen only after upgrade to 2.2.23 or is this a fresh install?

Can you make a dump of what messages are exchanged on 10.0.0.123:8080 
using ngrep or wireshark?

Regards,

Stephan.

On Sun, Apr 3, 2016 at 4:19 PM, Stephan Bosch <stephan at rename-it.nl>
wrote:
>> Unfortunately I do not know (yet) which client action produces these
>> log lines. "GET null null" seems not to be a sensible request
in any
>> case.
>>
>> Anyone seeing the same effect?
>
>
> Did this happen only after upgrade to 2.2.23 or is this a fresh install?
>
This effect has been observed with 2.2.18 (initial install) and after
upgrading to 2.2.23 as well.

> Can you make a dump of what messages are exchanged on 10.0.0.123:8080 using
> ngrep or wireshark?
>
I've captured some requests and they look like this (some parts
changed due to privacy concerns):

GET
/solr/select?fl=uid,score&rows=439&sort=uid+asc&q={!lucene+q.op%3dAND}hdr:%3c56Fxxxx3A6.7080904
at domain.de%3e+OR+hdr:%3c664DCDxxxxx1A4FACD8B7922C495FEF at
CZCHOWS1356.prg%5c-domain.com%3e+OR+hdr:%3c00cxxxxxde3$70ad7880$52
 ... (many many more OR hdrs)
&fq=%2Bbox:f696f93xxxxxx6e+%2Buser:user at domain.de HTTP/1.1

The total request size is 31708 bytes and it contains many (hundreds?)
of 'OR hdrs' (side note: I wonder which client action triggers these
kind of requests, maybe the user selected hundreds of mails for
search?)

I _think_ this is a problem of the URL length / max http header size.
(Debian Jessie) Tomcat7 very likely does not accept more than 32kb
data in a request.

I wonder if Dovecot should limit SOLR requests to a specific size and
deny long requests with an imap error (?)

Chris