Insert ObjectMessage as JSON when using JsonTemplateLayout

[svh-06]

Hi,

I have used the appender with JSON layout to include a JSON object in the message attribute of each log message by using ObjectMessage.

<Console name="console-jsonlayout" target="SYSTEM_OUT">
    <JsonLayout properties="true" compact="true" eventEol="true" complete="false" objectMessageAsJsonObject="true" charset="UTF-8" />
</Console>

Log output:

{"instant":{"epochSecond":1698869090,"nanoOfSecond":416393000},"thread":"scheduling-1","level":"INFO","loggerName":"com.example.lggingapp.LogMessageService","message":{"foo":"abc","bar":"xyz"},"endOfBatch":false,"loggerFqcn":"org.apache.logging.log4j.spi.AbstractLogger","contextMap":{},"threadId":42,"threadPriority":5}

This worked fine so. However I want to use the appender with JsonTemplate to create log messages that fit the ElasticSearch layout.

<Console name="console-jsontemplate" target="SYSTEM_OUT">
    <JsonTemplateLayout eventTemplateUri="classpath:EcsLayout.json" />
</Console>

The problem now is, that the ObjectMessage containing my own message Object is now just being added with its instance hash:

Log output:
{"@timestamp":"2023-11-01T20:04:50.416Z","ecs.version":"1.2.0","log.level":"INFO","message":"com.example.loggingapp.SimpleMessageEntity@3a4a22df","process.thread.name":"scheduling-1","log.logger":"com.example.loggingapp.LogMessageService"}

So my question is: For JsonLayout there was the parameter objectMessageAsJsonObject="true" to add my message entity as JSON to the log entry instead of its instance hash - how can I achieve this with JsonTemplateLayout?
Is there a similar option to set? Could not find anything in the docs.

Thank you in advance!

[vy]

For one, we strongly recommend all Gelf- and JsonLayout users to migrate to JsonTemplateLayout, JTL for short. It is feature-rich, faster, and customizable; simply better. Hence, you are on the right path.

JTL falls back to Object#toString() for types that are not known to it. Earlier I created LOG4J2-3082 to allow JTL to use external serializers (e.g., Jackson) too, though I am swamped with other Log4j priorities. Though you can still achieve this using a custom message resolver.

Creating a custom message resolver

You need to create a custom message resolver and its factory. See the Extending section of the JTL manual for an example. There you can reuse code from org.apache.logging.log4j.layout.template.json.resolver.MessageResolver.

Paying somebody to implement LOG4J2-3082

I happen to be the JTL creator and maintainer. 😅 Though Log4j is more than an individual. Check out our sponsorship page. You can sponsor either me or another Log4j maintainer of your preference to implement LOG4J2-3082.

[brianmaresca]

this is extremely helpful. dare i ask - could you please shed some light on how to make this garbage free?

    @Override
    public void resolve(LogEvent logEvent, JsonWriter jsonWriter) {
        ObjectMessage message = (ObjectMessage) logEvent.getMessage();
        Object value = message.getParameter();
        String valueJson;
        try {
            // With sufficient sorcery, this call can be made garbage-free.
            valueJson = OBJECT_MAPPER.writeValueAsString(value);
        } catch (JsonProcessingException error) {
            throw new RuntimeException(error);
        }
        jsonWriter.writeRawString(valueJson);
    }

[vy]

@brianmaresca, there are a couple of ways you can achieve this. The easiest way from the top of my head is:

CustomWriter writer = writerRecycler.acquire();
try {
    objectMapper.writeValue(writer, value);
    jsonWriter.writeRawString(writer);
} finally {
    writerRecycler.release(writer);
}

Log4j has an internal TruncatingBufferedWriter that you can get inspired for CustomWriter, which needs to implement both Writer and CharSequence.

[miberg81]

Hi, what goes in this custom resolver? Can you please give an example, which would create valid json message?

[vy]

Hi, what goes in this custom resolver? Can you please give an example, which would create valid json message?

As I stated earlier:

See the Extending section of the JTL manual for an example. There you can reuse code from org.apache.logging.log4j.layout.template.json.resolver.MessageResolver.

MessageResolver contains specialization on ObjectMessage. There you can insert your custom logic to convert your object to JSON, for instance, using Jackson, Gson, etc.

[ppkarwasz]

The problem now is, that the ObjectMessage containing my own message Object is now just being added with its instance hash

If you are logging objects that don't have a proper toString() method, you should probably take a more generic approach, that gives a meaningful result regardless of the layout your are using:

1. Create a custom MessageFactory2 that uses your favorite JSON mapper. An stub factory is shown below.
2. Pass an instance of the factory to the LogManager.getLogger() call:

   private static final Logger logger = LogManager.getLogger(JsonMessageFactory.INSTANCE);

3. You can now safely log any Object: JTL will recognize the message as valid JSON and will not stringify it.
   Other layouts such as PatternLayout will print the JsonMessage.getFormattedMessage() instead of Object.toString().

Custom message factory

  public class JsonMessageFactory extends AbstractMessageFactory {
    public static final MessageFactory2 INSTANCE = new JsonMessageFactory();
      @Override
      public Message newMessage(String pattern, Object... params) {
          return new ParameterizedMessage(pattern, params);
      }
  
      @Override
      public Message newMessage(Object obj) {
          return new JsonObjectMessage(obj);
      }
  
      private static class JsonObjectMessage extends ObjectMessage implements MultiformatMessage {
          private static final String[] FORMATS = new String[] {"JSON"};
  
          public JsonObjectMessage(Object obj) {
              super(obj);
          }
  
          @Override
          public String[] getFormats() {
              return FORMATS;
          }
  
          @Override
          public String getFormattedMessage(String[] ignored) {
              return getFormattedMessage();
          }
  
          @Override
          public String getFormattedMessage() {
              // Insert your logic here:
              Object obj = getParameter();
              ...
          }
      }
  }

[vy]

@ppkarwasz, I discourage this approach for two main reasons:

1. It makes the API assume that the effective layout is always JSON-based. For one, one should not make assumptions at the API level about the implementation. Second, effective layout can change depending on the deployment environment – e.g., Pattern Layout on local and JSON Template Layout at production.
2. I find the suggested approach invasive (in particular, given the user only needs specialization for a very limited number of log statements) and difficult to get to get right (e.g., your example can cause serious performance impact if the user was already taking advantage of ReusableParameterizedMessage).

I still think he need to reuse MessageResolver via composition (not inheritance), specialize on ObjectMessage-type, and delegate the rest to the MessageResolver.

[ppkarwasz]

@vy,

1. It makes the API assume that the effective layout is always JSON-based.

It's not a complete solution, but a step in the right direction.
Currently the OP is logging objects that don't override Object.toString(). This basically breaks each layout. Each layout must be amended to deal with this.

I don't recommend using log methods that take Object as parameter, such as info(Object), but if they are used, they should return some sort of useful output for any layout.

JSON is still readable by humans. Of course a complete solution might convert the object as the any type of the OpenTelemetry Logs Data Model and provide multiple output formats.

2. I find the suggested approach invasive (in particular, given the user only needs specialization for a very limited number of log statements) and difficult to get to get right (e.g., your example can cause serious performance impact if the user was already taking advantage of `ReusableParameterizedMessage`).

The main point of my solution is to generate a MultiFormatMessage. Depending on the amount of logging calls, users can:

• use a logger with a specialized message factory, if there are many log statements,
• create a helper method the returns a Supplier<MultiFormatMessage> otherwise.

[miberg81]

Thank you for response. Before using JsonTemplateLayout i used to log in the following way: logger.debug(gson.toJson(myNestedObject): The result was that not the whole java log record was jsonized, but just the message part. It was ok, but i wanted both to have it all jsonized and for the result to be more elastic friendly So i used the recommended JsonTemplateLayout. It did the trick regarding making the whole of log level jsonized, but when i needed to log the same nested object with gson.toJson(nestedObject) somehow escape backslashes appeared everywhere (only in the message part of the log record) My question is, if i implement in the way you suggest, what guarantees no backslashes will be generated? What is the advantage of message resolver over my previous approach, if at the end i still have to use Gson for example? Another thing i could not understand on the official docs: if i want to add another property at the root level of the JsonTemplateLayout, is it possible to sippe add another key+value, or i absolutely must use the additionalFields described in the official docs. Thank you in advance for your patience

…

On Thu, Jul 18, 2024, 16:52 Piotr P. Karwasz ***@***.***> wrote: The problem now is, that the ObjectMessage containing my own message Object is now just being added with its instance hash If you are logging objects that don't have a proper toString() method, you should probably take a more generic approach, that gives a meaningful result regardless of the layout your are using: 1. Create a custom MessageFactory2 <https://logging.apache.org/log4j/2.x/javadoc/log4j-api/org/apache/logging/log4j/message/MessageFactory2.html> that uses your favorite JSON mapper. An stub factory is shown below. 2. Pass an instance of the factory to the LogManager.getLogger() <https://logging.apache.org/log4j/2.x/javadoc/log4j-api/org/apache/logging/log4j/LogManager.html#getLogger(org.apache.logging.log4j.message.MessageFactory)> call: private static final Logger logger = LogManager.getLogger(JsonMessageFactory.INSTANCE); 3. You can now safely log any Object: JTL will recognize the message as valid JSON and will not stringify it. Other layouts such as PatternLayout will print the JsonMessage.getFormattedMessage() instead of Object.toString(). Custom message factory public class JsonMessageFactory extends AbstractMessageFactory { public static final MessageFactory2 INSTANCE = new JsonMessageFactory(); @OverRide public Message newMessage(String pattern, Object... params) { return new ParameterizedMessage(pattern, params); } @OverRide public Message newMessage(Object obj) { return new JsonObjectMessage(obj); } private static class JsonObjectMessage extends ObjectMessage implements MultiformatMessage { private static final String[] FORMATS = new String[] {"JSON"}; public JsonObjectMessage(Object obj) { super(obj); } @OverRide public String[] getFormats() { return FORMATS; } @OverRide public String getFormattedMessage(String[] ignored) { return getFormattedMessage(); } @OverRide public String getFormattedMessage() { // Insert your logic here: Object obj = getParameter(); ... } } } — Reply to this email directly, view it on GitHub <#1939 (comment)>, or unsubscribe <https://github.com/notifications/unsubscribe-auth/AEG5HL5OU27Y6GHDJY3JEB3ZM7CARAVCNFSM6AAAAABLCPC6Z6VHI2DSMVQWIX3LMV43URDJONRXK43TNFXW4Q3PNVWWK3TUHMYTAMBYGUYDMMQ> . You are receiving this because you commented.Message ID: ***@***.***>

[ppkarwasz]

My question is, if i implement in the way you suggest, what guarantees no backslashes will be generated?

As you can see in the documentation of message resolver and the revamped documentation of MapMessage, JTL (and other appenders) treats MapMessages differently.
You actually just need to return a MultiformatMessage from your custom MessageFactory2 to be sure to obtain a JSON Object, instead of a JSON String:

logging-log4j2/log4j-layout-template-json/src/main/java/org/apache/logging/log4j/layout/template/json/resolver/MessageResolver.java

Lines 145 to 158 in d5ab2f2

	// Try `Message` serializer
	if (writeMessage(jsonWriter, message)) {
	return;
	}
	// Try `MultiformatMessage` serializer
	if (writeMultiformatMessage(jsonWriter, message)) {
	return;
	}
	// Try `ObjectMessage` serializer
	if (writeObjectMessage(jsonWriter, message)) {
	return;
	}

You need to use MapMessage if you want it to work with other appenders, like the OpenTelemetry appender, but it requires more work.

What is the advantage of message resolver over my previous approach, if at the end i still have to use Gson for example?

logger.debug(gson.toJson(myNestedObject);

In this case GSON is called eagerly, whether the DEBUG level is enabled or not. If you implement a MessageFactory2 or MessageResolver, GSON will be called only if the message is going to be logged.

Note: you can also use lambdas to make your code lazy:

logger.debug(() -> gson.toJson(myNestedObject);

The difference between the MessageFactory2 and the MessageResolver approach is that the latter only works with JTL.
The MessageFactory2 approach will also give a decent result if you any other layouts.

if i want to add another property at the root level of the JsonTemplateLayout, is it possible to simply add another key+value, or i absolutely must use the additionalFields described in the official docs.

I don't if we can come up with a simpler way than EventTemplateAdditionalField:

<JsonTemplateLayout>
    <EventTemplateAdditionalField key="key" value="value"/>
</JsonTemplateLayout>

[vy]

My question is, if i implement in the way you suggest, what guarantees no backslashes will be generated?

Yes, please start with reading the sources of MessageResolver and you will get the picture.

What is the advantage of message resolver over my previous approach, if at the end i still have to use Gson for example?

Your previous approach – i.e., log.info(toJson(obj)) – has two major problems:

1. It makes an assumption about the layout at the API layer. You should not. For instance, you can use Pattern Layout locally for a more human-readable output and use JTL at production, etc.
2. You are always producing text, not JSON. All examples below will produce text, not JSON:

log.info(toJson(1)); // produces "1"
log.info(toJson(Arrays.asList(1,2,3))); // produces "[1,2,3]"
log.info(toJson(Map.of("foo", 1, "bar", 2)); // produces "{\"foo\":1,\"bar\"2}"

Another thing i could not understand on the official docs: if i want to add another property at the root level of the JsonTemplateLayout, is it possible to sippe add another key+value, or i absolutely must use the additionalFields described in the official docs.

For one, what is the problem with additional event fields? What do you want to do and you are not able to using additional event fields? (There are are several ways you can add key-value pairs. But we first need to understand the problem.)

[vy]

Note: you can also use lambdas to make your code lazy:

logger.debug(() -> gson.toJson(myNestedObject);

@ppkarwasz, this is simply wrong. Please stop suggesting ways people can shoot themselves.

@miberg81, I explained who should not do this above.

[miberg81]

Hi,
If i have a class as follows:

public class ExampleClass {
    private static final String property 1= "AAA";
     private static final String property 2= "BBB";
    // constructor

    public void logMethod(Object nestedObject) {
         log.info(nestedObject);
    }
}

I would like to to have a log output, using the JTL, which has the following structure:

{
   "property 1" : "AAA",
    "property 2"  : "BBB",
    "message": // here i need my nestedObject as json 
}

i need this whole output to be elastic friendly
How would you tackle this?

1. do i need a resolver for AAA and another resolver for BBB
2. what should i be logging to acomplish this ,only my nestedObject ot the whole ExampleClass object
3. given that the JsonLayoutTemplate.json is inside jar, should i use additional fields mechanism
   (why not just make a copy of JsonLayoutTemplate.json to my proiject resources folder, then add this 2 fileds at the end of it:

{
   "@timestamp": {
    "$resolver": "timestamp",
    "pattern": {
      "format": "yyyy-MM-dd'T'HH:mm:ss.SSS'Z'",
      "timeZone": "UTC"
    }
  },
  "ecs.version": "1.2.0"
....
....
.....
   "property 1" : "AAA",
    "property 2"  : "BBB"
}

[miberg81]

I hope now i explained the given problem.

[vy]

@miberg81, I don't think you would want the JSON structure produced by encoding arbitrary objects to be merged into your JTL structure. This surely will shoot you in the foot while using it with Elasticsearch. Consider the following:

public static final class StringTyped { public final String label = "x"; }
public static final class IntTyped { public final int label = 1; }

// Will write `label` to a `String`-typed field
log.info(new StringTyped());

// Will try to write `label`, which is an `int`, to a `String`-typed field, and *WILL FAIL*!
log.info(new IntTyped());

Hence, don't allow an arbitrary structure in the eventual JSON produced by JTL, in particular, while using Elasticsearch as a log sink.

[miberg81]

Hi, @vy
Thank you for the answer and the example. I'm afraid i did not fuuly understand what did you mean by "write...to a String-typed field". Where is this assumption that the field is string typed? Is it in the log.info implementation or the JTL itself? A bit confused... Also, regarding elastic, i guess you meant that elastic was expecting the same structure under a given index?(am i write?). But what if the class i'm logging from ("ExampleClass") is always logging a complex nested object of the same structure and i'm always sending logs of this class the a separate elastic index. Would it be ok then to merge this structure to JTL? or still not...

[miberg81]

Beacuse i'm relatively new to log4j as a whole and i see the JsonLayout is depricated and JTL is what is recommened. ..
So as a new user i imagine probably the streanth of it being that i'm able to design the template of my log by the means of the JasonTemplateLayout.json file itself.
So, i might desigh it in , say, with 3 or 4 deapth levels (if i wanted to), then decide, for example, that i wanted the "message" field to be on level 3 instead of root level for example. This freedom of customization would surely requre the use of my custom template (overriding the one from the jar),
This again brings back my initial question of why(or when) i needed the "additional fields" mechanism (if instead of using this mechanism i could just design the template the way i wanted)?...
Or this mechanism works well if i want to work with the default template(inside the jar) and override some fields of it? Which way is the prefered way? (use of default in jar file or custom file)?

[vy]

@miberg81, imagine I try to insert the following two documents into Elasticsearch:

{"foo": [1,2,3]}
{"foo": "bar"}

[Last time I checked,] Elastic will fail on the 2nd document, since its type for field foo is incompatible with the former one. Hence, you cannot blindly store arbitrary structures in Elastic – from a best-practice perspective, you shouldn't also. That is the reason why JTL tries to make you follow a strict structure, to avoid these kind of problems.

@miberg81, I have the impression you're trying to solve a problem that doesn't exist. Instead of providing full flexibility, start with basics, grow your experience, and extend your setup when it is needed.