From 52250b8a2086ca361fc3c3912720e3eb3d495b17 Mon Sep 17 00:00:00 2001 From: Poison Date: Tue, 12 Sep 2023 12:45:03 +0800 Subject: [PATCH] Fix incorrect timeout message (#13001) * Fix incorrect timeout message * Remove @Disabled annotation to enable unit test --- .../exchange/support/DefaultFuture.java | 2 +- .../exchange/support/DefaultFutureTest.java | 37 +++++++++++++++++++ 2 files changed, 38 insertions(+), 1 deletion(-) diff --git a/dubbo-remoting/dubbo-remoting-api/src/main/java/org/apache/dubbo/remoting/exchange/support/DefaultFuture.java b/dubbo-remoting/dubbo-remoting-api/src/main/java/org/apache/dubbo/remoting/exchange/support/DefaultFuture.java index f49ef15867..75544e9927 100644 --- a/dubbo-remoting/dubbo-remoting-api/src/main/java/org/apache/dubbo/remoting/exchange/support/DefaultFuture.java +++ b/dubbo-remoting/dubbo-remoting-api/src/main/java/org/apache/dubbo/remoting/exchange/support/DefaultFuture.java @@ -276,7 +276,7 @@ public class DefaultFuture extends CompletableFuture { private String getTimeoutMessage(boolean scan) { long nowTimestamp = System.currentTimeMillis(); - return (sent > 0 ? "Waiting server-side response timeout" : "Sending request timeout in client-side") + return (sent > 0 && sent - start < timeout ? "Waiting server-side response timeout" : "Sending request timeout in client-side") + (scan ? " by scan timer" : "") + ". start time: " + (new SimpleDateFormat("yyyy-MM-dd HH:mm:ss.SSS").format(new Date(start))) + ", end time: " + (new SimpleDateFormat("yyyy-MM-dd HH:mm:ss.SSS").format(new Date(nowTimestamp))) + "," diff --git a/dubbo-remoting/dubbo-remoting-api/src/test/java/org/apache/dubbo/remoting/exchange/support/DefaultFutureTest.java b/dubbo-remoting/dubbo-remoting-api/src/test/java/org/apache/dubbo/remoting/exchange/support/DefaultFutureTest.java index 8188720480..171d040cd9 100644 --- a/dubbo-remoting/dubbo-remoting-api/src/test/java/org/apache/dubbo/remoting/exchange/support/DefaultFutureTest.java +++ b/dubbo-remoting/dubbo-remoting-api/src/test/java/org/apache/dubbo/remoting/exchange/support/DefaultFutureTest.java @@ -86,6 +86,43 @@ class DefaultFutureTest { } } + /** + * for example, it will print like this: + * before a future is created, time is : 2023-09-03 18:20:14.535 + * after a future is timeout, time is : 2023-09-03 18:20:14.669 + *

+ * The exception info print like: + * Sending request timeout in client-side by scan timer. + * start time: 2023-09-03 18:20:14.544, end time: 2023-09-03 18:20:14.598... + */ + @Test + public void clientTimeoutSend() throws Exception { + final DateTimeFormatter formatter = DateTimeFormatter.ofPattern("yyyy-MM-dd HH:mm:ss.SSS"); + System.out.println("before a future is create , time is : " + LocalDateTime.now().format(formatter)); + // timeout after 5 milliseconds. + Channel channel = new MockedChannel(); + Request request = new Request(10); + DefaultFuture f = DefaultFuture.newFuture(channel, request, 5, null); + System.gc(); // events such as Full GC will increase the time required to send messages. + + // mark the future is sent + DefaultFuture.sent(channel, request); + while (!f.isDone()) { + // spin + Thread.sleep(100); + } + System.out.println("after a future is timeout , time is : " + LocalDateTime.now().format(formatter)); + + // get operate will throw a timeout exception, because the future is timeout. + try { + f.get(); + } catch (Exception e) { + Assertions.assertTrue(e.getCause() instanceof TimeoutException, "catch exception is not timeout exception!"); + System.out.println(e.getMessage()); + Assertions.assertTrue(e.getMessage().startsWith(e.getCause().getClass().getCanonicalName() + ": Sending request timeout in client-side")); + } + } + /** * for example, it will print like this: * before a future is create , time is : 2018-06-21 15:11:31