Re: imap4d: unable to connect via TLS

Maurizio Avogadro <[email protected]> Fri, 18 Feb 2022 01:40:33 +0100
Newsgroups gmane.comp.gnu.mailutils.bugs
Message-ID <[email protected]>
Il 17/02/22 20:33, Sergey Poznyakoff ha scritto:
> To begin with, enable transcript in your server section:
> 
> server 0.0.0.0:993 {
>     transcript yes;
>     ...
> }
> 
>> Could the segfaults be related with the attempt Thunderbird does to
>> create the other folders (Sent, Drafts and Trash),
> 
> Judging by the output you got, it doesn't get this far.  It looks like the
> coredump occurs during TLS handshake.

It seems to occur in the authentication phase.

I attached 2 syslog snippets obtained with 'transcript yes':

- auth_plain.log is the result of an authentication attempt in PLAIN mode
   Also contains the output of ltrace and strace during a PLAIN auth attempt.

- auth_cram-md5.log is the result of two authentication attempt in "encrypted"
   mode: the client reports that password wasn't accepted and I tried to input
   it a second time, then I cancelled the attempt.

I also tried with other MUAs getting identical outcomes (some also attempt to
login with 'authenticate LOGIN', but fail just the same).

I checked and reinstalled all the dependencies.

Summing up: the only authentication method accepted seems to be from command
line, openssl s_connect, '. LOGIN <username> <password>' (which doesn't require
any hashing), every other method fails.

Can you figure out what's going on? Is there a way to get further info?

> That's intended.  If you don't need your home directory to be visible
> within your personal namespace, create a directory for imap
> (e.g. ~/.imap) and add the following to your imap4d configuration:
> 
>    namespace personal {
>      prefix "";
>      directory "$home/.imap";
>    }
> 
> Please read
> 
>   https://mailutils.org/manual/html_node/Namespace.html
> 
> for a detailed discussion on how to configure imap4d namespaces.

Thanks, this seems indeed to stop $home listing.

