Friday, August 3, 2012

Configure slf4j with log4j on Weblogic



It is neccessary to use filtering classloader to avoid discovery of Weblogic own version of slf4j jars. With prefer-application-packages option application classloader loads org.slf4j packages from application instead of Weblogic installation

Annoying SLF4J problem in Weblogic server 12c http://blog.terrencemiao.com/archives/annoying-slf4j-problem-in-weblogic-server-12c

 prefer-application-packages
Used for filtering ClassLoader configuration. Specifies a list of packages for classes that must always be loaded from the application. http://docs.oracle.com/cd/E24329_01/web.1211/e21049/weblogic_xml.htm#autoId24

Weblogic log without prefer-application-packages and after redeploy with the option set in weblogic.xml 
Aug 3, 2012 11:20:03 PM dave.TestSlf4jLogger doGet
INFO: Hello World- info
Aug 3, 2012 11:20:04 PM dave.TestSlf4jLogger doGet
INFO: Hello World- info
Aug 3, 2012 11:20:05 PM dave.TestSlf4jLogger doGet
INFO: Hello World- info
Aug 3, 2012 11:20:05 PM dave.TestSlf4jLogger doGet
INFO: Hello World- info
Aug 3, 2012 11:20:05 PM dave.TestSlf4jLogger doGet
INFO: Hello World- info
SLF4J: Class path contains multiple SLF4J bindings.
SLF4J: Found binding in [jar:file:/usr/app/weblogic121/modules/org.slf4j.jdk14_1.6.1.0.jar!/org/slf4j/impl/StaticLoggerBinder.class]
SLF4J: Found binding in [zip:/home/dave/workspace38/testSLF4JWAR/WebContent/WEB-INF/lib/slf4j-log4j12-1.6.6.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]
log4j: Parsing for [root] with value=[DEBUG, file, stdout].
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}:%L - %m%n].
log4j: End of parsing for "file".
log4j: Setting property [file] to [/tmp/testSLF4j.log].
log4j: Setting property [maxBackupIndex] to [1].
log4j: Setting property [maxFileSize] to [1MB].
log4j: setFile called: /tmp/testSLF4j.log, true
log4j: setFile ended
log4j: Parsed "file" options.
log4j: Parsing appender named "stdout".
log4j: Parsing layout options for "stdout".
log4j: Setting property [conversionPattern] to [%d{ABSOLUTE} %5p %c{1}:%L - %m%n].
log4j: End of parsing for "stdout".
log4j: Setting property [target] to [System.out].
log4j: Parsed "stdout" options.
log4j: Finished configuring.
23:23:07,943 DEBUG TestSlf4jLogger:41 - Hello World - debug
23:23:07,949  INFO TestSlf4jLogger:42 - Hello World- info
23:23:08,590 DEBUG TestSlf4jLogger:41 - Hello World - debug
23:23:08,592  INFO TestSlf4jLogger:42 - Hello World- info
23:23:09,386 DEBUG TestSlf4jLogger:41 - Hello World - debug
23:23:09,387  INFO TestSlf4jLogger:42 - Hello World- info
log file created 
[dave@dave testSLF4JWAR]$ more /tmp/testSLF4j.log 
23:23:07,943 DEBUG TestSlf4jLogger:41 - Hello World - debug
23:23:07,949  INFO TestSlf4jLogger:42 - Hello World- info
23:23:08,590 DEBUG TestSlf4jLogger:41 - Hello World - debug
23:23:08,592  INFO TestSlf4jLogger:42 - Hello World- info
23:23:09,386 DEBUG TestSlf4jLogger:41 - Hello World - debug
23:23:09,387  INFO TestSlf4jLogger:42 - Hello World- info
libraries in project
[dave@dave testSLF4JWAR]$ ls -1 WebContent/WEB-INF/lib/ 
log4j-1.2.16.jar
slf4j-api-1.6.6.jar
slf4j-log4j12-1.6.6.jar
slf4j libraries in Weblogic 
[dave@dave testSLF4JWAR]$ find /app/weblogic121/ -name "*slf4j*"
/app/weblogic121/modules/org.slf4j.jdk14_1.6.1.0.jar
/app/weblogic121/modules/org.slf4j.ext_1.6.1.0.jar
/app/weblogic121/modules/org.slf4j.api_1.6.1.0.jar
log4j.properties 
log4j.debug=true

# Root logger option
log4j.rootLogger=DEBUG, file, stdout

