Skip to content

Commit b2edc4f

Browse files
committed
feat: add auth debugging to all auth modules
1 parent 0052ec6 commit b2edc4f

12 files changed

Lines changed: 677 additions & 96 deletions

File tree

‎backend/helpers/authDebug.ts‎

Lines changed: 66 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,66 @@
1+
/**
2+
* What an authentication module has to say about one attempt, while the `authDebug` flag is on.
3+
*
4+
* A failed login deliberately tells whoever is at the login screen almost nothing: every refusal
5+
* arrives as one of a handful of coded errors (`ERR_LOGIN_FAILED`, `ERR_STRATEGY_MISCONFIGURED`,
6+
* `ERR_PROVIDER_REQUEST_FAILED`), because that form is open to whoever can reach the wiki and a
7+
* message naming the check that refused is a message telling an attacker what to change. This is the
8+
* other half of that arrangement: the detail goes to the server log, where the administrator setting
9+
* the strategy up can read it and nobody else can.
10+
*
11+
* Which is what makes it the difference between a directory that cannot be reached, the wiki's own
12+
* bind credentials being wrong, a search base with a typo in it, a filter matching two people and a
13+
* password that is simply not the right one — five different things to go and fix, all of which reach
14+
* the user as the same `ERR_LOGIN_FAILED`.
15+
*
16+
* **Never a credential, whatever is being diagnosed**: not the password being tried, not the
17+
* strategy's own bind credentials or client secret, not a token a provider issued. Configuration is
18+
* quoted freely — a search filter or an issuer URL is what the message is *for* — and secrets are
19+
* described instead: whether one is set, never what it is.
20+
*
21+
* @param strategy The module instance. Every one carries `strategyId`, and `models/authentication.ts`
22+
* sets `module` on it right after construction, so a message says which of several
23+
* strategies of the same kind it is about.
24+
*/
25+
export function strategyDebug(
26+
strategy: { strategyId: string; module?: string },
27+
message: string
28+
): void {
29+
WIKI.models.flags.authDebug(
30+
`${strategy.module ?? 'unknown'} strategy ${strategy.strategyId}: ${message}`
31+
)
32+
}
33+
34+
/**
35+
* Which of a set of settings are empty, by the names the admin area shows them under.
36+
*
37+
* The titles rather than the config keys, because these names are only ever read in a log message
38+
* about a strategy that will not work, and the point of such a message is to name the field to go and
39+
* fill in — "Client Secret is empty", not `clientSecret`.
40+
*/
41+
export function missingSettings(settings: Record<string, unknown>): string {
42+
const missing = Object.entries(settings)
43+
.filter(([, value]) => !value)
44+
.map(([title]) => title)
45+
return `${missing.join(', ')} ${missing.length > 1 ? 'are' : 'is'} empty`
46+
}
47+
48+
/**
49+
* What a directory, a provider or the network said, as far as it can be put on one line.
50+
*
51+
* Every field of it earns its place, and each comes from a different kind of failure:
52+
*
53+
* - the **class name**, because `ldapts` raises a result-code error whose message is often only the
54+
* code's own name — and `InvalidCredentialsError` on the wiki's own search connection is what
55+
* says the strategy's bind DN is wrong rather than the person's password;
56+
* - the **code**, which is an LDAP result code (49, 32) that a directory's documentation is indexed
57+
* by, or a socket error's (`ECONNREFUSED`, `ETIMEDOUT`) that is the whole answer on its own;
58+
* - the OAuth2 **`error` / `error_description`**, which `openid-client` attaches when a provider
59+
* refuses something and is the provider's own account of why — `invalid_client` for a rotated
60+
* secret, `invalid_grant` for a redirect URI it does not have registered.
61+
*/
62+
export function describeAuthError(err: any): string {
63+
const code = err?.code === undefined ? '' : ` [${err.code}]`
64+
const detail = [err?.error, err?.error_description].filter(Boolean).join(': ')
65+
return `${err?.name ?? 'Error'}${code}: ${err?.message ?? err}${detail ? ` (${detail})` : ''}`
66+
}

‎backend/models/flags.ts‎

