Journalctl。用户单元的输出消​​失

Question

我有一个非常简单的 SystemD 用户单元：

~/.config/systemd/user/logtest.service

[Unit]
Description=log test
After=network.target

[Service]
Type=oneshot
ExecStart=/home/andrey/tmp/1.sh

[Install]
WantedBy=default.target

1.sh 只是echo

#!/bin/bash
echo "123"

我开始systemctl start --user logtest.service
然后我检查日志journalctl --user-unit logtest -n5，但在此输出中看不到我的123。为什么？？？？

journalctl  --user-unit  logtest -n5                                                                          
-- Logs begin at Сб 2016-10-15 22:17:53 +07, end at Пт 2017-01-06 16:03:16 +07. --
янв 06 16:03:15 andrcomp systemd[1524]: Started log test.
янв 06 16:03:16 andrcomp systemd[1524]: Starting log test...
янв 06 16:03:16 andrcomp systemd[1524]: Started log test.
янв 06 16:03:16 andrcomp systemd[1524]: Starting log test...
янв 06 16:03:16 andrcomp systemd[1524]: Started log test.

但如果我将sleep 1 添加到1.sh：

#!/bin/bash
echo "123"
sleep 1

然后123出现在我的日志中

$ journalctl  --user-unit  logtest -n5                                                                          
-- Logs begin at Сб 2016-10-15 22:17:53 +07, end at Пт 2017-01-06 16:10:25 +07. --
янв 06 16:07:57 andrcomp systemd[1524]: Starting log test...
янв 06 16:07:57 andrcomp systemd[1524]: Started log test.
янв 06 16:10:24 andrcomp systemd[1524]: Starting log test...
янв 06 16:10:24 andrcomp 1.sh[3760]: 123
янв 06 16:10:25 andrcomp systemd[1524]: Started log test.

为什么？

如果我检查所有用户日志，那么 123 就在这里（1.sh 中没有 sleep）

$ journalctl --user -n5                                                                                         
-- Logs begin at Вс 2016-12-18 16:15:56 +07, end at Пт 2017-01-06 16:13:32 +07. --
янв 06 16:13:32 andrcomp 1.sh[3997]: 123
янв 06 16:13:32 andrcomp systemd[1524]: Started log test.
янв 06 16:13:32 andrcomp systemd[1524]: Starting log test...
янв 06 16:13:32 andrcomp 1.sh[4007]: 123
янв 06 16:13:32 andrcomp systemd[1524]: Started log test.

但我只需要查看某些单元日志

它作为系统单元工作正常（/usr/lib/systemd/system/logtest_syst.service）

$ journalctl -u logtest_syst                                                                                    
-- Logs begin at Сб 2016-10-15 22:17:53 +07, end at Пт 2017-01-06 15:43:59 +07. --
янв 06 15:43:59 andrcomp systemd[1]: Starting log test...
янв 06 15:43:59 andrcomp 1.sh[1082]: 123
янв 06 15:43:59 andrcomp systemd[1]: Started log test.

睡眠有什么魔力？或者它可能不是检查用户单元日志的正确方法？

Answer 1

有一个标记为 CLOSED CANTFIX 的错误：Journalctl miss to show logs from unit

根据 Red Hat 高级软件工程师 Michal Sekletar 的说法：

这是一个已知问题。 systemd-journald 有时无法记录有关日志消息源自的单元的信息。如果记录消息的进程是短暂的，则更有可能遇到此问题。

[...]

日志不会在任何地方消失。只是对于一些源自短期进程的日志消息，journald 无法确定相应的 cgroup（单元）。因此，如果您根据单位名称应用过滤，您将看不到这些日志行。在内核为我们提供一种以非 racy 方式收集 cgroup 信息的方法之前，我们对此无能为力。但话又说回来，日志在那里，您使用基于时间的过滤的第一个命令证明了这一点。

因此，您应该能够使用以下命令查看脚本的输出（没有睡眠的脚本）：

journalctl --since "2016-10-15 22:17:53"