[RCU] Slow displaying INBOX with thousands emails

[Alexey]

Hello.

I have user with approximately 500000 emails in his INBOX folder and
this is not limit. And there is some inconvenience in viewing this
folder. It takes about 5-7 seconds to display list of emails in folder.
Pagination is set to 100 emails per page. I checked that IMAP server
complete request "FETCH 1:100 ENVELOPE" in 147ms, and "FETCH 1:*
ENVELOPE" in 6 second. This is why I begun to think that RoundCube may
request for all emails instead of 100. Roundcube is configured for
default sort order: descending by receiving date.

Regards, Alexey.

[A.L.E.C]

I have user with approximately 500000 emails in his INBOX folder and this is not limit.
And there is some inconvenience in viewing this folder. It takes about 5-7 seconds to
display list of emails in folder.
Pagination is set to 100 emails per page. I checked that IMAP server complete request
"FETCH 1:100 ENVELOPE" in 147ms, and "FETCH 1:* ENVELOPE" in 6 second. This is why I begun
to think that RoundCube may request for all emails instead of 100. Roundcube is configured
for default sort order: descending by receiving date.

Try with disabled or just different sorting (in messages list options menu). Enable
imap_debug to see in the log what imap commands are used and with what timing.

[Alexey]

Ok, I trace it with imap_debug option.

First level of slowness was `thread` mode. [UID THREAD REFS US-ASCII
ALL] 1s
Second level of little slowness was `sort by date`. [UID SORT (ARRIVAL)
US-ASCII ALL] 0.7s
Final query looks like this: [UID SEARCH ALL] 0.1s

But how 1 + 0.7 became 3.5s of `waiting` request time? (I get it from
profiler in browser)

And is there in chance to increase performance without disabling
threads?

Post by A.L.E.C

I have user with approximately 500000 emails in his INBOX folder and this is not limit.
And there is some inconvenience in viewing this folder. It takes about 5-7 seconds to
display list of emails in folder.
Pagination is set to 100 emails per page. I checked that IMAP server complete request
"FETCH 1:100 ENVELOPE" in 147ms, and "FETCH 1:* ENVELOPE" in 6 second.
This is why I begun
to think that RoundCube may request for all emails instead of 100.
Roundcube is configured
for default sort order: descending by receiving date.

Try with disabled or just different sorting (in messages list options menu). Enable
imap_debug to see in the log what imap commands are used and with what timing.

[A.L.E.C]

First level of slowness was `thread` mode. [UID THREAD REFS US-ASCII ALL] 1s
Second level of little slowness was `sort by date`. [UID SORT (ARRIVAL) US-ASCII ALL] 0.7s
Final query looks like this: [UID SEARCH ALL] 0.1s
But how 1 + 0.7 became 3.5s of `waiting` request time? (I get it from profiler in browser)

Maybe it's parsing the THREAD response, but I don't know. It also is FETCHing messages for
a hundred threads, no?

And is there in chance to increase performance without disabling threads?

Did you try setting sorting to None? You can consider enabling imap_cache.

[Alexey]

Post by A.L.E.C
Maybe it's parsing the THREAD response, but I don't know. It also is
FETCHing messages for a hundred threads, no?

Fetching is extremely fast (0.004 + 0.000 + 0.003 secs).
Could you explain, why there is 3 numbers? (in previous message I show
you only the last one)

Post by A.L.E.C

And is there in chance to increase performance without disabling threads?

Did you try setting sorting to None? You can consider enabling
imap_cache.

$config['imap_cache'] = 'memcache';
did nothing (sure, memcached is running and configured for RC)

[A.L.E.C]

Post by Alexey

Post by A.L.E.C
Maybe it's parsing the THREAD response, but I don't know. It also is
FETCHing messages for a hundred threads, no?

Fetching is extremely fast (0.004 + 0.000 + 0.003 secs).

So, you're showing the imap server timings. Note the response need to be sent and parsed
by the client.

hint: you can configure $config['log_date_format'] = 'd-M-Y H:i:s.u' to get microsecond
precision in the log. It might not work on old PHP versions.

hint: you can set $config['performance_stats'] = true to log real time of the PHP script
execution into logs/console.log.

[Daniel Harke]

Hey,

i have the same problem in my installation. i'm using 1.3.7 and 1.4-beta
to test the performance.

everytime RC gets in touch with the mailserver the speed slows down. if
there is only contact with the db (settings for example) the speed is ok.

Alec, thanks for the hints. i get:

