Skip to main content
[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index] [List Home]
Re: [jetty-users] Embedded Jetty + Logging - cannot log to file
I had added a Log4jConfigListener to my web.xml because I'd read somewhere that was how to get my log4j.xml imported into the app. I've tried a lot of things, at this point, so I'm sure I still have some cruft left over, but I removed that. I also removed the JDK logging and changed to ch.qos.logback. 

I'm getting errors like this:



From: jetty-users-bounces@xxxxxxxxxxx [jetty-users-bounces@xxxxxxxxxxx] on behalf of Joakim Erdfelt [joakim@xxxxxxxxxxx]
Sent: Wednesday, September 24, 2014 11:45 AM
To: JETTY user mailing list
Subject: Re: [jetty-users] Embedded Jetty + Logging - cannot log to file

That log4j error appears to be from an expected spring configuration you have.
 org.springframework.web.util.Log4jConfigListener.contextInitialized(Log4jConfigListener.java:46)

You should look into that, it might be a something discovering log4j on the classpath (possibly in your mexp.jar) or from a forced configuration telling spring to always assume/start log4j based logging.

Either way, you have to clean up your classpath and make sure that mexp.jar has no duplicates of classes from other jars.
Mixing fat/uber jars with normal jars is possible, but rarely done, as it requires an intimate knowledge of everything in the fat/uber jar.


--
Joakim Erdfelt <joakim@xxxxxxxxxxx>
Expert advice, services and support from from the Jetty & CometD experts

On Wed, Sep 24, 2014 at 8:35 AM, Dunn, Barclay <Barclay.Dunn@xxxxxxxxxx> wrote:
Thanks Joakim for this in-depth explanation. I have noticed the slf4j binding conflict and have searched on that previously without success. I think it occurs because mexp.jar, which contains all the code for my app, expands into a temp dir that is a subdir of my main directory (to solve another issue of needing a path visible to the app to contain my css, js, and image files) so there are two copies of the same jar on the classpath. I can't figure out if there is a way not to expand slf4j-jdk14.jar when expanding mexp.jar - do you know?

Furthermore ... I actually want to use the JDK logging implementation. I'm including log4j because I got a runtime error saying this (JettyWebApp.java:95 is the server.start() line in my jetty runner):

WARNING: FAILED o.e.j.w.WebAppContext@3af0ce45{/,file:/usr/local/mexp/resources/webapp/,STARTING}{file:/usr/local/mexp/mexp.jar}: java.lang.NoClassDefFoundError: org/apache/log4j/xml/DOMConfigurator
java.lang.NoClassDefFoundError: org/apache/log4j/xml/DOMConfigurator
at org.springframework.util.Log4jConfigurer.initLogging(Log4jConfigurer.java:69)
at org.springframework.web.util.Log4jWebConfigurer.initLogging(Log4jWebConfigurer.java:153)
at org.springframework.web.util.Log4jConfigListener.contextInitialized(Log4jConfigListener.java:46)
at org.eclipse.jetty.server.handler.ContextHandler.callContextInitialized(ContextHandler.java:798)
at org.eclipse.jetty.servlet.ServletContextHandler.callContextInitialized(ServletContextHandler.java:444)
at org.eclipse.jetty.server.handler.ContextHandler.startContext(ContextHandler.java:789)
at org.eclipse.jetty.servlet.ServletContextHandler.startContext(ServletContextHandler.java:294)
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)
Caused by: java.lang.ClassNotFoundException: org.apache.log4j.xml.DOMConfigurator
at java.net.URLClassLoader$1.run(URLClassLoader.java:366)
...

From: Joakim Erdfelt <joakim@xxxxxxxxxxx>
Reply-To: JETTY user mailing list <jetty-users@xxxxxxxxxxx>
Date: Tuesday, September 23, 2014 at 6:17 PM
To: JETTY user mailing list <jetty-users@xxxxxxxxxxx>
Subject: Re: [jetty-users] Embedded Jetty + Logging - cannot log to file

Typo...

