Funny headers_checks matching

Previous Topic Next Topic
 
classic Classic list List threaded Threaded
14 messages Options
Reply | Threaded
Open this post in threaded view
|

Funny headers_checks matching

Jures
Hi
I'm trying to replace To: header with header_checks regexp rule. The funny thing is, as I've figured out, the rule works perfectly if the Received: header is after the To: header (or missing), but does nothing if it is before the To: header. I've tried running in debug mode but couldn't get any insight to it.. I'm running postfix-2.7.1 on solaris10..

When I check it via

postmap -q - regexp/etc/postfix/header_checks < /tmp/mail.headers

I always get a match, regardless of position of the Received headers, but not via delivery..

The rule/header_checks itself is:
# cat /etc/postfix/header_checks
/^To: \+1234567\/TYPE=PLMN$/
 REPLACE To: 1919/TYPE=PLMN

And when To: is first it gets matched:
Sep 13 13:26:37 fps-mta3 postfix/smtpd[16755]: [ID 197553 mail.info] < unknown[10.40.0.20]: DATA
Sep 13 13:26:37 fps-mta3 postfix/smtpd[16755]: [ID 197553 mail.info] > unknown[10.40.0.20]: 354 End data with <CR><LF>.<CR><LF>
Sep 13 13:26:37 fps-mta3 postfix/cleanup[16757]: [ID 197553 mail.info] 4C1198C01: replace: header To: +1234567/TYPE=PLMN from unknown[10.40.0.20]; from=<+1111111/TYPE=[hidden email]> to=<[hidden email]> proto=ESMTP helo=<mta2.domain.com>: To: 1919/TYPE=PLMN
Sep 13 13:26:37 fps-mta3 postfix/cleanup[16757]: [ID 197553 mail.info] 4C1198C01: message-id=<>
Sep 13 13:26:37 fps-mta3 postfix/smtpd[16755]: [ID 197553 mail.info] public/cleanup socket: wanted attribute: status

Any ideas on this feature?

Thanks
Jure
Reply | Threaded
Open this post in threaded view
|

Re: Funny headers_checks matching

Wietse Venema
Jure Simsic:
> Hi
> I'm trying to replace To: header with header_checks regexp rule. The funny
> thing is, as I've figured out, the rule works perfectly if the Received:
> header is after the To: header (or missing), but does nothing if it is
> before the To: header. I've tried running in debug mode but couldn't get any
> insight to it.. I'm running postfix-2.7.1 on solaris10..

Please show evidence in the form of actual email messages that
the To: is replaced and is not replaced.

        Wietse
Reply | Threaded
Open this post in threaded view
|

Re: Funny headers_checks matching

Wietse Venema
Wietse Venema:

> Jure Simsic:
> > Hi
> > I'm trying to replace To: header with header_checks regexp rule. The funny
> > thing is, as I've figured out, the rule works perfectly if the Received:
> > header is after the To: header (or missing), but does nothing if it is
> > before the To: header. I've tried running in debug mode but couldn't get any
> > insight to it.. I'm running postfix-2.7.1 on solaris10..
>
> Please show evidence in the form of actual email messages that
> the To: is replaced and is not replaced.

And the corresponding Postfix logging for those messages.

        Wietse
Reply | Threaded
Open this post in threaded view
|

Re: Funny headers_checks matching

Noel Jones-2
In reply to this post by Jures
On 9/16/2010 3:02 AM, Jure Simsic wrote:

> Hi
> I'm trying to replace To: header with header_checks regexp
> rule. The funny thing is, as I've figured out, the rule works
> perfectly if the Received: header is after the To: header (or
> missing), but does nothing if it is before the To: header.
> I've tried running in debug mode but couldn't get any insight
> to it.. I'm running postfix-2.7.1 on solaris10..
>
> When I check it via
>
> postmap -q - regexp/etc/postfix/header_checks < /tmp/mail.headers
>
> I always get a match, regardless of position of the Received
> headers, but not via delivery..
>

Your conclusion that the order of the headers affects matching
is quite unlikely.  You haven't given us enough evidence to
find your error.

And why are you trying to replace the To: header anyway?


   -- Noel Jones
Reply | Threaded
Open this post in threaded view
|

Re: Funny headers_checks matching

Terry Carmen
In reply to this post by Jures
Quoting Jure Simsic <[hidden email]>:

> Hi
> I'm trying to replace To: header with header_checks regexp rule.
The funny
> thing is, as I've figured out, the rule works perfectly if the
Received:
> header is after the To: header (or missing), but does nothing if it
is
> before the To: header. I've tried running in debug mode but
couldn't get any
> insight to it.. I'm running postfix-2.7.1 on solaris10..

Post your header_checks file. There's probably something wrong with it.

Terry

Reply | Threaded
Open this post in threaded view
|

Re: Funny headers_checks matching

Jures
As the list refuses me to post such long debugs, I'm splitting my mail in two:

This is application specific mail (actually some delivery reports for MMS) and I need to do a lot of envelope and content rewrites as different operators have rather specific approach to standards.. But luckily postfix can fix this, at least when this mystery gets resolved..

Here are the specifics:

header_checks file (REGEXP):

/^To: \+1234567\/TYPE=PLMN$/
 REPLACE To: 1919/TYPE=PLMN
-------------------------------------------------
This is the mail I've been testing with, I just moved the To: header above or below Received:

EHLO mms-mta2.domain1.com
MAIL FROM:<+11111111/TYPE=[hidden email]> SIZE=2087
RCPT TO:<+1234567/TYPE=[hidden email]> ORCPT=rfc822;+2B1234567/[hidden email]
DATA
X-Mms-3GPP-MMS-Version: 6.3.0
X-Mms-Ack-Request: Yes
X-Mms-Message-Type: MM4_forward.REQ
X-Mms-Delivery-Report: Yes
Received: from smtp.domain1.com ([127.0.0.1])
.by localhost (mobi-mailv78.domain1.com [127.0.0.1]) (amavisd-new, port 10024)
To: +1234567/TYPE=PLMN
From: +11111111/TYPE=PLMN
Date: Mon, 06 Sep 2010 11:09:56 +0000
Content-Type: multipart/related; Type="application/smil"; Start="<YoCEK>"; boundary="Nokia-mm-messageHandler-BoUnDaRy-=_
-1883574436"
Sender: +11111111/TYPE=[hidden email]
X-Mms-Originator-System: [hidden email]
X-Mms-Message-ID: "TITMBAoEBgQAAEmtAAAGzAAAAHgAAAAB"
X-Mms-Transaction-ID: "TITMBAoEBgQAAEmtAAAGzAAAAHgAAAAA1"
Message-ID: <[hidden email]>
X-Mms-Originator-R/S-Delivery-Report: NO
.
QUIT
-------------------------------------------------

This are the debug logs on these tests, first the one with the To: header before Received:, hence matched:

