Cannot get logging to work right with embedded Jetty

Question

I have an app using embedded Jetty. Everything works well, except for logging. I am now trying to use logback, but am getting fatal errors.

The app loads as you can see:

 $ java -XX:+UseConcMarkSweepGC -XX:PermSize=64M -XX:MaxPermSize=256M -Xms1G -Xmx1G -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=/tmp -jar /usr/local/mexp/mexp.jar server /usr/local/mexp/mexp.json
10:46:02.093 [main] DEBUG org.eclipse.jetty.util.log - Logging to Logger[org.eclipse.jetty.util.log] via org.eclipse.jetty.util.log.Slf4jLog
10:46:02.098 [main] INFO  org.eclipse.jetty.util.log - Logging initialized @76ms

followed by pages and pages of DEBUG statements describing loading of every class in my app. This suggests it is not finding the logback.xml, where I have set logging level for org.eclipse.jetty to ERROR.

Eventually, I am getting the following exceptions when the app loads:

10:46:30.349 [main] DEBUG o.e.jetty.webapp.WebAppClassLoader - loaded class org.slf4j.impl.StaticLoggerBinder from sun.misc.Launcher$AppClassLoader@659c2931
10:46:30.354 [main] WARN  o.e.j.u.component.AbstractLifeCycle - FAILED o.e.j.w.WebAppContext@4e4e745{/,file:/usr/local/mexp/resources/webapp/,STARTING}{file:/usr/local/mexp/mexp.jar}: java.lang.LinkageError: loader constraint violation: when resolving method "org.slf4j.impl.StaticLoggerBinder.getLoggerFactory()Lorg/slf4j/ILoggerFactory;" the class loader (instance of org/eclipse/jetty/webapp/WebAppClassLoader) of the current class, org/slf4j/LoggerFactory, and the class loader (instance of sun/misc/Launcher$AppClassLoader) for resolved class, org/slf4j/impl/StaticLoggerBinder, have different Class objects for the type LoggerFactory; used in the signature
java.lang.LinkageError: loader constraint violation: when resolving method "org.slf4j.impl.StaticLoggerBinder.getLoggerFactory()Lorg/slf4j/ILoggerFactory;" the class loader (instance of org/eclipse/jetty/webapp/WebAppClassLoader) of the current class, org/slf4j/LoggerFactory, and the class loader (instance of sun/misc/Launcher$AppClassLoader) for resolved class, org/slf4j/impl/StaticLoggerBinder, have different Class objects for the type LoggerFactory; used in the signature
    at org.slf4j.LoggerFactory.getILoggerFactory(LoggerFactory.java:306) ~[mexp.jar:na]
    at org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:276) ~[mexp.jar:na]
    at org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:288) ~[mexp.jar:na]
    at com.rc.util.logging.RCLog.<init>(RCLog.java:28) ~[mexp.jar:na]
    at com.rc.commonwebapp.servlet.filter.SessionTXManager.<init>(SessionTXManager.java:43) ~[na:na]
    at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method) ~[na:1.7.0_45]
    at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:57) ~[na:1.7.0_45]
    at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45) ~[na:1.7.0_45]
    at java.lang.reflect.Constructor.newInstance(Constructor.java:526) ~[na:1.7.0_45]
    at java.lang.Class.newInstance(Class.java:374) ~[na:1.7.0_45]
    at org.eclipse.jetty.server.handler.ContextHandler$Context.createInstance(ContextHandler.java:2370) ~[mexp.jar:na]
    at org.eclipse.jetty.servlet.ServletContextHandler$Context.createFilter(ServletContextHandler.java:1146) ~[mexp.jar:na]
    at org.eclipse.jetty.servlet.FilterHolder.initialize(FilterHolder.java:120) ~[mexp.jar:na]
    at org.eclipse.jetty.servlet.ServletHandler.initialize(ServletHandler.java:850) ~[mexp.jar:na]
    at org.eclipse.jetty.servlet.ServletContextHandler.startContext(ServletContextHandler.java:298) ~[mexp.jar:na]
    at org.eclipse.jetty.webapp.WebAppContext.startWebapp(WebAppContext.java:1341) ~[mexp.jar:na]
    at org.eclipse.jetty.webapp.WebAppContext.startContext(WebAppContext.java:1334) ~[mexp.jar:na]
    at org.eclipse.jetty.server.handler.ContextHandler.doStart(ContextHandler.java:741) ~[mexp.jar:na]
    at org.eclipse.jetty.webapp.WebAppContext.doStart(WebAppContext.java:497) ~[mexp.jar:na]
    at org.eclipse.jetty.util.component.AbstractLifeCycle.start(AbstractLifeCycle.java:68) [mexp.jar:na]
    at org.eclipse.jetty.util.component.ContainerLifeCycle.start(ContainerLifeCycle.java:132) [mexp.jar:na]
    at org.eclipse.jetty.server.Server.start(Server.java:380) [mexp.jar:na]
    at org.eclipse.jetty.util.component.ContainerLifeCycle.doStart(ContainerLifeCycle.java:114) [mexp.jar:na]
    at org.eclipse.jetty.server.handler.AbstractHandler.doStart(AbstractHandler.java:61) [mexp.jar:na]
    at org.eclipse.jetty.server.Server.doStart(Server.java:347) [mexp.jar:na]
    at org.eclipse.jetty.util.component.AbstractLifeCycle.start(AbstractLifeCycle.java:68) [mexp.jar:na]
    at com.pronto.JettyWebApp.main(JettyWebApp.java:95) [mexp.jar:na]

