DEV Community

Cover image for Prisma query logging y PostgreSQL: dónde termina el ORM y empieza la base
Juan Torchia
Juan Torchia Subscriber

Posted on • Originally published at juanchi.dev

Prisma query logging y PostgreSQL: dónde termina el ORM y empieza la base

Prisma query logging y PostgreSQL: dónde termina el ORM y empieza la base

Activé query logging en Prisma, vi los queries llegando a la consola, y asumí que tenía visibilidad completa sobre lo que pasaba en la base. Spoiler: no la tenía.

Los logs de Prisma muestran la query que el cliente envía y el tiempo que tardó desde la perspectiva del ORM — incluyendo serialización, red y el overhead del driver. Lo que no muestran es qué hace PostgreSQL con esa query adentro: si usó un índice, si hizo un sequential scan, si hubo lock wait, si el planner eligió mal el plan. Esa parte vive en Postgres, no en el ORM.

Mi tesis: los query logs de Prisma son una herramienta de debugging de patrones, no de diagnóstico de base de datos. Confundirlos lleva a buscar el problema en el lugar equivocado y a tomar decisiones de optimización sin evidencia real.


Qué dice la documentación oficial de Prisma — y qué no dice

La documentación oficial de Prisma logging es clara sobre lo que el sistema ofrece: tres niveles de log (INFO, WARN, ERROR) más el nivel especial query, que emite la query SQL, los parámetros, la duración y el target.

La configuración básica se ve así:

// Inicializamos el cliente con logging de queries habilitado
const prisma = new PrismaClient({
  log: [
    {
      emit: 'event',   // emitimos como evento para procesarlo nosotros
      level: 'query',
    },
    {
      emit: 'stdout',  // errores y warnings van directo a consola
      level: 'error',
    },
    {
      emit: 'stdout',
      level: 'warn',
    },
  ],
})

// Escuchamos el evento de query para loguear con estructura
prisma.$on('query', (e) => {
  console.log({
    query: e.query,       // SQL generado por Prisma
    params: e.params,     // parámetros bindeados
    duration: e.duration, // duración en ms desde el cliente Prisma
    target: e.target,     // nombre del datasource (ej: "db")
  })
})
Enter fullscreen mode Exit fullscreen mode

Lo que la doc no menciona explícitamente es que e.duration mide el tiempo desde que el cliente Prisma envía la query hasta que recibe la respuesta. Ese número incluye latencia de red, parsing del driver, serialización del resultado y eventual contención del connection pool. No es el tiempo que PostgreSQL tardó en ejecutar la query. Son cosas distintas y mezclarlas genera diagnósticos incorrectos.

Para capturar el tiempo real de ejecución en Postgres, necesitás pg_stat_statements o EXPLAIN ANALYZE directamente en la base. Esas herramientas viven del lado del motor, no del ORM.


El error más común: confundir duración de cliente con tiempo de ejecución en Postgres

Un patrón típico en equipos que empiezan a usar Prisma: ven una query con duration: 800 en los logs y concluyen que "la query es lenta". Puede ser cierto. Pero también puede ser que la query en Postgres tarde 20ms y los 780ms restantes sean contención en el pool, latencia de red o deserialization overhead de un resultado muy grande.

Sin distinción entre esos tiempos, cualquier optimización es especulativa.

Un escenario concreto donde esto pega: consultás una tabla con muchas columnas y seleccionás SELECT * porque Prisma, por defecto con findMany(), trae todos los campos. El tiempo de ejecución en Postgres puede ser razonable, pero el tiempo de transferencia y serialización del payload puede ser lo que infla la duración que ves en el log. La solución no es un índice — es un select explícito:

// En vez de traer todos los campos (comportamiento default de findMany)
const usuarios = await prisma.usuario.findMany()

// Seleccionamos solo lo que necesitamos
const usuarios = await prisma.usuario.findMany({
  select: {
    id: true,
    email: true,
    creadoEn: true,
    // excluimos columnas grandes como avatarBase64, metadataJson, etc.
  },
})
Enter fullscreen mode Exit fullscreen mode

