Mailing List Archive: DBMail: users

dbmail very slow performance on imap SEARCH and SORT commands

Index | Next | Previous | View Threaded

erwin at lubbers

Jun 8, 2010, 2:51 AM

Post #1 of 11 (1289 views)
Permalink

dbmail very slow performance on imap SEARCH and SORT commands

Hi,

I'm wondering why my dbmail (2.2.13) installation is performing so slow on imap search and sort operations. We're using a 64 Gb/SAS MySQL server dedicated to dbmail as storage (around 300 Gb in use) and serveral 4 Gb machines for the dbmail-imap processes.

I did try a session by telneting to port 143 and than the following happens:

.. LOGIN "username" "password"

Dbmail responsed immediatly with it's OK. Then:

.. SELECT "INBOX"

And again it tells within an eyeblink that there are 1039 messages in the INBOX. Then:

.. SEARCH ALL UNDELETED

This response takes 56.3 seconds (!) for those 1039 messages. And a

.. SORT (DATE) US-ASCII ALL UNDELETED

took 38.6 seconds.

In this time there seems to be no query running on the MySQL server (or it must run for a very short time so my 1 second updates with mysqladmin doesn't seem to catch it).

Anyone an idea how to improve the performance?

Regards,
Erwin

_______________________________________________
DBmail mailing list
DBmail [at] dbmail
http://mailman.fastxs.nl/cgi-bin/mailman/listinfo/dbmail

paul at nfg

Jun 8, 2010, 3:36 AM

Post #2 of 11 (1205 views)
Permalink

Re: dbmail very slow performance on imap SEARCH and SORT commands [In reply to]

Erwin Lubbers wrote:
> Hi,
>
> I'm wondering why my dbmail (2.2.13) installation is performing so slow on imap search and sort operations. We're using a 64 Gb/SAS MySQL server dedicated to dbmail as storage (around 300 Gb in use) and serveral 4 Gb machines for the dbmail-imap processes.
>
> I did try a session by telneting to port 143 and than the following happens:
>
> ... LOGIN "username" "password"
>
> Dbmail responsed immediatly with it's OK. Then:
>
> ... SELECT "INBOX"
>
> And again it tells within an eyeblink that there are 1039 messages in the INBOX. Then:
>
> ... SEARCH ALL UNDELETED

That one should really be very fast.

>
> This response takes 56.3 seconds (!) for those 1039 messages. And a
>
> ... SORT (DATE) US-ASCII ALL UNDELETED
>
> took 38.6 seconds.

This one is taking too long on my server. Mostly query-bound time.

>
> In this time there seems to be no query running on the MySQL server (or it must run for a very short time so my 1 second updates with mysqladmin doesn't seem to catch it).

That is too weird. Normally slow response is an indication of a poorly
performing query. Did the process involved take up a lot of CPU? Try
running vmstat while your running these commands.

>
> Anyone an idea how to improve the performance?

Setup dbmail.conf to log slow queries, and use 'explain' to locate
missing of poorly configured indexes. And post back your findings.

--
________________________________________________________________
Paul Stevens paul at nfg.nl
NET FACILITIES GROUP GPG/PGP: 1024D/11F8CD31
The Netherlands________________________________http://www.nfg.nl
_______________________________________________
DBmail mailing list
DBmail [at] dbmail
http://mailman.fastxs.nl/cgi-bin/mailman/listinfo/dbmail

erwin at lubbers

Jun 8, 2010, 4:07 AM

Post #3 of 11 (1202 views)
Permalink

Re: dbmail very slow performance on imap SEARCH and SORT commands [In reply to]

Op 8 jun 2010, om 12:36 heeft Paul J Stevens het volgende geschreven:

> Erwin Lubbers wrote:
>> Hi,
>>
>> I'm wondering why my dbmail (2.2.13) installation is performing so slow on imap search and sort operations. We're using a 64 Gb/SAS MySQL server dedicated to dbmail as storage (around 300 Gb in use) and serveral 4 Gb machines for the dbmail-imap processes.
>>
>> I did try a session by telneting to port 143 and than the following happens:
>>
>> ... LOGIN "username" "password"
>>
>> Dbmail responsed immediatly with it's OK. Then:
>>
>> ... SELECT "INBOX"
>>
>> And again it tells within an eyeblink that there are 1039 messages in the INBOX. Then:
>>
>> ... SEARCH ALL UNDELETED
>
> That one should really be very fast.
>
>>
>> This response takes 56.3 seconds (!) for those 1039 messages. And a
>>
>> ... SORT (DATE) US-ASCII ALL UNDELETED
>>
>> took 38.6 seconds.
>
> This one is taking too long on my server. Mostly query-bound time.
>
>>
>> In this time there seems to be no query running on the MySQL server (or it must run for a very short time so my 1 second updates with mysqladmin doesn't seem to catch it).
>
> That is too weird. Normally slow response is an indication of a poorly
> performing query. Did the process involved take up a lot of CPU? Try
> running vmstat while your running these commands.
>

I did restart dbmail-imapd and then did the search. vmstat shows no significant change in memory usage. CPU load goes from almost 100% idle to around 50% for around 5 seconds (the search answer took much more time to complete). I also started vmstat on the MySQL server and it doesn't show any change in CPU and/or memory usage (only normal small fluctuations).

>>
>> Anyone an idea how to improve the performance?
>
> Setup dbmail.conf to log slow queries, and use 'explain' to locate
> missing of poorly configured indexes. And post back your findings.
>

I'm already logging slow queries, but never catched one. Even if I set the values to:

query_time_info = 2
query_time_message = 4
query_time_warning = 6

No query is seen as slow.

>
> --
> ________________________________________________________________
> Paul Stevens paul at nfg.nl
> NET FACILITIES GROUP GPG/PGP: 1024D/11F8CD31
> The Netherlands________________________________http://www.nfg.nl
> _______________________________________________
> DBmail mailing list
> DBmail [at] dbmail
> http://mailman.fastxs.nl/cgi-bin/mailman/listinfo/dbmail

_______________________________________________
DBmail mailing list
DBmail [at] dbmail
http://mailman.fastxs.nl/cgi-bin/mailman/listinfo/dbmail

erwin at lubbers

Jun 8, 2010, 6:16 AM

Post #4 of 11 (1204 views)
Permalink

Re: dbmail very slow performance on imap SEARCH and SORT commands [In reply to]

Op 8 jun 2010, om 12:36 heeft Paul J Stevens het volgende geschreven:

> Erwin Lubbers wrote:
>> Hi,
>>
>> I'm wondering why my dbmail (2.2.13) installation is performing so slow on imap search and sort operations. We're using a 64 Gb/SAS MySQL server dedicated to dbmail as storage (around 300 Gb in use) and serveral 4 Gb machines for the dbmail-imap processes.
>>
>> I did try a session by telneting to port 143 and than the following happens:
>>
>> ... LOGIN "username" "password"
>>
>> Dbmail responsed immediatly with it's OK. Then:
>>
>> ... SELECT "INBOX"
>>
>> And again it tells within an eyeblink that there are 1039 messages in the INBOX. Then:
>>
>> ... SEARCH ALL UNDELETED
>
> That one should really be very fast.
>
>>
>> This response takes 56.3 seconds (!) for those 1039 messages. And a
>>
>> ... SORT (DATE) US-ASCII ALL UNDELETED
>>
>> took 38.6 seconds.
>
> This one is taking too long on my server. Mostly query-bound time.
>
>>
>> In this time there seems to be no query running on the MySQL server (or it must run for a very short time so my 1 second updates with mysqladmin doesn't seem to catch it).
>
> That is too weird. Normally slow response is an indication of a poorly
> performing query. Did the process involved take up a lot of CPU? Try
> running vmstat while your running these commands.
>
>>
>> Anyone an idea how to improve the performance?
>
> Setup dbmail.conf to log slow queries, and use 'explain' to locate
> missing of poorly configured indexes. And post back your findings.
>
>

Did try another test (with the same commands) on a server (2 Gb, 3 Ghz single core CPU, no other processes running) where only a dbmail-imapd is running on a private IP address, so there is no interference with other sessions and the results are dramatic. CPU load goes to 100% for multiple seconds (vmstat updates every second):

procs -----------memory---------- ---swap-- -----io---- --system-- ----cpu----
r b swpd free buff cache si so bi bo in cs us sy id wa
0 0 0 1979036 31396 43008 0 0 0 0 1011 7 0 0 100 0
0 0 0 1979036 31396 43008 0 0 0 0 1011 9 0 0 100 0
1 0 0 1979036 31396 43008 0 0 0 0 1025 12 28 1 71 0
1 0 0 1979036 31396 43008 0 0 0 0 1013 13 100 0 0 0
1 0 0 1979036 31396 43008 0 0 0 0 1011 9 100 0 0 0
1 0 0 1979036 31396 43008 0 0 0 0 1012 9 100 0 0 0
1 0 0 1979036 31396 43008 0 0 0 0 1011 7 100 0 0 0
1 0 0 1979036 31396 43008 0 0 0 0 1011 9 100 0 0 0
1 0 0 1979036 31396 43008 0 0 0 0 1011 9 100 0 0 0
1 0 0 1979036 31396 43008 0 0 0 0 1017 11 100 0 0 0
0 0 0 1979036 31396 43008 0 0 0 0 1031 20 18 0 82 0
0 0 0 1979036 31396 43008 0 0 0 0 1012 9 0 0 100 0
0 0 0 1979036 31396 43008 0 0 0 0 1011 7 0 0 100 0

> --
> ________________________________________________________________
> Paul Stevens paul at nfg.nl
> NET FACILITIES GROUP GPG/PGP: 1024D/11F8CD31
> The Netherlands________________________________http://www.nfg.nl
> _______________________________________________
> DBmail mailing list
> DBmail [at] dbmail
> http://mailman.fastxs.nl/cgi-bin/mailman/listinfo/dbmail

_______________________________________________
DBmail mailing list
DBmail [at] dbmail
http://mailman.fastxs.nl/cgi-bin/mailman/listinfo/dbmail

paul at nfg

Jun 8, 2010, 6:45 AM

Post #5 of 11 (1193 views)
Permalink

Re: dbmail very slow performance on imap SEARCH and SORT commands [In reply to]

Erwin Lubbers wrote:

> procs -----------memory---------- ---swap-- -----io---- --system-- ----cpu----
> r b swpd free buff cache si so bi bo in cs us sy id wa
> 0 0 0 1979036 31396 43008 0 0 0 0 1011 7 0 0 100 0
> 0 0 0 1979036 31396 43008 0 0 0 0 1011 9 0 0 100 0
> 1 0 0 1979036 31396 43008 0 0 0 0 1025 12 28 1 71 0
> 1 0 0 1979036 31396 43008 0 0 0 0 1013 13 100 0 0 0
> 1 0 0 1979036 31396 43008 0 0 0 0 1011 9 100 0 0 0
> 1 0 0 1979036 31396 43008 0 0 0 0 1012 9 100 0 0 0
> 1 0 0 1979036 31396 43008 0 0 0 0 1011 7 100 0 0 0
> 1 0 0 1979036 31396 43008 0 0 0 0 1011 9 100 0 0 0
> 1 0 0 1979036 31396 43008 0 0 0 0 1011 9 100 0 0 0
> 1 0 0 1979036 31396 43008 0 0 0 0 1017 11 100 0 0 0
> 0 0 0 1979036 31396 43008 0 0 0 0 1031 20 18 0 82 0
> 0 0 0 1979036 31396 43008 0 0 0 0 1012 9 0 0 100 0
> 0 0 0 1979036 31396 43008 0 0 0 0 1011 7 0 0 100 0

That's just plain nasty! Almost no context-switching, what is the cpu
doing???

Try running it through valgrind or strace on stdin/stdout:

strace -o /tmp/trace /usr/sbin/dbmail-imapd -n

--
________________________________________________________________
Paul Stevens paul at nfg.nl
NET FACILITIES GROUP GPG/PGP: 1024D/11F8CD31
The Netherlands________________________________http://www.nfg.nl
_______________________________________________
DBmail mailing list
DBmail [at] dbmail
http://mailman.fastxs.nl/cgi-bin/mailman/listinfo/dbmail

erwin at lubbers

Jun 8, 2010, 8:53 AM

Post #6 of 11 (1182 views)
Permalink

Re: dbmail very slow performance on imap SEARCH and SORT commands [In reply to]

Op 8 jun 2010, om 15:45 heeft Paul J Stevens het volgende geschreven:

> Erwin Lubbers wrote:
>
>> procs -----------memory---------- ---swap-- -----io---- --system-- ----cpu----
>> r b swpd free buff cache si so bi bo in cs us sy id wa
>> 0 0 0 1979036 31396 43008 0 0 0 0 1011 7 0 0 100 0
>> 0 0 0 1979036 31396 43008 0 0 0 0 1011 9 0 0 100 0
>> 1 0 0 1979036 31396 43008 0 0 0 0 1025 12 28 1 71 0
>> 1 0 0 1979036 31396 43008 0 0 0 0 1013 13 100 0 0 0
>> 1 0 0 1979036 31396 43008 0 0 0 0 1011 9 100 0 0 0
>> 1 0 0 1979036 31396 43008 0 0 0 0 1012 9 100 0 0 0
>> 1 0 0 1979036 31396 43008 0 0 0 0 1011 7 100 0 0 0
>> 1 0 0 1979036 31396 43008 0 0 0 0 1011 9 100 0 0 0
>> 1 0 0 1979036 31396 43008 0 0 0 0 1011 9 100 0 0 0
>> 1 0 0 1979036 31396 43008 0 0 0 0 1017 11 100 0 0 0
>> 0 0 0 1979036 31396 43008 0 0 0 0 1031 20 18 0 82 0
>> 0 0 0 1979036 31396 43008 0 0 0 0 1012 9 0 0 100 0
>> 0 0 0 1979036 31396 43008 0 0 0 0 1011 7 0 0 100 0
>
> That's just plain nasty! Almost no context-switching, what is the cpu
> doing???
>
> Try running it through valgrind or strace on stdin/stdout:
>
> strace -o /tmp/trace /usr/sbin/dbmail-imapd -n
>

I did a trace and tried all select statements that are send to the MySQL server directly and the all respond within 0.01-0.05s. The part of the trace between my SEARCH command and the completed row is attached (I turned on time logging, to see what part takes so much time).

There is a gap of around 3 seconds directly after I entered the . SEARCH ALL UNDELETED command. And there is a very large (almost 14 seconds) gap after reading the results from MySQL of the SELECT that is done for the SEARCH command.

Attachments:

trace.txt (11.2 KB)

paul at nfg

Jun 8, 2010, 1:55 PM

Post #7 of 11 (1194 views)
Permalink

Re: dbmail very slow performance on imap SEARCH and SORT commands [In reply to]

> There is a gap of around 3 seconds directly after I entered the .
> SEARCH ALL UNDELETED command.

which would be explained by you taking 3 seconds to enter that command.

> And there is a very large (almost 14
> seconds) gap after reading the results from MySQL of the SELECT that
> is done for the SEARCH command.

that one is tricky. Could you try again with trace_syslog=5, that would
give better indication where in the dbmail code the bottleneck is
occuring, or if it's in libmysqlclient.

--
________________________________________________________________
Paul Stevens paul at nfg.nl
NET FACILITIES GROUP GPG/PGP: 1024D/11F8CD31
The Netherlands________________________________http://www.nfg.nl
_______________________________________________
DBmail mailing list
DBmail [at] dbmail
http://mailman.fastxs.nl/cgi-bin/mailman/listinfo/dbmail

erwin at lubbers

Jul 1, 2010, 1:47 AM

Post #8 of 11 (1130 views)
Permalink

Re: dbmail very slow performance on imap SEARCH and SORT commands [In reply to]

Hi Paul,

A bit delay in my answer. But I did make a trace with the level set to 5. I did copy-and-paste the following commands directly after the strace command, so there is no delay seen while imapd was waiting for my commands to enter:

.. LOGIN "***user***" "***password***"
.. SELECT "INBOX"
.. SEARCH ALL UNDELETED
.. SORT (DATE) US-ASCII ALL UNDELETED
.. LOGOUT

The trace is attached.

Regards,
Erwin

Attachments:

trace.txt (178 KB)

namailsj at yahoo

Jul 6, 2010, 9:17 AM

Post #9 of 11 (1109 views)
Permalink

Re: dbmail very slow performance on imap SEARCH and SORT commands [In reply to]

I'm also seeing a somewhat similar problem, in addition to the delay I'm also seeing dbmail-imapd taking 100% CPU during that session.

I'm attaching the log file for dbmail with TRACE_SYSLOG = 10
This logfile is only for "SEARCH ALL UNDELETED" IMAP command.

My database is big, ~300GB, I've also tested this with creating a brand new db in mysql and I wasn't able to reproduce the problem, even though the mysql SELECT statement returns right away, (I'm not sure though) but it seems to be somehow related to database.

Thank you for any help that anybody can provide.

----- Original Message ----
From: Erwin Lubbers <erwin [at] lubbers>
To: DBMail mailinglist <dbmail [at] dbmail>
Sent: Thu, July 1, 2010 1:47:18 AM
Subject: Re: [Dbmail] dbmail very slow performance on imap SEARCH and SORT commands

Hi Paul,

A bit delay in my answer. But I did make a trace with the level set to 5. I did copy-and-paste the following commands directly after the strace command, so there is no delay seen while imapd was waiting for my commands to enter:

... LOGIN "***user***" "***password***"
... SELECT "INBOX"
... SEARCH ALL UNDELETED
... SORT (DATE) US-ASCII ALL UNDELETED
... LOGOUT

The trace is attached.

Regards,
Erwin

Op 8 jun 2010, om 22:55 heeft Paul J Stevens het volgende geschreven:

>
>> There is a gap of around 3 seconds directly after I entered the .
>> SEARCH ALL UNDELETED command.
>
> which would be explained by you taking 3 seconds to enter that command.
>
>> And there is a very large (almost 14
>> seconds) gap after reading the results from MySQL of the SELECT that
>> is done for the SEARCH command.
>
> that one is tricky. Could you try again with trace_syslog=5, that would
> give better indication where in the dbmail code the bottleneck is
> occuring, or if it's in libmysqlclient.
>
> --
> ________________________________________________________________
> Paul Stevens paul at nfg.nl
> NET FACILITIES GROUP GPG/PGP: 1024D/11F8CD31
> The Netherlands________________________________http://www.nfg.nl
> _______________________________________________
> DBmail mailing list
> DBmail [at] dbmail
> http://mailman.fastxs.nl/cgi-bin/mailman/listinfo/dbmail

Attachments:

dbmail-log.txt (5.01 KB)

namailsj at yahoo

Jul 6, 2010, 3:06 PM

Post #10 of 11 (1121 views)
Permalink

Re: dbmail very slow performance on imap SEARCH and SORT commands [In reply to]

After some more digging, I think the problem might be reproduced by following
these steps:

1. Create a new database and table structure for dbmail.
2. create a test user - test [at] test
3. Alter table "dbmail_messages" to start message_idnr from a high number.
ALTER TABLE dbmail_messages auto_increment = 99999999;
4. send 30 to 40 test messages to the test [at] test mailbox and then test imap.

Now dbmail-imapd will cause 100% (or high) CPU and show a delay while running
SEARCH and SORT commands. I hope this helps in further narrowing down the
problem.

I have a lots of users and emails in the production database and the
message_idnr is very high, could this be causing a bottleneck in dbmail-imapd?

----- Original Message ----
From: N Sj <namailsj [at] yahoo>
To: DBMail mailinglist <dbmail [at] dbmail>
Sent: Tue, July 6, 2010 9:17:24 AM
Subject: Re: [Dbmail] dbmail very slow performance on imap SEARCH and SORT
commands

I'm also seeing a somewhat similar problem, in addition to the delay I'm also
seeing dbmail-imapd taking 100% CPU during that session.

I'm attaching the log file for dbmail with TRACE_SYSLOG = 10
This logfile is only for "SEARCH ALL UNDELETED" IMAP command.

My database is big, ~300GB, I've also tested this with creating a brand new db
in mysql and I wasn't able to reproduce the problem, even though the mysql
SELECT statement returns right away, (I'm not sure though) but it seems to be
somehow related to database.

Thank you for any help that anybody can provide.

----- Original Message ----
From: Erwin Lubbers <erwin [at] lubbers>
To: DBMail mailinglist <dbmail [at] dbmail>
Sent: Thu, July 1, 2010 1:47:18 AM
Subject: Re: [Dbmail] dbmail very slow performance on imap SEARCH and SORT
commands

Hi Paul,

A bit delay in my answer. But I did make a trace with the level set to 5. I did
copy-and-paste the following commands directly after the strace command, so
there is no delay seen while imapd was waiting for my commands to enter:

.... LOGIN "***user***" "***password***"
.... SELECT "INBOX"
.... SEARCH ALL UNDELETED
.... SORT (DATE) US-ASCII ALL UNDELETED
.... LOGOUT

The trace is attached.

Regards,
Erwin

Op 8 jun 2010, om 22:55 heeft Paul J Stevens het volgende geschreven:

>
>> There is a gap of around 3 seconds directly after I entered the .
>> SEARCH ALL UNDELETED command.
>
> which would be explained by you taking 3 seconds to enter that command.
>
>> And there is a very large (almost 14
>> seconds) gap after reading the results from MySQL of the SELECT that
>> is done for the SEARCH command.
>
> that one is tricky. Could you try again with trace_syslog=5, that would
> give better indication where in the dbmail code the bottleneck is
> occuring, or if it's in libmysqlclient.
>
> --
> ________________________________________________________________
> Paul Stevens paul at nfg.nl
> NET FACILITIES GROUP GPG/PGP: 1024D/11F8CD31
> The Netherlands________________________________http://www.nfg.nl
> _______________________________________________
> DBmail mailing list
> DBmail [at] dbmail
> http://mailman.fastxs.nl/cgi-bin/mailman/listinfo/dbmail

_______________________________________________
DBmail mailing list
DBmail [at] dbmail
http://mailman.fastxs.nl/cgi-bin/mailman/listinfo/dbmail

erwin at lubbers

Jul 7, 2010, 3:23 AM

Post #11 of 11 (1120 views)
Permalink

Re: dbmail very slow performance on imap SEARCH and SORT commands [In reply to]

I looked at my production dbmail and the current message_idnr in my dbmail_messages table is almost at 65.000.000. And there are many other tables with very high auto increment values, i.e. the dbmail_headervalue which is at an index of almost 202.000.000.

Op 7 jul 2010, om 00:06 heeft N Sj het volgende geschreven:

> After some more digging, I think the problem might be reproduced by following
> these steps:
>
> 1. Create a new database and table structure for dbmail.
> 2. create a test user - test [at] test
> 3. Alter table "dbmail_messages" to start message_idnr from a high number.
> ALTER TABLE dbmail_messages auto_increment = 99999999;
> 4. send 30 to 40 test messages to the test [at] test mailbox and then test imap.
>
> Now dbmail-imapd will cause 100% (or high) CPU and show a delay while running
> SEARCH and SORT commands. I hope this helps in further narrowing down the
> problem.
>
> I have a lots of users and emails in the production database and the
> message_idnr is very high, could this be causing a bottleneck in dbmail-imapd?
>
>
>

_______________________________________________
DBmail mailing list
DBmail [at] dbmail
http://mailman.fastxs.nl/cgi-bin/mailman/listinfo/dbmail

Index | Next | Previous | View Threaded

Interested in having your list archived? Contact Gossamer Threads