Event Logging Approach

VersionDateAuthorDescription
1.0 02/27/2013 Leslie Power Initial Document
1.108/15/2016Tabassum JafriUpdated MessageID in Common Extraction section.
1.208/25/2016Tabassum JafriUpdated definitions of elements in Common Extraction section. 
1.308/26/2016 Tabassum JafriIncluded the missing database columns. 
1.409/01/2016 Tabassum Jafri Updated document with PRL comments.


Business Requirements

There are two formal high level business goals, supported by multiple requirements. The two goals are that
CONNECT will provide the ability to count and produce durations for the following values:

  • Number of a given transaction type (PD, QD, RD, etc.)
  • Number of a given transaction group
  • Number of transactions from a specific gateway
  • Total duration for given transaction type
  • Total duration for a given transaction group

CONNECT will be able to track and report on the following data points:

  • Error
  • Performance
  • Transaction Type
  • Payload
  • Error Messages log (without PHI data)

Design Considerations and Design Decisions

In addition to the articulated business requirements, the CONNECT team considered the following non-functional requirements:

Category

Requirement

Performance

The Performance Test Plan requirements are incorporated by reference. For testing purposes we use the database event logger

Modifiability

Adopters must be able to create their own logging repository. The creation of new logging repositories is a development-time activity

Modifiability

Adopters must be able to choose what logging repository to log events to. The decision of target repositories is a deployment-time activity

Modifiability

Adopters must be able to create new events and trigger those events at runtime points of their own choosing. This is a development-time activity

Reusability

Event logging should be minimally coupled to the existing adapters and gateway implementations. Adopter adapter implementations should be able to reuse event logging without modification to the event logging subsystem

Reusability

Logging repositories should not depend on the structure of the services being logged. Put another way, an entirely new service or new version of an existing service should not require logging repository changes

Design Approach

Initialization

Initialization is performed via Spring configuration. We have two configuration files, corresponding to the event recording and event creating subsystems. Event recording is initialized via the EventLoggerFactoryConfig.xml file. Zero, one, or multiple EventLogger instances can be created and registered with the EventLoggerRegistrar. Adopters may choose to write their own configuration file or may call EventLoggerRegistrar.registerLogger at runtime with their own EventLoggers. The default configuration has two consumers for the events: one to write the data to a file and the other to save it to a database. This is a producer-consumer pattern. The transport of the events is extensible, and the default implementation is an asynchronous callback. This callback can be extended to send a JMS message or make a remote call.

Event creation is initialized via eventlogging.xml. The CONNECT team has chosen an aspect approach. Adopters must annotate their methods with the appropriate event annotation and the logging subsystem will record entry and exit. Alternatively, adopters can write their own EventAdviceDelegate and initialize it instead of the BaseEventDelegate.

Event recording and event creation are tied together via the EventManager class.  EventManager is the concrete implementation of both EventLoggerRegistrar and EventRecorder.  

Runtime

The following classes are involved in the runtime creation and recording of an event as described in the sequence diagram that follows.

Before the event loggers can log any event, the event must be registered. Events signaled before an event logger is registered will not be logged.

Lifecycle

The lifecycle of a NwHIN message contains many discrete parts that work together in order to process a complete transaction. Each discrete part can be referred to as an "event." The Event Logging framework gives CONNECT the ability to record these events. The framework has been developed in a generic way so that CONNECT users can easily extend our model to collect information on whatever aspects of the system their business needs require. With a better view of the lifecycle and the time between each event, it is possible to generate various reports such as performance, load, and failures.  Listed below are true events, meaning they are related to the lifecycle of the processing of a message. However, the events aren't limited to only these lifecycle events, and the design allows for clear extension for events and event loggers.

Event Name

Lifecycle

Trigger Point

BEGIN_INBOUND_MESSAGE

Responding GW

Responding gateway receives a message from the NwHIN

END_INBOUND_MESSAGE

Responding GW

Responding gateway sends a response message over the NwHIN

BEGIN_INBOUND_PROCESSING

Responding GW

Beginning of the responding gateway's processing

END_INBOUND_PROCESSING

Responding GW

After the responding gateway has formulated a response

BEGIN_DELEGATION_TO_ADAPTER

Responding GW

Messages are delegated to the adapter for additional processing

