Hello,
Here is the complete log of the connections, IPS x-d out, but I tried
twice, once on 587, once with smtps enabled. Any help appreciated.
Thanks.
Dave.
#tail -f /var/log/mail.log
2024-04-02T09:48:08.220604-04:00 hostname
postfix/submission/smtpd[1529]: connect from
xxx.xxx.xxx.xxx[xxx.xxx.xxx.xxx]
2024-04-02T09:48:08.220939-04:00 hostname
postfix/submission/smtpd[1529]: smtp_stream_setup: maxtime=300
enable_deadline=0 min_data_rate=0
2024-04-02T09:48:08.221246-04:00 hostname
postfix/submission/smtpd[1529]: match_hostname:
smtpd_client_event_limit_exceptions: xxx.xxx.xxx.xxx ~? 127.0.0.0/8
2024-04-02T09:48:08.221434-04:00 hostname
postfix/submission/smtpd[1529]: match_hostaddr:
smtpd_client_event_limit_exceptions: xxx.xxx.xxx.xxx ~? 127.0.0.0/8
2024-04-02T09:48:08.221704-04:00 hostname
postfix/submission/smtpd[1529]: match_list_match: xxx.xxx.xxx.xxx: no match
2024-04-02T09:48:08.221881-04:00 hostname
postfix/submission/smtpd[1529]: match_list_match: xxx.xxx.xxx.xxx: no match
2024-04-02T09:48:08.222386-04:00 hostname
postfix/submission/smtpd[1529]: auto_clnt_open: connected to private/anvil
2024-04-02T09:48:08.222577-04:00 hostname
postfix/submission/smtpd[1529]: private/anvil: wanted attribute: protocol
2024-04-02T09:48:08.222801-04:00 hostname
postfix/submission/smtpd[1529]: input attribute name: protocol
2024-04-02T09:48:08.222935-04:00 hostname
postfix/submission/smtpd[1529]: input attribute value: anvil_protocol
2024-04-02T09:48:08.223103-04:00 hostname
postfix/submission/smtpd[1529]: private/anvil: wanted attribute: (list
terminator)
2024-04-02T09:48:08.223264-04:00 hostname
postfix/submission/smtpd[1529]: input attribute name: (end)
2024-04-02T09:48:08.223453-04:00 hostname
postfix/submission/smtpd[1529]: send attr request = connect
2024-04-02T09:48:08.223579-04:00 hostname
postfix/submission/smtpd[1529]: send attr ident = submission:xxx.xxx.xxx.xxx
2024-04-02T09:48:08.223857-04:00 hostname
postfix/submission/smtpd[1529]: private/anvil: wanted attribute: status
2024-04-02T09:48:08.223987-04:00 hostname
postfix/submission/smtpd[1529]: input attribute name: status
2024-04-02T09:48:08.224153-04:00 hostname
postfix/submission/smtpd[1529]: input attribute value: 0
2024-04-02T09:48:08.224389-04:00 hostname
postfix/submission/smtpd[1529]: private/anvil: wanted attribute: count
2024-04-02T09:48:08.224565-04:00 hostname
postfix/submission/smtpd[1529]: input attribute name: count
2024-04-02T09:48:08.224734-04:00 hostname
postfix/submission/smtpd[1529]: input attribute value: 1
2024-04-02T09:48:08.225001-04:00 hostname
postfix/submission/smtpd[1529]: private/anvil: wanted attribute: rate
2024-04-02T09:48:08.225165-04:00 hostname
postfix/submission/smtpd[1529]: input attribute name: rate
2024-04-02T09:48:08.225314-04:00 hostname
postfix/submission/smtpd[1529]: input attribute value: 1
2024-04-02T09:48:08.225465-04:00 hostname
postfix/submission/smtpd[1529]: private/anvil: wanted attribute: (list
terminator)
2024-04-02T09:48:08.225610-04:00 hostname
postfix/submission/smtpd[1529]: input attribute name: (end)
2024-04-02T09:48:08.225750-04:00 hostname
postfix/submission/smtpd[1529]: > xxx.xxx.xxx.xxx[xxx.xxx.xxx.xxx]: 220
hostname.example.com ESMTP
2024-04-02T09:48:08.225896-04:00 hostname
postfix/submission/smtpd[1529]: smtp_stream_setup: maxtime=300
enable_deadline=0 min_data_rate=0
2024-04-02T09:48:08.226037-04:00 hostname
postfix/submission/smtpd[1529]: watchdog_pat: 0x55810ef6a110
2024-04-02T09:48:08.293029-04:00 hostname
postfix/submission/smtpd[1529]: < xxx.xxx.xxx.xxx[xxx.xxx.xxx.xxx]: EHLO
we-guess.mozilla.org
2024-04-02T09:48:08.293161-04:00 hostname
postfix/submission/smtpd[1529]: improper command pipelining after EHLO
from xxx.xxx.xxx.xxx[xxx.xxx.xxx.xxx]: QUIT\r\n
2024-04-02T09:48:08.293252-04:00 hostname
postfix/submission/smtpd[1529]: match_list_match: xxx.xxx.xxx.xxx: no match
2024-04-02T09:48:08.293413-04:00 hostname
postfix/submission/smtpd[1529]: match_list_match: xxx.xxx.xxx.xxx: no match
2024-04-02T09:48:08.293480-04:00 hostname
postfix/submission/smtpd[1529]: > xxx.xxx.xxx.xxx[xxx.xxx.xxx.xxx]:
250-hostname.example.com
2024-04-02T09:48:08.293547-04:00 hostname
postfix/submission/smtpd[1529]: > xxx.xxx.xxx.xxx[xxx.xxx.xxx.xxx]:
250-PIPELINING
2024-04-02T09:48:08.293613-04:00 hostname
postfix/submission/smtpd[1529]: > xxx.xxx.xxx.xxx[xxx.xxx.xxx.xxx]:
250-SIZE 52428800
2024-04-02T09:48:08.293675-04:00 hostname
postfix/submission/smtpd[1529]: > xxx.xxx.xxx.xxx[xxx.xxx.xxx.xxx]: 250-ETRN
2024-04-02T09:48:08.293738-04:00 hostname
postfix/submission/smtpd[1529]: > xxx.xxx.xxx.xxx[xxx.xxx.xxx.xxx]:
250-STARTTLS
2024-04-02T09:48:08.293801-04:00 hostname
postfix/submission/smtpd[1529]: > xxx.xxx.xxx.xxx[xxx.xxx.xxx.xxx]:
250-ENHANCEDSTATUSCODES
2024-04-02T09:48:08.293863-04:00 hostname
postfix/submission/smtpd[1529]: > xxx.xxx.xxx.xxx[xxx.xxx.xxx.xxx]:
250-8BITMIME
2024-04-02T09:48:08.293926-04:00 hostname
postfix/submission/smtpd[1529]: > xxx.xxx.xxx.xxx[xxx.xxx.xxx.xxx]: 250-DSN
2024-04-02T09:48:08.293992-04:00 hostname
postfix/submission/smtpd[1529]: > xxx.xxx.xxx.xxx[xxx.xxx.xxx.xxx]:
250-SMTPUTF8
2024-04-02T09:48:08.294065-04:00 hostname
postfix/submission/smtpd[1529]: > xxx.xxx.xxx.xxx[xxx.xxx.xxx.xxx]: 250
CHUNKING
2024-04-02T09:48:08.294135-04:00 hostname
postfix/submission/smtpd[1529]: smtp_stream_setup: maxtime=300
enable_deadline=0 min_data_rate=0
2024-04-02T09:48:08.294196-04:00 hostname
postfix/submission/smtpd[1529]: watchdog_pat: 0x55810ef6a110
2024-04-02T09:48:08.294262-04:00 hostname
postfix/submission/smtpd[1529]: < xxx.xxx.xxx.xxx[xxx.xxx.xxx.xxx]: QUIT
2024-04-02T09:48:08.294326-04:00 hostname
postfix/submission/smtpd[1529]: > xxx.xxx.xxx.xxx[xxx.xxx.xxx.xxx]: 221
2.0.0 Bye
2024-04-02T09:48:08.294391-04:00 hostname
postfix/submission/smtpd[1529]: match_hostname:
smtpd_client_event_limit_exceptions: xxx.xxx.xxx.xxx ~? 127.0.0.0/8
2024-04-02T09:48:08.294451-04:00 hostname
postfix/submission/smtpd[1529]: match_hostaddr:
smtpd_client_event_limit_exceptions: xxx.xxx.xxx.xxx ~? 127.0.0.0/8
2024-04-02T09:48:08.294512-04:00 hostname
postfix/submission/smtpd[1529]: match_list_match: xxx.xxx.xxx.xxx: no match
2024-04-02T09:48:08.294572-04:00 hostname
postfix/submission/smtpd[1529]: match_list_match: xxx.xxx.xxx.xxx: no match
2024-04-02T09:48:08.294640-04:00 hostname
postfix/submission/smtpd[1529]: send attr request = disconnect
2024-04-02T09:48:08.294704-04:00 hostname
postfix/submission/smtpd[1529]: send attr ident = submission:xxx.xxx.xxx.xxx
2024-04-02T09:48:08.294764-04:00 hostname
postfix/submission/smtpd[1529]: private/anvil: wanted attribute: status
2024-04-02T09:48:08.294826-04:00 hostname
postfix/submission/smtpd[1529]: input attribute name: status
2024-04-02T09:48:08.294887-04:00 hostname
postfix/submission/smtpd[1529]: input attribute value: 0
2024-04-02T09:48:08.294946-04:00 hostname
postfix/submission/smtpd[1529]: private/anvil: wanted attribute: (list
terminator)
2024-04-02T09:48:08.295006-04:00 hostname
postfix/submission/smtpd[1529]: input attribute name: (end)
2024-04-02T09:48:08.295097-04:00 hostname
postfix/submission/smtpd[1529]: disconnect from
xxx.xxx.xxx.xxx[xxx.xxx.xxx.xxx] ehlo=1 quit=1 commands=2
This is the port 465 atempt.
#tail -f /var/log/mail.log
2024-04-02T09:49:02.211864-04:00 hostname postfix/smtps/smtpd[1575]:
connect from xxx.xxx.xxx.xxx[xxx.xxx.xxx.xxx]
2024-04-02T09:49:02.212128-04:00 hostname postfix/smtps/smtpd[1575]:
smtp_stream_setup: maxtime=300 enable_deadline=0 min_data_rate=0
2024-04-02T09:49:02.212215-04:00 hostname postfix/smtps/smtpd[1575]:
send attr request = seed
2024-04-02T09:49:02.212294-04:00 hostname postfix/smtps/smtpd[1575]:
send attr size = 32
2024-04-02T09:49:02.212374-04:00 hostname postfix/smtps/smtpd[1575]:
private/tlsmgr: wanted attribute: status
2024-04-02T09:49:02.212458-04:00 hostname postfix/smtps/smtpd[1575]:
input attribute name: status
2024-04-02T09:49:02.212552-04:00 hostname postfix/smtps/smtpd[1575]:
input attribute value: 0
2024-04-02T09:49:02.212642-04:00 hostname postfix/smtps/smtpd[1575]:
private/tlsmgr: wanted attribute: seed
2024-04-02T09:49:02.212733-04:00 hostname postfix/smtps/smtpd[1575]:
input attribute name: seed
2024-04-02T09:49:02.212826-04:00 hostname postfix/smtps/smtpd[1575]:
input attribute value: TQH60OxX/hpi07ebSmEWL4g74EdmGTN3avxd+np2j7I=
2024-04-02T09:49:02.212913-04:00 hostname postfix/smtps/smtpd[1575]:
private/tlsmgr: wanted attribute: (list terminator)
2024-04-02T09:49:02.212998-04:00 hostname postfix/smtps/smtpd[1575]:
input attribute name: (end)
2024-04-02T09:49:02.419571-04:00 hostname postfix/smtps/smtpd[1575]:
SSL_accept error from xxx.xxx.xxx.xxx[xxx.xxx.xxx.xxx]: -1
2024-04-02T09:49:02.419716-04:00 hostname postfix/smtps/smtpd[1575]:
warning: TLS library problem: error:0A000412:SSL routines::sslv3 alert
bad certificate:../ssl/record/rec_layer_s3.c:1590:SSL alert number 42:
2024-04-02T09:49:02.419834-04:00 hostname postfix/smtps/smtpd[1575]:
smtp_stream_setup: maxtime=300 enable_deadline=0 min_data_rate=0
2024-04-02T09:49:02.419929-04:00 hostname postfix/smtps/smtpd[1575]:
match_hostname: smtpd_client_event_limit_exceptions: xxx.xxx.xxx.xxx ~?
127.0.0.0/8
2024-04-02T09:49:02.420012-04:00 hostname postfix/smtps/smtpd[1575]:
match_hostaddr: smtpd_client_event_limit_exceptions: xxx.xxx.xxx.xxx ~?
127.0.0.0/8
2024-04-02T09:49:02.420111-04:00 hostname postfix/smtps/smtpd[1575]:
match_list_match: xxx.xxx.xxx.xxx: no match
2024-04-02T09:49:02.420199-04:00 hostname postfix/smtps/smtpd[1575]:
match_list_match: xxx.xxx.xxx.xxx: no match
2024-04-02T09:49:02.420275-04:00 hostname postfix/smtps/smtpd[1575]:
auto_clnt_open: connected to private/anvil
2024-04-02T09:49:02.420356-04:00 hostname postfix/smtps/smtpd[1575]:
private/anvil: wanted attribute: protocol
2024-04-02T09:49:02.420453-04:00 hostname postfix/smtps/smtpd[1575]:
input attribute name: protocol
2024-04-02T09:49:02.420533-04:00 hostname postfix/smtps/smtpd[1575]:
input attribute value: anvil_protocol
2024-04-02T09:49:02.420615-04:00 hostname postfix/smtps/smtpd[1575]:
private/anvil: wanted attribute: (list terminator)
2024-04-02T09:49:02.420695-04:00 hostname postfix/smtps/smtpd[1575]:
input attribute name: (end)
2024-04-02T09:49:02.420782-04:00 hostname postfix/smtps/smtpd[1575]:
send attr request = disconnect
2024-04-02T09:49:02.420874-04:00 hostname postfix/smtps/smtpd[1575]:
send attr ident = smtps:xxx.xxx.xxx.xxx
2024-04-02T09:49:02.420957-04:00 hostname postfix/smtps/smtpd[1575]:
private/anvil: wanted attribute: status
2024-04-02T09:49:02.421036-04:00 hostname postfix/smtps/smtpd[1575]:
input attribute name: status
2024-04-02T09:49:02.421129-04:00 hostname postfix/smtps/smtpd[1575]:
input attribute value: 0
2024-04-02T09:49:02.421210-04:00 hostname postfix/smtps/smtpd[1575]:
private/anvil: wanted attribute: (list terminator)
2024-04-02T09:49:02.421288-04:00 hostname postfix/smtps/smtpd[1575]:
input attribute name: (end)
2024-04-02T09:49:02.421374-04:00 hostname postfix/smtps/smtpd[1575]:
lost connection after CONNECT from xxx.xxx.xxx.xxx[xxx.xxx.xxx.xxx]
2024-04-02T09:49:02.421466-04:00 hostname postfix/smtps/smtpd[1575]:
disconnect from xxx.xxx.xxx.xxx[xxx.xxx.xxx.xxx] commands=0/0
2024-04-02T09:49:25.927626-04:00 hostname postfix/smtps/smtpd[1575]:
connect from xxx.xxx.xxx.xxx[xxx.xxx.xxx.xxx]
2024-04-02T09:49:25.927819-04:00 hostname postfix/smtps/smtpd[1575]:
smtp_stream_setup: maxtime=300 enable_deadline=0 min_data_rate=0
2024-04-02T09:49:25.927883-04:00 hostname postfix/smtps/smtpd[1575]:
auto_clnt_open: connected to private/tlsmgr
2024-04-02T09:49:25.927940-04:00 hostname postfix/smtps/smtpd[1575]:
private/tlsmgr: wanted attribute: protocol
2024-04-02T09:49:25.928001-04:00 hostname postfix/smtps/smtpd[1575]:
input attribute name: protocol
2024-04-02T09:49:25.928074-04:00 hostname postfix/smtps/smtpd[1575]:
input attribute value: tlsmgr_protocol
2024-04-02T09:49:25.928161-04:00 hostname postfix/smtps/smtpd[1575]:
private/tlsmgr: wanted attribute: (list terminator)
2024-04-02T09:49:25.928226-04:00 hostname postfix/smtps/smtpd[1575]:
input attribute name: (end)
2024-04-02T09:49:25.928280-04:00 hostname postfix/smtps/smtpd[1575]:
send attr request = seed
2024-04-02T09:49:25.928332-04:00 hostname postfix/smtps/smtpd[1575]:
send attr size = 32
2024-04-02T09:49:25.928395-04:00 hostname postfix/smtps/smtpd[1575]:
private/tlsmgr: wanted attribute: status
2024-04-02T09:49:25.928448-04:00 hostname postfix/smtps/smtpd[1575]:
input attribute name: status
2024-04-02T09:49:25.928505-04:00 hostname postfix/smtps/smtpd[1575]:
input attribute value: 0
2024-04-02T09:49:25.928557-04:00 hostname postfix/smtps/smtpd[1575]:
private/tlsmgr: wanted attribute: seed
2024-04-02T09:49:25.928614-04:00 hostname postfix/smtps/smtpd[1575]:
input attribute name: seed
2024-04-02T09:49:25.928667-04:00 hostname postfix/smtps/smtpd[1575]:
input attribute value: dxMR9/tWKYBdOzREfYCLCCa75S8/fNs0Nb9cOtIhjM4=
2024-04-02T09:49:25.928722-04:00 hostname postfix/smtps/smtpd[1575]:
private/tlsmgr: wanted attribute: (list terminator)
2024-04-02T09:49:25.928774-04:00 hostname postfix/smtps/smtpd[1575]:
input attribute name: (end)
2024-04-02T09:49:26.015199-04:00 hostname dovecot: imap-login:
Disconnected: Aborted login by logging out (no auth attempts in 1 secs):
user=<>, rip=xxx.xxx.xxx.xxx, lip=190.92.151.100, session=<Db7QXx0VrS9oDWll>
2024-04-02T09:49:26.015559-04:00 hostname postfix/smtps/smtpd[1575]:
SSL_accept error from xxx.xxx.xxx.xxx[xxx.xxx.xxx.xxx]: -1
2024-04-02T09:49:26.015729-04:00 hostname postfix/smtps/smtpd[1575]:
warning: TLS library problem: error:0A000412:SSL routines::sslv3 alert
bad certificate:../ssl/record/rec_layer_s3.c:1590:SSL alert number 42:
2024-04-02T09:49:26.015818-04:00 hostname postfix/smtps/smtpd[1575]:
smtp_stream_setup: maxtime=300 enable_deadline=0 min_data_rate=0
2024-04-02T09:49:26.015875-04:00 hostname postfix/smtps/smtpd[1575]:
match_hostname: smtpd_client_event_limit_exceptions: xxx.xxx.xxx.xxx ~?
127.0.0.0/8
2024-04-02T09:49:26.015932-04:00 hostname postfix/smtps/smtpd[1575]:
match_hostaddr: smtpd_client_event_limit_exceptions: xxx.xxx.xxx.xxx ~?
127.0.0.0/8
2024-04-02T09:49:26.015985-04:00 hostname postfix/smtps/smtpd[1575]:
match_list_match: xxx.xxx.xxx.xxx: no match
2024-04-02T09:49:26.016045-04:00 hostname postfix/smtps/smtpd[1575]:
match_list_match: xxx.xxx.xxx.xxx: no match
2024-04-02T09:49:26.016142-04:00 hostname postfix/smtps/smtpd[1575]:
send attr request = disconnect
2024-04-02T09:49:26.016207-04:00 hostname postfix/smtps/smtpd[1575]:
send attr ident = smtps:xxx.xxx.xxx.xxx
2024-04-02T09:49:26.016263-04:00 hostname postfix/smtps/smtpd[1575]:
private/anvil: wanted attribute: status
2024-04-02T09:49:26.016316-04:00 hostname postfix/smtps/smtpd[1575]:
input attribute name: status
2024-04-02T09:49:26.016369-04:00 hostname postfix/smtps/smtpd[1575]:
input attribute value: 0
2024-04-02T09:49:26.016422-04:00 hostname postfix/smtps/smtpd[1575]:
private/anvil: wanted attribute: (list terminator)
2024-04-02T09:49:26.016475-04:00 hostname postfix/smtps/smtpd[1575]:
input attribute name: (end)
2024-04-02T09:49:26.016528-04:00 hostname postfix/smtps/smtpd[1575]:
lost connection after CONNECT from xxx.xxx.xxx.xxx[xxx.xxx.xxx.xxx]
2024-04-02T09:49:26.016584-04:00 hostname postfix/smtps/smtpd[1575]:
disconnect from xxx.xxx.xxx.xxx[xxx.xxx.xxx.xxx] commands=0/0
On 4/1/2024 4:17 PM, Viktor Dukhovni via Postfix-users wrote:
On Mon, Apr 01, 2024 at 04:09:34PM -0400, David Mehler via Postfix-users wrote:
In my master.cf I do have smtpd_tls_wrappermode but it's in the commented
out service for port 465, I'm using submission.
I've checked with postconf and smtpd_tls_wrappermode is set to no.
Of course, but Thunderbird might be attempting wrapper-mode (implicit
TLS), which could then be logged as a pipelining violation.
Is there any additional information I can provide?
Please keep the suggestions coming.
The full unedited log entry has already been requested. For meaningful
help, post the log entry.
--
Sent from Mozilla Thunderbird 91.13.1
_______________________________________________
Postfix-users mailing list -- postfix-users@postfix.org
To unsubscribe send an email to postfix-users-le...@postfix.org
