SpringBoot 编写的接口调用时间过长的原因

这两天项目组的一个小伙子遇见一个奇怪的问题, 使用SpringBoot编写了一个API接口,在第一次和第二次调用的时候, 速度在10ms以内完成, 但是在第三次的时候, 会慢到1s左右,慢了100倍.而且后面非常稳定, 从第三次,第四次,第五次等都是1s左右.为了排除业务问题,把接口代码简化成:

public R info()

{

for(int i = 0; i < 100; i ++)

{

System.out.println(i);

}

return R.ok();

}

这样的代码,排除了一切数据访问,获取redis锁等业务逻辑,就简单的sysout输出100个数,就可以出现上面说的问题.

经过2天的排查,发现是logback惹的祸.

logback有一个功能是使用SocketAppender, 把日志通过socket的形式发送给第三方中间件(比如kafka等),但是如果没有接收方, logback会持续把日志放到socket的缓存里面,并且这个放的方式是阻塞的,一旦缓存满了, 就会由于一直放不进去,超时以后才会执行下一步代码.所以就会发现,执行每一步代码,都会发生阻塞,超时,然后执行,然后再阻塞,超时.从而导致了java的所有代码执行都会有延迟.

具体代码就不贴了, 搜索 SocketAppender, 就会有较多的资料