Re: [exim] Strange system filter behaviour.

Top Page
Delete this message
Reply to this message
Author: Molly Fletcher
Date:  
To: <exim-users@exim.org>
CC: Ian Eiloart
Subject: Re: [exim] Strange system filter behaviour.
On 11/10/12 19:45, Phil Pennock wrote:
> On 2012-10-11 at 14:00 +0100, Molly Fletcher wrote:
>> Don't seem to be any lines starting "Filter:" when I do this yet it's
>> definitely hitting the filter as the input message is getting saved to
>> the filename I specified in the save clause I added previously to the
>> filter trying to debug it:
> Oh. The debug status isn't propagating. Well crap.
>
> If you run a second exim on a different port, started with -d on the
> command-line, that _should_ propagate.
>
> Sorry.
>
> -Phil


That worked:

 5958 3095 bytes read from /etc/exim4/exim.filter
 5958 data is an Exim filter program
 5958 Filter: start of processing
 5958 Condition is false: $header_from: contains spammers1.co.uk
 5958 Condition is false: $header_to: contains root@???
 5958 Condition is false: $header_from: contains spammers2.co.uk
 5958 Condition is false: $header_from: contains spammers3.com
 5958 Condition is false: $header_from: contains spammers4..com
 5958 Condition is false: $header_from: contains spammers5.com
 5958 Condition is false: $header_from: contains spammers6.com
 5958 Condition is false: $header_from: contains spammers7.com
 5958 Condition is false: $header_subject: contains [redacted]
 5958 Condition is false: $header_from: contains spammers8.cn
 5958 Condition is false: $header_to: contains redsipserver.com
 5958 Condition is false: $header_subject: begins Read:
 5958 Condition is false: $header_from: contains spammer9@???
 5958 Sub-condition is true: $h_to: contains bigcorp.com
 5958 Sub-condition is true: $sender_address: contains @redembedded.com
 5958 Condition is true: $h_to: contains bigcorp.com and
$sender_address: contains @redembedded.com
 5958 Match expanded arguments:
 5958   Subject = http://192.168.2.2  :
 5958   Pattern =
(http|https|ftp)://([01]?\d\d?|2[0-4]\d|25[0-5])\.([01]?\d\d?|2[0-4]\d|25[0-5])\.([01]?\d\d?|2[0-4]\d|25[0-5])\.([01]?\d\d?|2[0-4]\d|25[0-5])
 5958   Condition is true: $message_body: matches
(http|https|ftp)://([01]?\\d\\d?|2[0-4]\\d|25[0-5])\\.([01]?\\d\\d?|2[0-4]\\d|25[0-5])\\.([01]?\\d\\d?|2[0-4]\\d|25[0-5])\\.([01]?\\d\\d?|2[0-4]\\d|25[0-5])
 5958 Filter: save message to: /var/log/exim4/filtertest
 5958 Filter: mail to: molly.fletcher@???
 5958         subject: WARNING-Numeric URL
 5958            text: WARNING: You sent an email to a bigcorp address
which contained a numeric (IP address) URL - this WILL BE REJECTED by
BigCORPs message filtering
 5958 Filtering set up at least one significant delivery or other action.
 5958 No other deliveries will occur.
 5958 Filter: end of processing
 5958 search_tidyup called
 5957 rda_interpret: subprocess yield=0 error=NULL
 5957 system filter returned 0
 5957 LOG: MAIN
 5957   original recipients ignored (system filter)
 5957 system filter added >molly.fletcher@???
 5957 system filter added /var/log/exim4/filtertest
 5957 Delivery address list:
 5957   >molly.fletcher@???
 5957   /var/log/exim4/filtertest
 5957 locking /var/spool/exim4/db/retry.lockfile
 5957 locked /var/spool/exim4/db/retry.lockfile
 5957 EXIM_DBOPEN(/var/spool/exim4/db/retry)
 5957 returned from EXIM_DBOPEN
 5957 opened hints database /var/spool/exim4/db/retry: flags=O_RDONLY
 5957 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
 5957 Considering: >molly.fletcher@???
 5957 unique = >molly.fletcher@???:system-filter
 5957 queued for local_delivery transport
 5957 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
 5957 Considering: /var/log/exim4/filtertest
 5957 unique = /var/log/exim4/filtertest:system-filter
 5957 queued for address_file transport
 5957 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
 5957 After routing:
 5957   Local deliveries:
 5957     /var/log/exim4/filtertest
 5957     >molly.fletcher@???
 5957   Remote deliveries:
 5957   Failed addresses:
 5957   Deferred addresses:
 5957 search_tidyup called
 5957 >>>>>>>>>>>>>>>> Local deliveries >>>>>>>>>>>>>>>>
 5957 --------> /var/log/exim4/filtertest <--------
 5957 locking /var/spool/exim4/db/retry.lockfile
 5957 locked /var/spool/exim4/db/retry.lockfile
 5957 EXIM_DBOPEN(/var/spool/exim4/db/retry)
 5957 returned from EXIM_DBOPEN
 5957 opened hints database /var/spool/exim4/db/retry: flags=O_RDONLY
 5957 dbfn_read: key=T:/var/log/exim4/filtertest:system-filter
 5957 no retry record exists
 5957 search_tidyup called
 5959 changed uid/gid: local delivery to /var/log/exim4/filtertest
