Logging to a Central Database

Introduction

Oracle Health Insurance applications and the runtime technology stack support various logging capabilities.

Examples of logs that are currently written:

Security log: to track (failed) login attempts.
Protected Health Information (PHI) log: to track which health insurance payer employee viewed specific member related information.
Dynamic Logic log: to track dynamic logic execution.
Application log: contains informational messages, warnings and errors. This log contains all messages that are logged by Oracle Health Insurance applications that are not in the Security log, the PHI log, or the Dynamic Logic log.
JVM GC log: garbage collection statistics.
Server output logs: detailed technical information about the state of specific JVM processes as written by the application server.

All Oracle Health Insurance applications use the Logback framework for logging data. Logback supports a wide variety of 'log appenders'; the best known appender is probably the file appender that is used by each JVM that runs the application to write log files to disk. In the Logback configuration, the logging level for specific loggers (e.g. per package or even per class) can be adjusted in order to get more detailed diagnostic data from the system.

The Oracle Health Insurance Logback Database Appender

When each JVM writes data to separate log files, it is relatively hard to get a complete overview. As an alternative, Oracle Health Insurance applications are capable of streaming the following Oracle Health Insurance application logs into database tables:

Log	Database Table	HTTP API resource
Application log	log_application_events	generic/logapplicationevents
PHI log	log_phi_events	generic/logphievents
Dynamic Logic log	log_dylo_events	generic/logdyloevents

Log

Database Table

HTTP API resource

Application log

log_application_events

generic/logapplicationevents

PHI log

log_phi_events

generic/logphievents

Dynamic Logic log

log_dylo_events

generic/logdyloevents

The final column specifies which HTTP API resource can be used to access and / or query logged messages.

For efficiency reasons, Oracle Health Insurance applications come with a specific Logback Database Appender for the Application and Dynamic Logic log. These loggers initially write to a file-backed buffer queue. The Oracle Health Insurance Database Appender (eventually) persists log events from the file-backed queue to the database.

If system property ohi.logging.target is set to value database, Oracle Health Insurance applications persist PHI access in the database as part of the request in which PHI data was accessed.

Starting with release 3.21.2.0.0 of Oracle Health Insurance applications, the Oracle Health Insurance Logback Database Appender is no longer used for logging PHI access.

The Oracle Health Insurance Database Appender assumes that log messages are formatted as JSON documents with a specific structure. It uses the well-known Logstash Logback Encoder for JSON encoding. The Oracle Health Insurance Database Appender applies the following default configuration settings for the encoder:

<encoder class="net.logstash.logback.encoder.LogstashEncoder">
  <providers>
    <mdc/>
    <context/>
    <nestedField>
      <fieldName>markers</fieldName>
      <providers>
        <logstashMarkers/>
      </providers>
    </nestedField>
    <nestedField>
      <fieldName>arguments</fieldName>
      <providers>
        <arguments/>
      </providers>
    </nestedField>
    <pattern>
      { "ohiLevel": "%ohiLevel" }
    </pattern>
    <fieldNames>
      <timestamp>timestamp</timestamp>
    </fieldNames>
  </providers>
</encoder>

If it is desirable to adjust the default settings make sure to retain the defaults that Oracle Health Insurance applications rely on. The following example adds a specific configuration for stack traces:

<encoder class="net.logstash.logback.encoder.LogstashEncoder">
  <providers>
    <mdc/>
    <context/>
    <nestedField>
      <fieldName>markers</fieldName>
      <providers>
        <logstashMarkers/>
      </providers>
    </nestedField>
    <nestedField>
      <fieldName>arguments</fieldName>
      <providers>
        <arguments/>
      </providers>
    </nestedField>
    <pattern>
      { "ohiLevel": "%ohiLevel" }
    </pattern>
    <fieldNames>
      <timestamp>timestamp</timestamp>
    </fieldNames>
    <stackTrace>
      <throwableConverter class="net.logstash.logback.stacktrace.ShortenedThrowableConverter">
        <maxDepthPerThrowable>30</maxDepthPerThrowable>
        <maxLength>2048</maxLength>
        <shortenedClassNameLength>20</shortenedClassNameLength>
        <exclude>^sun\.reflect\..*\.invoke</exclude>
        <exclude>^net\.sf\.cglib\.proxy\.MethodProxy\.invoke</exclude>
        <rootCauseFirst>true</rootCauseFirst>
      </throwableConverter>
    </stackTrace>
  </providers>
