dovecot - Apr 2013 - Slow DNS warnings (proxy/auth)

Hello,

I've just finished transiting our proxies from perdition to dovecot
(2.1.7-7 Debian). 
Yesterday 12 messages (all within the same second) like this caught my
attention:
---
Apr 25 17:19:09 pp11 dovecot: auth: Warning: proxy(redacted at
gol.com,xx.xx.xx.xx,<26hUEivbfQBlMrMS>): DNS lookup for
mb04.dentaku.gol.com took 5.002 s
---

Now this machine at that time was handling a load of about 2 logins per
second, about 20% of what it previously handled with perdition w/o a
hiccup.
It also runs a local caching nameserver and the A record for the mailbox
server in question was most definitely cached at the time (verified via
TTL). 
The machine in question was very bored and certainly capable of handling
hundreds if not thousands of DNS queries per second at that moment.

In short, I can't see any reason how the lookup could have taken so long, so
my guess is there are some issues with the dns-helper (locking, stepping on each
others feet, not being spawned fast enough) causing this.


Some general remarks, dovecot as proxy feels "heavier" than perdition.

In the CPU area that's probably a more subjective impression, because all
the little helper processes make it clear what's going on where. 
Though the "config" process being rather active is something that
perdition
definitely doesn't do, it reads the config once at start time and that's
it. 
All the IPC and central processes of course also make dovecot rather
file handle hungry.

Memory wise it's about 35% bigger than perdition and that's not
subjective
at all. ^o^
About one MB per proxy process/connection for dovecot in my case.
Caveat emptor. ^o^

Regards,

Christian
-- 
Christian Balzer        Network/Systems Engineer                
chibi at gol.com   	Global OnLine Japan/Fusion Communications
http://www.gol.com/

On 26.4.2013, at 11.57, Christian Balzer <chibi at gol.com> wrote:
> Apr 25 17:19:09 pp11 dovecot: auth: Warning: proxy(redacted at
gol.com,xx.xx.xx.xx,<26hUEivbfQBlMrMS>): DNS lookup for
mb04.dentaku.gol.com took 5.002 s
> ---
> 
> Now this machine at that time was handling a load of about 2 logins per
> second, about 20% of what it previously handled with perdition w/o a
> hiccup.
> It also runs a local caching nameserver and the A record for the mailbox
> server in question was most definitely cached at the time (verified via
> TTL). 
> The machine in question was very bored and certainly capable of handling
> hundreds if not thousands of DNS queries per second at that moment.
> 
> In short, I can't see any reason how the lookup could have taken so
long, so my guess is there are some issues with the dns-helper (locking,
stepping on each others feet, not being spawned fast enough) causing this.
No idea.
> Some general remarks, dovecot as proxy feels "heavier" than
perdition.
> 
> In the CPU area that's probably a more subjective impression, because
all
> the little helper processes make it clear what's going on where. 
> Though the "config" process being rather active is something that
perdition
> definitely doesn't do, it reads the config once at start time and
that's
> it. 
> All the IPC and central processes of course also make dovecot rather
> file handle hungry.
> 
> Memory wise it's about 35% bigger than perdition and that's not
subjective
> at all. ^o^
> About one MB per proxy process/connection for dovecot in my case.
> Caveat emptor. ^o^
You could also switch to high-performance mode:
http://wiki2.dovecot.org/LoginProcess