phoenix-commits mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From jamestay...@apache.org
Subject [6/9] phoenix git commit: PHOENIX-1446 Add/fix logging for LIMIT optimization
Date Thu, 13 Nov 2014 06:54:12 GMT
PHOENIX-1446 Add/fix logging for LIMIT optimization

Conflicts:
	phoenix-core/src/main/java/org/apache/phoenix/iterate/BaseResultIterators.java
	phoenix-core/src/main/java/org/apache/phoenix/jdbc/PhoenixStatement.java
	phoenix-core/src/main/java/org/apache/phoenix/util/QueryUtil.java


Project: http://git-wip-us.apache.org/repos/asf/phoenix/repo
Commit: http://git-wip-us.apache.org/repos/asf/phoenix/commit/e526cdd1
Tree: http://git-wip-us.apache.org/repos/asf/phoenix/tree/e526cdd1
Diff: http://git-wip-us.apache.org/repos/asf/phoenix/diff/e526cdd1

Branch: refs/heads/3.0
Commit: e526cdd17f90382e4e4b611b495f8c639d770855
Parents: ae5d819
Author: James Taylor <jtaylor@salesforce.com>
Authored: Wed Nov 12 16:40:03 2014 -0800
Committer: James Taylor <jtaylor@salesforce.com>
Committed: Wed Nov 12 22:47:26 2014 -0800

----------------------------------------------------------------------
 .../org/apache/phoenix/execute/ScanPlan.java    |  7 +++++
 .../phoenix/iterate/BaseResultIterators.java    | 31 ++++++++++++--------
 .../phoenix/iterate/ParallelIterators.java      |  5 ++--
 .../apache/phoenix/iterate/SerialIterators.java |  5 ++--
 .../apache/phoenix/jdbc/PhoenixStatement.java   | 20 ++++++++++++-
 .../java/org/apache/phoenix/util/QueryUtil.java | 18 +++++++++++-
 6 files changed, 66 insertions(+), 20 deletions(-)
----------------------------------------------------------------------


http://git-wip-us.apache.org/repos/asf/phoenix/blob/e526cdd1/phoenix-core/src/main/java/org/apache/phoenix/execute/ScanPlan.java
----------------------------------------------------------------------
diff --git a/phoenix-core/src/main/java/org/apache/phoenix/execute/ScanPlan.java b/phoenix-core/src/main/java/org/apache/phoenix/execute/ScanPlan.java
index a3ca629..c35d81c 100644
--- a/phoenix-core/src/main/java/org/apache/phoenix/execute/ScanPlan.java
+++ b/phoenix-core/src/main/java/org/apache/phoenix/execute/ScanPlan.java
@@ -54,6 +54,8 @@ import org.apache.phoenix.schema.stats.GuidePostsInfo;
 import org.apache.phoenix.schema.stats.StatisticsUtil;
 import org.apache.phoenix.util.ScanUtil;
 import org.apache.phoenix.util.SchemaUtil;
+import org.slf4j.Logger;
+import org.slf4j.LoggerFactory;
 
 
 