Este cambio puede bajar la duración visible en logs sin tocar ningún índice. Si hubieras ido directo a Postgres a "optimizar la query", habrías perdido tiempo buscando un problema que no existía ahí.


Cuándo Prisma logging alcanza y cuándo necesitás mirar PostgreSQL

Esta es la decisión técnica que más importa. Armé una guía de criterios basada en lo que cada capa puede y no puede mostrarte:

Prisma query logging alcanza cuando:

  • Detectás un N+1: ves decenas de queries iguales en el log para una sola request. Este es el caso de uso donde Prisma logging brilla. Si querés profundizar en patrones de N+1 en Server Actions, hay más contexto en este post sobre Prisma y Next.js 16.
  • Buscás queries innecesarias: logs te muestran si una pantalla hace queries que no debería hacer.
  • Verificás que select explícito funciona: podés confirmar que Prisma genera el SQL correcto antes de llegar a la base.
  • Depurás filtros mal escritos: la query logueada te muestra si el where se traduce como esperás.
  • Mapeás frecuencia de queries por endpoint: con emit por evento podés contar y agrupar sin herramientas externas.

Necesitás mirar PostgreSQL directamente cuando:

  • La duración del cliente es alta pero el patrón de queries parece correcto: investigá pg_stat_statements para ver tiempo real en Postgres.
  • Sospechás un sequential scan: EXPLAIN ANALYZE en la misma query te dice si hay un índice que no se está usando.
  • Hay bloqueos o deadlocks: pg_locks y pg_stat_activity son las herramientas. Prisma no ve esto.
  • El problema aparece bajo carga pero no en local: puede ser contención del pool o autovacuum que se activa con volumen real. Ninguna de las dos cosas aparece en logs de ORM.
  • Querés entender el plan del query planner: el plan puede cambiar con los datos reales y con las estadísticas de la tabla. Solo EXPLAIN ANALYZE te lo muestra.
-- Corrés esto directamente en PostgreSQL para ver el plan real de ejecución
EXPLAIN (ANALYZE, BUFFERS, FORMAT TEXT)
SELECT u.id, u.email
FROM "Usuario" u
WHERE u.estado = 'activo'
ORDER BY u."creadoEn" DESC
LIMIT 50;

-- Buffers=true muestra cuántos bloques leyó de disco vs caché
-- Analyze=true ejecuta la query de verdad (cuidado en tablas con writes pesados)
Enter fullscreen mode Exit fullscreen mode

Checklist de diagnóstico: por dónde empezar

Antes de optimizar algo, respondé estas preguntas en orden:

1. ¿El log de Prisma muestra muchas queries para una sola operación?
   → Sí: revisá N+1, eager loading, relaciones mal cargadas
   → No: seguí

2. ¿El SQL generado tiene sentido? ¿Traemos columnas que no usamos?
   → Problema: agregá select explícito en Prisma
   → OK: seguí

3. ¿La duración en Prisma es alta de forma consistente o esporádica?
   → Esporádica: investigá pool contention, conexiones agotadas
   → Consistente: seguí

4. ¿Tenés pg_stat_statements habilitado en PostgreSQL?
   → No: habilitarlo es el próximo paso antes de seguir diagnosticando
   → Sí: buscá la query por query text y mirá mean_exec_time real

5. ¿El plan de ejecución usa índice o sequential scan?
   → EXPLAIN ANALYZE en la query real con datos reales
   → Si hay seq scan en tabla grande con filtros, ahí está el problema
Enter fullscreen mode Exit fullscreen mode

Límites claros: qué no podés concluir solo con Prisma logs

Esto importa y no lo suficiente gente lo dice:

  • No podés concluir que "la query es lenta" basándote solo en e.duration sin saber cuánto de ese tiempo es Postgres vs overhead del driver vs red.
  • No podés detectar lock waits ni deadlocks desde el cliente ORM. Un query que espera un lock va a aparecer con duración alta, pero el motivo es invisible desde Prisma.
  • No podés ver si autovacuum está compitiendo con tus writes. Ese ruido de fondo aparece como lentitud intermitente que no correlaciona con ningún patrón en el log del cliente.
  • No podés validar que un índice se está usando sin EXPLAIN. Que Prisma genere un WHERE correcto no garantiza que Postgres elija el índice que esperás.
  • No podés reproducir el comportamiento bajo carga real solo con logs locales. El pool tiene un tamaño máximo (configurable con connection_limit en el datasource), y la contención aparece cuando hay concurrencia real.

