乐趣区

关于后端:如何优雅的记录业务日志

jiezi

在开发中，除了系统日志外，很多时候咱们还须要记录业务日志。业务日志的记录通常不须要很精密，仅记录要害状态扭转的工夫点、及前后数据变动即可。当然语言为 Java，基于 Spring 框架。

咱们学习 Spring AOP 时，理解到其利用场景中，比拟重要的一个就是能够用来做日志记录。这种的话，能够依据切入点 (Point Cut) 类型的不同来达到不同的成果。比方能够拦挡所有的 Controller 来记录申请起源 IP、申请参数、响应后果、耗时等。

1. 记录 API 拜访日志

简略的示例，并非本文重点。通过拦挡所有的 Controller 控制器，来记录所有的输出、输入。

1.1 Aspect 代码示例

@Slf4j
@Aspect
@Order(1)
@Component
public class WebLogAspect {private static final Set<String> EXCLUDE_LOG_URIS = Set.of();

    @Pointcut("execution(public * com.example.*.controller.*.*(..))")
    public void logPc() {}

    @Before("logPc()")
    public void doBefore(JoinPoint jp) {final HttpServletRequest request = getRequest();
        if (Objects.isNull(request)) {return;}
        //
        long startTime = System.currentTimeMillis();
        final WebLog.WebLogBuilder wlb = WebLog.builder();
        /* 配合 Swagger 应用
        final MethodSignature signature = (MethodSignature) jp.getSignature();
        final Method method = signature.getMethod();
        if (method.isAnnotationPresent(ApiOperation.class)) {ApiOperation ao = method.getAnnotation(ApiOperation.class);
            wlb.desc(ao.value());
        }
         */
        final String requestURI = request.getRequestURI();
        // 申请入参
        if (EXCLUDE_LOG_URIS.contains(requestURI)) {wlb.parameter("***");
        } else {wlb.parameter(jp.getArgs());
        }
        // 其余参数
        wlb.beginTime(startTime);
        wlb.methodName(request.getMethod());
        wlb.uri(requestURI).ip(CommonUtil.getIpAddress(request));
        // 日志输入
        final WebLog webLog = wlb.build();
        log.info("[接口入参] {}", JSONUtil.toJsonStr(webLog));
    }

    @Around("logPc()")
    public Object doAround(ProceedingJoinPoint jp) throws Throwable {final HttpServletRequest request = getRequest();
        if (Objects.isNull(request)) {return jp.proceed();
        }
        //
        final WebLog.WebLogBuilder wlb = WebLog.builder();
        long startTime = System.currentTimeMillis();
        final Object proceed = jp.proceed();
        long endTime = System.currentTimeMillis();
        /* 配合 Swagger 应用
        final MethodSignature signature = (MethodSignature) jp.getSignature();
        final Method method = signature.getMethod();
        if (method.isAnnotationPresent(ApiOperation.class)) {ApiOperation ao = method.getAnnotation(ApiOperation.class);
            wlb.desc(ao.value());
        }
         */
        final String requestURI = request.getRequestURI();
        // 申请入参
        if (EXCLUDE_LOG_URIS.contains(requestURI)) {wlb.parameter("***").result("***");
        } else {wlb.parameter(jp.getArgs()).result(proceed);
        }
        // 其余参数
        wlb.beginTime(startTime).costTime(endTime-startTime);
        wlb.methodName(request.getMethod());
        wlb.uri(requestURI).ip(CommonUtil.getIpAddress(request));
        // 日志输入
        final WebLog webLog = wlb.build();
        log.info("[接口出参] {}", JSONUtil.toJsonStr(webLog));
        //
        return proceed;
    }

    private HttpServletRequest getRequest() {ServletRequestAttributes attributes = (ServletRequestAttributes) RequestContextHolder.getRequestAttributes();
        return Optional.ofNullable(attributes).map(ServletRequestAttributes::getRequest).orElse(null);
    }
}

