什么?我一行日志代码竟然让接口响应延迟了1s

一、背景

在某次开发过程中,对于一个接口,我只是加了一行代码竟然让接口响应延迟大大增加,感觉是很小一个错误,在此记录一下。

二、情景复现

先简单模拟一下当时的代码:

import lombok.extern.slf4j.Slf4j;
import org.springframework.web.bind.annotation.GetMapping;
import org.springframework.web.bind.annotation.RestController;

import java.util.concurrent.TimeUnit;

@RestController
@Slf4j
public class TestController {

    @GetMapping("/hello")
    public String hello(String type) {
        if ("old".equals(type)) {
            log.debug("type is old: {}", test());
        }
        return "hello," + type;
    }

    private String test() {
        try {
            // 模拟方法内容耗时
            TimeUnit.SECONDS.sleep(1);
        } catch (InterruptedException e) {
            e.printStackTrace();
        }
        System.out.println("test method run...");
        return "old";
    }

}

把应用日志级别指定为INFO级别:

logging:
  level: 
    root: info

代码逻辑很简单,参数type如果是old,日志级别是debug的话,需要打印一下debug日志,debug日志中需要调用一个方法。

下面我们进行测试:

  • 首先测试正常参数

    在这里插入图片描述

    可以看到此时响应时间在几十毫秒的样子。

  • 测试特殊参数

    在这里插入图片描述

    可以看到此时响应时间增长到1000多毫秒了,两者只是一行日志的区别。

三、问题解决

通过查看应用日志可以发现,即使是日志级别为debug才会打印的日志信息,也会触发里面的方法执行:

在这里插入图片描述

解决方法也很简单,增加一个判断就行,修改代码:

@GetMapping("/hello")
    public String hello(String type) {
        if ("old".equals(type)) {
            if (log.isDebugEnabled()) { // 判断是否是debug级别日志,否则不触发test()方法执行
                log.debug("type is old: {}", test());
            }
        }
        return "hello," + type;
    }

重新测试:

在这里插入图片描述

可以看到此时,方法耗时已经下降到正常范围了,通过应用日志也可以发现test()方法不再执行。

  • 6
    点赞
  • 1
    收藏
    觉得还不错? 一键收藏
  • 0
    评论
评论
添加红包

请填写红包祝福语或标题

红包个数最小为10个

红包金额最低5元

当前余额3.43前往充值 >
需支付:10.00
成就一亿技术人!
领取后你会自动成为博主和红包主的粉丝 规则
hope_wisdom
发出的红包
实付
使用余额支付
点击重新获取
扫码支付
钱包余额 0

抵扣说明:

1.余额是钱包充值的虚拟货币,按照1:1的比例进行支付金额的抵扣。
2.余额无法直接购买下载,可以购买VIP、付费专栏及课程。

余额充值