and

java.lang.LinkageError: loader constraint violation: when resolving method "org.slf4j.impl.StaticLoggerBinder.getLoggerFactory()Lorg/slf4j/ILoggerFactory;" the class loader (instance of org/eclipse/jetty/webapp/WebAppClassLoader) of the current class, org/slf4j/LoggerFactory, and the class loader (instance of sun/misc/Launcher$AppClassLoader) for resolved class, org/slf4j/impl/StaticLoggerBinder, have different Class objects for the type LoggerFactory; used in the signature
    at org.slf4j.LoggerFactory.getILoggerFactory(LoggerFactory.java:306) ~[mexp.jar:na]
    at org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:276) ~[mexp.jar:na]
    at org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:288) ~[mexp.jar:na]
    at com.rc.util.logging.RCLog.<init>(RCLog.java:28) ~[mexp.jar:na]
    at com.rc.commonwebapp.servlet.filter.SessionTXManager.<init>(SessionTXManager.java:43) ~[na:na]
    at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method) ~[na:1.7.0_45]
    at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:57) ~[na:1.7.0_45]
    at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45) ~[na:1.7.0_45]
    at java.lang.reflect.Constructor.newInstance(Constructor.java:526) ~[na:1.7.0_45]
    at java.lang.Class.newInstance(Class.java:374) ~[na:1.7.0_45]
    at org.eclipse.jetty.server.handler.ContextHandler$Context.createInstance(ContextHandler.java:2370) ~[mexp.jar:na]
    at org.eclipse.jetty.servlet.ServletContextHandler$Context.createFilter(ServletContextHandler.java:1146) ~[mexp.jar:na]
    at org.eclipse.jetty.servlet.FilterHolder.initialize(FilterHolder.java:120) ~[mexp.jar:na]
    at org.eclipse.jetty.servlet.ServletHandler.initialize(ServletHandler.java:850) ~[mexp.jar:na]
    at org.eclipse.jetty.servlet.ServletContextHandler.startContext(ServletContextHandler.java:298) ~[mexp.jar:na]
    at org.eclipse.jetty.webapp.WebAppContext.startWebapp(WebAppContext.java:1341) ~[mexp.jar:na]
    at org.eclipse.jetty.webapp.WebAppContext.startContext(WebAppContext.java:1334) ~[mexp.jar:na]
    at org.eclipse.jetty.server.handler.ContextHandler.doStart(ContextHandler.java:741) ~[mexp.jar:na]
    at org.eclipse.jetty.webapp.WebAppContext.doStart(WebAppContext.java:497) ~[mexp.jar:na]
    at org.eclipse.jetty.util.component.AbstractLifeCycle.start(AbstractLifeCycle.java:68) ~[mexp.jar:na]
    at org.eclipse.jetty.util.component.ContainerLifeCycle.start(ContainerLifeCycle.java:132) ~[mexp.jar:na]
    at org.eclipse.jetty.server.Server.start(Server.java:380) ~[mexp.jar:na]
    at org.eclipse.jetty.util.component.ContainerLifeCycle.doStart(ContainerLifeCycle.java:114) ~[mexp.jar:na]
    at org.eclipse.jetty.server.handler.AbstractHandler.doStart(AbstractHandler.java:61) ~[mexp.jar:na]
    at org.eclipse.jetty.server.Server.doStart(Server.java:347) ~[mexp.jar:na]
    at org.eclipse.jetty.util.component.AbstractLifeCycle.start(AbstractLifeCycle.java:68) ~[mexp.jar:na]
    at com.pronto.JettyWebApp.main(JettyWebApp.java:95) [mexp.jar:na]
