Kohei Nozaki's blog 

Logging with log4j appenders

Posted on Thursday Feb 13, 2014 at 10:59AM in Technology

  • We can use WildFly's logging mechanism with log4j appenders.

Environment

  • WildFly 8.0.0.Final
  • Oracle JDK7u51
  • OS X 10.9.2

Precondition

  • Ensure we already have a logger named “hoge.logger1”.
  • I will use this servlet to logging test.
package logger;

import java.io.IOException;

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

@WebServlet("/")
public class LogServlet extends HttpServlet {
    private static final org.slf4j.Logger SLF4J_LOGGER1 = org.slf4j.LoggerFactory.getLogger("hoge.logger1");

    protected void doGet(HttpServletRequest request, HttpServletResponse response) throws ServletException, IOException {
        StringBuilder sb = new StringBuilder(1200);
        for(int i=0; i<1200; i++){
            sb.append(i%10);
        }

        SLF4J_LOGGER1.info("0-1199: {}", sb);
        SLF4J_LOGGER1.info("exception logging test", new AssertionError("test"));
    }
}
  • Log4j is shipped with out-of-box WildFly8 so we don't need any preparation about log4j.

Defining with org.apache.log4j.FileAppender

Create an custom-handler named “LOG4J_FILE”

/subsystem=logging/custom-handler=LOG4J_FILE:add( \
 class="org.apache.log4j.FileAppender", \
 module="org.apache.log4j", \
 named-formatter=PATTERN, \
 level=INFO, \
 properties={ \
  File="/tmp/log4jtest.log", \
  Append=true})

Assign the handler to a logger

/subsystem=logging/logger=hoge.logger1:assign-handler(name=LOG4J_FILE)

Output

2014-03-07 14:57:46,538 INFO  [hoge.logger1] (default task-10) 0-1199: 012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789
2014-03-07 14:57:46,538 INFO  [hoge.logger1] (default task-10) exception logging test: java.lang.AssertionError: test
        at logger.LogServlet.doGet(LogServlet.java:22) [classes:]
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:687) [jboss-servlet-api_3.1_spec-1.0.0.Final.jar:1.0.0.Final]
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:790) [jboss-servlet-api_3.1_spec-1.0.0.Final.jar:1.0.0.Final]
        at io.undertow.servlet.handlers.ServletHandler.handleRequest(ServletHandler.java:85) [undertow-servlet-1.0.0.Final.jar:1.0.0.Final]
        at io.undertow.servlet.handlers.security.ServletSecurityRoleHandler.handleRequest(ServletSecurityRoleHandler.java:61) [undertow-servlet-1.0.0.Final.jar:1.0.0.Final]
        at io.undertow.servlet.handlers.ServletDispatchingHandler.handleRequest(ServletDispatchingHandler.java:36) [undertow-servlet-1.0.0.Final.jar:1.0.0.Final]
        at org.wildfly.extension.undertow.security.SecurityContextAssociationHandler.handleRequest(SecurityContextAssociationHandler.java:78)
        at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:25) [undertow-core-1.0.0.Final.jar:1.0.0.Final]
        at io.undertow.servlet.handlers.security.SSLInformationAssociationHandler.handleRequest(SSLInformationAssociationHandler.java:113) [undertow-servlet-1.0.0.Final.jar:1.0.0.Final]
        at io.undertow.security.handlers.AuthenticationCallHandler.handleRequest(AuthenticationCallHandler.java:52) [undertow-core-1.0.0.Final.jar:1.0.0.Final]
        at io.undertow.security.handlers.AbstractConfidentialityHandler.handleRequest(AbstractConfidentialityHandler.java:45) [undertow-core-1.0.0.Final.jar:1.0.0.Final]
        at io.undertow.servlet.handlers.security.ServletConfidentialityConstraintHandler.handleRequest(ServletConfidentialityConstraintHandler.java:61) [undertow-servlet-1.0.0.Final.jar:1.0.0.Final]
        at io.undertow.servlet.handlers.security.CachedAuthenticatedSessionHandler.handleRequest(CachedAuthenticatedSessionHandler.java:70) [undertow-servlet-1.0.0.Final.jar:1.0.0.Final]
        at io.undertow.security.handlers.SecurityInitialHandler.handleRequest(SecurityInitialHandler.java:76) [undertow-core-1.0.0.Final.jar:1.0.0.Final]
        at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:25) [undertow-core-1.0.0.Final.jar:1.0.0.Final]
        at org.wildfly.extension.undertow.security.jacc.JACCContextIdHandler.handleRequest(JACCContextIdHandler.java:61)
        at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:25) [undertow-core-1.0.0.Final.jar:1.0.0.Final]
        at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:25) [undertow-core-1.0.0.Final.jar:1.0.0.Final]
        at io.undertow.servlet.handlers.ServletInitialHandler.handleFirstRequest(ServletInitialHandler.java:240) [undertow-servlet-1.0.0.Final.jar:1.0.0.Final]
        at io.undertow.servlet.handlers.ServletInitialHandler.dispatchRequest(ServletInitialHandler.java:227) [undertow-servlet-1.0.0.Final.jar:1.0.0.Final]
        at io.undertow.servlet.handlers.ServletInitialHandler.access$000(ServletInitialHandler.java:73) [undertow-servlet-1.0.0.Final.jar:1.0.0.Final]
        at io.undertow.servlet.handlers.ServletInitialHandler$1.handleRequest(ServletInitialHandler.java:146) [undertow-servlet-1.0.0.Final.jar:1.0.0.Final]
        at io.undertow.server.Connectors.executeRootHandler(Connectors.java:168) [undertow-core-1.0.0.Final.jar:1.0.0.Final]
        at io.undertow.server.HttpServerExchange$1.run(HttpServerExchange.java:687) [undertow-core-1.0.0.Final.jar:1.0.0.Final]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) [rt.jar:1.7.0_51]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) [rt.jar:1.7.0_51]
        at java.lang.Thread.run(Thread.java:744) [rt.jar:1.7.0_51]

Defining with org.apache.log4j.net.SyslogAppender

Create an custom-handler named “LOG4J_SYSLOG”

/subsystem=logging/custom-handler=LOG4J_SYSLOG:add( \
 class="org.apache.log4j.net.SyslogAppender", \
 module="org.apache.log4j", \
 formatter="%-5p [%c] (%t) %s%E%n", \
 level=INFO, \
 properties={ \
  Header=true, \
  syslogHost="localhost:514", \
  facility="local1", \
  facilityPrinting=false})

Assign the handler to a logger

/subsystem=logging/logger=hoge.logger1:assign-handler(name=LOG4J_SYSLOG)

Output

Mar  7 15:02:33 kyle-no-MacBook.local INFO  [hoge.logger1] (default task-1) 0-119]: 0123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456...
Mar  7 15:02:33 kyle-no-MacBook.local Unknown: ...78901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789
Mar  7 15:02:33 kyle-no-MacBook.local INFO  [hoge.logger1] (default task-1) exception logging tes]: java.lang.AssertionError: test
                at logger.LogServlet.doGet(LogServlet.java:22) [classes:]
                at javax.servlet.http.HttpServlet.service(HttpServlet.java:687) [jboss-servlet-api_3.1_spec-1.0.0.Final.jar:1.0.0.Final]
                at javax.servlet.http.HttpServlet.service(HttpServlet.java:790) [jboss-servlet-api_3.1_spec-1.0.0.Final.jar:1.0.0.Final]
                at io.undertow.servlet.handlers.ServletHandler.handleRequest(ServletHandler.java:85) [undertow-servlet-1.0.0.Final.jar:1.0.0.Final]
                at io.undertow.servlet.handlers.security.ServletSecurityRoleHandler.handleRequest(ServletSecurityRoleHandler.java:61) [undertow-servlet-1.0.0.Final.jar:1.0.0.Final]
                at io.undertow.servlet.handlers.ServletDispatchingHandler.handleRequest(ServletDispatchingHandler.java:36) [undertow-servlet-1.0.0.Final.jar:1.0.0.Final]