Sep 13 13:26:37 fps-mms-mta3 postfix/smtpd[16755]: [ID 197553 mail.info] connect from unknown[10.40.0.20]
Sep 13 13:26:37 fps-mms-mta3 postfix/smtpd[16755]: [ID 197553 mail.info] match_hostname: unknown ~? 10.40.0.33/32
Sep 13 13:26:37 fps-mms-mta3 postfix/smtpd[16755]: [ID 197553 mail.info] match_hostaddr: 10.40.0.20 ~? 10.40.0.33/32
Sep 13 13:26:37 fps-mms-mta3 postfix/smtpd[16755]: [ID 197553 mail.info] match_hostname: unknown ~? 10.40.0.20/32
Sep 13 13:26:37 fps-mms-mta3 postfix/smtpd[16755]: [ID 197553 mail.info] match_hostaddr: 10.40.0.20 ~? 10.40.0.20/32
Sep 13 13:26:37 fps-mms-mta3 postfix/smtpd[16755]: [ID 197553 mail.info] > unknown[10.40.0.20]: 220 mmc.domain1.com ESMTP
Sep 13 13:26:37 fps-mms-mta3 postfix/smtpd[16755]: [ID 197553 mail.info] watchdog_pat: 8c000
Sep 13 13:26:37 fps-mms-mta3 postfix/smtpd[16755]: [ID 197553 mail.info] < unknown[10.40.0.20]: EHLO mms-mta2.domain1.com
Sep 13 13:26:37 fps-mms-mta3 postfix/smtpd[16755]: [ID 197553 mail.info] improper command pipelining after EHLO from unknown[10.40.0.20]
Sep 13 13:26:37 fps-mms-mta3 postfix/smtpd[16755]: [ID 197553 mail.info] > unknown[10.40.0.20]: 250-mms-mta3.domain1.com
Sep 13 13:26:37 fps-mms-mta3 postfix/smtpd[16755]: [ID 197553 mail.info] > unknown[10.40.0.20]: 250-PIPELINING
Sep 13 13:26:37 fps-mms-mta3 postfix/smtpd[16755]: [ID 197553 mail.info] > unknown[10.40.0.20]: 250-SIZE 10240000
Sep 13 13:26:37 fps-mms-mta3 postfix/smtpd[16755]: [ID 197553 mail.info] > unknown[10.40.0.20]: 250-VRFY
Sep 13 13:26:37 fps-mms-mta3 postfix/smtpd[16755]: [ID 197553 mail.info] match_list_match: unknown: no match
Sep 13 13:26:37 fps-mms-mta3 postfix/smtpd[16755]: [ID 197553 mail.info] match_list_match: 10.40.0.20: no match
Sep 13 13:26:37 fps-mms-mta3 postfix/smtpd[16755]: [ID 197553 mail.info] > unknown[10.40.0.20]: 250-ETRN
Sep 13 13:26:37 fps-mms-mta3 postfix/smtpd[16755]: [ID 197553 mail.info] > unknown[10.40.0.20]: 250-ENHANCEDSTATUSCODES
Sep 13 13:26:37 fps-mms-mta3 postfix/smtpd[16755]: [ID 197553 mail.info] > unknown[10.40.0.20]: 250-8BITMIME
Sep 13 13:26:37 fps-mms-mta3 postfix/smtpd[16755]: [ID 197553 mail.info] > unknown[10.40.0.20]: 250 DSN
Sep 13 13:26:37 fps-mms-mta3 postfix/smtpd[16755]: [ID 197553 mail.info] watchdog_pat: 8c000
Sep 13 13:26:37 fps-mms-mta3 postfix/smtpd[16755]: [ID 197553 mail.info] < unknown[10.40.0.20]: MAIL FROM:<+11111111/TYPE=[hidden email]> SIZE=2087
Sep 13 13:26:37 fps-mms-mta3 postfix/smtpd[16755]: [ID 197553 mail.info] extract_addr: input: <+11111111/TYPE=[hidden email]>
Sep 13 13:26:37 fps-mms-mta3 postfix/smtpd[16755]: [ID 197553 mail.info] smtpd_check_addr: addr=+11111111/TYPE=[hidden email]
Sep 13 13:26:37 fps-mms-mta3 postfix/smtpd[16755]: [ID 197553 mail.info] ctable_locate: move existing entry key +11111111/TYPE=[hidden email]
Sep 13 13:26:37 fps-mms-mta3 postfix/smtpd[16755]: [ID 197553 mail.info] extract_addr: in: <+11111111/TYPE=[hidden email]>, result: +11111111/TYPE=[hidden email]
Sep 13 13:26:37 fps-mms-mta3 postfix/smtpd[16755]: [ID 197553 mail.info] fsspace: .: block size 512, blocks free 10195766
Sep 13 13:26:37 fps-mms-mta3 postfix/smtpd[16755]: [ID 197553 mail.info] smtpd_check_queue: blocks 512 avail 10195766 min_free 0 msg_size_limit 10240000
Sep 13 13:26:37 fps-mms-mta3 postfix/smtpd[16755]: [ID 197553 mail.info] > unknown[10.40.0.20]: 250 2.1.0 Ok
Sep 13 13:26:37 fps-mms-mta3 postfix/smtpd[16755]: [ID 197553 mail.info] watchdog_pat: 8c000
Sep 13 13:26:37 fps-mms-mta3 postfix/smtpd[16755]: [ID 197553 mail.info] < unknown[10.40.0.20]: RCPT TO:<+1234567/TYPE=[hidden email]> ORCPT=rfc822;+2B1234567/[hidden email]
Sep 13 13:26:37 fps-mms-mta3 postfix/smtpd[16755]: [ID 197553 mail.info] extract_addr: input: <+1234567/TYPE=[hidden email]>
Sep 13 13:26:37 fps-mms-mta3 postfix/smtpd[16755]: [ID 197553 mail.info] smtpd_check_addr: addr=+1234567/TYPE=[hidden email]
Sep 13 13:26:37 fps-mms-mta3 postfix/smtpd[16755]: [ID 197553 mail.info] ctable_locate: move existing entry key +1234567/TYPE=[hidden email]
Sep 13 13:26:37 fps-mms-mta3 postfix/smtpd[16755]: [ID 197553 mail.info] extract_addr: in: <+1234567/TYPE=[hidden email]>, result: +1234567/TYPE=[hidden email]
Sep 13 13:26:37 fps-mms-mta3 postfix/smtpd[16755]: [ID 197553 mail.info] >>> START Recipient address RESTRICTIONS <<<
Sep 13 13:26:37 fps-mms-mta3 postfix/smtpd[16755]: [ID 197553 mail.info] generic_checks: name=permit_mynetworks
Sep 13 13:26:37 fps-mms-mta3 postfix/smtpd[16755]: [ID 197553 mail.info] permit_mynetworks: unknown 10.40.0.20
Sep 13 13:26:37 fps-mms-mta3 postfix/smtpd[16755]: [ID 197553 mail.info] match_hostname: unknown ~? 10.40.0.33/32
Sep 13 13:26:37 fps-mms-mta3 postfix/smtpd[16755]: [ID 197553 mail.info] match_hostaddr: 10.40.0.20 ~? 10.40.0.33/32
Sep 13 13:26:37 fps-mms-mta3 postfix/smtpd[16755]: [ID 197553 mail.info] match_hostname: unknown ~? 10.40.0.20/32
Sep 13 13:26:37 fps-mms-mta3 postfix/smtpd[16755]: [ID 197553 mail.info] match_hostaddr: 10.40.0.20 ~? 10.40.0.20/32
Sep 13 13:26:37 fps-mms-mta3 postfix/smtpd[16755]: [ID 197553 mail.info] generic_checks: name=permit_mynetworks status=1
Sep 13 13:26:37 fps-mms-mta3 postfix/smtpd[16755]: [ID 197553 mail.info] >>> CHECKING RECIPIENT MAPS <<<
Sep 13 13:26:37 fps-mms-mta3 postfix/smtpd[16755]: [ID 197553 mail.info] ctable_locate: leave existing entry key +1234567/TYPE=[hidden email]
Sep 13 13:26:37 fps-mms-mta3 postfix/smtpd[16755]: [ID 197553 mail.info] dict_regexp_lookup: /etc/postfix/canonical-recipient: +1234567/type=[hidden email]
Sep 13 13:26:37 fps-mms-mta3 postfix/smtpd[16755]: [ID 197553 mail.info] maps_find: recipient_canonical_maps: regexp:/etc/postfix/canonical-recipient(0,lock|fold_fix): +1234567/type=[hidden email] = [hidden email]
Sep 13 13:26:37 fps-mms-mta3 postfix/smtpd[16755]: [ID 197553 mail.info] mail_addr_find: +1234567/type=[hidden email] -> [hidden email]
Sep 13 13:26:37 fps-mms-mta3 postfix/smtpd[16755]: [ID 197553 mail.info] smtpd_check_rewrite: trying: permit_inet_interfaces
Sep 13 13:26:37 fps-mms-mta3 postfix/smtpd[16755]: [ID 197553 mail.info] permit_inet_interfaces: unknown 10.40.0.20
Sep 13 13:26:37 fps-mms-mta3 postfix/smtpd[16755]: [ID 197553 mail.info] before input_transp_cleanup: cleanup flags = enable_header_body_filter enable_automatic_bcc enable_address_mapping enable_milters
Sep 13 13:26:37 fps-mms-mta3 postfix/smtpd[16755]: [ID 197553 mail.info] after input_transp_cleanup: cleanup flags = enable_header_body_filter enable_automatic_bcc enable_address_mapping
Sep 13 13:26:37 fps-mms-mta3 postfix/smtpd[16755]: [ID 197553 mail.info] connect to subsystem public/cleanup
Sep 13 13:26:37 fps-mms-mta3 postfix/smtpd[16755]: [ID 197553 mail.info] public/cleanup socket: wanted attribute: queue_id
Sep 13 13:26:37 fps-mms-mta3 postfix/smtpd[16755]: [ID 197553 mail.info] input attribute name: queue_id
Sep 13 13:26:37 fps-mms-mta3 postfix/smtpd[16755]: [ID 197553 mail.info] input attribute value: 4C1198C01
Sep 13 13:26:37 fps-mms-mta3 postfix/smtpd[16755]: [ID 197553 mail.info] public/cleanup socket: wanted attribute: (list terminator)
Sep 13 13:26:37 fps-mms-mta3 postfix/smtpd[16755]: [ID 197553 mail.info] input attribute name: (end)
Sep 13 13:26:37 fps-mms-mta3 postfix/smtpd[16755]: [ID 197553 mail.info] send attr flags = 178
Sep 13 13:26:37 fps-mms-mta3 postfix/smtpd[16755]: [ID 197553 mail.info] 4C1198C01: client=unknown[10.40.0.20]
Sep 13 13:26:37 fps-mms-mta3 postfix/smtpd[16755]: [ID 197553 mail.info] > unknown[10.40.0.20]: 250 2.1.5 Ok
Sep 13 13:26:37 fps-mms-mta3 postfix/smtpd[16755]: [ID 197553 mail.info] watchdog_pat: 8c000
Sep 13 13:26:37 fps-mms-mta3 postfix/smtpd[16755]: [ID 197553 mail.info] < unknown[10.40.0.20]: DATA
Sep 13 13:26:37 fps-mms-mta3 postfix/smtpd[16755]: [ID 197553 mail.info] > unknown[10.40.0.20]: 354 End data with <CR><LF>.<CR><LF>
Sep 13 13:26:37 fps-mms-mta3 postfix/cleanup[16757]: [ID 197553 mail.info] 4C1198C01: replace: header To: +1234567/TYPE=PLMN from unknown[10.40.0.20]; from=<+11111111/TYPE=[hidden email]> to=<[hidden email]> proto=ESMTP helo=<mms-mta2.domain1.com>: To: 1919/TYPE=PLMN
Sep 13 13:26:37 fps-mms-mta3 postfix/cleanup[16757]: [ID 197553 mail.info] 4C1198C01: message-id=<>
Sep 13 13:26:37 fps-mms-mta3 postfix/smtpd[16755]: [ID 197553 mail.info] public/cleanup socket: wanted attribute: status
Sep 13 13:26:37 fps-mms-mta3 postfix/smtpd[16755]: [ID 197553 mail.info] input attribute name: status
Sep 13 13:26:37 fps-mms-mta3 postfix/smtpd[16755]: [ID 197553 mail.info] input attribute value: 0
Sep 13 13:26:37 fps-mms-mta3 postfix/smtpd[16755]: [ID 197553 mail.info] public/cleanup socket: wanted attribute: reason
Sep 13 13:26:37 fps-mms-mta3 postfix/smtpd[16755]: [ID 197553 mail.info] input attribute name: reason
Sep 13 13:26:37 fps-mms-mta3 postfix/smtpd[16755]: [ID 197553 mail.info] input attribute value: (end)
Sep 13 13:26:37 fps-mms-mta3 postfix/qmgr[16753]: [ID 197553 mail.info] 4C1198C01: from=<+11111111/TYPE=[hidden email]>, size=1017, nrcpt=1 (queue active)
Sep 13 13:26:37 fps-mms-mta3 postfix/smtpd[16755]: [ID 197553 mail.info] public/cleanup socket: wanted attribute: (list terminator)
Sep 13 13:26:37 fps-mms-mta3 postfix/smtpd[16755]: [ID 197553 mail.info] input attribute name: (end)
Sep 13 13:26:37 fps-mms-mta3 postfix/smtpd[16755]: [ID 197553 mail.info] > unknown[10.40.0.20]: 250 2.0.0 Ok: queued as 4C1198C01
Sep 13 13:26:37 fps-mms-mta3 postfix/smtpd[16755]: [ID 197553 mail.info] watchdog_pat: 8c000
Sep 13 13:26:37 fps-mms-mta3 postfix/smtpd[16755]: [ID 197553 mail.info] < unknown[10.40.0.20]: QUIT
Sep 13 13:26:37 fps-mms-mta3 postfix/smtpd[16755]: [ID 197553 mail.info] > unknown[10.40.0.20]: 221 2.0.0 Bye
Sep 13 13:26:37 fps-mms-mta3 postfix/smtpd[16755]: [ID 197553 mail.info] smtp_flush: EOF
Sep 13 13:26:37 fps-mms-mta3 postfix/smtpd[16755]: [ID 197553 mail.info] match_hostname: unknown ~? 10.40.0.33/32
Sep 13 13:26:37 fps-mms-mta3 postfix/smtpd[16755]: [ID 197553 mail.info] match_hostaddr: 10.40.0.20 ~? 10.40.0.33/32
Sep 13 13:26:37 fps-mms-mta3 postfix/smtpd[16755]: [ID 197553 mail.info] match_hostname: unknown ~? 10.40.0.20/32
Sep 13 13:26:37 fps-mms-mta3 postfix/smtpd[16755]: [ID 197553 mail.info] match_hostaddr: 10.40.0.20 ~? 10.40.0.20/32
Sep 13 13:26:37 fps-mms-mta3 postfix/smtpd[16755]: [ID 197553 mail.info] lost connection after QUIT from unknown[10.40.0.20]
Sep 13 13:26:37 fps-mms-mta3 postfix/smtpd[16755]: [ID 197553 mail.info] disconnect from unknown[10.40.0.20]
Sep 13 13:26:37 fps-mms-mta3 postfix/smtp[16758]: [ID 197553 mail.info] 4C1198C01: to=<[hidden email]>, orig_to=<+1234567/TYPE=[hidden email]>, relay=10.40.0.75[10.40.0.75]:25, delay=0.03, delays=0.02/0/0/0.01, dsn=2.0.0, status=sent (250 <4C2C5DE400179E4C> Mail accepted)
Sep 13 13:26:37 fps-mms-mta3 postfix/qmgr[16753]: [ID 197553 mail.info] 4C1198C01: removed
Reply | Threaded
Open this post in threaded view
|

