On 2008-07-16 at 13:53 +0100, Sam Smith wrote:
> On Wed, Jul 09, 2008 at 09:45:40PM -0700, Phil Pennock wrote:
> > Also, lookup caches are flushed after routing, for instance, so if
> > there's data that you want to use again at delivery (Transport) time, it
> > makes sense to use "address_data" on the Router to preserve it and
> > $address_data in the Transport to retrieve it; this data is stored in
> > the spool file.
I'm re-ordering to put the config after the log files so we can look at
what's happening and then how to fix it for your setup.
> 13:07:43 4698 SMTP>> 250 OK
> 13:07:50 4698 SMTP<< rcpt to: joseph@???
> 13:07:50 4698 processing "accept"
> 13:07:50 4698 accept: condition test succeeded
I'm hoping that this "accept all recipients" setup is only for initial
debugging and that you'll switch to recipient verification for use?
Note that recipient verification will typically add one lookup, but if
this is a problem then you can have the RCPT ACL permit only one
recipient per message and store the lookup results in an $acl_m_foo
variable. Note how $acl_m_* are per-message, not per-recipient.
> 13:07:54 4707 Considering: joseph@???
[...]
> 13:07:54 4707 --------> db_user router <--------
> 13:07:54 4707 local_part=joseph domain=samibm.com
[...]
> 13:07:54 4707 search_find: file="NULL"
> 13:07:54 4707 key="select mailbox,username,uid from mailtest where username='joseph'" partial=-1 affix=NULL starflags=0
Checks the cache but this hasn't been looked up yet, so proceeds to do a
lookup.
> 13:07:54 4707 LRU list:
> 13:07:54 4707 internal_search_find: file="NULL"
> 13:07:54 4707 type=pgsql key="select mailbox,username,uid from mailtest where username='joseph'"
> 13:07:54 4707 database lookup required for select mailbox,username,uid from mailtest where username='joseph'
> 13:07:54 4707 PGSQL query: select mailbox,username,uid from mailtest where username='joseph'
> 13:07:54 4707 PGSQL new connection: host=127.0.0.1 port= database=testdb user=root
> 13:07:54 4707 lookup yielded: mailbox=/home/joseph/mail username=joseph uid=1004
> 13:07:54 4707 expanding: ${lookup pgsql {select mailbox,username,uid from mailtest where username='${quote_pgsql:$local_part}'}}
> 13:07:54 4707 result: mailbox=/home/joseph/mail username=joseph uid=1004
> 13:07:54 4707 expanding: ${extract {username}{${lookup pgsql {select mailbox,username,uid from mailtest where username='${quote_pgsql:$local_part}'}}}}
> 13:07:54 4707 result: joseph
> 13:07:54 4707 joseph in "joseph"? yes (matched "joseph")
> 13:07:54 4707 expanding: R: local_user for $local_part@$domain
> 13:07:54 4707 result: R: local_user for joseph@???
> 13:07:54 4707 R: local_user for joseph@???
> 13:07:54 4707 calling db_user router
> 13:07:54 4707 db_user router called for joseph@???
> 13:07:54 4707 domain = samibm.com
> 13:07:54 4707 set transport db_mail_spool
> 13:07:54 4707 queued for db_mail_spool transport: local_part = joseph
> 13:07:54 4707 domain = samibm.com
> 13:07:54 4707 errors_to=NULL
> 13:07:54 4707 domain_data=NULL localpart_data=NULL
> 13:07:54 4707 routed by db_user router
> 13:07:54 4707 envelope to: joseph@???
> 13:07:54 4707 transport: db_mail_spool
Routing done. Decision made. Note that caches flushed after routing.
> 13:07:54 4707 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
> 13:07:54 4707 After routing:
> 13:07:54 4707 Local deliveries:
> 13:07:54 4707 joseph@???
> 13:07:54 4707 Remote deliveries:
> 13:07:54 4707 Failed addresses:
> 13:07:54 4707 Deferred addresses:
> 13:07:54 4707 search_tidyup called
> 13:07:54 4707 close PGSQL connection: 127.0.0.1/testdb/root
There's the search_tidyup cache flushing and the DB being closed.
> 13:07:54 4707 >>>>>>>>>>>>>>>> Local deliveries >>>>>>>>>>>>>>>>
> 13:07:54 4707 --------> joseph@??? <--------
> 13:07:54 4707 locking /var/spool/exim4/db/retry.lockfile
> 13:07:54 4707 locked /var/spool/exim4/db/retry.lockfile
> 13:07:54 4707 EXIM_DBOPEN(/var/spool/exim4/db/retry)
> 13:07:54 4707 returned from EXIM_DBOPEN
> 13:07:54 4707 opened hints database /var/spool/exim4/db/retry: flags=O_RDONLY
> 13:07:54 4707 dbfn_read: key=T:joseph@???
> 13:07:54 4707 no retry record exists
> 13:07:54 4707 expanding: uid
> 13:07:54 4707 result: uid
> 13:07:54 4707 expanding: $local_part
> 13:07:54 4707 result: joseph
> 13:07:54 4707 expanding: select mailbox,username,uid from mailtest where username='${quote_pgsql:$local_part}'
> 13:07:54 4707 result: select mailbox,username,uid from mailtest where username='joseph'
> 13:07:54 4707 search_open: pgsql "NULL"
> 13:07:54 4707 search_find: file="NULL"
> 13:07:54 4707 key="select mailbox,username,uid from mailtest where username='joseph'" partial=-1 affix=NULL starflags=0
> 13:07:54 4707 LRU list:
> 13:07:54 4707 internal_search_find: file="NULL"
> 13:07:54 4707 type=pgsql key="select mailbox,username,uid from mailtest where username='joseph'"
> 13:07:54 4707 database lookup required for select mailbox,username,uid from mailtest where username='joseph'
> 13:07:54 4707 PGSQL query: select mailbox,username,uid from mailtest where username='joseph'
> 13:07:54 4707 PGSQL new connection: host=127.0.0.1 port= database=testdb user=root
> 13:07:54 4707 lookup yielded: mailbox=/home/joseph/mail username=joseph uid=1004
> 13:07:54 4707 expanding: ${lookup pgsql {select mailbox,username,uid from mailtest where username='${quote_pgsql:$local_part}'}}
> 13:07:54 4707 result: mailbox=/home/joseph/mail username=joseph uid=1004
> 13:07:54 4707 expanding: ${extract{uid}{${lookup pgsql {select mailbox,username,uid from mailtest where username='${quote_pgsql:$local_part}'}}}}
> 13:07:54 4707 result: 1004
> 13:07:54 4707 seeking password data for user "1004": cache not available
> 13:07:54 4707 search_tidyup called
> 13:07:54 4707 close PGSQL connection: 127.0.0.1/testdb/root
There's the second lookup, for delivery. And the DB connections are
closed as, presumably, part of a general security precaution of not
keeping open resources from before dropping privs which might let the
unprivileged process grab the data.
> 13:07:54 4711 changed uid/gid: local delivery to joseph <joseph@???> transport=db_mail_spool
> 13:07:54 4711 uid=1004 gid=8 pid=4711
And there, we switched uid/gid for delivery in a child process (pid
4711), which needs its own lookup, so you're going to do all this work
again. Oh, and this means that user joseph needs to be permitted to
query the routing DB, so your permissions are perhaps more lax than they
could be (or this only works for the admin account).
It's fairly common to not use a DB where you're going to be delivering
to user mailboxes owned by individual users but instead to a spool all
owned by a common user, etc.
> hide pgsql_servers = 127.0.0.1/testdb/root/;lkjlk
> exim_path = /usr/sbin/exim4
> domainlist local_domains = samibm.com : localhost
> PGS_VAR = {lookup pgsql \
> {select mailbox,username,uid from mailtest \
> where username='${quote_pgsql:$local_part}'}}
> acl_smtp_rcpt=accept
> begin routers
> notlocal:
> driver = dnslookup
> domains = ! +local_domains
> transport = remote_smtp
> db_user:
> debug_print = "R: local_user for $local_part@$domain"
> driver = accept
> domains = +local_domains
> local_parts = ${extract {username}{$PGS_VAR}}
> transport = db_mail_spool
> cannot_route_message = Unknown user : not a v_user
Add to this "db_user" Router:
address_data = $PGS_VAR
That lookup will be cached. You should be able to even see that happen
in the debug logs. :)
> begin transports
> db_mail_spool:
> debug_print = "T: db appendfile for $local_part@$domain"
> driver = appendfile
> file = ${extract {mailbox}{$PGS_VAR}}
> delivery_date_add
> envelope_to_add
> return_path_add
> group = mail
> user = ${extract{uid}{$PGS_VAR}}
> mode = 0660
> mode_fail_narrower = false
Now use:
file = ${extract {mailbox}{$address_data}}
user = ${extract {uid}{$address_data}}
With this, you have one lookup in the Router, used twice (via the
cache); the first validates the address, the second stores it in a
per-recipient variable of auxiliary data provided by Exim. This is
stored in the headers/metadata spool file (*-H).
You then use the $address_data variable to refer to this explicit cache,
no matter that you're doing this even after dropping privileges, etc.
So, down to one lookup so time to add more back in by adding the
verification. :)
Regards,
-Phil
