CBT hangs ( but does not crash ) on bo.EnterTrade() call

I need some ideas about what might be going wrong during a custom backtest which seems to cause Amibroker to simply hang while it is running. I am using Amibroker v6.16. I will provide code and a custom debug printout below, but first here's the background.

Background Context:
I've been using a low-level CBT for almost three years with no problems. I have run the current version literally thousands of times without a hitch.

Typically I run it on formulas which contain about 100 tickers and a few thousand trades. This problem showed up after I tried to run it on the Russell 2000, generating about 60,000 trades over a 9 year backtest period across 2003 tickers.

The Problem:
The formula passes verify and also runs fine through Explore and Scan in the analysis window. However, when I run a backtest, the CBT only runs until it finds the first signals to open trades . It seems to enter the first eighteen trades fine but on the seventh call to bo.EnterTrade(), Amibroker simply hangs on that call. There are no error messages and it doesn't crash. It simply doesn't exit the call. The CPU keeps churning too, though memory eventually empties and jumps around between 2.4 MB and 3.0 MB. I have let it run for as long as 3 days and it doesn't complete and I have to kill the broker.exe process and start the program again.

I can see from the custom debug readout that the inputs to bo.EnterTrade() are normal. This isn't an edge case as far as I can see except for the fact that it is a much larger watchlist of tickers than I normally use. This causes the CBT to create a couple of large matrices (app. 2000 x 2000), though it at least seems to do this without error. Also, for each of the tickers in the Russell 2000, the formula creates 5 static variable arrays ( 10,000 total ). In settings, I have Amibroker set to allow 5000 open positions, so that shouldn't be a problem.

Here's a screenshot of Amibroker's resource usage during the hang period. As I said, the CPU is churning along, though I have no idea what it could be doing. There's a _Trace() statement on the bo.EnterTrade() call and it never exits.

Screenshot 2020-12-07 022405

This sort of behavior has only happened once before, about 18 mos. ago, and I can't recall how I fixed it.

I'm posting to the forum to ask for ideas, as I'm out of hypotheses to test about what might be causing it.

Has anyone experienced a issue with hanging like this using the CBT bo.EnterTrade() method? If not, any ideas of what other things I could be looking at/testing? I'm sort of at my wit's end.

Here is _Trace output near the point where it stops, showing relevant inputs.

CBT: loop number 6341 processing ticker CATM
bo.Equity is 1e+006
Entering trade. price: 26.8067; sigPosSize: -0.731707; eq is 1e+006
CBT: loop number 6342 processing ticker CATO
bo.Equity is 1e+006
CBT: loop number 6343 processing ticker CATY
bo.Equity is 1e+006
CBT: loop number 6344 processing ticker CBAN
bo.Equity is 1e+006
CBT: loop number 6345 processing ticker CBAY
bo.Equity is 1e+006
CBT: loop number 6346 processing ticker CBB
bo.Equity is 1e+006
CBT: loop number 6347 processing ticker CBFV
bo.Equity is 1e+006
CBT: loop number 6348 processing ticker CBIO
bo.Equity is 1e+006
Entering trade. price: 578.698; sigPosSize: -0.650407; eq is 1e+006

It hangs on CBIO with what look like perfectly normal inputs after succeeding on calls using other tickers with similar inputs.

Here's the CBT code.

// Section 10: Custom Backtester
SetCustomBacktestProc("");

