Anonymous | Login
Project:
RSS
  
News | My View | View Issues | Roadmap | Summary

View Issue Details[ Jump to Notes ] [ Issue History ] [ Print ]
ID
0043367
TypeCategorySeverityReproducibilityDate SubmittedLast Update
defect[Retail Modules] Web POSmajoralways2020-02-28 11:192020-03-16 12:52
ReportergorkaionView Statuspublic 
Assigned Torqueralta 
PriorityhighResolutionfixedFixed in VersionRR20Q2
StatusclosedFix in branchFixed in SCM revision4a75b4ca37b8
ProjectionnoneETAnoneTarget Version
OSAnyDatabaseAnyJava version
OS VersionDatabase versionAnt version
Product VersionSCM revision 
Review Assigned Tojorge-garcia
Regression level
Regression date
Regression introduced in release
Regression introduced by commit
Triggers an Emergency PackNo
Summary

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

DescriptionOn 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 ReproduceDefine 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 SolutionThe 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.
TagsNo tags attached.
Attached Files

- Relationships [ Relation Graph ] [ Dependency Graph ]
related to defect 0043369 closedprakashmurugesan88 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 (reporter)
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 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

Copyright © 2000 - 2009 MantisBT Group
Powered by Mantis Bugtracker