On Wed, Feb 28, 2018 at 2:03 PM, Tito <[email protected]> wrote:
> Hi,
>
> forgot to add the [PATCH] tag so I resend it.
>
> Ciao,
> Tito
>
> On 04/02/2018 19:53, Denys Vlasenko wrote:
>>
>> On Thu, Nov 30, 2017 at 9:51 PM, Tito <[email protected]> wrote:
>>>
>>> On 11/30/2017 08:26 PM, Deweloper wrote:
>>>>
>>>> Many applets are daemons (or can be run as daemons) and send messages to
>>>> syslog. The problem is that the messages don't have accurate,
>>>> individually
>>>> assigned severity; they are all LOG_ERR. Effectively, system
>>>> administrator sees
>>>> a lot of ERRORs in the log even when everything goes well. It seems that
>>>> libbb
>>>> provides only bb_error_msg() as a convenient way to print a message
>>>> (including
>>>> sending it to syslog), while a more generic function taking severity as
>>>> well
>>>> would be needed instead. grep -r 'syslog(' shows that only some
>>>> loginutils call
>>>> syslog() directly. In other places bb_error_msg() is used even for
>>>> informational or verbose debugging messages. Just have a look at output
>>>> of
>>>> grep -r 'bb_error_msg('
>>>>
>>>> Do you have an idea how to clean this up? Shouldn't these messages be
>>>> sent to a
>>>> new function, e.g. bb_msg(), which would additionally take "severity"
>>>> argument?
>>
>>
>> The "severity" arg usually ends up being a PITA.
>> For example, it's rather unreadable.
>> Then, it tends to proliferate: after you have errors/not-errors,
>> then someone wants critical/errors/not-errors/debug - which adds
>> another dimension to coding every error message: "what severity is it?!"
>>
>>
>>> 4) create a function that changes syslog_level to LOG_INFO, add it to
>>> libbb,
>>>     and then change the code of the applets accordingly, for example:
>>>
>>> void FAST_FUNC bb_info_msg(const char *s, ...)
>>> {
>>>          va_list p;
>>> #if ENABLE_FEATURE_SYSLOG
>>>          smallint syslog_level_old =  syslog_level;
>>>          syslog_level = LOG_INFO;
>>> #endif
>>>          va_start(p, s);
>>>          bb_verror_msg(s, p, NULL);
>>> #if ENABLE_FEATURE_SYSLOG
>>>          syslog_level = syslog_level_old;
>>> #endif
>>>          va_end(p);
>>> }
>>
>>
>> I like this. Feel free to send patches doing this.
>>
>>> I wonder if the compiler could be so smart to see that this is
>>> the same as bb_error_msg when  ENABLE_FEATURE_SYSLOG is not set
>>> and optimize it out.
>>
>>
>> #if !ENABLE_FEATURE_SYSLOG
>> #define bb_info_msg(...) bb_error_msg(__VA_ARGS__)
>> #endif
>>
>
> Hi,
> attached you will find a patch that adds bb_info_msg function to libbb.
> This patch is tested with and without CONFIG_SYSLOG
> set but there are no users yet.
>
> Ciao,
> Tito
>
> --- include/libbb.h.orig        2018-02-04 23:27:22.000000000 +0100
> +++ include/libbb.h     2018-02-04 23:43:08.054064117 +0100
> @@ -1277,6 +1277,11 @@ extern void (*die_func)(void);
>  extern void xfunc_die(void) NORETURN FAST_FUNC;
>  extern void bb_show_usage(void) NORETURN FAST_FUNC;
>  extern void bb_error_msg(const char *s, ...) __attribute__ ((format
> (printf, 1, 2))) FAST_FUNC;
> +#if ENABLE_FEATURE_SYSLOG
> +extern void bb_info_msg(const char *s, ...) __attribute__ ((format (printf,
> 1, 2))) FAST_FUNC;
> +#else
> +#define bb_info_msg(...)       bb_error_msg(__VA_ARGS__)
> +#endif
>  extern void bb_error_msg_and_die(const char *s, ...) __attribute__
> ((noreturn, format (printf, 1, 2))) FAST_FUNC;
>  extern void bb_perror_msg(const char *s, ...) __attribute__ ((format
> (printf, 1, 2))) FAST_FUNC;
>  extern void bb_simple_perror_msg(const char *s) FAST_FUNC;
> --- libbb/verror_msg.c.orig     2017-07-24 00:27:51.000000000 +0200
> +++ libbb/verror_msg.c  2018-02-05 00:54:09.587081933 +0100
> @@ -180,3 +180,17 @@ void FAST_FUNC bb_error_msg(const char *
>         bb_verror_msg(s, p, NULL);
>         va_end(p);
>  }
> +
> +#if ENABLE_FEATURE_SYSLOG
> +void FAST_FUNC bb_info_msg(const char *s, ...)
> +{
> +       va_list p;
> +       smallint syslog_level_old =  syslog_level;
> +
> +       syslog_level = LOG_INFO;
> +       va_start(p, s);
> +       bb_verror_msg(s, p, NULL);
> +       syslog_level = syslog_level_old;
> +       va_end(p);
> +}
> +#endif


I'm thinking about it and I think this looks good at first glance,
but in practice has usability problems.

You can see these problems more clearly when you imagine
yourself coding and having to decide whether a given "error" condition
(e.g. failure to open a file) should be bb_error_msg
or bb_info_msg?

Well, it depends on *what file it is*.

If you fail to open "/proc/cmdline", this is probably not
something unexpected and worthy of logging to syslog.
If modprobe encounters this condition, it can simply assume
kernel command line had no module params.

OTOH, crond failing to open its logfile is unexpected.

How libbb function open_or_warn() supposed to decide this?

I really hate having yet another flavor of it,
open_or_warn_loudly(). For one, *the caller of open_or_warn()*
may not know the severity either.

Putting my admin hat on, I say that I become much happier
when I set up my boxes to have separate logs for separate
services/daemons. No mixing of unrelated messages.
No "one daemon spammed the log overnight with gazillions of messages,
rotating everybody else's logs into oblivion".

Maybe centralized syslog is not the best design?

The downside is that there is no one central log to look for
"serious problems", you need to chase down "which one of my
services spews errors to its log?". This was never a big problem
for me, but maybe it is for someone else, on bigger systems?

I imagine this may be solved by adding a "send this to syslog"
pattern(s) on a per-service basis.

E.g. log every service separately, but if admin wants to see
ntpd time steps in syslog as well, as indication
of something going seriously wrong, the pattern would be "setting time to":

2016-09-26_21:02:57.79012 ntpd: reply from 83.167.252.118: delay
0.491095 is too high, ignoring
2016-09-26_21:03:01.02105 ntpd: current time is 2016-09-26 23:02:59.805699
2016-09-26_21:03:01.02113 ntpd: setting time to 2016-09-26
23:03:01.020781 (offset +1.215082s)
2016-09-26_21:03:01.02255 ntpd: update from:92.62.233.2
offset:+0.000000 delay:0.996227 jitter:0.487573 clock drift:-4.413ppm
tc:4
_______________________________________________
busybox mailing list
[email protected]
http://lists.busybox.net/mailman/listinfo/busybox

Reply via email to