details: https://code.openbravo.com/erp/devel/pi/rev/715af3267f4b changeset: 28829:715af3267f4b user: Mark <m.molina <at> nectus.com> date: Tue Mar 15 11:29:37 2016 -0400 summary: Fixes issue 32458: Added log information in process executed when Validating Costing Rule.
Several log information was added to be able to follow information when the "Validate Costing Rule" process is executed. details: https://code.openbravo.com/erp/devel/pi/rev/0435c3f22231 changeset: 28830:0435c3f22231 user: Alvaro Ferraz <alvaro.ferraz <at> openbravo.com> date: Mon Mar 21 10:09:07 2016 +0100 summary: Related to issue 32458: Code review improvements Add log only in Costing Rule process three main steps. diffstat: src/org/openbravo/costing/CostingRuleProcess.java | 77 ++++++++++++++++++++-- 1 files changed, 67 insertions(+), 10 deletions(-) diffs (197 lines): diff -r 775ccd9fca46 -r 0435c3f22231 src/org/openbravo/costing/CostingRuleProcess.java --- a/src/org/openbravo/costing/CostingRuleProcess.java Mon Mar 21 09:22:39 2016 +0100 +++ b/src/org/openbravo/costing/CostingRuleProcess.java Mon Mar 21 10:09:07 2016 +0100 @@ -72,6 +72,8 @@ @Override public void execute(ProcessBundle bundle) throws Exception { + long start = System.currentTimeMillis(); + log4j.debug("Starting CostingRuleProcess at: " + new Date()); logger = bundle.getLogger(); OBError msg = new OBError(); msg.setType("Success"); @@ -117,7 +119,7 @@ // Set valid from date startingDate = DateUtils.truncate(new Date(), Calendar.SECOND); rule.setStartingDate(startingDate); - log4j.debug("setting starting date " + startingDate); + log4j.debug("Setting starting date " + startingDate); prevCostingRule.setEndingDate(startingDate); OBDal.getInstance().save(prevCostingRule); OBDal.getInstance().flush(); @@ -165,6 +167,9 @@ OBContext.restorePreviousMode(); } bundle.setResult(msg); + long end = System.currentTimeMillis(); + log4j.debug("Ending CostingRuleProcess at: " + new Date() + ". Duration: " + (end - start) + + " ms."); } private void migrationCheck() { @@ -255,6 +260,7 @@ Client client = OBDal.getInstance().get(Client.class, OBContext.getOBContext().getCurrentClient().getId()); + long t1 = System.currentTimeMillis(); StringBuffer insert = new StringBuffer(); insert.append(" insert into " + TransactionCost.ENTITY_NAME); insert.append(" (" + TransactionCost.PROPERTY_ID); @@ -298,8 +304,11 @@ queryInsert.setParameterList("orgs", childOrgs); queryInsert.setDate("date", date); queryInsert.setString("client", client.getId()); - queryInsert.executeUpdate(); + int n1 = queryInsert.executeUpdate(); + log4j.debug("InitializeOldTrx inserted " + n1 + " records. Took: " + + (System.currentTimeMillis() - t1) + " ms."); + long t2 = System.currentTimeMillis(); StringBuffer update = new StringBuffer(); update.append(" update " + MaterialTransaction.ENTITY_NAME); update.append(" set " + MaterialTransaction.PROPERTY_ISCOSTCALCULATED + " = true"); @@ -318,7 +327,9 @@ queryUpdate.setParameterList("orgs", childOrgs); queryUpdate.setDate("date", date); queryUpdate.setString("client", client.getId()); - queryUpdate.executeUpdate(); + int n2 = queryUpdate.executeUpdate(); + log4j.debug("InitializeOldTrx updated " + n2 + " records. Took: " + + (System.currentTimeMillis() - t2) + " ms."); OBDal.getInstance().getSession().flush(); OBDal.getInstance().getSession().clear(); @@ -330,16 +341,21 @@ } protected void createCostingRuleInits(String ruleId, Set<String> childOrgs, Date date) { + long t1 = System.currentTimeMillis(); CostingRule rule = OBDal.getInstance().get(CostingRule.class, ruleId); ScrollableResults stockLines = getStockLines(childOrgs, date); + log4j.debug("GetStockLines took: " + (System.currentTimeMillis() - t1) + " ms."); + // The key of the Map is the concatenation of orgId and warehouseId + long t2 = System.currentTimeMillis(); Map<String, String> initLines = new HashMap<String, String>(); Map<String, Long> maxLineNumbers = new HashMap<String, Long>(); InventoryCountLine closingInventoryLine = null; InventoryCountLine openInventoryLine = null; - int i = 1; + int i = 0; try { while (stockLines.next()) { + long t3 = System.currentTimeMillis(); Object[] stockLine = stockLines.get(); String productId = (String) stockLine[0]; String attrSetInsId = (String) stockLine[1]; @@ -382,25 +398,41 @@ insertInventoryLine(cri.getCloseInventory(), productId, attrSetInsId, uomId, orderUOMId, locatorId, qty == null ? null : qty.abs(), BigDecimal.ZERO, orderQty == null ? null : orderQty.abs(), BigDecimal.ZERO, lineNo, openInventoryLine); - } + i++; if ((i % 100) == 0) { OBDal.getInstance().flush(); OBDal.getInstance().getSession().clear(); // Reload rule after clear session. rule = OBDal.getInstance().get(CostingRule.class, ruleId); } - i++; + + log4j.debug("Create closing/opening inventory line took: " + + (System.currentTimeMillis() - t3) + " ms."); } } finally { stockLines.close(); } + log4j.debug("Create " + i + " closing/opening inventory lines took: " + + (System.currentTimeMillis() - t2) + " ms."); + // Process closing physical inventories. + long t4 = System.currentTimeMillis(); rule = OBDal.getInstance().get(CostingRule.class, ruleId); + i = 0; for (CostingRuleInit cri : rule.getCostingRuleInitList()) { + long t5 = System.currentTimeMillis(); new InventoryCountProcess().processInventory(cri.getCloseInventory(), false); + log4j.debug("Processing closing inventory took: " + (System.currentTimeMillis() - t5) + + " ms."); + i++; } + log4j.debug("Processing " + i + " closing inventories took: " + + (System.currentTimeMillis() - t4) + " ms."); + + log4j + .debug("CreateCostingRuleInits method took: " + (System.currentTimeMillis() - t1) + " ms."); } private ScrollableResults getStockLines(Set<String> childOrgs, Date date) { @@ -526,12 +558,19 @@ private void updateInventoriesCostAndProcessInitInventories(String ruleId, Date startingDate, boolean existsPreviousRule) { + long t1 = System.currentTimeMillis(); CostingRule rule = OBDal.getInstance().get(CostingRule.class, ruleId); + int i = 0; for (CostingRuleInit cri : rule.getCostingRuleInitList()) { + long t2 = System.currentTimeMillis(); ScrollableResults trxs = getInventoryLineTransactions(cri.getCloseInventory()); - int i = 1; + log4j.debug("GetInventoryLineTransactions took: " + (System.currentTimeMillis() - t2) + + " ms."); + long t3 = System.currentTimeMillis(); + int j = 0; try { while (trxs.next()) { + long t4 = System.currentTimeMillis(); MaterialTransaction trx = (MaterialTransaction) trxs.get(0); // Remove 1 second from transaction date to ensure that cost is calculated with previous // costing rule. @@ -576,24 +615,42 @@ initICL.setCost(cost); OBDal.getInstance().save(initICL); - if ((i % 100) == 0) { + j++; + if ((j % 100) == 0) { OBDal.getInstance().flush(); OBDal.getInstance().getSession().clear(); cri = OBDal.getInstance().get(CostingRuleInit.class, cri.getId()); } - i++; + + log4j.debug("Update inventory line cost took: " + (System.currentTimeMillis() - t4) + + " ms."); } } finally { trxs.close(); } + OBDal.getInstance().flush(); + log4j.debug("Update " + j + "inventory line costs took: " + (System.currentTimeMillis() - t3) + + " ms."); - OBDal.getInstance().flush(); + long t5 = System.currentTimeMillis(); cri = OBDal.getInstance().get(CostingRuleInit.class, cri.getId()); new InventoryCountProcess().processInventory(cri.getInitInventory(), false); + log4j.debug("Processing opening inventory took: " + (System.currentTimeMillis() - t5) + + " ms."); + i++; } + log4j.debug("Processing " + i + " opening inventories took: " + + (System.currentTimeMillis() - t1) + " ms."); + if (!existsPreviousRule) { + long t6 = System.currentTimeMillis(); updateInitInventoriesTrxDate(startingDate, ruleId); + log4j.debug("UpdateInitInventoriesTrxDate took: " + (System.currentTimeMillis() - t6) + + " ms."); } + + log4j.debug("UpdateInventoriesCostAndProcessInitInventories method took: " + + (System.currentTimeMillis() - t1) + " ms."); } protected MaterialTransaction getInventoryLineTransaction(InventoryCountLine icl) { ------------------------------------------------------------------------------ Transform Data into Opportunity. Accelerate data analysis in your applications with Intel Data Analytics Acceleration Library. Click to learn more. http://pubads.g.doubleclick.net/gampad/clk?id=278785351&iu=/4140 _______________________________________________ Openbravo-commits mailing list Openbravo-commits@lists.sourceforge.net https://lists.sourceforge.net/lists/listinfo/openbravo-commits
