Commit Graph

55 Commits

Author SHA1 Message Date
Zbigniew Jędrzejewski-Szmek b3a7915805 basic/log: add debug-level log_oom() variant
This is useful for contexts where only debug-level messages are allowed.
2020-12-11 08:22:41 +01:00
Lennart Poettering 1c36b8bf53 log: add helper set sets log level in all realms
Prompted-by: #17903
2020-12-09 18:26:17 +01:00
Yu Watanabe db9ecf0501 license: LGPL-2.1+ -> LGPL-2.1-or-later 2020-11-09 13:23:58 +09:00
Lennart Poettering 27ffec0831 log: update comment
The logic was changed in bc694c06e6, let's
update the comment accordingly.
2020-09-30 16:06:55 +02:00
Lennart Poettering 9ee806d1a8 log: optionally display thread ID in log output to tty
This is very useful when playing around with threaded tests, but should
be useful in other cases too.
2020-09-29 15:51:53 +02:00
Zbigniew Jędrzejewski-Szmek 44f0dd628c basic/log: make log_{info,warning,...} return void
log_debug still returns 0. I think it is legitimate to use 'return log_debug()' to
return 0. It is different than the other functions, since we often want to supress
errors logged at debug level. This case is quite common in the codebase and
we could use 'return log_debug_errno()' to make the code more consise.

For all other variants, a separate return line is required.
Previous commit changes all the non-conforming instances, now we can make it mandatory.
2020-09-08 17:40:46 +02:00
Filipe Brandenburger 41d1f469cf log: introduce log_parse_environment_cli() and log_setup_cli()
Presently, CLI utilities such as systemctl will check whether they have a tty
attached or not to decide whether to parse /proc/cmdline or EFI variable
SystemdOptions looking for systemd.log_* entries.

But this check will be misleading if these tools are being launched by a
daemon, such as a monitoring daemon or automation service that runs in
background.

Make log handling of CLI tools uniform by never checking /proc/cmdline or EFI
variables to determine the logging level.

Furthermore, introduce a new log_setup_cli() shortcut to set up common options
used by most command-line utilities.
2020-06-24 16:49:26 +02:00
Lennart Poettering 01262d0d9e
Merge pull request #13084 from ddstreet/log_time
log: add support for prefixing console log messages with current timestamp
2020-03-30 17:57:34 +02:00
Daan De Meyer f455f8633e Silence Wstring-plus-int warning when using clangd with GCC. 2020-03-21 22:30:59 +01:00
Dan Streetman c5673ed0de log: add support for prefixing console log messages with current timestamp 2020-02-10 07:01:30 -05:00
Zbigniew Jędrzejewski-Szmek ab1a1ba5dc Drop trailing slash from assert_cc() definition
We use assert_cc(...); almost everywhere. Let's always require that.

https://github.com/systemd/systemd/issues/12997#issuecomment-510103988
2019-07-17 12:57:20 +02:00
Zbigniew Jędrzejewski-Szmek 62c6bbbc09 tree-wide: use PROJECT_FILE instead of __FILE__
This replaces the internal uses of __FILE__ with the new macro.
2019-07-04 10:36:00 +02:00
Zbigniew Jędrzejewski-Szmek a0b15b4177 basic/log: add a define for path relative to source root
When using build/ directory inside of the source directory:
__FILE__: ../src/test/test-log.c
RELATIVE_SOURCE_PATH: ..
PROJECT_FILE: src/test/test-log.c

When using a build directory outside of the source directory:
__FILE__: ../../../home/zbyszek/src/systemd-work/src/test/test-log.c
RELATIVE_SOURCE_PATH: ../../../home/zbyszek/src/systemd-work
PROJECT_FILE: src/test/test-log.c
2019-07-04 10:27:19 +02:00
Yu Watanabe f6d6d53237 log: expose log_object_internalv() 2019-03-21 23:37:39 +09:00
Yu Watanabe ee96382fdb log: make log_syntax() assign correct errno and show valid error cause 2019-03-04 15:18:06 +09:00
Zbigniew Jędrzejewski-Szmek 5dc881a359 basic/log: add note about operator precendence 2018-11-22 10:56:43 +01:00
Zbigniew Jędrzejewski-Szmek baaa35ad70 coccinelle: make use of SYNTHETIC_ERRNO
Ideally, coccinelle would strip unnecessary braces too. But I do not see any
option in coccinelle for this, so instead, I edited the patch text using
search&replace to remove the braces. Unfortunately this is not fully automatic,
in particular it didn't deal well with if-else-if-else blocks and ifdefs, so
there is an increased likelikehood be some bugs in such spots.

