Thank you Jeremy for your quick reply.
On Saturday 12 December 2015 13:34:39 Jeremy Harris wrote:
> On 11/12/15 17:20, Rainer Dorsch wrote:
> > I do not expect that there is any expert out there who could explain right
> > away what is going wrong, but does anybody know how to debug such an
> > issue? Can I log which .forward rule did apply?
>
> Have a play with a "-d-all+delivery+filter" commandline option.
>
>
> http://exim.org/exim-html-current/doc/html/spec_html/ch-the_exim_command_lin
> e.html#SECID39
That was indeed helpful and it provides great log messages. Though the issue is still
not entirely clear for me:
Apparently, the message is identified as an error_message:
Dec 12 16:53:03 netcup exim4[13510]: 14658 Condition is true: error_message
The manual
http://www.exim.org/exim-html-current/doc/html/spec_html/filter_ch-forwarding_and_filtering_in_exim.html
mentions error_message in the context of a delivery failure message (though it is not
entirely clear to me if it applies only to the delivery failure message).
In my case it is definitely no delivery failure message and from the log for me no
obvious other error is visible either (the "no IP address found for host" shows also on
some other messages which work ok).
Does anybody see why the message below triggers an error_message?
Dec 12 16:52:58 netcup exim4[13510]: 13852 Connection request from
115.73.16.126 port 26375
Dec 12 16:52:58 netcup exim4[13510]: 13852 1 SMTP accept process running
Dec 12 16:52:58 netcup exim4[13510]: 13852 Listening...
Dec 12 16:52:58 netcup exim4[13510]: 14645 Process 14645 is handling incoming
connection from [115.73.16.126]
Dec 12 16:52:58 netcup exim4[13510]: 14645 LOG: host_lookup_failed MAIN
Dec 12 16:52:58 netcup exim4[13510]: 14645 no IP address found for host
adsl.viettel.vn (during SMTP connection from [115.73.16.126])
Dec 12 16:52:58 netcup exim4[13510]: 14645 Process 14645 is ready for new
message
Dec 12 16:53:00 netcup exim4[13510]: 14645 R: system_aliases for
metzingen@???
Dec 12 16:53:00 netcup exim4[13510]: 14645 R: system_aliases for rd@???
Dec 12 16:53:00 netcup exim4[13510]: 14645 R: lowuid_aliases for rd@???
(UID 2809)
Dec 12 16:53:00 netcup exim4[13510]: 14645 R: local_user for rd@???
Dec 12 16:53:00 netcup exim4[13510]: PDKIM >> Hashed body data, canonicalized
>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
Dec 12 16:53:00 netcup exim4[13510]: PDKIM
<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
<<<<<<<<<<<<<<
Dec 12 16:53:00 netcup exim4[13510]: 14645 trying server 127.0.0.1, port 783
Dec 12 16:53:00 netcup spamd[12400]: spamd: connection from localhost
[127.0.0.1]:40029 to port 783, fd 5
Dec 12 16:53:00 netcup spamd[12400]: spamd: setuid to Debian-exim succeeded
Dec 12 16:53:00 netcup spamd[12400]: spamd: checking message (unknown) for
Debian-exim:101
Dec 12 16:53:03 netcup spamd[12400]: spamd: identified spam (16.5/5.0) for Debian-
exim:101 in 2.5 seconds, 639 bytes.
Dec 12 16:53:03 netcup spamd[12400]: spamd: result: Y 16 -
BODY_URI_ONLY,FSL_HELO_BARE_IP_2,MISSING_MID,PYZOR_CHECK,RCVD_HELO_IP_M
ISMATCH,RCVD_IN_BRBL_LASTEXT,RCVD_IN_PBL,RCVD_NUMERIC_HELO,RDNS_NONE,
URIBL_BLOCKED,URIBL_DBL_ABUSE_BOTCC,URI_HEX scantime=
2.5,size=639,user=Debian-
exim,uid=101,required_score=5.0,rhost=localhost,raddr=127.0.0.1,rport=40029,mid
=(unknown),autolearn=spam autolearn_force=no
Dec 12 16:53:03 netcup exim4[13510]: 14645 unspool_mbox(): unlinking
'/var/spool/exim4/scan/1a7mTk-0003oD-BM/1a7mTk-0003oD-BM.eml'
Dec 12 16:53:03 netcup exim4[13510]: 14645 LOG: MAIN
Dec 12 16:53:03 netcup exim4[13510]: 14645 <= <> H=(115.73.55.172)
[115.73.16.126] P=smtp S=2605
Dec 12 16:53:03 netcup exim4[13510]: 14645 forked delivery process 14656
Dec 12 16:53:03 netcup exim4[13510]: 14645 Process 14645 is ready for new
message
Dec 12 16:53:03 netcup spamd[15650]: prefork: child states: II
Dec 12 16:53:03 netcup exim4[13510]: 14645 LOG: smtp_connection MAIN
Dec 12 16:53:03 netcup exim4[13510]: 14645 SMTP connection from
(115.73.55.172) [115.73.16.126] closed by QUIT
Dec 12 16:53:03 netcup exim4[13510]: 13852 child 14645 ended: status=0x0
Dec 12 16:53:03 netcup exim4[13510]: 13852 normal exit, 0
Dec 12 16:53:03 netcup exim4[13510]: 13852 0 SMTP accept processes now running
Dec 12 16:53:03 netcup exim4[13510]: 13852 Listening...
Dec 12 16:53:03 netcup exim4[13510]: 14656 Exim version 4.84 uid=101 gid=103
pid=14656 D=40200
Dec 12 16:53:03 netcup exim4[13510]: Berkeley DB: Berkeley DB 5.3.28: (September
9, 2013)
Dec 12 16:53:03 netcup exim4[13510]: Support for: crypteq iconv() IPv6 PAM Perl
Expand_dlfunc GnuTLS move_frozen_messages Content_Scanning DKIM Old_Demime
PRDR OCSP
Dec 12 16:53:03 netcup exim4[13510]: Lookups (built-in): lsearch wildlsearch
nwildlsearch iplsearch cdb dbm dbmjz dbmnz dnsdb dsearch ldap ldapdn ldapm mysql
nis nis0 passwd pgsql sqlite
Dec 12 16:53:03 netcup exim4[13510]: Authenticators: cram_md5 cyrus_sasl dovecot
plaintext spa
Dec 12 16:53:03 netcup exim4[13510]: Routers: accept dnslookup ipliteral iplookup
manualroute queryprogram redirect
Dec 12 16:53:03 netcup exim4[13510]: Transports: appendfile/maildir/mailstore/mbx
autoreply lmtp pipe smtp
Dec 12 16:53:03 netcup exim4[13510]: Fixed never_users: 0
Dec 12 16:53:03 netcup exim4[13510]: Size of off_t: 8
Dec 12 16:53:03 netcup exim4[13510]: Compiler: GCC [4.9.2]
Dec 12 16:53:03 netcup exim4[13510]: Library version: GnuTLS: Compile: 3.3.8
Dec 12 16:53:03 netcup exim4[13510]: Runtime: 3.3.8
Dec 12 16:53:03 netcup exim4[13510]: Library version: Cyrus SASL: Compile: 2.1.26
Dec 12 16:53:03 netcup exim4[13510]: Runtime: 2.1.26 [Cyrus SASL]
Dec 12 16:53:03 netcup exim4[13510]: Library version: PCRE: Compile: 8.35
Dec 12 16:53:03 netcup exim4[13510]: Runtime: 8.35 2014-04-04
Dec 12 16:53:03 netcup exim4[13510]: Library version: MySQL: Compile: 5.5.42
[(Debian)]
Dec 12 16:53:03 netcup exim4[13510]: Runtime: 5.5.46
Dec 12 16:53:03 netcup exim4[13510]: Library version: SQLite: Compile: 3.8.7.4
Dec 12 16:53:03 netcup exim4[13510]: Runtime: 3.8.7.1
Dec 12 16:53:03 netcup exim4[13510]: WHITELIST_D_MACROS: "OUTGOING"
Dec 12 16:53:03 netcup exim4[13510]: TRUSTED_CONFIG_LIST:
"/etc/exim4/trusted_configs"
Dec 12 16:53:03 netcup exim4[13510]: 14656 configuration file is
/var/lib/exim4/config.autogenerated
Dec 12 16:53:03 netcup exim4[13510]: 14656 log selectors = 00000ffc 00632001
Dec 12 16:53:03 netcup exim4[13510]: 14656 cwd=/var/spool/exim4 4 args:
/usr/sbin/exim4 -d=0x40200 -Mc 1a7mTk-0003oD-BM
Dec 12 16:53:03 netcup exim4[13510]: 14656 trusted user
Dec 12 16:53:03 netcup exim4[13510]: 14656 admin user
Dec 12 16:53:03 netcup exim4[13510]: 14656 R: system_aliases for
metzingen@???
Dec 12 16:53:03 netcup exim4[13510]: 14656 R: system_aliases for rd@???
Dec 12 16:53:03 netcup exim4[13510]: 14656 R: userforward for rd@???
Dec 12 16:53:03 netcup exim4[13510]: 14658 Condition is true: error_message
Dec 12 16:53:03 netcup exim4[13510]: 14658 writing filter log as euid 2809