Thank you!
auth_plain.txt (text/plain, 12.6 KB)
Feb 18 00:29:16 mybox imap4d[64428]: TLS established using AES-128-GCM-AEAD (TLS1.3)
Feb 18 00:29:16 mybox imap4d[64428]: S: * OK IMAP4rev1
Feb 18 00:29:16 mybox imap4d[64429]: TLS established using AES-128-GCM-AEAD (TLS1.3)
Feb 18 00:29:16 mybox imap4d[64429]: S: * OK IMAP4rev1
Feb 18 00:29:16 mybox imap4d[64429]: C: 26 capability
Feb 18 00:29:16 mybox imap4d[64429]: S: * CAPABILITY IMAP4rev1 NAMESPACE ID IDLE LITERAL+ UNSELECT AUTH=GSSAPI AUTH=ANONYMOUS AUTH=EXTERNAL AUTH=LOGIN AUTH=PLAIN AUTH=SECURID AUTH=DIGEST-MD5 AUTH=CRAM-MD5 AUTH=SCRAM-SHA-1 AUTH=SCRAM-SHA-1-PLUS AUTH=SCRAM-SHA-256 AUTH=SCRAM-SHA-256-PLUS AUTH=SAML20 AUTH=OPENID20 AUTH=GSSAPI AUTH=GS2-KRB5
Feb 18 00:29:16 mybox imap4d[64429]: S: 26 OK CAPABILITY Completed
Feb 18 00:29:16 mybox imap4d[64428]: C: 43 capability
Feb 18 00:29:16 mybox imap4d[64428]: S: * CAPABILITY IMAP4rev1 NAMESPACE ID IDLE LITERAL+ UNSELECT AUTH=GSSAPI AUTH=ANONYMOUS AUTH=EXTERNAL AUTH=LOGIN AUTH=PLAIN AUTH=SECURID AUTH=DIGEST-MD5 AUTH=CRAM-MD5 AUTH=SCRAM-SHA-1 AUTH=SCRAM-SHA-1-PLUS AUTH=SCRAM-SHA-256 AUTH=SCRAM-SHA-256-PLUS AUTH=SAML20 AUTH=OPENID20 AUTH=GSSAPI AUTH=GS2-KRB5
Feb 18 00:29:16 mybox imap4d[64428]: S: 43 OK CAPABILITY Completed
Feb 18 00:29:24 mybox imap4d[64428]: C: 44 authenticate PLAIN
Feb 18 00:29:24 mybox imap4d[64429]: C: 27 authenticate PLAIN
Feb 18 00:29:24 mybox imap4d[64428]: S: +
Feb 18 00:29:24 mybox imap4d[64429]: S: +
Feb 18 00:29:24 mybox kernel: [13885.517632] imap4d[64429]: segfault at 0 ip 00007f02d3006479 sp 00007fff3bcf7b10 error 4 in libmailutils.so.8.0.0[7f02d2f70000+a4000]
Feb 18 00:29:24 mybox imap4d[64429]: C: [redacted]
Feb 18 00:29:24 mybox imap4d[63697]: process 64429 terminated on signal 11
Feb 18 00:29:24 mybox imap4d[64428]: C: [redacted]
Feb 18 00:29:24 mybox imap4d[63697]: process 64428 terminated on signal 11
Feb 18 00:29:24 mybox kernel: [13885.522479] imap4d[64428]: segfault at 0 ip 00007f02d3006479 sp 00007fff3bcf7b10 error 4 in libmailutils.so.8.0.0[7f02d2f70000+a4000]
Feb 18 00:29:24 mybox imap4d[64473]: TLS established using AES-128-GCM-AEAD (TLS1.3)
Feb 18 00:29:24 mybox imap4d[64473]: S: * OK IMAP4rev1
Feb 18 00:29:24 mybox imap4d[64474]: TLS established using AES-128-GCM-AEAD (TLS1.3)
Feb 18 00:29:24 mybox imap4d[64474]: S: * OK IMAP4rev1
Feb 18 00:29:24 mybox imap4d[64473]: C: 21 capability
Feb 18 00:29:24 mybox imap4d[64473]: S: * CAPABILITY IMAP4rev1 NAMESPACE ID IDLE LITERAL+ UNSELECT AUTH=GSSAPI AUTH=ANONYMOUS AUTH=EXTERNAL AUTH=LOGIN AUTH=PLAIN AUTH=SECURID AUTH=DIGEST-MD5 AUTH=CRAM-MD5 AUTH=SCRAM-SHA-1 AUTH=SCRAM-SHA-1-PLUS AUTH=SCRAM-SHA-256 AUTH=SCRAM-SHA-256-PLUS AUTH=SAML20 AUTH=OPENID20 AUTH=GSSAPI AUTH=GS2-KRB5
Feb 18 00:29:24 mybox imap4d[64473]: S: 21 OK CAPABILITY Completed
Feb 18 00:29:24 mybox imap4d[64474]: C: 40 capability
Feb 18 00:29:24 mybox imap4d[64474]: S: * CAPABILITY IMAP4rev1 NAMESPACE ID IDLE LITERAL+ UNSELECT AUTH=GSSAPI AUTH=ANONYMOUS AUTH=EXTERNAL AUTH=LOGIN AUTH=PLAIN AUTH=SECURID AUTH=DIGEST-MD5 AUTH=CRAM-MD5 AUTH=SCRAM-SHA-1 AUTH=SCRAM-SHA-1-PLUS AUTH=SCRAM-SHA-256 AUTH=SCRAM-SHA-256-PLUS AUTH=SAML20 AUTH=OPENID20 AUTH=GSSAPI AUTH=GS2-KRB5
Feb 18 00:29:24 mybox imap4d[64474]: S: 40 OK CAPABILITY Completed
Feb 18 00:29:24 mybox imap4d[64473]: C: 22 authenticate PLAIN
Feb 18 00:29:24 mybox imap4d[64473]: S: +
Feb 18 00:29:24 mybox imap4d[64473]: C: [redacted]
Feb 18 00:29:24 mybox kernel: [13885.839712] imap4d[64473]: segfault at 0 ip 00007f02d3006479 sp 00007fff3bcf7b10 error 4 in libmailutils.so.8.0.0[7f02d2f70000+a4000]
Feb 18 00:29:24 mybox imap4d[63697]: process 64473 terminated on signal 11
Feb 18 00:29:24 mybox imap4d[64474]: C: 41 authenticate PLAIN
Feb 18 00:29:24 mybox imap4d[64474]: S: +
Feb 18 00:29:24 mybox imap4d[64474]: C: [redacted]
Feb 18 00:29:24 mybox imap4d[63697]: process 64474 terminated on signal 11
Feb 18 00:29:24 mybox kernel: [13885.843863] imap4d[64474]: segfault at 0 ip 00007f02d3006479 sp 00007fff3bcf7b10 error 4 in libmailutils.so.8.0.0[7f02d2f70000+a4000]



