Re: [exim] Rejecting Recipients at RCPT stage

Startseite
Nachricht löschen
Nachricht beantworten
Autor: Zlatko Mesaros
Datum:  
To: Exim-users
Betreff: Re: [exim] Rejecting Recipients at RCPT stage
And as promised here is the debug:

exim -d+all -bhc 200.128.150.11

16:25:25 7963 Exim version 4.63 uid=0 gid=0 pid=7963 D=fffdffff
Berkeley DB: Sleepycat Software: Berkeley DB 4.3.29: (September 12, 2006)
Support for: crypteq iconv() IPv6 PAM Perl TCPwrappers OpenSSL
Content_Scanning Old_Demime
Lookups: lsearch wildlsearch nwildlsearch iplsearch cdb dbm dbmnz dnsdb
dsearch ldap ldapdn ldapm mysql nis nis0 nisplus passwd pgsql sqlite
Authenticators: cram_md5 cyrus_sasl plaintext spa
Routers: accept dnslookup ipliteral manualroute queryprogram redirect
Transports: appendfile/maildir/mailstore/mbx autoreply lmtp pipe smtp
Fixed never_users: 0
Size of off_t: 4
16:25:25 7963 changed uid/gid: forcing real = effective
16:25:25 7963 uid=0 gid=0 pid=7963
16:25:25 7963 auxiliary group list: <none>
16:25:25 7963 seeking password data for user "root": cache not available
16:25:25 7963 getpwnam() succeeded uid=0 gid=0
16:25:25 7963 configuration file is /etc/exim/exim.conf
16:25:25 7963 log selectors = 00000ffc 00089001
16:25:25 7963 trusted user
16:25:25 7963 admin user
16:25:25 7963 changed uid/gid: privilege not needed
16:25:25 7963 uid=93 gid=93 pid=7963
16:25:25 7963 auxiliary group list: 12 93
16:25:25 7963 originator: uid=0 gid=0 login=root name=root
16:25:25 7963 sender address = root@???
16:25:25 7963 sender_fullhost = [200.128.150.11]
16:25:25 7963 sender_rcvhost = [200.128.150.11]

**** SMTP testing session as if from host 200.128.150.11
**** but without any ident (RFC 1413) callback.
**** This is not for real!

