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
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

Back to the top