给日志打标签,让你的日志定位再无困难
背景
不知道各位在生产日志中定位问题时有没有碰到这样的场景:由于coding的时候日志输出的比较少,出现问题时,很难通过日志去定位到问题。又或者是,你明明coding的时候有输出日志。但是在庞大的日志文件中,由于业务线程并发比较多,你输出的日志又没有加关键信息。你也很难定位到你所需要的日志信息。
之前在公司里写业务代码时,为了使每个RPC调用能被日志记录下来,我们在公司基础组件里定义了一个切面,拦截所有的RPC调用,方法开始之前,在日志里输出调用的服务和方法以及参数,方法结束时输出方法的耗时。我相信很多人也是这么做的。
这样一来 ,所有的调用都能通过参数里的关键信息被搜索到。也能定位到调用是什么结束的以及耗时。
但是在有些业务方法中,也打上了很多的业务日志。由于核心业务的tps和qps很高,日志是互相穿插的。如果你的日志没有打上关键的业务信息(比如订单号,业务ID),那就很难在日志中被定位出来。
也许有些童鞋会说,用线程号呀。通过搜索业务ID定位到调用开始的地方,再搜索这条线程的线程号,就可以定位整个请求的所有日志。其实之前我也是这么干的,但是线程一般都是由线程池进行管理的,在tps很高的业务中,同一个线程号有可能短时间会出现多次,但是却是不同的请求。而且业务方法中可能也会有异步线程,导致了线程号会变。这样对于定位日志就又增加了难度。当然最后可以通过对时间戳的分析,还是可以定位到具体日志。但是这样就增加了定位的时间成本。
如果你的公司对微服务使用了分布式追踪,那么定位日志可以通过traceId来解决。如果没有在生产上应用分布式追踪,又想在并发比较高的应用的日志上快速定位到所需要的日志。其中一个比较有效的办法就是:规范日志的输出格式
。
在每行日志输出时尽可能的加上关键的业务信息,然后定位起来就比较清晰了,例如:
这里每一行日志都加上了订单号和请求ID,我们把这样的日志头信息称之为日志标签
,有了这些标签定位起来就比较容易了。
那这样是不是意味着每写一行日志,都必须加上这样日志标签信息呢?这是不是也麻烦了?
答案是不用的。
推荐一款自动给日志打标签实现精确定位的日志切面框架,你使用了这个,你的日志可以实现自定义的业务标签!
点击Aspect-log跳转到开源主页,或者复制以下地址:
https://gitee.com/bryan31/aspect-log
Aspect-log介绍
这是一款小巧,轻量级,对业务几乎无侵入的日志切面框架。特性为:
- 使用简单,不侵入业务代码。只需要在方法上配置标注
- 支持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"/>
如果你使用springboot,AspectLog切面会自动装配好。
一键配置方法
这种方式用javassit实现,只需要一句话就可以实现。自动识别当前主流的日志框架。
@SpringBootApplication
public class Runner {
static {AspectLogEnhance.enhance();}//进行日志增强,自动判断日志框架
public static void main(String[] args) {
try {
SpringApplication.run(Runner.class, args);
} catch (Throwable e) {
e.printStackTrace();
}
while (true) {
try {
Thread.sleep(60000);
} catch (Throwable e) {
e.printStackTrace();
}
}
}
}
针对于主流的Log日志框架作了适配(推荐用这种)
针对于每种Log日志框架提供了适配,具体使用方法请参照项目主页里的文档。
如何使用
接下来在你的方法上加上@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 - <-NO1234_jenny-> 加了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] 代码控制示例
结尾
日志输出对于一个服务来说,即是执行轨迹的记录,也是寻错找源的根本。日志打的全面而工整,对于排查问题来说,是事半功倍的,相信小伙伴都有看过乱糟糟的日志吧,在一堆这样的日志文件中取寻根溯源,那是极其痛苦的。
我相信很多开发者都有着代码洁癖,工程的架构,代码的结构,变量的定义,都有着苛刻的要求。这是种好习惯,这种好习惯会使代码的阅读和理解事半功倍。
所以Aspect-log就是这样一款能让你的日志也变得工整和赏心悦目的工具。
最后附上Aspect-log的工程主页,欢迎关注和提出issue
希望这款小工具能让你的日志变得工整,能让你的排查变得简单而快捷。
联系作者
微信关注 「jishuyuanren」或者扫描以下二维码获取更多技术干货: