[opendmarc-users] opendmarc added as postfix milter not processing, postfix logs show "abort all milters"?
PGNd
dev at pgnd.us
Fri Jun 26 20:03:26 PDT 2015
Posted this 1st at postfix list; it was suggested I bring it here.
I'm running postfix + amavisd (spf, dkim, clamav & spamassassin)
I've now added opendmarc milter to a postfix service
[127.0.0.1]:10031 inet n - n - - smtpd
-o syslog_name=postfix/postQ-rcv
> -o milter_protocol=6
> -o smtpd_milters=inet:[127.0.0.1]:8893
-o content_filter=relay2vpn:[internal.mail-backend.DDDD.com]:12345
-o receive_override_options=no_header_body_checks,no_unknown_recipient_checks,no_address_mappings
-o mynetworks=127.0.0.0/8,10.1.0.25
-o smtpd_authorized_xforward_hosts=127.0.0.0/8
-o smtpd_helo_restrictions=
-o smtpd_client_restrictions=permit_mynetworks,reject
-o smtpd_sender_restrictions=
-o smtpd_relay_restrictions=permit_mynetworks,reject
-o smtpd_recipient_restrictions=permit_mynetworks,reject
-o smtpd_data_restrictions=
-o smtpd_end_of_data_restrictions=
-o smtpd_etrn_restrictions=
opendmarc is currently config'd as
/etc/opendmarc/opendmarc.conf
MilterDebug 5
Syslog true
SyslogFacility mail
UMask 0002
UserID opendmarc
AuthservID mail.DDDD.com
AuthservIDWithJobID false
TrustedAuthservIDs localhost,mail.DDDD.com,mail-backend.DDDD.com
Background true
BaseDirectory /var/run/opendmarc
EnableCoreDumps false
IgnoreAuthenticatedClients false
PidFile /var/run/opendmarc/opendmarc.pid
HistoryFile /var/run/opendmarc/opendmarc.dat
RecordAllMessages false
RejectFailures false
ReportCommand /usr/local/sbin/sendmail -t
IgnoreHosts /etc/opendmarc/ignore.hosts
RequiredHeaders false
Socket inet:8893 at 127.0.0.1
SoftwareHeader true
SPFIgnoreResults false
SPFSelfValidate false
started, opendmarc is listening
telnet 127.0.0.1 8893
Trying 127.0.0.1...
Connected to 127.0.0.1.
Escape character is '^]'.
on message receipt, I'm not seeing any DMARC verification or header-adds.
there's no syslog output re: opendmarc.
on message submit, postfix logs show nothing milter-port-related in non-verbose mode
...
Jun 26 15:24:17 mailhost postfix/postQ-rcv/smtpd[16863]: connect from localhost[127.0.0.1]
Jun 26 15:24:17 mailhost postfix/postQ-rcv/smtpd[16863]: E35FC607D8: client=localhost[127.0.0.1], orig_queue_id=16493607B9, orig_client=out5-smtp.messagingengine.com[66.111.4.29]
Jun 26 15:24:17 mailhost postfix/cleanup[16858]: E35FC607D8: message-id=<1435365254.2685866.308941233.3D17F628 at webmail.messagingengine.com>
Jun 26 15:24:17 mailhost postfix/qmgr[16816]: E35FC607D8: from=<test at XYZW.com>, size=4466, nrcpt=1 (queue active)
Jun 26 15:24:17 mailhost postfix/postQ-rcv/smtpd[16863]: disconnect from localhost[127.0.0.1] ehlo=1 xforward=1 mail=1 rcpt=1 data=1 quit=1 commands=6
Jun 26 15:24:17 mailhost postfix/amavis-feed/smtp[16859]: 16493607B9: to=<postmaster at DDDD1.com>, relay=127.0.0.1[127.0.0.1]:20002, delay=0.86, delays=0.01/0.01/0/0.83, dsn=2.0.0, status=sent (250 2.0.0 from MTA(smtp:[127.0.0.1]:10031): 250 2.0.0 Ok: queued as E35FC607D8)
Jun 26 15:24:17 mailhost postfix/qmgr[16816]: 16493607B9: removed
Jun 26 15:24:18 mailhost postfix/relay2vpn/smtp[16865]: E35FC607D8: to=<postmaster at DDDD1.com>, relay=internal.mail-backend.DDDD.com[10.2.0.25]:12345, delay=0.55, delays=0/0.01/0.31/0.22, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as 57377102846)
Jun 26 15:24:18 mailhost postfix/qmgr[16816]: E35FC607D8: removed
turning on verbose log for the service, it appears the milter's being skipped & aborted,
...
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: process generation: 14 (14)
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: match_string: parent_domain_matches_subdomains: smtpd_client_event_limit_exceptions ~? debug_peer_list
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: match_list_match: smtpd_client_event_limit_exceptions: no match
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: match_string: parent_domain_matches_subdomains: mynetworks ~? debug_peer_list
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: match_list_match: mynetworks: no match
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: name_mask: host
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: been_here: X.X.X.142/32: 0
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: been_here: X.X.X.143/32: 0
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: mynetworks_core: X.X.X.142/32 X.X.X.143/32
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: match_string: parent_domain_matches_subdomains: mynetworks ~? debug_peer_list
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: match_list_match: mynetworks: no match
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: match_string: parent_domain_matches_subdomains: relay_domains ~? debug_peer_list
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: match_list_match: relay_domains: no match
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: database lmdb:/etc/postfix/relay_transports: using size limit 16777216 during open
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: dict_open: lmdb:/etc/postfix/relay_transports
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: match_string: parent_domain_matches_subdomains: permit_mx_backup_networks ~? debug_peer_list
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: match_list_match: permit_mx_backup_networks: no match
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: database lmdb:/etc/postfix/aliases: using size limit 16777216 during open
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: dict_open: lmdb:/etc/postfix/aliases
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: database lmdb:/etc/postfix/canonical: using size limit 16777216 during open
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: dict_open: lmdb:/etc/postfix/canonical
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: match_string: parent_domain_matches_subdomains: smtpd_access_maps ~? debug_peer_list
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: match_list_match: smtpd_access_maps: no match
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: unknown_helo_hostname_tempfail_action = defer_if_permit
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: unknown_address_tempfail_action = defer_if_permit
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: unverified_recipient_tempfail_action = defer_if_permit
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: unverified_sender_tempfail_action = defer_if_permit
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: name_mask: 0
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: auto_clnt_create: transport=local endpoint=private/tlsmgr
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: auto_clnt_open: connected to private/tlsmgr
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: send attr request = seed
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: send attr size = 32
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: private/tlsmgr: wanted attribute: status
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: input attribute name: status
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: input attribute value: 0
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: private/tlsmgr: wanted attribute: seed
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: input attribute name: seed
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: input attribute value: DNM6Z7LQhf4qkvDtx61j1cJe5z2N5YButGRFw3IPD3I=
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: private/tlsmgr: wanted attribute: (list terminator)
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: input attribute name: (end)
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: send attr request = policy
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: send attr cache_type = smtpd
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: private/tlsmgr: wanted attribute: status
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: input attribute name: status
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: input attribute value: 0
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: private/tlsmgr: wanted attribute: cachable
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: input attribute name: cachable
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: input attribute value: 0
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: private/tlsmgr: wanted attribute: timeout
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: input attribute name: timeout
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: input attribute value: 3600
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: private/tlsmgr: wanted attribute: (list terminator)
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: input attribute name: (end)
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: match_string: parent_domain_matches_subdomains: fast_flush_domains ~? debug_peer_list
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: match_list_match: fast_flush_domains: no match
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: name_mask: no_header_body_checks
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: name_mask: no_unknown_recipient_checks
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: name_mask: no_address_mappings
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: auto_clnt_create: transport=local endpoint=private/anvil
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: connection established
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: master_notify: status 0
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: name_mask: resource
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: name_mask: software
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: connect from localhost[127.0.0.1]
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: match_list_match: localhost: no match
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: match_list_match: 127.0.0.1: no match
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: match_hostname: smtpd_authorized_xforward_hosts: localhost ~? 127.0.0.0/8
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: match_hostaddr: smtpd_authorized_xforward_hosts: 127.0.0.1 ~? 127.0.0.0/8
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: smtp_stream_setup: maxtime=300 enable_deadline=0
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: match_hostname: smtpd_client_event_limit_exceptions: localhost ~? 127.0.0.0/8
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: match_hostaddr: smtpd_client_event_limit_exceptions: 127.0.0.1 ~? 127.0.0.0/8
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: name_mask: silent-discard
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: name_mask: etrn
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: name_mask: dsn
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: >>> START Client host RESTRICTIONS <<<
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: generic_checks: name=permit_mynetworks
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: permit_mynetworks: localhost 127.0.0.1
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: match_hostname: mynetworks: localhost ~? 127.0.0.0/8
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: match_hostaddr: mynetworks: 127.0.0.1 ~? 127.0.0.0/8
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: match_list_match: permit_mynetworks: no match
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: generic_checks: name=permit_mynetworks status=1
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: >>> END Client host RESTRICTIONS <<<
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: report connect to all milters
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: milter_macro_lookup: "j"
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: milter_macro_lookup: result "mailhost.DDDD.com"
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: milter_macro_lookup: "{daemon_name}"
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: milter_macro_lookup: result "mailhost.DDDD.com"
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: milter_macro_lookup: "v"
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: milter_macro_lookup: result "Postfix 3.0.1"
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: milter8_connect: non-protocol events for protocol version 4:
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: milter8_connect: transport=inet endpoint=localhost:8893
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: trying... [127.0.0.1]
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: vstream_tweak_tcp: TCP_MAXSEG 21845
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: fd=17: stream buffer size old=0 new=43690
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: milter8_connect: my_version=0x4
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: milter8_connect: my_actions=0x1ff SMFIF_ADDHDRS SMFIF_CHGBODY SMFIF_ADDRCPT SMFIF_DELRCPT SMFIF_CHGHDRS SMFIF_QUARANTINE SMFIF_CHGFROM SMFIF_ADDRCPT_PAR SMFIF_SETSYMLIST
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: milter8_connect: my_events=0x37f SMFIP_NOCONNECT SMFIP_NOHELO SMFIP_NOMAIL SMFIP_NORCPT SMFIP_NOBODY SMFIP_NOHDRS SMFIP_NOEOH SMFIP_NOUNKNOWN SMFIP_NODATA
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: milter8_connect: milter inet:localhost:8893 version 4
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: milter8_connect: events SMFIP_NOHELO SMFIP_NOBODY SMFIP_NOUNKNOWN SMFIP_NODATA
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: milter8_connect: requests SMFIF_ADDHDRS SMFIF_ADDRCPT SMFIF_QUARANTINE
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: milter8_conn_event: milter inet:localhost:8893: connect localhost/127.0.0.1
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: event: SMFIC_CONNECT; macros: j=mailhost.DDDD.com {daemon_name}=mailhost.DDDD.com v=Postfix 3.0.1
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: reply: SMFIR_ACCEPT data 0 bytes
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: > localhost[127.0.0.1]: 220 mail.DDDD.com ESMTP . No UCE permitted.
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: < localhost[127.0.0.1]: EHLO localhost
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: report helo to all milters
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: milter_macro_lookup: "{tls_version}"
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: milter_macro_lookup: "{cipher}"
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: milter_macro_lookup: "{cipher_bits}"
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: milter_macro_lookup: "{cert_subject}"
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: milter_macro_lookup: "{cert_issuer}"
>>> Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: milter8_helo_event: skip milter inet:localhost:8893
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: match_list_match: localhost: no match
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: match_list_match: 127.0.0.1: no match
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: > localhost[127.0.0.1]: 250-mailhost.DDDD.com
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: > localhost[127.0.0.1]: 250-PIPELINING
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: > localhost[127.0.0.1]: 250-SIZE 10240000
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: > localhost[127.0.0.1]: 250-VRFY
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: > localhost[127.0.0.1]: 250-STARTTLS
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: > localhost[127.0.0.1]: 250-XFORWARD NAME ADDR PROTO HELO SOURCE PORT IDENT
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: > localhost[127.0.0.1]: 250-ENHANCEDSTATUSCODES
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: > localhost[127.0.0.1]: 250 8BITMIME
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: < localhost[127.0.0.1]: XFORWARD ADDR=66.111.4.29 NAME=out5-smtp.messagingengine.com PORT=52682 PROTO=ESMTP HELO=out5-smtp.messagingengine.com SOURCE=REMOTE IDENT=4C82B607B9
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: > localhost[127.0.0.1]: 250 2.0.0 Ok
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: < localhost[127.0.0.1]: MAIL FROM:<test at XYZW.com> BODY=7BIT
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: extract_addr: input: <test at XYZW.com>
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: smtpd_check_addr: addr=test at XYZW.com
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: connect to subsystem private/rewrite
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: send attr request = rewrite
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: send attr rule = local
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: send attr address = test at XYZW.com
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: private/rewrite socket: wanted attribute: flags
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: input attribute name: flags
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: input attribute value: 0
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: private/rewrite socket: wanted attribute: address
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: input attribute name: address
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: input attribute value: test at XYZW.com
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: private/rewrite socket: wanted attribute: (list terminator)
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: input attribute name: (end)
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: rewrite_clnt: local: test at XYZW.com -> test at XYZW.com
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: send attr request = resolve
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: send attr sender =
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: send attr address = test at XYZW.com
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: private/rewrite socket: wanted attribute: flags
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: input attribute name: flags
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: input attribute value: 0
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: private/rewrite socket: wanted attribute: transport
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: input attribute name: transport
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: input attribute value: amavisfeed
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: private/rewrite socket: wanted attribute: nexthop
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: input attribute name: nexthop
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: input attribute value: [127.0.0.1]:20003
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: private/rewrite socket: wanted attribute: recipient
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: input attribute name: recipient
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: input attribute value: test at XYZW.com
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: private/rewrite socket: wanted attribute: flags
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: input attribute name: flags
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: input attribute value: 4096
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: private/rewrite socket: wanted attribute: (list terminator)
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: input attribute name: (end)
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: resolve_clnt: `' -> `test at XYZW.com' -> transp=`amavisfeed' host=`[127.0.0.1]:20003' rcpt=`test at XYZW.com' flags= class=default
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: ctable_locate: install entry key test at XYZW.com
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: extract_addr: in: <test at XYZW.com>, result: test at XYZW.com
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: send attr request = rewrite
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: send attr rule = local
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: send attr address = double-bounce
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: private/rewrite socket: wanted attribute: flags
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: input attribute name: flags
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: input attribute value: 0
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: private/rewrite socket: wanted attribute: address
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: input attribute name: address
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: input attribute value: double-bounce at mail.DDDD.com
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: private/rewrite socket: wanted attribute: (list terminator)
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: input attribute name: (end)
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: rewrite_clnt: local: double-bounce -> double-bounce at mail.DDDD.com
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: report sender to all milters
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: milter_macro_lookup: "i"
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: milter_macro_lookup: "{auth_type}"
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: milter_macro_lookup: "{auth_authen}"
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: milter_macro_lookup: "{auth_author}"
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: milter_macro_lookup: "{mail_addr}"
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: ctable_locate: leave existing entry key test at XYZW.com
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: milter_macro_lookup: result "test at XYZW.com"
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: milter_macro_lookup: "{mail_host}"
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: ctable_locate: leave existing entry key test at XYZW.com
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: milter_macro_lookup: result "[127.0.0.1]:20003"
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: milter_macro_lookup: "{mail_mailer}"
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: ctable_locate: leave existing entry key test at XYZW.com
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: milter_macro_lookup: result "amavisfeed"
>>> Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: milter8_mail_event: skip milter inet:localhost:8893
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: smtpd_check_rewrite: trying: permit_inet_interfaces
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: permit_inet_interfaces: localhost 127.0.0.1
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: fsspace: .: block size 4096, blocks free 1216777
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: smtpd_check_queue: blocks 4096 avail 1216777 min_free 0 msg_size_limit 10240000
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: > localhost[127.0.0.1]: 250 2.1.0 Ok
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: < localhost[127.0.0.1]: RCPT TO:<postmaster at DDDD1.com>
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: extract_addr: input: <postmaster at DDDD1.com>
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: smtpd_check_addr: addr=postmaster at DDDD1.com
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: send attr request = rewrite
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: send attr rule = local
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: send attr address = postmaster at DDDD1.com
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: private/rewrite socket: wanted attribute: flags
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: input attribute name: flags
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: input attribute value: 0
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: private/rewrite socket: wanted attribute: address
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: input attribute name: address
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: input attribute value: postmaster at DDDD1.com
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: private/rewrite socket: wanted attribute: (list terminator)
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: input attribute name: (end)
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: rewrite_clnt: local: postmaster at DDDD1.com -> postmaster at DDDD1.com
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: send attr request = resolve
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: send attr sender =
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: send attr address = postmaster at DDDD1.com
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: private/rewrite socket: wanted attribute: flags
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: input attribute name: flags
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: input attribute value: 0
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: private/rewrite socket: wanted attribute: transport
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: input attribute name: transport
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: input attribute value: relay2vpn
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: private/rewrite socket: wanted attribute: nexthop
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: input attribute name: nexthop
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: input attribute value: [internal.mail-backend.DDDD.com]:12345
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: private/rewrite socket: wanted attribute: recipient
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: input attribute name: recipient
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: input attribute value: postmaster at DDDD1.com
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: private/rewrite socket: wanted attribute: flags
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: input attribute name: flags
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: input attribute value: 2048
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: private/rewrite socket: wanted attribute: (list terminator)
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: input attribute name: (end)
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: resolve_clnt: `' -> `postmaster at DDDD1.com' -> transp=`relay2vpn' host=`[internal.mail-backend.DDDD.com]:12345' rcpt=`postmaster at DDDD1.com' flags= class=relay
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: ctable_locate: install entry key postmaster at DDDD1.com
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: extract_addr: in: <postmaster at DDDD1.com>, result: postmaster at DDDD1.com
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: >>> START Recipient address RESTRICTIONS <<<
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: generic_checks: name=permit_mynetworks
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: permit_mynetworks: localhost 127.0.0.1
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: match_hostname: mynetworks: localhost ~? 127.0.0.0/8
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: match_hostaddr: mynetworks: 127.0.0.1 ~? 127.0.0.0/8
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: match_list_match: permit_mynetworks: no match
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: generic_checks: name=permit_mynetworks status=1
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: >>> END Recipient address RESTRICTIONS <<<
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: >>> START Recipient address RESTRICTIONS <<<
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: generic_checks: name=permit_mynetworks
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: permit_mynetworks: localhost 127.0.0.1
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: match_hostname: mynetworks: localhost ~? 127.0.0.0/8
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: match_hostaddr: mynetworks: 127.0.0.1 ~? 127.0.0.0/8
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: match_list_match: permit_mynetworks: no match
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: generic_checks: name=permit_mynetworks status=1
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: >>> END Recipient address RESTRICTIONS <<<
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: report recipient to all milters (flags=0x0)
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: milter_macro_lookup: "i"
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: milter_macro_lookup: "{rcpt_addr}"
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: ctable_locate: leave existing entry key postmaster at DDDD1.com
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: milter_macro_lookup: result "postmaster at DDDD1.com"
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: milter_macro_lookup: "{rcpt_host}"
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: ctable_locate: leave existing entry key postmaster at DDDD1.com
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: milter_macro_lookup: result "[internal.mail-backend.DDDD.com]:12345"
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: milter_macro_lookup: "{rcpt_mailer}"
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: ctable_locate: leave existing entry key postmaster at DDDD1.com
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: milter_macro_lookup: result "relay2vpn"
>>> Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: milter8_rcpt_event: skip milter inet:localhost:8893
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: before input_transp_cleanup: cleanup flags = enable_header_body_filter enable_automatic_bcc enable_address_mapping enable_milters
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: after input_transp_cleanup: cleanup flags = enable_milters
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: name_mask: sendmail
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: name_mask: verify
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: connect to subsystem public/cleanup
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: public/cleanup socket: wanted attribute: queue_id
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: input attribute name: queue_id
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: input attribute value: 3538F607D8
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: public/cleanup socket: wanted attribute: (list terminator)
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: input attribute name: (end)
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: send attr flags = 192
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: send 0 milters
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: 3538F607D8: client=localhost[127.0.0.1], orig_queue_id=4C82B607B9, orig_client=out5-smtp.messagingengine.com[66.111.4.29]
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: > localhost[127.0.0.1]: 250 2.1.5 Ok
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: < localhost[127.0.0.1]: DATA
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: report data to all milters
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: milter_macro_lookup: "i"
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: milter_macro_lookup: result "3538F607D8"
>>> Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: milter8_data_event: skip milter inet:localhost:8893
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: send 0 milters
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: > localhost[127.0.0.1]: 354 End data with <CR><LF>.<CR><LF>
Jun 26 15:27:19 mailhost postfix/cleanup[17014]: 3538F607D8: message-id=<1435365432.2686125.308941937.0CF22F94 at webmail.messagingengine.com>
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: public/cleanup socket: wanted attribute: status
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: input attribute name: status
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: input attribute value: 0
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: public/cleanup socket: wanted attribute: reason
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: input attribute name: reason
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: input attribute value: (end)
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: public/cleanup socket: wanted attribute: (list terminator)
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: input attribute name: (end)
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: > localhost[127.0.0.1]: 250 2.0.0 Ok: queued as 3538F607D8
Jun 26 15:27:19 mailhost postfix/qmgr[16972]: 3538F607D8: from=<test at XYZW.com>, size=4462, nrcpt=1 (queue active)
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: abort all milters
>>> Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: milter8_abort: skip milter inet:localhost:8893
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: < localhost[127.0.0.1]: QUIT
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: > localhost[127.0.0.1]: 221 2.0.0 Bye
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: match_hostname: smtpd_client_event_limit_exceptions: localhost ~? 127.0.0.0/8
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: match_hostaddr: smtpd_client_event_limit_exceptions: 127.0.0.1 ~? 127.0.0.0/8
>>> Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: abort all milters
>>> Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: milter8_abort: skip milter inet:localhost:8893
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: disconnect event to all milters
>>> Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: milter8_disc_event: skip quit milter inet:localhost:8893
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: disconnect from localhost[127.0.0.1] ehlo=1 xforward=1 mail=1 rcpt=1 data=1 quit=1 commands=6
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: master_notify: status 1
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: connection closed
Jun 26 15:27:19 mailhost postfix/amavis-feed/smtp[17015]: 4C82B607B9: to=<postmaster at DDDD1.com>, relay=127.0.0.1[127.0.0.1]:20002, delay=0.93, delays=0.01/0.01/0/0.9, dsn=2.0.0, status=sent (250 2.0.0 from MTA(smtp:[127.0.0.1]:10031): 250 2.0.0 Ok: queued as 3538F607D8)
Jun 26 15:27:19 mailhost postfix/qmgr[16972]: 4C82B607B9: removed
Jun 26 15:27:19 mailhost postfix/relay2vpn/smtp[17021]: 3538F607D8: to=<postmaster at DDDD1.com>, relay=internal.mail-backend.DDDD.com[10.2.0.25]:12345, delay=0.57, delays=0.03/0.01/0.3/0.23, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as 9BBE2102846)
Jun 26 15:27:19 mailhost postfix/qmgr[16972]: 3538F607D8: removed
Jun 26 15:27:24 mailhost postfix/postQ-rcv/smtpd[17019]: auto_clnt_close: disconnect private/tlsmgr stream
Jun 26 15:27:24 mailhost postfix/postQ-rcv/smtpd[17019]: rewrite stream disconnect
Why's this being aborted/skipped?
More information about the opendmarc-users
mailing list