Previously, we logged also the location (file:line func). nm-logging.c
supported format flags to control the timestamp, the location, and alignment
of the timestamp.
We want that all our logging backends log the same messages. That is,
both syslog and journal should have our ~default~ logging format, that
is with timestamp but without location.
Drop the unused code.
(cherry picked from commit cc828431b8)
- reorder entries in src/Makefile.am so that general names
are all at the beginning (AM_CPPFLAGS, sbin_PROGRAMS)
and the names for a certain library/binary are grouped
together
- have libNetworkManager.la reuse libNetworkManagerBase.la.
- let all components in src/Makefile.am use the same AM_CPPFLAGS,
except libsystem-nm.la.
- move callouts/nm-dispatcher-api.h to shared/ directory. It
is obviously not internal API to callouts, and callouts is
not a library. Thus, the right place is shared/.
The function name is no longer visible in the default
logging output. It is anyway only used together with
journal logging to set "CODE_FUNC".
Drop it. It allows to remove the strings from the binary,
which decreases the object size of a default build of NetworkManager
from 2437400 to 2412824 bytes (-24k, -1%).
The logging domain VPN_PLUGIN controlls logging of the VPN plugins.
Especially at verbose levels <debug> and <trace>, the plugins might
reveal sensitive information in the logging.
Thus, this level should not be enabled by a
$ nmcli logging general level DEBUG domains ALL
It should only be enabled when requested explicitly.
$ nmcli logging general level DEBUG domains ALL,VPN_PLUGIN:DEBUG
Previously, the special level VPN_PLUGIN was entirely excluded from
ALL and DEFAULT domains and it was entirely disabled by default. That
is however to strict, as it completely silences the VPN plugins by
defult. Now, enable them by default up to level INFO.
VPN plugins should take care that they don't reveal sensitive
information at levels <info> (LOG_NOTICE) and higher (less verbose).
For more verbose levels they may print passwords, but that should
still be avoided as far as possible.
This logging domain will be used to enable debugging of the VPN plugins.
However, the plugins might expose sensitive data in this mode, so exclude
the new domain from "LOGD_ALL".
Basically every logging statement is wrapped by a nm_logging_enabled()
to evaluate the function call of the logging lazy.
Make the function a candidate for inlining, it safes some space. On
a default build it goes for me from 2580584 to 2560104 bytes (20k).
$ ./autogen.sh && make && strip ./src/NetworkManager
We really expect this assertion not to be violated.
As we want for nm_logging_enabled() to become smaller and inline,
remove the runtime assertion from regular builds.
Live fast and dangerous.
Instead of calling _ensure_initialized() at various places
to ensure that we setup logging before any logging commands
are executed, initialize the logging fields in the global variable.
This removes code from nm_logging_enabled(), which we want to
become a static inline function.
In our usage of glib logging, every g_critical()/g_return*()/g_warning()
is considered a bug. They must not occur in a regular program run,
so that we can run NetworkManager with G_DEBUG=fatal-warnings.
On the other hand, all nm_log() statements (even with severity <error>)
are valid conditions that can occur at runtime.
As a consequence, when nm-logging uses glib as backend, we must not use
G_LOG_LEVEL_WARNING level. Otherwise
$ /usr/sbin/NetworkManager --debug --g-fatal-warnings
will dump core on the message
"<warn> glib-version: cannot handle SIGUSR1 and SIGUSR2 signals. Consider upgrading glib to 2.36.0 or newer"
Thereby, downgrade the glib level for "<info>" to G_LOG_LEVEL_INFO.
str_if_set() was added to replace the non-standard gcc extension "?:".
However, "?:" is supported by clang as well and we already use it at
several places.
Also, str_if_set() did not follow our naming scheme and renaming to
nm_str_if_set() would be ugly. So just drop it.
Choose a new logging format.
- the logging format must not be configurable and it must be the
same for all backends. It is neat that journal supports additional
fields, but an average user still posts the output of plain
journalctl, without "--output verbose" (which would also be hard
to read).
Also, we get used to a certain logging format, so having different
formats is confusing. If one format is better then another, it should
be used for all backends: syslog, journal and debug.
The only question is, what is the best format.
- the timestamp: I find it useful to see how much time between two
events passed. The timestamp printed by syslog doesn't have sufficient
granularity, and the internal journal fields are not readily available.
We used to print the timestamps for <error>, <debug> and <trace>,
but ommited them for <info> and <warn> levels. We now print them for
all levels, which has a uniform alignment.
- the location: the "[file:line] func():" part is mostly redundant
and results in wide lines. It also causes a misalignment of the
logging lines, or -- as I recently added alignment of the location --
it results in awkward whitespace and truncation.
But the location is really just necessary because our logging messages
are bad:
"<debug> [1456397604.038226] (9) 11-dhclient succeeded"
The solution to this is not
"<debug> [1456397604.038226] [nm-dispatcher.c:358] dispatcher_results_process(): (9) 11-dhclient succeeded"
but a properly worded message:
"<debug> [1456397604.038226] dispatcher: request #9, script 11-dhclient succeeded"
- logging-message: we need to write better logging messages.
I like some form of "tags" that are easy to grep:
"platform: signal: link changed: 4: ..."
Downside is, that this is not nice to read as a full sentence.
So, especially for <info> and <warn> logging, more human readable
messages are better.
We should find a compromise, where the log message explains what
happens, but is still concise and contains patterns that are easy
to grep and identify visually.
https://mail.gnome.org/archives/networkmanager-list/2016-February/msg00077.html
Most interestingly is also, whether we can link libsystemd.a without
having undefined references (which might be wrongly satisfied by an
externally loaded libsystem shared library.
"NetworkManagerUtils.h" contains a bunch of helper tools for core
daemon ("src/").
Unfortunately, it has dependencies to other parts of core,
such as "nm-device.h" and "nm-platform.h". Split out a part
of tools that are independent so that they can be used without
dragging in other dependencies.
"nm-core-utils.h" should only use libnm-core, "nm-logging.h"
and shared.
"NetworkManagerUtils.h" should provide all "nm-core-utils.h" and
possibly other utilities that have larger dependencies.
"nm-logging.h" is a basic core module that should have few other
dependencies. Instead of letting nm-logging.c directly call a function
from "nm-linux-platform.c", let platform register a handler as needed.
This way, you can build a core library containing nm-logging but no
nm-platform.
Change the logging format. For syslog, we will now always
print the timestamp (also for <info> and <warn> messages).
Also, when printing the file location, we will always
align it.
For journal logging, also enable the timestamp. While the timestamp
is already captured separately by journal, most of the time a user
will look at the syslog like output from journal, so we want the
timestamps there too.
- All internal source files (except "examples", which are not internal)
should include "config.h" first. As also all internal source
files should include "nm-default.h", let "config.h" be included
by "nm-default.h" and include "nm-default.h" as first in every
source file.
We already wanted to include "nm-default.h" before other headers
because it might contains some fixes (like "nm-glib.h" compatibility)
that is required first.
- After including "nm-default.h", we optinally allow for including the
corresponding header file for the source file at hand. The idea
is to ensure that each header file is self contained.
- Don't include "config.h" or "nm-default.h" in any header file
(except "nm-sd-adapt.h"). Public headers anyway must not include
these headers, and internal headers are never included after
"nm-default.h", as of the first previous point.
- Include all internal headers with quotes instead of angle brackets.
In practice it doesn't matter, because in our public headers we must
include other headers with angle brackets. As we use our public
headers also to compile our interal source files, effectively the
result must be the same. Still do it for consistency.
- Except for <config.h> itself. Include it with angle brackets as suggested by
https://www.gnu.org/software/autoconf/manual/autoconf.html#Configuration-Headers
When setting the logging with omitting the domains, we would
use the previously set logging domains. That was wrong since
the addition of the 'KEEP' level:
(1) $ nmcli g l level INFO domains DNS,CORE
$ nmcli g l
LEVEL DOMAINS
INFO DNS,CORE
(2) $ nmcli g l level KEEP domains PPP:TRACE
$ nmcli g l
LEVEL DOMAINS
INFO PPP:TRACE,DNS,CORE
(3) $ nmcli g l level ERR
$ nmcli g l
LEVEL DOMAINS
ERR PPP:TRACE
with this change, command (3) effectively translates to:
$ nmcli g l level ERR domains PPP,DNS,CORE
$ nmcli g l
LEVEL DOMAINS
ERR PPP,DNS,CORE
"nm-logging.c" uses several global variables. As their name doesn't
indicate that they are global variables, this is quite confusing.
Pack them all into a struct @global, which effectively puts the
variables into a separate namespace.
When debug-logging for platform is enabled, every access to sysctl
is cached (to log the last values).
This cache can grow quite large if the system has a large number of
interfaces (e.g. docker creating veth pairs for each container).
We already used to clear the cache, when we were about to access
sysctl *and* logging was disabled in the meantime.
Now, when logging setup changes, immediately clear the cache.
Having "nm-logging.c" call into platform code is a bit of a hack
and a better design would be to have logging code emit a signal to
which platform would subscribe. But that seems to involve much
more code (especially, as no other users care about such a signal
and because nm-logging is not a GObject).
Also, log a warning when the cache grows large to inform the user
about the cache and what he can do to clear it. The extra effort to
clear the cache when changing logging setup is done so that we do
what we tell the user: changing the logging level, will clear the
cache -- right away, not some time later when the next message is
logged.
Without this, the user cannot configure only certain logging domains
without touching them all.
E.g.
# nmcli general logging level DEBUG domains PLATFORM
will disable all non-PLATFORM domains.
Well, the user can do:
# nmcli general logging level INFO domains PLATFORM:DEBUG
# nmcli general logging level DEBUG domains ALL:INFO,PLATFORM
but in this case all non-PLATFORM domains are reset explicitly.
Now the user can:
# nmcli general logging level KEEP domains PLATFORM:DEBUG
# nmcli general logging level DEBUG domains ALL:KEEP,PLATFORM
which will only change the platform domain.
Especially systemd, which makes use of the error argument for logging, likes
to represent errors as negative numbers. We hence must invert a negative error
code to get the real errno.
The localization headers are now included via "nm-default.h".
Also fixes several places, where we wrongly included <glib/gi18n-lib.h>
instead of <glib/gi18n.h>. For example under "clients/" directory.
"NONE" was wrongly part of @domain_descs and thus advertised
via `NetworkManager --help`. But since its @num was set to
LOGD_NONE (zero), it was already rejected by nm_logging_setup().
The only way to disable logging for a domain entirely is to
omit the domain from the "domains" list. For example:
"level=INFO, domains=PLATFORM,..."
Now add an explicit level "OFF" to facilitate configuration like:
"level=INFO, domains=ALL,WIFI_SCAN:OFF"
It also supports
"level=OFF, domains=PLATFORM:INFO"
but this is for the most part equivalent to
"level=INFO, domains=PLATFORM"
Rather than randomly including one or more of <glib.h>,
<glib-object.h>, and <gio/gio.h> everywhere (and forgetting to include
"nm-glib-compat.h" most of the time), rename nm-glib-compat.h to
nm-glib.h, include <gio/gio.h> from there, and then change all .c
files in NM to include "nm-glib.h" rather than including the glib
headers directly.
(Public headers files still have to include the real glib headers,
since nm-glib.h isn't installed...)
Also, remove glib includes from header files that are already
including a base object header file (which must itself already include
the glib headers).
