Duplicated pattern in console

[sanova]

i'm trying to migrate to log4j 2. I configured it and now i have a simple log system working in the console.
I don't understand why, despite having set a pattern in the configuration file, an unexpected pattern is displayed in the output messages.

Here my log4j2.properties file:

# Name of the configuration
name = PropertiesConfig

rootLogger = INFO, STDOUT

# Direct log messages to stdout
appender.console.type = Console
appender.console.name = STDOUT
appender.console.layout.type = PatternLayout
appender.console.layout.pattern = [%-5p] %d{yyyy-MM-dd HH:mm:ss.SSS} %c{1}:%L - %m%n

# Log Level
logger.siag.name = it.siag
logger.siag.level = TRACE
#logger.siag.additivity = false
#logger.siag.appenderRef.console.ref = STDOUT

And here the output i see in the console:

15:53:08,443 INFO  [stdout] (default task-2) [TRACE] 2023-12-30 15:53:08.441 Proxy:133 - Optional basic auth specified... adding BasicAuth credentials
15:53:08,547 INFO  [stdout] (default task-3) [DEBUG] 2023-12-30 15:53:08.547 Proxy:242 - Finished proxiedRequest url:https://.....
15:53:08,554 INFO  [stdout] (default task-2) [DEBUG] 2023-12-30 15:53:08.554 Proxy:242 - Finished proxiedRequest url:https://......
15:53:16,580 INFO  [stdout] (pool-15-thread-1) [TRACE] 2023-12-30 15:53:16.580 FMEJobMonitorListener:85 - FMEScheduler: Start monitoring job execution

i mean this part of the output message:

15:53:08,443 INFO [stdout] (default task-2)

Is it normal? is there a way to prevent this behavior?

Thanks in advanced

[ppkarwasz]

What environment are you running in? Several application servers call System.setOut and wrap all calls to System.out.

[sanova]

The application runs in a jboss environment. But the same application with log4j 1 doesn't have this behavior.
What i did was replace Log4j 1 with version 2.

If i uncomment the line:

logger.siag.additivity = false

it doesn't display eny message. So it seems it's only Log4j writing; otherwise, I think I should see at least that part of the message. Is that correct?

[ppkarwasz]

The "additivity" setting decides whether messages sent to all children of the "it.siag" logger should be also sent to the root logger's appenders (in your case STDOUT). Since you didn't configure any appenders for "it.siag" itself (the logger.siag.appenderRef.console.ref line is commented), uncommenting the logger.siag.additivity line will effectively ignore those events.

Regarding the "15:53:08,443 INFO [stdout] (default task-2)" prefix and looking at this StackOverlow question it seems that Wildfly/JBoss AS redirects all access to System.out to its own console appender. I don't know how to configure it, but @jamezp certainly does.

The console appender does have a direct="true" option, but that might mess up the logs of the entire server.

[sanova]

Thank you very much, You have clarified the concept very well for me.
And yes, you are right. It seems Jboss/Wildfly adds its own message to STDOUT. Indeed setting a log file appender it writes message with the right layout following the pattern i set in the configuration file and i don't see that part of message in the log file.
It is not clear why i didn't see it with log4j1. Anyway it's not important and it's not a real problem to see it only in the console.

Thank you for your answer. I will try to find a solution reading the post you suggested me.

[jamezp]

The reason you don't see it with log4j1 is JBoss EAP/WildFly use a forked version of log4j where the ConsoleAppender is updated to write directly to System.out. We do not fork log4j-core because WildFly itself does not ship with log4j-core, but its own implementation of the log4j-api which delegates to the jboss-logmanager.

Looking at the log4j2 ConsoleAppender, I do think using direct="true" would likely work. It's using the FileDescriptor which is effectively what the forked log4j1 ConsoleAppender is doing.

Note that with WildFly 27+ log4j1 is no longer included in WildFly.