[#4515]fix access log not correct when guard timeout

apache · Sep 14, 2024 · 09655b1 · 09655b1
1 parent bd2d65c
commit 09655b1
Show file tree

Hide file tree

Showing 3 changed files with 25 additions and 4 deletions.
diff --git a/.../apache/servicecomb/common/accessLog/core/element/impl/DurationMillisecondAccessItem.java b/.../apache/servicecomb/common/accessLog/core/element/impl/DurationMillisecondAccessItem.java
@@ -26,12 +26,19 @@
 public class DurationMillisecondAccessItem implements AccessLogItem<RoutingContext> {
   @Override
   public void appendServerFormattedItem(ServerAccessLogEvent accessLogEvent, StringBuilder builder) {
-    builder.append(accessLogEvent.getMilliEndTime() - accessLogEvent.getMilliStartTime());
+    builder.append(calc(accessLogEvent.getMilliEndTime(), accessLogEvent.getMilliStartTime()));
   }
 
   @Override
   public void appendClientFormattedItem(InvocationFinishEvent finishEvent, StringBuilder builder) {
-    builder.append((finishEvent.getInvocation().getInvocationStageTrace().getFinish() -
+    builder.append(calc(finishEvent.getInvocation().getInvocationStageTrace().getFinish(),
         finishEvent.getInvocation().getInvocationStageTrace().getStartSend()) / 1000_000);
   }
+
+  private long calc(long end, long begin) {
+    if (begin == 0 || end == 0) {
+      return 0;
+    }
+    return end - begin;
+  }
 }
diff --git a/...a/org/apache/servicecomb/common/accessLog/core/element/impl/DurationSecondAccessItem.java b/...a/org/apache/servicecomb/common/accessLog/core/element/impl/DurationSecondAccessItem.java
@@ -28,12 +28,19 @@ public class DurationSecondAccessItem implements AccessLogItem<RoutingContext> {
 
   @Override
   public void appendServerFormattedItem(ServerAccessLogEvent accessLogEvent, StringBuilder builder) {
-    builder.append((accessLogEvent.getMilliEndTime() - accessLogEvent.getMilliStartTime()) / 1000);
+    builder.append(calc(accessLogEvent.getMilliEndTime(), accessLogEvent.getMilliStartTime()) / 1000);
   }
 
   @Override
   public void appendClientFormattedItem(InvocationFinishEvent finishEvent, StringBuilder builder) {
-    builder.append((finishEvent.getInvocation().getInvocationStageTrace().getFinish() -
+    builder.append(calc(finishEvent.getInvocation().getInvocationStageTrace().getFinish(),
         finishEvent.getInvocation().getInvocationStageTrace().getStartSend()) / 1000_000_000);
   }
+
+  private long calc(long end, long begin) {
+    if (begin == 0 || end == 0) {
+      return 0;
+    }
+    return end - begin;
+  }
 }
diff --git a/...rg/apache/servicecomb/common/accessLog/core/element/impl/DurationMillisecondItemTest.java b/...rg/apache/servicecomb/common/accessLog/core/element/impl/DurationMillisecondItemTest.java
@@ -64,6 +64,13 @@ public void testAppendFormattedElement() {
     ELEMENT.appendServerFormattedItem(accessLogEvent, strBuilder);
     Assertions.assertEquals("1", strBuilder.toString());
 
+    strBuilder = new StringBuilder();
+    ELEMENT.appendClientFormattedItem(finishEvent, strBuilder);
+    Assertions.assertEquals("0", strBuilder.toString());
+
+    when(invocationStageTrace.getStartSend()).thenReturn(1000L);
+    when(invocationStageTrace.getFinish()).thenReturn(1001_000L);
+
     strBuilder = new StringBuilder();
     ELEMENT.appendClientFormattedItem(finishEvent, strBuilder);
     Assertions.assertEquals("1", strBuilder.toString());