Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

feat: allow format as json #63

Merged
merged 1 commit into from
Jul 17, 2024
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension


Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
37 changes: 32 additions & 5 deletions README.md
Original file line number Diff line number Diff line change
Expand Up @@ -104,16 +104,43 @@ Example of logger configuration that is utilizing `encryptionAlgorithm` and `enc
<avio-logger:config name="ts-logger-test-config-encryption" doc:name="AVIO Logger Config" doc:id="e4f60146-7ee7-404a-a177-ac187c874bdd" applicationVersion="#[p('api.version')]" defaultCategory="com.avioconsulting.mule" encryptionAlgorithm="PBEWithHmacSHA512AndAES_128" encryptionPassword="${secure::encryption.password}"/>
```

# Support for automatically including trace and span IDs in each log (v2.2.x)
# Support for automatically including trace and span IDs in each log (v2.2.x+)

This feature is designed to be used in tandom with the [Mule OpenTelemetry Module.](https://github.com/avioconsulting/mule-opentelemetry-module) If the Mule OpenTelemetry Module is included in your project, AVIO Logger will automatically include the following attributes in each log's `messageAttributes` section.
1. `traceId` - Trace id of the current request
2. `spanId` - Span Id for the component used for creating context
3. `spanIdLong` - Long number value of the `spanId` for services that require a long number for Span IDs (i.e DataDog)
4. `traceIdLongLowPart` - Long value of the Trace Id Low part

- `traceId` - Trace id of the current request
- `spanId` - Span Id for the component used for creating context
- `spanIdLong` - Long number value of the `spanId` for services that require a long number for Span IDs (i.e DataDog)
- `traceIdLongLowPart` - Long value of the Trace Id Low part

If the OpenTelemetry Module is not in use, there is no configuration necessary and the logs will not include these additional messageAttributes.

# Format As Json (v2.3 onwards)
Some Log4J appenders (eg. OpenTelemetry Appender) may not support using Log4j Layouts but the log aggregation backend may require log messages in JSON format. In such scenarios, it is possible to format the lag message as JSON string.

Mule Custom Logger v2.3 introduced a new configuration flag to format the log message as a JSON string -

```xml
<avio-logger:config name="AVIO_Logger_Config_Json"
applicationName="${otel.service.name}"
applicationVersion="1.0"
environment="#[p('mule.env')]"
formatAsJson="true"> // Configure to format as JSON
</avio-logger:config>
```
Following two sample log statements shows the difference.

Log without JSON formatting prints the java string version of the object -

`
INFO 2024-07-16 12:58:53,183 [[MuleRuntime].uber.10: [simple-otel].simple-otel-log-flow-custom-logger.CPU_LITE @2306b18c] [processor: simple-otel-log-flow-custom-logger/processors/1; event: 0d99c380-4345-11ef-b9db-ca89f39a1b65] com.avioconsulting.api: {timestamp=2024-07-16T07:28:53.183Z, appName=simple-otel, appVersion=1.0, env=dev, correlationId=0d99c380-4345-11ef-b9db-ca89f39a1b65, message=Sample otel custom log, messageAttributes={traceId=fc010d3d5393cfd1606e2dd3adc56049, traceIdLongLowPart=6948541662255997001, spanId=8d267add2300b701, spanIdLong=10170951898656454401}, exception={statusCode=null, detail=null}}
`

Log with JSON formatting prints correctly formatted JSON string -

`
INFO 2024-07-16 12:58:53,189 [[MuleRuntime].uber.10: [simple-otel].simple-otel-log-flow-custom-logger.CPU_LITE @2306b18c] [processor: simple-otel-log-flow-custom-logger/processors/2; event: 0d99c380-4345-11ef-b9db-ca89f39a1b65] com.avioconsulting.api: {"timestamp":"2024-07-16T07:28:53.188Z","appName":"simple-otel","appVersion":"1.0","env":"dev","correlationId":"0d99c380-4345-11ef-b9db-ca89f39a1b65","message":"Sample otel custom log Json","messageAttributes":{"traceId":"fc010d3d5393cfd1606e2dd3adc56049","traceIdLongLowPart":"6948541662255997001","spanId":"8d267add2300b701","spanIdLong":"10170951898656454401"},"exception":{}}
`

# Using the Timer Scope
The timer scope allows you to unobtrusively measure the time taken to execute the processors within the scope. For example,
Expand Down
7 changes: 6 additions & 1 deletion pom.xml
Original file line number Diff line number Diff line change
Expand Up @@ -7,7 +7,7 @@
<groupId>com.avioconsulting.mule</groupId>
<artifactId>mule-custom-logger</artifactId>
<name>Mule Custom Logger</name>
<version>2.2.1-SNAPSHOT</version>
<version>2.3.0-SNAPSHOT</version>
<packaging>mule-extension</packaging>
<description>Mule Custom Logger module that provides standard structured logging</description>
<url>https://github.com/${project.github.repository}</url>
Expand Down Expand Up @@ -208,6 +208,11 @@
<version>2.17.1</version>
<scope>provided</scope>
</dependency>
<dependency>
<groupId>com.google.code.gson</groupId>
<artifactId>gson</artifactId>
<version>2.11.0</version>
</dependency>
</dependencies>
<repositories>
<repository>
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -7,6 +7,7 @@
import com.avioconsulting.mule.logger.api.processor.MessageAttributes;
import com.avioconsulting.mule.logger.internal.config.CustomLoggerConfiguration;
import com.avioconsulting.mule.logger.internal.utils.CustomLoggerUtils;
import com.google.gson.Gson;
import java.time.Instant;
import java.time.ZoneId;
import java.time.format.DateTimeFormatter;
Expand All @@ -18,6 +19,7 @@
import org.apache.logging.log4j.message.MapMessage;
import org.apache.logging.log4j.message.Message;
import org.apache.logging.log4j.message.ObjectMessage;
import org.apache.logging.log4j.message.SimpleMessage;
import org.mule.runtime.api.component.location.ComponentLocation;
import org.mule.runtime.extension.api.runtime.parameter.ParameterResolver;
import org.slf4j.LoggerFactory;
Expand Down Expand Up @@ -58,7 +60,8 @@ public void log(LogProperties logProperties,
loggerConfig.getApplicationVersion(),
loggerConfig.getEnvironment(),
loggerConfig.getDefaultCategory(),
loggerConfig.isEnableV1Compatibility());
loggerConfig.isEnableV1Compatibility(),
loggerConfig.isFormatAsJson());
}

