Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
28 changes: 17 additions & 11 deletions backend/config/logger.ts
Original file line number Diff line number Diff line change
Expand Up @@ -17,6 +17,22 @@ import pino from 'pino'
const isDev = process.env.NODE_ENV !== 'production'
const level = process.env.LOG_LEVEL ?? (isDev ? 'debug' : 'info')

const SECRET_KEYS = ['password', 'currentPassword', 'newPassword', 'token', 'refreshToken']

// Redactar campos sensibles si aparecen accidentalmente. pino has no
// recursive wildcard: secrets are hidden at the first three levels. The SQL
// of a failed db.query carries its values interpolated (texts, plates,
// hashes); err.code and err.message stay
export const redact = {
paths: [
...SECRET_KEYS.flatMap((key) => [key, `*.${key}`, `*.*.${key}`]),
'req.headers.authorization',
'req.headers.cookie',
'*.sql',
],
censor: '[REDACTED]',
}

export const logger = pino({
level,
...(isDev
Expand All @@ -31,15 +47,5 @@ export const logger = pino({
},
}
: {}),
// Redactar campos sensibles si aparecen accidentalmente
redact: {
paths: [
'*.password',
'*.token',
'*.refreshToken',
'req.headers.authorization',
'req.headers.cookie',
],
censor: '[REDACTED]',
},
redact,
})
4 changes: 4 additions & 0 deletions backend/controllers/messages/conversation-controller.ts
Original file line number Diff line number Diff line change
Expand Up @@ -9,6 +9,7 @@ import {
} from '../../models/messages/index.js'
import { ERROR_CODES, SUCCESS_CODES } from '../../config/error-codes.js'
import { logger } from '../../config/logger.js'
import { logAdminOverride } from '../../middlewares/accessLog.js'
import {
createConversationSchema,
addParticipantsSchema,
Expand Down Expand Up @@ -86,6 +87,7 @@ export class ConversationController {
code: ERROR_CODES.MESSAGES_NO_ACCESS,
})
}
if (!isParticipant) logAdminOverride(req, 'read_conversation', { conversationId })

const conversation = await ConversationRepository.getByIdWithDetails(conversationId, userId)

Expand Down Expand Up @@ -435,6 +437,7 @@ export class ConversationController {
code: ERROR_CODES.MESSAGES_ADMIN_OR_SYSTEM_DELETE,
})
}
if (!isConversationAdmin) logAdminOverride(req, 'delete_conversation', { conversationId })

// Eliminar conversacion completa (mensajes se eliminan por CASCADE)
await ConversationRepository.deleteComplete(conversationId)
Expand Down Expand Up @@ -760,6 +763,7 @@ export class ConversationController {
}
const { limit } = query.data
const conversations = await ConversationRepository.getAll(limit)
logAdminOverride(req, 'list_all_conversations', { count: conversations.length })

return res.status(200).json({
success: true,
Expand Down
3 changes: 3 additions & 0 deletions backend/controllers/messages/message-controller.ts
Original file line number Diff line number Diff line change
Expand Up @@ -7,6 +7,7 @@ import { NotificationRepository } from '../../repositories/notifications/notific
import { MESSAGE_CONSTANTS } from '../../models/messages/index.js'
import { ERROR_CODES, SUCCESS_CODES } from '../../config/error-codes.js'
import { logger } from '../../config/logger.js'
import { logAdminOverride } from '../../middlewares/accessLog.js'
import {
NotificationModule,
NotificationRelatedTo,
Expand Down Expand Up @@ -55,6 +56,7 @@ export class MessageController {
code: ERROR_CODES.MESSAGES_NO_ACCESS,
})
}
if (!isParticipant) logAdminOverride(req, 'read_messages', { conversationId })

// Parametros de paginacion
const page = messagePageQuerySchema.safeParse(req.query)
Expand Down Expand Up @@ -302,6 +304,7 @@ export class MessageController {
code: ERROR_CODES.MESSAGES_ONLY_OWN_DELETE,
})
}
if (!isSender) logAdminOverride(req, 'delete_message', { messageId })

