Apache Camel: A few log tricks
Logging is great because you can write messages in human-readable form that are automatically timestamped. Originally used more for local debugging, it is nowadays used more and more to observe the state of a system. When something happened and why.
Camel supports both of these uses cases through the logger EIP (enterprise integration pattern) and the log data component. On a surface level they are similar and fairly straightforward. It’s however good to know the differences between both and how far you can take them. It turns out pretty far.
Log EIP: the default logger
By default Camel provides the logger pattern:
Let’s start with the most basic log example in Camel:
<route>
<from uri="scheduler:foo?repeatCount=1"/>
<log message="Hello"/>
</route>This simply logs the “Hello” message. Think of this as the equivalent of a Java log command:
logger.info("Hello");If you want more control over the log you can add the logging level and name:
<route id="MyCoolRoute">
<from uri="scheduler:foo?repeatCount=1"/>
<setBody>
<constant>world</constant>
</setBody>
<log message="Hello ${body}!" loggingLevel="INFO" logName="com.mycompany.MyCoolRoute"/>
</route>This outputs:
2024-11-21T14:45:50.459+01:00 INFO 2636 --- [gateway] [scheduler://foo] com.mycompany.MyCoolRoute : Hello world!Logs can also easily embedded within Camel’s route logic:
<route>
<from uri="direct:a"/>
<choice>
<when>
<simple>${header.foo} == 'bar'</simple>
<log message="Eating a bar" loggingLevel="INFO"/>
</when>
<when>
<simple>${header.foo} == 'cheese'</simple>
<log message="Eating cheese" loggingLevel="WARN"/>
</when>
<otherwise>
<log message="Eating shit" loggingLevel="FATAL"/>
</otherwise>
</choice>
</route>Data logging
The thing with Camel is that it’s message-orientated. This mean the data is mostly within an exchange:
You can use the simple language in the logger EIP to get data out of the exchange. For example by providing a specific header, like ${header.foo} or you can print the body ${body}.
But what if you want to see many parts of the exchange without specifying every part? For this you can you use the log data component:
A simple example
<route id="MyNotSoCoolRoute">
<from uri="scheduler:foo?repeatCount=1"/>
<setBody>
<constant>Hello you</constant>
</setBody>
<setHeaders>
<setHeader name="myHeader">
<constant>you</constant>
</setHeader>
<setHeader name="otherHeader">
<constant>me</constant>
</setHeader>
</setHeaders>
<to uri="log:com.mycompany.MyNotSoCoolRoute?level=INFO"/>
</route>
This is the log output:
2024-11-21T16:06:05.753+01:00 INFO 2636 --- [gateway] [scheduler://foo] com.mycompany.MyCoolRoute : Exchange[ExchangePattern: InOnly, BodyType: String, Body: Hello you]As you can see the body, the body type and exchange pattern are logged, but not the headers. If you want to add headers to the log output, you need to add the option showHeaders=true. In the documentation there are 18 options to show a specific part of the exchange or not.
A quick shortcut
There is also shortcut to quickly show everything in a human readable form:
<to uri="log:com.mycompany.MyCoolRoute??showAll=true&multiline=true"/> In the example route this would give the following output:
2024-11-21T16:17:23.381+01:00 INFO 2636 --- [gateway] [scheduler://foo] com.mycompany.MyCoolRoute : Exchange[
Id: 50FD391EDA3BB11-0000000000000007
RouteGroup: null
RouteId: 19000-19050
ExchangePattern: InOnly
Properties: {CamelMessageHistory=[MetricsMessageHistory[routeId=19000-19050, node=setBody7], MetricsMessageHistory[routeId=19000-19050, node=setHeaders5], MetricsMessageHistory[routeId=19000-19050, node=to6]], CamelToEndpoint=log://com.mycompany.MyCoolRoute??showAll=true&multiline=true, MetricsRoutePolicy-19000-19050=com.codahale.metrics.Timer$Context@2d480b83}
Headers: {breadcrumbId=50FD391EDA3BB11-0000000000000007, myHeader=you, otherHeader=me}
BodyType: String
Body: Hello you
]
Dynamic logging
How about combining a log message with a log of the exchange data? Since 4.9.0 this is possible:
<log message="The complete data:\n ${logExchange}"/>The output:
2024-12-06T18:58:26.338+01:00 INFO 15396 --- [gateway] [scheduler://foo] _fcac318c-7b2e-419c-a0ec-bd6a0e364035:14 : The complete data:
Exchange[
Id 56BE87D90EC5A8B-0000000000000002
Headers {breadcrumbId=56BE87D90EC5A8B-0000000000000002, myHeader=you, otherHeader=me}
BodyType String
Body Hello you
]xStructured logging
Logs are very useful, but the problem with log files is they are just unstructured text data. This makes it hard to query them for any sort of useful information. Because logs are continuously stored in search databases like Elastic or Splunk, there is also a need for more structured logs.
Structured logging is the practice to put log information in a consistent format, mostly JSON. Camel doesn’t provide a structured log out-of-the-box, but it does provide ways to use custom loggers. In this blog we create 3 structured loggers:
- Log with a custom processor
- Log with an ExchangeFormatter
- Log with a log framework
1. Log with a custom processor
Let’s start with using a Camel processor. This is one of the easiest ways to enhance logs, because the input of a processor is a Camel exchange. As output we like to have a JSON in an OpenTelemetry format.
The code of the processor:
import com.fasterxml.jackson.core.JsonProcessingException;
import com.fasterxml.jackson.databind.ObjectMapper;
import org.apache.camel.Exchange;
import org.apache.camel.Processor;
import java.time.Instant;
import java.time.ZoneOffset;
import java.time.format.DateTimeFormatter;
import java.util.HashMap;
import java.util.Map;
public class OpenTelemetryLogProcessor implements Processor {
public void process(Exchange exchange) throws Exception {
String json = format(exchange);
System.out.println(json);
}
private String format(Exchange exchange) throws JsonProcessingException {
// Map the exchange
Object inBody = exchange.getIn().getBody();
Map<String, Object> exchangeMap = new HashMap<>();
exchangeMap.put("ExchangePattern", exchange.getPattern().toString());
exchangeMap.put("Body", inBody != null ? inBody.toString() : "null");
exchangeMap.put("Headers", exchange.getIn().getHeaders());
// Create a timestamp
Instant now = Instant.now();
String formattedTime = DateTimeFormatter
.ofPattern("yyyy-MM-dd'T'HH:mm:ss.SSS'Z'")
.withZone(ZoneOffset.UTC)
.format(now);
// Map it to opentelemetry log format
Map<String, Object> map = new HashMap<>();
map.put("timestamp", formattedTime);
map.put("logLevel", "INFO");
map.put("serviceName", exchange.getFromRouteId());
map.put("message", exchange.getExchangeId());
map.put("attributes",exchangeMap);
ObjectMapper mapper = new ObjectMapper();
String jsonString = mapper.writeValueAsString(map);
return jsonString;
}
}So in around 50 lines when can create a structured log.
Using the custom log processor
Next step is to bind this processor to the CamelContext:
registry.bind("opentelemetryProcessor", new OpenTelemetryLogProcessor());Now we can use the processor in any route:
<route id="logRoute">
<from uri="scheduler:foo?repeatCount=1"/>
<setBody>
<constant>Hello you</constant>
</setBody>
<setHeaders>
<setHeader name="myHeader">
<constant>you</constant>
</setHeader>
<setHeader name="otherHeader">
<constant>me</constant>
</setHeader>
</setHeaders>
<process ref="opentelemetryProcessor"/>
</route> The log output in the console:
{
"timestamp": "2024-11-21T22:46:50.310Z"
"logLevel": "INFO",
"serviceName": "19000-19050",
"message": "E8075FE171272A3-0000000000000000",
"attributes": {
"ExchangePattern": "InOnly",
"Headers": {
"breadcrumbId": "E8075FE171272A3-0000000000000000",
"myHeader": "you",
"otherHeader": "me"
},
"Body": "Hello you",
},
}2. Log with a custom ExchangeFormatter
A processor has its limits in providing parameters. Components are better. For example, the log component has a built-in DefaultExchangeFormatter. This formatter takes an exchange and, as we have seen, adds only the parts configured by the user.
The log component allows to use your own formatter. In our case we create a JSON formatter that outputs a structured log. The output JSON is in the Elastic common schema format. The code of this custom ExchangeFormatter is on my GitHub page.
To make this formatter globally available we add it to the Camel registry:
registry.bind("jsonExchangeFormatter", new JsonExchangeFormatter());And then use it:
<to uri="log:com.mycompany.ecsLogRoute?showAll=true"/>The output:
2024-11-21T17:33:31.312+01:00 INFO 13276 --- [gateway] [scheduler://foo] com.mycompany.ecsLogRoute : {
"Headers": {
"myHeader": "you",
"breadcrumbId": "DA78CDA1A271026-0000000000000000",
"otherHeader": "me"
},
"BodyType": "String",
"Body": "Hello you"
}As you can see it’s a normal log by the log component and the JSON by the formatter.
Bypass the default logger
If we don’t want to use a (slfj) log then we can also use our custom exchanges format directly from a processor. For this task, we create a class that implements Processor:
import org.apache.camel.Exchange;
import org.apache.camel.Processor;
public class MyLogProcessor implements Processor {
public void process(Exchange exchange) throws Exception {
JsonExchangeFormatter jsonFormatter = new JsonExchangeFormatter();
jsonFormatter.setShowAll(true);
String json = jsonFormatter.format(exchange);
System.out.println(json);
}
}Then we bind the context to this processor:
registry.bind("myLogProcessor", new MyLogProcessor());And then use it within our route:
<route id="logRoute">
<from uri="scheduler:foo?repeatCount=1"/>
<setBody>
<constant>Hello you</constant>
</setBody>
<setHeaders>
<setHeader name="myHeader">
<constant>you</constant>
</setHeader>
<setHeader name="otherHeader">
<constant>me</constant>
</setHeader>
</setHeaders>
<process ref="myLogProcessor"/>
</route>The output log is:
{
"ExchangePattern": "InOnly",
"Headers": {
"myHeader": "you",
"breadcrumbId": "AD8305CFDB22134-0000000000000000",
"otherHeader": "me"
},
"RouteId": "19000-19050",
"BodyType": "String",
"Properties": {"MetricsRoutePolicy-19000-19050": "com.codahale.metrics.Timer$Context@3a773bf8"},
"Body": "Hello you",
"ExchangeId": "AD8305CFDB22134-0000000000000000"
}3. Log with a log framework
It’s also possible to use a custom logger:
<log message="Me Got ${body}" logger="customJsonLog"/>However to use this you need to add a custom Logback logger (At least, if you don’t want to enable it for all logs).
LoggerContext context = (LoggerContext) LoggerFactory.getILoggerFactory();
context.setName("json");
// Set up the JSON encoder (LogstashEncoder)
JsonEncoder jsonEncoder = new JsonEncoder();
jsonEncoder.setContext(context); // Link to the logger context
jsonEncoder.start();
// Create a console appender
ConsoleAppender<ILoggingEvent> consoleAppender = new ConsoleAppender<>();
consoleAppender.setContext(context);
consoleAppender.setEncoder(jsonEncoder);
consoleAppender.start();
// Get the desired logger and cast it to Logback's Logger
Logger logger = (Logger) LoggerFactory.getLogger("json");
// Add the appender to the logger
logger.addAppender(consoleAppender);
registry.bind("customJsonLog",logger);The output:
{"sequenceNumber":0,"timestamp":1732218572177,"nanoseconds":177952800,"level":"INFO","threadName":"Camel (camel-1) thread #2 - scheduler:\/\/foo","loggerName":"json","context":{"name":"json","birthdate":1732218431209,"properties":{}},"mdc": {},"message":"Me Got Hello you","throwable":null}Some final remarks
This blog showed some basic examples of logging, while the structured log examples showed how far you take logging in Camel.
On a more general note on structured logging. More and more structured logging formats are available and supported by various frameworks. Recently, Spring Boot has added support for structured logging:
This let you support the follow structured log formats:
Note that probably ECS will develop further into the industry standard for structured logs as this format is adopted by the OpenTelemetry project:
Happy logging.
