Re: [Exim] Problem with transport_filter

Top Page
Delete this message
Reply to this message
Author: Lichi Cosmin
Date:  
To: exim-users
Subject: Re: [Exim] Problem with transport_filter
--
On Friday 04 July 2003 14:40, you wrote:
> On Fri, 4 Jul 2003, Lichi Cosmin wrote:
> >    I run exim with -d, and the things are the same...

>
> Post the output so we can see it, please.


I have attached the output...
--
This is the output when I run exim with -t and I send a message
from root to a user, with a simple transport_filter in configure
file.


root@clichi-vm:/var/spool/mail# /usr/exim/bin/exim -d -t
Exim version 4.20 uid=0 gid=0 pid=3261 D=fbb95cfd
Berkeley DB: Sleepycat Software: Berkeley DB 3.3.11: (July 12, 2001)
Support for:
Authenticators:
Routers: accept dnslookup ipliteral manualroute queryprogram redirect
Transports: appendfile autoreply pipe smtp
changed uid/gid: forcing real = effective
uid=0 gid=0 pid=3261
auxiliary group list: <none>
configuration file is /usr/exim/configure
log selector = 020d99d8
trusted user
admin user
changed uid/gid: privilege not needed
uid=0 gid=0 pid=3261
auxiliary group list: <none>
originator: uid=0 gid=0 login=root name=
sender address = root@???
set_process_info: 3261 accepting a local non-SMTP message from <root@???>
Sender: root@???
search_tidyup called
From: <root@???>
To: <cosmin@???>
Subject: test

>>Headers received:

From: <root@???>
To: <cosmin@???>
Subject: test

rewrite_one_header: type=F:
From: <root@???>
rewrite_one_header: type=T:
To: <cosmin@???>
search_tidyup called
>>Headers after local additions:

P Received: from root by clichi-vm.iavx.ro with local (Exim 4.20)
        id 19YQvV-0000qb-GT
        for cosmin@???; Fri, 04 Jul 2003 15:49:05 +0200
F From: <root@???>
T To: <cosmin@???>
  Subject: test
I Message-Id: <E19YQvV-0000qb-GT@???>
  Date: Fri, 04 Jul 2003 15:49:05 +0200


test
.
Data file written for message 19YQvV-0000qb-GT
calling local_scan(); timeout=300
local_scan() returned 0 NULL
Writing spool header file
Size of headers = 312
LOG: MAIN
<= root@??? U=root P=local S=318
search_tidyup called
>>>>>>>>>>>>>>>> Exim pid=3261 terminating with rc=0 >>>>>>>>>>>>>>>>

set_process_info: 3262 delivering 19YQvV-0000qb-GT
reading spool file 19YQvV-0000qb-GT-H
user=root uid=0 gid=0 sender=root@???
sender_local=1 ident=root
Non-recipients:
Empty Tree
---- End of tree ----
recipients_count=1
body_linecount=1 message_linecount=8
Delivery address list:
cosmin@???
locking /var/spool/exim/db/retry.lockfile
locked /var/spool/exim/db/retry.lockfile
no retry data available
>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>

Considering: cosmin@???
unique = cosmin@???
no domain retry record
no address retry record
cosmin@???: queued for routing
>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>

routing cosmin@???
--------> dnslookup router <--------
local_part=cosmin domain=clichi-vm.iavx.ro
checking domains
clichi-vm.iavx.ro in "@"? yes (matched "@")
clichi-vm.iavx.ro in "! +local_domains"? no (matched "! +local_domains")
dnslookup router skipped: domains mismatch
--------> system_aliases router <--------
local_part=cosmin domain=clichi-vm.iavx.ro
calling system_aliases router
rda_interpret (string): ${lookup{$local_part}lsearch{/etc/mail/aliases}}
search_open: lsearch "/etc/mail/aliases"
search_find: file="/etc/mail/aliases"
key="cosmin" partial=-1 affix=NULL starflags=0
LRU list:
8/etc/mail/aliases
End
internal_search_find: file="/etc/mail/aliases"
type=lsearch key="cosmin"
file lookup required for cosmin
in /etc/mail/aliases
lookup failed
expanded:
file is not a filter file
parse_forward_list:
system_aliases router declined for cosmin@???
--------> userforward router <--------
local_part=cosmin domain=clichi-vm.iavx.ro
checking for local user
calling userforward router
rda_interpret (file): $home/.forward
expanded: /home/cosmin/.forward
stat(/home/cosmin/.)=0
/home/cosmin/.forward does not exist
userforward router declined for cosmin@???
--------> localuser router <--------
local_part=cosmin domain=clichi-vm.iavx.ro
checking for local user
finduser used cached passwd data for cosmin
calling localuser router
localuser router called for cosmin@???
domain = clichi-vm.iavx.ro
set transport local_delivery
queued for local_delivery transport: local_part = cosmin
domain = clichi-vm.iavx.ro
errors_to=NULL
domain_data=NULL localpart_data=NULL
routed by localuser router
envelope to: cosmin@???
transport: local_delivery
>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>