if (Status("action") == actionPortfolio) {
    bo = GetBacktesterObject();	//  Get backtester object
    
    bo.PreProcess();	//  Do pre-processing
	cash = bo.InitialEquity; 
	exposure = 0;
	barsInPeriod = BarCount - 1;   
	tDelay = GetTradeDelay();
	delayExists = NOT IsNull(tDelay) AND NOT AlmostEqual(tDelay, 0);
		
/**/	
	tStop = False;
	reentryDelay = 2;
	portOffline = 11;
	tStopLongAmt = 0.1;
	tStopShortAmt = 0.05;
	portStopAmt = 0.15;
	lastPortStop = 0;
	entryAmt = 0;
	dd = 0;
	
 
	ts = GetAllTickers(RetrieveWL(rootComposite)); //CategoryGetSymbols(categoryWatchlist, CategoryFind("TRADEDTICKERS", categoryWatchlist));
	numTicks = StrCount(ts, ",") + 1;
	buyMtx = Matrix(numTicks, BarCount);
	sellMtx = Matrix(numTicks, BarCount);
	for (index = 0; (member = StrExtract(ts, index)) != ""; ++index)   { //  Loop through all signals at this bar
		temp = Nz(StaticVarGet(member + "PositionScore"));
		if (delayExists AND temp[0] >= 0) 
			StaticVarSet(member + "PositionScore", Ref(temp, -tDelay));
		else if (temp[0] < 0) { // negative value signals external ticker, time delay already applied 
			temp[0] += 10; // normalize the position score signal by adding back the 10 subtracted in RootNode
			StaticVarSet(member + "PositionScore", temp);		
		} // end else it is a ticker managed by an external manager
		
		buyMtx = MxSetBlock(buyMtx, index, index, 0, BarCount - 1, Nz(GetBuyArray(member, GetBuyString()), 0.01));
		sellMtx = MxSetBlock(sellMtx, index, index, 0, BarCount - 1, Nz(GetSellArray(member, GetSellString()), 0.01));	
	} // End for each tradeable ticker in the tree

/**/ loop = 0;
	eqHist = 0;	
    for (i = GetFirstBarInRange(); i <= GetLastBarInRange(); ++i)	{ //  Loop through all bars
  
		if (GetDebug("CBT"))
			_TRACE("**********************In CBT at bar " + i + "****************************");
		eq = 0;		
		if (tStop AND i > 0) { 
			dd = MaxDD(eqHist, lastPortStop, i - 1);		
		}
		
		// Calculate the current value of equity
		for (index = 0; (member = StrExtract(ts, index)) != ""; ++index) { // for each tradeable ticker
			trade = bo.FindOpenPos(member);		
			rebal = StaticVarGet(member + "_rebal");
/**/ 		_TRACE("CBT: loop number " + ++loop + " processing ticker " + member);
				
			if (NOT IsNull(trade)) {
										
				if (rebal[i]) { // Begin rebal signal for this trade			
					
					trade_ps = Nz(StaticVarGet(trade.Symbol + "PositionScore")) * 100;
					currPosSize = 100 * (SafeDiv(trade.GetPositionValue(), bo.Equity));					
					scaleOut = trade_ps[i] < currPosSize;					
									
					if (GetDebug("CBT"))
						_TRACE("In CBT Calc Equity: Found open position on " + trade.Symbol);


					if (AlmostEqual( trade_ps[i], 0) AND scaleOut) { // close the trade
						price = sellMtx[index][i];				

						if (GetDebug("CBT")) {
							_TRACE("CBT calculating current value of equity, exiting trade: i is " + i + " and trade.Symbol is " + sigSymbol + " and price is " + price);
							_TRACE("                    ");
						}

/**/					_TRACE("Closing trade. price is " + price);

						bo.ExitTrade( i, trade.Symbol, price );
						/**/ entryAmt[index] = 0;					

						cash += trade.Shares * price;

						if (GetDebug("CBT")) {
							_TRACE("CBT Exited Trade: Cost/Proceeds were " + price * trade.Shares + " and cash is now " + cash);
							_TRACE("                    ");
						}

					} // end close the trade
					else if (scaleOut) { // reduce the position size
						targetValue = (abs(trade_ps[i]) / 100) * bo.Equity;
						price = sellMtx[index][i];
						value = abs(targetValue - trade.GetPositionValue());

						if (GetDebug("CBT")) {
							_TRACE("CBT About to Scale Trade: i is " + i + " and sig.Symbol is " + trade.Symbol);
							_TRACE("CBT New Trade: scaleIn is " + scaleIn + " and sig.Price is " + price + " and value is " + value);
							_TRACE("                    ");
						}

/**/					_TRACE("Scaling out of trade. price is " + price + "; and scale out size is " + abs(trade_ps[i] - currPosSize) * -1);

						bo.ScaleTrade(i, trade.Symbol, scaleOut, price, abs(trade_ps[i] - currPosSize) * -1);
						/**/ if (NOT AlmostEqual(value, 0)) 
								entryAmt[index] = targetValue;
						
						cash += value;
						
						if (GetDebug("CBT")) {
							_TRACE("CBT Scaled Trade: isLong was " + (sigPosScore > 0) + " scaleIn was " + scaleIn);
							_TRACE("CBT Scaled Trade: Proceeds/Cost was " + value + " and cash is now " + cash);													
							_TRACE("                    ");
						}
					
					} // end reduce the position size
				}  // end rebal is true
				else { // rebal is false

					price = sellMtx[index][i]; //GetSellArray(trade.Symbol, GetSellString());
					eq += trade.Shares * price; //price[i];
					
				} // end if rebal is false
				
				if (trade.IsLong AND tStop AND i > 0) { // apply trailing stop rule to the long trade
					price = sellMtx[index][i]; //GetSellArray(trade.Symbol, GetSellString());

					eq += trade.Shares * price; //price[i];
										

					if ((1 - tStopLongAmt) * entryAmt[index] >= trade.Shares * price[i] OR abs(dd) >= 100 * portStopAmt) {

						_TRACE("=================================================================");
						_TRACE("Stop loss on long trade for ticker "+member+" at bar "+i);							
						_TRACE("entryAmt[index] is "+entryAmt[index]);
						_TRACE("trade.Shares is "+trade.Shares);
						_TRACE("price[i - 1] is "+price[i - 1]+" and price[i] is "+price[i]);
						_TRACE("long tolerance on value is "+(1 - tStopLongAmt)*entryAmt[index]);
						_TRACE("actual current value on long trade is "+trade.Shares*price[i - 1]);


						if (abs(dd) >= 100 * portStopAmt) {
						
							if ( AlmostEqual(i, barsInPeriod)) {
								msg = StaticVarGetText("dailyActivityLog");
								msg += "\nWARNING!!!! A portfolio stop loss has been triggered"; 
								StaticVarSetText("dailyActivityLog", msg);
							} // End if i = last bar in range
							
							lastPortStop = i;
							_TRACE("***** Portfolio stop loss occurring at bar " + i);
							psStop = Nz(StaticVarGet(member + "PositionScore"));
							for (x = i + 1; x <= i + portOffline; ++x) 
								if (x < BarCount) psStop[x] = 0; 
								
							StaticVarSet(member + "PositionScore", psStop);
						} // end if portfolio level stop loss
						else {

							if ( AlmostEqual(i, barsInPeriod)) {
								msg = StaticVarGetText("dailyActivityLog");
								msg += "\nTEST WARNING!!!! A trade stop loss has been triggered for security " + member; 
								StaticVarSetText("dailyActivityLog", msg);
							} // End if i = last bar in range

							psStop = Nz(StaticVarGet(member+"PositionScore"));
							for (x = i + 1; x <= i + reentryDelay; ++x) 
								if (x < BarCount) psStop[x] = 0;
							StaticVarSet(member+"PositionScore", psStop);
						} // end else trade level stop loss
						
					} // End if long trade stop loss is triggered
						
					
					if (GetDebug("CBT"))
						_TRACE("Position value (long) was " + trade.Shares + " * " + price[i] + " = "+trade.Shares * price[i]);
				} // End if trade is long
				else if (tStop AND i > 0) { // apply trailing stop rule to the short trade
					price = buyMtx[index][i]; //GetBuyArray(trade.Symbol, GetBuyString());

					eq -= trade.Shares * price; //price[i];
					eqHist[i] = eq;
															

					if ((1 + tStopShortAmt) * entryAmt[index] <= trade.Shares * price[i] OR abs(dd) >= 100 * portStopAmt) {

						_TRACE("=================================================================");
						_TRACE("Stop loss on short trade for ticker " + member + " at bar " + i);							
						_TRACE("entryAmt[index] is " + entryAmt[index]);
						_TRACE("trade.Shares is " + trade.Shares);
						_TRACE("price[i - 1] is " + price[i - 1] + " and price[i] is " + price[i]);
						_TRACE("short tolerance on value is " + (1 + tStopShortAmt) * entryAmt[index]);
						_TRACE("actual current value on short trade is " + trade.Shares * price[i - 1]);
						
						if (abs(dd) >= 100 * portStopAmt) {

							if ( AlmostEqual(i, barsInPeriod)) {
								msg = StaticVarGetText("dailyActivityLog");
								msg += "\nTEST WARNING!!!! A portfolio stop loss has been triggered "; 
								StaticVarSetText("dailyActivityLog", msg);
							} // End if i = last bar in range

							lastPortStop = i;
							_TRACE("***** Portfolio stop loss occurring at bar "+i);
							psStop = Nz(StaticVarGet(member+"PositionScore"));
							for (x = i + 1; x <= i + portOffline; x++) 
								if (x < BarCount) psStop[x] = 0;
							StaticVarSet(member + "PositionScore", psStop);
						} // end if portfolio level stop loss
						else {

							if ( AlmostEqual(i, barsInPeriod)) {
								msg = StaticVarGetText("dailyActivityLog");
								msg += "\nWARNING!!!! A trade stop loss has been triggered for security " + member; 
								StaticVarSetText("dailyActivityLog", msg);
							} // End if i = last bar in range

							psStop = Nz(StaticVarGet(member+"PositionScore"));
							for (x = i + 1; x <= i + reentryDelay; x++) 
								if (x < BarCount) psStop[x] = 0;
							StaticVarSet(member + "PositionScore", psStop);
						} // end else trade level stop loss
						
					} // End if short trade stop loss is triggered
																
					if (GetDebug("CBT"))
						_TRACE("Position value (short) was " + trade.Shares + " * " + price[i] + " = " + trade.Shares * price[i]);
						
				} // End if trade is short
			
			} // End if trade is not NULL
		} // End for each tradeable ticker of the portfolio tree
				
		if (GetDebug("CBT")) {
			_TRACE("CBT Calc Equity: equity is " + eq + " at bar " + i + " after adding position values");
		}
		
		eq += cash; 
		eqHist[i] = eq;

		if (GetOption("UsePrevBarEquityForPosSizing"))
			if ( i > 0 ) eq = eqHist[i - 1];
				
		if (GetDebug("CBT")) {
			_TRACE("CBT Calc Equity: equity is " + eq + " at bar " + i + " after cash");
			_TRACE("CBT Calc Equity: cash was " + cash);
			_TRACE("           ");
		}

		prevPosScore = 0;
		for (index = 0; (member = StrExtract(ts, index)) != ""; ++index)   { //  Loop through all signals at this bar
			ps = Nz(StaticVarGet(member + "PositionScore")) * 100; // retrieve signal
			rebal = StaticVarGet(member +  "_rebal");
/**/ 		_TRACE("CBT: loop number " + ++loop + " processing ticker " + member);
			_TRACE("bo.Equity is " + bo.Equity);
			
// 		_TRACE("CBT: at bar " + i + " with ticker " + member + " retrieved ps of " + ps[i]);

			if (LastValue(IsNull(ps))) ps = 0;
			ticker = member; 
			sigPosScore = ps[i];			
			sigPosSize = -1 * abs(ps[i]);
			if ( i > 0 ) prevPosScore = ps[ i - 1 ];
			sigSymbol = member;
			sigType = 0;
			sigIsLong = -1 * (sigPosScore > 0);
			sigIsScale = 0;
			if (AlmostEqual(i, 0) OR ps[i] >= ps[i - 1])
				price = buyMtx[index][i]; //GetBuyArray(ticker, GetBuyString());
			else
				price = sellMtx[index][i]; //GetSellArray(ticker, GetSellString());			
			sigPrice = price;
			sigIsEntry = 0;
			sigIsExit = 0;
			sigIsScale = 0;
			exposure[i] += abs(sigPosSize);
			if (sigPosSize < -100 AND NOT AlmostEqual(sigPosSize, -100)) {
				_TRACE("ERROR! At bar " + i + " sigSymbol allocation is greater than 1 for ticker " + sigSymbol + ". sigPosSize is " + sigPosSize);
				sigPosSize = -100;
			}
			
			if (!IsNull(sigPosScore) AND sigSymbol != COMPOSITE_PREFIX + "CASH" AND rebal[i]) { // Begin position score exists for a ticker
				if (GetDebug("CBT")) {	
 					_TRACE("CBT Processing Signal: Score for symbol " + sigSymbol + " and PosScore is " + sigPosScore);
					_TRACE("CBT Processing Signal: Type is " + sigType);
					_TRACE("CBT Processing Signal: Size is " + sigPosSize + " and isLong is " + sigIsLong);
					_TRACE("CBT Processing Signal: sig.ScaleTrade is " + sigIsScale + " and sigPrice is " + sigPrice);
					_TRACE("Sig.IsEntry() : " + sigIsEntry);
					_TRACE("Sig.IsExit() : " + sigIsExit);
					_TRACE("Sig.IsScale() : " + sigIsScale);			
					_TRACE("            ");
				}

				if (!AlmostEqual(sigPosScore, 0) AND IsNull(bo.FindOpenPos(sigSymbol))) { // No currently open position
					value = ( abs(sigPosSize) / 100 ) * eq;

					if (GetDebug("CBT")) {
						_TRACE("CBT About to Enter New Trade: i is " + i + " and sig.Symbol is " + sigSymbol);
						_TRACE("CBT New Trade: sig.PosScore is " + sigPosScore + " and sig.Price is " + sigPrice + " and value is " + value);
						_TRACE("                    ");
					}

/**/			_TRACE("Entering trade. price: " + sigPrice + "; sigPosSize: " + sigPosSize + "; eq is " + eq);

					bo.EnterTrade( i, sigSymbol, sigPosScore > 0, sigPrice, sigPosSize );
					
					if (GetDebug("CBT")) {
						_TRACE("CBT Successfully exited bo.EnterTrade.");
					}
						
					/**/ entryAmt[index] = value;
					
					if (sigPosScore > 0)
						cash -= value;
					else
						cash += value;
						
					if (GetDebug("CBT")) {
						_TRACE("CBT Entered Trade: Cost was " + value + " and cash is now " + cash);
						_TRACE("                    ");
					}
					
				} // End Open a trade
				else if (AlmostEqual(sigPosScore, 0)) {
					trade = bo.FindOpenPos(sigSymbol);
					if (NOT IsNull(trade)) {
						if (trade.IsLong)
							cash += trade.Shares * sigPrice;
						else
							cash -= trade.Shares * sigPrice;		
					cash -= trade.GetCommission();

					if (GetDebug("CBT")) {
						_TRACE("CBT About to Exit Trade: i is " + i + " and sig.Symbol is " + sigSymbol + " and sig.Price is " + sigPrice);
						_TRACE("                    ");
					}
								
					bo.ExitTrade(i, sigSymbol, sigPrice);
					/**/ entryAmt[index] = 0;
					
					if (GetDebug("CBT")) {
						_TRACE("CBT Exited Trade: Cost/Proceeds were " + sigPrice * trade.Shares + " and cash is now " + cash);
						_TRACE("                    ");
					}
					
					} // End trade is not null
				} // End position score is 0, close a trade	
				else {
					trade = bo.FindOpenPos(sigSymbol);
					if (NOT IsNull(trade)) {
						currPosSize = 100 * (SafeDiv(trade.GetPositionValue(), bo.Equity));
						currValue = trade.GetPositionValue(); //(trade.Shares*sigPrice);
						longReversal = trade.IsLong AND sigPosScore < 0;
						shortReversal = sigPosScore > 0 AND NOT trade.IsLong;
						isReversal = longReversal OR shortReversal;
					}
					else {
						currPosSize = 0;
						currValue = 0;
						isReversal = False;
					}
					
					if (!isReversal) {	
						scaleIn = ps[i] >  currPosSize; 
						targetValue = (abs(sigPosSize) / 100) * eq;
						value = abs(targetValue - currValue);

						if (GetDebug("CBT")) {
							_TRACE("CBT About to Scale Trade: i is " + i + " and sig.Symbol is " + sigSymbol);
							_TRACE("CBT New Trade: scaleIn is " + scaleIn + " and sig.Price is "+sigPrice + " and value is " + value);
							_TRACE("                    ");
						}

/**/			_TRACE("Scaling into trade. price: " + sigPrice + "sigPosSize: " + sigPosSize);
				_TRACE("currPosSize: " + currPosSize + "; currValue " + currValue + "; targetValue: " + targetValue);
				_TRACE("size of scaleIn is: " + abs(ps[i] - currPosSize) * -1);

						bo.ScaleTrade(i, sigSymbol, scaleIn, sigPrice, abs(ps[i] - currPosSize) * -1);
						/**/ if (NOT AlmostEqual(value, 0)) 
								entryAmt[index] = targetValue;
						
						if (sigPosScore > 0) {
							if (scaleIn)
								cash -= value;
							else
								cash += value;
						} // end if scaling long trade
						else {
							if (scaleIn)
								cash += value;
							else
								cash -= value;						
						} // End else scaling a short trade
						
						if (GetDebug("CBT")) {
							_TRACE("CBT Scaled Trade: isLong was " + (sigPosScore > 0) + " scaleIn was " + scaleIn);
							_TRACE("CBT Scaled Trade: Proceeds/Cost was " + value + " and cash is now " + cash);													
							_TRACE("                    ");
						}

					} // End if not a reversal
					else {
						if (GetDebug("CBT"))
							_TRACE("CBT Scaled Trade: Trade is a reversal.");
						if (trade.IsLong)
							cash += trade.Shares*sigPrice;
						else
							cash -= trade.Shares*sigPrice;	
						cash -= trade.GetCommission();	
						if (GetDebug("CBT")) {
							_TRACE("CBT Reversal, About to Close Old Trade: i is "+i+" and sig.Symbol is " + sigSymbol);
							_TRACE("CBT Reversal: sig.Price is " + sigPrice);
							_TRACE("                    ");
						}

						bo.ExitTrade(i, sigSymbol, sigPrice);						
	
						value = ( abs(sigPosSize) / 100) * eq;

						if (GetDebug("CBT")) {
							_TRACE("CBT Reversal, About to Open New Trade: i is " + i + " and sig.Symbol is " + sigSymbol);
							_TRACE("CBT New Trade: sig.PosScore is " + sigPosScore+" and sig.Price is " + sigPrice+" and value is " + value);
							_TRACE("                    ");
						}

						bo.EnterTrade( i, sigSymbol, sigPosScore > 0, sigPrice, value );	
						/**/ entryAmt[index] = value;
											
						if (sigPosScore > 0)
							cash -= value; 
						else
							cash += value; 
							
						if (GetDebug("CBT")) {	
						_TRACE("CBT Entered Trade: Cost was " + value + " and cash is now " + cash);
						_TRACE("                    ");
						}

					} // End else is a reversal				
				} // End else not opening or closing a trade	

			} // End if sig.Symbol is a trading system mgr
        } // End for each signal
        
 //       bo.HandleStops( i );	//  Handle programmed stops at this bar
		bo.UpdateStats( i, 1 );	//  Update MAE/MFE stats for bar
        bo.UpdateStats( i, 2 );	//  Update stats at bar's end
    }	//  End of for loop over bars
    
    bo.PostProcess();	//  Do post-processing

	AddToComposite(bo.EquityArray / 1000000, rootComposite, "X", atcFlagEnableInBacktest|atcFlagCompositeGroup|atcFlagDeleteValues|atcFlagEnableInIndicator|atcFlagEnableInPortfolio); 

	CAR = Nz(StaticVarGet("CAR"));
	mxDD = Nz(StaticVarGet("maxDD"));
	exposure = Sum(exposure, BarIndex() + 1) / (BarIndex() + 1);
	expose = Nz(exposure[BarCount - 1]); 
	stats = bo.GetPerformanceStats(0);
	RAR = Nz(stats.GetValue("CAR") * (100 / expose)); 
	vol = Nz(StaticVarGet("Volatility"));
	negVol = Nz(StaticVarGet("NegativeVolatility"));
	sharpe = Nz(StaticVarGet("Sharpe"));
	sortino = Nz(StaticVarGet("Sortino"));
	berg = Nz(StaticVarGet("Bergino"));
	winPCT = Nz(StaticVarGet("winPCT"));
	avgPctGain = Nz(StaticVarGet("avgPctGain"));
	avgPctLoss = Nz(StaticVarGet("avgPctLoss"));
	kelly =	Nz(StaticVarGet("kelly"));
	avgTradeLength = Nz(StaticVarGet("avgTradeLength"));
	cl = Nz(Correlation(bo.EquityArray, Foreign(INDEX_PREFIX + "SPX", "C"), barsInPeriod - 1));
	correl = cl[GetLastBarInRange()];
 	eqlWghtCAR = Nz(StaticVarGet("equalWeightPort"));
	eqlWghtDD =	Nz(StaticVarGet("equalWeightMxDD"));
	randWghtCAR = Nz(StaticVarGet("randomWghtCAR"));
	randWghtCARstd = Nz(StaticVarGet("randomWghtCARstd"));
	randWghtDD =	Nz(StaticVarGet("randomWghtMxDD"));
	randWghtDDstd = Nz(StaticVarGet("randomWghtMxDDstd"));

     
 	// Here we add custom metric to backtest report
	bo.AddCustomMetric( "CAR", CAR, False, False, 2, 4);
	bo.AddCustomMetric("MaxDD", mxDD, False, False, 2, 6);
	bo.AddCustomMetric( "Exposure", expose, False, False, 2, 4);
	bo.AddCustomMetric( "RAR", RAR, False, False, 2, 4);
	bo.AddCustomMetric( "Volatility", vol, False, False, 2, 4);
	bo.AddCustomMetric("NegativeVol", negVol, False, False, 2, 4);
	bo.AddCustomMetric( "Sortino", sortino, False, False, 2, 4);
	bo.AddCustomMetric( "Sharpe", sharpe, False, False, 2, 4);
	bo.AddCustomMetric("Bergino", berg, False, False, 2, 4);
	bo.AddCustomMetric("winPct", winPCT, False, False, 2, 4);
	bo.AddCustomMetric("avgPctGain", avgPctGain, False, False, 2, 4);
	bo.AddCustomMetric("avgPctLoss", avgPctLoss, False, False, 2, 4);
	bo.AddCustomMetric("kelly", kelly, False, False, 2, 4);
	bo.AddCustomMetric("avgTradeLength", avgTradeLength, False, False, 2, 4);
	bo.AddCustomMetric("Correlation to S&P 500", correl, False, False, 2, 4);

	bo.AddCustomMetric("CAR, Equal Weights (annual rebal)", eqlWghtCAR, False, False, 2, 4);
	bo.AddCustomMetric("MaxDD, Equal Weight", eqlWghtDD, False, False, 2, 4);
	bo.AddCustomMetric("CAR, Random Weights", randWghtCAR, False, False, 2, 4);
	bo.AddCustomMetric("Std Dev, Random CAR", randWghtCARstd, False, False, 2, 4);
	bo.AddCustomMetric("MaxDD, Random Weight", randWghtDD, False, False, 2, 4);
	bo.AddCustomMetric("Std Dev, Random MaxDD", randWghtDDstd, False, False, 2, 4);
	
	
} // end custom backtester

You are using relatively old version. It is advised to upgrade.

Such old version REQUIRES that your in-memory cache MUST BE LARGER than
number of symbols under test. Go to Tools->Preferences, "Data" and make sure you are not running out of cache.

Here is a snapshot of the resource monitor at the point AB hangs,
Screenshot 2020-12-07 163454

Thanks. I upped the cache requirements and it stopped in the same place. Here are the settings for the latest run,

Screenshot 2020-12-07 160112

In the minutes after this, AB releases some memory and RAM goes down to 17GB and Disk goes down to 1%.

I use v6.16 because I'm heavily dependent on a custom DLL I've developed to do a lot of statistical processing and Bayesian inference, and v6.16 is the last AB version that allows me to easily develop in both the AFL and Visual Studio environments.

My machine has 32GB of RAM and 2TB of hard disk. I've set the cache to 30GB and the resource monitor is 20GB plus whatever is stored on disk in the windows cache, I guess.

The memory use soars from 5GB to the 24'ish GB in the CBT during creation of two large matrices to hold buy and sell arrays for each of the tickers in the R2000. I have always created them to avoid using Foreign() calls within the main loop of the CBT, because I found AB wasn't that used more memory than the matrices ( at least in past uses). Would rewriting this using arrays stored with VarGet() or StaticVarGet() calls serve the same purpose while allowing the formula to complete?

Can this be something other than a resource issue?

Can you reproduce this problem with a simpler AFL file (including some Phase 1 logic) that others could run?

Are you certain that you haven't tried to enter more trades than Max Positions is set for?

Apparent "hang" is typical when you run out of RAM and Windows desperately starts swapping to disk. Since disk is terribly slow (compared to RAM) it takes ages and "freezes" everything.

Your Task Manager shows 93% of memory so it definitely looks like running out of memory.
Unfortunately Windows itself, Google and other things that you run consume memory too and Windows does not deal with memory fragmentation well and memory stats provided by Task Manager are false/misleading. The memory reported by Task manager is not memory allocated, but so called "working set size". It is smaller than private bytes allocated by program.

True memory usage is shown by Process Explorer and VMMap programs.

Note: be careful NOT to try to create matrices larger than 2GB each because it will fail (with error 60).

1 Like

Update: I've spent the week trying to isolate the problem. I copied the CBT to a separate file and ran it with skeleton code and the CBT completed. I added some of the more memory intense code from the formula and it still completed.

I went back to the real formula and commented out the memory intensive function calls outside of the CBT, and then I re-wrote the CBT to not create the two big matrices. Instead, it saves the price arrays using VarSet() and retrieves them using VarGet(). Here's what that code looks like. The GetAllTickers() call returns a string with the 2003 tickers in the Russell 2000 watchlist.

	ts = GetAllTickers(RetrieveWL(rootComposite)); //CategoryGetSymbols(categoryWatchlist, CategoryFind("TRADEDTICKERS", categoryWatchlist));
	numTicks = StrCount(ts, ",") + 1;
//	buyMtx = Matrix(numTicks, BarCount);
//	sellMtx = Matrix(numTicks, BarCount);
	for (index = 0; (member = StrExtract(ts, index)) != ""; ++index)   { //  Loop through all signals at this bar
		temp = Nz(StaticVarGet(member + "PositionScore"));
		if (delayExists AND temp[0] >= 0) 
			StaticVarSet(member + "PositionScore", Ref(temp, -tDelay));
		else if (temp[0] < 0) { // negative value signals external ticker, time delay already applied 
			temp[0] += 10; // normalize the position score signal by adding back the 10 subtracted in RootNode
			StaticVarSet(member + "PositionScore", temp);		
		} // end else it is a ticker managed by an external manager
		
//		buyMtx = MxSetBlock(buyMtx, index, index, 0, BarCount - 1, Nz(GetBuyArray(member, GetBuyString())));
//		sellMtx = MxSetBlock(sellMtx, index, index, 0, BarCount - 1, Nz(GetSellArray(member, GetSellString())));	
		
		VarSet("buyMtx_" + NumToStr(index) + "_" + member, GetBuyArray(member, GetBuyString()));
		VarSet("sellMtx_" + NumToStr(index) + "_" + member, GetSellArray(member, GetSellString()));
		
	} // End for each tradeable ticker in the tree

The result is the CBT gets slightly further in its processing before hanging. Instead of hanging when it enters an order on CBIO, it hangs when it enters an order on CVLG.

However, the resource monitor looks completely different. This is what it looks like when the call to bo.EnterTrade() hangs,

Screenshot 2020-12-12 2004

You can see it looks completely different than in the previous hang. There's clearly something about being in the formula context which is causing problems with entering trades, but I don't feel I know enough to formulate good hypotheses. From everything I know, the formula has finished executing and the bo.EnterTrade() calls should be atomic, unless there's a resource issue not even hinted at by the monitor.

What don't I know?

Here's the full CBT after tweaking,

// Section 10: Custom Backtester
SetCustomBacktestProc("");

if (Status("action") == actionPortfolio) {
    bo = GetBacktesterObject();	//  Get backtester object
    
    bo.PreProcess();	//  Do pre-processing
	cash = bo.InitialEquity; 
	exposure = 0;
	barsInPeriod = BarCount - 1;   
	tDelay = GetTradeDelay();
	delayExists = NOT IsNull(tDelay) AND NOT AlmostEqual(tDelay, 0);
		
/**/	
	tStop = False;
	reentryDelay = 2;
	portOffline = 11;
	tStopLongAmt = 0.1;
	tStopShortAmt = 0.05;
	portStopAmt = 0.15;
	lastPortStop = 0;
	entryAmt = 0;
	dd = 0;
	
 
	ts = GetAllTickers(RetrieveWL(rootComposite)); //CategoryGetSymbols(categoryWatchlist, CategoryFind("TRADEDTICKERS", categoryWatchlist));
	numTicks = StrCount(ts, ",") + 1;
//	buyMtx = Matrix(numTicks, BarCount);
//	sellMtx = Matrix(numTicks, BarCount);
	for (index = 0; (member = StrExtract(ts, index)) != ""; ++index)   { //  Loop through all signals at this bar
		temp = Nz(StaticVarGet(member + "PositionScore"));
		if (delayExists AND temp[0] >= 0) 
			StaticVarSet(member + "PositionScore", Ref(temp, -tDelay));
		else if (temp[0] < 0) { // negative value signals external ticker, time delay already applied 
			temp[0] += 10; // normalize the position score signal by adding back the 10 subtracted in RootNode
			StaticVarSet(member + "PositionScore", temp);		
		} // end else it is a ticker managed by an external manager
		
//		buyMtx = MxSetBlock(buyMtx, index, index, 0, BarCount - 1, Nz(GetBuyArray(member, GetBuyString())));
//		sellMtx = MxSetBlock(sellMtx, index, index, 0, BarCount - 1, Nz(GetSellArray(member, GetSellString())));	
		
		VarSet("buyMtx_" + NumToStr(index) + "_" + member, GetBuyArray(member, GetBuyString()));
		VarSet("sellMtx_" + NumToStr(index) + "_" + member, GetSellArray(member, GetSellString()));
		
	} // End for each tradeable ticker in the tree

/**/ loop = 0;
	eqHist = 0;	
    for (i = GetFirstBarInRange(); i <= GetLastBarInRange(); ++i)	{ //  Loop through all bars
		eq = 0;
		  
		if (GetDebug("CBT"))
			_TRACE("**********************In CBT at bar " + i + "****************************");
		
		if (tStop AND i > 0) { 
			dd = MaxDD(eqHist, lastPortStop, i - 1);		
		}
		
		// Calculate the current value of equity
		for (index = 0; (member = StrExtract(ts, index)) != ""; ++index) { // for each tradeable ticker
			trade = bo.FindOpenPos(member);		
			rebal = StaticVarGet(member + "_rebal");
/**/			buyMtx = VarGet("buyMtx_" + NumToStr(index) + "_" + member);
/**/			sellMtx = VarGet("sellMtx_" + NumToStr(index) + "_" + member);
			
/**/ 		_TRACE("CBT: loop number " + ++loop + " processing ticker " + member);
				
//			if (NOT IsNull(trade) AND buyMtx[index][i] != 0) {
			if (NOT IsNull(trade) AND buyMtx[i] != 0) {
										
				if (rebal[i]) { // Begin rebal signal for this trade			
					
					trade_ps = Nz(StaticVarGet(trade.Symbol + "PositionScore"));
					currPosSize = 100 * (SafeDiv(trade.GetPositionValue(), bo.Equity));					
					scaleOut = trade_ps[i] * 100 < currPosSize;					
									
					if (GetDebug("CBT"))
						_TRACE("In CBT Calc Equity: Found open position on " + trade.Symbol);


					if (AlmostEqual( trade_ps[i], 0) AND scaleOut) { // close the trade
//						price = sellMtx[index][i];				
						price = sellMtx[i];				

						if (GetDebug("CBT")) {
							_TRACE("CBT calculating current value of equity, exiting trade: i is " + i + " and trade.Symbol is " + sigSymbol + " and price is " + price);
							_TRACE("                    ");
						}

/**/					_TRACE("Closing trade. price is " + price);

						bo.ExitTrade( i, trade.Symbol, price );
						/**/ entryAmt[index] = 0;					

						cash += trade.Shares * price;

						if (GetDebug("CBT")) {
							_TRACE("CBT Exited Trade: Cost/Proceeds were " + price * trade.Shares + " and cash is now " + cash);
							_TRACE("                    ");
						}

					} // end close the trade
					else if (scaleOut) { // reduce the position size
						targetValue = (abs(trade_ps[i])) * bo.Equity;
//						price = sellMtx[index][i];
						price = sellMtx[i];
						value = abs(targetValue - trade.GetPositionValue());

						if (GetDebug("CBT")) {
							_TRACE("CBT About to Scale Trade: i is " + i + " and sig.Symbol is " + trade.Symbol);
							_TRACE("CBT New Trade: scaleIn is " + scaleIn + " and sig.Price is " + price + " and value is " + value);
							_TRACE("                    ");
						}

/**/					_TRACE("Scaling out of trade. price is " + price + "; and scale out size is " + abs( ( trade_ps[i] * 100 ) - currPosSize) * -1);

						bo.ScaleTrade(i, trade.Symbol, 0, price, abs( ( trade_ps[i] * 100 ) - currPosSize) * -1);
						/**/ if (NOT AlmostEqual(value, 0)) 
								entryAmt[index] = targetValue;
						
						cash += value;
						
						if (GetDebug("CBT")) {
							_TRACE("CBT Scaled Trade: isLong was " + (sigPosScore > 0) + " scaleIn was " + scaleIn);
							_TRACE("CBT Scaled Trade: Proceeds/Cost was " + value + " and cash is now " + cash);													
							_TRACE("                    ");
						}
					
					} // end reduce the position size
				}  // end rebal is true
				else { // rebal is false

//					price = sellMtx[index][i]; //GetSellArray(trade.Symbol, GetSellString());
					price = sellMtx[i]; //GetSellArray(trade.Symbol, GetSellString());
					eq += trade.Shares * price; //price[i];
					
				} // end if rebal is false
				
				if (trade.IsLong AND tStop AND i > 0) { // apply trailing stop rule to the long trade
//					price = sellMtx[index][i]; //GetSellArray(trade.Symbol, GetSellString());
					price = sellMtx[i]; //GetSellArray(trade.Symbol, GetSellString());

					eq += trade.Shares * price; //price[i];
										

					if ((1 - tStopLongAmt) * entryAmt[index] >= trade.Shares * price[i] OR abs(dd) >= 100 * portStopAmt) {

						_TRACE("=================================================================");
						_TRACE("Stop loss on long trade for ticker "+member+" at bar "+i);							
						_TRACE("entryAmt[index] is "+entryAmt[index]);
						_TRACE("trade.Shares is "+trade.Shares);
						_TRACE("price[i - 1] is "+price[i - 1]+" and price[i] is "+price[i]);
						_TRACE("long tolerance on value is "+(1 - tStopLongAmt)*entryAmt[index]);
						_TRACE("actual current value on long trade is "+trade.Shares*price[i - 1]);


						if (abs(dd) >= 100 * portStopAmt) {
						
							if ( AlmostEqual(i, barsInPeriod)) {
								msg = StaticVarGetText("dailyActivityLog");
								msg += "\nWARNING!!!! A portfolio stop loss has been triggered"; 
								StaticVarSetText("dailyActivityLog", msg);
							} // End if i = last bar in range
							
							lastPortStop = i;
							_TRACE("***** Portfolio stop loss occurring at bar " + i);
							psStop = Nz(StaticVarGet(member + "PositionScore"));
							for (x = i + 1; x <= i + portOffline; ++x) 
								if (x < BarCount) psStop[x] = 0; 
								
							StaticVarSet(member + "PositionScore", psStop);
						} // end if portfolio level stop loss
						else {

							if ( AlmostEqual(i, barsInPeriod)) {
								msg = StaticVarGetText("dailyActivityLog");
								msg += "\nTEST WARNING!!!! A trade stop loss has been triggered for security " + member; 
								StaticVarSetText("dailyActivityLog", msg);
							} // End if i = last bar in range

							psStop = Nz(StaticVarGet(member+"PositionScore"));
							for (x = i + 1; x <= i + reentryDelay; ++x) 
								if (x < BarCount) psStop[x] = 0;
							StaticVarSet(member+"PositionScore", psStop);
						} // end else trade level stop loss
						
					} // End if long trade stop loss is triggered
						
					
					if (GetDebug("CBT"))
						_TRACE("Position value (long) was " + trade.Shares + " * " + price[i] + " = "+trade.Shares * price[i]);
				} // End if trade is long
				else if (tStop AND i > 0) { // apply trailing stop rule to the short trade
//					price = buyMtx[index][i]; //GetBuyArray(trade.Symbol, GetBuyString());
					price = buyMtx[i]; //GetBuyArray(trade.Symbol, GetBuyString());

					eq -= trade.Shares * price; //price[i];
					eqHist[i] = eq;
															

					if ((1 + tStopShortAmt) * entryAmt[index] <= trade.Shares * price[i] OR abs(dd) >= 100 * portStopAmt) {

						_TRACE("=================================================================");
						_TRACE("Stop loss on short trade for ticker " + member + " at bar " + i);							
						_TRACE("entryAmt[index] is " + entryAmt[index]);
						_TRACE("trade.Shares is " + trade.Shares);
						_TRACE("price[i - 1] is " + price[i - 1] + " and price[i] is " + price[i]);
						_TRACE("short tolerance on value is " + (1 + tStopShortAmt) * entryAmt[index]);
						_TRACE("actual current value on short trade is " + trade.Shares * price[i - 1]);
						
						if (abs(dd) >= 100 * portStopAmt) {

							if ( AlmostEqual(i, barsInPeriod)) {
								msg = StaticVarGetText("dailyActivityLog");
								msg += "\nTEST WARNING!!!! A portfolio stop loss has been triggered "; 
								StaticVarSetText("dailyActivityLog", msg);
							} // End if i = last bar in range

							lastPortStop = i;
							_TRACE("***** Portfolio stop loss occurring at bar "+i);
							psStop = Nz(StaticVarGet(member + "PositionScore"));
							for (x = i + 1; x <= i + portOffline; x++) 
								if (x < BarCount) psStop[x] = 0;
							StaticVarSet(member + "PositionScore", psStop);
						} // end if portfolio level stop loss
						else {

							if ( AlmostEqual(i, barsInPeriod)) {
								msg = StaticVarGetText("dailyActivityLog");
								msg += "\nWARNING!!!! A trade stop loss has been triggered for security " + member; 
								StaticVarSetText("dailyActivityLog", msg);
							} // End if i = last bar in range

							psStop = Nz(StaticVarGet(member+"PositionScore"));
							for (x = i + 1; x <= i + reentryDelay; x++) 
								if (x < BarCount) psStop[x] = 0;
							StaticVarSet(member + "PositionScore", psStop);
						} // end else trade level stop loss
						
					} // End if short trade stop loss is triggered
																
					if (GetDebug("CBT"))
						_TRACE("Position value (short) was " + trade.Shares + " * " + price[i] + " = " + trade.Shares * price[i]);
						
				} // End if trade is short
			
			} // End if trade is not NULL
		} // End for each tradeable ticker of the portfolio tree
				
		if (GetDebug("CBT")) {
			_TRACE("CBT Calc Equity: equity is " + eq + " at bar " + i + " after adding position values");
		}
		
		eq += cash; 
		eqHist[i] = eq;

		if (GetOption("UsePrevBarEquityForPosSizing"))
			if ( i > 0 ) eq = eqHist[i - 1];
				
		if (GetDebug("CBT")) {
			_TRACE("CBT Calc Equity: equity is " + eq + " at bar " + i + " after cash");
			_TRACE("CBT Calc Equity: cash was " + cash);
			_TRACE("           ");
		}

		for (index = 0; (member = StrExtract(ts, index)) != ""; ++index)   { //  Loop through all signals at this bar
			ps = Nz(StaticVarGet(member + "PositionScore")) * 100; // retrieve signal
			rebal = StaticVarGet(member +  "_rebal");
/**/		buyMtx = VarGet("buyMtx_" + NumToStr(index) + "_" + member);
/**/		sellMtx = VarGet("sellMtx_" + NumToStr(index) + "_" + member);
			
/**/ 		_TRACE("CBT: loop number " + ++loop + " processing ticker " + member);
			_TRACE("bo.Equity is " + bo.Equity);
			
// 		_TRACE("CBT: at bar " + i + " with ticker " + member + " retrieved ps of " + ps[i]);

			if (LastValue(IsNull(ps))) ps = 0;
			ticker = member; 
			sigPosScore = ps[i];			
			sigPosSize = -1 * abs(ps[i]);
			sigSymbol = member;
			sigType = 0;
			sigIsLong = -1 * (sigPosScore > 0);
			sigIsScale = 0;
/*			
			if (AlmostEqual(i, 0) OR ps[i] >= ps[i - 1])
				sigPrice = buyMtx[index][i]; //GetBuyArray(ticker, GetBuyString());
			else
				sigPrice = sellMtx[index][i]; //GetSellArray(ticker, GetSellString());			
*/				
/**/		if (AlmostEqual(i, 0) OR ps[i] >= ps[i - 1])
				sigPrice = buyMtx[i]; //GetBuyArray(ticker, GetBuyString());
			else
				sigPrice = sellMtx[i]; //GetSellArray(ticker, GetSellString());			
			sigIsEntry = 0;
			sigIsExit = 0;
			sigIsScale = 0;
			exposure[i] += abs(sigPosSize);
			if (sigPosSize < -100 AND NOT AlmostEqual(sigPosSize, -100)) {
				_TRACE("ERROR! At bar " + i + " sigSymbol allocation is greater than 1 for ticker " + sigSymbol + ". sigPosSize is " + sigPosSize);
				sigPosSize = -100;
			}
			
			if (!IsNull(sigPosScore) AND sigSymbol != COMPOSITE_PREFIX + "CASH" AND rebal[i] AND sigPrice != 0) { // Begin position score exists for a ticker
				if (GetDebug("CBT")) {	
 					_TRACE("CBT Processing Signal: Score for symbol " + sigSymbol + " and PosScore is " + sigPosScore);
					_TRACE("CBT Processing Signal: Type is " + sigType);
					_TRACE("CBT Processing Signal: Size is " + sigPosSize + " and isLong is " + sigIsLong);
					_TRACE("CBT Processing Signal: sig.ScaleTrade is " + sigIsScale + " and sigPrice is " + sigPrice);
					_TRACE("Sig.IsEntry() : " + sigIsEntry);
					_TRACE("Sig.IsExit() : " + sigIsExit);
					_TRACE("Sig.IsScale() : " + sigIsScale);			
					_TRACE("            ");
				}

				if (!AlmostEqual(sigPosScore, 0) AND IsNull(bo.FindOpenPos(sigSymbol))) { // No currently open position
					value = ( abs(sigPosSize) / 100 ) * eq;

					if (GetDebug("CBT")) {
						_TRACE("CBT About to Enter New Trade: i is " + i + " and sig.Symbol is " + sigSymbol);
						_TRACE("CBT New Trade: sig.PosScore is " + sigPosScore + " and sig.Price is " + sigPrice + " and value is " + value);
						_TRACE("                    ");
					}

/**/			_TRACE("Entering trade. price: " + sigPrice + "; sigPosSize: " + sigPosSize + "; eq is " + eq);

					bo.EnterTrade( i, sigSymbol, sigPosScore > 0, sigPrice, sigPosSize );
					
					if (GetDebug("CBT")) {
						_TRACE("CBT Successfully exited bo.EnterTrade.");
					}
						
					/**/ entryAmt[index] = value;
					
					if (sigPosScore > 0)
						cash -= value;
					else
						cash += value;
						
					if (GetDebug("CBT")) {
						_TRACE("CBT Entered Trade: Cost was " + value + " and cash is now " + cash);
						_TRACE("                    ");
					}
					
				} // End Open a trade
				else if (AlmostEqual(sigPosScore, 0)) {
					trade = bo.FindOpenPos(sigSymbol);
					if (NOT IsNull(trade)) {
						if (trade.IsLong)
							cash += trade.Shares * sigPrice;
						else
							cash -= trade.Shares * sigPrice;		
					cash -= trade.GetCommission();

					if (GetDebug("CBT")) {
						_TRACE("CBT About to Exit Trade: i is " + i + " and sig.Symbol is " + sigSymbol + " and sig.Price is " + sigPrice);
						_TRACE("                    ");
					}
								
					bo.ExitTrade(i, sigSymbol, sigPrice);
					/**/ entryAmt[index] = 0;
					
					if (GetDebug("CBT")) {
						_TRACE("CBT Exited Trade: Cost/Proceeds were " + sigPrice * trade.Shares + " and cash is now " + cash);
						_TRACE("                    ");
					}
					
					} // End trade is not null
				} // End position score is 0, close a trade	
				else {
					trade = bo.FindOpenPos(sigSymbol);
					if (NOT IsNull(trade)) {
						currPosSize = 100 * (SafeDiv(trade.GetPositionValue(), bo.Equity));
						currValue = trade.GetPositionValue(); //(trade.Shares*sigPrice);
						longReversal = trade.IsLong AND sigPosScore < 0;
						shortReversal = sigPosScore > 0 AND NOT trade.IsLong;
						isReversal = longReversal OR shortReversal;
					}
					else {
						currPosSize = 0;
						currValue = 0;
						isReversal = False;
					}
					
					if (!isReversal) {	
						scaleIn = ps[i] >  currPosSize; 
						targetValue = (abs(sigPosSize) / 100) * eq;
						value = abs(targetValue - currValue);

						if (GetDebug("CBT")) {
							_TRACE("CBT About to Scale Trade: i is " + i + " and sig.Symbol is " + sigSymbol);
							_TRACE("CBT New Trade: scaleIn is " + scaleIn + " and sig.Price is "+sigPrice + " and value is " + value);
							_TRACE("                    ");
						}

/**/			_TRACE("Scaling into trade. price: " + sigPrice + "sigPosSize: " + sigPosSize);
				_TRACE("currPosSize: " + currPosSize + "; currValue " + currValue + "; targetValue: " + targetValue);
				_TRACE("size of scaleIn is: " + abs(ps[i] - currPosSize) * -1);

						bo.ScaleTrade(i, sigSymbol, scaleIn, sigPrice, abs(ps[i] - currPosSize) * -1);
						/**/ if (NOT AlmostEqual(value, 0)) 
								entryAmt[index] = targetValue;
						
						if (sigPosScore > 0) {
							if (scaleIn)
								cash -= value;
							else
								cash += value;
						} // end if scaling long trade
						else {
							if (scaleIn)
								cash += value;
							else
								cash -= value;						
						} // End else scaling a short trade
						
						if (GetDebug("CBT")) {
							_TRACE("CBT Scaled Trade: isLong was " + (sigPosScore > 0) + " scaleIn was " + scaleIn);
							_TRACE("CBT Scaled Trade: Proceeds/Cost was " + value + " and cash is now " + cash);													
							_TRACE("                    ");
						}

					} // End if not a reversal
					else {
						if (GetDebug("CBT"))
							_TRACE("CBT Scaled Trade: Trade is a reversal.");
						if (trade.IsLong)
							cash += trade.Shares*sigPrice;
						else
							cash -= trade.Shares*sigPrice;	
						cash -= trade.GetCommission();	
						if (GetDebug("CBT")) {
							_TRACE("CBT Reversal, About to Close Old Trade: i is "+i+" and sig.Symbol is " + sigSymbol);
							_TRACE("CBT Reversal: sig.Price is " + sigPrice);
							_TRACE("                    ");
						}

						bo.ExitTrade(i, sigSymbol, sigPrice);						
	
						value = ( abs(sigPosSize) / 100) * eq;

						if (GetDebug("CBT")) {
							_TRACE("CBT Reversal, About to Open New Trade: i is " + i + " and sig.Symbol is " + sigSymbol);
							_TRACE("CBT New Trade: sig.PosScore is " + sigPosScore+" and sig.Price is " + sigPrice+" and value is " + value);
							_TRACE("                    ");
						}

						bo.EnterTrade( i, sigSymbol, sigPosScore > 0, sigPrice, value );	
						/**/ entryAmt[index] = value;
											
						if (sigPosScore > 0)
							cash -= value; 
						else
							cash += value; 
							
						if (GetDebug("CBT")) {	
						_TRACE("CBT Entered Trade: Cost was " + value + " and cash is now " + cash);
						_TRACE("                    ");
						}

					} // End else is a reversal				
				} // End else not opening or closing a trade	

			} // End if sig.Symbol is a trading system mgr
        } // End for each signal
        
 //       bo.HandleStops( i );	//  Handle programmed stops at this bar
		bo.UpdateStats( i, 1 );	//  Update MAE/MFE stats for bar
        bo.UpdateStats( i, 2 );	//  Update stats at bar's end
    }	//  End of for loop over bars
    
    bo.PostProcess();	//  Do post-processing

	AddToComposite(bo.EquityArray / 1000000, rootComposite, "X", atcFlagEnableInBacktest|atcFlagCompositeGroup|atcFlagDeleteValues|atcFlagEnableInIndicator|atcFlagEnableInPortfolio); 

	CAR = Nz(StaticVarGet("CAR"));
	mxDD = Nz(StaticVarGet("maxDD"));
	exposure = Sum(exposure, BarIndex() + 1) / (BarIndex() + 1);
	expose = Nz(exposure[BarCount - 1]); 
	stats = bo.GetPerformanceStats(0);
	RAR = Nz(stats.GetValue("CAR") * (100 / expose)); 
	vol = Nz(StaticVarGet("Volatility"));
	negVol = Nz(StaticVarGet("NegativeVolatility"));
	sharpe = Nz(StaticVarGet("Sharpe"));
	sortino = Nz(StaticVarGet("Sortino"));
	berg = Nz(StaticVarGet("Bergino"));
	winPCT = Nz(StaticVarGet("winPCT"));
	avgPctGain = Nz(StaticVarGet("avgPctGain"));
	avgPctLoss = Nz(StaticVarGet("avgPctLoss"));
	kelly =	Nz(StaticVarGet("kelly"));
	avgTradeLength = Nz(StaticVarGet("avgTradeLength"));
	cl = Nz(Correlation(bo.EquityArray, Foreign(INDEX_PREFIX + "SPX", "C"), barsInPeriod - 1));
	correl = cl[GetLastBarInRange()];
 	eqlWghtCAR = Nz(StaticVarGet("equalWeightPort"));
	eqlWghtDD =	Nz(StaticVarGet("equalWeightMxDD"));
	randWghtCAR = Nz(StaticVarGet("randomWghtCAR"));
	randWghtCARstd = Nz(StaticVarGet("randomWghtCARstd"));
	randWghtDD =	Nz(StaticVarGet("randomWghtMxDD"));
	randWghtDDstd = Nz(StaticVarGet("randomWghtMxDDstd"));

     
 	// Here we add custom metric to backtest report
	bo.AddCustomMetric( "CAR", CAR, False, False, 2, 4);
	bo.AddCustomMetric("MaxDD", mxDD, False, False, 2, 6);
	bo.AddCustomMetric( "Exposure", expose, False, False, 2, 4);
	bo.AddCustomMetric( "RAR", RAR, False, False, 2, 4);
	bo.AddCustomMetric( "Volatility", vol, False, False, 2, 4);
	bo.AddCustomMetric("NegativeVol", negVol, False, False, 2, 4);
	bo.AddCustomMetric( "Sortino", sortino, False, False, 2, 4);
	bo.AddCustomMetric( "Sharpe", sharpe, False, False, 2, 4);
	bo.AddCustomMetric("Bergino", berg, False, False, 2, 4);
	bo.AddCustomMetric("winPct", winPCT, False, False, 2, 4);
	bo.AddCustomMetric("avgPctGain", avgPctGain, False, False, 2, 4);
	bo.AddCustomMetric("avgPctLoss", avgPctLoss, False, False, 2, 4);
	bo.AddCustomMetric("kelly", kelly, False, False, 2, 4);
	bo.AddCustomMetric("avgTradeLength", avgTradeLength, False, False, 2, 4);
	bo.AddCustomMetric("Correlation to S&P 500", correl, False, False, 2, 4);

	bo.AddCustomMetric("CAR, Equal Weights (annual rebal)", eqlWghtCAR, False, False, 2, 4);
	bo.AddCustomMetric("MaxDD, Equal Weight", eqlWghtDD, False, False, 2, 4);
	bo.AddCustomMetric("CAR, Random Weights", randWghtCAR, False, False, 2, 4);
	bo.AddCustomMetric("Std Dev, Random CAR", randWghtCARstd, False, False, 2, 4);
	bo.AddCustomMetric("MaxDD, Random Weight", randWghtDD, False, False, 2, 4);
	bo.AddCustomMetric("Std Dev, Random MaxDD", randWghtDDstd, False, False, 2, 4);
	
	
} // end custom backtester```

