如何低侵入的记录调用日志

前言

前阵子朋友他老大叫他实现这么一个功能,就是低侵入的记录接口每次的请求响应日志,然后并统计每次请求调用的成功、失败次数以及响应耗时,当时朋友的实现思路是在每个业务的controller的方法上加一个自定义注解,然后写一个aop,以这个自定义注解为pointcut来记录日志。

这种AOP+注解来实现日志记录,应该是很常见的实现方式。然而朋友在落地的时候,发现项目要加自定义注解的地方太多。后面我就跟他说,那就不写注解,直接以形如下

execution(* com.github.lybgeek.logaop.service..*.*(..))

这样不行吗?他说他这个功能他老大是希望给各个项目组使用,像我上面的方法,估计行不通,我就问他说为啥行不通,他说各个项目的包名都不一样,如果我那种思路,他就说这样在代码里poincut不得要这么写

execution(* com.github.lybgeek.a.service..*.*(..) 
|| * com.github.lybgeek.b.service..*.*(..) || * com.github.lybgeek.c.service..*.*(..) )

这样每次新加要日志记录,都得改切面代码,还不如用自定注解来的好。听完他的解释,我一脸黑人问号脸。于是就趁着5.1假期期间,写个demo实现上面的需求

业务场景

低侵入的记录接口每次的请求响应日志,然后并统计每次请求调用的成功、失败次数以及响应耗时

这个业务需求应该算是很简单,实现的难点就在于低侵入,提到低侵入,我首先想到是使用者无需写代码,或者只需写少量代码或者仅需简单配置一下,最好能做到业务无感知。

实现手段

我这边提供2种思路

  • javaagent + byte-buddy
  • springboot自动装配 + AOP

javaagent

1、什么是javaagent

javaagent是一个简单优雅的java agent,利用java自带的instrument特性+javassist/byte-buddy字节码可以实现对类的拦截或者增强。

javaAgent 是运行在 main方法之前的拦截器,它内定的方法名叫 premain ,也就是说先执行 premain 方法然后再执行 main 方法

2、如何实现一个javaagent

  • a、必须实现premain方法

示例:

public class AgentDemo {

    public static void premain(String agentArgs, Instrumentation inst) {
        System.out.println("agentArgs : " + agentArgs);
        inst.addTransformer(new DefineTransformer(),true);
    }

    static class DefineTransformer implements ClassFileTransformer {

        @Override
        public byte[] transform(ClassLoader loader, String className, Class<?> classBeingRedefined, ProtectionDomain protectionDomain, byte[] classfileBuffer) throws IllegalClassFormatException {
            System.out.println("premain load Class:" + className);
            return classfileBuffer;
        }
    }
}
  • b、在META-INF目录添加MANIFEST.MF文档,内容形如下
Manifest-Version: 1.0
Implementation-Version: 0.0.1-SNAPSHOT
Premain-Class: com.github.lybgeek.agent.ServiceLogAgent
Can-Redefine-Classes: true

其中Premain-Class是必选项。MANIFEST.MF可以利用maven插件进行生成,插件如下

 <plugin>
                <groupId>org.apache.maven.plugins</groupId>
                <artifactId>maven-jar-plugin</artifactId>
                <version>3.2.0</version>
                <configuration>
                    <archive>
                        <manifest>
                            <addClasspath>true</addClasspath>
                        </manifest>
                        <manifestEntries>
                            <Premain-Class>com.github.lybgeek.agent.ServiceLogAgent</Premain-Class>
                            <Agent-Class>com.github.lybgeek.agent.ServiceLogAgent</Agent-Class>
                            <Can-Redefine-Classes>true</Can-Redefine-Classes>
                            <Can-Retransform-Classes>true</Can-Retransform-Classes>
                        </manifestEntries>
                    </archive>
                </configuration>
            </plugin>

3、业务代码如何使用javagent

java -javaagent:agentjar文件的位置 [= 传入 premain的参数 ] -jar 要运行的jar文件

:-javaagent一定要在-jar之前,不然不会生效

byte-buddy

1、什么是byte-buddy

Byte Buddy是一个JVM的运行时代码生成器,你可以利用它创建任何类,且不像JDK动态代理那样强制实现一个接口。Byte Buddy还提供了简单的API,便于手工、通过Java Agent,或者在构建期间修改字节码

2、byte-buddy教程

