logging to systemd journal from shell scripts?

Sanjeev K Sharma · 2013-08-18 17:33:13

I've gotten used to having journalctl -ef running all the time in a window whenever I suspect something bad is happening.

I'd like to use it for debugging shell scripts too; instead of doing this

echo "ran" >> /tmp/LOG

in shell scripts, how to send messages to syslog?

my google-fu 's just not powerful enough ....

65kid · 2013-08-18 17:47:29

man systemd-cat

Sanjeev K Sharma · 2013-08-18 21:00:21

65kid wrote:

man systemd-cat

good stuff, thanks.

doesn't do 100% what I wanted. I'm not seeing a way to assign a unit name, so I can't do quick and easy filtering like this

journalctl -e --unit=database_stuff --no-pager

back to grep ...

80% of the way there is awesome.

edit: actually when I use the "-t" option, the identifier ends up in field 'SYSLOG_IDENTIFIER' ... 90% of the way there

Last edited by Sanjeev K Sharma (2013-08-18 21:05:04)

percent20 · 2013-08-19 13:54:39

Keep us updated when you get there, then a quick update on exactly what you did please.

Sanjeev K Sharma · 2013-08-20 01:07:43

Beyond what the man page says there's not much.

Lennart was asked a question specifically about structured logging (which I now know is what I was looking for) from shell scripts and he answered

"systemd-cat doesn't do that ..."

percent20 wrote:

Keep us updated when you get there, then a quick update on exactly what you did please.

will do.

Last edited by Sanjeev K Sharma (2013-08-20 01:08:08)

fukawi2 · 2013-08-20 02:22:51

Does `logger` not do what you want?

Sanjeev K Sharma · 2013-08-20 03:04:30

fukawi2 wrote:

Does `logger` not do what you want?

it's an interface to the regular syslog, right? I'm playing with moving everything to systemd ... exploring moving all my scripts to the one log solution ... take a look at the output of

journalctl -o verbose

I'd like to be able to fill in many of those fields so I can query all the database stuff at the same time (postgres and my own scripts), or log the progress and success/failures of the nightly backups the same way - grouped with the right project or work type and very quickly searchable.

If I get back into active development this would solve a lot of problems, a lot of the busy-work, manual management or book-keeping I used to have to do.

EDIT: just a personal note, across about 2 months I had a bunch of hardware go bad on me, one piece after the other, after 3 years of minimal failures. In the last week I moved to Arch from Ubuntu and I've gotten so, so used to having a scrolling journal in the background, instead of switching terminals every once in a while to check different logs, anxiously, paranoia-edly[0] checking to see if anything new has gone down the cr*pper.

If I go a while without another failure I'll stop doing it of coursebut it's quite the convenience.

[1] similar to calculatedly - though it could be paranoiacally (cognate to cloacally, which also is not a real word)

Last edited by Sanjeev K Sharma (2013-08-20 03:13:08)

fukawi2 · 2013-08-20 05:27:30

Sanjeev K Sharma wrote:

fukawi2 wrote:
Does `logger` not do what you want?
it's an interface to the regular syslog, right? I'm playing with moving everything to systemd ... exploring moving all my scripts to the one log solution ... take a look at the output of

Ah, you might be right. I hate journalctl so still have syslog installed. Thought logger was sending it to the journal then onto syslog. Must be going direct to syslog.

WonderWoofy · 2013-08-20 05:31:48

logger will still work, as anything that would get sent to the syslog gets picked up by the juornal. But there is a systemd tool specifically for this. It is 'systemd-cat' and I use it for a few things. It works well.

Bevan · 2013-09-19 22:50:57

Although this thread is one month old I want to comment on this because I also struggeled with it.

You can use logger or systemd-cat to get messages into the journal. If you do this from inside of a running service most of the time the fields _SYSTEMD_UNIT, _SYSTEMD_CGROUP etc. are missing and you are not able to see these messages if you filter by a specific unit. The reason for this is a race condition, because the logger/systemd-cat process dies before journald can get the information it needs.

A workaround is to use a long-running systemd-cat (or logger) and use a named pipe to feed messages into it. Short example:

#!/bin/bash

PIPE=/tmp/my-script.out
mkfifo $PIPE

# Start logging to journal
systemd-cat < $PIPE &
sleep_pid=$(
        sleep 9999d > $PIPE &  # keep pipe open
        echo $!                # but allow us to close it later...
)

