cluster-devel.redhat.com archive mirror
 help / color / mirror / Atom feed
* [Cluster-devel] cluster/logging settings
@ 2008-10-30 17:17 David Teigland
  2008-10-30 18:20 ` Fabio M. Di Nitto
  0 siblings, 1 reply; 10+ messages in thread
From: David Teigland @ 2008-10-30 17:17 UTC (permalink / raw)
  To: cluster-devel.redhat.com

The new logging section in cluster.conf has the following settings:
to_stderr
to_syslog
to_file
syslog_facilty
syslog_level
logfile
debug

Here is my interpretation of how they all work:

a,b,c,x,y,z are "connections" that are all *controlled independently*
a is always on
b is always on
c is connected if debug=on
x is connected if to_stderr=yes
y is connected if to_syslog=yes
z is connected if to_file=yes

sources                    destinations  (destination-specific options)

error --a--|               |--x-- stderr
warn  --b--|---------------|--y-- syslog (syslog_facility, syslog_level)
debug --c--|               |--z-- file   (logfile)


syslog_facility and syslog_level settings are only passed to syslog and do
not effect connections in this picture at all.  Similarly, logfile is only
relevant to the file output, and does not effect any connections.

So, a,b,c can all be turned on, and if y is enabled, then syslog can be
tuned to filter some of them out.  There's no way to selectively filter
things out of file or stderr; if x or z are turned on, they will let
everything pass that comes down the pipe (a,b,c).

Common settings: a,b,c,y,z are turned on, and syslog_level is set to WARN.
Messages a,b,c will all appear in the log file, but only a,b will appear
in syslog.



^ permalink raw reply	[flat|nested] 10+ messages in thread

* [Cluster-devel] cluster/logging settings
  2008-10-30 17:17 [Cluster-devel] cluster/logging settings David Teigland
@ 2008-10-30 18:20 ` Fabio M. Di Nitto
  2008-10-30 19:02   ` David Teigland
  0 siblings, 1 reply; 10+ messages in thread
From: Fabio M. Di Nitto @ 2008-10-30 18:20 UTC (permalink / raw)
  To: cluster-devel.redhat.com

On Thu, 30 Oct 2008, David Teigland wrote:

> The new logging section in cluster.conf has the following settings:
> to_stderr
> to_syslog
> to_file
> syslog_facilty
> syslog_level
> logfile
> debug
>
> Here is my interpretation of how they all work:
>
> a,b,c,x,y,z are "connections" that are all *controlled independently*
> a is always on
> b is always on
> c is connected if debug=on
> x is connected if to_stderr=yes
> y is connected if to_syslog=yes
> z is connected if to_file=yes
>
> sources                    destinations  (destination-specific options)
>
> error --a--|               |--x-- stderr
> warn  --b--|---------------|--y-- syslog (syslog_facility, syslog_level)
> debug --c--|               |--z-- file   (logfile)
>
>
> syslog_facility and syslog_level settings are only passed to syslog and do
> not effect connections in this picture at all.  Similarly, logfile is only
> relevant to the file output, and does not effect any connections.
>
> So, a,b,c can all be turned on, and if y is enabled, then syslog can be
> tuned to filter some of them out.  There's no way to selectively filter
> things out of file or stderr; if x or z are turned on, they will let
> everything pass that comes down the pipe (a,b,c).

let's assume this:

logt_print(LOG_CRIT, "critblabla\n");
logt_print(LOG_INFO, "infoblabla\n");
if(debug)
   logt_print(LOG_DEBUG, "debugblabla\n");

If I set log_level to LOG_INFO, I do expect to see both critblabla and 
infoblabla on all selected outputs.

If I set log_level to LOG_DEBUG, I clearly expect to see debugblabla 
passing throgh as well.
(except if filtering to syslog is enabled, but we already agreed on this
as required feature so I won't mention it as special case anylonger).

I often expect that enabling LOG_DEBUG as priority, it will also enable 
debugging code in general and viceversa. If I set debug=on, I want to be 
able to catch LOG_DEBUG automatically, because i assume that most of the 
LOG_DEBUG is wrapped between if(debug) { } statements. I don't feel the 
need to set two options to enable full debugging.

Now, clearly this is only my expectation and that's how I wrote 
ccs_read_logging to act.

Probably what are mixing up here are:
- LOG_DEBUG for print operation != LOG_DEBUG for syslog.
- debug=on != LOG_DEBUG.

I don't have any objections to roll back and make debug=on different from 
priority=LOG_DEBUG as long as all the others agree on what they want (and 
both is not an option ;)).

Fabio

--
I'm going to make him an offer he can't refuse.



^ permalink raw reply	[flat|nested] 10+ messages in thread

* [Cluster-devel] cluster/logging settings
  2008-10-30 18:20 ` Fabio M. Di Nitto
