Gianpaolo Del Matto
2008-Aug-06 14:29 UTC
[Dovecot] Dovecot proxying results in "too many open files"
Hi,
Some words about my Dovecot setup:
- 10 dovecot servers
- each server has some local mailboxes
- each server has proxying enabled to seamlessly
connect to another host if the mailbox is not local
Running Dovecot 1.1.1 on FreeBSD 6.3-RELEASE-p3.
First of all, local mailbox access is fine.
Proxying works also as expected.
Now for the actual problem:
Shortly after startup, Dovecot starts throwing errors concerning
connection which should be proxied.
Here are some examples from the logs:
Aug 6 15:49:10 dovecot: imap-login: socket() failed: Too many open
files
Aug 6 15:49:10 dovecot: imap-login: proxy(XYZ): connect(1.2.3.4, 143)
failed: Too many open files
Aug 6 15:49:10 dovecot: imap-login: accept() failed: Too many open
files
Aug 6 15:49:10 dovecot: imap-login: socket() failed: Too many open
files
Aug 6 15:49:10 dovecot: imap-login: proxy(XYZ): connect(1.2.3.4, 143)
failed: Too many open files
Aug 6 15:49:10 dovecot: imap-login: socket() failed: Too many open
files
Aug 6 15:49:10 dovecot: imap-login: proxy(XYZ): connect(1.2.3.4, 143)
failed: Too many open files
Aug 6 15:49:10 dovecot: imap-login: socket() failed: Too many open
files
Aug 6 15:49:10 dovecot: imap-login: proxy(XYZ): connect(1.2.3.4, 143)
failed: Too many open files
Aug 6 15:49:11 dovecot: imap-login: socket() failed: Too many open
files
[..]
Aug 6 16:00:05 dovecot: imap-login: accept() failed: Too many open
files
Aug 6 16:00:08 dovecot: imap-login: accept() failed: Too many open
files
Aug 6 16:00:11 dovecot: imap-login: accept() failed: Too many open
files
Aug 6 16:00:13 dovecot: imap-login: accept() failed: Too many open
files
As from the context it seems to be a file descriptor issue, as such I
have done
the following:
- added a 'limits -e -n 32768 -U dovecot' to dovecot startup file to
ensure it has enough FD's
- additionally, I've checked my kernel file limits, however I always
set it through loader and sysctl to
be as large as 64k
# sysctl -a |grep files
kern.maxfiles: 65535
kern.maxfilesperproc: 32768
kern.openfiles: 1632
- also checked the limits of the dovecot user like this:
# su -c dovecot root -c 'ulimit -a'
core file size (blocks, -c) unlimited
data seg size (kbytes, -d) 1048576
file size (blocks, -f) unlimited
max locked memory (kbytes, -l) unlimited
max memory size (kbytes, -m) unlimited
open files (-n) 32768
pipe size (512 bytes, -p) 1
stack size (kbytes, -s) 131072
cpu time (seconds, -t) unlimited
max user processes (-u) 5547
virtual memory (kbytes, -v) unlimited
- done some monitoring of file descriptor usage for the dovecot user,
though somewhat inacurate, like this:
while [ : ]; do date; fstat -u dovecot |wc -l; sleep 1; done
this gave me these results while tailing the logfile:
Wed Aug 6 15:44:12 CEST 2008
585
Wed Aug 6 15:44:13 CEST 2008
579
Wed Aug 6 15:44:14 CEST 2008
582
Wed Aug 6 15:44:15 CEST 2008
582
Wed Aug 6 15:44:16 CEST 2008
586
Wed Aug 6 15:44:17 CEST 2008
585
Wed Aug 6 15:44:18 CEST 2008
582
So it didn't seem to be anywhere near the theoretical upper limit I've
set at 32k.
On the other hand, when restarting Dovecot, it works for a few minutes
for at least as long as the FD usage as reported above stays at around
500.
I remember from the docs that dovecot-login would require the double
amount of file descriptors to run.
Assuming my report is somewhat inaccurate and lags behind, I could
imagine
that upon a proxy requests it would effectively peak our at some 500 x
2 FDs.
Thus effectively reaching the 1024 FD barrier.
I conclude this from the fact that I currently have some 350 - 450
logins in parallel,
most of which can and shell be proxied.
From the error message in the logs I got the impression, that only
proxied
connections are affected.
I was not able to reproduce the issue with non-proxied logins to local
mailboxes.
Some further steps I've done from the configuration side to no avail:
- disabled imaps/pop3s/ssl
- changed between login_process_per_connection yes/no
- played around with login_max_connections et all (raised/lowered)
limits
- tried with/without plugins enabled
- tried with SQL-based and passwd-file based userdb/passdb, single and
mixed
Dovecot config:
# dovecot -n
# 1.1.1: /usr/local/etc/dovecot.conf
base_dir: /var/run/dovecot/
protocols: imap pop3
listen: *, [::]
ssl_disable: yes
ssl_cert_file: /usr/local/etc/postfix/tls/server.crt
ssl_key_file: /usr/local/etc/postfix/tls/server.key
disable_plaintext_auth: no
verbose_ssl: yes
login_dir: /var/run/dovecot/login
login_executable(default): /usr/local/libexec/dovecot/imap-login
login_process_per_connection: no
login_greeting_capability(default): yes
login_greeting_capability(imap): yes
login_greeting_capability(pop3): no
login_processes_count: 16
login_max_processes_count: 64
login_max_connections: 64
max_mail_processes: 256
mail_max_userip_connections: 3
verbose_proctitle: yes
mail_privileged_group: mail
mail_uid: 1000
mail_gid: 1000
mail_location: maildir:~/Maildir
fsync_disable: yes
maildir_copy_preserve_filename: yes
mail_drop_priv_before_exec: yes
mail_executable(default): /mailserver/scripts/dovecot/imap
mail_executable(imap): /mailserver/scripts/dovecot/imap
mail_executable(pop3): /mailserver/scripts/dovecot/pop3
mail_plugins: expire mail_log
mail_plugin_dir(default): /usr/local/lib/dovecot/imap
mail_plugin_dir(imap): /usr/local/lib/dovecot/imap
mail_plugin_dir(pop3): /usr/local/lib/dovecot/pop3
mail_log_max_lines_per_sec: 0
imap_client_workarounds(default): delay-newmail netscape-eoh tb-extra-
mailbox-sep
imap_client_workarounds(imap): delay-newmail netscape-eoh tb-extra-
mailbox-sep
imap_client_workarounds(pop3):
pop3_no_flag_updates(default): no
pop3_no_flag_updates(imap): no
pop3_no_flag_updates(pop3): yes
pop3_enable_last(default): no
pop3_enable_last(imap): no
pop3_enable_last(pop3): yes
pop3_uidl_format(default): %08Xu%08Xv
pop3_uidl_format(imap): %08Xu%08Xv
pop3_uidl_format(pop3): UID%u-%v
pop3_client_workarounds(default):
pop3_client_workarounds(imap):
pop3_client_workarounds(pop3): outlook-no-nuls oe-ns-eoh
namespace:
type: private
inbox: yes
list: yes
subscriptions: yes
namespace:
type: private
separator: .
prefix: INBOX.
hidden: yes
auth default:
mechanisms: plain login cram-md5
cache_size: 131072
username_translation: #@/@%@
username_format: %Lu
verbose: yes
debug: yes
debug_passwords: yes
worker_max_request_count: 16384
passdb:
driver: sql
args: /usr/local/etc/dovecot-sql.conf
userdb:
driver: prefetch
userdb:
driver: passwd-file
args: username_format=%n /usr/local/etc/postfix/tables/
deliver_passwd
userdb:
driver: sql
args: /usr/local/etc/dovecot-sql.conf
socket:
type: listen
client:
path: /var/spool/postfix/private/auth
mode: 432
user: postfix
group: postfix
master:
path: /var/run/dovecot/auth-master
mode: 384
user: vpostfix
group: vpostfix
plugin:
expire: Trash 14 Trash/* 14 Spam 14 Spam/* 14 VirusAlerts 14
VirusAlerts/* 14 Quarantine 14 Quarantine/* 14
expire_dict: proxy::expire
dict:
expire: mysql:/usr/local/etc/dovecot-expire.conf
Maybe I am missing something here.
I'd really, really appreciate some help on this
to get it sorted out.
Thank you.
Regards,
Gianpaolo
Timo Sirainen
2008-Aug-06 16:55 UTC
[Dovecot] Dovecot proxying results in "too many open files"
On Aug 6, 2008, at 10:29 AM, Gianpaolo Del Matto wrote:> Aug 6 15:49:10 dovecot: imap-login: socket() failed: Too many open > files > Aug 6 15:49:10 dovecot: imap-login: proxy(XYZ): connect(1.2.3.4, > 143) failed: Too many open filesLogin processes change the fd limits themselves, but looks like the value wasn't calculated correctly for SSL connections. This should help: http://hg.dovecot.org/dovecot-1.1/rev/ea6aea0a4cbb -------------- next part -------------- A non-text attachment was scrubbed... Name: PGP.sig Type: application/pgp-signature Size: 194 bytes Desc: This is a digitally signed message part URL: <http://dovecot.org/pipermail/dovecot/attachments/20080806/a6a1d687/attachment-0002.bin>
Gianpaolo Del Matto
2008-Aug-06 16:57 UTC
[Dovecot] Dovecot proxying results in "too many open files"
Hi again,
Here's some more information on the case.
In the meanwhile I tried the same setup with
Dovecot 1.1.2, still the same result
As I saw in fstat on FreeBSD memory mapped files
are ommited, so I did some further yet inaccurate
monitoring with mmaped files included.
while [ : ]; do date; fstat -m -u dovecot |wc -l; sleep 1; done
Wed Aug 6 18:37:05 CEST 2008
918
Wed Aug 6 18:37:06 CEST 2008
923
Wed Aug 6 18:37:07 CEST 2008
917
Wed Aug 6 18:37:08 CEST 2008
911
Wed Aug 6 18:37:09 CEST 2008
912
Wed Aug 6 18:37:10 CEST 2008
914
Wed Aug 6 18:37:11 CEST 2008
913
Wed Aug 6 18:37:13 CEST 2008
912
Wed Aug 6 18:37:14 CEST 2008
911
Wed Aug 6 18:37:15 CEST 2008
909
Wed Aug 6 18:37:16 CEST 2008
912
Wed Aug 6 18:37:17 CEST 2008
910
So actually I am very close to the 1024 FD barrier,
so the question remains, if Dovecot inherits
FD_SETSIZE from libc and if this might be the cause
of the whole trouble.
During testing I did also a build of both
1.1.1 and 1.1.2 without SSL and mysql libraries,
so basically just "plain" Dovecout without anything,
though that made no difference at all.
Greetings,
Gianpaolo
Gianpaolo Del Matto
2008-Aug-06 18:08 UTC
[Dovecot] Dovecot proxying results in "too many open files"
Hello Timo Well, that was fast indeed. Thank you! I applied the patch to 1.1.2 and recompiled it, so far it did not happen within the last 30 minutes. I will let you know what it looks like in a day or two. Am 06.08.2008 um 18:55 schrieb Timo Sirainen:> On Aug 6, 2008, at 10:29 AM, Gianpaolo Del Matto wrote: > >> Aug 6 15:49:10 dovecot: imap-login: socket() failed: Too many open >> files >> Aug 6 15:49:10 dovecot: imap-login: proxy(XYZ): connect(1.2.3.4, >> 143) failed: Too many open files > > Login processes change the fd limits themselves, but looks like the > value wasn't calculated correctly for SSL connections. This should > help: http://hg.dovecot.org/dovecot-1.1/rev/ea6aea0a4cbb >Greetings, Gianpaolo