局部日志反复，在 @Before 和@Around两处记录。在控制器内可能抛出一些 RunTimeException 这些会由 ExceptionHandler 全局异样处理器拦挡解决，这里不再细讲。后续独自一篇文章解说。

在理论应用时，发现有些不重要但查问数据量比拟大的接口。比方查问某某分页数据，会导致 parameter 或result俩参数打印出大量字符串。所以加了一层判断，遇到这种接口疏忽其参数和返回值。但保留其余数据。

其实这样打印日志，是存在一些问题的：

  • 日志的存储是个问题，如果访问量比拟大，日志增长飞快。
  • 打印日志是比拟耗时的，尤其是将 lineNo 打印。
  • 存在肯定安全隐患。毕竟将所有输入输出均裸露在日志中。

1.2 Controller 示例及日志

@Slf4j
@RestController
@RequestMapping("leads")
@RequiredArgsConstructor
public class LeadController {
    private final LeadService leadService;

    @PostMapping
    public RestResp<Boolean> addLeads(@Validated @RequestBody LeadReqVO vo) {final boolean result = leadService.addLead(vo);
        return RestResp.ok(result);
    }
}

模仿申请

### 创立线索
POST http://localhost:28800/leads
Content-Type: application/json

{
  "username": "小明的妈妈",
  "phone": "+5633089972",
  "email": "ming.xiao22@gmail.com",
  "channel": "OA-XX-XX",
  "subject": "Chinese"
}

查看日志

2022-11-30 15:13:36.737  INFO 87959 --- [io-28800-exec-1] c.e.s.c.WebLogAspect  : [接口入参] {"costTime":0,"parameter":[{"phone":"+5633089972","subject":"Chinese","channel":"OA-XX-XX","email":"ming.xiao22@gmail.com","username":"小明的妈妈"}],"ip":"127.0.0.1","methodName":"POST","beginTime":1669792416714,"uri":"/leads"}
2022-11-30 15:13:36.752  INFO 87959 --- [io-28800-exec-1] c.e.s.c.WebLogAspect  : [接口出参] {"result":{"msg":"ok","code":200,"data":false},"costTime":37,"parameter":[{"phone":"+5633089972","subject":"Chinese","channel":"OA-XX-XX","email":"ming.xiao22@gmail.com","username":"小明的妈妈"}],"ip":"127.0.0.1","methodName":"POST","beginTime":1669792416714,"uri":"/leads"}

2 业务日志记录

在 留资 -> 商机 过程中，因为 CRM 应用的是内部第三方服务。导致数据大略有两次次要的交互。

  • 留资进线: 留资是在自研落地页。用户提交到咱们零碎外部，通过简略数据处理后。定时候批次推送到 CRM 中。
  • 线索转商机: 留资进入到 CRM 中，会以线索的模式存在。此时销售能够跟进该线索，当能够转为商机时。会有转商机动作，该动作须要携带销售欠缺后的数据，转到咱们零碎中。此时会在零碎中发送创立账号等操作，便于家长后续预约试听课等流程。

开始这块是只有一些系统日志。当产生一些意外状况时，常常会被业务方要求查问某某家长的留资、进线、转商机等等时间轴。这个场景是很费时费力的事件。一个工单过去可能就要解决几个小时，很可能最终发现这不是咱们的问题。

所以咱们须要这么一套货色，来记录 家长留资 -> 进线 -> 转商机 -> 商机后续动作 整个流程。(逻辑已简化)

次要模块有:

  • 线索(Lead)
  • 商机(Deal)
  • 家长(Parent)
  • 学生(Student)

波及的动作大略有:

  • 线索_进线(->CRM)
  • 线索_转商机(<-CRM)
  • 商机_所有者 (销售) 被批改(<-CRM)
  • 商机_成单同步(->CRM)

形容完大略业务场景后，咱们开始着手设计。因为这些业务逻辑根本曾经存在，咱们只是要在要害节点做一些记录。并不需要特地的细节，这种场景很适宜 AOP 的思维。