After routing:
  Local deliveries:
    cosmin@???
  Remote deliveries:
  Failed addresses:
  Deferred addresses:
search_tidyup called

>>>>>>>>>>>>>>>> Local deliveries >>>>>>>>>>>>>>>>

--------> cosmin@??? <--------
locking /var/spool/exim/db/retry.lockfile
locked /var/spool/exim/db/retry.lockfile
no retry data available
search_tidyup called
root@clichi-vm:/var/spool/mail# changed uid/gid: local delivery to cosmin <cosmin@???> transport=local_delivery
uid=1000 gid=100 pid=3263
auxiliary group list: <none>
home=/home/cosmin current=/home/cosmin
set_process_info: 3263 delivering 19YQvV-0000qb-GT to cosmin using local_delivery
direct command:
argv[0] = /usr/test/bin/bd/filter
direct command after expansion:
argv[0] = usr/test/bin/bd/filter
appendfile transport entered
appendfile: mode=660 notify_comsat=0 quota=0
file=/var/mail/cosmin format=unix
message_prefix=From ${if def:return_path{$return_path}{MAILER-DAEMON}} ${tod_bsdinbox}\n
message_suffix=\n
locking by lockfile fcntl
lock name: /var/mail/cosmin.lock
hitch name: /var/mail/cosmin.lock.clichi-vm.iavx.ro.3f0585d6.00000cbf
lock file created
mailbox /var/mail/cosmin is locked
writing to file /var/mail/cosmin
writing data block fd=5 size=53 timeout=0
process 3264 running as transport filter: write=8 read=9
writing data block fd=8 size=441 timeout=0
writing error 32: Broken pipe
process 3265 writing to transport filter
copying from the filter
waiting for filter process
filter process returned 69
waiting for writing process
end of filtering transport writing: yield=0
errno=32 more_errno=0
appendfile yields 1 with errno=32 more_errno=0
search_tidyup called
local_delivery transport returned DEFER for cosmin@???
added retry item for T:cosmin@???: errno=32 0 flags=0
post-process cosmin@??? (1)
LOG: MAIN
== cosmin@??? R=localuser T=local_delivery defer (32): Broken pipe: error while writing to /var/mail/cosmin
>>>>>>>>>>>>>>>> deliveries are done >>>>>>>>>>>>>>>>

changed uid/gid: post-delivery tidying
uid=0 gid=0 pid=3262
auxiliary group list: <none>
set_process_info: 3262 tidying up after delivering 19YQvV-0000qb-GT
Processing retry items
Succeeded addresses:
Failed addresses:
Deferred addresses:
cosmin@???
locking /var/spool/exim/db/retry.lockfile
locked /var/spool/exim/db/retry.lockfile
opened hints database /var/spool/exim/db/retry: flags=2
address match: subject=cosmin@??? pattern=*
clichi-vm.iavx.ro in "*"? yes (matched "*")
cosmin@??? in "*"? yes (matched "*")
retry for T:cosmin@??? = *
dbfn_read: key=T:cosmin@???
Writing retry data for T:cosmin@???
first failed=1057326550 last try=1057326550 next try=1057327450 expired=0
error 32 0: Broken pipe
dbfn_write: key=T:cosmin@???
end of retry processing
time on queue = 33s
warning counts: required 0 done 0
delivery deferred: update_spool=1 header_rewritten=0
Writing spool header file
Size of headers = 312
end delivery of 19YQvV-0000qb-GT
search_tidyup called
search_tidyup called

root@clichi-vm:/var/spool/mail#

---------------------------------------------------------------------------------------------
And this is the same message, but no transport_filter in configure file