Re: Funny headers_checks matching

Jures
Part two:

And here it is with the reverse order (Received: before To:), hence missed (had to delete some generic parts to post):

Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] connect from unknown[10.40.0.20]
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] match_hostname: unknown ~? 10.40.0.33/32
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] match_hostaddr: 10.40.0.20 ~? 10.40.0.33/32
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] match_hostname: unknown ~? 10.40.0.20/32
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] match_hostaddr: 10.40.0.20 ~? 10.40.0.20/32
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] > unknown[10.40.0.20]: 220 mmc.domain1.com ESMTP
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] watchdog_pat: 8c000
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] < unknown[10.40.0.20]: EHLO mms-mta2.domain1.com
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] improper command pipelining after EHLO from unknown[10.40.0.20]
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] > unknown[10.40.0.20]: 250-mms-mta3.domain1.com
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] > unknown[10.40.0.20]: 250-PIPELINING
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] > unknown[10.40.0.20]: 250-SIZE 10240000
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] > unknown[10.40.0.20]: 250-VRFY
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] match_list_match: unknown: no match
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] match_list_match: 10.40.0.20: no match
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] > unknown[10.40.0.20]: 250-ETRN
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] > unknown[10.40.0.20]: 250-ENHANCEDSTATUSCODES
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] > unknown[10.40.0.20]: 250-8BITMIME
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] > unknown[10.40.0.20]: 250 DSN
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] watchdog_pat: 8c000
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] < unknown[10.40.0.20]: MAIL FROM:<+11111111/TYPE=[hidden email]> SIZE=2087
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] extract_addr: input: <+11111111/TYPE=[hidden email]>
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] smtpd_check_addr: addr=+11111111/TYPE=[hidden email]
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] connect to subsystem private/rewrite
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] send attr request = rewrite
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] send attr rule = local
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] send attr address = +11111111/TYPE=[hidden email]
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] private/rewrite socket: wanted attribute: flags
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] input attribute name: flags
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] input attribute value: 0
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] private/rewrite socket: wanted attribute: address
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] input attribute name: address
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] input attribute value: +11111111/TYPE=[hidden email]
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] private/rewrite socket: wanted attribute: (list terminator)
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] input attribute name: (end)
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] rewrite_clnt: local: +11111111/TYPE=[hidden email] -> +11111111/TYPE=[hidden email]
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] send attr request = resolve
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] send attr sender =
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] send attr address = +11111111/TYPE=[hidden email]
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] private/rewrite socket: wanted attribute: flags
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] input attribute name: flags
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] input attribute value: 0
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] private/rewrite socket: wanted attribute: transport
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] input attribute name: transport
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] input attribute value: smtp
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] private/rewrite socket: wanted attribute: nexthop
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] input attribute name: nexthop
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] input attribute value: mms.domain2.com
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] private/rewrite socket: wanted attribute: recipient
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] input attribute name: recipient
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] input attribute value: +11111111/TYPE=[hidden email]
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] private/rewrite socket: wanted attribute: flags
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] input attribute name: flags
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] input attribute value: 4096
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] private/rewrite socket: wanted attribute: (list terminator)
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] input attribute name: (end)
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] resolve_clnt: `' -> `+11111111/TYPE=[hidden email]' -> transp=`smtp' host=`mms.domain2.com' rcpt=`+11111111/TYPE=[hidden email]' flags= class=default
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] ctable_locate: install entry key +11111111/TYPE=[hidden email]
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] extract_addr: in: <+11111111/TYPE=[hidden email]>, result: +11111111/TYPE=[hidden email]
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] fsspace: .: block size 512, blocks free 10195766
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] smtpd_check_queue: blocks 512 avail 10195766 min_free 0 msg_size_limit 10240000
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] > unknown[10.40.0.20]: 250 2.1.0 Ok
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] watchdog_pat: 8c000
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] < unknown[10.40.0.20]: RCPT TO:<+1234567/TYPE=[hidden email]> ORCPT=rfc822;+2B1234567/[hidden email]
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] extract_addr: input: <+1234567/TYPE=[hidden email]>
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] smtpd_check_addr: addr=+1234567/TYPE=[hidden email]
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] send attr request = rewrite
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] send attr rule = local
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] send attr address = +1234567/TYPE=[hidden email]
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] private/rewrite socket: wanted attribute: flags
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] input attribute name: flags
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] input attribute value: 0
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] private/rewrite socket: wanted attribute: address
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] input attribute name: address
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] input attribute value: +1234567/TYPE=[hidden email]
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] private/rewrite socket: wanted attribute: (list terminator)
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] input attribute name: (end)
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] rewrite_clnt: local: +1234567/TYPE=[hidden email] -> +1234567/TYPE=[hidden email]
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] send attr request = resolve
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] send attr sender =
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] send attr address = +1234567/TYPE=[hidden email]
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] private/rewrite socket: wanted attribute: flags
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] input attribute name: flags
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] input attribute value: 0
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] private/rewrite socket: wanted attribute: transport
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] input attribute name: transport
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] input attribute value: smtp
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] private/rewrite socket: wanted attribute: nexthop
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] input attribute name: nexthop
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] input attribute value: 10.40.0.75
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] private/rewrite socket: wanted attribute: recipient
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] input attribute name: recipient
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] input attribute value: +1234567/TYPE=[hidden email]
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] private/rewrite socket: wanted attribute: flags
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] input attribute name: flags
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] input attribute value: 2048
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] private/rewrite socket: wanted attribute: (list terminator)
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] input attribute name: (end)
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] resolve_clnt: `' -> `+1234567/TYPE=[hidden email]' -> transp=`smtp' host=`10.40.0.75' rcpt=`+1234567/TYPE=[hidden email]' flags= class=relay
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] ctable_locate: install entry key +1234567/TYPE=[hidden email]
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] extract_addr: in: <+1234567/TYPE=[hidden email]>, result: +1234567/TYPE=[hidden email]
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] send attr request = rewrite
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] send attr rule = local
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] send attr address = double-bounce
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] private/rewrite socket: wanted attribute: flags
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] input attribute name: flags
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] input attribute value: 0
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] private/rewrite socket: wanted attribute: address
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] input attribute name: address
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] input attribute value: [hidden email]
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] private/rewrite socket: wanted attribute: (list terminator)
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] input attribute name: (end)
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] rewrite_clnt: local: double-bounce -> [hidden email]
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] >>> START Recipient address RESTRICTIONS <<<
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] generic_checks: name=permit_mynetworks
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] permit_mynetworks: unknown 10.40.0.20
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] match_hostname: unknown ~? 10.40.0.33/32
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] match_hostaddr: 10.40.0.20 ~? 10.40.0.33/32
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] match_hostname: unknown ~? 10.40.0.20/32
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] match_hostaddr: 10.40.0.20 ~? 10.40.0.20/32
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] generic_checks: name=permit_mynetworks status=1
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] >>> CHECKING RECIPIENT MAPS <<<
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] ctable_locate: leave existing entry key +1234567/TYPE=[hidden email]
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] dict_regexp_lookup: /etc/postfix/canonical-recipient: +1234567/type=[hidden email]
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] maps_find: recipient_canonical_maps: regexp:/etc/postfix/canonical-recipient(0,lock|fold_fix): +1234567/type=[hidden email] = [hidden email]
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] mail_addr_find: +1234567/type=[hidden email] -> [hidden email]
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] smtpd_check_rewrite: trying: permit_inet_interfaces
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] permit_inet_interfaces: unknown 10.40.0.20
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] before input_transp_cleanup: cleanup flags = enable_header_body_filter enable_automatic_bcc enable_address_mapping enable_milters
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] after input_transp_cleanup: cleanup flags = enable_header_body_filter enable_automatic_bcc enable_address_mapping
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] connect to subsystem public/cleanup
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] public/cleanup socket: wanted attribute: queue_id
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] input attribute name: queue_id
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] input attribute value: 22FA58C00
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] public/cleanup socket: wanted attribute: (list terminator)
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] input attribute name: (end)
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] send attr flags = 178
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] 22FA58C00: client=unknown[10.40.0.20]
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] > unknown[10.40.0.20]: 250 2.1.5 Ok
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] watchdog_pat: 8c000
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] < unknown[10.40.0.20]: DATA
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] > unknown[10.40.0.20]: 354 End data with <CR><LF>.<CR><LF>
Sep 13 13:25:16 fps-mms-mta3 postfix/cleanup[16757]: [..info] 22FA58C00: message-id=<>
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] public/cleanup socket: wanted attribute: status
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] input attribute name: status
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] input attribute value: 0
Sep 13 13:25:16 fps-mms-mta3 postfix/qmgr[16753]: [..info] 22FA58C00: from=<+11111111/TYPE=[hidden email]>, size=1025, nrcpt=1 (queue active)
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] public/cleanup socket: wanted attribute: reason
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] input attribute name: reason
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] input attribute value: (end)
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] public/cleanup socket: wanted attribute: (list terminator)
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] input attribute name: (end)
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] > unknown[10.40.0.20]: 250 2.0.0 Ok: queued as 22FA58C00
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] watchdog_pat: 8c000
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] < unknown[10.40.0.20]: QUIT
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] > unknown[10.40.0.20]: 221 2.0.0 Bye
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] smtp_flush: EOF
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] match_hostname: unknown ~? 10.40.0.33/32
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] match_hostaddr: 10.40.0.20 ~? 10.40.0.33/32
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] match_hostname: unknown ~? 10.40.0.20/32
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] match_hostaddr: 10.40.0.20 ~? 10.40.0.20/32
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] lost connection after QUIT from unknown[10.40.0.20]
Sep 13 13:25:16 mta3 pfx/smtpd[16755]: [..info] disconnect from unknown[10.40.0.20]
Sep 13 13:25:16 fps-mms-mta3 postfix/smtp[16758]: [..info] 22FA58C00: to=<[hidden email]>, orig_to=<+1234567/TYPE=[hidden email]>, relay=10.40.0.75[10.40.0.75]:25, delay=0.09, delays=0.05/0.02/0/0.01, dsn=2.0.0, status=sent (250 <4C2C5CBF0018CC11> Mail accepted)
Sep 13 13:25:16 fps-mms-mta3 postfix/qmgr[16753]: [..info] 22FA58C00: removed

