(servicecomb-java-chassis) branch 2.8.x updated: [#4515]fix access log not correct when guard timeout (#4526)

[liubao]

This is an automated email from the ASF dual-hosted git repository.

liubao pushed a commit to branch 2.8.x
in repository https://gitbox.apache.org/repos/asf/servicecomb-java-chassis.git


The following commit(s) were added to refs/heads/2.8.x by this push:
     new e39c33040 [#4515]fix access log not correct when guard timeout (#4526)
e39c33040 is described below

commit e39c330407f53de4cf552fde754a3743348142a4
Author: liubao68 <bi...@qq.com>
AuthorDate: Sat Sep 14 18:23:45 2024 +0800

    [#4515]fix access log not correct when guard timeout (#4526)
---
 .../core/element/impl/DurationMillisecondAccessItem.java      | 11 +++++++++--
 .../accessLog/core/element/impl/DurationSecondAccessItem.java | 11 +++++++++--
 .../core/element/impl/DurationMillisecondItemTest.java        |  7 +++++++
 3 files changed, 25 insertions(+), 4 deletions(-)

diff --git 
a/common/common-access-log/src/main/java/org/apache/servicecomb/common/accessLog/core/element/impl/DurationMillisecondAccessItem.java
 
b/common/common-access-log/src/main/java/org/apache/servicecomb/common/accessLog/core/element/impl/DurationMillisecondAccessItem.java
index e0bde4ad3..9d5703120 100644
--- 
a/common/common-access-log/src/main/java/org/apache/servicecomb/common/accessLog/core/element/impl/DurationMillisecondAccessItem.java
+++ 
b/common/common-access-log/src/main/java/org/apache/servicecomb/common/accessLog/core/element/impl/DurationMillisecondAccessItem.java
@@ -26,12 +26,19 @@ import io.vertx.ext.web.RoutingContext;
 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/common/common-access-log/src/main/java/org/apache/servicecomb/common/accessLog/core/element/impl/DurationSecondAccessItem.java
 
b/common/common-access-log/src/main/java/org/apache/servicecomb/common/accessLog/core/element/impl/DurationSecondAccessItem.java
index 2da34026d..9dcd015fc 100644
--- 
a/common/common-access-log/src/main/java/org/apache/servicecomb/common/accessLog/core/element/impl/DurationSecondAccessItem.java
+++ 
b/common/common-access-log/src/main/java/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/common/common-access-log/src/test/java/org/apache/servicecomb/common/accessLog/core/element/impl/DurationMillisecondItemTest.java
 
b/common/common-access-log/src/test/java/org/apache/servicecomb/common/accessLog/core/element/impl/DurationMillisecondItemTest.java
index 7ad32b23f..c97afc41d 100644
--- 
a/common/common-access-log/src/test/java/org/apache/servicecomb/common/accessLog/core/element/impl/DurationMillisecondItemTest.java
+++ 
b/common/common-access-log/src/test/java/org/apache/servicecomb/common/accessLog/core/element/impl/DurationMillisecondItemTest.java
@@ -64,6 +64,13 @@ public class DurationMillisecondItemTest {
     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());