Significantly improved logic for restarting grid nodes, to prevent orphan session in the new session queue and chances of a bad TestSlot that cannot be cleaned up.

dima-groupon · dima-groupon · commit 09971282cfe1 · 2014-10-21T17:56:45.000-04:00
diff --git a/CHANGELOG.txt b/CHANGELOG.txt
@@ -1,3 +1,4 @@
+1.6.1 - [BUG] Significantly improved logic for restarting grid nodes, to prevent orphan session in the new session queue and chances of a bad TestSlot that cannot be cleaned up.
 1.6.0 - Better session tracking, on the /session_history endpoint
       - [BUG] fixing inability to start the grid hub because the webdriver 2.44 has broken JSON dependency
       - Adding a machine view at http://localhost:3000
diff --git a/SeleniumGridExtras/pom.xml b/SeleniumGridExtras/pom.xml
@@ -6,7 +6,7 @@
 
     <groupId>com.groupon.selenium-grid-extras</groupId>
     <artifactId>SeleniumGridExtras</artifactId>
-    <version>1.6.0-SNAPSHOT</version>
+    <version>1.6.1-SNAPSHOT</version>
 
     <repositories>
         <repository>
diff --git a/SeleniumGridExtras/src/main/java/com/groupon/seleniumgridextras/config/FirstTimeRunConfig.java b/SeleniumGridExtras/src/main/java/com/groupon/seleniumgridextras/config/FirstTimeRunConfig.java
@@ -107,7 +107,7 @@ private static void askToRecordVideo(Config defaultConfig) {
       logger.info("Setting node to record videos");
 
       answer =
-          askQuestion("How many videos should node keep in history?",
+          askQuestion("How many videos should node keep in threads?",
                       "10");
 
       logger.info("Will keep " + answer + " videos");
diff --git a/SeleniumGridExtras/src/main/java/com/groupon/seleniumgridextras/grid/proxies/SetupTeardownProxy.java b/SeleniumGridExtras/src/main/java/com/groupon/seleniumgridextras/grid/proxies/SetupTeardownProxy.java
@@ -41,7 +41,7 @@
 import com.google.gson.JsonObject;
 import com.google.gson.JsonParser;
 
-import com.groupon.seleniumgridextras.grid.proxies.sessions.history.SessionHistoryThreadPool;
+import com.groupon.seleniumgridextras.grid.proxies.sessions.threads.NodeRestartCallable;
 import com.groupon.seleniumgridextras.utilities.HttpUtility;
 import com.groupon.seleniumgridextras.utilities.JsonWireCommandTranslator;
 
@@ -65,6 +65,8 @@
 import java.util.LinkedList;
 import java.util.List;
 import java.util.Map;
+import java.util.concurrent.ExecutorService;
+import java.util.concurrent.Executors;
 import java.util.concurrent.Future;
 
 import javax.servlet.http.HttpServletRequest;
@@ -76,6 +78,7 @@ public class SetupTeardownProxy extends DefaultRemoteProxy implements TestSessio
     private boolean available = true;
     private boolean restarting = false;
     private List<String> sessionsRecording = new LinkedList<String>();
+    protected static ExecutorService cachedPool;
 
     private static Logger logger = Logger.getLogger(SetupTeardownProxy.class);
 
@@ -85,31 +88,6 @@ public SetupTeardownProxy(RegistrationRequest request, Registry registry) {
         writeProxyLog("Attaching a node: " + getHost());
     }
 
-    @Override
-    public TestSession getNewSession(Map<String, Object> requestedCapability) {
-        synchronized (this) {
-            if (timeToReboot() && !this.isBusy()) {
-                setAvailable(false);
-                setRestarting(false);
-//        killBrowserForCurrentSession();
-                stopGridNode();
-                rebootGridExtrasNode();
-            }
-
-            if (isAvailable()) {
-                TestSession session = super.getNewSession(requestedCapability);
-                if (session == null) {
-                    return null;
-                } else {
-                    SessionHistoryThreadPool.registerNewSession(session);
-                    return session;
-                }
-            } else {
-                return null;
-            }
-
-        }
-    }
 
     @Override
     public void beforeCommand(TestSession session, HttpServletRequest request,
@@ -137,6 +115,12 @@ public void afterSession(TestSession session) {
         super.afterSession(session);
         stopVideoRecording(session.getExternalKey().getKey());
         callRemoteGridExtrasAsync("teardown", new HashMap<String, String>());
+
+        if (cachedPool == null) {
+            cachedPool = Executors.newCachedThreadPool();
+        }
+
+        cachedPool.submit(new NodeRestartCallable(this, session));
     }
 
     private boolean alreadyRecordingCurrentSession(String session) {
@@ -183,13 +167,13 @@ private void updateLastCommand(String session, HttpServletRequest request) {
         callRemoteGridExtrasAsync("video", params);
     }
 
-    protected void stopGridNode() {
+    public void stopGridNode() {
         writeProxyLog("Asking " + getHost() + " to stop grid node politely");
         writeProxyLog(callRemoteGridExtras("stop_grid?port=5555"));
         unregister();
     }
 
-    private void rebootGridExtrasNode() {
+    public void rebootGridExtrasNode() {
         writeProxyLog("Asking SeleniumGridExtras to reboot " + getHost());
         writeProxyLog(callRemoteGridExtras("reboot"));
     }
@@ -224,7 +208,8 @@ private Future<String> callRemoteGridExtrasAsync(String action, Map<String, Stri
         return returnedFuture;
     }
 
-    private JsonObject callRemoteGridExtras(String action) {
+
+    public JsonObject callRemoteGridExtras(String action) {
         String returnedString;
 
         try {
@@ -237,13 +222,13 @@ private JsonObject callRemoteGridExtras(String action) {
             return (JsonObject) j.parse(returnedString);
 
         } catch (MalformedURLException e) {
-            writeProxyLog(e.toString());
-            e.printStackTrace();
+            logger.error("Attempt to contact node has failed with " + e.getMessage(), e);
         } catch (ProtocolException e) {
-            writeProxyLog(e.toString());
-            e.printStackTrace();
+            logger.error("Attempt to contact node has failed with " + e.getMessage(), e);
         } catch (IOException e) {
-            e.printStackTrace();
+            logger.error("Attempt to contact node has failed with " + e.getMessage(), e);
+        } catch (Exception e) {
+            logger.error("Attempt to contact node has failed with " + e.getMessage(), e);
         }
 
         return null;
@@ -257,35 +242,11 @@ protected boolean isAvailable() {
         return this.available;
     }
 
-    protected void setAvailable(boolean available) {
+    public void setAvailable(boolean available) {
         this.available = available;
     }
 
-    protected boolean timeToReboot() {
-        JsonObject status = callRemoteGridExtras("grid_status");
-
-        boolean nodeRunning = status.get("node_running").getAsBoolean();
-        int sessionsStarted = status.get("node_sessions_started").getAsInt();
-        int sessionLimit = status.get("node_sessions_limit").getAsInt();
-
-        if (!nodeRunning) {
-            writeProxyLog("The grid node on " + getHost() + " does not seem to be running");
-        } else if (sessionLimit == 0) {
-            return false;
-        } else if (sessionsStarted >= sessionLimit) {
-            System.out
-                    .println("Node " + getHost() + " has reached " + sessionsStarted + " of " + sessionLimit
-                            + " test session, time to reboot");
-        } else {
-            return false;
-
-        }
-        setAvailable(false);
-        return true;
-    }
-
     public void unregister() {
-        writeProxyLog("Sending Un register command for " + getHost());
         addNewEvent(new RemoteUnregisterException("Unregistering the node."));
     }
 
diff --git a/SeleniumGridExtras/src/main/java/com/groupon/seleniumgridextras/grid/proxies/sessions/threads/NodeRestartCallable.java b/SeleniumGridExtras/src/main/java/com/groupon/seleniumgridextras/grid/proxies/sessions/threads/NodeRestartCallable.java
@@ -0,0 +1,96 @@
+package com.groupon.seleniumgridextras.grid.proxies.sessions.threads;
+
+import com.google.gson.JsonObject;
+import com.groupon.seleniumgridextras.grid.proxies.SetupTeardownProxy;
+import org.apache.log4j.Logger;
+import org.openqa.grid.internal.TestSession;
+import org.openqa.grid.selenium.proxy.DefaultRemoteProxy;
+
+import java.util.concurrent.Callable;
+
+
+public class NodeRestartCallable implements Callable {
+
+    public static final int TIME_FOR_PROXY_TO_FREEUP = 2000;
+    private static Logger logger = Logger.getLogger(NodeRestartCallable.class);
+
+    protected SetupTeardownProxy proxy;
+    protected TestSession session;
+
+    public NodeRestartCallable(SetupTeardownProxy proxy, TestSession session) {
+        this.proxy = proxy;
+        this.session = session;
+    }
+
+
+    @Override
+    public String call() throws Exception {
+        //TODO: This is a huge improvment in the reboot logic compared to how it used to be. But this method needs clean up done by fresh eyes
+
+        try {
+            //Giving the proxy a couple of seconds to recover post session. This also gives us opportunity to check if the new build is trying to pick it up
+            logger.info(String.format("Giving %s proxy %s ms to free up", this.proxy.getId(), TIME_FOR_PROXY_TO_FREEUP));
+            Thread.sleep(TIME_FOR_PROXY_TO_FREEUP);
+        } catch (InterruptedException e) {
+            logger.error(e);
+        }
+
+        try {
+
+
+
+            if (this.proxy.isBusy() || this.proxy.getRegistry().getNewSessionRequestCount() != 0){
+                String message = String.format("Proxy %s is currently %s busy and has there are %s items in the queue. Will not attempt to reboot node until the grid is free",
+                        this.proxy.getId(),
+                        (this.proxy.isBusy() ? "" : "not"),
+                        this.proxy.getRegistry().getNewSessionRequestCount());
+
+                logger.info(message);
+                return message;
+            }
+
+            JsonObject status = proxy.callRemoteGridExtras("grid_status");
+
+            if (status == null) {
+                String message = String.format("Problem communicating with %s, will not attempt to reboot", proxy.getRemoteHost().getHost());
+                logger.warn(message);
+                return message;
+            }
+
+            int sessionsStarted = status.get("node_sessions_started").getAsInt();
+            int sessionLimit = status.get("node_sessions_limit").getAsInt();
+
+            if (sessionLimit == 0) {
+                String message = String.format("Node %s with proxy %s is set to never reboot, skipping this step",
+                        proxy.getRemoteHost().getHost(), proxy.getId());
+                logger.info(message);
+                return message;
+            }
+
+            if (sessionsStarted >= sessionLimit) {
+                String message = String.format("Node %s has executed has executed %s sessions, the limit is %s so it is time to reboot it",
+                        proxy.getRemoteHost().getHost(), sessionsStarted, sessionLimit);
+
+                logger.info(message);
+                proxy.setAvailable(false);
+                proxy.setRestarting(false);
+                proxy.stopGridNode();
+                proxy.rebootGridExtrasNode();
+
+
+                return message;
+            }
+        } catch (Exception e) {
+            //Capture any unexpected exception and print it to log. Currently the hub will completely ignore any
+            //Exception, this way at least we can try to debug it.
+            String message = String.format("Something didn't go right when trying to reboot node %s : %s",
+                    proxy.getRemoteHost().getHost(), e.getMessage());
+            logger.error(message, e);
+            return message;
+        }
+
+        return ""; //Should never get to this point
+    }
+
+
+}
diff --git a/SeleniumGridExtras/src/main/java/com/groupon/seleniumgridextras/grid/proxies/sessions/threads/SessionHistoryCallable.java b/SeleniumGridExtras/src/main/java/com/groupon/seleniumgridextras/grid/proxies/sessions/threads/SessionHistoryCallable.java
@@ -1,4 +1,4 @@
-package com.groupon.seleniumgridextras.grid.proxies.sessions.history;
+package com.groupon.seleniumgridextras.grid.proxies.sessions.threads;
 
 import com.groupon.seleniumgridextras.config.DefaultConfig;
 import com.groupon.seleniumgridextras.loggers.SessionHistoryLog;
@@ -58,7 +58,7 @@ public String call() throws Exception {
             SessionHistoryLog.setOutputDir(DefaultConfig.SESSION_LOG_DIRECTORY);
             SessionHistoryLog.newSession(this.session.getSlot().getRemoteURL().getHost(), sessionDetails);
         } catch (Exception e) {
-            logger.error("Something went wrong when gathering information for new session history", e);
+            logger.error("Something went wrong when gathering information for new session threads", e);
         }
         return sessionDetails.toString();
     }
diff --git a/SeleniumGridExtras/src/main/java/com/groupon/seleniumgridextras/grid/proxies/sessions/threads/SessionHistoryThreadPool.java b/SeleniumGridExtras/src/main/java/com/groupon/seleniumgridextras/grid/proxies/sessions/threads/SessionHistoryThreadPool.java
@@ -1,4 +1,4 @@
-package com.groupon.seleniumgridextras.grid.proxies.sessions.history;
+package com.groupon.seleniumgridextras.grid.proxies.sessions.threads;
 
 import org.apache.log4j.Logger;
 import org.openqa.grid.internal.TestSession;
diff --git a/SeleniumGridExtras/src/main/java/com/groupon/seleniumgridextras/loggers/NodeSessionHistory.java b/SeleniumGridExtras/src/main/java/com/groupon/seleniumgridextras/loggers/NodeSessionHistory.java
@@ -46,7 +46,7 @@ public void backupToFile(){
         try {
             FileIOUtility.writePrettyJsonToFile(outputFile, sessions, false);
         } catch (IOException e) {
-            logger.warn("Unable to backup session history to file for " + outputFile.getAbsolutePath());
+            logger.warn("Unable to backup session threads to file for " + outputFile.getAbsolutePath());
             logger.warn(e);
             e.printStackTrace();  //To change body of catch statement use File | Settings | File Templates.
         }
diff --git a/SeleniumGridExtras/src/main/java/com/groupon/seleniumgridextras/loggers/SessionHistoryLog.java b/SeleniumGridExtras/src/main/java/com/groupon/seleniumgridextras/loggers/SessionHistoryLog.java
@@ -53,7 +53,7 @@ protected static void resetMemory() {
             history = new HashMap<String, NodeSessionHistory>();
         } else {
             //delete all reference to objects to make objects ready for garbage collection
-            //Doing it this way, just in case the history map is refered to anywhere, and does not get garbage collected
+            //Doing it this way, just in case the threads map is refered to anywhere, and does not get garbage collected
             //This is done in hopes of reducing memory bloat, if a JVM expert is reading this, please fix it!
             //-Love, Dima
             history.clear();
diff --git a/SeleniumGridExtras/src/main/java/com/groupon/seleniumgridextras/tasks/SessionHistory.java b/SeleniumGridExtras/src/main/java/com/groupon/seleniumgridextras/tasks/SessionHistory.java
@@ -21,7 +21,7 @@ public SessionHistory() {
 //        params.addProperty(JsonCodec.WebDriver.Grid.HOST, "Host on which the session is kept");
 
 
-        addResponseDescription(JsonCodec.WebDriver.Grid.LOGS, "An array with session history per node");
+        addResponseDescription(JsonCodec.WebDriver.Grid.LOGS, "An array with session threads per node");
 
 
         setAcceptedParams(params);
@@ -39,7 +39,7 @@ public JsonObject execute() {
         try {
             getJsonResponse().addNestedMapValues(JsonCodec.WebDriver.Grid.LOGS, SessionHistoryLog.getTodaysHistoryAsMap());
         } catch (Exception e) {
-            String error = String.format("Something went wrong when reading session history\n%s",
+            String error = String.format("Something went wrong when reading session threads\n%s",
                     Throwables.getStackTraceAsString(e));
            logger.error(error);
             getJsonResponse().addKeyValues(JsonCodec.ERROR, error);
diff --git a/SeleniumGridExtras/src/main/java/com/groupon/seleniumgridextras/tasks/config/TaskDescriptions.java b/SeleniumGridExtras/src/main/java/com/groupon/seleniumgridextras/tasks/config/TaskDescriptions.java
@@ -123,7 +123,7 @@ public static class Description {
                 UPDATE_NODE_CONFIG =
                 "Send the current config to the central location to be stored";
         public static final String VIDEO = "Starts and stops video recording";
-        public static final String SESSION_HISTORY = "Displays the history of test session on all nodes or per node basis";
+        public static final String SESSION_HISTORY = "Displays the threads of test session on all nodes or per node basis";
         public static final String IE_MIXED_CONTENT = "Changes mixed content for Internet Explorer on/off. No param for current status";
     }
 
diff --git a/SeleniumGridExtras/src/test/ruby/rubygems/specification.rb b/SeleniumGridExtras/src/test/ruby/rubygems/specification.rb
@@ -43,7 +43,7 @@ class Gem::Specification
   #
   #   spec   ruby
   #    ver    ver yyyy-mm-dd description
-  #     -1 <0.8.0            pre-spec-version-history
+  #     -1 <0.8.0            pre-spec-version-threads
   #      1  0.8.0 2004-08-01 Deprecated "test_suite_file" for "test_files"
   #                          "test_file=x" is a shortcut for "test_files=[x]"
   #      2  0.9.5 2007-10-01 Added "required_rubygems_version"

Original file line number	Diff line number	Diff line change
`@@ -1,3 +1,4 @@`
	`1`	`+1.6.1 - [BUG] Significantly improved logic for restarting grid nodes, to prevent orphan session in the new session queue and chances of a bad TestSlot that cannot be cleaned up.`
`1`	`2`	`1.6.0 - Better session tracking, on the /session_history endpoint`
`2`	`3`	`- [BUG] fixing inability to start the grid hub because the webdriver 2.44 has broken JSON dependency`
`3`	`4`	`- Adding a machine view at http://localhost:3000`
Original file line number	Diff line number	Diff line change
`@@ -1,4 +1,4 @@`
`1`		`-package com.groupon.seleniumgridextras.grid.proxies.sessions.history;`
	`1`	`+package com.groupon.seleniumgridextras.grid.proxies.sessions.threads;`
`2`	`2`
`3`	`3`	`import com.groupon.seleniumgridextras.config.DefaultConfig;`
`4`	`4`	`import com.groupon.seleniumgridextras.loggers.SessionHistoryLog;`
`@@ -58,7 +58,7 @@ public String call() throws Exception {`
`58`	`58`	`SessionHistoryLog.setOutputDir(DefaultConfig.SESSION_LOG_DIRECTORY);`
`59`	`59`	`SessionHistoryLog.newSession(this.session.getSlot().getRemoteURL().getHost(), sessionDetails);`
`60`	`60`	`} catch (Exception e) {`
`61`		`- logger.error("Something went wrong when gathering information for new session history", e);`
	`61`	`+ logger.error("Something went wrong when gathering information for new session threads", e);`
`62`	`62`	`}`
`63`	`63`	`return sessionDetails.toString();`
`64`	`64`	`}`
Original file line number	Diff line number	Diff line change
`@@ -46,7 +46,7 @@ public void backupToFile(){`
`46`	`46`	`try {`
`47`	`47`	`FileIOUtility.writePrettyJsonToFile(outputFile, sessions, false);`
`48`	`48`	`} catch (IOException e) {`
`49`		`- logger.warn("Unable to backup session history to file for " + outputFile.getAbsolutePath());`
	`49`	`+ logger.warn("Unable to backup session threads to file for " + outputFile.getAbsolutePath());`
`50`	`50`	`logger.warn(e);`
`51`	`51`	`e.printStackTrace(); //To change body of catch statement use File \| Settings \| File Templates.`
`52`	`52`	`}`