Como usar a etapa de perfil de execução para avaliar suas consultas do Gremlin

APLICA-SE AO: Gremlin

Este artigo fornece uma visão geral de como usar a etapa de perfil de execução dos bancos de dados de grafo do Azure Cosmos DB for Gremlin. Esta etapa fornece informações relevantes para solução de problemas e otimizações de consulta e é compatível com qualquer consulta Gremlin que possa ser executada em uma conta de API do Gremlin do Cosmos DB.

Para usar essa etapa, basta acrescentar a chamada executionProfile() de função ao final da consulta do Gremlin. Sua consulta do Gremlin será executada e o resultado da operação retornará um objeto de resposta JSON com o perfil de execução de consulta.

Por exemplo:

    // Basic traversal
    g.V('mary').out()

    // Basic traversal with execution profile call
    g.V('mary').out().executionProfile()

Depois de chamar a etapa executionProfile(), a resposta será um objeto JSON que inclui a etapa do Gremlin executada, o tempo total que levou e uma matriz dos operadores de runtime do Cosmos DB que a instrução resultou.

Observação

Esta implementação para o perfil de execução não está definida na especificação do Apache Tinkerpop. Ela é específica da implementação do Azure Cosmos DB for Gremlin.

Exemplo de resposta

A seguir está um exemplo anotado da saída que será retornada:

Observação

Este exemplo é anotado com comentários que explicam a estrutura geral da resposta. Uma resposta executionProfile real não conterá nenhum comentário.

[
  {
    // The Gremlin statement that was executed.
    "gremlin": "g.V('mary').out().executionProfile()",

    // Amount of time in milliseconds that the entire operation took.
    "totalTime": 28,

    // An array containing metrics for each of the steps that were executed. 
    // Each Gremlin step will translate to one or more of these steps.
    // This list is sorted in order of execution.
    "metrics": [
      {
        // This operation obtains a set of Vertex objects.
        // The metrics include: time, percentTime of total execution time, resultCount, 
        // fanoutFactor, count, size (in bytes) and time.
        "name": "GetVertices",
        "time": 24,
        "annotations": {
          "percentTime": 85.71
        },
        "counts": {
          "resultCount": 2
        },
        "storeOps": [
          {
            "fanoutFactor": 1,
            "count": 2,
            "size": 696,
            "time": 0.4
          }
        ]
      },
      {
        // This operation obtains a set of Edge objects. 
        // Depending on the query, these might be directly adjacent to a set of vertices, 
        // or separate, in the case of an E() query.
        //
        // The metrics include: time, percentTime of total execution time, resultCount, 
        // fanoutFactor, count, size (in bytes) and time.
        "name": "GetEdges",
        "time": 4,
        "annotations": {
          "percentTime": 14.29
        },
        "counts": {
          "resultCount": 1
        },
        "storeOps": [
          {
            "fanoutFactor": 1,
            "count": 1,
            "size": 419,
            "time": 0.67
          }
        ]
      },
      {
        // This operation obtains the vertices that a set of edges point at.
        // The metrics include: time, percentTime of total execution time and resultCount.
        "name": "GetNeighborVertices",
        "time": 0,
        "annotations": {
          "percentTime": 0
        },
        "counts": {
          "resultCount": 1
        }
      },
      {
        // This operation represents the serialization and preparation for a result from 
        // the preceding graph operations. The metrics include: time, percentTime of total 
        // execution time and resultCount.
        "name": "ProjectOperator",
        "time": 0,
        "annotations": {
          "percentTime": 0
        },
        "counts": {
          "resultCount": 1
        }
      }
    ]
  }
]

Observação

A etapa executionProfile executará a consulta Gremlin. Isso inclui as etapas addV ou addE, que vão resultar na criação e confirmar as alterações especificadas na consulta. Como resultado, as unidades de solicitação geradas pela consulta Gremlin também serão cobradas.

Objetos de resposta do perfil de execução