Mar  7 15:02:33 kyle-no-MacBook.local ...est(SecurityContextAssociationHandler.java: 78)
                at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:25) [undertow-core-1.0.0.Final.jar:1.0.0.Final]
                at io.undertow.servlet.handlers.security.SSLInformationAssociationHandler.handleRequest(SSLInformationAssociationHandler.java:113) [undertow-servlet-1.0.0.Final.jar:1.0.0.Final]
                at io.undertow.security.handlers.AuthenticationCallHandler.handleRequest(AuthenticationCallHandler.java:52) [undertow-core-1.0.0.Final.jar:1.0.0.Final]
                at io.undertow.security.handlers.AbstractConfidentialityHandler.handleRequest(AbstractConfidentialityHandler.java:45) [undertow-core-1.0.0.Final.jar:1.0.0.Final]
                at io.undertow.servlet.handlers.security.ServletConfidentialityConstraintHandler.handleRequest(ServletConfidentialityConstraintHandler.java:61) [undertow-servlet-1.0.0.Final.jar:1.0.0.Final]
Mar  7 15:02:33 kyle-no-MacBook.local ...Handler.handleRequest(CachedAuthenticatedSessionHandler.java: 70) [undertow-servlet-1.0.0.Final.jar:1.0.0.Final]
                at io.undertow.security.handlers.SecurityInitialHandler.handleRequest(SecurityInitialHandler.java:76) [undertow-core-1.0.0.Final.jar:1.0.0.Final]
                at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:25) [undertow-core-1.0.0.Final.jar:1.0.0.Final]
                at org.wildfly.extension.undertow.security.jacc.JACCContextIdHandler.handleRequest(JACCContextIdHandler.java:61)
                at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:25) [undertow-core-1.0.0.Final.jar:1.0.0.Final]
                at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:25) [undertow-core-1.0.0.Final.jar:1.0.0.Final]
                at io.undertow.servlet.handlers.ServletInitialHandler.handleFirstRequest(ServletInitialHandler.java:240) [undertow-servlet-1.0.0.Final.jar:1.0.0.Final]
Mar  7 15:02:33 kyle-no-MacBook.local ...ertow.servlet.handlers.ServletInitialHandler.dispatchRequest(ServletInitialHandler.java: 227) [undertow-servlet-1.0.0.Final.jar:1.0.0.Final]
                at io.undertow.servlet.handlers.ServletInitialHandler.access$000(ServletInitialHandler.java:73) [undertow-servlet-1.0.0.Final.jar:1.0.0.Final]
                at io.undertow.servlet.handlers.ServletInitialHandler$1.handleRequest(ServletInitialHandler.java:146) [undertow-servlet-1.0.0.Final.jar:1.0.0.Final]
                at io.undertow.server.Connectors.executeRootHandler(Connectors.java:168) [undertow-core-1.0.0.Final.jar:1.0.0.Final]
                at io.undertow.server.HttpServerExchange$1.run(HttpServerExchange.java:687) [undertow-core-1.0.0.Final.jar:1.0.0.Final]
                at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) [rt.jar:1.7.0_51]
                at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) [rt.jar:1.7.0_51]
                at java.lang.Thread.run(Thread.java:744) [rt.jar:1.7.0_51]

Conclusion

  • Anyway, we can use log4j appenders with custom-handler surely.
  • But something goes wrong with exception logging with SyslogAppender.
    • Some parts of stacktraces were lost.
    • The last digit of message strings are replaced by ']'.

References

  1. [AS7-4925] Log4j appenders should also be allowed for custom handlers - JBoss Issue Tracker
  2. Log4jAppenderHandler usage | Community
  3. #8059525 - Pastie
  4. Use Log4j appender as custom-handler in AS 7.1…. | Community
  5. Magnus K Karlsson: How to setup log4j Syslog Appender in JBoss EAP 6
  6. Programming fun at startup: log4j TCP SyslogAppender

Comments [0]

Tags: wildfly

No one has commented yet.

Leave a Comment

HTML Syntax: NOT allowed

Welcome

You're viewing a weblog entry titled Logging with log4j appenders. If you like this entry you might want to:

del.icio.us Bookmark it submit to dig digg.com Digg it

This is just one entry in the weblog Kohei Nozaki's blog. Why don't you visit the main page of the weblog?

Related entries