自己使用springcloud搭建了一套简单的网关,在做压测时发现时不时的会出现请求超时,排查了一下发现是zuul filter执行时间长,但实际上zuulfiter中并没有什么执行逻辑,自己在run中打印了执行时间,耗时是0毫秒;但是通过ctx.getFilterExecutionSummary()打印的执行时间却是1000+毫秒,看源码中zuulfilter的执行逻辑,也没发现有耗时的地方。使用的是2.0.3.Release版本,还请大神帮忙给看下,以下贴出主要代码。
自定义的父类,只是为了统一处理异常:
public abstract class GatewayFilter extends ZuulFilter {
private static final Logger logger = LoggerFactory.getLogger(GatewayFilter.class);
public abstract Object doRun() throws GatewayException;
@Override
public Object run() throws ZuulException {
try {
Object data = doRun();
return data;
}catch (GatewayException ex){
throw new ZuulException(ex, ex.getCause().getMessage(), HttpStatus.INTERNAL_SERVER_ERROR.value(),ex.getMessage());
}
}
}
自定义Filter,仅仅只是写入接到请求的时间:
public class PreAfterServlet30Filter extends GatewayFilter {
private static final Logger logger = LoggerFactory.getLogger(PreAfterServlet30Filter.class);
public PreAfterServlet30Filter() {
}
@Override
public String filterType() {
return PRE_TYPE;
}
@Override
public int filterOrder() {
return -2;
}
@Override
public Object doRun() {
long st = System.currentTimeMillis();
final RequestContext ctx = RequestContext.getCurrentContext();
final HttpServletRequest request = ctx.getRequest();
ctx.set("REQUEST_BEGIN_TIME",st);
String requestUniqueKey = request.getParameter("uniqKey");
logger.info("PreAfterServlet30Filter, requestUniqueKey :{}, cost:{}" , new Object[]{requestUniqueKey , System.currentTimeMillis() - st});
return null;
}
@Override
public boolean shouldFilter() {
return true;
}
}
日志输出信息:
2019-08-14 21:40:49.972 [http-nio-8080-exec-63] INFO c.xxx.PreAfterServlet30Filter - PreAfterServlet30Filter, requestUniqueKey :29d1f24c50fb55af0ce128f2977d12a4, cost:0
2019-08-14 21:40:51.434 [http-nio-8080-exec-63] WARN xxxx.PostRequestFilter - 127.0.0.1|/xxx.action|GET|29d1f24c50fb55af0ce128f2977d12a4|1462|ServletDetectionFilter[SUCCESS][0ms], Servlet30WrapperFilter[SUCCESS][0ms], PreAfterServlet30Filter[SUCCESS][ 1380ms ], xxxFilter[SUCCESS][26ms], PreDecorationFilter[SUCCESS][0ms], xxxPreFilter[SUCCESS][27ms], xxxFilter[SUCCESS][0ms], xxxFilter[SUCCESS][28ms]ms]