Ludovic Pouzenc
2018-Dec-20 17:09 UTC
Authentication/Penalty disabled (socket mode=0) introduces constant 5 sec delays (2.27 on debian 9)
Hi,
I hit a bizare problem with dovecot 2.2.7 on debian 9 with LMTP enabled and
auth/penalty disabled as documented here :
https://wiki.dovecot.org/Authentication/Penalty
Use case : I run a swaks command to send an email to an exim4 that tries to make
a callout to dovecot-lmtp.
At RCPT TO: swaks hangs 5.0<something-small> seconds then process normally
(exim is waiting for callout completion).
with strace, I see 5 second delay with many tries to socket connection.
(PID 9652 was an auth process freshly forked)
[pid 9652] socket(AF_UNIX, SOCK_STREAM, 0) = 14
[pid 9652] fcntl(14, F_GETFL) = 0x2 (flags O_RDWR)
[pid 9652] fcntl(14, F_SETFL, O_RDWR|O_NONBLOCK) = 0
[pid 9652] connect(14, {sa_family=AF_UNIX,
sun_path="anvil-auth-penalty"}, 110) = -1 ECONNREFUSED (Connection
refused)
[pid 9652] close(14) = 0
[pid 9652] nanosleep({tv_sec=0, tv_nsec=20000000}, NULL) = 0
[pid 9652] socket(AF_UNIX, SOCK_STREAM, 0) = 14
[pid 9652] fcntl(14, F_GETFL) = 0x2 (flags O_RDWR)
[pid 9652] fcntl(14, F_SETFL, O_RDWR|O_NONBLOCK) = 0
[pid 9652] connect(14, {sa_family=AF_UNIX,
sun_path="anvil-auth-penalty"}, 110) = -1 ECONNREFUSED (Connection
refused)
[pid 9652] close(14) = 0
[pid 9652] nanosleep({tv_sec=0, tv_nsec=50000000}, NULL) = 0
[pid 9652] socket(AF_UNIX, SOCK_STREAM, 0) = 14
[pid 9652] fcntl(14, F_GETFL) = 0x2 (flags O_RDWR)
[pid 9652] fcntl(14, F_SETFL, O_RDWR|O_NONBLOCK) = 0
[pid 9652] connect(14, {sa_family=AF_UNIX,
sun_path="anvil-auth-penalty"}, 110) = -1 ECONNREFUSED (Connection
refused)
[pid 9652] close(14) = 0
[pid 9652] nanosleep({tv_sec=0, tv_nsec=90000000}, NULL) = 0
with ddd I get to:
src/lib-master/anvil-client.c: int anvil_client_connect(struct anvil_client
*client, bool retry) {
//[...]
fd = retry ? net_connect_unix_with_retries(client->path, 5000) :
net_connect_unix(client->path);
//[...]
and retry is forced to TRUE by the caller and net_connect_unix_with_retries
retries in case of ECONNREFUSED.
How I get into it :
ssh -X root at telegraphe-test
apt install dovecot-dbg
cd /dev/shm
apt source dovecot
cd dovecot-2.2.27
pidof dovecot
ddd /usr/sbin/dovecot
set follow-fork-mode child
attach 11833
cont
# 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:
(gdb) bt
#0 0x00007f81528af270 in __nanosleep_nocancel () at
../sysdeps/unix/syscall-template.S:84
#1 0x00007f81528d8b84 in usleep (useconds=<optimized out>) at
../sysdeps/posix/usleep.c:32
#2 0x00007f815329368e in net_connect_unix_with_retries (path=0x562dc200ce10
<error: Cannot access memory at address 0x562dc200ce10>, msecs=msecs at
entry=5000) at net.c:347
#3 0x00007f815320ce0d in anvil_client_connect (client=0x562dc200cda0,
retry=retry at entry=true) at anvil-client.c:136
#4 0x0000562dc1429f5d in auth_penalty_init (path=0x562dc1451846 <error:
Cannot access memory at address 0x562dc1451846>) at auth-penalty.c:37
#5 0x0000562dc1424166 in main_preinit () at main.c:202
#6 main (argc=<optimized out>, argv=<optimized out>) at main.c:396
(gdb) bt full
#1 0x00007f81528d8b84 in usleep (useconds=<optimized out>) at
../sysdeps/posix/usleep.c:32
ts = {tv_sec = 0, tv_nsec = 80000000}
#2 0x00007f815329368e in net_connect_unix_with_retries (path=0x562dc200ce10
<error: Cannot access memory at address 0x562dc200ce10>, msecs=msecs at
entry=5000) at net.c:347
start = {tv_sec = 1545319486, tv_usec = 241864}
now = {tv_sec = 1545319490, tv_usec = 198061}
fd = -1
#3 0x00007f815320ce0d in anvil_client_connect (client=0x562dc200cda0,
retry=retry at entry=true) at anvil-client.c:136
fd = <optimized out>
__FUNCTION__ = <error reading variable __FUNCTION__ (Cannot access
memory at address 0x7f81532a8260)>
#4 0x0000562dc1429f5d in auth_penalty_init (path=0x562dc1451846 <error:
Cannot access memory at address 0x562dc1451846>) at auth-penalty.c:37
No locals.
#5 0x0000562dc1424166 in main_preinit () at main.c:202
mod_set = <error reading variable mod_set (Cannot access memory at
address 0x7ffda885db80)>
#6 main (argc=<optimized out>, argv=<optimized out>) at main.c:396
c = <optimized out>
Backtrace stopped: Cannot access memory at address 0x7ffda885dbf8
(gdb)
Code I've read :
src/auth/main.c: static void main_preinit(void)
if (!worker)
auth_penalty = auth_penalty_init(AUTH_PENALTY_ANVIL_PATH);
auth_request_stats_init();
src/auth/auth-penalty.c: struct auth_penalty *auth_penalty_init(const char
*path)
if (anvil_client_connect(penalty->client, TRUE) < 0)
penalty->disabled = TRUE;
else {
src/lib-master/anvil-client.c: int anvil_client_connect(struct anvil_client
*client, bool retry)
fd = retry ? net_connect_unix_with_retries(client->path, 5000) :
net_connect_unix(client->path);
src/lib/net.c : int net_connect_unix_with_retries(const char *path, unsigned int
msecs) {
struct timeval start, now;
int fd;
if (gettimeofday(&start, NULL) < 0)
i_panic("gettimeofday() failed: %m");
do {
fd = net_connect_unix(path);
if (fd != -1 || (errno != EAGAIN && errno !=
ECONNREFUSED)) // <------------------ HERE, I go into ECONNREFUSED case
during 5 seconds
break;
/* busy. wait for a while. */
usleep(((rand() % 10) + 1) * 10000);
if (gettimeofday(&now, NULL) < 0)
i_panic("gettimeofday() failed: %m");
} while (timeval_diff_msecs(&now, &start) < (int)msecs);
return fd;
}
Additionnal environment infos (mailboxes are NFS-backed) :
lsb_release -a
No LSB modules are available.
Distributor ID: Debian
Description: Debian GNU/Linux 9.2 (stretch)
Release: 9.2
Codename: stretch
mount | grep ^/
/dev/sda1 on / type ext4 (rw,relatime,errors=remount-ro,data=ordered)
mount | grep nfs
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)
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)
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)
telegraphe-test:~# apt-cache policy dovecot-core
dovecot-core:
Install??: 1:2.2.27-3+deb9u2
Candidat?: 1:2.2.27-3+deb9u2
Table de version?:
*** 1:2.2.27-3+deb9u2 500
500 http://miroir/debian stretch/main amd64 Packages
500 http://security.debian.org/debian-security stretch/updates/main
amd64 Packages
100 /var/lib/dpkg/status
telegraphe-test:~# dovecot -n
# 2.2.27 (c0f36b0): /etc/dovecot/dovecot.conf
# Pigeonhole version 0.4.16 (fed8554)
doveconf: Warning: service auth { client_limit=10000 } is lower than required
under max. load (10240)
# OS: Linux 4.9.0-4-amd64 x86_64 Debian 9.2 nfs
auth_verbose = yes
default_client_limit = 10000
default_process_limit = 2048
lda_mailbox_autocreate = yes
lda_mailbox_autosubscribe = yes
mail_debug = yes
mail_fsync = always
mail_location = maildir:/var/mail/maildir/%u
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 index ihave duplicate
mime foreverypart extracttext
mmap_disable = yes
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 separator = /
}
passdb {
driver = pam
}
plugin {
sieve =
file:/var/mail/mailconf/%1u/%u/sieve;active=/var/mail/mailconf/%1u/%u/.dovecot.sieve
sieve_before = /var/mail/mailconf/global/sieve/before.d
sieve_global = /var/mail/mailconf/global/sieve
sieve_vacation_dont_check_recipient = yes
}
protocols = " imap lmtp sieve sieve"
service anvil {
unix_listener anvil-auth-penalty {
mode = 00
}
}
service lmtp {
inet_listener lmtp {
port = 24
}
}
service managesieve {
process_limit = 16
}
ssl_cert = </etc/ssl/certs/telegraphe7_cert.pem
ssl_key = # hidden, use -P to show it
syslog_facility = local0
userdb {
driver = passwd
}
verbose_proctitle = yes
protocol lmtp {
auth_username_format = %n
mail_plugins = " sieve"
}
protocol imap {
mail_max_userip_connections = 20
}
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.
Could it be saved with a dedicated config entry to disable auth-penalty ?
Is there solution to have auth-penalty working while having perdition IMAP proxy
?
Regards,
Ludovic Pouzenc
--
Ludovic POUZENC - Ing?nieur Syst?me
IMT Mines Albi (http://www.imt-mines-albi.fr)
81013 ALBI CT Cedex 09 - Tel : 05 63 49 33 56
-------------- next part --------------
An HTML attachment was scrubbed...
URL:
<https://dovecot.org/pipermail/dovecot/attachments/20181220/b2942a3b/attachment.html>
Stephan Bosch
2019-Jan-06 19:04 UTC
Authentication/Penalty disabled (socket mode=0) introduces constant 5 sec delays (2.27 on debian 9)
Op 20/12/2018 om 18:09 schreef Ludovic Pouzenc:> Hi, > > I hit a bizare problem with dovecot 2.2.7 on debian 9 with LMTP enabled and auth/penalty disabled as documented here : > https://wiki.dovecot.org/Authentication/Penalty > > Use case : I run a swaks command to send an email to an exim4 that tries to make a callout to dovecot-lmtp. > At RCPT TO: swaks hangs 5.0<something-small> seconds then process normally (exim is waiting for callout completion). > > with strace, I see 5 second delay with many tries to socket connection.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? Regards, Stephan.> > (PID 9652 was an auth process freshly forked) > > [pid 9652] socket(AF_UNIX, SOCK_STREAM, 0) = 14 > [pid 9652] fcntl(14, F_GETFL) = 0x2 (flags O_RDWR) > [pid 9652] fcntl(14, F_SETFL, O_RDWR|O_NONBLOCK) = 0 > [pid 9652] connect(14, {sa_family=AF_UNIX, sun_path="anvil-auth-penalty"}, 110) = -1 ECONNREFUSED (Connection refused) > [pid 9652] close(14) = 0 > [pid 9652] nanosleep({tv_sec=0, tv_nsec=20000000}, NULL) = 0 > [pid 9652] socket(AF_UNIX, SOCK_STREAM, 0) = 14 > [pid 9652] fcntl(14, F_GETFL) = 0x2 (flags O_RDWR) > [pid 9652] fcntl(14, F_SETFL, O_RDWR|O_NONBLOCK) = 0 > [pid 9652] connect(14, {sa_family=AF_UNIX, sun_path="anvil-auth-penalty"}, 110) = -1 ECONNREFUSED (Connection refused) > [pid 9652] close(14) = 0 > [pid 9652] nanosleep({tv_sec=0, tv_nsec=50000000}, NULL) = 0 > [pid 9652] socket(AF_UNIX, SOCK_STREAM, 0) = 14 > [pid 9652] fcntl(14, F_GETFL) = 0x2 (flags O_RDWR) > [pid 9652] fcntl(14, F_SETFL, O_RDWR|O_NONBLOCK) = 0 > [pid 9652] connect(14, {sa_family=AF_UNIX, sun_path="anvil-auth-penalty"}, 110) = -1 ECONNREFUSED (Connection refused) > [pid 9652] close(14) = 0 > [pid 9652] nanosleep({tv_sec=0, tv_nsec=90000000}, NULL) = 0 > > > with ddd I get to: > src/lib-master/anvil-client.c: int anvil_client_connect(struct anvil_client *client, bool retry) { > //[...] > fd = retry ? net_connect_unix_with_retries(client->path, 5000) : net_connect_unix(client->path); > //[...] > > and retry is forced to TRUE by the caller and net_connect_unix_with_retries retries in case of ECONNREFUSED. > > > How I get into it : > > ssh -X root at telegraphe-test > > apt install dovecot-dbg > cd /dev/shm > apt source dovecot > cd dovecot-2.2.27 > pidof dovecot > ddd /usr/sbin/dovecot > set follow-fork-mode child > attach 11833 > cont > > # 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: > > > (gdb) bt > #0 0x00007f81528af270 in __nanosleep_nocancel () at ../sysdeps/unix/syscall-template.S:84 > #1 0x00007f81528d8b84 in usleep (useconds=<optimized out>) at ../sysdeps/posix/usleep.c:32 > #2 0x00007f815329368e in net_connect_unix_with_retries (path=0x562dc200ce10 <error: Cannot access memory at address 0x562dc200ce10>, msecs=msecs at entry=5000) at net.c:347 > #3 0x00007f815320ce0d in anvil_client_connect (client=0x562dc200cda0, retry=retry at entry=true) at anvil-client.c:136 > #4 0x0000562dc1429f5d in auth_penalty_init (path=0x562dc1451846 <error: Cannot access memory at address 0x562dc1451846>) at auth-penalty.c:37 > #5 0x0000562dc1424166 in main_preinit () at main.c:202 > #6 main (argc=<optimized out>, argv=<optimized out>) at main.c:396 > > (gdb) bt full > #1 0x00007f81528d8b84 in usleep (useconds=<optimized out>) at ../sysdeps/posix/usleep.c:32 > ts = {tv_sec = 0, tv_nsec = 80000000} > #2 0x00007f815329368e in net_connect_unix_with_retries (path=0x562dc200ce10 <error: Cannot access memory at address 0x562dc200ce10>, msecs=msecs at entry=5000) at net.c:347 > start = {tv_sec = 1545319486, tv_usec = 241864} > now = {tv_sec = 1545319490, tv_usec = 198061} > fd = -1 > #3 0x00007f815320ce0d in anvil_client_connect (client=0x562dc200cda0, retry=retry at entry=true) at anvil-client.c:136 > fd = <optimized out> > __FUNCTION__ = <error reading variable __FUNCTION__ (Cannot access memory at address 0x7f81532a8260)> > #4 0x0000562dc1429f5d in auth_penalty_init (path=0x562dc1451846 <error: Cannot access memory at address 0x562dc1451846>) at auth-penalty.c:37 > No locals. > #5 0x0000562dc1424166 in main_preinit () at main.c:202 > mod_set = <error reading variable mod_set (Cannot access memory at address 0x7ffda885db80)> > #6 main (argc=<optimized out>, argv=<optimized out>) at main.c:396 > c = <optimized out> > Backtrace stopped: Cannot access memory at address 0x7ffda885dbf8 > (gdb) > > Code I've read : > > src/auth/main.c: static void main_preinit(void) > > if (!worker) > auth_penalty = auth_penalty_init(AUTH_PENALTY_ANVIL_PATH); > auth_request_stats_init(); > > src/auth/auth-penalty.c: struct auth_penalty *auth_penalty_init(const char *path) > > if (anvil_client_connect(penalty->client, TRUE) < 0) > penalty->disabled = TRUE; > else { > > src/lib-master/anvil-client.c: int anvil_client_connect(struct anvil_client *client, bool retry) > > fd = retry ? net_connect_unix_with_retries(client->path, 5000) : > net_connect_unix(client->path); > > src/lib/net.c : int net_connect_unix_with_retries(const char *path, unsigned int msecs) { > struct timeval start, now; > int fd; > > if (gettimeofday(&start, NULL) < 0) > i_panic("gettimeofday() failed: %m"); > > do { > fd = net_connect_unix(path); > if (fd != -1 || (errno != EAGAIN && errno != ECONNREFUSED)) // <------------------ HERE, I go into ECONNREFUSED case during 5 seconds > break; > > /* busy. wait for a while. */ > usleep(((rand() % 10) + 1) * 10000); > if (gettimeofday(&now, NULL) < 0) > i_panic("gettimeofday() failed: %m"); > } while (timeval_diff_msecs(&now, &start) < (int)msecs); > return fd; > } > > Additionnal environment infos (mailboxes are NFS-backed) : > > lsb_release -a > No LSB modules are available. > Distributor ID: Debian > Description: Debian GNU/Linux 9.2 (stretch) > Release: 9.2 > Codename: stretch > > > mount | grep ^/ > /dev/sda1 on / type ext4 (rw,relatime,errors=remount-ro,data=ordered) > > mount | grep nfs > 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) > 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) > 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) > > > > telegraphe-test:~# apt-cache policy dovecot-core > dovecot-core: > Install??: 1:2.2.27-3+deb9u2 > Candidat?: 1:2.2.27-3+deb9u2 > Table de version?: > *** 1:2.2.27-3+deb9u2 500 > 500http://miroir/debian stretch/main amd64 Packages > 500http://security.debian.org/debian-security stretch/updates/main amd64 Packages > 100 /var/lib/dpkg/status > > telegraphe-test:~# dovecot -n > # 2.2.27 (c0f36b0): /etc/dovecot/dovecot.conf > # Pigeonhole version 0.4.16 (fed8554) > doveconf: Warning: service auth { client_limit=10000 } is lower than required under max. load (10240) > # OS: Linux 4.9.0-4-amd64 x86_64 Debian 9.2 nfs > auth_verbose = yes > default_client_limit = 10000 > default_process_limit = 2048 > lda_mailbox_autocreate = yes > lda_mailbox_autosubscribe = yes > mail_debug = yes > mail_fsync = always > mail_location = maildir:/var/mail/maildir/%u > 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 index ihave duplicate mime foreverypart extracttext > mmap_disable = yes > 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 > separator = / > } > passdb { > driver = pam > } > plugin { > sieve =file:/var/mail/mailconf/%1u/%u/sieve;active=/var/mail/mailconf/%1u/%u/.dovecot.sieve > sieve_before = /var/mail/mailconf/global/sieve/before.d > sieve_global = /var/mail/mailconf/global/sieve > sieve_vacation_dont_check_recipient = yes > } > protocols = " imap lmtp sieve sieve" > service anvil { > unix_listener anvil-auth-penalty { > mode = 00 > } > } > service lmtp { > inet_listener lmtp { > port = 24 > } > } > service managesieve { > process_limit = 16 > } > ssl_cert = </etc/ssl/certs/telegraphe7_cert.pem > ssl_key = # hidden, use -P to show it > syslog_facility = local0 > userdb { > driver = passwd > } > verbose_proctitle = yes > protocol lmtp { > auth_username_format = %n > mail_plugins = " sieve" > } > protocol imap { > mail_max_userip_connections = 20 > } > > > > 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. > > Could it be saved with a dedicated config entry to disable auth-penalty ? > > Is there solution to have auth-penalty working while having perdition IMAP proxy ? > > Regards, > Ludovic Pouzenc > -- > Ludovic POUZENC - Ing?nieur Syst?me > IMT Mines Albi (http://www.imt-mines-albi.fr) > 81013 ALBI CT Cedex 09 - Tel : 05 63 49 33 56
Ludovic Pouzenc
2019-Jan-08 10:05 UTC
Authentication/Penalty disabled (socket mode=0) introduces constant 5 sec delays (2.27 on debian 9)
Hi,
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.
A collegue of mine, Laurent Guerby, has found a workaround for us and
it's findings seems very valuable for this ticket.
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.
I think now a clean reproducer of the problem is :
(I go through a fairly similar one but not this exact one)
* take a vanilla Debian 9 (probably not limited this particular
version/distro)
* make sure use have non-root local unix user account (adduser
testimap for instance)
* apt install dovecot-imapd
* keep default config (it may need TLS certificate addition, default
config make uses of auth-penalty and system auth, don't touch that now)
* let it start at least one time (should be already started after install)
* try at least 1 auth via IMAP (against a local unix user account
* verify that auth-penalty socket exists
* check with lsof if some process have opened it
o Should see 1 dovecot process
* change dovecot config to not use penalty
o service anvil { ?? unix_listener anvil-auth-penalty { ???? mode
= 00 ?? } }
* restart dovecot
* check if the auth-penalty socket exists
o For me it persists and it seems now to be the root problem
* (here you can do anything like dovecot stop / start, dovecot will
never remove the auth-penalty socket by itself)
* check with lsof if some process have opened it
o No process
* try at least 2 auth (against a a local unix user account) via IMAP
o You should have 5 second penalty twice
The socket open retries loop happens if the socket exists but noone
"listen" on it.
The socket open retries loop don't happen if the socket does not exists
at all.
(I think there is 1 try, the system returns non existing error, this
bails out)
Regards,
Ludovic
On 06/01/2019 20:04, Stephan Bosch wrote:>
> Op 20/12/2018 om 18:09 schreef Ludovic Pouzenc:
>> Hi,
>>
>> I hit a bizare problem with dovecot 2.2.7 on debian 9 with LMTP
>> enabled and auth/penalty disabled as documented here :
>> ? https://wiki.dovecot.org/Authentication/Penalty
>>
>> Use case : I run a swaks command to send an email to an exim4 that
>> tries to make a callout to dovecot-lmtp.
>> At RCPT TO: swaks hangs 5.0<something-small> seconds then process
>> normally (exim is waiting for callout completion).
>>
>> with strace, I see 5 second delay with many tries to socket connection.
>
> 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?
>
>
> Regards,
>
> Stephan.
>
>
>
>
>>
>> (PID 9652 was an auth process freshly forked)
>>
>> [pid? 9652] socket(AF_UNIX, SOCK_STREAM, 0) = 14
>> [pid? 9652] fcntl(14, F_GETFL)????????? = 0x2 (flags O_RDWR)
>> [pid? 9652] fcntl(14, F_SETFL, O_RDWR|O_NONBLOCK) = 0
>> [pid? 9652] connect(14, {sa_family=AF_UNIX,
>> sun_path="anvil-auth-penalty"}, 110) = -1 ECONNREFUSED
(Connection
>> refused)
>> [pid? 9652] close(14)?????????????????? = 0
>> [pid? 9652] nanosleep({tv_sec=0, tv_nsec=20000000}, NULL) = 0
>> [pid? 9652] socket(AF_UNIX, SOCK_STREAM, 0) = 14
>> [pid? 9652] fcntl(14, F_GETFL)????????? = 0x2 (flags O_RDWR)
>> [pid? 9652] fcntl(14, F_SETFL, O_RDWR|O_NONBLOCK) = 0
>> [pid? 9652] connect(14, {sa_family=AF_UNIX,
>> sun_path="anvil-auth-penalty"}, 110) = -1 ECONNREFUSED
(Connection
>> refused)
>> [pid? 9652] close(14)?????????????????? = 0
>> [pid? 9652] nanosleep({tv_sec=0, tv_nsec=50000000}, NULL) = 0
>> [pid? 9652] socket(AF_UNIX, SOCK_STREAM, 0) = 14
>> [pid? 9652] fcntl(14, F_GETFL)????????? = 0x2 (flags O_RDWR)
>> [pid? 9652] fcntl(14, F_SETFL, O_RDWR|O_NONBLOCK) = 0
>> [pid? 9652] connect(14, {sa_family=AF_UNIX,
>> sun_path="anvil-auth-penalty"}, 110) = -1 ECONNREFUSED
(Connection
>> refused)
>> [pid? 9652] close(14)?????????????????? = 0
>> [pid? 9652] nanosleep({tv_sec=0, tv_nsec=90000000}, NULL) = 0
>>
>>
>> with ddd I get to:
>> src/lib-master/anvil-client.c: int anvil_client_connect(struct
>> anvil_client *client, bool retry) {
>> //[...]
>> fd = retry ? net_connect_unix_with_retries(client->path, 5000) :
>> net_connect_unix(client->path);
>> //[...]
>>
>> and retry is forced to TRUE by the caller and
>> net_connect_unix_with_retries retries in case of ECONNREFUSED.
>>
>>
>> How I get into it :
>>
>> ssh -X root at telegraphe-test
>>
>> apt install dovecot-dbg
>> cd /dev/shm
>> apt source dovecot
>> cd dovecot-2.2.27
>> pidof dovecot
>> ddd /usr/sbin/dovecot
>> set follow-fork-mode child
>> attach 11833
>> cont
>>
>> # 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:
>>
>>
>> (gdb) bt
>> #0? 0x00007f81528af270 in __nanosleep_nocancel () at
>> ../sysdeps/unix/syscall-template.S:84
>> #1? 0x00007f81528d8b84 in usleep (useconds=<optimized out>) at
>> ../sysdeps/posix/usleep.c:32
>> #2? 0x00007f815329368e in net_connect_unix_with_retries
>> (path=0x562dc200ce10 <error: Cannot access memory at address
>> 0x562dc200ce10>, msecs=msecs at entry=5000) at net.c:347
>> #3? 0x00007f815320ce0d in anvil_client_connect
>> (client=0x562dc200cda0, retry=retry at entry=true) at
anvil-client.c:136
>> #4? 0x0000562dc1429f5d in auth_penalty_init (path=0x562dc1451846
>> <error: Cannot access memory at address 0x562dc1451846>) at
>> auth-penalty.c:37
>> #5? 0x0000562dc1424166 in main_preinit () at main.c:202
>> #6? main (argc=<optimized out>, argv=<optimized out>) at
main.c:396
>>
>> (gdb) bt full
>> #1? 0x00007f81528d8b84 in usleep (useconds=<optimized out>) at
>> ../sysdeps/posix/usleep.c:32
>> ???????? ts = {tv_sec = 0, tv_nsec = 80000000}
>> #2? 0x00007f815329368e in net_connect_unix_with_retries
>> (path=0x562dc200ce10 <error: Cannot access memory at address
>> 0x562dc200ce10>, msecs=msecs at entry=5000) at net.c:347
>> ???????? start = {tv_sec = 1545319486, tv_usec = 241864}
>> ???????? now = {tv_sec = 1545319490, tv_usec = 198061}
>> ???????? fd = -1
>> #3? 0x00007f815320ce0d in anvil_client_connect
>> (client=0x562dc200cda0, retry=retry at entry=true) at
anvil-client.c:136
>> ???????? fd = <optimized out>
>> ???????? __FUNCTION__ = <error reading variable __FUNCTION__ (Cannot
>> access memory at address 0x7f81532a8260)>
>> #4? 0x0000562dc1429f5d in auth_penalty_init (path=0x562dc1451846
>> <error: Cannot access memory at address 0x562dc1451846>) at
>> auth-penalty.c:37
>> No locals.
>> #5? 0x0000562dc1424166 in main_preinit () at main.c:202
>> ???????? mod_set = <error reading variable mod_set (Cannot access
>> memory at address 0x7ffda885db80)>
>> #6? main (argc=<optimized out>, argv=<optimized out>) at
main.c:396
>> ???????? c = <optimized out>
>> Backtrace stopped: Cannot access memory at address 0x7ffda885dbf8
>> (gdb)
>>
>> Code I've read :
>>
>> src/auth/main.c: static void main_preinit(void)
>>
>> ???????? if (!worker)
>> ???????????????? auth_penalty =
>> auth_penalty_init(AUTH_PENALTY_ANVIL_PATH);
>> ???????? auth_request_stats_init();
>>
>> src/auth/auth-penalty.c: struct auth_penalty *auth_penalty_init(const
>> char *path)
>>
>> ???????? if (anvil_client_connect(penalty->client, TRUE) < 0)
>> ???????????????? penalty->disabled = TRUE;
>> ???????? else {
>>
>> src/lib-master/anvil-client.c: int anvil_client_connect(struct
>> anvil_client *client, bool retry)
>>
>> ???????? fd = retry ? net_connect_unix_with_retries(client->path,
>> 5000) :
>> ???????????????? net_connect_unix(client->path);
>>
>> src/lib/net.c : int net_connect_unix_with_retries(const char *path,
>> unsigned int msecs) {
>> ???????? struct timeval start, now;
>> ???????? int fd;
>> ???? ???????? if (gettimeofday(&start, NULL) < 0)
>> ???????????????? i_panic("gettimeofday() failed: %m");
>> ???? ???????? do {
>> ???????????????? fd = net_connect_unix(path);
>> ???????????????? if (fd != -1 || (errno != EAGAIN && errno !=
>> ECONNREFUSED))? // <------------------ HERE, I go into ECONNREFUSED
>> case during 5 seconds
>> ???????????????????????? break;
>> ???? ???????????????? /* busy. wait for a while. */
>> ???????????????? usleep(((rand() % 10) + 1) * 10000);
>> ???????????????? if (gettimeofday(&now, NULL) < 0)
>> ???????????????????????? i_panic("gettimeofday() failed:
%m");
>> ???????? } while (timeval_diff_msecs(&now, &start) <
(int)msecs);
>> ???????? return fd;
>> }
>>
>> Additionnal environment infos (mailboxes are NFS-backed) :
>>
>> lsb_release -a
>> No LSB modules are available.
>> Distributor ID:??? Debian
>> Description:??? Debian GNU/Linux 9.2 (stretch)
>> Release:??? 9.2
>> Codename:??? stretch
>>
>>
>> mount | grep ^/
>> /dev/sda1 on / type ext4 (rw,relatime,errors=remount-ro,data=ordered)
>>
>> mount | grep nfs
>> 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)
>> 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)
>> 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)
>>
>>
>>
>> telegraphe-test:~# apt-cache policy dovecot-core
>> dovecot-core:
>> ?? Install??: 1:2.2.27-3+deb9u2
>> ?? Candidat?: 1:2.2.27-3+deb9u2
>> ? Table de version?:
>> ? *** 1:2.2.27-3+deb9u2 500
>> ???????? 500http://miroir/debian? stretch/main amd64 Packages
>> ???????? 500http://security.debian.org/debian-security
>> stretch/updates/main amd64 Packages
>> ???????? 100 /var/lib/dpkg/status
>>
>> telegraphe-test:~# dovecot -n
>> # 2.2.27 (c0f36b0): /etc/dovecot/dovecot.conf
>> # Pigeonhole version 0.4.16 (fed8554)
>> doveconf: Warning: service auth { client_limit=10000 } is lower than
>> required under max. load (10240)
>> # OS: Linux 4.9.0-4-amd64 x86_64 Debian 9.2 nfs
>> auth_verbose = yes
>> default_client_limit = 10000
>> default_process_limit = 2048
>> lda_mailbox_autocreate = yes
>> lda_mailbox_autosubscribe = yes
>> mail_debug = yes
>> mail_fsync = always
>> mail_location = maildir:/var/mail/maildir/%u
>> 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 index ihave duplicate mime foreverypart
>> extracttext
>> mmap_disable = yes
>> 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 >> ?? separator = /
>> }
>> passdb {
>> ?? driver = pam
>> }
>> plugin {
>> ?? sieve
>>
=file:/var/mail/mailconf/%1u/%u/sieve;active=/var/mail/mailconf/%1u/%u/.dovecot.sieve
>> ?? sieve_before = /var/mail/mailconf/global/sieve/before.d
>> ?? sieve_global = /var/mail/mailconf/global/sieve
>> ?? sieve_vacation_dont_check_recipient = yes
>> }
>> protocols = " imap lmtp sieve sieve"
>> service anvil {
>> ?? unix_listener anvil-auth-penalty {
>> ???? mode = 00
>> ?? }
>> }
>> service lmtp {
>> ?? inet_listener lmtp {
>> ???? port = 24
>> ?? }
>> }
>> service managesieve {
>> ?? process_limit = 16
>> }
>> ssl_cert = </etc/ssl/certs/telegraphe7_cert.pem
>> ssl_key =? # hidden, use -P to show it
>> syslog_facility = local0
>> userdb {
>> ?? driver = passwd
>> }
>> verbose_proctitle = yes
>> protocol lmtp {
>> ?? auth_username_format = %n
>> ?? mail_plugins = " sieve"
>> }
>> protocol imap {
>> ?? mail_max_userip_connections = 20
>> }
>>
>>
>>
>> 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.
>>
>> Could it be saved with a dedicated config entry to disable
>> auth-penalty ?
>>
>> Is there solution to have auth-penalty working while having perdition
>> IMAP proxy ?
>>
>> Regards,
>> Ludovic Pouzenc
>> --
>> Ludovic POUZENC - Ing?nieur Syst?me
>> IMT Mines Albi? (http://www.imt-mines-albi.fr)
>> 81013 ALBI CT Cedex 09 - Tel : 05 63 49 33 56
--
Ludovic POUZENC - Ing?nieur Syst?me
IMT Mines Albi (http://www.imt-mines-albi.fr)
81013 ALBI CT Cedex 09 - Tel : 05 63 49 33 56
-------------- next part --------------
An HTML attachment was scrubbed...
URL:
<https://dovecot.org/pipermail/dovecot/attachments/20190108/8500768b/attachment-0001.html>
Possibly Parallel Threads
- Authentication/Penalty disabled (socket mode=0) introduces constant 5 sec delays (2.27 on debian 9)
- Authentication/Penalty disabled (socket mode=0) introduces constant 5 sec delays (2.27 on debian 9)
- "sieve: failed to store into mailbox 'Junk': Read-only mbox" over root_squashed NFS, lmtp : euid/egid set and access() don't mix together for me
- dovecot 2.0 vs. SELinux
- 2.2.34 fails to build on OpenBSD