@ 2008-10-30 19:02   ` David Teigland
  2008-10-31  5:28     ` Fabio M. Di Nitto
  0 siblings, 1 reply; 10+ messages in thread
From: David Teigland @ 2008-10-30 19:02 UTC (permalink / raw)
  To: cluster-devel.redhat.com

On Thu, Oct 30, 2008 at 07:20:21PM +0100, Fabio M. Di Nitto wrote:
> >a,b,c,x,y,z are "connections" that are all *controlled independently*
> >a is always on
> >b is always on
> >c is connected if debug=on
> >x is connected if to_stderr=yes
> >y is connected if to_syslog=yes
> >z is connected if to_file=yes
> >
> >sources                    destinations  (destination-specific options)
> >
> >error --a--|               |--x-- stderr
> >warn  --b--|---------------|--y-- syslog (syslog_facility, syslog_level)
> >debug --c--|               |--z-- file   (logfile)
> >
> >
> >syslog_facility and syslog_level settings are only passed to syslog and do
> >not effect connections in this picture at all.  Similarly, logfile is only
> >relevant to the file output, and does not effect any connections.
> >
> >So, a,b,c can all be turned on, and if y is enabled, then syslog can be
> >tuned to filter some of them out.  There's no way to selectively filter
> >things out of file or stderr; if x or z are turned on, they will let
> >everything pass that comes down the pipe (a,b,c).
> 
> let's assume this:
> 
> logt_print(LOG_CRIT, "critblabla\n");
> logt_print(LOG_INFO, "infoblabla\n");
> if(debug)
>   logt_print(LOG_DEBUG, "debugblabla\n");
> 
> If I set log_level to LOG_INFO, I do expect to see both critblabla and 
> infoblabla on all selected outputs.

Note that you've said "log_level", but it's actually "syslog_level", which
might lead people to different conclusions about what the option does.

> If I set log_level to LOG_DEBUG, I clearly expect to see debugblabla 
> passing throgh as well.
> (except if filtering to syslog is enabled, but we already agreed on this
> as required feature so I won't mention it as special case anylonger).
> 
> I often expect that enabling LOG_DEBUG as priority, it will also enable 
> debugging code in general and viceversa. If I set debug=on, I want to be 
> able to catch LOG_DEBUG automatically, because i assume that most of the 
> LOG_DEBUG is wrapped between if(debug) { } statements. I don't feel the 
> need to set two options to enable full debugging.

You don't need to.  Under my scheme, you set debug=on, and full debugging
appears in the log file where most people want it, and it doesn't appear
in syslog where most people wouldn't want it.  If someone *does* want all
debugging to appear in syslog, then they set debug=on and
syslog_level=debug to get it... (and once they see the result, they'll
change it back, because it's really not nice to see all that in
/var/log/messages.)

Under your scheme, syslog_level and debug change each other in confusing
and redundant ways.  By setting debug=on you automatically get all
debugging in syslog (in addition to the logfile usually), which is not
where we wanted it...  So we added yet another complication:
LOG_MODE_FILTER_DEBUG_FROM_SYSLOG, which counteracts the bad effects of
the debug/syslog_level interaction which we didn't really want in the
first place.  See how complicated this gets when you have one option
changing another one, but not quite the way you want, so you add another
flag to work around the unintended effects of one setting implicitly
changing another?  It's bad all around: just keep them independent and all
the pain goes away.

(We wouldn't need FILTER_DEBUG_FROM_SYSLOG in my scheme because you
control each source and destination point explicitly; you say exactly what
you want, and get it.)

> Now, clearly this is only my expectation and that's how I wrote 
> ccs_read_logging to act.
> 
> Probably what are mixing up here are:
> - LOG_DEBUG for print operation != LOG_DEBUG for syslog.
> - debug=on != LOG_DEBUG.
> 
> I don't have any objections to roll back and make debug=on different from 
> priority=LOG_DEBUG as long as all the others agree on what they want (and 
> both is not an option ;)).