This: 
    slf4j-api.jar        - the actual log4j api jar

Should be: 
    slf4j-api.jar        - the actual slf4j api jar


--
Joakim Erdfelt <joakim@xxxxxxxxxxx>
Expert advice, services and support from from the Jetty & CometD experts

On Tue, Sep 23, 2014 at 3:13 PM, Joakim Erdfelt <joakim@xxxxxxxxxxx> wrote:
Ooof.  OK
  • <artifactId>slf4j-jdk14</artifactId> is for making slf4j output/emit jdk14 logging events.
  • mexp.jar is also an emitter of slf4j logging events (this is now an slf4j binding conflict)
  • jetty doesn't use log4j, it uses its own StdErrLog (emit to System.err), or Slf4jLog (if slf4j is present, emit to slf4j api), and can be configured for JavaUtilLog (emit to jdk14 logging api).
  • Since you have slf4j present on your classpath Jetty is likely using the Slf4jLog implementation internally.
First things first, you have to understand how slf4j works.

It has 2 basic features.
  1. It can masquerade and be any (1..n) of the popular logging frameworks from the point of view of those APIs
  2. It can route to any logging framework you want.  This is called the binding layer.  There can be only 1.  Pick wisely.
Now, if you want to capture everything, but only use log4j for actual "to file" management, you'll want the following.

Your type 1 (masquerade) jars
  • jul-to-slf4j.jar     - pretends to be a java.util.logging Logger (routes to slf4j)
  • jcl-over-slf4j.jar  - pretends to be commons-logging (routes to slf4j)
  • slf4j-api.jar        - the actual log4j api jar
Your type 2 (binding) jar
  • slf4j-log4j.jar      - slf4j routing to log4j implementation
Your log file management jar
  • log4j.jar             - the logging layer you seem to want to use
Do this and you'll start to be able to configure your logging via log4j, no matter what class / library emitted the logging event.

--
Joakim Erdfelt <joakim@xxxxxxxxxxx>
Expert advice, services and support from from the Jetty & CometD experts

On Tue, Sep 23, 2014 at 1:31 PM, Dunn, Barclay <Barclay.Dunn@xxxxxxxxxx> wrote:
Hello list,

I'm using embedded Jetty and I want my application to log to a file. I am okay with Jetty logging its output to stdout. I have a log4j.xml config file that is clearly being imported but the app isn't heeding the instructions in log4j.xml.

Here's my embedded-Jetty runner (abridged):

    public static void main(String[] args) throws Exception {

        Server server = new Server();

        // PARSE JSON INPUT
        MEXPJsonProps mexpJsonProps = ConfigurationManager.parseJsonInput(args[1]);

        // CREATE CONNECTORS
...
        // set the connectors
        server.setConnectors(new Connector[] { http, httpAdmin });

        Map<String, String> localConfiguration = mexpJsonProps.getLocalConfiguration();

        // CREATE CONTEXT
        WebAppContext context = new WebAppContext();
        context.setContextPath("/");

        ProtectionDomain domain = JettyWebApp.class.getProtectionDomain();
        URL location = domain.getCodeSource().getLocation();
        context.setWar(location.toExternalForm());

        context.setDescriptor(location.toExternalForm() + "/WEB-INF/web.xml");

        // SET UP JSP CONFIGS
...

        System.setProperty("java.util.logging.config.file", "log4j.xml");

        // Set the handler
        server.setHandler(context);

        server.start();
        server.join();
    }

Here's the log4j.xml file. I'm using a very simple one to start:

<?xml version="1.0" encoding="UTF-8" ?>
<!DOCTYPE log4j:configuration SYSTEM "log4j.dtd">
<log4j:configuration debug="true"
 
<appender name="file" class="org.apache.log4j.RollingFileAppender">
  <param name="append" value="false" />
  <param name="maxFileSize" value="10KB" />
  <param name="maxBackupIndex" value="5" />
  <param name="file" value="/usr/local/mexp/logs/mexp.service.log" />
  <layout class="org.apache.log4j.PatternLayout">
