Hi,

I am using your library. It is really nice and easy to use. Thankyou for all your hard work. I wanted to ask is JacksonModule feature is implemented in latest version. I am trying to use it. Here is my configuration.

`<Elasticsearch name="Elasticsearch">
         <IndexName indexName="spring-app-scheduler-local-index"/>
         <JacksonJsonLayout>
             <ExampleJacksonModule />
                 <PooledItemSourceFactory poolName="itemPool" itemSizeInBytes="1024" initialPoolSize="3000"/>
                 <JacksonMixIn mixInClass="com.bupa.schedulerservice.json.CustomLogEventMixIn"
                              targetClass="org.apache.logging.log4j.core.LogEvent"/>
                </JacksonJsonLayout>
                <AsyncBatchDelivery batchSize="1000" deliveryInterval="10000" >
                    <IndexTemplate name="spring-app-scheduler-local-index" path="classpath:indexTemplate-local.json" />
                    <HCHttp serverUris="url">
                        <PooledItemSourceFactory poolName="batchPool" itemSizeInBytes="1024000" initialPoolSize="3"/>
                        <Security>
                        <BasicCredentials username="xxxx" password="xxxx" />
                        </Security>
                </HCHttp>
            </AsyncBatchDelivery>
        </Elasticsearch>`

And here is the class

`@Plugin(name = ExampleJacksonModulePlugin.PLUGIN_NAME, category = Node.CATEGORY, elementType = "JacksonModule", printObject = true)
public class ExampleJacksonModulePlugin extends SimpleModule implements JacksonModule {

    private static final long serialVersionUID = 1L;

     public static final String PLUGIN_NAME = "ExampleJacksonModule";

    @Override
    public void applyTo(ObjectMapper objectMapper) {
        // Uncomment to register your module
         objectMapper.registerModule(new JavaTimeModule());
         JsonMapper.builder().disable(SerializationFeature.WRITE_DATES_AS_TIMESTAMPS);
        // ...
        // And log whatever useful info you need. Or not..?
        //getLogger().info("{} applied", getClass().getSimpleName());
    }

    @PluginBuilderFactory
    public static ExampleJacksonModulePlugin.Builder newBuilder() {
        return new ExampleJacksonModulePlugin.Builder();
    }

    public static class Builder implements org.apache.logging.log4j.core.util.Builder<ExampleJacksonModulePlugin> {

        @Override
        public ExampleJacksonModulePlugin build() {
            return new ExampleJacksonModulePlugin();
        }

    }

}`

But it seems not loading. Am I doing anything wrong?

Thanks & Regards Bast Mahmood Ahmed

Thank you for the good word :pray: I happy that you found it easy and useful.

JacksonModule is implemented, yes.

In order for Log4j2 to load any plugin, it's definition needs to be added to META-INF/org/apache/logging/log4j/core/config/plugins/Log4j2Plugins.dat file. This file is usually generated by Log4j2 PluginProcessor during compile process. If the file is not on your classpath, Log4j2 will complain:

ERROR JacksonJsonLayout contains an invalid element or attribute "ExampleJacksonModule"

Could you post the log from your application's startup, please?

Also, make sure that your plugin is present in production sources (main/src/java?). I just noticed that the JacksonModuleExample plugin is not detected during project's tests JAR build. I probably need to declare this processor explicitly somehow. Always learning...

I created a branch for you in the examples project. Module is applied just fine:

2023-12-10 12:29:47,363 main INFO BatchEmitterFactory class found org.appenders.log4j2.elasticsearch.hc.AsyncBatchEmitterFactory
2023-12-10 12:29:47,373 main INFO Using org.appenders.log4j2.elasticsearch.hc.AsyncBatchEmitterFactory as BatchEmitterServiceProvider
2023-12-10 12:29:47,437 main INFO ExampleJacksonModulePlugin applied
2023-12-10 12:29:47,495 main INFO Pool [batchPool] 3 pooled elements added. Total pooled elements: 3. Took: 16ms

so it doesn't look like an issue with JacksonModule so far. I hope it helps

