场景:最近需要将大量数据实时同步到es中,代码写好之后接口怎么查都很慢,但是能做的缓存和各种优化已经都做了,排查到最后发现是Log日志引起的耗时,下面测试一些log日志的具体耗时。
@Slf4j
@RestController
@RequestMapping("/system/atest")
public class AtestController {
@GetMapping("/testLog")
public String testLog(){
long start = System.currentTimeMillis();
log.info("test log");
log.info("耗时:{}ms",System.currentTimeMillis()-start);
return System.currentTimeMillis()-start+"ms";
}
}
上面接口在控制台输出两条日志,test log和test log的耗时,并返回整个接口的耗时,下面是结果信息。
控制台日志信息:
接口返回结果:
可以看到test log这一行日志控制台输出耗时为100ms,接口返回的为192ms,耗时输出的log大约耗时92ms,postman显示接口执行时间为203ms。
log.info()一条日志信息耗时约70-100ms,这要是在循环里打印日志信息,接口的查询耗时会直线上升,生产环境大量的循环中尽量不要打印日志信息