每天学五分钟 Liunx | 有趣的 log

说明：看 systemd log 的时候发现了一段有意思的打印，不太明白为什么会这样，贴出来与朋友们分享，欢迎知道的朋友们说明下，非常感谢。

 

问题描述：服务启动时，会执行 python 脚本，该脚本去调用编译好的 C++ 可执行文件。在这之间都会有 log 输出，从时间上看是 C++ 的 log 先打印，而后打印 python 的 log。为什么会出现这样的 log 打印方式？

 

示例演示

python 脚本：

import sys
import subprocess
import re
 
print("I am python, the first command")
cmd = "hello"
subprocess.call(cmd.split())
print("I am python, the second command")
subprocess.call(cmd.split())
subprocess.call(cmd.split())
print("OK, you win CPlusCPlus, I reminber you")

 

C++ 可执行文件 hello：

[root@lianhua lianhua_debug.log]# cat hello.cpp
#include <stdio.h>
 
int main(void)
{
    printf("Hello, I am CPlusPlus, who are you?
");
 
    return 0;
}
 
[root@lianhua lianhua_debug.log]# gcc -c hello.cpp
[root@lianhua lianhua_debug.log]# gcc -o hello hello.cpp
[root@lianhua lianhua_debug.log]# env | grep usr
PATH=/sbin:/bin:/usr/sbin:/usr/bin:/usr/local/bin/
[root@lianhua lianhua_debug.log]# mv hello /usr/bin/
[root@lianhua lianhua_debug.log]# hello
Hello, I am CPlusPlus, who are you?

 

systemd service lianhua_debug：

[root@lianhua lianhua_debug.log]# systemctl cat lianhua_debug_log
# /usr/lib/systemd/system/lianhua_debug_log.service
[Unit]
Description=lianhua_debug_log.service
 
[Service]
Type=oneshot
RemainAfterExit=yes
ExecStart=/bin/python /home/lianhuasheng/lianhua_debug.log/lianhua_debug_log.py

 

启动 service：

[root@lianhua lianhua_debug.log]# systemctl status lianhua_debug_log
● lianhua_debug_log.service
   Loaded: loaded (/usr/lib/systemd/system/lianhua_debug_log.service; static; vendor preset: disabled)
   Active: active (exited) since Sat 2020-05-30 12:57:10 CST; 26min ago
  Process: 28671 ExecStart=/bin/python /home/lianhuasheng/lianhua_debug.log/lianhua_debug_log.py (code=exited, status=0/SUCCESS)
Main PID: 28671 (code=exited, status=0/SUCCESS)
 
May 30 12:57:10 lianhua.localdomain systemd[1]: Starting lianhua_debug_log.service...
May 30 12:57:10 lianhua.localdomain python[28671]: Hello, I am CPlusPlus, who are you?
May 30 12:57:10 lianhua.localdomain python[28671]: Hello, I am CPlusPlus, who are you?
May 30 12:57:10 lianhua.localdomain python[28671]: Hello, I am CPlusPlus, who are you?
May 30 12:57:10 lianhua.localdomain python[28671]: I am python, the first command
May 30 12:57:10 lianhua.localdomain python[28671]: I am python, the second command
May 30 12:57:10 lianhua.localdomain python[28671]: OK, you win CPlusCPlus, I remember you
May 30 12:57:10 lianhua.localdomain systemd[1]: Started lianhua_debug_log.service.

可以看到启动服务之后，输出的 log 是执行 hello 的 log，然后才是 python 脚本的输出 log。

 

 

而直接通过命令 /bin/python /home/lianhuasheng/lianhua_debug.log/lianhua_debug_log.py 执行就会出现不一样的 log 打印：

[root@lianhua lianhua_debug.log]# /bin/python /home/lianhuasheng/lianhua_debug.log/lianhua_debug_log.py
I am python, the first command
Hello, I am CPlusPlus, who are you?
I am python, the second command
Hello, I am CPlusPlus, who are you?
Hello, I am CPlusPlus, who are you?
OK, you win CPlusCPlus, I remember you

 

是不是很奇怪，为什么出现不一样的 log 打印方式呢？

个人理解不应该是先执行 python 脚本，打印 python log 然后子进程执行 hello 打印 hello 的 log，子进程退出继续执行 python 脚本，打印 python 的 log（第二种直接执行 python 脚本的方式） 这样的吗？为什么 systemd 会出现完全不一样的 log 打印呢？

 

 

（未完，待续...）