I also removed part of the patch that coccinelle generated for udev, where we
returns -1 for failure. This should be fixed independently.
2018-11-22 10:54:38 +01:00
Zbigniew Jędrzejewski-Szmek 52d86690d6 basic/log: add concept of "synthethic errnos"
Synthetic errnos are processed like normal, and may be used in %m and become
the return value from log_*(), but they are not logged in the journal.
2018-11-22 10:45:08 +01:00
Lennart Poettering 6bf3c61c57 log: introduce new helper call log_setup_service()
Let's reduce the common boilerplate and have a single setup function
used by all service code to setup logging.
2018-11-20 11:18:22 +01:00
Lennart Poettering 0c69794138 tree-wide: remove Lennart's copyright lines
These lines are generally out-of-date, incomplete and unnecessary. With
SPDX and git repository much more accurate and fine grained information
about licensing and authorship is available, hence let's drop the
per-file copyright notice. Of course, removing copyright lines of others
is problematic, hence this commit only removes my own lines and leaves
all others untouched. It might be nicer if sooner or later those could
go away too, making git the only and accurate source of authorship
information.
2018-06-14 10:20:20 +02:00
Lennart Poettering 818bf54632 tree-wide: drop 'This file is part of systemd' blurb
This part of the copyright blurb stems from the GPL use recommendations:

https://www.gnu.org/licenses/gpl-howto.en.html

The concept appears to originate in times where version control was per
file, instead of per tree, and was a way to glue the files together.
Ultimately, we nowadays don't live in that world anymore, and this
information is entirely useless anyway, as people are very welcome to
copy these files into any projects they like, and they shouldn't have to
change bits that are part of our copyright header for that.

hence, let's just get rid of this old cruft, and shorten our codebase a
bit.
2018-06-14 10:20:20 +02:00
Zbigniew Jędrzejewski-Szmek a1230ff972 basic/log: add the log_struct terminator to macro
This way all callers do not need to specify it.
Exhaustively tested by running test-log under valgrind ;)
2018-06-04 13:46:03 +02:00
Lennart Poettering 17cac366ae nspawn: make sure our container PID 1 keeps logging to the original stderr as long as possible
If we log to the pty that is configured as stdin/stdout/stderr of the
container too early we risk filling it up in full before we start
processing the pty from the parent process, resulting in deadlocks.
Let's hence keep a copy of the original tty we were started on before
setting up stdin/stdout/stderr, so that we can log to it, and keep using
it as long as we can.

Since the kernel's pty internal buffer is pretty small this actually
triggered deadlocks when we debug logged at lot from nspawn's child
processes, see: https://github.com/systemd/systemd/pull/9024#issuecomment-390403674

With this change we won't use the pty at all, only the actual payload we
start will, and hence we won't deadlock on it, ever.
2018-05-22 16:52:50 +02:00
Zbigniew Jędrzejewski-Szmek 11a1589223 tree-wide: drop license boilerplate
Files which are installed as-is (any .service and other unit files, .conf
files, .policy files, etc), are left as is. My assumption is that SPDX
identifiers are not yet that well known, so it's better to retain the
extended header to avoid any doubt.

I also kept any copyright lines. We can probably remove them, but it'd nice to
obtain explicit acks from all involved authors before doing that.
2018-04-06 18:58:55 +02:00
Franck Bui 848e863acc basic/macros: rename noreturn into _noreturn_ (#8456)
"noreturn" is reserved and can be used in other header files we include:

  [   16s] In file included from /usr/include/gcrypt.h:30:0,
  [   16s]                  from ../src/journal/journal-file.h:26,
  [   16s]                  from ../src/journal/journal-vacuum.c:31:
  [   16s] /usr/include/gpg-error.h:1544:46: error: expected ‘,’ or ‘;’ before ‘)’ token
  [   16s]  void gpgrt_log_bug (const char *fmt, ...)    GPGRT_ATTR_NR_PRINTF(1,2);