root@clichi-vm:/var/spool/mail# /usr/exim/bin/exim -d -t
Exim version 4.20 uid=0 gid=0 pid=3316 D=fbb95cfd
Berkeley DB: Sleepycat Software: Berkeley DB 3.3.11: (July 12, 2001)
Support for:
Authenticators:
Routers: accept dnslookup ipliteral manualroute queryprogram redirect
Transports: appendfile autoreply pipe smtp
changed uid/gid: forcing real = effective
uid=0 gid=0 pid=3316
auxiliary group list: <none>
configuration file is /usr/exim/configure
log selector = 020d99d8
trusted user
admin user
changed uid/gid: privilege not needed
uid=0 gid=0 pid=3316
auxiliary group list: <none>
originator: uid=0 gid=0 login=root name=
sender address = root@???
set_process_info: 3316 accepting a local non-SMTP message from <root@???>
Sender: root@???
search_tidyup called
From: <root@???>
To: <cosmin@???>
Subject: test1

>>Headers received:

From: <root@???>
To: <cosmin@???>
Subject: test1

rewrite_one_header: type=F:
From: <root@???>
rewrite_one_header: type=T:
To: <cosmin@???>
search_tidyup called
>>Headers after local additions:

P Received: from root by clichi-vm.iavx.ro with local (Exim 4.20)
        id 19YR0H-0000rU-Pm
        for cosmin@???; Fri, 04 Jul 2003 15:54:00 +0200
F From: <root@???>
T To: <cosmin@???>
  Subject: test1
I Message-Id: <E19YR0H-0000rU-Pm@???>
  Date: Fri, 04 Jul 2003 15:54:00 +0200


test1
.
Data file written for message 19YR0H-0000rU-Pm
calling local_scan(); timeout=300
local_scan() returned 0 NULL
Writing spool header file
Size of headers = 313
LOG: MAIN
<= root@??? U=root P=local S=320
search_tidyup called
>>>>>>>>>>>>>>>> Exim pid=3316 terminating with rc=0 >>>>>>>>>>>>>>>>

set_process_info: 3317 delivering 19YR0H-0000rU-Pm
reading spool file 19YR0H-0000rU-Pm-H
user=root uid=0 gid=0 sender=root@???
sender_local=1 ident=root
Non-recipients:
Empty Tree
---- End of tree ----
recipients_count=1
body_linecount=1 message_linecount=8
Delivery address list:
cosmin@???
locking /var/spool/exim/db/retry.lockfile
locked /var/spool/exim/db/retry.lockfile
no retry data available
>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>

Considering: cosmin@???
unique = cosmin@???
no domain retry record
no address retry record
cosmin@???: queued for routing
>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>

routing cosmin@???
--------> dnslookup router <--------
local_part=cosmin domain=clichi-vm.iavx.ro
checking domains
clichi-vm.iavx.ro in "@"? yes (matched "@")
clichi-vm.iavx.ro in "! +local_domains"? no (matched "! +local_domains")
dnslookup router skipped: domains mismatch
--------> system_aliases router <--------
local_part=cosmin domain=clichi-vm.iavx.ro
calling system_aliases router
rda_interpret (string): ${lookup{$local_part}lsearch{/etc/mail/aliases}}
search_open: lsearch "/etc/mail/aliases"
search_find: file="/etc/mail/aliases"
key="cosmin" partial=-1 affix=NULL starflags=0
LRU list:
8/etc/mail/aliases
End
internal_search_find: file="/etc/mail/aliases"
type=lsearch key="cosmin"
file lookup required for cosmin
in /etc/mail/aliases
lookup failed
expanded:
file is not a filter file
parse_forward_list:
system_aliases router declined for cosmin@???
--------> userforward router <--------
local_part=cosmin domain=clichi-vm.iavx.ro
checking for local user
calling userforward router
rda_interpret (file): $home/.forward
expanded: /home/cosmin/.forward
stat(/home/cosmin/.)=0
/home/cosmin/.forward does not exist
userforward router declined for cosmin@???
--------> localuser router <--------
local_part=cosmin domain=clichi-vm.iavx.ro
checking for local user
finduser used cached passwd data for cosmin
calling localuser router
localuser router called for cosmin@???
domain = clichi-vm.iavx.ro
set transport local_delivery
queued for local_delivery transport: local_part = cosmin
domain = clichi-vm.iavx.ro
errors_to=NULL
domain_data=NULL localpart_data=NULL
routed by localuser router
envelope to: cosmin@???
transport: local_delivery
>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>

After routing:
  Local deliveries:
    cosmin@???
  Remote deliveries:
  Failed addresses:
  Deferred addresses:
search_tidyup called

>>>>>>>>>>>>>>>> Local deliveries >>>>>>>>>>>>>>>>