END_DELEGATION_TO_ADAPTER

Responding GW

After the adapter has processed the message and formed a response

BEGIN_OUTBOUND_MESSAGE

Requesting GW

Requesting gateway receives a message from an adapter

END_OUTBOUND_MESSAGE

Requesting GW

Requesting gateway responds to a message from the adapter

BEGIN_OUTBOUND_PROCESSING

Requesting GW

At the beginning of the requesting gateway's processing

END_OUTBOUND_PROCESSING

Requesting GW

At the end of the requesting gateway's processing

BEGIN_INVOCATION_TO_NWHIN

Requesting GW

Message is sent to the responding gateway

END_INVOCATION_TO_NWHIN

Requesting GW

Response is returned from the responding gateway

MESSAGE_PROCESSING_FAILED

Any

Any time and represents a failure

Responding Gateway Life-Cycle State Diagram

Below are two diagrams depicting the life cycles as events for both inbound messages and outbound messages.

An inbound message that has successfully been responded to will record BEGIN_INBOUND_MESSAGE, BEGIN_INBOUND_PROCESSING, BEGIN_DELEGATION_TO_ADAPTER, END_DELEGATION_TO_ADAPTER, END_INBOUND_PROCESSING and END_INBOUND_MESSAGE in order. By analyzing the time differences between the BEGIN_INBOUND_MESSAGE and END_INBOUND_MESSAGE, one can tell how long it took to respond to a NwHIN request.  Failures can occur after any BEGIN event.  In the case of failure, a MESSAGE_PROCESSING_FAILED event will be logged instead of the matching END event.  Every BEGIN will be paired with either an END or a FAILED event.  Note that it is possible for one step in the processing chain to fail and an outer BEGIN/END pair to complete normally.

Requesting Gateway Life-Cycle State Diagram

An outbound message that has been successfully transmitted will record the following events in order: BEGIN_OUTBOUND_MESSAGE, BEGIN_OUTBOUND_PROCESSING, BEGIN_INVOCATION_TO_NWHIN, END_INVOCATION_TO_NWHIN, END_OUTBOUND_PROCESSING, and END_OUTBOUND_MESSAGE. By analyzing the time differences between BEGIN_OUTBOUND_MESSAGE and END_OUTBOUND_PROCESSING, one can tell how long it took to make a NwHIN request.  Failures can occur after any BEGIN event.  In case of failure, a MESSAGE_PROCESSING_FAILED event will be logged instead of the matching END event. Every BEGIN will be paired with either an END or a FAILED event.  Note that it is possible for one step in the processing chain to fail and an outer BEGIN/END pair to complete normally.

Class Diagrams

Extension Points

Events

By implementing the Event interface any class can become a new event. The EventManager has no knowledge about the Event implementation class--making this an ideal location for extension.

Event Loggers

Extending the abstract EventLogger and registering it with the EventManager. The new EventLogger is notified whenever an event occurs. EventManager has no knowledge about concrete EventLogger classes--making it an ideal location for extension.

Database Design

We use a single table to capture event information. Each event is a separate row in the database.

Field

Type

Null

Key

Default

Notes

id

bigint(20)

NO

PRI

NULL

auto_increment field acting as primary key.

name

varchar(100)

NO


NULL

From the event names enumeration

description

longtext

YES


NULL

JSON string. See data conversion below

transactionId

varchar(100)

YES


NULL

a unique id assigned to a single transaction that spans multiple NwHIN requests. For example, PD-QD-RD transaction will have a single unique transactionId.  

messageId

varchar(100)

YES


NULL

unique id to identify a request.

serviceType

varchar(100) 

YES
NULL string representing the type of NwHIN request.  
initiatingHcid

varchar(100) 

YES 
NULLhome community id of a  initiating gateway
respondingHcids varchar(100)YES 
NULL home community id of responding gateway(s)

eventTime

timestamp

NO


CURRENT_TIMESTAMP

CURRENT_TIMESTAMP. 1s precision in MySQL

Data Conversion

The description of each event is constructed from the request, response, and/or fault information.

Common Extractions

The following extractions are not specific to the message type. The extraction occurs from the SOAP envelope or explicit annotations in the java code.

Event Field

Cardinality

Field Value Location

Message ID

0..1