However, I noticed that you're trying to:

Use JavaTimeModule: LogEvent, in current shape, uses org.apache.logging.log4j.core.time.Instant, not java.time.Instant, so unless you're creating your own LogEvent(s), this module is probably not necessary

This line has no effect:

JsonMapper.builder().disable(SerializationFeature.WRITE_DATES_AS_TIMESTAMPS);

You're trying to amend the way timestamp are serialized. Unless you have a very good reason for it, I don't recommend it as it allocates a lot of objects along the way - something that this project is trying to avoid by using long and timeMillis. If you'd like to: 3a. simply rename it, see log4j2-elasticsearch-16 with
```
"@timestamp":  {
"type": "date",
"format: "epoch_millis"
}
```
in the index template 3b. really use formatted date, see the InstantSerializer from the branch mentioned above.

And finally, since most of the options above is just my guesswork, I think I need to ask: does any of the options above fit your need? If not, what is the exact output that you'd like to achieve?

@rfoltyns Thank you so much. With your help I am able to achieve what I wanted. But still ExampleJacksonModulePlugin is not applying. Anyways basically I wanted to send date on the elk instead of milliseconds. Your InstantSerialiser was the solution that I wanted 👍 Although now the date is sending to elk but I want to know why my ExampleJacksonModule is not applying. What I am doing wrong. Here what I did. Here is my log4j2-spring-local.xml. It is sending logs directly to elk. As it is local, so I am using console, file appender and elasticserach. But for log4j2-spring-uat.xml. It would be just elastic search. Anyway, here is my log4j2-spring-local.xml.

My log file names are log4j2-spring-local.xml and log4j2-spring-uat.xml. They are not just simple lo4j2.xml. Can this is the problem for not applying ExampleJacksonModule ?

<configuration xmlns:xi="http://www.w3.org/2001/XInclude" status="WARN">

    <Properties>
        <Property name="filename">./logs/${spring:spring.application.name}.log</Property>
    </Properties>

    <appenders>

        <Console name="Console" target="SYSTEM_OUT">
            <PatternLayout pattern="%d{yyyy-MM-dd HH:mm:ss.SSS} [%t] %-5level %logger{36} - %msg%n"/>
        </Console>

        <RollingFile name="RollingFile" fileName="${filename}" filePattern="${filename}-%d{yyyy-MM-dd}-%i.log">
            <PatternLayout>
                <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%t] %X{id} %X{username} %-5level %c{36} %l: %msg%n</pattern>
            </PatternLayout>
            <Policies>
                <SizeBasedTriggeringPolicy size="10 MB" />
            </Policies>
            <DefaultRolloverStrategy min="1" max="4" />
        </RollingFile>

        <Elasticsearch name="Elasticsearch">
            <IndexName indexName="spring-app-scheduler-local-index"/>
            <JacksonJsonLayout>
                <ExampleJacksonModule/>
                <JacksonMixIn mixInClass="com.bupa.schedulerservice.json.CustomLogEventMixIn"
                              targetClass="org.apache.logging.log4j.core.LogEvent"/>
                <PooledItemSourceFactory poolName="itemPool" itemSizeInBytes="1024" initialPoolSize="6000"/>
            </JacksonJsonLayout>
            <AsyncBatchDelivery batchSize="1000" deliveryInterval="10000" >
                <IndexTemplate name="spring-app-scheduler-local-index-template" path="classpath:indexTemplate-local.json" apiVersion="7" />
                <HCHttp serverUris="https://url">
                    <PooledItemSourceFactory poolName="batchPool" itemSizeInBytes="1024000" initialPoolSize="3"/>
                    <Security>
                        <BasicCredentials username="user" password="pass" />
                    </Security>
                </HCHttp>
            </AsyncBatchDelivery>
        </Elasticsearch>

    </appenders>

    <loggers>
        <root level="warn">
            <appender-ref ref="Console" />
            <appender-ref ref="RollingFile" />
            <appender-ref ref="Elasticsearch"/> 
        </root>
        <logger name="com.bupa.schedulerservice" level="info" />
        <logger name="org.apache" level="info" />
        <logger name="org.springframework" level="info" />
        <logger name="org.springframework.jdbc" level="trace" />
    </loggers>