--------> cosmin@??? <--------
locking /var/spool/exim/db/retry.lockfile
locked /var/spool/exim/db/retry.lockfile
no retry data available
search_tidyup called
changed uid/gid: local delivery to cosmin <cosmin@???> transport=local_delivery
uid=1000 gid=100 pid=3318
auxiliary group list: <none>
home=/home/cosmin current=/home/cosmin
set_process_info: 3318 delivering 19YR0H-0000rU-Pm to cosmin using local_delivery
appendfile transport entered
appendfile: mode=660 notify_comsat=0 quota=0
file=/var/mail/cosmin format=unix
message_prefix=From ${if def:return_path{$return_path}{MAILER-DAEMON}} ${tod_bsdinbox}\n
message_suffix=\n
locking by lockfile fcntl
lock name: /var/mail/cosmin.lock
hitch name: /var/mail/cosmin.lock.clichi-vm.iavx.ro.3f0586fb.00000cf6
lock file created
mailbox /var/mail/cosmin is locked
writing to file /var/mail/cosmin
writing data block fd=5 size=53 timeout=0
writing data block fd=5 size=443 timeout=0
writing data block fd=5 size=1 timeout=0
root@clichi-vm:/var/spool/mail# appendfile yields 0 with errno=0 more_errno=0
search_tidyup called
journalling cosmin@???
local_delivery transport returned OK for cosmin@???
post-process cosmin@??? (0)
cosmin@??? delivered
LOG: MAIN
=> cosmin <cosmin@???> R=localuser T=local_delivery
>>>>>>>>>>>>>>>> deliveries are done >>>>>>>>>>>>>>>>

changed uid/gid: post-delivery tidying
uid=0 gid=0 pid=3317
auxiliary group list: <none>
set_process_info: 3317 tidying up after delivering 19YR0H-0000rU-Pm
Processing retry items
Succeeded addresses:
cosmin@???: no retry items
Failed addresses:
Deferred addresses:
end of retry processing
LOG: MAIN
Completed
end delivery of 19YR0H-0000rU-Pm
search_tidyup called
search_tidyup called

root@clichi-vm:/var/spool/mail#

____________________________________________________________________________________________

The program used as transport_filter is working...
This is the output when I send a mail from root to root
with the transport_filter

root@clichi-vm:/var/spool/mail# /usr/exim/bin/exim -d -t
Exim version 4.20 uid=0 gid=0 pid=3371 D=fbb95cfd
Berkeley DB: Sleepycat Software: Berkeley DB 3.3.11: (July 12, 2001)
Support for:
Authenticators:
Routers: accept dnslookup ipliteral manualroute queryprogram redirect
Transports: appendfile autoreply pipe smtp
changed uid/gid: forcing real = effective
uid=0 gid=0 pid=3371
auxiliary group list: <none>
configuration file is /usr/exim/configure
log selector = 020d99d8
trusted user
admin user
changed uid/gid: privilege not needed
uid=0 gid=0 pid=3371
auxiliary group list: <none>
originator: uid=0 gid=0 login=root name=
sender address = root@???
set_process_info: 3371 accepting a local non-SMTP message from <root@???>
Sender: root@???
search_tidyup called
From: <root@???>
To: <root@???>
Subject: test2

>>Headers received:

From: <root@???>
To: <root@???>
Subject: test2

rewrite_one_header: type=F:
From: <root@???>
rewrite_one_header: type=T:
To: <root@???>
search_tidyup called
>>Headers after local additions:

P Received: from root by clichi-vm.iavx.ro with local (Exim 4.20)
        id 19YR5W-0000sN-IA
        for root@???; Fri, 04 Jul 2003 15:59:25 +0200
F From: <root@???>
T To: <root@???>
  Subject: test2
I Message-Id: <E19YR5W-0000sN-IA@???>
  Date: Fri, 04 Jul 2003 15:59:25 +0200


test2
.
Data file written for message 19YR5W-0000sN-IA
calling local_scan(); timeout=300
local_scan() returned 0 NULL
Writing spool header file
Size of headers = 309
LOG: MAIN
<= root@??? U=root P=local S=316
search_tidyup called
>>>>>>>>>>>>>>>> Exim pid=3371 terminating with rc=0 >>>>>>>>>>>>>>>>

root@clichi-vm:/var/spool/mail# set_process_info: 3372 delivering 19YR5W-0000sN-IA
reading spool file 19YR5W-0000sN-IA-H
user=root uid=0 gid=0 sender=root@???
sender_local=1 ident=root
Non-recipients:
Empty Tree
---- End of tree ----
recipients_count=1
body_linecount=1 message_linecount=8
Delivery address list:
root@???
locking /var/spool/exim/db/retry.lockfile
locked /var/spool/exim/db/retry.lockfile
no retry data available
>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>

