Welcome! Log In Create A New Profile

Advanced

STARTTLS Issue in Background Authentication with NGINX and Postfix

July 17, 2024 07:11AM
Hello,

I am making multiple Postfix servers addressable through a single address using an NGINX mail proxy.
However, I am experiencing SSL/TLS issues on port 587 or 465.

My configuration and the log outputs are as follows.

How can I resolve this issue?

/var/log/mail.log:

Jul 12 22:05:34 mail postfix/submission/smtpd[54599]: connect from unknown[my_proxy_server_ip]
Jul 12 22:05:34 mail postfix/submission/smtpd[54599]: smtp_stream_setup: maxtime=300 enable_deadline=0
Jul 12 22:05:34 mail postfix/submission/smtpd[54599]: name_mask: chunking
Jul 12 22:05:34 mail postfix/submission/smtpd[54599]: > unknown[my_proxy_server_ip]: 220 mail.mydomain.com ESMTP Postfix
Jul 12 22:05:34 mail postfix/submission/smtpd[54599]: watchdog_pat: 0x55b7b1a018f0
Jul 12 22:05:34 mail postfix/submission/smtpd[54599]: < unknown[my_proxy_server_ip]: EHLO mail.mydomain.com
Jul 12 22:05:34 mail postfix/submission/smtpd[54599]: dict_pcre_lookup: /etc/postfix/command_filter.pcre: EHLO mail.mydomain.com
Jul 12 22:05:34 mail postfix/submission/smtpd[54599]: discarding EHLO keywords: CHUNKING
Jul 12 22:05:34 mail postfix/submission/smtpd[54599]: match_list_match: unknown: no match
Jul 12 22:05:34 mail postfix/submission/smtpd[54599]: match_list_match: my_proxy_server_ip: no match
Jul 12 22:05:34 mail postfix/submission/smtpd[54599]: > unknown[my_proxy_server_ip]: 250-mail.mydomain.com
Jul 12 22:05:34 mail postfix/submission/smtpd[54599]: > unknown[my_proxy_server_ip]: 250-PIPELINING
Jul 12 22:05:34 mail postfix/submission/smtpd[54599]: > unknown[my_proxy_server_ip]: 250-SIZE 15728640
Jul 12 22:05:34 mail postfix/submission/smtpd[54599]: > unknown[my_proxy_server_ip]: 250-ETRN
Jul 12 22:05:34 mail postfix/submission/smtpd[54599]: > unknown[my_proxy_server_ip]: 250-STARTTLS
Jul 12 22:05:34 mail postfix/submission/smtpd[54599]: > unknown[my_proxy_server_ip]: 250-XCLIENT NAME ADDR PROTO HELO REVERSE_NAME PORT LOGIN DESTADDR DESTPORT
Jul 12 22:05:34 mail postfix/submission/smtpd[54599]: > unknown[my_proxy_server_ip]: 250-ENHANCEDSTATUSCODES
Jul 12 22:05:34 mail postfix/submission/smtpd[54599]: > unknown[my_proxy_server_ip]: 250-8BITMIME
Jul 12 22:05:35 mail postfix/submission/smtpd[54599]: > unknown[my_proxy_server_ip]: 250 DSN
Jul 12 22:05:35 mail postfix/submission/smtpd[54599]: watchdog_pat: 0x55b7b1a018f0
Jul 12 22:05:35 mail postfix/submission/smtpd[54599]: < unknown[my_proxy_server_ip]: XCLIENT ADDR=my_agent_ip NAME=[UNAVAILABLE]
Jul 12 22:05:35 mail postfix/submission/smtpd[54599]: dict_pcre_lookup: /etc/postfix/command_filter.pcre: XCLIENT ADDR=my_agent_ip NAME=[UNAVAILABLE]
Jul 12 22:05:35 mail postfix/submission/smtpd[54599]: match_hostname: smtpd_authorized_xclient_hosts: unknown ~? my_proxy_server_ip
Jul 12 22:05:35 mail postfix/submission/smtpd[54599]: match_hostaddr: smtpd_authorized_xclient_hosts: my_agent_ip ~? my_proxy_server_ip
Jul 12 22:05:35 mail postfix/submission/smtpd[54599]: match_list_match: unknown: no match
Jul 12 22:05:35 mail postfix/submission/smtpd[54599]: match_list_match: my_agent_ip: no match
Jul 12 22:05:35 mail postfix/submission/smtpd[54599]: match_hostname: smtpd_client_event_limit_exceptions: unknown ~? 127.0.0.1
Jul 12 22:05:35 mail postfix/submission/smtpd[54599]: match_hostaddr: smtpd_client_event_limit_exceptions: my_agent_ip ~? 127.0.0.1
Jul 12 22:05:35 mail postfix/submission/smtpd[54599]: match_hostname: smtpd_client_event_limit_exceptions: unknown ~? [::1]
Jul 12 22:05:35 mail postfix/submission/smtpd[54599]: match_hostaddr: smtpd_client_event_limit_exceptions: my_agent_ip ~? [::1]
Jul 12 22:05:35 mail postfix/submission/smtpd[54599]: match_hostname: smtpd_client_event_limit_exceptions: unknown ~? my_proxy_server_ip
Jul 12 22:05:35 mail postfix/submission/smtpd[54599]: match_hostaddr: smtpd_client_event_limit_exceptions: my_agent_ip ~? my_proxy_server_ip
Jul 12 22:05:35 mail postfix/submission/smtpd[54599]: match_hostname: smtpd_client_event_limit_exceptions: unknown ~? my_home_ip
Jul 12 22:05:35 mail postfix/submission/smtpd[54599]: match_hostaddr: smtpd_client_event_limit_exceptions: my_agent_ip ~? my_home_ip
Jul 12 22:05:35 mail postfix/submission/smtpd[54599]: match_hostname: smtpd_client_event_limit_exceptions: unknown ~? my_agent_ip
Jul 12 22:05:35 mail postfix/submission/smtpd[54599]: match_hostaddr: smtpd_client_event_limit_exceptions: my_agent_ip ~? my_agent_ip
Jul 12 22:05:35 mail postfix/submission/smtpd[54599]: name_mask: chunking
Jul 12 22:05:35 mail postfix/submission/smtpd[54599]: > unknown[my_agent_ip]: 220 mail.mydomain.com ESMTP Postfix
Jul 12 22:05:35 mail postfix/submission/smtpd[54599]: watchdog_pat: 0x55b7b1a018f0
Jul 12 22:05:35 mail postfix/submission/smtpd[54599]: < unknown[my_agent_ip]: EHLO mail.mydomain.com
Jul 12 22:05:35 mail postfix/submission/smtpd[54599]: dict_pcre_lookup: /etc/postfix/command_filter.pcre: EHLO mail.mydomain.com
Jul 12 22:05:35 mail postfix/submission/smtpd[54599]: discarding EHLO keywords: CHUNKING
Jul 12 22:05:35 mail postfix/submission/smtpd[54599]: match_list_match: unknown: no match
Jul 12 22:05:35 mail postfix/submission/smtpd[54599]: match_list_match: my_agent_ip: no match
Jul 12 22:05:35 mail postfix/submission/smtpd[54599]: > unknown[my_agent_ip]: 250-mail.mydomain.com
Jul 12 22:05:35 mail postfix/submission/smtpd[54599]: > unknown[my_agent_ip]: 250-PIPELINING
Jul 12 22:05:35 mail postfix/submission/smtpd[54599]: > unknown[my_agent_ip]: 250-SIZE 15728640
Jul 12 22:05:35 mail postfix/submission/smtpd[54599]: > unknown[my_agent_ip]: 250-ETRN
Jul 12 22:05:35 mail postfix/submission/smtpd[54599]: > unknown[my_agent_ip]: 250-STARTTLS
Jul 12 22:05:35 mail postfix/submission/smtpd[54599]: > unknown[my_agent_ip]: 250-ENHANCEDSTATUSCODES
Jul 12 22:05:35 mail postfix/submission/smtpd[54599]: > unknown[my_agent_ip]: 250-8BITMIME
Jul 12 22:05:35 mail postfix/submission/smtpd[54599]: > unknown[my_agent_ip]: 250 DSN
Jul 12 22:05:35 mail postfix/submission/smtpd[54599]: watchdog_pat: 0x55b7b1a018f0
Jul 12 22:05:35 mail postfix/submission/smtpd[54599]: < unknown[my_agent_ip]: AUTH PLAIN 77+9c2VuZGVybWFpbEBteWRvbWFpbi5jb23vv71hc2QxMjMzMjEtLQ==
Jul 12 22:05:35 mail postfix/submission/smtpd[54599]: dict_pcre_lookup: /etc/postfix/command_filter.pcre: AUTH PLAIN 77+9c2VuZGVybWFpbEBteWRvbWFpbi5jb23vv71hc2QxMjMzMjEtLQ==
Jul 12 22:05:35 mail postfix/submission/smtpd[54599]: > unknown[my_agent_ip]: 530 5.7.0 Must issue a STARTTLS command first
Jul 12 22:05:35 mail postfix/submission/smtpd[54599]: watchdog_pat: 0x55b7b1a018f0
Jul 12 22:05:35 mail postfix/submission/smtpd[54599]: smtp_get: EOF
Jul 12 22:05:35 mail postfix/submission/smtpd[54599]: match_hostname: smtpd_client_event_limit_exceptions: unknown ~? 127.0.0.1
Jul 12 22:05:35 mail postfix/submission/smtpd[54599]: match_hostaddr: smtpd_client_event_limit_exceptions: my_agent_ip ~? 127.0.0.1
Jul 12 22:05:35 mail postfix/submission/smtpd[54599]: match_hostname: smtpd_client_event_limit_exceptions: unknown ~? [::1]
Jul 12 22:05:35 mail postfix/submission/smtpd[54599]: match_hostaddr: smtpd_client_event_limit_exceptions: my_agent_ip ~? [::1]
Jul 12 22:05:35 mail postfix/submission/smtpd[54599]: match_hostname: smtpd_client_event_limit_exceptions: unknown ~? my_proxy_server_ip
Jul 12 22:05:35 mail postfix/submission/smtpd[54599]: match_hostaddr: smtpd_client_event_limit_exceptions: my_agent_ip ~? my_proxy_server_ip
Jul 12 22:05:35 mail postfix/submission/smtpd[54599]: match_hostname: smtpd_client_event_limit_exceptions: unknown ~? my_home_ip
Jul 12 22:05:35 mail postfix/submission/smtpd[54599]: match_hostaddr: smtpd_client_event_limit_exceptions: my_agent_ip ~? my_home_ip
Jul 12 22:05:35 mail postfix/submission/smtpd[54599]: match_hostname: smtpd_client_event_limit_exceptions: unknown ~? my_agent_ip
Jul 12 22:05:35 mail postfix/submission/smtpd[54599]: match_hostaddr: smtpd_client_event_limit_exceptions: my_agent_ip ~? my_agent_ip
Jul 12 22:05:35 mail postfix/submission/smtpd[54599]: lost connection after EHLO from unknown[my_agent_ip]
Jul 12 22:05:35 mail postfix/submission/smtpd[54599]: disconnect from unknown[my_agent_ip] ehlo=2 xclient=0/1 auth=0/1 commands=2/4


