W dniu 2015-06-15 o 17:57, Jeremy Harris pisze:
> On 15/06/15 13:31, Jeremy Harris wrote:
>> On 15/06/15 11:46, Marcin Mirosław wrote:
>>> I wrongly configured event_action, I used too levels of brackets:
>>> event_action = ${if eq {msg:delivery}{$event_name} { {${lookup
>>> pgsql{SQL_POCZTA_WYCH}}} } }
>>>
>>> I added those line in transport. And then in main log I got:
>>> 2015-06-14 23:47:32 1Z4FfI-00048y-FX == aaaaaa@???
>>> R=dnslookup_batv T=external_smtp_batv defer (2): No such file or directory
>>>
>>> I spent a couple of minutes to find out what was the reason of this.
>>> Could it be possible to add some more information to logged information
>>> that this error comes from event_action?
>>
>> I'll have a think on that.
>
> The trouble here is that it was (probably) syntactically valid; the
> result of the expansion was not what you expected, but for this
> event it is ignored anyway - so there should not have been a
> semantic failure either.
>
> I'd like to see a debug run showing that it was actually the
> event that caused the defer.
Hi!
Thank you for both answers. I reproduced this situation on diffrent box,
using such event_action:
event_action = ${if eq {msg:delivery}{$event_name} { {${lookup
pgsql{select 1}}} } }
(I hope I didn't strip too much)
# exim -d+all -M 1Z4Zop-00089J-CO
> 21:16:55 1086 Exim version 4.85 uid=0 gid=0 pid=1086 D=fffdffff
> Berkeley DB: Berkeley DB 4.8.30: (2014-12-18)
> Support for: crypteq iconv() IPv6 Expand_dlfunc OpenSSL Content_Scanning DKIM Old_Demime PRDR OCSP Experimental_SRS Experimental_Event Experimental_DSN
> Lookups (built-in): lsearch wildlsearch nwildlsearch iplsearch cdb dbm dbmjz dbmnz dnsdb dsearch passwd pgsql
> Authenticators: cram_md5 plaintext spa
> Routers: accept dnslookup ipliteral manualroute queryprogram redirect
> Transports: appendfile/mailstore autoreply lmtp pipe smtp
> Fixed never_users: 0
> Size of off_t: 8
> Compiler: GCC [4.8.4]
> Library version: OpenSSL: Compile: OpenSSL 1.0.1o 12 Jun 2015
> Runtime: OpenSSL 1.0.1o 12 Jun 2015
> : built on: Sat Jun 13 19:59:56 2015
> Library version: PCRE: Compile: 8.36
> Runtime: 8.36 2014-09-26
> 21:16:55 1086 Total 12 lookups
> WHITELIST_D_MACROS unset
> TRUSTED_CONFIG_LIST unset
> 21:16:55 1086 changed uid/gid: forcing real = effective
> 21:16:55 1086 uid=0 gid=0 pid=1086
> 21:16:55 1086 auxiliary group list: <none>
> 21:16:55 1087 changed uid/gid: calling tls_validate_require_cipher
> 21:16:55 1087 uid=8 gid=12 pid=1087
> 21:16:55 1087 auxiliary group list: <none>
> 21:16:55 1086 tls_validate_require_cipher child 1087 ended: status=0x0
> 21:16:55 1086 configuration file is /etc/exim/exim.conf
> 21:16:55 1086 log selectors = 000004fe 00232321
> 21:16:55 1086 cwd=/etc/exim 4 args: exim -d+all -M 1Z4Zop-00089J-CO
> 21:16:55 1086 trusted user
> 21:16:55 1086 admin user
[...]
> 21:16:55 1086 >>>>>>>>>>>>>>>> Remote deliveries >>>>>>>>>>>>>>>> [175/4733]
> 21:16:55 1086 --------> test@??? <--------
> 21:16:55 1086 expanding: $return_path
> 21:16:55 1086 result: marcin@???
> 21:16:55 1086 expanding: niktnicniewieole
> 21:16:55 1086 result: niktnicniewieole
> 21:16:55 1086 prvs: hash source is '0608marcin@???'
> 21:16:55 1086 expanding: ${prvs {$return_path}{niktnicniewieole}}
> 21:16:55 1086 result: prvs=06088217e3=marcin@???
> 21:16:55 1086 search_tidyup called
> 21:16:55 1086 set_process_info: 1086 delivering 1Z4Zop-00089J-CO: waiting for a remote delivery subprocess to finish
> 21:16:55 1086 selecting on subprocess pipes
> 21:16:55 1089 changed uid/gid: remote delivery to test@??? with transport=external_smtp_batv
> 21:16:55 1089 uid=8 gid=12 pid=1089
> 21:16:55 1089 auxiliary group list: <none>
> 21:16:55 1089 set_process_info: 1089 delivering 1Z4Zop-00089J-CO using external_smtp_batv
> 21:16:55 1089 external_smtp_batv transport entered
> 21:16:55 1089 test@???
> 21:16:55 1089 checking status of example.com
> 21:16:55 1089 locking /var/spool/exim/db/retry.lockfile
> 21:16:55 1089 locked /var/spool/exim/db/retry.lockfile
> 21:16:55 1089 EXIM_DBOPEN(/var/spool/exim/db/retry)
> 21:16:55 1089 returned from EXIM_DBOPEN
> 21:16:55 1089 opened hints database /var/spool/exim/db/retry: flags=O_RDONLY
> 21:16:55 1089 dbfn_read: key=T:example.com:2606:2800:220:1:248:1893:25c8:1946
> 21:16:55 1089 dbfn_read: key=T:example.com:2606:2800:220:1:248:1893:25c8:1946:1Z4Zop-00089J-CO
> 21:16:55 1089 no message retry record
> 21:16:55 1089 example.com [2606:2800:220:1:248:1893:25c8:1946] status = usable
> 21:16:55 1089 2606:2800:220:1:248:1893:25c8:1946 in serialize_hosts? no (option unset)
> 21:16:55 1089 delivering 1Z4Zop-00089J-CO to example.com [2606:2800:220:1:248:1893:25c8:1946] (test@???)
> 21:16:55 1089 set_process_info: 1089 delivering 1Z4Zop-00089J-CO to example.com [2606:2800:220:1:248:1893:25c8:1946] (test@???)
> 21:16:55 1089 Connecting to example.com [2606:2800:220:1:248:1893:25c8:1946]:25 ... Event(tcp:connect): event_action=|${if eq {msg:delivery}{$event_name} {
> {${lookup pgsql{select 1}}} } }| delivery_IP=2606:2800:220:1:248:1893:25c8:1946
> 21:16:55 1089 expanding: msg:delivery
> 21:16:55 1089 result: msg:delivery
> 21:16:55 1089 expanding: $event_name
> 21:16:55 1089 result: tcp:connect
> 21:16:55 1089 condition: eq {msg:delivery}{$event_name}
> 21:16:55 1089 result: false
> 21:16:55 1089 expanding: select 1
> 21:16:55 1089 result: select 1
> 21:16:55 1089 skipping: result is not used
> 21:16:55 1089 expanding: {${lookup pgsql{select 1}}
> 21:16:55 1089 result: {
> 21:16:55 1089 skipping: result is not used
> 21:16:55 1089 expanding: ${if eq {msg:delivery}{$event_name} { {${lookup pgsql{select 1}}} } }
> 21:16:55 1089 result: }
> 21:16:55 1089 Event(tcp:connect): event_action returned " }"
> 21:16:55 1089 LOG: MAIN
> 21:16:55 1089 H=example.com [2606:2800:220:1:248:1893:25c8:1946] No such file or directory
> 21:16:56 1089 Event(msg:host:defer): event_action=|${if eq {msg:delivery}{$event_name} { {${lookup pgsql{select 1}}} } }| delivery_IP=2606:2800:220:1:248:18
> 93:25c8:1946
> 21:16:56 1089 expanding: msg:delivery
> 21:16:56 1089 result: msg:delivery
> 21:16:56 1089 expanding: $event_name
> 21:16:56 1089 result: msg:host:defer
> 21:16:56 1089 condition: eq {msg:delivery}{$event_name}
> 21:16:56 1089 result: false
> 21:16:56 1089 expanding: select 1
> 21:16:56 1089 result: select 1
> 21:16:56 1089 skipping: result is not used
> 21:16:56 1089 expanding: {${lookup pgsql{select 1}}
> 21:16:56 1089 result: {
> 21:16:56 1089 skipping: result is not used
> 21:16:56 1089 expanding: ${if eq {msg:delivery}{$event_name} { {${lookup pgsql{select 1}}} } }
> 21:16:56 1089 result: }
> 21:16:56 1089 Event(msg:host:defer): event_action returned " }"
> 21:16:56 1089 set_process_info: 1089 delivering 1Z4Zop-00089J-CO: just tried example.com [2606:2800:220:1:248:1893:25c8:1946] for test@???: result D
> EFER
> 21:16:56 1089 added retry item for T:example.com:2606:2800:220:1:248:1893:25c8:1946: errno=2 more_errno=0,A flags=2
> 21:16:56 1089 address match test: subject=*@example.com pattern=*
> 21:16:56 1089 example.com in "*"? yes (matched "*")
> 21:16:56 1089 *@example.com in "*"? yes (matched "*")
> 21:16:56 1089 checking status of example.com
> 21:16:56 1089 locking /var/spool/exim/db/retry.lockfile
> 21:16:56 1089 locked /var/spool/exim/db/retry.lockfile
> 21:16:56 1089 EXIM_DBOPEN(/var/spool/exim/db/retry)
> 21:16:56 1089 returned from EXIM_DBOPEN
> 21:16:56 1089 opened hints database /var/spool/exim/db/retry: flags=O_RDONLY
> 21:16:56 1089 dbfn_read: key=T:example.com:93.184.216.34
> 21:16:56 1089 dbfn_read: key=T:example.com:93.184.216.34:1Z4Zop-00089J-CO
> 21:16:56 1089 no message retry record
> 21:16:56 1089 example.com [93.184.216.34] status = usable
> 21:16:56 1089 93.184.216.34 in serialize_hosts? no (option unset)
> 21:16:56 1089 delivering 1Z4Zop-00089J-CO to example.com [93.184.216.34] (test@???)
> 21:16:56 1089 set_process_info: 1089 delivering 1Z4Zop-00089J-CO to example.com [93.184.216.34] (test@???)
> 21:16:56 1089 Connecting to example.com [93.184.216.34]:25 ... Event(tcp:connect): event_action=|${if eq {msg:delivery}{$event_name} { {${lookup pgsql{selec
> t 1}}} } }| delivery_IP=93.184.216.34
> 21:16:56 1089 expanding: msg:delivery
> 21:16:56 1089 result: msg:delivery
> 21:16:56 1089 expanding: $event_name
> 21:16:56 1089 result: tcp:connect
> 21:16:56 1089 condition: eq {msg:delivery}{$event_name}
> 21:16:56 1089 result: false
> 21:16:56 1089 expanding: select 1
> 21:16:56 1089 result: select 1
> 21:16:56 1089 skipping: result is not used
> 21:16:56 1089 expanding: {${lookup pgsql{select 1}}
> 21:16:56 1089 result: {
> 21:16:56 1089 skipping: result is not used
> 21:16:56 1089 expanding: ${if eq {msg:delivery}{$event_name} { {${lookup pgsql{select 1}}} } }
> 21:16:56 1089 result: }
> 21:16:56 1089 Event(tcp:connect): event_action returned " }"
> 21:16:56 1089 LOG: MAIN
> 21:16:56 1089 H=example.com [93.184.216.34] No such file or directory
> 21:16:56 1089 Event(msg:host:defer): event_action=|${if eq {msg:delivery}{$event_name} { {${lookup pgsql{select 1}}} } }| delivery_IP=93.184.216.34
> 21:16:56 1089 expanding: msg:delivery
> 21:16:56 1089 result: msg:delivery
> 21:16:56 1089 expanding: $event_name
> 21:16:56 1089 result: msg:host:defer
> 21:16:56 1089 condition: eq {msg:delivery}{$event_name}
> 21:16:56 1089 result: false
> 21:16:56 1089 expanding: select 1
> 21:16:56 1089 result: select 1
> 21:16:56 1089 skipping: result is not used
> 21:16:56 1089 expanding: {${lookup pgsql{select 1}}
> 21:16:56 1089 result: {
> 21:16:56 1089 skipping: result is not used
> 21:16:56 1089 expanding: ${if eq {msg:delivery}{$event_name} { {${lookup pgsql{select 1}}} } }
> 21:16:56 1089 result: }
> 21:16:56 1089 Event(msg:host:defer): event_action returned " }"
> 21:16:56 1089 set_process_info: 1089 delivering 1Z4Zop-00089J-CO: just tried example.com [93.184.216.34] for test@???: result DEFER
> 21:16:56 1089 added retry item for T:example.com:93.184.216.34: errno=2 more_errno=0,A flags=2
> 21:16:56 1089 all IP addresses skipped or deferred at least one address
> 21:16:56 1089 updating wait-external_smtp_batv database
> 21:16:56 1089 locking /var/spool/exim/db/wait-external_smtp_batv.lockfile
> 21:16:56 1089 locked /var/spool/exim/db/wait-external_smtp_batv.lockfile
> 21:16:56 1089 EXIM_DBOPEN(/var/spool/exim/db/wait-external_smtp_batv)
> 21:16:56 1089 returned from EXIM_DBOPEN
> 21:16:56 1089 opened hints database /var/spool/exim/db/wait-external_smtp_batv: flags=O_RDWR
> 21:16:56 1089 dbfn_read: key=example.com
> 21:16:56 1089 already listed for example.com
> 21:16:56 1089 Leaving external_smtp_batv transport
> 21:16:56 1089 set_process_info: 1089 delivering 1Z4Zop-00089J-CO (just run external_smtp_batv for test@??? in subprocess)
