The objectMapper.findAndRegisterModules() not registering modules in quarkus-logging-json in native mode

[idachev]

Describe the bug

If the JavaTimeModule class is available, I expect the ObjectMapper used by quarkus-logging-json to register it as a module.

That does not happen in native build.

Expected behavior

If the JavaTimeModule class is available, I expect the ObjectMapper used by quarkus-logging-json to register it as a module.

Actual behavior

This exception is thrown:

Caused by: com.fasterxml.jackson.databind.exc.InvalidDefinitionException: Java 8 date/time type `java.time.Instant` not supported by default: add Module "com.fasterxml.jackson.datatype:jackson-datatype-jsr310" to enable handling

How to Reproduce?

A simple code to test:

Map<String, Object> event = new HashMap<>();
event.put("time", Instant.now());

log.info("Test msg", kv("event", event));

That will not dump any json message and will log an error that jsr310 should be registered.

Output of uname -a or ver

5.15.0-86-generic #96-Ubuntu SMP Wed Sep 20 08:23:49 UTC 2023 x86_64 x86_64 x86_64 GNU/Linux

Output of java -version

openjdk 17.0.8.1 2023-08-24

Mandrel or GraalVM version (if different from Java)

No response

Quarkus version or git rev

3.2.6.Final

Build tool (ie. output of mvnw --version or gradlew --version)

No response

Additional information

No response

[idachev]

The issue is so capsulated that I used some reflection magic to fix this: https://github.com/quarkiverse/quarkus-logging-json/blob/main/runtime/src/main/java/io/quarkiverse/loggingjson/jackson/JacksonJsonFactory.java

[idachev]

For all that comes to this ticket here are the files that I wrote to fix this:

quarkus-logging-json-workaround-36937.zip

And the code itself for indexing from google/github:

package app;

import io.quarkiverse.loggingjson.JsonFormatter;
import io.quarkiverse.loggingjson.JsonProvider;
import io.quarkiverse.loggingjson.config.Config;
import io.quarkus.bootstrap.logging.InitialConfigurator;
import io.quarkus.bootstrap.logging.QuarkusDelayedHandler;
import io.quarkus.runtime.StartupEvent;
import jakarta.enterprise.context.ApplicationScoped;
import jakarta.enterprise.event.Observes;
import java.lang.reflect.Field;
import java.util.Arrays;
import java.util.List;
import lombok.SneakyThrows;
import lombok.extern.slf4j.Slf4j;
import org.jboss.logmanager.handlers.AsyncHandler;
import org.jboss.logmanager.handlers.ConsoleHandler;

/**
 * This is a workaround for the problem described here in native mode:
 *
 * <p><a href="https://github.com/quarkusio/quarkus/issues/36937">Quarkus Issue #36937</a>
 *
 * <p>In short it register a new JsonFormatter with a custom JsonFactory that uses a custom
 * ObjectMapper that has the needed JavaTimeModule registered.
 */
@ApplicationScoped
@Slf4j
public class AppStartup {

  @SneakyThrows
  @SuppressWarnings({"java:S1181"})
  void onStart(@Observes final StartupEvent ev) {
    log.info("The application is starting...");

    try {
      setJsonFormatter();
    } catch (final Throwable t) {
      log.error("Failed to set JsonFactory, error: {}", t.getMessage(), t);
    }
  }

  @SuppressWarnings("resource")
  public static void setJsonFormatter() {
    final QuarkusDelayedHandler delayedHandler = InitialConfigurator.DELAYED_HANDLER;

    final AsyncHandler handler =
        Arrays.stream(delayedHandler.getHandlers())
            .filter(AsyncHandler.class::isInstance)
            .findFirst()
            .map(AsyncHandler.class::cast)
            .orElseThrow();

    final ConsoleHandler consoleHandler =
        Arrays.stream(handler.getHandlers())
            .filter(ConsoleHandler.class::isInstance)
            .findFirst()
            .map(ConsoleHandler.class::cast)
            .orElseThrow();

    if (consoleHandler.getFormatter() instanceof final JsonFormatter jsonFormatter) {
      replaceJsonFormatter(consoleHandler, jsonFormatter);
    }
  }

  private static void replaceJsonFormatter(
      final ConsoleHandler consoleHandler, final JsonFormatter oldJsonFormatter) {

    final List<JsonProvider> providers = getProviders(oldJsonFormatter);

    final String recordDelimiter = getRecordDelimiter(oldJsonFormatter);

    final Config config = new Config();
    config.recordDelimiter = recordDelimiter;

    consoleHandler.setFormatter(
        new JsonFormatter(providers, new CustomJacksonJsonFactory(), config));

    log.info("JsonFormatter replaced");
  }

  @SneakyThrows
  @SuppressWarnings({"unchecked", "java:S3011"})
  private static List<JsonProvider> getProviders(final JsonFormatter jsonFormatter) {

    final Field jsonFactoryField = JsonFormatter.class.getDeclaredField("providers");

    jsonFactoryField.setAccessible(true);

    return (List<JsonProvider>) jsonFactoryField.get(jsonFormatter);
  }

