80

In older Linux systems, the logger command can be used to send a log message to syslog.

Reading where does logger log its messages to in Arch Linux?, it seems that syslog messages and the logger command line app only talk to the systemd journal if a socket for message forwarding is set up.

So what's the modern equivalent of the logger command? How can I send a message directly to the systemd journal from the command line?

mikemaccana
  • 3,070
  • 5
  • 24
  • 29
  • we can also configure rsyslog to take journalctl logs as input and then output them as files also via rsyslog. – Luv33preet Jun 08 '17 at 07:15
  • `logger` logs to the journal. – Cliff May 08 '20 at 03:31
  • @Cliff logger is part of syslog, uses syslog facilities and priorities, etc. – mikemaccana May 08 '20 at 13:31
  • @mikemaccana I know, but there is no command-line way I can find to fully interface with `journald`. And sure, `logger` can use syslog facilities and priorities, but it doesn't have to. But the `logger` manpage's "See Also" section mentions `systemd` more than syslog. http://man7.org/linux/man-pages/man1/logger.1.html Plus, `systemd-cat` does not allow me to set custom fields, so what is the point of using it instead of `logger`? – Cliff May 09 '20 at 17:00

2 Answers2

110

systemd-cat is the equivalent to logger:

echo 'hello' | systemd-cat

In another terminal, running journalctl -f:

Feb 07 13:38:33 localhost.localdomain cat[15162]: hello

Priorities are specified just by part of the string:

echo 'hello' | systemd-cat -p info
echo 'hello' | systemd-cat -p warning
echo 'hello' | systemd-cat -p emerg

Warnings are bold, emergencies are bold and red. Scary stuff.

You can also use an 'identifier' which is arbitrary, to specify the app name. These are like syslog's old facilities, but you're not stuck with ancient things like lpr uucp nntp or the ever-descriptive local0 through local7. 

echo 'hello' | systemd-cat -t someapp -p emerg

Is logged as:

Feb 07 13:48:56 localhost.localdomain someapp[15278]: hello
mikemaccana
  • 3,070
  • 5
  • 24
  • 29
  • 12
    Very useful. You can filter to the log messages created with `-t` using the following command: `journalctl -t someapp` – Att Righ Oct 01 '17 at 13:05
7

Since the question mentions Arch Linux (systemd-controlled from day one) and logging, I'll hazard a guess it is related to logging from a systemd service. Here's another logging technique for shell scripts invoked from systemd service units. systemd can be (and by default is) set up to listen to the service's processes stderr and/or stdout, and forward messages to the journal. When a message starts with a 3-character prefix '<' N '>', where N is a digit from 0 to 7, systemd interprets it as the log level, omits it, and logs the rest of the string at the specified level.

It is convenient, since any stderr message from any command will be automatically logged at the error level. Another fd is reserved for logging at an arbitrary different severity.

This is of course available to all programs, not only shell scripts.

Example

A shell script (Bash in this case, relying on process substitution and trap ... EXIT behavior), taken from a real service's ExecStartPre script:

#!/bin/bash

# Redirect stderr such that any message is reported as an error to journald by
# prepending '<3>' to it. Use fd 4 (the saved stderr) to directly report other
# severity levels.
exec 4>&2 2> >(while read -r REPLY; do printf >&4 '<3>%s\n' "$REPLY"; done)

# Systemd can kill the logging subshell swiftly when we exit, and lose messages.
# Close the subshell before exiting the main program explicitly. This will block
# until the read builtin reads the EOF.
trap 'exec >&2-' EXIT

### From this point on, all stderr messages will be logged to syslog as errors
### via the subshell running the while loop. Fd 4 is the old stderr, and may
### be used to specify non-error level:

echo >&2 "This message is logged as an error, red and bold."

echo >&4 "<5>This is logged as a notice-level message, dim and boring."

echo >&4 "This is logged at the default severity level, 'info' unless changed."

The settings in the unit file generally do not need to be set specially. stderr logging works out of the box, unless globally overridden in systemd-system.conf(5) or journald.conf(5). The defaults are:

[Service]
; These defaults may be overridden in systemd-system.conf(5).
;StandardError=journal
;StandardOutput=journal

; These defaults may be overridden in journald.conf(5).
;LogLevelMax=debug
;LogRateLimitIntervalSec=10000
;LogRateLimitBurst=30s

; Extra fields may be added to every message.
;LogExtraFields=

;; Other settings:

; Defaults to process name. NOT the unit name, but rather basename(3) of the $0.
;SyslogIdentifier=

; For messages written without the <N> prefix.
;SyslogLevel=info

;SyslogFacility=daemon

; For completeness only: The level-parsing machinery can be disabled, but that
; was the whole point...
;SyslogLevelPrefix=true

Note that systemd redirects all commands invoked with the Exec* settings, not only the main service process ExecStart, but also ExecStartPre, ExecStartPost, etc.

To run the example, save the above script as logging-test.sh, run with systemd-run as a temporary unit, then query the full properties of every log record. If you do not see the info level message, check if journald.conf limits the logging level stored in the journal to a higher value.

$ systemd-run --user --wait ./logging-test.sh
$ journalctl -t logging-test.sh
$ journalctl -t logging-test.sh -o json-pretty

The logging levels are defined in sd-daemon(3):

