I've added an opendmarc milter to a service
[127.0.0.1]:10031 inet n - n - - smtpd
-o syslog_name=postfix/postQ-rcv
> -o milter_protocol=6
> -o smtpd_milters=inet:localhost:8893
> -o non_smtpd_milters=inet:localhost: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 listening
telnet localhost 8893
Trying ::1...
telnet: connect to address ::1: Connection refused
Trying 127.0.0.1...
Connected to localhost.
Escape character is '^]'.
on message receipt, I'm not seeing any DMARC verification or header-adds.
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.3d17f...@webmail.messagingengine.com>
Jun 26 15:24:17 mailhost postfix/qmgr[16816]: E35FC607D8:
from=<t...@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=<postmas...@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=<postmas...@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:<t...@xyzw.com> BODY=7BIT
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: extract_addr:
input: <t...@xyzw.com>
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]:
smtpd_check_addr: addr=t...@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 = t...@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: t...@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: t...@xyzw.com -> t...@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 = t...@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: t...@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:
`' -> `t...@xyzw.com' -> transp=`amavisfeed' host=`[127.0.0.1]:20003'
rcpt=`t...@xyzw.com' flags= class=default
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: ctable_locate:
install entry key t...@xyzw.com
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: extract_addr:
in: <t...@xyzw.com>, result: t...@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-bou...@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-bou...@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 t...@xyzw.com
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]:
milter_macro_lookup: result "t...@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 t...@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 t...@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:<postmas...@dddd1.com>
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: extract_addr:
input: <postmas...@dddd1.com>
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]:
smtpd_check_addr: addr=postmas...@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 = postmas...@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: postmas...@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: postmas...@dddd1.com -> postmas...@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 = postmas...@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: postmas...@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:
`' -> `postmas...@dddd1.com' -> transp=`relay2vpn'
host=`[internal.mail-backend.DDDD.com]:12345' rcpt=`postmas...@dddd1.com'
flags= class=relay
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: ctable_locate:
install entry key postmas...@dddd1.com
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]: extract_addr:
in: <postmas...@dddd1.com>, result: postmas...@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 postmas...@dddd1.com
Jun 26 15:27:19 mailhost postfix/postQ-rcv/smtpd[17019]:
milter_macro_lookup: result "postmas...@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 postmas...@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 postmas...@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.0cf22...@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=<t...@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=<postmas...@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=<postmas...@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 is the message not making it to that milter for processing?
