dovecot - Mar 2023 - iPhone Mail clients generate high Solr I/O

Hi,

I'm running a mail server with Dovecot 2.3.20 and Apache Solr as FTS 
backend.

It seems that iPhone/iPad Mail clients are generating some IMAP 
searches, especially on header Message-ID, that are increasing our Solr 
I/O load, especially during the night.

Are these kind of queries normal? What are they?

You can find some logs below.

Dovecot logs:

Mar 13 21:06:14 dovecot: imap-login: Login: user=<user at domain>, 
method=PLAIN, rip=x.x.x.x, lip=z.z.z.z, mpid=11263, secured, 
session=<PQSppM32gePCBJGh>
Mar 13 21:06:14 dovecot: imap(user at domain) session=<PQSppM32gePCBJGh>: 
ID sent: name=iPhone Mail, version=20D67, os=iOS, os-version=16.3.1 (20D67)
Mar 13 21:06:14 dovecot: imap(user at domain) session=<PQSppM32gePCBJGh>: 
Disconnected: Logged out in=207 out=1128 deleted=0 expunged=0 
autoexpunged=0 trashed=0 appended=0 hdr_count=0 hdr_bytes=0 body_count=0 
body_bytes=0

Solr logs:

2023-03-13 21:06:14.411 INFO? (qtp1671846437-1652) [?? x:dovecot] 
o.a.s.c.S.Request [dovecot]? webapp=/solr path=/select 
params={q={!lucene+q.op%3DAND}hdr:<DB8P189MB08692AE65580C36C3B7D6F53C1F59 at
domain6.tld>+OR+hdr:<\!\%26\!AAAAAAAAAAAYAAAAAAAAAI\/Oo\%2BConZZMkCvmEY7yWqjCgAAAEAAAAP968Yud4n1LmhwJxWgTURQBAAAAAA%3D%3D
at
domain5.tld>+OR+hdr:<CALEb\-gfyeQ1zJhjGKS3V8Rn3gk3byNa9co9nOU1L2BtUtKO0aw
at domain7.tld>+OR+hdr:<AS4P195MB1790AA65F5F367F3CF0888BEDEA19 at
domain5.tld>+OR+hdr:<24E36A6E5BB2410C8090482B3E1EB40F at
domain8.tld>&fl=uid,score&sort=uid+asc&fq=%2Bbox:d0f433254ee1b161c82c00002e1056c4+%2Buser:user
at domain&rows=88&wt=xml}
hits=0 status=0 QTime=275
2023-03-13 21:06:14.511 INFO? (qtp1671846437-1628) [?? x:dovecot] 
o.a.s.c.S.Request [dovecot]? webapp=/solr path=/select 
params={q={!lucene+q.op%3DAND}hdr:<af03d59c\-2cd5\-1165\-aea5\-6ce7cfe16a89
at
domain.tld>+OR+hdr:<CAJbcrLvxCOGy6fcKBuhuu9B1SALwm9opS\-\-O\-kcMd3nevKrf1A
at
domain7.tld>+OR+hdr:<00eb01d8c8dc$caa8a580$5ff9f080$@domain1.tld>+OR+hdr:<VE1PR08MB4846DD525845DC743D47ED52EEBA9
at
domain7.tld>+OR+hdr:<00c701d8bb83$f307bc70$d9173550$@domain1.tld>&fl=uid,score&sort=uid+asc&fq=%2Bbox:d0f433254ee1b161c82c00002e1056c4+%2Buser:user
at domain&rows=88&wt=xml}
hits=0 status=0 QTime=59
2023-03-13 21:06:14.714 INFO? (qtp1671846437-1652) [?? x:dovecot] 
o.a.s.c.S.Request [dovecot]? webapp=/solr path=/select 
params={q={!lucene+q.op%3DAND}hdr:<AS4P195MB179002723893D3932AF83A4CDEA29 at
domain5.tld>+OR+hdr:<F3112D85FDF144319FB0ABE348A75AE5 at
domain8.tld>+OR+hdr:<AM9PR10MB510032098A44B16182C9AAF39C4D9 at
domain8.tld>+OR+hdr:<\!\%26\!AAAAAAAAAAAYAAAAAAAAAI\/Oo\%2BConZZMkCvmEY7yWqjCgAAAEAAAADl2MLfkWRxJjQW\%2B3dOhZn0BAAAAAA%3D%3D
at
domain5.tld>+OR+hdr:<CAJbcrLtAEjLO0wbK5AAp8a3p0iRaoUeKA1wsD2ppDFeMnhL\-kA
at
domain7.tld>&fl=uid,score&sort=uid+asc&fq=%2Bbox:d0f433254ee1b161c82c00002e1056c4+%2Buser:user
at domain&rows=88&wt=xml}
hits=0 status=0 QTime=178
2023-03-13 21:06:14.771 INFO? (qtp1671846437-1628) [?? x:dovecot] 
o.a.s.c.S.Request [dovecot]? webapp=/solr path=/select 
params={q={!lucene+q.op%3DAND}hdr:<DU0P189MB208990AA60E3EB5CB2F9BE98DCD39 at
domain>+OR+hdr:<DDA00A9A19CE4864AD87EF31B0E2113F at
domain8.tld>+OR+hdr:<GV1PR01MB882049EDFF560AF4F4444F4BB1EE9 at
domain7.tld>&fl=uid,score&sort=uid+asc&fq=%2Bbox:d0f433254ee1b161c82c00002e1056c4+%2Buser:user
at domain&rows=88&wt=xml}
hits=0 status=0 QTime=34
2023-03-13 21:06:14.899 INFO? (qtp1671846437-1652) [?? x:dovecot] 
o.a.s.c.S.Request [dovecot]? webapp=/solr path=/select 
params={q={!lucene+q.op%3DAND}hdr:<AS4P195MB1790922D3154E37AEF263FD1DEDF9 at
domain5.tld>+OR+hdr:<02E5E16DF27945B6A764F49A5D9E055E at
domain8.tld>+OR+hdr:<CAEK\-5TdF_f%3Dn\%2BL1VWj3EVP9i%3DQe\%2BWaYcW%3DFNy8GSLfE5O1U7dw
at domain7.tld>+OR+hdr:<4edb1720076ab71575067b0fc2b5d96c at
domain2.tld>+OR+hdr:<1657012847.68884591 at
domain6.tld>&fl=uid,score&sort=uid+asc&fq=%2Bbox:4830f5144ee1b161c82c00002e1056c4+%2Buser:user
at domain&rows=1&wt=xml}
hits=0 status=0 QTime=46

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/20230320/782673fc/attachment-0001.htm>

