Skip to content

Commit 90b0202

Browse files
mprokopchuksureshanaparti
mprokopchuk
authored and
sureshanaparti
committed
Support OpenTelemetry distributed tracing instrumentation
- Add support to API layer - All API requests get a traceId in LogContext (via ApiTraceFilter) - Read the trace and span threadcontext key names from the environment - Instrument cloudstack Agents and VM operations
1 parent 62020b2 commit 90b0202

35 files changed

Lines changed: 713 additions & 93 deletions

File tree

‎agent/conf/log4j-cloud.xml.in‎

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -30,7 +30,7 @@ under the License.
3030
<Policies>
3131
<TimeBasedTriggeringPolicy/>
3232
</Policies>
33-
<PatternLayout pattern="%d{DEFAULT} %-5p [%c{3}] (%t:%x) (logid:%X{logcontextid}) %m%ex%n"/>
33+
<PatternLayout pattern="%d{DEFAULT} %-5p [%c{3}] (%t:%x) (logid:%X{logcontextid}) (traceid:%X{traceid}) %m%ex%n"/>
3434
</RollingFile>
3535

3636
<!-- ============================== -->
@@ -39,7 +39,7 @@ under the License.
3939

4040
<Console name="CONSOLE" target="SYSTEM_OUT">
4141
<ThresholdFilter level="OFF" onMatch="ACCEPT" onMismatch="DENY"/>
42-
<PatternLayout pattern="%-5p [%c{3}] (%t:%x) (logid:%X{logcontextid}) %m%ex%n"/>
42+
<PatternLayout pattern="%-5p [%c{3}] (%t:%x) (logid:%X{logcontextid}) (traceid:%X{traceid}) %m%ex%n"/>
4343
</Console>
4444
</Appenders>
4545

‎api/pom.xml‎

Lines changed: 5 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -71,6 +71,11 @@
7171
<artifactId>cloud-framework-direct-download</artifactId>
7272
<version>${project.version}</version>
7373
</dependency>
74+
<dependency>
75+
<groupId>io.opentelemetry.instrumentation</groupId>
76+
<artifactId>opentelemetry-instrumentation-annotations</artifactId>
77+
<version>${cs.opentelemetry-instrumentation.version}</version>
78+
</dependency>
7479
<dependency>
7580
<groupId>io.opentelemetry</groupId>
7681
<artifactId>opentelemetry-api</artifactId>

‎api/src/main/java/org/apache/cloudstack/api/filter/ApiTraceFilter.java‎

Lines changed: 28 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -32,6 +32,10 @@
3232
import javax.servlet.ServletResponse;
3333

