OnBarUpdate is not getting called

[saltminer]

Hi guys, got a strange one for you.
I have a large strategy, which has been loading 3 additional timeframes. It has been months in development and is working fine.
This week I had to add another timeframe, a Day bar series of the same instrument as the chart. I'm doing it like this:

if (aTR_Filter_Enabled)
{
Add(PeriodType.Day,1);
}

The trouble is, when this is activated (when the user-input 'aTR_Filter_Enabled' is true, and the Day timeframe is added, OnBarUpdate() never executes.

* There are no errors in the Log tab of the Control Centre.
* I have print statements in the OnStartUp() showing me what bars series I have, the output is this (which proves OnStartUp() is being executed:

total timeframes loaded is 5
0: ES 03-12 3Renko, count is 302
1: ES 03-12 2Minute, count is 1262
2: YM ##-## 4Renko, count is 470
3: ES 03-12 5Renko, count is 119
4: ES 03-12 1Day, count is 3

* I have a print statement the very first thing of OnBarUpdate() to try to prove it is getting called. Nothing.

I've had a look in the Trace file. Here is a large slab, but there is an Exception down the bottom hopefully you can help me with.

012-03-01 21:28:18:280 ApplicationStart done, took 30.4 secs
2012-03-01 21:29:10:650 (Unknown) Cbi.Connection.Connect0 Disconnected assembly=7.0.1000.9 date=1/03/2012
2012-03-01 21:29:10:650 (Unknown) Cbi.Connection.Connect1
2012-03-01 21:29:10:650 (Kinetick REALTIME) Cbi.Connection.Connect9
2012-03-01 21:29:10:712 (Kinetick REALTIME) Cbi.Connection.ProcessEventArgs.ConnectionStatusEv entArgs Connecting Connecting NoError
2012-03-01 21:29:10:728 (Kinetick REALTIME) Cbi.Connection.ConnectNow1: DataConnection=False
2012-03-01 21:29:10:728 (Kinetick REALTIME) Cbi.Connection.ConnectNow2
2012-03-01 21:29:10:728 (Kinetick REALTIME) Cbi.Connection.ConnectNow.CreateLoader
2012-03-01 21:29:10:728 Server.Client.Connect
2012-03-01 21:29:10:744 Server.Client.Loop0-0: 64.202.118.179/31654
2012-03-01 21:29:12:538 Server.Client.Loop1-0
2012-03-01 21:29:12:538 (Kinetick REALTIME) Cbi.Connection.ConnectNow.Connect
2012-03-01 21:29:12:538 (Kinetick REALTIME) Cbi.Connection.ConnectNow9 ok
2012-03-01 21:29:12:553 (Kinetick REALTIME) Cbi.ConnectionStatusEventArgs.Process: Connecting Connecting
2012-03-01 21:29:12:553 (Kinetick REALTIME) Kinetick.Adapter.Connect: login=405398 newsDaysBack=1
2012-03-01 21:29:12:662 (Kinetick REALTIME) Kinetick.Adapter.ConnectNow: retrieving server info
2012-03-01 21:29:16:453 (Kinetick REALTIME) Kinetick.Adapter.ConnectNow.AccountLogin: '66.112.148.212:60000'
2012-03-01 21:29:16:453 (Kinetick REALTIME) Kinetick.Adapter.ConnectNow.HistoryLookup: '66.112.148.210:60050'
2012-03-01 21:29:16:453 (Kinetick REALTIME) Kinetick.Adapter.ConnectNow.MarketDepthLogin: '66.112.148.211:60001'
2012-03-01 21:29:16:453 (Kinetick REALTIME) Kinetick.Adapter.ConnectNow.News: '66.112.148.209:60018'
2012-03-01 21:29:17:171 (Kinetick REALTIME) Kinetick.Adapter.ConnectNow: NINJATRADER
2012-03-01 21:29:18:107 (Kinetick REALTIME) Kinetick.Adapter.ConnectNow: LOGIN
2012-03-01 21:29:18:419 (Kinetick REALTIME) Kinetick.Adapter.ConnectNow: PASSWORD
2012-03-01 21:29:19:620 (Kinetick REALTIME) Kinetick.Adapter.ConnectNow: READY
2012-03-01 21:29:19:636 (Kinetick REALTIME) Kinetick.Adapter.ConnectNow.Auth: 'NYMEX_GBX DME_GBX COMEX_GBX CME_GBX CBOT_GBX'
2012-03-01 21:29:19:636 (Kinetick REALTIME) Kinetick.Adapter.ConnectNow: starting L1 thread...
2012-03-01 21:29:19:636 (Kinetick REALTIME) Kinetick.Adapter.ConnectNow: starting L2 thread...
2012-03-01 21:29:19:636 (Kinetick REALTIME) Kinetick.Adapter.ConnectNow: starting historical data thread...
2012-03-01 21:29:19:651 (Kinetick REALTIME) Kinetick.Adapter.ConnectNow: starting news thread...
2012-03-01 21:29:19:667 (Kinetick REALTIME) Kinetick.Adapter.BarsWorker: started historical data thread
2012-03-01 21:29:19:667 (Kinetick REALTIME) Kinetick.Adapter.NewsWorker: started news thread
2012-03-01 21:29:19:979 (Kinetick REALTIME) Kinetick.Adapter.L1Worker: started L1 thread
2012-03-01 21:29:20:104 (Kinetick REALTIME) Cbi.Connection.ProcessEventArgs.ConnectionStatusEv entArgs Connected Connected NoError
2012-03-01 21:29:20:135 (Kinetick REALTIME) Cbi.Connection.ProcessEventArgs.AccountEventArgs: name='Sim101'
2012-03-01 21:29:20:135 (Kinetick REALTIME) Cbi.AccountEventArgs.Process: Sim101
2012-03-01 21:29:20:150 (Db) Db.Globals.Recover1: 'Sim101'
2012-03-01 21:29:20:603 (Db) Db.Globals.Recover2: 'Sim101'
2012-03-01 21:29:20:618 (Kinetick REALTIME) Cbi.Account.RestorePositionExecutions1: account='Sim101'
2012-03-01 21:29:20:618 (Kinetick REALTIME) Cbi.Account.RestorePositionExecutions9: account='Sim101'
2012-03-01 21:29:20:618 (Kinetick REALTIME) Cbi.AccountUpdateEventArgs.Process: Account='Sim101' ItemType='BuyingPower' Currency='Unknown' Value=1000000
2012-03-01 21:29:20:634 (Kinetick REALTIME) Cbi.AccountUpdateEventArgs.Process: Account='Sim101' ItemType='CashValue' Currency='Unknown' Value=500000
2012-03-01 21:29:20:634 (Kinetick REALTIME) Cbi.AccountUpdateEventArgs.Process: Account='Sim101' ItemType='ExcessEquity' Currency='Unknown' Value=1000000
2012-03-01 21:29:20:634 (Kinetick REALTIME) Cbi.AccountUpdateEventArgs.Process: Account='Sim101' ItemType='InitialMargin' Currency='Unknown' Value=0
2012-03-01 21:29:20:634 (Kinetick REALTIME) Cbi.AccountUpdateEventArgs.Process: Account='Sim101' ItemType='RealizedProfitLoss' Currency='Unknown' Value=0
2012-03-01 21:29:20:650 (Kinetick REALTIME) Cbi.ConnectionStatusEventArgs.Process: Connected Connected
2012-03-01 21:29:20:650 (Kinetick REALTIME) defaultTimeToClose=15/02/2011 12:00:00 AM flattenAll=False
2012-03-01 21:29:21:648 (Kinetick REALTIME) Data.Bars.GetBarsNow: instrument='YM ##-##' from='2012-03-01 19:00:00' to='2012-03-01 23:59:59' period=1 Tick splitAdjusted=False dividendAdjusted=False bars=0 session='Default 24/7'
2012-03-01 21:29:24:239 (Kinetick REALTIME) Data.Bars.GetBarsNow: instrument='ES ##-##' from='2012-03-01 19:00:00' to='2012-03-01 23:59:59' period=1 Tick splitAdjusted=False dividendAdjusted=False bars=0 session='Default 24/7'
2012-03-01 21:29:30:245 (Kinetick REALTIME) Data.Bars.GetBarsNow: instrument='$CADCHF' from='2012-03-01' to='2012-03-01' period=1 Min splitAdjusted=False dividendAdjusted=False bars=0 session='Default 24/7'
2012-03-01 21:29:33:583 (Kinetick REALTIME) Data.Bars.GetBarsNow: instrument='ES 03-12' from='2012-03-01 19:00:00' to='2012-03-01 23:59:59' period=1 Tick splitAdjusted=False dividendAdjusted=False bars=0 session='US Equities ETH'
2012-03-01 21:29:40:821 (Kinetick REALTIME) Data.Bars.GetBarsNow: instrument='ES ##-##' from='2012-03-01' to='2012-03-01' period=1 Min splitAdjusted=False dividendAdjusted=False bars=0 session='Default 24/7'
2012-03-01 21:29:45:221 (Kinetick REALTIME) Data.Bars.GetBarsNow: instrument='ES 03-12' from='2012-03-01' to='2012-03-01' period=1 Min splitAdjusted=False dividendAdjusted=False bars=0 session='CME US Index Futures ETH'
2012-03-01 21:31:14:404 (Kinetick REALTIME) Data.Bars.GetBarsNow: instrument='ES 03-12' from='2012-03-01' to='2012-03-01' period=1 Min splitAdjusted=False dividendAdjusted=False bars=0 session='US Equities ETH'
2012-03-01 21:31:16:697 (Kinetick REALTIME) Data.Bars.GetBarsNow: instrument='YM ##-##' from='2012-03-01 21:00:00' to='2012-03-01 23:59:59' period=1 Tick splitAdjusted=False dividendAdjusted=False bars=0 session='US Equities ETH'
2012-03-01 21:31:19:255 (Kinetick REALTIME) Data.Bars.GetBarsNow: instrument='ES 03-12' from='2012-02-29' to='2012-02-29' period=Daily splitAdjusted=False dividendAdjusted=False bars=0 session='US Equities ETH'
2012-03-01 21:31:20:191 (Kinetick REALTIME) Data.Bars.GetBarsNow: instrument='ES 03-12' from='2012-03-01' to='2012-03-01' period=Daily splitAdjusted=False dividendAdjusted=False bars=0 session='US Equities ETH'
2012-03-01 21:34:04:076 Code.Editor.OnLoad: Failed to reference 'NinjaTrader.Custom, Version=7.0.1000.9, Culture=neutral, PublicKeyToken=null': System.IO.FileNotFoundException: The specified module could not be found. (Exception from HRESULT: 0x8007007E)
at System.Reflection.Assembly._nLoad(AssemblyName fileName, String codeBase, Evidence assemblySecurity, Assembly locationHint, StackCrawlMark& stackMark, Boolean throwOnFileNotFound, Boolean forIntrospection)
at System.Reflection.Assembly.nLoad(AssemblyName fileName, String codeBase, Evidence assemblySecurity, Assembly locationHint, StackCrawlMark& stackMark, Boolean throwOnFileNotFound, Boolean forIntrospection)
at System.Reflection.Assembly.InternalLoad(AssemblyNa me assemblyRef, Evidence assemblySecurity, StackCrawlMark& stackMark, Boolean forIntrospection)
at System.Reflection.Assembly.InternalLoadFrom(String assemblyFile, Evidence securityEvidence, Byte[] hashValue, AssemblyHashAlgorithm hashAlgorithm, Boolean forIntrospection, StackCrawlMark& stackMark)
at System.Reflection.Assembly.LoadFrom(String assemblyFile)
at NinjaTrader.Code.Editor.OnLoad(Object sender, EventArgs e)

2

Thanks in advance,
saltminer

[NinjaTrader_Bertrand]

Hi saltminer, how much data are you loading up to run the strategy? Please remember that the BarsRequired would need to be satisfied for all series involved for the OnBarUpdate() to be called from the strategy / script.

[saltminer]

Ah, thanks. Changing the BarsRequired down to 2 got it going.
saltminer

[saltminer]

Ah, not so fast.

OnBarUpdate() is now called once, but never again.
There are no errors shown in the Log tab.
There is nothing dubious in the Trace file.
I have print statments throughout OnBarUpdate() and I can see I am getting all the way through to the end. I should see a call for every bar on the chart yet to go, but I'm not. It is quite perplexing.
No trades are taking place on this first execution.

Here is the data from within this first-and-only OnBarUpdate()

OnBarUpdate() (initialise) total timeframes loaded is 5
0: ES 03-12 3Renko, Count is 1006, CurrentBar=353
1: ES 03-12 2Minute, Count is 4353, CurrentBar=1357
2: YM ##-## 4Renko, Count is 1781, CurrentBar=701
3: ES 03-12 5Renko, Count is 389, CurrentBar=139
4: ES 03-12 1Day, Count is 13, CurrentBar=3
debug point 1049
debug point 1071
debug point 1094
debug point 1106
debug point 1109
debug point 1145
debug point 1218
debug point 1315
debug point 1416, now in BIP = 0, bar 353 of 1006
debug point 1854
debug point 1861
debug point 1881 end of OnBarUpdate()

Any ideas?
saltminer

[NinjaTrader_Bertrand]

Is this still being run with BarsRequired = 2? How much data are you loading up here? You could see an OnBarUpdate() only for the bars were BarsRequired for all your series is satisfied, for the others it would not be called, so not even a single bars object OnBarUpdate(). If you email me the script and setup I will gladly give it a run here, too and compare.

Also, if you comment out the day - it would work as you expect still, correct?

[saltminer]

Hi Bertrand,
in the printout below there is visible the Count of all bar series. Loading up is 13 days (more than the 2 required) and then hundreds of everything else. I should see hundreds of OnBarUpdate() calls but I only get one.
I have now commented out the Day bar series and it still remains the same. It is so strange, as this worked earlier in the week. In many years of programming for Ninja I've never seen just one OnBarUpdate() call.
I tried a different strategy and it worked fine. I'm going to try a previous build of this strategy to see if I can get it running again.
If you've never seen this behaviour of a single OnBarUpdate() call, then fine, I've managed something to create something new. If you have, let me know what a way out of this situation might be.
Cheers,
saltminer

[saltminer]

While we're on this topic, I've got another strategy on daily bars that also loads Monthly bars and Minute bars.

I have a question about the number of bars Ninja loads in each bar series. I seem to only be able to get 13 months in the monthly timeframe loaded. I am using ES ##-## so the data goes back a long way.
I wrote a stats printout, and set the chart to look bar 2000 bars. This is what it loaded :

sdThesisTester loaded, timeframe stats:
[0] contains 2000 bars, earliest one 8/04/2004 2:00:00 PM
[1] contains 13 bars, earliest one 1/04/2011 3:00:00 PM
[2] contains 350183 bars, earliest one 4/03/2011 4:01:00 PM

Only 13 monthly bars!
If I change the chart to Monthly bars, to force Ninja to load monthly bars, I get this:

sdThesisTester loaded, timeframe stats:
[0] contains 175 bars, earliest one 1/10/1997 2:00:00 PM
[1] contains 175 bars, earliest one 1/10/1997 2:00:00 PM
[2] contains 2120479 bars, earliest one 7/09/2005 6:33:00 AM

Additional monthly timeframe now contains the same amount of bars as the chart, which makes sense. I then change the chart back to daily, and I get the first result again, only 13 monthly bars.
Why? Ninja has those months in its cache. It is able to download them on demand from the live data connection. Yet it doesn't load them into the strategy.
I need more than 13 bars in a bar series.

Why does it do this, and how can I force the loading of more bars?

** UPDATE.**
Using the CustomRange, the bar series all load to the same date. That's more like it!

sdThesisTester loaded, timeframe stats:
[0] contains 799 bars, earliest one 3/01/2009 4:00:00 PM
[1] contains 39 bars, earliest one 1/02/2009 4:00:00 PM
[2] contains 1107337 bars, earliest one 31/12/2008 4:01:00 PM

I also get the expected results when selecting Days:

sdThesisTester loaded, timeframe stats:
[0] contains 799 bars, earliest one 3/01/2009 4:00:00 PM
[1] contains 39 bars, earliest one 1/02/2009 4:00:00 PM
[2] contains 1107337 bars, earliest one 31/12/2008 4:01:00 PM

So there seems to be something buggy in the Bars option in the DataSeries dialogue.

Cheers,
saltminer

[NinjaTrader_Bertrand]

Hi saltminer, thanks for that detailed post and your efforts - would you forwarding me the test script to support and also emailing me which broker / data-provider you're using here in testing so I could replicate the exact setup in my testing as well?

I will then attempt to reproduce here on our end and update you.

Thanks again,

[jbaarsch]

I have encountered the same issue. I tried to comment out the add day bar line and it still never hits my onbarupdate(). I attach my debugger (visual studio) to the worker process and put a break point in the OnBarUpdate() and it never hits. Below are my initialize and onbarupdate methods. I am running through the Strategy Analyzer against SPY using Kinetick as the data provider. I have min bars set to 20 and time frame 1/1/2012 - 12/18/2012. Please let me know if you need more information to replicate. Thanks in advance, ~Joe

"
/// <summary>
/// This method is used to configure the strategy and is called once before any strategy method is called.
/// </summary>
protected override void Initialize()
{
//Add day data inside
Add(this.Instrument.FullName, PeriodType.Day,1);
ExitOnClose = true; //Cancels all open orders on close of designated period
this.EntriesPerDirection = 1;
// CalculateOnBarClose = true;
}

/// <summary>
/// Called on each bar update event (incoming tick)
/// </summary>
protected override void OnBarUpdate()
{
if (BarsInProgress == 1) return; //Nothing to process on Daily bars

EnterLong(10,"test");
}"

[NinjaTrader_Matthew]

Originally Posted by jbaarsch

I have encountered the same issue. I tried to comment out the add day bar line and it still never hits my onbarupdate(). I attach my debugger (visual studio) to the worker process and put a break point in the OnBarUpdate() and it never hits. Below are my initialize and onbarupdate methods. I am running through the Strategy Analyzer against SPY using Kinetick as the data provider. I have min bars set to 20 and time frame 1/1/2012 - 12/18/2012. Please let me know if you need more information to replicate. Thanks in advance, ~Joe

"
/// <summary>
/// This method is used to configure the strategy and is called once before any strategy method is called.
/// </summary>
protected override void Initialize()
{
//Add day data inside
Add(this.Instrument.FullName, PeriodType.Day,1);
ExitOnClose = true; //Cancels all open orders on close of designated period
this.EntriesPerDirection = 1;
// CalculateOnBarClose = true;
}

/// <summary>
/// Called on each bar update event (incoming tick)
/// </summary>
protected override void OnBarUpdate()
{
if (BarsInProgress == 1) return; //Nothing to process on Daily bars

EnterLong(10,"test");
}"

You will want to add a CurrentBars check to your OnBarUpdate method to ensure that your added series has enough data

if(CurrentBars[0] < BarsRequired || CurrentBars[1] < BarsRequired)
return;

[jbaarsch]

Thank you for the reply, it led me to figure out I did not have enough historical data downloaded for my test period. Once I downloaded more historical data I was able to hit OnBarUpdate() and could move on to more interesting issues

Cheers,
Joe