</configuration>

For UAT log file is same. But here is the logger part

    <loggers>
        <root level="warn">
        <appender-ref ref="Elasticsearch"/>
    </root>
    <logger name="com.bupa.schedulerservice" level="info" />
        <logger name="org.apache" level="info" />
        <logger name="org.springframework" level="info" />
    </loggers>

Here is my indexTemplate-local.json.

    {
        "index_patterns": [
            "spring-app-scheduler-local-*"
    ],
        "template": {
            "mappings": {
            "properties": {
            "@timestamp": {
                "type": "date",
            "format": "epoch_millis"
            }
        }
            }
        }
    }

CustomLogEventMixIn.class is exactly same as you provided in your project. Same for ExamplejacksonModule.

Here how I am logging into my SpringBoot Application.

    @SpringBootApplication
    @ConfigurationPropertiesScan
    public class AppSchedulerServiceApplication {

        private static final Logger LOGGER = LogManager.getLogger();

    public static void main(String[] args) {
        SpringApplication.run(AppSchedulerServiceApplication.class, args);
        LOGGER.info("Starting application");
    }
    }

Similarly in other places.

@Repository
public class MyRepositoryImpl implements MyRepository {
    private static final Logger LOGGER = LogManager.getLogger();
    ....
    private Map<String, Object> callStoredProcedure(String storedProcedureName, Map<String, Object> inputParameters) {

        SqlParameterSource spInputParameter = new MapSqlParameterSource(inputParameters);

        simpleJdbcCall = new SimpleJdbcCall(nphiesJdbcTemplate)
                .withProcedureName(storedProcedureName);

        try {
            LOGGER.info("Calling Stored Procedure: {}", storedProcedureName);
            Map<String, Object> result = simpleJdbcCall.execute(spInputParameter);
            LOGGER.info("Stored Procedure: {} called successfully", storedProcedureName);
            return result;
        } catch (Exception e) {
            LOGGER.error("Error in calling Stored Procedure: {}", storedProcedureName, e);
            throw new RuntimeException(e);
        }
    }
}

Thanks & Regards Basit Mahmood Ahmed

It looks like there is a lot to fix in your code. Also, a few crucially important distinctions between solutions I suggested are worth noting.

Let's start with fixes:

Status logger level WARN will ignore any INFO level logggin done by this project. You'll not be able to see what exactly is going on during the startup and the log I mentioned earlier will not be visible. For development, please change this:
```
<configuration xmlns:xi="http://www.w3.org/2001/XInclude" status="WARN">
```
to this:
```
<configuration xmlns:xi="http://www.w3.org/2001/XInclude" status="INFO">
```
Root logger level will also filter out anything that you're trying to log. I suggest one of 2 solutions: changing it to info (<root level="warn"> to <root level="info">) or using <logger name="com.bupa.schedulerservice" level="info" /> correctly:
```
private static final Logger LOGGER = LogManager.getLogger(MyRepository.class);
```
and
```
<root level="warn">
<appender-ref ref="Console" />
</root>
<logger name="com.bupa.schedulerservice" level="info">
<appender-ref ref="Elasticsearch"/>
</logger>
```
Again, this line has no effect at all:
```
JsonMapper.builder().disable(SerializationFeature.WRITE_DATES_AS_TIMESTAMPS);
```
You probably want to apply it to the parameter of the applyTo method (incoming objectMapper):
```
objectMapper.builder().disable(SerializationFeature.WRITE_DATES_AS_TIMESTAMPS);
```
but even then, it will not be utilized at all, since this plugin does not operate on Java dates
JavaTimeModule makes no sense with this project. There are no instances of java.time classes that would be serialized by the object mapper that you're configuring, so this line is also obsolete
```
objectMapper.registerModule(new JavaTimeModule());
```

If you'd like a proof that the module is actually configured, please run the example from the branch I shared:

[localhost log4j2-elasticsearch-hc-springboot]$ mvn clean install && java -Dlog4j.configurationFile=log4j2.xml -jar target/log4j2-elasticsearch-hc-springboot-0.0.1-SNAPSHOT.jar

followed by

curl -XPOST -H "Content-Type: application/json" -d "{}" http://localhost:9200/log4j2*/_search | jq

Result will contain a document similar to this one:

{
"_index": "log4j2-elasticsearch-hc-springboot-2023-12-11-13",
"_id": "bZn8WIwBhVDBhcpN8GtF",
"_score": 1.0,
"_source": {
    "@timestamp": "2023-12-11T12:47:00.234",
    "loggerName": "com.github.rfoltyns.Application",
    "level": "INFO",
    "message": "Hello, World!",
    "thread": "main",
    "hostname": "undefined",
    "ctxVariable": "ea462834-f078-493f-8472-096a11938e3b"
}
}

Also, plase uncomment ExampleJacksonModulePlugin:28:

getLogger().info("{} applied", getClass().getSimpleName());

With status logger at INFO level, it will give you a definite proof that the code in your plugin was applied:

main INFO ExampleJacksonModulePlugin applied

I copied your code as-is and it worked out-of-the-box, but the changes that you're making to the mapper make no difference (again, no java.time and no dates serialized anywhere anyway, because Log4j2 has it's own MutableInstant class)

=======================================================

Now, let's move to distinctions between long and formatted dates:

The way you use index template at the moment suggests that you're not after formatted date. This section:
```
"@timestamp": {
"type": "date",
"format": "epoch_millis"
}
```
will tell the ES node that incoming @timestamp field is long. That's not how the example I provded in the branch works. In the example, LogEvent.getInstant() is serialized atm (assuming that the MixIn class is exactly the same) and LogEvent.timeMillis (the default way used in this project) is ignore. In order for this template to make any sense, you need an output that will result in documents similar to this:
```
{
"_index": "log4j2-elasticsearch-hc-springboot-2023-12-11-13",
"_id": "bpkFWYwBhVDBhcpNJ2sp",
"_score": 1.0,
"_source": {
"@timestamp": 1702296901475,
"loggerName": "elasticsearch",
"level": "INFO",
"message": "Hello, World!",
"thread": "main",
"hostname": "undefined",
"ctxVariable": "notSupportedWithAsyncLogger"
}
}
```

If you'd like to use this index template, just rename timeMillis to @timestamp and use long. If you'd like to have a formatted date, see point 2. below - a completely separate solution.

In order to get a formatted date like this:
```
"@timestamp": "2023-12-11T12:15:00.475",
```
don't use the index template, use the example I provided before as-is and carefully port it over to your project.

I suggest a cycle similar to following:

mvn clean install
java -Dlog4j.configurationFile=log4j2.xml -jar target/log4j2-elasticsearch-hc-springboot-0.0.1-SNAPSHOT.jar
curl -XPOST -H "Content-Type: application/json" -d "{}" http://localhost:9200/log4j2*/_search | jq

check the result and delete the index:

curl -XDELETE http://localhost:9200/log4j2*

change or break the example from the branch and repeat. Once you're happy with the result, port it over to your project.

If you have more issues, please also post a log from your application.

I hope it helps

@rfoltyns Thanks for your valuable suggestions. Let's start. I have only this following dependency in my project.

I have local profile activated. This is my log4j2-spring-local.xml file. I followed your suggestions regarding changing the warn to info. At this stage I am not applying JacksonModulePlugin. It is not loading still, but I will put the logs in the end regarding the error.

