Strange execution behavior foresees the future w OnBarClose

[giogio1]

I am not able to understand the behavior shown in the attached picture. It is a 10 seconds chart of a playback real time execution with the playback playing. The strategy uses a simple managed approach.
It shows the execution and stop placement actually happening 5 seconds past 9am (9 00 05 00 PM).
In the chart the blue arrow showing the "Z1L" long entry al 20218.5 at the bar 2042 which has the time 21:00:10. I imagine that this is correct, it shows the execution on the chart at the first bar available after the actual execution.
The bar 2041 ends and gets plotted at 21:00:00. The Watch4 window of the Vs debugger shows also 9PM for bar 2041. All of this is correct to me.
The problem is that the debugger (and the chart with the pink line) shows that the Market Position is Long at the bar 2041, before the actual execution even at the first tick of the bar as I am using
The behavior is independent from the order fill resolution but if I Calculate on each tick it disappears.
Can you explain me the logic?
Thank you.
G

[NinjaTrader_Jesse]

Hello giogio1,

While I wouldn't be able to comment on the values that visual studio displays as that is an external software we could review the situation using built in platform tools like prints, do you see the same output using a print?

[giogio1]

Hi Jesse,
Thank you for looking into it. Printing it allowed me to better understand the problem. I added the printout of the OnExecutionUpdate() and OnOrderUpdate() but for unknown reasons Trace Order = true during State.SetDefaults didn't do anything. I also observed the behavior slowly.
The pictures are self explanatory. Please note that the pink line at the 20219.16 price point is the plotting of the Stop Order gotten when OnOrderUpdate() reported Stop Loss Accepted..
The pictures show the behavior with OnBarClose and OnEachTick.
My observation is the following:
With OnEachTick:
The order gets executed at 9:04:37 PM and reported by OnOrderUpdate and OnExecutionUpdate 3 seconds later at 9:04:40 PM
With OnBarClose:
The order gets executed at 9:04:?? PM and reported by OnOrderUpdate and OnExecutionUpdate 3 seconds later at 9:04:40 PM but it is reported on the chart by the blue arrow and in the order tab 10 seconds later at 9:04:50 PM.
It looks strange that OnEachTick the Orders tab reports the order execution first but with OnBarClose get reported last on the Orders tab.

One thing I'd like to underline, the problem seems to be on the reporting only but as far a strategy coding is concerned it looks ok because there is no looking into the future. Am I correct or am I confused?

Best,
Gio

PS The Pink Line reporting the stop price is plot by OnBarUpdate by the follwoing code:

// snippet
OnBarUpdate()
{
       if (Position.MarketPosition != MarketPosition.Flat)
       {
            PlotSR[0] = this.stopPrice;
        }
}



[ATTACH=JSON]{"data-align":"none","data-size":"medium","data-attachmentid":1323319}[/ATTACH]
OnOrderUpdate(...)
{
        if (order.OrderState == NinjaTrader.Cbi.OrderState.Accepted)
        {
                Print(Time[0] + " OnOrderUpdate " + order.ToString() + "   " + error.ToString());
                this.stopPrice = order.StopPrice;
​        }
}

OnExecutionUpdate()
{
        Print(Time[0] + " OnExecutionUpdate " + execution.ToString() + " marketPosition " + marketPosition + " time " + time.ToString());
}
​

Playback execution behavior OnBarClose.jpg




Playback execution behavior OnEachTick.jpg

[NinjaTrader_Jesse]

Hello giogio1

In the code you are using the print contains the bar time which is not relevant to the order, from OnOrderUpdate or OnExecutionUpdate you would need to use passed in time variable to know when that event happened.

Time[0] is only going to be relevant from OnBarUpdate for when you submit an entry.

[giogio1]

With this screenshot I am attempting to be clearer.
With processing OnBarClose the execution is reported by TraceOrders and at time 9:04:50pm and on the chart the execution is also reported with an arrow at time 9:04:50pm, but the code reports long positions already on bar 2062 at 9:04:40pm.
It could be OK once it is understood the reason of the behavior. Can you clarify?
Gio

[NinjaTrader_Jesse]

Hello giogio1

I can't see what code was used in that situation to estimate the result. In the previous code you had shown you are using Time[0] in the order event overrides so that would not produce the correct times when printing and lead to discrepancies in the prints. You are also printing the Market Position which is the position direction, not the strategies current position from OnExecutionUpdate.

