Logging in OIM custom code

Proper logging is one of the main considerations during custom development. This is no different in OIM projects in which custom code is being developed and deployed to OIM. Proper logging is fundamental part of development, helping in finding issues, fixing them and also in reporting relevant runtime conditions.

This post shows how to leverage the Oracle Fusion Middleware infrastructure in which OIM runs in order to create proper logging information from custom code. It is not the intent of this post to cover all logging considerations; there are plenty of materials on the internet and book stores to cover the basics.
This is another post of the Oracle Identity Manager Academy. To check other tricks, tips and examples you can find the academy post here.


OIM running on WebLogic leverages ODL for logging. ODL stands for Oracle Diagnostic Logging, the OIM related documentation is available here. This documentation provides details on the out-of-the-box loggers, how they can be changed, where the logging statements go, and what each log level will produce. The image below depicts some of the OIM loggers:

When it comes to proper logging in your custom code, the task is pretty simple. Below a very basic example of an OIM event handler containing some logging related code:

...
import java.util.logging.Level;
import java.util.logging.Logger;
 
public class MyCustomEventHandler implements PostProcessHandler {
     
    private static Logger myLogger = Logger.getLogger("MY.CUSTOM.LOGGER");
     
    public EventResult execute(long l, long l1, Orchestration orchestration) {
        
        myLogger.entering("MyCustomEventHandler", "execute");
      
        try {
            myLogger.logp(Level.FINEST, "MyCustomEventHandler", "execute", "Trying to convert X to an integer");
             
            int x = Integer.parseInt("x");
        }
        catch (NumberFormatException e) {
            myLogger.logp(Level.SEVERE, "MyCustomEventHandler", "execute", "Error during operation "+e.getMessage(), e);
        } 
        myLogger.exiting("MyCustomEventHandler", "execute");
         
        return new EventResult();
    }
 
...

Some important details about the code above:

• Although it could, it does not use ODL APIs, it uses plain java.util.logging classes. At runtime, FMW stack redirects the java.util.logging logging to ODL logging. This makes your life easier when compiling the code as you do not need extra libraries.
• It is very important to mention that the code is intentionally forcing a Java exception by trying to parse an alpha String into a Java integer. The intention was to force the exception to happen for demonstrating the logging use
• The logger being used is name ‘MY.CUSTOM.LOGGER’.
• The code is an event handler, but the same logging approach can be used in other customizations like scheduled tasks, notification providers, plug-ins in general and also in UI customizations
• There are different log levels being used by the code. Below a simplified table showing the mapping between ODL and java.logging levels (click here for a complete table):

Java Log Level	ODL Level
SEVERE	ERROR:1
WARNING	WARNING:1
INFO	NOTIFICATION:1
CONFIG	NOTIFICATION:16
FINE	TRACE:1
FINER	TRACE:16
FINEST	TRACE:32

When the custom code is loaded for the first time, ODL will create the proper logger instances, and they will be exposed through /em console. Then the logging level can be changed accordingly to the needs. The image below depicts the custom logger and it shows how log level changes can be persisted to survive server restarts:

And below the excerpt from the log file with the log statements generated by the code above:

[2014-06-03T12:57:53.284-07:00] [wls_oim1] [WARNING] [ADF_FACES-30118] [oracle.adfinternal.view.faces.renderkit.rich.SelectItemUtils] [tid: [ACTIVE].ExecuteThread: '1' for queue: 'weblogic.kernel.Default (self-tuning)'] [userId: xelsysadm] [ecid: 004yjFhM1xh2rIQ5Ib_Aif0006Tz000JZ4,0:3] [APP: oracle.iam.console.identity.self-service.ear#V2.0] [DSID: 0000KPZJ3LD2rIQ5Ib_Aif1JZYPa000008] [URI: /identity/faces/home] No help provider found for helpTopicId=modify_user.
[2014-06-03T12:57:53.605-07:00] [wls_oim1] [NOTIFICATION] [] [OAM Notification Logger] [tid: [ACTIVE].ExecuteThread: '0' for queue: 'weblogic.kernel.Default (self-tuning)'] [userId: oiminternal] [ecid: 004yjFhM1xh2rIQ5Ib_Aif0006Tz000JZ4,0] [APP: oim#11.1.2.0.0] Notification status true

[2014-06-03T12:57:53.892-07:00] [wls_oim1] [TRACE:16] [] [MY.CUSTOM.LOGGER] [tid: [ACTIVE].ExecuteThread: '0' for queue: 'weblogic.kernel.Default (self-tuning)'] [userId: oiminternal] [ecid: 004yjFhM1xh2rIQ5Ib_Aif0006Tz000JZ4,0] [APP: oim#11.1.2.0.0] [SRC_CLASS: MyCustomEventHandler] [SRC_METHOD: execute] ENTRY
[2014-06-03T12:57:53.892-07:00] [wls_oim1] [TRACE:32] [] [MY.CUSTOM.LOGGER] [tid: [ACTIVE].ExecuteThread: '0' for queue: 'weblogic.kernel.Default (self-tuning)'] [userId: oiminternal] [ecid: 004yjFhM1xh2rIQ5Ib_Aif0006Tz000JZ4,0] [APP: oim#11.1.2.0.0] [SRC_CLASS: MyCustomEventHandler] [SRC_METHOD: execute] Trying to convert X to an integer
[2014-06-03T12:57:53.892-07:00] [wls_oim1] [ERROR] [] [MY.CUSTOM.LOGGER] [tid: [ACTIVE].ExecuteThread: '0' for queue: 'weblogic.kernel.Default (self-tuning)'] [userId: oiminternal] [ecid: 004yjFhM1xh2rIQ5Ib_Aif0006Tz000JZ4,0] [APP: oim#11.1.2.0.0] Error during operation For input string: "x"
java.lang.NumberFormatException: For input string: "x"
        at java.lang.NumberFormatException.forInputString(NumberFormatException.java:48)
        at java.lang.Integer.parseInt(Integer.java:449)
        at java.lang.Integer.parseInt(Integer.java:499)
        at oracle.iam.demo.eventhandlers.MyCustomEventHandler.execute(MyCustomEventHandler.java:27)
        at oracle.iam.platform.kernel.impl.OrchProcessData.runPostProcessEvents(OrchProcessData.java:1490)
        at oracle.iam.platform.kernel.impl.OrchProcessData.runEvents(OrchProcessData.java:896)
        at oracle.iam.platform.kernel.impl.OrchProcessData.executeEvents(OrchProcessData.java:357)
        at oracle.iam.platform.kernel.impl.OrchestrationEngineImpl.resumeProcess(OrchestrationEngineImpl.java:948)
        at oracle.iam.platform.kernel.impl.OrchestrationEngineImpl.resumeProcess(OrchestrationEngineImpl.java:978)
        at oracle.iam.platform.kernel.impl.OrhestrationAsyncTask.execute(OrhestrationAsyncTask.java:134)
        at oracle.iam.platform.async.impl.TaskExecutor.executeUnmanagedTask(TaskExecutor.java:99)
        at oracle.iam.platform.async.impl.TaskExecutor.execute(TaskExecutor.java:69)
        at oracle.iam.platform.async.messaging.MessageReceiver.onMessage(MessageReceiver.java:68)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
        at java.lang.reflect.Method.invoke(Method.java:597)
        at com.bea.core.repackaged.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:310)
        at com.bea.core.repackaged.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:182)
        at com.bea.core.repackaged.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:149)
        at com.bea.core.repackaged.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:89)
        at com.bea.core.repackaged.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
        at com.bea.core.repackaged.springframework.aop.support.DelegatingIntroductionInterceptor.doProceed(DelegatingIntroductionInterceptor.java:131)
        at com.bea.core.repackaged.springframework.aop.support.DelegatingIntroductionInterceptor.invoke(DelegatingIntroductionInterceptor.java:119)
        at com.bea.core.repackaged.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
        at com.bea.core.repackaged.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
        at $Proxy411.onMessage(Unknown Source)
        at weblogic.ejb.container.internal.MDListener.execute(MDListener.java:583)
        at weblogic.ejb.container.internal.MDListener.transactionalOnMessage(MDListener.java:486)
        at weblogic.ejb.container.internal.MDListener.onMessage(MDListener.java:388)
        at weblogic.jms.client.JMSSession.onMessage(JMSSession.java:4659)
        at weblogic.jms.client.JMSSession.execute(JMSSession.java:4345)
        at weblogic.jms.client.JMSSession.executeMessage(JMSSession.java:3821)
        at weblogic.jms.client.JMSSession.access$000(JMSSession.java:115)
        at weblogic.jms.client.JMSSession$UseForRunnable.run(JMSSession.java:5170)
        at weblogic.work.SelfTuningWorkManagerImpl$WorkAdapterImpl.run(SelfTuningWorkManagerImpl.java:545)
        at weblogic.work.ExecuteThread.execute(ExecuteThread.java:256)
        at weblogic.work.ExecuteThread.run(ExecuteThread.java:221)
[2014-06-03T12:57:53.892-07:00] [wls_oim1] [TRACE:16] [] [MY.CUSTOM.LOGGER] [tid: [ACTIVE].ExecuteThread: '0' for queue: 'weblogic.kernel.Default (self-tuning)'] [userId: oiminternal] [ecid: 004yjFhM1xh2rIQ5Ib_Aif0006Tz000JZ4,0] [APP: oim#11.1.2.0.0] [SRC_CLASS: MyCustomEventHandler] [SRC_METHOD: execute] RETURN

By using the approach described in this post, the custom logging statements will be written to the <managed-serve-name>-diagnostics.log located, in the out-of-the-box configuration, under $DOMAIN_HOME/servers/<server_name>/logs. You can also create your own ODL log handlers and redirect your custom logging to a different log file, check the documentation here on how to do that. The Fusion Middleware logging infrastructure used by OIM has been the same since first 11g release, so this blog post applies to all the 11g versions. Have fun!