Related to issue 35384: Code review improvements
authorAlvaro Ferraz <alvaro.ferraz@openbravo.com>
Fri, 23 Jun 2017 11:25:32 +0200
changeset 32386 b3da3000ba8d
parent 32385 ea7a25da9285
child 32387 f9c0d1127795
Related to issue 35384: Code review improvements
src/org/openbravo/costing/CostAdjustmentProcess.java
src/org/openbravo/costing/CostingBackground.java
src/org/openbravo/costing/CostingMigrationProcess.java
--- a/src/org/openbravo/costing/CostAdjustmentProcess.java	Wed Jun 21 16:23:42 2017 -0400
+++ b/src/org/openbravo/costing/CostAdjustmentProcess.java	Fri Jun 23 11:25:32 2017 +0200
@@ -339,8 +339,8 @@
 
   public static JSONObject doProcessCostAdjustment(CostAdjustment costAdjustment)
       throws OBException {
-    String docNo = costAdjustment.getDocumentNo();
-    log.debug("Starting doProcessCostAdjustment() for cost adjustment: {}", docNo);
+    log.debug("Starting doProcessCostAdjustment() for cost adjustment: {}",
+        costAdjustment.getDocumentNo());
     long t1 = System.currentTimeMillis();
     CostAdjustmentProcess cap = WeldUtils
         .getInstanceFromStaticBeanManager(CostAdjustmentProcess.class);
--- a/src/org/openbravo/costing/CostingBackground.java	Wed Jun 21 16:23:42 2017 -0400
+++ b/src/org/openbravo/costing/CostingBackground.java	Fri Jun 23 11:25:32 2017 +0200
@@ -110,23 +110,18 @@
       int batch = 0;
       int counter = 0;
       int counterBatch;
+      int pendingTrxs = 0;
       long elapsedTime = 0;
-      long avgTimePerBatch = 0;
-      int pendingTrxs = 0;
-      int pendingBatches = 0;
       if (log4j.isDebugEnabled()) {
         pendingTrxs = getTransactionsBatchCount(orgsWithRule);
         log4j.debug("Pending transactions: " + pendingTrxs);
-        pendingBatches = (pendingTrxs % BATCH_SIZE == 0) ? (pendingTrxs / BATCH_SIZE)
-            : (pendingTrxs / BATCH_SIZE) + 1;
-        log4j.debug("Pending batches: " + pendingBatches);
       }
+
       trxs = getTransactionsBatch(orgsWithRule);
       while (!trxs.isEmpty()) {
         long t1 = System.currentTimeMillis();
         batch++;
         counterBatch = 0;
-        pendingBatches--;
         for (String trxId : trxs) {
           if (killProcess) {
             throw new OBException("Process killed");
@@ -146,17 +141,20 @@
               + ". Took: " + (t4 - t3) + " ms.");
         }
         trxs = getTransactionsBatch(orgsWithRule);
-        long t2 = System.currentTimeMillis();
-
-        log4j.debug("Processing batch: " + batch + " (" + counterBatch + " transactions) took: "
-            + (t2 - t1) + " ms.");
 
         if (log4j.isDebugEnabled()) {
+          long t2 = System.currentTimeMillis();
+          log4j.debug("Processing batch: " + batch + " (" + counterBatch + " transactions) took: "
+              + (t2 - t1) + " ms.");
           pendingTrxs -= counterBatch;
+          int pendingBatches = (pendingTrxs % BATCH_SIZE == 0) ? (pendingTrxs / BATCH_SIZE)
+              : (pendingTrxs / BATCH_SIZE) + 1;
+          elapsedTime += t2 - t1;
+          long avgTimePerBatch = elapsedTime / batch / 1000;
           log4j.debug("Pending transactions: " + pendingTrxs);
-          elapsedTime += t2 - t1;
-          avgTimePerBatch = elapsedTime / batch;
-          log4j.debug("Estimated time to finish: " + (avgTimePerBatch * pendingBatches) + " ms.");
+          log4j.debug("Average time per batch: " + avgTimePerBatch
+              + " seconds. Estimated time to finish: " + (avgTimePerBatch * pendingBatches)
+              + " seconds.");
         }
       }
 
@@ -259,8 +257,7 @@
     trxQry.setParameter("now", new Date());
     trxQry.setParameterList("orgs", orgsWithRule);
     trxQry.setMaxResults(1);
-    Long trxCount = (Long) trxQry.uniqueResult();
-    return trxCount.intValue();
+    return ((Long) trxQry.uniqueResult()).intValue();
   }
 
   private void initializeMtransCostDateAcct() throws Exception {
--- a/src/org/openbravo/costing/CostingMigrationProcess.java	Wed Jun 21 16:23:42 2017 -0400
+++ b/src/org/openbravo/costing/CostingMigrationProcess.java	Fri Jun 23 11:25:32 2017 +0200
@@ -101,11 +101,10 @@
 
   @Override
   public void execute(ProcessBundle bundle) throws Exception {
+    long start = System.currentTimeMillis();
+    log4j.debug("Starting CostingMigrationProcess at: " + new Date());
+
     logger = bundle.getLogger();
-    long start = System.currentTimeMillis();
-    long startPhase = 0;
-    long endPhase = 0;
-    log4j.debug("Starting CostingMigrationProcess at: " + new Date());
     OBError msg = new OBError();
     conn = bundle.getConnection();
     msg.setType("Success");
@@ -124,19 +123,19 @@
           .registerSQLFunction("now", new StandardSQLFunction("now", new DateType()));
 
       if (!isMigrationFirstPhaseCompleted()) {
-        startPhase = System.currentTimeMillis();
+        long t1 = System.currentTimeMillis();
         log4j.debug("Starting CostingMigrationProcess first phase at: " + new Date());
         doChecks();
         updateLegacyCosts();
         createRules();
         createMigrationFirstPhaseCompletedPreference();
-        endPhase = System.currentTimeMillis();
+        long t2 = System.currentTimeMillis();
         log4j.debug("Ending CostingMigrationProcess first phase at: " + new Date() + ". Duration: "
-            + (endPhase - startPhase) + " ms.");
+            + (t2 - t1) + " ms.");
       }
 
       else {
-        startPhase = System.currentTimeMillis();
+        long t1 = System.currentTimeMillis();
         log4j.debug("Starting CostingMigrationProcess second phase at: " + new Date());
         checkAllInventoriesAreProcessed();
         for (CostingRule rule : getRules()) {
@@ -147,12 +146,13 @@
         updateReportRoles();
         CostingStatus.getInstance().setMigrated();
         deleteMigrationFirstPhaseCompletedPreference();
-        endPhase = System.currentTimeMillis();
+        long t2 = System.currentTimeMillis();
         log4j.debug("Ending CostingMigrationProcess second phase at: " + new Date()
-            + ". Duration: " + (endPhase - startPhase) + " ms.");
+            + ". Duration: " + (t2 - t1) + " ms.");
       }
+    }
 