[giogio1]

Thank You Jesse for your reply. To respond to your attention to this issue I decided to spend some time and build a test case reduced to the bare minimum, the full code is below and it is conceived for a 100 bars chart. which I then play for another 4 bars.
In the Plot the Orange Line is the stop loss line taken from OnBarUpdated() .
Position.MarketPosition is no longer flat already at 9:00:20 pm as shown by the orange stop loss line that is also availabe at 9:00:20 pm.
But its entry order gets accepted and filled after, at 9:00:24 pm.
Is it a bug ? How should I think it ?
Best
Gio

using System;
using System.ComponentModel;
using System.Diagnostics;
using System.Windows.Media;
using NinjaTrader.Cbi;
using NinjaTrader.Data;
using NinjaTrader.Gui.Chart;
using NinjaTrader.NinjaScript.Indicators;
using NinjaTrader.NinjaScript.Strategies;
using NinjaTrader.Gui;

namespace NinjaTrader.NinjaScript.Strategies
{
    public class TestCase1 : Strategy
    {
        private double managedStop = 0;

        protected override void OnStateChange()
        {
            switch (State)
            {
                case State.SetDefaults:
                    ClearOutputWindow();
                    Calculate = Calculate.OnBarClose;
                    EntriesPerDirection = 3;
                    OrderFillResolution = OrderFillResolution.Standard;
                    TraceOrders = true;
                    IsInstantiatedOnEachOptimizationIteration = true;
                    AddPlot(new Stroke(Brushes.Coral, 1), PlotStyle.Square, "Stop");
                    break;
             }
        }

        protected override void OnBarUpdate()
        {
            if (State == State.Historical) return;

            // FOR A 100 Bars Chart !
            if (Position.MarketPosition == MarketPosition.Flat && CurrentBar == 101)
            {
                Print("Line Code prior EntryLong - Market Order on bar " + CurrentBar + " at Time[0] = " + Time[0] + "Position.MarketPosition:" + Position.MarketPosition);
                SetStopLoss(CalculationMode.Ticks, 6);
                EnterLong();
            }

            if (Position.MarketPosition != MarketPosition.Flat && CurrentBar == 103)
            {
                ExitLong();
            }
            if (CurrentBar >= 101 && CurrentBar <= 103) Print("Line Code after EntryLong -  bar " + CurrentBar + " at Time[0] = " + Time[0] + "Position.MarketPosition:" + Position.MarketPosition);

            if ((Position.MarketPosition != MarketPosition.Flat) && (this.managedStop != 0))
            {
                Values[0][0] = this.managedStop;
            }
        }

        protected override void OnOrderUpdate(Order order, double limitPrice, double stopPrice, int quantity, int filled, double averageFillPrice,
                                    OrderState orderState, DateTime time, ErrorCode error, string nativeError)
        {
            Print("order.Time:" + order.Time + " OnOrderUpdate " + order.ToString() + "   " + error.ToString() + " time:" + time.ToString());

            if ((order.OrderState == NinjaTrader.Cbi.OrderState.Accepted) && (order.Name == "Stop loss"))
            {
                this.managedStop = order.StopPrice;
            }
        }
    }
}  ​

[NinjaTrader_Jesse]

Hello giogio1,

From the prints that appears to be correct, there are no delays in processing added in playback like there would be in realtime or sim. The position is updated immediately and your prints show that. In realtime you would likely need to wait at least 1 OnBarUpdate event for the position object to update. The 9:20 time is because you are using a 10 second data series and that is when the condition was true and is also the time of the bar being printed.

[giogio1]

Thank you Jesse for taking the time to respond. I realize my observation may seem pedantic and I'll stop here, promise. It is ok for me to accept the situation but I also marked the picture to get a better understanding. The Bar ends at the second 20 and shows to have the filled position long already. The order appear to be submitted at the second 24, that is after. You may agree with me that to understand this my mental process becomes quite convoluted and cannot make much sense of it. I can live with it but I wander of you can explain where my reasoning is wrong.
Writing you I realize that the order is actually send at the bar of 20seconds and get filled instantly at the 20th second. But then the reporting of the order acceptance and submission should be also get reported at the 20th second, not four second later. Where am I incorrect?
Thank you,
Gio