OnBarUpdate timing issue

[drtomaso]

I'm seeing something a bit unexpected with the OnBarUpdate method, while using time based charts on MarketDataType.Last. Namely, the timestamp difference between the bar (Time[0]) and current system time (DateTime.Now) can vary wildly- more so than can be explained by clock differences or routine market data transmission delays.

To test, I have written a simple strategy that compares Time[0] and DateTime.Now, and outputs the difference in seconds. I also made sure to sync my system clock before each test, to minimize the impact of clock-skew. I then ran it in real time on 15s Last time series, choosing the 15 seconds only to generate a lot of data points quickly- I have also run this on minute charts with similar results, and can provide documentation of that if needed.

Here are some sample outputs:
1/31/2013 1:11:00 PM Instrument SPYBar Series: 0 Current System Time: 1/31/2013 1:11:00 PM Bar Time: 1/31/2013 1:11:00 PM Bar is 0.9987365 stale.
1/31/2013 1:11:15 PM Instrument SPYBar Series: 0 Current System Time: 1/31/2013 1:11:20 PM Bar Time: 1/31/2013 1:11:15 PM Bar is 5.5912325 stale.
1/31/2013 1:11:30 PM Instrument SPYBar Series: 0 Current System Time: 1/31/2013 1:11:30 PM Bar Time: 1/31/2013 1:11:30 PM Bar is 0.7175375 stale.
1/31/2013 1:11:45 PM Instrument SPYBar Series: 0 Current System Time: 1/31/2013 1:11:45 PM Bar Time: 1/31/2013 1:11:45 PM Bar is 0.5603375 stale.
1/31/2013 1:12:00 PM Instrument SPYBar Series: 0 Current System Time: 1/31/2013 1:12:04 PM Bar Time: 1/31/2013 1:12:00 PM Bar is 4.2778895 stale.
1/31/2013 1:12:15 PM Instrument SPYBar Series: 0 Current System Time: 1/31/2013 1:12:15 PM Bar Time: 1/31/2013 1:12:15 PM Bar is 0.9021455 stale.
1/31/2013 1:12:30 PM Instrument SPYBar Series: 0 Current System Time: 1/31/2013 1:12:30 PM Bar Time: 1/31/2013 1:12:30 PM Bar is 0.558434 stale.
1/31/2013 1:12:45 PM Instrument SPYBar Series: 0 Current System Time: 1/31/2013 1:12:45 PM Bar Time: 1/31/2013 1:12:45 PM Bar is 0.7713275 stale.
1/31/2013 1:13:00 PM Instrument SPYBar Series: 0 Current System Time: 1/31/2013 1:13:00 PM Bar Time: 1/31/2013 1:13:00 PM Bar is 0.710801 stale.
1/31/2013 1:13:15 PM Instrument SPYBar Series: 0 Current System Time: 1/31/2013 1:13:19 PM Bar Time: 1/31/2013 1:13:15 PM Bar is 4.8003995 stale.
1/31/2013 1:13:30 PM Instrument SPYBar Series: 0 Current System Time: 1/31/2013 1:13:32 PM Bar Time: 1/31/2013 1:13:30 PM Bar is 2.0535215 stale.
1/31/2013 1:13:45 PM Instrument SPYBar Series: 0 Current System Time: 1/31/2013 1:13:45 PM Bar Time: 1/31/2013 1:13:45 PM Bar is 0.0155825 stale.
1/31/2013 1:14:00 PM Instrument SPYBar Series: 0 Current System Time: 1/31/2013 1:14:03 PM Bar Time: 1/31/2013 1:14:00 PM Bar is 3.4265135 stale.
1/31/2013 1:14:15 PM Instrument SPYBar Series: 0 Current System Time: 1/31/2013 1:14:25 PM Bar Time: 1/31/2013 1:14:15 PM Bar is 10.30109 stale.

So, we see delays ebbing and flowing between 0.01s and 10.3s. Anyway, I started to develop a theory, so I switched to something more thinly traded. Here is what I saw for the same strategy, applied to a 15s bar last of ERX- its completely and unbelievably off.

1/31/2013 1:17:45 PM Instrument ERXBar Series: 0 Current System Time: 1/31/2013 1:18:11 PM Bar Time: 1/31/2013 1:17:45 PM Bar is 26.1294095 stale.
1/31/2013 1:18:15 PM Instrument ERXBar Series: 0 Current System Time: 1/31/2013 1:26:47 PM Bar Time: 1/31/2013 1:18:15 PM Bar is 512.8131365 stale.
1/31/2013 1:27:00 PM Instrument ERXBar Series: 0 Current System Time: 1/31/2013 1:29:46 PM Bar Time: 1/31/2013 1:27:00 PM Bar is 166.736255 stale.