Reply | Threaded
Open this post in threaded view
|

Re: Funny headers_checks matching

Wietse Venema
In reply to this post by Jures
Jure Simsic:
> As the list refuses me to post such long debugs, I'm splitting my mail in
> two:

No-one here asked for DEBUG logging, so you just wasted a lot
of electrons sending information that no-one will look at.

        Wietse
Reply | Threaded
Open this post in threaded view
|

Re: Funny headers_checks matching

Jures
On Fri, Sep 17, 2010 at 1:16 PM, Wietse Venema <[hidden email]> wrote:
Jure Simsic:
> As the list refuses me to post such long debugs, I'm splitting my mail in
> two:

No-one here asked for DEBUG logging, so you just wasted a lot
of electrons sending information that no-one will look at.


Ok, that's what I had. I tried to work it out myself first and see if there is any explanation for that behavior. In case you feel more meaningful data is in non debug information, here it is: 

No match:
Sep 17 15:11:58 fps-mms-mta3 postfix/smtpd[18258]: [ID 197553 mail.info] connect from unknown[10.40.0.20]
Sep 17 15:11:58 fps-mms-mta3 postfix/smtpd[18258]: [ID 197553 mail.info] improper command pipelining after EHLO from unknown[10.40.0.20]
Sep 17 15:11:58 fps-mms-mta3 postfix/smtpd[18258]: [ID 197553 mail.info] 81F348C63: client=unknown[10.40.0.20]
Sep 17 15:11:58 fps-mms-mta3 postfix/cleanup[18261]: [ID 197553 mail.info] 81F348C63: message-id=<>
Sep 17 15:11:58 fps-mms-mta3 postfix/smtpd[18258]: [ID 197553 mail.info] lost connection after QUIT from unknown[10.40.0.20]
Sep 17 15:11:58 fps-mms-mta3 postfix/smtpd[18258]: [ID 197553 mail.info] disconnect from unknown[10.40.0.20]
Sep 17 15:11:58 fps-mms-mta3 postfix/qmgr[18256]: [ID 197553 mail.info] 81F348C63: from=<+11111111/TYPE=[hidden email]>, size=1025, nrcpt=1 (queue active)
Sep 17 15:11:58 fps-mms-mta3 postfix/smtp[18262]: [ID 197553 mail.info] 81F348C63: to=<[hidden email]>, orig_to=<+1234567/TYPE=[hidden email]>, relay=10.40.0.75[10.40.0.75]:25, delay=0.08, delays=0.04/0.03/0/0.01, dsn=2.0.0, status=sent (250 <4C2C5DE40018A0C4> Mail accepted)
Sep 17 15:11:58 fps-mms-mta3 postfix/qmgr[18256]: [ID 197553 mail.info] 81F348C63: removed

