Intermittent "Relaying Denied" error.

I've got sendmail 8.13.1, on a RHEL 4 box, with local bind. I'm
handling about 6000 messages a day total. They're addressed to any
one of the 25 or so domains I host, about half for local delivery, and
the other half get forwarded on to gmail/yahoo/comcast accounts.

99% of the time everything is fine. But about twice a day, I'm
getting errors where mail that is destined for one of my domains is
being rejected:

Aug 21 14:03:10 tinasserver sendmail[28220]: m7LJ2bhO028220:
ruleset=check_rcpt, arg1=<tina@skywhisperer.com>, relay=rv-
out-0506.google.com [209.85.198.233], reject=550 5.7.1
<tina@skywhisperer.com>... Relaying denied. Proper authentication
required.

It's not restricted to one domain or one user. It's not related to
what domain is sending the email, either. Most of the time, no one
notices because it's hitting on spam, but it's hitting a real message
once every few weeks. I've triple-checked my local-host-names list,
and they're all in there.

I verified that by checking that the domains are in the class w:

[root@tinasserver tina]# echo '$=w' | sendmail -bt | grep
skywhisperer.com
skywhisperer.com

I do have a very minimal access.db:

localhost.localdomain RELAY
localhost RELAY
127.0.0.1 RELAY

ClientRate:127.0.0.1 0
ClientRate: 10

I'm entirely at a loss. I don't see DNS errors, and the readme says
that would result in a different error message anyway. Just to be
sure, I turned on:

FEATURE(`accept_unresolvable_domains')dnl

To see if it would help. It didn't.

It doesn't seem to be related to particularly high load times on the
machine, or within sendmail. It's not happening at any particular time
of the day, and it doesn't seem to happen in clumps. I've got the SA/
MimeDefang/clamav stack, but it looks like the 500 is being returned
before MimeDefang sees it.

Any ideas? My next step will have to be to step up the sendmail
debugging level, but it's such a rare problem that I'm hesitant to do
that. Anything else I should check?

Tina

On 8/22/2008 2:45 PM, Tina Marie wrote:
> Aug 21 14:03:10 tinasserver sendmail[28220]: m7LJ2bhO028220:
> ruleset=check_rcpt, arg1=<tina@skywhisperer.com>,
> relay=rv-out-0506.google.com [209.85.198.233], reject=550 5.7.1
> <tina@skywhisperer.com>... Relaying denied. Proper authentication
> required.

> Any ideas? My next step will have to be to step up the sendmail
> debugging level, but it's such a rare problem that I'm hesitant to do
> that. Anything else I should check?

Two things:
- Is this an inbound or outbound message? I can't tell for sure from
the single log entry. I'd expect to see the associated "... from=< ..."
and "... to=< ..." log lines as well.
- What is the "check_rcpt" rule set doing?



Grant. . . .

On Aug 22, 10:14*pm, Grant Taylor <gtay...@riverviewtech.net> wrote:
> Two things:
> * - Is this an inbound or outbound message? *I can't tell for sure from
> the single log entry. *I'd expect to see the associated "... from=< ...."
> and "... to=< ..." log lines as well.
> * - What is the "check_rcpt" rule set doing?

Sorry. It's an inbound message. It's always happening on inbound
messages.

This is the complete log for that message:

Aug 21 14:03:10 tinasserver sendmail[28220]: m7LJ2bhO028220:
ruleset=check_rcpt, arg1=<tina@skywhisperer.com>, relay=rv-
out-0506.google.com [209.85.198.233], reject=550 5.7.1
<tina@skywhisperer.com>... Relaying denied. Proper authentication
required.
Aug 21 14:03:10 tinasserver sendmail[28220]: m7LJ2bhO028220:
from=<[someone]@gmail.com>, size=0, class=0, nrcpts=0, proto=ESMTP,
daemon=MTA, relay=rv-out-0506.google.com [209.85.198.233]

[someone] is a valid gmail address, in the form of
firstname.lastname@gmail.com. They resent the message 5 minutes
later, and it was successful.

I haven't done anything specific for check_rcpt. This looks like the
relevant bit of my .cf file:

SLocal_check_rcpt
Scheck_rcpt
R$* $: $1 $| $>"Local_check_rcpt" $1
R$* $| $#$* $#$2
R$* $| $* $@ $>"Basic_check_rcpt" $1

SBasic_check_rcpt
# empty address?
R<> $#error $@ nouser $: "553 User address required"
R$@ $#error $@ nouser $: "553 User address required"
# check for deferred delivery mode
R$* $: < $&{deliveryMode} > $1
R< d > $* $@ deferred
R< $* > $* $: $2


################################################## ####################
R$* $: $1 $| @ $>"Rcpt_ok" $1
R$* $| @ $#TEMP $+ $: $1 $| T $2
R$* $| @ $#$* $#$2
R$* $| @ RELAY $@ RELAY
R$* $| @ $* $: O $| $>"Relay_ok" $1
R$* $| T $+ $: T $2 $| $>"Relay_ok" $1
R$* $| $#TEMP $+ $#error $2
R$* $| $#$* $#$2
R$* $| RELAY $@ RELAY
R T $+ $| $* $#error $1
# anything else is bogus
R$* $#error $@ 5.7.1 $: "550 Relaying denied. Proper
authentication required."

Tina

On Aug 22, 10:14*pm, Grant Taylor <gtay...@riverviewtech.net> wrote:
> * - What is the "check_rcpt" rule set doing?

This, to be exact:

[root@tinasserver tina]# sendmail -bt -d21.4
ADDRESS TEST MODE (ruleset 3 NOT automatically invoked)
Enter <ruleset> <address>
> check_rcpt {tina@skywhisperer.com}
check_rcpt input: {tina @ skywhisperer . com}
-----skip subr Local_check_rcpt (185)
rewritten as: {tina @ skywhisperer . com} $| {tina @ skywhisperer .
com}
Basic_check_rcpt input: {tina @ skywhisperer . com}
rewrite: RHS $&{deliveryMode} => "i"
rewritten as: < i > {tina @ skywhisperer . com}
rewritten as: {tina @ skywhisperer . com}
Rcpt_ok input: {tina @ skywhisperer . com}
ParseRecipient input: {tina @ skywhisperer . com}
CanonAddr input: {tina @ skywhisperer . com}
canonify input: {tina @ skywhisperer . com}
rewritten as: {tina @ skywhisperer . com} < @ >
rewritten as: {tina @ skywhisperer . com}
rewritten as: < {tina @ skywhisperer . com} >
rewritten as: {tina @ skywhisperer . com}
rewritten as: {tina < @ skywhisperer . com} >
Canonify2 input: {tina < @ skywhisperer . com} >
rewrite: RHS $&{daemon_flags} => "(NULL)"
rewritten as: $| {tina < @ skywhisperer . com} >
rewritten as: {tina < @ skywhisperer . com} >
Canonify2 returns: {tina < @ skywhisperer . com} >
rewritten as: {tina < @ skywhisperer . com} >
canonify returns: {tina < @ skywhisperer . com} >
Parse0 input: {tina < @ skywhisperer . com} >
rewritten as: < > {tina < @ skywhisperer . com} >
rewritten as: {tina < @ skywhisperer . com} >
Parse0 returns: {tina < @ skywhisperer . com} >
rewritten as: {tina < @ skywhisperer . com} >
CanonAddr returns: {tina < @ skywhisperer . com} >
rewritten as: < ? > {tina < @ skywhisperer . com} >
rewritten as: < ? > {tina < @ skywhisperer . com} >
rewritten as: {tina < @ skywhisperer . com} >
ParseRecipient returns: {tina < @ skywhisperer . com} >
rewritten as: {tina < @ skywhisperer . com} >
rewritten as: < ? > {tina < @ skywhisperer . com} >
rewritten as: < > < {tina < @ skywhisperer . com} > > $| < F : {tina @
skywhisperer . com} > < D : skywhisp erer . com}
>
SearchList input: < + To > $| < F : {tina @ skywhisperer .
com} > < D : skywhisperer . com} > < >
F input: < {tina @ skywhisperer . com} > < ? > < + To
> < >
rewritten as: < ? > < {tina @ skywhisperer . com} > < ? > < + To > < >
rewritten as: < ? > < {tina @ skywhisperer . com} > < ? > < + To > < >
rewritten as: < ? > < >
F returns: < ? > < >
rewritten as: < + To > $| < D : skywhisperer . com} > < > $| < ? > < >
SearchList input: < + To > $| < D : skywhisperer . com} > < >
D input: < skywhisperer . com} > < ? > < + To > < >
rewritten as: < ? > < skywhisperer . com} > < ? > < + To > < >
rewritten as: < ? > < skywhisperer . com} > < ? > < + To > < >
D input: < com} > < ? > < + To > < >
rewritten as: < ? > < com} > < ? > < + To > < >
rewritten as: < ? > < com} > < ? > < + To > < >
rewritten as: < ? > < >
D returns: < ? > < >
rewritten as: < ? > < >
D returns: < ? > < >
rewritten as: < + To > $| < > $| < ? > < >
rewritten as: < ? >
SearchList returns: < ? >
rewritten as: < ? >
SearchList returns: < ? >
rewritten as: < @ > < {tina < @ skywhisperer . com} > > $| < ? >
rewritten as: < ? > < {tina < @ skywhisperer . com} > >
rewritten as: @ {tina < @ skywhisperer . com} >
rewritten as: {tina < @ skywhisperer . com} >
RelayTLS input:
rewrite: RHS $&{verify} => "(NULL)"
rewritten as: < ? >
rewritten as: NO
RelayTLS returns: NO
rewritten as: {tina < @ skywhisperer . com} > $| NO
rewritten as: {tina < @ skywhisperer . com} >
rewrite: RHS $&{auth_type} => "(NULL)"
-----skip subr Local_Relay_Auth (174)
rewritten as: {tina < @ skywhisperer . com} > $|
rewrite: RHS $&{auth_type} => "(NULL)"
rewritten as: {tina < @ skywhisperer . com} > $|
rewritten as: {tina < @ skywhisperer . com} >
D input: < skywhisperer . com} > < ? > < + To > <
{tina < @ skywhisperer . com} > >
rewritten as: < ? > < skywhisperer . com} > < ? > < + To > < {tina < @
skywhisperer . com} > >
rewritten as: < ? > < skywhisperer . com} > < ? > < + To > < {tina < @
skywhisperer . com} > >
D input: < com} > < ? > < + To > < {tina < @
skywhisperer . com} > >
rewritten as: < ? > < com} > < ? > < + To > < {tina < @ skywhisperer .
com} > >
rewritten as: < ? > < com} > < ? > < + To > < {tina < @ skywhisperer .
com} > >
rewritten as: < ? > < {tina < @ skywhisperer . com} > >
D returns: < ? > < {tina < @ skywhisperer . com} > >
rewritten as: < ? > < {tina < @ skywhisperer . com} > >
D returns: < ? > < {tina < @ skywhisperer . com} > >
rewritten as: < ? > < {tina < @ skywhisperer . com} > >
rewritten as: {tina < @ skywhisperer . com} >
rewritten as: < ? > {tina < @ skywhisperer . com} >
rewritten as: < REMOTE > {tina < @ skywhisperer . com} >
rewritten as: {tina < @ skywhisperer . com} >
Rcpt_ok returns: {tina < @ skywhisperer . com} >
rewritten as: {tina @ skywhisperer . com} $| @ {tina < @
skywhisperer . com} >
Relay_ok input: {tina @ skywhisperer . com}
rewrite: RHS $&{client_addr} => "(NULL)"
rewritten as:
rewritten as: RELAY
Relay_ok returns: RELAY
rewritten as: O $| RELAY
rewritten as: RELAY
Basic_check_rcpt returns: RELAY
rewritten as: RELAY
check_rcpt returns: RELAY

Tina Marie <skywhisperer@gmail.com> writes in comp.mail.sendmail:

> I've got sendmail 8.13.1, on a RHEL 4 box, with local bind. I'm
> handling about 6000 messages a day total. They're addressed to any
> one of the 25 or so domains I host, about half for local delivery, and
> the other half get forwarded on to gmail/yahoo/comcast accounts.
>
> 99% of the time everything is fine. But about twice a day, I'm
> getting errors where mail that is destined for one of my domains is
> being rejected:
>
> Aug 21 14:03:10 tinasserver sendmail[28220]: m7LJ2bhO028220:
> ruleset=check_rcpt, arg1=<tina@skywhisperer.com>, relay=rv-
> out-0506.google.com [209.85.198.233], reject=550 5.7.1
> <tina@skywhisperer.com>... Relaying denied. Proper authentication
> required.

That is just general Relaying denied message. cf/m4/proto.m4:

ifdef(`_USE_AUTH_', `"550 Relaying denied. Proper authentication required."', `"550 Relaying denied"'))')

> I verified that by checking that the domains are in the class w:
>
> [root@tinasserver tina]# echo '$=w' | sendmail -bt | grep
> skywhisperer.com
> skywhisperer.com

But is deamon restart ?

/ Kari Hurtta

On Aug 24, 4:30*am, Kari Hurtta <hurtta
+comp.mail.sendm...@siilo.fmi.fi> wrote:
> But is deamon restart ?

Many times. Logs say it's been going on for over a month, but that
domain's been in the class w for at least a year.

Tina

On Aug 24, 1:05*pm, Tina Marie <skywhispe...@gmail.com> wrote:
> On Aug 24, 4:30*am, Kari Hurtta <hurtta
>
> +comp.mail.sendm...@siilo.fmi.fi> wrote:
> > But is deamon restart ?
>
> Many times. *Logs say it's been going on for over a month, but that
> domain's been in the class w for at least a year.
>
> Tina

Simply because I hate googling and finding the question I want to ask
but no answer, here's an update. I turned debugging up to 25, and
there was still nothing interesting in the logs. I removed all the '-
o's from my configuration. I turned off access.db. I went back to
the 8.13 shipping cf file, adding only the MimeDefang milter, and it
still was happening. I then took out the MimeDefang calls (and, boy,
did that make my users thrilled!), and it was still happening.

Finally, in a last burst of desperation, I rebooted the server after
281 days of uptime. And I haven't seen the error since. The only
thing I can think of is that some version somewhere got out of whack.

Tina

On Sep 4, 1:47 pm, Tina Marie <skywhispe...@gmail.com> wrote:
> Finally, in a last burst of desperation, I rebooted the server after
> 281 days of uptime. And I haven't seen the error since. The only
> thing I can think of is that some version somewhere got out of whack.
>
Lets hope. You'd think that stopping/restarting would have helped,
unless
there was maybe a library that hadn't been seen properly during an
upgrade...
Maybe IPCs/shared memory was doing something nasty.

Hope it continues to stay running properly.

Tuc