1

It seems, that I cannot exclude the JBoss/ Wildfly Logging Subsystem.

I have an Java EE ear and would like to use slf4j API together with log4J2 Implementation.

My intention was to disable JBoss logging subsystem to let my slf4j log4j2 implementation handle the logging. But I still get duplicate handling of stdout:

12:55:00,820 INFO [stdout] (Thread-316) 12:55:00 INFO

the ear structure is as follows:

d-----       03.07.2020     12:53                lib
d-----       03.07.2020     12:53                META-INF
-a----       03.07.2020     12:53          13238 org.example-helloworld-ejb-1.0-SNAPSHOT.jar
-a----       03.07.2020     12:53        3598717 org.example-helloworld-web-1.0-SNAPSHOT.war

the lib directory:

-a----       03.07.2020     12:53          26586 javax.annotation-javax.annotation-api-1.3.2.jar
-a----       03.07.2020     12:53          63679 javax.ejb-javax.ejb-api-3.2.2.jar
-a----       03.07.2020     12:53          28016 javax.transaction-javax.transaction-api-1.3.jar
-a----       03.07.2020     12:53         126898 javax.ws.rs-javax.ws.rs-api-2.1.1.jar
-a----       03.07.2020     12:53         292301 org.apache.logging.log4j-log4j-api-2.13.3.jar
-a----       03.07.2020     12:53        1714164 org.apache.logging.log4j-log4j-core-2.13.3.jar
-a----       03.07.2020     12:53          23590 org.apache.logging.log4j-log4j-slf4j-impl-2.13.3.jar
-a----       03.07.2020     12:53           1526 org.example-helloworld-config-1.0-SNAPSHOT.jar
-a----       03.07.2020     12:53           6071 org.example-helloworld-model-1.0-SNAPSHOT.jar
-a----       03.07.2020     12:53          41203 org.slf4j-slf4j-api-1.7.25.jar

the META-INF directory:

-a---- 03.07.2020 12:53 470 jboss-deployment-structure.xml

content of jboss-deployment-structure.xml:

<jboss-deployment-structure
        xmlns="urn:jboss:deployment-structure:1.2"
        xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance">


    <deployment>

        <dependencies>
            <module name="config"/>
        </dependencies>

    <exclude-subsystems>
        <subsystem name="logging" />
    </exclude-subsystems>

    </deployment>

</jboss-deployment-structure>

Furthermore I modified the standalone.xml:

[..]
 <profile>
        <subsystem xmlns="urn:jboss:domain:logging:8.0">
            <add-logging-api-dependencies value="false"/>
            <console-handler name="CONSOLE">
                <formatter>
[..]

My log4j2.xml:

<?xml version="1.0" encoding="UTF-8"?>
<Configuration monitorInterval="3" status="INFO">
  <Appenders>
    <Console name="Console1" target="SYSTEM_OUT">
      <PatternLayout pattern="%d{HH:mm:ss.SSS} [%t] %-5level %logger{1.}} - %msg%n"/>
    </Console>
  </Appenders>
  <Loggers>
    <Root level="all">
      <AppenderRef ref="Console1"/>
    </Root>
  </Loggers>
</Configuration>

NOTE: I also tried using logback as the logging implementation. This also produces duplicately formatted output to stdout.#

Any hints to solve/ workaround this highly appreciated!

kerner1000
  • 3,382
  • 1
  • 37
  • 57
  • What does your log4j2 configuration look like? It looks like you're using a console appender which would result the output you're seeing. BTW there is no `logmanager` subsystem so that can be removed. – James R. Perkins Jul 06 '20 at 18:45
  • many thanks for the reply! Yes, I have a console appender registered. Is this not correct, if I want to write to STDOUT? – kerner1000 Jul 07 '20 at 15:48

1 Answers1

2

If you want to use log4j-core, the log4j2 log manager implementation, in your deployment with slf4j you'll need to include the correct dependencies in your deployment which you appear to be doing.

You'll then need to tell WildFly to not add the logging dependencies to your deployment. The following options will exclude the logging dependencies from being added to your deployment

  1. Use a jboss-deployment-structure.xml to exclude the logging subsystem
<?xml version="1.0" encoding="UTF-8"?>
<jboss-deployment-structure>
    <deployment>
        <exclude-subsystems>
            <subsystem name="logging"/>
        </exclude-subsystems>
    </deployment>
