You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@lens.apache.org by pr...@apache.org on 2015/08/11 14:20:44 UTC
[21/50] [abbrv] incubator-lens git commit: LENS-426 : Improve logging
in estimate path
LENS-426 : Improve logging in estimate path
Project: http://git-wip-us.apache.org/repos/asf/incubator-lens/repo
Commit: http://git-wip-us.apache.org/repos/asf/incubator-lens/commit/456690ca
Tree: http://git-wip-us.apache.org/repos/asf/incubator-lens/tree/456690ca
Diff: http://git-wip-us.apache.org/repos/asf/incubator-lens/diff/456690ca
Branch: refs/heads/current-release-line
Commit: 456690ca738a15de939edfe3ac1c2ad662ba2bac
Parents: 03444ba
Author: Amareshwari Sriramadasu <am...@apache.org>
Authored: Wed Jul 29 13:53:45 2015 +0530
Committer: Amareshwari Sriramadasu <am...@apache.org>
Committed: Wed Jul 29 13:53:45 2015 +0530
----------------------------------------------------------------------
.../lens/cube/parse/CubeQueryContext.java | 13 +-
.../lens/cube/parse/ExpressionResolver.java | 4 +-
.../lens/cube/parse/StorageTableResolver.java | 44 +++----
.../lens/cube/parse/TimerangeResolver.java | 9 +-
.../server/query/QueryExecutionServiceImpl.java | 124 +++++++++----------
.../apache/lens/server/rewrite/RewriteUtil.java | 12 +-
6 files changed, 105 insertions(+), 101 deletions(-)
----------------------------------------------------------------------
http://git-wip-us.apache.org/repos/asf/incubator-lens/blob/456690ca/lens-cube/src/main/java/org/apache/lens/cube/parse/CubeQueryContext.java
----------------------------------------------------------------------
diff --git a/lens-cube/src/main/java/org/apache/lens/cube/parse/CubeQueryContext.java b/lens-cube/src/main/java/org/apache/lens/cube/parse/CubeQueryContext.java
index 65c240a..d753e3f 100644
--- a/lens-cube/src/main/java/org/apache/lens/cube/parse/CubeQueryContext.java
+++ b/lens-cube/src/main/java/org/apache/lens/cube/parse/CubeQueryContext.java
@@ -441,8 +441,10 @@ public class CubeQueryContext implements TrackQueriedColumns {
if (!optDim.isRequiredInJoinChain) {
optDim.isRequiredInJoinChain = isRequiredInJoin;
}
- log.info("Adding optional dimension:{} optDim:{} {} isRef:{}", dim , optDim,
- (cubeCol == null ? "" : " for column:" + cubeCol), isRef);
+ if (log.isDebugEnabled()) {
+ log.debug("Adding optional dimension:{} optDim:{} {} isRef:{}", dim , optDim,
+ (cubeCol == null ? "" : " for column:" + cubeCol), isRef);
+ }
} catch (HiveException e) {
throw new SemanticException(e);
}
@@ -498,6 +500,9 @@ public class CubeQueryContext implements TrackQueriedColumns {
}
public void print() {
+ if (!log.isDebugEnabled()) {
+ return;
+ }
StringBuilder builder = new StringBuilder();
builder.append("ASTNode:" + ast.dump() + "\n");
builder.append("QB:");
@@ -578,7 +583,7 @@ public class CubeQueryContext implements TrackQueriedColumns {
builder.append("\n Destination:");
builder.append("\n\t dest expr:" + qb.getParseInfo().getDestForClause(clause).dump());
}
- log.info(builder.toString());
+ log.debug(builder.toString());
}
void printJoinTree(QBJoinTree joinTree, StringBuilder builder) {
@@ -914,7 +919,7 @@ public class CubeQueryContext implements TrackQueriedColumns {
}
dimsToQuery.putAll(pickCandidateDimsToQuery(joiningTables));
}
- log.info("Picked Fact:{} dimsToQuery: {}" + dimsToQuery, cfacts);
+ log.info("Picked Fact:{} dimsToQuery: {}", cfacts, dimsToQuery);
pickedDimTables = dimsToQuery.values();
pickedFacts = cfacts;
if (cfacts != null) {
http://git-wip-us.apache.org/repos/asf/incubator-lens/blob/456690ca/lens-cube/src/main/java/org/apache/lens/cube/parse/ExpressionResolver.java
----------------------------------------------------------------------
diff --git a/lens-cube/src/main/java/org/apache/lens/cube/parse/ExpressionResolver.java b/lens-cube/src/main/java/org/apache/lens/cube/parse/ExpressionResolver.java
index 895cb06..5bdb412 100644
--- a/lens-cube/src/main/java/org/apache/lens/cube/parse/ExpressionResolver.java
+++ b/lens-cube/src/main/java/org/apache/lens/cube/parse/ExpressionResolver.java
@@ -589,7 +589,7 @@ class ExpressionResolver implements ContextRewriter {
// But for now, they are not eligible expressions
for (TimeRange range : cubeql.getTimeRanges()) {
if (!esc.isValidInTimeRange(range)) {
- log.info("Removing expression " + esc + " as it is not valid in timerange queried");
+ log.info("Removing expression {} as it is not valid in timerange queried", esc);
iterator.remove();
removedEsc.add(esc);
removed = true;
@@ -620,7 +620,7 @@ class ExpressionResolver implements ContextRewriter {
}
}
if (toRemove) {
- log.info("Removing expression " + esc + " as its columns are unavailable in timerange queried");
+ log.info("Removing expression {} as its columns are unavailable in timerange queried", esc);
iterator.remove();
removedEsc.add(esc);
removed = true;
http://git-wip-us.apache.org/repos/asf/incubator-lens/blob/456690ca/lens-cube/src/main/java/org/apache/lens/cube/parse/StorageTableResolver.java
----------------------------------------------------------------------
diff --git a/lens-cube/src/main/java/org/apache/lens/cube/parse/StorageTableResolver.java b/lens-cube/src/main/java/org/apache/lens/cube/parse/StorageTableResolver.java
index 5fb2441..aa76c0c 100644
--- a/lens-cube/src/main/java/org/apache/lens/cube/parse/StorageTableResolver.java
+++ b/lens-cube/src/main/java/org/apache/lens/cube/parse/StorageTableResolver.java
@@ -194,7 +194,7 @@ class StorageTableResolver implements ContextRewriter {
// check if partition exists
foundPart = client.dimTableLatestPartitionExists(tableName);
if (foundPart) {
- log.info("Adding existing partition {}", StorageConstants.LATEST_PARTITION_VALUE);
+ log.debug("Adding existing partition {}", StorageConstants.LATEST_PARTITION_VALUE);
} else {
log.info("Partition {} does not exist on {}", StorageConstants.LATEST_PARTITION_VALUE, tableName);
}
@@ -286,7 +286,7 @@ class StorageTableResolver implements ContextRewriter {
storageTableMap.put(updatePeriod, storageTables);
}
isStorageAdded = true;
- log.info("Adding storage table:{} for fact:{} for update period {}", table, fact, updatePeriod);
+ log.debug("Adding storage table:{} for fact:{} for update period {}", table, fact, updatePeriod);
storageTables.add(table);
}
if (!isStorageAdded) {
@@ -542,7 +542,7 @@ class StorageTableResolver implements ContextRewriter {
log.info("No max interval for range: {} to {}", fromDate, toDate);
return false;
}
- log.info("Max interval for {} is: {}", fact, interval);
+ log.debug("Max interval for {} is: {}", fact, interval);
Set<String> storageTbls = new LinkedHashSet<String>();
storageTbls.addAll(validStorageMap.get(fact).get(interval));
@@ -554,7 +554,7 @@ class StorageTableResolver implements ContextRewriter {
part = new FactPartition(partCol, toDate, interval, null, partWhereClauseFormat);
partitions.add(part);
part.getStorageTables().add(storageTbl);
- log.info("Added continuous fact partition for storage table " + storageTbl);
+ log.info("Added continuous fact partition for storage table {}", storageTbl);
}
return true;
}
@@ -586,24 +586,24 @@ class StorageTableResolver implements ContextRewriter {
Date dt = iter.next();
Date nextDt = iter.peekNext();
FactPartition part = new FactPartition(partCol, dt, interval, null, partWhereClauseFormat);
- log.info("candidate storage tables for searching partitions: {}", storageTbls);
+ log.debug("candidate storage tables for searching partitions: {}", storageTbls);
updateFactPartitionStorageTablesFrom(fact, part, storageTbls);
- log.info("Storage tables containing Partition {} are: {}", part, part.getStorageTables());
+ log.debug("Storage tables containing Partition {} are: {}", part, part.getStorageTables());
if (part.isFound()) {
- log.info("Adding existing partition {}", part);
+ log.debug("Adding existing partition {}", part);
partitions.add(part);
- log.info("Looking for look ahead process time partitions for {}", part);
+ log.debug("Looking for look ahead process time partitions for {}", part);
if (processTimePartCol == null) {
- log.info("processTimePartCol is null");
+ log.debug("processTimePartCol is null");
} else if (partCol.equals(processTimePartCol)) {
- log.info("part column is process time col");
+ log.debug("part column is process time col");
} else if (updatePeriods.first().equals(interval)) {
- log.info("Update period is the least update period");
+ log.debug("Update period is the least update period");
} else if ((iter.getNumIters() - iter.getCounter()) > lookAheadNumParts) {
// see if this is the part of the last-n look ahead partitions
- log.info("Not a look ahead partition");
+ log.debug("Not a look ahead partition");
} else {
- log.info("Looking for look ahead process time partitions for {}", part);
+ log.debug("Looking for look ahead process time partitions for {}", part);
// check if finer partitions are required
// final partitions are required if no partitions from
// look-ahead
@@ -618,28 +618,28 @@ class StorageTableResolver implements ContextRewriter {
updateFactPartitionStorageTablesFrom(fact, processTimePartition,
part.getStorageTables());
if (processTimePartition.isFound()) {
- log.info("Finer parts not required for look-ahead partition :{}", part);
+ log.debug("Finer parts not required for look-ahead partition :{}", part);
} else {
- log.info("Looked ahead process time partition {} is not found", processTimePartition);
+ log.debug("Looked ahead process time partition {} is not found", processTimePartition);
TreeSet<UpdatePeriod> newset = new TreeSet<UpdatePeriod>();
newset.addAll(updatePeriods);
newset.remove(interval);
- log.info("newset of update periods:{}", newset);
+ log.debug("newset of update periods:{}", newset);
if (!newset.isEmpty()) {
// Get partitions for look ahead process time
- log.info("Looking for process time partitions between {} and {}", pdt, nextPdt);
+ log.debug("Looking for process time partitions between {} and {}", pdt, nextPdt);
Set<FactPartition> processTimeParts =
getPartitions(fact, TimeRange.getBuilder().fromDate(pdt).toDate(nextPdt).partitionColumn(
processTimePartCol).build(), newset, false, skipStorageCauses, missingPartitions);
- log.info("Look ahead partitions: {}", processTimeParts);
+ log.debug("Look ahead partitions: {}", processTimeParts);
TimeRange timeRange = TimeRange.getBuilder().fromDate(dt).toDate(nextDt).build();
for (FactPartition pPart : processTimeParts) {
- log.info("Looking for finer partitions in pPart: {}", pPart);
+ log.debug("Looking for finer partitions in pPart: {}", pPart);
for (Date date : timeRange.iterable(pPart.getPeriod(), 1)) {
partitions.add(new FactPartition(partCol, date, pPart.getPeriod(), pPart,
partWhereClauseFormat));
}
- log.info("added all sub partitions blindly in pPart: {}", pPart);
+ log.debug("added all sub partitions blindly in pPart: {}", pPart);
// if (!getPartitions(fact, dt, cal.getTime(), partCol, pPart, partitions,
// newset, false,
// skipStorageCauses, nonExistingParts)) {
@@ -658,7 +658,7 @@ class StorageTableResolver implements ContextRewriter {
if (!getPartitions(fact, dt, nextDt, partCol, partitions, newset, false, skipStorageCauses,
missingPartitions)) {
- log.info("Adding non existing partition {}", part);
+ log.debug("Adding non existing partition {}", part);
if (addNonExistingParts) {
// Add non existing partitions for all cases of whether we populate all non existing or not.
missingPartitions.add(part);
@@ -672,7 +672,7 @@ class StorageTableResolver implements ContextRewriter {
return false;
}
} else {
- log.info("Finer granual partitions added for {}", part);
+ log.debug("Finer granual partitions added for {}", part);
}
}
}
http://git-wip-us.apache.org/repos/asf/incubator-lens/blob/456690ca/lens-cube/src/main/java/org/apache/lens/cube/parse/TimerangeResolver.java
----------------------------------------------------------------------
diff --git a/lens-cube/src/main/java/org/apache/lens/cube/parse/TimerangeResolver.java b/lens-cube/src/main/java/org/apache/lens/cube/parse/TimerangeResolver.java
index 820d77d..91c0c75 100644
--- a/lens-cube/src/main/java/org/apache/lens/cube/parse/TimerangeResolver.java
+++ b/lens-cube/src/main/java/org/apache/lens/cube/parse/TimerangeResolver.java
@@ -175,7 +175,7 @@ class TimerangeResolver implements ContextRewriter {
ReferencedQueriedColumn refCol = refColIter.next();
for (TimeRange range : cubeql.getTimeRanges()) {
if (!refCol.col.isColumnAvailableInTimeRange(range)) {
- log.debug("The refernced column:" + refCol.col.getName() + " is not in the range queried");
+ log.debug("The refernced column: {} is not in the range queried", refCol.col.getName());
refColIter.remove();
break;
}
@@ -199,8 +199,7 @@ class TimerangeResolver implements ContextRewriter {
CubeColumn column = cubeql.getCube().getColumnByName(col);
for (TimeRange range : cubeql.getTimeRanges()) {
if (!column.isColumnAvailableInTimeRange(range)) {
- log.info("Timerange queried is not in column life for " + column
- + ", Removing join paths containing the column");
+ log.info("Timerange queried is not in column life for {}, Removing join paths containing the column", column);
// Remove join paths containing this column
Map<Aliased<Dimension>, List<SchemaGraph.JoinPath>> allPaths = joinContext.getAllPaths();
@@ -211,7 +210,7 @@ class TimerangeResolver implements ContextRewriter {
while (joinPathIterator.hasNext()) {
SchemaGraph.JoinPath path = joinPathIterator.next();
if (path.containsColumnOfTable(col, (AbstractCubeTable) cubeql.getCube())) {
- log.info("Removing join path:" + path + " as columns :" + col + " is not available in the range");
+ log.info("Removing join path: {} as columns :{} is not available in the range", path, col);
joinPathIterator.remove();
if (joinPaths.isEmpty()) {
// This dimension doesn't have any paths left
@@ -254,7 +253,7 @@ class TimerangeResolver implements ContextRewriter {
}
if (!invalidTimeRanges.isEmpty()){
cubeql.addFactPruningMsgs(cfact.fact, CandidateTablePruneCause.factNotAvailableInRange(invalidTimeRanges));
- log.info("Not considering " + cfact + " as it's not available for time ranges: " + invalidTimeRanges);
+ log.info("Not considering {} as it's not available for time ranges: {}", cfact, invalidTimeRanges);
iter.remove();
}
}
http://git-wip-us.apache.org/repos/asf/incubator-lens/blob/456690ca/lens-server/src/main/java/org/apache/lens/server/query/QueryExecutionServiceImpl.java
----------------------------------------------------------------------
diff --git a/lens-server/src/main/java/org/apache/lens/server/query/QueryExecutionServiceImpl.java b/lens-server/src/main/java/org/apache/lens/server/query/QueryExecutionServiceImpl.java
index 1316257..ae6d682 100644
--- a/lens-server/src/main/java/org/apache/lens/server/query/QueryExecutionServiceImpl.java
+++ b/lens-server/src/main/java/org/apache/lens/server/query/QueryExecutionServiceImpl.java
@@ -280,7 +280,7 @@ public class QueryExecutionServiceImpl extends BaseLensService implements QueryE
public void onEvent(DriverEvent event) {
// Need to restore session only in case of hive driver
if (event instanceof DriverSessionStarted) {
- log.info("New driver event by driver " + event.getDriver());
+ log.info("New driver event by driver {}", event.getDriver());
handleDriverSessionStart(event);
}
}
@@ -310,10 +310,10 @@ public class QueryExecutionServiceImpl extends BaseLensService implements QueryE
try {
Class<?> clazz = Class.forName(acceptorClass);
QueryAcceptor acceptor = (QueryAcceptor) clazz.newInstance();
- log.info("initialized query acceptor: " + acceptor);
+ log.info("initialized query acceptor: {}", acceptor);
queryAcceptors.add(acceptor);
} catch (Exception e) {
- log.warn("Could not load the acceptor:" + acceptorClass, e);
+ log.warn("Could not load the acceptor: {}", acceptorClass, e);
throw new LensException("Could not load acceptor" + acceptorClass, e);
}
}
@@ -350,9 +350,9 @@ public class QueryExecutionServiceImpl extends BaseLensService implements QueryE
driver.registerDriverEventListener(driverEventListener);
}
drivers.put(driverClass.getName(), driver);
- log.info("Driver for " + driverClass + " is loaded");
+ log.info("Driver for {} is loaded", driverClass);
} catch (Exception e) {
- log.warn("Could not load the driver:" + driverClass, e);
+ log.warn("Could not load the driver:{}", driverClass, e);
throw new LensException("Could not load driver " + driverClass, e);
}
}
@@ -363,7 +363,7 @@ public class QueryExecutionServiceImpl extends BaseLensService implements QueryE
Class<? extends DriverSelector> driverSelectorClass = conf.getClass(DRIVER_SELECTOR_CLASS,
MinQueryCostSelector.class,
DriverSelector.class);
- log.info("Using driver selector class: " + driverSelectorClass.getCanonicalName());
+ log.info("Using driver selector class: {}", driverSelectorClass.getCanonicalName());
driverSelector = driverSelectorClass.newInstance();
} catch (Exception e) {
throw new LensException("Couldn't instantiate driver selector class. Class name: "
@@ -688,7 +688,7 @@ public class QueryExecutionServiceImpl extends BaseLensService implements QueryE
}
logSegregationContext.setLogSegragationAndQueryId(ctx.getQueryHandleString());
- log.info("Polling status for " + ctx.getQueryHandle());
+ log.info("Polling status for {}", ctx.getQueryHandle());
try {
// session is not required to update status of the query
// don't need to wrap this with acquire/release
@@ -788,7 +788,7 @@ public class QueryExecutionServiceImpl extends BaseLensService implements QueryE
synchronized (ctx) {
QueryStatus before = ctx.getStatus();
if (!ctx.queued() && !ctx.finished() && !ctx.getDriverStatus().isFinished()) {
- log.info("Updating status for " + ctx.getQueryHandle());
+ log.info("Updating status for {}", ctx.getQueryHandle());
try {
ctx.getSelectedDriver().updateStatus(ctx);
ctx.setStatus(ctx.getDriverStatus().toQueryStatus());
@@ -796,7 +796,7 @@ public class QueryExecutionServiceImpl extends BaseLensService implements QueryE
// Driver gave exception while updating status
setFailedStatus(ctx, "Status update failed", exc.getMessage(), exc.buildLensErrorTO(this.errorCollection));
- log.error("Status update failed for " + handle, exc);
+ log.error("Status update failed for {}", handle, exc);
}
// query is successfully executed by driver and
@@ -854,7 +854,7 @@ public class QueryExecutionServiceImpl extends BaseLensService implements QueryE
case SUCCESSFUL:
return new QuerySuccess(ctx.getEndTime(), prevState, currState, query);
default:
- log.warn("Query " + query + " transitioned to " + currState + " state from " + prevState + " state");
+ log.warn("Query {} transitioned to {} state from {} state", query, currState, prevState);
return null;
}
}
@@ -883,7 +883,7 @@ public class QueryExecutionServiceImpl extends BaseLensService implements QueryE
try {
getEventService().notifyEvent(event);
} catch (LensException e) {
- log.warn("LensEventService encountered error while handling event: " + event.getEventId(), e);
+ log.warn("LensEventService encountered error while handling event: {}", event.getEventId(), e);
}
}
}
@@ -928,7 +928,7 @@ public class QueryExecutionServiceImpl extends BaseLensService implements QueryE
}
try {
lensServerDao.insertFinishedQuery(finishedQuery);
- log.info("Saved query " + finishedQuery.getHandle() + " to DB");
+ log.info("Saved query {} to DB", finishedQuery.getHandle());
} catch (Exception e) {
log.warn("Exception while purging query ", e);
finishedQueries.add(finished);
@@ -944,13 +944,13 @@ public class QueryExecutionServiceImpl extends BaseLensService implements QueryE
} catch (Exception e) {
log.warn("Exception while closing query with selected driver.", e);
}
- log.info("Purging: " + finished.getCtx().getQueryHandle());
+ log.info("Purging: {}", finished.getCtx().getQueryHandle());
allQueries.remove(finished.getCtx().getQueryHandle());
resultSets.remove(finished.getCtx().getQueryHandle());
}
fireStatusChangeEvent(finished.getCtx(),
new QueryStatus(1f, CLOSED, "Query purged", false, null, null, null), finished.getCtx().getStatus());
- log.info("Query purged: " + finished.getCtx().getQueryHandle());
+ log.info("Query purged: {}", finished.getCtx().getQueryHandle());
} catch (LensException e) {
incrCounter(QUERY_PURGER_COUNTER);
@@ -982,7 +982,7 @@ public class QueryExecutionServiceImpl extends BaseLensService implements QueryE
PreparedQueryContext prepared = preparedQueryQueue.take();
logSegregationContext.setLogSegragationAndQueryId(prepared.getQueryHandleString());
destroyPreparedQuery(prepared);
- log.info("Purged prepared query: " + prepared.getPrepareHandle());
+ log.info("Purged prepared query: {}", prepared.getPrepareHandle());
} catch (LensException e) {
incrCounter(PREPARED_QUERY_PURGER_COUNTER);
log.error("Error closing prepared query ", e);
@@ -1114,10 +1114,10 @@ public class QueryExecutionServiceImpl extends BaseLensService implements QueryE
for (Thread th : new Thread[]{querySubmitter, statusPoller, queryPurger, prepareQueryPurger}) {
try {
- log.debug("Waiting for" + th.getName());
+ log.debug("Waiting for {}", th.getName());
th.join();
} catch (InterruptedException e) {
- log.error("Error waiting for thread: " + th.getName(), e);
+ log.error("Error waiting for thread: {}", th.getName(), e);
}
}
@@ -1235,7 +1235,6 @@ public class QueryExecutionServiceImpl extends BaseLensService implements QueryE
// log operations yet to complete and check if we can proceed with at least one driver
if (!completed) {
- String debugInfo = "session: " + ctx.getLensSessionIdentifier() + " query:" + ctx.getLogHandle();
int inCompleteDrivers = 0;
for (int i = 0; i < runnables.size(); i++) {
@@ -1244,13 +1243,12 @@ public class QueryExecutionServiceImpl extends BaseLensService implements QueryE
++inCompleteDrivers;
// Cancel the corresponding task
estimateFutures.get(i).cancel(true);
- log.warn("Timeout reached for estimate task for driver " + r.getDriver() + " " + debugInfo);
+ log.warn("Timeout reached for estimate task for driver {}" + r.getDriver());
}
}
if (inCompleteDrivers == ctx.getDriverContext().getDrivers().size()) {
- throw new LensException("None of the drivers could complete within given timeout: " + estimateLatchTimeout
- + ". " + debugInfo);
+ throw new LensException("None of the drivers could complete within timeout: " + estimateLatchTimeout);
}
}
} catch (InterruptedException exc) {
@@ -1367,20 +1365,20 @@ public class QueryExecutionServiceImpl extends BaseLensService implements QueryE
if (!succeeded) {
failureCause = estimateRunnable.getFailureCause();
cause = estimateRunnable.getCause();
- log.error("Estimate failed for driver " + driver + " cause: " + failureCause);
+ log.error("Estimate failed for driver {} cause: {}", driver, failureCause);
}
estimateGauge.markSuccess();
} else {
- log.error("Estimate skipped since rewrite failed for driver " + driver + " cause: " + failureCause);
+ log.error("Estimate skipped since rewrite failed for driver {} cause: {}", driver, failureCause);
}
} catch (Throwable th) {
- log.error("Error computing estimate for driver " + driver, th);
+ log.error("Error computing estimate for driver {}", driver, th);
} finally {
completed = true;
try {
release(ctx.getLensSessionIdentifier());
} catch (LensException e) {
- log.error("Could not release session: " + ctx.getLensSessionIdentifier(), e);
+ log.error("Could not release session: {}", ctx.getLensSessionIdentifier(), e);
} finally {
estimateCompletionLatch.countDown();
}
@@ -1547,7 +1545,7 @@ public class QueryExecutionServiceImpl extends BaseLensService implements QueryE
throws LensException {
PreparedQueryContext prepared = null;
try {
- log.info("ExplainAndPrepare: " + sessionHandle.toString() + " query: " + query);
+ log.info("ExplainAndPrepare: session:{} query: {}", sessionHandle, query);
acquire(sessionHandle);
prepared = prepareQuery(sessionHandle, query, lensConf, SubmitOp.EXPLAIN_AND_PREPARE);
prepared.setQueryName(queryName);
@@ -1585,7 +1583,7 @@ public class QueryExecutionServiceImpl extends BaseLensService implements QueryE
public QueryHandle executePrepareAsync(LensSessionHandle sessionHandle, QueryPrepareHandle prepareHandle,
LensConf conf, String queryName) throws LensException {
try {
- log.info("ExecutePrepareAsync: " + sessionHandle.toString() + " query:" + prepareHandle.getPrepareHandleId());
+ log.info("ExecutePrepareAsync: session:{} prepareHandle:{}", sessionHandle, prepareHandle.getPrepareHandleId());
acquire(sessionHandle);
PreparedQueryContext pctx = getPreparedQueryContext(sessionHandle, prepareHandle);
Configuration qconf = getLensConf(sessionHandle, conf);
@@ -1613,8 +1611,8 @@ public class QueryExecutionServiceImpl extends BaseLensService implements QueryE
public QueryHandleWithResultSet executePrepare(LensSessionHandle sessionHandle, QueryPrepareHandle prepareHandle,
long timeoutMillis, LensConf conf, String queryName) throws LensException {
try {
- log.info("ExecutePrepare: " + sessionHandle.toString() + " query:" + prepareHandle.getPrepareHandleId()
- + " timeout:" + timeoutMillis);
+ log.info("ExecutePrepare: session:{} prepareHandle: {} timeout:{}", sessionHandle,
+ prepareHandle.getPrepareHandleId(), timeoutMillis);
acquire(sessionHandle);
PreparedQueryContext pctx = getPreparedQueryContext(sessionHandle, prepareHandle);
Configuration qconf = getLensConf(sessionHandle, conf);
@@ -1641,7 +1639,7 @@ public class QueryExecutionServiceImpl extends BaseLensService implements QueryE
public QueryHandle executeAsync(LensSessionHandle sessionHandle, String query, LensConf conf, String queryName)
throws LensException {
try {
- log.info("ExecuteAsync: " + sessionHandle.toString() + " query: " + query);
+ log.info("ExecuteAsync: session:{} query: {}", sessionHandle, query);
acquire(sessionHandle);
Configuration qconf = getLensConf(sessionHandle, conf);
accept(query, qconf, SubmitOp.EXECUTE);
@@ -1701,7 +1699,7 @@ public class QueryExecutionServiceImpl extends BaseLensService implements QueryE
log.debug("Added to Queued Queries:{}", ctx.getQueryHandleString());
allQueries.put(ctx.getQueryHandle(), ctx);
fireStatusChangeEvent(ctx, ctx.getStatus(), before);
- log.info("Returning handle " + ctx.getQueryHandle().getHandleId());
+ log.info("Returning handle {}", ctx.getQueryHandle().getHandleId());
return ctx.getQueryHandle();
}
@@ -1715,7 +1713,7 @@ public class QueryExecutionServiceImpl extends BaseLensService implements QueryE
public boolean updateQueryConf(LensSessionHandle sessionHandle, QueryHandle queryHandle, LensConf newconf)
throws LensException {
try {
- log.info("UpdateQueryConf:" + sessionHandle.toString() + " query: " + queryHandle);
+ log.info("UpdateQueryConf: session:{} queryHandle: {}", sessionHandle, queryHandle);
acquire(sessionHandle);
QueryContext ctx = getQueryContext(sessionHandle, queryHandle);
if (ctx != null && (ctx.queued())) {
@@ -1740,7 +1738,7 @@ public class QueryExecutionServiceImpl extends BaseLensService implements QueryE
public boolean updateQueryConf(LensSessionHandle sessionHandle, QueryPrepareHandle prepareHandle, LensConf newconf)
throws LensException {
try {
- log.info("UpdatePreparedQueryConf:" + sessionHandle.toString() + " query: " + prepareHandle);
+ log.info("UpdatePreparedQueryConf: session:{} prepareHandle:{}", sessionHandle, prepareHandle);
acquire(sessionHandle);
PreparedQueryContext ctx = getPreparedQueryContext(sessionHandle, prepareHandle);
ctx.updateConf(newconf.getProperties());
@@ -1844,7 +1842,7 @@ public class QueryExecutionServiceImpl extends BaseLensService implements QueryE
public QueryHandleWithResultSet execute(LensSessionHandle sessionHandle, String query, long timeoutMillis,
LensConf conf, String queryName) throws LensException {
try {
- log.info("Blocking execute " + sessionHandle.toString() + " query: " + query + " timeout: " + timeoutMillis);
+ log.info("Blocking execute session:{} query: {} timeout: {}", sessionHandle, query, timeoutMillis);
acquire(sessionHandle);
Configuration qconf = getLensConf(sessionHandle, conf);
accept(query, qconf, SubmitOp.EXECUTE);
@@ -1952,7 +1950,7 @@ public class QueryExecutionServiceImpl extends BaseLensService implements QueryE
public void onCompletion(QueryHandle handle) {
synchronized (this) {
succeeded = true;
- log.info("Query " + handle + " with time out succeeded");
+ log.info("Query {} with time out succeeded", handle);
this.notify();
}
}
@@ -1967,7 +1965,7 @@ public class QueryExecutionServiceImpl extends BaseLensService implements QueryE
public void onError(QueryHandle handle, String error) {
synchronized (this) {
succeeded = false;
- log.info("Query " + handle + " with time out failed");
+ log.info("Query {} with time out failed", handle);
this.notify();
}
}
@@ -1984,7 +1982,7 @@ public class QueryExecutionServiceImpl extends BaseLensService implements QueryE
public QueryResultSetMetadata getResultSetMetadata(LensSessionHandle sessionHandle, QueryHandle queryHandle)
throws LensException {
try {
- log.info("GetResultSetMetadata: " + sessionHandle.toString() + " query: " + queryHandle);
+ log.info("GetResultSetMetadata: session:{} query: {}", sessionHandle, queryHandle);
acquire(sessionHandle);
LensResultSet resultSet = getResultset(queryHandle);
if (resultSet != null) {
@@ -2008,7 +2006,7 @@ public class QueryExecutionServiceImpl extends BaseLensService implements QueryE
public QueryResult fetchResultSet(LensSessionHandle sessionHandle, QueryHandle queryHandle, long startIndex,
int fetchSize) throws LensException {
try {
- log.info("FetchResultSet:" + sessionHandle.toString() + " query:" + queryHandle);
+ log.info("FetchResultSet: session:{} query:{}", sessionHandle, queryHandle);
acquire(sessionHandle);
return getResultset(queryHandle).toQueryResult();
} finally {
@@ -2025,7 +2023,7 @@ public class QueryExecutionServiceImpl extends BaseLensService implements QueryE
@Override
public void closeResultSet(LensSessionHandle sessionHandle, QueryHandle queryHandle) throws LensException {
try {
- log.info("CloseResultSet:" + sessionHandle.toString() + " query: " + queryHandle);
+ log.info("CloseResultSet:session:{} query:{}", sessionHandle, queryHandle);
acquire(sessionHandle);
resultSets.remove(queryHandle);
// Ask driver to close result set
@@ -2044,7 +2042,7 @@ public class QueryExecutionServiceImpl extends BaseLensService implements QueryE
@Override
public boolean cancelQuery(LensSessionHandle sessionHandle, QueryHandle queryHandle) throws LensException {
try {
- log.info("CancelQuery: " + sessionHandle.toString() + " query:" + queryHandle);
+ log.info("CancelQuery: session:{} query:{}", sessionHandle, queryHandle);
acquire(sessionHandle);
QueryContext ctx = getQueryContext(sessionHandle, queryHandle);
@@ -2086,7 +2084,7 @@ public class QueryExecutionServiceImpl extends BaseLensService implements QueryE
try {
status = StringUtils.isBlank(state) ? null : Status.valueOf(state);
} catch (IllegalArgumentException e) {
- throw new BadRequestException("Bad state argument passed, possible" + " values are " + Status.values(), e);
+ throw new BadRequestException("Bad state argument passed, possible values are " + Status.values(), e);
}
boolean filterByStatus = status != null;
queryName = queryName.toLowerCase();
@@ -2118,7 +2116,7 @@ public class QueryExecutionServiceImpl extends BaseLensService implements QueryE
List<QueryHandle> persistedQueries = lensServerDao.findFinishedQueries(state, userName, queryName, fromDate,
toDate);
if (persistedQueries != null && !persistedQueries.isEmpty()) {
- log.info("Adding persisted queries " + persistedQueries.size());
+ log.info("Adding persisted queries {}", persistedQueries.size());
all.addAll(persistedQueries);
}
}
@@ -2195,7 +2193,7 @@ public class QueryExecutionServiceImpl extends BaseLensService implements QueryE
@Override
public boolean destroyPrepared(LensSessionHandle sessionHandle, QueryPrepareHandle prepared) throws LensException {
try {
- log.info("DestroyPrepared: " + sessionHandle.toString() + " query:" + prepared);
+ log.info("DestroyPrepared: {} prepareHandle:{}", sessionHandle, prepared);
acquire(sessionHandle);
destroyPreparedQuery(getPreparedQueryContext(sessionHandle, prepared));
return true;
@@ -2229,7 +2227,7 @@ public class QueryExecutionServiceImpl extends BaseLensService implements QueryE
public QueryCost estimate(final String requestId, LensSessionHandle sessionHandle, String query, LensConf lensConf)
throws LensException {
try {
- log.info("Estimate: " + sessionHandle.toString() + " query:" + query);
+ log.info("Estimate: session :{} query:{}", sessionHandle, query);
acquire(sessionHandle);
Configuration qconf = getLensConf(sessionHandle, lensConf);
ExplainQueryContext estimateQueryContext = new ExplainQueryContext(requestId, query,
@@ -2253,7 +2251,7 @@ public class QueryExecutionServiceImpl extends BaseLensService implements QueryE
public QueryPlan explain(final String requestId, LensSessionHandle sessionHandle, String query, LensConf lensConf)
throws LensException {
try {
- log.info("Explain: " + sessionHandle.toString() + " query:" + query);
+ log.info("Explain: session:{} query:{}", sessionHandle, query);
acquire(sessionHandle);
Configuration qconf = getLensConf(sessionHandle, lensConf);
ExplainQueryContext explainQueryContext = new ExplainQueryContext(requestId, query,
@@ -2340,10 +2338,10 @@ public class QueryExecutionServiceImpl extends BaseLensService implements QueryE
driver = (LensDriver) driverCls.newInstance();
driver.configure(conf);
} catch (Exception e) {
- log.error("Could not instantiate driver:" + driverClsName, e);
+ log.error("Could not instantiate driver:{}", driverClsName, e);
throw new IOException(e);
}
- log.info("Driver state for " + driverClsName + " will be ignored");
+ log.info("Driver state for {} will be ignored", driverClsName);
}
driver.readExternal(in);
}
@@ -2398,7 +2396,7 @@ public class QueryExecutionServiceImpl extends BaseLensService implements QueryE
}
}
queuedQueries.addAll(allRestoredQueuedQueries);
- log.info("Recovered " + allQueries.size() + " queries");
+ log.info("Recovered {} queries", allQueries.size());
}
}
@@ -2433,7 +2431,7 @@ public class QueryExecutionServiceImpl extends BaseLensService implements QueryE
}
}
}
- log.info("Persisted " + allQueries.size() + " queries");
+ log.info("Persisted {} queries", allQueries.size());
}
}
@@ -2627,24 +2625,24 @@ public class QueryExecutionServiceImpl extends BaseLensService implements QueryE
List<ResourceEntry> resources = session.getLensSessionPersistInfo().getResources();
if (resources != null && !resources.isEmpty()) {
for (ResourceEntry resource : resources) {
- log.info("Restoring resource " + resource + " for session " + lensSession);
+ log.info("Restoring resource {} for session {}", resource, lensSession);
String command = "add " + resource.getType().toLowerCase() + " " + resource.getLocation();
try {
// Execute add resource query in blocking mode
hiveDriver.execute(createResourceQuery(command, sessionHandle, hiveDriver));
resource.restoredResource();
- log.info("Restored resource " + resource + " for session " + lensSession);
+ log.info("Restored resource {} for session {}", resource, lensSession);
} catch (Exception exc) {
- log.error("Unable to add resource " + resource + " for session " + lensSession, exc);
+ log.error("Unable to add resource {} for session {}", resource, lensSession, exc);
}
}
} else {
- log.info("No resources to restore for session " + lensSession);
+ log.info("No resources to restore for session {}", lensSession);
}
} catch (Exception e) {
log.warn(
- "Lens session went away! " + lensSession + " driver session: "
- + ((DriverSessionStarted) event).getDriverSessionID(), e);
+ "Lens session went away! {} driver session: {}", lensSession,
+ ((DriverSessionStarted) event).getDriverSessionID(), e);
} finally {
release(sessionHandle);
}
@@ -2676,8 +2674,8 @@ public class QueryExecutionServiceImpl extends BaseLensService implements QueryE
Collection<ResourceEntry> dbResources = session.getDBResources(ctx.getDatabase());
if (CollectionUtils.isNotEmpty(dbResources)) {
- log.info("Proceeding to add resources for DB "
- + session.getCurrentDatabase() + " for query " + ctx.getLogHandle() + " resources: " + dbResources);
+ log.info("Proceeding to add resources for DB {} for query {} resources: {}", session.getCurrentDatabase(),
+ ctx.getLogHandle(), dbResources);
List<ResourceEntry> failedDBResources = addResources(dbResources, sessionHandle, hiveDriver);
Iterator<ResourceEntry> itr = dbResources.iterator();
@@ -2688,8 +2686,7 @@ public class QueryExecutionServiceImpl extends BaseLensService implements QueryE
}
}
} else {
- log.info("No need to add DB resources for session: " + sessionIdentifier
- + " db= " + session.getCurrentDatabase());
+ log.info("No need to add DB resources for session: {} db= {}", sessionIdentifier, session.getCurrentDatabase());
}
hiveDriver.setResourcesAddedForSession(sessionIdentifier, ctx.getDatabase());
}
@@ -2697,8 +2694,8 @@ public class QueryExecutionServiceImpl extends BaseLensService implements QueryE
// Get pending session resources which needed to be added for this database
Collection<ResourceEntry> pendingResources =
session.getPendingSessionResourcesForDatabase(ctx.getDatabase());
- log.info("Adding pending " + pendingResources.size() + " session resources for session " + sessionIdentifier
- + " for database " + ctx.getDatabase());
+ log.info("Adding pending {} session resources for session {} for database {}", pendingResources.size(),
+ sessionIdentifier, ctx.getDatabase());
List<ResourceEntry> failedResources = addResources(pendingResources, sessionHandle, hiveDriver);
// Mark added resources so that we don't add them again. If any of the resources failed
// to be added, then they will be added again
@@ -2726,8 +2723,7 @@ public class QueryExecutionServiceImpl extends BaseLensService implements QueryE
addSingleResourceToHive(hiveDriver, res, sessionHandle);
} catch (LensException exc) {
failedResources.add(res);
- log.error("Error adding resources for session "
- + sessionHandle.getPublicId().toString() + " resources: " + res.getLocation(), exc.getCause());
+ log.error("Error adding resources for session {} resources: {}", sessionHandle, res.getLocation(), exc);
}
}
return failedResources;
@@ -2744,7 +2740,7 @@ public class QueryExecutionServiceImpl extends BaseLensService implements QueryE
}
String command = "add " + res.getType().toLowerCase() + " " + uri;
driver.execute(createResourceQuery(command, sessionHandle, driver));
- log.info("Added resource to hive driver for session " + sessionIdentifier + " cmd: " + command);
+ log.info("Added resource to hive driver for session {} cmd: {}", sessionIdentifier, command);
}
private boolean removeFromLaunchedQueries(final QueryContext finishedQuery) {
http://git-wip-us.apache.org/repos/asf/incubator-lens/blob/456690ca/lens-server/src/main/java/org/apache/lens/server/rewrite/RewriteUtil.java
----------------------------------------------------------------------
diff --git a/lens-server/src/main/java/org/apache/lens/server/rewrite/RewriteUtil.java b/lens-server/src/main/java/org/apache/lens/server/rewrite/RewriteUtil.java
index 52edffc..5844010 100644
--- a/lens-server/src/main/java/org/apache/lens/server/rewrite/RewriteUtil.java
+++ b/lens-server/src/main/java/org/apache/lens/server/rewrite/RewriteUtil.java
@@ -91,7 +91,9 @@ public final class RewriteUtil {
throws SemanticException, LensException {
ASTNode ast = HQLParser.parseHQL(query, conf);
- log.debug("User query AST:{}", ast.dump());
+ if (log.isDebugEnabled()) {
+ log.debug("User query AST:{}", ast.dump());
+ }
List<CubeQueryInfo> cubeQueries = new ArrayList<CubeQueryInfo>();
findCubePositions(ast, cubeQueries, query);
for (CubeQueryInfo cqi : cubeQueries) {
@@ -112,7 +114,7 @@ public final class RewriteUtil {
throws SemanticException {
int childCount = ast.getChildCount();
if (ast.getToken() != null) {
- if (ast.getChild(0) != null) {
+ if (log.isDebugEnabled() && ast.getChild(0) != null) {
log.debug("First child: {} Type:{}", ast.getChild(0), ((ASTNode) ast.getChild(0)).getToken().getType());
}
if (ast.getToken().getType() == HiveParser.TOK_QUERY
@@ -150,7 +152,9 @@ public final class RewriteUtil {
"UNION ALL");
}
}
- log.debug("Adding cqi {} query:{}", cqi, originalQuery.substring(cqi.startPos, cqi.endPos));
+ if (log.isDebugEnabled()) {
+ log.debug("Adding cqi {} query:{}", cqi, originalQuery.substring(cqi.startPos, cqi.endPos));
+ }
cubeQueries.add(cqi);
} else {
for (int childPos = 0; childPos < childCount; ++childPos) {
@@ -325,7 +329,7 @@ public final class RewriteUtil {
toHQLGauge.markSuccess();
qIndex++;
- log.debug("Rewritten query:", hqlQuery);
+ log.debug("Rewritten query:{}", hqlQuery);
builder.append(hqlQuery);
start = cqi.endPos;