@@ -65,6 +67,7 @@ import org.apache.phoenix.util.SchemaUtil;
  * @since 0.1
  */
 public class ScanPlan extends BaseQueryPlan {
+    private static final Logger logger = LoggerFactory.getLogger(ScanPlan.class);
     private List<KeyRange> splits;
     private List<List<Scan>> scans;
     private boolean allowPageFilter;
@@ -152,6 +155,10 @@ public class ScanPlan extends BaseQueryPlan {
             if (perScanLimit * estRowSize < estRegionSize) {
                 isSerial = true;
             }
+            if (logger.isDebugEnabled()) logger.debug("With LIMIT=" + perScanLimit 
+                    + ", estimated row size=" + estRowSize 
+                    + ", estimated region size=" + estRegionSize + " (" + (gpsInfo == null
? "without " : "with ") + "stats)" 
+                    + ": " + (isSerial ? "SERIAL" : "PARALLEL") + " execution");
         }
         ResultIterators iterators;
         if (isSerial) {

http://git-wip-us.apache.org/repos/asf/phoenix/blob/e526cdd1/phoenix-core/src/main/java/org/apache/phoenix/iterate/BaseResultIterators.java
----------------------------------------------------------------------
diff --git a/phoenix-core/src/main/java/org/apache/phoenix/iterate/BaseResultIterators.java
b/phoenix-core/src/main/java/org/apache/phoenix/iterate/BaseResultIterators.java
index 763daf3..7f635c3 100644
--- a/phoenix-core/src/main/java/org/apache/phoenix/iterate/BaseResultIterators.java
+++ b/phoenix-core/src/main/java/org/apache/phoenix/iterate/BaseResultIterators.java
@@ -94,6 +94,7 @@ public abstract class BaseResultIterators extends ExplainTable implements
Result
     private final PTableStats tableStats;
     private final byte[] physicalTableName;
     private final QueryPlan plan;
+    protected final String scanId;
     // TODO: too much nesting here - breakup into new classes.
     private final List<List<List<Pair<Scan,Future<PeekingResultIterator>>>>>
allFutures;
 
@@ -136,6 +137,8 @@ public abstract class BaseResultIterators extends ExplainTable implements
Result
         physicalTableName = table.getPhysicalName().getBytes();
         tableStats = useStats() ? new MetaDataClient(context.getConnection()).getTableStats(table)
: PTableStats.EMPTY_STATS;
         Scan scan = context.getScan();
+        // Used to tie all the scans together during logging
+        scanId = UUID.randomUUID().toString();
         if (projector.isProjectEmptyKeyValue()) {
             Map<byte [], NavigableSet<byte []>> familyMap = scan.getFamilyMap();
             // If nothing projected into scan and we only have one column family, just allow
everything
@@ -454,9 +457,6 @@ public abstract class BaseResultIterators extends ExplainTable implements
Result
         if (!scans.isEmpty()) { // Add any remaining scans
             parallelScans.add(scans);
         }
-        if (logger.isDebugEnabled()) {
-            logger.debug("The parallelScans: " + parallelScans);
-        }
         return parallelScans;
     }
 
@@ -473,8 +473,12 @@ public abstract class BaseResultIterators extends ExplainTable implements
Result
      */
     @Override
     public List<PeekingResultIterator> getIterators() throws SQLException {
+        Scan scan = context.getScan();
+        if (logger.isDebugEnabled()) {
+            logger.debug("Getting iterators for " + this);
+        }
         boolean success = false;
-        boolean isReverse = ScanUtil.isReversed(context.getScan());
+        boolean isReverse = ScanUtil.isReversed(scan);
         final ConnectionQueryServices services = context.getConnection().getQueryServices();
         ReadOnlyProps props = services.getProps();
         int numSplits = size();
@@ -482,10 +486,8 @@ public abstract class BaseResultIterators extends ExplainTable implements
Result
         final List<List<Pair<Scan,Future<PeekingResultIterator>>>>
futures = Lists.newArrayListWithExpectedSize(numSplits);
         allFutures.add(futures);
         SQLException toThrow = null;
-        // TODO: what purpose does this scanID serve?
-        final UUID scanId = UUID.randomUUID();
         try {
-            submitWork(scanId, scans, futures, splits.size());
+            submitWork(scans, futures, splits.size());
             int timeoutMs = props.getInt(QueryServices.THREAD_TIMEOUT_MS_ATTRIB, DEFAULT_THREAD_TIMEOUT_MS);
             boolean clearedCache = false;
             for (List<Pair<Scan,Future<PeekingResultIterator>>> future
: reverseIfNecessary(futures,isReverse)) {
@@ -512,7 +514,7 @@ public abstract class BaseResultIterators extends ExplainTable implements
Result
                             // as we need these to be in order
                             addIterator(iterators, concatIterators);
                             concatIterators = Collections.emptyList();
-                            submitWork(scanId, newNestedScans, newFutures, newNestedScans.size());
+                            submitWork(newNestedScans, newFutures, newNestedScans.size());
                             allFutures.add(newFutures);
                             for (List<Pair<Scan,Future<PeekingResultIterator>>>
newFuture : reverseIfNecessary(newFutures, isReverse)) {
                                 for (Pair<Scan,Future<PeekingResultIterator>>
newScanPair : reverseIfNecessary(newFuture, isReverse)) {
@@ -576,7 +578,12 @@ public abstract class BaseResultIterators extends ExplainTable implements
Result
         for (List<List<Pair<Scan,Future<PeekingResultIterator>>>>
futures : allFutures) {
             for (List<Pair<Scan,Future<PeekingResultIterator>>> futureScans
: futures) {
                 for (Pair<Scan,Future<PeekingResultIterator>> futurePair : futureScans)
{
-                    cancelledWork |= futurePair.getSecond().cancel(false);
+                    if (futurePair != null) { // FIXME: null check should not be necessary
+                        Future<PeekingResultIterator> future = futurePair.getSecond();
+                        if (future != null) {
+                            cancelledWork |= future.cancel(false);
+                        }
+                    }
                 }
             }
         }
@@ -614,8 +621,8 @@ public abstract class BaseResultIterators extends ExplainTable implements
Result
     
 
     abstract protected String getName();    
-    abstract protected void submitWork(final UUID scanId, List<List<Scan>> nestedScans,
-            List<List<Pair<Scan,Future<PeekingResultIterator>>>>
nestedFutures, int estFlattenedSize);
+    abstract protected void submitWork(List<List<Scan>> nestedScans, List<List<Pair<Scan,Future<PeekingResultIterator>>>>
nestedFutures,
+            int estFlattenedSize);
 
     @Override
     public int size() {
@@ -634,6 +641,6 @@ public abstract class BaseResultIterators extends ExplainTable implements
Result
 
 	@Override
 	public String toString() {
-		return "ResultIterators [name=" + getName() + ",scans=" + scans + "]";
+		return "ResultIterators [name=" + getName() + ",id=" + scanId + ",scans=" + scans + "]";
 	}
 }
\ No newline at end of file

http://git-wip-us.apache.org/repos/asf/phoenix/blob/e526cdd1/phoenix-core/src/main/java/org/apache/phoenix/iterate/ParallelIterators.java
----------------------------------------------------------------------
diff --git a/phoenix-core/src/main/java/org/apache/phoenix/iterate/ParallelIterators.java
b/phoenix-core/src/main/java/org/apache/phoenix/iterate/ParallelIterators.java
index 5e0ff91..f7661fc 100644
--- a/phoenix-core/src/main/java/org/apache/phoenix/iterate/ParallelIterators.java
+++ b/phoenix-core/src/main/java/org/apache/phoenix/iterate/ParallelIterators.java
@@ -20,7 +20,6 @@ package org.apache.phoenix.iterate;
 import java.sql.SQLException;
 import java.util.Collections;
 import java.util.List;
-import java.util.UUID;
 import java.util.concurrent.ExecutorService;
 import java.util.concurrent.Future;
 
@@ -54,8 +53,8 @@ public class ParallelIterators extends BaseResultIterators {
     }
 
     @Override
-    protected void submitWork(final UUID scanId, List<List<Scan>> nestedScans,
-            List<List<Pair<Scan,Future<PeekingResultIterator>>>>
nestedFutures, int estFlattenedSize) {
+    protected void submitWork(List<List<Scan>> nestedScans, List<List<Pair<Scan,Future<PeekingResultIterator>>>>
nestedFutures,
+            int estFlattenedSize) {
         // Pre-populate nestedFutures lists so that we can shuffle the scans
         // and add the future to the right nested list. By shuffling the scans
         // we get better utilization of the cluster since our thread executor

http://git-wip-us.apache.org/repos/asf/phoenix/blob/e526cdd1/phoenix-core/src/main/java/org/apache/phoenix/iterate/SerialIterators.java
----------------------------------------------------------------------
diff --git a/phoenix-core/src/main/java/org/apache/phoenix/iterate/SerialIterators.java b/phoenix-core/src/main/java/org/apache/phoenix/iterate/SerialIterators.java
index f550ec8..44a1324 100644
--- a/phoenix-core/src/main/java/org/apache/phoenix/iterate/SerialIterators.java
+++ b/phoenix-core/src/main/java/org/apache/phoenix/iterate/SerialIterators.java
@@ -20,7 +20,6 @@ package org.apache.phoenix.iterate;
 import java.sql.SQLException;
 import java.util.Collections;
 import java.util.List;
-import java.util.UUID;
 import java.util.concurrent.ExecutorService;
 import java.util.concurrent.Future;
 
@@ -59,8 +58,8 @@ public class SerialIterators extends BaseResultIterators {
     }
 
     @Override
-    protected void submitWork(final UUID scanId, List<List<Scan>> nestedScans,
-            List<List<Pair<Scan,Future<PeekingResultIterator>>>>
nestedFutures, int estFlattenedSize) {
+    protected void submitWork(List<List<Scan>> nestedScans, List<List<Pair<Scan,Future<PeekingResultIterator>>>>
nestedFutures,
+            int estFlattenedSize) {
         // Pre-populate nestedFutures lists so that we can shuffle the scans
         // and add the future to the right nested list. By shuffling the scans
         // we get better utilization of the cluster since our thread executor

http://git-wip-us.apache.org/repos/asf/phoenix/blob/e526cdd1/phoenix-core/src/main/java/org/apache/phoenix/jdbc/PhoenixStatement.java
----------------------------------------------------------------------
diff --git a/phoenix-core/src/main/java/org/apache/phoenix/jdbc/PhoenixStatement.java b/phoenix-core/src/main/java/org/apache/phoenix/jdbc/PhoenixStatement.java
index 8fbb8a6..22b5301 100644
--- a/phoenix-core/src/main/java/org/apache/phoenix/jdbc/PhoenixStatement.java
+++ b/phoenix-core/src/main/java/org/apache/phoenix/jdbc/PhoenixStatement.java
@@ -116,9 +116,12 @@ import org.apache.phoenix.schema.tuple.Tuple;
 import org.apache.phoenix.util.ByteUtil;
 import org.apache.phoenix.util.KeyValueUtil;
 import org.apache.phoenix.util.PhoenixContextExecutor;
+import org.apache.phoenix.util.QueryUtil;
 import org.apache.phoenix.util.SQLCloseable;
 import org.apache.phoenix.util.SQLCloseables;
 import org.apache.phoenix.util.ServerUtil;
+import org.slf4j.Logger;
+import org.slf4j.LoggerFactory;
 
 import com.google.common.base.Throwables;
 import com.google.common.collect.ListMultimap;
@@ -144,6 +147,8 @@ import com.google.common.collect.Lists;
  * @since 0.1
  */
 public class PhoenixStatement implements Statement, SQLCloseable, org.apache.phoenix.jdbc.Jdbc7Shim.Statement
{
+    private static final Logger logger = LoggerFactory.getLogger(PhoenixStatement.class);
+    
     public enum Operation {
         QUERY("queried", false),
         DELETE("deleted", true),
@@ -212,7 +217,14 @@ public class PhoenixStatement implements Statement, SQLCloseable, org.apache.pho
                         QueryPlan plan = stmt.compilePlan(PhoenixStatement.this, Sequence.ValueOp.RESERVE_SEQUENCE);
                         plan = connection.getQueryServices().getOptimizer().optimize(
                                 PhoenixStatement.this, plan);
-                        PhoenixResultSet rs = newResultSet(plan.iterator(), plan.getProjector());
+                         // this will create its own trace internally, so we don't wrap this
+                         // whole thing in tracing
+                        ResultIterator resultIterator = plan.iterator();
+                        if (logger.isDebugEnabled()) {
+                            String explainPlan = QueryUtil.getExplainPlan(resultIterator);
+                            logger.debug("Explain plan: " + explainPlan);
+                        }
+                        PhoenixResultSet rs = newResultSet(resultIterator, plan.getProjector());
                         resultSets.add(rs);
                         setLastQueryPlan(plan);
                         setLastResultSet(rs);
@@ -993,12 +1005,18 @@ public class PhoenixStatement implements Statement, SQLCloseable, org.apache.pho
     }
 
     public MutationPlan compileMutation(String sql) throws SQLException {
+        if (logger.isDebugEnabled()) {
+            logger.debug("Execute update: " + sql);
+        }
         CompilableStatement stmt = parseStatement(sql);
         return compileMutation(stmt, sql);
     }
 
     @Override
     public ResultSet executeQuery(String sql) throws SQLException {
+        if (logger.isDebugEnabled()) {
+            logger.debug("Execute query: " + sql);
+        }
         CompilableStatement stmt = parseStatement(sql);
         if (stmt.getOperation().isMutation()) {
             throw new ExecuteQueryNotApplicableException(sql);

http://git-wip-us.apache.org/repos/asf/phoenix/blob/e526cdd1/phoenix-core/src/main/java/org/apache/phoenix/util/QueryUtil.java
----------------------------------------------------------------------
diff --git a/phoenix-core/src/main/java/org/apache/phoenix/util/QueryUtil.java b/phoenix-core/src/main/java/org/apache/phoenix/util/QueryUtil.java
index 7b50404..e32847d 100644
--- a/phoenix-core/src/main/java/org/apache/phoenix/util/QueryUtil.java
+++ b/phoenix-core/src/main/java/org/apache/phoenix/util/QueryUtil.java
@@ -25,6 +25,8 @@ import java.util.List;
 
 import javax.annotation.Nullable;
 
+import org.apache.phoenix.iterate.ResultIterator;
+
 import com.google.common.base.Function;
 import com.google.common.base.Joiner;
 import com.google.common.base.Preconditions;
@@ -162,4 +164,18 @@ public final class QueryUtil {
         }
         return buf.toString();
     }
-}
+
+    public static String getExplainPlan(ResultIterator iterator) throws SQLException {
+        List<String> steps = Lists.newArrayList();
+        iterator.explain(steps);
+        StringBuilder buf = new StringBuilder();
+        for (String step : steps) {
+            buf.append(step);
+            buf.append('\n');
+        }
+        if (buf.length() > 0) {
+            buf.setLength(buf.length()-1);
+        }
+        return buf.toString();
+    }
+}
\ No newline at end of file


Mime
View raw message