Troubleshooting example: trade rejection

The Caplin stack provides many log files that can help you find the cause of an issue. Using a trade submission rejection as an example, this page walks you through the process of tracking an issue back through the layers of the Caplin stack.

The error message in the web application

In this example, a user’s request for an RFS SPOT price on GBPUSD has been rejected.

the trade submission failed

The error message provides no detail on the cause of the rejection. To find out more information, we need to trace the issue back to the log file closest to where the rejection occurred. The first log to examine is the web application’s StreamLink log.

The StreamLink log is disabled by default. To enable StreamLink logging:

  1. Append the querystring "?debug=fine" to the web application’s URL, and reload the web application. The value 'fine' specifies the level of logging detail. There are three possible levels of detail, shown below:

    • fine — used for tracing messages. This level includes the size of the response queue and the update queue for messages received from Liberator.

    • finer — used for fairly detailed tracing messages. This level includes the RTTP messages sent in each direction between the client and Liberator.

    • finest — used for the most detailed tracing messages. This level includes the HTTP headers of the HTTP communication with Liberator.

  2. If your browser notifies you that it has blocked a popup window, enable popups for this URL and reload the web application.

With StreamLink logging now enabled, repeating the request for stream generates the following log entries:

<timestamp> - FINE   : Out - Contrib [subject=/PRIVATE/TRADE/FX, fields=[MsgType=Submit,...
<timestamp> - FINE   : In - ContribEvent [subject=/PRIVATE/TRADE/FX]
<timestamp> - FINE   : In - ActionFailEvent [subject=/PRIVATE/TRADE/FX]

Looking at each log entry in turn:

  • "Out - Contrib" records the trade submission to Liberator. The submission is recorded as a 'Contrib' (a contribution) to the FX trade channel, /PRIVATE/TRADE/FX. Channels are one-to-one subscriptions between a client and the Caplin Platform that enable the exchange of messages. The knowledge that /PRIVATE/TRADE/FX is a messaging channel will be important when we come to analyse server-side logs (next section).

    There are three signs that /PRIVATE/TRADE/FX is a channel. Firstly, /PRIVATE/TRADE/FX is the conventional subject of the FX trade channel in Caplin’s FX solutions. Secondly, the 'PRIVATE' namespace is conventionally reserved for channels. Thirdly, we know from the log that a client contribution was made to the /PRIVATE/TRADE/FX, and client contributions are only made to channels.

  • "In - ContribEvent" records Liberator’s successful reception of the contribution.

  • "In - ActionFailEvent" records Liberator’s failure to process the contribution. The reason is not given.

We now know that the contribution to the /PRIVATE/TRADE/FX channel was acknowledged by Liberator, but the processing of the contribution failed for an as-yet-unknown reason. The next step is to search Liberator’s logs for more information.

Analysing Liberator’s log

Liberator’s general log is located at <dfw-path>/servers/liberator/var/event-rttpd.log, where <dfw-path> is the path to your Caplin Deployment Framework installation.

The string to search for in the event-rttpd.log file is dependant on the configuration of the Caplin Platform. Liberator handles all subscriptions to /PRIVATE/TRADE/FX as individual channels. While all users who subscribe to /PRIVATE/TRADE/FX subscribe to the same subject, internally Liberator will map each user’s subscription to a new private subject, creating a one-to-one, bi-directional channel of communication between each user and the Caplin Platform. The logs of Caplin Platform components record the internal subjects of channels; thus we need to know what subject /PRIVATE/TRADE/FX maps to if we are to search for it.

Mapping schemes are configured using Liberator’s object-map configuration item. To find the mapping scheme used for /PRIVATE/TRADE/FX, search for the string "object-map" in your Deployment Framework’s directory hierarchy. In this example, which uses a RET backend, we find that the mapping used is:

object-map          "/PRIVATE/TRADE/FX"   "/PRIVATE/TRADE/FX/%u"

The %u in the second parameter indicates that the user’s username will be appended to the channel’s subject, so the string we need to search for is "/PRIVATE/TRADE/FX/user1@example.com".

Searching event-rttpd.log for "/PRIVATE/TRADE/FX/user1@example.com" finds the entry below. The important information is highlighted in yellow:

<timestamp>: INFO: Contrib by <0uHQ0H6cmPiJFiwLdk6J5u> to </PRIVATE/TRADE/FX> failed: auth denied for </PRIVATE/TRADE/FX/user1@example.com> with code 0

The issue is a permissions issue, and for more information we will need to consult the logs of Liberator’s Permissioning Service.

Analysing the Permissioning Service log

The Permissioning Service log is located at <dfw-path>/servers/liberator/var/auth-rttpd.log, where <dfw-root> is the path to your Caplin Deployment Framework installation.

The default logging level of the Permissioning Service is INFO. You need to set the logging level to at least DEBUG in order to capture the reason behind a pass or fail decision.

To change the logging level of the Permissioning Service:

  1. Open <dfw_root>/global_config/overrides/<permissioning_adapter_blade>/Liberator/etc/javaauth.conf for editing.

  2. Change the log-level configuration option to DEBUG.

  3. Save your changes.

  4. Restart the Deployment Framework.

    ./dfw stop
    ./dfw start

If you have updated the logging level of the Permissioning Service, you will need to repeat the RFS trade submission in your web browser in order to capture new, more-detailed log messages.

Search auth-rttpd.log for entries that end in "…​for user user1@example.com to contrib on product /PRIVATE/TRADE/FX/user1@example.com". Each of the log entries returned contains information about a permission that was checked. For example, the log entry below records a check for permission to trade in GBPUSD.

checkWrite: criteria=PermissionMatchCriterion[product=[ALL_PRODUCTS],permissionNameSpace=FX_CURRENCY_PAIR_TRADE_LIST, action=GBPUSD] for user user1@example.com to contrib on product /PRIVATE/TRADE/FX/user1@example.com

You will find several such permission checks. Scroll through until you find the one that failed:

checkWrite request by user1@example.com to /PRIVATE/TRADE/FX/user1@example.com result: Authentication result: Failure: Denied

Prior to the log entry detailing the failure, you will find an entry that provides the reason for the authentication failure.

PermissioningEngine MASTER: NO_PERMISSION RFS-SPOT action in permissionNameSpace FX_RFS for user user1@example.com on product ALL_PRODUCTS

Conclusion

The request for an RFS SPOT price on GBPUSD was rejected because user1@example.com has not been assigned the RFS-SPOT permission.

See also: