We can't detect the date time when Order is chagend to status as 'complete'

[cristianmalfesi]

When process an Order on Magento 2 we have different status like Pending, Invoiced, Shipment, Complete, etc. Working in production mode we found that is too difficult detect the datetime when an Order change to 'complete' status.
There is a table called 'sales_order_status_history' that save the history of every step on one order. But we tested change in different way the order, and allways show the field status = 'processing', inclusively when order is changed to status = 'complete'. In this way can not detect the real dateime when order go changing to different status.

Preconditions

On production mode on Magento 2 using Luma theme, simulate a purchase on frontend with normal user, this create an Order in pending mode (the payment method is not important, we have tested with different methods).

Environment: Tested using Magento 2.1.3 and 2.1.6 (PHP 7, Mysql 5.6, Nginx)

Steps to reproduce

1. Go to frontend, make a purchase, using any payment method, and finish the purchase process on checkout.
2. Got to admin panel, search the order generated, make a shipment and update order status.
3. Again open the order and generate Invoice and update order status.
   4.Finally check that order show the order status = 'complete'

Expected result

1. If we make a SQL on database checking datetime of every change of status of one order, the result show allways in processing mode. You can try look the process on one order with this SQL command:
   SELECT h.status, h.created_at, h.entity_name
   FROM sales_order AS o
   INNER JOIN sales_order_status_history AS h ON h.parent_id = o.entity_id
   WHERE o.increment_id = '3000004389';

We spected a result like:
status | created_at | entity_name
processing 2017-05-08 19:05:08 order
Complete 2017-05-19 19:48:38 invoice

Actual result

1. The SQL proposed show nothing, because table sales_order_status_history allways have status in processing value.
   Current result:
   status | created_at | entity_name
   processing 2017-05-08 19:05:08 order
   processing 2017-05-19 19:48:38 invoice

[PushEngineering]

I can recreate the same issue (Magento 2.1.3, PHP7, AWS RDS Aurora (5.6)).

For our Magento 1.8 deployments this table works correctly and is the basis for much of our audit reporting.

[cristianmalfesi]

Yeah, I have tested also on AWS RDS and using docker locally with different templates and making clean installations.

[cristianmalfesi]

Can anyone tell me where I can modify the code that save records on table sales_order_status_history???

[mynameismud]

So I did a whole bunch of searching through the source code...essentially looking for uses of "Order::STATE_COMPLETE". I can only find one occurrence of code setting this state.

Here:
Magento/Sales/Model/ResourceModel/Order/Handler/State.php, line 29.

This "check(Order $order)" method only appears to be used in one place in the code:
Magento/Sales/Model/ResourceModel/Order.php, line 173

So it appears that any time an Order object is saved, the status is potentially changed depending on several checks of other property values/states.

Here is the call stack as near as I can tell:

Magento/Sales/Model/ShipOrder.php, line 173
...$this->orderRepository->save($order);
Magento/Sales/Model/OrderRepository.php, line 157
...$this->metadata->getMapper()->save($entity);
Magento/Sales/Model/ResourceModel/Order.php, line 173
...$this->stateHandler->check($object);

But none of this adds a record to the history

The method that is called everywhere to do this is:
Magento/Sales/Model/Order.php, line 997
...public function addStatusHistoryComment($comment, $status = false)

It seems that any logic that wants to add a status history entry will need to do so explicitly by calling this method.

[cristianmalfesi]

Hi mynameismud :)
You are right about the code. But we have to think that history change also when Invoice and Shipping are updated. So, I think we must check the code on these two modules also. I will check this and back with the info.

[cristianmalfesi]

After check carefully the steps for one order in different order of execution I can confirm that we can use the field updated_at of table Sales_Order for know the datetime when Order is updated to Status = Complete
This field updated_at is only updated when status is changed on every steps executed over the Order.

[mynameismud]

That's good news, but I still think we should add code that inserts the history records properly when the order is shipped. Ideally every change of .status and .updated_at would trigger a history entry. But it appears that most extensions wrote their own logic for inserting history. There are many references, for example, in the Paypal and Auth.net extensions (cancels, refunds, etc). So it looks like we'll need to add our own history insertion calls.

[AlexWorking]

Hello, @chm1975 . Based on Your issue an internal ticket was created - MAGETWO-69941. You'll be informed when the issue is fixed. Thank's for applying.