A resposta de uma função executionProfile() produzirá uma hierarquia de objetos JSON com a seguinte estrutura:

  • Objeto de operação Gremlin: representa a operação do Gremlin inteira que foi executada. Contém as propriedades a seguir.

    • gremlin: a instrução do Gremlin explícita que foi executada.
    • totalTime: o tempo, em milissegundos, em que a execução da etapa incorreu.
    • metrics: uma matriz que contém cada um dos operadores de runtime do Cosmos DB que foram executados para atender à consulta. Essa lista é classificada em ordem de execução.
  • Operadores de runtime do Cosmos DB: representa cada um dos componentes de toda a operação do Gremlin. Essa lista é classificada em ordem de execução. Cada objeto contém as seguintes propriedades:

    • name: nome do operador. Esse é o tipo de etapa que foi avaliado e executado. Leia mais na tabela a seguir.
    • time: quantidade de tempo, em milissegundos, que um determinado operador levou.
    • annotations: contém informações adicionais, específicas para o operador que foi executado.
    • annotations.percentTime: percentual do tempo total necessário para executar o operador específico.
    • counts: número de objetos que foram retornados da camada de armazenamento por este operador. Isso está contido no valor escalar counts.resultCount interno.
    • storeOps: representa uma operação de armazenamento que pode abranger uma ou várias partições.
    • storeOps.fanoutFactor: representa o número de partições que essa operação de armazenamento específica acessou.
    • storeOps.count: representa o número de resultados que essa operação de armazenamento retornou.
    • storeOps.size: representa o tamanho em bytes do resultado de uma determinada operação de armazenamento.
Operador de runtime do Gremlin do Cosmos DB Descrição
GetVertices Esta etapa obtém um conjunto de objetos predicados da camada de persistência.
GetEdges Esta etapa obtém as bordas que são adjacentes a um conjunto de vértices. Essa etapa pode resultar em uma ou várias operações de armazenamento.
GetNeighborVertices Esta etapa obtém os vértices que estão conectados a um conjunto de bordas. As bordas contêm as chaves de partição e as IDs de seus vértices de origem e de destino.
Coalesce Esta etapa conta a avaliação de duas operações sempre que a etapa do Gremlin coalesce() é executada.
CartesianProductOperator Esta etapa computa um produto cartesiano entre dois conjuntos de dados. Geralmente executado sempre que os predicados to() ou from() são usados.
ConstantSourceOperator Esta etapa computa uma expressão para produzir um valor constante como resultado.
ProjectOperator Esta etapa prepara e serializa uma resposta usando o resultado de operações anteriores.
ProjectAggregation Esta etapa prepara e serializa uma resposta para uma operação de agregação.

Observação

Esta lista continuará a ser atualizada à medida que novos operadores forem adicionados.

Exemplos de como analisar uma resposta de perfil de execução

Veja os seguintes exemplos de otimizações comuns que podem ser expostas usando a resposta do perfil de execução:

  • Consulta do tipo fan-out cega.
  • Consulta não filtrada.

Padrões de consulta do tipo fan-out cega

Suponha a seguinte resposta de perfil de execução de um grafo particionado:

[
  {
    "gremlin": "g.V('tt0093640').executionProfile()",
    "totalTime": 46,
    "metrics": [
      {
        "name": "GetVertices",
        "time": 46,
        "annotations": {
          "percentTime": 100
        },
        "counts": {
          "resultCount": 1
        },
        "storeOps": [
          {
            "fanoutFactor": 5,
            "count": 1,
            "size": 589,
            "time": 75.61
          }
        ]
      },
      {
        "name": "ProjectOperator",
        "time": 0,
        "annotations": {
          "percentTime": 0
        },
        "counts": {
          "resultCount": 1
        }
      }
    ]
  }
]

É possível chegar às seguintes conclusões com isso:

  • A consulta é uma pesquisa de ID única, uma vez que a instrução do Gremlin segue o padrão g.V('id').
  • Com base na métrica time, a latência dessa consulta parece estar alta, pois é mais de 10 ms para uma só operação de leitura de ponto.
  • Se olharmos para o objeto storeOps, poderemos ver que o fanoutFactor é 5, o que significa que cinco partições foram acessadas por essa operação.

