test(auth): security utils unit tests and controller integration tests; structured logging and error handling

docs/api/auth-error-handling.md

@@ -0,0 +1,5 @@
+# Auth API error handling
+
+`POST /auth/password-reset/request` no longer fails when the reset email cannot be sent. Previously a mail-provider error propagated as a `500`, which let a caller tell registered addresses (500) from unknown ones (silent success). The failure is now caught and logged (`auth.password_reset_email_failed`, with the user id and a hash of the email, never the address or token), and the response is the same as for an unknown address.
+
+The reset token is still created, so a retry from the user produces a fresh token and email.

docs/api/auth-structured-logging.md

@@ -0,0 +1,16 @@
+# Auth API structured logging
+
+`AuthService` now uses the project's `AppLogger`. Security-relevant events are logged as a short constant message plus a metadata object with a stable `event` name, instead of interpolated sentences, so they can be filtered and alerted on in the JSON logs produced in production:
+
+| `event` | Level | Fields |
+| --- | --- | --- |
+| `auth.refresh_token_reuse` | error | `userId`, `jti`, `family`, `ipAddress` |
+| `auth.token_rotated` | log | `userId`, `emailHash`, `family`, `ipAddress` |
+| `auth.logout` | log | `userId`, `emailHash`, `loggedOutAt` |
+| `auth.blacklist_access_token_failed` / `auth.blacklist_refresh_token_failed` | warn | `userId`, `error` |
+| `auth.lockout_email_failed` | error | `userId`, `emailHash`, `error` |
+| `auth.captcha_failed` / `auth.captcha_error` | warn / error | `errorCodes` / `error` |
+| `auth.verification_resent` | log | `userId` |
+| `auth.password_reset_email_failed` | error | `userId`, `emailHash`, `error` |
+
+Emails appear only as a short hash, and `AppLogger` redacts fields such as `password`, `token` and `secret` before writing.

docs/api/auth-tests.md

@@ -0,0 +1,6 @@
+# Auth API tests
+
+- **Unit** - `src/auth/security.utils.spec.ts` covers the crypto helpers behind login and 2FA: `sanitizeUser`, hashing/redaction, base32, backup codes, TOTP (RFC 6238 test vectors, window and trimming behaviour), otpauth/QR URLs and `parseDuration`.
+- **Integration** - `test/e2e/auth-controller.integration.spec.ts` boots `AuthController` over HTTP with the same `ValidationPipe` settings as `main.ts`, mocked `AuthService` and guards: valid and invalid login/register/refresh/password-reset requests (400 for invalid, unknown fields rejected, service untouched), and guarded routes (`/auth/me`, `/auth/change-password`).
+
+Run with `npx jest src/auth/security.utils.spec.ts test/e2e/auth-controller.integration.spec.ts`.

src/auth/auth.service.ts

