Arch Linux

Kim

Member

Registered: 2024-02-12

Posts: 7

systemd --user and logger command in bash script

Hello community,

i wrote a simple bash (test) script and added it to a systemd service unit.

This is the script:

#!/bin/bash

logger -p "error" "This is a test log entry"
exit 1

while true; do
        sleep 2
done

I added the following content to "/etc/systemd/system/test.service":

[Unit]
Description=test

[Service]
ExecStart=/home/test/test.sh

[Install]
WantedBy=multi-user.target

When I start the service and display the result with “sudo systemctl status test.service”, the error message (in red) is displayed in the output, as it should be.

Now i want to use this script in user context. So i copied the service file to "~/.config/systemd/user" and only changed the "WantedBy" to "default.target".
But now when I try to start the script with “systemctl --user start test.service” and then display the status with “systemctl --user status test.service”, there is no error message.

But if I start the service again and again, an error message appears at some point. And then it suddenly stops.

Summary:
- In the “system context”, the logger command always writes the error message to the journal
- In the “user context”, the logger command only sometimes writes the error message to the journal

Regards
Kim

ua4000

Member

Registered: 2015-10-14

Posts: 487

Re: systemd --user and logger command in bash script

Did you use

systemctl --user daemon-reload

after adding /changing the unit file on disk ?

And have a look at

sudo journalctl

without --user, if the log contains the unit start and finisch.

Kim

Member

Registered: 2024-02-12

Posts: 7

Re: systemd --user and logger command in bash script

Yes i used "systemctl --user daemon-reload".
And when using only "journalctl" it shows the message.

Jun 16 15:42:14 Notebook systemd[61614]: Started test.
Jun 16 15:42:14 Notebook test[66461]: This is a test log entry
Jun 16 15:42:14 Notebook systemd[61614]: test.service: Main process exited, code=exited, status=1/FAILURE
Jun 16 15:42:14  systemd[61614]: test.service: Failed with result 'exit-code'.

ua4000

Member

Registered: 2015-10-14

Posts: 487

Re: systemd --user and logger command in bash script

This is a good or a bad example ?
Can you post the logs from the --user and the system above, when you had the issue ?

Please also post the used command to start your unit - do you use  "start" or "restart" ?

Kim

Member

Registered: 2024-02-12

Posts: 7

Re: systemd --user and logger command in bash script

It is a bad result. I expect to see all the messages if I just type "journalctl". But I expect the same for "journalctl --user".
I am using the "start" command.

That is the output for "journalctl" after "systemctl --user start test.service":

Jun 17 12:11:10 Notebook systemd[13016]: Started test.
Jun 17 12:11:10 Notebook test[22422]: This is a test log entry
Jun 17 12:11:10 Notebook systemd[13016]: test.service: Main process exited, code=exited, status=1/FAILURE
Jun 17 12:11:10 Notebook systemd[13016]: test.service: Failed with result 'exit-code'.

That is the output for "journalctl --user" after the same "systemctl --user start test.service" as above:

Jun 17 12:11:10 Notebook systemd[13016]: Started test.
Jun 17 12:11:10 Notebook systemd[13016]: test.service: Main process exited, code=exited, status=1/FAILURE
Jun 17 12:11:10 Notebook systemd[13016]: test.service: Failed with result 'exit-code'.

After 3 Repeats (That means i type "systemctl --user start test.service again") it shows the following in both command (journalctl and journalctl --user):

Jun 17 12:16:01 Notebook systemd[23909]: Started test.
Jun 17 12:16:01 Notebook test[25860]: This is a test log entry
Jun 17 12:16:01 Notebook systemd[23909]: test.service: Main process exited, code=exited, status=1/FAILURE
Jun 17 12:16:01 Notebook systemd[23909]: test.service: Failed with result 'exit-code'.

And after another retry it is again like the first example (logging message only on full journal).

Kim

Member

Registered: 2024-02-12

Posts: 7

Re: systemd --user and logger command in bash script

I assume that the "logger" command is killed too early by systemd.

When i modify the service file like this:
(Added KillMode)

[Unit]
Description=test

[Service]
ExecStart=/home/test/test.sh
KillMode=process

[Install]
WantedBy=multi-user.target

And the script like this:
(Add & to the and of the logger command)

#!/bin/bash

logger -p "error" "This is a test log entry" &
exit 1

while true; do
        sleep 2
done

Then the error message will always show up with "systemctl --user".
But that is not a solution because "KillMode=process" only kills the main process. Better solution is "wait for logger command an that kill main pid".

damjan

Member

Registered: 2006-05-30

Posts: 454

Re: systemd --user and logger command in bash script

There's a race condition where if a program just starts, logs something and immediately exits, journald doesn't have the time to associate the log stream with the unit.

The logs are there somewhere in the journal, they are just not associated with the unit/--user manager.

Kim

Member

Registered: 2024-02-12

Posts: 7

Re: systemd --user and logger command in bash script

That could fit my error description! I will continue to inform myself about this.
What is a good solution to avoid this type of race condition in my logging example?

In a real world example i want to start a bash script with systemd. The script should check some preconditions (e.g. whether all packages are installed) and if the dependencies are not fulfilled, it should be terminated immediately with a visible (systemctl --user status test.service) error message.