`
<?xml version="1.0" encoding="UTF-8"?><!DOCTYPE xml>
<configuration xmlns:xi="http://www.w3.org/2001/XInclude" status="info">

<Properties>
    <Property name="filename">./logs/${spring:spring.application.name}.log</Property>
</Properties>

<appenders>

    <Console name="Console" target="SYSTEM_OUT">
        <PatternLayout pattern="%d{yyyy-MM-dd HH:mm:ss.SSS} [%t] %-5level %logger{36} - %msg%n"/>
    </Console>

    <RollingFile name="RollingFile" fileName="${filename}" filePattern="${filename}-%d{yyyy-MM-dd}-%i.log">
        <PatternLayout>
                <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%t] %X{id} %X{username} %-5level %c{36} %l: %msg%n</pattern>
        </PatternLayout>
        <Policies>
            <SizeBasedTriggeringPolicy size="10 MB" />
        </Policies>
        <DefaultRolloverStrategy min="1" max="4" />
    </RollingFile>

    <Elasticsearch name="Elasticsearch">
       <IndexName indexName="spring-app-scheduler-local-index"/>
       <JacksonJsonLayout>
           <JacksonMixIn mixInClass="pk.training.basit.Log4j2ElasticSearch.json.CustomLogEventMixIn"
                          targetClass="org.apache.logging.log4j.core.LogEvent"/>
               <PooledItemSourceFactory poolName="itemPool" itemSizeInBytes="1024" initialPoolSize="6000"/>
       </JacksonJsonLayout>
       <AsyncBatchDelivery batchSize="1000" deliveryInterval="10000" >
           <IndexTemplate name="spring-app-scheduler-local-index-template" path="classpath:indexTemplate-local.json" apiVersion="7" />
            <HCHttp serverUris="https://url">
                <PooledItemSourceFactory poolName="batchPool" itemSizeInBytes="1024000" initialPoolSize="3"/>
                <Security>
                    <BasicCredentials username="name" password="password" />
                </Security>
            </HCHttp>
        </AsyncBatchDelivery>
    </Elasticsearch>

</appenders>

    <loggers>
    <root level="info">
        <appender-ref ref="Console" />
        <appender-ref ref="RollingFile" />
        <appender-ref ref="Elasticsearch"/> 
    </root>
    <logger name="pk.training.basit.Log4j2ElasticSearch" level="info" />
        <logger name="org.apache" level="info" />
        <logger name="org.springframework" level="info" />
        <logger name="org.springframework.jdbc" level="trace" />
    </loggers>
</configuration>

My indexTemplate-local.json contains the following. It is exactly same as you provided in the example.

Here is the CustomEventLogMixinClass

Now when I run the application. On ELK I got this. Note that I am getting @timestamp filed which is yyyy-MM-ddTHH:mm:ss format.

This was exactly what I wanted. Before you posted your example, I was only getting timemillis in long. Infact I tried this getInstant(). But it's return type is log4j.core..time.Instant instead of Java.Time. At that stage I was getting long for this field too on ELK. But with the serialization this filed is now date instead of long with the correct date format. With this now if I create Index Pattern in KIbana. I can choose the timestamp field.

Previously there was no time filed when I was trying. OfCourse, I didn't know how to do that. There were just long on ELK. So far so good. At this point I want your valuable suggestions regarding the settings. In your example you are explicitly getting the logger using

` Logger logger = LogManager.getLogger("elasticsearch"); `

But in my case, I am just getting it

` Logger logger = LogManager.getLogger();`

or Logger logger = LogManager.getLogger(className);

Actually, I don't want to use particular logger. I want that in code I just use Logger logger = LogManager.getLogger(); and in the log4j2 file if there are multiple appenders. It automatically goes to those appenders. Which is happening right now. I am logging console, file and elasticsearch.

On UAT or prod maybe I just log to elk or elk and file both. Anyways. Regarding UAT or production what settings will you suggest for log4j2. Right now it is same as local but only logging to elk..

Do I also use info here in Configuration or warn is fine for UAT ?

What settings will you suggest for efficient logging. In your example you are using many configurations. I know this configuration depends on your need. But if you suggest like at least use these configurations for efficient logging.

In your example you are using AsyncLogger. But I am using logger. Do I change my logger to AsyncLogger for UAT and prod ? Or any other suggestion that you think it would be useful for me.

<configuration xmlns:xi="http://www.w3.org/2001/XInclude" status="WARN">
    <Console name="Console" target="SYSTEM_OUT">
        <PatternLayout pattern="%d{yyyy-MM-dd HH:mm:ss.SSS} [%t] %-5level %logger{36} - %msg%n"/>
    </Console>
    <RollingFile name="RollingFile" fileName="${filename}" filePattern="${filename}-%d{yyyy-MM-dd}-%i.log">
        ....
    </RollingFile>
    <Elasticsearch name="Elasticsearch">
        ....
    </Elasticsearch>
    <loggers>
            <root level="info">
            <appender-ref ref="Elasticsearch"/> 
        </root>
        <logger name="com.bupa.schedulerservice" level="info" />
            <logger name="org.apache" level="info" />
            <logger name="org.springframework" level="info" />
            <logger name="org.springframework.jdbc" level="trace" />
    </loggers>
</configuration>

Now come to ExampleJacksonModulePlugin. When I was trying to get the date field in elk that time I tried this. Intensions you know now. May be I don't need it now but I am curious why it is not applying. Here are the logs.

Thanks & Regards Basit Mahmood Ahmed

Wow! Eclipse! I haven't used it since 2016 :)

I finally reproduced the issue you're experiencing.

In order for Log4j2 to be able to use your plugin, it needs to be declared in this file:

META-INF/org/apache/logging/log4j/core/config/plugins/Log4j2Plugins.dat

This file is generated by org.apache.logging.log4j.core.config.plugins.processor.PluginProcessor. It simply scans your files for @Plugin annotations and adds it to the dat file. I think that Maven invokes this processor by default during the build process. Eclipse does not (I use IntelliJ that has this processor invoked by default, so I couldn't reproduce it before)

In order to force Eclipse to do so, you need to:

Enable annotation processing. Configure it in project properties: Right-click on you project -> Select 'Properties' -> Java Compiler -> Annotation Processing -> Check 'Enable Annotation Processing'

enable-annotation-processing

I have no idea whether the 'Generated directories' make any difference here.

Once processing is enabled, go to 'Annotation Processing' -> 'Factory Path' and 'Add External JAR' that contains org.apache.logging.log4j.core.config.plugins.processor.PluginProcessor - log4j2-core.jar. You need to locate in your local Maven repo

==========================================

Now, back to timestamps.

You're almost there. Your MixIn kicks in correctly and you have a @timestamp field in your JSON output, but now your index template is obsolete. Think of an index template as a way to tell ES node "Here's how you should interpret my JSON, Dear Elasticsearch Node". Elasticsearch "understands" @timestamp field with datetime string by default, so you don't need indexTemplate-local.json at all.

By default, this project uses LogEvent.getTimeMillis(), therefore, in order to see the timeMillis column as the date column in Kibana, you need to:

Use indexTemplate-local.json
Don't use CustomLogEventMixIn

But, given that you'd like to have a datetime string instead:

Delete indexTemplate-local.json
Use CustomLogEventMixIn

==========================================

As for logging level recommendation in your UAT environment - it depends whether you'd like to have visibility of any logging that this project does or not. I can't make that decision for you :)

Root loggers? Ok, you know what you need best :)

Loggers vs AsyncLoggers - that solely depends on your needs. If you like your log to be actually written to a file before you continue with your code, use Logger. If you want just fire-and-forget style logging, use AsyncLogger. Each one has it's trade-offs - it's up to you to decide.

As for settings for efficient logging - it depends on the actual number of logs per second you anticipate. I can only recommend using buffer pools (PooledImteSourceFactory), but sizing depends on:

delivery interval
batch size
log size
number of concurrent batches you'd like to support
read timeout to name just a few.

There is no single, works-for-everyone configuration. For example, if you produce 100 logs per minute, you can:

1 batch of 100 logs every minute
10 batches of 10 logs every 6 seconds
whatever other conbination

Which one is better for you? I don't know. Pool sizing, batch sizing, delivery interval and http client timeout are only for you to decide (once heavily tested)

Other, advanced optimizations are disabled by default. You should use each one of them after careful considerations. Most of them are not really that useful until you start sending hundreds of thousands of logs per second.

rfoltyns / log4j2-elasticsearch

IS JacksonModule is implemented in latest version? #94

=======================================================