一些关于如何写好日志的感悟

这里写自定义目录标题

一些关于日志的感悟1. 前置说明2. 案例说明3. 最佳实践3.1 部署角度3.2 依赖角度3.3 模块角度

一些关于日志的感悟

本文适用做业务开发的程序员,而那些顶尖开发者的开发者(即提供系统,平台,框架的那些牛人)参考这份文章的意义不是很大

1. 前置说明

首先说说在AI盛行的当下为何还要写这样一篇文章:作者在review很多同学的代码时(当然现在部分大公司已经是AI在做了),实在觉得看不下去。我发现有一个现象非常明显:就是日志写得非常清晰的代码大概率是一份好的代码,或者有些模块不打日志,而是采用明确的异常或者错误码形式返回的代码也基本上可以得到“这一份代码值得一看”(毕竟review好的代码是一种非常给力的学习方式)的评价。当然关于日志规范的文章,请读者Google一下或者与ChatGPT(当然deepseek也是个好选择,国内最近是很火的)聊一下,都可以给你很多条条框框。很多同学会说:我的日志全部符合规范,为何就从这一点可以判定是一份不是很好的代码,所以本文介绍一些日志方面的感悟(后面空闲再补一份异常和错误码的文章)来解答一下这个问题。 作为一个非科班出身的计算机行业从业者,我从毕业到现在工作虽然还没满十年,但是一直以来从没有放弃过学习优秀代码的实践,从安全行业入门,到后来内核大部分模块的原理到互联网大数据后端到各式各样的业务,唯一一个共同点(不论是技术栈还是语言类型)是:每个涉及到代码都会存在需要处理日志的情况,当然很多人会说,还有一些频繁发生的内存管理问题,崩溃问题等等,但是相对于日志而言,这些都不是贯穿的,比如你用了高级语言,类似java,go,甚至是python,可能内存都是有GC帮你解决了大部分的问题的。

2. 案例说明

废话多了一点,进入正题。作者现在review代码的第一步就是了解方案(我们大陆地区比较喜欢敏捷开发,方案都是口头的),然后就是全览代码中的日志,所以先看几个案例:

1. call the self defined function and receive an abnormal value

#define logger_error(fmt, args...) printf("ERROR [%s:%d] " fmt "\n", __FUNCTION__, __LINE__, ##args)

int HandleFunctionA(param A, param B, ...){

...

}

int Handle() {

...

int ret = HandleFunctionA(a, b, c);

if(ret < 0) {

logger_error("HandleFunctionA failed, ret: %d", ret)

return ret;

}

...

}

2. unknown type when doing switch

int Handle() {

...

switch(type) {

case A: {

...

} break;

case B: {

...

} break;

default: {

logger_error("unknown type: %d", type)

return ret;

}

}

...

}

3. useless log

int business(A *a){

if(!a) {

logger_error("A is nullptr");

return -1;

}

}

int Handle() {

...

A *a = (A*)malloc(sizeof(A));

if(!a) {

logger_error("failed to malloc A");

return -1;

}

int ret = business(a);

...

}

4. promote debug to info

int Handle() {

...

logger_info("start to write the value: %s", value);

...

}

有太多太多的例子了,包括作者在内,我敢100%肯定所有人都写过或者正在写这样的日志,单纯的从代码角度看:这些日志是不违反通用的日志规范的,因为我看了很多通用的日志规范,都是规定该记什么级别的日志,在哪里记日志,日志内容应该包括时间,接口等详细信息。但是很少有文章告诉你这些详细信息是什么?怎么记录才是详细的?时间,接口名,错误码是啥就详细了么?

古语道:当局者迷,旁观者清。用到这里也是非常恰当的,如果你是这块代码的继任者(也许写这个代码原始作者因为一些事情不再维护),亦或者你是这个程序或者系统的维护者,每天都要处理非常多的日志,你对这块业务非常熟,但是你对这块代码不熟悉,你会觉得这种日志会不会给你带来非常多的压力?因为我们就是在创造这样的无厘头的日志,只有原始的代码作者才能理解(更有甚者,原始作者自己在这种代码上线后可能发生看不懂这种日志的情况,这在现实情况中并不少见)。

上面已经提到,如果我们不是以一个开发者角度,而是以一个继任维护者或者运维人员角度去脑袋中debug一下这种代码,面对打印出这种错误日志后,我们应该怎么做?如果作为继任维护者,我觉得你还没有到给原作者交接成功的单子上署名的时候;如果你作为运维人员遇到这种错误日志时,我觉得你的下一步一定是拿着这个日志给这个代码的开发打电话,虽然这时候他可能在睡觉。你一定会问:HandleFunctionA failed代表了什么意思呢?你得到的回复也差不多下面几个:

FunctionA不重要,我只是记录一下调用失败了,没啥关系,我还在睡觉,别烦我;嗯,你先确认一下业务那边有没有其他的反馈?这是一个XXX模块,主要是用于XXX,目前看这块有备份,应该还好,麻烦你把详细的日志传我一份,我后面分析一下看,我需要休息;FunctionA错误说明XXX模块基本不可用了,这个模块不是我负责的,你找其他人吧;啊?FunctionA挂了?不可能啊,怎么会呢?有没有更详细的日志或者其他的打印?没有?那这是为啥呀?这时候你不得不从床上爬起来

当然,我猜测你可能还有第五种情况:FunctionA是啥,我没有印象我调用过这个函数啊。是不是那该死(我也比较肯定70%的开发程序员脾气都不是很好,因为很容易盲目的自信)的运维弄错了?嗯,一定是弄错了。

这种类型的日志我们就不再继续展开了,因为我想用更多的时间来说明我们应该怎么做才可以认为是非常好的日志。我比较担心文章太长(废话太多,嗯,我知道已经太多了)导致你没有耐心读下去,那么就真的浪费我的辛苦了,哈哈

3. 最佳实践

读到这里,该有的问题你应该是了解了的,那么我们应该怎么样去记录一份有效的日志,能够一眼就可以分析到问题的原因在哪里呢?从我的经验来看下面的步骤会是一条比较好的思路:

从部署角度去写日志;从依赖角度去写日志;从模块角度去写日志;最后才是你自己的业务日志(从common sense的业务逻辑思维去写日志,作为一个第一次知道这个业务的角色去记录异常信息);

接下去我们将按照上述顺序来说明一下如何能够写好有效的日志。

3.1 部署角度

对于互联网或者移动互联网,更或者下一代WEB3.0到来的时代,都不会是单机或者单程序运行的时代,更多的还是业务功能的模块化,精细化,也许展现在你终端的一张照片是来自于2000公里外的一台设备上,那么你如果是这个业务的开发者,你需要面对这2000公里外的数据的调用方式,这时候如果稍不注意你可能就会写出上面的案例1,如果你把他改一下呢:

int Handle() {

...

int ret = HandleFunctionA(a, b, c);

if(ret < 0) {

// no one knows the Function A, but the maintainer will realize

// that your program depends on the specified storage, of course,

// if you have more than one storage, you must write it with the

// determined name of the storage

logger_error("something error occurred in storage device, reason: %s",

get_err_msg(ret));

return ret;

}

...

}

