如何打印日志

日志打印对研发来说，是很有必要的，如何打印好日志，让日志能反映出处理流程，让日志能反映出问题所在，这个很重要，不好的日志，会加大研发排查问题的难度，过多的日志也会对研发造成干扰，如何打印日志，成了研发必须要掌握的技能。

日志存在的问题

安全问题
- 将用户的敏感信息打印在了日志中
日志级别不合理
- 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

logger.Errorf(ctx, "[rpc][people_corehr_starter] code not 0 : %v", resp)
logger.Infof("[AccessLog][func: %v][req: %+v]", methodName, request)

问题：直接打印使用了%v 打印了整个结构体。

结构体往往包含许多字段，我们在打印日志时往往只关注其中一小部分字段的值，但很多同学为了方便会直接打印整个结构体；这种方式不仅仅会造成资源的浪费还有可能会导致安全的问题。

case2

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

 if err != nil {
      return result, errors.New("transfer interface to map[string]interface failed")
   }

未在错误发生地打印错误信息，导致原始的错误信息丢失

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

 if err != nil || resp == nil {
      logger.Warnf(ctx, "[AggregateTimeline] err=%s", err.Error())
      return nil, err
   }

问题：日志级别不合理，接口访问失败且无重试逻辑，业务接口已无法正常工作，应打印Error日志。

当前服务中warn日志泛滥的情况较为普遍，且很少有人关注warn日志，在大家的日常日志打印中应更加谨慎的使用warn日志。

case 6

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
}

代码：

 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")

问题：同一错误在不同日志中重复打印

【建议】同一错误在调用链中仅打印一次错误日日志

问题代码：

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

如何打印日志

测试

测试