2.1 日志记录指标格局

  • bizId: 业务 ID。如线索 ID、商机 ID
  • module: 模块。线索、商机等
  • type: 动作。如线索转商机等
  • param: 参数。看具体业务场景

为了不便获取 bizId，咱们创立个接口。通过实现该接口中的办法，来裸露业务 ID。
同时，为了标准。还需新建几个枚举类。

/**
 * 业务 ID 获取口
 *
 * @author lpe234
 */
public interface BizIdentify {

    /**
     * 获取 BizId (大部分状况是 DealId)
     *
     * @return bizId
     */
    String getBizId();}

@Getter
@ToString
@AllArgsConstructor
public enum EventLogModule {LEADS("LEADS", "线索", "Leads"),
    DEALS("DEALS", "商机", "Deals"),
    PARENTS("PARENTS", "家长", "Accounts"),
    STUDENTS("STUDENTS", "学生", "Contacts"),
    ;

    private final String key;
    private final String val;
    private final String alias;
}

@Getter
@ToString
@AllArgsConstructor
public enum EventLogType {CONTACT_TO_LEADS("CONTACT_TO_LEADS", "留资进线"),
    LEAD_TO_DEAL("LEAD_TO_DEAL", "线索转商机"),
    CHANGE_CC("CHANGE_CC", "批改 CC"),
    ORDER_CLOSED_WON("ORDER_CLOSED_WON", "已成单回传"),
    ;

    private final String key;
    private final String val;
}

2.2 定义注解

通过注解的形式。能够很好的去标识，哪些办法须要被记录。并且注解能够配合 SpEL 来实现一些更灵便的操作。如本注解中的logArg，就可不便的标注参数名并通过反射形式来获取参数具体内容。

@Target(ElementType.METHOD)
@Retention(RetentionPolicy.RUNTIME)
@Documented
public @interface BizLog {

    /**
     * 日志记录模块
     *
     * @return logModule
     */
    EventLogModule logModule() default EventLogModule.DEALS;

    /**
     * 日志记录起因
     *
     * @return logType
     */
    EventLogType logType();

    /**
     * 须要记录的参数
     * @return param name
     */
    String logArg() default "vo";}

2.3 业务日志切面

思维很简略，通过 @BizLog 注解来标识哪些办法须要解决。在进入办法前，通过反射形式将所需内容获取到，并记录到日志零碎。本文间接应用 log.info 来模仿。业务理论场景，存储的 ES。次要为了不便检索。

@Slf4j
@Aspect
@Component
public class BizLogAspect {@Pointcut("@annotation(com.example.sgdemo.annotation.BizLog)")
    public void logPointCut() {}

    @Before("logPointCut()")
    public void logBefore(JoinPoint point) {log.debug("[ZOHO 日志记录] 切入点 args=>{}", point.getArgs());
        //
        try {final BizLog bizLog = getBizLog(point);
            final String logArg = bizLog.logArg();
            Object rawParam = getRawParam(point, logArg);
            if (Objects.isNull(rawParam)) {log.error("[ZOHO 日志记录] 参数获取异样, 请查看 methodSign=>{}, logArg=>{}", point.getSignature(), logArg);
                return;
            }
            // 商机 ID
            String dealId = null;
            if (rawParam instanceof BizIdentify) {dealId = ((BizIdentify) rawParam).getBizId();}
            // 日志记录
            doSaveLog(bizLog.logModule(), bizLog.logType(), dealId, rawParam);
        } catch (Exception ex) {log.warn("[ZOHO 日志记录] 异样 ex=>{}", ex.getLocalizedMessage(), ex);
        }
    }

    private static BizLog getBizLog(JoinPoint point) {final MethodSignature methodSign = (MethodSignature) point.getSignature();
        final Method method = methodSign.getMethod();
        return method.getAnnotation(BizLog.class);
    }