</encoder>

Other configuration options for the Oracle Health Insurance Database Appender are listed in the following table:

Parameter Explanation Required?

Parameter	Explanation	Required?
connectionSource	For the Oracle Health Insurance Database Appender to work it needs access to a database. Make sure to only use a JNDI Connection Source. Without specifying a connection source the application does not start; it will throw an IllegalStateException with message "OhiAppender cannot function without a connection source"	Yes
logType	Currently supported log types are `application` and `dylo`. Without specifying a log type the application will not start; it will throw an IllegalStateException with message "OhiAppender cannot function without a specific log type".	Yes
bufferDir	The Database Appender buffers log messages in a file-backed queue or buffer. Queue files will be written in the specified directory. If a bufferDir is not specified the application uses the value of system property "java.io.tmpdir". If the application cannot write to the configured directory then the application will not start; it will throw an IllegalStateException with message "Cannot write to path <path>"	Yes
drainInterval	By default the file-backed queue will be drained every 5 milliseconds. This value can be overwritten if desired. The minimum is 1 millisecond. Specifying a drain interval below 1 millisecond prevents the application from starting; it will throw an IllegalStateException with message "Invalid timeout to drain queue specified: <specified_time_interval>"	No
drainBatchSize	By default, messages from the file-backed queue will be persisted in batches with a max size of 2000. This value can be overwritten if desired. The minimum batch size is 1 (note that such a value is extremely inefficient!). If a batch size smaller than 1 is specified the application will not start; it will throw an IllegalStateException with message "Invalid batch size for draining queue specified: <specified_time_interval>"	No
rollCycle	Files for the file-backed queue roll over periodically. The files that are no longer used are removed automatically in order to limit disk space use. This parameter allows specification of the roll cycle. The default value is HOURLY, that allows storing 256 million entries per hour (disk space permitting). The alternative value is DAILY (4 billion entries per day). Contact Oracle Health Insurance development in the unusual case the buffer should accommodate larger amounts of log entries.	No
duplicateDuration	Setting a value for this parameter filters duplicate events with level `ERROR` to prevent the system from logging many occurrences of the same ERROR in a short period of time which may cause its logging capability to be 'flooded'. The application considers an ERROR event to be a duplicate if an event for the same logger and with the same (raw) message was logged in the last 'duplicateDuration' milliseconds. This is only applicable for ERROR messages in the Application log. It is disabled by default. Setting this value to 300000 milliseconds will log an error message once per thread and will suppress the same error message logged in that thread for the next 5 minutes.	No

connectionSource

For the Oracle Health Insurance Database Appender to work it needs access to a database. Make sure to only use a JNDI Connection Source.

Without specifying a connection source the application does not start; it will throw an IllegalStateException with message "OhiAppender cannot function without a connection source"

Yes

logType

Currently supported log types are application and dylo. Without specifying a log type the application will not start; it will throw an IllegalStateException with message "OhiAppender cannot function without a specific log type".

Yes

bufferDir

The Database Appender buffers log messages in a file-backed queue or buffer. Queue files will be written in the specified directory.

If a bufferDir is not specified the application uses the value of system property "java.io.tmpdir". If the application cannot write to the configured directory then the application will not start; it will throw an IllegalStateException with message "Cannot write to path <path>"

Yes

drainInterval

By default the file-backed queue will be drained every 5 milliseconds. This value can be overwritten if desired. The minimum is 1 millisecond.

Specifying a drain interval below 1 millisecond prevents the application from starting; it will throw an IllegalStateException with message "Invalid timeout to drain queue specified: <specified_time_interval>"

drainBatchSize

By default, messages from the file-backed queue will be persisted in batches with a max size of 2000. This value can be overwritten if desired. The minimum batch size is 1 (note that such a value is extremely inefficient!).

If a batch size smaller than 1 is specified the application will not start; it will throw an IllegalStateException with message "Invalid batch size for draining queue specified: <specified_time_interval>"

rollCycle