注: 如果再介绍byte-buddy使用,则篇幅会比较长,因此提供以下2个byte-buddy学习链接,感兴趣的朋友可以点击查看

https://blog.gmem.cc/byte-buddy-study-note

https://notes.diguage.com/byte-buddy-tutorial/

如何利用javaagent + byte-buddy实现低侵入记录日志

1、编写agent入口类

public class ServiceLogAgent {


    public static String base_package_key = "agent.basePackage";

    public static void premain(String agentArgs, Instrumentation inst) {
        System.out.println("loaded agentArgs :" + agentArgs);
        Properties properties = PropertiesUtils.getProperties(agentArgs);
        ServiceLogHelperFactory serviceLogHelperFactory = new ServiceLogHelperFactory(properties);
        serviceLogHelperFactory.getServiceLogHelper().initTable();

        AgentBuilder.Transformer transformer = (builder, typeDescription, classLoader, javaModule) -> {
            return builder
                    .method(ElementMatchers.<MethodDescription>any()) // 拦截任意方法
                    .intercept(MethodDelegation.to(new ServiceLogInterceptor(serviceLogHelperFactory))); // 委托
        };

        AgentBuilder.Listener listener = new AgentBuilder.Listener() {
            private Log log = LogFactory.getLog(AgentBuilder.Listener.class);

            @Override
            public void onDiscovery(String s, ClassLoader classLoader, JavaModule javaModule, boolean b) {
            }

            @Override
            public void onTransformation(TypeDescription typeDescription, ClassLoader classLoader, JavaModule javaModule, boolean b, DynamicType dynamicType) {
            }

            @Override
            public void onIgnored(TypeDescription typeDescription, ClassLoader classLoader, JavaModule javaModule, boolean b) {
            }

            @Override
            public void onError(String s, ClassLoader classLoader, JavaModule javaModule, boolean b, Throwable throwable) {
                log.error(throwable.getMessage(),throwable);
            }

            @Override
            public void onComplete(String s, ClassLoader classLoader, JavaModule javaModule, boolean b) {
            }

        };

        new AgentBuilder
                .Default()
                // 指定需要拦截的类
                .type(ElementMatchers.nameStartsWith(properties.getProperty(base_package_key)))
                .and(ElementMatchers.isAnnotatedWith(Service.class))
                .transform(transformer)
                .with(listener)
                .installOn(inst);
    }


}

2、编写拦截器

public class ServiceLogInterceptor {
    private Log log = LogFactory.getLog(ServiceLogInterceptor.class);


    private ServiceLogHelperFactory serviceLogHelperFactory;

    public ServiceLogInterceptor(ServiceLogHelperFactory serviceLogHelperFactory) {
        this.serviceLogHelperFactory = serviceLogHelperFactory;
    }

    @RuntimeType
    public Object intercept(@AllArguments Object[] args, @Origin Method method, @SuperCall Callable<?> callable) {
        long start = System.currentTimeMillis();
        long costTime = 0L;
        String status = ServiceLog.SUCEESS;
        Object result = null;
        String respResult = null;
        try {
            // 原有函数执行
            result = callable.call();
            respResult = JsonUtils.object2json(result);
        } catch (Exception e){
            log.error(e.getMessage(),e);
            status = ServiceLog.FAIL;
            respResult = e.getMessage();
        } finally{
            costTime = System.currentTimeMillis() - start;
            saveLog(args, method, costTime, status, respResult);
        }
        return result;
    }

    private void saveLog(Object[] args, Method method, long costTime, String status, String respResult) {
        if(!isSkipLog(method)){
            ServiceLog serviceLog = serviceLogHelperFactory.createServiceLog(args,method);
            serviceLog.setCostTime(costTime);
            serviceLog.setRespResult(respResult);
            serviceLog.setStatus(status);
            ServiceLogHelper serviceLogHelper = serviceLogHelperFactory.getServiceLogHelper();
            serviceLogHelper.saveLog(serviceLog);
        }
    }


    private boolean isSkipLog(Method method){
        ServiceLogProperties serviceLogProperties = serviceLogHelperFactory.getServiceLogProperties();
        List<String> skipLogServiceNameList = serviceLogProperties.getSkipLogServiceNameList();
        if(!CollectionUtils.isEmpty(skipLogServiceNameList)){
            String currentServiceName = method.getDeclaringClass().getName() + ServiceLogProperties.CLASS_METHOD_SPITE + method.getName();
            return skipLogServiceNameList.contains(currentServiceName);
        }
        return false;
    }



}

