2026-08-17 11:58:38 -05:00
# Diseño de Logging
2026-08-17 10:34:12 -05:00
2026-08-17 11:58:38 -05:00
> 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`.
2026-08-17 10:34:12 -05:00
## Objetivo
2026-08-17 11:58:38 -05:00
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` .
2026-08-17 10:34:12 -05:00
2026-08-17 11:58:38 -05:00
## Piezas
2026-08-17 10:34:12 -05:00
2026-08-17 11:58:38 -05:00
### `context.py`
2026-08-17 10:34:12 -05:00
2026-08-17 11:58:38 -05:00
Dos `ContextVar` por request (aisladas entre corrutinas concurrentes de
FastAPI):
2026-08-17 10:34:12 -05:00
2026-08-17 11:58:38 -05:00
- `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).
2026-08-17 10:34:12 -05:00
2026-08-17 11:58:38 -05:00
### `main.py`
2026-08-17 10:34:12 -05:00
2026-08-17 11:58:38 -05:00
- `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()` .
2026-08-17 10:34:12 -05:00
2026-08-17 11:58:38 -05:00
### `logger_config.py` — `JsonFormatter`
2026-08-17 10:34:12 -05:00
2026-08-17 11:58:38 -05:00
En modo `"production"` (default), cada línea de log —tanto en consola como
en `logs/backend.log` — es un JSON con esta forma:
2026-08-17 10:34:12 -05:00
```json
2026-08-17 11:58:38 -05:00
{ "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 }
2026-08-17 10:34:12 -05:00
```
2026-08-17 11:58:38 -05:00
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.
2026-08-17 10:34:12 -05:00
2026-08-17 11:58:38 -05:00
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.
2026-08-17 10:34:12 -05:00
2026-08-17 11:58:38 -05:00
## Qué NO se loguea
2026-08-17 10:34:12 -05:00
2026-08-17 11:58:38 -05:00
`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.
2026-08-17 10:34:12 -05:00
2026-08-17 11:58:38 -05:00
## Verificación
2026-08-17 10:34:12 -05:00
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).
2026-08-17 11:58:38 -05:00
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` .
2026-08-17 10:34:12 -05:00
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** .