/ /

Database Profiler

Docs Home

/ /

Analizar el rendimiento del query

Conceptos CRUD de MongoDB

Optimización de consultas

Analizar el rendimiento del query

Database Profiler

Salida del perfilador de base de datos

El perfilador de base de datos captura la información sobre las operaciones de lectura y escritura, las operaciones de cursor y los comandos de base de datos. Para configurar el perfil de base de datos y establecer los umbrales para capturar datos de perfil, consulta el perfilador de base de datos section.

El generador de perfiles de base de datos escribe datos en el system.profile colección, que es una colección con tamaño fijo. Para ver el resultado del perfilador, utiliza consultas normales de MongoDB en la colección system.profile.

Nota

Debido a que el generador de perfiles de base de datos escribe datos system.profile en la colección de una base de datos, el generador de perfiles registra cierta actividad de escritura, incluso para bases de datos que, de otro modo, serían de solo lectura.

currentOp y el perfilador de base de datos reportan la misma información básica de diagnóstico para las operaciones CRUD, incluyendo lo siguiente:

Estas operaciones también se incluyen en el registro de las query lentas. Consulta slowOpThresholdMs para obtener más información sobre el registro de query lentas.

Al utilizar Queryable Encryption, las operaciones CRUD en colecciones encriptadas se omiten de la colección system.profile. Para más detalles, consulte restricción.

Ya no es posible realizar ninguna operación, incluidas las lecturas, en la colección system.profile desde dentro de una transacción.

Campos de salida

Para cada operación, los documentos creados por el generador de perfiles de base de datos incluyen un subconjunto de los siguientes campos. La selección precisa de campos en estos documentos depende del tipo de operación.

Nota

Para obtener la salida específica de su versión de MongoDB, consulte la versión correspondiente del Manual de MongoDB.

system.profile.op

El tipo de operación. Los valores posibles son:

command
count
distinct
geoNear
getMore
group
insert
mapReduce
query
remove
update

system.profile.ns: El espacio de nombres al que se dirige la operación. En MongoDB, los espacios de nombres tienen la forma de la base de datos, seguido de un punto. () y, a continuación, del nombre de la colección.

system.profile.command

Un documento que contiene el objeto de comando completo asociado con esta operación.

Por ejemplo, la siguiente salida contiene el objeto de comando para una operación en una colección find llamada items en una base de datos test llamada:

"command" : {
  "find" : "items",
  "filter" : {
    "sku" : 1403978
  },
  ...
  "$db" : "test"
}

El siguiente resultado de ejemplo contiene el objeto de comando para una operación getMore generado por un comando con ID de cursor 19234103609 en una colección llamada items en una base de datos llamada test:

"command" : {
    "getMore" : Long("19234103609"),
    "collection" : "items",
    "batchSize" : 10,
    ...
    "$db" : "test"
},

Si el documento de comando supera los 50 kilobytes, el documento tiene la siguiente forma:

"command" : {
  "$truncated": <string>,
  "comment": <string>
}

El campo $truncated contiene un resumen de cadena del documento, excluyendo el campo comment, si lo hay. Si el resumen aún supera los 50 kilobytes, se trunca aún más, lo que se indica con puntos suspensivos (...) al final de la cadena.

El campo comment está presente si se pasó un comentario a la operación. Se puede adjuntar un comentario a cualquier comando de base de datos.

system.profile.originatingCommand: Para las operaciones "getmore" que recuperan el siguiente lote de resultados de un cursor, el campo originatingCommand contiene el objeto de comando completo (por ejemplo, find o aggregate) que creó originalmente ese cursor.

system.profile.cursorid: El ID del cursor al que se accede mediante operaciones query y getmore.

system.profile.keysExamined

El número de claves de índices que MongoDB analizó para realizar la operación.

En general, si keysExamined es mucho mayor que nreturned, la base de datos está escaneando muchas claves de índice para encontrar los documentos de resultados. Considere crear o ajustar índices para mejorar el rendimiento de las consultas. .