To make matters worse, I had a 15s last chart of ERX up at the same time- OnBarUpdate appears to have never fired for a bar at 13:18:00 that is displayed on the chart. I also witnessed the bar at 13:27:00 remain on the chart for several minutes- as a solid green bar- suddenly update after several minutes, to solidly red.

I then took a close look at my 15s chart for ERX- each bar does not represent 15 seconds, or rather, there can be huge, undrawn gaps between bars. On the chart I mentioned, I see 15 second bars at
13:17:00
13:17:45
13:18:00
13:18:15
13:27:00
13:30:00

This poses some questions for me:
(1) Does Ninja track time, or does it realize that the 15s bar its currently working on is only closed when the next tick comes in (even if its several minutes later)? This implies that for any strategy driving off time charts using OnBarClose=true, you could incurr MASSIVE slippage because you will only realize the bar is closed (and generate an order) several minutes after the fact, when a fill at a different price level completes. Is there any way to force time based events into the model?

(2) Can the data provider (Kinetick in this case) be sending corrections? This is the only thing that can explain a 15 second bar being changed several minutes after the fact.

(3) Why would OnBarUpdate miss an entire bar?

[NinjaTrader_Matthew]

1) NinjaTrader does not keep track of time. The time of the bars (time[0]) are natively time stamped from Kinetick. OnBarUpdate is only called if there has been a tick received. If you're running on last price, and there haven't been any ticks in this time, OBU will not fire.

You can create your own custom timer method. I'd suggest looking at the BarTimer indicator that ships with NinjaTrader for any idea on how to do this.

There are also other event handlers you can work in, such as OnMarketData or OnMarketDepth which are executed when there has been a change to the L1 or L2 data:

http://www.ninjatrader.com/support/helpGuides/nt7/onmarketdata.htm

http://www.ninjatrader.com/support/helpGuides/nt7/onmarketdepth.htm

2) Any corrections that Kinetick would be sending wouldn't come in a real-time feed. You may see historical prices change after a reload, but not in real-time

3) If there was not a Last trade in this period, there will not be anything drawn. To visualize this gap, you can right click on the chart--> select "Properties"--> set the 'Equidistant bar spacing' to false.

I'm also including a Reference Sample on Using Custom Events to give you an idea on how you can access the information you're looking for at a custom time, rather than relying on a tick to be received like we have in OBU:

http://www.ninjatrader.com/support/forum/showthread.php?t=5965

[drtomaso]

Matthew-

Thanks for the quick reply!

On point (3), this is the problem I am seeing exactly- I do see the bar on the chart, with no corresponding log print fron OnBarUpdate (OBU).

What about this: do these "reloads" have to be triggered manually? Or can they be triggered from the market data vendor side- something like a silent disconnect/reconnect/re-transmit? Could a vendor just resend a bar? If that is the case, this may explain both the "magically updating" bar I saw AND the missed OBU- that bar I see on the chart was drawn as a result of some sort of re-transmission- and this doesn't trigger OBU (I never saw OBU re-print for the bar that was "corrected" so this seems to lend credence to the theory).

I'll take a look at those links you sent as well, but I hesitate to move strategy logic into OnMarketData simply because I want the code run in real time to be as close as possible to that which is run through the backtester, and OMD doesnt fire on backtest data.

[NinjaTrader_Matthew]

Happy to help and welcome to our forums by the way.


To clarify, you can see the bar form on the chart, but OBU is not being called? Or this is only after the chart has been reloaded? If it is the first, can you reproduce this?

Yes, a vendor may change historical bars. The reload has to be done manually on a live chart, but a disconnect/reconnect will also reload the chat.

Just a quick note (I assume you know this, but for anyone who may be lurking) a backtest is always CalculateOnBarClose = true. If you want intraday granularity, you can always add a smaller series to obtain this during backtesting:

http://www.ninjatrader.com/support/forum/showthread.php?t=6652

[drtomaso]

Matthew-

To be clear, I did not manually reload the chart at any point. However, the chart may have been opened *after* the 13:18:00 time stamp- the sequence was I started the strategy on ERX in the control center window, *then* launched a new chart for ERX. The chart may have opened and gotten an updated 13:18:00 print that wouldn't have been available to the strategy, and this would seem to explain the behavior.

That said, I definitely saw the 13:27:00 bar update in place- it changed from green to red around the time that the 13:30 bar printed- without any reload of the chart. What I cannot tell because I don't have the exact timing of the observed change is whether the OBU triggered for the original bar (green) or the updated bar (red). Its possible that the retransmission of the 13:27 bar occurred before the first tick of the 13:30 bar was observed- farther out than the 15s window, but still time stamped for 13:27:00 bar: I assume in that case, the bar would re-render on the chart- just like any update that would happen within the 15s window, and then the OBU would fire on the first received tick for the 13:30 bar.

Long story short- it looks like I need to snap some more, clearer examples to be able to say there is a problem here. The big take away for me is the relationship between the bar and processing time.