chore: Make server startup error messages more useful (#2130)

mykola-mokhnach · web-flow · commit 41769295f6af · 2024-03-10T13:52:37.000+01:00
diff --git a/src/main/java/io/appium/java_client/service/local/AppiumDriverLocalService.java b/src/main/java/io/appium/java_client/service/local/AppiumDriverLocalService.java
@@ -17,8 +17,8 @@
 package io.appium.java_client.service.local;
 
 import com.google.common.annotations.VisibleForTesting;
+import lombok.Getter;
 import lombok.SneakyThrows;
-import org.openqa.selenium.net.UrlChecker;
 import org.openqa.selenium.os.ExternalProcess;
 import org.openqa.selenium.remote.service.DriverService;
 import org.slf4j.Logger;
@@ -30,14 +30,12 @@
 import java.io.File;
 import java.io.IOException;
 import java.io.OutputStream;
-import java.net.MalformedURLException;
 import java.net.URL;
 import java.time.Duration;
 import java.util.ArrayList;
 import java.util.List;
 import java.util.Map;
 import java.util.Optional;
-import java.util.concurrent.TimeUnit;
 import java.util.concurrent.locks.ReentrantLock;
 import java.util.function.BiConsumer;
 import java.util.function.Consumer;
@@ -67,7 +65,9 @@ public final class AppiumDriverLocalService extends DriverService {
     private final Duration startupTimeout;
     private final ReentrantLock lock = new ReentrantLock(true); //uses "fair" thread ordering policy
     private final ListOutputStream stream = new ListOutputStream().add(System.out);
+    private final AppiumServerAvailabilityChecker availabilityChecker = new AppiumServerAvailabilityChecker();
     private final URL url;
+    @Getter
     private String basePath;
 
     private ExternalProcess process = null;
@@ -97,10 +97,6 @@ public AppiumDriverLocalService withBasePath(String basePath) {
         return this;
     }
 
-    public String getBasePath() {
-        return this.basePath;
-    }
-
     @SneakyThrows
     private static URL addSuffix(URL url, String suffix) {
         return url.toURI().resolve("." + (suffix.startsWith("/") ? suffix : "/" + suffix)).toURL();
@@ -131,36 +127,40 @@ public boolean isRunning() {
             }
 
             try {
-                ping(IS_RUNNING_PING_TIMEOUT);
-                return true;
-            } catch (UrlChecker.TimeoutException e) {
+                return ping(IS_RUNNING_PING_TIMEOUT);
+            } catch (AppiumServerAvailabilityChecker.ConnectionTimeout
+                     | AppiumServerAvailabilityChecker.ConnectionError e) {
                 return false;
-            } catch (MalformedURLException e) {
-                throw new AppiumServerHasNotBeenStartedLocallyException(e.getMessage(), e);
+            } catch (InterruptedException e) {
+                throw new RuntimeException(e);
             }
         } finally {
             lock.unlock();
         }
+    }
 
+    private boolean ping(Duration timeout) throws InterruptedException {
+        var baseURL = fixBroadcastAddresses(getUrl());
+        var statusUrl = addSuffix(baseURL, "/status");
+        return availabilityChecker.waitUntilAvailable(statusUrl, timeout);
     }
 
-    private void ping(Duration timeout) throws UrlChecker.TimeoutException, MalformedURLException {
-        URL baseURL = getUrl();
-        String host = baseURL.getHost();
+    private URL fixBroadcastAddresses(URL url) {
+        var host = url.getHost();
         // The operating system will block direct access to the universal broadcast IP address
         if (host.equals(BROADCAST_IP4_ADDRESS)) {
-            baseURL = replaceHost(baseURL, BROADCAST_IP4_ADDRESS, "127.0.0.1");
-        } else if (host.equals(BROADCAST_IP6_ADDRESS)) {
-            baseURL = replaceHost(baseURL, BROADCAST_IP6_ADDRESS, "::1");
+            return replaceHost(url, BROADCAST_IP4_ADDRESS, "127.0.0.1");
+        }
+        if (host.equals(BROADCAST_IP6_ADDRESS)) {
+            return replaceHost(url, BROADCAST_IP6_ADDRESS, "::1");
         }
-        URL status = addSuffix(baseURL, "/status");
-        new UrlChecker().waitUntilAvailable(timeout.toMillis(), TimeUnit.MILLISECONDS, status);
+        return url;
     }
 
     /**
      * Starts the defined appium server.
      *
-     * @throws AppiumServerHasNotBeenStartedLocallyException If an error occurs while spawning the child process.
+     * @throws AppiumServerHasNotBeenStartedLocallyException If an error occurs on Appium server startup.
      * @see #stop()
      */
     @Override
@@ -172,40 +172,75 @@ public void start() throws AppiumServerHasNotBeenStartedLocallyException {
             }
 
             try {
-                ExternalProcess.Builder processBuilder = ExternalProcess.builder()
+                var processBuilder = ExternalProcess.builder()
                         .command(this.nodeJSExec.getCanonicalPath(), nodeJSArgs)
                         .copyOutputTo(stream);
                 nodeJSEnvironment.forEach(processBuilder::environment);
                 process = processBuilder.start();
+            } catch (IOException e) {
+                throw new AppiumServerHasNotBeenStartedLocallyException(e);
+            }
+
+            var didPingSucceed = false;
+            try {
                 ping(startupTimeout);
-            } catch (Exception e) {
-                final Optional<String> output = ofNullable(process)
-                        .map(ExternalProcess::getOutput)
-                        .filter(o -> !isNullOrEmpty(o));
-                destroyProcess();
-                List<String> errorLines = new ArrayList<>();
-                errorLines.add("The local appium server has not been started");
-                errorLines.add(String.format("Reason: %s", e.getMessage()));
-                if (e instanceof UrlChecker.TimeoutException) {
-                    errorLines.add(String.format(
-                            "Consider increasing the server startup timeout value (currently %sms)",
-                            startupTimeout.toMillis()
-                    ));
-                }
-                errorLines.add(
-                        String.format("Node.js executable path: %s", nodeJSExec.getAbsolutePath())
-                );
-                errorLines.add(String.format("Arguments: %s", nodeJSArgs));
-                output.ifPresent(o -> errorLines.add(String.format("Output: %s", o)));
+                didPingSucceed = true;
+            } catch (AppiumServerAvailabilityChecker.ConnectionTimeout
+                     | AppiumServerAvailabilityChecker.ConnectionError e) {
+                var errorLines = new ArrayList<>(generateDetailedErrorMessagePrefix(e));
+                errorLines.addAll(retrieveServerDebugInfo());
                 throw new AppiumServerHasNotBeenStartedLocallyException(
                         String.join("\n", errorLines), e
                 );
+            } catch (InterruptedException e) {
+                throw new RuntimeException(e);
+            } finally {
+                if (!didPingSucceed) {
+                    destroyProcess();
+                }
             }
         } finally {
             lock.unlock();
         }
     }
 
