Hi there,
I think I've found a bug in the MySql portion of the code when it is
being used in an appendfile transport.
Quick info:
exim v3.30, compiled with gcc 3.0, solaris 8.
Plain description of the problem:
Exim will open a tcp connection to the MySQL server and then forget the
close the socket when finished delivery and exiting causing an warning
error on the mysql server to be generated/logged and delayed shutdown
of the corresponding process.
More in depth description:
What I've been able to determine (I haven't gone through code yet),
Exim will correctly do the entire open/query/close process with the
MySQL server when dealing with a director/router. Ie: when specifing
the "search_type = mysql" option with a corresponding "query = ..." line
in the configuration. But when using a $lookup statement, exim doesn't
close the connection properly (search_tidyup doesn't know of the new
connection). Normally not really a problem, but MySQL daemon will
generate a line in it's logfile as well as take ~30 seconds to timeout
the connection, which causes a partial DOS against the database if enough
queries are generated (which we found out when stress testing it. :-)
See end of the message for a complete -d9 dump of a test message being
generated on the commandline.
Hopefully it's enough to find the problem. If you have any questions,
don't hestiate to email me: westr@???
PS: Noted that exim doesn't use the internal database cache between
queries either.
Cheers,
Ross.
Here's a clip from the configuration file of a good director:
-=- Start
pop3_user:
driver = aliasfile
search_type = mysql
query = "select spoolfile from pop3 where UID='$local_part' and
active='1'"
transport = local_delivery
-=- End
And here's the clip of the ${lookup... statement
-=- Start
local_delivery:
driver = appendfile
file = ${lookup mysql{select spoolfile from pop3 where
UID='$local_part' and active='1'}{$value}fail}
delivery_date_add
envelope_to_add
return_path_add
user = exim
group = mail
mode = 0660
-=- End
Note: Server+password sanitized, but work correctly.
-=- exim -d9 westr@???
Exim version 3.30 debug level 9 uid=101 gid=14
probably ndbm
Caller is an admin user
originator: uid=101 gid=14 login=westr name=
sender address = westr@???
set_process_info: 4328 accepting a local non-SMTP message from <westr@???>
Sender: westr@???
Recipients:
westr@???
search_tidyup called
>>Original headers (size=69):
From: <westr@???>
To: <westr@???>
Subject: Exim Test 2
rewrite_one_header: type=F:
From: <westr@???>
rewrite_one_header: type=T:
To: <westr@???>
>>Final headers:
P Received: from westr by blinky with local (Exim 3.30 #15)
id 15JiB1-00017o-00
for westr@???; Mon, 09 Jul 2001 17:03:11 -0400
F From: <westr@???>
T To: <westr@???>
Subject: Exim Test 2
I Message-Id: <E15JiB1-00017o-00@blinky>
Date: Mon, 09 Jul 2001 17:03:11 -0400
search_tidyup called
Data file written for message 15JiB1-00017o-00
Writing spool header file
Size of headers = 280
LOG: 0 MAIN
<= westr@??? U=westr P=local S=324
search_tidyup called
exec /usr/local/bin/exim -d9 -Mc 15JiB1-00017o-00
Exim version 3.30 debug level 9 uid=50 gid=50
probably ndbm
Caller is an admin user
Caller is a trusted user
set_process_info: 4329 delivering specified messages
delivering message 15JiB1-00017o-00
set_process_info: 4329 delivering 15JiB1-00017o-00
Opened spool file 15JiB1-00017o-00-H
user=westr uid=101 gid=14 sender=westr@???
sender_local=1 resent=no ident=westr
Non-recipients:
Empty Tree
---- End of tree ----
recipients_count=1
body_linecount=5 message_linecount=8
Delivery address list:
westr@???
locked /remote/spool0/blinky/db/retry.lockfile
opened DB file /remote/spool0/blinky/db/retry: flags=0
>>>>>>>>>>>>>>>>>>>>>>>>
Considering: westr@???
pipeman.ca in local_domains? yes (matched pipeman.ca)
pipeman.ca in percent_hack_domains? no (end of list)
unique = westr@???
dbfn_read: key=D:westr@???
westr@???: queued for directing
>>>>>>>>>>>>>>>>>>>>>>>>
directing westr@???
calling domain_aliases director
df_lookup entered: search type = mysql
domain_aliases director: mysql query=select destination from exim where
email='westr@???'
search_open: mysql "NULL"
search_find: file="NULL"
key="select destination from exim where email='westr@???'" partial=-1
LRU list:
internal_search_find: file="NULL"
type=mysql key="select destination from exim where email='westr@???'"
database lookup required for select destination from exim where email='westr@???'
MYSQL query: select destination from exim where email='westr@???'
MYSQL new connection: ***Connection INfo Removed***
lookup yielded: westr
parse_extract_addresses: westr
extract item: westr
domain_aliases director generated westr@???
errors_to=NULL transport=NULL
uid=unset gid=unset home=NULL
domain_aliases director succeeded for westr
locked /remote/spool0/blinky/db/retry.lockfile
opened DB file /remote/spool0/blinky/db/retry: flags=0
>>>>>>>>>>>>>>>>>>>>>>>>
Considering: westr@???
pipeman.ca in local_domains? yes (matched pipeman.ca)
pipeman.ca in percent_hack_domains? no (end of list)
unique = \westr@???
dbfn_read: key=D:westr@???
westr@???: queued for directing
>>>>>>>>>>>>>>>>>>>>>>>>
directing westr@???
domain_aliases director skipped: previously directed westr@???
calling domain_aliases_catchall director
df_lookup entered: search type = mysql
domain_aliases_catchall director: mysql query=select destination from exim where
email='*@pipeman.ca'
search_open: mysql "NULL"
cached open
search_find: file="NULL"
key="select destination from exim where email='*@pipeman.ca'" partial=-1
LRU list:
internal_search_find: file="NULL"
type=mysql key="select destination from exim where email='*@pipeman.ca'"
database lookup required for select destination from exim where email='*@pipeman.ca'
MYSQL query: select destination from exim where email='*@pipeman.ca'
MYSQL using cached connection for ***Connection Info Removed***
MYSQL: no data found
lookup failed
domain_aliases_catchall director declined for westr: MYSQL: no data found
westr in "postmaster"? no (end of list)
force_postmaster director skipped: local part mismatch
calling pop3_user director
df_lookup entered: search type = mysql
pop3_user director: mysql query=select spoolfile from pop3 where UID='westr' and active='1'
search_open: mysql "NULL"
cached open
search_find: file="NULL"
key="select spoolfile from pop3 where UID='westr' and active='1'" partial=-1
LRU list:
internal_search_find: file="NULL"
type=mysql key="select spoolfile from pop3 where UID='westr' and active='1'"
database lookup required for select spoolfile from pop3 where UID='westr' and active='1'
MYSQL query: select spoolfile from pop3 where UID='westr' and active='1'
MYSQL using cached connection for ***Connection info removed***
lookup yielded: /remote/mail0/pipeman.ca/westr
queued for local_delivery transport: local_part=westr domain=pipeman.ca
errors_to=NULL
domain_data=NULL local_part_data=NULL
pop3_user director succeeded for westr
>>>>>>>>>>>>>>>>>>>>>>>>
After directing:
Local deliveries:
westr@???
Remote deliveries:
Failed addresses:
Addresses to be routed:
Deferred addresses:
search_tidyup called
close MYSQL connection: *** Connection INFO removed ***
>>>>>> Local deliveries >>>>>>
locked /remote/spool0/blinky/db/retry.lockfile
opened DB file /remote/spool0/blinky/db/retry: flags=0
dbfn_read: key=T:westr@???
delivering westr@??? as westr using local_delivery:
uid=50 gid=6 home=NULL current=/
auxiliary group list: <none>
set_process_info: 4330 delivering 15JiB1-00017o-00 to westr using local_delivery
appendfile transport entered
search_open: mysql "NULL"
search_find: file="NULL"
key="select spoolfile from pop3 where UID='westr' and active='1'" partial=-1
LRU list:
internal_search_find: file="NULL"
type=mysql key="select spoolfile from pop3 where UID='westr' and active='1'"
database lookup required for select spoolfile from pop3 where UID='westr' and active='1'
MYSQL query: select spoolfile from pop3 where UID='westr' and active='1'
MYSQL new connection: ***Connection INFO removed***
lookup yielded: /remote/mail0/pipeman.ca/westr
appendfile: mode=660 notify_comsat=0 quota=0
file=/remote/mail0/pipeman.ca/westr format=unix
prefix=From ${if def:return_path{$return_path}{MAILER-DAEMON}} ${tod_bsdinbox}\n
suffix=\n
locking by lockfile fcntl
lock name: /remote/mail0/pipeman.ca/westr.lock
hitch name: /remote/mail0/pipeman.ca/westr.lock.blinky.3b4a1c1a.000010ea
lock file created
mailbox /remote/mail0/pipeman.ca/westr is locked
writing to file /remote/mail0/pipeman.ca/westr
writing data block fd=7 size=47 timeout=0
writing data block fd=7 size=462 timeout=0
writing data block fd=7 size=1 timeout=0
appendfile yields 0 with errno=0 more_errno=0
journalled \westr@???
local_delivery transport returned OK for westr@???
post-process westr@??? (0)
westr@??? succeeded: adding to nonrecipients list
westr@???: children all complete
LOG: 0 MAIN
=> westr <westr@???> D=pop3_user T=local_delivery
search_tidyup called
set_process_info: 4329 tidying up after delivering 15JiB1-00017o-00
Processing retry items
Succeeded addresses:
westr@???: no retry items
westr@???: no retry items
westr@???: no retry items
Failed addresses:
Deferred addresses:
end of retry processing
LOG: 0 MAIN
Completed
end delivery of 15JiB1-00017o-00
search_tidyup called
search_tidyup called
-=- End
