I am middle in developing a custom log4j2 logger for the Oracle SOA Suite. The class is a fat or self-contained jar. It has a log4j2.xml configuration file with a logger and appender
<?xml version="1.0" encoding="UTF-8"?>
<configuration status="error" name="JSONLogger">
<Properties>
<Property name="log-path">/var/tmp</Property>
</Properties>
<Appenders>
<Console name="Console" target="SYSTEM_OUT" level="FATAL">
<PatternLayout pattern="%m%n" />
</Console>
<RollingRandomAccessFile name="RollingFile" fileName="${log-path}/jsonlogger.json"
filePattern="${log-path}/%d{yyyyMMdd}_jsonlogger-%i.json"
immediateFlush="false">
<PatternLayout>
<pattern>%m%n</pattern>
</PatternLayout>
<Policies>
<TimeBasedTriggeringPolicy />
<SizeBasedTriggeringPolicy size="10 MB" />
</Policies>
<DefaultRolloverStrategy max="4"/>
</RollingRandomAccessFile>
<Async name="Async">
<AppenderRef ref="RollingFile"/>
</Async>
</Appenders>
<Loggers>
<Logger name="JSONLogger" level="trace" additivity="false">
<AppenderRef ref="Async" />
</Logger>
<Root level="fatal">
<AppenderRef ref="Console" />
</Root>
</Loggers>
When running the JUnit tests, the logger writes to the jsonlogger.json file as expected.
On my weblogic server i have deployed the log4j2.xml configuration file and set the java property log4j.configurationFile to the location of the log4j2.xml file. When i deploy the jar to my Weblogic 12c server, the logger works fine when invoked from a fault policy. Only it is logging to the wrong file.
It logs this to the weblogic diagnostics file
<Nov 11, 2016, 5:18:34,278 PM CET> <Error> <JSONLogger> <BEA-000000> <{"LOB":"*** TEST ****","Service":"B","Proces":"C","OptionalFields":{"melding":"Service unavailable for not available for a prolonged period","FaultPolicyID":"RemoteFaults","FaultType":"bpel","Partnerlink":"SimpleSyncUnavail","PortType":"{http://xmlns.oracle.com/JSONLogger/reddippedSimpleUnavail/BPELProcess}BPELProcess"},"level":"ERROR","thread_name":"[ACTIVE] ExecuteThread: '58' for queue: 'weblogic.kernel.Default (self-tuning)'","class":"com.reddipped.jsonlogger.JSONLogger","logger_name":"JSONLogger","@timestamp":"2016-11-11 17:18:34.270+0100"}>
Instead of this to the json file specified in log4j2 configuration
{"LOB":"*** TEST ****","Service":"B","Proces":"C","OptionalFields":{"melding":"Service unavailable for not available for a prolonged period","FaultPolicyID":"RemoteFaults","FaultType":"bpel","Partnerlink":"SimpleSyncUnavail","PortType":"{http://xmlns.oracle.com/JSONLogger/reddippedSimpleUnavail/BPELProcess}BPELProcess"},"level":"ERROR","thread_name":"[ACTIVE] ExecuteThread: '58' for queue: 'weblogic.kernel.Default (self-tuning)'","class":"com.reddipped.jsonlogger.JSONLogger","logger_name":"JSONLogger","@timestamp":"2016-11-11 17:18:34.270+0100"}
So probably the odl-logger defined in the /config/fmwconfig/servers//logging.xml is used.
Any ways to debug/resolve this ?
-- update 1 --
I added some debug statements to determine if at runtime when executed from a fault-policy the correct configuration file was used.
try {
System.out.println("**PNE** CLASS LOGGER PATH " + LOGGER.getClass().getProtectionDomain().getCodeSource().getLocation().toURI().getPath()) ;
} catch (Exception e) {
System.out.println("**PNE** CLASS LOGGER PATH FAiled") ;
}
System.out.println("**PNE** Config Location : " + org.apache.logging.log4j.core.LoggerContext.getContext().getConfiguration()) ;
Map<String, Appender> appenders = org.apache.logging.log4j.core.LoggerContext.getContext().getConfiguration().getAppenders() ;
for (String appender : appenders.keySet()) {
System.out.println("**PNE** APPENDER " + appender);
System.out.println("**PNE** APPENDER " + appenders.get(appender).toString());
}
System.out.println("**PNE** SYSTEM PROPERTY " + System.getProperty("log4j.configurationFile") ) ;
System.out.println("**PNE** :-) JSONLogger DEBUG " + lob + ":" + service + ":" + proces ) ;
LOGGER.error()
.field("LOB", lob)
.field("Service",service)
.field("Proces", proces)
.map("OptionalFields", optionalFields).log() ;
The expected log4j configuration file is loaded indeed and the appender is retrieved from the logger context.
**PNE** Config Location : XmlConfiguration[location=/u01/data/domains/soa12c/log4j2.xml]
**PNE** APPENDER RollingFile
**PNE** APPENDER RollingFile
**PNE** APPENDER Async
**PNE** APPENDER Async
**PNE** APPENDER Console
**PNE** APPENDER Console
**PNE** SYSTEM PROPERTY /u01/data/domains/soa12c/log4j2.xml
**PNE** :-) JSONLogger DEBUG Unknown:Unknown:Unknown
<Nov 12, 2016, 10:00:40,184 AM CET> <Error> <JSONLogger> <BEA-000000> <{"LOB":"Unknown","Service":"Unknown","Proces":"Unknown","OptionalFields":{"melding":"Service unavailable for not available for a prolonged period","FaultPolicyID":"RemoteFaults","FaultType":"bpel","Partnerlink":"SimpleSyncUnavail","PortType":"{http://xmlns.oracle.com/JSONLogger/reddippedSimpleUnavail/BPELProcess}BPELProcess"},"level":"ERROR","thread_name":"[ACTIVE] ExecuteThread: '0' for queue: 'weblogic.kernel.Default (self-tuning)'","class":"com.reddipped.jsonlogger.JSONLogger","logger_name":"JSONLogger","@timestamp":"2016-11-12 10:00:40.184+0100"}>
**>>PNE** JSONLOGGERUnknownUnknownUnknownUnknown{melding=Service unavailable for not available for a prolonged period, FaultPolicyID=RemoteFaults, FaultType=bpel, Partnerlink=SimpleSyncUnavail, PortType={http://xmlns.oracle.com/JSONLogger/reddippedSimpleUnavail/BPELProcess}BPELProcess}
What is puzzling me is that the actual logging still is logged to the diagnostics logs.
-- update 2 --
Logging is not sent to the diagnostics logs as mentioned earlier, but to the server.out files. So the log4j loggings seems to have been routed to the Console instead of the logger.
The log4j2.xml did contain an error, the Console appender had the illegal attribute "level". After removing this the file /var/tmp/jsonlogger.json is created, but stays empty. Logging is still sent to server.out.
-- update 3 --
Could it be that the logging is intercepted by JUL ? If so how can i determine if it is intercepted ?
