0043367: Performance issues when using attributes and having many instances with the same description

Description

On a environment using instance attributes (for example with expiration date)

In case you have many attribute set instances with the same description the OrderLoader is very slow.

Steps To Reproduce

Define some products using instance attributes. Generate attribute set instances with the same description. For example using an attribute set with expiration date and assigning the same date in several receipts.

As it is an instance attribute it generates many records in the m_attributesetinstance with the same description.

Create a Sales Order using one of the products using that instance and check the timings of the OrderLoader.

2020-02-27 08:14:07,459 [Import Entry - 5] DEBUG org.openbravo.retail.posterminal.OrderLoader - Order with docno: XXXXX saved correctly. Initial flush: 2; Generate bobs:2617; Save bobs:0; First flush:0; Process Payments:17969 Final flush: 1473
2020-02-27 08:14:07,459 [Import Entry - 5] DEBUG org.openbravo.retail.posterminal.OrderLoader - Order total time: 24944
2020-02-27 08:14:09,057 [Import Entry - 5] DEBUG org.openbravo.mobile.core.process.DataSynchronizationProcess - Total process org.openbravo.retail.posterminal.OrderLoader time: 26564

Enabling debug mode on OBDal most of the time is in flushed (23s out of 26s)

2020-02-27 08:13:42,507 [Import Entry - 5] DEBUG org.openbravo.dal.service.OBDal - Flush of 11 entities and 86 collections took: 6
2020-02-27 08:13:42,516 [Import Entry - 5] DEBUG org.openbravo.dal.service.OBDal - Flush of 18 entities and 241 collections took: 1
2020-02-27 08:13:46,238 [Import Entry - 5] DEBUG org.openbravo.dal.service.OBDal - Flush of 31988 entities and 832092 collections took: 1093
2020-02-27 08:13:48,017 [Import Entry - 5] DEBUG org.openbravo.dal.service.OBDal - Flush of 31988 entities and 832092 collections took: 1777
2020-02-27 08:13:49,002 [Import Entry - 5] DEBUG org.openbravo.dal.service.OBDal - Flush of 31990 entities and 832105 collections took: 980
2020-02-27 08:13:50,131 [Import Entry - 5] DEBUG org.openbravo.dal.service.OBDal - Flush of 31991 entities and 832113 collections took: 1122
2020-02-27 08:13:51,791 [Import Entry - 5] DEBUG org.openbravo.dal.service.OBDal - Flush of 31991 entities and 832113 collections took: 1659
2020-02-27 08:13:53,318 [Import Entry - 5] DEBUG org.openbravo.dal.service.OBDal - Flush of 31991 entities and 832113 collections took: 1524
2020-02-27 08:13:54,236 [Import Entry - 5] DEBUG org.openbravo.dal.service.OBDal - Flush of 31992 entities and 832136 collections took: 909
2020-02-27 08:13:55,135 [Import Entry - 5] DEBUG org.openbravo.dal.service.OBDal - Flush of 31993 entities and 832139 collections took: 895
2020-02-27 08:13:56,787 [Import Entry - 5] DEBUG org.openbravo.dal.service.OBDal - Flush of 32001 entities and 832163 collections took: 1638
2020-02-27 08:13:57,799 [Import Entry - 5] DEBUG org.openbravo.dal.service.OBDal - Flush of 32002 entities and 832173 collections took: 997
2020-02-27 08:13:59,354 [Import Entry - 5] DEBUG org.openbravo.dal.service.OBDal - Flush of 32002 entities and 832186 collections took: 1549
2020-02-27 08:14:01,056 [Import Entry - 5] DEBUG org.openbravo.dal.service.OBDal - Flush of 32004 entities and 832202 collections took: 1690
2020-02-27 08:14:02,667 [Import Entry - 5] DEBUG org.openbravo.dal.service.OBDal - Flush of 32007 entities and 832299 collections took: 1600
2020-02-27 08:14:03,543 [Import Entry - 5] DEBUG org.openbravo.dal.service.OBDal - Flush of 32008 entities and 832299 collections took: 872
2020-02-27 08:14:05,011 [Import Entry - 5] DEBUG org.openbravo.dal.service.OBDal - Flush of 32008 entities and 832299 collections took: 1466
2020-02-27 08:14:05,983 [Import Entry - 5] DEBUG org.openbravo.dal.service.OBDal - Flush of 32015 entities and 832317 collections took: 958
2020-02-27 08:14:07,459 [Import Entry - 5] DEBUG org.openbravo.dal.service.OBDal - Flush of 32015 entities and 832317 collections took: 1471
2020-02-27 08:14:09,025 [Import Entry - 5] DEBUG org.openbravo.dal.service.OBDal - Flush of 32015 entities and 832317 collections took: 1565