[27-Oct-2018 08:28:55.046979]: <cb98mc7a> settings [3.9 MB/4.2 MB]:
0.3435 sec
[27-Oct-2018 08:28:56.841621]: <cb98mc7a> settings/identities [3.9
MB/4.2 MB]: 0.1268 sec
[27-Oct-2018 08:28:58.022314]: <cb98mc7a> settings/edit-identity [4.7
MB/5.0 MB]: 0.2692 sec
[27-Oct-2018 08:28:59.351677]: <cb98mc7a> settings/plugin.managesieve
[4.9 MB/5.1 MB]: 0.6408 sec
[27-Oct-2018 08:29:59.707223]: <cb98mc7a> settings/refresh [3.3 MB/3.7
MB]: 0.0836 sec
[27-Oct-2018 08:36:51.834207]: <cb98mc7a> settings/responses [3.9 MB/4.2
MB]: 0.1180 sec
[27-Oct-2018 08:36:53.852503]: <cb98mc7a> settings/identities [3.9
MB/4.2 MB]: 0.1564 sec
[27-Oct-2018 08:36:54.978280]: <cb98mc7a> settings/edit-identity [4.7
MB/5.0 MB]: 0.1311 sec
[27-Oct-2018 08:36:58.066700]: <cb98mc7a> settings/folders [5.3 MB/5.6
MB]: 0.8678 sec
[27-Oct-2018 08:37:00.482370]: <cb98mc7a> settings/preferences [3.9
MB/4.2 MB]: 0.0907 sec
[27-Oct-2018 08:37:01.904104]: <cb98mc7a> settings/edit-prefs [5.0
MB/5.5 MB]: 0.2720 sec

i think the speed is fine there.

If there is contact with the mailserver i receive:

[27-Oct-2018 10:27:21 +0200]: <cb98mc7a> mail [4.9 MB/5.3 MB]: 8.3537 sec
[27-Oct-2018 10:27:22 +0200]: <cb98mc7a> mail/getunread [4.2 MB/4.7 MB]:
0.2159 sec
[27-Oct-2018 10:27:22 +0200]: <cb98mc7a> mail/list [5.0 MB/5.1 MB]:
0.4553 sec
[27-Oct-2018 08:27:47.544593]: <cb98mc7a> mail/list [4.8 MB/4.9 MB]:
0.5457 sec
[27-Oct-2018 08:27:49.191417]: <cb98mc7a> mail/list [5.4 MB/5.5 MB]:
0.3324 sec
[27-Oct-2018 08:27:57.451979]: <cb98mc7a> mail/list [6.4 MB/6.7 MB]:
4.6583 sec
[27-Oct-2018 08:27:59.868111]: <cb98mc7a> mail/list [5.0 MB/5.2 MB]:
0.2182 sec
[27-Oct-2018 08:28:30.835897]: <cb98mc7a> mail/refresh [4.5 MB/4.7 MB]:
8.5152 sec

IMAP debugging says that the speed is also ok, but maybe i am searching
at the wrong place? For example i get:

[27-Oct-2018 08:27:57.325247]: <cb98mc7a> [F154] S: A0009 OK Fetch
completed (0.001 + 0.000 secs).
[27-Oct-2018 08:27:57.431208]: <cb98mc7a> [F154] S: A0011 OK
Getquotaroot completed (0.001 + 0.000 secs).

Enabling messages_cache changes nothing. Using Redis the same..

Maybe someone has another hint to debug my performance issues or another
configuration mode to test.

Thanks,

Daniel

Post by A.L.E.C

Post by Alexey

Post by A.L.E.C
Maybe it's parsing the THREAD response, but I don't know. It also is
FETCHing messages for a hundred threads, no?

Fetching is extremely fast (0.004 + 0.000 + 0.003 secs).

So, you're showing the imap server timings. Note the response need to be sent and parsed
by the client.
hint: you can configure $config['log_date_format'] = 'd-M-Y H:i:s.u' to get microsecond
precision in the log. It might not work on old PHP versions.
hint: you can set $config['performance_stats'] = true to log real time of the PHP script
execution into logs/console.log.

[Ranbir]

Post by Daniel Harke
Maybe someone has another hint to debug my performance issues or another
configuration mode to test.

I had speed issues when I joined my Dovecot server to my freeipa
domain. I started using the pam module so that user lookups were
against freeipa (kerberos + ldap). Eventually I figured it out and now
the speed problems are gone.

Have a look here:

https://www.dovecot.org/list/dovecot/2016-June/104480.html

Maybe there's something there that could help you out.

Regards,

Ranbir

[Alexey]

Post by A.L.E.C
So, you're showing the imap server timings. Note the response need to
be sent and parsed by the client.

Yes, and since my client is roundcube I wrote to this maillist, to solve
this performance issue.

