Improve logging of http requests to aid debugging

spec/unit/http-api/fetch.spec.ts

@@ -14,11 +14,14 @@ See the License for the specific language governing permissions and
 limitations under the License.
 */
 
+import { mocked } from "jest-mock";
+
 import { FetchHttpApi } from "../../../src/http-api/fetch";
 import { TypedEventEmitter } from "../../../src/models/typed-event-emitter";
 import { ClientPrefix, HttpApiEvent, HttpApiEventHandlerMap, IdentityPrefix, IHttpOpts, Method } from "../../../src";
 import { emitPromise } from "../../test-utils/test-utils";
-import { QueryDict } from "../../../src/utils";
+import { defer, QueryDict } from "../../../src/utils";
+import { logger } from "../../../src/logger";
 
 describe("FetchHttpApi", () => {
  const baseUrl = "http://baseUrl";
@@ -290,4 +293,30 @@ describe("FetchHttpApi", () => {
  runTests(baseUrlWithTrailingSlash);
  });
  });
+
+ it("should not log query parameters", async () => {
+ jest.useFakeTimers();
+ const deferred = defer<Response>();
+ const fetchFn = jest.fn().mockReturnValue(deferred.promise);
+ jest.spyOn(logger, "debug").mockImplementation(() => {});
+ const api = new FetchHttpApi(new TypedEventEmitter<any, any>(), { baseUrl, prefix, fetchFn });
+ const prom = api.requestOtherUrl(Method.Get, "https://server:1234/some/path#fragment?query=param");
+ jest.advanceTimersByTime(1234);
+ deferred.resolve({ ok: true, text: () => Promise.resolve("RESPONSE") } as Response);
+ await prom;
+ expect(logger.debug).not.toHaveBeenCalledWith("fragment");
+ expect(logger.debug).not.toHaveBeenCalledWith("query");
+ expect(logger.debug).not.toHaveBeenCalledWith("param");
+ expect(logger.debug).toHaveBeenCalledTimes(2);
+ expect(mocked(logger.debug).mock.calls[0]).toMatchInlineSnapshot(`
+ [
+ "FetchHttpApi: --> GET https://server:1234/some/path",
+ ]
+ `);
+ expect(mocked(logger.debug).mock.calls[1]).toMatchInlineSnapshot(`
+ [
+ "FetchHttpApi: <-- undefined 1234ms GET https://server:1234/some/path",
+ ]
+ `);
+ });
 });

src/http-api/fetch.ts

@@ -25,6 +25,7 @@ import { ConnectionError, MatrixError } from "./errors";
 import { HttpApiEvent, HttpApiEventHandlerMap, IHttpOpts, IRequestOpts } from "./interface";
 import { anySignal, parseErrorResponse, timeoutSignal } from "./utils";
 import { QueryDict } from "../utils";
+import { logger } from "../logger";
 
 type Body = Record<string, any> | BodyInit;
 
@@ -225,6 +226,9 @@ export class FetchHttpApi<O extends IHttpOpts> {
  body?: Body,
  opts: Pick<IRequestOpts, "headers" | "json" | "localTimeoutMs" | "keepAlive" | "abortSignal"> = {},
  ): Promise<ResponseType<T, O>> {
+ const urlForLogs = this.clearUrlParamsForLogs(url);
+ logger.debug(`FetchHttpApi: --> ${method} ${urlForLogs}`);
+
  const headers = Object.assign({}, opts.headers || {});
  const json = opts.json ?? true;
  // We can't use getPrototypeOf here as objects made in other contexts e.g. over postMessage won't have same ref
@@ -260,6 +264,7 @@ export class FetchHttpApi<O extends IHttpOpts> {
  const { signal, cleanup } = anySignal(signals);
 
  let res: Response;
+ const start = Date.now();
  try {
  res = await this.fetch(url, {
  signal,
@@ -274,7 +279,10 @@ export class FetchHttpApi<O extends IHttpOpts> {
  credentials: "omit", // we send credentials via headers
  keepalive: keepAlive,
  });
+
+ logger.debug(`FetchHttpApi: <-- ${res.status} ${Date.now() - start}ms ${method} ${urlForLogs}`);
  } catch (e) {
+ logger.debug(`FetchHttpApi: <-- ${e} ${Date.now() - start}ms ${method} ${urlForLogs}`);
  if ((<Error>e).name === "AbortError") {
  throw e;
  }
@@ -293,6 +301,22 @@ export class FetchHttpApi<O extends IHttpOpts> {
  return res as ResponseType<T, O>;
  }
 
+ private clearUrlParamsForLogs(url: URL | string): string {
+ try {
+ let asUrl: URL;
+ if (typeof url === "string") {
+ asUrl = new URL(url);
+ } else {
+ asUrl = url;
+ }
+ // get just the path to remove any potential url param that could have
+ // some potential secrets
+ return asUrl.origin + asUrl.pathname;
+ } catch (error) {
+ // defensive coding for malformed url
+ return "??";
+ }
+ }
  /**
  * Form and return a homeserver request URL based on the given path params and prefix.
  * @param path - The HTTP path <b>after</b> the supplied prefix e.g. "/createRoom".