Proposed Solution

The flush times degrades when it loads 30k entities and 830k in memory and they are never cleared.

Fix should review:
- Why it is required to load so many objects in Hibernate cache
- Execute a clearSession after the flush to free the cache.

Reviewing the log we have find out that the issue is in org.openbravo.retail.posterminal.utility.AttributesUtils class.

This class is searching attributesetinstances by description. Loading all found instances in memory by using .list(). In reality we just need to know if there are 0, 1 or more than 1. And we will only use the 1st result.
Consider:
- setting a limit to get just 2 attribute set instances.
- changing the select clause to return just the IDs instead of full objects.

Later something similar is done searching for stock if there are more than 1 attribute set instance.In this case we only use the 1st one.
Consider:
- setting a limit to retrieve just 1 value.
- changing the select clause to get the attributesetinstance id instead of the full storagedetail object.

Check if it is possible to return a proxy object instead of the full baseobobject.

In customer instance just setting the proposed limits the time executing the orderloader has decreased to less than 1 second.

Tags

No tags attached.

Attached Files

Relationships [ Relation Graph ] [ Dependency Graph ]

related to

defect

0043369

closed

prakashmurugesan88

When using instance attributes shipment might use an instance from a different product

Notes
(0118549) hgbot (developer) 2020-03-12 15:24	Repository: erp/pmods/org.openbravo.retail.posterminal Changeset: 4a75b4ca37b8f87b1131e5755e053a60b95731de Author: Rafael Queralta <rafaelcuba81 <at> gmail.com> Date: Thu Mar 12 10:21:15 2020 -0400 URL: http://code.openbravo.com/erp/pmods/org.openbravo.retail.posterminal/rev/4a75b4ca37b8f87b1131e5755e053a60b95731de [^] Fixed BUG-43367: Performance issues when using attributes and having many instances with the same description - Limit to get just 2 attribute set instances was introduced --- M src/org/openbravo/retail/posterminal/utility/AttributesUtils.java ---

(0118619) jorge-garcia (viewer) 2020-03-16 12:52	Code reviewed

Issue History
Date Modified	Username	Field	Change
2020-02-28 11:19	gorkaion	New Issue
2020-02-28 11:19	gorkaion	Assigned To	=> Retail
2020-02-28 11:19	gorkaion	OBNetwork customer	=> Gold
2020-02-28 11:19	gorkaion	Support ticket	=> 14694
2020-02-28 11:19	gorkaion	Resolution time	=> 1584658800
2020-02-28 11:19	gorkaion	Triggers an Emergency Pack	=> No
2020-02-28 11:32	gorkaion	Relationship added	related to 0043369
2020-03-10 23:01	rqueralta	Assigned To	Retail => rqueralta
2020-03-10 23:01	rqueralta	Status	new => scheduled
2020-03-12 15:24	hgbot	Checkin
2020-03-12 15:24	hgbot	Note Added: 0118549
2020-03-12 15:24	hgbot	Status	scheduled => resolved
2020-03-12 15:24	hgbot	Resolution	open => fixed
2020-03-12 15:24	hgbot	Fixed in SCM revision	=> http://code.openbravo.com/erp/pmods/org.openbravo.retail.posterminal/rev/4a75b4ca37b8f87b1131e5755e053a60b95731de [^]
2020-03-16 11:09	jorge-garcia	Review Assigned To	=> jorge-garcia
2020-03-16 12:52	jorge-garcia	Note Added: 0118619
2020-03-16 12:52	jorge-garcia	Status	resolved => closed
2020-03-16 12:52	jorge-garcia	Fixed in Version	=> RR20Q2