Match:
Sep 17 15:12:22 fps-mms-mta3 postfix/smtpd[18258]: [ID 197553 mail.info] connect from unknown[10.40.0.20]
Sep 17 15:12:22 fps-mms-mta3 postfix/smtpd[18258]: [ID 197553 mail.info] improper command pipelining after EHLO from unknown[10.40.0.20]
Sep 17 15:12:22 fps-mms-mta3 postfix/smtpd[18258]: [ID 197553 mail.info] 467D18C64: client=unknown[10.40.0.20]
Sep 17 15:12:22 fps-mms-mta3 postfix/cleanup[18261]: [ID 197553 mail.info] 467D18C64: replace: header To: +1234567/TYPE=PLMN from unknown[10.40.0.20]; from=<+11111111/TYPE=[hidden email]> to=<[hidden email]> proto=ESMTP helo=<mms-mta2.domain1.com>: To: 1919/TYPE=PLMN
Sep 17 15:12:22 fps-mms-mta3 postfix/cleanup[18261]: [ID 197553 mail.info] 467D18C64: message-id=<>
Sep 17 15:12:22 fps-mms-mta3 postfix/smtpd[18258]: [ID 197553 mail.info] lost connection after QUIT from unknown[10.40.0.20]
Sep 17 15:12:22 fps-mms-mta3 postfix/smtpd[18258]: [ID 197553 mail.info] disconnect from unknown[10.40.0.20]
Sep 17 15:12:22 fps-mms-mta3 postfix/qmgr[18256]: [ID 197553 mail.info] 467D18C64: from=<+11111111/TYPE=[hidden email]>, size=1017, nrcpt=1 (queue active)
Sep 17 15:12:22 fps-mms-mta3 postfix/smtp[18262]: [ID 197553 mail.info] 467D18C64: to=<[hidden email]>, orig_to=<+1234567/TYPE=[hidden email]>, relay=10.40.0.75[10.40.0.75]:25, delay=0.05, delays=0.02/0/0/0.02, dsn=2.0.0, status=sent (250 <4C2C5CBF0019D62A> Mail accepted)
Sep 17 15:12:22 fps-mms-mta3 postfix/qmgr[18256]: [ID 197553 mail.info] 467D18C64: removed


