The Output Prefix

The output prefix is that initial portion of each output record that has the same structure as every other, and consists of six fields. The first three are generated by the shim, possibly with help from the system logger, but without reference to the event type. The last three, the src-tag-ver triple, are event specific; in the case of requests and messages, the tag and ver are defined by the IB tws api.

Table 4.3 gives an example of the output prefix as captured by the system logger; the text of the table differs from that actually logged in that the vertical bars that originally separated the fields are here indicated by column rules, and a heading has been added for clarity.

There are actually two forms of output prefix, as the shim performs IO directly to a file descriptor, or this task is delegated to the system logger via the syslog() standard library call, in which case that procedure prepends additional text. Here the prepended text consists of the date, formatted time, hostname, and following colon. Note that although the textual value of the initial field differs, the number of columns in the table, and number of fields that would be counted by splitting on vertical bars, remains the same.

Table 4.3: Examples of the output format prefix

prepended log text and process id	seconds	$\mu$ secs	src	tag	ver
May 8 10:27:54 pippin : 27865	37674	1010583	4	100	5
May 8 10:27:54 pippin : 27865	37674	1010590	4	100	5
May 8 10:27:54 pippin : 27865	37674	1010598	4	100	5
May 8 10:27:54 pippin : 27865	37674	1010643	3	9	1
May 8 10:27:54 pippin : 27865	37674	1343459	3	4	2
May 8 10:27:54 pippin : 27865	37674	1343500	2	2	0
May 8 10:27:54 pippin : 27865	37674	1343515	2	7	0

Considering the leftmost three fields, the process id, here 27865, can be used to group log records by session. The seconds since midnight and $\mu$secs values (see § 8.6, § 9.2.1, and § C.2.3) are primarily of use in benchmarking performance, although they in addition provide a unique key for the events of that day. Given 37674 seconds since midnight and noting that $37674 = 60 \times (60 \times 10 + 27) + 54$, we confirm that the session occurred at 10:27:54 am. Although duplicative here, direct output to a file would lack the logger prepend, so that the seconds field is not in general redundant.

The three rightmost fields are probably more widely used than the first three, since together they map one-to-one to the event type, so that they enable event type switching, about which more in the next section.