3434
public class ApiTraceFilter implements Filter {
35+
36+
// Cap the accepted trace id length to avoid log/DB bloat from a crafted header.
37+
private static final int MAX_TRACE_ID_LENGTH = 128;
38+
3539
@Override
3640
public void init(FilterConfig filterConfig) throws ServletException {
3741
}
@@ -41,16 +45,37 @@ public void doFilter(ServletRequest request, ServletResponse response, FilterCha
4145
throws IOException, ServletException {
4246
try {
4347
HttpServletRequest httpReq = (HttpServletRequest) request;
44-
String traceId = httpReq.getHeader(LogContext.X_B3_TRACEID_KEY);
48+
String traceId = sanitizeTraceId(httpReq.getHeader(LogContext.TRACEID_KEY));
4549
if (StringUtils.isBlank(traceId)) {
4650
traceId = UUID.randomUUID().toString();
4751
}
4852

49-
LogContext.current().putContextParameter(LogContext.X_B3_TRACEID_KEY, traceId);
53+
LogContext.current().putContextParameter(LogContext.TRACEID_KEY, traceId);
5054
chain.doFilter(request, response);
5155
} finally {
52-
LogContext.current().removeContextParameter(LogContext.X_B3_TRACEID_KEY);
56+
LogContext.current().removeContextParameter(LogContext.TRACEID_KEY);
57+
}
58+
}
59+
60+
/**
61+
* Returns the caller-supplied trace id only if it is safe to log and store: no control
62+
* characters (prevents log forging) and within a bounded length. Otherwise returns null so a
63+
* fresh id is generated.
64+
*/
65+
private String sanitizeTraceId(String traceId) {
66+
if (traceId == null) {
67+
return null;
68+
}
69+
String trimmed = traceId.trim();
70+
if (trimmed.isEmpty() || trimmed.length() > MAX_TRACE_ID_LENGTH) {
71+
return null;
72+
}
73+
for (int i = 0; i < trimmed.length(); i++) {
74+
if (Character.isISOControl(trimmed.charAt(i))) {
75+
return null;
76+
}
5377
}
78+
return trimmed;
5479
}
5580

5681
@Override

‎api/src/main/java/org/apache/cloudstack/context/LogContext.java‎

Lines changed: 49 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -16,11 +16,16 @@
1616
// under the License.
1717
package org.apache.cloudstack.context;
1818

19+
import java.io.File;
20+
import java.io.IOException;
1921
import java.util.ArrayList;
2022
import java.util.HashMap;
2123
import java.util.Map;
24+
import java.util.Properties;
2225
import java.util.UUID;
2326

27+
import com.cloud.utils.PropertiesUtil;
28+
import com.cloud.utils.StringUtils;
2429
import org.apache.logging.log4j.Logger;
2530
import org.apache.logging.log4j.LogManager;
2631

@@ -54,9 +59,43 @@ public class LogContext {
5459
private long userId;
5560
private final Map<String, String> context = new HashMap<String, String>();
5661

57-
public final static String X_B3_TRACEID_KEY = "traceid";
58-
public final static String MOSAIC_TRACE_ID_KEY = "mosaic_trace_id";
59-
public final static String MOSAIC_SPAN_ID_KEY = "mosaic_span_id";
62+
public final static String TRACEID_KEY = "traceid";
63+
64+
/**
65+
* MDC keys under which the active OpenTelemetry ids are published. The names are
66+
* deployment specific, so they are read from server.properties and fall back to a
67+
* neutral default when the property is absent or blank.
68+
*/
69+
public final static String TRACE_ID_KEY_PROPERTY = "otel.trace.id.mdc.key";
70+
public final static String SPAN_ID_KEY_PROPERTY = "otel.span.id.mdc.key";
71+
72+
public final static String DEFAULT_TRACE_ID_KEY = "otel_trace_id";
73+
public final static String DEFAULT_SPAN_ID_KEY = "otel_span_id";
74+
75+
private final static Properties SERVER_PROPERTIES = loadServerProperties();
76+
77+
public final static String TRACE_ID_KEY = traceKeyFromProperties();
78+
public final static String SPAN_ID_KEY = spanKeyFromProperties();
79+
80+
private static Properties loadServerProperties() {
81+
try {
82+
File file = PropertiesUtil.findConfigFile("server.properties");
83+
return file == null ? new Properties() : PropertiesUtil.loadFromFile(file);
84+
} catch (IOException e) {
85+
LOGGER.warn("Could not read server.properties, using the default MDC key names", e);
86+
return new Properties();
87+
}
88+
}
89+
90+
private static String traceKeyFromProperties() {
91+
String value = SERVER_PROPERTIES.getProperty(TRACE_ID_KEY_PROPERTY);
92+
return StringUtils.isBlank(value) ? DEFAULT_TRACE_ID_KEY : value.trim();
93+
}
94+
95+
private static String spanKeyFromProperties() {
96+
String value = SERVER_PROPERTIES.getProperty(SPAN_ID_KEY_PROPERTY);
97+
return StringUtils.isBlank(value) ? DEFAULT_SPAN_ID_KEY : value.trim();
98+
}
6099

61100
static EntityManager s_entityMgr;
62101

@@ -83,12 +122,17 @@ protected LogContext(User user, Account account, String logContextId) {
83122

84123
public void putContextParameter(String key, String value) {
85124
context.put(key, value);
86-
MDC.put(key, value);
125+
ThreadContext.put(key, value);
126+
if (value == null) {
127+
ThreadContext.remove(key);
128+
} else {
129+
ThreadContext.put(key, value);
130+
}
87131
}
88132

89133
public void removeContextParameter(String key) {
90134
context.remove(key);
91-
MDC.remove(key);
135+
ThreadContext.remove(key);
92136
}
93137

94138
public void removeContextParameters() {

‎api/src/main/java/org/apache/cloudstack/context/TraceContextMdcWrapper.java‎

Lines changed: 15 additions & 14 deletions
Original file line numberDiff line numberDiff line change
@@ -16,18 +16,19 @@
1616
// under the License.
1717
package org.apache.cloudstack.context;
1818

19-
import org.apache.log4j.MDC;
20-
2119
import io.opentelemetry.api.trace.Span;
2220
import io.opentelemetry.api.trace.SpanContext;
2321
import io.opentelemetry.context.Context;
2422
import io.opentelemetry.context.ContextStorage;
2523
import io.opentelemetry.context.Scope;
24+
import org.apache.logging.log4j.ThreadContext;
2625

2726
/**
2827
* Mirrors the active OpenTelemetry span onto the Log4j MDC so management-server log
29-
* lines carry mosaic_trace_id and mosaic_span_id on every thread that has an active
28+
* lines carry trace and span ids on every thread that has an active
3029
* span (API requests, agent-command dispatch, async jobs), not just the servlet path.
30+
* The MDC key names come from {@link LogContext#TRACE_ID_KEY} and
31+
* {@link LogContext#SPAN_ID_KEY}, which are environment driven.
3132
*
3233
* The OpenTelemetry agent populates the log MDC automatically for Log4j2 and Logback,
3334
* but not for Log4j 1.2 (reload4j), which the management server uses. This wrapper
@@ -53,29 +54,29 @@ public static void register() {
5354

5455
@Override
5556
public Scope attach(Context toAttach) {
56-
Object previousTraceId = MDC.get(LogContext.MOSAIC_TRACE_ID_KEY);
57-
Object previousSpanId = MDC.get(LogContext.MOSAIC_SPAN_ID_KEY);
57+
String previousTraceId = ThreadContext.get(LogContext.TRACE_ID_KEY);
58+
String previousSpanId = ThreadContext.get(LogContext.SPAN_ID_KEY);
5859
SpanContext spanContext = Span.fromContext(toAttach).getSpanContext();
5960
if (spanContext.isValid()) {
60-
MDC.put(LogContext.MOSAIC_TRACE_ID_KEY, spanContext.getTraceId());
61-
MDC.put(LogContext.MOSAIC_SPAN_ID_KEY, spanContext.getSpanId());
61+
ThreadContext.put(LogContext.TRACE_ID_KEY, spanContext.getTraceId());
62+
ThreadContext.put(LogContext.SPAN_ID_KEY, spanContext.getSpanId());
6263
} else {
63-
MDC.remove(LogContext.MOSAIC_TRACE_ID_KEY);
64-
MDC.remove(LogContext.MOSAIC_SPAN_ID_KEY);
64+
ThreadContext.remove(LogContext.TRACE_ID_KEY);
65+
ThreadContext.remove(LogContext.SPAN_ID_KEY);
6566
}
6667
Scope delegateScope = delegate.attach(toAttach);
6768
return () -> {
6869
delegateScope.close();
69-
restore(LogContext.MOSAIC_TRACE_ID_KEY, previousTraceId);
70-
restore(LogContext.MOSAIC_SPAN_ID_KEY, previousSpanId);
70+
restore(LogContext.TRACE_ID_KEY, previousTraceId);
71+
restore(LogContext.SPAN_ID_KEY, previousSpanId);
7172
};
7273
}
7374

74-
private static void restore(String key, Object previous) {
75+
private static void restore(String key, String previous) {
7576
if (previous != null) {
76-
MDC.put(key, previous);
77+
ThreadContext.put(key, previous);
7778
} else {
78-
MDC.remove(key);
79+
ThreadContext.remove(key);
7980
}
8081
}
8182

‎api/src/main/resources/META-INF/cloudstack/api-config/spring-api-config-context.xml‎

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -28,5 +28,6 @@
2828
>
2929

3030
<bean id="apiServiceConfiguration" class="org.apache.cloudstack.config.ApiServiceConfiguration" />
31+
<bean id="apiTraceFilter" class="org.apache.cloudstack.api.filter.ApiTraceFilter"/>
3132

3233
</beans>

‎api/src/test/java/org/apache/cloudstack/context/TraceContextMdcWrapperTest.java‎

Lines changed: 12 additions & 12 deletions
Original file line numberDiff line numberDiff line change
@@ -16,7 +16,7 @@
1616
// under the License.
1717
package org.apache.cloudstack.context;
1818

19-
import org.apache.log4j.MDC;
19+
import org.apache.logging.log4j.ThreadContext;
2020
import org.junit.After;
2121
import org.junit.Assert;
2222
import org.junit.Test;
@@ -53,8 +53,8 @@ public Context current() {
5353

5454
@After
5555
public void tearDown() {
56-
MDC.remove(LogContext.MOSAIC_TRACE_ID_KEY);
57-
MDC.remove(LogContext.MOSAIC_SPAN_ID_KEY);
56+
ThreadContext.remove(LogContext.TRACE_ID_KEY);
57+
ThreadContext.remove(LogContext.SPAN_ID_KEY);
5858
}
5959

6060
private static Context contextWithSpan(String traceId, String spanId) {
@@ -65,32 +65,32 @@ private static Context contextWithSpan(String traceId, String spanId) {
6565
@Test
6666
public void putsTraceContextOnMdcWhileScopeOpenAndRestoresOnClose() {
6767
Scope scope = wrapper.attach(contextWithSpan(TRACE_ID, SPAN_ID));
68-
Assert.assertEquals(TRACE_ID, MDC.get(LogContext.MOSAIC_TRACE_ID_KEY));
69-
Assert.assertEquals(SPAN_ID, MDC.get(LogContext.MOSAIC_SPAN_ID_KEY));
68+
Assert.assertEquals(TRACE_ID, ThreadContext.get(LogContext.TRACE_ID_KEY));
69+
Assert.assertEquals(SPAN_ID, ThreadContext.get(LogContext.SPAN_ID_KEY));
7070

7171
scope.close();
72-
Assert.assertNull(MDC.get(LogContext.MOSAIC_TRACE_ID_KEY));
73-
Assert.assertNull(MDC.get(LogContext.MOSAIC_SPAN_ID_KEY));
72+
Assert.assertNull(ThreadContext.get(LogContext.TRACE_ID_KEY));
73+
Assert.assertNull(ThreadContext.get(LogContext.SPAN_ID_KEY));
7474
}
7575

7676
@Test
7777
public void leavesMdcUnsetWhenNoActiveSpan() {
7878
Scope scope = wrapper.attach(Context.root());
79-
Assert.assertNull(MDC.get(LogContext.MOSAIC_TRACE_ID_KEY));
80-
Assert.assertNull(MDC.get(LogContext.MOSAIC_SPAN_ID_KEY));
79+
Assert.assertNull(ThreadContext.get(LogContext.TRACE_ID_KEY));
80+
Assert.assertNull(ThreadContext.get(LogContext.SPAN_ID_KEY));
8181
scope.close();
8282
}
8383

8484
@Test
8585
public void restoresOuterSpanWhenNestedScopeCloses() {
8686
Scope outer = wrapper.attach(contextWithSpan(TRACE_ID, SPAN_ID));
8787
Scope inner = wrapper.attach(contextWithSpan(OTHER_TRACE_ID, OTHER_SPAN_ID));
88-
Assert.assertEquals(OTHER_TRACE_ID, MDC.get(LogContext.MOSAIC_TRACE_ID_KEY));
88+
Assert.assertEquals(OTHER_TRACE_ID, ThreadContext.get(LogContext.TRACE_ID_KEY));
8989

9090
inner.close();
91-
Assert.assertEquals(TRACE_ID, MDC.get(LogContext.MOSAIC_TRACE_ID_KEY));
91+
Assert.assertEquals(TRACE_ID, ThreadContext.get(LogContext.TRACE_ID_KEY));
9292

9393
outer.close();
94-
Assert.assertNull(MDC.get(LogContext.MOSAIC_TRACE_ID_KEY));
94+
Assert.assertNull(ThreadContext.get(LogContext.TRACE_ID_KEY));
9595
}
9696
}

‎client/conf/log4j-cloud.xml.in‎

Lines changed: 5 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -34,7 +34,7 @@ under the License.
3434
<Policies>
3535
<TimeBasedTriggeringPolicy/>
3636
</Policies>
37-
<PatternLayout pattern="%d{DEFAULT} %-5p [%c{1.}] (%t:%x) (logid:%X{logcontextid}) %m%ex{filters(${filters})}%n"/>
37+
<PatternLayout pattern="%d{DEFAULT} %-5p [%c{1.}] (%t:%x) (logid:%X{logcontextid}) (traceid:%X{traceid}) %m%ex{filters(${filters})}%n"/>
3838
</RollingFile>
3939

4040

@@ -43,7 +43,7 @@ under the License.
4343
<Policies>
4444
<TimeBasedTriggeringPolicy/>
4545
</Policies>
46-
<PatternLayout pattern="%d{DEFAULT} %-5p [%c{1.}] (%t:%x) (logid:%X{logcontextid}) %m%ex{filters(${filters})}%n"/>
46+
<PatternLayout pattern="%d{DEFAULT} %-5p [%c{1.}] (%t:%x) (logid:%X{logcontextid}) (traceid:%X{traceid}) %m%ex{filters(${filters})}%n"/>
4747
</RollingFile>
4848

4949
<!-- ============================== -->
@@ -52,7 +52,7 @@ under the License.
5252

5353
<Syslog name="SYSLOG" host="localhost" facility="LOCAL6">
5454
<ThresholdFilter level="WARN" onMatch="ACCEPT" onMismatch="DENY"/>
55-
<PatternLayout pattern="%d{DEFAULT} %-5p [%c{1.}] (%t:%x) (logid:%X{logcontextid}) %m%ex{filters(${filters})}%n"/>
55+
<PatternLayout pattern="%d{DEFAULT} %-5p [%c{1.}] (%t:%x) (logid:%X{logcontextid}) (traceid:%X{traceid}) %m%ex{filters(${filters})}%n"/>
5656
</Syslog>
5757

5858
<!-- ============================== -->
@@ -61,7 +61,7 @@ under the License.
6161

6262
<AlertSyslogAppender name="ALERTSYSLOG" syslogHosts="" facility="LOCAL6">
6363
<ThresholdFilter level="WARN" onMatch="ACCEPT" onMismatch="DENY"/>
64-
<PatternLayout pattern="%d{DEFAULT} %-5p [%c{1.}] (%t:%x) (logid:%X{logcontextid}) %m%ex{filters(${filters})}%n"/>
64+
<PatternLayout pattern="%d{DEFAULT} %-5p [%c{1.}] (%t:%x) (logid:%X{logcontextid}) (traceid:%X{traceid}) %m%ex{filters(${filters})}%n"/>
6565
</AlertSyslogAppender>
6666

6767
<!-- ============================== -->
@@ -70,7 +70,7 @@ under the License.
7070

7171
<Console name="CONSOLE" target="SYSTEM_OUT">
7272
<ThresholdFilter level="OFF" onMatch="ACCEPT" onMismatch="DENY"/>
73-
<PatternLayout pattern="%-5p [%c{1.}] (%t:%x) (logid:%X{logcontextid}) %m%ex{filters(${filters})}%n"/>
73+
<PatternLayout pattern="%-5p [%c{1.}] (%t:%x) (logid:%X{logcontextid}) (traceid:%X{traceid}) %m%ex{filters(${filters})}%n"/>
7474
</Console>
7575

7676
<!-- ============================== -->

‎client/src/main/java/org/apache/cloudstack/ServerDaemon.java‎

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -111,7 +111,7 @@ public class ServerDaemon implements Daemon {
111111

112112
public static void main(final String... anArgs) throws Exception {
113113
// Install the trace-context to MDC hook before the server starts, so every
114-
// thread with an active OpenTelemetry span carries mosaic_trace_id in its logs.
114+
// thread with an active OpenTelemetry span carries the trace id in its logs.
115115
TraceContextMdcWrapper.register();
116116
final ServerDaemon daemon = new ServerDaemon();
117117
daemon.init(null);

‎client/src/main/webapp/WEB-INF/web.xml‎

Lines changed: 10 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -64,6 +64,16 @@
6464
<load-on-startup>6</load-on-startup>
6565
</servlet>
6666

67+
<filter>
68+
<filter-name>apiTraceFilter</filter-name>
69+
<filter-class>org.apache.cloudstack.api.filter.ApiTraceFilter</filter-class>
70+
</filter>
71+
72+
<filter-mapping>
73+
<filter-name>apiTraceFilter</filter-name>
74+
<url-pattern>/api/*</url-pattern>
75+
</filter-mapping>
76+
6777
<servlet-mapping>
6878
<servlet-name>apiServlet</servlet-name>
6979
<url-pattern>/api/*</url-pattern>

0 commit comments

Comments
 (0)