API профилирования

Раздел query содержит подробное время выполнения дерева запросов, выполняемого Lucene на определенном фрагменте. Общая структура этого дерева запросов будет напоминать ваш исходный запрос Elasticsearch, но может быть немного (или иногда сильно) отличаться. Она также будет использовать похожие, но не всегда идентичные имена. Используя наш предыдущий пример запроса match, давайте проанализируем раздел query:

"query": [
    {
       "type": "BooleanQuery",
       "description": "message:get message:search",
       "time_in_nanos": "11972972",
       "breakdown": {...},               
       "children": [
          {
             "type": "TermQuery",
             "description": "message:get",
             "time_in_nanos": "3801935",
             "breakdown": {...}
          },
          {
             "type": "TermQuery",
             "description": "message:search",
             "time_in_nanos": "205654",
             "breakdown": {...}
          }
       ]
    }
]

Основываясь на структуре профиля, мы видим, что наш запрос match был переписан Lucene в BooleanQuery с двумя операндами (оба содержат TermQuery). Поле type отображает имя класса Lucene и часто совпадает с эквивалентным именем в Elasticsearch. Поле description отображает текст объяснения Lucene для запроса и предназначено для помощи в различении частей вашего запроса (например, message:get и message:search являются TermQuery и в противном случае выглядели бы одинаково).

Поле time_in_nanos показывает, что для выполнения всего BooleanQuery этот запрос потребовал ~11,9 мс. Зафиксированное время включает время всех дочерних элементов.

Поле breakdown предоставит подробные данные о том, как было затрачено время, мы посмотрим на это чуть позже. Наконец, массив children перечисляет любые подзапросы, которые могут быть присутствуют. Поскольку мы искали два значения ("get search"), наш BooleanQuery содержит два дочерних TermQueries. Они имеют идентичную информацию (тип, время, детализация и т. д.). Дочерние элементы могут иметь свои собственные дочерние элементы.

Компонент breakdown предоставляет подробную статистику времени о выполнении низкоуровневых операций Lucene:

"breakdown": {
  "set_min_competitive_score_count": 0,
  "match_count": 5,
  "shallow_advance_count": 0,
  "set_min_competitive_score": 0,
  "next_doc": 39022,
  "match": 4456,
  "next_doc_count": 5,
  "score_count": 5,
  "compute_max_score_count": 0,
  "compute_max_score": 0,
  "advance": 84525,
  "advance_count": 1,
  "score": 37779,
  "build_scorer_count": 2,
  "create_weight": 4694895,
  "shallow_advance": 0,
  "create_weight_count": 1,
  "build_scorer": 7112295,
  "count_weight": 0,
  "count_weight_count": 0
}

Время указано в наносекундах реального времени и не нормализовано. Все замечания по общему time_in_nanos применимы и здесь. Цель детализации - дать вам представление о том, А) какие механизмы в Lucene фактически потребляют время, и Б) величину различий во времени между различными компонентами. Как и общее время, детализация включает время всех дочерних элементов.

Значения статистики таковы:

Раздел Collectors ответа показывает подробные сведения об исполнении на высоком уровне. Lucene работает, определяя «Collector», который отвечает за координацию обхода, подсчёта очков и сбора совпадающих документов. Collectors также позволяют одному запросу записывать результаты агрегации, выполнять нескомпонованные «глобальные» запросы, выполнять фильтры после запроса и т. д.

Рассмотрим предыдущий пример:

"collector": [
  {
    "name": "QueryPhaseCollector",
    "reason": "search_query_phase",
    "time_in_nanos": 775274,
    "children" : [
      {
        "name": "SimpleTopScoreDocCollector",
        "reason": "search_top_hits",
        "time_in_nanos": 775274
      }
    ]
  }
]

Мы видим коллектор верхнего уровня, названный QueryPhaseCollector, который содержит дочерний элемент SimpleTopScoreDocCollector. SimpleTopScoreDocCollector — это стандартный «подсчёт очков и сортировка» Collector, используемый Elasticsearch. Поле reason пытается дать простое словесное описание имени класса. Поле time_in_nanos аналогично времени в дереве запросов: время, измеряемое от начала до конца, включая все дочерние элементы. Аналогично, поле children перечисляет все подколлекторы. Когда запрашиваются агрегации, QueryPhaseCollector будет содержать дополнительный коллектор с причиной aggregation, который выполняет агрегации.

