Files
mini-erp/mini-backend/docs/logging-plan.md
T
2026-08-17 11:58:38 -05:00

85 lines
4.0 KiB
Markdown

# Diseño de Logging
> Nota: este documento describía originalmente un plan pendiente. Ya está
> implementado tal como se describe abajo; se conserva el nombre del
> archivo por los enlaces existentes desde `index.md`.
## Objetivo
Cada línea de log queda etiquetada automáticamente con el `request_id` de
la petición HTTP y con el empleado conectado que la originó (`webUser`,
`emp_id`, `full_name`), en formato JSON, sin tener que pasar esos datos a
mano en cada llamada a `logger.info/warning/error`.
## Piezas
### `context.py`
Dos `ContextVar` por request (aisladas entre corrutinas concurrentes de
FastAPI):
- `request_id_ctx` — expuesta via `get_request_id()` / `set_request_id()`.
- `current_user_ctx` — dict `{"webUser", "emp_id", "full_name"}`, expuesta
via `get_current_user()` / `set_current_user(webUser, full_name="", emp_id="-")`.
Por defecto ambas quedan en `"-"` cuando no hay usuario autenticado
(por ejemplo, en el propio `POST /api/Login` antes de validar credenciales).
### `main.py`
- `correlation_id_middleware` llama a `set_request_id()` con el header
`X-Request-ID` entrante o un UUID generado si no viene.
- `session_middleware`, tras validar el token con
`validate_and_refresh_session()`, llama a
`set_current_user(webUser, get_employee_name(webUser), get_emp_id(webUser))`
para que el resto de la petición (incluyendo las llamadas a
`forward_to_sapb1`) quede etiquetada con ese usuario.
- `routers/auth.py` también llama a `set_current_user(...)` en un login
exitoso, porque `/api/Login` no pasa por el `session_middleware`
(todavía no hay token) y de otro modo su propio log quedaría sin usuario.
- `LOG_ENVIRONMENT` (variable de entorno, default `"production"`) decide el
formato de salida en `setup_logging()`.
### `logger_config.py` — `JsonFormatter`
En modo `"production"` (default), cada línea de log —tanto en consola como
en `logs/backend.log`— es un JSON con esta forma:
```json
{"timestamp": "2026-08-14T15:32:10.123456+00:00", "level": "INFO", "request_id": "3f2a...", "webUser": "jgarcia", "emp_id": "11", "full_name": "Juan García", "http_method": "GET", "endpoint": "Items", "status_code": 200, "message": "[200] GET Items", "module": "sap", "function": "forward_to_sapb1", "line": 141}
```
Campos siempre presentes: `timestamp`, `level`, `request_id`, `webUser`,
`emp_id`, `full_name`, `message`, `module`, `function`, `line`. Campos
opcionales (`http_method`, `endpoint`, `status_code`) se agregan solo si el
`logger.info/warning/error(...)` que generó la línea los pasó vía
`extra={...}` — este es el patrón que usan `core/sap.py`,
`core/api_gateway.py` y `routers/reports.py` para dejar trazabilidad de
cada llamada saliente. Si el log viene de una excepción (`exc_info`), se
agrega también `exception` con el traceback formateado.
En cualquier otro valor de `LOG_ENVIRONMENT` (por ejemplo `"development"`),
la consola usa un formato de texto plano legible
(`%(asctime)s [%(levelname)s] %(module)s.%(funcName)s:%(lineno)d - %(message)s`)
en vez de JSON — pensado para desarrollo local, no para buscar en el
archivo. El archivo `logs/backend.log` (rotativo, 5 MB x 3 backups vía
`RotatingFileHandler`) siempre se escribe en JSON sin importar el entorno.
## Qué NO se loguea
`routers/auth.py` nunca escribe `Password` / `U_WEB_PASS` en los logs, ni en
éxito ni en fallo de login — solo el `webUser`, el `EmployeeID` y si el
intento fue exitoso o el motivo del rechazo (`"Usuario no registrado"`,
`"Usuario inactivo"`, contraseña incorrecta). Al auditar un cambio en el
flujo de login, verificar que esta regla se mantenga.
## Verificación
1. Levantar el backend (local o Docker).
2. Loguearse con un usuario de prueba y hacer un par de llamadas reales
(GET a algún catálogo, POST/PATCH a algo).
3. Revisar `logs/backend.log`: cada línea debe traer `webUser`, `emp_id`,
`full_name`, y las líneas de proxy SAP también `http_method`,
`endpoint`, `status_code`.
4. `grep` de la contraseña de prueba sobre todo `logs/backend.log` (y la
salida de consola) para confirmar que **no aparece en ningún lado**.