<param name="ConversionPattern" 
value="%d{yyyy-MM-dd HH:mm:ss} %-5p %c{1}:%L - %m%n" />
  </layout>
</appender>
 
<root>
<level value="ERROR" />
<appender-ref ref="file" />
</root>
 </log4j:configuration>

I'm using slf4j via JDK logger:

            <dependency>
                <groupId>org.slf4j</groupId>
                <artifactId>slf4j-jdk14</artifactId>
                <version>1.7.7</version>
                <exclusions>
                    <exclusion>
                        <groupId>org.slf4j</groupId>
                        <artifactId>slf4j-api</artifactId>
                    </exclusion>
                </exclusions>
            </dependency>
            <dependency>
                <groupId>org.slf4j</groupId>
                <artifactId>slf4j-api</artifactId>
                <version>1.7.7</version>
            </dependency>

Nothing is being appended to the file I've specified. I know the app is parsing log4j.xml, because previously I had an incorrect path to the logging output file in log4j.xml and the app complained (to stdout).

Here's the first lines of logging output:

hackintosh:mexp barclayadunn$ 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

Sep 23, 2014 4:16:52 PM org.eclipse.jetty.util.log.Log initialized

INFO: Logging initialized @65ms

Sep 23, 2014 4:16:52 PM org.eclipse.jetty.server.Server doStart

INFO: jetty-9.2.z-SNAPSHOT

Sep 23, 2014 4:17:19 PM org.eclipse.jetty.server.handler.ContextHandler$Context log

INFO: Set web app root system property: 'webapp.root' = [/usr/local/mexp/resources/webapp]

Sep 23, 2014 4:17:20 PM org.eclipse.jetty.server.handler.ContextHandler$Context log

INFO: Initializing log4j from [/usr/local/mexp/resources/webapp/WEB-INF/log4j.xml]

log4j: reset attribute= "false".

log4j: Threshold ="null".

log4j: Level value for root is  [ERROR].

log4j: root level set to ERROR

log4j: Class name: [org.apache.log4j.RollingFileAppender]

log4j: Setting property [append] to [false].

log4j: Setting property [maxFileSize] to [10KB].

log4j: Setting property [maxBackupIndex] to [5].

log4j: Setting property [file] to [/usr/local/mexp/logs/mexp.service.log].

log4j: Parsing layout of class: "org.apache.log4j.PatternLayout"

log4j: Setting property [conversionPattern] to [%d{yyyy-MM-dd HH:mm:ss} %-5p %c{1}:%L - %m%n].

log4j: setFile called: /usr/local/mexp/logs/mexp.service.log, false

log4j: setFile ended

log4j: Adding appender named [file] to category [root].

Sep 23, 2014 4:17:20 PM org.eclipse.jetty.server.handler.ContextHandler$Context log

INFO: Initializing Spring root WebApplicationContext

SLF4J: Class path contains multiple SLF4J bindings.

SLF4J: Found binding in [jar:file:/usr/local/mexp/resources/webapp/WEB-INF/lib/slf4j-jdk14-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.JDK14LoggerFactory]

Sep 23, 2014 4:17:20 PM com.rc.util.logging.RCLog info

INFO: Entering initialization

Sep 23, 2014 4:17:20 PM com.pronto.common.util.FileUtil getInputStream

INFO:  -> Found /WEB-INF/log4j.xml in resource bundle

Sep 23, 2014 4:17:20 PM com.rc.util.logging.RCLog info

INFO: Exiting initialization

Sep 23, 2014 4:17:20 PM com.pronto.common.util.FileUtil getInputStream

INFO:  -> Found /mpds.properties in resource bundle

Sep 23, 2014 4:17:21 PM com.rc.util.logging.RCLog info

INFO: Entering servlet init.

Sep 23, 2014 4:17:21 PM org.quartz.impl.StdSchedulerFactory instantiate

INFO: Using default implementation for ThreadExecutor

Sep 23, 2014 4:17:21 PM org.quartz.core.SchedulerSignalerImpl <init>

