[asterisk-users] Logging different verbosity levels

Kevin Harwell kharwell at sangoma.com
Mon May 23 18:12:46 CDT 2022 

So this turned out more complicated than I originally thought!

My expectation:

Verbosity gets logged using an "at least" check against the current
system's verbose level, which if passed subsequently gets checked against
the logging channel's verbose level. Thus only verbose messages with a
level less than or equal to the system's level AND the channel's level
would be logged to that channel. For example given a system verbose level
of 3, and your setup then the following should occur:

same => n,Verbose(0,Test message verbosity 0) ; gets logged to
logtest.verbose.3, logtest.verbose.2, logtest.verbose.1, and
logtest.verbose.0
same => n,Verbose(1,Test message verbosity 1) ; gets logged to
logtest.verbose.3, logtest.verbose.2, and logtest.verbose.1
same => n,Verbose(2,Test message verbosity 2) ; gets logged to
logtest.verbose.3 and logtest.verbose.2
same => n,Verbose(3,Test message verbosity 3) ; gets logged to
logtest.verbose.3
same => n,Verbose(4,Test message verbosity 4) ; nothing logged
same => n,Verbose(5,Test message verbosity 5) ; nothing logged
same => n,Verbose(6,Test message verbosity 6) ; nothing logged
same => n,Verbose(7,Test message verbosity 7) ; nothing logged
same => n,Verbose(8,Test message verbosity 8) ; nothing logged
same => n,Verbose(9,Test message verbosity 9) ; nothing logged

Reality:

What you saw in your output. As to why? Well it's a bit of a mess and it's
been that way for a while it seems. To start the app_verbose application
gets capped at verbose level 4. Meaning the following:

same => n,Verbose(7,Test message verbosity 7)

Essentially gets changed to:

same => n,Verbose(4,Test message verbosity 7)

Next, Asterisk sets the global verbose logging level according to the
following order with each level potentially overriding if greater than the
preceding:

1) core verbose level (set in asterisk.conf)
2) console level (set via system CLI, or asterisk CLI)
3) channel log level (set in logger.conf, e.g. verbose(9))

This means in asterisk.conf if you set verbose=2, and then on the CLI set
it to 3, and then for any channel in logger.conf specify verbose(9) then
the final level will be 9! The levels too are tracked via different
variables so given the preceding example the following will be output:

*CLI> core show settings
...
Root console verbosity:      2
...

Despite the actual level being 9.

Lastly, when the logger goes to output the actual log message to a channel
it does indeed first check if the channel's verbosity level is greater than
some "level" variable. But guess what? This variable is always equal to 0.
Thus as long as a channel's level is > 0 it always passes and the message
is output.

So you can see in your setup the final system level is indeed 9, and all
app_verbose messages being output are forced to 4 or less. Since the system
level is 9, and the channel's verbosity level is greater than zero then all
messages are output to all files.

Hope that makes sense!

Given all that, in my opinion there seems to be at least one or more bugs
with regards to verbose logging. Please file an issue at
https://issues.asterisk.org/. Feel free to copy/paste what's here as part
of the issue description.


On Mon, May 23, 2022 at 3:29 AM Antony Stone <
Antony.Stone at asterisk.open.source.it> wrote:

> Hi.
>
> Does no-one else know either?  I thought this was a simple question, and
> it
> was just me being unable to find the appropriate documentation to explain
> how
> these logging levels work.
>
> Please, can anyone help?
>
> On Friday 20 May 2022 at 15:33:45, Antony Stone wrote:
>
> > Hi.
> >
> > I'm trying to use different logging verbosity levels to get dialplan
> output
> > into different log files, and there's clearly something I haven't
> > understood about how Asterisk does this...
> >
> >
> > I have the following in /etc/asterisk/logger.conf:
> >
> > [logfiles]
> > logtest.verbose.0 => verbose(0)
> > logtest.verbose.1 => verbose(1)
> > logtest.verbose.2 => verbose(2)
> > logtest.verbose.3 => verbose(3)
> > logtest.verbose.4 => verbose(4)
> > logtest.verbose.5 => verbose(5)
> > logtest.verbose.6 => verbose(6)
> > logtest.verbose.7 => verbose(7)
> > logtest.verbose.8 => verbose(8)
> > logtest.verbose.9 => verbose(9)
> >
> > I then put the following at a particular point in my dialplan:
> >
> > same => n,Verbose(0,Test message verbosity 0)
> > same => n,Verbose(1,Test message verbosity 1)
> > same => n,Verbose(2,Test message verbosity 2)
> > same => n,Verbose(3,Test message verbosity 3)
> > same => n,Verbose(4,Test message verbosity 4)
> > same => n,Verbose(5,Test message verbosity 5)
> > same => n,Verbose(6,Test message verbosity 6)
> > same => n,Verbose(7,Test message verbosity 7)
> > same => n,Verbose(8,Test message verbosity 8)
> > same => n,Verbose(9,Test message verbosity 9)
> >
> > I was expecting to get each message output into the respective filename,
> > but instead I got 10 files with the expected filenames, and all
> containing
> > every test message, no matter which verbosity level it was output at.
> >
> > I'm sure there's just something basic which I haven't understaood from
> >
> >
> https://wiki.asterisk.org/wiki/display/AST/Asterisk+16+Application_Verbose
> >
> > and
> >
> > https://wiki.asterisk.org/wiki/display/AST/Logging+Configuration
> >
> >
> > Can someone please show me what I'm missing, so that I can get each
> > Verbose(N,Message) dialplan command to send its message into the log file
> > numbered N?
> >
> >
> > Thanks,
> >
> >
> > Antony.
>
> --
> The Magic Words are Squeamish Ossifrage.
>
>                                                    Please reply to the
> list;
>                                                          please *don't* CC
> me.
>
> --
> _____________________________________________________________________
> -- Bandwidth and Colocation Provided by http://www.api-digital.com --
>
> Check out the new Asterisk community forum at:
> https://community.asterisk.org/
>
> New to Asterisk? Start here:
>       https://wiki.asterisk.org/wiki/display/AST/Getting+Started
>
> asterisk-users mailing list
> To UNSUBSCRIBE or update options visit:
>    http://lists.digium.com/mailman/listinfo/asterisk-users
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.digium.com/pipermail/asterisk-users/attachments/20220523/344d16b7/attachment.html>

More information about the asterisk-users mailing list