syslog日志打印

Posted 2020-10-05 lifehacker

最近syslog出了一次问题，我们配置了不同appname打印到不同文件。现在用不同appname打印log的时候，偶然会混在一起。检查过配置后，觉得不是配置问题，如果是配置问题应该每一条都会打错位置。后来同事发现是c接口线程不安全导致的。这里不是指syslog的libc接口线程不安全，是我们调用syslog的lua接口封装有问题。

 

syslog是一个历史悠久的日志记录标准。一般的日志记录流程是这样的：内核会在内核空间，创建好一个ring buffer，然后调用printk函数在这个buffer里进行打印。用户空间的程序要访问这个buffer，可以通过两种方式读到，一个是/proc/kmsg，另一个是sys_syslog系统调用。

 

内核ring buffer主要由两个程序读取：dmesg（1）和klogd（8），前者是供用户按需调用，查看内核信息，后者是从/proc/kmsg中自动读取（或者在/proc还没挂载的时候，调用sys_syslog接口读取），并转发到syslogd或者命令行，这是与内核相关的流程。

 

用户空间的流程主要是由syslogd（8）来处理，它会监听一些unix domain socket，比如 /dev/log（具体路径可配置），或者UDP的514端口。同时也会从klogd（8）读取日志。然后，syslogd会把这些信息打印到/log，或者通过自己的UDP协议发送到远端。具体配置在/etc/syslog.conf

 

用户空间的程序会调用libc函数syslog（3）来进行打印。libc会将日志打到unix domain socket： /dev/log，并由syslogd(8)来读取。

 

syslog(3)的接口主要用到的有openlog, syslog, closelog三个，分别是打开，关闭，和打印日志。openlog()先连接到系统logger，然后syslog接口打印日志。多线程的时候，openlog之后，还没有调syslog接口写日志，就切换到其他线程了。其他线程也调用了openlog和syslog来打印日志。切回来到原来的线程，再syslog的时候就会打印到错误的地方了。感觉openlog的接口设计也有点问题，一般是open完返回一个东西作为凭证。

 

解决方法有三种，一种是skynet内新建一个服务，所有日志都打到这个服务，这个服务再打印日志，相当于利用skynet的消息队列做锁保护。另一种是调整syslog参数的priority，保证不同appname对应不同priority。最后一种是直接对这个函数加锁，保证线程安全。

 

又及：libc的syslog接口，唯一做的就是新建，连接，写入，关闭udp socket，和自己直接做没有任何区别。对于过载，因为内核用的是ringbuffer，估计就直接覆盖前面的了。