##############
### ltrace ###
##############
[...]
request_init(0x7ffd2ec054b0, 2, 0x55d12341f5e0, 1)                                                                                                         = 0x7ffd2ec054b0
sock_host(0x7ffd2ec054b0, 0, 0, 0x64347061)                                                                                                                = 0
hosts_access(0x7ffd2ec054b0, 0x7f702362eae0, 0x7ffd2ec0346c, 0x7f7023350ef7)                                                                               = 1
request_init(0x7ffd2ec054b0, 2, 0x55d12341f5e0, 1)                                                                                                         = 0x7ffd2ec054b0
sock_host(0x7ffd2ec054b0, 0, 0, 0x64347061)                                                                                                                = 0
hosts_access(0x7ffd2ec054b0, 0x7f702362eae0, 0x7ffd2ec0346c, 0x7f7023350ef7)                                                                               = 1
--- SIGCHLD (Child exited) ---
--- SIGCHLD (Child exited) ---
request_init(0x7ffd2ec054b0, 2, 0x55d12341f5e0, 1)                                                                                                         = 0x7ffd2ec054b0
sock_host(0x7ffd2ec054b0, 0, 0, 0x64347061)                                                                                                                = 0
hosts_access(0x7ffd2ec054b0, 0x7f702362eae0, 0x7ffd2ec0346c, 0x7f7023350ef7)                                                                               = 1
request_init(0x7ffd2ec054b0, 2, 0x55d12341f5e0, 1)                                                                                                         = 0x7ffd2ec054b0
sock_host(0x7ffd2ec054b0, 0, 0, 0x64347061)                                                                                                                = 0
hosts_access(0x7ffd2ec054b0, 0x7f702362eae0, 0x7ffd2ec0346c, 0x7f7023350ef7)                                                                               = 1
--- SIGCHLD (Child exited) ---
--- SIGCHLD (Child exited) ---



