diff --git a/dubbo-rpc/dubbo-rpc-api/src/main/java/org/apache/dubbo/rpc/filter/TimeoutFilter.java b/dubbo-rpc/dubbo-rpc-api/src/main/java/org/apache/dubbo/rpc/filter/TimeoutFilter.java index ad783efd992..c00689fc1c8 100644 --- a/dubbo-rpc/dubbo-rpc-api/src/main/java/org/apache/dubbo/rpc/filter/TimeoutFilter.java +++ b/dubbo-rpc/dubbo-rpc-api/src/main/java/org/apache/dubbo/rpc/filter/TimeoutFilter.java @@ -25,6 +25,7 @@ import org.apache.dubbo.rpc.Invoker; import org.apache.dubbo.rpc.Result; import org.apache.dubbo.rpc.RpcException; +import org.apache.dubbo.rpc.RpcInvocation; import java.util.Arrays; @@ -36,21 +37,38 @@ public class TimeoutFilter implements Filter { private static final Logger logger = LoggerFactory.getLogger(TimeoutFilter.class); + private static final String TIMEOUT_FILTER_START_TIME = "timeout_filter_start_time"; + @Override public Result invoke(Invoker invoker, Invocation invocation) throws RpcException { - long start = System.currentTimeMillis(); - Result result = invoker.invoke(invocation); - long elapsed = System.currentTimeMillis() - start; - if (invoker.getUrl() != null - && elapsed > invoker.getUrl().getMethodParameter(invocation.getMethodName(), - "timeout", Integer.MAX_VALUE)) { - if (logger.isWarnEnabled()) { - logger.warn("invoke time out. method: " + invocation.getMethodName() - + " arguments: " + Arrays.toString(invocation.getArguments()) + " , url is " - + invoker.getUrl() + ", invoke elapsed " + elapsed + " ms."); + if (invocation.getAttachments() != null) { + long start = System.currentTimeMillis(); + invocation.getAttachments().put(TIMEOUT_FILTER_START_TIME, String.valueOf(start)); + } else { + if (invocation instanceof RpcInvocation) { + RpcInvocation invc = (RpcInvocation) invocation; + long start = System.currentTimeMillis(); + invc.setAttachment(TIMEOUT_FILTER_START_TIME, String.valueOf(start)); } } - return result; + return invoker.invoke(invocation); } + @Override + public Result onResponse(Result result, Invoker invoker, Invocation invocation) { + String startAttach = invocation.getAttachment(TIMEOUT_FILTER_START_TIME); + if (startAttach != null) { + long elapsed = System.currentTimeMillis() - Long.valueOf(startAttach); + if (invoker.getUrl() != null + && elapsed > invoker.getUrl().getMethodParameter(invocation.getMethodName(), + "timeout", Integer.MAX_VALUE)) { + if (logger.isWarnEnabled()) { + logger.warn("invoke time out. method: " + invocation.getMethodName() + + " arguments: " + Arrays.toString(invocation.getArguments()) + " , url is " + + invoker.getUrl() + ", invoke elapsed " + elapsed + " ms."); + } + } + } + return result; + } }