Como uma conclusão dessa análise, podemos determinar que a primeira consulta está acessando mais partições do que o necessário. Isso pode ser resolvido especificando a chave de particionamento na consulta como um predicado. Isso resultará em menos latência e menos custo por consulta. Saiba mais sobre o particionamento de grafo. Uma consulta mais ideal seria g.V('tt0093640').has('partitionKey', 't1001').

Padrões de consulta não filtrados

Compare as duas respostas de perfil de execução a seguir. Para simplificar, esses exemplos usam um só grafo particionado.

Essa primeira consulta recupera todos os vértices com o rótulo tweet e então obtém seus vértices vizinhos:

[
  {
    "gremlin": "g.V().hasLabel('tweet').out().executionProfile()",
    "totalTime": 42,
    "metrics": [
      {
        "name": "GetVertices",
        "time": 31,
        "annotations": {
          "percentTime": 73.81
        },
        "counts": {
          "resultCount": 30
        },
        "storeOps": [
          {
            "fanoutFactor": 1,
            "count": 13,
            "size": 6819,
            "time": 1.02
          }
        ]
      },
      {
        "name": "GetEdges",
        "time": 6,
        "annotations": {
          "percentTime": 14.29
        },
        "counts": {
          "resultCount": 18
        },
        "storeOps": [
          {
            "fanoutFactor": 1,
            "count": 20,
            "size": 7950,
            "time": 1.98
          }
        ]
      },
      {
        "name": "GetNeighborVertices",
        "time": 5,
        "annotations": {
          "percentTime": 11.9
        },
        "counts": {
          "resultCount": 20
        },
        "storeOps": [
          {
            "fanoutFactor": 1,
            "count": 4,
            "size": 1070,
            "time": 1.19
          }
        ]
      },
      {
        "name": "ProjectOperator",
        "time": 0,
        "annotations": {
          "percentTime": 0
        },
        "counts": {
          "resultCount": 20
        }
      }
    ]
  }
]

Observe o perfil da mesma consulta, mas agora com um filtro adicional, has('lang', 'en'), antes de explorar os vértices adjacentes:

[
  {
    "gremlin": "g.V().hasLabel('tweet').has('lang', 'en').out().executionProfile()",
    "totalTime": 14,
    "metrics": [
      {
        "name": "GetVertices",
        "time": 14,
        "annotations": {
          "percentTime": 58.33
        },
        "counts": {
          "resultCount": 11
        },
        "storeOps": [
          {
            "fanoutFactor": 1,
            "count": 11,
            "size": 4807,
            "time": 1.27
          }
        ]
      },
      {
        "name": "GetEdges",
        "time": 5,
        "annotations": {
          "percentTime": 20.83
        },
        "counts": {
          "resultCount": 18
        },
        "storeOps": [
          {
            "fanoutFactor": 1,
            "count": 18,
            "size": 7159,
            "time": 1.7
          }
        ]
      },
      {
        "name": "GetNeighborVertices",
        "time": 5,
        "annotations": {
          "percentTime": 20.83
        },
        "counts": {
          "resultCount": 18
        },
        "storeOps": [
          {
            "fanoutFactor": 1,
            "count": 4,
            "size": 1070,
            "time": 1.01
          }
        ]
      },
      {
        "name": "ProjectOperator",
        "time": 0,
        "annotations": {
          "percentTime": 0
        },
        "counts": {
          "resultCount": 18
        }
      }
    ]
  }
]

Essas duas consultas atingiram o mesmo resultado, no entanto, a primeira exigirá mais unidades de solicitação, pois precisa iterar um conjunto de dados inicial maior antes de consultar os itens adjacentes. Podemos ver os indicadores desse comportamento ao comparar os seguintes parâmetros de ambas as respostas:

  • O valor metrics[0].time é maior na primeira resposta, o que indica que essa única etapa demorou mais para ser resolvida.
  • O valor metrics[0].counts.resultsCount é mais alto também na primeira resposta, o que indica que o conjunto de dados de trabalho inicial foi maior.

Próximas etapas