Lines changed: 5 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -8,7 +8,11 @@
88
export const FLAGS = {
99
/** Consumed by the frontend, which reveals unfinished features when it is on. */
1010
experimental: 'Unfinished features are offered in the interface.',
11-
/** Consumed by `models/users.ts` and `api/authentication.ts` via `authDebug()` below. */
11+
/**
12+
* Consumed by `models/users.ts` and `api/authentication.ts` via `authDebug()` below, and by every
13+
* authentication module through `helpers/authDebug.ts` — which is the half that says *why* a
14+
* strategy refused somebody, since what reaches the login screen is only ever a coded error.
15+
*/
1216
authDebug: 'Login and account creation attempts are logged in detail.',
1317
/** Consumed by the query logger in `core/db.ts`. */
1418
sqlLog: 'Every database query is logged.'

‎backend/models/users.ts‎

Lines changed: 9 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -919,11 +919,15 @@ class Users {
919919
const unmatched = profile.groups.filter(
920920
(name) => !all.some((grp) => grp.name.toLowerCase() === name.toLowerCase())
921921
)
922-
if (unmatched.length > 0) {
923-
WIKI.models.flags.authDebug(
924-
`Strategy ${strategy.id} named ${unmatched.length} group(s) this wiki does not have, for user ${userId}: ${unmatched.join(', ')}`
925-
)
926-
}
922+
/*
923+
Both halves of the answer, and logged even when the provider named nothing: an empty claim is
924+
the commonest reason a group mapping appears not to work, and it is silent everywhere else — the
925+
wanted set below then simply equals the current one. What the provider said about this person is
926+
logged by the module; this is what the wiki could do with it.
927+
*/
928+
WIKI.models.flags.authDebug(
929+
`Strategy ${strategy.id} named ${profile.groups.length} group(s) for user ${userId}: ${matched.length} matched a wiki group (${matched.map((grp) => grp.name).join(', ') || 'none'})${unmatched.length > 0 ? `, ${unmatched.length} did not (${unmatched.join(', ')})` : ''}`
930+
)
927931

928932
const current = await this.getUserGroupIds(userId)
929933
const autoEnroll = strategy.autoEnrollGroups ?? []

‎backend/modules/authentication/discord/authentication.ts‎

Lines changed: 45 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -1,3 +1,4 @@
1+
import { missingSettings, strategyDebug } from '../../../helpers/authDebug.ts'
12
import type { AuthFlow, AuthFlowCallback, ProviderProfile } from '../../../models/authentication.ts'
23

34
/** Where a person signs in. Not under `/api`, unlike everything else Discord answers. */
@@ -66,6 +67,10 @@ export default class DiscordAuthentication {
6667
const clientSecret = this.conf.clientSecret || ''
6768
const serverId = (this.conf.serverId || '').trim()
6869
if (!clientId || !clientSecret) {
70+
strategyDebug(
71+
this,
72+
`is not configured: ${missingSettings({ 'Client ID': clientId, 'Client Secret': clientSecret })}`
73+
)
6974
throw new Error('ERR_STRATEGY_MISCONFIGURED')
7075
}
7176
if (this.conf.mapGroups === true && !serverId) {
@@ -115,6 +120,12 @@ export default class DiscordAuthentication {
115120
WIKI.logger.warn(
116121
`Discord strategy ${this.strategyId} asked for ${path} and the API answered ${resp.status}.`
117122
)
123+
// -> The body as well as the status, under the flag: Discord's error payload names the scope
124+
// that was not granted or the intent the bot is missing, which the status alone does not
125+
strategyDebug(
126+
this,
127+
`GET ${path} answered ${resp.status}: ${await resp.text().catch(() => '(no body)')}`
128+
)
118129
throw new Error('ERR_PROVIDER_REQUEST_FAILED')
119130
}
120131
return resp.json()
@@ -172,6 +183,10 @@ export default class DiscordAuthentication {
172183
let names = await this.roleNames(serverId)
173184
if (names.size < 1) {
174185
// -> No bot token. The IDs are the whole of what Discord will say about these roles
186+
strategyDebug(
187+
this,
188+
`no Bot Token is configured, so the ${roleIds.length} role(s) held can only be matched by ID: ${roleIds.join(', ') || 'none'}`
189+
)
175190
return roleIds
176191
}
177192
if (roleIds.some((id) => !names.has(id))) {
@@ -249,15 +264,26 @@ export default class DiscordAuthentication {
249264
try {
250265
token = (await tokenResp.json()) as Record<string, any>
251266
} catch {
267+
strategyDebug(
268+
this,
269+
`the token exchange answered ${tokenResp.status} with something that is not JSON — is something else answering for ${API}?`
270+
)
252271
throw new Error('ERR_TOKEN_EXCHANGE_FAILED')
253272
}
254273
if (!tokenResp.ok || token.error || !token.access_token) {
274+
// -> Discord's own account of the refusal, which names the cause: `invalid_client` for a Client
275+
// Secret that has been reset, `invalid_grant` for a Redirect URI it does not have registered
276+
strategyDebug(
277+
this,
278+
`the token exchange answered ${tokenResp.status}: ${[token.error, token.error_description].filter(Boolean).join(': ') || 'no access token'}`
279+
)
255280
throw new Error('ERR_TOKEN_EXCHANGE_FAILED')
256281
}
257282
const bearer = `Bearer ${token.access_token}`
258283

259284
const account = await this.api('/users/@me', bearer)
260285
if (!account?.id) {
286+
strategyDebug(this, 'the API answered with no account for this token')
261287
throw new Error('ERR_NO_PROVIDER_ACCOUNT')
262288
}
263289
/*
@@ -266,6 +292,10 @@ export default class DiscordAuthentication {
266292
by, so it is refused rather than trusted.
267293
*/
268294
if (!account.email || account.verified !== true) {
295+
strategyDebug(
296+
this,
297+
`${account.username} ${account.email ? 'has not confirmed their address with Discord' : 'gave no address — was the `email` scope granted?'}`
298+
)
269299
throw new Error('ERR_NO_VERIFIED_EMAIL_FROM_PROVIDER')
270300
}
271301

@@ -283,23 +313,36 @@ export default class DiscordAuthentication {
283313
bearer
284314
)
285315
if (!member) {
316+
// -> 404, which Discord uses for both cases. Said as both, since a mistyped Server ID and a
317+
// person who is not in the server are one answer here and two different things to fix
318+
strategyDebug(
319+
this,
320+
`${account.username} is not in server ${serverId}, or there is no such server`
321+
)
286322
throw new Error('ERR_ACCOUNT_NOT_ALLOWED')
287323
}
288324
roleIds = Array.isArray(member.roles)
289325
? member.roles.filter((id: unknown): id is string => typeof id === 'string')
290326
: []
291327
}
292328

329+
const groups =
330+
this.conf.mapGroups === true ? await this.groupsFor(serverId, roleIds) : undefined
331+
strategyDebug(
332+
this,
333+
`${account.username} (${account.id}) signs in as <${account.email}>${groups ? `, holding ${groups.length} mapped role(s): ${groups.join(', ') || 'none'}` : ', groups not mapped'}`
334+
)
335+
293336
return {
294337
id: String(account.id),
295338
email: account.email,
296339
// -> `global_name` is the display name; `username` is the handle, and is all an account that
297340
// has not set one has
298341
name: account.global_name || account.username,
299342
picture: this.pictureFor(account),
300-
...(this.conf.mapGroups === true
343+
...(groups
301344
? {
302-
groups: await this.groupsFor(serverId, roleIds),
345+
groups,
303346
groupsExclusive: this.conf.unassignMissingGroups === true
304347
}
305348
: {})

‎backend/modules/authentication/entra/authentication.ts‎

Lines changed: 79 additions & 18 deletions
Original file line numberDiff line numberDiff line change
@@ -1,4 +1,5 @@
11
import * as client from 'openid-client'
2+
import { describeAuthError, missingSettings, strategyDebug } from '../../../helpers/authDebug.ts'
23
import type { AuthFlow, AuthFlowCallback, ProviderProfile } from '../../../models/authentication.ts'
34

45
/** Where a tenant's OpenID Connect metadata lives. `{tenant}` is the one thing configurable about it. */
@@ -52,16 +53,30 @@ export default class EntraAuthentication {
5253
}
5354
const { tenantId, clientId, clientSecret } = this.conf
5455
if (!tenantId || !clientId || !clientSecret) {
56+
strategyDebug(
57+
this,
58+
`is not configured: ${missingSettings({ 'Directory (tenant) ID': tenantId, 'Application (client) ID': clientId, 'Client Secret': clientSecret })}`
59+
)
5560
throw new Error('ERR_STRATEGY_MISCONFIGURED')
5661
}
5762
if (MULTI_TENANT.includes(String(tenantId).toLowerCase())) {
63+
strategyDebug(
64+
this,
65+
`has \`${tenantId}\` as its Directory (tenant) ID, which is a multi-tenant placeholder — this module needs the tenant's own ID, since it accepts tokens from that directory alone (see MULTI_TENANT)`
66+
)
5867
throw new Error('ERR_STRATEGY_MISCONFIGURED')
5968
}
60-
this.config = await client.discovery(
61-
new URL(ISSUER_TEMPLATE.replace('{tenant}', encodeURIComponent(tenantId))),
62-
clientId,
63-
clientSecret
64-
)
69+
const issuer = ISSUER_TEMPLATE.replace('{tenant}', encodeURIComponent(tenantId))
70+
strategyDebug(this, `reading the tenant's metadata from ${issuer}`)
71+
try {
72+
this.config = await client.discovery(new URL(issuer), clientId, clientSecret)
73+
} catch (err: any) {
74+
strategyDebug(
75+
this,
76+
`could not read the tenant's metadata from ${issuer}: ${describeAuthError(err)}`
77+
)
78+
throw err
79+
}
6580
return this.config
6681
}
6782

@@ -86,13 +101,26 @@ export default class EntraAuthentication {
86101
codeVerifier
87102
}: AuthFlowCallback): Promise<ProviderProfile> {
88103
const config = await this.configuration()
89-
const tokens = await client.authorizationCodeGrant(config, new URL(currentUrl), {
90-
expectedState: state,
91-
expectedNonce: nonce,
92-
pkceCodeVerifier: codeVerifier
93-
})
104+
let tokens
105+
try {
106+
tokens = await client.authorizationCodeGrant(config, new URL(currentUrl), {
107+
expectedState: state,
108+
expectedNonce: nonce,
109+
pkceCodeVerifier: codeVerifier
110+
})
111+
} catch (err: any) {
112+
// -> The state, the PKCE verifier, the code exchange and the ID token's signature, issuer,
113+
// audience and nonce are all checked in there, so this covers a redirect URI the app
114+
// registration does not have, an expired client secret, and a mismatched tenant alike
115+
strategyDebug(this, `the tenant's answer did not check out: ${describeAuthError(err)}`)
116+
throw err
117+
}
94118
const claims = tokens.claims()
95119
if (!claims?.sub) {
120+
strategyDebug(
121+
this,
122+
'the tenant returned no ID token, so there is nothing signed saying who signed in'
123+
)
96124
throw new Error('ERR_NO_ID_TOKEN')
97125
}
98126

@@ -103,16 +131,37 @@ export default class EntraAuthentication {
103131
*/
104132
let info: Record<string, any> = claims
105133
if (config.serverMetadata().userinfo_endpoint) {
106-
info = {
107-
...claims,
108-
...(await client.fetchUserInfo(config, tokens.access_token, claims.sub))
134+
try {
135+
info = {
136+
...claims,
137+
...(await client.fetchUserInfo(config, tokens.access_token, claims.sub))
138+
}
139+
} catch (err: any) {
140+
strategyDebug(this, `the userinfo endpoint could not be read: ${describeAuthError(err)}`)
141+
throw err
109142
}
110143
}
144+
strategyDebug(this, `the tenant says: ${Object.keys(info).join(', ')}`)
111145

112-
const email = info[this.conf.emailClaim || 'email']
146+
const emailClaim = this.conf.emailClaim || 'email'
147+
const email = info[emailClaim]
113148
if (!email || typeof email !== 'string') {
149+
/*
150+
The single most common way an Entra strategy does not work, which is why the log says what to
151+
do about it: `email` is only emitted for an account with a Mail attribute or a tenant that
152+
maps the optional claim, and `preferred_username` is where the address is otherwise.
153+
*/
154+
strategyDebug(
155+
this,
156+
`the \`${emailClaim}\` claim carries no address — set Email Claim to \`preferred_username\`, or map the \`email\` optional claim on the app registration`
157+
)
114158
throw new Error('ERR_NO_EMAIL_FROM_PROVIDER')
115159
}
160+
const groups = this.conf.mapGroups === true ? this.groupsFrom(info) : undefined
161+
strategyDebug(
162+
this,
163+
`${claims.sub} signs in as <${email}>${groups ? `, in ${groups.length} tenant group(s)` : ', groups not mapped'}`
164+
)
116165
return {
117166
// -> `oid` is the account's identifier within the tenant and `sub` is its identifier for this
118167
// one application. `sub` is the one to link by: it is what the ID token was verified as
@@ -121,9 +170,9 @@ export default class EntraAuthentication {
121170
email,
122171
name: (info[this.conf.displayNameClaim || 'name'] as string) || email,
123172
picture: this.pictureFrom(info),
124-
...(this.conf.mapGroups === true
173+
...(groups
125174
? {
126-
groups: this.groupsFrom(info),
175+
groups,
127176
groupsExclusive: this.conf.unassignMissingGroups === true
128177
}
129178
: {})
@@ -147,10 +196,22 @@ export default class EntraAuthentication {
147196

148197
/** The group names — or, as Entra usually has it, the group object IDs — the claim carries. */
149198
private groupsFrom(info: Record<string, any>): string[] {
150-
const value = info[this.conf.groupsClaim || 'groups']
199+
const claim = this.conf.groupsClaim || 'groups'
200+
const value = info[claim]
151201
const raw = typeof value === 'string' ? [value] : Array.isArray(value) ? value : []
152-
return raw
202+
const names = raw
153203
.filter((entry) => typeof entry === 'string' && entry.trim().length > 0)
154204
.map((entry) => entry.trim())
205+
/*
206+
Logged even when it is empty, and especially then: a tenant emits this claim only for an app
207+
registration configured to ask for it, and an empty answer is not distinguishable on the wiki
208+
side from somebody genuinely being in no group. The values are worth seeing too — object IDs
209+
where an administrator expected names is the other half of why a mapping matches nothing.
210+
*/
211+
strategyDebug(
212+
this,
213+
`the \`${claim}\` claim names ${names.length} group(s): ${names.join(', ') || 'none'}`
214+
)
215+
return names
155216
}
156217
}

0 commit comments

Comments
 (0)