[asterisk-dev] Some less wild thoughts about logging

[Jay R. Ashworth]

[ un-threaded ]

On Tue, Sep 09, 2008 at 06:02:38PM +0200, Johan Wilfer wrote:
> I guess logging.conf i logically, but how?
> 
> I would however gladly volunteer to help in the janitor project.
> 
> Arguments that would be helpful in a database (for filtering)
> *) uniqueid for the call
> *) time (epoch, not text)
> more?

Well, perhaps it's not already well understood.  :-)

So I'll babble anyway, and perhaps someone productive will find it
comprehensible rather than compost.

===

Logging has two issues: where and what.

Where has to be: screen, file, syslog, with configurable (ranges of)
verbose and debug for each -- and possibly more than one of
{file,syslog}.

Like so:

# dest	verbose	debug
screen	12	20
local3	6	0
/var/log/asterisk/basic	6	0
/var/log/asterisk/debug	12	20

(note: all levels pulled out of my butt, where the wild monkeys fly)

Screen logging can have fancy color codes if you like; file logging had
better not.  No line wrapping either.  The goal is to be compatible with
log watcher programs; look at their expectation for formatting, but in
general, big long lines of ASCII7 text with newlines at the end.

Why syslog?

Cause lots of people have ridiculous amounts of infrastructure built up
around syslog; failing to support it violates my first principle of
design: Get The Glue Right.   (See the VGA and PS2 connectors on the ADDS
4000 serial terminal for more on this.)

===

What needs to be logged is this:

DATE TIME HOST asterisk MODULE LEVEL SEVERITY CHANNEL CALLID CALLTAG MESSAGE

DATE and TIME should be compatible with the appropriate facility, or in
YYYY-MM-DD HH:MM:SS.SSSS format (timezone tag in keeping with the
convention -- which means I'll look up later whether they're usually in
zone of UTC :-)

HOST is the local hostname, of course

asterisk is the subsystem tag

MODULE is the tag for the core, a builtin subsystem, an application, or
the basename of an AGI on whose behalf this particular message was
generated.

LEVEL is the verbose or debug level the message was generated at (v7,d12)

SEVERITY is the level of importance of the message.  It might be
optional, since you can infer it from the LEVEL.

CHANNEL is the Asterisk Channel identifier related to the message if
there is one, else "-"

CALLID is the internal Asterisk Call Unique ID

CALLTAG is an application level Call identifier, set, perhaps, by an
Application, Dialplan or AGI.  I don't think anything has a place to
store this, but it really needs to be in there.

MESSAGE is the actual message, including any other necessary parameters
to allow its useful interpretation.  Putting in the CHANNEL will help
with 60-70% of those "you couldn't do that to *what*??" questions, but
not all.

There are *lots* of messages generated by Asterisk that are a waste of
space because you can't tell which call or channel they're talking about
and on a busy system, there's too much interleaving to allow you to
guess.

This can make problems undiagnosable, especially when they occur under
load.

===

I run a cluster with 12 diallers, a spare * box, 2 web servers, and about
5 DBMS boxes, running VICIdial for 257 seats.  Because Asterisk's logging
and verbosity are so unreasonably haphazard, there are times when I
simply cannot tell why something's not working as expected.

We're running 1.2 at the moment, because Matt's not happy with 1.4's
stability under the load we generate, but no one's told me that the
logging has ever been appreciably improved even for 1.6.

My intuition is that since it's so hard to determine which messages in a
log come from what, no one has any particular amount of infrastructure
built up around parsing Asterisk logs in real time, but I'd be interested
to hear...

Cheers,
-- jra
-- 
Jay R. Ashworth                   Baylink                      jra at baylink.com
Designer                     The Things I Think                       RFC 2100
Ashworth & Associates     http://baylink.pitas.com                     '87 e24
St Petersburg FL USA      http://photo.imageinc.us             +1 727 647 1274

	     Those who cast the vote decide nothing.
	     Those who count the vote decide everything.
	       -- (Josef Stalin)