@@ -1,7 +1,6 @@
 import {
   BadRequestException,
   Injectable,
-  Logger,
   NotFoundException,
   Optional,
   ServiceUnavailableException,
@@ -86,7 +85,7 @@ interface RecaptchaVerifyResponse {
 
 @Injectable()
 export class AuthService {
-  private readonly logger = new Logger(AuthService.name);
+  private readonly logger = new AppLogger(AuthService.name);
   private readonly issuer = 'PropChain';
 
   private readonly registrationIpMap = new Map<string, { email: string; expiresAt: Date }>();
@@ -356,9 +355,12 @@ export class AuthService {
       if (shouldLock) {
         const lockoutDuration = 30;
         await this.emailService.sendAccountLockedEmail(user.email, lockoutDuration).catch((err) => {
-          this.logger.error(
-            `Failed to send account locked email to user ${user.id} (${this.hashEmail(user.email)}): ${err.message}`,
-          );
+          this.logger.error('Failed to send account locked email', {
+            event: 'auth.lockout_email_failed',
+            userId: user.id,
+            emailHash: this.hashEmail(user.email),
+            error: err.message,
+          });
         });
         throw new UnauthorizedException(
           `Account locked due to too many failed login attempts. Please try again in ${lockoutDuration} minutes.`,
@@ -517,9 +519,13 @@ export class AuthService {
       await this.handleTokenReuse(blacklistedToken, payload.jti, ipAddress, userAgent);
       await this.fraudService.handleTokenReuse(payload.sub, payload.jti, ipAddress, userAgent);
 
-      this.logger.error(
-        `Refresh token reuse detected for user ${payload.sub} (JTI: ${payload.jti}, Family: ${payload.family}). IP: ${ipAddress}`,
-      );
+      this.logger.error('Refresh token reuse detected', {
+        event: 'auth.refresh_token_reuse',
+        userId: payload.sub,
+        jti: payload.jti,
+        family: payload.family,
+        ipAddress,
+      });
 
       throw new UnauthorizedException(
         'Token reuse detected. All sessions have been invalidated for security. Please login again.',
@@ -555,9 +561,13 @@ export class AuthService {
     // Issue new token pair with SAME family ID
     const tokens = await this.issueTokenPair(user, payload.family, ipAddress, userAgent);
 
-    this.logger.log(
-      `Token rotated for user ${user.id} (${this.hashEmail(user.email)}). Family: ${payload.family}. IP: ${ipAddress}`,
-    );
+    this.logger.log('Refresh token rotated', {
+      event: 'auth.token_rotated',
+      userId: user.id,
+      emailHash: this.hashEmail(user.email),
+      family: payload.family,
+      ipAddress,
+    });
 
     return {
       user: sanitizeUser(user),
@@ -621,9 +631,11 @@ export class AuthService {
         });
       } catch (error: unknown) {
         // Token might already be expired or invalid, continue with logout
-        this.logger.warn(
-          `Failed to blacklist access token for user ${user.sub}: ${(error as Error).message}`,
-        );
+        this.logger.warn('Failed to blacklist access token', {
+          event: 'auth.blacklist_access_token_failed',
+          userId: user.sub,
+          error: (error as Error).message,
+        });
       }
     }
 
@@ -647,16 +659,21 @@ export class AuthService {
           throw error;
         }
         // Token might already be expired or invalid, continue with logout
-        this.logger.warn(
-          `Failed to blacklist refresh token for user ${user.sub}: ${(error as Error).message}`,
-        );
+        this.logger.warn('Failed to blacklist refresh token', {
+          event: 'auth.blacklist_refresh_token_failed',
+          userId: user.sub,
+          error: (error as Error).message,
+        });
       }
     }
 
     // Log the logout event
-    this.logger.log(
-      `User ${user.sub} (${this.hashEmail(user.email)}) logged out successfully at ${logoutTime.toISOString()}`,
-    );
+    this.logger.log('User logged out', {
+      event: 'auth.logout',
+      userId: user.sub,
+      emailHash: this.hashEmail(user.email),
+      loggedOutAt: logoutTime.toISOString(),
+    });
 
     return {
       message: 'Logged out successfully',
@@ -1869,10 +1886,16 @@ export class AuthService {
         return true;
       }
 
-      this.logger.warn(`CAPTCHA verification failed: ${JSON.stringify(data['error-codes'])}`);
+      this.logger.warn('CAPTCHA verification failed', {
+        event: 'auth.captcha_failed',
+        errorCodes: data['error-codes'] ?? [],
+      });
       return false;
     } catch (error: unknown) {
-      this.logger.error(`Error verifying CAPTCHA: ${(error as Error).message}`);
+      this.logger.error('Error verifying CAPTCHA', {
+        event: 'auth.captcha_error',
+        error: (error as Error).message,
+      });
       return false;
     }
   }
@@ -1973,6 +1996,6 @@ export class AuthService {
         this.logger.error('Failed to queue verification email:', err?.message || err);
       });
 
-    this.logger.log(`Verification email resent for user ${user.id}`);
+    this.logger.log('Verification email resent', { event: 'auth.verification_resent', userId: user.id });
   }
 }

src/auth/security.utils.spec.ts

@@ -0,0 +1,167 @@
+import {
+  buildOtpAuthUrl,
+  buildQrCodeUrl,
+  createSha256,
+  decodeBase32,
+  generateBackupCodes,
+  generateReactivationToken,
+  generateTotpCode,
+  parseDuration,
+  randomBase32Secret,
+  randomToken,
+  redactEmail,
+  sanitizeUser,
+  verifyBackupCode,
+  verifyTotpCode,
+} from './security.utils';
+
+// RFC 6238 test secret: ASCII "12345678901234567890" in base32.
+const RFC_SECRET = 'GEZDGNBVGY3TQOJQGEZDGNBVGY3TQOJQ';
+
+describe('security.utils', () => {
+  describe('sanitizeUser', () => {
+    it('removes password and two-factor secrets but keeps other fields', () => {
+      const user = {
+        id: 'u1',
+        email: 'a@example.com',
+        password: 'hash',
+        twoFactorSecret: 'secret',
+        twoFactorBackupCodes: ['x'],
+      };
+      expect(sanitizeUser(user)).toEqual({ id: 'u1', email: 'a@example.com' });
+    });
+
+    it('does not mutate its input', () => {
+      const user = { id: 'u1', password: 'hash' };
+      sanitizeUser(user);
+      expect(user.password).toBe('hash');
+    });
+  });
+
+  describe('hashing helpers', () => {
+    it('createSha256 matches the known digest of "abc"', () => {
+      expect(createSha256('abc')).toBe(
+        'ba7816bf8f01cfea414140de5dae2223b00361a396177a9cb410ff61f20015ad',
+      );
+    });
+
+    it('redactEmail is a short, stable, non-reversible token', () => {
+      const redacted = redactEmail('user@example.com');
+      expect(redacted).toHaveLength(8);
+      expect(redacted).toBe(redactEmail('user@example.com'));
+      expect(redacted).not.toContain('user');
+      expect(redacted).not.toBe(redactEmail('other@example.com'));
+    });
+
+    it('randomToken returns 2*size hex characters and differs between calls', () => {
+      const a = randomToken(16);
+      expect(a).toMatch(/^[0-9a-f]{32}$/);
+      expect(a).not.toBe(randomToken(16));
+    });
+
+    it('generateReactivationToken returns a token and its sha256 hash', () => {
+      const { token, hash } = generateReactivationToken();
+      expect(hash).toBe(createSha256(token));
+    });
+  });
+
+  describe('base32', () => {
+    it('randomBase32Secret has the requested length and alphabet', () => {
+      expect(randomBase32Secret(20)).toMatch(/^[A-Z2-7]{20}$/);
+    });
+
+    it('decodeBase32 decodes the RFC 6238 secret', () => {
+      expect(decodeBase32(RFC_SECRET).toString('ascii')).toBe('12345678901234567890');
+    });
+
+    it('decodeBase32 ignores padding, case and characters outside the alphabet', () => {
+      expect(decodeBase32('gezd gnbv gy3t qojq gezd gnbv gy3t qojq==').toString('ascii')).toBe(
+        '12345678901234567890',
+      );
+    });
+  });
+
+  describe('backup codes', () => {
+    it('generates the requested number of 8-character upper-case hex codes', () => {
+      const codes = generateBackupCodes(5);
+      expect(codes).toHaveLength(5);
+      codes.forEach((code) => expect(code).toMatch(/^[0-9A-F]{8}$/));
+    });
+
+    it('verifyBackupCode finds the matching hash, ignoring case and whitespace', () => {
+      const hashes = ['ABCD1234', 'DEADBEEF'].map(createSha256);
+      expect(verifyBackupCode('  deadbeef ', hashes)).toBe(hashes[1]);
+    });
+
+    it('verifyBackupCode returns undefined for an unknown code or no hashes', () => {
+      expect(verifyBackupCode('00000000', [createSha256('ABCD1234')])).toBeUndefined();
+      expect(verifyBackupCode('ABCD1234', [])).toBeUndefined();
+    });
+  });
+
+  describe('TOTP', () => {
+    it('matches the RFC 6238 SHA-1 test vectors', () => {
+      // T = 59s -> 94287082 (8 digits); the 6-digit code is its last six digits.
+      expect(generateTotpCode({ secret: RFC_SECRET, digits: 8, timestamp: 59_000 })).toBe('94287082');
+      expect(generateTotpCode({ secret: RFC_SECRET, timestamp: 59_000 })).toBe('287082');
+      // T = 1111111109s -> 07081804 (8 digits).
+      expect(generateTotpCode({ secret: RFC_SECRET, digits: 8, timestamp: 1_111_111_109_000 })).toBe(
+        '07081804',
+      );
+    });
+
+    it('verifyTotpCode accepts the current code and one adjacent period', () => {
+      const now = 59_000;
+      expect(verifyTotpCode({ secret: RFC_SECRET, code: '287082', timestamp: now })).toBe(true);
+      // Same code, verified 30s later: still inside the +/-1 window.
+      expect(verifyTotpCode({ secret: RFC_SECRET, code: '287082', timestamp: now + 30_000 })).toBe(
+        true,
+      );
+    });
+
+    it('verifyTotpCode rejects codes outside the window or when the window is 0', () => {
+      expect(verifyTotpCode({ secret: RFC_SECRET, code: '287082', timestamp: 59_000 + 90_000 })).toBe(
+        false,
+      );
+      expect(
+        verifyTotpCode({ secret: RFC_SECRET, code: '287082', timestamp: 59_000 + 30_000, window: 0 }),
+      ).toBe(false);
+      expect(verifyTotpCode({ secret: RFC_SECRET, code: '000000', timestamp: 59_000 })).toBe(false);
+    });
+
+    it('verifyTotpCode trims whitespace around the submitted code', () => {
+      expect(verifyTotpCode({ secret: RFC_SECRET, code: ' 287082 ', timestamp: 59_000 })).toBe(true);
+    });
+  });
+
+  describe('otpauth URLs', () => {
+    it('buildOtpAuthUrl encodes the label and issuer', () => {
+      const url = buildOtpAuthUrl('a+b@example.com', RFC_SECRET, 'Prop Chain');
+      expect(url).toBe(
+        `otpauth://totp/Prop%20Chain%3Aa%2Bb%40example.com?secret=${RFC_SECRET}&issuer=Prop%20Chain&algorithm=SHA1&digits=6&period=30`,
+      );
+    });
+
+    it('buildQrCodeUrl url-encodes the otpauth URL', () => {
+      const otp = buildOtpAuthUrl('a@example.com', RFC_SECRET);
+      expect(buildQrCodeUrl(otp)).toBe(`https://quickchart.io/qr?text=${encodeURIComponent(otp)}`);
+    });
+  });
+
+  describe('parseDuration', () => {
+    it.each([
+      ['30s', 30],
+      ['15m', 900],
+      ['2h', 7200],
+      ['7d', 604800],
+      ['45', 45],
+      ['5M', 300],
+    ])('parses %s as %i seconds', (input, expected) => {
+      expect(parseDuration(input, 1)).toBe(expected);
+    });
+
+    it.each([[''], ['   '], ['abc'], ['-5'], ['0']])('falls back for %p', (input) => {
+      expect(parseDuration(input, 99)).toBe(99);
+    });
+  });
+});