</var/log/exim4/filtertest> transport=address_file
 5959   uid=104 gid=112 pid=5959
 5959   auxiliary group list: <none>
 5959   home=NULL current=/
 5959 set_process_info:  5959 delivering 1TMfc9-0001Xe-R0 to
/var/log/exim4/filtertest using address_file
 5959 appendfile transport entered
 5959 appendfile: mode=600 notify_comsat=0 quota=0 warning=0
 5959   file=/var/log/exim4/filtertest format=unix
 5959   message_prefix=From ${if
def:return_path{$return_path}{MAILER-DAEMON}} ${tod_bsdinbox}\n
 5959   message_suffix=\n
 5959   maildir_use_size_file=no
 5959   locking by lockfile fcntl
 5959 lock name: /var/log/exim4/filtertest.lock
 5959 hitch name:
/var/log/exim4/filtertest.lock.mail1.redembedded.com.50782026.00001747
 5959 lock file created
 5959 mailbox /var/log/exim4/filtertest is locked
 5959 writing to file /var/log/exim4/filtertest
 5959 writing data block fd=8 size=61 timeout=0
 5959 writing data block fd=8 size=569 timeout=0
 5959 writing data block fd=8 size=1 timeout=0
 5959 appendfile yields 0 with errno=0 more_errno=0
 5957 journalling /var/log/exim4/filtertest:system-filter
 5959 search_tidyup called
 5957 address_file transport returned OK for /var/log/exim4/filtertest
 5957 post-process /var/log/exim4/filtertest (0)
 5957 /var/log/exim4/filtertest delivered
 5957 LOG: MAIN
 5957   => /var/log/exim4/filtertest <system-filter>
F=<molly.fletcher@???> P=<molly.fletcher@???>
T=address_file S=631 QT=1m9s DT=0s
 5957 --------> >molly.fletcher@??? <--------
 5957 locking /var/spool/exim4/db/retry.lockfile
 5957 locked /var/spool/exim4/db/retry.lockfile
 5957 EXIM_DBOPEN(/var/spool/exim4/db/retry)
 5957 returned from EXIM_DBOPEN
 5957 opened hints database /var/spool/exim4/db/retry: flags=O_RDONLY
 5957 dbfn_read: key=T:>molly.fletcher@???:system-filter
 5957 no retry record exists
 5957 search_tidyup called
 5960 changed uid/gid: local delivery to >molly.fletcher@???
<>molly.fletcher@???> transport=local_delivery
 5960   uid=104 gid=112 pid=5960
 5960   auxiliary group list: <none>
 5960   home=NULL current=/
 5960 set_process_info:  5960 delivering 1TMfc9-0001Xe-R0 to

>molly.fletcher@??? using local_delivery

 5960 local_delivery transport entered
 5960   >molly.fletcher@???
 5960 using the transport's hosts: exmail.redembedded.com
 5960 getting address for exmail.redembedded.com
 5960 DNS lookup of exmail.redembedded.com (AAAA) gave NO_DATA
 5960 returning DNS_NODATA
 5960 DNS lookup of exmail.redembedded.com (A) succeeded
 5960 fully qualified name = exmail.redembedded.com
 5960 exmail.redembedded.com 10.82.128.38 mx=-1 sort=-393
 5960 redembedded.com in queue_smtp_domains? no (option unset)
 5960 checking status of exmail.redembedded.com
 5960 locking /var/spool/exim4/db/retry.lockfile
 5960 locked /var/spool/exim4/db/retry.lockfile
 5960 EXIM_DBOPEN(/var/spool/exim4/db/retry)
 5960 returned from EXIM_DBOPEN
 5960 opened hints database /var/spool/exim4/db/retry: flags=O_RDONLY
 5960 dbfn_read: key=T:exmail.redembedded.com:10.82.128.38
 5960 dbfn_read: key=T:exmail.redembedded.com:10.82.128.38:1TMfc9-0001Xe-R0
 5960 no host retry record
 5960 no message retry record
 5960 exmail.redembedded.com [10.82.128.38] status = usable
 5960 10.82.128.38 in serialize_hosts? no (option unset)
 5960 delivering 1TMfc9-0001Xe-R0 to exmail.redembedded.com