INFO: Initialized Scheduler Signaller of type: class org.quartz.core.SchedulerSignalerImpl

Sep 23, 2014 4:17:21 PM org.quartz.core.QuartzScheduler <init>

INFO: Quartz Scheduler v.2.2.1 created.

Sep 23, 2014 4:17:21 PM org.quartz.plugins.xml.XMLSchedulingDataProcessorPlugin initialize

INFO: Registering Quartz Job Initialization Plug-in.

Sep 23, 2014 4:17:21 PM org.quartz.simpl.RAMJobStore initialize

INFO: RAMJobStore initialized.

Sep 23, 2014 4:17:21 PM org.quartz.core.QuartzScheduler initialize

INFO: 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.


Sep 23, 2014 4:17:21 PM org.quartz.impl.StdSchedulerFactory instantiate

INFO: Quartz scheduler 'MexpScheduler' initialized from an externally provided properties instance.

Sep 23, 2014 4:17:21 PM org.quartz.impl.StdSchedulerFactory instantiate

INFO: Quartz scheduler version: 2.2.1

Sep 23, 2014 4:17:21 PM org.quartz.xml.XMLSchedulingDataProcessor processFile

INFO: Parsing XML file: mexp-dev-jobs.xml with systemId: mexp-dev-jobs.xml

Sep 23, 2014 4:17:22 PM org.quartz.xml.XMLSchedulingDataProcessor scheduleJobs

INFO: Adding 13 jobs, 13 triggers.

Sep 23, 2014 4:17:22 PM org.quartz.xml.XMLSchedulingDataProcessor scheduleJobs

INFO: Adding job: skuLevelBiddingReportGroup.skuLevelBiddingReportJob

Sep 23, 2014 4:17:22 PM org.quartz.xml.XMLSchedulingDataProcessor scheduleJobs

INFO: Adding job: emailNotificationsGroup.emailNotificationsJob

Sep 23, 2014 4:17:22 PM org.quartz.xml.XMLSchedulingDataProcessor scheduleJobs

INFO: Adding job: balanceReplenishmentGroup.balanceReplenishmentJob

Sep 23, 2014 4:17:22 PM org.quartz.xml.XMLSchedulingDataProcessor scheduleJobs

INFO: Adding job: balanceReplenishmentCappedInvoiceGroup.balanceReplenishmentCappedInvoiceJob

Sep 23, 2014 4:17:22 PM org.quartz.xml.XMLSchedulingDataProcessor scheduleJobs

INFO: Adding job: merchantTxnProcessingGroup.merchantTxnProcessingJob

Sep 23, 2014 4:17:22 PM org.quartz.xml.XMLSchedulingDataProcessor scheduleJobs

INFO: Adding job: feedFileManagerGroup.feedFileManagerJob

Sep 23, 2014 4:17:22 PM org.quartz.xml.XMLSchedulingDataProcessor scheduleJobs

INFO: Adding job: merchantPaymentManagerGroup.merchantPaymentManagerJob

Sep 23, 2014 4:17:22 PM org.quartz.xml.XMLSchedulingDataProcessor scheduleJobs

INFO: Replacing job: merchantTxnProcessingGroup.merchantTxnProcessingJob

Sep 23, 2014 4:17:22 PM org.quartz.xml.XMLSchedulingDataProcessor scheduleJobs

INFO: Adding job: expiredAccountUpdaterGroup.expiredAccountUpdaterJob

Sep 23, 2014 4:17:22 PM org.quartz.xml.XMLSchedulingDataProcessor scheduleJobs

INFO: Adding job: placementsForDatasyncUpdaterGroup.placementsForDatasyncUpdaterJob

Sep 23, 2014 4:17:22 PM org.quartz.xml.XMLSchedulingDataProcessor scheduleJobs

INFO: Adding job: placementPaymentProcessingGroup.placementPaymentProcessingJob

Sep 23, 2014 4:17:22 PM org.quartz.xml.XMLSchedulingDataProcessor scheduleJobs

