回复
一款给日志打标签实现精确定位的日志切面利器
gnt_xxy
发布于 2023-1-10 10:53
浏览
0收藏
1
不知道各位在生产日志中定位问题时有没有碰到这样的场景：由于coding的时候日志输出的比较少，出现问题时，很难通过日志去定位到问题。又或者是，你明明coding的时候有输出日志。但是在庞大的日志文件中，由于业务线程并发比较多，你输出的日志又没有加关键信息。你也很难定位到你所需要的日志信息。
之前在公司里写业务代码时，为了使每个RPC调用能被日志记录下来，我们在公司基础组件里定义了一个切面，拦截所有的RPC调用，方法开始之前，在日志里输出调用的服务和方法以及参数，方法结束时输出方法的耗时。我相信很多人也是这么做的。
这样一来 ，所有的调用都能通过参数里的关键信息被搜索到。也能定位到调用是什么结束的以及耗时。
但是在有些业务方法中，也打上了很多的业务日志。由于核心业务的tps和qps很高，日志是互相穿插的。如果你的日志没有打上关键的业务信息(比如订单号，业务ID)，那就很难在日志中被定位出来。
也许有些童鞋会说，用线程号呀。通过搜索业务ID定位到调用开始的地方，再搜索这条线程的线程号，就可以定位整个请求的所有日志。其实之前我也是这么干的，但是线程一般都是由线程池进行管理的，在tps很高的业务中，同一个线程号有可能短时间会出现多次，但是却是不同的请求。而且业务方法中可能也会有异步线程，导致了线程号会变。这样对于定位日志就又增加了难度。当然最后可以通过对时间戳的分析，还是可以定位到具体日志。但是这样就增加了定位的时间成本。
如果你的公司对微服务使用了分布式追踪，那么定位日志可以通过traceId来解决。如果没有在生产上应用分布式追踪，又想在并发比较高的应用的日志上快速定位到所需要的日志。其中一个比较有效的办法就是：规范日志的输出格式。
在每行日志输出时尽可能的加上关键的业务信息，然后定位起来就比较清晰了，例如：
这里每一行日志都加上了订单号和请求ID，我们把这样的日志头信息称之为日志标签，有了这些标签定位起来就比较容易了。
那这样是不是意味着每写一行日志，都必须加上这样日志标签信息呢？这是不是也麻烦了？
答案是不用的。
推荐一款自动给日志打标签实现精确定位的日志切面框架，你使用了这个，你的日志可以实现自定义的业务标签！
2
这是一款小巧，轻量级，对业务几乎无侵入的日志切面框架。特性为：
- 使用简单，不侵入业务代码。只需要在方法上配置标注
- 支持log4j，logback，log4j2三种常见的日志框架
- 配置极其简单。提供“一键配置”，自动识别日志框架
- 在方法上配置，无论调用多深或者异步调用。也可以统一加上日志标签
- 无性能损耗
使用方法很简单，如果你是springboot，aspect-log提供了自动装配，GAV为：
<dependency>
<groupId>com.yomahub</groupId>
<artifactId>aspect-log-spring-boot-starter</artifactId>
<version>1.2</version>
<dependency>如果你是spring，GAV为：
<dependency>
<groupId>com.yomahub</groupId>
<artifactId>aspect-log-core</artifactId>
<version>1.2</version>
<dependency>spring的项目同时需要在你的application.xml里定义
<bean class="com.yomahub.aspectlog.aop.AspectLogAop"/>接下来在你的方法上加上@AspectLog标注，简单的例子如下：
@AspectLog({"id"})
public void demo1(String id,String name){
log.info("这是第一条日志");
log.info("这是第二条日志");
log.info("这是第三条日志");
new Thread(() -> log.info("这是异步日志")).start();
}假设id的值为'NO1234'，日志打出来的样子如下：
2020-02-08 20:22:33.945 [main] INFO Demo - [NO1234] 这是第一条日志
2020-02-08 20:22:33.945 [main] INFO Demo - [NO1234] 这是第二条日志
2020-02-08 20:22:33.945 [main] INFO Demo - [NO1234] 这是第三条日志
2020-02-08 20:22:33.948 [Thread-3] INFO Demo - [NO1234] 这是异步日志
@AspectLog支持多个标签:
@AspectLog({"id","name"})
public void demo1(String id,String name){
log.info("这是第一条日志");
log.info("这是第二条日志");
log.info("这是第三条日志");
new Thread(() -> log.info("这是异步日志")).start();
}假设传入id的值为'NO1234'，name为'jenny'，日志打出来的样子如下：
2020-02-08 22:09:40.101 [main] INFO Demo - [NO1234-jenny] 这是第一条日志
2020-02-08 22:09:40.101 [main] INFO Demo - [NO1234-jenny] 这是第二条日志
2020-02-08 22:09:40.102 [main] INFO Demo - [NO1234-jenny] 这是第三条日志
2020-02-08 22:09:40.103 [Thread-3] INFO Demo - [NO1234-jenny] 这是异步日志
@AspectLog支持自定pattern和多个参数的连接符
@AspectLog(value = {"id","name"},pattern = "<-{}->",joint = "_")
public void demo(String id,String name){
log.info("加了patter和joint的示例");
}日志打出来的样子如下：
2020-02-08 22:09:40.103 [main] INFO Demo - 加了patter和joint的示例
@AspectLog支持点操作符，适用于对象的取值，支持类型为业务对象和Map
@AspectLog({"person.id","person.age","person.company.department.dptId"})
public void demo(Person person){
log.info("多参数加多层级示例");
}日志打出来的样子如下：
2020-02-08 22:09:40.110 [main] INFO Demo - [31-25-80013] 多参数加多层级示例
@AspectLog支持自定义Convert，适用于更复杂的业务场景
@AspectLog(convert = CustomAspectLogConvert.class)
public void demo(Person person){
log.info("自定义Convert示例");
}
public class CustomAspectLogConvert implements AspectLogConvert {
@Override
public String convert(Object[] args){
Person person = (Person)args[0];
return "PERSON(" + person.getId() + ")";
}
}日志打印出来的样子如下：
2020-02-20 17:05:12.414 [main] INFO Demo - [PERSON(31] 自定义Convert示例
@AspectLog支持编程式设值
public void demo(){
AspectLogContext.putLogValue("[SO1001]");
log.info("代码控制示例");
}日志打出来的样子：
2020-02-08 22:09:40.110 [main] INFO Demo - [SO1001] 代码控制示例3
日志输出对于一个服务来说，即是执行轨迹的记录，也是寻错找源的根本。日志打的全面而工整，对于排查问题来说，是事半功倍的，相信小伙伴都有看过乱糟糟的日志吧，在一堆这样的日志文件中取寻根溯源，那是极其痛苦的。
我相信很多开发者都有着代码洁癖，工程的架构，代码的结构，变量的定义，都有着苛刻的要求。这是种好习惯，这种好习惯会使代码的阅读和理解事半功倍。
所以Aspect-log就是这样一款能让你的日志也变得工整和赏心悦目的工具。
最后附上Aspect-log的工程主页，欢迎关注和提出issue
https://bryan31.gitee.io/aspect-log
希望这款小工具能让你的日志变得工整，能让你的排查变得简单而快捷。
文章转载自公众号：元人部落
分类
已于2023-1-10 10:55:23修改
赞
收藏
回复
相关推荐
