Docker遇到Syslog的踩坑小记

霍明明 360云计算

女主宣言:

Docker 作为时下最火爆的容器技术，我们HULK虚拟化团队也推出了基于docker+k8s的stark容器管理平台，当前已经开始为业务部门提供容器化服务。
该文章就是基于业务部门在使用过程中遇到的日志问题展开的，主要描述了 Docker 中启动syslog记录日志时候遇到的坑，坑，坑。最终刨根问底给出了解决方案，希望能给大家一些启发。
PS：丰富的一线技术、多元化的表现形式，尽在“HULK一线技术杂谈”，点关注哦！

1.背景描述

一天，小刚在群里吼说：“ 亲们，我在Docker（CentOS:7.2）容器中，想调用syslog记录信息，是这样做的：我自己在容器中启动了rsyslogd，之后记录普通info级别信息，但是我在/var/log/messages中看不到，我检查了rsyslog.conf没有发现问题，请问亲们知道这个是为什么吗？ ”

我的第一反应是权限的问题，然后在群里对吼了一句：“很可能是权限的问题，启动容器时加一下--privileged试试呢？ ”

然后，小刚就屁颠屁颠去试了。过了不一会儿，小刚又在群里吼说：“还是不行哈！这可咋整？你们给看一下吧！！！”

我擦，顿时脑子有点懵B：“看来问题没这么简单哈。需要好好看看。”

2.排查过程

我赶紧使用CentOS7.2 的镜像启动个容器安装 rsyslog也感受一下。不试不知道，一试问题还不少。容器里居然没有 systemd，使用systemctl start rsyslog 启动 rsyslog 服务时报“Failedto get D-Bus connection: Operation not permitted”异常。也就是说当前的用户没有权限执行该操作。 CentOS7的坑真多，一个问题一个问题解决吧。

思路一

啥都不说，加--privileged试试，居然还是不行，汗！Google了一把，搜出一票来（大部分是雷同转载），扫了一遍，对于容器内部 systemd 不能使用，官方的理由是：

systemd requires the CAP_SYS_ADMIN capability. This means runningdocker with --privileged. Not good for a base image.
systemd requires access to the cgroups filesystem.
systemd has a number of unit files that don’t matter in a container, andthey cause errors if they’re not removed

总的来说还是权限的问题，处于安全的考虑，很多capability 宿主系统是没有直接放开给默认启动的容器的。
那为啥我加了--privileged 特权还是无法使用 systemd呢？搜了一下，看大家都是在 dockerrun 时执行CMD为/sbin/init 就可以了
例如： dockerrun --privileged -itd centos:latest /sbin/init，看下/sbin/init 是什么：

[root@1626f8dee274 /]# ll /sbin/initlrwxrwxrwx. 1 root root 22 Apr  1 01:02 /sbin/init -> ../lib/systemd/systemd

是 systemd的软连，还是不太明白，为什么必须启动进程为systemd才可以。难道 systemd 和rsyslog 有什么特殊的关系？经过一番倒腾没找到这俩东东有啥必然的关系，放弃这条路，继续找…..

思路二
在走头无路的时候，我突然想起来，官方 DockerHub 应该会有 CentOS 7 的 rsyslog 镜像吧，搞一个下来，研究研究不就知道了，太疯狂了，高兴地不得了。赶紧搞个镜像试试：
以下是我搜到的官方rsyslog的镜像列表

[root@docker01 huomingming]# docker search rsyslog.......quiver/rsyslog    Rsyslog for CentOS 7    0      [OK]........

拉取了标红的镜像 quiver/rsyslog 创建容器看了一下，容器正常启动，rsyslog 也正常工作，docker inspect 看了一下该镜像没有发现做过什么特殊设置。奇了怪啦！它是怎么做到的？
检查下rsyslog版本，我擦，有新发现，版本不一样，哈哈，难道是版本的问题？不说了，赶紧试试这个版本吧。他用的版本是：rsyslog-7.6.7-1.el7.x86_64，我们镜像中yum install后安装的版本是rsyslog-7.4.7-12.el7.x86_64。
快来尝尝鲜！经过一番折腾（国外的源，不解释…...）终于安装完成，更令人兴奋的是居然working、working、working……
到此，我认为终于可以松一口气了，升级一下rsyslog版本呗，先让业务用着，然后我再慢慢去刨根问底儿。

刨根问底

