lens git commit: LENS-1307: LENS 1307 execute_with_timout not timing out after timeout time

[pu...@apache.org]

Repository: lens
Updated Branches:
  refs/heads/master 051ad2d3e -> 9d21940be


LENS-1307: LENS 1307 execute_with_timout not timing out after timeout time


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

Branch: refs/heads/master
Commit: 9d21940beb2489ad82fc3d54c914a92eef9b1d6a
Parents: 051ad2d
Author: Puneet Gupta <pu...@gmail.com>
Authored: Wed Sep 14 11:00:12 2016 +0530
Committer: Puneet <pu...@inmobi.com>
Committed: Wed Sep 14 11:00:12 2016 +0530

----------------------------------------------------------------------
 .../server/query/QueryExecutionServiceImpl.java | 21 +++++++++++---------
 1 file changed, 12 insertions(+), 9 deletions(-)
----------------------------------------------------------------------


http://git-wip-us.apache.org/repos/asf/lens/blob/9d21940b/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 a9aa497..dafe93d 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
@@ -2277,6 +2277,7 @@ public class QueryExecutionServiceImpl extends BaseLensService implements QueryE
     long timeoutMillis, Configuration conf) throws LensException {
     QueryHandle handle = submitQuery(ctx);
     long timeOutTime = ctx.getSubmissionTime() + timeoutMillis;
+    log.info("query {} is executed with a timeout of {} and will timeout by {}", handle, timeoutMillis, timeOutTime);
     QueryHandleWithResultSet result = new QueryHandleWithResultSet(handle);
 
     boolean isQueued = true;
@@ -2303,25 +2304,24 @@ public class QueryExecutionServiceImpl extends BaseLensService implements QueryE
     QueryCompletionListenerImpl listener = new QueryCompletionListenerImpl(handle);
     long totalWaitTime = timeOutTime - System.currentTimeMillis();
 
-    if (totalWaitTime > 0 && !queryCtx.getStatus().executed() && !queryCtx.getStatus().finished()) {
+    if (System.currentTimeMillis() < timeOutTime
+      && !queryCtx.getStatus().executed() && !queryCtx.getStatus().finished()) {
       log.info("Registering for query {} completion notification", ctx.getQueryHandleString());
       queryCtx.getSelectedDriver().registerForCompletionNotification(ctx, totalWaitTime, listener);
       try {
         // We will wait for a few millis at a time until we reach max required wait time and also check the state
         // each time we come out of the wait.
         // This is done because the registerForCompletionNotification and query execution completion can happen
-        // parallely especailly in case of drivers like JDBC and in that case completion notification may not be
-        //  received by this listener. So its better to break the wait into smaller ones.
+        // parallely especially in case of drivers like JDBC and in that case completion notification may not be
+        // received by this listener. So its better to break the wait into smaller ones.
         long waitMillisPerCheck = totalWaitTime/10;
-        waitMillisPerCheck = (waitMillisPerCheck > 500) ? 500 : waitMillisPerCheck; // Lets keep max as 500
-        long totalWaitMillisSoFar = 0;
+        waitMillisPerCheck = (waitMillisPerCheck > 500) ? 500 : waitMillisPerCheck; // Lets keep max as 0.5 sec
         synchronized (listener) {
-          while (totalWaitMillisSoFar < totalWaitTime
+          while (System.currentTimeMillis() < timeOutTime
             && !listener.querySuccessful
             && !queryCtx.getStatus().executed()
             && !queryCtx.getStatus().finished()) {
             listener.wait(waitMillisPerCheck);
-            totalWaitMillisSoFar += waitMillisPerCheck;
             if (!listener.querySuccessful) {
               //update ths status in case query is not successful yet
               queryCtx = getUpdatedQueryContext(sessionHandle, handle);
@@ -2388,9 +2388,12 @@ public class QueryExecutionServiceImpl extends BaseLensService implements QueryE
    */
   private void addQueryToCancellationPool(QueryContext queryCtx, Configuration config, long timeoutMillis) {
     if (config.getBoolean(CANCEL_QUERY_ON_TIMEOUT, DEFAULT_CANCEL_QUERY_ON_TIMEOUT)) {
-      log.info("Query {} will be cancelled as it could not be completed within the specified timeout interval {}",
-        queryCtx.getQueryHandle(), timeoutMillis);
+      log.info("Query {} could not be completed within the specified timeout interval. It will be cancelled",
+        queryCtx.getQueryHandleString());
       queryCancellationPool.submit(new CancelQueryTask(queryCtx.getQueryHandle()));
+    } else {
+      log.info("Query {} could not be completed within the specified timeout interval. Query cancellation is disabled",
+        queryCtx.getQueryHandleString());
     }
   }