This is an automated email from the ASF dual-hosted git repository.
wujimin pushed a commit to branch master
in repository https://gitbox.apache.org/repos/asf/servicecomb-java-chassis.git
The following commit(s) were added to refs/heads/master by this push:
new f3ec388 [SCB-1153] provide traceId-invocationId by marker mechanism
f3ec388 is described below
commit f3ec3889cedbb3c55be2d1dd60bf646da26ff3a5
Author: wujimin <[email protected]>
AuthorDate: Thu Feb 14 15:51:17 2019 +0800
[SCB-1153] provide traceId-invocationId by marker mechanism
---
.../org/apache/servicecomb/core/Invocation.java | 13 ++++
.../apache/servicecomb/core/tracing/ScbMarker.java | 89 ++++++++++++++++++++++
.../apache/servicecomb/core/TestInvocation.java | 17 +++++
demo/perf/src/main/resources/logback.xml | 2 +-
.../metrics/core/publish/SlowInvocationLogger.java | 12 +--
.../core/publish/TestSlowInvocationLogger.java | 3 -
.../invocation/context/InvocationContext.java | 9 +++
7 files changed, 132 insertions(+), 13 deletions(-)
diff --git a/core/src/main/java/org/apache/servicecomb/core/Invocation.java
b/core/src/main/java/org/apache/servicecomb/core/Invocation.java
index 46c3c4a..67b8494 100644
--- a/core/src/main/java/org/apache/servicecomb/core/Invocation.java
+++ b/core/src/main/java/org/apache/servicecomb/core/Invocation.java
@@ -21,6 +21,7 @@ import java.util.Collection;
import java.util.List;
import java.util.Map;
import java.util.concurrent.Executor;
+import java.util.concurrent.atomic.AtomicLong;
import org.apache.commons.lang3.StringUtils;
import org.apache.servicecomb.core.definition.OperationMeta;
@@ -31,6 +32,7 @@ import
org.apache.servicecomb.core.event.InvocationFinishEvent;
import org.apache.servicecomb.core.event.InvocationStartEvent;
import org.apache.servicecomb.core.invocation.InvocationStageTrace;
import org.apache.servicecomb.core.provider.consumer.ReferenceConfig;
+import org.apache.servicecomb.core.tracing.ScbMarker;
import org.apache.servicecomb.core.tracing.TraceIdGenerator;
import org.apache.servicecomb.foundation.common.event.EventManager;
import org.apache.servicecomb.foundation.common.utils.SPIServiceUtils;
@@ -43,6 +45,8 @@ import
org.apache.servicecomb.swagger.invocation.SwaggerInvocation;
public class Invocation extends SwaggerInvocation {
private static final Collection<TraceIdGenerator> TRACE_ID_GENERATORS =
loadTraceIdGenerators();
+ protected static final AtomicLong INVOCATION_ID = new AtomicLong();
+
static Collection<TraceIdGenerator> loadTraceIdGenerators() {
return SPIServiceUtils.getPriorityHighestServices(generator ->
generator.getName(), TraceIdGenerator.class);
}
@@ -83,6 +87,12 @@ public class Invocation extends SwaggerInvocation {
// because isEdge() only affect to apm/metrics output, no need to change so
many logic
private boolean edge;
+ private long invocationId;
+
+ public long getInvocationId() {
+ return invocationId;
+ }
+
public HttpServletRequestEx getRequestEx() {
return requestEx;
}
@@ -126,6 +136,7 @@ public class Invocation extends SwaggerInvocation {
}
private void init(OperationMeta operationMeta, Object[] swaggerArguments) {
+ this.invocationId = INVOCATION_ID.getAndIncrement();
this.schemaMeta = operationMeta.getSchemaMeta();
this.operationMeta = operationMeta;
this.swaggerArguments = swaggerArguments;
@@ -237,6 +248,8 @@ public class Invocation extends SwaggerInvocation {
for (TraceIdGenerator traceIdGenerator : TRACE_ID_GENERATORS) {
initTraceId(traceIdGenerator);
}
+
+ marker = new ScbMarker(this);
}
protected void initTraceId(TraceIdGenerator traceIdGenerator) {
diff --git
a/core/src/main/java/org/apache/servicecomb/core/tracing/ScbMarker.java
b/core/src/main/java/org/apache/servicecomb/core/tracing/ScbMarker.java
new file mode 100644
index 0000000..f2b5e76
--- /dev/null
+++ b/core/src/main/java/org/apache/servicecomb/core/tracing/ScbMarker.java
@@ -0,0 +1,89 @@
+/*
+ * Licensed to the Apache Software Foundation (ASF) under one or more
+ * contributor license agreements. See the NOTICE file distributed with
+ * this work for additional information regarding copyright ownership.
+ * The ASF licenses this file to You under the Apache License, Version 2.0
+ * (the "License"); you may not use this file except in compliance with
+ * the License. You may obtain a copy of the License at
+ *
+ * http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ */
+package org.apache.servicecomb.core.tracing;
+
+import java.util.Collections;
+import java.util.Iterator;
+
+import org.apache.servicecomb.core.Invocation;
+import org.slf4j.Marker;
+
+public class ScbMarker implements Marker {
+ private static final long serialVersionUID = -1L;
+
+ private final Invocation invocation;
+
+ private String name;
+
+ public ScbMarker(Invocation invocation) {
+ this.invocation = invocation;
+ }
+
+ public Invocation getInvocation() {
+ return invocation;
+ }
+
+ @Override
+ public final String getName() {
+ if (name == null) {
+ name = invocation.getTraceId() + "-" + invocation.getInvocationId();
+ }
+ return name;
+ }
+
+ @Override
+ public void add(Marker reference) {
+
+ }
+
+ @Override
+ public boolean remove(Marker reference) {
+ return false;
+ }
+
+ @Deprecated
+ @Override
+ public boolean hasChildren() {
+ return false;
+ }
+
+ @Override
+ public boolean hasReferences() {
+ return false;
+ }
+
+ @SuppressWarnings("unchecked")
+ @Override
+ public Iterator<Marker> iterator() {
+ return Collections.EMPTY_LIST.iterator();
+ }
+
+ @Override
+ public boolean contains(Marker other) {
+ return false;
+ }
+
+ @Override
+ public boolean contains(String name) {
+ return false;
+ }
+
+ @Override
+ public String toString() {
+ return getName();
+ }
+}
diff --git a/core/src/test/java/org/apache/servicecomb/core/TestInvocation.java
b/core/src/test/java/org/apache/servicecomb/core/TestInvocation.java
index fb3e001..48dedcb 100644
--- a/core/src/test/java/org/apache/servicecomb/core/TestInvocation.java
+++ b/core/src/test/java/org/apache/servicecomb/core/TestInvocation.java
@@ -294,4 +294,21 @@ public class TestInvocation {
Assert.assertEquals(nanoTime,
invocation.getInvocationStageTrace().getFinishBusiness());
}
+
+ @Test
+ public void marker(@Mocked ReferenceConfig referenceConfig) {
+ Invocation.INVOCATION_ID.set(0);
+
+ Invocation invocation = new Invocation(referenceConfig, operationMeta,
swaggerArguments);
+ invocation.addContext(Const.TRACE_ID_NAME, "abc");
+ invocation.onStart(0);
+ Assert.assertEquals("abc-0", invocation.getMarker().toString());
+ Assert.assertEquals("abc-0", invocation.getMarker().getName());
+
+ invocation = new Invocation(referenceConfig, operationMeta,
swaggerArguments);
+ invocation.addContext(Const.TRACE_ID_NAME, "abc");
+ invocation.onStart(0);
+ Assert.assertEquals("abc-1", invocation.getMarker().toString());
+ Assert.assertEquals("abc-1", invocation.getMarker().getName());
+ }
}
diff --git a/demo/perf/src/main/resources/logback.xml
b/demo/perf/src/main/resources/logback.xml
index d753514..5264742 100644
--- a/demo/perf/src/main/resources/logback.xml
+++ b/demo/perf/src/main/resources/logback.xml
@@ -20,7 +20,7 @@
<jmxConfigurator/>
<appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
<encoder>
- <pattern>%d [%level] [%thread] - %msg (%F:%L\)%n</pattern>
+ <pattern>%d[%level][%thread][%marker] - %msg (%F:%L\)%n</pattern>
</encoder>
</appender>
<root level="INFO">
diff --git
a/metrics/metrics-core/src/main/java/org/apache/servicecomb/metrics/core/publish/SlowInvocationLogger.java
b/metrics/metrics-core/src/main/java/org/apache/servicecomb/metrics/core/publish/SlowInvocationLogger.java
index 8a115ff..e0c866a 100644
---
a/metrics/metrics-core/src/main/java/org/apache/servicecomb/metrics/core/publish/SlowInvocationLogger.java
+++
b/metrics/metrics-core/src/main/java/org/apache/servicecomb/metrics/core/publish/SlowInvocationLogger.java
@@ -70,12 +70,11 @@ public class SlowInvocationLogger {
private void logSlowProducer(Invocation invocation, Response response,
OperationConfig operationConfig) {
RestOperationMeta restOperationMeta =
invocation.getOperationMeta().getExtData(RestConst.SWAGGER_REST_OPERATION);
InvocationStageTrace stageTrace = invocation.getInvocationStageTrace();
- LOGGER.warn(""
+ LOGGER.warn(invocation.getMarker(), ""
+ "slow({} ms) invocation, {}:\n"
+ " http method: {}\n"
+ " url : {}\n"
+ " status code: {}\n"
- + " traceId : {}\n"
+ " total : {} ms\n"
+ " prepare : {} ms\n"
+ " threadPoolQueue : {} ms\n"
@@ -91,7 +90,6 @@ public class SlowInvocationLogger {
restOperationMeta.getHttpMethod(),
restOperationMeta.getAbsolutePath(),
response.getStatusCode(),
- invocation.getTraceId(),
formatTime(stageTrace.calcTotalTime()),
formatTime(stageTrace.calcInvocationPrepareTime()),
formatTime(stageTrace.calcThreadPoolQueueTime()),
@@ -107,12 +105,11 @@ public class SlowInvocationLogger {
private void logSlowConsumer(Invocation invocation, Response response,
OperationConfig operationConfig) {
RestOperationMeta restOperationMeta =
invocation.getOperationMeta().getExtData(RestConst.SWAGGER_REST_OPERATION);
InvocationStageTrace stageTrace = invocation.getInvocationStageTrace();
- LOGGER.warn(""
+ LOGGER.warn(invocation.getMarker(), ""
+ "slow({} ms) invocation, {}:\n"
+ " http method: {}\n"
+ " url : {}\n"
+ " status code: {}\n"
- + " traceId : {}\n"
+ " total : {} ms\n"
+ " prepare : {} ms\n"
+ " handlers request : {} ms\n"
@@ -129,7 +126,6 @@ public class SlowInvocationLogger {
restOperationMeta.getHttpMethod(),
restOperationMeta.getAbsolutePath(),
response.getStatusCode(),
- invocation.getTraceId(),
formatTime(stageTrace.calcTotalTime()),
formatTime(stageTrace.calcInvocationPrepareTime()),
formatTime(stageTrace.calcHandlersRequestTime()),
@@ -147,12 +143,11 @@ public class SlowInvocationLogger {
private void logSlowEdge(Invocation invocation, Response response,
OperationConfig operationConfig) {
RestOperationMeta restOperationMeta =
invocation.getOperationMeta().getExtData(RestConst.SWAGGER_REST_OPERATION);
InvocationStageTrace stageTrace = invocation.getInvocationStageTrace();
- LOGGER.warn(""
+ LOGGER.warn(invocation.getMarker(), ""
+ "slow({} ms) invocation, {}:\n"
+ " http method: {}\n"
+ " url : {}\n"
+ " status code: {}\n"
- + " traceId : {}\n"
+ " total : {} ms\n"
+ " prepare : {} ms\n"
+ " threadPoolQueue : {} ms\n"
@@ -173,7 +168,6 @@ public class SlowInvocationLogger {
restOperationMeta.getHttpMethod(),
restOperationMeta.getAbsolutePath(),
response.getStatusCode(),
- invocation.getTraceId(),
formatTime(stageTrace.calcTotalTime()),
formatTime(stageTrace.calcInvocationPrepareTime()),
formatTime(stageTrace.calcThreadPoolQueueTime()),
diff --git
a/metrics/metrics-core/src/test/java/org/apache/servicecomb/metrics/core/publish/TestSlowInvocationLogger.java
b/metrics/metrics-core/src/test/java/org/apache/servicecomb/metrics/core/publish/TestSlowInvocationLogger.java
index 303fa88..921a5c8 100644
---
a/metrics/metrics-core/src/test/java/org/apache/servicecomb/metrics/core/publish/TestSlowInvocationLogger.java
+++
b/metrics/metrics-core/src/test/java/org/apache/servicecomb/metrics/core/publish/TestSlowInvocationLogger.java
@@ -124,7 +124,6 @@ public class TestSlowInvocationLogger {
+ " http method: null\n"
+ " url : null\n"
+ " status code: 0\n"
- + " traceId : null\n"
+ " total : 0.0 ms\n"
+ " prepare : 0.0 ms\n"
+ " handlers request : 0.0 ms\n"
@@ -164,7 +163,6 @@ public class TestSlowInvocationLogger {
+ " http method: null\n"
+ " url : null\n"
+ " status code: 0\n"
- + " traceId : null\n"
+ " total : 0.0 ms\n"
+ " prepare : 0.0 ms\n"
+ " threadPoolQueue : 0.0 ms\n"
@@ -206,7 +204,6 @@ public class TestSlowInvocationLogger {
+ " http method: null\n"
+ " url : null\n"
+ " status code: 0\n"
- + " traceId : null\n"
+ " total : 0.0 ms\n"
+ " prepare : 0.0 ms\n"
+ " threadPoolQueue : 0.0 ms\n"
diff --git
a/swagger/swagger-invocation/invocation-core/src/main/java/org/apache/servicecomb/swagger/invocation/context/InvocationContext.java
b/swagger/swagger-invocation/invocation-core/src/main/java/org/apache/servicecomb/swagger/invocation/context/InvocationContext.java
index 0807beb..dd7ef6d 100644
---
a/swagger/swagger-invocation/invocation-core/src/main/java/org/apache/servicecomb/swagger/invocation/context/InvocationContext.java
+++
b/swagger/swagger-invocation/invocation-core/src/main/java/org/apache/servicecomb/swagger/invocation/context/InvocationContext.java
@@ -24,6 +24,8 @@ import java.util.Map.Entry;
import javax.ws.rs.core.Response.Status;
import javax.ws.rs.core.Response.StatusType;
+import org.slf4j.Marker;
+
/**
* 设置特定的Cse Context数据
*/
@@ -37,6 +39,9 @@ public class InvocationContext {
protected Map<String, Object> localContext = new HashMap<>();
+ // provide traceid-invocationId, so that can log them by %marker
+ protected Marker marker;
+
public InvocationContext() {
httpStatus = Status.OK;
}
@@ -127,4 +132,8 @@ public class InvocationContext {
public void setStatus(int statusCode) {
this.httpStatus = statusMgr.getOrCreateByStatusCode(statusCode);
}
+
+ public Marker getMarker() {
+ return marker;
+ }
}
