<html>
<head>
<meta http-equiv="Content-Type" content="text/html; charset=UTF-8">
</head>
<body text="#000000" bgcolor="#FFFFFF">
<p>Hi,</p>
<p>I can confirm that in the bad behavior, the 5 second delay occurs
at each AUTH in our case. I think the configuration we have kill
auth process at each end of AUTH (and fork a new one for next next
AUTH). I think the "disable" flag is local to the process that is
killed / respawned.<br>
</p>
<p>A collegue of mine, Laurent Guerby, has found a workaround for us
and it's findings seems very valuable for this ticket.</p>
<p>We now know how to not having the troubles in our setup : by
manual removing the auth-penalty socket with "rm" (or by rebooting
the whole VM because the socket is in a tmpfs). The rm is needed
only one time.<br>
</p>
<p>I think now a clean reproducer of the problem is :</p>
<p> (I go through a fairly similar one but not this exact one)<br>
</p>
<ul>
<li>take a vanilla Debian 9 (probably not limited this particular
version/distro)</li>
<li>make sure use have non-root local unix user account (adduser
testimap for instance)<br>
</li>
<li>apt install dovecot-imapd</li>
<li>keep default config (it may need TLS certificate addition,
default config make uses of auth-penalty and system auth, don't
touch that now)</li>
<li>let it start at least one time (should be already started
after install)<br>
</li>
<li>try at least 1 auth via IMAP (against a local unix user
account </li>
<li>verify that auth-penalty socket exists</li>
<li>check with lsof if some process have opened it</li>
<ul>
<li>Should see 1 dovecot process<br>
</li>
</ul>
<li>change dovecot config to not use penalty <br>
</li>
<ul>
<li>service anvil {
unix_listener anvil-auth-penalty {
mode = 00
}
}</li>
</ul>
<li>restart dovecot</li>
<li>check if the auth-penalty socket exists</li>
<ul>
<li>For me it persists and it seems now to be the root problem</li>
</ul>
<li>(here you can do anything like dovecot stop / start, dovecot
will never remove the auth-penalty socket by itself)<br>
</li>
<li>check with lsof if some process have opened it</li>
<ul>
<li>No process</li>
</ul>
<li>try at least 2 auth (against a a local unix user account) via
IMAP</li>
<ul>
<li>You should have 5 second penalty twice</li>
</ul>
</ul>
<p>The socket open retries loop happens if the socket exists but
noone "listen" on it.<br>
The socket open retries loop don't happen if the socket does not
exists at all.</p>
<p>(I think there is 1 try, the system returns non existing error,
this bails out)<br>
</p>
<p>Regards,<br>
Ludovic<br>
</p>
<div class="moz-cite-prefix">On 06/01/2019 20:04, Stephan Bosch
wrote:<br>
</div>
<blockquote type="cite"
cite="mid:792fa00c-9613-be28-f490-fc26215890f0@rename-it.nl">
<br>
Op 20/12/2018 om 18:09 schreef Ludovic Pouzenc:
<br>
<blockquote type="cite">Hi,
<br>
<br>
I hit a bizare problem with dovecot 2.2.7 on debian 9 with LMTP
enabled and auth/penalty disabled as documented here :
<br>
<a class="moz-txt-link-freetext" href="https://wiki.dovecot.org/Authentication/Penalty">https://wiki.dovecot.org/Authentication/Penalty</a>
<br>
<br>
Use case : I run a swaks command to send an email to an exim4
that tries to make a callout to dovecot-lmtp.
<br>
At RCPT TO: swaks hangs 5.0<something-small> seconds then
process normally (exim is waiting for callout completion).
<br>
<br>
with strace, I see 5 second delay with many tries to socket
connection.
<br>
</blockquote>
<br>
The sources confirm this behavior, but only for the first
connection attempt (i.e. the first 5 seconds of reconnections),
which happens at auth startup (which then takes 5 seconds longer).
After that, it will mark auth-penalty as disabled and it will not
try connecting to it again. Is that what you're referring to?
<br>
<br>
<br>
Regards,
<br>
<br>
Stephan.
<br>
<br>
<br>
<br>
<br>
<blockquote type="cite">
<br>
(PID 9652 was an auth process freshly forked)
<br>
<br>
[pid 9652] socket(AF_UNIX, SOCK_STREAM, 0) = 14
<br>
[pid 9652] fcntl(14, F_GETFL) = 0x2 (flags O_RDWR)
<br>
[pid 9652] fcntl(14, F_SETFL, O_RDWR|O_NONBLOCK) = 0
<br>
[pid 9652] connect(14, {sa_family=AF_UNIX,
sun_path="anvil-auth-penalty"}, 110) = -1 ECONNREFUSED
(Connection refused)
<br>
[pid 9652] close(14) = 0
<br>
[pid 9652] nanosleep({tv_sec=0, tv_nsec=20000000}, NULL) = 0
<br>
[pid 9652] socket(AF_UNIX, SOCK_STREAM, 0) = 14
<br>
[pid 9652] fcntl(14, F_GETFL) = 0x2 (flags O_RDWR)
<br>
[pid 9652] fcntl(14, F_SETFL, O_RDWR|O_NONBLOCK) = 0
<br>
[pid 9652] connect(14, {sa_family=AF_UNIX,
sun_path="anvil-auth-penalty"}, 110) = -1 ECONNREFUSED
(Connection refused)
<br>
[pid 9652] close(14) = 0
<br>
[pid 9652] nanosleep({tv_sec=0, tv_nsec=50000000}, NULL) = 0
<br>
[pid 9652] socket(AF_UNIX, SOCK_STREAM, 0) = 14
<br>
[pid 9652] fcntl(14, F_GETFL) = 0x2 (flags O_RDWR)
<br>
[pid 9652] fcntl(14, F_SETFL, O_RDWR|O_NONBLOCK) = 0
<br>
[pid 9652] connect(14, {sa_family=AF_UNIX,
sun_path="anvil-auth-penalty"}, 110) = -1 ECONNREFUSED
(Connection refused)
<br>
[pid 9652] close(14) = 0
<br>
[pid 9652] nanosleep({tv_sec=0, tv_nsec=90000000}, NULL) = 0
<br>
<br>
<br>
with ddd I get to:
<br>
src/lib-master/anvil-client.c: int anvil_client_connect(struct
anvil_client *client, bool retry) {
<br>
//[...]
<br>
fd = retry ? net_connect_unix_with_retries(client->path,
5000) : net_connect_unix(client->path);
<br>
//[...]
<br>
<br>
and retry is forced to TRUE by the caller and
net_connect_unix_with_retries retries in case of ECONNREFUSED.
<br>
<br>
<br>
How I get into it :
<br>
<br>
ssh -X root@telegraphe-test
<br>
<br>
apt install dovecot-dbg
<br>
cd /dev/shm
<br>
apt source dovecot
<br>
cd dovecot-2.2.27
<br>
pidof dovecot
<br>
ddd /usr/sbin/dovecot
<br>
set follow-fork-mode child
<br>
attach 11833
<br>
cont
<br>
<br>
# Send an e-mail from swaks to exim that use transport=smtp in
LMTP mode to dovecot-lmtp, press interrupt while exim is
blocking after RCPT TO:
<br>
<br>
<br>
(gdb) bt
<br>
#0 0x00007f81528af270 in __nanosleep_nocancel () at
../sysdeps/unix/syscall-template.S:84
<br>
#1 0x00007f81528d8b84 in usleep (useconds=<optimized
out>) at ../sysdeps/posix/usleep.c:32
<br>
#2 0x00007f815329368e in net_connect_unix_with_retries
(path=0x562dc200ce10 <error: Cannot access memory at address
0x562dc200ce10>, msecs=msecs@entry=5000) at net.c:347
<br>
#3 0x00007f815320ce0d in anvil_client_connect
(client=0x562dc200cda0, retry=retry@entry=true) at
anvil-client.c:136
<br>
#4 0x0000562dc1429f5d in auth_penalty_init (path=0x562dc1451846
<error: Cannot access memory at address 0x562dc1451846>)
at auth-penalty.c:37
<br>
#5 0x0000562dc1424166 in main_preinit () at main.c:202
<br>
#6 main (argc=<optimized out>, argv=<optimized
out>) at main.c:396
<br>
<br>
(gdb) bt full
<br>
#1 0x00007f81528d8b84 in usleep (useconds=<optimized
out>) at ../sysdeps/posix/usleep.c:32
<br>
ts = {tv_sec = 0, tv_nsec = 80000000}
<br>
#2 0x00007f815329368e in net_connect_unix_with_retries
(path=0x562dc200ce10 <error: Cannot access memory at address
0x562dc200ce10>, msecs=msecs@entry=5000) at net.c:347
<br>
start = {tv_sec = 1545319486, tv_usec = 241864}
<br>
now = {tv_sec = 1545319490, tv_usec = 198061}
<br>
fd = -1
<br>
#3 0x00007f815320ce0d in anvil_client_connect
(client=0x562dc200cda0, retry=retry@entry=true) at
anvil-client.c:136
<br>
fd = <optimized out>
<br>
__FUNCTION__ = <error reading variable __FUNCTION__
(Cannot access memory at address 0x7f81532a8260)>
<br>
#4 0x0000562dc1429f5d in auth_penalty_init (path=0x562dc1451846
<error: Cannot access memory at address 0x562dc1451846>)
at auth-penalty.c:37
<br>
No locals.
<br>
#5 0x0000562dc1424166 in main_preinit () at main.c:202
<br>
mod_set = <error reading variable mod_set (Cannot
access memory at address 0x7ffda885db80)>
<br>
#6 main (argc=<optimized out>, argv=<optimized
out>) at main.c:396
<br>
c = <optimized out>
<br>
Backtrace stopped: Cannot access memory at address
0x7ffda885dbf8
<br>
(gdb)
<br>
<br>
Code I've read :
<br>
<br>
src/auth/main.c: static void main_preinit(void)
<br>
<br>
if (!worker)
<br>
auth_penalty =
auth_penalty_init(AUTH_PENALTY_ANVIL_PATH);
<br>
auth_request_stats_init();
<br>
<br>
src/auth/auth-penalty.c: struct auth_penalty
*auth_penalty_init(const char *path)
<br>
<br>
if (anvil_client_connect(penalty->client, TRUE) <
0)
<br>
penalty->disabled = TRUE;
<br>
else {
<br>
<br>
src/lib-master/anvil-client.c: int anvil_client_connect(struct
anvil_client *client, bool retry)
<br>
<br>
fd = retry ?
net_connect_unix_with_retries(client->path, 5000) :
<br>
net_connect_unix(client->path);
<br>
<br>
src/lib/net.c : int net_connect_unix_with_retries(const char
*path, unsigned int msecs) {
<br>
struct timeval start, now;
<br>
int fd;
<br>
if (gettimeofday(&start, NULL) < 0)
<br>
i_panic("gettimeofday() failed: %m");
<br>
do {
<br>
fd = net_connect_unix(path);
<br>
if (fd != -1 || (errno != EAGAIN &&
errno != ECONNREFUSED)) // <------------------ HERE, I go
into ECONNREFUSED case during 5 seconds
<br>
break;
<br>
/* busy. wait for a while. */
<br>
usleep(((rand() % 10) + 1) * 10000);
<br>
if (gettimeofday(&now, NULL) < 0)
<br>
i_panic("gettimeofday() failed: %m");
<br>
} while (timeval_diff_msecs(&now, &start) <
(int)msecs);
<br>
return fd;
<br>
}
<br>
<br>
Additionnal environment infos (mailboxes are NFS-backed) :
<br>
<br>
lsb_release -a
<br>
No LSB modules are available.
<br>
Distributor ID: Debian
<br>
Description: Debian GNU/Linux 9.2 (stretch)
<br>
Release: 9.2
<br>
Codename: stretch
<br>
<br>
<br>
mount | grep ^/
<br>
/dev/sda1 on / type ext4
(rw,relatime,errors=remount-ro,data=ordered)
<br>
<br>
mount | grep nfs
<br>
nfs1:/mail/maildir on /var/maildir type nfs
(rw,relatime,vers=3,rsize=65536,wsize=65536,namlen=255,hard,proto=tcp,timeo=600,retrans=2,sec=sys,mountaddr=172.16.2.28,mountvers=3,mountport=635,mountproto=udp,local_lock=none,addr=172.16.2.28)<br>
nfs1:/mail on /var/mail type nfs
(rw,relatime,vers=3,rsize=65536,wsize=65536,namlen=255,hard,proto=tcp,timeo=600,retrans=2,sec=sys,mountaddr=172.16.2.28,mountvers=3,mountport=635,mountproto=udp,local_lock=none,addr=172.16.2.28)<br>
cifs1:/homepermanents/info/lpouzenc on /home/lpouzenc type nfs
(rw,nosuid,nodev,relatime,vers=3,rsize=65536,wsize=65536,namlen=255,hard,proto=tcp,timeo=600,retrans=2,sec=sys,mountaddr=172.16.2.29,mountvers=3,mountport=635,mountproto=udp,local_lock=none,addr=172.16.2.29)<br>
<br>
<br>
<br>
telegraphe-test:~# apt-cache policy dovecot-core
<br>
dovecot-core:
<br>
Installé : 1:2.2.27-3+deb9u2
<br>
Candidat : 1:2.2.27-3+deb9u2
<br>
Table de version :
<br>
*** 1:2.2.27-3+deb9u2 500
<br>
500http://miroir/debian stretch/main amd64 Packages
<br>
500http://security.debian.org/debian-security
stretch/updates/main amd64 Packages
<br>
100 /var/lib/dpkg/status
<br>
<br>
telegraphe-test:~# dovecot -n
<br>
# 2.2.27 (c0f36b0): /etc/dovecot/dovecot.conf
<br>
# Pigeonhole version 0.4.16 (fed8554)
<br>
doveconf: Warning: service auth { client_limit=10000 } is lower
than required under max. load (10240)
<br>
# OS: Linux 4.9.0-4-amd64 x86_64 Debian 9.2 nfs
<br>
auth_verbose = yes
<br>
default_client_limit = 10000
<br>
default_process_limit = 2048
<br>
lda_mailbox_autocreate = yes
<br>
lda_mailbox_autosubscribe = yes
<br>
mail_debug = yes
<br>
mail_fsync = always
<br>
mail_location = maildir:/var/mail/maildir/%u
<br>
managesieve_notify_capability = mailto
<br>
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 index ihave duplicate mime foreverypart
extracttext
<br>
mmap_disable = yes
<br>
namespace inbox {
<br>
inbox = yes
<br>
location =
<br>
mailbox Drafts {
<br>
special_use = \Drafts
<br>
}
<br>
mailbox Junk {
<br>
special_use = \Junk
<br>
}
<br>
mailbox Sent {
<br>
special_use = \Sent
<br>
}
<br>
mailbox "Sent Messages" {
<br>
special_use = \Sent
<br>
}
<br>
mailbox Trash {
<br>
special_use = \Trash
<br>
}
<br>
prefix =
<br>
separator = /
<br>
}
<br>
passdb {
<br>
driver = pam
<br>
}
<br>
plugin {
<br>
sieve
=<a class="moz-txt-link-freetext" href="file:/var/mail/mailconf/%1u/%u/sieve;active=/var/mail/mailconf/%1u/%u/.dovecot.sieve">file:/var/mail/mailconf/%1u/%u/sieve;active=/var/mail/mailconf/%1u/%u/.dovecot.sieve</a><br>
sieve_before = /var/mail/mailconf/global/sieve/before.d
<br>
sieve_global = /var/mail/mailconf/global/sieve
<br>
sieve_vacation_dont_check_recipient = yes
<br>
}
<br>
protocols = " imap lmtp sieve sieve"
<br>
service anvil {
<br>
unix_listener anvil-auth-penalty {
<br>
mode = 00
<br>
}
<br>
}
<br>
service lmtp {
<br>
inet_listener lmtp {
<br>
port = 24
<br>
}
<br>
}
<br>
service managesieve {
<br>
process_limit = 16
<br>
}
<br>
ssl_cert = </etc/ssl/certs/telegraphe7_cert.pem
<br>
ssl_key = # hidden, use -P to show it
<br>
syslog_facility = local0
<br>
userdb {
<br>
driver = passwd
<br>
}
<br>
verbose_proctitle = yes
<br>
protocol lmtp {
<br>
auth_username_format = %n
<br>
mail_plugins = " sieve"
<br>
}
<br>
protocol imap {
<br>
mail_max_userip_connections = 20
<br>
}
<br>
<br>
<br>
<br>
Could you see a config tuning that keeps auth-penalty out of the
way (it seems to behaves badly here, because we have perdition
IMAP proxy in front, and it keeps track only of his IP and adds
2/4/8/15s delays to "random" legit clients.
<br>
<br>
Could it be saved with a dedicated config entry to disable
auth-penalty ?
<br>
<br>
Is there solution to have auth-penalty working while having
perdition IMAP proxy ?
<br>
<br>
Regards,
<br>
Ludovic Pouzenc
<br>
-- <br>
Ludovic POUZENC - Ingénieur Système
<br>
IMT Mines Albi (<a class="moz-txt-link-freetext" href="http://www.imt-mines-albi.fr">http://www.imt-mines-albi.fr</a>)
<br>
81013 ALBI CT Cedex 09 - Tel : 05 63 49 33 56
<br>
</blockquote>
</blockquote>
<pre class="moz-signature" cols="72">--
Ludovic POUZENC - Ingénieur Système
IMT Mines Albi (<a class="moz-txt-link-freetext" href="http://www.imt-mines-albi.fr">http://www.imt-mines-albi.fr</a>)
81013 ALBI CT Cedex 09 - Tel : 05 63 49 33 56</pre>
</body>
</html>