二零二三年四月第一周技术周报

看了一下当时的周报,值得说的事情也就是关于日志整理的事情,然后就是关于一个配置下发服务的多地部署。关于多地部署的事情,下一篇技术周报再详细说明。

首先来说说,日志方面的事情。现在的话,线上有很多服务。然后目前DEBUG的日志,是用了腾讯云的CLS。而目前存在一些问题,这些服务的日志有些分散,不太好找。如果一个请求跨越了多个服务,有可能需要研发去跨越几个日志集然后来定位问题。然后就是,这些服务技术栈并不统一,并没有一个统一的日志监控框架来监控这些服务的状态。目前追踪跨服务的请求使用TraceID,TraceID是在请求进入网关服务或者入口服务的时候自动生成的。TraceID有可能是纯数字,也有可能是数字带字母。后续的服务之间的请求基本上会带有TraceID这个字段,用于追踪请求。然而,也还有很多请求内容里不带TraceID,导致服务没办法从请求本身来拿到TraceID,只能索性重新生成一个,所以这些请求在各个服务之间的TraceID都会不同。总而言之,理论上,正常情况下,一个TraceID将伴随一个请求,从进入追踪范围到出追踪范围为止。

另外还有个问题,就是这些个日志集中,日志内带有的字段也不太统一,有写日志集的请求内容的字段叫X,有些又叫Y。有些字段日志的结构上有,实际输出的日志中却没有填写。如此这些,都增加了新的研发上手定位BUG原因的学习成本。上述这些问题,都很让人头疼。

还有一个就是降本增效的问题,在目前的已有日志的基础上需要看看还有哪些日志可以精简优化的。整个部门,每个月的单单存储和整理日志成本都十多万。而我负责的这一块的业务量又占大头,日志量也是非常大的,每天大概有540亿条日志。所以,我需要在这一块多下功夫。

对于当前的的TraceID问题,我采取先把同样技术栈服务的TraceID的生成方式和传递方式都改为统一的。对于Java技术栈的服务,用的无非都是Spring Boot框架。所以我对每个服务都增加了一个统一的拦截器,来拦截请求和响应。对于请求,这些Java服务处理的都是文本类型的请求,基本上都是JSON格式编码的。所以,无外乎就是检查JSON字段中是否有相应的traceId字段,如果有的话,那就拿来用。具体就是把TraceID放置到线程私有化存储中(MDC),伴随着这个线程处理。这个方法也有局限性,有些请求会在某些步骤上进行异步处理,转移到其他线程池的线程上处理了。这样,TraceID的追踪就丢失了。我的办法是写一个包装类,接管所有异步处理的需求,参数与调用方式和原来一模一样,然后在其中检查上一个线程中是否含有TraceID字段,然后把TraceID字段先放到包装类产生的对象中。切换到另一个线程后,这个线程先看看包装类对象中是否有上一个线程存下的TraceID,如果有就提取这个TraceID然后记录到自己的私有化存储中。这样TraceID的追踪就不会中断了。

请求拦截器的TraceID生成过程,也可以提一下。由于很多以前的老服务使用了二进制的请求格式,技术原因导致了这些请求无法灵活变更。一旦更改了请求,那么上下游都需要重新编译生成编解码器,然后重新部署。这对于日志改造来说,工作量不可接受。然后有很多请求中,TraceID是long类型的,而非字符串。所以我就需要照顾这些老服务,大家都统一使用long类型的TraceID。然后,我还希望在TraceID中带有一些额外的信息,比如说这个请求是从哪个地方被赋予TraceID的。如果这个信息能直接从TraceID中看出来,那就再好不过了。所以我不是简单地随机生成一串数字当作TraceID,而是保留前面的4位数字。前两位用99作为开头,表示这个是使用了统一后的TraceID方案,和以前的纯数字的TraceID区分开来。然后,后两位数字按序号表示各个服务。01,表示网关服务A;02,表示入口服务B等等,这个我来手动分配,最后会把分配方案写到文档中。后面的数字,都是随机生成的。

