From: Charles Gregory (cgregoryhwcn.org)
Date: Wed Nov 01 2006 - 10:53:20 CST

• Messages sorted by: [ date ] [ thread ] [ subject ] [ author ]

Greetings!

Got a weird one for ya. Messages are 'sticking' in the queue, I think
because of something 'timing out' in procmail, but only for a few users.

Background: To enable spamassassin for some users on an old box with
sendmail (too much trouble to setup spamassassin), I set their .forward
files to send the mail to 'host6' which has postfix and spamassassin,
which then delivers the mail back into their NFS mounted mailboxes on
'host4'. Works most of the time..... and is *still working for most users.

Messages that are 'stuck' in the queue show behaviour like this:

Oct 28 21:57:47 host6 postfix/smtpd[21148]: 66BF2B68FF:
   client=host4.hwcn.org[199.212.94.75]
Oct 28 21:57:47 host6 postfix/cleanup[21149]: 66BF2B68FF:
   message-id=<28299671210818.DCDBD1BD92796EKO>
Oct 28 21:57:47 host6 postfix/nqmgr[20762]: 66BF2B68FF:
   from=<chlorinebimetallismrrbrand.com>, size=1248, nrcpt=2 (queue
   active)

....Yes, I know this is probably spam. It's just an example.

Oct 28 21:57:56 host6 postfix/local[21150]: 66BF2B68FF:
   to=<user04host6.hwcn.org>, relay=local, delay=9, status=sent
   ("|/usr/bin/procmail -a "$EXTENSION"")

....delivered successfully to user04. So I would presume that the message
format is not 'messing up' spamassassin or postfix.
But this message should also have been delivered to user05, but instead
I see postfix repeatedly 'trying' delivery.....

Oct 29 00:56:13 host6 postfix/nqmgr[21689]: 66BF2B68FF:
 from=<chlorinebimetallismrrbrand.com>, size=1248, nrcpt=2 (queue active)
Oct 29 04:58:22 host6 postfix/nqmgr[30346]: 66BF2B68FF:
 from=<chlorinebimetallismrrbrand.com>, size=1248, nrcpt=2 (queue active)
<snip>
Oct 30 01:06:12 host6 postfix/nqmgr[1147]: fatal: 66BF2B68FF: timeout
 receiving delivery status from transport: local
<snip>
Oct 30 01:08:16 host6 postfix/nqmgr[2010]: 66BF2B68FF:
 from=<chlorinebimetallismrrbrand.com>, size=1248, nrcpt=2 (queue active)
Oct 30 06:11:13 host6 postfix/nqmgr[3342]: 66BF2B68FF:
 from=<chlorinebimetallismrrbrand.com>, size=1248, nrcpt=2 (queue active)
<snip>
Oct 30 21:12:17 host6 postfix/nqmgr[6683]: fatal: 66BF2B68FF: timeout
 receivingdelivery status from transport: local
<snip>
Oct 30 21:16:04 host6 postfix/nqmgr[8408]: 66BF2B68FF:
 from=<chlorinebimetallismrrbrand.com>, size=1248, nrcpt=2 (queue active)
<snip>
Oct 31 22:21:09 host6 postfix/nqmgr[15884]: 66BF2B68FF:
 to=<user05host6.hwcn.org>, relay=none, delay=264202,
 status=deferred (unknown mail transport error)
<snip>
Oct 31 23:33:01 host6 postfix/nqmgr[17425]: 66BF2B68FF:
 from=<chlorinebimetallismrrbrand.com>, size=1248, nrcpt=2 (queue active)

... up to the current moment. The message is still undelivered.

Currently all mail for user05 is following this pattern with one odd
exception. Notice that this all starts Oct 28 21:57:47 ....
BUT I have single successful delivery on Oct 29, after several retries.

Oct 29 04:58:22 host6 postfix/nqmgr[30346]: 33CCDB68E6:
 from=<wwwrunschlumpf.esb-net.de>, size=4202, nrcpt=1 (queue active)
Oct 29 10:01:13 host6 postfix/nqmgr[31494]: 33CCDB68E6:
 from=<wwwrunschlumpf.esb-net.de>, size=4202, nrcpt=1 (queue active)
Oct 29 15:06:11 host6 postfix/nqmgr[32664]: 33CCDB68E6:
 from=<wwwrunschlumpf.esb-net.de>, size=4202, nrcpt=1 (queue active)
Oct 29 20:06:12 host6 postfix/nqmgr[1147]: 33CCDB68E6:
 from=<wwwrunschlumpf.esb-net.de>, size=4202, nrcpt=1 (queue active)
Oct 29 20:06:12 host6 postfix/local[1148]: 33CCDB68E6:
 to=<user05host6.hwcn.org>, relay=local, delay=195037,
 status=sent ("|/usr/bin/procmail -a "$EXTENSION"")

So it's not an absolute 'failing' of user05, but something that is tying
up resources. But other users are still being delivered with no delay, so
somehow the 'resource consumption' is only with user05. Now this pattern
*has* briefly appeared for a couple of other users. So I would be inclined
to blame some malformed piece of spam. I can trace this back to Oct 23
(yeah, the user was slow to notice) where

I also notice this in the logs around that time:
Oct 23 04:09:21 host6 postfix/local[15119]: A02CEB688C:
to=<hreads01host6.hwcn.org>, relay=local, delay=110, status=sent
("|/usr/bin/procmail -a "$EXTENSION"")
Oct 23 04:09:21 host6 postfix/local[15119]: warning: close file
/hwcn/hosts/hamiltonreads.ca/./home/hreads01/.forward: No such file or
directory

Their .forward file is still there. Is this a failing of NFS?
If any/all of this looks familiar to anyone, I'd appreciate some pointers.
I continue to dig through logs.

And yes, I've deliberately NOT provided my postconf, because I can't see
how a setting like that would apply to only one user and not all.
But if you really want to see it, I'll toss it in. Nothing exciting
though....

Thanks in advance!

- Charles

• Messages sorted by: [ date ] [ thread ] [ subject ] [ author ]