如何打印日志
日志打印对研发来说,是很有必要的, 如何打印好日志,让日志能反映出处理流程,让日志能反映出问题所在,这个很重要,不好的日志,会加大研发排查问题的难度,过多的日志也会对研发造成干扰,如何打印日志,成了研发必须要掌握的技能。
日志存在的问题
- 安全问题
- 将用户的敏感信息打印在了日志中
- 日志级别不合理
- warning日志较为泛滥,且少有人关注
- 部分阻塞业务流程的错误,未正确使用error日志
- 错误日志重复打印
- 同一个错误在不同的位置重复打印
- 无效日志较为泛滥
- 一个正常处理的请求触发上千条info日志
- 日志缺乏关键信息
- 日志中缺乏关键的信息,进而导致难以定位问题
好的日志
- 快速定位线上问题
- 日志是定位线上问题的重要途径
- 杜绝安全问题
- 随意的日志打印可能会造成用户信息泄漏,引发安全事故
- 提升系统性能
- 错误的日志打印方法可能会造成系统性能的下降
- 了解系统运行的状态
- 合理的日志打印可以帮助研发先于用户甚至QA发现问题。
日志级别
级别 | 使用场景 | 是否需要报警 | 是否要立即处理 |
---|---|---|---|
DEBUG | 研发调试时使用的日志,生产环境不记录DEBUG日志,生产环境不应打印DEBUG日志 | 不用 | 不用 |
INFO | 业务流程的关键信息,可用于线上的case排查。数量不宜过多,单条日志长度不宜过大 | 不用 | 不用 |
Warn | 警告信息,指的业务发生了不符合流程的事件,但一般不影响业务的正常执行。常见场景:用户输入参数错误;rpc访问失败但重试成功;rpc访问失败但有容灾; | 不用 | 有空了看看 |
ERROR | 服务出现了异常,例如MySQL/Redis错误、下游调用失败、内存不足。每一条Error日志都需要研发同学关注 | 要 | 及时查看 |
Fatal | 导致系统崩溃的错误信息(使用量较少) | 要 | 立即处理 |
日志打印原则
记录完整
- 【强制】关键日志必须打印路径,打印日志必须带上关键信息
- 【强制】日志打印时必须携带logID
- 【建议】日志记录应包含一定关键调用参数,不要单纯记录错误结果
- 【建议】在错误发生的现场打印日志,防止错误信息丢失 保证性能
- 【强制】日志打印应避免无谓的资源消耗,只在错误分支使用的变量不应无条件初始化
- 【强制】不应在for循环中打印info日志,单条正常请求的日志数量不应大于20
- 【强制】不应使用info日志打印中使用%v输出整个结构体(error除外)
- 【建议】不应使用%v输出整个结构体(error除外)
- 【建议】谨慎的使用日志进行打点 合理分级
- 【强制】日志打印时应选择合适的级别 保证安全
- 【强制】原则上禁止日志汇总禁止打印用户L4级别的日志
- 【强制】日志打印满足飞书日志打印安全规范
- 【建议】使用合适的脱敏方式对敏感信息进行脱敏 其他
- 【强制】除初始化失败外,禁止主动panic
举例
BadeCase
case 1
代码语言:javascript复制logger.Errorf(ctx, "[rpc][people_corehr_starter] code not 0 : %v", resp)
logger.Infof("[AccessLog][func: %v][req: % v]", methodName, request)
问题:直接打印使用了%v
打印了整个结构体。
结构体往往包含许多字段,我们在打印日志时往往只关注其中一小部分字段的值,但很多同学为了方便会直接打印整个结构体;这种方式不仅仅会造成资源的浪费还有可能会导致安全的问题。
case2
代码语言:javascript复制for _,v:= range value1{
...
for _,v:= range value2{
...
logger.Infof(ctx, "[RowDetailPrepareData.BuildRowDimensionInfo][%s:%s] show_row_ActiveWorkforce %s %s : %d",
wpProgrammeID, prepareData.DraftID, wpRow.ID, domain.GetRowDimensionUniqKey(ctx, wpRow), wpRow.ActiveWorkforce)
}
}
剖析:在双重的for循环中打印了info日志,造成正常请求产生大量的info日志影响系统性能。
case 4
代码语言:javascript复制 if err != nil {
return result, errors.New("transfer interface to map[string]interface failed")
}
未在错误发生地打印错误信息,导致原始的错误信息丢失
代码语言:javascript复制logger.Warnf(ctx, "[ReleasePreTransfer] removePreTransferInfo fail. err=%s. uniqueIDList=%s",
removePreTransferErr.Error(), releasePreTransferReq.UniqueID)
问题:使用Base64对敏感的用户信息加密后打印在日志中。
通过Base64对敏感信息进行转换后,仅仅只能做到表面的脱敏,本质上Base64加密是开发人员规避安全检测的手段,虽然进行Base64转换后可以避免安全日志扫描的检测,Base64、Unicode 等有明确的特征(比如 Base64 只包含 64 个可打印字符),很容易被识别并被反解,从而导致信息泄露。
日志打印应杜绝安全问题;禁止通过Base64,Unicode等编码方式对敏感数据进行日志打印。
case5
代码语言:javascript复制 if err != nil || resp == nil {
logger.Warnf(ctx, "[AggregateTimeline] err=%s", err.Error())
return nil, err
}
问题:日志级别不合理,接口访问失败且无重试逻辑,业务接口已无法正常工作,应打印Error日志。
当前服务中warn日志泛滥的情况较为普遍,且很少有人关注warn日志,在大家的日常日志打印中应更加谨慎的使用warn日志。
case 6
代码语言:javascript复制func checkBaseResp(ctx context.Context, base *base.BaseResp) error {
if base == nil {
logger.Errorf(ctx, "[wukong][checkBaseResp] base response illegal")
return errors.New("base response illegal")
}
if constant.WuKongRespSpecialCode.Contains(int64(base.StatusCode)) {
logger.Infof(ctx, "[Wukong][checkBaseResp] success. code: %d, message: %s",
base.StatusCode, base.StatusMessage)
return nil
}
if base.GetStatusCode() != constant.ErrCodeSuccess {
logger.Errorf(ctx, "[Wukong][checkBaseResp] failed. code: %d, message: %s",
base.StatusCode, base.StatusMessage)
return errors.New("wukong checkBaseResp failed")
}
return nil
}
func (mr *MasterDataRPC) AggregateTimeline(ctx context.Context, request *readmodel.AggregateTimelineRequest) (*readmodel.AggregateTimelineResponse, error) {
ctx = BuildOpenAPIMGGrayContext(ctx, constant.OpenAPIMethodAggregateTimeline)
resp, err := client.AggregateTimeline(ctx, request)
if err != nil || resp == nil {
logger.Errorf(ctx, "[AggregateTimeline] err=%s", err.Error())
return nil, err
}
err = checkBaseResp(ctx, resp.BaseResp)
if err != nil {
logger.Errorf(ctx, "[AggregateTimeline] checkBaseResp failed")
return nil, err
}
return resp, nil
}
代码:
代码语言:javascript复制 logger.Errorf(ctx, "[Wukong][checkBaseResp] failed. code: %d, message: %s",
base.StatusCode, base.StatusMessage)
logger.Errorf(ctx, "[wukong][checkBaseResp] base response illegal")
logger.Errorf(ctx, "[AggregateTimeline] checkBaseResp failed")
问题:同一错误在不同日志中重复打印
【建议】同一错误在调用链中仅打印一次错误日日志
问题代码:
代码语言:javascript复制logger.Infof(ctx, "[NotifyEventHandler][HandleMessage] Start to HandleMessage Before unmarshal")
logrus.Warnf("[GetPkgIDByDptID] can't find pkgID,dptID:%s", DptID)
问题:
案例一:处理MQ消息的入口日志却未打印MQ消息的唯一标记MsgID
案例二:日志打印时未传入ctx导致日志缺乏logID,无法通过logID检索到该日志 案例三:在程序的关键分岔点未打印日志
案例四:在特殊的条件分岔未打印日志 【强制】关键日志必须打印路径,打印日志必须带上关键信息 【强制】日志打印时必须携带logID