nginx mail proxy configuration:

mail {

server_name mail.mydomain.com;
auth_http localhost/auth/auth.php;
pop3_capabilities "TOP" "USER" "UIDL" "PIPELINING" "SASL";
imap_capabilities "IMAP4rev1" "UIDPLUS" "IDLE" "LITERAL+" "QUOTA";
smtp_capabilities "SIZE 53477376" "8BITMIME" "ENHANCEDSTATUSCODES" "PIPELINING" "DSN";

proxy_smtp_auth on;
proxy on;
proxy_pass_error_message on;
proxy_timeout 300s;

starttls on;
ssl_protocols TLSv1.2 TLSv1.3;
ssl_ciphers HIGH:!ADH:!MD5:@STRENGTH;
ssl_session_cache shared:TLSSL:16m;
ssl_session_timeout 10m;
ssl_certificate /etc/letsencrypt/live/mail.mydomain.com/fullchain.pem;
ssl_certificate_key /etc/letsencrypt/live/mail.mydomain.com/privkey.pem;
ssl_dhparam /etc/ssl/certs/dhparam.pem;

server {
listen 25;
listen [::]:25;
protocol smtp;
smtp_auth none;
starttls only;
auth_http_header PORT 25;
}

server {
listen 465 ssl;
listen [::]:465 ssl;
protocol smtp;
smtp_auth login plain;
auth_http_header PORT 465;
}

server {
listen 587;
listen [::]:587;
protocol smtp;
smtp_auth login plain;
starttls only;
auth_http_header PORT 587;
}

server {
listen 110;
listen [::]:110;
protocol pop3;
starttls only;
}

server {
listen 995 ssl;
listen [::]:995 ssl;
protocol pop3;
}

server {
listen 143;
listen [::]:143;
protocol imap;
starttls only;
}

server {
listen 993 ssl;
listen [::]:993 ssl;
protocol imap;
}
}


auth.php codes:

header("HTTP/1.0 200 OK");
header("Auth-Status: OK");
header("Auth-Server: $server");
header("Auth-Port: $port"); // If the request is using the SMTP protocol, the $port variable will be set to 587.
exit();
Subject Author Posted

STARTTLS Issue in Background Authentication with NGINX and Postfix

keljix July 17, 2024 07:11AM



Sorry, only registered users may post in this forum.

Click here to login

Online Users

Guests: 138
Record Number of Users: 8 on April 13, 2023
Record Number of Guests: 500 on July 15, 2024
Powered by nginx      Powered by FreeBSD      PHP Powered      Powered by MariaDB      ipv6 ready