for i in 1 2 3; do
        echo "a message from my script!" | tee $PIPE
        sleep 1
done

kill $sleep_pid
rm $PIPE

The sleep is necessary so that an echo into the pipe does not close the stream and closes systemd-cat. It's not very pretty but I did not find a more clean solution, yet...

Btw: This whole situation may improve some time when information about the logging process will be sent directly along with the log message so there will be no race anymore:
https://bugzilla.redhat.com/show_bug.cgi?id=963620

Last edited by Bevan (2013-09-20 00:59:18)

aesiris · 2013-09-20 02:28:29

Bevan wrote:

The sleep is necessary so that an echo into the pipe does not close the stream and closes systemd-cat. It's not very pretty but I did not find a more clean solution, yet...

If you want you can avoid the sleep by opening the fifo on a file descriptor

systemd-cat < $PIPE &
exec 3>$PIPE

echo message > $PIPE
echo other message >&3

exec 3>&-
#closing file descriptor 3 closes the fifo

Bevan · 2013-09-20 10:30:53

aesiris wrote:

If you want you can avoid the sleep by opening the fifo on a file descriptor
systemd-cat < $PIPE &
exec 3>$PIPE

echo message > $PIPE
echo other message >&3

exec 3>&-
#closing file descriptor 3 closes the fifo

That works great. Thank you :-)

Sanjeev K Sharma · 2013-09-25 18:01:11

Thanks, I will try to apply the pipe stuff. I can see it will be useful.

Another tip - I'm using this command to log (this was a debugging message when I wasn't sure what the script was doing)

/usr/bin/systemd-cat -t "supermemo_backup" /usr/bin/echo "WORKING DIR CHANGED TO"

NOTE THE underscores; without the underscores the "-t" parameter splits its parameter on the spaces so you'll get several entries from one invocation, with different SYSLOG_IDENTIFIER, instead of one.

and when I want to follow the script in real time I use this type of command to track the log

urxvt -geometry 157x71+787+9 -e journalctl -n99  -f SYSLOG_IDENTIFIER=supermemo_backup &

And variations on this, depending on the logging I want to see ... all the standard things

journalctl _GID=1000
journalctl -e --unit cronie.service

I'm finding the bash_completions package a good way to explore the logs and learn journalctl and systemctl.

Apologies for not adding the "-t" discovery earlier, I hadn't realized I had not put it here.

Now, if only I had completion files for "ss" (network stuff) and "ps"

Last edited by Sanjeev K Sharma (2013-09-25 18:17:19)

Sanjeev K Sharma · 2013-09-25 20:34:26

this prepends "SYSLOG_IDENTIFIER_XXXX" to every line (and searchable with the entry I showed earlier)

systemd-cat -t 'SYSLOG_IDENTIFIER_XXXX'< $PIPE & 
...

Bevan wrote:

aesiris wrote:
If you want you can avoid the sleep by opening the fifo on a file descriptor
systemd-cat < $PIPE &
exec 3>$PIPE

echo message > $PIPE
echo other message >&3

exec 3>&-
#closing file descriptor 3 closes the fifo
That works great. Thank you :-)

Arch Linux

#1 2013-08-18 17:33:13

logging to systemd journal from shell scripts?

#2 2013-08-18 17:47:29

Re: logging to systemd journal from shell scripts?

#3 2013-08-18 21:00:21

Re: logging to systemd journal from shell scripts?

#4 2013-08-19 13:54:39

Re: logging to systemd journal from shell scripts?

#5 2013-08-20 01:07:43

Re: logging to systemd journal from shell scripts?

#6 2013-08-20 02:22:51

Re: logging to systemd journal from shell scripts?

#7 2013-08-20 03:04:30

Re: logging to systemd journal from shell scripts?

#8 2013-08-20 05:27:30

Re: logging to systemd journal from shell scripts?

#9 2013-08-20 05:31:48

Re: logging to systemd journal from shell scripts?

#10 2013-09-19 22:50:57

Re: logging to systemd journal from shell scripts?

#11 2013-09-20 02:28:29

Re: logging to systemd journal from shell scripts?

#12 2013-09-20 10:30:53

Re: logging to systemd journal from shell scripts?

#13 2013-09-25 18:01:11

Re: logging to systemd journal from shell scripts?

#14 2013-09-25 20:34:26

Re: logging to systemd journal from shell scripts?

Board footer