Bug 1714373 - systemd-cat output not associated with the unit that generated it
Summary: systemd-cat output not associated with the unit that generated it
Keywords:
Status: CLOSED DUPLICATE of bug 963620
Alias: None
Product: Fedora
Classification: Fedora
Component: systemd
Version: 30
Hardware: Unspecified
OS: Unspecified
unspecified
unspecified
Target Milestone: ---
Assignee: systemd-maint
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2019-05-27 21:51 UTC by Robin A. Meade
Modified: 2019-07-21 09:39 UTC (History)
6 users (show)

Fixed In Version:
Clone Of:
Environment:
Last Closed: 2019-07-21 09:39:53 UTC
Type: Bug
Embargoed:


Attachments (Terms of Use)

Description Robin A. Meade 2019-05-27 21:51:21 UTC
Description of problem:

I tried a simple tutorial [1] and didn't get the expected behavior from systemd-cat:


File: /lib/systemd/system/myservice.service
```
[Unit]
Description=Example systemd service.

[Service]
Type=simple
ExecStart=/bin/bash /usr/bin/test_service.sh

[Install]
WantedBy=multi-user.target
```


File: /usr/bin/test_service.sh
```
DATE=`date '+%Y-%m-%d %H:%M:%S'`
echo "Example service started at ${DATE}" | systemd-cat -p info

while :
do
echo "Looping...";
sleep 30;
done
```

Then I started and got status:

```
sudo systemctl start myservice
sudo systemctl status myservice
```

EXPECTED:

I expcted to see the "Example service started at ..." line in the output of the status command, but did not.

I did see it in the output of `sudo journalctl -f` but not `sudo journalctl -f myservice`

Thus it seemms the output of systemd-cat is not getting associated with the unit.

Version-Release number of selected component (if applicable):

$ systemd-cat --version
systemd 241 (v241-8.git9ef65cb.fc30)
+PAM +AUDIT +SELINUX +IMA -APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD +IDN2 -IDN +PCRE2 default-hierarchy=hybrid

[1] https://www.linode.com/docs/quick-answers/linux/start-service-at-boot/

Comment 1 Robin A. Meade 2019-05-27 22:24:50 UTC
Possible explanation:

https://bbs.archlinux.org/viewtopic.php?pid=1326954#p1326954

"The reason for this is a race condition, because the logger/systemd-cat process dies before journald can get the information it needs."
-- September 2013

Comment 2 Robin A. Meade 2019-05-27 22:55:07 UTC
I integrated the workaround offered in the above archlinux.org forum and it worked:

File: /usr/bin/test_service.sh
```
# The script: /usr/bin/test_service.sh
sudo tee /usr/bin/test_service.sh > /dev/null << "EOF"
# For info messages:
info=/tmp/myservice-systemd-cat-pipe-info
mkfifo "$info"
trap "exec 3>&-; rm $info" EXIT
systemd-cat -p info < "$info" &
exec 3>"$info"

# For warning messages:
warning=/tmp/myservice-systemd-cat-pipe-warning
mkfifo "$warning"
trap "exec 4>&-; rm $warning" EXIT
systemd-cat -p warning < "$warning" &
exec 4>"$warning"

# For err messages:
err=/tmp/myservice-systemd-cat-pipe-err
mkfifo "$err"
trap "exec 5>&-; rm $err" EXIT
systemd-cat -p err < "$err" &
exec 5>"$err"

echo "This is an information message" > "$info"
echo "This is an warning message" > "$warning"
echo "This is an error message" > "$err"

DATE=`date '+%Y-%m-%d %H:%M:%S'`
echo "Example service started at ${DATE}" > "$info"

while :
do
  echo "Looping...";
  sleep 30;
done
EOF

```

Comment 3 Zbigniew Jędrzejewski-Szmek 2019-07-21 09:39:53 UTC
Yep, not much we can do unless the kernel helps us.

*** This bug has been marked as a duplicate of bug 963620 ***


Note You need to log in before you can comment on or make changes to this bug.