Следует отметить, что время коллекторов независимо от времени запросов. Они вычисляются, объединяются и нормализуются независимо! Из-за характера выполнения Lucene невозможно «слить» время коллекторов в раздел запросов, поэтому они отображаются в отдельных разделах.

Для справки, различные причины коллекторов:

Все запросы в Lucene проходят процесс «переписывания». Запрос (и его подзапросы) могут быть переписаны один или несколько раз, и процесс продолжается до тех пор, пока запрос не перестанет изменяться. Этот процесс позволяет Lucene выполнять оптимизации, такие как удаление избыточных условий, замена одного запроса на более эффективный путь выполнения и т. д. Например, Boolean → Boolean → TermQuery можно переписать в TermQuery, потому что в этом случае все Booleanы не нужны.

Процесс переписывания сложный и трудно отображаемый, так как запросы могут значительно изменяться. Вместо отображения промежуточных результатов отображается только общее время переписывания (в наносекундах). Это значение является кумулятивным и содержит общее время переписывания всех запросов.

Для демонстрации немного более сложного запроса и соответствующих результатов мы можем проанализировать следующий запрос:

resp = client.search(
    index="my-index-000001",
    profile=True,
    query={
        "term": {
            "user.id": {
                "value": "elkbee"
            }
        }
    },
    aggs={
        "my_scoped_agg": {
            "terms": {
                "field": "http.response.status_code"
            }
        },
        "my_global_agg": {
            "global": {},
            "aggs": {
                "my_level_agg": {
                    "terms": {
                        "field": "http.response.status_code"
                    }
                }
            }
        }
    },
    post_filter={
        "match": {
            "message": "search"
        }
    },
)
print(resp)

response = client.search(
  index: 'my-index-000001',
  body: {
    profile: true,
    query: {
      term: {
        'user.id' => {
          value: 'elkbee'
        }
      }
    },
    aggregations: {
      my_scoped_agg: {
        terms: {
          field: 'http.response.status_code'
        }
      },
      my_global_agg: {
        global: {},
        aggregations: {
          my_level_agg: {
            terms: {
              field: 'http.response.status_code'
            }
          }
        }
      }
    },
    post_filter: {
      match: {
        message: 'search'
      }
    }
  }
)
puts response

const response = await client.search({
  index: "my-index-000001",
  profile: true,
  query: {
    term: {
      "user.id": {
        value: "elkbee",
      },
    },
  },
  aggs: {
    my_scoped_agg: {
      terms: {
        field: "http.response.status_code",
      },
    },
    my_global_agg: {
      global: {},
      aggs: {
        my_level_agg: {
          terms: {
            field: "http.response.status_code",
          },
        },
      },
    },
  },
  post_filter: {
    match: {
      message: "search",
    },
  },
});
console.log(response);

GET /my-index-000001/_search
{
  "profile": true,
  "query": {
    "term": {
      "user.id": {
        "value": "elkbee"
      }
    }
  },
  "aggs": {
    "my_scoped_agg": {
      "terms": {
        "field": "http.response.status_code"
      }
    },
    "my_global_agg": {
      "global": {},
      "aggs": {
        "my_level_agg": {
          "terms": {
            "field": "http.response.status_code"
          }
        }
      }
    }
  },
  "post_filter": {
    "match": {
      "message": "search"
    }
  }
}

Этот пример содержит:

API возвращает следующий результат:

{
  ...
  "profile": {
    "shards": [
      {
        "id": "[P6xvulHtQRWuD4YnubWb7A][my-index-000001][0]",
        "node_id": "P6xvulHtQRWuD4YnubWb7A",
        "shard_id": 0,
        "index": "my-index-000001",
        "cluster": "(local)",
        "searches": [
          {
            "query": [
              {
                "type": "TermQuery",
                "description": "message:search",
                "time_in_nanos": 141618,
                "breakdown": {
                  "set_min_competitive_score_count": 0,
                  "match_count": 0,
                  "shallow_advance_count": 0,
                  "set_min_competitive_score": 0,
                  "next_doc": 0,
                  "match": 0,
                  "next_doc_count": 0,
                  "score_count": 0,
                  "compute_max_score_count": 0,
                  "compute_max_score": 0,
                  "advance": 3942,
                  "advance_count": 4,
                  "count_weight_count": 0,
                  "score": 0,
                  "build_scorer_count": 2,
                  "create_weight": 38380,
                  "shallow_advance": 0,
                  "count_weight": 0,
                  "create_weight_count": 1,
                  "build_scorer": 99296
                }
              },
              {
                "type": "TermQuery",
                "description": "user.id:elkbee",
                "time_in_nanos": 163081,
                "breakdown": {
                  "set_min_competitive_score_count": 0,
                  "match_count": 0,
                  "shallow_advance_count": 0,
                  "set_min_competitive_score": 0,
                  "next_doc": 2447,
                  "match": 0,
                  "next_doc_count": 4,
                  "score_count": 4,
                  "compute_max_score_count": 0,
                  "compute_max_score": 0,
                  "advance": 3552,
                  "advance_count": 1,
                  "score": 5027,
                  "count_weight_count": 0,
                  "build_scorer_count": 2,
                  "create_weight": 107840,
                  "shallow_advance": 0,
                  "count_weight": 0,
                  "create_weight_count": 1,
                  "build_scorer": 44215
                }
              }
            ],
            "rewrite_time": 4769,
            "collector": [
              {
                "name": "QueryPhaseCollector",
                "reason": "search_query_phase",
                "time_in_nanos": 1945072,
                "children": [
                  {
                    "name": "SimpleTopScoreDocCollector",
                    "reason": "search_top_hits",
                    "time_in_nanos": 22577
                  },
                  {
                    "name": "AggregatorCollector: [my_scoped_agg, my_global_agg]",
                    "reason": "aggregation",
                    "time_in_nanos": 867617
                  }
                ]
              }
            ]
          }
        ],
        "aggregations": [...], 
        "fetch": {...}
      }
    ]
  }
}

Как видите, вывод значительно более подробный, чем раньше. Все основные части запроса представлены:

Дерево коллекторов достаточно простое, демонстрируя, как один QueryPhaseCollector, содержащий обычный коллектор очков SimpleTopScoreDocCollector для сбора лучших совпадений, а также BucketCollectorWrapper для выполнения всех агрегаций в области видимости.

Необходимо сделать специальное замечание о запросах класса MultiTermQuery. Это включает запросы с подстановкой, регулярными выражениями и расплывчатыми запросами. Эти запросы генерируют очень подробные ответы и не являются слишком структурированными.

По существу, эти запросы переписывают себя для каждого сегмента. Если вы представите запрос с подстановкой b*, он технически может соответствовать любому токену, начинающемуся с буквы «b». Перечислить все возможные комбинации было бы невозможно, поэтому Lucene переписывает запрос в контексте оцениваемого сегмента, например, один сегмент может содержать токены [bar, baz], поэтому запрос переписывается в комбинацию BooleanQuery «bar» и «baz». Другой сегмент может содержать только токен [bakery], поэтому запрос переписывается в один TermQuery для «bakery».

Из-за этой динамической переписывки для каждого сегмента чистая структура дерева искажается и больше не следует чистому «родословью», показывающему, как один запрос переписывается в другой. На данный момент мы можем только извиниться и порекомендовать свернуть детали дочерних элементов запроса, если он слишком сложен. К счастью, все статистические данные о времени верны, просто не верен физический макет в ответе, поэтому достаточно проанализировать MultiTermQuery верхнего уровня и проигнорировать его дочерние элементы, если вы найдёте подробности слишком сложными для интерпретации.

Надеемся, что это будет исправлено в будущих итерациях, но это сложная проблема, которая ещё в процессе решения. :)

Компонент breakdown предоставляет подробную статистику о выполнении на низком уровне:

"breakdown": {
  "reduce": 0,
  "build_aggregation": 30885,
  "build_aggregation_count": 1,
  "initialize": 2623,
  "initialize_count": 1,
  "reduce_count": 0,
  "collect": 45786,
  "collect_count": 4,
  "build_leaf_collector": 18211,
  "build_leaf_collector_count": 1
}

Каждое свойство в компоненте breakdown соответствует внутреннему методу агрегирования. Например, свойство build_leaf_collector измеряет наносекунды, потраченные на выполнение метода агрегирования getLeafCollector(). Свойства, заканчивающиеся на _count, записывают количество вызовов соответствующего метода. Например, "collect_count": 2 означает, что агрегация вызвала метод collect() для двух различных документов. Свойство reduce зарезервировано для будущих целей и всегда возвращает значение 0.

Временные характеристики указаны в наносекундах реального времени и не нормализованы. Здесь применяются все замечания по поводу общего time. Цель детализации – показать, какие компоненты Elasticsearch потребляют больше времени, и оценить разницу во времени между различными компонентами. Как и общее время, детализация включает время всех дочерних элементов.