3、通过maven将agent打包成jar

4、效果演示

首先idea在启动类的vm参数,加入形如下内容

 -javaagent:F:\springboot-learning\springboot-agent\springboot-javaagent-log\target\agent-log.jar=F:\springboot-learning\springboot-agent\springboot-javaagent-log\target\classes\agent.properties

效果图


image.png

image.png

image.png

如何利用自动装配+AOP实现低侵入记录日志

注: 其实朋友那种方式也差不多可以了,只需把poincut的外移到配置文件文件即可

1、编写切面

@Slf4j
public class ServiceLogAdvice implements MethodInterceptor {

    private LogService logService;

    public ServiceLogAdvice(LogService logService) {
        this.logService = logService;
    }

    @Override
    public Object invoke(MethodInvocation invocation)  {

        long start = System.currentTimeMillis();
        long costTime = 0L;
        String status = ServiceLog.SUCEESS;
        Object result = null;
        String respResult = null;
        try {
            // 原有函数执行
            result = invocation.proceed();
            respResult = JSON.toJSONString(result);
        } catch (Throwable e){
            log.error(e.getMessage(),e);
            status = ServiceLog.FAIL;
            respResult = e.getMessage();
        } finally{
            costTime = System.currentTimeMillis() - start;
            saveLog(invocation.getArguments(), invocation.getMethod(), costTime, status, respResult);
        }
        return result;

    }

    private void saveLog(Object[] args, Method method, long costTime, String status, String respResult) {
            ServiceLog serviceLog = ServiceLog.builder()
                                    .serviceName(method.getDeclaringClass().getName())
                                    .costTime(costTime)
                                    .methodName(method.getName())
                                    .status(status)
                                    .reqArgs(JSON.toJSONString(args))
                                    .respResult(respResult).build();
           logService.saveLog(serviceLog);
    }
}

2、注入切面bean

 @Bean
    @ConditionalOnMissingBean
    public AspectJExpressionPointcutAdvisor serviceLogAspectJExpressionPointcutAdvisor(AopLogProperties aopLogProperties) {
        AspectJExpressionPointcutAdvisor advisor = new AspectJExpressionPointcutAdvisor();
        advisor.setExpression(aopLogProperties.getPointcut());
        advisor.setAdvice(serviceLogAdvice());
        return advisor;
    }

3、编写自动装配类

@Configuration
@EnableConfigurationProperties(AopLogProperties.class)
@ConditionalOnProperty(prefix = "servicelog",name = "enabled",havingValue = "true",matchIfMissing = true)
public class AopLogAutoConfiguration {

    @Autowired
    private JdbcTemplate jdbcTemplate;

    @Bean
    @ConditionalOnMissingBean
    public LogService logService(){
        return new LogServiceImpl(jdbcTemplate);
    }

    @Bean
    @ConditionalOnMissingBean
    public ServiceLogAdvice serviceLogAdvice(){
        return new ServiceLogAdvice(logService());
    }

    @Bean
    @ConditionalOnMissingBean
    public AspectJExpressionPointcutAdvisor serviceLogAspectJExpressionPointcutAdvisor(AopLogProperties aopLogProperties) {
        AspectJExpressionPointcutAdvisor advisor = new AspectJExpressionPointcutAdvisor();
        advisor.setExpression(aopLogProperties.getPointcut());
        advisor.setAdvice(serviceLogAdvice());
        return advisor;
    }


}

4、编写spring.factories

org.springframework.boot.autoconfigure.EnableAutoConfiguration=\
    com.github.lybgeek.logaop.config.AopLogAutoConfiguration

5、效果演示

在业务代码做如下配置

  • 5.1 在pom.xml引入starter
  <dependency>
            <groupId>com.github.lybgeek</groupId>
            <artifactId>aoplog-springboot-starter</artifactId>
            <version>0.0.1-SNAPSHOT</version>
        </dependency>
  • 5.2 在yml文件中配置pointcut
servicelog:
  pointcut: execution(* com.github.lybgeek.mock.service.client..*.*(..))
  enabled: true
  • 5.3 效果图
image.png

在这里插入图片描述

总结

以上主要列举了通过javaagent和aop加自动装配2两种方式来实现低侵入记录日志。其实这两种实现在一些开源的方案用得挺多的,比如byte-buddy在skywalking和arthas就有使用到,比如MethodInterceptor 在spring事务中就有用到。所以多看些源码,在设计方案时,有时候会产生意想不到的火花

