Re: whoson logging

[Matti Aarnio <mea@nic.funet.fi>]

On Tue, May 20, 2003 at 04:34:11PM +0300, Andrey Blochintsev wrote:
> On Tue, 20 May 2003, Matti Aarnio wrote:
> > On Tue, May 20, 2003 at 02:55:51PM +0300, Andrey Blochintsev wrote:
...
> >   Do check if I got it right.   Oh yes, and Eugene should check it too.
> 
> I have found negatime message counts in mailq -QQQ

Nothing new in there.  It has been in my TODO fix list for a long time..

> # > mailq -QQQ
> # Kids: 149  Idle: 92  Msgs:  -8  Thrds: 188  Rcpnts:  717  Uptime: 221817 sec
> # Msgs in 79435 out 78019 stored -8 (705) Rcpnts in 185473 out 184733 stored 740
> 
> As i understand: global_wrkcnt variable decreases two times for
> each ETRN/turnme request. The first decrement caused by call of unctlfile():
>           sfprintf(sfstderr,
>                    "%s: SHOULD NOT HAPPEN: cfp->head == NULL; spoolid: %s\n",
>                    progname, cfp->spoolid);
>           unctlfile(cfp, 1);
>           sfprintf(sfstderr,
>                    "%s: SHOULD NOT HAPPEN: cfp->head == NULL; spoolid: %s\n",
>                    progname, cfp->spoolid);
>           unctlfile(cfp, 1);
> from cfp_free0() and the second by "normal" cleanup.

I never see that "SHOULD NOT HAPPEN" (not even as a single entry)
in my logs.  Furthermore, I have "etrn-cluster" running myself,
which means that the smtpserver signals the scheduler directly.

However I do have tons of 'resync' activity for various reasons,
and during that there definitely does happen negative counting..

Resyncing file "Q/K/262714-3638" (ino=262714 pid=24406 of=1 ho='web.de') reqcnt=8 global-work-count=-2172
 .. resynced!  (wrkcnt -2172)
Resyncing file "I/G/263854-3638" (ino=263854 pid=24406 of=8 ho='web.de') reqcnt=1 global-work-count=-2172
 .. resynced!  (wrkcnt -2172)
Resyncing file "R/M/263418-3638" (ino=263418 pid=24406 of=7 ho='web.de') reqcnt=5 global-work-count=-2172
 .. resynced!  (wrkcnt -2172)
Resyncing file "X/G/263568-3638" (ino=263568 pid=24406 of=4 ho='web.de') reqcnt=1 global-work-count=-2174
 .. resynced!  (wrkcnt -2174)
Resyncing file "P/E/263358-3638" (ino=263358 pid=24406 of=2 ho='web.de') reqcnt=2 global-work-count=-2174
 .. resynced!  (wrkcnt -2174)
Resyncing file "H/R/263163-3639" (ino=263163 pid=24406 of=1 ho='web.de') reqcnt=5 global-work-count=-2174
 .. resynced!  (wrkcnt -2174)

These happening means that for some reason scheduler is re-feeding
something that has been processed already, or has already been fed
into processing.

Likely these happen also when message is to two or more addresses
at the same domain.

-- 
/Matti Aarnio	<mea@nic.funet.fi>
-
To unsubscribe from this list: send the line "unsubscribe zmailer" in
the body of a message to majordomo@nic.funet.fi