public void log(LogProperties logProperties,
Expand All @@ -71,13 +74,14 @@ public void log(LogProperties logProperties,
String applicationVersion,
String environment,
String defaultCategory,
boolean enableV1Compatibility) {
boolean enableV1Compatibility,
boolean formatAsJson) {
if (enableV1Compatibility) {
logV1(logProperties, messageAttributes,
exceptionProperties, additionalProperties,
location, correlationId,
applicationName, applicationVersion,
environment, defaultCategory);
environment, defaultCategory, formatAsJson);
} else {
Logger logger = CustomLoggerUtils.initLogger(defaultCategory, logProperties.getCategory(),
logProperties.getCategorySuffix());
Expand Down Expand Up @@ -147,20 +151,27 @@ public void log(LogProperties logProperties,
logContext.put("location", getLocationInformation(location));
}

/*
* Check system property avio.logger.useMapMessage to turn on MapMessage usage
* in studio.
* This allows pattern layout to display specific attributes of the MapMessage
*/
Message message;
if ("true".equalsIgnoreCase(System.getProperty("avio.logger.useMapMessage"))) {
message = new MapMessage<>(logContext);
} else {
message = new ObjectMessage(logContext);
}
writeLog(logContext, logger, level, formatAsJson);
}
}

logger.log(level, message);
private void writeLog(Map<String, Object> logContext, Logger logger, Level level, boolean formatAsJson) {
/*
* Check system property avio.logger.useMapMessage to turn on MapMessage usage
* in studio.
* This allows pattern layout to display specific attributes of the MapMessage
*/
Message message;
if ("true".equalsIgnoreCase(System.getProperty("avio.logger.useMapMessage"))) {
message = new MapMessage<>(logContext);
} else if (formatAsJson) {
Gson gson = new Gson();
String json = gson.toJson(logContext);
message = new SimpleMessage(json);
} else {
message = new ObjectMessage(logContext);
}
logger.log(level, message);
}

public static Map<String, String> getLocationInformation(ComponentLocation location) {
Expand All @@ -182,7 +193,8 @@ public void logV1(LogProperties logProperties,
String applicationName,
String applicationVersion,
String environment,
String defaultCategory) {
String defaultCategory,
boolean formatAsJson) {

Logger logger = CustomLoggerUtils.initLogger(defaultCategory, logProperties.getCategory(),
logProperties.getCategorySuffix());
Expand Down Expand Up @@ -220,16 +232,7 @@ public void logV1(LogProperties logProperties,
logContext.put("location", getLocationInformation(location));
}

/* 1.2.1 - Changed to MapMessage instead of ObjectMessage */
/* Check system property - avio.custom.logger.env */
/* this lets us differentiate to use simplified logging locally */
Message message;
if ("true".equalsIgnoreCase(System.getProperty("avio.logger.useMapMessage"))) {
message = new MapMessage<>(logContext);
} else {
message = new ObjectMessage(logContext);
}
logger.log(level, message);
writeLog(logContext, logger, level, formatAsJson);
}

}
Original file line number Diff line number Diff line change
Expand Up @@ -89,6 +89,13 @@ public class CustomLoggerConfiguration implements Startable, Initialisable {
@Expression(ExpressionSupport.NOT_SUPPORTED)
private boolean enableV1Compatibility;

@Parameter
@DisplayName("Format as JSON")
@Summary("Writes the Log message as JSON String. This can be useful where appenders (eg. OpenTelemetry) does not support using layouts but backend system requires a JSON formatted message.")
@Optional(defaultValue = "false")
@Expression(ExpressionSupport.NOT_SUPPORTED)
private boolean formatAsJson;

@Parameter
@DisplayName("Compression Strategy")
@Summary("Enumerated Compression Strategy value to compress payload before logging")
Expand Down Expand Up @@ -160,6 +167,10 @@ public boolean isEnableV1Compatibility() {
return enableV1Compatibility;
}

public boolean isFormatAsJson() {
return formatAsJson;
}

public Compressor getCompressor() {
return compressor;
}
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -60,7 +60,40 @@ public void log_verifyLogPropertiesNoPayloadNoAttributes_test() {
applicationVersion,
environment,
defaultCategory,
enableV1Compatibility);
enableV1Compatibility, false);