Exception in thread "main" java.lang.LinkageError: loader constraint violation: when resolving method "org.slf4j.impl.StaticLoggerBinder.getLoggerFactory()Lorg/slf4j/ILoggerFactory;" the class loader (instance of org/eclipse/jetty/webapp/WebAppClassLoader) of the current class, org/slf4j/LoggerFactory, and the class loader (instance of sun/misc/Launcher$AppClassLoader) for resolved class, org/slf4j/impl/StaticLoggerBinder, have different Class objects for the type LoggerFactory; used in the signature
    at org.slf4j.LoggerFactory.getILoggerFactory(LoggerFactory.java:306)
    at org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:276)
    at org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:288)
    at com.rc.util.logging.RCLog.<init>(RCLog.java:28)
    at com.rc.commonwebapp.servlet.filter.SessionTXManager.<init>(SessionTXManager.java:43)
    at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
    at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:57)
    at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
    at java.lang.reflect.Constructor.newInstance(Constructor.java:526)
    at java.lang.Class.newInstance(Class.java:374)
    at org.eclipse.jetty.server.handler.ContextHandler$Context.createInstance(ContextHandler.java:2370)
    at org.eclipse.jetty.servlet.ServletContextHandler$Context.createFilter(ServletContextHandler.java:1146)
    at org.eclipse.jetty.servlet.FilterHolder.initialize(FilterHolder.java:120)
    at org.eclipse.jetty.servlet.ServletHandler.initialize(ServletHandler.java:850)
    at org.eclipse.jetty.servlet.ServletContextHandler.startContext(ServletContextHandler.java:298)
    at org.eclipse.jetty.webapp.WebAppContext.startWebapp(WebAppContext.java:1341)
    at org.eclipse.jetty.webapp.WebAppContext.startContext(WebAppContext.java:1334)
    at org.eclipse.jetty.server.handler.ContextHandler.doStart(ContextHandler.java:741)
    at org.eclipse.jetty.webapp.WebAppContext.doStart(WebAppContext.java:497)
    at org.eclipse.jetty.util.component.AbstractLifeCycle.start(AbstractLifeCycle.java:68)
    at org.eclipse.jetty.util.component.ContainerLifeCycle.start(ContainerLifeCycle.java:132)
    at org.eclipse.jetty.server.Server.start(Server.java:380)
    at org.eclipse.jetty.util.component.ContainerLifeCycle.doStart(ContainerLifeCycle.java:114)
    at org.eclipse.jetty.server.handler.AbstractHandler.doStart(AbstractHandler.java:61)
    at org.eclipse.jetty.server.Server.doStart(Server.java:347)
    at org.eclipse.jetty.util.component.AbstractLifeCycle.start(AbstractLifeCycle.java:68)
    at com.pronto.JettyWebApp.main(JettyWebApp.java:95)

Some web searching on java.lang.LinkageError suggests that Jetty and my app have different class loaders that are conflicting when trying to load LoggerFactory. I'm not sure what to do next.

ETA: Per @PavelHoral's suggestion I added <scope>provided</scope> to my pom.xml (dependencyManagement section) but that results in this when I attempt to start the app:

2014-09-28 16:47:42.491:INFO::main: Logging initialized @66ms
Exception in thread "main" java.lang.NoClassDefFoundError: org/slf4j/LoggerFactory
    at com.rc.util.config.ConfigurationManager.<clinit>(ConfigurationManager.java:31)
    at com.pronto.JettyWebApp.main(JettyWebApp.java:39)
