0044316: [20Q2] Performance degradation in inventory update during ticket processing

Anonymous | Login

Project:

News | My View | View Issues | Roadmap | Summary

View Revisions: Issue #44316		[ All Revisions ] [ Back to Issue ]
Summary	0044316: [20Q2] Performance degradation in inventory update during ticket processing

Revision	2020-06-09 16:33 by inaki_garcia
Description	We have observed a performance degradation from 20Q1 into 20Q2 in the ticket processing times when executing the ticket creation JMeter test on top of the MultiOrg Sampledata. The tests simulates the creation of 100 tickets, per each of the 100 threads or terminals working concurrently. Each of the threads do as follows: - A ticket in the POS is created, with one line, and it is completed - Then, it is synchronized with the BackEnd and the test waits for 14 seconds before creating another ticket - Each thread uses a different terminal, user, organization and warehouse - Each thread updates a different stock By analyzing the pg statistics, we can have observed that the query with the biggest performance hit is the m_update_inventory pl: 20Q1: funcname calls total_time self_time m_update_inventory 9999 60597,629 59776,81 uuid_generate_v4 877743 8715 8715 m_get_stock_param 1300 7876,088 7717,419 20Q2: funcname calls total_time self_time m_update_inventory 9996 3428939,577 3428035,721 m_get_stock_param 9996 38791,438 37794,888 uuid_generate_v4 749340 6477,539 6477,539 With more research, we have found that this pl is explicitly called in the OrderLoader when creating a shipment (ShipmentUtils.createNewShipment()) Also, the warehouse actions like create transactions are executed with the triggers disabled in the orderLoader, so this function is not being called by the triggers We have measured the processing times by reading the Import Order entries, both by leaving and removing the call to this trigger to confirm the scope of the performance regression: 20Q1: 136ms 20Q1 (without calling m_update_inventory): 135ms 20Q2: 440ms 20Q2 (without calling m_update_inventory): 146ms However, we are still to find the cause behind this, since: - There are no extra triggers against the storage detail table in that environment - Each thread acts against different stock records, there should be no concurrency problems - We have used the same exact data (sampledata of 20Q1) in both tests, so the problem is not related to the data either

Revision	2020-06-09 16:32 by inaki_garcia
Description	We have observed a performance degradation from 20Q1 into 20Q2 in the ticket processing times when executing the ticket creation JMeter test. The tests simulates the creation of 100 tickets, per each of the 100 threads or terminals working concurrently. Each of the threads do as follows: - A ticket in the POS is created, with one line, and it is completed - Then, it is synchronized with the BackEnd and the test waits for 14 seconds before creating another ticket - Each thread uses a different terminal, user, organization and warehouse - Each thread updates a different stock By analyzing the pg statistics, we can have observed that the query with the biggest performance hit is the m_update_inventory pl: 20Q1: funcname calls total_time self_time m_update_inventory 9999 60597,629 59776,81 uuid_generate_v4 877743 8715 8715 m_get_stock_param 1300 7876,088 7717,419 20Q2: funcname calls total_time self_time m_update_inventory 9996 3428939,577 3428035,721 m_get_stock_param 9996 38791,438 37794,888 uuid_generate_v4 749340 6477,539 6477,539 With more research, we have found that this pl is explicitly called in the OrderLoader when creating a shipment (ShipmentUtils.createNewShipment()) Also, the warehouse actions like create transactions are executed with the triggers disabled in the orderLoader, so this function is not being called by the triggers We have measured the processing times by reading the Import Order entries, both by leaving and removing the call to this trigger to confirm the scope of the performance regression: 20Q1: 136ms 20Q1 (without calling m_update_inventory): 135ms 20Q2: 440ms 20Q2 (without calling m_update_inventory): 146ms However, we are still to find the cause behind this, since: - There are no extra triggers against the storage detail table in that environment - Each thread acts against different stock records, there should be no concurrency problems - We have used the same exact data (sampledata of 20Q1) in both tests, so the problem is not related to the data either

Revision	2020-06-09 11:43 by inaki_garcia
Description	Hi all, During last week, I've been investigating this topic with Iñaki. We have more information about it but, sadly, we do not understand yet what is the problem. That is why I am writing this mail, both to share with you what we have found and to ask for any suggestions or help about what can we look into, or any ideas about what is the problem. I am also adding Stefan to this mail, maybe he can give us any new ideas or suggestions. First, this topic was raised because QA has found a performance degradation from 20Q1 into 20Q2 in a test that they run. This performance degradation is reproducible, but we do not know where it comes from. The test that is executed does the following: A ticket in the POS is created, with one line, and it is completed Then, it is synchronized with the BackEnd and the test waits for 14 seconds before creating another ticket This test is executed in 100 different threads, each one of them creates 100 tickets Each thread uses a different terminar, user, organization and warehouse Each thread updates a different stock From the pg statistics, we can see that the biggest performance impact is in the m_update_inventory pl: 20Q1: funcname calls total_time self_time m_update_inventory 9999 60597,629 59776,81 uuid_generate_v4 877743 8715 8715 m_get_stock_param 1300 7876,088 7717,419 20Q2: funcname calls total_time self_time m_update_inventory 9996 3428939,577 3428035,721 m_get_stock_param 9996 38791,438 37794,888 uuid_generate_v4 749340 6477,539 6477,539 With more research, we have found that this pl is explicitly called in the OrderLoader when creating a shipment (ShipmentUtils.createNewShipment()) Also, the warehouse actions like create transactions are executed with the triggers disabled in the orderLoader, so this function is not being called by the triggers As a test, if we skip this call, we have measured this times: 20Q1: 136ms 20Q1 (without calling m_update_inventory): 135ms 20Q2: 440ms 20Q2 (without calling m_update_inventory): 146ms So it seems that the problem is at this point. However, we do not know why: There are no extra triggers against the storage detail table in that environment Since each thread acts against different stock records, there should be no concurrency problems We have used the same exact data (sampledata of 20Q1) in both tests, so the problem is not related to the data either Again, we do not know how to continue with this topic, so any help would be appreciated. Thanks in advance. Regards.