Files for the file-backed queue roll over periodically. The files that are no longer used are removed automatically in order to limit disk space use. This parameter allows specification of the roll cycle. The default value is HOURLY, that allows storing 256 million entries per hour (disk space permitting). The alternative value is DAILY (4 billion entries per day).

Contact Oracle Health Insurance development in the unusual case the buffer should accommodate larger amounts of log entries.

duplicateDuration

Setting a value for this parameter filters duplicate events with level ERROR to prevent the system from logging many occurrences of the same ERROR in a short period of time which may cause its logging capability to be 'flooded'.

The application considers an ERROR event to be a duplicate if an event for the same logger and with the same (raw) message was logged in the last 'duplicateDuration' milliseconds.

This is only applicable for ERROR messages in the Application log. It is disabled by default.

Setting this value to 300000 milliseconds will log an error message once per thread and will suppress the same error message logged in that thread for the next 5 minutes.

The log type parameter for the appender drives

proper filtering of log messages, e.g. to ensure that PHI log messages do not show up in the Application log;
storing of log messages in the database.

The following paragraphs list the Logback configuration for each of these logs.

Please note that:

the below Logback configuration samples omit the encoder, implying use of the Oracle Health Insurance default settings for it;
the buffer directory lists imaginary locations "/writable/log/storage/buffer/…". Make sure the actual buffer directory that is configured is writable. If that is not the case then the application will log an IllegalStateException in the managed server’s log.

Logging Dynamic Logic execution

Sample configuration for an Oracle Health Insurance Database Appender for Dynamic Logic execution logging:

<configuration debug="true" scan="true" scanPeriod="60 seconds">
 <contextListener class="ch.qos.logback.classic.jul.LevelChangePropagator"/>

 <conversionRule conversionWord="ohiLevel"
  converterClass="com.oracle.healthinsurance.utils.logging.logback.OhiLogLevelConverter"/>

 <appender name="dyloAppender"
  class="com.oracle.healthinsurance.loggingsupport.appender.impl.OhiAppender">
     <connectionSource class="ch.qos.logback.core.db.JNDIConnectionSource">
         <jndiLocation>jdbc/policiesUserOhiApplicationDS</jndiLocation>
     </connectionSource>
     <logType>dylo</logType>
     <bufferDir>/writable/log/storage/buffer/dylo</bufferDir>
 </appender>

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

Note that all Dynamic Logic scripts are in package namespace ohi.dynamiclogic. To enable logging any statements for that package add the following logger:

<logger name="ohi.dynamiclogic" level="trace"/>

Application log

Sample configuration for an Oracle Health Insurance Database Appender for remaining log messages (that should not end up in the PHI log, or the Dynamic Logic log):

<configuration debug="true" scan="true" scanPeriod="60 seconds">
 <contextListener class="ch.qos.logback.classic.jul.LevelChangePropagator"/>

 <conversionRule conversionWord="ohiLevel"
  converterClass="com.oracle.healthinsurance.utils.logging.logback.OhiLogLevelConverter"/>

 <appender name="applicationAppender"
  class="com.oracle.healthinsurance.loggingsupport.appender.impl.OhiAppender">
     <connectionSource class="ch.qos.logback.core.db.JNDIConnectionSource">
         <jndiLocation>jdbc/policiesUserOhiApplicationDS</jndiLocation>
     </connectionSource>
     <logType>application</logType>
     <bufferDir>/writable/log/storage/buffer/application</bufferDir>
 </appender>

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

Tracking the Oracle Health Insurance appender’s status

The Oracle Health Insurance Logback Database Appender is capable of writing messages about its own state to the Oracle Health Insurance logs. Its status can be tracked using Logback status listeners and by redirecting messages that it writes to "Standard Out" and "Standard Error" to the server log.

Enable LogBack Status listeners for the Oracle Health Insurance Database Appender

Enable the LogBack status listener by:

Setting the Logback configuration debug flag to true as was done in the samples above.
Attaching a status listener as in the following example:

<configuration>
  <statusListener class="ch.qos.logback.core.status.OnConsoleStatusListener" />
  ...
</configuration>

Refer to the Logback documentation for a complete overview of capabilities. The Oracle Health Insurance Logback Database Appender writes LogBack status messages during initialization and shutdown.

Tracking the logger’s status using LogBack

