fix: Properly log request errors
MODIFY
lib/jsonwp-proxy/proxy.js
lib/jsonwp-proxy/proxy.js
@@ -118,9 +118,34 @@ class JWProxy {
return proxyBase + remainingUrl;
}
+ syncDownstreamProtocol (resBodyObj, isSessionCreationRequest) {
+ if (!this.downstreamProtocol) {
+ this.downstreamProtocol = this.getProtocolFromResBody(resBodyObj);
+ log.debug(`Determined the downstream protocol as '${this.downstreamProtocol}'`);
+ } else if (isSessionCreationRequest) {
+ // It might be that we proxy API calls to the downstream driver
+ // without creating a session first
+ // and it responds using the default proto,
+ // but then after createSession request is sent the internal proto is changed
+ // to the other one based on the actually provided caps
+ const previousValue = this.downstreamProtocol;
+ this.downstreamProtocol = this.getProtocolFromResBody(resBodyObj);
+ if (previousValue && previousValue !== this.downstreamProtocol) {
+ log.debug(`Updated the downstream protocol to '${this.downstreamProtocol}' ` +
+ `as per session creation request`);
+ } else {
+ log.debug(`Determined the downstream protocol as '${this.downstreamProtocol}' ` +
+ `per session creation request`);
+ }
+ }
+ }
+
async proxy (url, method, body = null) {
method = method.toUpperCase();
const newUrl = this.getUrlForProxy(url);
+ const truncateBody = (content) => _.truncate(
+ _.isString(content) ? content : JSON.stringify(content),
+ { length: LOG_OBJ_LENGTH });
const reqOpts = {
agent: false,
url: newUrl,
@@ -139,9 +164,7 @@ class JWProxy {
try {
reqOpts.json = JSON.parse(body);
} catch (e) {
- throw new Error('Cannot interpret the request body as valid JSON: ' +
- _.truncate(_.isString(body) ? body : JSON.stringify(body),
- {length: LOG_OBJ_LENGTH}));
+ throw new Error(`Cannot interpret the request body as valid JSON: ${truncateBody(body)}`);
}
} else {
reqOpts.json = body;
@@ -154,8 +177,7 @@ class JWProxy {
}
log.debug(`Proxying [${method} ${url || '/'}] to [${method} ${newUrl}] ` +
- (body ? `with body: ${_.truncate(_.isString(body) ? body : JSON.stringify(body),
- {length: LOG_OBJ_LENGTH})}` : 'with no body'));
+ (body ? `with body: ${truncateBody(body)}` : 'with no body'));
const throwProxyError = (error) => {
const message = `The request to ${url} has failed`;
@@ -165,6 +187,7 @@ class JWProxy {
err.statusCode = 500;
throw err;
};
+ let isResponseLogged = false;
try {
const res = await this.request(reqOpts);
// `res.body` might be really big
@@ -175,34 +198,13 @@ class JWProxy {
// If it cannot be coerced to an object then the response is wrong
throwProxyError(res.body);
}
- log.debug(`Got response with status ${res.statusCode}: ` +
- _.truncate(_.isString(res.body) ? res.body : JSON.stringify(res.body), {
- length: LOG_OBJ_LENGTH,
- })
- );
+ log.debug(`Got response with status ${res.statusCode}: ${truncateBody(res.body)}`);
+ isResponseLogged = true;
const isSessionCreationRequest = /\/session$/.test(url) && method === 'POST';
if (isSessionCreationRequest && res.statusCode === 200) {
this.sessionId = resBodyObj.sessionId;
}
- if (!this.downstreamProtocol) {
- this.downstreamProtocol = this.getProtocolFromResBody(resBodyObj);
- log.debug(`Determined the downstream protocol as '${this.downstreamProtocol}'`);
- } else if (isSessionCreationRequest) {
- // It might be that we proxy API calls to the downstream driver
- // without creating a session first
- // and it responds using the default proto,
- // but then after createSession request is sent the internal proto is changed
- // to the other one based on the actually provided caps
- const previousValue = this.downstreamProtocol;
- this.downstreamProtocol = this.getProtocolFromResBody(resBodyObj);
- if (previousValue && previousValue !== this.downstreamProtocol) {
- log.debug(`Updated the downstream protocol to '${this.downstreamProtocol}' ` +
- `as per session creation request`);
- } else {
- log.debug(`Determined the downstream protocol as '${this.downstreamProtocol}' ` +
- `per session creation request`);
- }
- }
+ this.syncDownstreamProtocol(resBodyObj, isSessionCreationRequest);
if (res.statusCode < 400 && this.downstreamProtocol === MJSONWP &&
_.has(resBodyObj, 'status') && parseInt(resBodyObj.status, 10) !== 0) {
// Some servers, like chromedriver may return response code 200 for non-zero JSONWP statuses
@@ -210,11 +212,24 @@ class JWProxy {
}
return [res, resBodyObj];
} catch (e) {
- if (util.hasValue(e.error)) {
- log.warn(`Got an unexpected response: ` +
- _.truncate(_.isString(e.error) ? e.error : JSON.stringify(e.error), {length: LOG_OBJ_LENGTH}));
+ // We only consider an error unexpected if this was not
+ // an async request module error or if the response cannot be cast to
+ // a valid JSON
+ if (!util.hasValue(e.error)) {
+ log.warn(e.message);
+ log.debug(e.stack);
+ } else {
+ if (!(_.isPlainObject(e.error) || /^\s*\{/.test(e.error))) {
+ if (isResponseLogged) {
+ log.warn('The response has an unknown format');
} else {
+ log.warn(`Got an unexpected response with status ${e.statusCode}: ${truncateBody(e.error)}`);
+ }
log.debug(e.stack);
+ } else if (!isResponseLogged) {
+ log.debug(`Got response with status ${e.statusCode}: ${truncateBody(e.error)}`);
+ isResponseLogged = true;
+ }
}
throw new errors.ProxyRequestError(`Could not proxy command to remote server. ` +
`Original error: ${e.message}`, e.error, e.statusCode);

fix: Properly log request errors (#348)