"Unable to match order state to execution"

[heech]

I received an alert + messages in the log this morning...

11/26/2008 6:57:16 AM|1|128|Starting NinjaScript strategy 'ProtectDown/3d1fbd264b67483ba2eb9578a17475c8' : On starting a real-time strategy - StrategySync=SubmitLive EntryHandling=AllEntries EntriesPerDirection=1 StopTargetHandling=ByStrategyPosition ErrorHandling=TakeNoAction ExitOnClose=False Set order quantity by=Strategy
11/26/2008 6:57:17 AM|1|32|Order='NT-4/707028387' Name='Sell' New State=PendingSubmit Instrument='MAC' Action=Sell Limit price=0 Stop price=11 Quantity=1,000 Type=Stop Filled=0 Fill price=0 Error=NoError Native error=''
11/26/2008 6:57:21 AM|1|32|Order='4502008081/707028387' Name='Sell' New State=Accepted Instrument='MAC' Action=Sell Limit price=0 Stop price=11 Quantity=1,000 Type=Stop Filled=0 Fill price=0 Error=NoError Native error=''
11/26/2008 6:57:21 AM|1|32|Order='4502008081/707028387' Name='Sell' New State=Working Instrument='MAC' Action=Sell Limit price=0 Stop price=11 Quantity=1,000 Type=Stop Filled=0 Fill price=0 Error=NoError Native error=''
11/26/2008 6:57:21 AM|1|32|Order='4500271885/707028387' Name='Sell' New State=Cancelled Instrument='MAC' Action=Sell Limit price=0 Stop price=11 Quantity=1,000 Type=Stop Filled=0 Fill price=0 Error=NoError Native error=''
11/26/2008 7:07:54 AM|1|32|Order='4502008081/707028387' Name='Sell' New State=Filled Instrument='MAC' Action=Sell Limit price=0 Stop price=11 Quantity=1,000 Type=Stop Filled=1000 Fill price=10.982 Error=NoError Native error=''
11/26/2008 7:07:54 AM|1|16|Execution='4502109406' Instrument='MAC' Account='707028387' Exchange=Default Price=10.98 Quantity=100 Market position=Short Operation=Insert Order='4502008081' Time='11/26/2008 7:07:54 AM'
11/26/2008 7:07:54 AM|1|16|Execution='4502109402' Instrument='MAC' Account='707028387' Exchange=Default Price=10.97 Quantity=300 Market position=Short Operation=Insert Order='4502008081' Time='11/26/2008 7:07:54 AM'
11/26/2008 7:07:54 AM|1|16|Execution='4502109397' Instrument='MAC' Account='707028387' Exchange=Default Price=10.97 Quantity=200 Market position=Short Operation=Insert Order='4502008081' Time='11/26/2008 7:07:54 AM'
11/26/2008 7:07:54 AM|1|16|Execution='4502109265' Instrument='MAC' Account='707028387' Exchange=Default Price=10.99 Quantity=100 Market position=Short Operation=Insert Order='4502008081' Time='11/26/2008 7:07:54 AM'
11/26/2008 7:07:54 AM|1|16|Execution='4502108925' Instrument='MAC' Account='707028387' Exchange=Default Price=11 Quantity=300 Market position=Short Operation=Insert Order='4502008081' Time='11/26/2008 7:07:54 AM'
11/26/2008 7:07:54 AM|0|128|Unable to match order state to execution: Order='4502008081/707028387' Name='Sell' State=Filled Instrument='MAC' Action=Sell Limit price=0 Stop price=11 Quantity=1,000 Strategy='ProtectDown' Type=Stop Tif=Day Oco='' Filled=1000 Fill price=10.982 Token='4de5a41889964344933a08a065aa9ec9' Gtd='12/1/2099 12:00:00 AM' / Execution='4502109406' Instrument='MAC' Account='707028387' Name='Sell' Exchange=Default Price=10.98 Quantity=100 Market position=Short Commission=0 Order='4502008081' Time='11/26/2008 7:07:54 AM'
11/26/2008 7:07:54 AM|0|128|Unable to match order state to execution: Order='4502008081/707028387' Name='Sell' State=Filled Instrument='MAC' Action=Sell Limit price=0 Stop price=11 Quantity=1,000 Strategy='ProtectDown' Type=Stop Tif=Day Oco='' Filled=1000 Fill price=10.982 Token='4de5a41889964344933a08a065aa9ec9' Gtd='12/1/2099 12:00:00 AM' / Execution='4502109402' Instrument='MAC' Account='707028387' Name='Sell' Exchange=Default Price=10.97 Quantity=300 Market position=Short Commission=0 Order='4502008081' Time='11/26/2008 7:07:54 AM'
11/26/2008 7:07:54 AM|0|128|Unable to match order state to execution: Order='4502008081/707028387' Name='Sell' State=Filled Instrument='MAC' Action=Sell Limit price=0 Stop price=11 Quantity=1,000 Strategy='ProtectDown' Type=Stop Tif=Day Oco='' Filled=1000 Fill price=10.982 Token='4de5a41889964344933a08a065aa9ec9' Gtd='12/1/2099 12:00:00 AM' / Execution='4502109397' Instrument='MAC' Account='707028387' Name='Sell' Exchange=Default Price=10.97 Quantity=200 Market position=Short Commission=0 Order='4502008081' Time='11/26/2008 7:07:54 AM'
11/26/2008 7:07:54 AM|0|128|Unable to match order state to execution: Order='4502008081/707028387' Name='Sell' State=Filled Instrument='MAC' Action=Sell Limit price=0 Stop price=11 Quantity=1,000 Strategy='ProtectDown' Type=Stop Tif=Day Oco='' Filled=1000 Fill price=10.982 Token='4de5a41889964344933a08a065aa9ec9' Gtd='12/1/2099 12:00:00 AM' / Execution='4502109265' Instrument='MAC' Account='707028387' Name='Sell' Exchange=Default Price=10.99 Quantity=100 Market position=Short Commission=0 Order='4502008081' Time='11/26/2008 7:07:54 AM'
11/26/2008 7:07:54 AM|0|128|Unable to match order state to execution: Order='4502008081/707028387' Name='Sell' State=Filled Instrument='MAC' Action=Sell Limit price=0 Stop price=11 Quantity=1,000 Strategy='ProtectDown' Type=Stop Tif=Day Oco='' Filled=1000 Fill price=10.982 Token='4de5a41889964344933a08a065aa9ec9' Gtd='12/1/2099 12:00:00 AM' / Execution='4502108925' Instrument='MAC' Account='707028387' Name='Sell' Exchange=Default Price=11 Quantity=300 Market position=Short Commission=0 Order='4502008081' Time='11/26/2008 7:07:54 AM'
11/26/2008 7:07:56 AM|1|64|Instrument='MAC' Account='707028387' Avg price=0 Quantity=0 Market position=Long Operation=Remove Currency=UsDollar

