dovecot - Feb 2014 - Feature request about Info: Internal login failure (pid=2296 id=17278) (internal failure, 1 successful auths)

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1

Hi,

since some time I'm plagued by internal login failures. With v2.2.10 I got 
the some additional error, that I should raise the process_limit for the 
imap service, then I got the hint to raise vsz_limit for the lmtp and 
imap serverices. 
These hints are very helpful and are some sort of unique feature of 
Dovecot - descriptive error messages.

Now I have upgraded a Webfrontend behind imapproxy -> Dovecot and get 
this during a phase in the day, several of messages go to large internal 
mailing lists and lots of users are connecting/disconnecting via IMAP, 
POP,& Web:

<login success>
imap: Error: Disconnected from auth server, aborting (client-pid=2296 
client-id=17278)
imap-login: Info: Internal login failure (pid=2296 id=17278) (internal 
failure, 1 successful auths) .... .

doveadm and to query the userdb [I have some processes that use Dovecot 
UserDB to query user data, which do not cache its information], & login 
into IMAP fail as well. Even connecting to the auth-userdb socket reveals 
no reaction - usually the VERSION prompts immediately. I now suppose that 
the deault auth_worker_max_count=30 is the culprit, because I query LDAP 
for passdb and userdb and client_count, but client_limit=0.

Would it be possible to add a warning to all limits "that max out"?
Or, if such "generic error" occurs, could Dovecot be enabled to dump a
list of which limit is used up to which level? Or something like that.

Also, I'm surprised to find that the "Internal login failure" is
at "Info"
level only.

Also note: It is very possible that the problem is caused by a client that 
goes havoc.

=====
Just to no trigger the "post your config" reply I give now and then 
myself:

