前言

在通过docker logs(m log是我自己创建的一个别名,等于docker logs)查看日志时,发现经常出现读不出来,或者只读出来一部分的情况。如下图:

  1. Error grabbing logs: error finding file position to start log tailing: unexpected number of bytes read from log message header.
  2. unexpected EOF
  3. Error grabbing logs: log message is too large (1952739189 > 1000000)

经过调查,有以下几种原因:

  1. Docker版本过低。目前已经对盒子上的docker版本进行了更新,现在都是24版本以上,不再存在本问题。
  2. 内存不足,这个只能通过增大内存解决。
  3. 运行过程中突然断电导致日志记录出现不完整的一条记录,导致日志无法读取。

本文针对第三种情况,记录如何排查并解决该问题。


正文

Docker的日志驱动有很多种,默认是json格式的日志。其优点是可读性强,直接拉取日志文件就可以清楚的看到日志的时间、内容等。缺点是占用空间大,性能差。因此,我们在船上的盒子里面使用的是local格式的日志。该格式除了日志本身的内容以外,是不可读的,但占用空间小,效率高,如下图:

docker 容器中的日志会自动清理吗 docker容器日志位置_docker 容器中的日志会自动清理吗


首先,需要找到损坏的日志文件。假设我们要读取的容器是cam0,那么要先通过docker ps命令找到它的container id。

docker 容器中的日志会自动清理吗 docker容器日志位置_容器_02

然后,进入到/var/lib/docker/container/{container_id}/local-logs/目录下(需要root权限),即可看到日志文件。

docker 容器中的日志会自动清理吗 docker容器日志位置_运维_03

第一次尝试

由于每一条日志Docker都会记录其发生的时间,并且精确到了纳秒级,因此我猜测他应该是使用的double格式记录的。通过vscode的hex编辑器打开日志,截取出其中几条日志,可以发现,每条日志的前24个字节,和最后4个字节是Docker生成的。其中前四个字节猜测为U32,代表数据长度。

docker 容器中的日志会自动清理吗 docker容器日志位置_docker_04

在这前面的24个字节中,我按照大端、小端模式,分别查看了每一种可能,发现按double解析出来,都不是时间戳。虽然知道时间戳就隐藏在这24字节中,但无论按哪种方式解析都无法和时间戳对应。因此这种方式以失败告终。

第二次尝试

既然Docker cli能解析日志,那么他的源码里面肯定有解析方法。所以我就开始扒源码,费尽千辛万苦,终于找到了解析代码。源码地址:https://github.com/moby/moby。查看daemon/logs.go文件,可以找到获取log的源码:

docker 容器中的日志会自动清理吗 docker容器日志位置_容器_05

这个函数前半部分都是在解析参数,像since、until之类的。直接看核心代码:

docker 容器中的日志会自动清理吗 docker容器日志位置_容器_06

然后找Readlogs的定义:

docker 容器中的日志会自动清理吗 docker容器日志位置_docker 容器中的日志会自动清理吗_07

可以看到实际上调用的是readLogsLocked,继续找:

docker 容器中的日志会自动清理吗 docker容器日志位置_容器_08


docker 容器中的日志会自动清理吗 docker容器日志位置_Docker_09


docker 容器中的日志会自动清理吗 docker容器日志位置_容器_10


终于找到关键了!看起来是一个protocol buffer格式,下一步搜索LogEntry,终于找到了他的原型:

docker 容器中的日志会自动清理吗 docker容器日志位置_Docker_11

接下来按照这个proto解析日志,发现果然可以成功解析!最开始的截图里面的日志,解析出来结果如下:

docker 容器中的日志会自动清理吗 docker容器日志位置_docker 容器中的日志会自动清理吗_12

解析解本

若因为异常断电导致日志无法读取,则是因为异常断电导致日志记录出错,出现protobuf无法解析、header中记录的日志长度超过限制等。因此我们可以跳过这些异常的日志,然后读取其余部分,避免完全不可读的情况。下面给出了一个Python脚本,大家可以自行尝试。

import datetime
import entry_pb2 as pb
import struct

with open('container.log', 'rb') as f:
    data = f.read()

i = 0
while i < len(data):
    try:
        size = struct.unpack('>I', data[i: i+4])[0]
        if size > 1000000:
            i += 1
            continue
        buf = data[i + 4: i + size + 4]
        log = pb.LogEntry()
        log.ParseFromString(buf)
        print(datetime.datetime.fromtimestamp(log.time_nano / 1000000000).strftime('%Y-%m-%d %H:%M:%S'), f'\t{i}\t', log.line.decode())
        i += 8 + size
    except:
        i += 1