Here we include grcrypt.h (which in turns include gpg-error.h) *after* we
"noreturn" was defined in macro.h.
2018-03-15 14:23:46 +09:00
Zbigniew Jędrzejewski-Szmek a3bf71378e basic/log: make log_object_internalv static
It makes the code easier to read, because it's obvious that the function
cannot be called from elsewhere.
2018-02-23 00:13:52 +01:00
Alan Jenkins cc2b9e6b20 rationalize interface for opening/closing logging
log_open_console() did not switch from stderr to /dev/console, when
"always_reopen_console" was set.  It was necessary to call
log_close_console() first.

By contrast, log_open() did switch between e.g. journald and kmsg according
to the value of "prohibit_ipc".

Let's fix log_open() to respect the values of all the log options, and we
can make log_close_*() private.

Also log_close_console() is changed.  There was some precaution, avoiding
closing the console fd if we are not PID 1.  I think commit 48a601fe made
a little mistake in leaving this in, and it only served to confuse
readers :).

Also I changed systemd-shutdown. Now we have log_set_prohibit_ipc(), let's
use it to clarify that systemd-shutdown is not expected to try and log via
journald (which it is about to kill).  We avoided ever asking it to, but
it's more convenient for the reader if they don't have to think about that.
In that sense, it's similar to using assert() to validate a function's
arguments.
2018-01-27 18:01:51 +00:00
Lennart Poettering 6c347d5024 log: remove LOG_TARGET_SAFE pseudo log target
This removes LOG_TARGET_SAFE. It's made redundant by the new
"prohibit-ipc" logging flag, as it used to have a similar effect: avoid
logging to the journal/syslog, i.e. any local services in order to avoid
deadlocks when we lock from PID 1 or its utility processes (such as
generators).

All previous users of LOG_TARGET_SAFE are switched over to the new
setting. This makes things a bit safer for all, as not even the
SYSTEMD_LOG_TARGET env var can be used to accidentally log to the
journal anymore in these programs.
2018-01-24 18:22:56 +01:00
Lennart Poettering 7a3be263d2 log: add brief comment for log_set_open_when_needed() and log_set_always_reopen_console()
These two deserve some explanation...
2018-01-24 18:22:56 +01:00
Lennart Poettering adf47c919a log: add new "prohibit_ipc" flag to logging system
If set, we'll avoid logging to any IPC log targets, i.e. syslog or the
journal, but allow stderr, kmsg, console logging.

This is useful as PID 1 wants to turn this off explicitly as long as the
journal is not up.

Previously we'd open/close the log stream to these services whenever
needed but this is incompatible with the "open_when_needed" logic
introduced in #6915, which might open the log streams whenever it likes,
including possibly inside of the child process we fork off that'll
become journald later on. Hence, let's make this all explicit, and
instead of managing when we open/close log streams add a boolean that
clearly prohibits the IPC targets when needed, so that opening can be
done at any time, but will honour this.

See: #7985
2018-01-24 18:22:56 +01:00
Lennart Poettering 6fdb8de42f log: make log_set_upgrade_syslog_to_journal() take effect immediately
This doesn't matter much, and we don't rely on it, but I think it's much
nicer if we log_set_target() and log_set_upgrade_syslog_to_journal() can
be called in either order and have the same effect.
2018-01-24 18:22:56 +01:00
Lennart Poettering c1e83af84e log: assign the realm to a variable first in log_full_errno_realm()
Let's avoid duplicate evaluation (which might have side-effects) and
assign the realm to an internal variable first, as we need it twice.
2018-01-11 14:44:31 +01:00
Lennart Poettering d04ce5a9c4 log: rework log_syntax_invalid_utf8() a bit
The macro used utf8.h functions without including that. Let's clean this
up, by moving that code inside of log.c.

