[ts-gen] [Re:] timestamps

Bill Pippin pippin at owlriver.net
Mon Oct 25 16:55:12 EDT 2010


It's good to hear from you.  Thanks for posting, and I hope
the shim is serving your purposes well.  About the shim's log
timestamps, you ask:

> is there an easy way to produce timestamps as milliseconds
> since midnight?

I'm a little concerned that this is not reasonably obvious,
given a test session; perhaps there is a portability issue I'm
not aware of that you are running into.  So, once you see
from the following how to interpret your log file, please let
us know whether or not that file gives you a microsecond
clock, as explained below.

As long the shim provides such a clock, the answer to your
question above would be: "Yes, just divide the high-frequency
part of the log time stamp pair by 1000 and you're set."

First, let me restate here what you may already know: log
file records have a common prefix, the first three fields of
which consist, first, of the process id; second, the low
frequency clock, seconds since midnight; and third, the high
frequency clock, either, with the "diff" option, a fractional
difference relative to the previous time stamp with seconds units,
and microsecond precision; or else, without that option --- and,
for your purposes, you want to avoid the "diff" option --- an
unsigned int value counting microseconds since startup, or since
the last rollover, whichever occurred most recently. 

So, for a 32bit system, you should see rollover around 70 minutes
after startup, and with 64bit, not at all; and in either case, since
the low and high frequency clocks stay closely in sync, you just
use the first of the timestamp fields to measure seconds, and the
second, modulo 10^6, to measure microseconds.

You can check this by running a shim session for a couple of hours,
started without the "diff" option and including a market data or
market depth subscription to ensure frequent time stamp updates.
The low and high frequency clocks should stay closely in sync.

E.g, on a 64bit dell here, and using "wait 3600" to control a one
hour session with a market depth subscription earlier this afternoon, 
the log shows approximately the same number of elapsed seconds for both
the low frequency and high frequency fields:

    3323|50612|   4056484|1|10| 0|select book STK:ISLAND:IBM:USD 25;|
    3323|50612|   4078191|1| 0| 0|                 wait 3600;|
    3323|50612|   4056646|2|10| 3|10|3|2|IBM|STK||0.0000||1|ISLAND|..
    3323|50612|   4559833|3|13| 1| 2|0|NSDQ|0|1|...| 1|insert|bid|...
    3323|54209|3601774934|3|13| 1| 2|9|NSDQ|1|1|...|11|update|bid|...
    3323|54212|3603926113|1|11| 0|cancel book STK:ISLAND:IBM:USD;|

         54212 3603926113
       - 50612  - 4078191
         ----- ----------
          3600 3599847922

Note above that, due to limited accuracy of the processor frequency
factor used to convert processor read timestamp counter values to 
time, there is some slight clock skew.  That being said, the high
frequency counter is reset once each IO time slot (about 20 msecs)
using the result from gettimeofday, so that skew is kept within
tight bounds.

Note also that we may in the future change the resolution of the
high frequency counter to nanoseconds, in order to provide a unique
id for journal records, and in that case rollover for a 32bit
system would occur each four seconds or so, still well beyond the
one second resolution of the low frequency clock.

Finally, I'd like to confirm what Russ said, that time stamp values
are with respect to the time the message is read from the IB tws.  

If you want to compare the shim's view of the system clock with
the IB tws process' view of that same clock, and keeping in mind
that there is a tcp socket read in between, you can look at the
payload value returned by the "select time" command, which generates
an IB tws api ReqCurrentTime event, along with the shim's timestamps
for the sent request and returned message events.

There is no way that I know of to accurately determine the clock
used by IB's upstream servers, other than by comparison of the
market data they send with that from other data feeds.  I suspect
you'll find such investigation to be fruitless, and Russ has
addressed this point in the past on the Yahoo list.



More information about the ts-general mailing list