# 2.2.10 (5432b55a2b87): /usr/local/dovecot-2.2.10/etc/dovecot/dovecot.conf
# OS: Linux 2.6.32-5-amd64 x86_64 Debian 6.0.8 
auth_cache_size = 10 M
auth_debug = yes
auth_mechanisms = plain login
auth_verbose = yes
base_dir = /var/run/dovecot2.2/
default_vsz_limit = 512 M
deliver_log_format = msgid=%m: %$ %p/%w "%f" "%s"
dict {
   acl = pgsql:/usr/local/dovecot-2.2.10/etc/dovecot/dovecot-dict-sql.conf.ext
   quota = pgsql:/usr/local/dovecot-2.2.10/etc/dovecot/dovecot-dict-sql.conf.ext
}
instance_name = dovecot2.2
lda_mailbox_autocreate = yes
lmtp_save_to_detail_mailbox = yes
log_path = /var/log/dovecot/dovecot2.2.log
log_timestamp = "%F %H:%M:%S "
mail_debug = yes
mail_gid = vmail
mail_log_prefix = "%Us(%u) [%p]: "
mail_max_userip_connections = 0
mail_plugins = " quota notify mail_log zlib acl"
mail_shared_explicit_inbox = yes
mail_uid = vmail
managesieve_notify_capability = mailto
managesieve_sieve_capability = fileinto reject envelope encoded-character
vacation subaddress comparator-i;ascii-numeric relational regex imap4flags copy
include variables body enotify environment mailbox date ihave imapflags
namespace {
   list = children
   location = maildir:%%h/Maildir:INDEX=~/Maildir/shared/%%u
   prefix = users.%%u.
   separator = .
   type = shared
}
namespace inbox {
   inbox = yes
   location    mailbox Drafts {
     special_use = \Drafts
   }
   mailbox Junk {
     special_use = \Junk
   }
   mailbox Sent {
     special_use = \Sent
   }
   mailbox "Sent Messages" {
     special_use = \Sent
   }
   mailbox Trash {
     special_use = \Trash
   }
   prefix = 
}
passdb {
   args = /usr/local/dovecot-2.2.10/etc/dovecot/dovecot-ldap.conf.ext
   driver = ldap
}
plugin {
   acl = vfile
   acl_shared_dict = proxy::acl
   antispam_allow_append_to_spam = yes
   antispam_backend = spool2dir
   antispam_spam = SPAM+ReportAsSPAM
   antispam_spool2dir_notspam = /tmp/spamspool/%%020lu-%%05lu-%u-H
   antispam_spool2dir_spam = /tmp/spamspool/%%020lu-%%05lu-%u-S
   antispam_trash = trash;TRASH;Trash;spam;SPAM;Spam;junk;JUNK;Junk;Deleted
Items;Deleted Messages;Gel&APY-schte Elemente;Gel&APY-schte Objekte;Junk
E-mail;Junk-E-Mail;INBOX.Trash;INBOX.TRASH;INBOX.trash
   mail_log_events = delete undelete expunge copy mailbox_delete mailbox_rename
   mail_log_fields = uid box msgid size vsize from subject
   quota = dict:User quota::proxy::quota
   quota_rule = *:storage=300MB
   quota_rule2 = Trash:storage=+30M
   recipient_delimiter = +
   sieve = ~/.dovecot.sieve
   sieve_dir = ~/sieve
   sieve_extensions = +imapflags
   sieve_max_actions = 0
   sieve_quota_max_storage = 3M
}
protocols = imap pop3 lmtp sieve
quota_full_tempfail = yes
service auth {
   unix_listener auth-client {
     mode = 0766
   }
   unix_listener auth-userdb {
     mode = 0766
     user = vmail
   }
}
service dict {
   unix_listener dict {
     group = vmail
     mode = 0660
     user = vmail
   }
}
service doveadm {
   unix_listener doveadm-server {
     mode = 0666
   }
}
service imap-login {
   process_min_avail = 4
   service_count = 0
   vsz_limit = 768 M
}
service imap {
   process_limit = 10000
   vsz_limit = 768 M
}
service lmtp {
   vsz_limit = 768 M
}
service managesieve-login {
   inet_listener sieve {
     port = 4190
   }
   inet_listener sieve_deprecated {
     port = 2000
   }
}
service pop3-login {
   process_min_avail = 5
   service_count = 0
   vsz_limit = 512 M
}
ssl_ca = </etc/ssl/certs/ca.crt
ssl_cert = </etc/ssl/certs/imap.pem
ssl_key = </etc/ssl/private/imap.key
userdb {
   driver = prefetch
}
userdb {
   args = /usr/local/dovecot-2.2.10/etc/dovecot/dovecot-ldap.conf.ext
   default_fields = home=/home/%u uid=vmail gid=vmail
   driver = ldap
}
verbose_proctitle = yes
protocol lmtp {
   mail_plugins = " quota notify mail_log zlib acl quota sieve"
}
protocol lda {
   mail_plugins = " quota notify mail_log zlib acl quota sieve"
}
protocol imap {
   mail_plugins = " quota notify mail_log zlib acl imap_quota imap_zlib
imap_acl antispam"
}

- -- 
Steffen Kaiser
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.11 (GNU/Linux)

iQEVAwUBUvjzZnD1/YhP6VMHAQKElQgAoBU3v5JD9kFNzan06UFG88sucvf6HZru
gLF6l7IZSWiY/IwouTBoseJcrXmgVG9sCk12gxvonO3iT0KVu1PyJZeTMaKtY3hS
I37J4iS88pmY3cGQNguYMSidrIvNOt6SW+Jv/9QxuYTJKYCqoEZRdP8yJ+dvrmQw
zpZEzKqcV+x4ofDLcpRxLZtXwb+Bl5AA9hoe/Md/UqzUEa9CYyvANoX63/zY7WS5
1VpK+a80/L6ukJUt9tPQTWSe0ALYmL6Cd4tAdC2Bsq7rN+6SQIcjxxr/9v8Byj8Q
BdtwUhpTazVm7CLOjnFiWxfXmHCL9BNrQUBBAd5docSydNDEUMmQng==r9QR
-----END PGP SIGNATURE-----

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1

On Mon, 10 Feb 2014, Steffen Kaiser wrote:
> <login success>
> imap: Error: Disconnected from auth server, aborting (client-pid=2296
> client-id=17278)
> imap-login: Info: Internal login failure (pid=2296 id=17278) (internal
> failure, 1 successful auths) .... .
for the archive:

I have found the client causing this error.
Some in-house program connected to auth-userdb, but did not closed the 
connection, rather it opened another connection to query the next user. 
Most of the time, the number of users was small, so nothing bad happened. 
But now and then up to 3000 users are to query. That broke the system.

However, my feature request remains:
Please add some way to query the current useage / fill of the limits. 
Maybe something like "doveadm who" for all sockets of Dovecot.

Kind regards,

- -- 
Steffen Kaiser
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.11 (GNU/Linux)

iQEVAwUBUvudhnD1/YhP6VMHAQID8gf/RP8Xmkd8SL22hUgTUojSEiyCyR29n/tt
0hjAEubtuMoTVPfGCz6hFyNOLqNowmJYiLsQarFyBX/peXm6yiGLMe4GJoa6N4Np
m0+bRUrBhh+IaQzw+PPfzVAeybQOFGtQ3xi/TXnM0qkoFrryZtLPaeqZeA0xMsDU
ObvINE2E+BHrTbBR/MCTuukpsmDSvORA7ixcIbXk//d5Q9+Mn/s7GIjQlHCAoC2U
2ER8H0Oe/VwDCBEUhJ0PFXMBSp2NEP9qU+R9hWtKG7uAfDCgN+rU+2Vlzi1ediWi
marcQJziO0MlOetrn+Vpqc7I4w0QNV1r9OImsvt6Ox/5d2iqVn8asA==ixQh
-----END PGP SIGNATURE-----

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1

On Mon, 10 Feb 2014, Steffen Kaiser wrote:
> <login success>
> imap: Error: Disconnected from auth server, aborting (client-pid=2296
> client-id=17278)
> imap-login: Info: Internal login failure (pid=2296 id=17278) (internal
> failure, 1 successful auths) .... .
for the archive:

I have found the client causing this error.
Some in-house program connected to auth-userdb, but did not closed the 
connection, rather it opened another connection to query the next user. 
Most of the time, the number of users was small, so nothing bad happened. 
But now and then up to 3000 users are to query. That broke the system.

However, my feature request remains:
Please add some way to query the current useage / fill of the limits. 
Maybe something like "doveadm who" for all sockets of Dovecot.

Kind regards,

- -- 
Steffen Kaiser
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.11 (GNU/Linux)

iQEVAwUBUvudhnD1/YhP6VMHAQID8gf/RP8Xmkd8SL22hUgTUojSEiyCyR29n/tt
0hjAEubtuMoTVPfGCz6hFyNOLqNowmJYiLsQarFyBX/peXm6yiGLMe4GJoa6N4Np
m0+bRUrBhh+IaQzw+PPfzVAeybQOFGtQ3xi/TXnM0qkoFrryZtLPaeqZeA0xMsDU
ObvINE2E+BHrTbBR/MCTuukpsmDSvORA7ixcIbXk//d5Q9+Mn/s7GIjQlHCAoC2U
2ER8H0Oe/VwDCBEUhJ0PFXMBSp2NEP9qU+R9hWtKG7uAfDCgN+rU+2Vlzi1ediWi
marcQJziO0MlOetrn+Vpqc7I4w0QNV1r9OImsvt6Ox/5d2iqVn8asA==ixQh
-----END PGP SIGNATURE-----

On 12 Feb 2014, at 09:12 , Steffen Kaiser <skdovecot at
smail.inf.fh-brs.de> wrote:
> Some in-house program connected to auth-userdb, but did not closed the
connection,
Is there a way to set a timeout on the open socket? Is it a socket?

Would lsof show the connections? (assuming your kernel is compatible with lsof,
mine is not so I can't check).
> Please add some way to query the current useage / fill of the limits. Maybe
something like "doveadm who" for all sockets of Dovecot.
That does seem like a useful feature to have.

-- 
"Part of the inhumanity of the computer is that, once it is competently
programmed and working smoothly, it is completely honest." - Isaac
Asimov