Все фрагменты, которые извлекли документы, будут иметь раздел fetch в профиле. Давайте выполним небольшой поиск и посмотрим на профиль извлечения:

resp = client.search(
    index="my-index-000001",
    filter_path="profile.shards.fetch",
    profile=True,
    query={
        "term": {
            "user.id": {
                "value": "elkbee"
            }
        }
    },
)
print(resp)

response = client.search(
  index: 'my-index-000001',
  filter_path: 'profile.shards.fetch',
  body: {
    profile: true,
    query: {
      term: {
        'user.id' => {
          value: 'elkbee'
        }
      }
    }
  }
)
puts response

const response = await client.search({
  index: "my-index-000001",
  filter_path: "profile.shards.fetch",
  profile: true,
  query: {
    term: {
      "user.id": {
        value: "elkbee",
      },
    },
  },
});
console.log(response);

GET /my-index-000001/_search?filter_path=profile.shards.fetch
{
  "profile": true,
  "query": {
    "term": {
      "user.id": {
        "value": "elkbee"
      }
    }
  }
}

И вот профиль извлечения:

{
  "profile": {
    "shards": [
      {
        "fetch": {
          "type": "fetch",
          "description": "",
          "time_in_nanos": 660555,
          "breakdown": {
            "next_reader": 7292,
            "next_reader_count": 1,
            "load_stored_fields": 299325,
            "load_stored_fields_count": 5,
            "load_source": 3863,
            "load_source_count": 5
          },
          "debug": {
            "stored_fields": ["_id", "_routing", "_source"]
          },
          "children": [
            {
              "type" : "FetchFieldsPhase",
              "description" : "",
              "time_in_nanos" : 238762,
              "breakdown" : {
                "process_count" : 5,
                "process" : 227914,
                "next_reader" : 10848,
                "next_reader_count" : 1
              }
            },
            {
              "type": "FetchSourcePhase",
              "description": "",
              "time_in_nanos": 20443,
              "breakdown": {
                "next_reader": 745,
                "next_reader_count": 1,
                "process": 19698,
                "process_count": 5
              },
              "debug": {
                "fast_path": 4
              }
            },
            {
              "type": "StoredFieldsPhase",
              "description": "",
              "time_in_nanos": 5310,
              "breakdown": {
                "next_reader": 745,
                "next_reader_count": 1,
                "process": 4445,
                "process_count": 5
              }
            }
          ]
        }
      }
    ]
  }
}

Поскольку это отладочная информация о том, как Elasticsearch выполняет извлечение, она может меняться от запроса к запросу и от версии к версии. Даже исправления могут изменить вывод здесь. Именно эта несогласованность делает его полезным для отладки.

В любом случае! time_in_nanos измеряет общее время фазы извлечения. breakdown подсчитывает и измеряет время подготовки на основе каждого сегмента в next_reader и время загрузки сохранённых полей в load_stored_fields. Раздел отладки содержит различную невременную информацию, в частности, stored_fields перечисляет сохранённые поля, которые нужно загрузить при извлечении. Если это пустой список, извлечение полностью пропустит загрузку сохранённых полей.

Раздел children содержит подфазы, выполняющие фактическую работу по извлечению, а breakdown содержит подсчеты и временные характеристики подготовки на основе каждого сегмента в next_reader и извлечение по документу в process.

Фаза DFS выполняется перед фазой запроса для сбора глобальной информации, относящейся к запросу. В настоящее время она используется в двух случаях:

В обоих этих случаях можно профилировать, установив profile в true в качестве части запроса поиска.

resp = client.indices.create(
    index="my-dfs-index",
    settings={
        "number_of_shards": 2,
        "number_of_replicas": 1
    },
    mappings={
        "properties": {
            "my-keyword": {
                "type": "keyword"
            }
        }
    },
)
print(resp)

resp1 = client.bulk(
    index="my-dfs-index",
    refresh=True,
    operations=[
        {
            "index": {
                "_id": "1"
            }
        },
        {
            "my-keyword": "a"
        },
        {
            "index": {
                "_id": "2"
            }
        },
        {
            "my-keyword": "b"
        }
    ],
)
print(resp1)