Let's also make the call return -EINVAL in all cases. This is in line
with log_oom() which also returns a well-defined error code even though
it doesn#t take one.
2018-01-11 14:44:31 +01:00
Lennart Poettering dccca82b1a log: minimize includes in log.h
log.h really should only include the bare minimum of other headers, as
it is really pulled into pretty much everything else and already in
itself one of the most basic pieces of code we have.

Let's hence drop inclusion of:

1. sd-id128.h because it's entirely unneeded in current log.h
2. errno.h, dito.
3. sys/signalfd.h which we can replace by a simple struct forward
   declaration
4. process-util.h which was needed for getpid_cached() which we now hide
   in a funciton log_emergency_level() instead, which nicely abstracts
   the details away.
5. sys/socket.h which was needed for struct iovec, but a simple struct
   forward declaration suffices for that too.

Ultimately this actually makes our source tree larger (since users of
the functionality above must now include it themselves, log.h won't do
that for them), but I think it helps to untangle our web of includes a
tiny bit.

(Background: I'd like to isolate the generic bits of src/basic/ enough
so that we can do a git submodule import into casync for it)
2018-01-11 14:44:31 +01:00
Lennart Poettering f1d34068ef tree-wide: add DEBUG_LOGGING macro that checks whether debug logging is on (#7645)
This makes things a bit easier to read I think, and also makes sure we
always use the _unlikely_ wrapper around it, which so far we used
sometimes and other times we didn't. Let's clean that up.
2017-12-15 11:09:00 +01:00
Zbigniew Jędrzejewski-Szmek 53e1b68390 Add SPDX license identifiers to source files under the LGPL
This follows what the kernel is doing, c.f.
https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/commit/?id=5fd54ace4721fc5ce2bb5aef6318fcf17f421460.
2017-11-19 19:08:15 +01:00
Lennart Poettering d3070fbdf6 core: implement /run/systemd/units/-based path for passing unit info from PID 1 to journald
And let's make use of it to implement two new unit settings with it:

1. LogLevelMax= is a new per-unit setting that may be used to configure
   log priority filtering: set it to LogLevelMax=notice and only
   messages of level "notice" and lower (i.e. more important) will be
   processed, all others are dropped.

2. LogExtraFields= is a new per-unit setting for configuring per-unit
   journal fields, that are implicitly included in every log record
   generated by the unit's processes. It takes field/value pairs in the
   form of FOO=BAR.

Also, related to this, one exisiting unit setting is ported to this new
facility:

3. The invocation ID is now pulled from /run/systemd/units/ instead of
   cgroupfs xattrs. This substantially relaxes requirements of systemd
   on the kernel version and the privileges it runs with (specifically,
   cgroupfs xattrs are not available in containers, since they are
   stored in kernel memory, and hence are unsafe to permit to lesser
   privileged code).

/run/systemd/units/ is a new directory, which contains a number of files
and symlinks encoding the above information. PID 1 creates and manages
these files, and journald reads them from there.

Note that this is supposed to be a direct path between PID 1 and the
journal only, due to the special runtime environment the journal runs
in. Normally, today we shouldn't introduce new interfaces that (mis-)use
a file system as IPC framework, and instead just an IPC system, but this
is very hard to do between the journal and PID 1, as long as the IPC
system is a subject PID 1 manages, and itself a client to the journal.

This patch cleans up a couple of types used in journal code:
specifically we switch to size_t for a couple of memory-sizing values,
as size_t is the right choice for everything that is memory.

Fixes: #4089
Fixes: #3041
Fixes: #4441
2017-11-16 12:40:17 +01:00
Lennart Poettering 16e4fd87c5 log: add a mode where we open the log fds for every single log message
This we can then make use in execute.c to make error logging a bit less
special when preparing for process execution, as we can still log but
don't have any fds open continously.
2017-09-26 17:46:33 +02:00
Lennart Poettering 915b1d0174 core: whenever a unit terminates, log its consumed resources to the journal
This adds a new recognizable log message for each unit invocation that
contains structured information about consumed resources of the unit as
a whole after it terminated. This is particular useful for apps that
want to figure out what the resource consumption of a unit given a
specific invocation ID was.

The log message is only generated for units that have at least one
XyzAccounting= property turned on, and currently only covers IP traffic and CPU
time metrics.
2017-09-22 15:28:05 +02:00
Lennart Poettering df0ff12775 tree-wide: make use of getpid_cached() wherever we can
This moves pretty much all uses of getpid() over to getpid_raw(). I
didn't specifically check whether the optimization is worth it for each
replacement, but in order to keep things simple and systematic I
switched over everything at once.
2017-07-20 20:27:24 +02:00
Zbigniew Jędrzejewski-Szmek e3e42fc2b5 Add comments to log_functions which shouldn't be called from library code (#6326) 2017-07-11 10:40:11 +02:00
Zbigniew Jędrzejewski-Szmek ff524019ef basic/log: split max log level into multiple "realms"
The single log level is split into an array of log levels. Which index in the
array is used can be determined for each compilation unit separately by setting
a macro before including log.h. All compilation units use the same index
(LOG_REALM_SYSTEMD), so there should be no functional change.

v2:
- the "realm" is squished into the level (upper bits that are not used by
  priority or facility), and unsquished later in functions in log.c.

v3:
- rename REALM_PLUS_LEVEL to LOG_REALM_PLUS_LEVEL and REALM to LOG_REALM_REMOVE_LEVEL.
2017-05-07 22:48:24 -04:00
Zbigniew Jędrzejewski-Szmek 93484b4790 basic/log: expose log_dispatch
This is useful when we want to avoid printf formatting on the message.
It's nicer than using log_struct with "%s" as the format, because printf
is slow and with a large message (like from a backtrace) this would require
extra unnecessary memory.

I'm not exposing all the fields in the wrapper: only level and errno.
Those are the most likely to be useful.
2017-04-21 13:39:03 -04:00
Zbigniew Jędrzejewski-Szmek ba360bb05c tree-wide: mark log_struct with _printf_ and fix fallout
log_struct takes multiple format strings, each one followed by arguments.
The _printf_ annotation is not sufficiently flexible to express this,
but we can still annotate the first format string, though not its
arguments (because their number is unknown).

With the annotation, the places which specified the message id or similar
as the first pattern cause a warning from -Wformat-nonliteral. This can
be trivially fixed by putting the MESSAGE= first.

This change will help find issues where a non-literal is erroneously used
as the pattern.
2017-04-21 13:37:04 -04:00
Zbigniew Jędrzejewski-Szmek 032b75419d basic/log: fix _printf_ annotation on log_object_internalv
Fixup for 4b58153dd2.

I saw this because of a clang warning. With gcc the -Wformat-nonliteral warning
doesn't seem to work as expected.

In two places, a string constructed with strjoina is used as the pattern. This
is safe, because we're taking a pattern which was already marked with _printf_
and prepending a known value to it.  Those places are marked with #pragma to
silence the warning.
2017-04-20 14:42:43 -04:00
Lennart Poettering 48a601fe5d log: never log into foreign fd #2 in PID 1 or its pre-execve() children
Fixes: #5401
2017-02-21 21:55:43 +01:00
Zbigniew Jędrzejewski-Szmek 2b0445262a tree-wide: add SD_ID128_MAKE_STR, remove LOG_MESSAGE_ID
Embedding sd_id128_t's in constant strings was rather cumbersome. We had
SD_ID128_CONST_STR which returned a const char[], but it had two problems:
- it wasn't possible to statically concatanate this array with a normal string
- gcc wasn't really able to optimize this, and generated code to perform the
  "conversion" at runtime.
Because of this, even our own code in coredumpctl wasn't using
SD_ID128_CONST_STR.

Add a new macro to generate a constant string: SD_ID128_MAKE_STR.
It is not as elegant as SD_ID128_CONST_STR, because it requires a repetition
of the numbers, but in practice it is more convenient to use, and allows gcc
to generate smarter code:

$ size .libs/systemd{,-logind,-journald}{.old,}
   text	   data	    bss	    dec	    hex	filename
1265204	 149564	   4808	1419576	 15a938	.libs/systemd.old
1260268	 149564	   4808	1414640	 1595f0	.libs/systemd
 246805	  13852	    209	 260866	  3fb02	.libs/systemd-logind.old
 240973	  13852	    209	 255034	  3e43a	.libs/systemd-logind
 146839	   4984	     34	 151857	  25131	.libs/systemd-journald.old
 146391	   4984	     34	 151409	  24f71	.libs/systemd-journald

It is also much easier to check if a certain binary uses a certain MESSAGE_ID:

$ strings .libs/systemd.old|grep MESSAGE_ID
MESSAGE_ID=%02x%02x%02x%02x%02x%02x%02x%02x%02x%02x%02x%02x%02x%02x%02x%02x
MESSAGE_ID=%02x%02x%02x%02x%02x%02x%02x%02x%02x%02x%02x%02x%02x%02x%02x%02x
MESSAGE_ID=%02x%02x%02x%02x%02x%02x%02x%02x%02x%02x%02x%02x%02x%02x%02x%02x
MESSAGE_ID=%02x%02x%02x%02x%02x%02x%02x%02x%02x%02x%02x%02x%02x%02x%02x%02x

$ strings .libs/systemd|grep MESSAGE_ID
MESSAGE_ID=c7a787079b354eaaa9e77b371893cd27
MESSAGE_ID=b07a249cd024414a82dd00cd181378ff
MESSAGE_ID=641257651c1b4ec9a8624d7a40a9e1e7
MESSAGE_ID=de5b426a63be47a7b6ac3eaac82e2f6f
MESSAGE_ID=d34d037fff1847e6ae669a370e694725
MESSAGE_ID=7d4958e842da4a758f6c1cdc7b36dcc5
MESSAGE_ID=1dee0369c7fc4736b7099b38ecb46ee7
MESSAGE_ID=39f53479d3a045ac8e11786248231fbf
MESSAGE_ID=be02cf6855d2428ba40df7e9d022f03d
MESSAGE_ID=7b05ebc668384222baa8881179cfda54
MESSAGE_ID=9d1aaa27d60140bd96365438aad20286
2017-02-15 00:45:12 -05:00
Lennart Poettering 4b58153dd2 core: add "invocation ID" concept to service manager
This adds a new invocation ID concept to the service manager. The invocation ID
identifies each runtime cycle of a unit uniquely. A new randomized 128bit ID is
generated each time a unit moves from and inactive to an activating or active
state.

The primary usecase for this concept is to connect the runtime data PID 1
maintains about a service with the offline data the journal stores about it.
Previously we'd use the unit name plus start/stop times, which however is
highly racy since the journal will generally process log data after the service
already ended.

The "invocation ID" kinda matches the "boot ID" concept of the Linux kernel,
except that it applies to an individual unit instead of the whole system.

The invocation ID is passed to the activated processes as environment variable.
It is additionally stored as extended attribute on the cgroup of the unit. The
latter is used by journald to automatically retrieve it for each log logged
message and attach it to the log entry. The environment variable is very easily
accessible, even for unprivileged services. OTOH the extended attribute is only
accessible to privileged processes (this is because cgroupfs only supports the
"trusted." xattr namespace, not "user."). The environment variable may be
altered by services, the extended attribute may not be, hence is the better
choice for the journal.

Note that reading the invocation ID off the extended attribute from journald is
racy, similar to the way reading the unit name for a logging process is.

This patch adds APIs to read the invocation ID to sd-id128:
sd_id128_get_invocation() may be used in a similar fashion to
sd_id128_get_boot().

PID1's own logging is updated to always include the invocation ID when it logs
information about a unit.

A new bus call GetUnitByInvocationID() is added that allows retrieving a bus
path to a unit by its invocation ID. The bus path is built using the invocation
ID, thus providing a path for referring to a unit that is valid only for the
current runtime cycleof it.

Outlook for the future: should the kernel eventually allow passing of cgroup
information along AF_UNIX/SOCK_DGRAM messages via a unique cgroup id, then we
can alter the invocation ID to be generated as hash from that rather than
entirely randomly. This way we can derive the invocation race-freely from the
messages.
2016-10-07 20:14:38 +02:00
Zbigniew Jędrzejewski-Szmek c337642992 basic/log: remove unused return value 2016-03-15 19:40:33 -04:00
Vito Caputo 9ed794a32d tree-wide: minor formatting inconsistency cleanups 2016-02-23 14:20:34 -08:00