As I am back at the site I can now provide some log information.
(PS: I have set the line length longer to avoid wrapping
log information)
Okay, here is normal message to a real user:
Sep 19 09:06:25 hotcube qmail: 969375985.801584 new msg 643380
Sep 19 09:06:25 hotcube qmail: 969375985.801693 info msg 643380: bytes 523 from
<[EMAIL PROTECTED]> qp 10712 uid 1005
Sep 19 09:06:25 hotcube qmail: 969375985.885090 starting delivery 1: msg 643380 to
local [EMAIL PROTECTED]
Sep 19 09:06:25 hotcube qmail: 969375985.885192 status: local 1/10 remote 0/20
Sep 19 09:06:26 hotcube qmail: 969375986.038075 delivery 1: success: did_0+0+1/
Sep 19 09:06:26 hotcube qmail: 969375986.038179 status: local 0/10 remote 0/20
Sep 19 09:06:26 hotcube qmail: 969375986.038206 end msg 643380
The above message was actually delivered.
Sep 19 09:08:51 hotcube qmail: 969376131.679441 new msg 643380
Sep 19 09:08:51 hotcube qmail: 969376131.679544 info msg 643380: bytes 555 from
<[EMAIL PROTECTED]> qp 10911 uid 1005
Sep 19 09:08:51 hotcube qmail: 969376131.762849 starting delivery 2: msg 643380 to
local [EMAIL PROTECTED]
Okay, this is me trying to send to the alias...
Sep 19 09:08:51 hotcube qmail: 969376131.762941 status: local 1/10 remote 0/20
Sep 19 09:08:51 hotcube qmail: 969376131.862814 new msg 643385
Sep 19 09:08:51 hotcube qmail: 969376131.862918 info msg 643385: bytes 658 from
<[EMAIL PROTECTED]> qp 10914 uid 1004
Sep 19 09:08:51 hotcube qmail: 969376131.961686 starting delivery 3: msg 643385 to
remote [EMAIL PROTECTED]
Okay, the address you see there is the hostname of the external
connection on the firewall, edited to at least pretend that I am
being secure here. It's the same as the address in "me", which makes
sense since that is probably where it came from. It is not the same
as the hostname on the box, which is "hotcube" (a bogus hostname).
I've put it in /etc/hosts like so:
192.168.0.102 hotcube dsl-XXXXXXXXXXXXXX-cgy.nucleus.com
Sep 19 09:08:51 hotcube qmail: 969376131.961782 status: local 1/10 remote 1/20
Sep 19 09:08:51 hotcube qmail: 969376131.961811 delivery 2: success:
did_0+1+0/qp_10914/
Sep 19 09:08:51 hotcube qmail: 969376131.961835 status: local 0/10 remote 1/20
Sep 19 09:08:51 hotcube qmail: 969376131.961857 end msg 643380
So far so good. Now the trouble begins:
Sep 19 09:09:52 hotcube qmail: 969376192.060626 delivery 3: deferral:
Sorry,_I_wasn't_able_to_establish_an_SMTP_connection._(#4.4.1)/
Wha? What's going on here? This would make sense if qmail were trying to
resolve the above hostname using DNS, for two reasons:
1. the nature of the firewall/proxy is such that it cannot forward requests
to internal services through the external interface
2. there is no forwarded SMTP port on the external firewall interface anyway
but it shouldn't be doing that, because I put dsl-XXXXXXXXXXXXXX-cgy.nucleus.com
in /etc/hosts. Is there something wrong with my /etc/hosts entry? A better question -
how exactly should I deal with this problem?
Now, yet more fun =)
I try to clear the queue using qmHandle. Oh, it clears the queue all right... and
does a whole lot more:
Sep 19 09:09:52 hotcube qmail: 969376192.060724 status: local 0/10 remote 0/20
Sep 19 09:10:52 hotcube qmail: 969376252.279645 status: exiting
Sep 19 09:10:52 hotcube qmail: 969376252.487147 status: local 0/10 remote 0/20
Sep 19 09:10:53 hotcube qmail: 969376253.304521 alert: cannot start: qmail-send is
already running
Sep 19 09:10:54 hotcube qmail: 969376254.324637 alert: cannot start: qmail-send is
already running
Sep 19 09:10:55 hotcube qmail: 969376255.344992 alert: cannot start: qmail-send is
already running
Sep 19 09:10:56 hotcube qmail: 969376256.365005 alert: cannot start: qmail-send is
already running
Sep 19 09:10:57 hotcube qmail: 969376257.385589 alert: cannot start: qmail-send is
already running
Aiee! You get the idea. I addressed this problem by killing qmail-lspawn, like so:
Sep 19 09:11:34 hotcube qmail: 969376294.263644 alert: oh no! lost spawn connection!
dying...
Sep 19 09:11:34 hotcube qmail: 969376294.263747 status: exiting
Sep 19 09:11:35 hotcube qmail: 969376295.137356 status: local 0/10 remote 0/20
but that's just a bandage, it doesn't fix qmHandle... any idea why this
might be happening?
Thanks,
Stephen Bosch
