Skip to content

Commit 4176929

Browse files
mykola-mokhnachmykola-mokhnach
authored
chore: Make server startup error messages more useful (#2130)
1 parent 6144fb2 commit 4176929

3 files changed

Lines changed: 241 additions & 48 deletions

File tree

‎src/main/java/io/appium/java_client/service/local/AppiumDriverLocalService.java‎

Lines changed: 76 additions & 41 deletions
Original file line numberDiff line numberDiff line change
@@ -17,8 +17,8 @@
1717
package io.appium.java_client.service.local;
1818

1919
import com.google.common.annotations.VisibleForTesting;
20+
import lombok.Getter;
2021
import lombok.SneakyThrows;
21-
import org.openqa.selenium.net.UrlChecker;
2222
import org.openqa.selenium.os.ExternalProcess;
2323
import org.openqa.selenium.remote.service.DriverService;
2424
import org.slf4j.Logger;
@@ -30,14 +30,12 @@
3030
import java.io.File;
3131
import java.io.IOException;
3232
import java.io.OutputStream;
33-
import java.net.MalformedURLException;
3433
import java.net.URL;
3534
import java.time.Duration;
3635
import java.util.ArrayList;
3736
import java.util.List;
3837
import java.util.Map;
3938
import java.util.Optional;
40-
import java.util.concurrent.TimeUnit;
4139
import java.util.concurrent.locks.ReentrantLock;
4240
import java.util.function.BiConsumer;
4341
import java.util.function.Consumer;
@@ -67,7 +65,9 @@ public final class AppiumDriverLocalService extends DriverService {
6765
private final Duration startupTimeout;
6866
private final ReentrantLock lock = new ReentrantLock(true); //uses "fair" thread ordering policy
6967
private final ListOutputStream stream = new ListOutputStream().add(System.out);
68+
private final AppiumServerAvailabilityChecker availabilityChecker = new AppiumServerAvailabilityChecker();
7069
private final URL url;
70+
@Getter
7171
private String basePath;
7272

7373
private ExternalProcess process = null;
@@ -97,10 +97,6 @@ public AppiumDriverLocalService withBasePath(String basePath) {
9797
return this;
9898
}
9999

100-
public String getBasePath() {
101-
return this.basePath;
102-
}
103-
104100
@SneakyThrows
105101
private static URL addSuffix(URL url, String suffix) {
106102
return url.toURI().resolve("." + (suffix.startsWith("/") ? suffix : "/" + suffix)).toURL();
@@ -131,36 +127,40 @@ public boolean isRunning() {
131127
}
132128

133129
try {
134-
ping(IS_RUNNING_PING_TIMEOUT);
135-
return true;
136-
} catch (UrlChecker.TimeoutException e) {
130+
return ping(IS_RUNNING_PING_TIMEOUT);
131+
} catch (AppiumServerAvailabilityChecker.ConnectionTimeout
132+
| AppiumServerAvailabilityChecker.ConnectionError e) {
137133
return false;
138-
} catch (MalformedURLException e) {
139-
throw new AppiumServerHasNotBeenStartedLocallyException(e.getMessage(), e);
134+
} catch (InterruptedException e) {
135+
throw new RuntimeException(e);
140136
}
141137
} finally {
142138
lock.unlock();
143139
}
140+
}
144141

142+
private boolean ping(Duration timeout) throws InterruptedException {
143+
var baseURL = fixBroadcastAddresses(getUrl());
144+
var statusUrl = addSuffix(baseURL, "/status");
145+
return availabilityChecker.waitUntilAvailable(statusUrl, timeout);
145146
}
146147

147-
private void ping(Duration timeout) throws UrlChecker.TimeoutException, MalformedURLException {
148-
URL baseURL = getUrl();
149-
String host = baseURL.getHost();
148+
private URL fixBroadcastAddresses(URL url) {
149+
var host = url.getHost();
150150
// The operating system will block direct access to the universal broadcast IP address
151151
if (host.equals(BROADCAST_IP4_ADDRESS)) {
152-
baseURL = replaceHost(baseURL, BROADCAST_IP4_ADDRESS, "127.0.0.1");
153-
} else if (host.equals(BROADCAST_IP6_ADDRESS)) {
154-
baseURL = replaceHost(baseURL, BROADCAST_IP6_ADDRESS, "::1");
152+
return replaceHost(url, BROADCAST_IP4_ADDRESS, "127.0.0.1");
153+
}
154+
if (host.equals(BROADCAST_IP6_ADDRESS)) {
155+
return replaceHost(url, BROADCAST_IP6_ADDRESS, "::1");
155156
}
156-
URL status = addSuffix(baseURL, "/status");
157-
new UrlChecker().waitUntilAvailable(timeout.toMillis(), TimeUnit.MILLISECONDS, status);
157+
return url;
158158
}
159159

160160
/**
161161
* Starts the defined appium server.
162162
*
163-
* @throws AppiumServerHasNotBeenStartedLocallyException If an error occurs while spawning the child process.
163+
* @throws AppiumServerHasNotBeenStartedLocallyException If an error occurs on Appium server startup.
164164
* @see #stop()
165165
*/
166166
@Override
@@ -172,40 +172,75 @@ public void start() throws AppiumServerHasNotBeenStartedLocallyException {
172172
}
173173

174174
try {
175-
ExternalProcess.Builder processBuilder = ExternalProcess.builder()
175+
var processBuilder = ExternalProcess.builder()
176176
.command(this.nodeJSExec.getCanonicalPath(), nodeJSArgs)
177177
.copyOutputTo(stream);
178178
nodeJSEnvironment.forEach(processBuilder::environment);
179179
process = processBuilder.start();
180+
} catch (IOException e) {
181+
throw new AppiumServerHasNotBeenStartedLocallyException(e);
182+
}
183+
184+
var didPingSucceed = false;
185+
try {
180186
ping(startupTimeout);
181-
} catch (Exception e) {
182-
final Optional<String> output = ofNullable(process)
183-
.map(ExternalProcess::getOutput)
184-
.filter(o -> !isNullOrEmpty(o));
185-
destroyProcess();
186-
List<String> errorLines = new ArrayList<>();
187-
errorLines.add("The local appium server has not been started");
188-
errorLines.add(String.format("Reason: %s", e.getMessage()));
189-
if (e instanceof UrlChecker.TimeoutException) {
190-
errorLines.add(String.format(
191-
"Consider increasing the server startup timeout value (currently %sms)",
192-
startupTimeout.toMillis()
193-
));
194-
}
195-
errorLines.add(
196-
String.format("Node.js executable path: %s", nodeJSExec.getAbsolutePath())
197-
);
198-
errorLines.add(String.format("Arguments: %s", nodeJSArgs));
199-
output.ifPresent(o -> errorLines.add(String.format("Output: %s", o)));
187+
didPingSucceed = true;
188+
} catch (AppiumServerAvailabilityChecker.ConnectionTimeout
189+
| AppiumServerAvailabilityChecker.ConnectionError e) {
190+
var errorLines = new ArrayList<>(generateDetailedErrorMessagePrefix(e));
191+
errorLines.addAll(retrieveServerDebugInfo());
200192
throw new AppiumServerHasNotBeenStartedLocallyException(
201193
String.join("\n", errorLines), e
202194
);
195+
} catch (InterruptedException e) {
196+
throw new RuntimeException(e);
197+
} finally {
198+
if (!didPingSucceed) {
199+
destroyProcess();
200+
}
203201
}
204202
} finally {
205203
lock.unlock();
206204
}
207205
}
208206

