Hello
Could somebody please explain if it's ok when statusListener.start method is invoked twice? I.e. can it be bug rather than feature?
As far as I understand it's getting invoked from LogerFactory.bind method:
private final static void bind() {
...
Set<URL> staticLoggerBinderPathSet = null;
// skip check under android, see also http://jira.qos.ch/browse/SLF4J-328
if (!isAndroid()) {
staticLoggerBinderPathSet = findPossibleStaticLoggerBinderPathSet();
reportMultipleBindingAmbiguity(staticLoggerBinderPathSet);
}
// the next line does the binding
StaticLoggerBinder.getSingleton(); <---fist from here
INITIALIZATION_STATE = SUCCESSFUL_INITIALIZATION;
reportActualBinding(staticLoggerBinderPathSet);
replayEvents(); <---then from here
...}
The stacktraces:
Connected to the target VM, address: 'localhost:7778', transport: 'socket'
at my.app.LogListener.start(PECQuartzListener.java:41)
at ch.qos.logback.core.joran.action.StatusListenerAction.end(StatusListenerAction.java:65)
at ch.qos.logback.core.joran.spi.Interpreter.callEndAction(Interpreter.java:309)
at ch.qos.logback.core.joran.spi.Interpreter.endElement(Interpreter.java:193)
at ch.qos.logback.core.joran.spi.Interpreter.endElement(Interpreter.java:179)
at ch.qos.logback.core.joran.spi.EventPlayer.play(EventPlayer.java:62)
at ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:155)
at ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:142)
at ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:103)
at ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:53)
at ch.qos.logback.classic.util.ContextInitializer.configureByResource(ContextInitializer.java:75)
at ch.qos.logback.classic.util.ContextInitializer.autoConfig(ContextInitializer.java:150)
at org.slf4j.impl.StaticLoggerBinder.init(StaticLoggerBinder.java:84)
at org.slf4j.impl.StaticLoggerBinder.<clinit>(StaticLoggerBinder.java:55)
at org.slf4j.LoggerFactory.bind(LoggerFactory.java:149) <=================================
at org.slf4j.LoggerFactory.performInitialization(LoggerFactory.java:124)
at org.slf4j.LoggerFactory.getILoggerFactory(LoggerFactory.java:390)
at org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:340)
at org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:361)
at my.app.AuthorisationListener.<init>(AuthorisationListener.java:34)
at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
at java.lang.reflect.Constructor.newInstance(Constructor.java:422)
at com.ibm.ws.managedobject.internal.ManagedObjectFactoryImpl.createManagedObject(ManagedObjectFactoryImpl.java:65)
at com.ibm.ws.webcontainer.osgi.webapp.WebApp.inject(WebApp.java:1250)
at com.ibm.ws.webcontainer.osgi.webapp.WebApp.injectAndPostConstruct(WebApp.java:1416)
at com.ibm.ws.webcontainer.osgi.webapp.WebApp.injectAndPostConstruct(WebApp.java:1404)
at com.ibm.ws.webcontainer.osgi.webapp.WebApp.loadListener(WebApp.java:813)
at com.ibm.ws.webcontainer.webapp.WebApp.loadLifecycleListeners(WebApp.java:2246)
at com.ibm.ws.webcontainer.webapp.WebApp.initialize(WebApp.java:1040)
at com.ibm.ws.webcontainer.webapp.WebApp.initialize(WebApp.java:6463)
at com.ibm.ws.webcontainer.osgi.DynamicVirtualHost.startWebApp(DynamicVirtualHost.java:446)
at com.ibm.ws.webcontainer.osgi.DynamicVirtualHost.startWebApplication(DynamicVirtualHost.java:441)
at com.ibm.ws.webcontainer.osgi.WebContainer.startWebApplication(WebContainer.java:1000)
at com.ibm.ws.webcontainer.osgi.WebContainer.startModule(WebContainer.java:824)
at com.ibm.ws.app.manager.web.internal.WebModuleHandlerImpl.deployModule(WebModuleHandlerImpl.java:103)
at com.ibm.ws.app.manager.module.internal.DeployedAppInfoBase.deployModule(DeployedAppInfoBase.java:871)
at com.ibm.ws.app.manager.module.internal.DeployedAppInfoBase.deployModules(DeployedAppInfoBase.java:831)
at com.ibm.ws.app.manager.module.internal.DeployedAppInfoBase.deployApp(DeployedAppInfoBase.java:818)
at com.ibm.ws.app.manager.ear.internal.EARApplicationHandlerImpl.install(EARApplicationHandlerImpl.java:84)
at com.ibm.ws.app.manager.internal.statemachine.StartAction.execute(StartAction.java:141)
at com.ibm.ws.app.manager.internal.statemachine.ApplicationStateMachineImpl.enterState(ApplicationStateMachineImpl.java:1192)
at com.ibm.ws.app.manager.internal.statemachine.ApplicationStateMachineImpl.run(ApplicationStateMachineImpl.java:805)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
java.lang.Exception
at my.app.LogListener.start(PECQuartzListener.java:41)
at ch.qos.logback.core.joran.action.StatusListenerAction.end(StatusListenerAction.java:65)
at ch.qos.logback.core.joran.spi.Interpreter.callEndAction(Interpreter.java:309)
at ch.qos.logback.core.joran.spi.Interpreter.endElement(Interpreter.java:193)
at ch.qos.logback.core.joran.spi.Interpreter.endElement(Interpreter.java:179)
at ch.qos.logback.core.joran.spi.EventPlayer.play(EventPlayer.java:62)
at ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:155)
at ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:142)
at ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:103)
at ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:53)
at ch.qos.logback.classic.util.ContextInitializer.configureByResource(ContextInitializer.java:75)
at ch.qos.logback.classic.util.ContextInitializer.autoConfig(ContextInitializer.java:150)
at ch.qos.logback.classic.selector.ContextJNDISelector.getLoggerContext(ContextJNDISelector.java:108)
at org.slf4j.impl.StaticLoggerBinder.getLoggerFactory(StaticLoggerBinder.java:108)
at org.slf4j.LoggerFactory.getILoggerFactory(LoggerFactory.java:396)
at org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:340)
at org.slf4j.LoggerFactory.replaySingleEvent(LoggerFactory.java:220)
at org.slf4j.LoggerFactory.replayEvents(LoggerFactory.java:195)
at org.slf4j.LoggerFactory.bind(LoggerFactory.java:152) <=================================
at org.slf4j.LoggerFactory.performInitialization(LoggerFactory.java:124)
at org.slf4j.LoggerFactory.getILoggerFactory(LoggerFactory.java:390)
at org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:340)
at org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:361)
at my.app.AuthorisationListener.<init>(AuthorisationListener.java:34)
at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
at java.lang.reflect.Constructor.newInstance(Constructor.java:422)
at com.ibm.ws.managedobject.internal.ManagedObjectFactoryImpl.createManagedObject(ManagedObjectFactoryImpl.java:65)
at com.ibm.ws.webcontainer.osgi.webapp.WebApp.inject(WebApp.java:1250)
at com.ibm.ws.webcontainer.osgi.webapp.WebApp.injectAndPostConstruct(WebApp.java:1416)
at com.ibm.ws.webcontainer.osgi.webapp.WebApp.injectAndPostConstruct(WebApp.java:1404)
at com.ibm.ws.webcontainer.osgi.webapp.WebApp.loadListener(WebApp.java:813)
at com.ibm.ws.webcontainer.webapp.WebApp.loadLifecycleListeners(WebApp.java:2246)
at com.ibm.ws.webcontainer.webapp.WebApp.initialize(WebApp.java:1040)
at com.ibm.ws.webcontainer.webapp.WebApp.initialize(WebApp.java:6463)
at com.ibm.ws.webcontainer.osgi.DynamicVirtualHost.startWebApp(DynamicVirtualHost.java:446)
at com.ibm.ws.webcontainer.osgi.DynamicVirtualHost.startWebApplication(DynamicVirtualHost.java:441)
at com.ibm.ws.webcontainer.osgi.WebContainer.startWebApplication(WebContainer.java:1000)
at com.ibm.ws.webcontainer.osgi.WebContainer.startModule(WebContainer.java:824)
at com.ibm.ws.app.manager.web.internal.WebModuleHandlerImpl.deployModule(WebModuleHandlerImpl.java:103)
at com.ibm.ws.app.manager.module.internal.DeployedAppInfoBase.deployModule(DeployedAppInfoBase.java:871)
at com.ibm.ws.app.manager.module.internal.DeployedAppInfoBase.deployModules(DeployedAppInfoBase.java:831)
at com.ibm.ws.app.manager.module.internal.DeployedAppInfoBase.deployApp(DeployedAppInfoBase.java:818)
at com.ibm.ws.app.manager.ear.internal.EARApplicationHandlerImpl.install(EARApplicationHandlerImpl.java:84)
at com.ibm.ws.app.manager.internal.statemachine.StartAction.execute(StartAction.java:141)
at com.ibm.ws.app.manager.internal.statemachine.ApplicationStateMachineImpl.enterState(ApplicationStateMachineImpl.java:1192)
at com.ibm.ws.app.manager.internal.statemachine.ApplicationStateMachineImpl.run(ApplicationStateMachineImpl.java:805)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
I'm trying to setup logging in an entangled ear app consisting of a bunch of separate war modules using SiftingAppender and JNDIBasedContextDiscriminator deployed to IBM Liberty. Can't reproduce it in simpler configuration. So far I've just removed all modules but one and start still invoked twice (the bp in AuthorisationListener.java:34 is triggered only once).
Any help is highly appreciated.
logback version is 1.1.7.
Best regards, Eugene.