-    } catch (final OBException e) {
+    catch (final OBException e) {
       OBDal.getInstance().rollbackAndClose();
       String resultMsg = OBMessageUtils.parseTranslation(e.getMessage());
       logger.log(resultMsg);
@@ -161,8 +161,9 @@
       msg.setTitle(OBMessageUtils.messageBD("Error"));
       msg.setMessage(resultMsg);
       bundle.setResult(msg);
+    }
 
-    } catch (final Exception e) {
+    catch (final Exception e) {
       OBDal.getInstance().rollbackAndClose();
       String message = DbUtility.getUnderlyingSQLException(e).getMessage();
       logger.log(message);
@@ -171,19 +172,22 @@
       msg.setTitle(OBMessageUtils.messageBD("Error"));
       msg.setMessage(message);
       bundle.setResult(msg);
+    }
 
-    } finally {
+    finally {
       OBContext.restorePreviousMode();
     }
+    bundle.setResult(msg);
+
     long end = System.currentTimeMillis();
     log4j.debug("Ending CostingMigrationProcess at: " + new Date() + ". Duration: " + (end - start)
         + " ms.");
-    bundle.setResult(msg);
   }
 
   private void doChecks() {
     long start = System.currentTimeMillis();
     log4j.debug("Starting doChecks() at: " + new Date());
+
     // Check all transactions have a legacy cost available.
     AlertRule legacyCostAvailableAlert = getLegacyCostAvailableAlert();
     if (legacyCostAvailableAlert == null) {
@@ -390,6 +394,7 @@
   private void updateLegacyCosts() {
     long start = System.currentTimeMillis();
     log4j.debug("Starting updateLegacyCosts() at: " + new Date());
+
     resetTransactionCosts();
     fixLegacyCostingCurrency();
 
@@ -437,6 +442,7 @@
   private void resetTransactionCosts() {
     long start = System.currentTimeMillis();
     log4j.debug("Starting resetTransactionCosts() at: " + new Date());
+
     TriggerHandler.getInstance().disable();
     try {
       // Reset costs in m_transaction_cost
@@ -460,6 +466,7 @@
     } finally {
       TriggerHandler.getInstance().enable();
     }
+
     long end = System.currentTimeMillis();
     log4j.debug("Ending resetTransactionCosts() at: " + new Date() + ". Duration: " + (end - start)
         + " ms.");
@@ -468,6 +475,7 @@
   private void fixLegacyCostingCurrency() {
     long start = System.currentTimeMillis();
     log4j.debug("Starting fixLegacyCostingCurrency() at: " + new Date());
+
     TriggerHandler.getInstance().disable();
     try {
       // Fix legacy costing currency
@@ -488,6 +496,7 @@
     } finally {
       TriggerHandler.getInstance().enable();
     }
+
     long end = System.currentTimeMillis();
     log4j.debug("Ending fixLegacyCostingCurrency() at: " + new Date() + ". Duration: "
         + (end - start) + " ms.");
@@ -496,6 +505,7 @@
   private void createRules() throws Exception {
     long start = System.currentTimeMillis();
     log4j.debug("Starting createRules() at: " + new Date());
+
     // Delete manually created rules.
     Query delQry = OBDal.getInstance().getSession()
         .createQuery("delete from " + CostingRule.ENTITY_NAME);
@@ -515,11 +525,15 @@
         calculateCosts(org);
       }
     }
+
     long end = System.currentTimeMillis();
     log4j.debug("Ending createRules() at: " + new Date() + ". Duration: " + (end - start) + " ms.");
   }
 
   private void processRule(CostingRule rule) {
+    long start = System.currentTimeMillis();
+    log4j.debug("Starting processRule() at: " + new Date());
+
     OrganizationStructureProvider osp = OBContext.getOBContext().getOrganizationStructureProvider(
         rule.getClient().getId());
     final Set<String> childOrgs = osp.getChildTree(rule.getOrganization().getId(), true);
@@ -531,9 +545,15 @@
     rule.setStartingDate(startingDate);
     log4j.debug("setting starting date " + startingDate);
     OBDal.getInstance().flush();
+
+    long end = System.currentTimeMillis();
+    log4j.debug("Ending processRule() at: " + new Date() + ". Duration: " + (end - start) + " ms.");
   }
 
   private void calculateCosts(Organization org) {
+    long start = System.currentTimeMillis();
+    log4j.debug("Starting calculateCosts() at: " + new Date());
+
     Currency cur = FinancialUtils.getLegalEntityCurrency(org);
     String curId = cur.getId();
     Set<String> orgs = OBContext.getOBContext()
@@ -610,6 +630,9 @@
     OBDal.getInstance().flush();
     insertTrxCosts();
 
+    long end = System.currentTimeMillis();
+    log4j.debug("Ending calculateCosts() at: " + new Date() + ". Duration: " + (end - start)
+        + " ms.");
   }
 
   private HashMap<String, BigDecimal> getCurrentValuedStock(String productId, String curId,
@@ -706,9 +729,6 @@
   }
 
   private ScrollableResults getLegacyCostScroll(String clientId, Set<String> naturalTree) {
-    long start = System.currentTimeMillis();
-    log4j.debug("Starting getLegacyCostScroll() at: " + new Date());
-
     StringBuffer where = new StringBuffer();
     where.append(" as c");
     where.append(" where c." + Costing.PROPERTY_CLIENT + ".id = :client");
@@ -733,18 +753,14 @@
     costingQry.setNamedParameter("client", clientId);
     costingQry.setNamedParameter("orgs", naturalTree);
     costingQry.setFetchSize(1000);
-
-    long end = System.currentTimeMillis();
-    log4j.debug("Ending getLegacyCostScroll() at: " + new Date() + ". Duration: " + (end - start)
-        + " ms.");
     return costingQry.scroll(ScrollMode.FORWARD_ONLY);
   }
 
   private void updateTrxLegacyCosts(Costing _cost, int standardPrecision, Set<String> naturalTree) {
     long start = System.currentTimeMillis();
     log4j.debug("Starting updateTrxLegacyCosts() at: " + new Date());
+
     Costing cost = OBDal.getInstance().get(Costing.class, _cost.getId());
-
     StringBuffer where = new StringBuffer();
     where.append(MaterialTransaction.PROPERTY_PRODUCT + ".id = :product");
     where.append("   and " + MaterialTransaction.PROPERTY_ORGANIZATION + ".id in (:orgs)");
@@ -816,6 +832,7 @@
   private void updateWithZeroCostRemainingTrx() {
     long start = System.currentTimeMillis();
     log4j.debug("Starting updateWithZeroCostRemainingTrx() at: " + new Date());
+
     int n = 0;
     TriggerHandler.getInstance().disable();
     try {
@@ -850,6 +867,7 @@
     } finally {
       TriggerHandler.getInstance().enable();
     }
+
     long end = System.currentTimeMillis();
     log4j.debug("Ending updateWithZeroCostRemainingTrx() at: " + new Date() + ". Duration: "
         + (end - start) + " ms. Updated: " + n + " transactions.");
@@ -895,10 +913,10 @@
   private void insertTrxCosts() {
     long start = System.currentTimeMillis();
     log4j.debug("Starting insertTrxCosts() at: " + new Date());
+
     TriggerHandler.getInstance().disable();
-    long countTrx = 0;
     try {
-      countTrx = Long.valueOf(CostingUtilsData.countTrxCosts(conn)).longValue();
+      long countTrx = Long.valueOf(CostingUtilsData.countTrxCosts(conn)).longValue();
       long iters = (countTrx % maxTrx == 0) ? (countTrx / maxTrx) : (countTrx / maxTrx) + 1;
       String pgLimit = null, oraLimit = null;
       if (StringUtils.equalsIgnoreCase(conn.getRDBMS(), "ORACLE")) {
@@ -914,19 +932,20 @@
     } catch (Exception e) {
       log4j.error(e.getMessage());
     } finally {
+      TriggerHandler.getInstance().enable();
+
       long end = System.currentTimeMillis();
       log4j.debug("Ending insertTrxCosts() at: " + new Date() + ". Duration: " + (end - start)
-          + " ms. Inserted: " + countTrx + " transactions.");
-      TriggerHandler.getInstance().enable();
+          + " ms.");
     }
   }
 
   private void insertStandardCosts() {
     long start = System.currentTimeMillis();
     log4j.debug("Starting insertStandardCosts() at: " + new Date());
+
     // Insert STANDARD cost for products with costtype = 'ST'.
     TriggerHandler.getInstance().disable();
-    int insertedTrx = 0;
     try {
       StringBuffer insert = new StringBuffer();
       insert.append(" insert into " + Costing.ENTITY_NAME);
@@ -990,16 +1009,17 @@
       queryInsert.setString("startingDate", startingDate);
       queryInsert.setString("limitDate", startingDate);
       queryInsert.setString("limitDate2", startingDate);
-      insertedTrx = queryInsert.executeUpdate();
+      queryInsert.executeUpdate();
 
       OBDal.getInstance().flush();
       OBDal.getInstance().getSession().clear();
     } finally {
       TriggerHandler.getInstance().enable();
     }
+
     long end = System.currentTimeMillis();
     log4j.debug("Ending insertStandardCosts() at: " + new Date() + ". Duration: " + (end - start)
-        + " ms. Inserted: " + insertedTrx + " transactions.");
+        + " ms.");
   }
 
   private CostingRule createCostingRule(Organization org) {