Filters and Async Appender
Hi All,
There is a library micrometer(https://micrometer.io/) used to collect metrics,
one of these metrics is a log rate, several calls for log.info, log.debug,
log.warn, etc.
Micrometer implements a
Filter(org.apache.logging.log4j.core.filter.AbstractFilter) and for each call
to the method filter we increment a counter.
After some research, I noticed that the method filter can be called multiple
times especially when an Async appender is configured and in this case, we have
a wrong logging rate. An application called on time the method
log.info("Test..") but the rate can easily be 2 instead of 1.
I tried to implement a solution but still not correct.
Now I am wondering if Filter still feasible for this use case, I am quite
convinced that will be not possible to use Filter to solve this.
So, now my question is: Is there another way to get the number calls for each
logging level? Or is there a workaround that can be implemented on the Filter
implementation to do the correct count?
Regards,
Dennys Fredericci
Re: Filters and Async Appender
A Global Filter can be called once during the isEnabled check and then again
when the event is actually logged. But Filters that are attached to Loggers,
Appender-Refs and Appenders should only be called once. I am not sure why
thought would be any different with an Async appender.
Ralph
> On Aug 4, 2020, at 12:55 PM, Dennys Fredericci
> wrote:
>
> Hi All,
>
> There is a library micrometer(https://micrometer.io/) used to collect
> metrics, one of these metrics is a log rate, several calls for log.info,
> log.debug, log.warn, etc.
>
> Micrometer implements a
> Filter(org.apache.logging.log4j.core.filter.AbstractFilter) and for each call
> to the method filter we increment a counter.
>
> After some research, I noticed that the method filter can be called multiple
> times especially when an Async appender is configured and in this case, we
> have a wrong logging rate. An application called on time the method
> log.info("Test..") but the rate can easily be 2 instead of 1.
>
> I tried to implement a solution but still not correct.
>
> Now I am wondering if Filter still feasible for this use case, I am quite
> convinced that will be not possible to use Filter to solve this.
>
> So, now my question is: Is there another way to get the number calls for
> each logging level? Or is there a workaround that can be implemented on the
> Filter implementation to do the correct count?
>
> Regards,
> Dennys Fredericci
>
>
>
Re: Filters and Async Appender
Hi Ralph,
First, thank you for your quick answer! :)
I just wrote a simple project to show you this behavior I am adding 2 filters
one should be global(at least I think) and other to the logger.
Project: https://github.com/dennysfredericci/log4j2-filter-spike
Main class:
https://github.com/dennysfredericci/log4j2-filter-spike/blob/master/src/main/java/br/com/fredericci/Main.java
The output will be:
Global Filter: 0
Logger Filter: 3
For some reason, the filter on the logger was called 3 times and the global
filter was never called.
Is there any mistake on how I am adding the global filter? Why it is not
working?
If a global filter is called just once will be perfect for my use case.
Thank you!
Regards,
Dennys Fredericci
On 2020/08/04 21:18:57, Ralph Goers wrote:
> A Global Filter can be called once during the isEnabled check and then again
> when the event is actually logged. But Filters that are attached to Loggers,
> Appender-Refs and Appenders should only be called once. I am not sure why
> thought would be any different with an Async appender.
>
> Ralph
>
>
>
> > On Aug 4, 2020, at 12:55 PM, Dennys Fredericci
> > wrote:
> >
> > Hi All,
> >
> > There is a library micrometer(https://micrometer.io/) used to collect
> > metrics, one of these metrics is a log rate, several calls for log.info,
> > log.debug, log.warn, etc.
> >
> > Micrometer implements a
> > Filter(org.apache.logging.log4j.core.filter.AbstractFilter) and for each
> > call to the method filter we increment a counter.
> >
> > After some research, I noticed that the method filter can be called
> > multiple times especially when an Async appender is configured and in this
> > case, we have a wrong logging rate. An application called on time the
> > method log.info("Test..") but the rate can easily be 2 instead of 1.
> >
> > I tried to implement a solution but still not correct.
> >
> > Now I am wondering if Filter still feasible for this use case, I am quite
> > convinced that will be not possible to use Filter to solve this.
> >
> > So, now my question is: Is there another way to get the number calls for
> > each logging level? Or is there a workaround that can be implemented on the
> > Filter implementation to do the correct count?
> >
> > Regards,
> > Dennys Fredericci
> >
> >
> >
>
>
>
Re: Filters and Async Appender
Hi Ralph,
I just noticed that I misread your email, so a global filter can be called
twice and filters attached to Loggers, Appender-Refs and Appenders should only
be called once. In that case i must use filters attached to loggers,
I changed the code to call the Configurator.reconfigure(config) and after that,
I have just one call to filters which are attached to Loggers but i also got
the error below:
2020-08-11 22:10:16,572 main ERROR Could not register mbeans
java.lang.NullPointerException
at
org.apache.logging.log4j.core.async.AsyncLoggerConfigDisruptor.createRingBufferAdmin(AsyncLoggerConfigDisruptor.java:417)
at
org.apache.logging.log4j.core.async.AsyncLoggerConfig.createRingBufferAdmin(AsyncLoggerConfig.java:199)
at
org.apache.logging.log4j.core.jmx.Server.registerLoggerConfigs(Server.java:366)
at
org.apache.logging.log4j.core.jmx.Server.reregisterMBeansAfterReconfigure(Server.java:186)
at
org.apache.logging.log4j.core.jmx.Server.reregisterMBeansAfterReconfigure(Server.java:141)
at
org.apache.logging.log4j.core.LoggerContext.setConfiguration(LoggerContext.java:629)
at
org.apache.logging.log4j.core.LoggerContext.reconfigure(LoggerContext.java:712)
at
org.apache.logging.log4j.core.config.Configurator.reconfigure(Configurator.java:239)
Any idea why I got it?
Here you can see the code which throws this Exception:
https://github.com/dennysfredericci/log4j2-filter-spike/blob/master/src/main/java/br/com/fredericci/Main.java
Thank you! :)
On 2020/08/04 21:18:57, Ralph Goers wrote:
> A Global Filter can be called once during the isEnabled check and then again
> when the event is actually logged. But Filters that are attached to Loggers,
> Appender-Refs and Appenders should only be called once. I am not sure why
> thought would be any different with an Async appender.
>
> Ralph
>
>
>
> > On Aug 4, 2020, at 12:55 PM, Dennys Fredericci
> > wrote:
> >
> > Hi All,
> >
> > There is a library micrometer(https://micrometer.io/) used to collect
> > metrics, one of these metrics is a log rate, several calls for log.info,
> > log.debug, log.warn, etc.
> >
> > Micrometer implements a
> > Filter(org.apache.logging.log4j.core.filter.AbstractFilter) and for each
> > call to the method filter we increment a counter.
> >
> > After some research, I noticed that the method filter can be called
> > multiple times especially when an Async appender is configured and in this
> > case, we have a wrong logging rate. An application called on time the
> > method log.info("Test..") but the rate can easily be 2 instead of 1.
> >
> > I tried to implement a solution but still not correct.
> >
> > Now I am wondering if Filter still feasible for this use case, I am quite
> > convinced that will be not possible to use Filter to solve this.
> >
> > So, now my question is: Is there another way to get the number calls for
> > each logging level? Or is there a workaround that can be implemented on the
> > Filter implementation to do the correct count?
> >
> > Regards,
> > Dennys Fredericci
> >
> >
> >
>
>
>
