Developer forum

Forum » Integration » OrderProvider Feature "Remove missing order lines" not working

OrderProvider Feature "Remove missing order lines" not working

E-mail notifications
Shawn Tehini Dynamicweb Employee
Shawn Tehini
Reply
Posted on 12/05/2021 21:48:52

Hi, 

Please see attached video reproducing issue.  

On a 9.10.8 site there is an issue with OrderLines not being removed if they are not in the import when order provider destination setting feature "Remove missing order lines" is selected. 

When an order is placed from the frontend, the record can be viewed in the database and exports successfully. After the order had been brought back on the Import Orders the issue occurs.  What is occuring is that the DW OrderLineId, OL*, is created and exported to ERP.  When the order syncs back from the ERP the import XML has ONLY the ERP OrderLineId of #_#.  The feature to "Remove missing order lines" should impor the new ERP OrderLineId and remove the DW generated OrderLineId.  However, both orderlines are remaining on the order. 

If you run the data integration job directly the feature works as expected.  

Here is the troubleshooting findings thus far:

- It occurs on the import and is irrelevant of if the order is a first time or edit
- If you run the export then import in close succession you increase the chances of the issue occurring.  We can repro about 9/10 times when running in close succession.
- If you run the export recycle the site and run the import you cannot repro the issue (suggests caching for sure)
- If you run the import twice in a row in quick succession to the export you often see the issue on the first import but never the second (further points to caching and race condition)
- If you run the data integration job the issue is never able to be reproduced
- If you pull the order with a primary key filter you can still repro the issue if you keep the order of operation the same
- If you leave a large gap of time between the export and import the repro is not showing
- If you clear the cache in the website (not a full restart just a break) we are still seeing the repro
 
Next we put a debugger on the solution and break point at the "Remove missing order lines" SQL query in the order provider.  We found the query is working as expected.  We did see a killall in the provider code for cache busting.  We think we saw that the issue was not in the "Remove missing order lines" piece of the order provider but was pointing up to the runner method.  
 
Does anyone know why this would be occuring or thoughts to further help?
 
Thanks, 
Shawn
 

 

 


Replies

 
Dmitriy Benyuk Dynamicweb Employee
Dmitriy Benyuk
Posted on 12/05/2021 23:45:35
Reply

Hi Shawn,
it looks like your order was saved exactly at the same time when your import job was run, see those logs for your exmple order:

2021-05-12 11:06:00.450: Start checking input files changing
2021-05-12 11:06:05.452: Finish checking input files changing
2021-05-12 11:06:05.452: reading configuration
2021-05-12 11:06:05.452: Starting import to temporary table for EcomOrders.
2021-05-12 11:06:05.546: Added 1 rows to temporary table for EcomOrders.
2021-05-12 11:06:05.546: Finished import to temporary table for EcomOrders.
2021-05-12 11:06:05.546: Starting import to temporary table for EcomOrderLines.
2021-05-12 11:06:05.618: Added 1 rows to temporary table for EcomOrderLines.
2021-05-12 11:06:05.618: Finished import to temporary table for EcomOrderLines.
2021-05-12 11:06:05.722: Job succeeded.

Ecom order log:
 

Wed, 12 May 2021 11:05:33 OrderHandler.ErpCallFailed ERP communication failed with error: System.NullReferenceException: Object reference not set to an instance of an object. at Dna.Ecommerce.LiveIntegration.OrderHandler.HandleIntegrationSuccess(Order order, String successState) at Dna.Ecommerce.LiveIntegration.OrderHandler.ProcessResponse(XmlDocument response, Order order, Boolean createOrder, String successState, String failedState)  
Wed, 12 May 2021 11:06:05 Order Order saved (IsCart:False, Complete:True), (IP:216.116.240.52, Url:/Admin/Content/Management/Pages/ScheduledTasks_cpl.aspx), Thread:42, HashCode:20167170)

 

As you can see the last line is a call for Order.Save() so probably the order is resaved with an old order line again after the DI job was run
I am not fully sure about the sequences here since no ms are shown in the Ecom log.

