Hello:
We recently tracked down an instance where our qpsmtpd server rejected a
legitimate email from one of our customers, where the 550 error message from
a simultaneous thread was accidentally sent to our customer's thread. Very
strange.
In the following logs, we have:
(1) our customer: tbmailer.triobet.com [83.218.12.49] on thread 16846
(2) a spammer: OL12-45.fibertel.com.ar [24.232.45.12] on thread 16845
The spammer's server triggers the check_earlytalker plugin. Then it triggers
the dnsbl plugin according to a spamhaus lookup. Our customer's server is
considered white by the greylisting plugin.
The error message is this one:
box[16846]: 550 http://www.spamhaus.org/query/bl?ip=24.232.45.12
(note the wrong PID). A copy of our customer's bounce message confirms
that they received this 550 error message verbatim.
Does anyone know why this would have happened? Is qpsmtpd not threadsafe? Or
is one of the plugins (check_earlytalker, dnsbl, greylisting) not
threadsafe? The "dispatching RSET" may also be a cause---because our mail
server is within P.R. China, both sides of our SMTP connections often
experience RSET
packets caused by the Great Firewall.
Here's a portion of the logs:
Sat May 26 15:09:34 2007 box[16846]: Accepted connection 7/40 from 83.218.12.49
/ tbmailer.triobet.com
Sat May 26 15:09:34 2007 box[16846]: Connection from tbmailer.triobet.com
[83.218.12.49]
Sat May 26 15:09:34 2007 box[16846]: logging::file
Sat May 26 15:09:34 2007 box[16846]: check_earlytalker
Sat May 26 15:09:35 2007 box[16845]: Accepted connection 6/40 from 24.232.45.12 /
OL12-45.fibertel.com.ar
Sat May 26 15:09:35 2007 box[16845]: Connection from OL12-45.fibertel.com.ar
[24.232.45.12]
Sat May 26 15:09:35 2007 box[16845]: logging::file
Sat May 26 15:09:35 2007 box[16845]: check_earlytalker
Sat May 26 15:09:35 2007 box[16845]: remote host started talking before we said
hello [24.232.45.12]
Sat May 26 15:09:35 2007 box[16845]: check_relay
Sat May 26 15:09:35 2007 box[16845]: whitelist
Sat May 26 15:09:35 2007 box[16845]: dnsbl
Sat May 26 15:09:35 2007 box[16845]: 220 fw.exoweb.net ESMTP qpsmtpd 0.32 ready; send us your mail,
but not your spam.
Sat May 26 15:09:35 2007 box[1495]: cleaning up after 16845
Sat May 26 15:09:35 2007 box[16846]: remote host said nothing spontaneous,
proceeding
Sat May 26 15:09:35 2007 box[16846]: check_relay
Sat May 26 15:09:35 2007 box[16846]: whitelist
Sat May 26 15:09:35 2007 box[16846]: dnsbl
Sat May 26 15:09:35 2007 box[16846]: 220 fw.exoweb.net ESMTP qpsmtpd 0.32 ready; send us your mail,
but not your spam.
Sat May 26 15:09:36 2007 box[16846]: dispatching HELO tbmailer.triobet.com
Sat May 26 15:09:36 2007 box[16846]: whitelist
Sat May 26 15:09:36 2007 box[16846]: check_spamhelo
Sat May 26 15:09:36 2007 box[16846]: 250 fw.exoweb.net Hi tbmailer.triobet.com [83.218.12.49]; I am
so happy to meet you.
Sat May 26 15:09:36 2007 box[16846]: dispatching MAIL FROM:<[EMAIL PROTECTED]>
Sat May 26 15:09:36 2007 box[16846]: full from_parameter: FROM:<[EMAIL
PROTECTED]>
Sat May 26 15:09:36 2007 box[16846]: from email address : [<[EMAIL PROTECTED]>]
Sat May 26 15:09:36 2007 box[16846]: whitelist
Sat May 26 15:09:36 2007 box[16846]: rhsbl
Sat May 26 15:09:36 2007 box[16846]: check_badmailfrom
Sat May 26 15:09:36 2007 box[16846]: greylisting
Sat May 26 15:09:36 2007 box[16846]: using /var/lib/qpsmtpd/greylisting/denysoft_greylist.dbm as
greylisting database
Sat May 26 15:09:36 2007 box[16846]: ts: Sat May 26 15:09:30 2007, now: Sat May
26 15:09:36 2007
Sat May 26 15:09:36 2007 box[16846]: key 83.218.12.49 is white, 21714 deliveries
Sat May 26 15:09:36 2007 box[16846]: getting mail from <[EMAIL PROTECTED]>
Sat May 26 15:09:36 2007 box[16846]: 250 <[EMAIL PROTECTED]>, sender OK - how exciting to get mail
from you!
Sat May 26 15:09:37 2007 box[16846]: dispatching RCPT TO:<[EMAIL PROTECTED]>
Sat May 26 15:09:37 2007 box[16846]: to email address : [<[EMAIL PROTECTED]>]
Sat May 26 15:09:37 2007 box[16846]: whitelist
Sat May 26 15:09:37 2007 box[16846]: rhsbl
Sat May 26 15:09:37 2007 box[16846]: dnsbl
Sat May 26 15:09:37 2007 box[16846]: 550
http://www.spamhaus.org/query/bl?ip=24.232.45.12
Sat May 26 15:09:37 2007 box[16846]: dispatching RSET
Sat May 26 15:09:37 2007 box[16846]: 250 OK
Sat May 26 15:09:38 2007 box[16846]: dispatching QUIT
Sat May 26 15:09:38 2007 box[16846]: 221 fw.exoweb.net closing connection. Have
a wonderful day.
Sat May 26 15:09:38 2007 box[16846]: logging::file
Sat May 26 15:09:38 2007 box[16846]: rhsbl
Sat May 26 15:09:38 2007 box[16846]: dnsbl
Sat May 26 15:09:39 2007 box[1495]: cleaning up after 16846
Thank you.
--
Darren Paul Griffith, IT Systems Administrator
www.exoweb.net, +86 135 2262 5129