    private static Object getRawParam(JoinPoint point, String argName) {final Object[] args = point.getArgs();
        final MethodSignature methodSign = (MethodSignature) point.getSignature();
        final int indexOf = ArrayUtils.indexOf(methodSign.getParameterNames(), argName);
        if (indexOf > -1) {return args[indexOf];
        }
        return null;
    }

    private void doSaveLog(EventLogModule logModule, EventLogType logType, String bizId, Object rawParam) {
        log.info("\n" +
                "[业务日志] ----------------\n" +
                "module: {}\n" +
                "type: {}\n" +
                "bizId: {}\n" +
                "param: {}\n" +
                "---------------------------\n", logModule, logType, bizId, rawParam);
    }
}

2.4 来模仿其中一个场景

模仿线索转商机场景。由 CRM 外部工作流触发，发动 HTTP 申请。

@Data
public class LeadToDealReqVO implements BizIdentify {

    private String dealId;
    private String phone;
    private String email;
    private String channel;
    // 商机阶段
    private String stage;

    /**
     * 获取 BizId (大部分状况是 DealId)
     *
     * @return bizId
     */
    @Override
    public String getBizId() {return dealId;}
}

业务解决

@Slf4j
@Service
public class LeadToDealServiceImpl implements LeadToDealService {@BizLog(logType = EventLogType.LEAD_TO_DEAL)
    @Override
    public boolean leadToDeal(LeadToDealReqVO vo) {log.info("[线索转商机] 解决中...");
        return true;
    }
}

触发执行，查看日志

2022-11-30 17:33:30.839  INFO 22986 --- [io-28800-exec-1] c.example.sgdemo.component.WebLogAspect  : [接口入参] {"costTime":0,"parameter":[{"stage":"To Schedule","phone":"+5633089972","dealId":"1234567890","channel":"OA-XX-XX","email":"ming.xiao22@gmail.com"}],"ip":"127.0.0.1","methodName":"POST","beginTime":1669800810820,"uri":"/leadToDeal"}
2022-11-30 17:33:30.856  INFO 22986 --- [io-28800-exec-1] c.example.sgdemo.component.BizLogAspect  : 
[业务日志] ----------------
module: EventLogModule.DEALS(key=DEALS, val= 商机, alias=Deals)
type: EventLogType.LEAD_TO_DEAL(key=LEAD_TO_DEAL, val= 线索转商机)
bizId: 1234567890
param: LeadToDealReqVO(dealId=1234567890, phone=+5633089972, email=ming.xiao22@gmail.com, channel=OA-XX-XX, stage=To Schedule)
---------------------------

2022-11-30 17:33:30.881  INFO 22986 --- [io-28800-exec-1] c.e.s.service.LeadToDealServiceImpl      : [线索转商机] 解决中...
2022-11-30 17:33:30.882  INFO 22986 --- [io-28800-exec-1] c.example.sgdemo.component.WebLogAspect  : [接口出参] {"result":{"msg":"ok","code":200,"data":true},"costTime":62,"parameter":[{"stage":"To Schedule","phone":"+5633089972","dealId":"1234567890","channel":"OA-XX-XX","email":"ming.xiao22@gmail.com"}],"ip":"127.0.0.1","methodName":"POST","beginTime":1669800810820,"uri":"/leadToDeal"}

3 后记

其实在业务代码理论批改过程中，发现局部状况是没方法应用注解解决的。究其原因是代码写的不标准，并不具备 高内聚低耦合 的个性。

其中一个业务 留资进线，须要在本地做很多的校验和解决，前几篇设计模式根本都跟这块的数据处理有关系。在行将推送到 CRM 的函数中，又对数据做了一些解决。在函数内部，基本拿不到最终的参数。

其实这种解决形式也简略：

  • 拆分函数，将解决和理论推送拆开，使其合乎 繁多职责。
  • 做肯定水平的容忍，保留日志服务对外提供性能，做肯定水平的 兼容?。

另: https://tech.meituan.com/…

退出移动版