# Direct log messages to a log file
log4j.appender.file=org.apache.log4j.RollingFileAppender
log4j.appender.file.File=/tmp/testSLF4j.log
log4j.appender.file.MaxFileSize=1MB
log4j.appender.file.MaxBackupIndex=1
log4j.appender.file.layout=org.apache.log4j.PatternLayout
log4j.appender.file.layout.ConversionPattern=%d{ABSOLUTE} %5p %c{1}:%L - %m%n

# Direct log messages to stdout
log4j.appender.stdout=org.apache.log4j.ConsoleAppender
log4j.appender.stdout.Target=System.out
log4j.appender.stdout.layout=org.apache.log4j.PatternLayout
log4j.appender.stdout.layout.ConversionPattern=%d{ABSOLUTE} %5p %c{1}:%L - %m%n
weblogic.xml 
<?xml version="1.0" encoding="UTF-8"?>
<wls:weblogic-web-app xmlns:wls="http://xmlns.oracle.com/weblogic/weblogic-web-app" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:schemaLocation="http://java.sun.com/xml/ns/javaee http://java.sun.com/xml/ns/javaee/web-app_2_5.xsd http://xmlns.oracle.com/weblogic/weblogic-web-app http://xmlns.oracle.com/weblogic/weblogic-web-app/1.4/weblogic-web-app.xsd">
    <wls:weblogic-version>12.1.1</wls:weblogic-version>
    <wls:context-root>testSLF4JWAR</wls:context-root>
    <wls:container-descriptor>
            <wls:prefer-application-packages>
                <wls:package-name>org.slf4j</wls:package-name>
            </wls:prefer-application-packages>
     </wls:container-descriptor>
</wls:weblogic-web-app>
Test servlet 
package dave;

import java.io.IOException;
import java.io.PrintWriter;

import javax.servlet.ServletException;
import javax.servlet.annotation.WebServlet;
import javax.servlet.http.HttpServlet;
import javax.servlet.http.HttpServletRequest;
import javax.servlet.http.HttpServletResponse;

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;


/**
 * Servlet implementation class TestSlf4jLogger
 */
@WebServlet("/TestSlf4jLogger")
public class TestSlf4jLogger extends HttpServlet {
    private static final long serialVersionUID = 1L;
    
    final Logger logger = LoggerFactory.getLogger(TestSlf4jLogger.class);
            
    /**
     * @see HttpServlet#HttpServlet()
     */
    public TestSlf4jLogger() {
        super();
        // TODO Auto-generated constructor stub
    }

    /**
     * @see HttpServlet#doGet(HttpServletRequest request, HttpServletResponse
     *      response)
     */
    protected void doGet(HttpServletRequest request,
            HttpServletResponse response) throws ServletException, IOException {
        PrintWriter out = response.getWriter();
        out.println("Hello World");
        logger.debug("Hello World - debug");
        logger.info("Hello World- info");
        
    }