Also I have found that after 20 sec a second run of the same DI job was run:
2021-05-12 11:06:26.928: Start checking input files changing
2021-05-12 11:06:31.929: Finish checking input files changing
2021-05-12 11:06:31.929: reading configuration
2021-05-12 11:06:31.929: Starting import to temporary table for EcomOrders.
2021-05-12 11:06:32.076: Added 1 rows to temporary table for EcomOrders.
2021-05-12 11:06:32.076: Finished import to temporary table for EcomOrders.
2021-05-12 11:06:32.076: Starting import to temporary table for EcomOrderLines.
2021-05-12 11:06:32.174: Added 1 rows to temporary table for EcomOrderLines.
2021-05-12 11:06:32.174: Finished import to temporary table for EcomOrderLines.
2021-05-12 11:06:32.285: Job succeeded.

So maybe you have some several tasks runnig simultaneous?

I can see you are using a custom scheduled task add-in so maybe it is doing smth wrong with the job/transactions/etc

Kind regards, Dmitrij

 
Shawn Tehini Dynamicweb Employee
Shawn Tehini
Posted on 13/05/2021 21:11:41
Reply

Hi Dmitrij,

 

Thanks for your response.  Mario is looking in to the custom scheduler task add-in to see if it can be playing a role in the running of the data integration job or anything else.

In the meantime, I think that duplicate log is due to the scheduled task running (which runs the data int) and then us manually running the data int job to show that the data int job removes the duplicate OrderLine when it is run a second time even though it does not remove it in the first run via the scheduled task. 

I created another example order for you leaving it in a broken state:

This order is in the "bad" state and only has 1 run on the data int job which was via the schedlued task.  From here if you run the data integraiton job again the OL* orderline will be removed leaving just the correct OrderLine.

Any further thoughts now knowing that dupliate logged run was manual?  This example on the same site has only a single run today 5/13.

Thanks, 
Shawn 

 
Dmitriy Benyuk Dynamicweb Employee
Dmitriy Benyuk
Posted on 13/05/2021 21:56:41
Reply

Hi Shawn,
Could you run this query and send me the output, since I can not see the milliseconds in the Sql Firehouse in Dynamicweb
and it looks like smth weird can happen just in the same time when the DI job is running:
sql to run on db directly:
select * from EcomOrderDebuggingInfo where OrderDebuggingInfoOrderId = 'WEB1007465'
order by OrderDebuggingInfoTime desc
I see that this query returns me the OrderSaved event just at the time:
2021-05-13 15:04:11
And DI job also is running at the same time:
2021-05-13 15:04:06.025: Start checking input files changing
2021-05-13 15:04:11.027: Finish checking input files changing
2021-05-13 15:04:11.027: reading configuration
2021-05-13 15:04:11.034: Starting import to temporary table for EcomOrders.
2021-05-13 15:04:11.243: Added 1 rows to temporary table for EcomOrders.
2021-05-13 15:04:11.243: Finished import to temporary table for EcomOrders.
2021-05-13 15:04:11.243: Starting import to temporary table for EcomOrderLines.
2021-05-13 15:04:11.385: Added 1 rows to temporary table for EcomOrderLines.
2021-05-13 15:04:11.385: Finished import to temporary table for EcomOrderLines.
2021-05-13 15:04:11.697: Job succeeded.

So I am wondering if Order Saved event is not demaging the DI job import results.

It is interesting why the Order saved event is called from the Scheduled task page?
Maybe your custom add-in is re-saving the order with its original order line and thus the order gets twice order lines then (the cached old one and the one imported from the DI job)?
Kind regards, Dmitrij

 

 
Shawn Tehini Dynamicweb Employee
Shawn Tehini
Posted on 13/05/2021 22:04:57
Reply

Sure thing!  That export is attached.

I see what you are seeing now that it is not the duplicate data integration job but rather the Order save event.  Mario is looking into that scheduled task add-in and I will bring this to his attention further.

Thanks, 
Shawn

 

 
Mario Santos Dynamicweb Employee
Mario Santos
Posted on 13/05/2021 23:59:48
Reply

Hi Dmitrij,

We found the order save method, it isn't on the scheduled task add-in itself. In this add-in we have some actions that run after the import, in this case was to generate a order state change, which uses the order save method. We now clear the cache before get the order and call the save method. It seems to have fixed the issue but Shawn will do further testing.

Thank you for your help.

BR, Mario

 

You must be logged in to post in the forum