innd logging conventions

Matus "fantomas" Uhlar uhlar at fantomas.sk
Sun Dec 24 16:25:55 UTC 2000


-> innd(8) records the following convention for innd logging:
-> 
->        Innd  also  makes  extensive  reports through syslog.  The
->        first word of the log message will be the name of the site
->        if  the  entry  is  site-specific (such as a ``connected''
->        message).  The first word will be ``SERVER'' if  the  mes-
->        sage  relates  to  the  server itself, such as when a read
->        error occurs.
-> 
->        If the second word is the four letters  ``cant''  then  an
->        error is being reported.  In this case, the next two words
->        generally name the system call  or  library  routine  that
->        failed,  and  the  object  upon which the action was being
->        performed.  The rest of the line may contain other  infor-
->        mation.
-> 
->        In other cases, the second word attempts to summarize what
->        change has been made, while the rest  of  the  line  gives
->        more  specific  information.  The word ``internal'' gener-
->        ally indicates an internal logic error.
-> 
-> What are people's general feelings about these conventions?  Are people
-> actively taking advantage of them?

Well, I am currently writing some utils that analyze syslog output for my
employer. I found innd one of programs that are very hard to analyze because
there's no simple way of analyzing it all, except of playing in patterns or
substring operations (I am doing it in perl) and thus I will process innd
later (and maybe make a patch)

What I'd like to do is change the way of writing output.

Oct 22 01:51:38 virtual innd: ME HISstats 0 hitpos 0 hitneg 99 missed 607 dne
Oct 22 01:00:53 virtual innd: SERVER paused Expiring process 90065

- these are quite easy to process

Oct 22 00:34:16 virtual innd: localhost connected 15 streaming allowed
Oct 22 21:52:00 virtual innd: localhost connected 17
Oct 22 00:34:16 virtual innd: localhost:15 closed seconds 0 accepted 0 refused 0 rejected 0
Oct 22 00:22:00 virtual innd: news.ke.sanet.sk closed
Oct 22 00:22:00 virtual innd: news.ke.sanet.sk flush
Oct 22 20:42:00 virtual innd: news.ke.sanet.sk opened news.ke.sanet.sk:17:file
Oct 22 11:11:10 virtual innd: news.ke.sanet.sk:17 NCmode "mode stream" received

- the second parameter is important and should be the first imho:
<date> virtual innd: connected <host> <fd> <args>
<date> virtual innd: closed <host> <fd> <args>
<date> virtual innd: flush <host>

etc...

Oct 22 00:22:00 virtual innd: f:news.ke.sanet.sk
Oct 22 07:42:01 virtual innd: f:news.vol.cz
Oct 22 01:00:54 virtual innd: h:Expiring process 90065
Oct 22 01:00:00 virtual innd: j:
Oct 22 01:00:53 virtual innd: m:Expiring process 90065
Oct 22 01:02:32 virtual innd: n:
Oct 22 01:00:00 virtual innd: s
Oct 22 01:00:39 virtual innd: z:Expiring process 90065

well, need to play much with these. afaik these are received commands via
control socket (ctlinnd blahblahblah) - it could be changed probably to make
it easier to process:

Oct 22 00:22:00 virtual innd: control flush news.ke.sanet.sk

 instead of 

Oct 22 00:22:00 virtual innd: f:news.ke.sanet.sk

so, i think first arguments should be those that define what happened and
just then, where it happened ("connect host", not "host connect"),
and, I'd like to split arguments that have "Static" and "dynamic" part as
mentioned above. That would imho make logd processing much more nice to
read/process

Well I know that the logs should be readable by people, and computer is very
fast ant it can process any kind of messages that are unique. But why to
make it harder ?

-> One of the difficulties in maintaining this convention in a way that is
-> applied consistently is that some of the error messages generated by innd
-> come from other portions of INN, particularly the storage manager but over
-> time from libinn as well.  Those portions obviously won't be prepending
-> SERVER since other parts of INN may call the same routines.

maybe every routine/module could prepend its name before the message ?

-> Also, should we keep the "cant" convention?  I'm a little bothered by the
-> grammatic incorrectness, but I'm leaning towards keeping it on the grounds
-> that changing things unnecessarily has little point.  Not every message
-> that should have cant currently does; if we keep it, I'll try to pick
-> those up as we go.  (It's tempting to use "can't" instead, though; it
-> really is.)

cant is good but please accept what i've mentioned above. I would like to
have simple and unique 

-> Finally, we actually also have a convention for logging that I'm going to
-> try to apply a bit more uniformly; LOG_CRIT for things that cause INN to
-> throttle or shutdown, LOG_ERR for things that may cause articles to be
-> lost or other similar levels of error, and LOG_WARNING for other things
-> that are wrong but not as bad.  My intention is to hook die up to
-> LOG_CRIT, warn up to LOG_ERR, and have code that wants to warn about
-> something less important just call syslog with LOG_WARNING directly.

agreed.

-> Does this all sound good to people?  Input?  Suggestions?

another one suggestion... news.daily (or better scanlogs) shouldn't expect
logfiles to be names news.notice, news.err, news.crit - let user(admin?)
define as he wants.

-- 
 Matus "fantomas" Uhlar, sysadmin at NEXTRA, Slovakia; IRCNET admin of *.sk
 uhlar at fantomas.sk ; http://www.fantomas.sk/ ; http://www.nextra.sk/
 42.7 percent of all statistics are made up on the spot. 

---
Odchozí zpráva obsahuje viry.
Zkontrolováno antivirovým systémem AVG (http://www.grisoft.cz).
Verze: 6.0.217 / Virová báze: 102 - datum vydání: 1/12/2000



More information about the inn-workers mailing list