Considering: root@???
unique = root@???
no domain retry record
no address retry record
root@???: queued for routing
>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>

routing root@???
--------> dnslookup router <--------
local_part=root domain=clichi-vm.iavx.ro
checking domains
clichi-vm.iavx.ro in "@"? yes (matched "@")
clichi-vm.iavx.ro in "! +local_domains"? no (matched "! +local_domains")
dnslookup router skipped: domains mismatch
--------> system_aliases router <--------
local_part=root domain=clichi-vm.iavx.ro
calling system_aliases router
rda_interpret (string): ${lookup{$local_part}lsearch{/etc/mail/aliases}}
search_open: lsearch "/etc/mail/aliases"
search_find: file="/etc/mail/aliases"
key="root" partial=-1 affix=NULL starflags=0
LRU list:
8/etc/mail/aliases
End
internal_search_find: file="/etc/mail/aliases"
type=lsearch key="root"
file lookup required for root
in /etc/mail/aliases
lookup failed
expanded:
file is not a filter file
parse_forward_list:
system_aliases router declined for root@???
--------> userforward router <--------
local_part=root domain=clichi-vm.iavx.ro
checking for local user
calling userforward router
rda_interpret (file): $home/.forward
expanded: /root/.forward
stat(/root/.)=0
/root/.forward does not exist
userforward router declined for root@???
--------> localuser router <--------
local_part=root domain=clichi-vm.iavx.ro
checking for local user
finduser used cached passwd data for root
calling localuser router
localuser router called for root@???
domain = clichi-vm.iavx.ro
set transport local_delivery
queued for local_delivery transport: local_part = root
domain = clichi-vm.iavx.ro
errors_to=NULL
domain_data=NULL localpart_data=NULL
routed by localuser router
envelope to: root@???
transport: local_delivery
>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>

After routing:
  Local deliveries:
    root@???
  Remote deliveries:
  Failed addresses:
  Deferred addresses:
search_tidyup called

>>>>>>>>>>>>>>>> Local deliveries >>>>>>>>>>>>>>>>

--------> root@??? <--------
locking /var/spool/exim/db/retry.lockfile
locked /var/spool/exim/db/retry.lockfile
no retry data available
search_tidyup called
changed uid/gid: local delivery to root <root@???> transport=local_delivery
uid=0 gid=0 pid=3373
auxiliary group list: <none>
home=/root current=/root
set_process_info: 3373 delivering 19YR5W-0000sN-IA to root using local_delivery
direct command:
argv[0] = /usr/test/bin/bd/filter
direct command after expansion:
argv[0] = /usr/test/bin/bd/filter
appendfile transport entered
appendfile: mode=660 notify_comsat=0 quota=0
file=/var/mail/root format=unix
message_prefix=From ${if def:return_path{$return_path}{MAILER-DAEMON}} ${tod_bsdinbox}\n
message_suffix=\n
locking by lockfile fcntl
lock name: /var/mail/root.lock
hitch name: /var/mail/root.lock.clichi-vm.iavx.ro.3f058840.00000d2d
lock file created
mailbox /var/mail/root is locked
writing to file /var/mail/root
writing data block fd=5 size=53 timeout=0
process 3374 running as transport filter: write=8 read=9
process 3375 writing to transport filter
copying from the filter
writing data block fd=8 size=437 timeout=0
waiting for filter process
waiting for writing process
writing data block fd=5 size=437 timeout=0
end of filtering transport writing: yield=1
writing data block fd=5 size=1 timeout=0
appendfile yields 0 with errno=0 more_errno=0
search_tidyup called
journalling root@???
local_delivery transport returned OK for root@???
post-process root@??? (0)
root@??? delivered
LOG: MAIN
=> root <root@???> R=localuser T=local_delivery
>>>>>>>>>>>>>>>> deliveries are done >>>>>>>>>>>>>>>>

changed uid/gid: post-delivery tidying
uid=0 gid=0 pid=3372
auxiliary group list: <none>
set_process_info: 3372 tidying up after delivering 19YR5W-0000sN-IA
Processing retry items
Succeeded addresses:
root@???: no retry items
Failed addresses:
Deferred addresses:
end of retry processing
LOG: MAIN
Completed
end delivery of 19YR5W-0000sN-IA
search_tidyup called
search_tidyup called


--