正文
本文记录了因为一个简单的日志需求，继而对linux环境下syslog、rsyslog、unix domain socket的学习。本文关注使用层面，并不涉及rsyslog的实现原理，感兴趣的读者可以参考rsyslog官网。另外，本文实验的环境实在debian8，如果是其他linux发行版本或者debian的其他版本，可能会稍微有些差异。
需求：
工作中有一个在Linux（debian8）环境下运行的服务器程序，用python语言实现，代码中有不同优先级的日志需要记录，开发的时候都是使用python的logging模块输出到文件，示例代码如下：
1 import logging, os 2 3 logger = None 4 def get_logger(): 5 global logger 6 if not logger: 7 logger = logging.getLogger('ServerLog') 8 logger.setLevel(logging.INFO) 9 filehandler = logging.FileHandler(os.environ['HOME'] + '/Server.log', encoding='utf8') 10 filehandler.setFormatter(logging.Formatter("%(asctime)s - %(levelname)s - %(message)s")) 11 logger.addHandler(filehandler) 12 return logger 13 14 def some_func(): 15 get_logger().info("call some_func") 16 17 if __name__ == '__main__': 18 some_func()
运行上面这段代码，就会在home目录下面产生一个server.log文件。
后来数据分析的部门说他们希望能够实时拿到一部分日志，他们有一台专门处理日志的服务器，那么怎么把日志发给他们呢？笔者之前并没有相关经验，数据分析部门的同事说，这种需求他们都是找运维人员帮忙。运维同事给出的方案很简单：产品把日志写到syslog，然后他们负责把带有某些关键字的日志转发给数据分析部门，在运维同事的指导下，把代码改成了这样:
1 import logging 2 import logging.handlers 3 4 logger = None 5 def get_logger(): 6 global logger 7 if not logger: 8 logger = logging.getLogger('ServerLog') 9 logger.setLevel(logging.INFO) 10 11 sys_handler = logging.handlers.SysLogHandler('/dev/log', facility=logging.handlers.SysLogHandler.LOG_LOCAL0) 12 syslog_tag = 'ServerLog' 13 sys_handler.setFormatter(logging.Formatter(syslog_tag + ":%(asctime)s - %(name)s - %(levelname)s - %(message)s")) 14 15 logger.addHandler(sys_handler) 16 return logger 17 18 def some_func(): 19 get_logger().info("call some_func") 20 21 if __name__ == '__main__': 22 some_func()
上面的代码修改了日志的输出形式，直观的感受就是从文件server.log 到了 /dev/log，但/dev/log对应的是SysLogHandler，并不是FileHandler，所以肯定不是一个普通的文件。此时，我有两个疑问：第一，这里我并没有将日志输出到home目录下的Server.log文件，但是程序运行的时候生成了这么一个文件；第二，怎么讲日志发送到数据分析部门的服务器。
不懂就问：
Q：新的代码下怎么生成Server.log文件，日志内容又是怎么转发到数据分析部门的服务器？
A: 这个是/etc/init.d/rsyslog这个后台程序根据/etc/rsyslog.conf 这个配置文件 将日志输出到不同的文件，包括网络文件，即其他服务器。看/etc/rsyslog.conf这个配置就明白了。
Q：OK，那python代码将文件输出到/dev/log跟 rsyslog又是什么关系呢？
A：python的sysloghandler会将日志发送到rsyslog，他们之间使用unix domain socket通信，具体看logging模块的源码就知道了
unix domain socket：
按照上面的对话的意思，python程序先将日志发送给rsyslog这个程序，然后rsyslog再处理收到的日志数据，所以先看logging代码：
SysLogHandler这个类在logging.handlers.py, 核心代码如下：
1 def __init__(self, address=('localhost', SYSLOG_UDP_PORT), 2 facility=LOG_USER, socktype=socket.SOCK_DGRAM): 3 """ 4 Initialize a handler. 5 6 If address is specified as a string, a UNIX socket is used. To log to a 7 local syslogd, "SysLogHandler(address="/dev/log")" can be used. 8 If facility is not specified, LOG_USER is used. 9 """ 10 logging.Handler.__init__(self) 11 12 self.address = address 13 self.facility = facility 14 self.socktype = socktype 15 16 if isinstance(address, basestring): 17 self.unixsocket = 1 18 self._connect_unixsocket(address) 19 else: 20 self.unixsocket = 0 21 self.socket = socket.socket(socket.AF_INET, socktype) 22 if socktype == socket.SOCK_STREAM: 23 self.socket.connect(address) 24 self.formatter = None 25 26 def _connect_unixsocket(self, address): 27 self.socket = socket.socket(socket.AF_UNIX, socket.SOCK_DGRAM) 28 # syslog may require either DGRAM or STREAM sockets 29 try: 30 self.socket.connect(address) 31 except socket.error: 32 self.socket.close() 33 self.socket = socket.socket(socket.AF_UNIX, socket.SOCK_STREAM) 34 self.socket.connect(address)
在__init__.doc里面写得很清楚，如果address是一个字符串（默认值是一个tuple），那么会建立一个unix socket（unix domain socket）。如果address为“/dev/log”（正如我们之前的python代码），那么输出到本机的syslogd程序。另外，在第27行 self.socket = socket.socket(socket.AF_UNIX, socket.SOCK_DGRAM) socket.socket的第一个参数family 的值为AF_UNIX，而不是我们经常使用的AF_INET(IPV4）或者AF_INET6(IPV6)。那么什么是unix domain socket呢？
unix domain socket是进程间通信（IPC：inter-process communication）的一种方式，其他还有管道、命名管道、消息队列、共享内存、socket之类的。unix domain socket与平常使用的socket（狭义的internet socket）有什么区别呢，那就是unix domain socket只能在同一台主机上的进程之间通信，普通的socket也可以通过'localhost'来在同一台主机通信，那么unix domain socket有哪些优势呢？
第一：不需要经过网络协议栈
第二：不需要打包拆包、计算校验和、维护序号和应答等
所以，优势就是性能好，一个字，快。
下面用一个简单的服务器客户端例子来看看unix domain socket的使用方法与过程：
服务器：uds_server.py
1 ADDR = '/tmp/uds_tmp' 2 3 import socket, os 4 5 def main(): 6 try: 7 sock = socket.socket(socket.AF_UNIX, socket.SOCK_STREAM) 8 if os.path.exists(ADDR): 9 os.unlink(ADDR) 10 sock.bind(ADDR) 11 sock.listen(5) 12 while True: 13 connection, address = sock.accept() 14 print "Data : %s" % connection.recv(1024); 15 connection.send("hello uds client") 16 connection.close() 17 finally: 18 sock.close() 19 20 if __name__ == '__main__': 21 main()
客户端：uds_client.py
1 ADDR = '/tmp/uds_tmp' 2 3 import socket 4 5 def main(): 6 sock = socket.socket(socket.AF_UNIX, socket.SOCK_STREAM) 7 sock.connect(ADDR) 8 sock.send('hello unix domain socket server') 9 print 'client recieve', sock.recv(1024) 10 sock.close() 11 12 if __name__ == '__main__': 13 main()
首先：运行服务器 python uds_server.py，这个时候在/tmp 目录下产生了文件，用ls查看详细信息如下：
可以看到，文件类型（第一个字段）为s，代表socket文件。（PS： 如果进程间用命令管道通信，也是利用中间文件，ls显示的文件类型为p）
运行客户端 python uds_client.py，在客户端和服务器端都有相应的输出，使用方法与普通socket没有什么大的差异。
日志转发流程：
在了解了unix domain socket这个概念之后，下面就比较简单了，首先是/dev/log这个文件，我们用ls来查看这个文件的信息
可以看到这个文件是一个符号链接文件，真实的文件是/run/systemd/journal/dev-log, 那么再来查看这个文件
ok，是一个socket文件，复合预期，按照之前的unix domain socket的例子，rsyslog也应该咋这个文件上监听，我们来看看
lsof fd可以列出所有使用了这个文件（linux下文件的概念比较宽泛）的进程，事实上我们看到只有systemd和systemd-j两个不明所以的进程。那么直接看看rsyslog使用的unix domain socket吧
额，可以看到rsyslogd使用的socket domain socket是/run/systemd/journal/syslog，并不是/run/systemd/journal/dev-log，这两个文件在同一个目录下，那么再来看看还有哪些进程使用了/run/systemd/journal/syslog。
so，systemd和rsyslogd都使用了这个文件，感觉像是应用进程(e.g. 上面的python程序）将日志通过/run/systemd/journal/dev-log（/dev/log背后真正的文件）发送到systemd， 然后systemd 再将日志通过/run/systemd/journal/syslog发送到rsyslogd，是不是这样呢，google了一下，发现了这篇文章understand-logging-in-linux，确实是这么一个过程：
systemd has a single monolithic log management program,
systemd-journald. This runs as a service managed by systemd.
- It reads
/dev/kmsgfor kernel log data.- It reads
/dev/log(a symbolic link to/run/systemd/journal/dev-log) for application log data from the GNU C library'ssyslog()function.- It listens on the
AF_LOCALstream socket at/run/systemd/journal/stdoutfor log data coming from systemd-managed services.- It listens on the
AF_LOCALdatagram socket at/run/systemd/journal/socketfor log data coming from programs that speak the systemd-specific journal protocol (i.e.sd_journal_sendv()et al.).- It mixes these all together.
- It writes to a set of system-wide and per-user journal files, in
/run/log/journal/or/var/log/journal/.- If it can connect (as a client) to an
AF_LOCALdatagram socket at/run/systemd/journal/syslogit writes journal data there, if forwarding to syslog is configured.
ok，到现在为止，我们知道了应用程序的日志是怎么转发到rsyslog，那么rsyslog怎么处理接收到的日志，秘密就在/etc/rsyslog.conf, 在打开这个配置文件之前，我们先看看rsyslog官网的简单描述：
RSYSLOG is the rocket-fast system for log processing.
原来R是rocket-fast的意思！火箭一般快！官网声称每秒可以处理百万级别的日志。rsyslogd在部分linux环境是默认的syslogd程序（至少在笔者的机器上），d是daemon的意思，后台进程。系统启动的时候就会启动该进程来处理日志（包括操作系统自身和用户进程的日志）。打开修改过的/etc/rsyslog.conf, 接下来就是见证奇迹的时刻
原来一举一动都在监控之中。这个文件是系统提供的，直接在这个文件上做修改显然不是明智之举。如上图红色部分，可以再rysyslog.d文件夹下增加自己的配置文件，定制日志过滤规则。那么看看的rsyslog.d文件夹下新增的tmp.conf
1 $FileOwner USERNAME 2 $FileGroup USERNAME 3 $FileCreateMode 0644 4 $DirCreateMode 0755 5 $Umask 0022 6 $template serverLog,"/home/USERNAME/Server.log" 7 $template LogFormat,"%msg% " 8 if $syslogfacility-text == 'local0' and $syslogtag contains 'ServerLog' then -?serverLog;LogFormat 9 10 #if $syslogfacility-text == 'local0' and $syslogtag contains 'ServerLog' then @someip:port 11 & stop
再来回顾一下对应的应用代码：
1 import logging 2 import logging.handlers 3 4 logger = None 5 def get_logger(): 6 global logger 7 if not logger: 8 logger = logging.getLogger('ServerLog') 9 logger.setLevel(logging.INFO) 10 11 sys_handler = logging.handlers.SysLogHandler('/dev/log', facility=logging.handlers.SysLogHandler.LOG_LOCAL0) 12 syslog_tag = 'ServerLog' 13 sys_handler.setFormatter(logging.Formatter(syslog_tag + ":%(asctime)s - %(name)s - %(levelname)s - %(message)s")) 14 15 logger.addHandler(sys_handler) 16 return logger 17 18 def some_func(): 19 get_logger().info("call some_func") 20 21 if __name__ == '__main__': 22 some_func()
注意：配置文件需要与应用代码配合，比如代码中第11行 facility=logging.handlers.SysLogHandler.LOG_LOCAL0 与 配置中 $syslogfacility-text == 'local0' 相对应；代码第12行 syslog_tag = 'ServerLog' 与 配置文件 $syslogtag contains 'ServerLog' 对应。关于python代码中syslogtag的设置，参考了stackoverflow上的这个问答。
当我们修改了配置时候需要通过命令 /etc/init.d/rsyslog restart 来重启rsyslogd，重启之后再运行之前的python文件，就可以了。
发送到远端服务器：
上面的tmp.conf文件注释掉了第10行，这一行的作用是将满足条件的日志发送到指定的其他机器上，IP：Port用来指定接受日志的远端rsyslogd程序。默认情况下rsyslogd在514端口监听。假设我需要给局域网内10.240.10.10发送syslog，第10行改成这样就行了：
if $syslogfacility-text == 'local0' and $syslogtag contains 'ServerLog' then @10.240.10.10
那么10.240.10.10主要开启rsyslogd的远程监听，并指定远端日志的输出规则，for example：
这个配置，让rsyslogd使用UDP和TCP协议同时在514端口上监听，并将非本机的日志输出到对应远端主机名的文件。注意，以上修改 都需要重启rsyslogd才能生效。
总结：
日志从应用程序到最终的日志文件（或者远程服务器）的流程如下：