I should re-say: When I run the real formula, it creates about 12,000 staticvar arrays ( 6 for each ticker ) which it uses in processing. Only one is called by the CBT but they still take memory, I suppose.

Forum discussion is pointless, no-one would help you, using some code fragments (like CBT only part).

If you want help, you have to send the entire code that reproduces the problem (it does not need to be your secret formula it just has to enough reproduce the problem), including all settings, i.e save project file (as .APX) to SUPPORT by email,
so it can be simply LOADED and RUN in development environment, without having to write other (missing) parts of the code.

Any problem can only be fixed if it is reproducible in controlled development environment.

3 Likes

As I said in my post, I've been trying to isolate and reproduce it for awhile now and was looking for new ideas about how. You should know by now, I never post here unless I've been working on something myself for a long time and am running out of ideas about what to try next.

Anyway, I continued to work on it today. I was finally able to reproduce it by running all the formulae in sequence which lead up to the CBT using Analyze instead of Backtest, so the CBT doesn't run, and then running the CBT by itself in a separate file. This had the effect of running the CBT with all the generated static vars used in the analysis present in memory, but all the other memory having been released. Lo and behold, the call hung when the CBT was run by itself under these conditions and at the exact same spot. So it seems I've run into some static var limit on my hardware or for AB.

I ran StaticVarInfo() and it gave me this,
totalmemory: 3.42255e+008
memory: 3.41706e+008

