Версия для печати темы
Нажмите сюда для просмотра этой темы в оригинальном формате
Форум программистов > MySQL > профилирование запросов в mysql


Автор: skyboy 24.9.2009, 09:23
Итак. Все тормозит, код клиентской части просто идеальный, записей в БД "вроде бы немного". Что делать? Заниматься profiling'ом.
Что для этого есть в mysql?
1. http://dev.mysql.com/doc/refman/5.0/en/slow-query-log.html - механизм, который производит запись запроса в отдельный лог в том случае, если этот запрос выполнялся дольше указанного периода(в секундах  - минимально 1, по умолчанию стоит 10 секунд). Хорошо эту штуку включить, если она не включена и есть доступ к конфигам - можно уже после обнаружения "тормозов" посмотреть, как система себя раньше "вела" - появились ли сбои по причине увеличения объема данных или проблема была и раньше, просто была незаметна из-за небольшой нагрузки.
2. http://dev.mysql.com/doc/refman/5.0/en/using-explain.html отображает ход выполнения указанного запроса. надо разобраться с нотацией результатов выполнения этой конструкции, да и информация пригодится только при условии наличия хотя бы базовых знаний о принципе работы СУБД, но здесь лучше разобраться раз и с удовольствием пользоваться.
3. начиная с версии 5.0.37 в mysql появился http://dev.mysql.com/tech-resources/articles/using-new-query-profiler.html, который позволяет в пределах сессиий запоминать время выполнения запросов и по выбранному запросу давать развернутую информацию.
пример выполнения скажет за себя:
Код

SET profiling=1;
SELECT COUNT(*) FROM information_schema.tables;
SHOW profiles;
SHOW profile FOR QUERY 1;

выдает
Цитата

"COUNT(*)"
"265"
// результат выполнения select запроса
"Query_ID"    "Duration"    "Query"
"1"    "0.81741225"    "SELECT COUNT(*) FROM information_schema.tables"
// результат выполнения "show profiles"
"Status"    "Duration"
"(initialization)"    "0.000006"
"checking query cache for query"    "0.0000852"
"checking permissions"    "0.0000102"
"Opening tables"    "0.0003627"
"System lock"    "0.0000057"
"Table lock"    "0.0000412"
"init"    "0.000029"
"optimizing"    "0.0000077"
"statistics"    "0.000016"
"preparing"    "0.0000152"
"executing"    "0.0196215"
"checking permissions"    "0.0000335"
"Opening tables"    "0.0002245"
"removing tmp table"    "0.0000145"
"Opening tables"    "0.000203"
"removing tmp table"    "0.0000135"
"Opening tables"    "0.000081"
"removing tmp table"    "0.0000085"
"Opening tables"    "0.0040647"
"removing tmp table"    "0.0004305"
"Opening tables"    "0.000101"
"removing tmp table"    "0.0000157"
"Opening tables"    "0.000124"
"removing tmp table"    "0.0000132"
"Opening tables"    "0.0000597"
"removing tmp table"    "0.00001"
"Opening tables"    "0.0023357"
"removing tmp table"    "0.0004092"
"Opening tables"    "0.0001157"
"removing tmp table"    "0.0000205"
"Opening tables"    "0.0001132"
"removing tmp table"    "0.0000147"
"Opening tables"    "0.0000805"
"removing tmp table"    "0.0000107"
"Opening tables"    "0.0001055"
"removing tmp table"    "0.0000192"
"Opening tables"    "0.0000852"
"removing tmp table"    "0.0000135"
"Opening tables"    "0.0001012"
"removing tmp table"    "0.0000107"
"Opening tables"    "0.0021872"
"removing tmp table"    "0.0003845"
"Opening tables"    "0.0001282"
"removing tmp table"    "0.000011"
"Opening tables"    "0.001933"
"removing tmp table"    "0.000378"
"checking permissions"    "0.4841377"
"Opening tables"    "0.0001075"
...
// еще 246 раз "opening table" со временем выполнения менее чем 0,00005
...
"Opening tables"    "0.0000405"
"checking permissions"    "0.2855055"
"Sending data"    "0.0007977"
"end"    "0.0000037"
"query end"    "0.0000045"
"freeing items"    "0.0000362"
"closing tables"    "0.000002"
"removing tmp table"    "0.000079"
"closing tables"    "0.0000037"
"logging slow query"    "0.0000015"
// результат выполнения show profile for query 1;

на примере видно: основная задержка - checking permissions(без учета их выполнение заняло бы около 0,05 с)
---------------------
Типичный процесс исправления узких мест вижу таким:
1. Лезем в загодя включенный slow query log и выуживаем долгие запросы.
2. Через любой клиент выполняем эти запросы, предварительно включив профилирование(set profiling=1;)
Выясняем, по какой причине запрос долго выполняется.
3. при помощи explain выясняем, какая именно конструкция приводит к тормозам, если на пункте 2 узким местом оказалось что-то, не имеющее отношения к системе безопасности(checking permissions), передачи данных(sending data) - короче говоря, надо разобраться ещё, что можно ускорить за счет оптимизации запроса, а для чего - надо лезть в конфиги(причем не только mysql сервера).
В принципе, пункты 2 и 3 вполне могут идти в другом порядке.

Добавлено @ 09:24
Если что-то пропустил, прошу дополнить.

Автор: skyboy 2.10.2009, 16:21
Век живи – век учись.
В комплекте бинарников mysql идет консольная тулза http://dev.mysql.com/doc/refman/5.1/en/mysqlslap.html, назначение которой - эмуляция клиентской загрузки. По сути - инструмент нагрузочного тестирования.
Правда, на хостинге у себя я его не обнаружил, что, пожалуй, оправдано smile

Автор: lumega 26.3.2014, 17:52
Добавлю, что есть графический инструмент для профилирования - http://www.profilesql.com/ru/. Позволяет позволяет делать и профилирование и explain. 
user posted image

Автор: kaa 20.4.2015, 11:55
страницей промазал

Powered by Invision Power Board (http://www.invisionboard.com)
© Invision Power Services (http://www.invisionpower.com)