LL:NG 2.0.8 Manager test for external/working SMTP fails @ SSL handshake, terminates connections
I'm connecting LL:NG 2.0.8, on Fedora32, to an existing SMTP submission server.
The server (Dovecot submission proxy) is in wide, production use here, available on my LAN @
10.50.4.65 : 50465
It works with dozens of web & server apps, as well as direct submissions from Thunderbird & Outlook clients.
Looking @ LL:NG src,
src/lemonldap-ng/lemonldap-ng-portal/lib/Lemonldap/NG/Portal/Lib/SMTP.pm
I note LL:NG uses perl mailer,
https://metacpan.org/pod/Email::Sender::Transport::SMTP
where, it apppears 'ssl_options' are passed to Net::SMTP constructor for 'ssl' connections, and should be of the form for extra options in IO::Socket::SSL
https://metacpan.org/pod/IO::Socket::SSL
I've config'd LL:NG with my usual IO::Socket::SLL-type config,
SMTPServer: 10.50.4.65
SMTPPort: 50465
SMTPAuthUser: 'admin@example.net'
SMTPAuthPass: 'testpasstestpass'
SMTPTLS: ssl
SMTPTLSOpts:
SSL_hostname: int.mx.example.com
SSL_ca_file: /srv/ssl/CA.crt
SSL_cert_file: /src/ssl/llng.client.EC.crt
SSL_key_file: /src/ssl/llng.client.EC.key
SSL_cipher_list: 'ECDHE-ECDSA-CHACHA20-POLY1305:ECDHE-RSA-CHACHA20-POLY1305:ECDHE-ECDSA-AES256-GCM-SHA384:ECDHE-ECDSA-AES128-GCM-SHA256:ECDHE-RSA-AES256-GCM-SHA384:ECDHE-RSA-AES128-GCM-SHA256:ECDHE-ECDSA-AES256-SHA384:ECDHE-ECDSA-AES128-SHA256:ECDHE-RSA-AES256-SHA384:ECDHE-RSA-AES128-SHA256'
SSL_version: 'TLSv1.2'
on exec of any LL:NG Manager/UI action, a mail-attempt is triggered. I can see this in the Dovecot Submission server logs,
==> /var/log/dovecot/dovecot-debug.log <==
2020-08-24 19:46:22 submission-login: Debug: smtp-server: conn 10.0.1.30:44336 [1]: Connection created
2020-08-24 19:46:22 auth: Debug: Loading modules from directory: /usr/lib64/dovecot/auth
2020-08-24 19:46:22 auth: Debug: Module loaded: /usr/lib64/dovecot/auth/lib20_auth_var_expand_crypt.so
2020-08-24 19:46:22 auth: Debug: Module loaded: /usr/lib64/dovecot/auth/libdriver_mysql.so
2020-08-24 19:46:22 auth: Debug: Module loaded: /usr/lib64/dovecot/auth/libdriver_sqlite.so
2020-08-24 19:46:22 auth: Debug: Read auth token secret from /run/dovecot//auth-token-secret.dat
2020-08-24 19:46:22 auth: Debug: passwd-file /usr/local/etc/dovecot/sec/users.conf: Read 173 users in 0 secs
2020-08-24 19:46:22 auth: Debug: auth client connected (pid=9111)
2020-08-24 19:46:22 submission-login: Debug: smtp-server: conn 10.0.1.30:44336 [1]: Sent: 220 int.mx.example.com Dovecot ready.
2020-08-24 19:46:22 submission-login: Debug: SSL: where=0x10, ret=1: before SSL initialization
2020-08-24 19:46:22 submission-login: Debug: SSL: where=0x2001, ret=1: before SSL initialization
2020-08-24 19:46:22 submission-login: Debug: SSL: where=0x2002, ret=-1: before SSL initialization
2020-08-24 19:46:22 submission-login: Debug: SSL: where=0x2002, ret=-1: before SSL initialization
2020-08-24 19:46:27 submission-login: Debug: SSL: where=0x2002, ret=-1: before SSL initialization
!!! 2020-08-24 19:46:27 submission-login: Debug: SSL error: Connection closed
2020-08-24 19:46:27 submission-login: Debug: smtp-server: conn 10.0.1.30:44336 [1]: Connection lost: Remote disconnected
2020-08-24 19:46:27 submission-login: Debug: smtp-server: conn 10.0.1.30:44336 [1]: Disconnected: Remote closed connection
2020-08-24 19:46:27 submission-login: Debug: smtp-server: conn 10.0.1.30:44336 [1]: Connection state reset
2020-08-24 19:46:27 submission-login: Debug: SSL: where=0x2002, ret=-1: before SSL initialization
2020-08-24 19:46:27 submission-login: Debug: SSL error: Connection closed
==> /var/log/dovecot/dovecot-info.log <==
2020-08-24 19:46:27 submission-login: Info: Remote closed connection: user=<>, rip=10.0.1.30, lip=10.50.4.65, TLS handshaking: Connection closed
==> /var/log/dovecot/dovecot-debug.log <==
2020-08-24 19:46:27 submission-login: Debug: smtp-server: conn 10.0.1.30:44336 [1]: Connection destroy
2020-08-24 19:46:27 submission-login: Debug: smtp-server: conn 10.0.1.30:44336 [1]: Disconnected: Connection closed (fd=-1)
NOTE that the connection/session is terminated with no apparent helo/ehlo handshake
whereas, exploring the connection -- initiated on the LL:NG server -- directly with 'openssl s_client',
openssl s_client \
-connect 10.50.4.65:50465 \
-CAfile /srv/ssl/CA.crt \
-cert /src/ssl/llng.client.EC.crt \
-key /src/ssl/llng.client.EC.key \
-cipher ECDHE-ECDSA-CHACHA20-POLY1305:ECDHE-RSA-CHACHA20-POLY1305:ECDHE-ECDSA-AES256-GCM-SHA384:ECDHE-ECDSA-AES128-GCM-SHA256:ECDHE-RSA-AES256-GCM-SHA384:ECDHE-RSA-AES128-GCM-SHA256:ECDHE-ECDSA-AES256-SHA384:ECDHE-ECDSA-AES128-SHA256:ECDHE-RSA-AES256-SHA384:ECDHE-RSA-AES128-SHA256 \
-min_protocol TLSv1.2 \
-max_protocol TLSv1.2 \
-verify +9 \
-verify_hostname int.mx.example.com \
-verifyCAfile /srv/ssl/CA.crt \
-crlf \
-4 \
-showcerts \
-bind 10.0.1.30
220 int.mx.example.com Dovecot ready.
>>> ehlo localhost
250-int.mx.example.com
250-8BITMIME
250-AUTH PLAIN
250-BURL imap
250-CHUNKING
250-ENHANCEDSTATUSCODES
250-SIZE
250 PIPELINING
... etc etc etc ...
logs a successful connection/handshake
==> /var/log/dovecot/dovecot-debug.log <==
2020-08-24 20:44:40 submission-login: Debug: smtp-server: conn 10.0.1.30:34163 [1]: Connection created
2020-08-24 20:44:40 auth: Debug: Loading modules from directory: /usr/lib64/dovecot/auth
2020-08-24 20:44:40 auth: Debug: Module loaded: /usr/lib64/dovecot/auth/lib20_auth_var_expand_crypt.so
2020-08-24 20:44:40 auth: Debug: Module loaded: /usr/lib64/dovecot/auth/libdriver_mysql.so
2020-08-24 20:44:40 auth: Debug: Module loaded: /usr/lib64/dovecot/auth/libdriver_sqlite.so
2020-08-24 20:44:40 auth: Debug: Read auth token secret from /run/dovecot//auth-token-secret.dat
2020-08-24 20:44:40 auth: Debug: passwd-file /usr/local/etc/dovecot/sec/users.conf: Read 173 users in 0 secs
2020-08-24 20:44:40 auth: Debug: auth client connected (pid=10197)
2020-08-24 20:44:40 submission-login: Debug: smtp-server: conn 10.0.1.30:34163 [1]: Sent: 220 int.mx.example.com Dovecot ready.
2020-08-24 20:44:40 submission-login: Debug: SSL: where=0x10, ret=1: before SSL initialization
2020-08-24 20:44:40 submission-login: Debug: SSL: where=0x2001, ret=1: before SSL initialization
2020-08-24 20:44:40 submission-login: Debug: SSL: where=0x2002, ret=-1: before SSL initialization
2020-08-24 20:44:40 submission-login: Debug: SSL: where=0x2001, ret=1: before SSL initialization
!!! 2020-08-24 20:44:40 submission-login: Debug: SSL: where=0x2001, ret=1: SSLv3/TLS read client hello
!!! 2020-08-24 20:44:40 submission-login: Debug: SSL: where=0x2001, ret=1: SSLv3/TLS write server hello
2020-08-24 20:44:40 submission-login: Debug: SSL: where=0x2001, ret=1: SSLv3/TLS write certificate
2020-08-24 20:44:40 submission-login: Debug: SSL: where=0x2001, ret=1: SSLv3/TLS write key exchange
2020-08-24 20:44:40 submission-login: Debug: SSL: where=0x2001, ret=1: SSLv3/TLS write server done
2020-08-24 20:44:40 submission-login: Debug: SSL: where=0x2002, ret=-1: SSLv3/TLS write server done
2020-08-24 20:44:40 submission-login: Debug: SSL: where=0x2002, ret=-1: SSLv3/TLS write server done
2020-08-24 20:44:40 submission-login: Debug: SSL: where=0x2002, ret=-1: SSLv3/TLS write server done
2020-08-24 20:44:40 submission-login: Debug: SSL: where=0x2001, ret=1: SSLv3/TLS write server done
2020-08-24 20:44:40 submission-login: Debug: SSL: where=0x2001, ret=1: SSLv3/TLS read client key exchange
2020-08-24 20:44:40 submission-login: Debug: SSL: where=0x2001, ret=1: SSLv3/TLS read change cipher spec
2020-08-24 20:44:40 submission-login: Debug: SSL: where=0x2001, ret=1: SSLv3/TLS read finished
2020-08-24 20:44:40 submission-login: Debug: SSL: where=0x2001, ret=1: SSLv3/TLS write change cipher spec
2020-08-24 20:44:40 submission-login: Debug: SSL: where=0x2001, ret=1: SSLv3/TLS write finished
2020-08-24 20:44:40 submission-login: Debug: SSL: where=0x20, ret=1: SSL negotiation finished successfully
!!! 2020-08-24 20:44:40 submission-login: Debug: SSL: where=0x2002, ret=1: SSL negotiation finished successfully
2020-08-24 20:44:40 submission-login: Debug: smtp-server: conn 10.0.1.30:34163 [1]: Sending replies
2020-08-24 20:44:40 submission-login: Debug: smtp-server: conn 10.0.1.30:34163 [1]: No more commands pending
==> /var/log/dovecot/dovecot-info.log <==
2020-08-24 20:44:54 submission: Info: Disconnect from 10.0.1.30: Shutting down in=75 out=63 (state=MAIL FROM)
==> /var/log/dovecot/dovecot-debug.log <==
2020-08-24 20:44:54 submission-login: Debug: SSL alert: close notify
where client/server helo continues, and SSL negotiation finishes 'successfully'