8 Replies Latest reply: Feb 1, 2008 10:08 AM by Juergen Zimmermann RSS

TRACE level doesn't work

Juergen Zimmermann Master

I tried to use the TRACE level in log4j.xml (and log4j.properties) and put this config file into an SAR archive: The TRACE level doesn't work!

However, DEBUG works... http://jira.jboss.org/jira/browse/JBAS-1853 isn't resolved completely.

Any workarounds for JBossAS 4.2.2 except listing the categories for level TRACE inside the global jboss-log4j.xml ?

  • 1. Re: TRACE level doesn't work
    jaikiran pai Master

    Are you packaging log4j jar in your application? If yes, which version of log4j? The TRACE level is available starting 1.2.12 version of log4j. Are you sure you are using this (or a higher version)? And when you say, it doesn't work, do you see any exceptions?

  • 2. Re: TRACE level doesn't work
    Juergen Zimmermann Master

    No log4j.jar is packaged with my EAR archive containing an EJB module as a JAR archive and a SAR archive. The SAR archive contains log4j.properties and META-INF/jboss-service.xml

    No exception can be found in server.log.

  • 3. Re: TRACE level doesn't work
    jaikiran pai Master

    Can you post the contents of your log4j.properties file? And also the code from where you are logging the TRACE level logs (if at all that class belongs to your application).

    Also, to make sure that your log4j.properties (which you mention is in a SAR) is indeed being picked up, edit the run.bat file (assuming you are on Windows OS) under %JBOSS_HOME%/bin to pass -Dlog4j.debug as a JVM parameter:

    set JAVA_OPTS=%JAVA_OPTS% -Dsun.rmi.dgc.client.gcInterval=3600000 -Dsun.rmi.dgc.server.gcInterval=3600000 -Dlog4j.debug


    Log4j prints out information about the location from where it picks up the log4j.xml/log4j.properties file. Keep an watch on the console and the server.log file for this information. You might see something like:
    log4j: Trying to find [log4j.xml] using context classloader org.jboss.system.server.NoAnnotationURLClassLoader@c9ba38.
    log4j: Trying to find [log4j.xml] using org.jboss.system.server.NoAnnotationURLClassLoader@c9ba38 class loader.
    log4j: Trying to find [log4j.xml] using ClassLoader.getSystemResource().
    log4j: Trying to find [log4j.properties] using context classloader org.jboss.system.server.NoAnnotationURLClassLoader@c9ba38.
    log4j: Using URL [jar:file:/D:/JBoss-4.2.2/jboss-4.2.2.GA/bin/run.jar!/log4j.properties] for automatic log4j configuration.
    log4j: Reading configuration from URL jar:file:/D:/JBoss-4.2.2/jboss-4.2.2.GA/bin/run.jar!/log4j.properties
    log4j: Parsing for [root] with value=[DEBUG, FILE, CONSOLE].
    log4j: Level token is [DEBUG].
    log4j: Category root set to DEBUG
    log4j: Parsing appender named "FILE".
    log4j: Parsing layout options for "FILE".
    log4j: Setting property [conversionPattern] to [%d{ABSOLUTE} %-5p [%c{1}] %m%n].
    log4j: End of parsing for "FILE".
    log4j: Setting property [append] to [false].
    log4j: Setting property [file] to [D:\JBoss-4.2.2\jboss-4.2.2.GA\server\jaikiran\log/boot.log].
    log4j: setFile called: D:\JBoss-4.2.2\jboss-4.2.2.GA\server\jaikiran\log/boot.log, false
    log4j: setFile ended
    log4j: Parsed "FILE" options.
    log4j: Parsing appender named "CONSOLE".
    log4j: Parsing layout options for "CONSOLE".
    log4j: Setting property [conversionPattern] to [%d{ABSOLUTE} %-5p [%c{1}] %m%n].
    log4j: End of parsing for "CONSOLE".
    log4j: Setting property [threshold] to [INFO].
    log4j: Setting property [target] to [System.out].
    log4j: Parsed "CONSOLE" options.
    log4j: Finished configuring.


  • 4. Re: TRACE level doesn't work
    Juergen Zimmermann Master

    This is the 1-line contents of my log4j.properties:

    log4j.logger.de.hska=TRACE


    The contents of a session bean is:
    @Stateless
    @Local(KundenverwaltungDao.class)
    final public class KundenverwaltungDaoBean implements KundenverwaltungDao {
     public static final Log LOG = LogFactory.getLog(KundenverwaltungDaoBean.class);
    ...
     if (LOG.isDebugEnabled()) {
     for (Kunde k: kunden) {
     LOG.debug(k);
     }
     }
    


    Now, I get the expected log records. However, changing "isDebugEnabled" to "isTraceEnabled" and "debug()" to "trace()" then nothing is logged.

    Using "-Dlog4j.debug" for log4j's internal log doesn't show anything regarding my log4j.properties (which is part of an EAR's SAR archive).

    Could it be that JBoss is internally setting the DEBUG level for everything and that's the reason for logging the stuff above with DEBUG level?

  • 5. Re: TRACE level doesn't work
    jaikiran pai Master

    It's not JBoss which sets the default logging level to DEBUG. Log4j does it. So, in your case the log4j.properties is not being picked up (you can verify this by setting the threshold to INFO in the log4j.properties and still log debug messages. I believe, you will see the debug log even when this threshold is set).

    For the sake of testing, i would suggest, you move the log4j.properties to the root of the ear file (or some other place which in the ear which is available in the classpath) and try out the trace level logs.

  • 6. Re: TRACE level doesn't work
    Juergen Zimmermann Master

    I tried putting log4j.properties in the root of the EAR module so that it is on the classpath -- no success.

    Looks like log categories have to be set in the central jboss-log4j.xml.
    Or is there another option not to touch this central config file?

  • 7. Re: TRACE level doesn't work
    jaikiran pai Master

    Tried this on my local setup with JBoss-4.2.2. Got it working. Here's what you have to do:

    1) Create a log4j.properties file and package it with your application and make it available in the classpath (i placed the log4j.properties file at the root of the EAR file). The log4j.properties looks like:

    log4j.logger.org.myapp=TRACE



    2) Also package the appropriate version of log4j jar with your application (this step and the next step are important because you will have to ensure that log4j initializes separately for your application and picks up the log4j.properties file). Place this log4j jar file in the application package so that it is made available in the classpath (i placed it in a folder named lib of the EAR file - remember that any jars in the lib folder of the EAR are by default added to the classpath and made available to the entire application, starting JBoss-4.2.x version).

    3) Enable classloader isolation for your application. This is necessary as explained in step#2. You will have to create a jboss-app.xml file and place it in the META-INF folder of the EAR. The jboss-app.xml looks like:
    <jboss-app>
     <loader-repository>
     org.myapp:loader=MyClassLoader
     <loader-repository-config>
     java2ParentDelegation=false
     </loader-repository-config>
     </loader-repository>
    
    
    
    </jboss-app>


    This is how my EAR file looks like:

    myApp.ear
     |
     |--- log4j.properties
     |
     |--- META-INF
     | |
     | |--- application.xml
     | |
     | |--- jboss-app.xml
     |
     |--- lib
     | |
     | |--- log4jxxx.jar


    And finally the -Dlo4j.debug prints out the following message when i invoke my application (this is just a sample output):

    2008-02-01 13:24:01,231 INFO [STDOUT] log4j: Trying to find [log4j.xml] using context classloader org.jboss.mx.loading.UnifiedClassLoader3@1038b78{ url=file:/D:/JBoss-4.2.2/jboss-4.2.2.GA/server/jaikiran/deploy/EJB3Persistence.ear/ ,addedOrder=45}.
    2008-02-01 13:24:01,247 INFO [STDOUT] log4j: Trying to find [log4j.xml] using org.jboss.mx.loading.UnifiedClassLoader3@1038b78{ url=file:/D:/JBoss-4.2.2/jboss-4.2.2.GA/server/jaikiran/deploy/EJB3Persistence.ear/ ,addedOrder=45} class loader.
    2008-02-01 13:24:01,262 INFO [STDOUT] log4j: Trying to find [log4j.xml] using ClassLoader.getSystemResource().
    2008-02-01 13:24:01,262 INFO [STDOUT] log4j: Trying to find [log4j.properties] using context classloader org.jboss.mx.loading.UnifiedClassLoader3@1038b78{ url=file:/D:/JBoss-4.2.2/jboss-4.2.2.GA/server/jaikiran/deploy/EJB3Persistence.ear/ ,addedOrder=45}.
     2008-02-01 13:24:01,262 INFO [STDOUT] log4j: Using URL [file:/D:/JBoss-4.2.2/jboss-4.2.2.GA/server/jaikiran/deploy/EJB3Persistence.ear/log4j.properties] for automatic log4j configuration.
     2008-02-01 13:24:01,262 INFO [STDOUT] log4j: Reading configuration from URL file:/D:/JBoss-4.2.2/jboss-4.2.2.GA/server/jaikiran/deploy/EJB3Persistence.ear/log4j.properties
    2008-02-01 13:24:01,262 INFO [STDOUT] log4j: Parsing for [root] with value=[DEBUG, stdout, logfile].
    2008-02-01 13:24:01,262 INFO [STDOUT] log4j: Level token is [DEBUG].
    2008-02-01 13:24:01,262 INFO [STDOUT] log4j: Category root set to DEBUG
    2008-02-01 13:24:01,278 INFO [STDOUT] log4j: Parsing appender named "stdout".
    2008-02-01 13:24:01,309 INFO [STDOUT] log4j: Parsing layout options for "stdout".
    2008-02-01 13:24:01,309 INFO [STDOUT] log4j: Setting property [conversionPattern] to [%d %p [%c] - <%m>%n].
    2008-02-01 13:24:01,325 INFO [STDOUT] log4j: End of parsing for "stdout".
    2008-02-01 13:24:01,325 INFO [STDOUT] log4j: Parsed "stdout" options.
    2008-02-01 13:24:01,325 INFO [STDOUT] log4j: Parsing appender named "logfile".
    2008-02-01 13:24:01,325 INFO [STDOUT] log4j: Parsing layout options for "logfile".
    2008-02-01 13:24:01,325 INFO [STDOUT] log4j: Setting property [conversionPattern] to [%d %p [%c] - %m%n].
    2008-02-01 13:24:01,325 INFO [STDOUT] log4j: End of parsing for "logfile".
    2008-02-01 13:24:01,340 INFO [STDOUT] log4j: Setting property [file] to [D:\JBoss-4.2.2\jboss-4.2.2.GA\server\jaikiran\log\test.log].
    2008-02-01 13:24:01,340 INFO [STDOUT] log4j: Setting property [maxFileSize] to [512KB].
    2008-02-01 13:24:01,340 INFO [STDOUT] log4j: Setting property [maxBackupIndex] to [3].
    2008-02-01 13:24:01,340 INFO [STDOUT] log4j: setFile called: D:\JBoss-4.2.2\jboss-4.2.2.GA\server\jaikiran\log\test.log, true
    2008-02-01 13:24:01,356 INFO [STDOUT] log4j: setFile ended
    2008-02-01 13:24:01,356 INFO [STDOUT] log4j: Parsed "logfile" options.
    2008-02-01 13:24:01,356 INFO [STDOUT] log4j: Parsing for [org.myapp] with value=[WARN].
    2008-02-01 13:24:01,356 INFO [STDOUT] log4j: Level token is [WARN].
    2008-02-01 13:24:01,356 INFO [STDOUT] log4j: Category org.myapp set to WARN
    2008-02-01 13:24:01,356 INFO [STDOUT] log4j: Handling log4j.additivity.org.myapp=[null]
    2008-02-01 13:24:01,356 INFO [STDOUT] log4j: Finished configuring.
    




  • 8. Re: TRACE level doesn't work
    Juergen Zimmermann Master

    Thank you. That's what I was looking for.