Caused by: java.lang.ClassNotFoundException: org.slf4j.LoggerFactory
    at java.net.URLClassLoader$1.run(URLClassLoader.java:366)
    at java.net.URLClassLoader$1.run(URLClassLoader.java:355)
    at java.security.AccessController.doPrivileged(Native Method)
    at java.net.URLClassLoader.findClass(URLClassLoader.java:354)
    at java.lang.ClassLoader.loadClass(ClassLoader.java:425)
    at sun.misc.Launcher$AppClassLoader.loadClass(Launcher.java:308)
    at java.lang.ClassLoader.loadClass(ClassLoader.java:358)
    ... 2 more

ETA: Per suggestion by @hd1 I added the bridge, which got rid of the LinkageError, so we're part way there. I'm still stymied by the fact that all of the logging goes to stdout and it's still at level DEBUG - not acceptable for a prod environment for sure, so I need to be able to configure this. Here is my logback.xml:

<configuration>
    <appender name="FILE" class="ch.qos.logback.core.FileAppender">
        <file>/usr/local/mexp/logs/mexp.service.log</file>
        <encoder>
            <pattern>"%-5p [%d{dd-MMM-yy HH:mm:ss}] [%t] %-20c %-3x:%m%n</pattern>
        </encoder>
    </appender>

    <appender name="AXIS" class="ch.qos.logback.core.FileAppender">
        <file>/usr/local/mexp/logs/axis.log</file>
        <encoder>
            <pattern>%-5p [%d{dd-MMM-yy HH:mm:ss}] :%m%n</pattern>
        </encoder>
    </appender>

    <appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
        <!-- The default pattern: Date Priority [Category] Message\n -->
        <encoder>
            <pattern>%d{ABSOLUTE} %-5p [%c{1}] %m%n</pattern>
        </encoder>
    </appender>

    <appender name="ASYNC" class="ch.qos.logback.classic.AsyncAppender">
        <appender-ref ref="AXIS"/>
    </appender>

    <logger name="org.apache">
        <level value="ERROR"/>
    </logger>

    <logger name="org.quartz">
        <level value="ERROR" />
    </logger>

    <logger name="org.hibernate">
        <level value="ERROR" />
    </logger>

    <logger name="org.apache.struts.action">
        <level value="INFO"/>
    </logger>

    <logger name="org.apache.catalina.cluster">
        <level value="INFO"/>
    </logger>

    <logger name="org">
        <level value="ERROR" />
    </logger>

    <logger name="net">
        <level value="ERROR" />
    </logger>

    <logger name="org.apache.axis.transport.http.HTTPSender" additivity="false">
        <level value="ERROR"/>
        <appender-ref ref="ASYNC"/>
    </logger>

    <logger name="com.mchange">
        <level value="ERROR"/>
    </logger>

    <!-- this silences the HttpClient chatter that starts with "httpclient.wire.header" and "httpclient.wire.content" -->
    <logger name="org.apache.commons.httpclient">
        <level value="fatal"/>
    </logger>
    <logger name="httpclient.wire.header">
        <level value="fatal"/>
    </logger>
    <logger name="httpclient.wire.content">
        <level value="fatal"/>
    </logger>

    <logger name="org.eclipse.jetty">
        <level value="ERROR"/>
    </logger>

    <!-- Log the real SQL -->
    <logger name="org.hibernate.SQL">
        <level value="ERROR"/>
    </logger>

    <root level="ERROR">
        <appender-ref ref="FILE"/>
    </root>
</configuration>

ETA: I also tried the logging separation described here - added this to web.xml:

<env-entry>
    <env-entry-name>logback/context-name</env-entry-name>
    <env-entry-type>java.lang.String</env-entry-type>
    <env-entry-value>mexp</env-entry-value>
</env-entry>

and this in my jetty runner main method

System.setProperty("logback.ContextSelector", "JNDI");

(and changed the name of the logback file to logback-mexp.xml) but all of that results in no change in behavior.

We're definitely getting closer, but for the bounty I need the whole solution. Thanks!

---

ETA the current state of things. I no longer get the LinkageError. My app loads and performs fine. In fact there has been a considerable improvement in that now I don't get pages and pages of DEBUG lines in stdout. I still get all my logging in stdout, like so:

 $ java -XX:+UseConcMarkSweepGC -XX:PermSize=64M -XX:MaxPermSize=256M -Xms1G -Xmx1G -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=/tmp -jar /usr/local/mexp/mexp.jar server /usr/local/mexp/mexp.json
