Использование расширенной отладки. Часть 4. Трассировка

+18
2.32K
Этот и несколько следующих постов про использование «Расширенной отладки» будут в основном полезны для разработчиков и желающих разобраться в InstantCMS 2 на уровне кода. Начну с небольшого поста про трассировку вызовов. Ведь всегда хочется понимать, что откуда вызывается и где источник тех или иных данных.



Небольшое вступление

При отладке компонентов и при изучении их работы на уровне кода часто приходится выяснять, какая ошибка и где именно произошла или в каком месте скрипта при его выполнении получаются интересующие разработчика данные. Например, возникает ошибка в SQL-запросе или он выполняется слишком долго. По тексту запроса, конечно, чаще всего можно понять, где он формируется в коде. Особенно когда вы – автор этого компонента. Но чтобы упростить поиски, хорошо бы вместе с текстом скрипта видеть и место, откуда запрос вызван.

Строка вызова

Разработчики InstantCMS 2 уже предусмотрели это и сделали во встроенной отладке вывод информации о месте вызова SQL-запроса: файл, номер строки и функция. Кроме того, вывели туда же время выполнения каждого запроса. Вот пример вывода запроса на «Главной» странице демо:



В «Расширенной отладке», конечно, тоже есть такие возможности:



Очень похоже. Но есть и разница. Кроме информации из стандартной отладки, в расширенной выводится порядковый номер запроса, а при желании и время от начала работы скрипта. Также показывается результат выполнения запроса: количество обработанных строк для запросов на изменение или количество возвращённых строк для запросов на выборку. В этом примере запрос вернул пять строк. При ошибке вместо результата показываются параметры и описание ошибки.

В первой строке лога мы видим, откуда был сделан запрос: метод modelContent->getContentItems(). Правда, в дефолтной и расширенной отладке эти строки отличаются.

В расширенной используется стандартный для PHP вывод: файл (номер строки) вызова -> класс (если есть) + метод/функция. Это во-первых, привычно программистам, а во-вторых, возможно потому, что можно посмотреть всю трассировку (об этом ниже).

В дефолтной отладке нет полной трассировки, поэтому разработчики совместили блоки из двух соседних строк трассировки. Из-за этого строка вызова выглядит несколько непривычно, но информативно — файл и номер строки указывают откуда непосредственно в указанном методе производится запрос.

Трассировка

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

В вышеприведённом примере лога на «Главной» странице демо, запросы к таблицам контента из метода modelContent->getContentItems() выполняются пять раз. Это можно легко увидеть при включении фильтров в «Расширенной отладке» (о фильтрах расскажу в следующем посте) или при подсчёте вручную в стандартной отладке. Но как оказалось, к одной и той же таблице ‘cms_con_news’ запрос делается из двух разных мест. В дефолтной отладке это не видно. А в расширенной это можно заметить по разным файлам в строке вызова (на скрине ниже выделено слово 'slider').
Чтобы понять, к чему относится именно этот запрос, хорошо бы посмотреть вызывающие функции вглубь хотя бы на несколько уровней.

Глубина трассировки

В «Расширенной отладке» есть возможность посмотреть трассировку на заданную глубину. Для её указания используются соответствующие выпадающие списки. Причём, на вкладке "Общие" есть список "Глубина трассировки для всех типов" (обведено зелёной рамкой на скрине ниже), значение из которого применяется ко всем категориям лога, если на их вкладках выбрано значение глубины трассировки "По настройкам для всех типов на вкладке 'Общие'".

Также можно для любой категории лога выбрать любое другое значение глубины.

Значения для категорий имеют приоритет над значением "Для всех типов". То есть, можно у всех категорий отключить трассировку, а включить лишь для нужных операций.

При установке компонента отладки глубина трассировки в настройках равна 3. Это значит, что в логе кроме строки вызова показываются ещё другие вызывающие функции на три уровня глубины. Трассировка делается от самого первого вызова метода/функции в коде до непосредственно отслеживаемой операции (в данном случае, до точки обращения к БД с запросом). При ограничении глубины выводятся самые последние вызовы.

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

Посмотрим на наш запрос с глубиной трассировки равной 3.

Конечно, красиво. Видно, что непосредственно запрос в БД делается из cmsDatabase->query(). Но нам этого маловато...

Полная трассировка

В некоторых случаях, как в нашем, 3 уровня глубины может оказаться недостаточно. Мы можем выбрать в списке глубины трассировки цифру побольше. Но чтобы не ошибиться, выберем значение "Полная трассировка" и обновим страницу.

Так становится очевидно, что SQL-запросы в примере были сделаны из двух разных виджетов с классами widgetContentList и widgetContentSlider.

"Глубокие" операции

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

В данном примере мы видим цепочку вызовов от стартового файла index.php. Судя по дальнейшим строчкам трассы, этот языковой файл компонента пользователей подключался при обработке хука на доступность страницы пользователю 'page_is_allowed'. При желании можно в настройках отладки включить фильтр инклудов по части его пути, чтобы вывести только один этот инклуд, а также включить вывод в лог событий и хуков. И тогда сразу станет ещё понятнее.
Таким же способом можно изучать даже самые "глубокие" операции.


А в одном из следующих постов я покажу, как посмотреть, какие же именно данные возвращают запросы и другие операции.
Всё это можно увидеть без программирования и изменения кода, в несколько щелчков мышки. Попробуйте!
0
Bubble Gumoff Bubble Gumoff 8 лет назад #
Отличный инструмент для слепых котят) Спасибо!
+2
WebMan WebMan 8 лет назад #
Здоровые, любопытные котята остаются слепыми совсем недолго и быстро прозревают. joke
0
Алексей Т Алексей Т 8 лет назад #
+ Огромный!
0
Alexprofi Alexprofi 8 лет назад #
Продолжаю плюсовать...

Еще от автора

Хуки-хухуки: Исключаем неактивных пользователей из списков
Как иногда начинают свой монолог неопытные стендаперы: «У всех в жизни было такое …
«Расширенная отладка» для InstantCMS 2.14.1 (v.14.1.2) – большое обновление для разработчиков
Новые возможности и удобства, облегчающие разработчикам отладку компонентов и шаблонов.
Использование расширенной отладки. Часть 11. Анализ ошибок 403/404 и редиректов
Одной из неудобных задач при отладке для меня является поиск причины ошибки 403/404.
Используя этот сайт, вы соглашаетесь с тем, что мы используем файлы cookie.