SLF4J + Logback does not log in WildFly

java logback wildfly
Leos Literak picture Leos Literak · Apr 15, 2014 · Viewed 21.3k times · Source

I run web application in WildFly 8 and for some reason it does not log. I use SLF4J with LOGBACK. The log file is created on deploy but it is empty. I do not see my log statements in wildfly logs either.

The class contains:

package com.blah.oops;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

static final Logger log = LoggerFactory.getLogger(EndpointImpl.class);

log.debug("request called");

War contains:

  • WEB-INF\lib\slf4j-api-1.7.5.jar
  • WEB-INF\lib\logback-classic-1.1.1.jar
  • WEB-INF\lib\logback-core-1.1.1.jar
  • WEB-INF\classes\logback.xml

Configuration file logback.xml contains:

<configuration scan="true" scanPeriod="10 seconds">
    <appender name="FILE" class="ch.qos.logback.core.FileAppender">
        <file>${LOG_PATH}/backend-main.log</file>
        <encoder>
            <pattern>%date %level [%thread] %logger{10} %msg%n</pattern>
        </encoder>
    </appender>

    <!-- PROFILER configuration -->
    <turboFilter class="ch.qos.logback.classic.turbo.MarkerFilter">
        <Marker>PROFILER</Marker>
        <OnMatch>ACCEPT</OnMatch>
        <!--  <OnMatch>DENY</OnMatch> -->
    </turboFilter>

    <logger name="org.eclipse.jetty.util.log" level="info"/>
    <logger name="com.blah" level="debug"/>
    <logger name="org.apache.cxf" level="warn"/>

    <root level="info">
        <appender-ref ref="FILE"/>
    </root>
</configuration>

console.log contains logback initialization:

.[0m.[0m10:19:52,716 INFO  [stdout] (MSC service thread 1-2) 10:19:52,489 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback.groovy]
.[0m.[0m10:19:52,717 INFO  [stdout] (MSC service thread 1-2) 10:19:52,489 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback-test.xml]
.[0m.[0m10:19:52,717 INFO  [stdout] (MSC service thread 1-2) 10:19:52,490 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Found resource [logback.xml] at [vfs:/content/backend.war/WEB-INF/classes/logback.xml]
.[0m.[0m10:19:52,717 INFO  [stdout] (MSC service thread 1-2) 10:19:52,501 |-INFO in ch.qos.logback.core.joran.spi.ConfigurationWatchList@666dc663 - URL [vfs:/content/backend.war/WEB-INF/classes/logback.xml] is not of type file
.[0m.[0m10:19:52,717 INFO  [stdout] (MSC service thread 1-2) 10:19:52,524 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - debug attribute not set
.[0m.[0m10:19:52,717 INFO  [stdout] (MSC service thread 1-2) 10:19:52,529 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - Setting ReconfigureOnChangeFilter scanning period to 10 seconds
.[0m.[0m10:19:52,718 INFO  [stdout] (MSC service thread 1-2) 10:19:52,529 |-INFO in ReconfigureOnChangeFilter{invocationCounter=0} - Will scan for changes in [[]] every 10 seconds.
.[0m.[0m10:19:52,718 INFO  [stdout] (MSC service thread 1-2) 10:19:52,529 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - Adding ReconfigureOnChangeFilter as a turbo filter
.[0m.[0m10:19:52,718 INFO  [stdout] (MSC service thread 1-2) 10:19:52,532 |-ERROR in ch.qos.logback.core.joran.action.PropertyAction - Could not find resource [acquirer.properties].
.[0m.[0m10:19:52,718 INFO  [stdout] (MSC service thread 1-2) 10:19:52,532 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.core.ConsoleAppender]
.[0m.[0m10:19:52,718 INFO  [stdout] (MSC service thread 1-2) 10:19:52,535 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [jettyConsole]
.[0m.[0m10:19:52,718 INFO  [stdout] (MSC service thread 1-2) 10:19:52,572 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.core.FileAppender]
.[0m.[0m10:19:52,719 INFO  [stdout] (MSC service thread 1-2) 10:19:52,573 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [FILE]
.[0m.[0m10:19:52,719 INFO  [stdout] (MSC service thread 1-2) 10:19:52,575 |-INFO in ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Assuming default type [ch.qos.logback.classic.encoder.PatternLayoutEncoder] for [encoder] property
.[0m.[0m10:19:52,719 INFO  [stdout] (MSC service thread 1-2) 10:19:52,576 |-INFO in ch.qos.logback.core.FileAppender[FILE] - File property is set to [/var/log/blah/backend-main.log]
.[0m.[0m10:19:52,719 INFO  [stdout] (MSC service thread 1-2) 10:19:52,591 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [org.eclipse.jetty.util.log] to INFO
.[0m.[0m10:19:52,719 INFO  [stdout] (MSC service thread 1-2) 10:19:52,592 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [com.blah] to DEBUG
.[0m.[0m10:19:52,719 INFO  [stdout] (MSC service thread 1-2) 10:19:52,592 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [org.apache.cxf] to WARN
.[0m.[0m10:19:52,720 INFO  [stdout] (MSC service thread 1-2) 10:19:52,592 |-INFO in ch.qos.logback.classic.joran.action.RootLoggerAction - Setting level of ROOT logger to INFO
.[0m.[0m10:19:52,720 INFO  [stdout] (MSC service thread 1-2) 10:19:52,713 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [FILE] to Logger[ROOT]
.[0m.[0m10:19:52,720 INFO  [stdout] (MSC service thread 1-2) 10:19:52,713 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - End of configuration.
.[0m.[0m10:19:52,720 INFO  [stdout] (MSC service thread 1-2) 10:19:52,714 |-INFO in ch.qos.logback.classic.joran.JoranConfigurator@30fbc21e - Registering current configuration as safe fallback point

It seems to me that LOGBACK is successfully configured. But log messages are lost. Any idea what is going there? It makes me no sense.

Answer

tmarwen picture tmarwen · Apr 15, 2014

WildFly adds slf4j as a default logging dependency Have you tried excluding the main implementation in jboss-deployment-structure.xml descriptor (It should go under the META-INF directory). This can be done with below lines:

<?xml version="1.0" encoding="UTF-8"?>
<jboss-deployment-structure>
  <deployment>
    <exclusions>
      <module name="org.apache.commons.logging" />
      <module name="org.apache.log4j" />
      <module name="org.jboss.logging" />
      <module name="org.jboss.logging.jul-to-slf4j-stub" />
      <module name="org.jboss.logmanager" />
      <module name="org.jboss.logmanager.log4j" />
      <module name="org.slf4j" />
      <module name="org.slf4j.impl" />
    </exclusions>
  </deployment>
</jboss-deployment-structure>

Related questions

How can I configure Logback to log different levels for a logger to different destinations?

How can I configure Logback to log different levels for a logger to different destinations? For example, given the following Logback configuration, will Logback record INFO messages to STDOUT and ERROR messages to STDERR? (Note that this example is a …

Read More
How to change root logging level programmatically for logback

I have the following logback.xml file: <configuration debug="true"> <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender"> <encoder> <pattern>%d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%…

Read More
Logging framework incompatibility

I'm building a small Java app and hoping to use logback for logging. My app has a dependency on an older project that does its logging via org.apache.commons | com.springsource.org.apache.commons.logging | 1.1.1 ...so my plan was …

Read More