Supervisor日志输出异常


Supervisor是用 Python 开发的在 Linux/Unix 系统下的一个进程管理工具。

Supervisor 管理的进程,当一个进程意外被杀死,Supervisor 监听到进程死后,会自动将它重新拉起,很方便的做到进程自动恢复的功能,不再需要自己写 shell 脚本来控制,这样就可以很方便的监听、启动、停止、重启一个或多个进程。

Supervisor日志输出异常


  • 我们内部的某个服务发生故障,需要排除日志,发现日志的输出文件不太正常,日志分散在了十个轮转日志里面一起打了,如下所示:
$ ls -lh app-web-stderr*
-rw-r--r-- 1 root root 100K Jul 24 15:49 app-web-stderr.log
-rw-r--r-- 1 root root 100K Jul 24 14:44 app-web-stderr.log.1
-rw-r--r-- 1 root root  98K Jul 24 14:44 app-web-stderr.log.2
......
-rw-r--r-- 1 root root 102K Jul 24 14:44 app-web-stderr.log.10

$ ls -lh app-web-stdout*
-rw-r--r-- 1 root root  99K Jul 24 16:45 app-web-stdout.log
-rw-r--r-- 1 root root 102K Jul 24 14:44 app-web-stdout.log.1
-rw-r--r-- 1 root root  98K Jul 24 14:44 app-web-stdout.log.2
......
-rw-r--r-- 1 root root 100K Jul 24 14:44 app-web-stdout.log.10
  • 排查了 Supervisor 和操作系统的服务日志,并没有发现有价值的报错信息。随即,排除了对应服务的 Supervisor 配置,大致如下所示:
[program:app]
directory=/opt/app
command=/usr/bin/python3 -m run_web
process_name=%(program_name)s_%(process_num)02d
user=chrism
numprocs=5
autostart=true
autorestart=unexpected
startsecs=1
startretries=3
stopasgroup=false
killasgroup=false
redirect_stderr=true
stdout_logfile=/data/logs
stdout_logfile_maxbytes=50MB
stdout_logfile_backups=10
stderr_logfile=/data/logs
stderr_logfile_maxbytes=50MB
stderr_logfile_backups=10
  • 可以看到,值得注意的配置就是下面这三个了,但是看了看使用上面也没有什么有问题的地方!
    • process_name => 启动多个进程时的进程命名规则
    • stderr_logfile => 错误日志文件路径
    • stdout_logfile => 正常日志文件路径
  • 所以,又看了下官方文档对于上述三个参数的解释,发现如下图的注意事项。可以看到,官方文档里面提示:当启用日志轮转的功能时,两个进程不可能共享同一个日志文件,如果使用的话将导致文件被损坏。这是就在考虑,是不是因为服务启动时启用多进程,导致多个进程同时写一个配置文件,导致日志输出发生异常。但是仔细考虑了下,发现如果真是这个问题,出问题的也只会是一个单个文件,并不会导致日志同时输出到多个轮转日志里面的。呃呃呃,没搞明白到底发生了什么事情。

Supervisor日志输出异常

  • 查了下服务器上面对应的 Supervisor 版本并不是最新的,考虑是不是 Supervisor 工具自身的 Bug 导致的呢?随后,翻看了官方仓库中的 CHANGES.rst 文件以及 issue 的相关条目,并没有发现相同问题的描述。
$ dpkg -l | grep supervisor
ii    supervisor    3.x.x-x.x    all    System for controlling process state
  • 这时抱着试一试的态度,通过 lsof 命令查看对应的十个日志文件,到底是那些进程打开的呢?使用如下命令,查看之后才发现,对应的这几个文件,都被 supervisor 进程给打开了。
$ sudo lsof draft-csc-test-stderr.log
COMMAND     PID   USER  FD   TYPE  DEVICE  SIZE/OFF      NODE  NAME
supervisor  2xx8  root  xxw   REG    x,xx  2431xx20  1416xx18  app-web-stderr.log
  • 走到这里,现在基本就可以大致判断出问题的原因了,就是因为某些因素或者工具 Bug 导致 Supervisor 异常接管对应日志文件,使日志内容输出到多个文件。后来通过重启 Supervisord 服务,使日志输出正常了,到现在为止也没有再出现同样的问题了。
# 重启服务
$ systemctl restart supervisor.service

文章作者: Escape
版权声明: 本博客所有文章除特別声明外,均采用 CC BY 4.0 许可协议。转载请注明来源 Escape !