[10.82.128.38] (>molly.fletcher@???)
 5960 set_process_info:  5960 delivering 1TMfc9-0001Xe-R0 to
exmail.redembedded.com [10.82.128.38] (>molly.fletcher@???)
 5960 Connecting to exmail.redembedded.com [10.82.128.38]:25 ... connected
 5960 waiting for data on socket
 5960 read response data: size=101
 5960   SMTP<< 220 winky.red.redembedded.com Microsoft ESMTP MAIL
Service ready at Fri, 12 Oct 2012 14:50:30 +0100
 5960 10.82.128.38 in hosts_avoid_esmtp? no (option unset)
 5960   SMTP>> EHLO mail1.redembedded.com
 5960 waiting for data on socket
 5960 read response data: size=264
 5960   SMTP<< 250-winky.red.redembedded.com Hello [10.82.1.26]
 5960          250-SIZE
 5960          250-PIPELINING
 5960          250-DSN
 5960          250-ENHANCEDSTATUSCODES
 5960          250-STARTTLS
 5960          250-X-ANONYMOUSTLS
 5960          250-AUTH NTLM
 5960          250-X-EXPS GSSAPI NTLM
 5960          250-8BITMIME
 5960          250-BINARYMIME
 5960          250-CHUNKING
 5960          250-XEXCH50
 5960          250-XRDST
 5960          250 XSHADOW
 5960 10.82.128.38 in hosts_require_tls? no (option unset)
 5960 10.82.128.38 in hosts_avoid_pipelining? no (option unset)
 5960 not using PIPELINING
 5960 10.82.128.38 in hosts_require_auth? no (option unset)
 5960   SMTP>> MAIL FROM:<molly.fletcher@???>
 5960 waiting for data on socket
 5960 read response data: size=21
 5960   SMTP<< 250 2.1.0 Sender OK
 5960   SMTP>> RCPT TO:<>molly.fletcher@???>
 5960 waiting for data on socket
 5960 read response data: size=27
 5960   SMTP<< 501 5.1.3 Invalid address
 5960 ok=1 send_quit=1 send_rset=1 continue_more=0 yield=0 first_address
is NULL
 5960 transport_check_waiting entered
 5960   sequence=1 local_max=500 global_max=-1
 5960 locking /var/spool/exim4/db/wait-local_delivery.lockfile
 5960 locked /var/spool/exim4/db/wait-local_delivery.lockfile
 5960 EXIM_DBOPEN(/var/spool/exim4/db/wait-local_delivery)
 5960 returned from EXIM_DBOPEN
 5960 opened hints database /var/spool/exim4/db/wait-local_delivery:
flags=O_RDWR
 5960 dbfn_read: key=exmail.redembedded.com
 5960 no messages waiting for exmail.redembedded.com
 5960   SMTP>> QUIT
 5960 set_process_info:  5960 delivering 1TMfc9-0001Xe-R0: just tried
exmail.redembedded.com [10.82.128.38] for

>molly.fletcher@???: result OK

5960 Leaving local_delivery transport
5960 search_tidyup called
5957 local_delivery transport returned FAIL for
>molly.fletcher@???

5957 post-process >molly.fletcher@??? (2)
5957 LOG: MAIN
5957 ** >molly.fletcher@??? <system-filter>
F=<molly.fletcher@???> P=<molly.fletcher@???>
T=local_delivery: SMTP error from remote mail server after RCPT
TO:<>molly.fletcher@???>: host exmail.redembedded.com
[10.82.128.38]: 501 5.1.3 Invalid address
5957 >>>>>>>>>>>>>>>> deliveries are done >>>>>>>>>>>>>>>>
5957 changed uid/gid: post-delivery tidying
5957 uid=104 gid=112 pid=5957
5957 auxiliary group list: <none>
5957 set_process_info: 5957 tidying up after delivering 1TMfc9-0001Xe-R0
5957 Processing retry items
5957 Succeeded addresses:
5957 /var/log/exim4/filtertest: no retry items
5957 system-filter: no retry items
5957 Failed addresses:
5957 >molly.fletcher@???: no retry items
5957 system-filter: no retry items
5957 Deferred addresses:
5957 end of retry processing
5957 processing failed address >molly.fletcher@???
5957 sending error message to: molly.fletcher@???



-- 
Molly Fletcher, IT System Administrator    <molly.fletcher@???>
Red Embedded Design            www.redembedded.com
Tel: +44 (0)1274 287724


This E-mail and any attachments hereto are strictly confidential and intended solely for the addressee. If you are not the intended addressee please notify the sender by return and delete the message.

You must not disclose, forward or copy this E-mail or attachments to any third party without the prior consent of the sender.

Red Embedded Design Registered in England, Company Number: 06688253
Registered Office: The Waterfront, Salts Mill Road, Saltaire, West Yorkshire, BD17 7EZ