NetBSD-Users archive
[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index][Old Index]
Re: Feed facility/priority to logger(1) via stdin - desirable extension or bad idea?
Hello,
thank you very much for the suggestions and questions.
Am 07.10.2022 um 21:39 schrieb Mouse:
With a lot of scripts and tools written, I have gotten into the habit
of logging all logging output to stderr, as well as any form of
payload to stdout.
What do you do with error messages, then?
The error messages also go into the logger via stderr. Strictly
speaking, from the stderr-output perspective I try to separate the use
cases. This means that either the tool runs interactively in the shell,
or it runs autonomously as part of an automatic pipeline. Neverthenless,
I want to produce all messages generically for both cases with no code
duplication.
Is there some reason you don't actually syslog() the log messages,
then, rather than sending them down a pipe? It sounds to me as though
you are going to have to make your log generator logging-aware, but,
then, I don't see what benefit you get from piping the output to a tool
instead of just logging it directly. (The obvious (to me) benefit is
that you can control facility and priority with the logging tool
instead of wiring it into the code, but here you're pushing it back
into the log-generation code anyway.)
Please let me illustrate using one of my backup scripts as an example.
This script can be run interactively if necessary. Regularly, however,
it is driven autonomously via cron.
It does not generate regular output on stdout but logs all steps
performed on stderr. There is a small helper function in the script for
this purpose:
```
#### Log Function ######################################################
log() {
local LEVEL=$1
local MESSAGE="$2"
if [ -t 2 ]; then
echo -n "$TC_NORM[" > /dev/stderr
case $LEVEL in
info)
echo -n "$TC_GREEN" > /dev/stderr
echo -n "INFO" > /dev/stderr
;;
warn)
echo -n "$TC_YELLOW" > /dev/stderr
echo -n "WARN" > /dev/stderr
;;
err)
echo -n "$TC_RED" > /dev/stderr
echo -n "ERR " > /dev/stderr
;;
*)
echo -n "----" > /dev/stderr
;;
esac
echo -n $TC_NORM > /dev/stderr
echo -n "] " > /dev/stderr
echo "$MESSAGE" > /dev/stderr
else
echo "$MESSAGE" > /dev/stderr
fi
}
```
So, depending on whether stderr is connected to a terminal or a pipe, a
different formatting of the output is chosen. I didn't intend to
emphasize on the usage of colours, it was just an example and I can
understand your concerns.
In the interactive case, it looks like this:
```
$ ./zdump backup
[WARN] Target changed (76213cde-31a8-497a-a016-9775f2a12549 ->
c3629a98-17b5-4751-b25e-a9fa338d20ed)
[INFO] Cleaning target ...
[INFO] Created snapshot tank/vol/net@0
[INFO] Starting full dump to tank_vol_net%0.full.zfs@localhost ...
[INFO] Completed in 37.324 seconds, 2.2 GB transferred (61 MB/sec)
```
In contrast, the raw output in the autonomous case will look like this:
```
Target changed (76213cde-31a8-497a-a016-9775f2a12549 ->
c3629a98-17b5-4751-b25e-a9fa338d20ed)
Cleaning target ...
Created snapshot tank/vol/net@0
Starting full dump to tank_vol_net%0.full.zfs@localhost ...
Completed in 37.324 seconds, 2.2 GB transferred (61 MB/sec)
```
In the crontab, the backup script is connected to the logger:
```
#minute hour mday month wday command
#
0 */6 * * * /home/mpeterma/zdump backup 2>&1
| logger -p local2.notice
```
As the result, everything is logged to local2.notice, independendly of
the scripts application log level.
In the example above, I could of course call the logger command directly
with the appropriate priority instead of the echoes on stderr. Anyway,
the motivation behind the idea is for the script case that one can save
calling a new logger process for each individual line to be output. The
advantage here would be a lower system load, although with today's
systems this probably won't matter that much unless you log hundreds of
lines.
In the case of tools or compiled programmes in general, it's more a
concern of the API. My understanding is that syslog() from the C
standard library is only available for C/C++ programmes, and for other
languages at most via FFI. This means that the direct call is not
possible in some cases. Instead, a connection to syslog would have to be
established via a network library that speaks the syslog protocol. This
requires that the programme knows where to find the syslogd service
(usually a configuration file pointing to the syslogd IP + Port / Unix
Domain Socket to use). This requires a lot of attention if you have
several environment to not mix up logging servers from development /
production. The advantage here would be a simpler configuration, and
also that I get exactly the same output on the console at development
time as I get in the log file later in production, without having to do
anything.
Regardless of the motivation, this strikes me as a reasonable thing.
Thanks :-) In the meantime I had a look at the implementation of the
logger from util-linux:
https://github.com/util-linux/util-linux/blob/master/misc-utils/logger.c
It seems to have the same origin as ours, but has been significantly
extended and adapted to the realities of the Linux world (logging as an
aspect of Systemd, direct network logging via TCP/IP and UDP). The
interesting part starts from line 995... I guess this could serve as a
starting point.
Speaking as a user, please do not assume that anyone sending logs to a
terminal wants coloured output. It's not true, and assuming it is
tends to produce annoyingly corrupted output when it's not applicable.
This is one of my bigger beefs with recent Ubuntu and Debian: more and
more tools blindly assume that (a) the user wants colour when the
output is going to a tty and (b) that it knows how to generate colour.
Each of those is false for me. Typically, the resulting output looks
like this (where I forced colour on on the command line because I've
gone to some lengths to get rid of it by default):
$ ls --color=always /
[0m[01;34mbin[0m [01;34metc[0m [01;34mlib[0m [01;34mmnt[0m [01;34mroot[0m [01;34mselinux[0m [30;42mtmp[0m [01;36mvmlinuz[0m
[01;34mboot[0m [01;34mhome[0m [01;34mlost+found[0m [01;34mopt[0m [01;34mrun[0m [01;34msrv[0m [01;34musr[0m
[01;34mdev[0m [01;36minitrd.img[0m [01;34mmedia[0m [01;34mproc[0m [01;34msbin[0m [01;34msys[0m [01;34mvar[0m
$
It's far worse with other tools. Modern gdb borders on unusable.
Here's an example, cut-and-pasted from the window I just did a test in:
Breakpoint 1, [33ml_cmp[m ([36mcookie[m=0x55555555b220 <list>, [36ma[m=0x55555555b020 <lines>, [36mb[m=0x55555555b028 <lines+8>) at [32mtest.c[m:106
106 [01;34mif[m [31m([mcookie [31m!=[m [31m&[mlist[31m)[m [01mpanic[m[31m();[m
[?2004h(gdb) l
gdb is blindly assuming I want colour, and furthermore assuming, not
only blindly but in defiance of active evidence that it's not so, that
the ISO 6429 values to X3.64's SGR sequence will generate it. (The
"active evidence" is that $TERM is a type whose description includes
not only no indication of colour support but no X3.64 at all.) It's
also generating other sequences, like that peculiar [?2004h, with the
same negative amount of reason to think they'll work.
As for gdb, that sounds like a bug. In the scripts where I use colors, I
get the corresponding control sequences at runtime with tput. So far
this works without any trouble.
```
vhost$ export TERM=xterm-256color
vhost$ TC_GREEN="$(tput AF 2)"
vhost$ TC_NORM="$(tput me)"
vhost$ echo $TC_GREEN This is green $TC_NORM
This is green
vhost$ export TERM=vt100
vhost$ TC_GREEN="$(tput AF 2)"
vhost$ TC_NORM="$(tput me)"
vhost$ echo $TC_GREEN This is not green because the terminal does not
support it $TC_NORM
This is not green because the terminal does not support it
```
Kind regards
Matthias
Home |
Main Index |
Thread Index |
Old Index