response = client.indices.create(
  index: 'my-dfs-index',
  body: {
    settings: {
      number_of_shards: 2,
      number_of_replicas: 1
    },
    mappings: {
      properties: {
        "my-keyword": {
          type: 'keyword'
        }
      }
    }
  }
)
puts response

response = client.bulk(
  index: 'my-dfs-index',
  refresh: true,
  body: [
    {
      index: {
        _id: '1'
      }
    },
    {
      "my-keyword": 'a'
    },
    {
      index: {
        _id: '2'
      }
    },
    {
      "my-keyword": 'b'
    }
  ]
)
puts response

const response = await client.indices.create({
  index: "my-dfs-index",
  settings: {
    number_of_shards: 2,
    number_of_replicas: 1,
  },
  mappings: {
    properties: {
      "my-keyword": {
        type: "keyword",
      },
    },
  },
});
console.log(response);

const response1 = await client.bulk({
  index: "my-dfs-index",
  refresh: "true",
  operations: [
    {
      index: {
        _id: "1",
      },
    },
    {
      "my-keyword": "a",
    },
    {
      index: {
        _id: "2",
      },
    },
    {
      "my-keyword": "b",
    },
  ],
});
console.log(response1);

PUT my-dfs-index
{
  "settings": {
    "number_of_shards": 2, 
    "number_of_replicas": 1
  },
  "mappings": {
      "properties": {
        "my-keyword": { "type": "keyword" }
      }
    }
}

POST my-dfs-index/_bulk?refresh=true
{ "index" : { "_id" : "1" } }
{ "my-keyword" : "a" }
{ "index" : { "_id" : "2" } }
{ "my-keyword" : "b" }

resp = client.search(
    index="my-dfs-index",
    search_type="dfs_query_then_fetch",
    pretty=True,
    size="0",
    profile=True,
    query={
        "term": {
            "my-keyword": {
                "value": "a"
            }
        }
    },
)
print(resp)

response = client.search(
  index: 'my-dfs-index',
  search_type: 'dfs_query_then_fetch',
  pretty: true,
  size: 0,
  body: {
    profile: true,
    query: {
      term: {
        "my-keyword": {
          value: 'a'
        }
      }
    }
  }
)
puts response

const response = await client.search({
  index: "my-dfs-index",
  search_type: "dfs_query_then_fetch",
  pretty: "true",
  size: 0,
  profile: true,
  query: {
    term: {
      "my-keyword": {
        value: "a",
      },
    },
  },
});
console.log(response);

GET /my-dfs-index/_search?search_type=dfs_query_then_fetch&pretty&size=0 
{
  "profile": true, 
  "query": {
    "term": {
      "my-keyword": {
        "value": "a"
      }
    }
  }
}

"dfs" : {
    "statistics" : {
        "type" : "statistics",
        "description" : "collect term statistics",
        "time_in_nanos" : 236955,
        "breakdown" : {
            "term_statistics" : 4815,
            "collection_statistics" : 27081,
            "collection_statistics_count" : 1,
            "create_weight" : 153278,
            "term_statistics_count" : 1,
            "rewrite_count" : 0,
            "create_weight_count" : 1,
            "rewrite" : 0
        }
    }
}

resp = client.indices.create(
    index="my-knn-index",
    mappings={
        "properties": {
            "my-vector": {
                "type": "dense_vector",
                "dims": 3,
                "index": True,
                "similarity": "l2_norm"
            }
        }
    },
)
print(resp)

resp1 = client.bulk(
    index="my-knn-index",
    refresh=True,
    operations=[
        {
            "index": {
                "_id": "1"
            }
        },
        {
            "my-vector": [
                1,
                5,
                -20
            ]
        },
        {
            "index": {
                "_id": "2"
            }
        },
        {
            "my-vector": [
                42,
                8,
                -15
            ]
        },
        {
            "index": {
                "_id": "3"
            }
        },
        {
            "my-vector": [
                15,
                11,
                23
            ]
        }
    ],
)
print(resp1)

response = client.indices.create(
  index: 'my-knn-index',
  body: {
    mappings: {
      properties: {
        "my-vector": {
          type: 'dense_vector',
          dims: 3,
          index: true,
          similarity: 'l2_norm'
        }
      }
    }
  }
)
puts response

response = client.bulk(
  index: 'my-knn-index',
  refresh: true,
  body: [
    {
      index: {
        _id: '1'
      }
    },
    {
      "my-vector": [
        1,
        5,
        -20
      ]
    },
    {
      index: {
        _id: '2'
      }
    },
    {
      "my-vector": [
        42,
        8,
        -15
      ]
    },
    {
      index: {
        _id: '3'
      }
    },
    {
      "my-vector": [
        15,
        11,
        23
      ]
    }
  ]
)
puts response