INFO: Adding job: switchingMerchantsToInvoiceGroup.switchingMerchantsToInvoiceJob

Sep 23, 2014 4:17:22 PM org.quartz.xml.XMLSchedulingDataProcessor scheduleJobs

INFO: Adding job: toggleActiveStateGroup.toggleActiveStateJob

Sep 23, 2014 4:17:22 PM org.quartz.core.QuartzScheduler start

INFO: Scheduler MexpScheduler_$_dev started.

Sep 23, 2014 4:17:22 PM org.eclipse.jetty.server.handler.ContextHandler doStart

INFO: Started o.e.j.w.WebAppContext@6783e43b{/,file:/usr/local/mexp/resources/webapp/,AVAILABLE}{file:/usr/local/mexp/mexp.jar}

Sep 23, 2014 4:17:22 PM org.quartz.plugins.history.LoggingTriggerHistoryPlugin triggerFired

INFO: Trigger JobSchedulingDataLoaderPlugin.JobSchedulingDataLoaderPlugin_jobInitializer_mexp-dev-jobs_xml fired job JobSchedulingDataLoaderPlugin.JobSchedulingDataLoaderPlugin_jobInitializer_mexp-dev-jobs_xml at:  16:17:22 09/23/2014

Sep 23, 2014 4:17:22 PM org.quartz.plugins.history.LoggingJobHistoryPlugin jobToBeExecuted

INFO: Job JobSchedulingDataLoaderPlugin.JobSchedulingDataLoaderPlugin_jobInitializer_mexp-dev-jobs_xml fired (by trigger JobSchedulingDataLoaderPlugin.JobSchedulingDataLoaderPlugin_jobInitializer_mexp-dev-jobs_xml) at:  16:17:22 09/23/2014

Sep 23, 2014 4:17:22 PM org.quartz.plugins.history.LoggingJobHistoryPlugin jobWasExecuted

INFO: Job JobSchedulingDataLoaderPlugin.JobSchedulingDataLoaderPlugin_jobInitializer_mexp-dev-jobs_xml execution complete at  16:17:22 09/23/2014 and reports: null

Sep 23, 2014 4:17:22 PM org.quartz.plugins.history.LoggingTriggerHistoryPlugin triggerComplete

INFO: Trigger JobSchedulingDataLoaderPlugin.JobSchedulingDataLoaderPlugin_jobInitializer_mexp-dev-jobs_xml completed firing job JobSchedulingDataLoaderPlugin.JobSchedulingDataLoaderPlugin_jobInitializer_mexp-dev-jobs_xml at  16:17:22 09/23/2014 with resulting trigger instruction code: DO NOTHING

Sep 23, 2014 4:17:22 PM org.eclipse.jetty.server.AbstractConnector doStart

INFO: Started ServerConnector@1c6c0838{HTTP/1.1}{0.0.0.0:8080}

Sep 23, 2014 4:17:22 PM org.eclipse.jetty.server.AbstractConnector doStart

INFO: Started ServerConnector@3cdd9094{HTTP/1.1}{0.0.0.0:8081}

Sep 23, 2014 4:17:22 PM org.eclipse.jetty.server.Server doStart

INFO: Started @30257ms

...

(further activity in the web app results in logging appended to stdout after this)


I see lines at the start about org.eclipse.jetty.util.log.Log. I don't know what this is but I definitely don't want it to override my preferences.


Any help would be appreciated. Ideally I'd prefer nothing logged to stdout other than embedded Jetty's initial startup.


Thanks,

Barclay



_______________________________________________
jetty-users mailing list
jetty-users@xxxxxxxxxxx
To change your delivery options, retrieve your password, or unsubscribe from this list, visit
https://dev.eclipse.org/mailman/listinfo/jetty-users



_______________________________________________
jetty-users mailing list
jetty-users@xxxxxxxxxxx
To change your delivery options, retrieve your password, or unsubscribe from this list, visit
https://dev.eclipse.org/mailman/listinfo/jetty-users

Back to the top