preamble
In the two previous real-world articles:
- OpenTelemetry Hands-on: Distributed Link Tracing from Scratch
- OpenTelemetry Hands-On: Application Metrics Monitoring from Scratch
Covers indicator tracking in observables andmetrics Surveillance, it is only right to begin the third part below:log (computing)。
But before you start logging it's still a good idea to combine link tracing and logging to see how the application is actually used in practice.
Usually the way we troubleshoot problems is to first query the exception logs to determine if the problem is with the current system.
If not, fish out the logs in thetrace_id Then go to the link query system and query the link to see exactly which system is the problem and then do the specific troubleshooting.
Something like this:
The log will printtrace_id cap (a poem)span_id。
If the logging system is well done, you can also just click on the
trace_idJump to the link system to query the link information directly.
MDC
The practice of associating trace information in the logs here has a proper name: MDC:(Mapped Diagnostic Context).
This is simply the contextual information used to troubleshoot the problem, usually consisting of key-value pairs, similar to data like this:
{
"timestamp" : "2024-08-05 17:27:31.097",
"level" : "INFO",
"thread" : "http-nio-9191-exec-1",
"mdc" : {
"trace_id" : "26242f945af80b044a60226af00211fb",
"trace_flags" : "01",
"span_id" : "3a7842b3e28ed5c8"
},
"logger" : "",
"message" : "request: name: \"1232\"\n",
"context" : "default"
}
Log4j and Logback in Java both provide corresponding implementations.
If we use the OpenTelemetry-suppliedjavaagent redeploymentlogback orLog4j It will automatically have the ability to printMDC The ability of the
java -javaagent:/Users/chenjie/Downloads/blog-img/demo/opentelemetry-javaagent-2.4.
For example, this is all we need to configure a logback with JSON output:
<appender name="PROJECT_LOG" class="">
<file>${PATH}/</file>
<rollingPolicy class="">
<fileNamePattern>${PATH}/demo_%</fileNamePattern>
<maxIndex>1</maxIndex>
</rollingPolicy>
<triggeringPolicy class="">
<maxFileSize>100MB</maxFileSize>
</triggeringPolicy>
<layout class="">
<jsonFormatter
class="">
<prettyPrint>true</prettyPrint>
</jsonFormatter>
<timestampFormat>yyyy-MM-dd' 'HH:mm:</timestampFormat>
</layout>
</appender>
<root level="INFO">
<appender-ref ref="STDOUT"/>
<appender-ref ref="PROJECT_LOG"/>
</root>
will be output in the log fileJSON format and bring theMDC The message.
Principle of Automatic MDC
I'm also curious about how OpenTelemetry automatically writes MDC information, and here's a quick example of how it works with thelogback As an example.
@Override
public ElementMatcher<TypeDescription> typeMatcher() {
return implementsInterface(named(""));
}
@Override
public void transform(TypeTransformer transformer) {
(
isMethod()
.and(isPublic())
.and(namedOneOf("getMDCPropertyMap", "getMdc"))
.and(takesArguments(0)),
() + "$GetMdcAdvice");
}
will be invoked before the()/getMdc() Buried points are made in these two functions.
The logic is written in the javaagent.
public Map<String, String> getMDCPropertyMap() {
// populate mdcPropertyMap if null
if (mdcPropertyMap == null) {
MDCAdapter mdc = ();
if (mdc instanceof LogbackMDCAdapter)
mdcPropertyMap = ((LogbackMDCAdapter) mdc).getPropertyMap();
else
mdcPropertyMap = ();
}
// mdcPropertyMap still null, use emptyMap()
if (mdcPropertyMap == null)
mdcPropertyMap = ();
return mdcPropertyMap;
}
This function actually returns the map data of a logback's built-in MDC by default (where we can customize the configuration).
All you have to do is write the trace's context information into this mdcPropertyMap.
Here is the source code from the OpenTelemetry agent:
Map<String, String> spanContextData = new HashMap<>();
SpanContext spanContext = (context).getSpanContext();
if (()) {
(traceIdKey(), ());
(spanIdKey(), ());
(traceFlagsKey(), ().asHex());
}
(());
if (()) {
Baggage baggage = (context);
// using a lambda here does not play nicely with instrumentation bytecode process
// (Java 6 related errors are observed) so relying on for loop instead for (<String, BaggageEntry> entry : ().entrySet()) {
(
// prefix all baggage values to avoid *es with existing context
"baggage." + (), ().getValue());
}}
if (contextData == null) {
contextData = spanContextData;
} else {
contextData = new UnionMap<>(contextData, spanContextData);
}
This is the core write logic, and you can also see from this code that the context of the span is retrieved directly from the top line, and what we need is thetrace_id/span_id It's all stored in the context, so you just need to get it and write it to the map.
We also know from the source code that as soon as we turn on the--baggage=true The configuration can also write data from the baggage to the MDC as well.
The trace in OpenTelemetry is easy to transfer across threads, so even if we print logs in multiple threads, the MDC data can still be transferred accurately.
Principle of MDC
public static final String MDC_ATTR_NAME = "mdc";
existlogback implementation is the one that will call thegetMDCPropertyMap() and then write it to a key ofmdc (used form a nominal expression)map in a file or console, and can eventually be written to a file or console.
This way the whole principle can be strung together.
Custom Logging Data
Mention that you can customize the MDC data in fact, there are also use scenarios, such as our business systems often have similar needs, the need to print some common business data in the log:
- userId、userName
- Client IP and other information
At this point we can create aLayout class to inherit:
public class CustomJsonLayout extends JsonLayout {
public CustomJsonLayout() {
}
protected void addCustomDataToJsonMap(Map<String, Object> map, ILoggingEvent event) {
("user_name", ("userName"));
("user_id", ("userId"));
("trace_id", ());
}
}
public class CustomJsonLayoutEncoder extends LayoutWrappingEncoder<ILoggingEvent> {
public CustomJsonLayoutEncoder() {
}
public void start() {
CustomJsonLayout jsonLayout = new CustomJsonLayout();
();
(false);
(true);
(new JacksonJsonFormatter());
();
(StandardCharsets.UTF_8);
(jsonLayout);
();
}}
The trace_id here is a function provided by skywalking when using skywalking: #traceId
Then just add the Configure this in theCustomJsonLayoutEncoder It will be possible to output logs according to our customized data:
<appender name="PROJECT_LOG" class="">
<file>${PATH}/</file>
<rollingPolicy class="">
<fileNamePattern>${PATH}/app_%</fileNamePattern>
<maxIndex>1</maxIndex>
</rollingPolicy>
<triggeringPolicy class="">
<maxFileSize>100MB</maxFileSize>
</triggeringPolicy>
<encoder class=""/>
</appender>
<root level="INFO">
<appender-ref ref="STDOUT"/>
<appender-ref ref="PROJECT_LOG"/>
</root>
Although this function can also be printed using the log cutout, it's still not as convenient as outputting directly in the log, which can be directly associated with our log, just with these extra fields.
Spring Boot Usage
OpenTelemetry There is aspring-boot-starter package for use when not using thejavaagent The case can also be buried automatically.
<dependencies>
<dependency>
<groupId></groupId>
<artifactId>opentelemetry-spring-boot-starter</artifactId>
<version>OPENTELEMETRY_VERSION</version>
</dependency>
</dependencies>
But in the earlyreleaseDirect printing of MDC logs is not yet supported:
The latest version already supports
Even after the default MDC output is supported, we can still customize the content, for example, if we want to change the name of the key fromtrace_id modify tootel_trace_id etc.
<appender name="OTEL" class=".v1_0.OpenTelemetryAppender">
<traceIdKey>otel_trace_id</traceIdKey>
<spanIdKey>otel_span_id</spanIdKey>
<traceFlagsKey>otel_trace_flags</traceFlagsKey>
</appender>
It's similar to the previous one, just modify it.
His implementation logic is actually similar to that of the previous auto instrument, except that it uses a different API.
auto instrument is a direct interception of code logic that modifies the return value of a map, whereas theOpenTelemetryAppender is inherited from interface, thus obtaining a rewrite of theMDC abilities, but essentially they are all the same and not much different.
The prerequisite for using it though is that we need to introduce one of the following dependencies:
<dependencies>
<dependency>
<groupId></groupId>
<artifactId>opentelemetry-logback-mdc-1.0</artifactId>
<version>OPENTELEMETRY_VERSION</version>
</dependency>
</dependencies>
If you don't want to modify thespringboot For a simpler solution, we can customize the MDC data by simply using the following configuration:
= trace_id=%mdc{trace_id} span_id=%mdc{span_id} trace_flags=%mdc{trace_flags} %5p
The key here can also be customized, as long as the placeholders are not taken incorrectly.
The prerequisite for using this is to load the javaagent, because the data here is written in the javaagent.
summarize
The above is aboutMDC existOpenTelemetry The use in the code has been analyzed both in terms of usage and source code logic, and I hope that it will be useful for theMDC cap (a poem)OpenTelemetry The understanding is a little deeper.
The concept and use of MDC is still very useful and is an essential tool for troubleshooting problems on a daily basis.