In This Section
Overview
Enabling message trace logging for an application can be useful in tracking down issues with message routing or message content. It can be enabled via the application configuration.
Enabling Message Trace
Message tracing is intended for debugging purposes and has very high overhead. For production auditing Binary Logging should be used instead.
The following ddl config snippet shows an application configured with message trace enabled:
The table below briefly describes the knobs that control message trace. See DDL Reference for more details.
property | Description |
|---|---|
| <enableMessageTrace> | Enables / disables diagnostic message tracing. |
| One of JsonPrettyPrintStyle (Default is SingleLine) | |
| One of MetadataDisplayPolicy (Default is Only) | |
| true or false, new feature to filter values for fields that aren't set (instead of display their default values) (Default is true) | |
| true or false, whether or not to output in json format, setting to false uses a more efficient text based display, but doesn't support single line or unset field filtering (Default is True) |
Message Trace Logger Name
When message tracing is enabled it is logged to the logger named 'nv.aep.msg' at level 'debug' by the applications AepEngine. When using SLF4J, use the SLF4J concrete logger configuration mechanisms to set the nv.aep.msg logger's trace level to TRACE to ensure message trace is emitted.
Message Trace Output
The following shows sample trace output for the Talon Starter applications processor
Understanding Message Trace Output
The above output uses Json Pretty printing with message metadata included. The trace prints the following:
- the engine name
- trace point for the message,
- the classname of the object,
- ...followed by metadata
- ...and the object fields (in this case with unset fields filtered).
Metadata
Metadata fields are defined in the IRogMetadata. They are summarized here for convenience.
Field | Description |
isMessage | Indicates whether the object is a message or not. This will always be true for message trace output |
isInboundMessage / isOutboundMessage | Indicates the message direction. Permissible values are in or out. Inbound messages, designated by in, are messages received inbound for processing on the primary or backup. Outbound messages, designated as out, are solicited or unsolicited messages sent by an application. |
|
|
messageBus | The bus on which the message was sent/received
|
messageChannel | The channel on which the message is sent/received
|
messageKey | The resolved message key i.e. the topic on which the message was sent/received
|
messageSender | The system-wide unique id of the message's sender. If outbound, the sender is the AEP engine that output the trace. |
messageFlow |
|
messageSequenceNumber | The message's sequence number. If outbound, then the message sequence number is assigned from the AEP engine's sequence number space it maintains for outbound messages. The difference, in value, between this field and the value of the Stable field indicates the number of outbound messages that are in the outbound 'pipeline' i.e. the number of messages pending acknowledgement from downstream agents. |
|
|
graphId |
|
parentId |
|
|
|
inMsgsInTransaction |
|
outMsgsInTransaction |
|
transactionInSequenceNumber | This field contains the inbound sequence number of a message relative to the transaction that it is part of. For inbound messages, this field contains the seuence number of the message (starting at 1) relative to the set of inbound messages that form the transaction. For outbound messages, this field contains the number of the inbound message in the transaction that triggered the outbound message. The transaction inbound sequence number starts at 1 for each transaction. |
transactionOutSequenceNumber | This field contains the outbound sequence number of a message relative to the transaction it is part of. For inbound messages, this field is always 0. For outbound messages, this field contains the sequence number of the message (starting at 1) relative to the set of outbound messages emitted by the transaction. The transacton outbound sequence number restarts at 1 for each transaction. |
possibleDuplicate | A backup engine in a clustered configured for EventSourcing with ReplicateBeforeSend holds outbound messages in an outbound queue. The primary piggybacks acknowledgements received from downstream for the outbound message sin the replication traffic which clear out the queue. When a primary fails over to the backup, the backup retransmits all unacknowledged messages in the outbound since it treats them as in-doubt. An engine uses this field to mark the message as 'possible duplicates' when retransmitted. |
|
|
outTs / | This field contains the timestamp at which a message was sent by an application. This timestamp does not record the time at which the message was actually written to the wire; a sent message is written to the wire when the transaction that it is part of is committed.
|
preProcessingTs /preProcessingTsMicros | This field contains the timestamp just before the message was dispatched for processing to app. Received messages may be traced prior to the message being dispatched to the application so this field may be unset at certain points in the message trace.
|
enqueueTs / | This field contains the timestamp just before a message was enqueued on an application's input queue. This timestamp can be compared with the preProcessingTs to determine the amount of time that the message spent on an application's input queue (unless the message is one received by a backup instance in which case preProcessingTs will have the Primary's preProcessingTs value.
|
Internal to the X Platform ***Point in Flow
An AEP engine output message trace at different points of the flow of the message through the engine. The highlighted portion above contains the point in the flow of the message at which point the trace was output. The following are the various permissible values:
| Point | Description | Primary/Backup |
|---|---|---|
| [MSG-IN] | A message was dispatched to the applications aep engine | Both |
| [MSG-IN-DUP] | The received message was flagged as a duplicate | Primary |
| [MSG-IN-FILTERED] | An inbound message was filtered by an application message filter | Primary |
| [MSG-REPL-OUT] | A message was queued for replication | Primary |
| [MSG-PER] | A message was queued for persistence | Both |
| [OBJ-ADD-IN] | A state object was added (from replay or primary member) | Backup |
| [OBJ-REM-IN] | A state object was removed (from replay or primary member) | Backup |
| [OBJ-UPD-IN] | A state object was removed (from replay or primary member) | Backup |
| [MSG-REPL-IN] | A message was received from the store (from replay or primary member) | Backup |
| MSG-OUT-Q | Output when an application performs an outbound send on a backup that is queued | Backup |
| [MSG-OUT] | An outbound message was sent via underlying bus transport (...not yet acked) | Primary |
Note that the metadata fields isInboundMessage and isOutboundMessage can be useful in cases where the same message type is both sent and received by an application where it might be otherwise confusing whether the message was a sent or received message.
Object Content
The values of the message fields are traced. If a message field is not set and messageTraceFilterUnsetFields is true then the field will be omitted for brevity. If a value is null or the default value it indicates that the application has explicitly set the field that way.