// Assertions
// Assert log properties
Assert.assertEquals(null, spyLogProperties.getPayload());
// Assert Message Attributes
Assert.assertEquals(null, spyMessageAttributes.getOTelContext());
ArrayList emptyList = new ArrayList();
Assert.assertEquals(emptyList, spyMessageAttributes.getAttributeList());

}

@Test
public void log_verifyJsonLogWriting() {
// Initialize, create mocks and spys
CustomLogger customLogger = new CustomLogger();
LogProperties logProperties = new LogProperties();
LogProperties spyLogProperties = spy(logProperties);
MessageAttributes messageAttributes = new MessageAttributes();
MessageAttributes spyMessageAttributes = spy(messageAttributes);
when(spyLogProperties.getPayload()).thenReturn(null);

// Call method
customLogger.log(spyLogProperties,
spyMessageAttributes,
mock(ExceptionProperties.class),
mock(AdditionalProperties.class),
mock(ComponentLocation.class),
correlationId,
applicationName,
applicationVersion,
environment,
defaultCategory,
enableV1Compatibility, true);

// Assertions
// Assert log properties
Expand Down Expand Up @@ -103,7 +136,7 @@ public void log_traceAndSpanDataIsInMessageAttributes_test() throws MuleExceptio
applicationVersion,
environment,
defaultCategory,
enableV1Compatibility);
enableV1Compatibility, false);

// Assertions
// Assert log properties
Expand Down
5 changes: 5 additions & 0 deletions src/test/resources/custom-logger-config.xml
Original file line number Diff line number Diff line change
Expand Up @@ -8,6 +8,9 @@ http://www.mulesoft.org/schema/mule/avio-logger http://www.mulesoft.org/schema/m
<avio-logger:config name="AVIO_Logger_Config" doc:name="AVIO Logger Config" doc:id="84bd2712-015b-46b8-93e9-94536774b8ad"
applicationVersion="#['1']" compressor="GZIP" encryptionAlgorithm="PBEWithHmacSHA512AndAES_128" encryptionPassword="example" enableFlowLogs="true"/>

<avio-logger:config name="AVIO_Logger_Config_Json" doc:name="AVIO Logger Config" doc:id="84bd2712-015b-46b8-93e9-94536774b8ad"
applicationVersion="#['1']" compressor="GZIP" encryptionAlgorithm="PBEWithHmacSHA512AndAES_128" encryptionPassword="example" enableFlowLogs="true" formatAsJson="true"/>

<flow name="custom-logger-configFlow" doc:id="0068e855-24dc-41a4-8e13-41ca38de99ba">
<set-variable value="#[{'traceId': '76d5bcae3d49ff2e1b5ace9f0dcbee42','spanId': 'fa6fbe46daf007b9','spanIdLong': '18045851443427018681','traceparent': '00-76d5bcae3d49ff2e1b5ace9f0dcbee42-fa6fbe46daf007b9-01','TRACE_TRANSACTION_ID': 'bfacf7c0-d583-11ee-adfa-bcd074a0357f','traceIdLongLowPart': '1971114969454603842'}]" doc:name="Set Variable" doc:id="d7a7dade-4453-40cb-97bc-3ca7034372c6" variableName="OTEL_TRACE_CONTEXT"/>
<avio-logger:log doc:name="Custom logger" doc:id="3a7b6ada-78ef-4f32-a14d-df126c8f887d"
Expand All @@ -16,5 +19,7 @@ http://www.mulesoft.org/schema/mule/avio-logger http://www.mulesoft.org/schema/m
payload="&#34;Example Payload&#34;"/>
<avio-logger:log doc:name="Custom logger" doc:id="322979c8-a722-4fea-a272-cf579529c78c"
config-ref="AVIO_Logger_Config" message="#['Logger should get correlation id from event']"/>
<avio-logger:log doc:name="Custom logger" doc:id="322979c8-a722-4fea-a272-cf579529c78c"
config-ref="AVIO_Logger_Config_Json" message="#['Logger printed as JSON String']"/>
</flow>
</mule>
Loading