[2.1.x] Performance bottleneck with org.osgi.service.log.LogReaderService

[AshenShalitha]

Hi team,

Recently we encountered a performance issue associated with pax-logging 1.11.3 and raised through [1]. This issue was resolved by introducing a new system parameter org.ops4j.pax.logging.eventAdminEnabled. However, in our latest test runs with pax-logging 1.11.15, we could observe that the performance bottleneck is not completely resolved yet and moved to a subsequent line. Please refer to the following stack trace. Is there any configuration to avoid this as well? Please advise.

org.ops4j.pax.logging.spi.support.LogReaderServiceImpl.fireEvent(org.osgi.service.log.LogEntry)
org.ops4j.pax.logging.log4j2.internal.PaxLoggingServiceImpl.handleEvents(org.osgi.framework.Bundle, org.osgi.framework.ServiceReference, int, java.lang.String, java.lang.Throwable)
org.ops4j.pax.logging.log4j2.internal.PaxLoggerImpl.doLog0(org.apache.logging.log4j.Marker, org.apache.logging.log4j.Level, int, java.lang.String, java.lang.String, java.lang.Throwable)
org.ops4j.pax.logging.log4j2.internal.PaxLoggerImpl.doLog(org.apache.logging.log4j.Marker, org.apache.logging.log4j.Level, int, java.lang.String, java.lang.String, java.lang.Throwable)
org.ops4j.pax.logging.log4j2.internal.PaxLoggerImpl.inform(java.lang.String, java.lang.Throwable)
org.ops4j.pax.logging.internal.TrackingLogger.inform(java.lang.String, java.lang.Throwable)
org.ops4j.pax.logging.jcl.JclLogger.info(java.lang.Object)
org.apache.synapse.mediators.MediatorLog.traceOrDebug(java.lang.Object)
org.apache.synapse.mediators.base.SequenceMediator.mediate(org.apache.synapse.MessageContext)
org.wso2.carbon.apimgt.gateway.handlers.ext.APIManagerExtensionHandler.mediate_aroundBody0(org.wso2.carbon.apimgt.gateway.handlers.ext.APIManagerExtensionHandler, org.apache.synapse.MessageContext, java.lang.String, org.aspectj.lang.JoinPoint)
org.wso2.carbon.apimgt.gateway.handlers.ext.APIManagerExtensionHandler.mediate(org.apache.synapse.MessageContext, java.lang.String)
org.wso2.carbon.apimgt.gateway.handlers.ext.APIManagerExtensionHandler.handleRequest_aroundBody2(org.wso2.carbon.apimgt.gateway.handlers.ext.APIManagerExtensionHandler, org.apache.synapse.MessageContext, org.aspectj.lang.JoinPoint)
org.wso2.carbon.apimgt.gateway.handlers.ext.APIManagerExtensionHandler.handleRequest(org.apache.synapse.MessageContext)
org.apache.synapse.rest.API.process(org.apache.synapse.MessageContext)
org.apache.synapse.rest.RESTRequestHandler.apiProcessNonDefaultStrategy(org.apache.synapse.MessageContext, org.apache.synapse.rest.API)
org.apache.synapse.rest.RESTRequestHandler.dispatchToAPI(org.apache.synapse.MessageContext)
org.apache.synapse.rest.RESTRequestHandler.process(org.apache.synapse.MessageContext)
org.apache.synapse.core.axis2.Axis2SynapseEnvironment.injectMessage(org.apache.synapse.MessageContext)
org.apache.synapse.core.axis2.SynapseMessageReceiver.receive(org.apache.axis2.context.MessageContext)
org.apache.axis2.engine.AxisEngine.receive(org.apache.axis2.context.MessageContext)
org.apache.synapse.transport.passthru.ServerWorker.processNonEntityEnclosingRESTHandler(org.apache.axiom.soap.SOAPEnvelope, org.apache.axis2.context.MessageContext, boolean)
org.apache.synapse.transport.passthru.ServerWorker.run()
org.apache.axis2.transport.base.threads.NativeWorkerPool$1.run()
java.util.concurrent.ThreadPoolExecutor.runWorker(java.util.concurrent.ThreadPoolExecutor$Worker)
java.util.concurrent.ThreadPoolExecutor$Worker.run()
java.lang.Thread.run()

[1] https://github.com/ops4j/org.ops4j.pax.logging/issues/480

[grgrzybek]

Hmm, again this is mandatory implementation of org.osgi.service.log.LogReaderService... Events are collected inside ... synchronized LinkedList, so I can imagine it's not very optimal (even if access to actual appender is also synchronized - depending on the appender of course).

I think you give me no choice (thanks! :)) but to introduce yet another flag...

[grgrzybek]

By the way, I'm going to simply set null as the service instead of no-op interface implementation - just to save few CPU cycles ;)

[tharindu1st]

@grgrzybek Can we get this fix port into 1.11.x version and get a release.

[grgrzybek]

Hi @tharindu1st, for 1.11.x it's fixed in #493 and released already in 1.11.16 ;)