注意,这里采用随机生成的方式,在每天这么大量的日志的情况下,可能产生重复。但我评估了一下,这种重复对我们定位问题这个需求来说,无关痛痒。所以索性重复就重复,再重复15分钟之内重复的概率也非常小,可以不考虑。最后,生成的TraceID都是固定位数,以99开头的数字。

在业务处理请求的过程中,会不断有日志输出,采用异步化的方式输出到日志盘中的目标文件中。这个日志输出的格式和分类需要强制统一,包含下面的内容:时间、日志等级、TraceID、对应线程ID与日志内容。这些都用“|”隔开来。然后,需要把不同等级的日志区分开来存储。后续腾讯云CLS会通过规则来监控这些日志文件的修改,然后采集这些输出的日志,通过上面的统一格式和区分等级,能更简单地统一各个服务的采集配置,并避免把一些低等级的日志采集上去。低等级的日志可以留在日志盘中,如果研发人员需要看,就可以登录到容器中来看。毕竟,相比于被CLS采集后,附带产生的流量、计算和存储的成本,日志盘的存储成本还是能接受。这样也算是通过差异化地方式提供服务来降低成本。后续,对于不是那么高频用到日志,只需要通过降低其日志等级来避免被采集,从而降低成本。值得一提的是,被采集上去的高等级日志,只会按照TraceID索引,而不再索引内容,这样可以非常有效地降低成本。我称这些日志为业务日志,这些日志在CLS上只能通过TraceID来找,而不必通过内容来查找。

在响应拦截器中,我们需要一次性向日志输出这个请求的简要信息,也就是Access日志,包括请求的字段,响应的字段,还有处理时间,容器的IP地址,TraceID,服务名称等等内容。Access日志将单独输出的access.log中,然后这个文件也将被CLS采集。CLS会按照其中最关键的字段(请求字段,响应字段,TraceID,服务名称)索引这些日志,后续我们通过模糊搜索请求字段或者响应字段就能定位到具体的一次业务请求了,我们可以对这个请求有直观地了解,然后也能拿到TraceID。通过TraceID,我们可以用CLS一次性找出与这次请求相关的所有业务日志,摸清楚这次业务请求的来龙去脉。

通过上面对于业务日志和Access日志的方案的设置,我能够避免让CLS建立全文索引(索引日志的所有内容),从而大幅度降低成本。虽然没有了全文索引,但是研发人员通过BUG单中的用户给出的信息,搜索请求或者响应中的对应字段,来查出TraceID,后续也能快速且准确找出所有有关的日志来。这实现了成本和易用性的一种平衡。还有一个没有提到的,就是被CLS采集上去的日志,就没必要在日志盘中长期存在了,可以设置滚动规则,1-2小时后就删除掉。

对于Node.js技术栈的服务,我也基本上采取相同的思路,通过框架提供的context能力,来处理TraceID。日志的输出和采集方案,也严格遵守Java服务的规范。然后还有C++技术栈的服务,那就麻烦很多,这些服务非常老了,但依然处于关键位置上。但我没时间处理这些了,这些服务出问题的概率非常小,先放着。

通过这样的处理,CLS上对每个服务配置日志文件的采集规则都是统一的了,大大简化了配置的繁琐程度。对于每一个服务,我们只需要复制粘贴现有的采集和索引规则即可,因为这些服务的日志格式和输出都是呈现形式都是相同的了。这样处理下来,有一个月的时间。完成后,日志这块确实都规范起来了,查问题也变得方便了。我也能对现有日志进行归类,看看哪些业务日志对查问题真正有效,哪些并没有太大的帮助。后续我再带着另一个同事,削减了一大批以前没发现的无效或者重复的日志,又节省了一大笔费用。具体地,我们两个经过评估分析发现每天可减少121亿条无效与重复的日志,削减现有成本的38%。