##############
### strace ###
##############
[...]
accept(3, {sa_family=AF_INET, sin_port=htons(33898), sin_addr=inet_addr("127.0.0.1")}, [112->16]) = 5
getpid()                                = 79931
getpeername(5, {sa_family=AF_INET, sin_port=htons(33898), sin_addr=inet_addr("127.0.0.1")}, [128->16]) = 0
getsockname(5, {sa_family=AF_INET, sin_port=htons(993), sin_addr=inet_addr("127.0.0.1")}, [128->16]) = 0
openat(AT_FDCWD, "/etc/hosts.allow", O_RDONLY) = 6
newfstatat(6, "", {st_mode=S_IFREG|0644, st_size=580, ...}, AT_EMPTY_PATH) = 0
read(6, "# /etc/hosts.allow: list of host"..., 4096) = 580
read(6, "", 4096)                       = 0
close(6)                                = 0
openat(AT_FDCWD, "/etc/hosts.deny", O_RDONLY) = 6
newfstatat(6, "", {st_mode=S_IFREG|0644, st_size=880, ...}, AT_EMPTY_PATH) = 0
read(6, "# /etc/hosts.deny: list of hosts"..., 4096) = 880
read(6, "", 4096)                       = 0
close(6)                                = 0
clone(child_stack=NULL, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0x7f91fe275c50) = 79970
close(5)                                = 0
pselect6(4, [3], NULL, NULL, NULL, NULL) = 1 (in [3])
accept(3, {sa_family=AF_INET, sin_port=htons(33900), sin_addr=inet_addr("127.0.0.1")}, [112->16]) = 5
getpid()                                = 79931
getpeername(5, {sa_family=AF_INET, sin_port=htons(33900), sin_addr=inet_addr("127.0.0.1")}, [128->16]) = 0
getsockname(5, {sa_family=AF_INET, sin_port=htons(993), sin_addr=inet_addr("127.0.0.1")}, [128->16]) = 0
openat(AT_FDCWD, "/etc/hosts.allow", O_RDONLY) = 6
newfstatat(6, "", {st_mode=S_IFREG|0644, st_size=580, ...}, AT_EMPTY_PATH) = 0
read(6, "# /etc/hosts.allow: list of host"..., 4096) = 580
read(6, "", 4096)                       = 0
close(6)                                = 0
openat(AT_FDCWD, "/etc/hosts.deny", O_RDONLY) = 6
newfstatat(6, "", {st_mode=S_IFREG|0644, st_size=880, ...}, AT_EMPTY_PATH) = 0
read(6, "# /etc/hosts.deny: list of hosts"..., 4096) = 880
read(6, "", 4096)                       = 0
close(6)                                = 0
clone(child_stack=NULL, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0x7f91fe275c50) = 79971
close(5)                                = 0
pselect6(4, [3], NULL, NULL, NULL, NULL) = ? ERESTARTNOHAND (To be restarted if no handler)
--- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_KILLED, si_pid=79971, si_uid=0, si_status=SIGSEGV, si_utime=1, si_stime=0} ---
rt_sigreturn({mask=[]})                 = -1 EINTR (Interrupted system call)
wait4(-1, [{WIFSIGNALED(s) && WTERMSIG(s) == SIGSEGV}], WNOHANG, NULL) = 79971
--- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_KILLED, si_pid=79970, si_uid=0, si_status=SIGSEGV, si_utime=0, si_stime=0} ---
rt_sigreturn({mask=[]})                 = 140735474657840
getpid()                                = 79931
sendto(4, "<19>Feb 18 01:17:26 imap4d[79931"..., 72, MSG_NOSIGNAL, NULL, 0) = 72
wait4(-1, [{WIFSIGNALED(s) && WTERMSIG(s) == SIGSEGV}], WNOHANG, NULL) = 79970
getpid()                                = 79931
sendto(4, "<19>Feb 18 01:17:26 imap4d[79931"..., 72, MSG_NOSIGNAL, NULL, 0) = 72
wait4(-1, 0x7fff87f96cc4, WNOHANG, NULL) = -1 ECHILD (No child processes)
pselect6(4, [3], NULL, NULL, NULL, NULL) = 1 (in [3])
accept(3, {sa_family=AF_INET, sin_port=htons(33902), sin_addr=inet_addr("127.0.0.1")}, [112->16]) = 5
wait4(-1, 0x7fff87f96ae4, WNOHANG, NULL) = -1 ECHILD (No child processes)
getpid()                                = 79931
getpeername(5, {sa_family=AF_INET, sin_port=htons(33902), sin_addr=inet_addr("127.0.0.1")}, [128->16]) = 0
getsockname(5, {sa_family=AF_INET, sin_port=htons(993), sin_addr=inet_addr("127.0.0.1")}, [128->16]) = 0
openat(AT_FDCWD, "/etc/hosts.allow", O_RDONLY) = 6
newfstatat(6, "", {st_mode=S_IFREG|0644, st_size=580, ...}, AT_EMPTY_PATH) = 0
read(6, "# /etc/hosts.allow: list of host"..., 4096) = 580
read(6, "", 4096)                       = 0
close(6)                                = 0
openat(AT_FDCWD, "/etc/hosts.deny", O_RDONLY) = 6
newfstatat(6, "", {st_mode=S_IFREG|0644, st_size=880, ...}, AT_EMPTY_PATH) = 0
read(6, "# /etc/hosts.deny: list of hosts"..., 4096) = 880
read(6, "", 4096)                       = 0
close(6)                                = 0
clone(child_stack=NULL, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0x7f91fe275c50) = 79977
close(5)                                = 0
pselect6(4, [3], NULL, NULL, NULL, NULL) = 1 (in [3])
accept(3, {sa_family=AF_INET, sin_port=htons(33904), sin_addr=inet_addr("127.0.0.1")}, [112->16]) = 5
getpid()                                = 79931
getpeername(5, {sa_family=AF_INET, sin_port=htons(33904), sin_addr=inet_addr("127.0.0.1")}, [128->16]) = 0
getsockname(5, {sa_family=AF_INET, sin_port=htons(993), sin_addr=inet_addr("127.0.0.1")}, [128->16]) = 0
openat(AT_FDCWD, "/etc/hosts.allow", O_RDONLY) = 6
newfstatat(6, "", {st_mode=S_IFREG|0644, st_size=580, ...}, AT_EMPTY_PATH) = 0
read(6, "# /etc/hosts.allow: list of host"..., 4096) = 580
read(6, "", 4096)                       = 0
close(6)                                = 0
openat(AT_FDCWD, "/etc/hosts.deny", O_RDONLY) = 6
newfstatat(6, "", {st_mode=S_IFREG|0644, st_size=880, ...}, AT_EMPTY_PATH) = 0
read(6, "# /etc/hosts.deny: list of hosts"..., 4096) = 880
read(6, "", 4096)                       = 0
close(6)                                = 0
clone(child_stack=NULL, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0x7f91fe275c50) = 79978
close(5)                                = 0
pselect6(4, [3], NULL, NULL, NULL, NULL) = ? ERESTARTNOHAND (To be restarted if no handler)
--- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_KILLED, si_pid=79978, si_uid=0, si_status=SIGSEGV, si_utime=1, si_stime=0} ---
rt_sigreturn({mask=[]})                 = -1 EINTR (Interrupted system call)
wait4(-1, [{WIFSIGNALED(s) && WTERMSIG(s) == SIGSEGV}], WNOHANG, NULL) = 79978
getpid()                                = 79931
sendto(4, "<19>Feb 18 01:17:27 imap4d[79931"..., 72, MSG_NOSIGNAL, NULL, 0) = 72
wait4(-1, 0x7fff87f96cc4, WNOHANG, NULL) = 0
pselect6(4, [3], NULL, NULL, NULL, NULL) = ? ERESTARTNOHAND (To be restarted if no handler)
--- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_KILLED, si_pid=79977, si_uid=0, si_status=SIGSEGV, si_utime=1, si_stime=0} ---
rt_sigreturn({mask=[]})                 = -1 EINTR (Interrupted system call)
wait4(-1, [{WIFSIGNALED(s) && WTERMSIG(s) == SIGSEGV}], WNOHANG, NULL) = 79977
getpid()                                = 79931
sendto(4, "<19>Feb 18 01:17:27 imap4d[79931"..., 72, MSG_NOSIGNAL, NULL, 0) = 72
wait4(-1, 0x7fff87f96cc4, WNOHANG, NULL) = -1 ECHILD (No child processes)
pselect6(4, [3], NULL, NULL, NULL, NULL^C) = ? ERESTARTNOHAND (To be restarted if no handler)
auth_cram-md5.txt (text/plain, 2.8 KB)
Feb 18 00:29:58 mybox imap4d[64652]: TLS established using AES-128-GCM-AEAD (TLS1.3)
Feb 18 00:29:58 mybox imap4d[64652]: S: * OK IMAP4rev1
Feb 18 00:29:58 mybox imap4d[64653]: TLS established using AES-128-GCM-AEAD (TLS1.3)
Feb 18 00:29:58 mybox imap4d[64653]: S: * OK IMAP4rev1
Feb 18 00:29:58 mybox imap4d[64653]: C: 60 capability
Feb 18 00:29:58 mybox imap4d[64653]: S: * CAPABILITY IMAP4rev1 NAMESPACE ID IDLE LITERAL+ UNSELECT AUTH=GSSAPI AUTH=ANONYMOUS AUTH=EXTERNAL AUTH=LOGIN AUTH=PLAIN AUTH=SECURID AUTH=DIGEST-MD5 AUTH=CRAM-MD5 AUTH=SCRAM-SHA-1 AUTH=SCRAM-SHA-1-PLUS AUTH=SCRAM-SHA-256 AUTH=SCRAM-SHA-256-PLUS AUTH=SAML20 AUTH=OPENID20 AUTH=GSSAPI AUTH=GS2-KRB5
Feb 18 00:29:58 mybox imap4d[64653]: S: 60 OK CAPABILITY Completed
Feb 18 00:29:58 mybox imap4d[64652]: C: 40 capability
Feb 18 00:29:58 mybox imap4d[64652]: S: * CAPABILITY IMAP4rev1 NAMESPACE ID IDLE LITERAL+ UNSELECT AUTH=GSSAPI AUTH=ANONYMOUS AUTH=EXTERNAL AUTH=LOGIN AUTH=PLAIN AUTH=SECURID AUTH=DIGEST-MD5 AUTH=CRAM-MD5 AUTH=SCRAM-SHA-1 AUTH=SCRAM-SHA-1-PLUS AUTH=SCRAM-SHA-256 AUTH=SCRAM-SHA-256-PLUS AUTH=SAML20 AUTH=OPENID20 AUTH=GSSAPI AUTH=GS2-KRB5
Feb 18 00:29:58 mybox imap4d[64652]: S: 40 OK CAPABILITY Completed
Feb 18 00:29:58 mybox imap4d[64653]: C: 61 authenticate CRAM-MD5
Feb 18 00:29:58 mybox imap4d[64653]: S: + PDEyOTA2NTA1NDE0MTc4MzAzNzg0LjBAbG9jYWxob3N0Pg==
Feb 18 00:29:58 mybox imap4d[64653]: C: [redacted]
Feb 18 00:29:58 mybox imap4d[64653]: GSASL error: Autenticazione non riuscita poiché non è stata fornita la password.
Feb 18 00:29:58 mybox imap4d[64652]: C: 41 authenticate CRAM-MD5
Feb 18 00:29:58 mybox imap4d[64653]: S: 61 NO AUTHENTICATE CRAM-MD5 authentication failed
Feb 18 00:29:58 mybox imap4d[64652]: S: + PDcyNDUxNjExNjE0MDY0MDc1NjUwLjBAbG9jYWxob3N0Pg==
Feb 18 00:29:58 mybox imap4d[64652]: C: [redacted]
Feb 18 00:29:58 mybox imap4d[64652]: GSASL error: Autenticazione non riuscita poiché non è stata fornita la password.
Feb 18 00:29:58 mybox imap4d[64652]: S: 41 NO AUTHENTICATE CRAM-MD5 authentication failed
Feb 18 00:30:13 mybox imap4d[64652]: C: 43 authenticate CRAM-MD5
Feb 18 00:30:13 mybox imap4d[64652]: S: + PDMxMzI0NDU5MTgzODkyMDM2MzUyLjBAbG9jYWxob3N0Pg==
Feb 18 00:30:13 mybox imap4d[64652]: C: [redacted]
Feb 18 00:30:13 mybox imap4d[64652]: GSASL error: Autenticazione non riuscita poiché non è stata fornita la password.
Feb 18 00:30:13 mybox imap4d[64652]: S: 43 NO AUTHENTICATE CRAM-MD5 authentication failed
Feb 18 00:30:15 mybox imap4d[64652]: unexpected eof on input
Feb 18 00:30:15 mybox imap4d[64652]: read error on control stream
Feb 18 00:30:15 mybox imap4d[63697]: process 64652 finished with code 74 (I/O error)
Feb 18 00:30:16 mybox imap4d[64653]: unexpected eof on input
Feb 18 00:30:16 mybox imap4d[64653]: read error on control stream
Feb 18 00:30:16 mybox imap4d[63697]: process 64653 finished with code 74 (I/O error)