There are no units on this readout, but if it is MB, looks like I've got 32GB of RAM on my machine and 34GB of static var used to achieve my analysis prior to going to the CBT. Here's the readout just before the CBT call to bo.EnterTrade() hangs, just so everyone can see things appear normal up to the event,

===========================
Calling bo.EnterTrade with inputs: i - 0; symbol - CRMD; price - 1.55; sigPosSize: -1.17884; eq is 1e+006; and bo.Equity is 1e+006
Exited bo.EnterTrade()
CBT: loop number 2468 processing ticker CRMT
CBT: loop number 2469 processing ticker CRNC
CBT: loop number 2470 processing ticker CRNX
CBT: loop number 2471 processing ticker CROX
CBT: loop number 2472 processing ticker CRS
CBT: loop number 2473 processing ticker CRTX
CBT: loop number 2474 processing ticker CRVL
CBT: loop number 2475 processing ticker CRY
CBT: loop number 2476 processing ticker CSBR
CBT: loop number 2477 processing ticker CSGS
CBT: loop number 2478 processing ticker CSII
CBT: loop number 2479 processing ticker CSOD
CBT: loop number 2480 processing ticker CSPR
CBT: loop number 2481 processing ticker CSTE
CBT: loop number 2482 processing ticker CSTL
CBT: loop number 2483 processing ticker CSTR
CBT: loop number 2484 processing ticker CSV
CBT: loop number 2485 processing ticker CSWI
CBT: loop number 2486 processing ticker CTB
CBT: loop number 2487 processing ticker CTBI
CBT: loop number 2488 processing ticker CTMX
CBT: loop number 2489 processing ticker CTO
CBT: loop number 2490 processing ticker CTRE
CBT: loop number 2491 processing ticker CTRN
Calling bo.EnterTrade with inputs: i - 0; symbol - CTRN; price - 8.19485; sigPosSize: -0.609779; eq is 1e+006; and bo.Equity is 1e+006
Exited bo.EnterTrade()
CBT: loop number 2492 processing ticker CTS
CBT: loop number 2493 processing ticker CTSO
CBT: loop number 2494 processing ticker CTT
CBT: loop number 2495 processing ticker CUB
CBT: loop number 2496 processing ticker CUBI
CBT: loop number 2497 processing ticker CUE
CBT: loop number 2498 processing ticker CURO
CBT: loop number 2499 processing ticker CUTR
CBT: loop number 2500 processing ticker CVA
CBT: loop number 2501 processing ticker CVBF
CBT: loop number 2502 processing ticker CVCO
CBT: loop number 2503 processing ticker CVCY
CBT: loop number 2504 processing ticker CVET
CBT: loop number 2505 processing ticker CVGW
CBT: loop number 2506 processing ticker CVI
CBT: loop number 2507 processing ticker CVLG
Calling bo.EnterTrade with inputs: i - 0; symbol - CVLG; price - 3.02333; sigPosSize: -0.894356; eq is 1e+006; and bo.Equity is 1e+006

