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 |
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. 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.
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? |
---|---|---|
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 |
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 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 |
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"/>
Logging access to Protected Health Information (PHI)
Sample configuration for an Oracle Health Insurance Database Appender for PHI 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="phiAppender"
class="com.oracle.healthinsurance.loggingsupport.appender.impl.OhiAppender">
<connectionSource class="ch.qos.logback.core.db.JNDIConnectionSource">
<jndiLocation>jdbc/policiesUserOhiApplicationDS</jndiLocation>
</connectionSource>
<logType>phi</logType>
<bufferDir>/writable/log/storage/buffer/phi</bufferDir>
</appender>
<root level="info">
<appender-ref ref="phiAppender" />
</root>
</configuration>
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, theeventDate
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 |
---|---|---|---|
logType |
The log type for which messages are bundled into a set. |
Yes |
One of |
startDateTime |
The application selects messages with an |
Yes |
|
endDateTime |
By default, the time span between |
Yes |
|
logLevel |
Log Level filter. Specification of:
|
No |
|
logger |
Filter for a specific logger. |
No |
|
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 togeneric/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.