Page History

...

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

Code Block

language	js

<16,8484,MY-COMPUTER> 20180830-13:06:14:836 (dbg)...[

AepEngine<processor-receive-driver>

AepEngine<processor>] [MSG-IN] {


  "className" : "com.neeve.

embedded_xvm_sample.

talon.starter.messages.

Event

Message",


  "metadata" : {

"graphId" : 0,
"inMsgsInTransaction" : false,
"isInboundMessage" : true,
"isInternal" : false,
"isLastTransaction" : false,
"isMessage" : true,
"isOutboundMessage" : false,
"isReplayedMessage" : false,
"messageBus" : null,
"messageChannel" : null,
"messageFlow" : 0,
"messageKey" : null,
"messageSender" : -1094759278,
"messageSequenceNumber" : 1000,
"outMsgsInTransaction" : false,
"outTs" : null,
"parentId" : null,
"preProcessingTs" : null,
"possibleDuplicate" : false,
"transactionInSequenceNumber" : 1,
"transactionOutSequenceNumber" : 0
},
"object" : {
"count" : 1000,
"val" : "hi"
}


    "enqueueTs" : "20180830-20:06:14.799",
    "enqueueTsMicros" : 1535659574799337,
    "graphId" : 0,
    "inMsgsInTransaction" : false,
    "isInboundMessage" : true,
    "isInternal" : false,
    "isLastTransaction" : false,
    "isMessage" : true,
    "isOutboundMessage" : false,
    "isReplayedMessage" : false,
    "messageBus" : "processor",
    "messageChannel" : "requests",
    "messageFlow" : 0,
    "messageKey" : null,
    "messageSender" : -905962955,
    "messageSequenceNumber" : 252,
    "outMsgsInTransaction" : false,
    "outTs" : null,
    "outTsMicros" : 0,
    "parentId" : null,
    "preProcessingTs" : null,
    "preProcessingTsMicros" : 0,
    "possibleDuplicate" : false,
    "transactionInSequenceNumber" : 1,
    "transactionOutSequenceNumber" : 0
  },
  "object" : {
    "count" : 252
  }
}

Understanding Message Trace Output

...

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

The following describe each of the message metadata fieldsMetadata 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 For received messages this value is only set if received from a message bus configured to set the bus name on receipt.
messageChannel	The channel on which the message is sent/received For received messages this value is only set if received from a message bus configured to set the channel name on receipt.
messageKey	The resolved message key i.e. the topic on which the message was sent/received For received messages this value is only set if received from a message bus configured to set the received channel key on receipt.
messageSender	The system-wide unique id of the message's sender. If outbound, the sender is the AEP engine that output the trace.
messageFlow	Internal to the X Platform ***
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	Internal to the X Platform ***
parentId	Internal to the X Platform ***

inMsgsInTransaction	Internal to the X Platform * (for transaction correlation) Note:** This field should not be confused with the direction of a traced message. This field actually indicates rather the opposite. It is used in outbound messages to indicates whether the transaction that the outbound message is part of contains inbound messages or not.
outMsgsInTransaction	Internal to the X Platform * (for transaction correlation) Note:** This field should not be confused with the direction of a traced message. This field actually indicates rather the opposite. It is used in inbound messages to indicates whether the transaction that the inbound message is part of contains outbound messages or not.
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. Note: All message retransmission is performed on failover using a separate transaction. Therefore, that specific transaction will not contain any inbound messages, all outbound messages will have the possible duplicate flag set and all messages will have the same transaction id. This transaction is the one that demarcates transactions that were performed by the agent as a backup from the transactions performed by the agent as a primary post failover.

outTs / outTsMicros	This field contains the timestamp at which a message was sent by an engineapplication. This fields is always populated by an engine for sends performed on an event sourced backup. However, on a primary, the engine delegates the responsibiity of stamping the outbound timestamp to the concerete message bus binding at play. Please refer to whether the concrete binding deployed support populating this field before relying on its presence.preProcessingTstimestamp 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. This field is populated by the engine when application calls sendMessage when it is configured to capture support metadata The timestamps reflect the number of milliseconds (or microseconds) since the epoch.
preProcessingTs /preProcessingTsMicros	This field contains the timestamp just before the message was dispatched for processing to app. This field will always contain the same value when dispatched on the primary and all backups in a cluster. This field is guaranteed to be populated and can be relied upon as the time a message was received by the application 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. The timestamps reflect the number of milliseconds (or microseconds) since the epoch. Because the pre-processing timestamp is used to provide HA consistent time for an application that is using Event Sourcing as an HaPolicy, this value is guaranteed to be set to the same value as used on the primary instance. A backup instance or a primary recovering from a transaction log will see the original preProcessingTs value.
enqueueTs / enqueuTsMicros	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. This field is populated by the engine when application calls sendMessage when it is configured to capture support metadata The timestamps reflect the number of milliseconds (or microseconds) since the epoch.

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:

...

The Talon Manual

Additional Links

Versions Compared

Old Version 3

New Version Current

Key

Message Trace Output

Understanding Message Trace Output

Metadata

Point in Flow