What does this mean?

[NinjaTrader_Josh]

heech,

Where are you submitting orders from? You may be hitting race conditions. Hard to say without isolating out the specific line/block of code that generated this error.

[heech]

Originally Posted by NinjaTrader_Josh

heech,

Where are you submitting orders from? You may be hitting race conditions. Hard to say without isolating out the specific line/block of code that generated this error.

Josh,

This is one of the stop orders generated by my strategy (mentioned in the log as well).

A race condition in NT order handling code, I assume you mean? It looks like it might be that.

[NinjaTrader_Josh]

Likely race condition. You will need to be mindful of the multi-threaded nature of NinjaTrader.

[heech]

Originally Posted by NinjaTrader_Josh

Likely race condition. You will need to be mindful of the multi-threaded nature of NinjaTrader.

Not sure what that means, Josh... in terms of being mindful. Do I need to do anything to synchronize *my* code, or are you saying I should just be aware of/ignore these errors when they pop up?

[NinjaTrader_Josh]

There is nothing you can do to synchronize NT being multi-threaded. You have to work with it and be aware of it.

[NinjaTrader_Ray]

Just curious, is this with IB TWS and if yes, what NT version are you using? Help > About.

[heech]

Originally Posted by NinjaTrader_Ray

Just curious, is this with IB TWS and if yes, what NT version are you using? Help > About.

No, this is going direct to TDAmeritrade. I'm version 6.5.1000.7.

I actually think this isn't a race condition, I'm suspecting something else (problems in my code?). I just had another stop order hit, and the same error message popped up... that's pretty bad luck on my part if it's a race condition.

I've had three stop orders hit today, and two gave the same error. Note that the two orders that gave errors filled on multiple orders, whereas the stop order that didn't error out filled on a single order. I suspect that's significant.

[NinjaTrader_Josh]

We cannot evaluate the scenario without seeing exact code. Please post simple as possible code snippet.

[heech]

Originally Posted by NinjaTrader_Josh

We cannot evaluate the scenario without seeing exact code. Please post simple as possible code snippet.

Josh,

Not sure what to show you... this is the stop order code. It's only called once at the beginning of day (or when position is entered)... so hours ago from when the error popped up.