16:25:25  7963 host in hosts_connection_nolog? no (option unset)
16:25:25  7963 LOG: smtp_connection MAIN
16:25:25  7963   SMTP connection from [200.128.150.11]
16:25:25  7963 host in host_lookup? yes (matched "*")
16:25:25  7963 looking up host name for 200.128.150.11
16:25:25  7963 DNS lookup of 11.150.128.200.in-addr.arpa (PTR) gave 
HOST_NOT_FOUND
16:25:25  7963 returning DNS_NOMATCH
16:25:25  7963 IP address lookup using gethostbyaddr()
16:25:25  7963 IP address lookup failed: h_errno=1
16:25:25  7963 LOG: host_lookup_failed MAIN
16:25:25  7963   no host name found for IP address 200.128.150.11
16:25:25  7963 sender_fullhost = [200.128.150.11]
16:25:25  7963 sender_rcvhost = [200.128.150.11]
16:25:25  7963 set_process_info:  7963 handling incoming connection from 
[200.128.150.11]
16:25:25  7963 host in host_reject_connection? no (option unset)
16:25:25  7963 host in sender_unqualified_hosts? no (option unset)
16:25:25  7963 host in recipient_unqualified_hosts? no (option unset)
16:25:25  7963 host in helo_verify_hosts? no (option unset)
16:25:25  7963 host in helo_try_verify_hosts? no (option unset)
16:25:25  7963 host in helo_accept_junk_hosts? no (option unset)
16:25:25  7963 expanding: $smtp_active_hostname ESMTP Exim 
$version_number $tod_full
16:25:25  7963    result: mail.abc.com ESMTP Exim 4.63 Sat, 16 Feb 2008 
16:25:25 +0200
16:25:25  7963 SMTP>> 220 mail.abc.com ESMTP Exim 4.63 Sat, 16 Feb 2008 
16:25:25 +0200
220 mail.abc.com ESMTP Exim 4.63 Sat, 16 Feb 2008 16:25:25 +0200
16:25:25  7963 smtp_setup_msg entered
HELO test.abc.com
16:26:07  7963 SMTP<< HELO test.abc.com
16:26:07  7963 test.abc.com in helo_lookup_domains? no (end of list)
16:26:07  7963 sender_fullhost = (test.abc.com) [200.128.150.11]
16:26:07  7963 sender_rcvhost = [200.128.150.11] (helo=test.abc.com)
16:26:07  7963 set_process_info:  7963 handling incoming connection from 
(test.abc.com) [200.128.150.11]
250 mail.abc.com Hello test.abc.com [200.128.150.11]
16:26:07  7963 SMTP>> 250 mail.abc.com Hello test.abc.com [200.128.150.11]
MAIL FROM: <herbert@???>
16:26:38  7963 SMTP<< MAIL FROM: <herbert@???>
16:26:38  7963 SMTP>> 250 OK
250 OK
RCPT TO: qwerty@???
16:26:54  7963 SMTP<< RCPT TO: qwerty@???
16:26:54  7963 using ACL "acl_check_rcpt"
16:26:54  7963 processing "accept"
16:26:54  7963 check hosts = :
16:26:54  7963 host in ":"? no (end of list)
16:26:54  7963 accept: condition test failed
16:26:54  7963 processing "deny"
16:26:54  7963 check domains = +local_domains
16:26:54  7963 abc.com in "abc.com:fax.abc.com"? yes (matched "abc.com")
16:26:54  7963 abc.com in "+local_domains"? yes (matched "+local_domains")
16:26:54  7963 check local_parts = ^[.] : ^.*[@%!/|]
16:26:54  7963 qwerty in "^[.] : ^.*[@%!/|]"? no (end of list)
16:26:54  7963 deny: condition test failed
16:26:54  7963 processing "deny"
16:26:54  7963 check domains = !+local_domains
16:26:54  7963 cached yes match for +local_domains
16:26:54  7963 cached lookup data = NULL
16:26:54  7963 abc.com in "!+local_domains"? no (matched 
"!+local_domains" - cached)
16:26:54  7963 deny: condition test failed
16:26:54  7963 processing "accept"
16:26:54  7963 check local_parts = postmaster
16:26:54  7963 qwerty in "postmaster"? no (end of list)
16:26:54  7963 accept: condition test failed
16:26:54  7963 processing "accept"
16:26:54  7963 check hosts = +relay_from_hosts
16:26:54  7963 host in 
"127.0.0.1/8:192.168.1.0/24:192.168.2.2/32:212.31.97.244/32:194.30.136.0/24:212.31.96.0/24:217.27.32.0/24:217.27.33.0/24:194.30.141.0/24:195.56.188.99/32:195.88.45.11/24:81.4.156.130/24:83.168.5.51/24:83.168.1.160/32:83.168.4.133/32:10.0.1.1/32:213.128.150.46/32:213.128.150.11/32:83.235.173.194/32:193.179.188.3/32:10.8.0.0/24:217.172.150.9/32:195.23.33.227/32:212.31.111.107/32:10.11.250.0/24:212.31.97.245/32"? 
no (end of list)
16:26:54  7963 host in "+relay_from_hosts"? no (end of list)
16:26:54  7963 accept: condition test failed
16:26:54  7963 processing "accept"
16:26:54  7963 check authenticated = *
16:26:54  7963 accept: condition test failed
16:26:54  7963 processing "require"
16:26:54  7963 check domains = +local_domains : +relay_domains
16:26:54  7963 cached yes match for +local_domains
16:26:54  7963 cached lookup data = NULL
16:26:54  7963 abc.com in "+local_domains : +relay_domains"? yes 
(matched "+local_domains" - cached)
16:26:54  7963 require: condition test succeeded
16:26:54  7963 processing "require"
16:26:54  7963 check verify = recipient
16:26:54  7963 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
16:26:54  7963 Verifying qwerty@???
16:26:54  7963 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
16:26:54  7963 Considering qwerty@???
16:26:54  7963 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
16:26:54  7963 routing qwerty@???
16:26:54  7963 --------> dnslookup router <--------
16:26:54  7963 local_part=qwerty domain=abc.com
16:26:54  7963 checking domains
16:26:54  7963 cached yes match for +local_domains
16:26:54  7963 cached lookup data = NULL
16:26:54  7963 abc.com in "! +local_domains"? no (matched "! 
+local_domains" - cached)
16:26:54  7963 dnslookup router skipped: domains mismatch
16:26:54  7963 --------> amavis router <--------
16:26:54  7963 local_part=qwerty domain=abc.com
16:26:54  7963 checking "condition"
16:26:54  7963 expanding: $interface_port
16:26:54  7963    result: -1
16:26:54  7963 expanding: 10025
16:26:54  7963    result: 10025
16:26:54  7963 expanding: $received_protocol
16:26:54  7963    result: smtp
16:26:54  7963 expanding: spam-scanned
16:26:54  7963    result: spam-scanned
16:26:54  7963 expanding: $sender_address
16:26:54  7963    result: herbert@???
16:26:54  7963 expanding:
16:26:54  7963    result:
16:26:54  7963 condition: or {{eq {$interface_port}{10025}} {eq 
{$received_protocol}{spam-scanned}} {eq {$sender_address}{}} }
16:26:54  7963    result: false
16:26:54  7963 expanding: 0
16:26:54  7963    result: 0
16:26:54  7963 skipping: result is not used
16:26:54  7963 expanding: 1
16:26:54  7963    result: 1
16:26:54  7963 expanding: ${if or {{eq {$interface_port}{10025}} {eq 
{$received_protocol}{spam-scanned}} {eq {$sender_address}{}} }{0}{1}}
16:26:54  7963    result: 1
16:26:54  7963 calling amavis router
16:26:54  7963 amavis router called for qwerty@???
16:26:54  7963   domain = abc.com
16:26:54  7963 route_item = * localhost byname
16:26:54  7963 abc.com in "*"? yes (matched "*")
16:26:54  7963 original list of hosts = "localhost" options = byname
16:26:54  7963 expanded list of hosts = "localhost" options = byname
16:26:54  7963 set transport amavis
16:26:54  7963 finding IP address for localhost
16:26:54  7963 calling host_find_byname
16:26:54  7963 gethostbyname2(af=inet6) returned 1 (HOST_NOT_FOUND)
16:26:54  7963 Actual local interface address is 127.0.0.1 (lo)
16:26:54  7963 Actual local interface address is 10.100.100.20 (eth1)
16:26:54  7963 Actual local interface address is 192.168.1.10 (eth2)
16:26:54  7963 Actual local interface address is 172.16.26.1 (vmnet8)
16:26:54  7963 Actual local interface address is 192.168.65.1 (vmnet1)
16:26:54  7963 Actual local interface address is 
fe80::214:85ff:fe16:b7ee (eth2)
16:26:54  7963 Actual local interface address is fe80::250:56ff:fec0:8 
(vmnet8)
16:26:54  7963 Actual local interface address is ::1 (lo)
16:26:54  7963 Actual local interface address is fe80::250:56ff:fec0:1 
(vmnet1)
16:26:54  7963 Actual local interface address is 
fe80::214:85ff:fe16:b7e2 (eth1)
16:26:54  7963 Configured local interface: address=127.0.0.1 port=10025
16:26:54  7963 local host found for non-MX address
16:26:54  7963 fully qualified name = localhost.localdomain
16:26:54  7963 gethostbyname2 looked up these IP addresses:
16:26:54  7963   name=localhost.localdomain address=127.0.0.1
16:26:54  7963 remote host address is the local host: abc.com: 
configured to try delivery anyway
16:26:54  7963 queued for amavis transport: local_part = qwerty
16:26:54  7963 domain = abc.com
16:26:54  7963   errors_to=NULL
16:26:54  7963   domain_data=NULL localpart_data=NULL
16:26:54  7963 routed by amavis router
16:26:54  7963   envelope to: qwerty@???
16:26:54  7963   transport: amavis
16:26:54  7963   host localhost.localdomain [127.0.0.1]
16:26:54  7963 ----------- end verify ------------
16:26:54  7963 require: condition test succeeded
16:26:54  7963 processing "accept"
16:26:54  7963 accept: condition test succeeded
16:26:54  7963 SMTP>> 250 Accepted
250 Accepted
DATA
16:27:46  7963 SMTP<< DATA
16:27:46  7963 SMTP>> 354 Enter message, ending with "." on a line by itself
354 Enter message, ending with "." on a line by itself
16:27:46  7963 search_tidyup called
1234
1234
16:27:50  7963 host in ignore_fromline_hosts? no (option unset)
16:27:50  7963 >>Headers received:
16:27:50  7963
16:27:50  7963 search_tidyup called
16:27:50  7963 >>Headers after rewriting and local additions:
16:27:50  7963
.
16:27:52  7963 Data file written for message 1JQO14-00024R-Ew
16:27:52  7963 expanding: ${tod_full}
16:27:52  7963    result: Sat, 16 Feb 2008 16:27:52 +0200
16:27:52  7963 condition: def:sender_rcvhost
16:27:52  7963    result: true
16:27:52  7963 expanding: from $sender_rcvhost
16:27:52  7963
16:27:52  7963    result: from [200.128.150.11] (helo=test.abc.com)
16:27:52  7963
16:27:52  7963 condition: def:sender_ident
16:27:52  7963    result: false
16:27:52  7963 expanding: $sender_ident
16:27:52  7963    result:
16:27:52  7963 skipping: result is not used
16:27:52  7963 expanding: from ${quote_local_part:$sender_ident}
16:27:52  7963    result: from
16:27:52  7963 skipping: result is not used
16:27:52  7963 condition: def:sender_helo_name
16:27:52  7963    result: false
16:27:52  7963 expanding: (helo=$sender_helo_name)
16:27:52  7963
16:27:52  7963    result: (helo=)
16:27:52  7963
16:27:52  7963 skipping: result is not used
16:27:52  7963 expanding: ${if def:sender_ident {from 
${quote_local_part:$sender_ident} }}${if def:sender_helo_name 
{(helo=$sender_helo_name)
16:27:52  7963  }}
16:27:52  7963    result:
16:27:52  7963 skipping: result is not used
16:27:52  7963 condition: def:received_protocol
16:27:52  7963    result: true
16:27:52  7963 expanding: with $received_protocol
16:27:52  7963    result: with smtp
16:27:52  7963 condition: def:tls_cipher
16:27:52  7963    result: false
16:27:52  7963 expanding: ($tls_cipher)
16:27:52  7963
16:27:52  7963    result: ()
16:27:52  7963
16:27:52  7963 skipping: result is not used
16:27:52  7963 condition: def:sender_address
16:27:52  7963    result: true
16:27:52  7963 expanding: (envelope-from <$sender_address>)
16:27:52  7963
16:27:52  7963    result: (envelope-from <herbert@???>)
16:27:52  7963
16:27:52  7963 condition: def:received_for
16:27:52  7963    result: true
16:27:52  7963 expanding:
16:27:52  7963  for $received_for
16:27:52  7963    result:
16:27:52  7963  for qwerty@???
16:27:52  7963 expanding: Received: ${if def:sender_rcvhost {from 
$sender_rcvhost
16:27:52  7963  }{${if def:sender_ident {from 
${quote_local_part:$sender_ident} }}${if def:sender_helo_name 
{(helo=$sender_helo_name)
16:27:52  7963  }}}}by $primary_hostname ${if def:received_protocol 
{with $received_protocol}} ${if def:tls_cipher {($tls_cipher)
16:27:52  7963  }}(Exim $version_number)
16:27:52  7963  ${if def:sender_address {(envelope-from <$sender_address>)
16:27:52  7963  }}id $message_exim_id${if def:received_for {
16:27:52  7963  for $received_for}}
16:27:52  7963    result: Received: from [200.128.150.11] 
(helo=test.abc.com)
16:27:52  7963  by mail.abc.com with smtp (Exim 4.63)
16:27:52  7963  (envelope-from <herbert@???>)
16:27:52  7963  id 1JQO14-00024R-Ew
16:27:52  7963  for qwerty@???
16:27:52  7963 >>Generated Received: header line
16:27:52  7963 P Received: from [200.128.150.11] (helo=test.abc.com)
16:27:52  7963  by mail.abc.com with smtp (Exim 4.63)
16:27:52  7963  (envelope-from <herbert@???>)
16:27:52  7963  id 1JQO14-00024R-Ew
16:27:52  7963  for qwerty@???; Sat, 16 Feb 2008 16:27:52 +0200
16:27:52  7963 No Content-Type: header - presumably not a MIME message.
16:27:52  7963 using ACL "acl_check_data"
16:27:52  7963 processing "accept"
16:27:52  7963 accept: condition test succeeded
16:27:52  7963 calling local_scan(); timeout=300
16:27:52  7963 local_scan() returned 0 NULL
16:27:52  7963 expanding: ${tod_full}
16:27:52  7963    result: Sat, 16 Feb 2008 16:27:52 +0200
16:27:52  7963 LOG: MAIN
16:27:52  7963   <= herbert@??? H=(test.abc.com) [200.128.150.11] 
P=smtp S=244
16:27:52  7963 SMTP>> 250 OK id=1JQO14-00024R-Ew
250 OK id=1JQO14-00024R-Ew


**** SMTP testing: that is not a real message id!

16:27:52 7963 smtp_setup_msg entered
QUIT
16:28:29 7963 SMTP<< QUIT
16:28:29 7963 SMTP>> 221 mail.abc.com closing connection
221 mail.abc.com closing connection
16:28:29 7963 LOG: smtp_connection MAIN
16:28:29 7963 SMTP connection from (test.abc.com) [200.128.150.11]
closed by QUIT
16:28:29 7963 search_tidyup called
16:28:29 7963 >>>>>>>>>>>>>>>> Exim pid=7963 terminating with rc=0
>>>>>>>>>>>>>>>>





On 2008-02-16 12:27, Graeme Fowler wrote:
> Hi Zlatko
>
> On Fri, 2008-02-15 at 16:27 +0200, Zlatko Mesaros wrote:
> > I am trying to figure out the way to reject the users during the SMTP
> > dialog rather then send bounce messages.
> > Actually - I would like to reply with '550 User does not exist' if the
> > RCPT yields no valid user.
>
> You're almost there. You already have the relevant "require verify =
> recipient" clause in your config, so if your test runs show the
> recipients as being accepted then there's something in your routers
> which is accepting them - a verify run sends the recipient address
> through the routers, in order, to make sure it would be accepted.
>
> I have a sneaking suspicion that your Amavis config is probably at fault
> - can you post your routers for us to make sure what's happening? I'd
> pitch at there being no conditions on it, or conditions which only check
> domains.
>
> Also, if you can do a debug run again but this time include the SMTP
> "chat" (as you put it) within the debug run, it'll show you where and
> why your invalid recipients get accepted.
>
> Graeme
>
>
>


--
_________________________________________________
Zlatko Mesaros

Senior IT Engineer
Dashofer Holding Ltd.     Tel: (+357) 25 87 89 80
Limassol / Cyprus         Fax: (+357) 25 87 82 26
_________________________________________________