«

etcd 故障排查之 `database file (xxx) does not match with snapshot`

一次有一位同事找到我,说 etcd 抽风了,不断的重启,帮忙分析原因。

遇到这种问题,不用慌,软件抽风(故障)是常态,治它(当然,不一定什么抽风都能找到病因并治好...)

首先想到的排查方法当然是查看日志,同事首先附上了 kubelet 日志,毕竟所有的pod都是由 kublet 来调度的。

从当时 kubelet.log 中,并没看到不断重启的原因,所以直接看故障组件的日志——etcd。

此时出现故障的集群式etcd-event,换做 etcd-server 或 etcd-network也是一样。登录故障的节点,找到 etcd 所在日志目录,比如:

/var/paas/sys/log/etcd-event/

该目录下有两个日志文件:

  1. etcd-event-init.log: etcd 启动日志,在启动时,由相关启动脚本生成。
  2. etcd-event.log: etcd 运行日志,在运行时,由 etcd 服务生成。

一般,先看下启动日志,看是否有明显异常,这里暂时没发现。

接着,看运行日志,要从日志级别来区分对待。

先补充一个知识点,etcd 有7钟日志级别,如下:

const (  
    // CRITICAL is the lowest log level; only errors which will end the program will be propagated.
    CRITICAL LogLevel = iota - 1
    // ERROR is for errors that are not fatal but lead to troubling behavior.
    ERROR
    // WARNING is for errors which are not fatal and not errors, but are unusual. Often sourced from misconfigurations.
    WARNING
    // NOTICE is for normal but significant conditions.
    NOTICE
    // INFO is a log level for common, everyday log updates.
    INFO
    // DEBUG is the default hidden level for more verbose updates about internal processes.
    DEBUG
    // TRACE is for (potentially) call by call tracing of programs.
    TRACE
)

代码中解释的很直观,而在具体日志中,都是以缩写的形式显示,如下:

switch l {  
    case CRITICAL:
        return "C"
    case ERROR:
        return "E"
    case WARNING:
        return "W"
    case NOTICE:
        return "N"
    case INFO:
        return "I"
    case DEBUG:
        return "D"
    case TRACE:
        return "T"
    default:
        panic("Unhandled loglevel")
    }

DEBUG 级别的日志,需要在 etcd 启动时设置参数打开,通常输出都是 INFO 以上的级别日志,而我们重点要关注的就是 WARNINGERRORCRITICAL 这三种。

回到运行日志,就让我们看到一条 CRITICAL 级别的日志:

2018-05-15 16:00:45.985584 C | etcdmain: database file (/var/etcd-data/etcd-event/etcd-event-2/member/snap/db index 16737187) does not match with snapshot (index 21909430).  

有日志就有方向了。从日志描述直观的想法就是,该节点中的 etcd 数据被破坏了。

因为是测试环境,可以先验证一把,再确认是否是数据原因。

日志中显示的路径是 etcd 容器中的路径,我们要找到对应在宿主机上的路径:

cd /var/paas/run/etcd-event  

在该目录下,有etcd对应的数据,目录结构一般长成这个样子

etcd-event-2/  
|-- config.ini
`-- member
    |-- snap
    |   |-- 000000000000082e-0000000000367bd9.snap
    |   |-- 0000000000000835-0000000000ff63a3.snap
    |   |-- 0000000000000835-0000000001112aae.snap
    |   |-- 0000000000000835-0000000001301526.snap
    |   |-- 0000000000000835-00000000014e4fb6.snap
    |   |-- 0000000001112aae.snap.db
    |   |-- 0000000001301526.snap.db
    |   |-- 00000000014e4fb6.snap.db
    |   `-- db
    `-- wal
        |-- 000000000000001d-00000000010e01cd.wal
        |-- 000000000000001e-00000000011f9d5e.wal
        |-- 000000000000001f-000000000130ecce.wal
        |-- 0000000000000020-0000000001423204.wal
        |-- 0000000000000021-000000000154852e.wal
        |-- 0000000000000022-00000000016650d1.wal
        `-- 0.tmp

出问题的数据就在这个 etcd-event-2/member/snap/db 上。

因为 etcd 是由三台集群搭建,数据是会相互同步的,我们先把这台节点上的数据目录移除(稳妥点只要改个名就好),之后它会从其它两个节点拉取数据(注意此时可能会比较消耗网络):

mv etcd-event-2 etcd-event-2-old  

等待 etcd 重启(kubelet会将其重新拉起),或手动重启,稍等 etcd 同步数据完成,再次查看 etcd 的运行日志,发现已经没有该条 CRITICAL 日志,查看 etcd 数据目录,发现重新生了数据目录

/var/paas/run/etcd-event/etcd-event-2

此时查看 etcd 状态,确保正常运行,不断 crash 并重启的问题随之也消失了。

分享