    /**
     * @see HttpServlet#doPost(HttpServletRequest request, HttpServletResponse
     *      response)
     */
    protected void doPost(HttpServletRequest request,
            HttpServletResponse response) throws ServletException, IOException {
        // TODO Auto-generated method stub
    }

}
Weblogic log with added ejb module 
LF4J: Class path contains multiple SLF4J bindings.
SLF4J: Found binding in [jar:file:/usr/app/weblogic121/modules/org.slf4j.jdk14_1.6.1.0.jar!/org/slf4j/impl/StaticLoggerBinder.class]
SLF4J: Found binding in [zip:/home/dave/workspace38/testSLF4jEAR/EarContent/APP-INF/lib/slf4j-log4j12-1.6.6.jar!/org/slf4j/impl/StaticLoggerBinder.class]
SLF4J: Found binding in [zip:/home/dave/workspace38/testSLF4JWAR/WebContent/WEB-INF/lib/slf4j-log4j12-1.6.6.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]
log4j: Parsing for [root] with value=[DEBUG, file, stdout].
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}:%L - %m%n].
log4j: End of parsing for "file".
log4j: Setting property [file] to [/tmp/testSLF4j.log].
log4j: Setting property [maxBackupIndex] to [1].
log4j: Setting property [maxFileSize] to [1MB].
log4j: setFile called: /tmp/testSLF4j.log, true
log4j: setFile ended
log4j: Parsed "file" options.
log4j: Parsing appender named "stdout".
log4j: Parsing layout options for "stdout".
log4j: Setting property [conversionPattern] to [%d{ABSOLUTE} %5p %c{1}:%L - %m%n].
log4j: End of parsing for "stdout".
log4j: Setting property [target] to [System.out].
log4j: Parsed "stdout" options.
log4j: Finished configuring.
00:07:24,873 DEBUG TestSlf4jLogger:46 - Hello World - debug
00:07:24,928  INFO TestSlf4jLogger:47 - Hello World- info
TestSLF4JService: Hello World
Aug 4, 2012 12:07:25 AM dave.TestSLF4JBean testLogger
INFO: TestSLF4JService: Hello World- info
Weblogic log after adding prefer-application-packages into weblogic-application.xml descriptor 
00:14:48,273 DEBUG TestSlf4jLogger:46 - Hello World - debug
00:14:48,277  INFO TestSlf4jLogger:47 - Hello World- info
SLF4J: Class path contains multiple SLF4J bindings.
SLF4J: Found binding in [jar:file:/usr/app/weblogic121/modules/org.slf4j.jdk14_1.6.1.0.jar!/org/slf4j/impl/StaticLoggerBinder.class]
SLF4J: Found binding in [zip:/home/dave/workspace38/testSLF4jEAR/EarContent/APP-INF/lib/slf4j-log4j12-1.6.6.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]
TestSLF4JService: Hello World
00:14:48,297 DEBUG TestSLF4JBean:26 - TestSLF4JService: Hello World - debug
00:14:48,297  INFO TestSLF4JBean:27 - TestSLF4JService: Hello World- info
weblogic-application.xml descriptor 
<?xml version="1.0" encoding="UTF-8"?>
<wls:weblogic-application xmlns:wls="http://xmlns.oracle.com/weblogic/weblogic-application" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:schemaLocation="http://java.sun.com/xml/ns/javaee http://java.sun.com/xml/ns/javaee/javaee_5.xsd http://xmlns.oracle.com/weblogic/weblogic-application http://xmlns.oracle.com/weblogic/weblogic-application/1.4/weblogic-application.xsd">
    <!--weblogic-version:12.1.1-->
    <wls:application-param>
        <wls:param-name>webapp.encoding.default</wls:param-name>
        <wls:param-value>UTF-8</wls:param-value>
    </wls:application-param>
    <wls:prefer-application-packages>
        <wls:package-name>org.slf4j</wls:package-name>
    </wls:prefer-application-packages>
</wls:weblogic-application>
EAR content 
dave@dave workspace38]$ ls testSLF4jEAR/EarContent/APP-INF/lib
log4j-1.2.16.jar  slf4j-api-1.6.6.jar  slf4j-log4j12-1.6.6.jar
[dave@dave workspace38]$ ls -1 testSLF4jEAR/EarContent/APP-INF/lib
log4j-1.2.16.jar
slf4j-api-1.6.6.jar
slf4j-log4j12-1.6.6.jar
[dave@dave workspace38]$ ls -1 testSLF4jEAR/EarContent/META-INF
weblogic-application.xml
test Session Bean 
package dave;

import javax.ejb.Stateless;

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

/**
 * Session Bean implementation class TestSLF4JService
 */
@Stateless
public class TestSLF4JBean implements TestSLF4JService {
    
    final Logger logger = LoggerFactory.getLogger(TestSLF4JBean.class);

    /**
     * Default constructor. 
     */
    public TestSLF4JBean() {
        // TODO Auto-generated constructor stub
    }
    
    public void testLogger(){
        
        System.out.println("TestSLF4JService: Hello World");
        logger.debug("TestSLF4JService: Hello World - debug");
        logger.info("TestSLF4JService: Hello World- info");
        
    }

}
injection of Session Bean in Servlet 

    @EJB
    TestSLF4JService service;
    
    
    /**
     * @see HttpServlet#doGet(HttpServletRequest request, HttpServletResponse
     *      response)
     */
    protected void doGet(HttpServletRequest request,
            HttpServletResponse response) throws ServletException, IOException {
        PrintWriter out = response.getWriter();
        out.println("Hello World");
        logger.debug("Hello World - debug");
        logger.info("Hello World- info");
        
        service.testLogger();
        
    }
Posted by at
Labels: ,

1 comment:

  1. Rakesh PrajapatiApril 27, 2017 at 3:14 AM

    I hit this issue today and struggled for half day. Finally landed on this post and root cause was same for me too. Adding entry in weblogic-application.xml fixed the issue.

    Cheers!
    Rakesh Prajapati

    ReplyDelete

Subscribe to: Post Comments (Atom)