const deleted = await MessageRepository.delete(messageId)
if (!deleted) {
Expand Down
3 changes: 3 additions & 0 deletions backend/index.ts
Original file line number Diff line number Diff line change
Expand Up @@ -8,6 +8,7 @@ import { logServerInfo } from './config/startup-logger.js'
import { logger } from './config/logger.js'
import { apiLimiter } from './middlewares/rateLimiter.js'
import { noStore } from './middlewares/noStore.js'
import { logAccessDenied } from './middlewares/accessLog.js'
import { corsMiddleware } from './config/cors.js'

import { CronService } from './services/cron/cron-service.js'
Expand Down Expand Up @@ -66,6 +67,8 @@ app.use(cookieParser())
app.use('/api', apiLimiter)
// Personal and financial data must not stay in browser or proxy caches
app.use('/api', noStore)
// Every 403 leaves a trace in the log
app.use('/api', logAccessDenied)

// ========================================
// RUTAS
Expand Down
38 changes: 38 additions & 0 deletions backend/middlewares/accessLog.ts
Original file line number Diff line number Diff line change
@@ -0,0 +1,38 @@
// middlewares/accessLog.ts
// Authorization decisions leave a trace in the log (ASVS 7.2): every 403 the
// API answers, and every time an admin reads or deletes messages of a
// conversation they are not in.

import type { Request, Response, NextFunction } from 'express'
import { logger } from '../config/logger.js'

// Goes before the routes: logs the 403 whichever middleware or handler sends it
export function logAccessDenied(req: Request, res: Response, next: NextFunction): void {
res.on('finish', () => {
if (res.statusCode !== 403) return
logger.warn(
{
event: 'access_denied',
userId: req.user?.id ?? null,
role: req.user?.role ?? null,
method: req.method,
// Without the query string, which may carry search terms
path: req.originalUrl.split('?')[0],
},
'[SECURITY] access denied'
)
})
next()
}

// An admin acting where only participants or owners can
export function logAdminOverride(
req: Request,
action: string,
target: Record<string, unknown>
): void {
logger.info(
{ event: 'admin_override', userId: req.user?.id ?? null, action, ...target },
'[SECURITY] admin access to conversations of others'
)
}
133 changes: 133 additions & 0 deletions backend/tests/security/access-log.test.ts
Original file line number Diff line number Diff line change
@@ -0,0 +1,133 @@
// tests/security/access-log.test.ts
// Regression tests for the log (ASVS 7.1 and 7.2). The SQL of a failed
// db.query went to the log with its values interpolated (texts, plates,
// hashes), and `*.password` only hid the field one level down. No 403 left a
// trace, nor did an admin reading or deleting messages of a conversation they
// are not in.

import { describe, it, expect, vi, beforeEach } from 'vitest'
import { EventEmitter } from 'node:events'
import { Writable } from 'node:stream'
import { readFileSync } from 'node:fs'
import { join, dirname } from 'node:path'
import { fileURLToPath } from 'node:url'
import pino from 'pino'
import type { Request, Response } from 'express'

vi.mock('../../config/logger.js', async (importOriginal) => {
const actual = await importOriginal<typeof import('../../config/logger.js')>()
return { ...actual, logger: { warn: vi.fn(), info: vi.fn(), error: vi.fn(), debug: vi.fn() } }
})

const { logger, redact } = await import('../../config/logger.js')
const { logAccessDenied } = await import('../../middlewares/accessLog.js')

const backend = join(dirname(fileURLToPath(import.meta.url)), '..', '..')
const read = (...p: string[]) => readFileSync(join(backend, ...p), 'utf8')

// One line written by a pino logger with the app's redaction
function logged(obj: Record<string, unknown>): Record<string, unknown> {
let line = ''
const out = new Writable({
write(chunk, _enc, done) {
line += chunk.toString()
done()
},
})
pino({ redact }, out).error(obj, 'test')
return JSON.parse(line)
}

describe('log redaction', () => {
it('hides the SQL of a mysql2 error, which carries the values', () => {
const err = Object.assign(new Error("Duplicate entry '1234-ABC'"), {
code: 'ER_DUP_ENTRY',
sql: "INSERT INTO t VALUES ('1234-ABC', 'nota privada')",
})
const line = JSON.stringify(logged({ err }))
expect(line).not.toContain('nota privada')
expect(line).toContain('ER_DUP_ENTRY')
})

it('hides passwords and tokens at any of the first three levels', () => {
const line = JSON.stringify(
logged({
password: 'p0',
body: { newPassword: 'p1', token: 't1' },
req: { body: { password: 'p2', currentPassword: 'p3', refreshToken: 't2' } },
})
)
for (const secret of ['p0', 'p1', 'p2', 'p3', 't1', 't2']) {
expect(line, secret).not.toContain(`"${secret}"`)
}
})
})

describe('403 responses are logged', () => {
beforeEach(() => vi.clearAllMocks())

function respond(status: number, user?: { id: string; role: string }) {
const res = Object.assign(new EventEmitter(), { statusCode: status })
const req = { method: 'DELETE', originalUrl: '/api/cashier/daily/3?x=secret', user }
const next = vi.fn()
logAccessDenied(req as unknown as Request, res as unknown as Response, next)
expect(next).toHaveBeenCalledOnce()
res.emit('finish')
}

it('logs who was refused what, without the query string', () => {
respond(403, { id: 'u1', role: 'recepcionista' })
expect(logger.warn).toHaveBeenCalledWith(
{
event: 'access_denied',
userId: 'u1',
role: 'recepcionista',
method: 'DELETE',
path: '/api/cashier/daily/3',
},
'[SECURITY] access denied'
)
})

it('ignores every other status', () => {
for (const status of [200, 201, 400, 401, 404, 500]) respond(status)
expect(logger.warn).not.toHaveBeenCalled()
})

it('runs for the whole API, before the routes', () => {
const index = read('index.ts')
const at = index.indexOf("app.use('/api', logAccessDenied)")
expect(at).toBeGreaterThan(-1)
expect(at).toBeLessThan(index.indexOf("app.use('/api/auth', authRoutes)"))
})
})

describe('admins acting on conversations they are not in are logged', () => {
const conversations = read('controllers', 'messages', 'conversation-controller.ts')
const messages = read('controllers', 'messages', 'message-controller.ts')

// Body of `static async name(` up to the next static method
function method(source: string, name: string): string {
const start = source.indexOf(`static async ${name}(`)
expect(start, name).toBeGreaterThan(-1)
const next = source.indexOf('static async ', start + 1)
return source.slice(start, next === -1 ? undefined : next)
}

it.each([
[conversations, 'getConversation', 'isParticipant', 'read_conversation'],
[conversations, 'deleteConversation', 'isConversationAdmin', 'delete_conversation'],
[messages, 'getMessages', 'isParticipant', 'read_messages'],
[messages, 'deleteMessage', 'isSender', 'delete_message'],
])('%#: %s logs the override', (source, name, own, action) => {
expect(method(source, name)).toMatch(
new RegExp(`if \\(!${own}\\) logAdminOverride\\(req, '${action}', \\{`)
)
})

it('the moderation list of every conversation is logged', () => {
expect(method(conversations, 'getAllConversations')).toContain(
"logAdminOverride(req, 'list_all_conversations'"
)
})
})
11 changes: 11 additions & 0 deletions docs/general/README.md
Original file line number Diff line number Diff line change
Expand Up @@ -93,6 +93,17 @@ if it does not match.
server to server).
- In production, unhandled errors return a generic message.

**Log**

- Every `403` is logged (`access_denied`: user, role, method and path, without
the query string), and so is every time an `admin` reads, lists or deletes
conversations or messages they are not in (`admin_override`).
- Passwords and tokens are hidden at the first three levels of each entry, and
so is the SQL of a failed query (`err.sql`), which carries its values.
- Failed logins keep the username that was typed (decided on 2026-10-12, left
as is): it is what reveals a brute-force attack, although someone may type
their password in that field.

**Database**

- Every schema change is a new, idempotent script in `backend/db-mysql/scripts/`
Expand Down
Loading