207+
private List<String> generateDetailedErrorMessagePrefix(RuntimeException e) {
208+
var errorLines = new ArrayList<String>();
209+
if (e instanceof AppiumServerAvailabilityChecker.ConnectionTimeout) {
210+
errorLines.add(String.format(
211+
"Appium HTTP server is not listening at %s after %s ms timeout. "
212+
+ "Consider increasing the server startup timeout value and "
213+
+ "check the server log for possible error messages occurrences.", getUrl(),
214+
((AppiumServerAvailabilityChecker.ConnectionTimeout) e).getTimeout().toMillis()
215+
));
216+
} else if (e instanceof AppiumServerAvailabilityChecker.ConnectionError) {
217+
var connectionError = (AppiumServerAvailabilityChecker.ConnectionError) e;
218+
var statusCode = connectionError.getResponseCode();
219+
var statusUrl = connectionError.getStatusUrl();
220+
var payload = connectionError.getPayload();
221+
errorLines.add(String.format(
222+
"Appium HTTP server has started and is listening although we were "
223+
+ "unable to get an OK response from %s. Make sure both the client "
224+
+ "and the server use the same base path '%s' and check the server log for possible "
225+
+ "error messages occurrences.", statusUrl, Optional.ofNullable(basePath).orElse("/")
226+
));
227+
errorLines.add(String.format("Response status code: %s", statusCode));
228+
payload.ifPresent(p -> errorLines.add(String.format("Response payload: %s", p)));
229+
}
230+
return errorLines;
231+
}
232+
233+
private List<String> retrieveServerDebugInfo() {
234+
var result = new ArrayList<String>();
235+
result.add(String.format("Node.js executable path: %s", nodeJSExec.getAbsolutePath()));
236+
result.add(String.format("Arguments: %s", nodeJSArgs));
237+
ofNullable(process)
238+
.map(ExternalProcess::getOutput)
239+
.filter(o -> !isNullOrEmpty(o))
240+
.ifPresent(o -> result.add(String.format("Server log: %s", o)));
241+
return result;
242+
}
243+
209244
/**
210245
* Stops this service is it is currently running. This method will attempt to block until the
211246
* server has been fully shutdown.

‎src/main/java/io/appium/java_client/service/local/AppiumServerAvailabilityChecker.java‎

Lines changed: 158 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,158 @@
1+
/*
2+
* Licensed under the Apache License, Version 2.0 (the "License");
3+
* you may not use this file except in compliance with the License.
4+
* See the NOTICE file distributed with this work for additional
5+
* information regarding copyright ownership.
6+
* You may obtain a copy of the License at
7+
*
8+
* http://www.apache.org/licenses/LICENSE-2.0
9+
*
10+
* Unless required by applicable law or agreed to in writing, software
11+
* distributed under the License is distributed on an "AS IS" BASIS,
12+
* WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
13+
* See the License for the specific language governing permissions and
14+
* limitations under the License.
15+
*/
16+
17+
package io.appium.java_client.service.local;
18+
19+
import lombok.Getter;
20+
21+
import java.io.BufferedReader;
22+
import java.io.IOException;
23+
import java.io.InputStream;
24+
import java.io.InputStreamReader;
25+
import java.net.HttpURLConnection;
26+
import java.net.URL;
27+
import java.time.Duration;
28+
import java.time.Instant;
29+
import java.util.LinkedList;
30+
import java.util.List;
31+
import java.util.Optional;
32+
33+
public class AppiumServerAvailabilityChecker {
34+
private static final Duration CONNECT_TIMEOUT = Duration.ofMillis(500);
35+
private static final Duration READ_TIMEOUT = Duration.ofSeconds(1);
36+
private static final Duration MAX_POLL_INTERVAL = Duration.ofMillis(320);
37+
private static final Duration MIN_POLL_INTERVAL = Duration.ofMillis(10);
38+
39+
/**
40+
* Verifies a possibility of establishing a connection
41+
* to a running Appium server.
42+
*
43+
* @param serverStatusUrl The URL of /status endpoint.
44+
* @param timeout Wait timeout. If the server responds with non-200 error
45+
* code then we are not going to retry, but throw an exception
46+
* immediately.
47+
* @return true in case of success
48+
* @throws InterruptedException If the API is interrupted
49+
* @throws ConnectionTimeout If it is not possible to successfully open
50+
* an HTTP connection to the server's /status endpoint.
51+
* @throws ConnectionError If an HTTP connection was opened successfully,
52+
* but non-200 error code was received.
53+
*/
54+
public boolean waitUntilAvailable(URL serverStatusUrl, Duration timeout) throws InterruptedException {
55+
var interval = MIN_POLL_INTERVAL;
56+
var start = Instant.now();
57+
IOException lastError = null;
58+
while (Duration.between(start, Instant.now()).compareTo(timeout) <= 0) {
59+
HttpURLConnection connection = null;
60+
try {
61+
connection = connectToUrl(serverStatusUrl);
62+
return checkResponse(connection);
63+
} catch (IOException e) {
64+
lastError = e;
65+
} finally {
66+
Optional.ofNullable(connection).ifPresent(HttpURLConnection::disconnect);
67+
}
68+
//noinspection BusyWait
69+
Thread.sleep(interval.toMillis());
70+
interval = interval.compareTo(MAX_POLL_INTERVAL) >= 0 ? interval : interval.multipliedBy(2);
71+
}
72+
throw new ConnectionTimeout(timeout, lastError);
73+
}
74+
75+
private HttpURLConnection connectToUrl(URL url) throws IOException {
76+
var connection = (HttpURLConnection) url.openConnection();
77+
connection.setConnectTimeout((int) CONNECT_TIMEOUT.toMillis());
78+
connection.setReadTimeout((int) READ_TIMEOUT.toMillis());
79+
connection.connect();
80+
return connection;
81+
}
82+
83+
private boolean checkResponse(HttpURLConnection connection) throws IOException {
84+
var responseCode = connection.getResponseCode();
85+
if (responseCode == HttpURLConnection.HTTP_OK) {
86+
return true;
87+
}
88+
var is = responseCode < HttpURLConnection.HTTP_BAD_REQUEST
89+
? connection.getInputStream()
90+
: connection.getErrorStream();
91+
throw new ConnectionError(connection.getURL(), responseCode, is);
92+
}
93+
94+
@Getter
95+
public static class ConnectionError extends RuntimeException {
96+
private static final int MAX_PAYLOAD_LEN = 1024;
97+
98+
private final URL statusUrl;
99+
private final int responseCode;
100+
private final Optional<String> payload;
101+
102+
/**
103+
* Thrown on server connection errors.
104+
*
105+
* @param statusUrl Appium server status URL.
106+
* @param responseCode The response code received from the URL above.
107+
* @param body The response body stream received from the URL above.
108+
*/
109+
public ConnectionError(URL statusUrl, int responseCode, InputStream body) {
110+
super(ConnectionError.class.getSimpleName());
111+
this.statusUrl = statusUrl;
112+
this.responseCode = responseCode;
113+
this.payload = readResponseStreamSafely(body);
114+
}
115+
116+
private static Optional<String> readResponseStreamSafely(InputStream is) {
117+
try (var br = new BufferedReader(new InputStreamReader(is))) {
118+
var result = new LinkedList<String>();
119+
String currentLine;
120+
var payloadSize = 0L;
121+
while ((currentLine = br.readLine()) != null) {
122+
result.addFirst(currentLine);
123+
payloadSize += currentLine.length();
124+
while (payloadSize > MAX_PAYLOAD_LEN && result.size() > 1) {
125+
payloadSize -= result.removeLast().length();
126+
}
127+
}
128+
var s = abbreviate(result);
129+
return s.isEmpty() ? Optional.empty() : Optional.of(s);
130+
} catch (IOException e) {
131+
return Optional.empty();
132+
}
133+
}
134+
135+
private static String abbreviate(List<String> filo) {
136+
var result = String.join("\n", filo).trim();
137+
return result.length() > MAX_PAYLOAD_LEN
138+
? "…" + result.substring(0, MAX_PAYLOAD_LEN)
139+
: result;
140+
}
141+
}
142+
143+
@Getter
144+
public static class ConnectionTimeout extends RuntimeException {
145+
private final Duration timeout;
146+
147+
/**
148+
* Thrown on server timeout errors.
149+
*
150+
* @param timeout Timeout value.
151+
* @param cause Timeout cause.
152+
*/
153+
public ConnectionTimeout(Duration timeout, Throwable cause) {
154+
super(ConnectionTimeout.class.getSimpleName(), cause);
155+
this.timeout = timeout;
156+
}
157+
}
158+
}

‎src/main/java/io/appium/java_client/service/local/AppiumServerHasNotBeenStartedLocallyException.java‎

Lines changed: 7 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -16,16 +16,16 @@
1616

1717
package io.appium.java_client.service.local;
1818

19-
2019
public class AppiumServerHasNotBeenStartedLocallyException extends RuntimeException {
20+
public AppiumServerHasNotBeenStartedLocallyException(String message, Throwable cause) {
21+
super(message, cause);
22+
}
2123

22-
private static final long serialVersionUID = 1L;
23-
24-
public AppiumServerHasNotBeenStartedLocallyException(String messege, Throwable t) {
25-
super(messege, t);
24+
public AppiumServerHasNotBeenStartedLocallyException(String message) {
25+
super(message);
2626
}
2727

28-
public AppiumServerHasNotBeenStartedLocallyException(String messege) {
29-
super(messege);
28+
public AppiumServerHasNotBeenStartedLocallyException(Throwable cause) {
29+
super(cause);
3030
}
3131
}

0 commit comments

Comments
 (0)