</jboss-deployment-structure>
  1. Change the add-logging-api-dependencies attribute to false. Note this affects all deployments.
/subsystem=logging:write-attribute(name=add-logging-api-dependencies, value=false)
  1. Use a jboss-deployment-structure.xml to exclude each logging module. Option 1 is a lot easier than this though.

The reason for the duplicate output is WildFly wraps System.out and System.err in a logger with the respective logger names of stdout and stderr. To work around this you'd need to add a new formatter, console-handler and logger to remove the default console handlers format.

/subsystem=logging/pattern-formatter=stdout:add(pattern="%s%n")
/subsystem=logging/console-handler=stdout:add(named-formatter=stdout, autoflush=true, target=System.out)
/subsystem=logging/logger=stdout:add(use-parent-handlers=false, handlers=[stdout])
James R. Perkins
  • 16,800
  • 44
  • 60
  • Many thanks for the help! Option 2: I understand but how will a secondary console handler help with this, can I somehow "wire" the handlers from the log4j2.xml to the logging subsystem handler? – kerner1000 Jul 08 '20 at 07:05
  • Option 1: Do I still have to "exclude" the logging subsystem? – kerner1000 Jul 08 '20 at 07:08
  • I tried a minimal working example using slf4j and logback. the output is not different: `10:06:37,449 INFO [stdout] (default task-2) 10:06:37.446 [default task-2] TRACE o.e.websocket.WebsocketEndpoint - Openend new session` – kerner1000 Jul 08 '20 at 08:08
  • The problem is that WildFly wraps `System.out` and `System.err` in a logger which the `ConsoleAppender` writes to. Adding the secondary console-handler with the `%s%n` pattern just works around this by not adding additional formatting. – James R. Perkins Jul 08 '20 at 14:47
  • I'm sorry I missed the slf4j for part of the question. I'll update the answer to actually answer the question for using slf4j and log4j2 in your deployment. – James R. Perkins Jul 08 '20 at 14:52
  • When applying those changes to our prod system (log subsystem urn:jboss:domain:logging:6.0) I get the following exception: `[standalone@localhost:9990 /] /subsystem=logging/pattern-formatter=stdout:add(pattern="%s%n") {"outcome" => "success"} [standalone@localhost:9990 /] /subsystem=logging/console-handler=stdout:add(named-formatter=stdout, autoflush=true, target=System.out) { "outcome" => "failed", "failure-description" => "WFLYCTL0158: Operation handler failed: java.lang.IllegalArgumentException: Formatter \"stdout\" is not found", "rolled-back" => true }` – kerner1000 Jul 08 '20 at 16:19
  • That's odd since you've clearly added it :) What version of WildFly is it? – James R. Perkins Jul 08 '20 at 17:49
  • On WildFly 20 it works nicely, on jboss eap 7.2.5 i get this error. To debug, I started with a fresh `standalone.xml` as well as copied from WildFly 20. The error persists. standalone.xml says this: `urn:jboss:domain:logging:6.0` – kerner1000 Jul 08 '20 at 18:55
  • 1
    Interesting. Looks like a bug. A workaround would be to use `/subsystem=logging/console-handler=stdout:add(formatter="%s%n", autoflush=true, target=System.out)` and just skip the `pattern-formatter` part. Or juts name the formatter something like `STDOUT` basically anything other than the same name/case as the handler. – James R. Perkins Jul 08 '20 at 20:30
  • @JamesR.Perkins I have the exact same issue from OP. I tried to exclude but nothing happens. what is the correct path to put the jboss-deployment-structure.xml ? – florin Mar 07 '22 at 15:01
  • For a WAR it would go in the `WEB-INF` directory. https://docs.wildfly.org/26/Developer_Guide.html#jboss-deployment-structure-file. Note that if your deployment is an EAR you'll need to exclude it for sub-deployments too. – James R. Perkins Mar 07 '22 at 16:26
  • @JamesR.Perkins I've put it in the right folder. I have the same issue but the solutions in this thread didn't help. Maybe it's something different in my scenario: https://stackoverflow.com/questions/71378338/java-ee-duplicate-info-on-same-log-line – florin Mar 07 '22 at 20:45