我正在一个脚本中使用ping，该脚本在 systemd 服务单元中运行。 ping 的输出有时（经常）在单位日志中丢失。即，它丢失了journalctl --user -u MyUnit。
请注意，无论脚本是ping在自己的循环中调用的长时间运行的脚本（变体 1），还是我使用计时器定期启动它（变体 2），我都可以观察到这一点。请注意，我还在额外的文件中记录时间戳，以验证脚本是否实际运行。确实总是如此。
变体1
脚本：
$ cat ~/ping_test
#!/bin/bash
ITERATION=0
while true
do
echo "Iteration $ITERATION"
let ITERATION=ITERATION+1
date >> timestamps
ping -c 1 vodafone.de
sleep 10
done
服务单位：
$ cat ~/.config/systemd/user/ping_test.service
[Unit]
Description=Ping Test
[Service]
ExecStart=%h/ping_test
[Install]
WantedBy=default.target
变体2
脚本：
$ cat ~/myscript
#!/bin/bash
echo HELLO
date >> timestamps
ping -c 1 vodafone.de
服务单位：
$ cat ~/.config/systemd/user/test.service
[Unit]
description = test
[Service]
ExecStart=%h/myscript
[Install]
WantedBy=default.target
定时器单位：
$ cat ~/.config/systemd/user/test.timer
[Unit]
Description = myscript
[Timer]
OnCalendar=*-*-* *:*:0/10
AccuracySec=1s
[Install]
WantedBy=timers.target
下面是变体 2 的输出，但变体 1 实际上也存在完全相同的问题。
下面显示了ping单位日志中有时会丢失来自的输出，即使其他输出可见。查看连续的消息，中间HELLO没有任何输出。PING
$ journalctl --user -n 40 --no-pager -u test
Dec 20 16:16:20 debian myscript[2839]: 1 packets transmitted, 1 received, 0% packet loss, time 0ms
Dec 20 16:16:20 debian myscript[2839]: rtt min/avg/max/mdev = 21.241/21.241/21.241/0.000 ms
Dec 20 16:16:30 debian systemd[1686]: Started test.service.
Dec 20 16:16:30 debian myscript[2842]: HELLO
Dec 20 16:16:40 debian systemd[1686]: Started test.service.
Dec 20 16:16:40 debian myscript[2845]: HELLO
Dec 20 16:16:50 debian systemd[1686]: Started test.service.
Dec 20 16:16:50 debian myscript[2849]: HELLO
Dec 20 16:16:50 debian myscript[2850]: PING vodafone.de (139.7.147.49) 56(84) bytes of data.
Dec 20 16:16:50 debian myscript[2850]: 64 bytes from hilfe.vodafone.de (139.7.147.49): icmp_seq=1 ttl=244 time=20.6 ms
Dec 20 16:16:50 debian myscript[2850]: --- vodafone.de ping statistics ---
Dec 20 16:16:50 debian myscript[2850]: 1 packets transmitted, 1 received, 0% packet loss, time 0ms
Dec 20 16:16:50 debian myscript[2850]: rtt min/avg/max/mdev = 20.591/20.591/20.591/0.000 ms
Dec 20 16:17:00 debian systemd[1686]: Started test.service.
Dec 20 16:17:00 debian myscript[2852]: HELLO
Dec 20 16:17:00 debian myscript[2853]: PING vodafone.de (139.7.147.49) 56(84) bytes of data.
Dec 20 16:17:00 debian myscript[2853]: 64 bytes from incubator.vodafone.de (139.7.147.49): icmp_seq=1 ttl=244 time=17.7 ms
Dec 20 16:17:00 debian myscript[2853]: --- vodafone.de ping statistics ---
Dec 20 16:17:00 debian myscript[2853]: 1 packets transmitted, 1 received, 0% packet loss, time 0ms
Dec 20 16:17:00 debian myscript[2853]: rtt min/avg/max/mdev = 17.718/17.718/17.718/0.000 ms
Dec 20 16:17:10 debian systemd[1686]: Started test.service.
Dec 20 16:17:10 debian myscript[2862]: HELLO
Dec 20 16:17:20 debian systemd[1686]: Started test.service.
Dec 20 16:17:20 debian myscript[2865]: HELLO
Dec 20 16:17:30 debian systemd[1686]: Started test.service.
Dec 20 16:17:30 debian myscript[2869]: HELLO
Dec 20 16:17:30 debian myscript[2870]: PING vodafone.de (139.7.147.49) 56(84) bytes of data.
Dec 20 16:17:30 debian myscript[2870]: 64 bytes from hilfe.vodafone.de (139.7.147.49): icmp_seq=1 ttl=244 time=20.3 ms
Dec 20 16:17:30 debian myscript[2870]: --- vodafone.de ping statistics ---
Dec 20 16:17:30 debian myscript[2870]: 1 packets transmitted, 1 received, 0% packet loss, time 0ms
Dec 20 16:17:30 debian myscript[2870]: rtt min/avg/max/mdev = 20.328/20.328/20.328/0.000 ms
Dec 20 16:17:40 debian systemd[1686]: Started test.service.
Dec 20 16:17:40 debian myscript[2872]: HELLO
Dec 20 16:17:40 debian myscript[2873]: PING vodafone.de (139.7.147.49) 56(84) bytes of data.
Dec 20 16:17:40 debian myscript[2873]: 64 bytes from incubator.vodafone.de (139.7.147.49): icmp_seq=1 ttl=244 time=22.9 ms
Dec 20 16:17:40 debian myscript[2873]: --- vodafone.de ping statistics ---
Dec 20 16:17:40 debian myscript[2873]: 1 packets transmitted, 1 received, 0% packet loss, time 0ms
Dec 20 16:17:40 debian myscript[2873]: rtt min/avg/max/mdev = 22.900/22.900/22.900/0.000 ms
Dec 20 16:17:50 debian systemd[1686]: Started test.service.
Dec 20 16:17:50 debian myscript[2877]: HELLO
下面显示 from 的输出ping并没有丢失，而且实际上是可见的，只是单位有时不正确。请注意，PING输出有时低于单位myscript（错误），有时低于单位[email protected]/test.service（正确）。
$ journalctl --user -n 40 --no-pager --output=with-unit
Wed 2023-12-20 16:20:10 UTC debian myscript[3065]: PING vodafone.de (139.7.147.49) 56(84) bytes of data.
Wed 2023-12-20 16:20:10 UTC debian myscript[3065]: 64 bytes from hilfe.vodafone.de (139.7.147.49): icmp_seq=1 ttl=244 time=19.0 ms
Wed 2023-12-20 16:20:10 UTC debian myscript[3065]: --- vodafone.de ping statistics ---
Wed 2023-12-20 16:20:10 UTC debian myscript[3065]: 1 packets transmitted, 1 received, 0% packet loss, time 0ms
Wed 2023-12-20 16:20:10 UTC debian myscript[3065]: rtt min/avg/max/mdev = 19.019/19.019/19.019/0.000 ms
Wed 2023-12-20 16:20:20 UTC debian [email protected]/init.scope[1686]: Started test.service.
Wed 2023-12-20 16:20:20 UTC debian [email protected]/test.service[3067]: HELLO
Wed 2023-12-20 16:20:20 UTC debian myscript[3068]: PING vodafone.de (139.7.147.49) 56(84) bytes of data.
Wed 2023-12-20 16:20:20 UTC debian myscript[3068]: 64 bytes from hilfe.vodafone.de (139.7.147.49): icmp_seq=1 ttl=244 time=18.8 ms
Wed 2023-12-20 16:20:20 UTC debian myscript[3068]: --- vodafone.de ping statistics ---
Wed 2023-12-20 16:20:20 UTC debian myscript[3068]: 1 packets transmitted, 1 received, 0% packet loss, time 0ms
Wed 2023-12-20 16:20:20 UTC debian myscript[3068]: rtt min/avg/max/mdev = 18.815/18.815/18.815/0.000 ms
Wed 2023-12-20 16:20:30 UTC debian [email protected]/init.scope[1686]: Started test.service.
Wed 2023-12-20 16:20:30 UTC debian [email protected]/test.service[3070]: HELLO
Wed 2023-12-20 16:20:30 UTC debian myscript[3071]: PING vodafone.de (139.7.147.49) 56(84) bytes of data.
Wed 2023-12-20 16:20:30 UTC debian myscript[3071]: 64 bytes from incubator.vodafone.de (139.7.147.49): icmp_seq=1 ttl=244 time=17.8 ms
Wed 2023-12-20 16:20:30 UTC debian myscript[3071]: --- vodafone.de ping statistics ---
Wed 2023-12-20 16:20:30 UTC debian myscript[3071]: 1 packets transmitted, 1 received, 0% packet loss, time 0ms
Wed 2023-12-20 16:20:30 UTC debian myscript[3071]: rtt min/avg/max/mdev = 17.773/17.773/17.773/0.000 ms
Wed 2023-12-20 16:20:40 UTC debian [email protected]/init.scope[1686]: Started test.service.
Wed 2023-12-20 16:20:40 UTC debian [email protected]/test.service[3073]: HELLO
Wed 2023-12-20 16:20:40 UTC debian myscript[3074]: PING vodafone.de (139.7.147.49) 56(84) bytes of data.
Wed 2023-12-20 16:20:40 UTC debian myscript[3074]: 64 bytes from incubator.vodafone.de (139.7.147.49): icmp_seq=1 ttl=244 time=19.3 ms
Wed 2023-12-20 16:20:40 UTC debian myscript[3074]: --- vodafone.de ping statistics ---
Wed 2023-12-20 16:20:40 UTC debian myscript[3074]: 1 packets transmitted, 1 received, 0% packet loss, time 0ms
Wed 2023-12-20 16:20:40 UTC debian myscript[3074]: rtt min/avg/max/mdev = 19.251/19.251/19.251/0.000 ms
Wed 2023-12-20 16:20:50 UTC debian [email protected]/init.scope[1686]: Started test.service.
Wed 2023-12-20 16:20:50 UTC debian [email protected]/test.service[3077]: HELLO
Wed 2023-12-20 16:20:50 UTC debian [email protected]/test.service[3078]: PING vodafone.de (139.7.147.49) 56(84) bytes of data.
Wed 2023-12-20 16:20:50 UTC debian [email protected]/test.service[3078]: 64 bytes from incubator.vodafone.de (139.7.147.49): icmp_seq=1 ttl=244 time=20.9 ms
Wed 2023-12-20 16:20:50 UTC debian [email protected]/test.service[3078]: --- vodafone.de ping statistics ---
Wed 2023-12-20 16:20:50 UTC debian [email protected]/test.service[3078]: 1 packets transmitted, 1 received, 0% packet loss, time 0ms
Wed 2023-12-20 16:20:50 UTC debian [email protected]/test.service[3078]: rtt min/avg/max/mdev = 20.893/20.893/20.893/0.000 ms
Wed 2023-12-20 16:21:00 UTC debian [email protected]/init.scope[1686]: Started test.service.
Wed 2023-12-20 16:21:00 UTC debian [email protected]/test.service[3080]: HELLO
Wed 2023-12-20 16:21:00 UTC debian myscript[3081]: PING vodafone.de (139.7.147.49) 56(84) bytes of data.
Wed 2023-12-20 16:21:00 UTC debian myscript[3081]: 64 bytes from hilfe.vodafone.de (139.7.147.49): icmp_seq=1 ttl=244 time=20.0 ms
Wed 2023-12-20 16:21:00 UTC debian myscript[3081]: --- vodafone.de ping statistics ---
Wed 2023-12-20 16:21:00 UTC debian myscript[3081]: 1 packets transmitted, 1 received, 0% packet loss, time 0ms
Wed 2023-12-20 16:21:00 UTC debian myscript[3081]: rtt min/avg/max/mdev = 19.992/19.992/19.992/0.000 ms
此外，/var/log/syslog（通过rsyslog）还包含全部消息。
目前我认为这是 systemd 中的一个错误。对我来说，服务单位似乎是有时未由启动的进程正确“继承”，因此日志无法正确捕获输出单元。
在虚拟机和 Raspberry Pi 操作系统中运行的未受影响的 Debian 12 Live（标准）实例上观察到。
答案1
那就别那么做！
创建一个每 10 秒运行一次 ping 的计时器单元。
/etc/systemd/system/ping.timer
[Unit]
Description=Runping every ten seconds
[Timer]
OnBootSec=10s
[Install]
WantedBy=timers.target
以及服务文件：
/etc/systemd/system/ping.service
[Unit]
Description=pinger
[Service]
ExecStart=/usr/bin/ping -c 1 vodafone.de
daemon-reload 并启用 ping 计时器..然后使用journalctl -u ping.service 查看其所有活动。