В этой статье мы обсудим инструменты, доступные для профилирования запросов в Manticore Search.
SHOW META
По умолчанию команда SHOW META
предоставляет статистику о ключевых словах, использованных в совпадении. Для каждого ключевого слова мы получаем количество документов, в которых было найдено ключевое слово, и общее количество попаданий. Высокие значения - например, документы почти столь же высоки, как общее количество документов в индексе - могут указывать на то, что ключевое слово является кандидатом для того, чтобы стать стоп-словом.
Вывод SHOW META можно обогатить, запустив демон searchd с –cpustats –iostats . Это позволяет собирать метрики запросов о затратах по IO и CPU, необходимых для выполнения запроса.
mysql> SELECT * FROM myindex WHERE MATCH('search engine*');SHOW META;
....
+-----------------------+---------+
| Variable_name | Value |
+-----------------------+---------+
| total | 1000 |
| total_found | 3994 |
| time | 0.090 |
| cpu_time | 42.950 |
| agents_cpu_time | 0.000 |
| io_read_time | 82.276 |
| io_read_ops | 1633 |
| io_read_kbytes | 1264.5 |
| io_write_time | 0.000 |
| io_write_ops | 0 |
| io_write_kbytes | 0.0 |
| agent_io_read_time | 0.000 |
| agent_io_read_ops | 0 |
| agent_io_read_kbytes | 0.0 |
| agent_io_write_time | 0.000 |
| agent_io_write_ops | 0 |
| agent_io_write_kbytes | 0.0 |
| keyword[0] | engine* |
| docs[0] | 55037 |
| hits[0] | 135095 |
| keyword[1] | search |
| docs[1] | 32768 |
| hits[1] | 53800 |
+-----------------------+---------+
23 rows in set (0.00 sec)
iostats
показывает, сколько данных было прочитано с диска, сколько I/O операций было выполнено и время, затраченное на это. Большое количество читаемых данных означает, что запрос содержит ключевые слова с множеством попаданий, которые необходимо прочитать для построения оценочного балла. Если данные не велики, но мы испытываем высокие времена, наше хранилище может быть медленным или перегруженным. Это может происходить из-за высокой нагрузки, но также может сигнализировать о том, что есть проблема с хранилищем, которую необходимо исследовать.
cpustats
предоставляет время ЦП, использованное для обработки. Если iostats низкие, а CPU высокий, наш запрос загружает ЦП. Обычно проблема с загрузкой CPU решается разделением индекса на несколько фрагментов и выполнением локальных кластерных поисков с использованием dist_threads
> 0. Долгие времена обработки ЦП также могут указывать на то, что сервер перегружен. Высокое время обработки ЦП может иметь различные причины, одной из распространенных причин являются расширения в случае поиска с подстановочными знаками (с помощью dict=keywords по умолчанию).
Метрики agent_
имеют значения в случае, если индекс распределенный, и показывают, сколько данных было записано/считано между основным индексом и его узлами.
SHOW PROFILE
Профилирование можно включить для каждой сессии с помощью
SET
PROFILING=1 (или передать profile:true
в случае HTTP API).
SHOW PROFILE
должен выполняться сразу после запроса. Он показывает, сколько времени затрачено на различные этапы выполнения запроса. Столбец switches показывает количество логических переключений состояния движка (не переключений контекста уровня ОС). Времена этапов могут помочь понять, почему запрос медленный. В приведенном ниже примере много времени затрачивается на этапах read_* из-за того, что запрос был выполнен сразу после загрузки индекса, поэтому ему необходимо выполнять чтения с диска. Профилирование распределенного индекса с удаленными узлами добавит этапы для подключения к агентам и времени ожидания удаленных результатов.
mysql> SHOW PROFILE;
+--------------+----------+----------+---------+
| Status | Duration | Switches | Percent |
+--------------+----------+----------+---------+
| unknown | 0.000827 | 4 | 0.91 |
| local_search | 0.000011 | 1 | 0.01 |
| sql_parse | 0.000019 | 1 | 0.02 |
| dict_setup | 0.000001 | 1 | 0.00 |
| parse | 0.000029 | 1 | 0.03 |
| transforms | 0.000104 | 1 | 0.11 |
| init | 0.000668 | 1169 | 0.73 |
| read_docs | 0.069948 | 1348 | 76.58 |
| read_hits | 0.012602 | 285 | 13.80 |
| get_docs | 0.004021 | 804 | 4.40 |
| get_hits | 0.002276 | 704 | 2.49 |
| filter | 0.000069 | 258 | 0.08 |
| rank | 0.000252 | 791 | 0.28 |
| sort | 0.000266 | 8 | 0.29 |
| finalize | 0.000234 | 1 | 0.26 |
| aggregate | 0.000014 | 2 | 0.02 |
| eval_post | 0.000000 | 1 | 0.00 |
| total | 0.091341 | 5380 | 0 |
+--------------+----------+----------+---------+
18 rows in set (0.00 sec)
SHOW PLAN
SHOW PLAN показывает, как выглядит оцененное дерево запроса полного текста. Это полезно для понимания того, как входной поиск преобразуется и выполняется. Ключевые слова показываются с их позицией в запросе и если они являются расширенными ключевыми словами, происходящими из термина с подстановочными знаками. В случае поиска с подстановочными знаками команда полезна, так как мы можем увидеть весь список расширений.
mysql> SHOW PLAN\G
*************************** 1. row ***************************
Variable: transformed_tree
Value: AND(
AND(KEYWORD(search, querypos=1)),
OR(
OR(
AND(KEYWORD(engineer, querypos=2, expanded)),
OR(
AND(KEYWORD(engineering, querypos=2, expanded)),
OR(
AND(KEYWORD(engineers, querypos=2, expanded)),
AND(KEYWORD(engines, querypos=2, expanded)))),
AND(KEYWORD(engineered, querypos=2, expanded))),
OR(
AND(KEYWORD(engine's, querypos=2, expanded)),
OR(
AND(KEYWORD(engine_power, querypos=2, expanded)),
AND(KEYWORD(engined, querypos=2, expanded)))),
AND(KEYWORD(engine, querypos=2, expanded)),
OR(KEYWORD(engine*, querypos=2, expanded))))
1 row in set (0.00 sec)
SHOW PLAN также требует включения профилирования и должен выполняться перед SHOW META.
В конечном счете, также необходимо мониторить системные ресурсы. Если вы запускаете другие активные сервисы помимо Manticore (например, базу данных или прикладной код), необходимо следить за воздействием этих сервисов. Хотя Manticore может работать наряду с другими сервисами, поскольку он может быть как ресурсоемким по ЦП, так и по вводу-выводу, для высоконагруженных настроек лучше всего иметь Manticore в отдельности, чтобы он не подвергался влиянию (или не влияло) других.