首页 > 代码库 > 由一个简单需求到Linux环境下的syslog、unix domain socket

由一个简单需求到Linux环境下的syslog、unix domain socket

 

  本文记录了因为一个简单的日志需求,继而对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 logger13 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 = ServerLog13         sys_handler.setFormatter(logging.Formatter(syslog_tag + ":%(asctime)s - %(name)s - %(levelname)s - %(message)s"))14 15         logger.addHandler(sys_handler)16     return logger17 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 = address13         self.facility = facility14         self.socktype = socktype15 16         if isinstance(address, basestring):17             self.unixsocket = 118             self._connect_unixsocket(address)19         else:20             self.unixsocket = 021             self.socket = socket.socket(socket.AF_INET, socktype)22             if socktype == socket.SOCK_STREAM:23                 self.socket.connect(address)24         self.formatter = None25 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 sockets29         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/kmsg for 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‘s syslog() function.
  • It listens on the AF_LOCAL stream socket at /run/systemd/journal/stdout for log data coming from systemd-managed services.
  • It listens on the AF_LOCAL datagram socket at /run/systemd/journal/socket for 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_LOCAL datagram 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

$FileOwner USERNAME$FileGroup USERNAME$FileCreateMode 0644$DirCreateMode 0755$Umask 0022$template serverLog,"/home/USERNAME/Server.log"$template LogFormat,"%msg%\n"if $syslogfacility-text == ‘local0‘ and $syslogtag contains ‘ServerLog‘ then -?serverLog;LogFormat& stop#if $syslogfacility-text == ‘local0‘ and $syslogtag contains ‘ServerLog‘ then @someip:port#& 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 = ServerLog13         sys_handler.setFormatter(logging.Formatter(syslog_tag + ":%(asctime)s - %(name)s - %(levelname)s - %(message)s"))14 15         logger.addHandler(sys_handler)16     return logger17 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文件,就可以了。

   技术分享

 

总结:

  日志从应用程序到最终的日志文件(或者远程服务器)的流程如下:

  技术分享

  

references:

inter-process communication

unix domain socket

understand-logging-in-linux

由一个简单需求到Linux环境下的syslog、unix domain socket