首页
学习
活动
专区
工具
TVP
发布
社区首页 >专栏 >docker日志丢失问题分析

docker日志丢失问题分析

作者头像
jeremyxu
发布2019-03-13 14:39:34
5.1K0
发布2019-03-13 14:39:34
举报

今天在工作遇到一个docker日志丢失的问题,最终一步步查找到原因了,这里记录一下过程。

问题

工作中把自己写的应用部署到kubernetes中后,用kubectl -n some-ns logs some-pod -c one-container命令查看不了该pod中container的日志,而用该命令去查看其它pod的日志,是可以正常显示的。

跟踪原因

首先怀疑是应用本身的程序问题,将应用在本机运行了一下,是可以正常输出日志到标准输出的。

接下来怀疑是kubernetes本身的问题,于是在kubernetes的某个节点上直接用docker命令运行起容器:

docker run --name some-name -d some-image
docker logs some-name # 这里还是没有输出日志

看来跟kubernetes无关,直接用docker run跑容器都没有输出日志啊。

不过一想应该docker本身应该不会存在这么大的问题,再做一个实验,同样的镜像,在我本机的docker环境中运行试一下:

docker run --name some-name -d some-image
docker logs some-name # 这里输出了日志

看来是服务器上的docker环境有些毛病。

然后看看docker的日志配置:

cat /etc/sysconfig/docker
...
OPTIONS='--selinux-enabled --log-driver=journald --signature-verification=false --graph=/data/docker'
...

docker的配置里是将日志发送到journald的,于是看下docker服务本身的日志:

journalctl _SYSTEMD_UNIT=docker.service

观察日志,日志发送应该是没有什么问题的。

接下来看看journald服务的日志:

journalctl _SYSTEMD_UNIT=systemd-journald.service
...
Jan 10 19:18:50 tshift-master systemd-journal[547]: Suppressed 1833 messages from /system.slice/docker.service
Jan 10 19:19:20 tshift-master systemd-journal[547]: Suppressed 1849 messages from /system.slice/docker.service
Jan 10 19:19:50 tshift-master systemd-journal[547]: Suppressed 1857 messages from /system.slice/docker.service
Jan 10 19:20:20 tshift-master systemd-journal[547]: Suppressed 2010 messages from /system.slice/docker.service
Jan 10 19:20:50 tshift-master systemd-journal[547]: Suppressed 1820 messages from /system.slice/docker.service
...

这里可以看到有大量的Suppressed xxx messages from /system.slice/docker.service的日志,从字面意思来理解,有很多日志被抑制了。

为啥会出现这种问题呢?参阅journald.conf的官方文档,可以看到下面这段话:

man journald.conf ... RateLimitInterval=, RateLimitBurst= Configures the rate limiting that is applied to all messages generated on the system. If, in the time interval defined by RateLimitInterval=, more messages than specified in RateLimitBurst= are logged by a service, all further messages within the interval are dropped until the interval is over. A message about the number of dropped messages is generated. This rate limiting is applied per-service, so that two services which log do not interfere with each other's limits. Defaults to 1000 messages in 30s. The time specification for RateLimitInterval= may be specified in the following units: "s", "min", "h", "ms", "us". To turn off any kind of rate limiting, set either value to 0. ...

也就是说docker这个服务输出日志超出了每30秒1000条的速率限制,因此超出部分的日志被journald丢弃了。

那么docker服务真的输出日志速率这么快吗?我这里用命令计算一下:

journalctl _SYSTEMD_UNIT=docker.service --since "2019-01-11 23:00:00" --until "2019-01-11 23:05:00" | wc -l
10011 # 10011/(5*60) * 30 = 1000

这样看来,docker服务输出日志的速度果然超出限制了。

解决办法

既然是docker服务输出日志的速率超限,自然有两种解法:降低docker日志的输出速率、增大journald的速率限制。

降低docker日志的输出速率

使用以下命令可以看到docker服务输出的日志:

journalctl _SYSTEMD_UNIT=docker.service --since "2019-01-11 23:00:00" --until "2019-01-11 23:05:00"

