钛节点

浅显地聊一聊中小公司的日志系统与Tracing（上）

发表@2022-04-09 15:15:53

更新@2023-04-27 21:10:51

嗨，大家好，我是说发文章就发文章的谢顶道人 --- 老李，我最近赢得了一个称号：下周发文谢顶老道，和下周回国那位快打平了。

我最近被催的要死要活的，所以我必须要写一篇接地气的关于工程应用领域的文章，我想来想去：就写一下我最近正好简单调研过的日志吧，而且是中小公司的日志，我结合自己过往的经历来很主观地唠唠日志系统。

老李环顾了一下四周，看看大伙儿都在说什么，比如这位：

![](https://ti-node.com/static/upload/PNP/a/img_87.png#width-full)

又比如这些后台里发消息的宝贝儿们：

![](https://ti-node.com/static/upload/PNP/a/img_93.png#width-full)

当然了，还有一些给我发电视剧剧照的：

![](https://ti-node.com/static/upload/PNP/a/img_89.png#width-full)

日志，一坨彼此之间物理上毫无关联的离散状态的字符串。首先我们需要统一思想：当业务系统遇到任何问题时候只能依靠日志中的蛛丝马迹去追查原因，所以日志必须要记录得好且全、记录得有格式化且有意义，而且有些错误即便在日志做到了前面两个得的前提下，也依然不好查询到原因，宛如隐疾定时炸弹。

本文简要目录：
一、统一思想
二、小公司的合理做法
三、中小公司在带有一丝丝服务拆分时的合理做法
四、延伸：MOMO和打车公司的解决思路

### 让我们先统一好思想

我在此将日志分为两类：

一、系统级系统：大家做的基本上都是服务器编程，所以我认为每条网络请求的日志都应该一条不落的记录下来，注意是一条不落，具体实现方式就是在请求收口处/拦截器/中间件处去统一收敛处理；除此之外，系统级日志还包括框架本身在遇到代码错误或异常时，框架记录的日志（比如Go可能出现的Panic、Java中可能出现的OOM、连接数据库失败等等）。

二、业务级日志：可能有人觉得上面每条网络请求的日志应该属于业务日志，我觉得无可厚非，以你为准。我所认为的业务日志是泛指业务研发在业务代码中为了便于调试或者发现问题而留下的Log::info()。

我在此说下我对所谓好的日志的理解与定义：

一、「系统与业务日志」统一格式化：JSON或者约定间隔符号比如||、或者双||，且日志尽量要以为key:value键值对方式，JSON是最粗暴的懒人做法

二、「系统日志」必含字段：注意此条只针对系统日志，至少应该包含请求接口名称（API）、请求方IP（Caller）、请求方入参数（Args）、服务方的返回结果（Resp）与本次调用耗费的时间（Took-Sec）。如果是HTTP服务，甚至HTTP Header也是有必要留下的

三、「系统与业务日志」必含字段之Request-ID：无论是系统日志还是业务日志，都应该记录该请求的Request-ID，Request-ID一定要由客户端去产生，接入层可以做兜底补充，这样客户端的请求可以与该请求在后续产生的所有日志很容易很自然的串联起来，这个问题我觉得不要问为什么或者是否有必要（文章后面我们会讨论在涉及到一定量微服务时候关于Tracing与日志讨论）

五、「系统与业务日志」必含字段之UID或者DID（设备ID）：在可以拿到UID的情况下一定要拿到UID并作为必需字段注入到日志中。为什么？因为很多时候锁定用户业务问题之前，你需要率先通过时间范围 + UID去搜索出用户在该时间段内所产生所有的接口访问记录；而在某些情况下无法得到用户UID的时候，DID则是必要补充手段（比如登陆时，用户可能就是没有UID的，此时DID则成了救命稻草）

六、日志目录统一化：这个仅仅是推荐，但并不强制。目录统一化的好处是对于日志收集工具、日志grep工具等会友好一些，我认为此项属于option选项，并不用强制化

七、日志组件统一化：其实一到六的所有问题，通过一个统一的日志组件就可以一劳永逸地全部解决掉。日志组件不需要你自己发明，直接找开源的包裹一下，适配一下自己的业务系统即可

我在此将故障分为两类：

一、系统级故障：我们认为此时由于各种各样的致命级错误，导致服务代码无法完成，比如PHP的Fatal级错误、Go中Panic等等

二、业务级故障：这应该是我们最常遇到的错误，也是最棘手的错误，本质上也不算错误，其实就是系统运行结果与用户操作预期不符合。比如用户下单，优惠券用上了说好要付10块，结果付了12块；或者用户预期看到的是结果A，结果返回的结果是B。此时系统并没有崩溃，只是业务代码中纰漏导致了最终结果

### 单体架构的小公司

明智的小公司业务系统跟业务量相对应，一般都是单体架构，后端研发人员数量大概在10-30人左右（上下误差10左右），此阶段最好的选择是云服务商的云日志服务，次级选择是自建ELK，最次是登陆到服务器上去查看日志（这种情况下如果有两台以及以上服务器，恐怕是很痛苦的一件事，有些同学此时会甚至编写网络版的grep工具在跳板机上去grep所有机器上的日志）。

所以针对这种情况，解决方案很简单：

一、第一步：如果认同前面「日志分类」与「良好日志格式」的同学，先实现这里或者实现以你为准的日志，总之目的只有一个---良好且有意义的日志

二、第二步：选择日志数据收集系统与检索系统，我认为按照顺序是云服务日志平台 > 自建ELK > 自己登陆到服务器上搞

在建设完成的情况下，一般遇到问题需要诊断时候：

一、如果是针对用户无法Request-ID时候，需要结合时间范围+UID锁定用户去搜索出用户在该时间段内产生的API请求记录，然后结合遇到问题的业务场景（也就是网页界面或者APP界面）锁定N条API请求，根据Request-ID查看本次请求中产生的所有日志，继而进一步锁定故障原因

二、如果是可以确定的某一条Request-ID请求，往往出现在测试或者联调阶段，这种的直接利用Request-ID搜索即可

### 带有一丝丝服务化性质的中小公司

具备一定的业务流量的中型公司，同时由于业务上已经具备了一定复杂程度做了一定的服务化措施，已经将一些较为公共的代码已经单独实现为独立的小服务，技术团队人数在百人规模左右。

一、第一步：如果认同前面「日志分类」与「良好日志格式」的同学，先实现这里或者实现以你为准的日志，总之目的只有一个---良好且有意义的日志

二、第二步：一定要选择云服务商提供的日志服务

查询与锁定问题的方式基本上与前面描述一致，相信聪明的你们也各有各的方式。但是，截止到目前这个规模，对日志链路记录与链路还原，已经产生一定量但并不一定是必需的诉求，什么意思呢？

老李举个例子，先来看一下中小规模公司可能出现的业务系统组织方式：

![](https://ti-node.com/static/upload/PNP/a/img_90.png#width-full)

在这种情况下，A、B、C与原巨无霸系统任意一个服务节点如果由于业务代码逻辑问题出现的业务故障（非系统故障，参考文前统一思想处的故障分类），都一定会导致最用户获得的实际结果与预期不符。

但是还好，不怕出问题，就怕出了问题不好查，查了赶紧修复止损就是好同志。截止到目前为止，如果你认同我所说的日志中必要字段之Request-ID，我觉得在这个业务故障是很容易被发现并锁定的。因为Request-ID可以串联出本次请求中所到达的服务节点中所有服务所产生的每一条请求日志，总结一下：

一、原巨无霸系统、A、B、C的系统日志中均记录每一条请求

二、每一条系统日志均包含至少入参（Args）与返回结果（Resp）

三、这些分散隔离的日志被必含字段Request-ID可以串联起来

因为你的业务日志以及系统日志满足上面三点，所以你可以很快锁定到底是哪一部分出了问题。你只需要在日志云服务或自建ELK上根据UID + 时间锁定API调用记录范围 ---> 锁定某条确定的API调用记录 ---> 根据Request-ID锁定所有日志，三步锁定故障范围。

截止到目前为止，上面的这套标准与守则，在一个标准Log组件与日志存储检索服务的合理搭配下，是完全可以极其快速并高效完成绝大多数业务故障。

并且如果你们严格遵守上面我们说好的约定，甚至还会有意外收获。不知道你还是否记得我们在日志中记录了一个Took-Sec，此时我们可以每天定时对这些日志进行离线抽样分析汇总，我们可以得到服务对外接口的平均耗时与接口调用占比，最终甚至可以得到访问量排名前N的接口的平均耗时为多少。

因为我们的日志中，还包含了系统故障日志，所以甚至可以在日志中出现故障时，及时发出报警。或者在某一次上线后，发现某个接口的平均耗时比昨天增加了XXX，这种情况也可以配置触发报警。

是的，合理的利用好「好的」日志可以几乎搞定一切，本质上说即便是Trace信息抑或Metric信息，说到底也是由文本记录的信息进行时序汇总分析后的结果，说不好听了：就是特立独行化的日志。

好了，有点儿跑偏了，让我们回到正途。

### 总结一下

上面的日志系统看起来不错吧？一个Request-ID帮了我们很多忙，现在我想给这个Request-ID去启用另外一个名字：TraceId。所以让我们再来一遍：一个TraceId帮了我们很多忙。但是这就满足了吗？并没有，我来说下缺陷是什么。

首先，由于业务系统相对不那么复杂，这个TraceID足以应付，但是实际上无论你用ELK或者日志云服务，都会存在两个至少会出现其一的问题：

一、如果A、B、C与原巨无霸服务的日志都存储在同一个空间中，根据TraceID搜索出的日志会出现一个网页中，由于服务不多，你还是可以用肉眼人脑人肉的方式去组织一下日志的调用顺序与调用层次关系，但是总归是需要你用人肉方式去还原

二、如果A、B、C与原巨无霸服务的日志是分开存储的，分别存储在自己的存储空间内，恭喜你，你需要拿这个TraceID分别打开个Tab页去搜索四个系统的日志，然后再人肉串联。同时记得，不要忘了找运维给你开通云服务的权限

那么有更好的方式去还原请求发生时日志的时序顺序与调用层次顺序吗？比如我用图来简单勾勒一下上面图中业务系统一次请求所产生的日志应该是怎样展现会更好：

![](https://ti-node.com/static/upload/PNP/a/img_91.png#width-full)

不好意思，灵魂画手了一把。图想表达的意思就是：通过在一个搜索框中输入TraceID进行搜索，与本次TraceID会话产生的所有日志均将被搜索到，并且按照时间顺序与调用层次关系，展现在同一个网页中，你只需要拖动鼠标依次展开每条日志，很方便的就能看到每个服务日志的入参与返回，甚至可以反馈出耗时图形。

有办法可以按照上面的方式去还原一个请求产生的日志历史现场吗？有。如果说可以直接利用的话，那就是可以借鉴一下Tracing机制，这个东西又有另外一个名字：分布式链路跟踪系统。

无论是老李之前在MM还是在互联网打车公司，那个日志系统做的堪称一绝，一些同学在离职后直呼当初没有研究一下那玩意，面对新入职的公司日志只能陷入无限怀念中：

![](https://ti-node.com/static/upload/PNP/a/img_92.png#width-full)

但是Tracing和日志，有什么关系与不同呢？老李之前所在的公司中，好的解决思路是什么呢？中小公司能否利用「开源组件」+「云服务」去用较小的代价去无限接近这种效果呢？

拜拜，下周。。。哦不，下篇文章见。