Oct 01, 2014 3:54:28 PM org.springframework.web.context.ContextLoader initWebApplicationContext
INFO: Root WebApplicationContext: initialization started
Oct 01, 2014 3:54:28 PM org.springframework.web.context.support.XmlWebApplicationContext prepareRefresh
INFO: Refreshing Root WebApplicationContext: startup date [Wed Oct 01 15:54:28 EDT 2014]; root of context hierarchy
Oct 01, 2014 3:54:28 PM org.springframework.beans.factory.xml.XmlBeanDefinitionReader loadBeanDefinitions
INFO: Loading XML bean definitions from class path resource [mexpPapiContext.xml]
Oct 01, 2014 3:54:28 PM org.springframework.web.context.ContextLoader initWebApplicationContext
INFO: Root WebApplicationContext: initialization completed in 352 ms
SLF4J: Class path contains multiple SLF4J bindings.
SLF4J: Found binding in [jar:file:/usr/local/mexp/resources/webapp/WEB-INF/lib/slf4j-log4j12-1.7.7.jar!/org/slf4j/impl/StaticLoggerBinder.class]
SLF4J: Found binding in [jar:file:/usr/local/mexp/mexp.jar!/org/slf4j/impl/StaticLoggerBinder.class]
SLF4J: See http://www.slf4j.org/codes.html#multiple_bindings for an explanation.
SLF4J: Actual binding is of type [org.slf4j.impl.Log4jLoggerFactory]
15:54:28,596  INFO GlobalRootManager:85 - Entering initialization
15:54:28,840  INFO GlobalRootManager:85 - Exiting initialization
15:54:28,868  INFO FileUtil:220 -  -> Found /mpds.properties in resource bundle
Oct 01, 2014 3:54:29 PM org.apache.struts.action.ActionServlet initChain
INFO: Loading chain catalog from jar:file:/usr/local/mexp/resources/webapp/WEB-INF/lib/struts-core-1.3.10.jar!/org/apache/struts/chain/chain-config.xml
Oct 01, 2014 3:54:29 PM org.apache.struts.action.ActionServlet initChain
INFO: Loading chain catalog from jar:file:/usr/local/mexp/mexp.jar!/org/apache/struts/chain/chain-config.xml
Oct 01, 2014 3:54:29 PM org.apache.struts.validator.ValidatorPlugIn initResources
INFO: Loading validation rules file from '/WEB-INF/struts/validator-rules.xml'
Oct 01, 2014 3:54:29 PM org.apache.struts.validator.ValidatorPlugIn initResources
INFO: Loading validation rules file from '/WEB-INF/struts/validation-mexp.xml'
15:54:29,529  INFO QuartzStartupServlet:85 - Entering servlet init.
15:54:29,562  INFO StdSchedulerFactory:1184 - Using default implementation for ThreadExecutor
15:54:29,575  INFO SchedulerSignalerImpl:61 - Initialized Scheduler Signaller of type: class org.quartz.core.SchedulerSignalerImpl
15:54:29,575  INFO QuartzScheduler:240 - Quartz Scheduler v.2.2.1 created.
15:54:29,576  INFO XMLSchedulingDataProcessorPlugin:200 - Registering Quartz Job Initialization Plug-in.
15:54:29,578  INFO RAMJobStore:155 - RAMJobStore initialized.
15:54:29,578  INFO QuartzScheduler:305 - Scheduler meta-data: Quartz Scheduler (v2.2.1) 'MexpScheduler' with instanceId 'dev'
  Scheduler class: 'org.quartz.core.QuartzScheduler' - running locally.
  NOT STARTED.
  Currently in standby mode.
  Number of jobs executed: 0
  Using thread pool 'org.quartz.simpl.SimpleThreadPool' - with 5 threads.
  Using job-store 'org.quartz.simpl.RAMJobStore' - which does not support persistence. and is not clustered.

