0045401: Performance issues on the Costing background process

Openbravo Issue Tracking System - Openbravo ERP
View Issue Details

ID	Project	Category	View Status	Date Submitted	Last Update
0045401	Openbravo ERP	04. Warehouse management	public	2020-11-09 15:56	2020-11-23 17:24

Reporter	egoitz
Assigned To	AtulOpenbravo
Priority	normal	Severity	major	Reproducibility	have not tried
Status	closed	Resolution	fixed
Platform		OS	5	OS Version
Product Version
Target Version		Fixed in Version	PR21Q1
Merge Request Status	approved
Review Assigned To
OBNetwork customer	Gold
Web browser
Modules	Core
Support ticket
Regression level
Regression date
Regression introduced in release
Regression introduced by commit
Triggers an Emergency Pack	No

Summary	0045401: Performance issues on the Costing background process
Description	On environments with big amount of data, and thousands of transactions done every month (using also AWO) the costing background process is slow
Steps To Reproduce	Execute the process on an environment with big amount of data and thousands of transactions pending to be calculated. Enabling the PostgreSQL log we see that the following query is taking more then 1 second in lots of executions. sum(materialmg0_.MovementQty) as col_0_0 from M_Transaction materialmg0 cross join AD_Ref_List adlist1_ where materialmg0_.M_Product_ID=$1 and materialmg0_.TrxProcessDate<=$2 and adlist1_.Value=materialmg0_.MovementType and adlist1_.AD_Reference_ID=$3 and (materialmg0_.TrxProcessDate>$4 or materialmg0_.TrxProcessDate=$5 and (adlist1_.Seqno>$6 or adlist1_.Seqno=$7 and (materialmg0_.MovementQty<$8 or materialmg0_.MovementQty=$9 and materialmg0_.M_Transaction_ID>$10))) and materialmg0_.IsCostCalculated='Y' and (materialmg0_.AD_Org_ID in ($11 , $12 , $13 , $14 , $15, ...., $251 , $252)) Enabling in debug the log of the Background process we see that ech transaction tooks between 200 and 400 ms.
Proposed Solution	After create a index on the M_transactions table that includes the columns (m_product_id, trxprocessdate) the performance has improved a lot. The query is now taking less than 400ms and each transaction on the Openbravo log in the background tooks between 20-40 ms
Additional Information
Tags	No tags attached.
Relationships
Attached Files

Issue History
Date Modified	Username	Field	Change
2020-11-09 15:56	egoitz	New Issue
2020-11-09 15:56	egoitz	Assigned To	=> Triage Finance
2020-11-09 15:56	egoitz	OBNetwork customer	=> Gold
2020-11-09 15:56	egoitz	Modules	=> Core
2020-11-09 15:56	egoitz	Resolution time	=> 1606777200
2020-11-09 15:56	egoitz	Triggers an Emergency Pack	=> No
2020-11-13 12:17	dmiguelez	Assigned To	Triage Finance => AtulOpenbravo
2020-11-15 15:16	AtulOpenbravo	Status	new => scheduled
2020-11-22 17:50	AtulOpenbravo	Note Added: 0124550
2020-11-22 17:56	hgbot	Merge Request Status	=> open
2020-11-22 17:56	hgbot	Note Added: 0124551
2020-11-23 17:24	hgbot	Merge Request Status	open => approved
2020-11-23 17:24	hgbot	Resolution	open => fixed
2020-11-23 17:24	hgbot	Status	scheduled => closed
2020-11-23 17:24	hgbot	Note Added: 0124572
2020-11-23 17:24	hgbot	Fixed in Version	=> PR21Q1
2020-11-23 17:24	hgbot	Note Added: 0124573

Notes

Test Plan

Query under test:

EXPLAIN ANALYZE SELECT sum(materialmg0_.MovementQty) AS col_0_0_
FROM M_Transaction materialmg0_
WHERE materialmg0_.M_Product_ID='C0E3824CC5184B7F9746D195ACAC2CCF'
  AND materialmg0_.TrxProcessDate<='2020-11-19 00:00:00'
  AND materialmg0_.IsCostCalculated='Y'
  AND (materialmg0_.AD_Org_ID in ('B843C30461EA4501935CB1D125C9C25A', 'DC206C91AA6A4897B44DA897936E0EC3',
  'E443A31992CB4635AFCAEABE7183CE85'));

Query Plan without index change:-

Aggregate (cost=545.48..545.49 rows=1 width=32) (actual time=0.527..0.528 rows=1 loops=1)
  -> Bitmap Heap Scan on m_transaction materialmg0_ (cost=14.88..545.23 rows=100 width=5) (actual time=0.105..0.491 rows=185 loops=1)
        Recheck Cond: ((m_product_id)::text = 'C0E3824CC5184B7F9746D195ACAC2CCF'::text)
        Filter: ((trxprocessdate <= '2020-11-19 00:00:00'::timestamp without time zone) AND (iscostcalculated = 'Y'::bpchar) AND ((ad_org_id)::text = ANY ('{B843C30461EA4501935CB1D125C9C25A,DC206C91AA6A4897B44DA897936E0EC3,E443A31992CB4635AFCAEABE7183CE85} (...)
        Rows Removed by Filter: 157
        Heap Blocks: exact=222
        -> Bitmap Index Scan on m_transaction_product (cost=0.00..14.85 rows=342 width=0) (actual time=0.076..0.076 rows=342 loops=1)
              Index Cond: ((m_product_id)::text = 'C0E3824CC5184B7F9746D195ACAC2CCF'::text)
Planning time: 0.357 ms
Execution time: 0.560 ms

Proposed Index:

CREATE INDEX m_transaction_product_trxprdt
  ON public.m_transaction
  USING btree
  (m_product_id COLLATE pg_catalog."default", TrxProcessDate);

Query Plan with index changed:-

Aggregate (cost=546.34..546.35 rows=1 width=32) (actual time=0.478..0.479 rows=1 loops=1)
  -> Bitmap Heap Scan on m_transaction materialmg0_ (cost=15.73..546.09 rows=101 width=5) (actual time=0.102..0.446 rows=187 loops=1)
        Recheck Cond: (((m_product_id)::text = 'C0E3824CC5184B7F9746D195ACAC2CCF'::text) AND (trxprocessdate <= '2020-11-19 00:00:00'::timestamp without time zone))
        Filter: ((iscostcalculated = 'Y'::bpchar) AND ((ad_org_id)::text = ANY ('{B843C30461EA4501935CB1D125C9C25A,DC206C91AA6A4897B44DA897936E0EC3,E443A31992CB4635AFCAEABE7183CE85}'::text[])))
        Rows Removed by Filter: 155
        Heap Blocks: exact=224
        -> Bitmap Index Scan on m_transaction_product_trxprdt (cost=0.00..15.71 rows=342 width=0) (actual time=0.074..0.074 rows=342 loops=1)
              Index Cond: (((m_product_id)::text = 'C0E3824CC5184B7F9746D195ACAC2CCF'::text) AND (trxprocessdate <= '2020-11-19 00:00:00'::timestamp without time zone))
Planning time: 0.267 ms
Execution time: 0.509 ms

Improvement is seen in the Actual time in the F&B International Group client data.