#define SD_EMERG   "<0>"  /* system is unusable */
#define SD_ALERT   "<1>"  /* action must be taken immediately */
#define SD_CRIT    "<2>"  /* critical conditions */
#define SD_ERR     "<3>"  /* error conditions */
#define SD_WARNING "<4>"  /* warning conditions */
#define SD_NOTICE  "<5>"  /* normal but significant condition */
#define SD_INFO    "<6>"  /* informational */
#define SD_DEBUG   "<7>"  /* debug-level messages */

References

kkm
  • 275
  • 2
  • 7
  • Thinking about this `<4>` etc could be useful not so much for shell scripts (where you'd just specify the priority and call `systemd-cat`) but for actual output from real programs (where calling third party apps is generally considered undesirable). – mikemaccana Oct 30 '20 at 11:10
  • 1
    This is both useful and used in C(++) programs; there is a reason why the constants are defined in a .h file :). Additionally, the best and recommended way to implement a long-running systemd service is by declaring `Type=notify` and posting a dbus notification when the service initialization completes. systemd can parallelize startup faster, by dropping a wait for _execve() after fork(), and still receive a sensible notification when the service completes initialization (or fails to do so). Also, these services get an extra human-readable line in `systemd status` message. – kkm Nov 01 '20 at 09:09
  • This is doable from a [ba]sh script as well, but painful indeed. Also, I would not call a bash program "not a real program." For some people, any program except written in Haskell is not a real program. :) In other words, this is a matter of opinion. – kkm Nov 01 '20 at 09:09
  • @mikemaccana, forgot to @ you. I was talking to myself! :) – kkm Nov 01 '20 at 12:03
  • Thanks @kkm! And yes maybe 'non-shell program' would have been better. – mikemaccana Nov 02 '20 at 10:05
  • Note that if you need emit untrusted content at the start of the message, you need to output `` prefix for the message because the untrusted part could start with `<7>` to hide it from the default logs. – Mikko Rantalainen Sep 10 '21 at 14:36
  • @MikkoRantalainen Good point, thanks! There is a possible issue, but does it affect security? When stderr is written by the while read loop in the subshell, `<3>` is always prepended. But when writing to the saved &4 explicitly, it's possible to mess up. echo, printf and especially cat >&4 are susceptible to inadvertent logging at an unexpected level. But an evil program can log nothing by, well, simply logging nothing, no overt need to prevent logging. I can't imagine a scenario when this becomes a security issue. Am I missing a possible one? Security is important, appreciate your insights. – kkm Sep 19 '21 at 15:19
  • If an evil program needs to do something that would emit a permanent log entry it may be able to prefix the permanent log entry with e.g. `<7>` which results the log entry to be ignored instead of being logged. I'm not aware other vulnerabilities but selectively supressing the logging. – Mikko Rantalainen Sep 20 '21 at 16:56
  • @MikkoRantalainen, thanks, I think I got it, but I'll restate: to hide logs that would otherwise go to &2, the evil program redirects stderr to &4 and prepends `<7>` to it, so that any program that it executes inherits fd4 and logs its stderr at the severity=7, correct? If so, I don't see that as a security issue: the exactly same effect is achieved by redirecting stderr to /dev/null (in fact even better, as severity 7 may be enabled). To avoid a confusion, I'm sure you know that this mechanism doesn't affect the syslog(2) call, only program's std{out,err} capture for logging to journald. – kkm Sep 20 '21 at 17:37
  • I meant the case where attacker can affect the message to be printed to the stream but cannot control the stream itself. Because the "remote" protocol is "if it starts with it's message level followed by message, otherwise the whole line is message to log at default level" which results in message that's supposed to be logged at default level possibly hidden by attacker controlled prefix `<7>`. Of course, if the attacker can redirect pipes all bets are off. – Mikko Rantalainen Sep 22 '21 at 08:29
  • @MikkoRantalainen, yes, but it's only part of the whole. All set up, anything you (or, rather your child processes: this is mainly a pure Bash serviice) write to &2 gets a `<3>` added, but &4 goes the former stderr, to the same journald-captured pipe. Nothing prevents the attacker from re-execve'ing itself with different redirections. All in all, everything said applies to any program whatsoever. If a C program uses the journald's `` protocol, and some other binary pretends to be it, you're pwnd deep and hard, and hiding logs made by spawned processes is a fairly weak hiding measure really. – kkm Sep 23 '21 at 03:50
  • @MikkoRantalainen, My main point is that &2 is already redirected to journald, and the thing that the program-in-the-middle has to do is to prevent its child from logging to &2 (at whichever level it does), it's elementarily doable. So i do not really see a security hole here. Anything which can add `` before writing to &2, can do same before writing to $4. Unless I'm totally missing your point, in which case I'll be glad to be corrected, please! – kkm Sep 23 '21 at 03:54
  • @MikkoRantalainen, rereading the convo, I think the strongest point is in your first message: “emit untrusted content at the start of the message“. Maybe &4 would be safer equipped with a similar `while read` subshell with like `perl -lpe 's/^\<\d\>//'` sanitizer. In my case it'd be an overkill. Generally, I agree that allowing a privileged script to run random programs is very unsafe. In my case, `gcloud` is pulling a shared machine SSH key on a newly created burst HPC cluster node from a common secret, so 'StrictHostChecking on` works, and a couple of `mv`, `cp` and other harmless stuff. – kkm Sep 23 '21 at 04:16
  • Yes, a safe implementation would somehow modify each printed line to always prepend at the start of every line that's going to forwarded system logger. If you can guarantee that no logged line ever starts with the character `<` you'll be fine without any extra tricks, too. – Mikko Rantalainen Sep 23 '21 at 10:02