======================================
As you can see, it is entering and exiting the call normally up until CVLG, where it enters and then just hangs. A note: nothing goes wrong with the rest of my computer so it's not a general resource issue. When I run these tests, I have Chrome open with about 50 tabs and I watch video etc. while this is going on, no problems. It's AB specifically that doesn't like something. Unfortunately, bo.EnterTrade() is throwing no error message or exception, so I don't know what is happening inside that black box. Also, the resource monitor shows it is still using a bunch of CPU ( even if I let it run for days ), so it is doing something even though it doesn't exit and shows no discernible progress.

What's the best way to handle this? Is there a configuration parameter for AB I can change ( best )? Do I need to go through a bunch of StaticVarRemove() calls before starting CBT processing ( bad )? Do I need to find a way to communicate between processes and threads without static vars ( worst )?

StaticVarInfo, Users' manual:

Quote:

  • "memory" - returns memory usage in bytes (not including memory used for variable name itself)
  • "totalmemory" - returns memory usage in bytes (including memory used for variable name)

As I said, I can't comment on something that I can't run on my end. Developers don't work that way. Developers have to run software in controlled environment and observe what happens as it happens. Playing guessing games is not scientific approach.

1 Like

This topic was automatically closed 100 days after the last reply. New replies are no longer allowed.