一、问题现象
rsyslog是linux系统中用来实现日志功能的服务。程序通过openlog/closelog和syslog接口可向系统日志文件中记录日志信息。备份服务程序也基于syslog记录日志。
但在某次功能验证环境上启动备份服务后，发现/var/log/messages无备份服务相关的日志。
备份服务日志打开参数：openlog("xxx", LOG_NDELAY|LOG_PID|LOG_CONS, LOG_LOCAL5);
二、排查过程
1、怀疑rsyslogd未启动。
执行systemctl status rsyslog，服务状态为active(running)，说明rsyslog服务正常。
2、怀疑rsyslogd配置异常。
通过tail -f /var/log/messages，查看后发现ceph-crash和cassandra等其他服务日志可正常输出，说明rsyslog服务确实正常工作。
Aug 23 16:30:00 node1 ceph-crash: ERROR:__main__:directory /var/lib/ceph/crash/posted does not exist; please create
Aug 23 16:30:01 node1 systemd: Started Session 25 of user root.
Aug 23 16:30:30 node1 ceph-crash: ERROR:__main__:directory /var/lib/ceph/crash/posted does not exist; please create
3、通过demo测试程序验证。
（1）准备demo程序，发现可正常输出到messages；说明日志服务正常。
[root@node1 home]# cat testlog_demo.c
#include <stdio.h>
#include <syslog.h>
int main(void) {
openlog("demo", LOG_CONS | LOG_PID, LOG_USER);
syslog(LOG_INFO, "---- This is a message from demo program.");
closelog();
return 0;
}
输出结果：
Aug 23 17:12:18 node1 demo[23304]: ---- This is a message from demo program.
（2）向demo程序添加备份服务的日志打开方式；发现备份服务的日志仍未打印。说明可能与日志参数有关。
[root@node1 home]# cat testlog_demo2.c
#include <stdio.h>
#include <syslog.h>
int main(void) {
openlog("demo2", LOG_CONS | LOG_PID, LOG_USER);
syslog(LOG_INFO, "---- This is a message from demo program.");
closelog();
openlog("hoo2",LOG_NDELAY|LOG_PID|LOG_CONS, LOG_LOCAL5);//log fail
syslog(LOG_ERR,"xixixi");
return 0;
}
输出结果：hoo2未打印
Aug 23 17:21:02 node1 ceph-crash: ERROR:__main__:directory /var/lib/ceph/crash/posted does not exist; please create
Aug 23 17:21:23 node1 demo2[23956]: ---- This is a message from demo program.
Aug 23 17:21:32 node1 ceph-crash: ERROR:__main__:directory /var/lib/ceph/crash/posted does not exist; please create
（3）将demo程序中的备份服务日志打开参数的LOG_LOCAL5改为demo的LOG_USER；发现备份服务日志可成功打印。
[root@node1 home]# cat testlog_demo3.c
#include <stdio.h>
#include <syslog.h>
int main(void) {
openlog("demo3", LOG_CONS | LOG_PID, LOG_USER);
syslog(LOG_INFO, "---- This is a message from demo program.");
closelog();
openlog("hoo3",LOG_NDELAY|LOG_PID|LOG_CONS, LOG_USER);//log success
syslog(LOG_ERR,"xixixi");
return 0;
}
输出结果：
Aug 23 17:27:32 node1 ceph-crash: ERROR:__main__:directory /var/lib/ceph/crash/posted does not exist; please create
Aug 23 17:27:34 node1 demo3[24350]: ---- This is a message from demo program.
Aug 23 17:27:34 node1 hoo3[24350]: xixixi
由此说明，问题现象与openlog的打开参数有关，LOG_LOCAL5参数未正常打印。
（4）查看rsyslog的配置文件，发现/var/log/messages的配置如下：
[root@node1 etc]# cat /etc/rsyslog.conf | grep /var/log/messages
*.debug;mail.none;authpriv.none;cron.none;local5.none /var/log/messages
[root@node1 etc]#
查看rsyslog配置文件的相关说明，发现配置参数local5.none的作用是设置local5日志通道不打印任何日志。
（5）修改rsyslog配置参数为local5.debug，设置为local5通道打印所有日志。
[root@node1 etc]# cat /etc/rsyslog.conf | grep /var/log/messages
*.debug;mail.none;authpriv.none;cron.none;local5.debug /var/log/messages
重启rsyslog服务：
[root@node1 etc]# systemctl restart rsyslog
[root@node1 etc]# systemctl status rsyslog
- rsyslog.service - System Logging Service
Loaded: loaded (/usr/lib/systemd/system/rsyslog.service; enabled; vendor preset: enabled)
Active: active (running) since Wed 2023-08-23 17:33:29 CST; 6s ago
Docs: man:rsyslogd(8)
Main PID: 24739 (rsyslogd)
Tasks: 3
CGroup: /system.slice/rsyslog.service
└─24739 /usr/sbin/rsyslogd -n
Aug 23 17:33:29 node1 systemd[1]: Starting System Logging Service...
Aug 23 17:33:29 node1 rsyslogd[24739]: [origin software="rsyslogd" swVersion="8.24.0-34.el7" x-pid="24739" x...start
Aug 23 17:33:29 node1 systemd[1]: Started System Logging Service.
Hint: Some lines were ellipsized, use -l to show in full.
重新执行demo3；发现日志可正常打印demo3的信息，包括hoo3的日志信息：
Aug 23 17:34:25 node1 demo3[24806]: ---- This is a message from demo program.
Aug 23 17:34:25 node1 hoo3[24806]: xixixi
由此说明，备份服务日志未正常打印，是因为rsyslog.conf的配置参数问题。
三、问题确认
重新启动备份服务程序，发现备份服务日志已打印正常。至此已破案，问题解决。