The Oracle Health Insurance Database Appender makes use of separate threads to write messages from the file-backed queue to the database. Within these threads, diagnostic messages can be written by enabling LogBack loggers. Make sure to log the messages about the Oracle Health Insurance Database Appender to a different appender. The following is a sample LogBack configuration for tracking the Oracle Health Insurance Database Appender, by writing messages to a specific file appender:

<conversionRule conversionWord="ohiLevel"
 converterClass="com.oracle.healthinsurance.utils.logging.logback.OhiLogLevelConverter"/>

<appender name="fileAppender" class="ch.qos.logback.core.rolling.RollingFileAppender">
    <encoder>
        <pattern>%d{ISO8601} %ohiLevel %logger{3} - %m%n</pattern>
    </encoder>
    <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
        <fileNamePattern>target/ohiAppenderFile-%d{yyyy-MM-dd}.%i.log</fileNamePattern>
        <timeBasedFileNamingAndTriggeringPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP">
            <maxFileSize>100MB</maxFileSize>
        </timeBasedFileNamingAndTriggeringPolicy>
    </rollingPolicy>
</appender>

<logger name="com.oracle.healthinsurance.loggingsupport.appender.impl.QueueFileListener"
 level="debug" additivity="false">
    <appender-ref ref="fileAppender"/>
</logger>
<logger name="com.oracle.healthinsurance.loggingsupport.appender.impl.OhiAppender"
 level="debug" additivity="false">
    <appender-ref ref="fileAppender"/>
</logger>
<logger name="com.oracle.healthinsurance.loggingsupport.appender.impl.LoggingEventBatchPersister"
 level="debug" additivity="false">
    <appender-ref ref="fileAppender"/>
</logger>

Access centrally stored logged data using HTTP API resources. The following paragraphs provide details for these as well as a number of examples.

Retrieving Log Messages

Note that users need to be properly authorized for accessing HTTP API resources.

Retrieve the default representation for each resource from the metadata specification or fetch a sample response by executing a GET request to any of the resources mentioned. For example, the default representation for application log events looks like the following example:

{"id": 96558,
 "application": "authorizations",
 "applicationVersion": "3.18.1.0.0",
 "eventLevel": "ERROR",
 "eventLogger": "c.o.h.d.d.i.c.p.DataReplicationTargetSynchronizationTaskTypeProcessor",
 "eventMessage": "Failed to retrieve and / or store events, closing data replication extraction task",
 "eventThread": "[STANDBY] ExecuteThread: '18' for queue: 'weblogic.kernel.Default (self-tuning)'",
 "hostName": "a_host",
 "instanceName": "authorizations_node1",
 "instanceType": "an_instance",
 "links": [
  {"href": "http://localhost:27041/api/generic/logapplicationevents/96558",
   "rel": "self"
  }
 ],
 "eventTimestamp": {
   "value": "2018-01-11T17:42:27.13+01:00"
  },
 "persistedTimestamp": {
   "value": "2018-01-11T17:42:31.304+01:00"
  }
}

Note that many attributes will be repeated for other logged messages as well.

When querying log messages, make sure to always filter on eventDate or persistedTimestamp as these are indexed. As the number of log messages grows, using these as access path makes sure request response times remain acceptable.

Example: checking for warnings and errors in the Application log

Use Query API capabilities to look for specific log messages. The following GET request returns errors or warnings in a specific hour on a specific day, ordered by the eventTimestamp of the messages:

/generic/logapplicationevents?q=eventLevel.in('WARN','ERROR') \
.and.eventDate.gt('2018-01-11T17:00:00').and.eventDate.lt('2018-01-12T18:00:00') \
&orderBy=eventTimestamp:asc

When it is executed using the following Accept header:

application/vnd.oracle.insurance.resource+json; fields="eventMessage|eventTimestamp"

the results should look like the following example, a more concise version of the previous application log event’s sample:

{"id": 96558,
 "eventMessage": "Failed to retrieve and / or store events, closing data replication extraction task",
 "links": [
  {"href": "http://localhost:27041/api/generic/logapplicationevents/96558",
   "rel": "self"
  }
 ],
 "eventTimestamp": {
   "value": "2018-01-11T17:42:27.13+01:00"
  }
}

Note the difference between eventDate and eventTimeStamp:

The precision for the eventDate is limited to seconds. Specifically for executing such queries efficiently, the eventDate is indexed.
The precision for the eventTimestamp includes microseconds as well as time zone information.

Checking access to PHI data

The application writes an entry to the PHI log when a system user accesses an insured member’s personal identifiable information, whether this is done through a web service or via the application’s user interface.

Following Dynamic Logic execution

Use the Dynamic Logic log to inspect Dynamic Logic execution.

For every Dynamic Logic execution a unique execution ID is generated that all messages logged during the execution will carry.

Sample messages that are logged for executing a Dynamic Logic script (edited for readability):

{
  "message" : "execution starts",
  "logger_name" : "ohi.dynamiclogic",
  "level" : "TRACE",
  "markers" : {
    "scriptexecutionid" : "da2e6719-e5d2-4112-85b9-4321929aeed9"
  }
}
{
  "message" : "Binding foo set to bar",
  "logger_name" : "ohi.dynamiclogic",
  "level" : "TRACE",
  "markers" : {
    "scriptexecutionid" : "da2e6719-e5d2-4112-85b9-4321929aeed9"
  }
}
{
  "message" : "result: true of type: class java.lang.Boolean",
  "logger_name" : "ohi.dynamiclogic",
  "level" : "TRACE",
  "markers" : {
    "scriptexecutionid" : "da2e6719-e5d2-4112-85b9-4321929aeed9"
  }
}
{
  "message" : "execution completed",
  "logger_name" : "ohi.dynamiclogic",
  "level" : "TRACE",
  "markers" : {
    "scriptexecutionid" : "da2e6719-e5d2-4112-85b9-4321929aeed9"
  }
}

Bundling Log Messages in a Data File Set

Use HTTP API resource generic/logfilesetspecifications to specify parameters for bundling multiple messages in a data file set.

bundling log messages is not available for log type phi

The following table explains the attributes for a log file set specification:

Attribute Explanation Required? Sample Value

Attribute	Explanation	Required?	Sample Value
logType	The log type for which messages are bundled into a set.	Yes	One of `application`; `dylo`
startDateTime	The application selects messages with an `eventTimestamp` between the specified `startDateTime` and `endDateTime` (see next row) to be included in the data file set.	Yes	`2018-01-12T00:00:00`
endDateTime	By default, the time span between `startDateTime` and `endDateTime` must not exceed two days. Adjust system property `ohi.logging.fileset.max.timespan` to allow for the specification of larger periods. Make sure to configure the database to accommodate creation of data file sets that span large periods of time.	Yes	`2018-01-14T00:00:00`
logLevel	Log Level filter. Specification of: `ERROR` results in selection of messages with level ERROR only `WARN` results in selection of messages with levels ERROR and WARN `INFO` results in selection of messages with levels ERROR, WARN and INFO `DEBUG` results in selection of messages with levels ERROR, WARN, INFO and DEBUG `TRACE` results in selection of messages with levels ERROR, WARN, INFO, DEBUG and TRACE	No	`ERROR`
logger	Filter for a specific logger.	No	`healthinsurance.loggingsupport.components`

logType

The log type for which messages are bundled into a set.

Yes

One of application; dylo

startDateTime

The application selects messages with an eventTimestamp between the specified startDateTime and endDateTime (see next row) to be included in the data file set.

Yes

2018-01-12T00:00:00

endDateTime

By default, the time span between startDateTime and endDateTime must not exceed two days. Adjust system property ohi.logging.fileset.max.timespan to allow for the specification of larger periods. Make sure to configure the database to accommodate creation of data file sets that span large periods of time.

Yes

2018-01-14T00:00:00

logLevel

Log Level filter. Specification of:

ERROR results in selection of messages with level ERROR only

WARN results in selection of messages with levels ERROR and WARN

INFO results in selection of messages with levels ERROR, WARN and INFO

DEBUG results in selection of messages with levels ERROR, WARN, INFO and DEBUG

TRACE results in selection of messages with levels ERROR, WARN, INFO, DEBUG and TRACE

ERROR

logger

Filter for a specific logger.

healthinsurance.loggingsupport.components

The resource allows creation of a log file set specification only. Existing log file set specifications cannot be changed or deleted.