^ permalink raw reply	[flat|nested] 10+ messages in thread

* [Cluster-devel] cluster/logging settings
  2008-10-30 19:02   ` David Teigland
@ 2008-10-31  5:28     ` Fabio M. Di Nitto
  2008-10-31  5:34       ` Fabio M. Di Nitto
  2008-10-31  6:26       ` Steven Dake
  0 siblings, 2 replies; 10+ messages in thread
From: Fabio M. Di Nitto @ 2008-10-31  5:28 UTC (permalink / raw)
  To: cluster-devel.redhat.com

On Thu, 30 Oct 2008, David Teigland wrote:

>> If I set log_level to LOG_INFO, I do expect to see both critblabla and
>> infoblabla on all selected outputs.
>
> Note that you've said "log_level", but it's actually "syslog_level", which
> might lead people to different conclusions about what the option does.

I meant syslog_level. You are right.

void logt_print(int level, char *fmt, ...)
{
         va_list ap;

         if (level > logt_priority)
                 return;

we send a logt_print(LOG_DEBUG..
but if syslog_level is set to LOG_INFO, that message will not make it 
anywhere, even if debug=on.

>
>> If I set log_level to LOG_DEBUG, I clearly expect to see debugblabla
>> passing throgh as well.
>> (except if filtering to syslog is enabled, but we already agreed on this
>> as required feature so I won't mention it as special case anylonger).
>>
>> I often expect that enabling LOG_DEBUG as priority, it will also enable
>> debugging code in general and viceversa. If I set debug=on, I want to be
>> able to catch LOG_DEBUG automatically, because i assume that most of the
>> LOG_DEBUG is wrapped between if(debug) { } statements. I don't feel the
>> need to set two options to enable full debugging.
>
> You don't need to.  Under my scheme, you set debug=on, and full debugging
> appears in the log file where most people want it, and it doesn't appear
> in syslog where most people wouldn't want it.

Not really.. see below the code snippet...

>  If someone *does* want all
> debugging to appear in syslog, then they set debug=on and
> syslog_level=debug to get it... (and once they see the result, they'll
> change it back, because it's really not nice to see all that in
> /var/log/messages.)

We all agreed on this already that's why we have the 
LOG_MODE_FILTER_DEBUG_FROM_SYSLOG that we should probably make a config 
option in cluster.conf or simply avoid by default.

> Under your scheme, syslog_level and debug change each other in confusing
> and redundant ways.

It's not really confusing.. debug enables LOG_DEBUG and LOG_DEBUG enables 
debug. The only thing that might be confusing is that you need to take 
into account global debug, (sub)system debug setting and priority.

>  By setting debug=on you automatically get all
> debugging in syslog (in addition to the logfile usually), which is not
> where we wanted it...  So we added yet another complication:
> LOG_MODE_FILTER_DEBUG_FROM_SYSLOG, which counteracts the bad effects of
> the debug/syslog_level interaction which we didn't really want in the
> first place.  See how complicated this gets when you have one option
> changing another one, but not quite the way you want, so you add another
> flag to work around the unintended effects of one setting implicitly
> changing another?  It's bad all around: just keep them independent and all
> the pain goes away.
>
> (We wouldn't need FILTER_DEBUG_FROM_SYSLOG in my scheme because you
> control each source and destination point explicitly; you say exactly what
> you want, and get it.)

Unless I am misreading your code:

void logt_print(int level, char *fmt, ...)
{
         va_list ap;

         if (level > logt_priority)
                 return;

we send a logt_print(LOG_DEBUG..
if syslog_level is set to LOG_INFO, that message will not make it
anywhere, even if debug=on.

maybe debug=on should really set syslog_level=LOG_DEBUG and 
LOG_MODE_FILTER_DEBUG_FROM_SYSLOG to make this really happen.

Fabio

--
I'm going to make him an offer he can't refuse.



^ permalink raw reply	[flat|nested] 10+ messages in thread

* [Cluster-devel] cluster/logging settings
  2008-10-31  5:28     ` Fabio M. Di Nitto
@ 2008-10-31  5:34       ` Fabio M. Di Nitto
  2008-10-31  6:26       ` Steven Dake
  1 sibling, 0 replies; 10+ messages in thread
From: Fabio M. Di Nitto @ 2008-10-31  5:34 UTC (permalink / raw)
  To: cluster-devel.redhat.com

On Fri, 31 Oct 2008, Fabio M. Di Nitto wrote:

> On Thu, 30 Oct 2008, David Teigland wrote:
>
>>> If I set log_level to LOG_INFO, I do expect to see both critblabla and
>>> infoblabla on all selected outputs.
>> 
>> Note that you've said "log_level", but it's actually "syslog_level", which
>> might lead people to different conclusions about what the option does.
>
> I meant syslog_level. You are right.
>
> void logt_print(int level, char *fmt, ...)
> {
>        va_list ap;
>
>        if (level > logt_priority)
>                return;
>
> we send a logt_print(LOG_DEBUG..
> but if syslog_level is set to LOG_INFO, that message will not make it 
> anywhere, even if debug=on.
>

^^sorry-- bad copy paste... it should have come out only once :)

Fabio

--
I'm going to make him an offer he can't refuse.



^ permalink raw reply	[flat|nested] 10+ messages in thread

* [Cluster-devel] cluster/logging settings
  2008-10-31  5:28     ` Fabio M. Di Nitto
  2008-10-31  5:34       ` Fabio M. Di Nitto
@ 2008-10-31  6:26       ` Steven Dake
  2008-11-04 20:58         ` David Teigland
  1 sibling, 1 reply; 10+ messages in thread
From: Steven Dake @ 2008-10-31  6:26 UTC (permalink / raw)
  To: cluster-devel.redhat.com


On Fri, 2008-10-31 at 06:28 +0100, Fabio M. Di Nitto wrote:
> On Thu, 30 Oct 2008, David Teigland wrote:
> 
> >> If I set log_level to LOG_INFO, I do expect to see both critblabla and
> >> infoblabla on all selected outputs.
> >
> > Note that you've said "log_level", but it's actually "syslog_level", which
> > might lead people to different conclusions about what the option does.
> 
> I meant syslog_level. You are right.
> 
> void logt_print(int level, char *fmt, ...)
> {
>          va_list ap;
> 
>          if (level > logt_priority)
>                  return;
> 
> we send a logt_print(LOG_DEBUG..
> but if syslog_level is set to LOG_INFO, that message will not make it 
> anywhere, even if debug=on.
> 
> >
> >> If I set log_level to LOG_DEBUG, I clearly expect to see debugblabla
> >> passing throgh as well.
> >> (except if filtering to syslog is enabled, but we already agreed on this
> >> as required feature so I won't mention it as special case anylonger).
> >>
> >> I often expect that enabling LOG_DEBUG as priority, it will also enable
> >> debugging code in general and viceversa. If I set debug=on, I want to be
> >> able to catch LOG_DEBUG automatically, because i assume that most of the
> >> LOG_DEBUG is wrapped between if(debug) { } statements. I don't feel the
> >> need to set two options to enable full debugging.
> >
> > You don't need to.  Under my scheme, you set debug=on, and full debugging
> > appears in the log file where most people want it, and it doesn't appear
> > in syslog where most people wouldn't want it.
> 
> Not really.. see below the code snippet...
> 
> >  If someone *does* want all
> > debugging to appear in syslog, then they set debug=on and
> > syslog_level=debug to get it... (and once they see the result, they'll
> > change it back, because it's really not nice to see all that in
> > /var/log/messages.)
> 
> We all agreed on this already that's why we have the 
> LOG_MODE_FILTER_DEBUG_FROM_SYSLOG that we should probably make a config 
> option in cluster.conf or simply avoid by default.
> 
> > Under your scheme, syslog_level and debug change each other in confusing
> > and redundant ways.
> 
> It's not really confusing.. debug enables LOG_DEBUG and LOG_DEBUG enables 
> debug. The only thing that might be confusing is that you need to take 
> into account global debug, (sub)system debug setting and priority.
> 
> >  By setting debug=on you automatically get all
> > debugging in syslog (in addition to the logfile usually), which is not
> > where we wanted it...  So we added yet another complication:
> > LOG_MODE_FILTER_DEBUG_FROM_SYSLOG, which counteracts the bad effects of
> > the debug/syslog_level interaction which we didn't really want in the
> > first place.  See how complicated this gets when you have one option
> > changing another one, but not quite the way you want, so you add another
> > flag to work around the unintended effects of one setting implicitly
> > changing another?  It's bad all around: just keep them independent and all
> > the pain goes away.
> >
> > (We wouldn't need FILTER_DEBUG_FROM_SYSLOG in my scheme because you
> > control each source and destination point explicitly; you say exactly what
> > you want, and get it.)
> 
> Unless I am misreading your code:
> 
> void logt_print(int level, char *fmt, ...)
> {
>          va_list ap;
> 
>          if (level > logt_priority)
>                  return;
> 
> we send a logt_print(LOG_DEBUG..
> if syslog_level is set to LOG_INFO, that message will not make it
> anywhere, even if debug=on.
> 
> maybe debug=on should really set syslog_level=LOG_DEBUG and 
> LOG_MODE_FILTER_DEBUG_FROM_SYSLOG to make this really happens
> 

Here is my take on how logging should work and does work in logsysv2.

There are two types of messages.  Those intended for users/admins and
those intended for developers.

Both of these message types should always be recorded *somewhere*.  The
entire concept of "LOG_LEVEL_DEBUG" is dubious to me.  If you want to
stick with that symanetic and definition that is fine, but really a
LOG_LEVEL_DEBUG means "this message is for the developer".  These
messages should be recorded and stored when a process segfaults, aborts
due to assertion, or at administrative request.  Since the frequency of
these messages is high there is no other option for recording them since
they must _always_ be recorded for the purposes of debugging a field
failure.  Recording to disk or syslog has significant performance
impact.

The only solution for these types of messages is to record them into a
flight recorder buffer which can be dumped:
1) at segv
2) at sigabt
3) at administrative request

This is a fundamental difference in how we have approached logging
debugging messages in the past but will lead to the ability to ensure we
_always_ have debug trace data available instead of telling the
user/admin "Go turn on debug and hope you can reproduce that error and
btw since 100000k messages are logged your disk will fill up with
irrelevant debug messages and your system will perform like mud".

Logging these in memory is the only solution that I see as suitable and
in all cases they should be filtered from any output source such as
stderr, file, or syslog.

Regards
-steve


 
> Fabio
> 
> --
> I'm going to make him an offer he can't refuse.
> 



^ permalink raw reply	[flat|nested] 10+ messages in thread

* [Cluster-devel] cluster/logging settings
  2008-10-31  6:26       ` Steven Dake
@ 2008-11-04 20:58         ` David Teigland
  2008-11-04 21:24           ` David Teigland
  2008-11-07  2:42           ` Steven Dake
  0 siblings, 2 replies; 10+ messages in thread
From: David Teigland @ 2008-11-04 20:58 UTC (permalink / raw)
  To: cluster-devel.redhat.com

On Thu, Oct 30, 2008 at 11:26:14PM -0700, Steven Dake wrote:
> There are two types of messages.  Those intended for users/admins and
> those intended for developers.
> 
> Both of these message types should always be recorded *somewhere*.  The
> entire concept of "LOG_LEVEL_DEBUG" is dubious to me.  If you want to
> stick with that symanetic and definition that is fine, but really a
> LOG_LEVEL_DEBUG means "this message is for the developer".  These
> messages should be recorded and stored when a process segfaults, aborts
> due to assertion, or at administrative request.  Since the frequency of
> these messages is high there is no other option for recording them since
> they must _always_ be recorded for the purposes of debugging a field
> failure.  Recording to disk or syslog has significant performance
> impact.
> 
> The only solution for these types of messages is to record them into a
> flight recorder buffer which can be dumped:
> 1) at segv
> 2) at sigabt
> 3) at administrative request
> 
> This is a fundamental difference in how we have approached logging
> debugging messages in the past but will lead to the ability to ensure we
> _always_ have debug trace data available instead of telling the
> user/admin "Go turn on debug and hope you can reproduce that error and
> btw since 100000k messages are logged your disk will fill up with
> irrelevant debug messages and your system will perform like mud".
> 
> Logging these in memory is the only solution that I see as suitable and
> in all cases they should be filtered from any output source such as
> stderr, file, or syslog.

There's a difference between high volume trace debug data stored in
memory, and low volume informational debug data that can be easily written
to a file.  Both kinds of data can be useful.

My programs are simple enough that low volume informational debug data is
enough for me to identify and fix a problem.  So, low volume informational
data is all I produce.  It can be useful to write this data to a file.

Your program is complex enough that high volume trace debug data is
usually needed for you to identify and fix a problem.  So, high volume
trace data is all you produce.  This is too much data to write to a file
(by the running program).

So, we're using "DEBUG" to refer to different things.  We need to define
two different levels (just for clarity in this discussion):
. DEBUGLO is low volume informational data like I use
. DEBUGHI is high volume trace data like you use

DEBUGHI messages wouldn't ever be logged to files by the program while
running.  DEBUGLO messages could be, though, if the user configured it.
So, circling back around, how should a user configure DEBUGLO messages to
appear in syslog or a logfile?   In particular, what would they enter in
the cluster.conf <logging/> section?  My suggestion is:

  syslog_level=foo
  logfile_level=bar

where foo and bar are one of the standard priority names in syslog.h.
So, if a user wanted DEBUGLO messages to appear in daemon.log, they'd set

  logging/<daemon>/logfile_level=debug

and if they wanted DEBUGLO messages to appear in /var/log/messages,

  logging/<daemon>/syslog_level=debug

(Note that "debug" means DEBUGLO here because DEBUGHI messages are only
saved in memory, not to files by a running program.)

There's another separate question I have about corosync, and that's
whether you could identify some limited number of messages that would be
appropriate for DEBUGLO?  They would be used by non-experts to do some
rough debugging of problems, and by experts to narrow down a problem
before digging into the high volume trace data.  I'd suggest that a good
starting point for DEBUGLO would be the data that openais has historically
put in /var/log/messages.  Data that helps you quickly triage a problem
(or verify that things are happening correctly) without stepping through
all the trace data.



^ permalink raw reply	[flat|nested] 10+ messages in thread

* [Cluster-devel] cluster/logging settings
  2008-11-04 20:58         ` David Teigland
@ 2008-11-04 21:24           ` David Teigland
  2008-11-07  2:42           ` Steven Dake
  1 sibling, 0 replies; 10+ messages in thread
From: David Teigland @ 2008-11-04 21:24 UTC (permalink / raw)
  To: cluster-devel.redhat.com

On Tue, Nov 04, 2008 at 02:58:47PM -0600, David Teigland wrote:
> the cluster.conf <logging/> section?  My suggestion is:
> 
>   syslog_level=foo
>   logfile_level=bar

FWIW, I'm not set on this if someone has a better suggestion.  I just want
something unambiguous.  "debug=on" has been shown to mean something
different to everyone.

Dave



^ permalink raw reply	[flat|nested] 10+ messages in thread

* [Cluster-devel] cluster/logging settings
  2008-11-04 20:58         ` David Teigland
  2008-11-04 21:24           ` David Teigland
@ 2008-11-07  2:42           ` Steven Dake
  2008-11-07  5:07             ` Fabio M. Di Nitto
  1 sibling, 1 reply; 10+ messages in thread
From: Steven Dake @ 2008-11-07  2:42 UTC (permalink / raw)
  To: cluster-devel.redhat.com


On Tue, 2008-11-04 at 14:58 -0600, David Teigland wrote:
> On Thu, Oct 30, 2008 at 11:26:14PM -0700, Steven Dake wrote:
> > There are two types of messages.  Those intended for users/admins and
> > those intended for developers.
> > 
> > Both of these message types should always be recorded *somewhere*.  The
> > entire concept of "LOG_LEVEL_DEBUG" is dubious to me.  If you want to
> > stick with that symanetic and definition that is fine, but really a
> > LOG_LEVEL_DEBUG means "this message is for the developer".  These
> > messages should be recorded and stored when a process segfaults, aborts
> > due to assertion, or at administrative request.  Since the frequency of
> > these messages is high there is no other option for recording them since
> > they must _always_ be recorded for the purposes of debugging a field
> > failure.  Recording to disk or syslog has significant performance
> > impact.
> > 
> > The only solution for these types of messages is to record them into a
> > flight recorder buffer which can be dumped:
> > 1) at segv
> > 2) at sigabt
> > 3) at administrative request
> > 
> > This is a fundamental difference in how we have approached logging
> > debugging messages in the past but will lead to the ability to ensure we
> > _always_ have debug trace data available instead of telling the
> > user/admin "Go turn on debug and hope you can reproduce that error and
> > btw since 100000k messages are logged your disk will fill up with
> > irrelevant debug messages and your system will perform like mud".
> > 
> > Logging these in memory is the only solution that I see as suitable and
> > in all cases they should be filtered from any output source such as
> > stderr, file, or syslog.
> 
> There's a difference between high volume trace debug data stored in
> memory, and low volume informational debug data that can be easily written
> to a file.  Both kinds of data can be useful.
> 
> My programs are simple enough that low volume informational debug data is
> enough for me to identify and fix a problem.  So, low volume informational
> data is all I produce.  It can be useful to write this data to a file.
> 
> Your program is complex enough that high volume trace debug data is
> usually needed for you to identify and fix a problem.  So, high volume
> trace data is all you produce.  This is too much data to write to a file
> (by the running program).
> 
> So, we're using "DEBUG" to refer to different things.  We need to define
> two different levels (just for clarity in this discussion):
> . DEBUGLO is low volume informational data like I use
> . DEBUGHI is high volume trace data like you use
> 
> DEBUGHI messages wouldn't ever be logged to files by the program while
> running.  DEBUGLO messages could be, though, if the user configured it.
> So, circling back around, how should a user configure DEBUGLO messages to
> appear in syslog or a logfile?   In particular, what would they enter in
> the cluster.conf <logging/> section?  My suggestion is:
> 
>   syslog_level=foo
>   logfile_level=bar
> 
> where foo and bar are one of the standard priority names in syslog.h.
> So, if a user wanted DEBUGLO messages to appear in daemon.log, they'd set
> 
>   logging/<daemon>/logfile_level=debug
> 
> and if they wanted DEBUGLO messages to appear in /var/log/messages,
> 
>   logging/<daemon>/syslog_level=debug
> 
> (Note that "debug" means DEBUGLO here because DEBUGHI messages are only
> saved in memory, not to files by a running program.)
> 
> There's another separate question I have about corosync, and that's
> whether you could identify some limited number of messages that would be
> appropriate for DEBUGLO?  They would be used by non-experts to do some
> rough debugging of problems, and by experts to narrow down a problem
> before digging into the high volume trace data.  I'd suggest that a good
> starting point for DEBUGLO would be the data that openais has historically
> put in /var/log/messages.  Data that helps you quickly triage a problem
> (or verify that things are happening correctly) without stepping through
> all the trace data.
> 

I thought about this a few days and this seems to make sense.  The
priority (ie: specifically LOG_LEVEL_DEBUG messages) would be selectable
per output medium (syslog, file, or stderr) and the high performance
tracing would use the trace macros or log_rec and only ever go to
memory.  Each output medium if configured would filter based upon a
filtering priority which is LOG_LEVEL_DEBUG or others.

This does require further API changes that Fabio would have to manage
with.

Regards
-steve



^ permalink raw reply	[flat|nested] 10+ messages in thread

* [Cluster-devel] cluster/logging settings
  2008-11-07  2:42           ` Steven Dake
@ 2008-11-07  5:07             ` Fabio M. Di Nitto
  0 siblings, 0 replies; 10+ messages in thread
From: Fabio M. Di Nitto @ 2008-11-07  5:07 UTC (permalink / raw)
  To: cluster-devel.redhat.com

On Thu, 2008-11-06 at 19:42 -0700, Steven Dake wrote:
> On Tue, 2008-11-04 at 14:58 -0600, David Teigland wrote:
> > On Thu, Oct 30, 2008 at 11:26:14PM -0700, Steven Dake wrote:
> > > There are two types of messages.  Those intended for users/admins and
> > > those intended for developers.
> > > 
> > > Both of these message types should always be recorded *somewhere*.  The
> > > entire concept of "LOG_LEVEL_DEBUG" is dubious to me.  If you want to
> > > stick with that symanetic and definition that is fine, but really a
> > > LOG_LEVEL_DEBUG means "this message is for the developer".  These
> > > messages should be recorded and stored when a process segfaults, aborts
> > > due to assertion, or at administrative request.  Since the frequency of
> > > these messages is high there is no other option for recording them since
> > > they must _always_ be recorded for the purposes of debugging a field
> > > failure.  Recording to disk or syslog has significant performance
> > > impact.
> > > 
> > > The only solution for these types of messages is to record them into a
> > > flight recorder buffer which can be dumped:
> > > 1) at segv
> > > 2) at sigabt
> > > 3) at administrative request
> > > 
> > > This is a fundamental difference in how we have approached logging
> > > debugging messages in the past but will lead to the ability to ensure we
> > > _always_ have debug trace data available instead of telling the
> > > user/admin "Go turn on debug and hope you can reproduce that error and
> > > btw since 100000k messages are logged your disk will fill up with
> > > irrelevant debug messages and your system will perform like mud".
> > > 
> > > Logging these in memory is the only solution that I see as suitable and
> > > in all cases they should be filtered from any output source such as
> > > stderr, file, or syslog.
> > 
> > There's a difference between high volume trace debug data stored in
> > memory, and low volume informational debug data that can be easily written
> > to a file.  Both kinds of data can be useful.
> > 
> > My programs are simple enough that low volume informational debug data is
> > enough for me to identify and fix a problem.  So, low volume informational
> > data is all I produce.  It can be useful to write this data to a file.
> > 
> > Your program is complex enough that high volume trace debug data is
> > usually needed for you to identify and fix a problem.  So, high volume
> > trace data is all you produce.  This is too much data to write to a file
> > (by the running program).
> > 
> > So, we're using "DEBUG" to refer to different things.  We need to define
> > two different levels (just for clarity in this discussion):
> > . DEBUGLO is low volume informational data like I use
> > . DEBUGHI is high volume trace data like you use
> > 
> > DEBUGHI messages wouldn't ever be logged to files by the program while
> > running.  DEBUGLO messages could be, though, if the user configured it.
> > So, circling back around, how should a user configure DEBUGLO messages to
> > appear in syslog or a logfile?   In particular, what would they enter in
> > the cluster.conf <logging/> section?  My suggestion is:
> > 
> >   syslog_level=foo
> >   logfile_level=bar
> > 
> > where foo and bar are one of the standard priority names in syslog.h.
> > So, if a user wanted DEBUGLO messages to appear in daemon.log, they'd set
> > 
> >   logging/<daemon>/logfile_level=debug
> > 
> > and if they wanted DEBUGLO messages to appear in /var/log/messages,
> > 
> >   logging/<daemon>/syslog_level=debug
> > 
> > (Note that "debug" means DEBUGLO here because DEBUGHI messages are only
> > saved in memory, not to files by a running program.)
> > 
> > There's another separate question I have about corosync, and that's
> > whether you could identify some limited number of messages that would be
> > appropriate for DEBUGLO?  They would be used by non-experts to do some
> > rough debugging of problems, and by experts to narrow down a problem
> > before digging into the high volume trace data.  I'd suggest that a good
> > starting point for DEBUGLO would be the data that openais has historically
> > put in /var/log/messages.  Data that helps you quickly triage a problem
> > (or verify that things are happening correctly) without stepping through
> > all the trace data.
> > 
> 
> I thought about this a few days and this seems to make sense.  The
> priority (ie: specifically LOG_LEVEL_DEBUG messages) would be selectable
> per output medium (syslog, file, or stderr) and the high performance
> tracing would use the trace macros or log_rec and only ever go to
> memory.  Each output medium if configured would filter based upon a
> filtering priority which is LOG_LEVEL_DEBUG or others.
> 
> This does require further API changes that Fabio would have to manage
> with.

Ok good that we are heading towards the same goal.

Before you fully dive into this code, let's finalize the config options
for logging across the board. The API change at this point is no problem
since cluster.git didn't move to the logsys v2 API yet.

I'll send a summary of the different thread in another email to the
different mailing lists. Users might have different ideas as well.

Fabio



^ permalink raw reply	[flat|nested] 10+ messages in thread

end of thread, other threads:[~2008-11-07  5:07 UTC | newest]

Thread overview: 10+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
2008-10-30 17:17 [Cluster-devel] cluster/logging settings David Teigland
2008-10-30 18:20 ` Fabio M. Di Nitto
2008-10-30 19:02   ` David Teigland
2008-10-31  5:28     ` Fabio M. Di Nitto
2008-10-31  5:34       ` Fabio M. Di Nitto
2008-10-31  6:26       ` Steven Dake
2008-11-04 20:58         ` David Teigland
2008-11-04 21:24           ` David Teigland
2008-11-07  2:42           ` Steven Dake
2008-11-07  5:07             ` Fabio M. Di Nitto

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).