15:54:29,578  INFO StdSchedulerFactory:1339 - Quartz scheduler 'MexpScheduler' initialized from an externally provided properties instance.
15:54:29,578  INFO StdSchedulerFactory:1343 - Quartz scheduler version: 2.2.1
15:54:29,592  INFO XMLSchedulingDataProcessor:471 - Parsing XML file: mexp-dev-jobs.xml with systemId: mexp-dev-jobs.xml
15:54:29,948  INFO XMLSchedulingDataProcessor:996 - Adding 13 jobs, 13 triggers.
15:54:29,949  INFO XMLSchedulingDataProcessor:1034 - Adding job: skuLevelBiddingReportGroup.skuLevelBiddingReportJob
15:54:29,951  INFO XMLSchedulingDataProcessor:1034 - Adding job: emailNotificationsGroup.emailNotificationsJob
15:54:29,952  INFO XMLSchedulingDataProcessor:1034 - Adding job: balanceReplenishmentGroup.balanceReplenishmentJob
15:54:29,953  INFO XMLSchedulingDataProcessor:1034 - Adding job: balanceReplenishmentCappedInvoiceGroup.balanceReplenishmentCappedInvoiceJob
15:54:29,954  INFO XMLSchedulingDataProcessor:1034 - Adding job: merchantTxnProcessingGroup.merchantTxnProcessingJob
15:54:29,956  INFO XMLSchedulingDataProcessor:1034 - Adding job: feedFileManagerGroup.feedFileManagerJob
15:54:29,957  INFO XMLSchedulingDataProcessor:1034 - Adding job: merchantPaymentManagerGroup.merchantPaymentManagerJob
15:54:29,958  INFO XMLSchedulingDataProcessor:1032 - Replacing job: merchantTxnProcessingGroup.merchantTxnProcessingJob
15:54:29,958  INFO XMLSchedulingDataProcessor:1034 - Adding job: expiredAccountUpdaterGroup.expiredAccountUpdaterJob
15:54:29,959  INFO XMLSchedulingDataProcessor:1034 - Adding job: placementsForDatasyncUpdaterGroup.placementsForDatasyncUpdaterJob
15:54:29,960  INFO XMLSchedulingDataProcessor:1034 - Adding job: placementPaymentProcessingGroup.placementPaymentProcessingJob
15:54:29,961  INFO XMLSchedulingDataProcessor:1034 - Adding job: switchingMerchantsToInvoiceGroup.switchingMerchantsToInvoiceJob
15:54:29,962  INFO XMLSchedulingDataProcessor:1034 - Adding job: toggleActiveStateGroup.toggleActiveStateJob
15:54:29,963  INFO QuartzScheduler:575 - Scheduler MexpScheduler_$_dev started.
15:54:29,982  INFO LoggingTriggerHistoryPlugin:387 - Trigger JobSchedulingDataLoaderPlugin.JobSchedulingDataLoaderPlugin_jobInitializer_mexp-dev-jobs_xml fired job JobSchedulingDataLoaderPlugin.JobSchedulingDataLoaderPlugin_jobInitializer_mexp-dev-jobs_xml at:  15:54:29 10/01/2014
15:54:29,983  INFO LoggingJobHistoryPlugin:469 - Job JobSchedulingDataLoaderPlugin.JobSchedulingDataLoaderPlugin_jobInitializer_mexp-dev-jobs_xml fired (by trigger JobSchedulingDataLoaderPlugin.JobSchedulingDataLoaderPlugin_jobInitializer_mexp-dev-jobs_xml) at:  15:54:29 10/01/2014
15:54:29,984  INFO LoggingJobHistoryPlugin:513 - Job JobSchedulingDataLoaderPlugin.JobSchedulingDataLoaderPlugin_jobInitializer_mexp-dev-jobs_xml execution complete at  15:54:29 10/01/2014 and reports: null
15:54:29,984  INFO LoggingTriggerHistoryPlugin:433 - Trigger JobSchedulingDataLoaderPlugin.JobSchedulingDataLoaderPlugin_jobInitializer_mexp-dev-jobs_xml completed firing job JobSchedulingDataLoaderPlugin.JobSchedulingDataLoaderPlugin_jobInitializer_mexp-dev-jobs_xml at  15:54:29 10/01/2014 with resulting trigger instruction code: DO NOTHING

Answer 1

Please see this page on the slf4j site. I suspect you've not included the appropriate bridge jar. For example, for log4j, you're going to need the following stanzas in your pom.xml:

<dependency>
    <groupId>org.slf4j</groupId>
    <artifactId>slf4j-api</artifactId>
    <version>1.7.7</version>