Si el diagnóstico requiere cualquiera de esos puntos, el log de Prisma es un punto de partida, no la respuesta.


FAQ: Prisma query logging y PostgreSQL

¿Cómo habilito el query logging en Prisma sin mandar todo a stdout?

Usá emit: 'event' en vez de emit: 'stdout' y manejás el evento prisma.$on('query', handler). Así podés filtrar, estructurar o mandarlo a tu sistema de logging sin contaminar la salida estándar en producción.

¿El duration del log de Prisma es el mismo que el tiempo de ejecución en PostgreSQL?

No. La duración del cliente Prisma incluye serialización, latencia de red y overhead del driver. El tiempo real de ejecución en Postgres lo obtenés con pg_stat_statements o EXPLAIN ANALYZE. Pueden diferir bastante dependiendo del tamaño del resultado y la latencia de red.

¿Cómo habilito pg_stat_statements en PostgreSQL?

Agregás pg_stat_statements a shared_preload_libraries en postgresql.conf, reiniciás el servidor y ejecutás CREATE EXTENSION IF NOT EXISTS pg_stat_statements; en la base. Desde ahí podés consultar pg_stat_statements para ver tiempos de ejecución reales por query.

¿Tiene sentido loguear queries en producción?

Depende del volumen. En producción con tráfico alto, loguear cada query puede generar overhead de I/O significativo. Una alternativa más prudente es loguear solo queries que superen un threshold de duración, o usar OpenTelemetry con sampling. El tema de observabilidad con trazas lo cubrí en el contexto de Spring Boot pero los principios son similares — más detalles en el post de OpenTelemetry.

¿Prisma tiene alguna forma de hacer EXPLAIN ANALYZE directamente?

No nativa. Podés usar prisma.$queryRaw para ejecutar EXPLAIN ANALYZE manualmente:

// Ejecutamos EXPLAIN ANALYZE via queryRaw para ver el plan real
const plan = await prisma.$queryRaw`
  EXPLAIN (ANALYZE, BUFFERS, FORMAT JSON)
  SELECT id, email FROM "Usuario" WHERE estado = 'activo'
`
console.log(JSON.stringify(plan, null, 2))
Enter fullscreen mode Exit fullscreen mode

Esto es útil en desarrollo para validar que el planner usa los índices que esperás.

¿Si no veo queries lentas en los logs de Prisma, puedo asumir que la base está bien?

No. La ausencia de queries lentas en el cliente no garantiza ausencia de problemas en Postgres. Puede haber table bloat, índices sin actualizar, autovacuum retrasado o queries que corren rápido individualmente pero generan presión acumulada. El diagnóstico de la base requiere sus propias herramientas.


Mi postura: son capas distintas, no alternativas

Lo incómodo de este tema es que la mayoría de la documentación de Prisma (incluyendo la oficial) muestra cómo configurar el logging sin aclarar explícitamente qué mide y qué no mide. Eso genera una suposición razonable pero incorrecta: que tener query logging activado equivale a tener visibilidad sobre el comportamiento de la base.

No es así. Prisma logging es debugging de capa ORM. PostgreSQL tiene su propia capa de observabilidad y necesita sus propias herramientas. Las dos son necesarias y se complementan, pero no se reemplazan.

Mi recomendación práctica: usá Prisma logging para detectar patrones de queries (N+1, selects innecesarios, queries duplicadas por request). Cuando el patrón parece correcto y el problema persiste, pasá a pg_stat_statements y EXPLAIN ANALYZE. No saltees el primer paso porque es más fácil de activar, pero tampoco te quedes ahí si la respuesta no aparece.

El próximo paso concreto: si tenés pg_stat_statements deshabilitado en tu base, eso es lo primero que habilitaría. Sin él, estás diagnosticando a ciegas en la capa que más importa.


Fuentes originales:


Este artículo fue publicado originalmente en juanchi.dev

Top comments (0)