Get log capture working in the new servlet.

Hardly elegant, but it now appears to capture a lot
of the same information, so we're making progress.

Author: shs96c

java/server/src/org/openqa/selenium/remote/server/BeginSession.java

@@ -23,14 +23,20 @@
 
 import com.google.common.collect.ImmutableMap;
 
+import com.sun.javafx.util.Logging;
+
 import org.openqa.selenium.SessionNotCreatedException;
+import org.openqa.selenium.logging.LogType;
+import org.openqa.selenium.logging.LoggingPreferences;
 import org.openqa.selenium.remote.BeanToJsonConverter;
 import org.openqa.selenium.remote.http.HttpRequest;
 import org.openqa.selenium.remote.http.HttpResponse;
+import org.openqa.selenium.remote.server.log.LoggingManager;
 
 import java.io.IOException;
 import java.io.InputStreamReader;
 import java.io.Reader;
+import java.util.logging.Level;
 
 class BeginSession implements CommandHandler {
 
@@ -63,6 +69,13 @@ public void execute(HttpRequest req, HttpResponse resp) throws IOException {
       allSessions.put(session);
     }
 
+    // Force capture of server-side logs since we don't have easy access to the request from the
+    // local end.
+    LoggingPreferences loggingPrefs = new LoggingPreferences();
+    loggingPrefs.enable(LogType.SERVER, Level.INFO);
+    LoggingManager.perSessionLogHandler().configureLogging(loggingPrefs);
+    LoggingManager.perSessionLogHandler().attachToCurrentThread(session.getId());
+
     Object toConvert;
       switch (session.getDownstreamDialect()) {
         case OSS:

java/server/src/org/openqa/selenium/remote/server/WebDriverServlet.java

@@ -23,19 +23,27 @@
 import static org.openqa.selenium.remote.CapabilityType.BROWSER_NAME;
 import static org.openqa.selenium.remote.server.DriverServlet.SESSION_TIMEOUT_PARAMETER;
 
+import com.google.common.base.Splitter;
 import com.google.common.net.HttpHeaders;
 import com.google.common.net.MediaType;
 
+import org.openqa.selenium.logging.LoggingHandler;
+import org.openqa.selenium.remote.SessionId;
+import org.openqa.selenium.remote.server.log.LoggingManager;
+import org.openqa.selenium.remote.server.log.PerSessionLogHandler;
 import org.openqa.selenium.remote.server.xdrpc.CrossDomainRpc;
 import org.openqa.selenium.remote.server.xdrpc.CrossDomainRpcLoader;
 
 import java.io.ByteArrayInputStream;
 import java.io.IOException;
+import java.util.List;
 import java.util.concurrent.ExecutionException;
 import java.util.concurrent.ExecutorService;
 import java.util.concurrent.Executors;
 import java.util.concurrent.Future;
 import java.util.concurrent.TimeoutException;
+import java.util.logging.Handler;
+import java.util.logging.Logger;
 
 import javax.servlet.ServletException;
 import javax.servlet.ServletInputStream;
@@ -46,6 +54,7 @@
 
 public class WebDriverServlet extends HttpServlet {
 
+  private static final Logger LOG = Logger.getLogger(WebDriverServlet.class.getName());
   public static final String ACTIVE_SESSIONS_KEY = WebDriverServlet.class.getName() + ".sessions";
 
   private static final String CROSS_DOMAIN_RPC_PATH = "/xdrpc";
@@ -57,6 +66,7 @@ public class WebDriverServlet extends HttpServlet {
 
   @Override
   public void init() throws ServletException {
+    configureLogging();
     log("Initialising WebDriverServlet");
 
     String value = getInitParameter(SESSION_TIMEOUT_PARAMETER);
@@ -73,6 +83,22 @@ public void init() throws ServletException {
     handlers = new AllHandlers(allSessions);
   }
 
+  private synchronized Logger configureLogging() {
+    Logger logger = Logger.getGlobal();
+    logger.addHandler(LoggingHandler.getInstance());
+
+    Logger rootLogger = Logger.getLogger("");
+    boolean sessionLoggerAttached = false;
+    for (Handler handler : rootLogger.getHandlers()) {
+      sessionLoggerAttached |= handler instanceof PerSessionLogHandler;
+    }
+    if (!sessionLoggerAttached) {
+      rootLogger.addHandler(LoggingManager.perSessionLogHandler());
+    }
+
+    return logger;
+  }
+
   @Override
   protected void service(HttpServletRequest request, HttpServletResponse response)
       throws IOException, ServletException {
@@ -165,25 +191,38 @@ public ServletInputStream getInputStream() throws IOException {
   private void handle(HttpServletRequest req, HttpServletResponse resp) {
     CommandHandler handler = handlers.match(req);
 
-    log("Found handler: " + handler);
+    LOG.info("Found handler: " + handler);
 
     boolean invalidateSession =
         handler instanceof ActiveSession &&
         "DELETE".equalsIgnoreCase(req.getMethod()) &&
         req.getPathInfo().equals("/session/" + ((ActiveSession) handler).getId());
 
     Future<?> execution = executor.submit(() -> {
+      // Clear the logs
+      PerSessionLogHandler sessionLogHandler = LoggingManager.perSessionLogHandler();
+      sessionLogHandler.clearThreadTempLogs();
+
       try {
         if (handler instanceof ActiveSession) {
+          sessionLogHandler .attachToCurrentThread(((ActiveSession) handler).getId());
           ActiveSession session = (ActiveSession) handler;
           Thread.currentThread().setName(String.format(
               "Handler thread for session %s (%s)",
               session.getId(),
               session.getCapabilities().get(BROWSER_NAME)));
         } else {
+          // All commands that take a session id expect that as the path fragment immediately after "/session".
+          List<String> fragments = Splitter.on('/').limit(4).splitToList(req.getPathInfo());
+          if (fragments.size() > 2) {
+            if ("session".equals(fragments.get(1))) {
+              sessionLogHandler.attachToCurrentThread(new SessionId(fragments.get(2)));
+            }
+          }
+
           Thread.currentThread().setName(req.getPathInfo());
         }
-        log(String.format(
+        LOG.info(String.format(
             "%s: Executing %s on %s (handler: %s)",
             Thread.currentThread().getName(),
             req.getMethod(),
@@ -197,6 +236,7 @@ private void handle(HttpServletRequest req, HttpServletResponse resp) {
         throw new RuntimeException(e);
       } finally {
         Thread.currentThread().setName("Selenium WebDriver Servlet - Quiescent Thread");
+        sessionLogHandler.detachFromCurrentThread();
       }
     });
 

java/server/src/org/openqa/selenium/remote/server/commandhandler/GetLogTypes.java

@@ -1,7 +1,24 @@
+// Licensed to the Software Freedom Conservancy (SFC) under one
+// or more contributor license agreements.  See the NOTICE file
+// distributed with this work for additional information
+// regarding copyright ownership.  The SFC licenses this file
+// to you under the Apache License, Version 2.0 (the
+// "License"); you may not use this file except in compliance
+// with the License.  You may obtain a copy of the License at
+//
+//   http://www.apache.org/licenses/LICENSE-2.0
+//
+// Unless required by applicable law or agreed to in writing,
+// software distributed under the License is distributed on an
+// "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
+// KIND, either express or implied.  See the License for the
+// specific language governing permissions and limitations
+// under the License.
+
 package org.openqa.selenium.remote.server.commandhandler;
 
 import static java.net.HttpURLConnection.HTTP_OK;
-import static org.openqa.selenium.remote.http.HttpMethod.POST;
+import static org.openqa.selenium.remote.http.HttpMethod.GET;
 
 import com.google.common.collect.ImmutableSet;
 import com.google.gson.Gson;
@@ -35,7 +52,7 @@ public GetLogTypes(Gson gson, ActiveSession session) {
   @Override
   public void execute(HttpRequest req, HttpResponse resp) throws IOException {
     // Try going upstream first. It's okay if this fails.
-    HttpRequest upReq = new HttpRequest(POST, String.format("/session/%s/log", session.getId()));
+    HttpRequest upReq = new HttpRequest(GET, String.format("/session/%s/log/types", session.getId()));
     HttpResponse upRes = new HttpResponse();
     session.execute(upReq, upRes);
 

java/server/src/org/openqa/selenium/remote/server/commandhandler/GetLogsOfType.java

@@ -17,6 +17,9 @@
 
 package org.openqa.selenium.remote.server.commandhandler;
 
+import static java.nio.charset.StandardCharsets.UTF_8;
+import static org.openqa.selenium.remote.http.HttpMethod.POST;
+
 import com.google.gson.Gson;
 
 import org.openqa.selenium.logging.LogEntries;
@@ -44,11 +47,15 @@ public GetLogsOfType(Gson gson, ActiveSession session) {
 
   @Override
   public void execute(HttpRequest req, HttpResponse resp) throws IOException {
-    Map<?, ?> args = gson.fromJson(req.getContentString(), Map.class);
+    String originalPayload = req.getContentString();
+
+    Map<?, ?> args = gson.fromJson(originalPayload, Map.class);
     String type = (String) args.get("type");
 
     if (!LogType.SERVER.equals(type)) {
-      session.execute(req, resp);
+      HttpRequest upReq = new HttpRequest(POST, String.format("/session/%s/log", session.getId()));
+      upReq.setContent(originalPayload.getBytes(UTF_8));
+      session.execute(upReq, resp);
       return;
     }