</dependency>
<dependency>
    <groupId>org.slf4j</groupId>
    <artifactId>slf4j-log4j12</artifactId>
    <version>1.7.7</version>
</dependency>
<dependency>
    <groupId>org.slf4j</groupId>
    <artifactId>log4j-over-slf4j</artifactId>
    <version>1.7.7</version>
</dependency>

<dependency>
    <groupId>log4j</groupId>
    <artifactId>log4j</artifactId>
    <version>1.2.17</version>
</dependency>

Hope that helps. If not, feel free to leave a comment.

Answer 2

I do not think there is a silver bullet here: logging in Java takes many forms and it takes attention to detail to get it right. Especially when class-loaders come in to play as is the case with web-apps.

The explanation about how logging works with Slf4j by Joakim Erdfelt is pretty good (I saw this in the mail-conversation you had with him earlier).

I can only add to do a proper clean-up:

• put the jar-files for Logback, the Slf4j-api and the required Slf4j-bridges (jcl-over-slf4j, log4j-over-slf4j) in the main/common/launch class-path.
• remove everything else that has anything to do with logging (log4j, commons-logging, etc.). The "dependencyManagement with scope provided" trick mentioned in the comments by Pavel Horal can come in handy here.
• for some components you need to programmatically set Slf4j as logger, e.g. for Hibernate 4.3 use System.setProperty("org.jboss.logging.provider", "slf4j"); before Hibernate is started.
• if Slf4j cannot be set as logger for a component, try setting Log4j. The slf4j-bridge "log4j-over-slf4j" will redirect the logging from Log4j to Slf4j and Slf4j will send it to the logging implementation (Logback). Note that you only need the bridge jar-file "log4j-over-slf4j" and NOT the log4j-jar (the bridge will provide replacements for the Log4j classes) in your main class-path.

You should now have only one jar-file and/or class in your entire assembly for your application for each logging related component mentioned in the first point of the clean-up. Double check that there are no logging related jar-files in any of the web-apps (WEB-INF/lib folders). On a side node: if you use JDBC-drivers, follow the same procedure (these tend to give trouble as well if they are not in the main class-path).

Before you start the clean-up you should verify your basic setup by using Logback with the Jetty embedded Hello World example.

It takes some effort to get all this logging going but, as you said, it is required for production and it has helped me during development: simply switching on trace/debugging for a third-party component (via a logger-category in logback-test.xml) can provide a lot of insight in what is happening (especially when combined with unit-tests).

Answer 3

I had this proble. Turns out I found an embarrasingly easy sollution (in my case).

Jetty didn't find my slf4j-*.jar(s) unless I added them as dependencies to the plugin configuration itself. I will not include my entire pom.xml but merely the plugin conf. Hope this helps.

Cheers

...
  <plugin>
<groupId>org.mortbay.jetty</groupId>
<artifactId>jetty-maven-plugin</artifactId>
<version>8.1.10.v20130312</version>
<configuration>
  <webAppConfig>
  </webAppConfig>
</configuration>
<dependencies>
  <dependency>
    <groupId>org.slf4j</groupId>
    <artifactId>slf4j-api</artifactId>
    <version>1.7.7</version>
  </dependency>
  <dependency>
    <groupId>org.slf4j</groupId>
    <artifactId>slf4j-log4j12</artifactId>
    <version>1.7.7</version>
  </dependency>
  <dependency>
    <groupId>org.slf4j</groupId>
    <artifactId>log4j-over-slf4j</artifactId>
    <version>1.7.7</version>
  </dependency>
  <dependency>
    <groupId>org.codehaus.fabric3</groupId>
    <artifactId>fabric3-atomikos-library</artifactId>
    <version>1.9.6</version>
  </dependency>
  <dependency>
    <groupId>javax.transaction</groupId>
    <artifactId>jta</artifactId>
    <version>1.1</version>
    <scope>runtime</scope>
  </dependency>
      <dependency>
        <groupId>org.codehaus.btm</groupId>
        <artifactId>btm-jetty6-lifecycle</artifactId>
        <version>1.3.3</version>
      </dependency>
</dependencies>
  </plugin>
...

I then checked the project dependency tree using the Maven Dependency Plugin and removed/excluded all unwanted logging frameworks included by dependencies and it worked.