Details
Major Description
I am working on a library for inserting opencensus-java distributed tracing data into Log4j LogEvents. I used a custom ContextDataInjector that reads the current tracing data and inserts it into the context data. The context data must be returned as a StringMap ( https://logging.apache.org/log4j/2.x/log4j-core/apidocs/org/apache/logging/log4j/core/ContextDataInjector.html#injectContextData(java.util.List,%20org.apache.logging.log4j.util.StringMap) ), so I used a SortedArrayStringMap. I used SortedArrayStringMap.putValue(String, Object) to insert objects for lazily formatting tracing data, for example, an object with a toString() method that formats a trace ID as lowercase base 16 (https://github.com/census-instrumentation/opencensus-java/blob/eabbc41366340e2833295894bc0f4d5dcddba1dd/contrib/log_correlation/log4j2/src/main/java/io/opencensus/contrib/logcorrelation/log4j2/ContextDataUtils.java#L151-L162 ). I noticed that multiple Log4j code paths call toString() on the values when the String is finally needed. However, when I tried using a JsonLayout and Context Map Lookup to put tracing data into a JSON structure, I got a ClassCastException, because the values were only cast to Strings.
The original issue for the ClassCastException in opencensus-java is https://github.com/census-instrumentation/opencensus-java/issues/1436 . The error is:
2018-09-14 20:59:52,690 main ERROR An exception occurred processing Appender File java.lang.ClassCastException: io.opencensus.contrib.logcorrelation.log4j2.ContextDataUtils$TraceIdToLowerBase16Formatter cannot be cast to java.lang.String at org.apache.logging.log4j.core.lookup.ContextMapLookup.lookup(ContextMapLookup.java:58) at org.apache.logging.log4j.core.lookup.Interpolator.lookup(Interpolator.java:188) at org.apache.logging.log4j.core.lookup.StrSubstitutor.resolveVariable(StrSubstitutor.java:1060) at org.apache.logging.log4j.core.lookup.StrSubstitutor.substitute(StrSubstitutor.java:982) at org.apache.logging.log4j.core.lookup.StrSubstitutor.substitute(StrSubstitutor.java:878) at org.apache.logging.log4j.core.lookup.StrSubstitutor.replace(StrSubstitutor.java:433) at org.apache.logging.log4j.core.layout.AbstractJacksonLayout.resolveAdditionalFields(AbstractJacksonLayout.java:292) at org.apache.logging.log4j.core.layout.AbstractJacksonLayout.wrapLogEvent(AbstractJacksonLayout.java:274) at org.apache.logging.log4j.core.layout.AbstractJacksonLayout.toSerializable(AbstractJacksonLayout.java:304) at org.apache.logging.log4j.core.layout.JsonLayout.toSerializable(JsonLayout.java:291) at org.apache.logging.log4j.core.layout.AbstractJacksonLayout.toSerializable(AbstractJacksonLayout.java:255) at org.apache.logging.log4j.core.layout.JsonLayout.toSerializable(JsonLayout.java:68) at org.apache.logging.log4j.core.layout.AbstractJacksonLayout.toSerializable(AbstractJacksonLayout.java:44) at org.apache.logging.log4j.core.layout.AbstractStringLayout.toByteArray(AbstractStringLayout.java:304) at org.apache.logging.log4j.core.layout.AbstractLayout.encode(AbstractLayout.java:210) at org.apache.logging.log4j.core.layout.AbstractLayout.encode(AbstractLayout.java:37) at org.apache.logging.log4j.core.appender.AbstractOutputStreamAppender.directEncodeEvent(AbstractOutputStreamAppender.java:177) at org.apache.logging.log4j.core.appender.AbstractOutputStreamAppender.tryAppend(AbstractOutputStreamAppender.java:170) at org.apache.logging.log4j.core.appender.AbstractOutputStreamAppender.append(AbstractOutputStreamAppender.java:161) at org.apache.logging.log4j.core.config.AppenderControl.tryCallAppender(AppenderControl.java:156) at org.apache.logging.log4j.core.config.AppenderControl.callAppender0(AppenderControl.java:129) at org.apache.logging.log4j.core.config.AppenderControl.callAppenderPreventRecursion(AppenderControl.java:120) at org.apache.logging.log4j.core.config.AppenderControl.callAppender(AppenderControl.java:84) at org.apache.logging.log4j.core.config.LoggerConfig.callAppenders(LoggerConfig.java:464) at org.apache.logging.log4j.core.config.LoggerConfig.processLogEvent(LoggerConfig.java:448) at org.apache.logging.log4j.core.config.LoggerConfig.log(LoggerConfig.java:431) at org.apache.logging.log4j.core.config.LoggerConfig.log(LoggerConfig.java:406) at org.apache.logging.log4j.core.config.AwaitCompletionReliabilityStrategy.log(AwaitCompletionReliabilityStrategy.java:63) at org.apache.logging.log4j.core.Logger.logMessage(Logger.java:146) at org.apache.logging.log4j.spi.AbstractLogger.tryLogMessage(AbstractLogger.java:2170) at org.apache.logging.log4j.spi.AbstractLogger.logMessageTrackRecursion(AbstractLogger.java:2125) at org.apache.logging.log4j.spi.AbstractLogger.logMessageSafely(AbstractLogger.java:2108) at org.apache.logging.log4j.spi.AbstractLogger.logMessage(AbstractLogger.java:2002) at org.apache.logging.log4j.spi.AbstractLogger.logIfEnabled(AbstractLogger.java:1974) at org.apache.logging.log4j.spi.AbstractLogger.warn(AbstractLogger.java:2624) at io.opencensus.contrib.logcorrelation.log4j.demo.OpenCensusLog4jLogCorrelationDemo.doWork(OpenCensusLog4jLogCorrelationDemo.java:60) at io.opencensus.contrib.logcorrelation.log4j.demo.OpenCensusLog4jLogCorrelationDemo.createSampledTrace(OpenCensusLog4jLogCorrelationDemo.java:50) at io.opencensus.contrib.logcorrelation.log4j.demo.OpenCensusLog4jLogCorrelationDemo.main(OpenCensusLog4jLogCorrelationDemo.java:44)
I'm not sure whether this is a bug or StringMap is not meant to hold lazy formatting objects.