After the application accepts the log file set specification request it starts creation of the data file set immediately. Created data files contain messages in the original JSON format. Issue GET requests on the link the application returned in order to retrieve the resource location to the data file set. Note that creating the data file set may take some time, depending on the amount of messages that need to be bundled and the workload of the system. The system returns an error message in case creation of the data file set failed.

Oracle Health Insurance applications retain the log file set specification and the resulting data file set for two days. The daily purge routine removes any older data file sets and the log file set specifications for these.

Adding Loggers and Setting Log Levels

At startup time, the application takes the initial Logback configuration from a configuration file. Make sure that a single copy of that configuration is available for all nodes that execute an instance of an Oracle Health Insurance application. Use HTTP API resource generic/loggers to manage loggers:

Get an overview of custom loggers that were defined using the generic/loggers API by executing a GET request to generic/loggers.
Add a logger with a specific log level by executing a POST request to generic/loggers.
Update the level of an existing logger by executing a PUT request to generic/loggers/{id}.
Unsetting a logger by executing a DELETE request to generic/loggers/{id}. In this case, the logger will inherit the log level of its parent.

The application propagates any changes made via the generic/loggers API to all nodes that execute an instance of an Oracle Health Insurance application.

For example, for adding a logger for package "com.oracle.healthinsurance.datareplication.service" with level DEBUG that is active for 120 minutes after its specification, send the following JSON payload:

{"logger": "com.oracle.healthinsurance.datareplication.service"
,"logLevel": "DEBUG"
,"duration": 120
}

The application will automatically remove the logger after the specified 120 minutes. To create a durable logger, that will not be removed by the application, set the duration to the value 0. The default duration for a logger is one hour. Alternatively, if a logger is no longer needed, remove it by sending a DELETE request for it.

The application does not add changes made via the generic/loggers API to the Logback configuration file. Instead, it re-activates durable loggers after restarting.

At startup the application initializes the specified loggers in the following order:

Loggers that are specified in the Logback configuration file.
After that loggers that were defined using the generic/loggers API. Note that customer-defined loggers may overwrite settings for loggers that are defined in the Logback configuration file.

customer-defined durable loggers must be maintained by the customer

Using the Diagnostic Context

Oracle Health Insurance applications log data in context. For example:

During Claims processing OHI Claims Adjudication and Pricing logs messages in context of the specific claim that is processed making it possible to gather all log messages for a specific claim.
Log messages written while processing Web Service requests can be tracked using a trace ID that is provided in the request. If the application did not receive a trace ID then it generates one and returns that in the response.

Purging Log Messages

When an Oracle Health Insurance application starts it registers a daily job in the database for purging log messages. Frequently purging log messages helps to limit the amount of log messages stored in the database.

Use HTTP API resource generic/logeventretentionperiods to manage retention periods for the various log types, application, dylo, and phi:

Get an overview of specified retention periods by executing a GET request to generic/logeventretentionperiods.
Add a retention period for a specific log type by executing a POST request to generic/logeventretentionperiods.
Update the retention period for a log type by executing a PUT request to generic/logeventretentionperiods/{id}.
Remove a retention period for a log type by executing a DELETE request to generic/logeventretentionperiods/{id}.

For example, for setting a retention period of 15 days for log type application POST the following JSON payload:

{"logType": "application"
,"retentionPeriod": 15
}

By default, Oracle Health Insurance applications enforce a minimal retention period for phi messages of 1825 days, approximately 5 years. Adjust system property ohi.logging.phi.min.retentionperiod for changing that value.

Use HTTP API resource generic/loglevelretentionperiods to override log type specific retention periods on a per log level basis.

For example, for setting a retention period of 3 days for event retention period application, level DEBUG, POST the following JSON payload:

{"logLevel": "DEBUG"
,"retentionPeriod": 3
,"logEventRetentionPeriod": {
    "logType": "application"
 }
}

the retention period for a level must be between 1 day and the number of days specified for the event retention period.

For efficiency reasons, log messages are purged in sets or partitions. For the Application log and Dynamic Logic log this is done per day, for the PHI log it is per month. As the system prohibits deleting the last set or partition this could result in retaining logged messages for which the retention period expired. These are purged as soon as new messages are logged in more recent sets or partitions.