  @SneakyThrows
  @SuppressWarnings({"java:S3011"})
  private static String getRecordDelimiter(final JsonFormatter jsonFormatter) {

    final Field jsonFactoryField = JsonFormatter.class.getDeclaredField("recordDelimiter");

    jsonFactoryField.setAccessible(true);

    return (String) jsonFactoryField.get(jsonFormatter);
  }
}

[idachev]

The other part of the code:

package app;

import com.fasterxml.jackson.core.JsonGenerator.Feature;
import com.fasterxml.jackson.databind.ObjectMapper;
import com.fasterxml.jackson.databind.SerializationFeature;
import com.fasterxml.jackson.datatype.jsr310.JavaTimeModule;
import io.quarkiverse.loggingjson.JsonFactory;
import io.quarkiverse.loggingjson.JsonGenerator;
import io.quarkiverse.loggingjson.StringBuilderWriter;
import java.io.IOException;
import java.util.ServiceConfigurationError;

public class CustomJacksonJsonFactory implements JsonFactory {
  private final com.fasterxml.jackson.core.JsonFactory jsonFactory = createJsonFactory();

  public CustomJacksonJsonFactory() {
    super();
  }

  @SuppressWarnings({"CallToPrintStackTrace", "java:S106"})
  private com.fasterxml.jackson.core.JsonFactory createJsonFactory() {
    final ObjectMapper objectMapper =
        (new ObjectMapper()).disable(SerializationFeature.FAIL_ON_EMPTY_BEANS);

    try {
      objectMapper.findAndRegisterModules();
    } catch (final ServiceConfigurationError e) {
      System.err.println("Error occurred while dynamically loading jackson modules");

      e.printStackTrace();
    }

    objectMapper.registerModule(new JavaTimeModule());

    return objectMapper.getFactory().disable(Feature.FLUSH_PASSED_TO_STREAM);
  }

  @Override
  public JsonGenerator createGenerator(final StringBuilderWriter writer) throws IOException {
    return new CustomJacksonJsonGenerator(jsonFactory.createGenerator(writer));
  }
}

[idachev]

And the last one, know that all are in the zip attached above.

package app;

import io.quarkiverse.loggingjson.JsonGenerator;
import java.io.IOException;
import java.math.BigDecimal;
import java.math.BigInteger;

public class CustomJacksonJsonGenerator implements JsonGenerator {
  private final com.fasterxml.jackson.core.JsonGenerator generator;

  CustomJacksonJsonGenerator(final com.fasterxml.jackson.core.JsonGenerator generator) {
    this.generator = generator;
  }

  @Override
  public void writeStartObject() throws IOException {
    generator.writeStartObject();
  }

  @Override
  public void writeEndObject() throws IOException {
    generator.writeEndObject();
  }

  @Override
  public void flush() throws IOException {
    generator.flush();
  }

  @Override
  public void close() throws IOException {
    generator.close();
  }

  @Override
  public void writeFieldName(final String name) throws IOException {
    generator.writeFieldName(name);
  }

  @Override
  public void writeObject(final Object pojo) throws IOException {
    generator.writeObject(pojo);
  }

  @Override
  public void writeObjectFieldStart(final String fieldName) throws IOException {
    generator.writeObjectFieldStart(fieldName);
  }

  @Override
  public void writeObjectField(final String fieldName, final Object pojo) throws IOException {
    generator.writeObjectField(fieldName, pojo);
  }

  @Override
  public void writeArrayFieldStart(final String fieldName) throws IOException {
    generator.writeArrayFieldStart(fieldName);
  }

  @Override
  public void writeEndArray() throws IOException {
    generator.writeEndArray();
  }

  @Override
  public void writeString(final String text) throws IOException {
    generator.writeString(text);
  }

  @Override
  public void writeStringField(final String fieldName, final String value) throws IOException {
    generator.writeStringField(fieldName, value);
  }

  @Override
  public void writeNumberField(final String fieldName, final short value) throws IOException {
    generator.writeNumberField(fieldName, value);
  }

  @Override
  public void writeNumberField(final String fieldName, final int value) throws IOException {
    generator.writeNumberField(fieldName, value);
  }

  @Override
  public void writeNumberField(final String fieldName, final long value) throws IOException {
    generator.writeNumberField(fieldName, value);
  }

  @Override
  public void writeNumberField(final String fieldName, final BigInteger value) throws IOException {
    generator.writeNumberField(fieldName, value);
  }

  @Override
  public void writeNumberField(final String fieldName, final float value) throws IOException {
    generator.writeNumberField(fieldName, value);
  }

  @Override
  public void writeNumberField(final String fieldName, final double value) throws IOException {
    generator.writeNumberField(fieldName, value);
  }

  @Override
  public void writeNumberField(final String fieldName, final BigDecimal value) throws IOException {
    generator.writeNumberField(fieldName, value);
  }
}