Dmitry Lychagin has submitted this change and it was merged. Change subject: [NO ISSUE][COMP] Check logging level before writing a log message ......................................................................
[NO ISSUE][COMP] Check logging level before writing a log message - user model changes: no - storage format changes: no - interface changes: no Details: - Cleanup: Check logging level before writing to the logger Change-Id: Ib126397c390f0d32436a80a306981106afa2a794 Reviewed-on: https://asterix-gerrit.ics.uci.edu/2543 Tested-by: Jenkins <jenk...@fulliautomatix.ics.uci.edu> Contrib: Jenkins <jenk...@fulliautomatix.ics.uci.edu> Integration-Tests: Jenkins <jenk...@fulliautomatix.ics.uci.edu> Reviewed-by: Michael Blow <mb...@apache.org> --- M hyracks-fullstack/algebricks/algebricks-core/src/main/java/org/apache/hyracks/algebricks/core/algebra/operators/logical/IntersectOperator.java M hyracks-fullstack/algebricks/algebricks-core/src/main/java/org/apache/hyracks/algebricks/core/algebra/operators/logical/visitors/FDsAndEquivClassesVisitor.java M hyracks-fullstack/algebricks/algebricks-core/src/main/java/org/apache/hyracks/algebricks/core/algebra/operators/logical/visitors/LogicalPropertiesVisitor.java M hyracks-fullstack/algebricks/algebricks-core/src/main/java/org/apache/hyracks/algebricks/core/rewriter/base/HeuristicOptimizer.java M hyracks-fullstack/algebricks/algebricks-rewriter/src/main/java/org/apache/hyracks/algebricks/rewriter/rules/EnforceStructuralPropertiesRule.java M hyracks-fullstack/algebricks/algebricks-rewriter/src/main/java/org/apache/hyracks/algebricks/rewriter/rules/subplan/IntroduceGroupByForSubplanRule.java M hyracks-fullstack/algebricks/algebricks-rewriter/src/main/java/org/apache/hyracks/algebricks/rewriter/util/JoinUtils.java M hyracks-fullstack/algebricks/algebricks-tests/src/test/java/org/apache/hyracks/algebricks/tests/util/AlgebricksHyracksIntegrationUtil.java 8 files changed, 74 insertions(+), 36 deletions(-) Approvals: Anon. E. Moose #1000171: Jenkins: Verified; ; Verified Michael Blow: Looks good to me, approved Objections: Jenkins: Violations found diff --git a/hyracks-fullstack/algebricks/algebricks-core/src/main/java/org/apache/hyracks/algebricks/core/algebra/operators/logical/IntersectOperator.java b/hyracks-fullstack/algebricks/algebricks-core/src/main/java/org/apache/hyracks/algebricks/core/algebra/operators/logical/IntersectOperator.java index 8a06ec4..c2e4541 100644 --- a/hyracks-fullstack/algebricks/algebricks-core/src/main/java/org/apache/hyracks/algebricks/core/algebra/operators/logical/IntersectOperator.java +++ b/hyracks-fullstack/algebricks/algebricks-core/src/main/java/org/apache/hyracks/algebricks/core/algebra/operators/logical/IntersectOperator.java @@ -155,9 +155,11 @@ Object expectedType = expected.getVarType(expectedVariables.get(i)); Object actualType = actual.getVarType(actualVariables.get(i)); if (!expectedType.equals(actualType)) { - AlgebricksConfig.ALGEBRICKS_LOGGER - .warn("Type of two variables are not equal." + expectedVariables.get(i) + " is of type: " - + expectedType + actualVariables.get(i) + " is of type: " + actualType); + if (AlgebricksConfig.ALGEBRICKS_LOGGER.isWarnEnabled()) { + AlgebricksConfig.ALGEBRICKS_LOGGER + .warn("Type of two variables are not equal." + expectedVariables.get(i) + " is of type: " + + expectedType + actualVariables.get(i) + " is of type: " + actualType); + } } } } diff --git a/hyracks-fullstack/algebricks/algebricks-core/src/main/java/org/apache/hyracks/algebricks/core/algebra/operators/logical/visitors/FDsAndEquivClassesVisitor.java b/hyracks-fullstack/algebricks/algebricks-core/src/main/java/org/apache/hyracks/algebricks/core/algebra/operators/logical/visitors/FDsAndEquivClassesVisitor.java index 39d522f..2d5780d 100644 --- a/hyracks-fullstack/algebricks/algebricks-core/src/main/java/org/apache/hyracks/algebricks/core/algebra/operators/logical/visitors/FDsAndEquivClassesVisitor.java +++ b/hyracks-fullstack/algebricks/algebricks-core/src/main/java/org/apache/hyracks/algebricks/core/algebra/operators/logical/visitors/FDsAndEquivClassesVisitor.java @@ -314,9 +314,11 @@ } } if (changed) { - AlgebricksConfig.ALGEBRICKS_LOGGER - .debug(">>>> Group-by list changed from " + GroupByOperator.veListToString(gByList) + " to " - + GroupByOperator.veListToString(newGbyList) + ".\n"); + if (AlgebricksConfig.ALGEBRICKS_LOGGER.isDebugEnabled()) { + AlgebricksConfig.ALGEBRICKS_LOGGER + .debug(">>>> Group-by list changed from " + GroupByOperator.veListToString(gByList) + " to " + + GroupByOperator.veListToString(newGbyList) + ".\n"); + } } gByList.clear(); gByList.addAll(newGbyList); diff --git a/hyracks-fullstack/algebricks/algebricks-core/src/main/java/org/apache/hyracks/algebricks/core/algebra/operators/logical/visitors/LogicalPropertiesVisitor.java b/hyracks-fullstack/algebricks/algebricks-core/src/main/java/org/apache/hyracks/algebricks/core/algebra/operators/logical/visitors/LogicalPropertiesVisitor.java index 5d9e2dc..ae93386 100644 --- a/hyracks-fullstack/algebricks/algebricks-core/src/main/java/org/apache/hyracks/algebricks/core/algebra/operators/logical/visitors/LogicalPropertiesVisitor.java +++ b/hyracks-fullstack/algebricks/algebricks-core/src/main/java/org/apache/hyracks/algebricks/core/algebra/operators/logical/visitors/LogicalPropertiesVisitor.java @@ -80,7 +80,7 @@ computeLogicalPropertiesRec(ref.getValue(), visitor, context); } op.accept(visitor, context); - if (AlgebricksConfig.DEBUG) { + if (AlgebricksConfig.DEBUG && AlgebricksConfig.ALGEBRICKS_LOGGER.isTraceEnabled()) { AlgebricksConfig.ALGEBRICKS_LOGGER.trace( "Logical properties visitor for " + op + ": " + context.getLogicalPropertiesVector(op) + "\n"); } diff --git a/hyracks-fullstack/algebricks/algebricks-core/src/main/java/org/apache/hyracks/algebricks/core/rewriter/base/HeuristicOptimizer.java b/hyracks-fullstack/algebricks/algebricks-core/src/main/java/org/apache/hyracks/algebricks/core/rewriter/base/HeuristicOptimizer.java index 4388032..9119d6c 100644 --- a/hyracks-fullstack/algebricks/algebricks-core/src/main/java/org/apache/hyracks/algebricks/core/rewriter/base/HeuristicOptimizer.java +++ b/hyracks-fullstack/algebricks/algebricks-core/src/main/java/org/apache/hyracks/algebricks/core/rewriter/base/HeuristicOptimizer.java @@ -90,7 +90,7 @@ final LogicalOperatorPrettyPrintVisitor pvisitor = context.getPrettyPrintVisitor(); pvisitor.reset(new AlgebricksAppendable()); PlanPrettyPrinter.printPlan(plan, pvisitor, 0); - AlgebricksConfig.ALGEBRICKS_LOGGER.info(name + ":\n" + pvisitor.get().toString()); + AlgebricksConfig.ALGEBRICKS_LOGGER.log(lvl, name + ":\n" + pvisitor.get().toString()); } } diff --git a/hyracks-fullstack/algebricks/algebricks-rewriter/src/main/java/org/apache/hyracks/algebricks/rewriter/rules/EnforceStructuralPropertiesRule.java b/hyracks-fullstack/algebricks/algebricks-rewriter/src/main/java/org/apache/hyracks/algebricks/rewriter/rules/EnforceStructuralPropertiesRule.java index da0466e..e8b446b 100644 --- a/hyracks-fullstack/algebricks/algebricks-rewriter/src/main/java/org/apache/hyracks/algebricks/rewriter/rules/EnforceStructuralPropertiesRule.java +++ b/hyracks-fullstack/algebricks/algebricks-rewriter/src/main/java/org/apache/hyracks/algebricks/rewriter/rules/EnforceStructuralPropertiesRule.java @@ -123,7 +123,9 @@ // somewhere else, too. physicalOptimizationConfig = context.getPhysicalOptimizationConfig(); - AlgebricksConfig.ALGEBRICKS_LOGGER.debug(">>>> Optimizing operator " + op.getPhysicalOperator() + ".\n"); + if (AlgebricksConfig.ALGEBRICKS_LOGGER.isDebugEnabled()) { + AlgebricksConfig.ALGEBRICKS_LOGGER.debug(">>>> Optimizing operator " + op.getPhysicalOperator() + ".\n"); + } PhysicalOptimizationsUtil.computeFDsAndEquivalenceClasses(op, context); @@ -132,8 +134,10 @@ new LinkedList<ILocalStructuralProperty>()); boolean changed = physOptimizeOp(opRef, pvector, false, context); op.computeDeliveredPhysicalProperties(context); - AlgebricksConfig.ALGEBRICKS_LOGGER.trace(">>>> Structural properties for " + op.getPhysicalOperator() + ": " - + op.getDeliveredPhysicalProperties() + "\n"); + if (AlgebricksConfig.ALGEBRICKS_LOGGER.isTraceEnabled()) { + AlgebricksConfig.ALGEBRICKS_LOGGER.trace(">>>> Structural properties for " + op.getPhysicalOperator() + ": " + + op.getDeliveredPhysicalProperties() + "\n"); + } context.addToDontApplySet(this, opRef.getValue()); @@ -142,6 +146,7 @@ private boolean physOptimizePlan(ILogicalPlan plan, IPhysicalPropertiesVector pvector, boolean nestedPlan, IOptimizationContext context) throws AlgebricksException { + boolean loggerTraceEnabled = AlgebricksConfig.ALGEBRICKS_LOGGER.isTraceEnabled(); boolean changed = false; for (Mutable<ILogicalOperator> root : plan.getRoots()) { if (physOptimizeOp(root, pvector, nestedPlan, context)) { @@ -149,8 +154,10 @@ } AbstractLogicalOperator op = (AbstractLogicalOperator) root.getValue(); op.computeDeliveredPhysicalProperties(context); - AlgebricksConfig.ALGEBRICKS_LOGGER.trace(">>>> Structural properties for " + op.getPhysicalOperator() + ": " - + op.getDeliveredPhysicalProperties() + "\n"); + if (loggerTraceEnabled) { + AlgebricksConfig.ALGEBRICKS_LOGGER.trace(">>>> Structural properties for " + op.getPhysicalOperator() + + ": " + op.getDeliveredPhysicalProperties() + "\n"); + } } return changed; } @@ -238,6 +245,8 @@ } } + boolean loggerTraceEnabled = AlgebricksConfig.ALGEBRICKS_LOGGER.isTraceEnabled(); + // The child index of the child operator to optimize first. int startChildIndex = getStartChildIndex(op, pr, nestedPlan, context); IPartitioningProperty firstDeliveredPartitioning = null; @@ -249,8 +258,10 @@ AbstractLogicalOperator child = (AbstractLogicalOperator) op.getInputs().get(childIndex).getValue(); IPhysicalPropertiesVector delivered = child.getDeliveredPhysicalProperties(); - AlgebricksConfig.ALGEBRICKS_LOGGER - .trace(">>>> Properties delivered by " + child.getPhysicalOperator() + ": " + delivered + "\n"); + if (loggerTraceEnabled) { + AlgebricksConfig.ALGEBRICKS_LOGGER + .trace(">>>> Properties delivered by " + child.getPhysicalOperator() + ": " + delivered + "\n"); + } IPartitioningRequirementsCoordinator prc = pr.getPartitioningCoordinator(); // Coordinates requirements by looking at the firstDeliveredPartitioning. Pair<Boolean, IPartitioningProperty> pbpp = prc.coordinateRequirements( @@ -259,8 +270,10 @@ IPhysicalPropertiesVector rqd = new StructuralPropertiesVector(pbpp.second, requiredProperty.getLocalProperties()); - AlgebricksConfig.ALGEBRICKS_LOGGER - .trace(">>>> Required properties for " + child.getPhysicalOperator() + ": " + rqd + "\n"); + if (loggerTraceEnabled) { + AlgebricksConfig.ALGEBRICKS_LOGGER + .trace(">>>> Required properties for " + child.getPhysicalOperator() + ": " + rqd + "\n"); + } // The partitioning property of reqdProperties[childIndex] could be updated here because // rqd.getPartitioningProperty() is the same object instance as requiredProperty.getPartitioningProperty(). IPhysicalPropertiesVector diff = delivered.getUnsatisfiedPropertiesFrom(rqd, @@ -280,7 +293,9 @@ delivered = newChild.getDeliveredPhysicalProperties(); IPhysicalPropertiesVector newDiff = newPropertiesDiff(newChild, rqd, mayExpandPartitioningProperties, context); - AlgebricksConfig.ALGEBRICKS_LOGGER.trace(">>>> New properties diff: " + newDiff + "\n"); + if (loggerTraceEnabled) { + AlgebricksConfig.ALGEBRICKS_LOGGER.trace(">>>> New properties diff: " + newDiff + "\n"); + } if (isRedundantSort(opRef, delivered, newDiff, context)) { opIsRedundantSort = true; @@ -304,7 +319,7 @@ } if (opIsRedundantSort) { - if (AlgebricksConfig.DEBUG) { + if (AlgebricksConfig.DEBUG && loggerTraceEnabled) { AlgebricksConfig.ALGEBRICKS_LOGGER .trace(">>>> Removing redundant SORT operator " + op.getPhysicalOperator() + "\n"); printOp(op); @@ -340,8 +355,10 @@ newChildEqClasses = context.getEquivalenceClassMap(newChild); newChildFDs = context.getFDList(newChild); } - AlgebricksConfig.ALGEBRICKS_LOGGER.trace( - ">>>> Required properties for new op. " + newChild.getPhysicalOperator() + ": " + required + "\n"); + if (AlgebricksConfig.ALGEBRICKS_LOGGER.isTraceEnabled()) { + AlgebricksConfig.ALGEBRICKS_LOGGER.trace( + ">>>> Required properties for new op. " + newChild.getPhysicalOperator() + ": " + required + "\n"); + } return newDelivered.getUnsatisfiedPropertiesFrom(required, mayExpandPartitioningProperties, newChildEqClasses, newChildFDs); @@ -446,7 +463,9 @@ } AbstractLogicalOperator newChild = (AbstractLogicalOperator) op.getInputs().get(childIndex).getValue(); IPhysicalPropertiesVector newDiff = newPropertiesDiff(newChild, required, true, context); - AlgebricksConfig.ALGEBRICKS_LOGGER.trace(">>>> New properties diff: " + newDiff + "\n"); + if (AlgebricksConfig.ALGEBRICKS_LOGGER.isTraceEnabled()) { + AlgebricksConfig.ALGEBRICKS_LOGGER.trace(">>>> New properties diff: " + newDiff + "\n"); + } if (newDiff != null) { addLocalEnforcers(op, childIndex, newDiff.getLocalProperties(), nestedPlan, context); } @@ -455,7 +474,7 @@ private void addLocalEnforcers(AbstractLogicalOperator op, int i, List<ILocalStructuralProperty> localProperties, boolean nestedPlan, IOptimizationContext context) throws AlgebricksException { - if (AlgebricksConfig.DEBUG) { + if (AlgebricksConfig.DEBUG && AlgebricksConfig.ALGEBRICKS_LOGGER.isTraceEnabled()) { AlgebricksConfig.ALGEBRICKS_LOGGER .trace(">>>> Adding local enforcers for local props = " + localProperties + "\n"); } @@ -523,7 +542,7 @@ } oo.getInputs().add(topOp); context.computeAndSetTypeEnvironmentForOperator(oo); - if (AlgebricksConfig.DEBUG) { + if (AlgebricksConfig.DEBUG && AlgebricksConfig.ALGEBRICKS_LOGGER.isTraceEnabled()) { AlgebricksConfig.ALGEBRICKS_LOGGER.trace(">>>> Added sort enforcer " + oo.getPhysicalOperator() + ".\n"); } return new MutableObject<ILogicalOperator>(oo); @@ -606,7 +625,7 @@ exchg.setExecutionMode(AbstractLogicalOperator.ExecutionMode.PARTITIONED); OperatorPropertiesUtil.computeSchemaAndPropertiesRecIfNull(exchg, context); context.computeAndSetTypeEnvironmentForOperator(exchg); - if (AlgebricksConfig.DEBUG) { + if (AlgebricksConfig.DEBUG && AlgebricksConfig.ALGEBRICKS_LOGGER.isDebugEnabled()) { AlgebricksConfig.ALGEBRICKS_LOGGER .debug(">>>> Added partitioning enforcer " + exchg.getPhysicalOperator() + ".\n"); printOp((AbstractLogicalOperator) op); @@ -626,7 +645,9 @@ private void printOp(AbstractLogicalOperator op) throws AlgebricksException { LogicalOperatorPrettyPrintVisitor pvisitor = new LogicalOperatorPrettyPrintVisitor(); PlanPrettyPrinter.printOperator(op, pvisitor, 0); - AlgebricksConfig.ALGEBRICKS_LOGGER.debug(pvisitor.get().toString()); + if (AlgebricksConfig.ALGEBRICKS_LOGGER.isDebugEnabled()) { + AlgebricksConfig.ALGEBRICKS_LOGGER.debug(pvisitor.get().toString()); + } } private List<OrderColumn> computeOrderColumns(IPhysicalPropertiesVector pv) { @@ -655,8 +676,10 @@ newOp.recomputeSchema(); newOp.computeDeliveredPhysicalProperties(context); context.computeAndSetTypeEnvironmentForOperator(newOp); - AlgebricksConfig.ALGEBRICKS_LOGGER.trace(">>>> Structural properties for " + newOp.getPhysicalOperator() + ": " - + newOp.getDeliveredPhysicalProperties() + "\n"); + if (AlgebricksConfig.ALGEBRICKS_LOGGER.isTraceEnabled()) { + AlgebricksConfig.ALGEBRICKS_LOGGER.trace(">>>> Structural properties for " + newOp.getPhysicalOperator() + + ": " + newOp.getDeliveredPhysicalProperties() + "\n"); + } PhysicalOptimizationsUtil.computeFDsAndEquivalenceClasses(newOp, context); } diff --git a/hyracks-fullstack/algebricks/algebricks-rewriter/src/main/java/org/apache/hyracks/algebricks/rewriter/rules/subplan/IntroduceGroupByForSubplanRule.java b/hyracks-fullstack/algebricks/algebricks-rewriter/src/main/java/org/apache/hyracks/algebricks/rewriter/rules/subplan/IntroduceGroupByForSubplanRule.java index c4ea604..5118bf3 100644 --- a/hyracks-fullstack/algebricks/algebricks-rewriter/src/main/java/org/apache/hyracks/algebricks/rewriter/rules/subplan/IntroduceGroupByForSubplanRule.java +++ b/hyracks-fullstack/algebricks/algebricks-rewriter/src/main/java/org/apache/hyracks/algebricks/rewriter/rules/subplan/IntroduceGroupByForSubplanRule.java @@ -201,7 +201,9 @@ //retain the intersection pkVars.retainAll(producedVars); } - AlgebricksConfig.ALGEBRICKS_LOGGER.debug("Found FD for introducing group-by: " + pkVars); + if (AlgebricksConfig.ALGEBRICKS_LOGGER.isDebugEnabled()) { + AlgebricksConfig.ALGEBRICKS_LOGGER.debug("Found FD for introducing group-by: " + pkVars); + } Mutable<ILogicalOperator> rightRef = join.getInputs().get(1); LogicalVariable testForNull = null; diff --git a/hyracks-fullstack/algebricks/algebricks-rewriter/src/main/java/org/apache/hyracks/algebricks/rewriter/util/JoinUtils.java b/hyracks-fullstack/algebricks/algebricks-rewriter/src/main/java/org/apache/hyracks/algebricks/rewriter/util/JoinUtils.java index 0bc2a5e..555d468 100644 --- a/hyracks-fullstack/algebricks/algebricks-rewriter/src/main/java/org/apache/hyracks/algebricks/rewriter/util/JoinUtils.java +++ b/hyracks-fullstack/algebricks/algebricks-rewriter/src/main/java/org/apache/hyracks/algebricks/rewriter/util/JoinUtils.java @@ -109,14 +109,19 @@ ILogicalOperator opBuild = op.getInputs().get(1).getValue(); LogicalPropertiesVisitor.computeLogicalPropertiesDFS(opBuild, context); ILogicalPropertiesVector v = context.getLogicalPropertiesVector(opBuild); - AlgebricksConfig.ALGEBRICKS_LOGGER - .debug("// HybridHashJoin inner branch -- Logical properties for " + opBuild + ": " + v + "\n"); + boolean loggerDebugEnabled = AlgebricksConfig.ALGEBRICKS_LOGGER.isDebugEnabled(); + if (loggerDebugEnabled) { + AlgebricksConfig.ALGEBRICKS_LOGGER + .debug("// HybridHashJoin inner branch -- Logical properties for " + opBuild + ": " + v + "\n"); + } if (v != null) { int size2 = v.getMaxOutputFrames(); HybridHashJoinPOperator hhj = (HybridHashJoinPOperator) op.getPhysicalOperator(); if (size2 > 0 && size2 * hhj.getFudgeFactor() <= hhj.getMemSizeInFrames()) { - AlgebricksConfig.ALGEBRICKS_LOGGER - .debug("// HybridHashJoin inner branch " + opBuild + " fits in memory\n"); + if (loggerDebugEnabled) { + AlgebricksConfig.ALGEBRICKS_LOGGER + .debug("// HybridHashJoin inner branch " + opBuild + " fits in memory\n"); + } // maintains the local properties on the probe side op.setPhysicalOperator( new InMemoryHashJoinPOperator(hhj.getKind(), hhj.getPartitioningType(), hhj.getKeysLeftBranch(), diff --git a/hyracks-fullstack/algebricks/algebricks-tests/src/test/java/org/apache/hyracks/algebricks/tests/util/AlgebricksHyracksIntegrationUtil.java b/hyracks-fullstack/algebricks/algebricks-tests/src/test/java/org/apache/hyracks/algebricks/tests/util/AlgebricksHyracksIntegrationUtil.java index 1df9824..9b3817e 100644 --- a/hyracks-fullstack/algebricks/algebricks-tests/src/test/java/org/apache/hyracks/algebricks/tests/util/AlgebricksHyracksIntegrationUtil.java +++ b/hyracks-fullstack/algebricks/algebricks-tests/src/test/java/org/apache/hyracks/algebricks/tests/util/AlgebricksHyracksIntegrationUtil.java @@ -91,10 +91,14 @@ } public static void runJob(JobSpecification spec) throws Exception { - AlgebricksConfig.ALGEBRICKS_LOGGER.info(spec.toJSON().toString()); + boolean loggerInfoEnabled = AlgebricksConfig.ALGEBRICKS_LOGGER.isInfoEnabled(); + if (loggerInfoEnabled) { + AlgebricksConfig.ALGEBRICKS_LOGGER.info(spec.toJSON().toString()); + } JobId jobId = hcc.startJob(spec, EnumSet.of(JobFlag.PROFILE_RUNTIME)); - AlgebricksConfig.ALGEBRICKS_LOGGER.info(jobId.toString()); + if (loggerInfoEnabled) { + AlgebricksConfig.ALGEBRICKS_LOGGER.info(jobId.toString()); + } hcc.waitForCompletion(jobId); } - } -- To view, visit https://asterix-gerrit.ics.uci.edu/2543 To unsubscribe, visit https://asterix-gerrit.ics.uci.edu/settings Gerrit-MessageType: merged Gerrit-Change-Id: Ib126397c390f0d32436a80a306981106afa2a794 Gerrit-PatchSet: 2 Gerrit-Project: asterixdb Gerrit-Branch: release-0.9.4-pre-rc Gerrit-Owner: Dmitry Lychagin <dmitry.lycha...@couchbase.com> Gerrit-Reviewer: Anon. E. Moose #1000171 Gerrit-Reviewer: Dmitry Lychagin <dmitry.lycha...@couchbase.com> Gerrit-Reviewer: Jenkins <jenk...@fulliautomatix.ics.uci.edu> Gerrit-Reviewer: Michael Blow <mb...@apache.org>