keysExamined está disponible para los siguientes comandos y operaciones:

system.profile.docsExamined

El número de documentos en la colección que MongoDB escaneó para llevar a cabo la operación.

docsExamined está disponible para los siguientes comandos y operaciones:

system.profile.hasSortStage

hasSortStage es un booleano que está true cuando una query no puede usar el orden en el índice para devolver los resultados ordenados solicitados; es decir, MongoDB debe ordenar los documentos después de recibirlos de un cursor. El campo solo aparece cuando el valor es true.

hasSortStage está disponible para los siguientes comandos y operaciones:

system.profile.usedDisk

Un booleano que indica si algún paso de agregación escribió datos en archivos temporales debido a restricciones de memoria.

Solo aparece si usedDisk es verdadero.

system.profile.ndeleted: El número de documentos eliminados por la operación.

system.profile.ninserted: El número de documentos insertados por la operación.

system.profile.nMatched: El número de documentos que coincide con la condición de query para la operación de actualización.

system.profile.nModified: El número de documentos modificados por la operación de actualización.

system.profile.upsert: Un valor booleano que indica el valor de la opción upsert de la operación de actualización. Solo aparece si upsert es verdadero.

system.profile.fromMultiPlanner

Un valor booleano que indica si el planificador de queries evaluó varios planes antes de escoger el plan de ejecución ganador para la query.

Solo se presenta cuando el valor es true.

system.profile.replanned

Un booleano que indica si el sistema de query eliminó un plan en caché y re-evaluó todos los planes candidatos.

Solo se presenta cuando el valor es true.

system.profile.replanReason

Una cadena que indica el motivo específico por el que se desalojó un plan almacenado en caché.

Solo se aplica cuando el valor de replanned es true.

system.profile.keysInserted: El número de claves de índice insertadas para una operación de escritura dada.

system.profile.writeConflicts: El número de conflictos encontrados durante la operación de guardar; por ejemplo, una operación de update intenta modificar el mismo documento que otra operación de update. Consulte también el conflicto de escritura.

system.profile.numYield: El número de veces que la operación cedió para permitir que otras operaciones se completaran. Por lo general, las operaciones ceden cuando necesitan acceder a datos que MongoDB aún no ha leído completamente en la memoria. Esto permite que se completen otras operaciones que tengan datos en memoria mientras MongoDB lee datos para la operación de liberación de recursos. Para obtener más información, consulta las preguntas frecuentes sobre cuándo se producen las operaciones.

system.profile.queryHash

Una cadena hexadecimal que representa un hash de la forma del query y depende únicamente de la forma del query. queryHash puede ayudar a identificar queries lentas (incluyendo el filtro de query de las operaciones de guardar) con la misma forma del query.

Nota

Como con cualquier función encriptada, dos formas del query diferentes pueden dar como resultado el mismo valor encriptado. Sin embargo, es poco probable que ocurran colisiones encriptadas entre diferentes formas del query.

Para obtener más información sobre queryHash y planCacheKey, consulta queryHash y planCacheKey.

system.profile.planCacheKey

Un hash de la clave para la entrada de caché del plan asociada con el query.

A diferencia del queryHash, el planCacheKey es una función tanto de la forma del query como de los índices actualmente disponibles para esa forma. Es decir, si se añaden/descartan índices que puedan admitir la forma del query, el valor de planCacheKey puede cambiar, mientras que el valor de queryHash no cambiaría.

Para obtener más información sobre queryHash y planCacheKey, consulta queryHash y planCacheKey.

system.profile.queryFramework: La estructura del query utilizada para procesar una operación.

system.profile.locks

El system.profile.locks proporciona información sobre diversos tipos de bloqueos y modos de bloqueo mantenidos durante la operación.

Los posibles tipos de bloqueo son:

Tipo de bloqueo	Descripción
`ParallelBatchWriterMode`	Representa un bloqueo para el modo de escritura por lotes paralelo. En versiones anteriores, la información de PBWM se informaba como parte de la información de bloqueo de `Global`.
`ReplicationStateTransition`	Representa el bloqueo tomado para las transiciones de estado del nodo del set de réplicas.
`Global`	Representa el bloqueo global.
`Database`	Representa el bloqueo de la base de datos.
`Collection`	Representa un bloqueo de colección.
`Mutex`	Representa una exclusión mutua.
`Metadata`	Representa un bloqueo de metadatos.
`oplog`	Representa un bloqueo en el oplog.

Los posibles modos de bloqueo para los tipos de cerradura son los siguientes:

Modo de bloqueo	Descripción
`R`	Representa un bloqueo compartido (S).
`W`	Representa un bloqueo exclusivo (X).
`r`	Representa un bloqueo de intención compartida (IS).
`w`	Representa un bloqueo de intención exclusiva (IX).

La información de bloqueo devuelta para los distintos tipos de bloqueo incluye:

system.profile.locks.acquireCount: Cantidad de veces que la operación adquirió el bloqueo en el modo especificado.

system.profile.locks.acquireWaitCount: Número de veces que la operación tuvo que esperar las acquireCount adquisiciones de bloqueo porque los bloqueos se mantuvieron en un modo conflictivo. es menor oacquireWaitCount igual acquireCount a.

system.profile.locks.timeAcquiringMicros

Tiempo acumulado en microsegundos que la operación tuvo que esperar para adquirir los bloqueos.

timeAcquiringMicros dividido por acquireWaitCount proporciona un tiempo de espera promedio aproximado para la moda de bloqueo particular.

system.profile.locks.deadlockCount: Número de veces que la operación encontró bloqueos mutuos al esperar la adquisición de bloqueos.

Para obtener más información sobre los modos de bloqueo, consulta ¿Qué tipo de bloqueo utiliza MongoDB?

system.profile.authorization

Novedades en la versión 5.0.0.

El número de veces que se accede al caché del usuario para cada operación. Estas métricas sólo se muestran cuando una operación ha accedido al usuario caché al menos una vez.

Estas métricas solo están disponibles cuando el registro de operaciones lentas o la creación de perfil de base de datos están activados.

system.profile.authorization no está incluido en la db.currentOp() salida.

system.profile.authorization.startedUserCacheAcquisitionAttempts: La cantidad de veces que la operación intentó acceder a la caché del usuario.

system.profile.authorization.completedUserCacheAcquisitionAttempts: El número de veces que la operación recuperó datos de usuario de la caché de usuario.

system.profile.authorization.userCacheWaitTimeMicros: El tiempo total que la operación pasó esperando respuestas de la caché de usuario.

system.profile.storage

La información proporciona métricas sobre los datos del motor de almacenamiento y el tiempo de espera para la system.profile.storage operación.

Las métricas de almacenamiento específicas solo se devuelven si los valores son mayores que cero.

system.profile.storage.data.bytesRead

Número de bytes leídos por la operación desde el disco hasta la caché.

Los datos leídos del disco a la caché incluyen todo lo necesario para ejecutar la consulta. Si los datos ya están en la caché, el número de bytes leídos del disco podría ser 0.

El número de bytes leídos del disco incluye más que los documentos consultados:

WiredTiger lee en unidades de páginas y una página puede contener uno o varios documentos. Si un documento se encuentra en una página, todos los documentos de esa página se cargan en la caché y se incluyen en el valor bytesRead.
Si la caché requiere gestión de páginas (como desalojo o relecturas), el valor de bytesRead incluye los datos leídos de disco en estas operaciones.
Si el índice no está en la caché o si el índice en la caché está obsoleto, WiredTiger lee varias páginas internas y de hojas del disco para reconstruir el índice en la caché.

system.profile.storage.data.timeReadingMicros: Tiempo en microsegundos que la operación tuvo que pasar para leer desde el disco.