+    private List<String> generateDetailedErrorMessagePrefix(RuntimeException e) {
+        var errorLines = new ArrayList<String>();
+        if (e instanceof AppiumServerAvailabilityChecker.ConnectionTimeout) {
+            errorLines.add(String.format(
+                    "Appium HTTP server is not listening at %s after %s ms timeout. "
+                            + "Consider increasing the server startup timeout value and "
+                            + "check the server log for possible error messages occurrences.", getUrl(),
+                    ((AppiumServerAvailabilityChecker.ConnectionTimeout) e).getTimeout().toMillis()
+            ));
+        } else if (e instanceof AppiumServerAvailabilityChecker.ConnectionError) {
+            var connectionError = (AppiumServerAvailabilityChecker.ConnectionError) e;
+            var statusCode = connectionError.getResponseCode();
+            var statusUrl = connectionError.getStatusUrl();
+            var payload = connectionError.getPayload();
+            errorLines.add(String.format(
+                    "Appium HTTP server has started and is listening although we were "
+                            + "unable to get an OK response from %s. Make sure both the client "
+                            + "and the server use the same base path '%s' and check the server log for possible "
+                            + "error messages occurrences.", statusUrl, Optional.ofNullable(basePath).orElse("/")
+            ));
+            errorLines.add(String.format("Response status code: %s", statusCode));
+            payload.ifPresent(p -> errorLines.add(String.format("Response payload: %s", p)));
+        }
+        return errorLines;
+    }
+
+    private List<String> retrieveServerDebugInfo() {
+        var result = new ArrayList<String>();
+        result.add(String.format("Node.js executable path: %s", nodeJSExec.getAbsolutePath()));
+        result.add(String.format("Arguments: %s", nodeJSArgs));
+        ofNullable(process)
+                .map(ExternalProcess::getOutput)
+                .filter(o -> !isNullOrEmpty(o))
+                .ifPresent(o -> result.add(String.format("Server log: %s", o)));
+        return result;
+    }
+
     /**
      * Stops this service is it is currently running. This method will attempt to block until the
      * server has been fully shutdown.
diff --git a/src/main/java/io/appium/java_client/service/local/AppiumServerAvailabilityChecker.java b/src/main/java/io/appium/java_client/service/local/AppiumServerAvailabilityChecker.java
@@ -0,0 +1,158 @@
+/*
+ * Licensed under the Apache License, Version 2.0 (the "License");
+ * you may not use this file except in compliance with the License.
+ * See the NOTICE file distributed with this work for additional
+ * information regarding copyright ownership.
+ * 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 io.appium.java_client.service.local;
+
+import lombok.Getter;
+
+import java.io.BufferedReader;
+import java.io.IOException;
+import java.io.InputStream;
+import java.io.InputStreamReader;
+import java.net.HttpURLConnection;
+import java.net.URL;
+import java.time.Duration;
+import java.time.Instant;
+import java.util.LinkedList;
+import java.util.List;
+import java.util.Optional;
+
+public class AppiumServerAvailabilityChecker {
+    private static final Duration CONNECT_TIMEOUT = Duration.ofMillis(500);
+    private static final Duration READ_TIMEOUT = Duration.ofSeconds(1);
+    private static final Duration MAX_POLL_INTERVAL = Duration.ofMillis(320);
+    private static final Duration MIN_POLL_INTERVAL = Duration.ofMillis(10);
+
+    /**
+     * Verifies a possibility of establishing a connection
+     * to a running Appium server.
+     *
+     * @param serverStatusUrl The URL of /status endpoint.
+     * @param timeout Wait timeout. If the server responds with non-200 error
+     *                code then we are not going to retry, but throw an exception
+     *                immediately.
+     * @return true in case of success
+     * @throws InterruptedException If the API is interrupted
+     * @throws ConnectionTimeout If it is not possible to successfully open
+     *         an HTTP connection to the server's /status endpoint.
+     * @throws ConnectionError If an HTTP connection was opened successfully,
+     *         but non-200 error code was received.
+     */
+    public boolean waitUntilAvailable(URL serverStatusUrl, Duration timeout) throws InterruptedException {
+        var interval = MIN_POLL_INTERVAL;
+        var start = Instant.now();
+        IOException lastError = null;
+        while (Duration.between(start, Instant.now()).compareTo(timeout) <= 0) {
+            HttpURLConnection connection = null;
+            try {
+                connection = connectToUrl(serverStatusUrl);
+                return checkResponse(connection);
+            } catch (IOException e) {
+                lastError = e;
+            } finally {
+                Optional.ofNullable(connection).ifPresent(HttpURLConnection::disconnect);
+            }
+            //noinspection BusyWait
+            Thread.sleep(interval.toMillis());
+            interval = interval.compareTo(MAX_POLL_INTERVAL) >= 0 ? interval : interval.multipliedBy(2);
+        }
+        throw new ConnectionTimeout(timeout, lastError);
+    }
+
+    private HttpURLConnection connectToUrl(URL url) throws IOException {
+        var connection = (HttpURLConnection) url.openConnection();
+        connection.setConnectTimeout((int) CONNECT_TIMEOUT.toMillis());
+        connection.setReadTimeout((int) READ_TIMEOUT.toMillis());
+        connection.connect();
+        return connection;
+    }
+
+    private boolean checkResponse(HttpURLConnection connection) throws IOException {
+        var responseCode = connection.getResponseCode();
+        if (responseCode == HttpURLConnection.HTTP_OK) {
+            return true;
+        }
+        var is = responseCode < HttpURLConnection.HTTP_BAD_REQUEST
+                ? connection.getInputStream()
+                : connection.getErrorStream();
+        throw new ConnectionError(connection.getURL(), responseCode, is);
+    }
+
+    @Getter
+    public static class ConnectionError extends RuntimeException {
+        private static final int MAX_PAYLOAD_LEN = 1024;
+
+        private final URL statusUrl;
+        private final int responseCode;
+        private final Optional<String> payload;
+
+        /**
+         * Thrown on server connection errors.
+         *
+         * @param statusUrl Appium server status URL.
+         * @param responseCode The response code received from the URL above.
+         * @param body The response body stream received from the URL above.
+         */
+        public ConnectionError(URL statusUrl, int responseCode, InputStream body) {
+            super(ConnectionError.class.getSimpleName());
+            this.statusUrl = statusUrl;
+            this.responseCode = responseCode;
+            this.payload = readResponseStreamSafely(body);
+        }
+
+        private static Optional<String> readResponseStreamSafely(InputStream is) {
+            try (var br = new BufferedReader(new InputStreamReader(is))) {
+                var result = new LinkedList<String>();
+                String currentLine;
+                var payloadSize = 0L;
+                while ((currentLine = br.readLine()) != null) {
+                    result.addFirst(currentLine);
+                    payloadSize += currentLine.length();
+                    while (payloadSize > MAX_PAYLOAD_LEN && result.size() > 1) {
+                        payloadSize -= result.removeLast().length();
+                    }
+                }
+                var s = abbreviate(result);
+                return s.isEmpty() ? Optional.empty() : Optional.of(s);
+            } catch (IOException e) {
+                return Optional.empty();
+            }
+        }
+
+        private static String abbreviate(List<String> filo) {
+            var result = String.join("\n", filo).trim();
+            return result.length() > MAX_PAYLOAD_LEN
+                ? "…" + result.substring(0, MAX_PAYLOAD_LEN)
+                : result;
+        }
+    }
+
+    @Getter
+    public static class ConnectionTimeout extends RuntimeException {
+        private final Duration timeout;
+
+        /**
+         * Thrown on server timeout errors.
+         *
+         * @param timeout Timeout value.
+         * @param cause Timeout cause.
+         */
+        public ConnectionTimeout(Duration timeout, Throwable cause) {
+            super(ConnectionTimeout.class.getSimpleName(), cause);
+            this.timeout = timeout;
+        }
+    }
+}
diff --git a/src/main/java/io/appium/java_client/service/local/AppiumServerHasNotBeenStartedLocallyException.java b/src/main/java/io/appium/java_client/service/local/AppiumServerHasNotBeenStartedLocallyException.java
@@ -16,16 +16,16 @@
 
 package io.appium.java_client.service.local;
 
-
 public class AppiumServerHasNotBeenStartedLocallyException extends RuntimeException {
+    public AppiumServerHasNotBeenStartedLocallyException(String message, Throwable cause) {
+        super(message, cause);
+    }
 
-    private static final long serialVersionUID = 1L;
-
-    public AppiumServerHasNotBeenStartedLocallyException(String messege, Throwable t) {
-        super(messege, t);
+    public AppiumServerHasNotBeenStartedLocallyException(String message) {
+        super(message);
     }
 
-    public AppiumServerHasNotBeenStartedLocallyException(String messege) {
-        super(messege);
+    public AppiumServerHasNotBeenStartedLocallyException(Throwable cause) {
+        super(cause);
     }
 }
