Performance Issue on using pax-logging 1.11.3 with log4j2 async logging.

[tharindu1st]

Hi All, When we use pax-logging 1.11.3 with async logging we see the high latency introduced in the following stack trace due to push log events into the OSGi service. Is there any configuration available to stop this service as I go through the code will not able to find any configuration.

org.eclipse.equinox.internal.event.EventHandlerTracker.getHandlers() (line: 162)
org.eclipse.equinox.internal.event.EventAdminImpl.dispatchEvent() (line: 110)
org.eclipse.equinox.internal.event.EventAdminImpl.postEvent() (line: 70)
org.eclipse.equinox.internal.event.EventComponent.postEvent() (line: 39)
org.ops4j.pax.logging.spi.support.EventAdminTracker.deliver() (line: 102)
org.ops4j.pax.logging.spi.support.EventAdminTracker.postEvent() (line: 64)
org.ops4j.pax.logging.log4j2.internal.PaxLoggingServiceImpl.handleEvents() (line: 322)
org.ops4j.pax.logging.log4j2.internal.PaxLoggerImpl.doLog0() (line: 358)
org.ops4j.pax.logging.log4j2.internal.PaxLoggerImpl.doLog() (line: 337)
org.ops4j.pax.logging.log4j2.internal.PaxLoggerImpl.inform() (line: 149)
org.ops4j.pax.logging.internal.TrackingLogger.inform() (line: 120)
org.ops4j.pax.logging.jcl.JclLogger.info() (line: 108)
org.apache.synapse.mediators.MediatorLog.traceOrDebug() (line: 82)
org.apache.synapse.mediators.AbstractListMediator.buildMessage() (line: 150)
org.apache.synapse.mediators.AbstractListMediator.mediate() (line: 95)
org.apache.synapse.mediators.AbstractListMediator.mediate() (line: 71)
org.apache.synapse.mediators.base.SequenceMediator.mediate() (line: 158)
org.wso2.carbon.apimgt.gateway.handlers.ext.APIManagerExtensionHandler.mediate_aroundBody0() (line: 73)
org.wso2.carbon.apimgt.gateway.handlers.ext.APIManagerExtensionHandler.mediate() (line: 58)
org.wso2.carbon.apimgt.gateway.handlers.ext.APIManagerExtensionHandler.handleRequest_aroundBody2() (line: 90)
org.wso2.carbon.apimgt.gateway.handlers.ext.APIManagerExtensionHandler.handleRequest() (line: 79)
org.apache.synapse.rest.API.process() (line: 368)
org.apache.synapse.rest.RESTRequestHandler.apiProcessNonDefaultStrategy() (line: 149)

[grgrzybek]

Good point and thanks for the report! I was thinking about disabling EventAdmin, but initially I wanted to focus on specification compliance. I'll check tomorrow!

[grgrzybek]

OK @tharindu1st I've checked the problem and I've added one configuration option:

org.ops4j.pax.logging.eventAdminEnabled

If you set it as either system (Karaf: etc/system.properties) or bundle context (Karaf: etc/config.properties) property with value false, Event admin will be skipped ENTIRELY.

This has to stay as defaulted to true (even if you omit the option entirely) for spec compliance...

I see you're using 1.11.x, so I'll fix this in 4 branches: 1.11.x, 1.12.x, 2.0.x, 2.1.x.

[tharindu1st]

Hi @grgrzybek , Thanks for your prompt reply, We will be waiting for the fix in 1.11.x range release.

[grgrzybek]

@tharindu1st 1.11.15 should be available in Maven Central soon. I'll send an announcement email tomorrow.

[tharikaGitHub]

Hi @grgrzybek we applied the pax-logging 1.11.15 jar and configured the property org.ops4j.pax.logging.eventAdminEnabled as false in our pax-logging.properties file. But seems still the line in [1] is executed causing the originally reported performance issue due to push events. Seems the configuration is not properly applied. Do you have any idea on what might be causing the issue? Or should we fix this?

[1] https://github.com/ops4j/org.ops4j.pax.logging/blob/logging-1.11.15/pax-logging-log4j2/src/main/java/org/ops4j/pax/logging/log4j2/internal/PaxLoggingServiceImpl.java#L345

[grgrzybek]

Indeed, this line is invoked, but the instance assigned to m_eventAdmin is a no-op implementation. Please check, because I tried to make sure (debugger) that it indeed works.