system.profile.storage.data.bytesWritten

Número de bytes escritos por la operación desde la caché al disco.

Normalmente, WiredTiger no requiere que la query se escriba en disco. Los datos modificados por la query se escriben en una caché en memoria que WiredTiger vacía en disco como parte de una operación de eliminación o punto de control. En tales casos, bytesWritten se muestra como 0.

Si el hilo que ejecuta la consulta requiere una gestión forzada de páginas (como una expulsión), WiredTiger escribe el contenido de la página en el disco. Es probable que este vaciado incluya datos no relacionados con los cambios realizados por la propia consulta, lo que puede provocar que bytesWritten muestre un valor superior al esperado.

system.profile.storage.data.timeWritingMicros: Tiempo en microsegundos que la operación tuvo que dedicar a guardar en el disco.

system.profile.storage.timeWaitingMicros.cache: Tiempo en microsegundos que la operación tuvo que esperar para tener espacio en la caché.

system.profile.storage.timeWaitingMicros.schemaLock: Tiempo en microsegundos que la operación (si modificaba el esquema) tuvo que esperar para adquirir un bloqueo de esquema.

system.profile.storage.timeWaitingMicros.handleLock: Tiempo en microsegundos que la operación tuvo que esperar para adquirir el bloqueo en los manejadores de datos necesarios.

system.profile.nreturned: El número de documentos devueltos por la operación.

system.profile.responseLength

La longitud, en bytes, del documento del resultado de la operación. Un responseLength grande puede afectar el rendimiento. Para limitar el tamaño del documento de resultados para una operación de query, puedes utilizar cualquiera de los siguientes métodos:

Nota

Cuando MongoDB escribe información del perfil de query en el registro, el valor de responseLength se encuentra en un campo denominado reslen.

system.profile.cpuNanos: Nuevo en la versión 6.3.
El tiempo total de CPU utilizado por una operación de query, en nanosegundos. Este campo solo está disponible en sistemas Linux.

system.profile.protocol: El formato de mensaje de solicitud del protocolo de conexión de MongoDB.

system.profile.millis: El tiempo en milisegundos desde la perspectiva de mongod, desde el inicio hasta el final de la operación.

planningTimeMicros: Nuevo en la versión 6.2.
El tiempo, en microsegundos, que el comando find o aggregate pasó en query planning.

system.profile.planSummary: Un resumen del plan de ejecución.

system.profile.execStats

Un documento que contiene las estadísticas de ejecución de la operación de query. Para otras operaciones, el valor es un documento vacío.

El system.profile.execStats presenta las estadísticas como un árbol; cada nodo proporciona las estadísticas de la operación ejecutada durante esa etapa de la operación de query.

Nota

La siguiente lista de campos para execStats no pretende ser exhaustiva ya que los campos devueltos varían según la etapa.

system.profile.execStats.stage

El nombre descriptivo de la operación realizada como parte de la ejecución de la query; p. ej.

COLLSCAN para un escaneo de colección
IXSCAN para el escaneo de claves de índice
FETCH para la recuperación de documentos

system.profile.execStats.inputStages: Un arreglo que contiene estadísticas de las operaciones que son las etapas de entrada de la etapa actual.

system.profile.ts: La marca de tiempo de la operación.

system.profile.client: La dirección IP o el nombre del host de la conexión cliente desde donde se origina la operación.

system.profile.appName: El identificador de la aplicación cliente que ejecutó la operación. Utiliza la opción de cadena de conexión appName para establecer un valor personalizado para el campo appName.

system.profile.allUsers: Una matriz de información de usuario autenticado (nombre de usuario y base de datos) para la sesión. Consulte también Usuarios en implementaciones autogestionadas.

system.profile.user: El usuario autenticado que ejecutó la operación. Si la operación no fue ejecutada por un usuario autenticado, el valor de este campo es una string vacía.