void BusinessA() {

...

int ret = Handle();

if(ret < 0) {

// you have recorded all the information about the error, now you

// can tell the maintainer how to recover the current scenario

logger_error("please check the following things: %s, you need to

do nothing after the depend storage device recovered

but to make sure it OK", check_list(ret));

}

..

}

你会不会对这种方式比较熟悉?似成相识的感觉油然而生?bingo,每个程序语言的编译器报错都是这么详细的,所以我们一直在使用的常用的工具,优秀的工具,如果你仔细去研究都是提升自我的一个个非常好的老师。

你的日志必须包含发生错误的部署依赖,错误原因,以及可能的检查方案(当然检查方案可能来自于你的依赖部署方的接口调用错误手册)。如果可以的话,你在日志上指明如何恢复是更优的,但是更多的时候因为你无法染指依赖的部署方,你可能需要给运维一个额外的手册。

我相信你会注意到,日志还是一行中完全显示是最优解,因为我们现在都是异步编程,分为多条日志,你找上下文还需要依赖一下工具进行线程合并操作。当然现在的日志本来就不是给人看了,都是机器识别了是吧,所以问题也不是很大。但是对于那些初创公司而言,作为技术总工的你还是需要这些细节处理的,因为大概率日志都得你亲自写脚本处理或者得人力去看(因为还没有成熟的流程能够保证日志是合规的)。

3.2 依赖角度

这里的依赖视角是那些通用的依赖,所有具备基本常规知识的人都一致认可的第三方库,而不是那些你们公司或者你们组内自己开发的非标库(非标库需要看下文第4点关于业务处理的日志)。我们还是直接举例好了,比如你的程序用到了密码学,我觉得大概率你不会自己造一个密码学算法,一定会用到第三方的库,如OpenSSL,mbedtls。这种第三方库你在调用时,我相信你用Google或者ChatGPT得到的合规日志来引导你也是只需要记录最多是WARN的日志,因为这种操作发生异常的概率比较低,你在调试阶段或者TestCase阶段就把算法问题解决了。但是我们还是会遇到一些场景,比如你对接了第三方传输过来的数据,你发现你无法解密或者对其进行签名验证,你应该如何记录这日志?下面的方案是否会让你继续睡觉而不受到运维的打扰?

相对于密码学,网络上非常多的公开资料,比如RSA2048的签名是256字节的(不管用哪种填充方式),同时我们也知道SHA256的计算结果是32字节的,所以这种时候,你的日志应该是要注重很多数据长度的内容:

int verify(char *data, int dlen, char *sig, int slen) {

// parameter check at first

int ret = RSA2048verify(data, dlen, sig, slen) {

// 1. 这里打印的时候不要写dlen,slen,没有人理解这是什么意思,你的日志应该能让刚毕业的学生都能看得懂

// 2. 这里不打印data和sig是涉及到安全问题的,同时我觉得也没有这个必要

logger_warn("RSA2048 verify failed, data len:%d, signature len:%d", dlen, slen);

return ret;

}

}

注意:这里只是举例,椭圆曲线就不一定是明确的结果,你可以按照算法特色去处理,但这些都会变为常识。

上文已经提到过,RSA2048 verify failed是没有人知道这里发生了什么,只知道调用失败了,那么对于日志而言,记录上下文是需要的,是什么来源的数据调用了这个接口失败了呢?业务层面在哪里,这不仅运维想要知道,作为开发者的你也是想要知道的,所以对于上述这种日志记录方式,事实上就会回到我们开篇举例的第一个日志问题上去:调用了一个函数,记录函数调用失败了。而且上文也提到了,我们现在都是异步编程,日志需要完整才好,所以我觉得有几种方式处理比较好:

// C 语言,设置一个线程全局变量用于接收异常

thread local char[256] error = {0};

int verify(char *data, int dlen, char *sig, int slen) {

// parameter check at first

int ret = RSA2048verify(data, dlen, sig, slen) {

// 当然256,你最好用全局变量或者宏处理

memset(error, 0, sizeof(error));

snprintf(error, 256,"RSA2048 verify failed, data len:%d, signature len:%d", dlen, slen);

return ret;

}

}

int business(char *data, int dlen, char *sig, int slen){

int ret = verify(data, dlen, sig, slen) {

// 错误在哪个业务上发生,原因是啥?可以做那些操作?

logger_error("business A verify failed, reason: %s, please check: %s", error, checklist(ret));

// 这种第三方库,你调用了哪个函数,应该可以明确错误的类型的,你还可以根据返回的值来处理checklist,例如

switch(ret){

case -1:

case -2:

}

}

}

// C++ 语言,直接抛出异常

thread local char[256] error = {0};

int verify(char *data, int dlen, char *sig, int slen) {

// parameter check at first

int ret = RSA2048verify(data, dlen, sig, slen) {

throw 3rd_exception(ret, "RSA2048 verify failed, data len: " + itoa(dlen) +", signature len: " + std::to_string(slen));

}

}

// Go 语言就更方便了,直接返回error即可,越高级越简单

写到这里,我相信你也感受到了有效日志的一个万变不离其宗的公式:什么业务在什么时间做了什么操作发生了什么异常,可能的原因是啥,能做的操作是啥?这就是运维角度的日志,并且考虑让运维看到日志可以及时尽量多的去帮你收集第一手资料,所以错误日志是带有驱动性的,但不能让运维成为驱动的传声筒。到目前为止,我遇到的所有运维与开发之间的矛盾基本都是来自于开发的自负。

3.3 模块角度

上面铺开了两种情况,但是更多的时候我们是自己的业务存在非常多的自研模块,包括组内其他人封装的模块,公司其他组的模块,自己也在写模块,那么从模块角度,因为释放的是接口,我通常的建议是:采用异常或者错误码形式去返回这些错误的详细信息(本文不详细展开这两项内容),但是也会遇到部分模块需要自己记录日志的情况,因为他可能也是一个独立业务的插件,也可能用于模块自身的数据边界定位,因为很多时候你发布了模块,公司其他人使用时会有一大堆的问题过来,你必须给予明确的查询方式或者错误引发的根因(相对于你实现的模块而言的根因)。说到这里我感觉是在写文章告诉你如何撇清别人抛过来的问题。其实最后你会发现这是在避免制造一些混乱和徒劳的争执,也许还可以帮助你解决多年未有的历史反复bug问题。 按照上面的业务在时间下的操作可能就不够了,这时候可能你还需要记录一下额外的信息,这一点作者当年毕业5年时遇到的一个非常严重的日志问题:写一个中间业务模块获取上游数据再供多个下层业务集成调用,当时没有经验,被多个业务追着打,而我无法自证自己处理是否正常,也无法证明确实是我上游的业务数据问题,因为某一个数据问题就记录所有数据条的日志,这种做法有效性和成本是不成比例的(当然家大业大的土豪公司请无视)。这里我把例子模糊化、异形化放到这里供大家参考(读者知道这么一个意思就好了,哈哈):

int handle(const char *data, const int dlen, char *newdata, const int nlen) {

// generate the new data with your implementation,

// it may have thousands of business logic under this function

}

这时候发现你的newdata并不符合预期(但是程序运行并没有出现错误,只是按照加工逻辑最后生成的数据不符合预期),要么data错了,要么就是你的handler处理错了,但是在没有任何证据的时候只能是怀疑你的handler,而此时你无法启动类似如下的方式去证明你的处理是正确的:

int handle(const char *data, const int dlen, char *newdata, const int nlen) {

// generate the new data with your implementation,

// it may have thousands of code line under this function

logger_info("original data: %s, dlen: %d, new data: %s, nlen: %d", data, dlen, newdata, nlen);

}

这种做法既违背了上面说的日志记录方式(但是遇到紧急情况你一定会想到先这么干的,我们不讨论临时方案的解决方式),最后也不一定达到效果:

data一定是可见字符串么?虽然是char*指针。如果这个函数是秒级百万数据调用呢?这个磁盘空间得多大才能扛得住?抗住了能捕捉到错误的数据么?而且还非常可能降低了你的并发性能。如果这类函数进入的数据无序状态,且按照一定名称需要归类,只是某个名称发生异常呢?你觉得这种场景直接可以把问题甩给业务方先自行查源数据,但是业务方会轻易放过你么?

所以遇到这种场景,我们换位思考一下,是等着业务方报错来找你,还是自行预警提醒业务方呢?所以遇到这种模块(作者在这里举例比较极端,处理了极端,你对其他的模块就游刃有余了)你肯定要选择后者?所以你能处理的方式是主动出击:

利用规则生成数据校验的规则(凡不符合校验规则都记录下来,这就是你深入了解业务的时候),作者在后面几年的大数据处理中得到规律,数据一定存在规律,超出你的阈值或者规律的数据就记录下来,这不会很多;发生异常后让运维去找你的下游业务方,别等他们找你。这是作者当时用的手段解决了大部分的问题。久而久之,作者直接在接口上写了,数据异常请自查数据,该接口非常稳定,哈哈。int handle(const char *data, const int dlen, char *newdata, const int nlen) {

// generate the new data with your implementation,

// it may have thousands of code line under this function

check(data, dlen, newdata, nlen);

}

void check(data, dlen, newdata, nlen) {

// there are many ways to check the data:

// 1. use a Threshold

// 2. expeired data

if(condition){

logger_error("the original xxx data may have exceptional fields, xxx, please do xxx");

}

}

从数据进入处记录数据量,从数据来源处记录数据量,确保你们在一定时间窗口内数据是没有丢失的场景的,所有数据都是被正常加工了的或者进入到你的check异常日志的,这时候起码你的上下游链路是保证了的;对于这种异常,我建议你的方案到代码实现最好是支持无序状态的,尽量避免因为数据来了,因为有序的状态要求,你直接丢掉了(有同学会说:我就是有序的,比如一个用户因为网络卡顿多次提交相同或者不同的相关信息);丢掉这个行为也是你的处理过程,也会进入到上面的第二点的统计信息中;同时针对丢掉的数据,也进入统计;

注意:对于上述这种自研的模块更多的采用统计信息来替代日志信息,而真正的代码逻辑的校验工作是在testcase中就应该完成了。

最后强调一句,很多人会说:要按照你的方式,我们根本无法敏捷,我们要的是业务快速上线。从作者这么多年的经验看:如果你不是这种方式处理你的代码,你每天会一边抱怨你的业务有多复杂,一边加班加点去改bug。但这很可能会受到老板的赏识:“这个小伙子够拼”,但如果这个公司是靠业务在维持运行的,我觉得老板的业务大概率应该是在不断缩水的(靠营销搞定的,作者没有亲身经历,不敢妄言),而对于你而言,这种状态是在温水煮青蛙,你不会得到除了部分业务特点外的任何技术长进(当然接下去AI这么火,可能不需要程序员了,只需要会聊天的产品设计师了)。对于初创公司而言,求快的方式应该更加慎重的把握方案的过程,进而把握实现过程,扎实基础和底层实现,用质变去收获量变。但是现在很多公司一是要求敏捷,二是又都是让那些刚毕业的小年轻去操刀实现逻辑,甚至方案。

本文后续再补充一些例子,其实文章早在年前一个月就写好了,过年一直没有拿起电脑,直到今天才发现就顺手发一下,。

上一篇: 阴阳师提灯小僧哪里多,2023阴阳师提灯小僧刷新位置一览
下一篇: 为什么体重没变但是人却看着胖了

相关推荐

2025日本银行大盘点:全面解析银行开户条件与主要银行
中国最美的温泉在哪儿?
网吧挂机锁(网吧挂机锁是什么)
软件公司研发岗位都有哪些
小树时代周末会审核吗 小树时代周末下款吗
2025日本银行大盘点:全面解析银行开户条件与主要银行