const response = await client.indices.create({
  index: "my-knn-index",
  mappings: {
    properties: {
      "my-vector": {
        type: "dense_vector",
        dims: 3,
        index: true,
        similarity: "l2_norm",
      },
    },
  },
});
console.log(response);

const response1 = await client.bulk({
  index: "my-knn-index",
  refresh: "true",
  operations: [
    {
      index: {
        _id: "1",
      },
    },
    {
      "my-vector": [1, 5, -20],
    },
    {
      index: {
        _id: "2",
      },
    },
    {
      "my-vector": [42, 8, -15],
    },
    {
      index: {
        _id: "3",
      },
    },
    {
      "my-vector": [15, 11, 23],
    },
  ],
});
console.log(response1);

PUT my-knn-index
{
  "mappings": {
    "properties": {
      "my-vector": {
        "type": "dense_vector",
        "dims": 3,
        "index": true,
        "similarity": "l2_norm"
      }
    }
  }
}

POST my-knn-index/_bulk?refresh=true
{ "index": { "_id": "1" } }
{ "my-vector": [1, 5, -20] }
{ "index": { "_id": "2" } }
{ "my-vector": [42, 8, -15] }
{ "index": { "_id": "3" } }
{ "my-vector": [15, 11, 23] }

resp = client.search(
    index="my-knn-index",
    profile=True,
    knn={
        "field": "my-vector",
        "query_vector": [
            -5,
            9,
            -12
        ],
        "k": 3,
        "num_candidates": 100
    },
)
print(resp)

response = client.search(
  index: 'my-knn-index',
  body: {
    profile: true,
    knn: {
      field: 'my-vector',
      query_vector: [
        -5,
        9,
        -12
      ],
      k: 3,
      num_candidates: 100
    }
  }
)
puts response

const response = await client.search({
  index: "my-knn-index",
  profile: true,
  knn: {
    field: "my-vector",
    query_vector: [-5, 9, -12],
    k: 3,
    num_candidates: 100,
  },
});
console.log(response);

POST my-knn-index/_search
{
  "profile": true, 
  "knn": {
    "field": "my-vector",
    "query_vector": [-5, 9, -12],
    "k": 3,
    "num_candidates": 100
  }
}

"dfs" : {
    "knn" : [
        {
        "vector_operations_count" : 4,
        "query" : [
            {
                "type" : "DocAndScoreQuery",
                "description" : "DocAndScore[100]",
                "time_in_nanos" : 444414,
                "breakdown" : {
                  "set_min_competitive_score_count" : 0,
                  "match_count" : 0,
                  "shallow_advance_count" : 0,
                  "set_min_competitive_score" : 0,
                  "next_doc" : 1688,
                  "match" : 0,
                  "next_doc_count" : 3,
                  "score_count" : 3,
                  "compute_max_score_count" : 0,
                  "compute_max_score" : 0,
                  "advance" : 4153,
                  "advance_count" : 1,
                  "score" : 2099,
                  "build_scorer_count" : 2,
                  "create_weight" : 128879,
                  "shallow_advance" : 0,
                  "create_weight_count" : 1,
                  "build_scorer" : 307595,
                  "count_weight": 0,
                  "count_weight_count": 0
                }
            }
        ],
        "rewrite_time" : 1275732,
        "collector" : [
            {
                "name" : "SimpleTopScoreDocCollector",
                "reason" : "search_top_hits",
                "time_in_nanos" : 17163
            }
        ]
    }   ]
}

Как и любой другой профилировщик, API профилирования вносит значительную нагрузку на выполнение поиска. Действие инструментирования вызовов методов низкого уровня, таких как collect, advance и next_doc, может быть довольно дорогим, так как эти методы вызываются в тесных циклах. Поэтому профилирование не должно по умолчанию включаться в производственных средах и не должно сравниваться с временами запросов без профилирования. Профилирование – это просто диагностический инструмент.

Также существуют случаи, когда специальные оптимизации Lucene отключены, так как они не подходят для профилирования. Это может привести к тому, что некоторые запросы будут показывать более высокие относительные времена, чем их не-профилированные аналоги, но в целом это не должно иметь существенного влияния по сравнению с другими компонентами в профилируемом запросе.