Skip to content

Commit 300b188

Browse files
hughnsclaude
andauthored
Log OAuth requests and responses (#5506)
* Log OAuth 2.0 requests and responses The OAuth 2.0 flows in `src/oauth` called `fetch` directly, so none of the requests to the identity provider's registration, device authorization, token or revocation endpoints appeared in the logs. This made debugging login and token refresh problems much harder than debugging Client-Server API calls, which `FetchHttpApi` logs. Add a `fetchWithLogging` wrapper which emits the same `-->`/`<--` debug lines as `FetchHttpApi`, including the request duration and the response status, and use it for all OAuth 2.0 requests. As with `FetchHttpApi`, neither the request nor the response body is logged and query parameter values are redacted, since they routinely carry credentials. `OAuth2`, `OAuth2.registerClient`, `startDeviceAuthorization` and `waitForDeviceAuthorization` all take an optional `Logger` so that callers can route these lines to the logger of their choice; they default to the js-sdk root logger. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com> Signed-off-by: Hugh Nimmo-Smith <hughns@matrix.org> * Mark as internal --------- Signed-off-by: Hugh Nimmo-Smith <hughns@matrix.org> Co-authored-by: Claude Opus 5 (1M context) <noreply@anthropic.com>
1 parent aa1aeed commit 300b188

6 files changed

Lines changed: 291 additions & 28 deletions

File tree

spec/unit/oauth/fetch.spec.ts

Lines changed: 164 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,164 @@
1+
/*
2+
Copyright 2026 The Matrix.org Foundation C.I.C.
3+
4+
Licensed under the Apache License, Version 2.0 (the "License");
5+
you may not use this file except in compliance with the License.
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+
import fetchMock from "@fetch-mock/vitest";
18+
import { type Mocked } from "vitest";
19+
20+
import { type Logger } from "../../../src/logger";
21+
import { OAuth2, startDeviceAuthorization } from "../../../src/oauth";
22+
import { fetchWithLogging } from "../../../src/oauth/fetch";
23+
import { makeDelegatedAuthMetadata } from "../../test-utils/auth";
24+
import { OAuthGrantType } from "../../../src/oauth/register";
25+
26+
describe("fetchWithLogging()", () => {
27+
let mockLogger: Mocked<Logger>;
28+
29+
beforeEach(() => {
30+
mockLogger = {
31+
debug: vi.fn(),
32+
} as unknown as Mocked<Logger>;
33+
});
34+
35+
afterEach(() => {
36+
vi.useRealTimers();
37+
});
38+
39+
it("should log the request and the response", async () => {
40+
vi.useFakeTimers();
41+
const responseResolvers = Promise.withResolvers<Response>();
42+
fetchMock.post("https://auth.org/token", responseResolvers.promise);
43+
44+
const prom = fetchWithLogging(mockLogger, "https://auth.org/token", { method: "POST" });
45+
vi.advanceTimersByTime(1234);
46+
responseResolvers.resolve(new Response("{}", { status: 200 }));
47+
await prom;
48+
49+
expect(mockLogger.debug).toHaveBeenCalledTimes(2);
50+
expect(mockLogger.debug.mock.calls[0]).toEqual(["OAuth2: --> POST https://auth.org/token"]);
51+
expect(mockLogger.debug.mock.calls[1]).toEqual(["OAuth2: <-- POST https://auth.org/token [1234ms 200]"]);
52+
});
53+
54+
it("should not log the values of query parameters", async () => {
55+
fetchMock.get("https://auth.org/whatever?token=super-secret", { status: 200, body: "{}" });
56+
57+
await fetchWithLogging(mockLogger, "https://auth.org/whatever?token=super-secret");
58+
59+
for (const call of mockLogger.debug.mock.calls) {
60+
expect(call[0]).not.toContain("super-secret");
61+
}
62+
expect(mockLogger.debug.mock.calls[0]).toEqual(["OAuth2: --> GET https://auth.org/whatever?token=xxx"]);
63+
});
64+
65+
it("should log the response status even when it is an error", async () => {
66+
fetchMock.post("https://auth.org/token", { status: 400, body: "{}" });
67+
68+
await fetchWithLogging(mockLogger, "https://auth.org/token", { method: "POST" });
69+
70+
expect(mockLogger.debug.mock.calls[1]).toEqual([
71+
expect.stringMatching(/^OAuth2: <-- POST https:\/\/auth\.org\/token \[\d+ms 400\]$/),
72+
]);
73+
});
74+
75+
it("should log and rethrow network errors", async () => {
76+
const error = new Error("Network error");
77+
fetchMock.post("https://auth.org/token", { throws: error });
78+
79+
await expect(fetchWithLogging(mockLogger, "https://auth.org/token", { method: "POST" })).rejects.toThrow(error);
80+
81+
expect(mockLogger.debug.mock.calls[1]).toEqual([
82+
expect.stringMatching(/^OAuth2: <-- POST https:\/\/auth\.org\/token \[\d+ms Error: Network error\]$/),
83+
]);
84+
});
85+
86+
describe("integration", () => {
87+
const delegatedAuthConfig = makeDelegatedAuthMetadata("https://auth.org/", [
88+
OAuthGrantType.DeviceAuthorization,
89+
]);
90+
91+
it("should log token endpoint requests made by OAuth2", async () => {
92+
fetchMock.post(delegatedAuthConfig.token_endpoint, {
93+
status: 200,
94+
body: { access_token: "abc123", token_type: "Bearer", expires_in: 300 },
95+
});
96+
97+
const auth = new OAuth2(
98+
delegatedAuthConfig,
99+
{ clientId: "test-client-id", redirectUri: "https://test.com" },
100+
mockLogger,
101+
);
102+
await auth.completeAuthorizationCodeGrant("code123");
103+
104+
expect(mockLogger.debug.mock.calls).toEqual([
105+
["OAuth2: --> POST https://auth.org/token"],
106+
[expect.stringMatching(/^OAuth2: <-- POST https:\/\/auth\.org\/token \[\d+ms 200\]$/)],
107+
]);
108+
});
109+
110+
it("should log revocation endpoint requests made by OAuth2", async () => {
111+
fetchMock.post(delegatedAuthConfig.revocation_endpoint, { status: 200, body: "{}" });
112+
113+
const auth = new OAuth2(
114+
delegatedAuthConfig,
115+
{ clientId: "test-client-id", redirectUri: "https://test.com" },
116+
mockLogger,
117+
);
118+
await auth.revokeToken("abc123", "access_token");
119+
120+
expect(mockLogger.debug.mock.calls[0]).toEqual(["OAuth2: --> POST https://auth.org/revoke"]);
121+
});
122+
123+
it("should log registration endpoint requests made by registerClient", async () => {
124+
fetchMock.post(delegatedAuthConfig.registration_endpoint, {
125+
status: 200,
126+
body: { client_id: "xyz789" },
127+
});
128+
129+
await OAuth2.registerClient(
130+
delegatedAuthConfig,
131+
{
132+
client_uri: "https://just.testing",
133+
redirect_uris: ["https://just.testing"],
134+
client_name: "Element",
135+
application_type: "web",
136+
},
137+
mockLogger,
138+
);
139+
140+
expect(mockLogger.debug.mock.calls[0]).toEqual(["OAuth2: --> POST https://auth.org/registration"]);
141+
});
142+
143+
it("should log device authorization endpoint requests", async () => {
144+
fetchMock.post(delegatedAuthConfig.device_authorization_endpoint!, {
145+
status: 200,
146+
body: {
147+
device_code: "device123",
148+
user_code: "USER123",
149+
verification_uri: "https://auth.org/link",
150+
expires_in: 300,
151+
},
152+
});
153+
154+
await startDeviceAuthorization({
155+
clientId: "test-client-id",
156+
scope: "test-scope",
157+
metadata: delegatedAuthConfig,
158+
logger: mockLogger,
159+
});
160+
161+
expect(mockLogger.debug.mock.calls[0]).toEqual(["OAuth2: --> POST https://auth.org/device"]);
162+
});
163+
});
164+
});

src/http-api/fetch.ts

Lines changed: 2 additions & 23 deletions
Original file line numberDiff line numberDiff line change
@@ -31,6 +31,7 @@ import {
3131
type Body,
3232
} from "./interface.ts";
3333
import { anySignal, parseErrorResponse, timeoutSignal } from "./utils.ts";
34+
import { sanitizeUrlForLogs } from "./logging.ts";
3435
import { type QueryDict } from "../utils.ts";
3536
import { TokenRefresher, TokenRefreshOutcome } from "./refresh.ts";
3637

@@ -241,7 +242,7 @@ export class FetchHttpApi<O extends IHttpOpts> {
241242
throw new Error("Invalid call to `FetchHttpApi` sets both `opts.json` and `opts.rawResponseBody`");
242243
}
243244

244-
const urlForLogs = this.sanitizeUrlForLogs(url);
245+
const urlForLogs = sanitizeUrlForLogs(url);
245246

246247
this.opts.logger?.debug(`FetchHttpApi: --> ${method} ${urlForLogs}`);
247248

@@ -330,28 +331,6 @@ export class FetchHttpApi<O extends IHttpOpts> {
330331
}
331332
}
332333

333-
private sanitizeUrlForLogs(url: URL | string): string {
334-
try {
335-
let asUrl: URL;
336-
if (typeof url === "string") {
337-
asUrl = new URL(url);
338-
} else {
339-
asUrl = url;
340-
}
341-
// Remove the values of any URL params that could contain potential secrets
342-
const sanitizedQs = new URLSearchParams();
343-
for (const key of asUrl.searchParams.keys()) {
344-
sanitizedQs.append(key, "xxx");
345-
}
346-
const sanitizedQsString = sanitizedQs.toString();
347-
const sanitizedQsUrlPiece = sanitizedQsString ? `?${sanitizedQsString}` : "";
348-
349-
return asUrl.origin + asUrl.pathname + sanitizedQsUrlPiece;
350-
} catch {
351-
// defensive coding for malformed url
352-
return "??";
353-
}
354-
}
355334
/**
356335
* Form and return a homeserver request URL based on the given path params and prefix.
357336
* @param path - The HTTP path <b>after</b> the supplied prefix e.g. "/createRoom".

src/http-api/logging.ts

Lines changed: 46 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,46 @@
1+
/*
2+
Copyright 2026 The Matrix.org Foundation C.I.C.
3+
4+
Licensed under the Apache License, Version 2.0 (the "License");
5+
you may not use this file except in compliance with the License.
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+
/**
18+
* Produce a version of the given URL which is safe to write to logs, by redacting the values of any query parameters,
19+
* as they may contain secrets.
20+
*
21+
* @internal
22+
* @param url - the URL to sanitize.
23+
* @returns the sanitized URL, or `"??"` if the URL could not be parsed.
24+
*/
25+
export function sanitizeUrlForLogs(url: URL | string): string {
26+
try {
27+
let asUrl: URL;
28+
if (typeof url === "string") {
29+
asUrl = new URL(url);
30+
} else {
31+
asUrl = url;
32+
}
33+
// Remove the values of any URL params that could contain potential secrets
34+
const sanitizedQs = new URLSearchParams();
35+
for (const key of asUrl.searchParams.keys()) {
36+
sanitizedQs.append(key, "xxx");
37+
}
38+
const sanitizedQsString = sanitizedQs.toString();
39+
const sanitizedQsUrlPiece = sanitizedQsString ? `?${sanitizedQsString}` : "";
40+
41+
return asUrl.origin + asUrl.pathname + sanitizedQsUrlPiece;
42+
} catch {
43+
// defensive coding for malformed url
44+
return "??";
45+
}
46+
}

src/oauth/authorize.ts

Lines changed: 10 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -27,6 +27,8 @@ import {
2727
import { Method } from "../http-api/index.ts";
2828
import { OAuthGrantType } from "./register.ts";
2929
import { sleep } from "../utils.ts";
30+
import { type Logger, logger as rootLogger } from "../logger.ts";
31+
import { fetchWithLogging } from "./fetch.ts";
3032

3133
/**
3234
* The expected response type from the token endpoint during authorization code flow
@@ -185,17 +187,20 @@ export function validateDeviceAuthorizationResponse(
185187
* @param options.clientId - the client ID returned from client registration.
186188
* @param options.scope - the scope to request for authorization.
187189
* @param options.metadata - the validated OAuth2 metadata for the Identity Provider.
190+
* @param options.logger - optional logger to use for the request, defaults to the root logger of the js-sdk.
188191
* @returns a promise that resolves to a device access token response,
189192
* or an error response if the user denies authorization or the device code expires.
190193
*/
191194
export const startDeviceAuthorization = async ({
192195
clientId,
193196
scope,
194197
metadata,
198+
logger = rootLogger,
195199
}: {
196200
clientId: string;
197201
scope: string;
198202
metadata: ValidatedAuthMetadata;
203+
logger?: Logger;
199204
}): Promise<DeviceAuthorizationResponse> => {
200205
const body = new URLSearchParams({ client_id: clientId, scope: scope }).toString();
201206

@@ -204,7 +209,7 @@ export const startDeviceAuthorization = async ({
204209
throw new Error("No device_authorization_endpoint given");
205210
}
206211

207-
const response = await fetch(url, {
212+
const response = await fetchWithLogging(logger, url, {
208213
method: Method.Post,
209214
headers: {
210215
"Content-Type": "application/x-www-form-urlencoded",
@@ -223,17 +228,20 @@ export const startDeviceAuthorization = async ({
223228
* @param options.session - The session returned from a previous call to {@link startDeviceAuthorization}.
224229
* @param options.metadata - The validated OAuth2 metadata for the Identity Provider.
225230
* @param options.clientId - The client ID returned from client registration.
231+
* @param options.logger - optional logger to use for the requests, defaults to the root logger of the js-sdk.
226232
* @returns a promise that resolves to a device access token response,
227233
* or an error response if the user denies authorization or the device code expires.
228234
*/
229235
export const waitForDeviceAuthorization = async ({
230236
session,
231237
metadata,
232238
clientId,
239+
logger = rootLogger,
233240
}: {
234241
session: DeviceAuthorizationResponse;
235242
metadata: ValidatedAuthMetadata;
236243
clientId: string;
244+
logger?: Logger;
237245
}): Promise<DeviceAccessTokenResponse | DeviceAccessTokenError> => {
238246
let interval = (session.interval ?? 5) * 1000; // poll interval
239247
const expiration = Date.now() + session.expires_in * 1000;
@@ -243,7 +251,7 @@ export const waitForDeviceAuthorization = async ({
243251
grant_type: OAuthGrantType.DeviceAuthorization,
244252
client_id: clientId,
245253
}).toString();
246-
const response = await fetch(metadata.token_endpoint, {
254+
const response = await fetchWithLogging(logger, metadata.token_endpoint, {
247255
method: Method.Post,
248256
headers: { "Content-Type": "application/x-www-form-urlencoded" },
249257
body,

src/oauth/fetch.ts

Lines changed: 54 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,54 @@
1+
/*
2+
Copyright 2026 The Matrix.org Foundation C.I.C.
3+
4+
Licensed under the Apache License, Version 2.0 (the "License");
5+
you may not use this file except in compliance with the License.
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+
import { sanitizeUrlForLogs } from "../http-api/logging.ts";
18+
import { Method } from "../http-api/method.ts";
19+
import { type Logger } from "../logger.ts";
20+
21+
/**
22+
* Perform a `fetch` request, logging the request and response in the same manner as
23+
* `FetchHttpApi` does for Client-Server API requests.
24+
*
25+
* Neither the request nor the response body is logged, as they routinely contain credentials.
26+
* Query parameter values are redacted for the same reason.
27+
*
28+
* @internal
29+
* @param logger - the logger to write the request and response lines to.
30+
* @param resource - the URL to request.
31+
* @param options - the options to pass to `fetch`.
32+
* @returns the `Response`, whatever its status code.
33+
* @throws rethrows whatever `fetch` threw, having logged it.
34+
*/
35+
export async function fetchWithLogging(
36+
logger: Logger,
37+
resource: URL | string,
38+
options: RequestInit = {},
39+
): Promise<Response> {
40+
const method = options.method ?? Method.Get;
41+
const urlForLogs = sanitizeUrlForLogs(resource);
42+
43+
logger.debug(`OAuth2: --> ${method} ${urlForLogs}`);
44+
45+
const start = Date.now();
46+
try {
47+
const res = await globalThis.fetch(resource, options);
48+
logger.debug(`OAuth2: <-- ${method} ${urlForLogs} [${Date.now() - start}ms ${res.status}]`);
49+
return res;
50+
} catch (e) {
51+
logger.debug(`OAuth2: <-- ${method} ${urlForLogs} [${Date.now() - start}ms ${e}]`);
52+
throw e;
53+
}
54+
}

0 commit comments

Comments
 (0)