On 3/20/23 09:52, Alessio Cecchi wrote:
> I'm running a mail server with Dovecot 2.3.20 and Apache Solr as FTS 
> backend.
> 
> It seems that iPhone/iPad Mail clients are generating some IMAP 
> searches, especially on header Message-ID, that are increasing our Solr 
> I/O load, especially during the night.
> 
> Are these kind of queries normal? What are they?
I don't know whether they are normal or not.  That requires knowledge 
about IMAP that I do not have.  It does seem odd that a mail client 
would be doing header searches unless the user is actually doing a 
search.  I would expect it to look messages up by the ID using other 
imap commands, not with a header search.  But my knowledge about IMAP is 
not complete enough to say for sure.
> You can find some logs below.
Those Solr logs show what SHOULD be low-impact queries on a system 
that's appropriately sized.

I suspect what's happening is that the Solr server doesn't have enough 
free memory (memory not allocated by ANY program) to effectively cache 
the index.

If there is enough free memory for the OS disk cache and the cache is 
reasonably warmed up, queries like the ones you showed should produce 
very little disk I/O, because the data that they need will be sitting in 
memory and an actual disk read is unnecessary.

Once the search completes, the record retrievals might result in a cache 
miss, but the amount of data that gets retrieved for a dovecot search 
result is quite small.  The data is compressed, so a few CPU cycles are 
required to decompress it.

Memory-related performance issues with Solr come up frequently enough 
that I wrote a wiki article about it:

https://cwiki.apache.org/confluence/display/solr/solrperformanceproblems

Thanks,
Shawn