Same file, just the To: and Received: switched places..

Jure
Reply | Threaded
Open this post in threaded view
|

Re: Funny headers_checks matching

Wietse Venema
Jure Simsic:

> On Fri, Sep 17, 2010 at 1:16 PM, Wietse Venema <[hidden email]> wrote:
>
> > Jure Simsic:
> > > As the list refuses me to post such long debugs, I'm splitting my mail in
> > > two:
> >
> > No-one here asked for DEBUG logging, so you just wasted a lot
> > of electrons sending information that no-one will look at.
> >
> >
> Ok, that's what I had. I tried to work it out myself first and see if there
> is any explanation for that behavior. In case you feel more meaningful data
> is in non debug information, here it is:
>
> No match:
> Sep 17 15:11:58 fps-mms-mta3 postfix/smtpd[18258]: [ID 197553 mail.info]

That is not what I asked for.

I asked for:

    > Please show evidence in the form of actual email messages that
    > the To: is replaced and is not replaced.

    And the corresponding Postfix logging for those messages.

So, could you please provide those actual email messages and
the corresponding Postfix logging for those messages, in one
posting to this mailing list.

In case this is not 100% clear, show REAL INPUT, show REAL LOGGING,
and show REAL RESULTS of the two messages that you believe demonstrate
the problem.

        Wietse
Reply | Threaded
Open this post in threaded view
|

Re: Funny headers_checks matching

Jures
On Fri, Sep 17, 2010 at 3:43 PM, Wietse Venema <[hidden email]> wrote:
Jure Simsic:
> On Fri, Sep 17, 2010 at 1:16 PM, Wietse Venema <[hidden email]> wrote:
>
> > Jure Simsic:
> > > As the list refuses me to post such long debugs, I'm splitting my mail in
> > > two:
> >
> > No-one here asked for DEBUG logging, so you just wasted a lot
> > of electrons sending information that no-one will look at.
> >
> >
> Ok, that's what I had. I tried to work it out myself first and see if there
> is any explanation for that behavior. In case you feel more meaningful data
> is in non debug information, here it is:
>
> No match:
> Sep 17 15:11:58 fps-mms-mta3 postfix/smtpd[18258]: [ID 197553 mail.info]

That is not what I asked for.

I asked for:

   > Please show evidence in the form of actual email messages that
   > the To: is replaced and is not replaced.

   And the corresponding Postfix logging for those messages.

So, could you please provide those actual email messages and
the corresponding Postfix logging for those messages, in one
posting to this mailing list.

In case this is not 100% clear, show REAL INPUT, show REAL LOGGING,
and show REAL RESULTS of the two messages that you believe demonstrate
the problem.

This is actually somewhat difficult as the endpoints are both applications, but i did a tcpdump to demonstrate this. In both cases the mail was sent by hand from one box to the postfix (telnet 10.40.0.23 25 < /tmp/test3). The content is the one I've already posted (I can post it again) and the only thing I needed to obfuscate is the domain names, but they are consistent (I'm a consultant and the client demands this, blah).. The header_checks is the same in both cases, as posted, REGEXP:
/^To: \+1234567\/TYPE=PLMN$/
 REPLACE To: 1919/TYPE=PLMN

The following are the SMTP going from this mta further on to the next mta, first time with modified To: and the second without modification, the difference is just the position of the headers in the source file.

Matched:
220 mms1.mms.domain1.com ESMTP Service (Multimedia IP message store 6.1.999.11) ready
EHLO mms-mta3.domain1.com
250-mms1.mms.domain1.com
250-DSN
250-8BITMIME
250-PIPELINING
250-HELP
250-AUTH
250 SIZE 2000000
MAIL FROM:<+11111111/TYPE=[hidden email]> SIZE=1017
RCPT TO:<[hidden email]> ORCPT=rfc822;+2B1234567/[hidden email]
DATA
250 MAIL FROM:<+11111111/TYPE=[hidden email]> OK
250 RCPT TO:<[hidden email]> OK
354 Start mail input; end with <CRLF>.<CRLF>
Received: from mms-mta2.domain1.com (unknown [10.40.0.20])
    by mms-mta3.domain1.com (Postfix) with ESMTP id CBDEA8C6D
    for <+1234567/TYPE=[hidden email]>; Fri, 17 Sep 2010 17:15:05 +0200 (CEST)
X-Mms-3GPP-MMS-Version: 6.3.0
X-Mms-Ack-Request: Yes
X-Mms-Message-Type: MM4_forward.REQ
X-Mms-Delivery-Report: Yes
To: 1919/TYPE=PLMN
Received: from smtp.domain1.com ([127.0.0.1])