从命令的输出来看,基本都是一些容器的标准输出,而刚好出问题的服务器上运行了大量容器,而且有些容器确实在大量输出日志。当然改法自然是调整这些容器的程序,一般来说就是设置更合理的日志级别。

增大journald的速率限制

如果服务器上运行了大量容器,每个容器输出一些日志,这些日志加起来也很容易超过journald的速率限制。因此还可以直接增大journald的速率限制。

# 直接修改/etc/systemd/journald.conf,增大RateLimitBurst配置项的取值,修改完毕后重启journald服务
vim /etc/systemd/journald.conf
systemctl restart systemd-journald

其它

journald配置文件的优化

在修改journald.conf里,发现其某些配置项并不合理,可以参考这里优化一下。

增大journald的速率限制的其它办法

查看journald.conf配置文件的文档时,还发现对于较新版本的systemd来说,可以只修改某个服务对应的日志速率限制参数,这样不用修改journald.conf影响全局,可惜这个特性只有较新版本的systemd才有。

RateLimitIntervalSec=, RateLimitBurst= Configures the rate limiting that is applied to all messages generated on the system. If, in the time interval defined by RateLimitIntervalSec=, more messages than specified in RateLimitBurst= are logged by a service, all further messages within the interval are dropped until the interval is over. A message about the number of dropped messages is generated. This rate limiting is applied per-service, so that two services which log do not interfere with each other’s limits. Defaults to 10000 messages in 30s. The time specification for RateLimitIntervalSec= may be specified in the following units: “s”, “min”, “h”, “ms”, “us”. To turn off any kind of rate limiting, set either value to 0. If a service provides rate limits for itself through LogRateLimitIntervalSec= and/or LogRateLimitBurst= in systemd.exec(5), those values will override the settings specified here.

总结

docker的日志输出逻辑还是比较清晰的,这里就不具体介绍了,参考官方文档就可以了,出了问题冷静一步步分析还是很靠谱的。

参考

  1. https://docs.docker.com/config/containers/logging/configure/
  2. https://wizardforcel.gitbooks.io/vbird-linux-basic-4e/content/160.html
  3. https://docs.lvrui.io/2017/02/19/%E6%9B%B4%E6%94%B9docker%E7%9A%84%E6%97%A5%E5%BF%97%E5%BC%95%E6%93%8E%E4%B8%BA-journald/
  4. https://www.freedesktop.org/software/systemd/man/journald.conf.html
  5. https://www.freedesktop.org/software/systemd/man/systemd.exec.html
  6. https://bani.com.br/2015/06/systemd-journal-what-does-systemd-journal-suppressed-n-messages-from-system-slice-mean/
  7. https://www.sulabs.net/?p=828
  8. https://www.howtoing.com/how-to-use-journalctl-to-view-and-manipulate-systemd-logs
本文参与 腾讯云自媒体分享计划,分享自作者个人站点/博客。
原始发表:2019-01-12,如有侵权请联系 cloudcommunity@tencent.com 删除

本文分享自 作者个人站点/博客 前往查看

如有侵权,请联系 cloudcommunity@tencent.com 删除。

本文参与 腾讯云自媒体分享计划  ,欢迎热爱写作的你一起参与!

评论
登录后参与评论
0 条评论
热度
最新
推荐阅读
目录
  • 问题
  • 跟踪原因
  • 解决办法
    • 降低docker日志的输出速率
      • 增大journald的速率限制
      • 其它
        • journald配置文件的优化
          • 增大journald的速率限制的其它办法
          • 总结
          • 参考
          相关产品与服务
          容器镜像服务
          容器镜像服务(Tencent Container Registry,TCR)为您提供安全独享、高性能的容器镜像托管分发服务。您可同时在全球多个地域创建独享实例,以实现容器镜像的就近拉取,降低拉取时间,节约带宽成本。TCR 提供细颗粒度的权限管理及访问控制,保障您的数据安全。
          领券
          问题归档专栏文章快讯文章归档关键词归档开发者手册归档开发者手册 Section 归档