demo链接

https://github.com/lyb-geek/springboot-learning/tree/master/springboot-agent

©著作权归作者所有,转载或内容合作请联系作者
  • 序言:七十年代末,一起剥皮案震惊了整个滨河市,随后出现的几起案子,更是在滨河造成了极大的恐慌,老刑警刘岩,带你破解...
    沈念sama阅读 220,063评论 6 510
  • 序言:滨河连续发生了三起死亡事件,死亡现场离奇诡异,居然都是意外死亡,警方通过查阅死者的电脑和手机,发现死者居然都...
    沈念sama阅读 93,805评论 3 396
  • 文/潘晓璐 我一进店门,熙熙楼的掌柜王于贵愁眉苦脸地迎上来,“玉大人,你说我怎么就摊上这事。” “怎么了?”我有些...
    开封第一讲书人阅读 166,403评论 0 357
  • 文/不坏的土叔 我叫张陵,是天一观的道长。 经常有香客问我,道长,这世上最难降的妖魔是什么? 我笑而不...
    开封第一讲书人阅读 59,110评论 1 295
  • 正文 为了忘掉前任,我火速办了婚礼,结果婚礼上,老公的妹妹穿的比我还像新娘。我一直安慰自己,他们只是感情好,可当我...
    茶点故事阅读 68,130评论 6 395
  • 文/花漫 我一把揭开白布。 她就那样静静地躺着,像睡着了一般。 火红的嫁衣衬着肌肤如雪。 梳的纹丝不乱的头发上,一...
    开封第一讲书人阅读 51,877评论 1 308
  • 那天,我揣着相机与录音,去河边找鬼。 笑死,一个胖子当着我的面吹牛,可吹牛的内容都是我干的。 我是一名探鬼主播,决...
    沈念sama阅读 40,533评论 3 420
  • 文/苍兰香墨 我猛地睁开眼,长吁一口气:“原来是场噩梦啊……” “哼!你这毒妇竟也来了?” 一声冷哼从身侧响起,我...
    开封第一讲书人阅读 39,429评论 0 276
  • 序言:老挝万荣一对情侣失踪,失踪者是张志新(化名)和其女友刘颖,没想到半个月后,有当地人在树林里发现了一具尸体,经...
    沈念sama阅读 45,947评论 1 319
  • 正文 独居荒郊野岭守林人离奇死亡,尸身上长有42处带血的脓包…… 初始之章·张勋 以下内容为张勋视角 年9月15日...
    茶点故事阅读 38,078评论 3 340
  • 正文 我和宋清朗相恋三年,在试婚纱的时候发现自己被绿了。 大学时的朋友给我发了我未婚夫和他白月光在一起吃饭的照片。...
    茶点故事阅读 40,204评论 1 352
  • 序言:一个原本活蹦乱跳的男人离奇死亡,死状恐怖,灵堂内的尸体忽然破棺而出,到底是诈尸还是另有隐情,我是刑警宁泽,带...
    沈念sama阅读 35,894评论 5 347
  • 正文 年R本政府宣布,位于F岛的核电站,受9级特大地震影响,放射性物质发生泄漏。R本人自食恶果不足惜,却给世界环境...
    茶点故事阅读 41,546评论 3 331
  • 文/蒙蒙 一、第九天 我趴在偏房一处隐蔽的房顶上张望。 院中可真热闹,春花似锦、人声如沸。这庄子的主人今日做“春日...
    开封第一讲书人阅读 32,086评论 0 23
  • 文/苍兰香墨 我抬头看了看天上的太阳。三九已至,却和暖如春,着一层夹袄步出监牢的瞬间,已是汗流浃背。 一阵脚步声响...
    开封第一讲书人阅读 33,195评论 1 272
  • 我被黑心中介骗来泰国打工, 没想到刚下飞机就差点儿被人妖公主榨干…… 1. 我叫王不留,地道东北人。 一个月前我还...
    沈念sama阅读 48,519评论 3 375
  • 正文 我出身青楼,却偏偏与公主长得像,于是被迫代替她去往敌国和亲。 传闻我的和亲对象是个残疾皇子,可洞房花烛夜当晚...
    茶点故事阅读 45,198评论 2 357

推荐阅读更多精彩内容