Monday, July 19, 2010

FIX logs analyzer. Part I.

FIX Log Analyzers (FIX Grep and FIX Eye) are the small tools, which were started for internal use only, developed with the lapse of time and finally grew up to the powerful (but still lightweight) product suit.

BTW Today there is a free demo version of FIX Eye available for download from official B2BITS web site.

Originally the main purpose of the utility was making testers' life easier. Namely:
  • Help FIX  newbies read and understand FIX logs
  • Save time for searching orders and related messages in logs to analyse order life-cycle
Additional requirements were:
  • Deal with any free-form text file (often there is a need to extract messages from log files with a lot of debug info)
  • Deal with multiple files (in most cases in and out messages are stored in multiple files, also data for different sessions can be in different files)
  • Deal with archives (log files grow fast so there is a need to take into account housekeeping procedures normally performed at the end of the day)

We started from the command-line tool, which would do all described above and obviously the best command tool pattern to fiollow was grep (I can hardly imagine solid developer or tester not familiar with grep syntax and regular expressions).
In the result we came up with the FIX Grep command line tool, which covered above-mentioned requirements (and does a bit more) plus mimicked the well-known grep interface. What does FIX Grep add to grep? It is not just several items however here are the most essential:

Grep: search unit is a line
FIX Grep: search unit is a FIX message (which obviously can be multi-line)

Grep: knows nothing about data semantics
FIX Grep: knows about FIX i.e. you can search for Execution Report instead of 35=8

Grep: treats line as sequence of bytes
FIX Grep: still can treat line as a sequence of bytes however it is possible to have search criteria specified separately for FIX fields, which is much easier in FIX Grep since the order of fields is undefined in FIX.

It seem the latest requires more explanation. The easiest way is to give an example. Let's say our goal is to find all buy market orders. In fact this means that we need to find all messages with 35=D (let it be New Order Single), 40=1 (OrdType), 54=1 (Side). Does not look like a challenging task for grep unless you realize that the order of the fields is not fixed, which makes you composing a sequence of calls. With the FIX Grep it is possible to specify filters separately for each field and do not care about their order.

There are many more features in FIX Grep as now it is a mature product. People are using it mostly in Linux (as we have beautiful Windows GUI alternative ;)). However there is another application of FIX Grep - reporting. It appeared that FIX Grep perfectly suitable for automated reports creation thanks to its extra features like building list of orders in their latest state, calculated total executed quantity and obviously export to CSV.

From FIX Grep to FIX Eye
FIX Eye was started pretty much similar to FIX Grep. It did not look like a big deal originally to extend FIX Grep to a GUI tool. But (pardon for truism) devil was in the details.

Obviously we have started from mock-ups and that was the first glitch. The battle started between myself and Mark. I was a strong proponent of kind of electronic tables style, whereas Mark insisted on a kind of search engine interface. The right answer (as it always happens) appeared to be a combination of two:

Search engine style:

Electronic table style:

Application starts in minimalistic shape, all floating panels are hidden, only search string is shown. Looks familiar, eh? Any text can be put in the search field, FIX Grep engine will find all relevant messages and show in table. The small injection of "my" approach is "show all" button - just press it and you will see all messages, which FIX Grep engine is able to find (needless to say that it can find everything, even invalid messages; just make sure that files are not encrypted).

Press the search button - and FIX Eye displays electronic table with all features you've got used to. Each message is a row, each field is a column. You can scroll, search in table, customize columns, sort, apply quick filter, and many more. The small injection of Mark's style here is a search edit box in the tool bar, which can be used any time to search for new data.

There are many more features of FIX Eye as a viewer but I will keep them for the second part of the review. Feature I would like to talk more about here is "order back-trace" as it was the first feature, which made FIX Eye something more than just a viewer.

Order back-trace
The idea of order back-trace (also referred as "order history") is pretty simple. For any given message in chain linked to an order FIX Eye should be able to identify original order, all its permutations (calculate intermediate states) and the final (current) state.

In fact the task consists of several subtasks:

  1. Find all relevant message
  2. Order messages by time
  3. Draw the diagram
Subtask 1 is quite trivial - FIX Protocol defines several identifiers, which simplify reverse engineering: OrderID, ClOrdID, OrigClOrdID. When all of them are populated (which is 99% the case) the lookup is straightforward.
Subtask 2 in most case is a challenge number one. At a glance it looks like trivial task - just rely on the order of messages in log file. However most applications write incoming and outgoing messages to the different files (from performance perspective; sending and receiving are two independent processes and you would not like them to have common file to write to, which would result in yet another synchronization point; for example B2BITS FIX Engine creates 2 separate files to log FIX messages; .in and .out). At the same time accuracy of the time fields in FIX is not enough to make definite decision as in modern systems messages can be received and sent even in the same millisecond. Fortunately in some cases you can make decision based on the context and sometime it is just not that important say if partial fill was received before or after replace request was sent.
Subtask 3 was the most disputable. The very first idea was just a table of messages that created the story. But obviously we were looking for something graphical, which would require just a quick glance. After all we have invented something like a mix between activity/state and sequence diagrams.
Here we have requests in the left column, execution reports in the right column and states in the middle.
The bottom part is a table with all relevant messages. The right most panel contains message description - you can select any figure on th picture or message in table.

The text on the figure is customizable. By default it is configured to show the most useful information - quantities, price, market, etc. But it is possible to change the template for each type of the figure.

There was an idea that after cancel request there are in fact two orders: the old one, which is not yet cancelled (until UROUT is received) and the new one, which is already created but not yet in force (until the old one is out). I believe the origin of this idea is the fact that you have two different requests (each with its own ClOrdID), for which you can receive execution report. If we followed this idea we would have to split the state on two different states on request and consider composite state. So far I think that this would overload the picture whereas benefits are doubtful. Still there is a chance that we will go this way.

To be continued.

No comments:

Post a Comment