Post by A.L.E.C
hint: you can set $config['performance_stats'] = true

mail [1.2 МБ/1.5 МБ]: 0.1386 sec
mail/getunread [929 КБ/997 КБ]: 0.0092 sec (it's probably for showing
counters in folders tree)
mail/list [1.3 МБ/52 МБ]: 1.0174 sec

[A.L.E.C]

Post by A.L.E.C
So, you're showing the imap server timings. Note the response need to
be sent and parsed by the client.

Yes, and since my client is roundcube I wrote to this maillist, to solve this performance
issue.

I'm just pointing out that e.g. a slow connection can cause the issue, so this don't have
to be Roundcube's fault. Is the IMAP server on the same host? What PHP version? What
Roundcube version?

Post by A.L.E.C
hint: you can set $config['performance_stats'] = true

mail [1.2 МБ/1.5 МБ]: 0.1386 sec
mail/getunread [929 КБ/997 КБ]: 0.0092 sec  (it's probably for showing counters in folders
tree)
mail/list [1.3 МБ/52 МБ]: 1.0174 sec

Here I see that list request takes 1 second. So, where's your 5-7?

ps. If you provide full debug log with THREAD and SORT responses I might take a look at
the code and see how performant is the parsing code and if there's any culprit. Also,
please be consistent/precise, first you say 5-7 seconds, then 3.5s and now I see 1 second.

[Matthew Broadhead]

in my experience roundcube is slow with a large inbox (or any large
mailbox).  searching is also slow.  it can even seem to crash at times. 
i am using dovecot as my imap server.
i will see if i can also provide debug output

Post by A.L.E.C

Post by A.L.E.C
So, you're showing the imap server timings. Note the response need to
be sent and parsed by the client.

Yes, and since my client is roundcube I wrote to this maillist, to solve this performance
issue.

I'm just pointing out that e.g. a slow connection can cause the issue, so this don't have
to be Roundcube's fault. Is the IMAP server on the same host? What PHP version? What
Roundcube version?

Post by A.L.E.C
hint: you can set $config['performance_stats'] = true

mail [1.2 МБ/1.5 МБ]: 0.1386 sec
mail/getunread [929 КБ/997 КБ]: 0.0092 sec  (it's probably for showing counters in folders
tree)
mail/list [1.3 МБ/52 МБ]: 1.0174 sec

Here I see that list request takes 1 second. So, where's your 5-7?
ps. If you provide full debug log with THREAD and SORT responses I might take a look at
the code and see how performant is the parsing code and if there's any culprit. Also,
please be consistent/precise, first you say 5-7 seconds, then 3.5s and now I see 1 second.

[Alexey]

Post by A.L.E.C
I'm just pointing out that e.g. a slow connection can cause the issue,
so this don't have to be Roundcube's fault. Is the IMAP server on the
same host? What PHP
version? What Roundcube version?

IMAP server is Dovecot 2.2.27 and it is on the same host and this host
is not load by memory or CPU at all.
Roundcube 1.3.7
PHP 7.0.30

Post by A.L.E.C
Here I see that list request takes 1 second. So, where's your 5-7?

5-7 seconds were measured by watch :-(
After I wrote you that Network Profiler in browser showed me 3.5 seconds
(lets start from this point, because 5 seconds subjective, sorry)
After I disabled `threads` page loaded in 1.6secs ±
1.6secs it's with tcp and tls connecting time (`waiting` time is 1.2secs
which is very close to 1secs). This is our current situation.

Post by A.L.E.C
ps. If you provide full debug log with THREAD and SORT responses I
might take a look at the code
and see how performant is the parsing code and if there's any culprit.

https://gist.githubusercontent.com/Alukardd/82418d77a148557fd2c4bb05bd37413d/raw/e62e4f76b47f5dbbeef377877a4f0ef9e8dc5ff3/imap

p.s. Thanks, for your help.

[A.L.E.C]

Post by Alexey
https://gist.githubusercontent.com/Alukardd/82418d77a148557fd2c4bb05bd37413d/raw/e62e4f76b47f5dbbeef377877a4f0ef9e8dc5ff3/imap

The file does not contain THREAD only SORT. And for SORT we can't probably do much. It's
0.8 sec. So, 1.2 - 0.8 = 0.4. The 0.4 second overhead is acceptable imho, and hard to
improve. Also, I don't see the overhead in the imap log, so it's hard to know where that
0.4s was spent. Maybe on writing to cache or on connecting to imap, that can be anything.

I expect some more place for improvement in THREAD response handling. I'm willing to
investigate if you provide the data. Also, you could enable memcache_debug, sql_debug and
performance_stats, to have more info.