WS-Addressing Header 'Message ID' or from the request's assertion block. If not present, CONNECT generates Message ID and pass to Nwhin request.

Transaction ID

0..1

WS-Addressing Header 'RelatesTo' (if present). Otherwise, it holds the internal Transaction ID by Message ID (database lookup). Not present if RelatesTo and Message ID are empty.

Response Message IDs

0..n

Web Service Context 'RESPONSE_MESSAGE_ID_LIST'

Action

1

Envelope/Header/Action

Service Type

1

Service Type for instance Document Submission for DS request. It is an annotated  property (serviceType) in Java class.

Version

1

'version' property on event annotation in Java class.

Document Submission (Spec 1.1 and 2.0)

The XPath expressions below are rooted by either ProvideAndRegisterDocumentSetRequest or RegistryResponse. ProvideAndRegisterDocumentSetRequest is defined in the 'urn:ihe:iti:xds-b:2007' namespace by the IHE XML schema file 'XDS.b_DocumentRepository.xsd'. RegistryResponse is defined in the 'urn:oasis:names:tc:ebxml-regrep:xsd:rs:3.0' namespace by the oasis XML schema file 'rs.xsd'.

Event Field

Message Object

Cardinality

Field Value Location (XPath)

Payload Type

Request

1...n

ProvideAndRegisterDocumentSetRequest/SubmitObjectRequest/RegistryObjectList/ExtrinsicObject[1...n]/Classification[@nodeRepresentation="formatCode"]/Slot[@name="codingScheme"]/ValueList/Value[1]

Payload Size

Request

1...n

ProvideAndRegisterDocumentSetRequest/SubmitObjectRequest/RegistryObjectList/ExtrinsicObject[1...n]/Slot[@name=size]/ValueList/Value

Initiating HCID

Assertion

1

assertion/homeCommunity/homeCommunityId

Responding HCID

NhinTargetCommunities

1...n

nhinTargetCommunities/nhinTargetCommunity[1...n]/homeCommunity/homeCommunityId

NPI

Assertion

0,1

Available in the assertion as an AttributeStatement... but CONNECT currently doesn't support it.

Status

Response

1

RegistryResponse[@status]

Error Code

Response

0...n

RegistryResponse/RegistryErrorList/RegistryError[1...n][@errorCode]

Document Submission Deferred Request (Spec 1.1)

XDRAcknowledgement is defined in the 'http://www.hhs.gov/healthit/nhin' namespace by the NHIN XML schema file 'xdr.xsd'.
Same as Document Submission Spec 1.1 except:

Event Field

Message Object

Cardinality

Field Value Location (XPath)

Status

Response

1

XDRAcknowledgement/message[@status]

Error Code

Response

0...n

XDRAcknowledgement/message/RegistryErrorList/RegistryError[1...n][@errorCode]

Document Submission Deferred Request (Spec 2.0)

Same as Document Submission Spec 2.0.

Document Submission Deferred Response (Spec 1.1 and 2.0)

The XPath expressions below are rooted by either XDRAcknowledgement or RegistryResponse. XDRAcknowledgement is defined in the 'http://www.hhs.gov/healthit/nhin' namespace by the NHIN XML schema file 'xdr.xsd'. RegistryResponse is defined in the 'urn:oasis:names:tc:ebxml-regrep:xsd:rs:3.0' namespace by the oasis XML schema file 'rs.xsd'.

Event Field

Message Object

Cardinality

Field Value Location (XPath)

Payload Type

Request

0

Not Available

Payload Size

Request

1...n

Not Available

Initiating HCID

Assertion

1

assertion/homeCommunity/homeCommunityId

Responding HCID

NhinTargetCommunities

1...n

nhinTargetCommunities/nhinTargetCommunity[1...n]/homeCommunity/homeCommunityId

NPI

Assertion

0,1

Available in the assertion as an AttributeStatement... but CONNECT currently doesn't support it.

Status (Before Ack)

Request

1

RegistryResponse[@status]

Status (After Ack)

Response

1

XDRAcknowledgement/message[@status]

Error Code (Before Ack)

Request

0...n

RegistryResponse/RegistryErrorList/RegistryError[1...n][@errorCode]

Error Code (After Ack)

Response

0...n

XDRAcknowledgement/message/RegistryErrorList/RegistryError[1...n][@errorCode]

Retrieve Document

The XPath expressions below are rooted by either DocumentResponse or RegistryResponse. DocumentResponse is defined in the 'urn:ihe:iti:xds-b:2007' namespace by the IHE XML schema file 'XDS.b_DocumentRepository.xsd'. RegistryResponse is defined in the 'urn:oasis:names:tc:ebxml-regrep:xsd:rs:3.0' namespace by the oasis XML schema file 'rs.xsd'.

Event Field

Message Object

Cardinality

Field Value Location (XPath)

Status

Response

1

RegistryResponse/Status

Responding HCIDs

Response

0..*

DocumentResponse/HomeCommunityId

ErrorCode

Response

0..*

RegistryResponse/RegistryErrorList/RegistryError

Document Query

The XPath expressions below are rooted by either AdhocQueryResponse, RegistryErrorList, or RegistryObjectList. AdhocQueryResponse is defined in the 'urn:oasis:names:tc:ebxml-regrep:xsd:query:3.0' namespace by the oasis XML schema file 'query.xsd'. RegistryErrorList and RegistryObjectList are defined in the 'urn:oasis:names:tc:ebxml-regrep:xsd:rs:3.0' namespace by the IHE XML schema file 'rs.xsd'.

Event Field

Message Object

Cardinality

Field Value Location (XPath)

Status

Response

1

AdhocQueryResponse/Status

Responding HCIDs

Response

0..*

RegistryObjectList/ExtrinsicObject/Home

ErrorCode

Response

0..*

RegistryErrorList/RegistryError/ErrorCode

Payload Type

Response

0..*

RegistryObjectList/ExtrinsicObject/Classification[@nodeRepresentation="formatCode"]/Slot[@name="codingScheme"]/ValueList/Value[1]

Payload Size

Response

0..*

RegistryObjectList/ExtrinsicObject/Slot[@name="size"]/ValueList/Value[1]

Patient Discovery

The XPath expressions below are rooted by either MCCI_IN000002UV01 or PRPA_IN201306UV02. MCCI_IN000002UV01 is defined in the 'urn:hl7-org:v3' namespace by the HL7 schema file 'MCCI_IN000002UV01.xsd'. PRPA_IN201306UV02 is defined in the 'urn:hl7-org:v3' namespace by the HL7 XML schema file 'PRPA_IN201306UV02.xsd'.

Event Field

Message Object

Cardinality

Field Value Location (XPath)

Status

Response

0..*

MCCI_IN000002UV01/acknowledgement[0..n]/acknowledgementDetail[0..n]/text[0]
Note: text may be base64 encoded.  The audit log will be the decoded value.

Responding HCID

Response

0..*

"urn:oid:" + /PRPA_IN201306UV02/controlActProcess/subject/registrationEvent/custodian/assignedEntity/id[root]

Admin Distribution

The XPath expressions below are rooted by EDXLDistribution, defined in the 'urn:oasis:names:tc:emergency:EDXL:DE:1.0' namespace by the oasis schema file 'edxl-de.xsd'.

Event Field

Message Object

Cardinality

Field Value Location (XPath)

Error Codes

Request

0

N/A

Payload Sizes

Request

0..*

EDXLDistribution/contentObject/nonXMLContent/size
+ EDXLDistribution/contentObject/XMLContent 
 (/keyXMLContent/size + /embeddedXMLContent/size)

Payload Types

Request

0

N/A

Responding HCIDs

Request

0

N/A

Statuses

Request

0..1 (required by schema, but no validation so may be empty)

EDXLDistribution/distributionStatus

TimeStamp

Request

0.. 1

EDXLDistribution/dateTimeSent

Application Programming Interface

The following classes and interfaces are anticipated APIs that adopters may call Event, EventRecorder, EventLoggerRegistrar, EventFactory, or EventLogger.

Performance

CONNECT can enable the ability to get more comprehensive performance logging and metric data (counts and duration) using improved logging. Event logging performance is characterized by (1) event generation and (2) event recording. Event generation occurs at greater than 3000 events / minute (50 events / second), sustained, in our test environment. Event recording to the log4j and/or event database meets the same performance. Adopter implementations of either event generation or event recording will impact the performance of the entire CONNECT solution. By default all event logging is synchronous.