by localhost (mobi-mailv78.domain1.com [127.0.0.1]) (amavisd-new, port 10024)
From: +11111111/TYPE=PLMN
Date: Mon, 06 Sep 2010 11:09:56 +0000
Content-Type: multipart/related; Type="application/smil"; Start="<YoCEK>"; boundary="Nokia-mm-messageHandler-BoUnDaRy-=_
-1883574436"
Sender: +11111111/TYPE=[hidden email]
X-Mms-Originator-System: [hidden email]
X-Mms-Message-ID: "TITMBAoEBgQAAEmtAAAGzAAAAHgAAAAB"
X-Mms-Transaction-ID: "TITMBAoEBgQAAEmtAAAGzAAAAHgAAAAA1"
Message-ID: <[hidden email]>
X-Mms-Originator-R/S-Delivery-Report: NO
.
QUIT
250 <4C2C5CBF0019DF84> Mail accepted
221 mms1.mms.domain1.com QUIT


Not matched:
220 mms8.mms.domain1.com ESMTP Service (Multimedia IP message store 6.1.999.11) ready
EHLO mms-mta3.domain1.com
250-mms8.mms.domain1.com
250-DSN
250-8BITMIME
250-PIPELINING
250-HELP
250-AUTH
250 SIZE 2000000
MAIL FROM:<+11111111/TYPE=[hidden email]> SIZE=1025
RCPT TO:<[hidden email]> ORCPT=rfc822;+2B1234567/[hidden email]
DATA
250 MAIL FROM:<+11111111/TYPE=[hidden email]> OK
250 RCPT TO:<[hidden email]> OK
354 Start mail input; end with <CRLF>.<CRLF>
Received: from mms-mta2.domain1.com (unknown [10.40.0.20])
    by mms-mta3.domain1.com (Postfix) with ESMTP id 373098C6E
    for <+1234567/TYPE=[hidden email]>; Fri, 17 Sep 2010 17:16:01 +0200 (CEST)
X-Mms-3GPP-MMS-Version: 6.3.0
X-Mms-Ack-Request: Yes
X-Mms-Message-Type: MM4_forward.REQ
X-Mms-Delivery-Report: Yes
Received: from smtp.domain1.com ([127.0.0.1])

by localhost (mobi-mailv78.domain1.com [127.0.0.1]) (amavisd-new, port 10024)
To: +1234567/TYPE=PLMN
From: +11111111/TYPE=PLMN
Date: Mon, 06 Sep 2010 11:09:56 +0000
Content-Type: multipart/related; Type="application/smil"; Start="<YoCEK>"; boundary="Nokia-mm-messageHandler-BoUnDaRy-=_
-1883574436"
Sender: +11111111/TYPE=[hidden email]
X-Mms-Originator-System: [hidden email]
X-Mms-Message-ID: "TITMBAoEBgQAAEmtAAAGzAAAAHgAAAAB"
X-Mms-Transaction-ID: "TITMBAoEBgQAAEmtAAAGzAAAAHgAAAAA1"
Message-ID: <[hidden email]>
X-Mms-Originator-R/S-Delivery-Report: NO
.
QUIT
250 <4C2C5F9700169399> Mail accepted
221 mms8.mms.domain1.com QUIT


And the corresponding log files as the message was accepted by this mta:

Matched:
Sep 17 17:15:05 fps-mms-mta3 postfix/smtpd[18354]: [ID 197553 mail.info] connect from unknown[10.40.0.20]
Sep 17 17:15:05 fps-mms-mta3 postfix/smtpd[18354]: [ID 197553 mail.info] improper command pipelining after EHLO from unknown[10.40.0.20]
Sep 17 17:15:05 fps-mms-mta3 postfix/smtpd[18354]: [ID 197553 mail.info] CBDEA8C6D: client=unknown[10.40.0.20]
Sep 17 17:15:05 fps-mms-mta3 postfix/cleanup[18357]: [ID 197553 mail.info] CBDEA8C6D: replace: header To: +1234567/TYPE=PLMN from unknown[10.40.0.20]; from=<+11111111/TYPE=[hidden email]> to=<[hidden email]> proto=ESMTP helo=<mms-mta2.domain1.com>: To: 1919/TYPE=PLMN
Sep 17 17:15:05 fps-mms-mta3 postfix/cleanup[18357]: [ID 197553 mail.info] CBDEA8C6D: message-id=<>
Sep 17 17:15:05 fps-mms-mta3 postfix/smtpd[18354]: [ID 197553 mail.info] lost connection after QUIT from unknown[10.40.0.20]
Sep 17 17:15:05 fps-mms-mta3 postfix/qmgr[18256]: [ID 197553 mail.info] CBDEA8C6D: from=<+11111111/TYPE=[hidden email]>, size=1017, nrcpt=1 (queue active)
Sep 17 17:15:05 fps-mms-mta3 postfix/smtpd[18354]: [ID 197553 mail.info] disconnect from unknown[10.40.0.20]
Sep 17 17:15:05 fps-mms-mta3 postfix/smtp[18358]: [ID 197553 mail.info] CBDEA8C6D: to=<[hidden email]>, orig_to=<+1234567/TYPE=[hidden email]>, relay=10.40.0.75[10.40.0.75]:25, delay=0.07, delays=0.04/0.02/0/0, dsn=2.0.0, status=sent (250 <4C2C5CBF0019DF84> Mail accepted)
Sep 17 17:15:05 fps-mms-mta3 postfix/qmgr[18256]: [ID 197553 mail.info] CBDEA8C6D: removed


Not matched:
Sep 17 17:16:01 fps-mms-mta3 postfix/smtpd[18354]: [ID 197553 mail.info] connect from unknown[10.40.0.20]
Sep 17 17:16:01 fps-mms-mta3 postfix/smtpd[18354]: [ID 197553 mail.info] improper command pipelining after EHLO from unknown[10.40.0.20]
Sep 17 17:16:01 fps-mms-mta3 postfix/smtpd[18354]: [ID 197553 mail.info] 373098C6E: client=unknown[10.40.0.20]
Sep 17 17:16:01 fps-mms-mta3 postfix/cleanup[18357]: [ID 197553 mail.info] 373098C6E: message-id=<>
Sep 17 17:16:01 fps-mms-mta3 postfix/smtpd[18354]: [ID 197553 mail.info] lost connection after QUIT from unknown[10.40.0.20]
Sep 17 17:16:01 fps-mms-mta3 postfix/smtpd[18354]: [ID 197553 mail.info] disconnect from unknown[10.40.0.20]
Sep 17 17:16:01 fps-mms-mta3 postfix/qmgr[18256]: [ID 197553 mail.info] 373098C6E: from=<+11111111/TYPE=[hidden email]>, size=1025, nrcpt=1 (queue active)
Sep 17 17:16:01 fps-mms-mta3 postfix/smtp[18358]: [ID 197553 mail.info] 373098C6E: to=<[hidden email]>, orig_to=<+1234567/TYPE=[hidden email]>, relay=10.40.0.75[10.40.0.75]:25, delay=0.03, delays=0.02/0/0/0.01, dsn=2.0.0, status=sent (250 <4C2C5F9700169399> Mail accepted)
Sep 17 17:16:01 fps-mms-mta3 postfix/qmgr[18256]: [ID 197553 mail.info] 373098C6E: removed