stopOrder = ExitLongStop(0, true, config.NumShares, holdPrice * stopMultiple, "", "");

holdPrice and stopMultiple are both static numbers from the point of view of this strategy (loaded from my cfg file).

I do use OnOrderUpdate, and here's the relevant code for orderstate.filled:

if (order.OrderState == OrderState.Filled)
{
if (debugging)
Print("Order filled: " + order);
if ((longOrder != null) && (order.Token == longOrder.Token))
{
if (debugging)
Print("Placing stop order...");
// longOrder filled... put in my stop order.
stopOrder = ExitLongStop(0, true, config.NumShares, holdPrice * stopMultiple, "", "");
return;
}
if ((stopOrder != null) && (order.Token == stopOrder.Token))
{
// Stop order has been filled....
stopOrder = null;
}
}

[NinjaTrader_Josh]

And have you isolated out the scenario when you reach these messages? Reproducible at will? What is the code doing right before it happens? The nature of these things is complicated. You need to do it step by step. Keep things very simple. One order at a time. Until you can isolate out exactly what is happening with your code we cannot assist much. Unfortunately we just don't have the bandwidth to be going through everyone's code in depth. What we need to see to further assist is the code you have isolated out (in this instance it may even be best to see the complete code of the isolated case so only show us the code that is absolutely necessary to reproduce), the behavior you think it should be doing, the behavior you are seeing, and all relevant evidence you have showing the contrary.

The key here is that you need to be able to reproduce it and inform us as to the steps to reproduce it and then we can proceed from there.

[heech]

Originally Posted by NinjaTrader_Josh

And have you isolated out the scenario when you reach these messages? Reproducible at will? What is the code doing right before it happens? The nature of these things is complicated. You need to do it step by step. Keep things very simple. One order at a time. Until you can isolate out exactly what is happening with your code we cannot assist much. Unfortunately we just don't have the bandwidth to be going through everyone's code in depth. What we need to see to further assist is the code you have isolated out (in this instance it may even be best to see the complete code of the isolated case so only show us the code that is absolutely necessary to reproduce), the behavior you think it should be doing, the behavior you are seeing, and all relevant evidence you have showing the contrary.

The key here is that you need to be able to reproduce it and inform us as to the steps to reproduce it and then we can proceed from there.

Josh,

I think you're barking up the wrong tree here. There's no way that this is remotely related to my code. Your last theory was that this is a race condition in the Ninja Trader order handling code, I don't know how it jumped to my application.

No, I have no way of reproducing the error... it isn't even an error generated by the strategy itself, and I have no intention of entering into positions and setting up stop orders just in hopes that I'll get multiple fills, and the platform will throw an alert. And just to be clear, it's not just a "log" message... I actually get a modal MessageBox with the alert (and not generated by my strategy).

I think the most likely explanation is that whatever logic is in place (perhaps linked to TDAmeritrade - I take it it's not a common choice for the execution broker) for handling order fulfillment is confusing partial fills with full order fills.

[NinjaTrader_Ray]

The situation is this:

- This error message pops up when NT receives (for example) a "Filled" state for an order that has generated multiple part fills
- In this example, we expect to see multiple "PartFilled" order states to be in sycn with the actuall executions reported in the OnExecution() method
- This means that you can't rely on using OnOrderUpdate() with this particular broker since sometimes they may provide all order state changes and sometimes they may not

The net result is that we would advise you not to use OnOrderUdpate() when trading through TDA. This occured before with IB (which is why I asked before) but this was an issue on our send that we fixed. I can see from your log info you posted that we really did not receive "PartFilled" states generated from the TDA adapter.

[heech]

Ray,

That's about what I figured was happening.

I'm not too concerned about OnOrderUpdate... if I get you correctly, my use of the function isn't the cause of the alert. You're just warning me about other consequences. I understand I might confuse a partial fill with a full fill, but at the time scales I'm trading at, it really shouldnt' be an issue 99.99% of the time. Regardless, I'll look into OnExecute().

In the mean time... are the Alert messages an issue? If I step away from my desk all day, and all hell breaks loose on the markets and I hit a lot of stop orders... am I going to end up with 50 messageboxes, and do you see that possibly breaking anything (like on-going execution of strategies)?

And if *it* is an issue... can I pleasepleaseplase get a patched version of the software that gives me the option to turn off that messagebox alert?

[NinjaTrader_Ray]

Depending on what the Alert message shows, if its an rejected order, the strategy will terminate immediately, if its some warning then there is the possibility that you can get an unwanted number of message boxes although I don't ever recall a situation where anyone has raised an issue due to an offensive number of message boxes. At this time, these boxes can't be surpressed.