Ejemplo de documento `system.profile`

Los siguientes ejemplos presentan documentos de muestra que se encuentran en la colección system.profile para operaciones en un autónomo:

El siguiente documento en la colección system.profile muestra métricas sobre una operación de query de ejemplo en la colección test.report:

{
   "op" : "query",
   "ns" : "test.report",
   "command" : {
      "find" : "report",
      "filter" : { "a" : { "$lte" : 500 } },
      "lsid" : {
         "id" : UUID("5ccd5b81-b023-41f3-8959-bf99ed696ce9")
      },
      "$db" : "test"
   },
   "cursorid" : 33629063128,
   "keysExamined" : 101,
   "docsExamined" : 101,
   "fromMultiPlanner" : true,
   "numYield" : 2,
   "nreturned" : 101,
   "queryHash" : "811451DD",
   "planCacheKey" : "759981BA",
   "queryFramework" : "classic",
   "locks" : {
      "Global" : {
         "acquireCount" : {
            "r" : Long(3),
            "w" : Long(3)
         }
      },
      "Database" : {
         "acquireCount" : { "r" : Long(3) },
         "acquireWaitCount" : { "r" : Long(1) },
         "timeAcquiringMicros" : { "r" : Long(69130694) }
      },
      "Collection" : {
         "acquireCount" : { "r" : Long(3) }
      }
   },
   "storage" : {
      "data" : {
         "bytesRead" : Long(14736),
         "timeReadingMicros" : Long(17)
      }
   },
   "responseLength" : 1305014,
   "protocol" : "op_msg",
   "millis" : 69132,
   "planningTimeMicros" : 129,
   "planSummary" : "IXSCAN { a: 1, _id: -1 }",
   "execStats" : {
      "stage" : "FETCH",
      "nReturned" : 101,
      "executionTimeMillisEstimate" : 0,
      "works" : 101,
      "advanced" : 101,
      "needTime" : 0,
      "needYield" : 0,
      "saveState" : 3,
      "restoreState" : 2,
      "isEOF" : 0,
      "docsExamined" : 101,
      "alreadyHasObj" : 0,
      "inputStage" : {
         ...
      }
   },
   "ts" : ISODate("2019-01-14T16:57:33.450Z"),
   "client" : "127.0.0.1",
   "appName" : "MongoDB Shell",
   "allUsers" : [
      {
         "user" : "someuser",
         "db" : "admin"
      }
   ],
   "user" : "someuser@admin"
}

La colecciónsystem.profileincluye métricas para la operacióngetMore. En este ejemplo, getMore devuelve documentos adicionales de la colección test.report.

{
   "op" : "getmore",
   "ns" : "test.report",
   "command" : {
      "getMore" : Long("33629063128"),
      "collection" : "report",
      "batchSize": 3,
      "lsid" : {
         "id": new UUID("3148c569-425c-4498-9168-5b7ee260bf27")
      },
      "$db" : "test"
   },
   originatingCommand: {
      "find: "report",
      "filter" : { "a" : { "$lte" : 500 } },
      "lsid" : {
         "id" : UUID("5ccd5b81-b023-41f3-8959-bf99ed696ce9")
      },
      "$db" : "test"
   },
   "cursorid" : Long("33629063128"),
   "keysExamined" : 101,
   "docsExamined" : 101,
   "fromMultiPlanner" : true,
   "numYield" : 2,
   "nreturned" : 3,
   "queryHash" : "811451DD",
   "planCacheKey" : "759981BA",
   "queryFramework": "classic"
   "locks" : {
      "Global" : {
         "acquireCount" : {
            "r" : Long(3),
            "w" : Long(3)
         }
      },
      "Database" : {
         "acquireCount" : { "r" : Long(3) },
         "acquireWaitCount" : { "r" : Long(1) },
         "timeAcquiringMicros" : { "r" : Long(69130694) }
      },
      "Collection" : {
         "acquireCount" : { "r" : Long(3) }
      }
   },
   readConcern: {level: 'local', provenance: 'implicitDefault'},
   "responseLength" : 1305014,
   "protocol" : "op_msg",
   "millis" : 69132,
   "planSummary" : "IXSCAN { a: 1, _id: -1 }",
   "execStats" : {
      "stage" : "FETCH",
      "filter" : { "a" : { "$lte" : 500 } },
      "nReturned" : 101,
      "executionTimeMillisEstimate" : 0,
      "works" : 104,
      "advanced" : 104,
      "needTime" : 0,
      "needYield" : 0,
      "saveState" : 3,
      "restoreState" : 2,
      "isEOF" : 0,
      "direction": 'forward',
      "docsExamined" : 104
   },
   "ts" : ISODate("2019-01-14T16:57:33.450Z"),
   "client" : "127.0.0.1",
   "appName" : "MongoDB Shell",
   "allUsers" : [
      {
         "user" : "someuser",
         "db" : "admin"
      }
   ],
   "user" : "someuser@admin"
}