技术人员总有一种情怀，那就是----不抛弃不放弃，遇到问题总要搞个明白。为了找到问题的根源，我进行了如下尝试：
strace 跟踪 rsyslogd 进程的系统调用，用 logger 给 rsyslog 发送数据，然后观察是否有数据写入。
了解 rsyslog 工作原理，从 rsyslog 本身去寻找原因。
第一个方法并没有任何收获，正常工作的rsyslog和不正常工作的rsyslog都没有任何信息。此路放弃。
然后依然决然的去了解了一下rsyslog的工作原理，其实最想搞明白的就是“系统日志是如何与 rsyslog 交互的？如何将数据写入 rsyslog 的？”知道了这些问题，也就能更好的理顺整个流程。
经过一番学习，焦点定位到了 rsyslog配置文件 /etc/rsyslog.con 中的下面几项配置：

#### MODULES ##### The imjournal module bellow is nowused as a message source instead of imuxsock.$ModLoad imuxsock # provides supportfor local system logging (e.g. via logger command)$ModLoad imjournal # provides accessto the systemd journal#$ModLoad imklog # reads kernelmessages (the same are read from journald)#$ModLoad immark  # provides --MARK-- message capability

很明显，这里标红的部分很明确的告诉了我们系统日志是如何写入到 rsyslog中的。
对，就是通过这个模块imuxsock完成的。从字面来看应该是通过socket来通信的，顺着这条思路继续往下缕，然后找到一篇文章，其中开篇是这样一句：“imuxsock模块提供通过本地 Unix sockets 访问 syslog 消息的能力。最重要的，这是 syslog 递送信息给 rsyslog 的机制，所以需要加载这个模块来读取系统日志socket，并处理本地运行的应用的日志。
先看看我的 rsyslog是否加载了该模块

[root@5aac1f6eb4cc /]# lsof | grepimuxsock.sorsyslogd   38    root  mem    REG              253,5   426504 58766264/usr/lib64/rsyslog/imuxsock.soin:imuxso  38  39root  mem    REG              253,5   426504 58766264/usr/lib64/rsyslog/imuxsock.sors:main    38 40 root  mem    REG              253,5   426504 58766264/usr/lib64/rsyslog/imuxsock.so

恩，已经加载了，放心了。再看看对应的 UNIX 域套接字是否存在

[root@5aac1f6eb4cc /]# netstat -anlpActive Internet connections (serversand established)Proto Recv-Q Send-Q Local Address           Foreign Address         State       PID/Program name   Active UNIX domain sockets (serversand established)Proto RefCnt Flags      Type       State         I-Node   PID/Program name    Path

我擦，居然没有，抓紧看看正常运行的容器里面是否有，标红部分即是.
[root@1e603440b4a9 /]# netstat -anlp
Active Internet connections (serversand established)
Proto Recv-Q Send-Q LocalAddress Foreign Address State PID/Program name
Active UNIX domain sockets (serversand established)
Proto RefCnt Flags Type State I-Node PID/Program name Path
unix 2 [ ] DGRAM 1694177 38/rsyslogd /dev/log

NM，居然有，此时有一种“柳暗花明又一村”的赶脚，感觉我找到问题的真谛了！！！
从上面我们可以看到这个 UNIXSocket 的路径为/dev/log：这是一个UNIX域套接字,这个套接字用来接收任何系统程序发送来的日志事件并将事件传递给 syslogd或者 rsyslogd 守护进程。原文是

“itreceives log events from any system program and sends the events to the syslogddaemon.”。

这个套接字会在两个地方被创建：一是 rsyslog 启动时创建；二是 systemd 启动时创建。
其实从这里再回头看 docker run --privileged -itd centos:latest /sbin/init 方式启动容器为啥可以的话，就会知道原来是 systemd 创建了 /dev/log 套接字，那，我们启动 rsyslog 时为啥就没创建成功呢？原因可能有多种：
rsyslog 对 /dev/log 套接字创建逻辑的bug。
Docker 权限限制
Docker 内启动 rsyslog 服务时权限不够。
具体是什么原因，下篇博文给出答案及分析。

3.小结

以上是对 Docker 中运行 rsyslog 问题的一个处理过程。类似这种问题的处理，通常先是从 Docker 本身的限制出发去寻找问题的原因，在排除 Docker 本身问题后，再从应用本身或者环境角度去考虑可能的原因，最终经过排查一步一步找到问题的根源。虽然经过3年的锤炼，Docker 正逐步的转变为基础架构的重要组成部分，但在实际使用过程中依然会有很多问题，而这些问题需要我们大家共同努力去不断的发掘、摸索和分享，为加快 Docker 的落地做一点贡献。

Docker遇到Syslog的踩坑小记