Is this clear as it is or do you require anything else?

Tnx
Jure
Reply | Threaded
Open this post in threaded view
|

Re: Funny headers_checks matching

Victor Duchovni
On Fri, Sep 17, 2010 at 05:35:45PM +0200, Jure Simsic wrote:

>   Matched:
>   220 mms1.mms.domain1.com ESMTP Service (Multimedia IP message store
>   6.1.999.11) ready
>   EHLO mms-mta3.domain1.com
>   250-mms1.mms.domain1.com
>   250-DSN
>   250-8BITMIME
>   250-PIPELINING
>   250-HELP
>   250-AUTH
>   250 SIZE 2000000
>   MAIL FROM:<+11111111/TYPE=[hidden email]> SIZE=1017
>   RCPT TO:<[hidden email]> ORCPT=rfc822;+2B1234567/
>   [hidden email] <TYPE%[hidden email]>
>   DATA
>   250 MAIL FROM:<+11111111/TYPE=[hidden email]> OK
>   250 RCPT TO:<[hidden email]> OK
>   354 Start mail input; end with <CRLF>.<CRLF>
>   Received: from mms-mta2.domain1.com (unknown [10.40.0.20])
> by mms-mta3.domain1.com (Postfix) with ESMTP id CBDEA8C6D
> for <+1234567/TYPE=[hidden email]>; Fri, 17 Sep 2010 17:15:05
>   +0200 (CEST)
>   X-Mms-3GPP-MMS-Version: 6.3.0
>   X-Mms-Ack-Request: Yes
>   X-Mms-Message-Type: MM4_forward.REQ
>   X-Mms-Delivery-Report: Yes
>   To: 1919/TYPE=PLMN
>   Received: from smtp.domain1.com ([127.0.0.1])
>

BLANK LINE TERMINATES THE HEADER: the content below is BODY content.

>   by localhost (mobi-mailv78.domain1.com [127.0.0.1]) (amavisd-new, port
>   10024)
>   From: +11111111/TYPE=PLMN
>   Date: Mon, 06 Sep 2010 11:09:56 +0000
>   Content-Type: multipart/related; Type="application/smil"; Start="<YoCEK>";
>   boundary="Nokia-mm-messageHandler-BoUnDaRy-=_
>   -1883574436"
>   Sender: +11111111/TYPE=[hidden email]
>   X-Mms-Originator-System: [hidden email]
>   X-Mms-Message-ID: "TITMBAoEBgQAAEmtAAAGzAAAAHgAAAAB"
>   X-Mms-Transaction-ID: "TITMBAoEBgQAAEmtAAAGzAAAAHgAAAAA1"
>   Message-ID: <[hidden email]>
>   X-Mms-Originator-R/S-Delivery-Report: NO
>   .
>   QUIT
>   250 <4C2C5CBF0019DF84> Mail accepted
>   221 mms1.mms.domain1.com QUIT


>   Not matched:
>   220 mms8.mms.domain1.com ESMTP Service (Multimedia IP message store
>   6.1.999.11) ready
>   EHLO mms-mta3.domain1.com
>   250-mms8.mms.domain1.com
>   250-DSN
>   250-8BITMIME
>   250-PIPELINING
>   250-HELP
>   250-AUTH
>   250 SIZE 2000000
>   MAIL FROM:<+11111111/TYPE=[hidden email]> SIZE=1025
>   RCPT TO:<[hidden email]> ORCPT=rfc822;+2B1234567/
>   [hidden email] <TYPE%[hidden email]>
>   DATA
>   250 MAIL FROM:<+11111111/TYPE=[hidden email]> OK
>   250 RCPT TO:<[hidden email]> OK
>   354 Start mail input; end with <CRLF>.<CRLF>
>   Received: from mms-mta2.domain1.com (unknown [10.40.0.20])
        by mms-mta3.domain1.com (Postfix) with ESMTP id 373098C6E
        for <+1234567/TYPE=[hidden email]>; Fri, 17 Sep 2010 17:16:01
>   +0200 (CEST)
>   X-Mms-3GPP-MMS-Version: 6.3.0
>   X-Mms-Ack-Request: Yes
>   X-Mms-Message-Type: MM4_forward.REQ
>   X-Mms-Delivery-Report: Yes
>   Received: from smtp.domain1.com ([127.0.0.1])
>

BLANK LINE TERMINATES THE HEADER: the content below is BODY content.

>   by localhost (mobi-mailv78.domain1.com [127.0.0.1]) (amavisd-new, port
>   10024)
>   To: +1234567/TYPE=PLMN
>   From: +11111111/TYPE=PLMN
>   Date: Mon, 06 Sep 2010 11:09:56 +0000
>   Content-Type: multipart/related; Type="application/smil"; Start="<YoCEK>";
>   boundary="Nokia-mm-messageHandler-BoUnDaRy-=_
>   -1883574436"
>   Sender: +11111111/TYPE=[hidden email]
>   X-Mms-Originator-System: [hidden email]
>   X-Mms-Message-ID: "TITMBAoEBgQAAEmtAAAGzAAAAHgAAAAB"
>   X-Mms-Transaction-ID: "TITMBAoEBgQAAEmtAAAGzAAAAHgAAAAA1"
>   Message-ID: <[hidden email]>
>   X-Mms-Originator-R/S-Delivery-Report: NO
>   .
>   QUIT
>   250 <4C2C5F9700169399> Mail accepted
>   221 mms8.mms.domain1.com QUIT

--
        Viktor.
Reply | Threaded
Open this post in threaded view
|

Re: Funny headers_checks matching

Jures
On Fri, Sep 17, 2010 at 5:52 PM, Victor Duchovni <[hidden email]> wrote:
On Fri, Sep 17, 2010 at 05:35:45PM +0200, Jure Simsic wrote:

BLANK LINE TERMINATES THE HEADER: the content below is BODY content.

Thanks, just figured it out. Actually it was not the blank line but the Received when multiline needs spaces in the beginning of the following lines and in the test file there were none. When I changed to 2 spaces at ^ it started working..

Thanks a lot.

Jure
Reply | Threaded
Open this post in threaded view
|

Re: Funny headers_checks matching

mouss-4
Le 17/09/2010 18:04, Jure Simsic a écrit :
On Fri, Sep 17, 2010 at 5:52 PM, Victor Duchovni <[hidden email]> wrote:
On Fri, Sep 17, 2010 at 05:35:45PM +0200, Jure Simsic wrote:

BLANK LINE TERMINATES THE HEADER: the content below is BODY content.

Thanks, just figured it out. Actually it was not the blank line but the Received when multiline needs spaces in the beginning of the following lines and in the test file there were none. When I changed to 2 spaces at ^ it started working..

instead of playing header_check games, see if canonical or generic (smtp_generic_maps) can do what you want.