La entrada de perfil para update (y delete) operación contiene todo el comando de actualización.

El siguiente documento en la colección system.profile muestra métricas para una operación de actualización de ejemplo en la colección test.report:

{
   "op" : "update",
   "ns" : "test.report",
   "command" : {
      "q" : { },
      "u" : { "$rename" : { "a" : "b" } },
      "multi" : true,
      "upsert" : false
   },
   "keysExamined" : 0,
   "docsExamined" : 25000,
   "nMatched" : 25000,
   "nModified" : 25000,
   "keysInserted" : 25000,
   "keysDeleted" : 25000000,
   "numYield" : 6985,
   "locks" : {
      "Global" : {
         "acquireCount" : { "r" : Long(6986), "w" : Long(13972) }
      },
      "Database" : {
         "acquireCount" : { "w" : Long(6986) },
         "acquireWaitCount" : { "w" : Long(1) },
         "timeAcquiringMicros" : { "w" : Long(60899375) }
      },
      "Collection" : {
         "acquireCount" : { "w" : Long(6986) }
      },
      "Mutex" : {
         "acquireCount" : { "r" : Long(25000) }
      }
   },
   "storage" : {
      "data" : {
         "bytesRead" : Long(126344060),
         "bytesWritten" : Long(281834762),
         "timeReadingMicros" : Long(94549),
         "timeWritingMicros" : Long(139361)
      }
   },
   "millis" : 164687,
   "planningTimeMicros" : 129,
   "planSummary" : "COLLSCAN",
   "execStats" : {
      "stage" : "UPDATE",
      "nReturned" : 0,
      "executionTimeMillisEstimate" : 103771,
      "works" : 25003,
      "advanced" : 0,
      "needTime" : 25002,
      "needYield" : 0,
      "saveState" : 6985,
      "restoreState" : 6985,
      "isEOF" : 1,
      "nMatched" : 25000,
      "nWouldModify" : 25000,
      "wouldInsert" : false,
      "inputStage" : {
         "stage" : "COLLSCAN",
         "nReturned" : 25000,
         "executionTimeMillisEstimate" : 0,
         "works" : 25002,
         "advanced" : 25000,
         "needTime" : 1,
         "needYield" : 0,
         "saveState" : 31985,
         "restoreState" : 31985,
         "isEOF" : 1,
         "direction" : "forward",
         "docsExamined" : 25000
      }
   },
   "ts" : ISODate("2019-01-14T23:33:01.806Z"),
   "client" : "127.0.0.1",
   "appName" : "MongoDB Shell",
   "allUsers" : [
      {
         "user" : "someuser",
         "db" : "admin"
      }
   ],
   "user" : "someuser@admin"
}

Volver

Database Profiler

Encontrar queries lentas

Nota

Campos de salida

Nota

Nota

Nota

Nota

Ejemplo de documento system.profile

Ejemplo de documento `system.profile`