fix: normalized the region and logged the otp properly

This commit is contained in:
Nathnael
2026-07-20 08:19:59 +00:00
parent c7195f077a
commit a45e1008fa
18 changed files with 812 additions and 63 deletions

View File

@@ -22,7 +22,18 @@ export type OtpTarget = { phone?: string; email?: string };
* Email targets pass through untouched.
*/
export function normalizeOtpTarget(target: OtpTarget): OtpTarget {
if (target.email || !target.phone) return target;
if (target.email) {
// Same contract as the phone branch below: the string stored on send and the
// one looked up on verify must be byte-identical, or the code is invisible to
// the verifier. Addresses reach us from a raw `@Body("email")` with no DTO or
// ValidationPipe, so `User@X.com`, `user@x.com` and a copy-paste with a
// trailing space are three different keys for one mailbox. Domains are
// case-insensitive (RFC 1035); local-parts are formally case-sensitive
// (RFC 5321 §2.4) but no mail provider in practice treats them so, and
// matching what users expect beats matching the letter of the spec here.
return { email: target.email.trim().toLowerCase() };
}
if (!target.phone) return target;
const raw = target.phone.trim();
const digits = raw.replace(/[^\d+]/g, '');
if (digits.startsWith('+')) return { phone: digits };
@@ -61,6 +72,9 @@ export class OtpService {
// Store under the canonical E.164 key so verify (which normalises the same
// way) always finds this row regardless of how either side typed the number.
const target = normalizeOtpTarget(rawTarget);
const channel = target.email ? "email" : "sms";
const label = this.targetLabel(target);
const startedAt = Date.now();
try {
// The verification code is generated server-side — never supplied by the
// caller — so the OTP stays a secret known only to the server and the
@@ -78,6 +92,14 @@ export class OtpService {
await this.otpRepository.createOtp(target, otp);
}
// `rotate` means a code already existed for this target and was replaced —
// the previous one is now dead. A user holding a slow-to-arrive SMS and
// typing its code will fail against the row; this line is how that shows up
// in the log rather than as an unexplained "invalid OTP" report.
this.logger.log(
`otp.issue channel=${channel} target=${label} action=${existing ? "rotate" : "create"}`,
);
// NOTE: do NOT reset the brute-force attempt counter on send. Clearing it
// here let an attacker wipe the per-target guess budget just by calling
// /otp/send between guesses. The counter is cleared only when the code is
@@ -86,40 +108,97 @@ export class OtpService {
// /otp/verify routes (a NestJS ThrottlerGuard / @Throttle) — none exists
// in the codebase yet.
if (target.email) {
// send email (queued to RabbitMQ via the shared Email service)
await this.emailClient.sendEmail({
to: target.email,
subject: "Your EDR Freight verification code",
text: `Your verification code is ${otp}`,
});
} else {
// send sms (queued to RabbitMQ via the shared SMS service)
await this.smsClient.sendSms({
to: target.phone as string,
message: `Your verification code is ${otp}`,
});
// Both clients report hand-off, not delivery — capture it rather than
// discarding it, so "queued=false" is distinguishable from a code that was
// published fine and lost downstream at the carrier.
const { queued } = target.email
? await this.emailClient.sendEmail({
to: target.email,
subject: "Your EDR Freight verification code",
text: `Your verification code is ${otp}`,
})
: await this.smsClient.sendSms({
to: target.phone as string,
message: `Your verification code is ${otp}`,
});
this.logger.log(
`otp.dispatch channel=${channel} target=${label} queued=${queued} latencyMs=${
Date.now() - startedAt
}`,
);
if (!queued) {
// The row is committed and we are about to answer "OTP sent successfully",
// but nothing left this process. Without this line the only symptom is a
// user who never receives a code — indistinguishable from carrier loss,
// and the misleading success response makes it look like our side worked.
this.logger.error(
`otp.dispatch.dropped channel=${channel} target=${label} rabbitmqEnabled=${
process.env.RABBITMQ_ENABLED ?? "unset"
} — transport reported no hand-off; no code will arrive for this send`,
);
}
// SECURITY: this logs a live credential in cleartext. Anyone with read
// access to the log stream can complete a password reset or a contract
// signature for the address on the same line. Kept deliberately (log
// aggregation is the debugging path for flaky SMS here) — if that tradeoff
// is ever revisited, gate on an env flag rather than deleting the line, so
// dev keeps its workflow.
this.logger.log(`OTP send for ${target.email ?? target.phone}: ${otp}`);
return {
success: true,
// Distinguishes "we published it" from "the transport is a no-op". The
// HTTP response shape is unchanged; the controller drops this field.
delivered: queued,
message: "OTP sent successfully",
};
} catch (error) {
// Log the real cause (DB/SMS/email failure) with its stack so a deployed
// "Failed to send OTP" 400 is diagnosable from the API logs, not opaque.
this.logger.error(
`Failed to send OTP to ${target.email ?? target.phone}: ${
error instanceof Error ? error.message : String(error)
}`,
`otp.dispatch.failed channel=${channel} target=${label} latencyMs=${
Date.now() - startedAt
}: ${error instanceof Error ? error.message : String(error)}`,
error instanceof Error ? error.stack : undefined,
);
throw new BadRequestException("Failed to send OTP");
}
}
/**
* Correlation key shared by every `otp.*` line for one address, so a send and
* its later verify can be joined with a single grep. The raw target is used
* because the code itself is already logged in cleartext above — hashing the
* address while printing the credential next to it would buy nothing.
*/
private targetLabel(target: OtpTarget): string {
return target.email ?? target.phone ?? "unknown";
}
/**
* One line per verify exit path. `result` is a closed set — ok | invalid |
* expired | exhausted | not_found — so failures can be counted by reason
* instead of inferred from error strings that the frontend also depends on.
*/
private logVerify(
target: OtpTarget,
mode: "simple" | "action",
result: "ok" | "invalid" | "expired" | "exhausted" | "not_found",
detail?: string,
) {
const line = `otp.verify channel=${
target.email ? "email" : "sms"
} target=${this.targetLabel(target)} mode=${mode} result=${result}${
detail ? ` ${detail}` : ""
}`;
if (result === "ok") this.logger.log(line);
else this.logger.warn(line);
}
// ---------------------------------------------------------------------------
// Verify OTP
// ---------------------------------------------------------------------------
@@ -134,6 +213,9 @@ export class OtpService {
// not found
if (!otpData) {
// No row for this key. Most often a normalisation mismatch or a code that
// was already consumed/burned — not necessarily a caller who never asked.
this.logVerify(target, "simple", "not_found");
throw new BadRequestException(
target.email ? "Email address not found" : "Phone number not found",
);
@@ -145,6 +227,12 @@ export class OtpService {
if (ageMs > this.ACTION_OTP_TTL_MS) {
await this.otpRepository.deleteOtp(otpData);
this.actionAttempts.delete(key);
this.logVerify(
target,
"simple",
"expired",
`ageMs=${ageMs} ttlMs=${this.ACTION_OTP_TTL_MS}`,
);
throw new BadRequestException(
"Verification code has expired. Request a new one.",
);
@@ -157,17 +245,30 @@ export class OtpService {
if (attempts >= this.MAX_ACTION_ATTEMPTS) {
await this.otpRepository.deleteOtp(otpData);
this.actionAttempts.delete(key);
this.logVerify(
target,
"simple",
"exhausted",
`attempts=${attempts}/${this.MAX_ACTION_ATTEMPTS} ageMs=${ageMs}`,
);
throw new BadRequestException(
"Too many incorrect attempts. Request a new code.",
);
}
this.actionAttempts.set(key, attempts);
this.logVerify(
target,
"simple",
"invalid",
`attempts=${attempts}/${this.MAX_ACTION_ATTEMPTS} ageMs=${ageMs}`,
);
throw new BadRequestException("Invalid OTP");
}
// single-use: consume the code on success so it can't be replayed.
await this.otpRepository.deleteOtp(otpData);
this.actionAttempts.delete(key);
this.logVerify(target, "simple", "ok", `ageMs=${ageMs}`);
return {
success: true,
@@ -210,6 +311,7 @@ export class OtpService {
const key = this.targetKey(target);
if (!otpData) {
this.logVerify(target, "action", "not_found");
throw new BadRequestException(
target.email
? "No verification code was requested for this email"
@@ -223,6 +325,7 @@ export class OtpService {
await this.otpRepository.deleteOtp(otpData);
this.actionAttempts.delete(key);
this.logVerify(target, "action", "expired", `ageMs=${ageMs} ttlMs=${ttlMs}`);
throw new BadRequestException(
"Verification code has expired. Request a new one.",
);
@@ -235,18 +338,31 @@ export class OtpService {
await this.otpRepository.deleteOtp(otpData);
this.actionAttempts.delete(key);
this.logVerify(
target,
"action",
"exhausted",
`attempts=${attempts}/${this.MAX_ACTION_ATTEMPTS} ageMs=${ageMs}`,
);
throw new BadRequestException(
"Too many incorrect attempts. Request a new code.",
);
}
this.actionAttempts.set(key, attempts);
this.logVerify(
target,
"action",
"invalid",
`attempts=${attempts}/${this.MAX_ACTION_ATTEMPTS} ageMs=${ageMs}`,
);
throw new BadRequestException("Invalid verification code");
}
// single-use: consume on success
await this.otpRepository.deleteOtp(otpData);
this.actionAttempts.delete(key);
this.logVerify(target, "action", "ok", `ageMs=${ageMs}`);
return { success: true };
}