Использование расширенной отладки. Часть 7. Контрольные точки

2466
При анализе работы движка CMS или при отладке своих компонентов/шаблонов требуется знать состояние переменных в разных местах кода. Частично эта задача решается выводом информации об основных операциях несколькими щелчками мышки в «Расширенной отладке». А для более точного понимания происходящего в любом месте кода можно использовать контрольные точки.

Использование расширенной отладки. Часть 7. Контрольные точки


Зачем они вообще нужны?

Ведь есть встроенные в PHP привычные функции var_dump и print_r, Давайте просто посмотрим на их вывод на примере стандартного виджета комментариев. Добавим в начало шаблона этого виджета /templates/default/controllers/comments/widgets/list/list.tpl.php строку:
Код PHP:
  1. <?php echo print_r($items); ?>
print_r
Обернём вывод в тег <pre>:
Код PHP:
  1. <?php echo '<pre>'.print_r($items, true).'</pre>'; ?>
print_r + pre
Посмотрим на вывод var_dump():
Код PHP:
  1. <?php var_dump($items); ?>
var_dump
Просто так обернуть var_dump() в <pre> не получится, нужно забирать результаты из буфера вывода:
Код PHP:
  1. <?php
  2. var_dump($items);
  3. $dump = ob_get_contents();
  4. echo '<pre>'.$dump.'</pre>';
  5. ?>
var_dump + pre через буфер

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

Поэтому в в «Расширенную отладку» была встроена функция для вывода контрольных значений dbg(), лишённая всех этих недостатков.
У неё только плюсы:
+ Короткое имя функции. Никакого дополнительного кода или оформления не требуется.
+ Вывод осуществляется в отдельный лог под готовой страницей, не нарушая расположение её элементов.
+ Поэтому не играет роли, в скрытом элементе делался вызов dbg() или в любом другом месте кода - данные вывода будут всегда в одном и том же месте и полностью читаемыми.
+ Выводимые структуры объектов и массивов максимально компактны при сохранении читаемости.
+ Многоуровневые отступы в структурах массивов и объектов. Уровни подсвечиваются вертикальными опорными линиями. Эти уровни также соблюдаются для yaml-массивов и длинных строк.
+ Большие блоки данных могут автоматически сворачиваться до небольшого окна с прокруткой или полностью разворачиваться в зависимости от выбранных вами настроек отладки. Блоки можно свернуть/развернуть одним кликом мышки.
+ Настраиваемое через css цветовое оформление структур, типов данных, элементов, значений, символов (скобок, стрелок и т.п.).
+ Работает в обоих режимах отладки: стандартном и полном.

Посмотрим, как выглядит тот же пример через dbg():
Код PHP:
  1. <?php dbg($items); ?>
dbg()

Контрольные точки

Контрольные точки (КТ) – это специальный короткий вызов метода класса отладки, который в текущее место лога выведет заданную вами информацию.

Для разрешения вывода КТ в лог нужно включить галку «Выводить в лог: Точки dbg()» на вкладке «Общие» и при необходимости там же задать глубину их трассировки.

Вызов КТ очень простой:
Код PHP:
  1. dbg($name, $data, $debug_on)
Параметры вызова:
* @param string $name Название точки, выводится в лог в кавычках после "Debugx_dbg"
* @param mixed $data Данные для вывода
* @param array $debug_on Массив флагов включения/отключения логирования для категорий лога

Все параметры необязательные.

Например, строка кода в виджете комментариев
Код PHP:
  1. dbg('PointName', cmsUser::getInstance()->nickname);
выведет такую контрольную точку в лог
Использование расширенной отладки. Часть 7. Контрольные точки


В этой строке:

'PointName' – заданное вами имя КТ. Его можно также создавать динамически на основе переменных.

140.67 – время с момента старта скрипта, в миллисекундах. Опционально выводится для всех строк лога и позволяет наглядно увидеть процесс выполнения кода по времени.

139.87 ms – время, прошедшее с момента предыдущей КТ или, если такой не было, то с момента старта скрипта (в примере как раз такой вариант). Таким образом, поставив две КТ в нужных местах, можно точно узнать, как долго выполняется код между ними.

[ sql, incl, events, hooks и так далее ] – количество и суммарное время произошедших с момента последней КТ (или с момента старта, если точек ещё не было) SQL-запросов, автозагрузок/инклудов, событий/хуков и других операций. Эта часть лога также позволяет легко понять, выполнялось ли что-то между двумя вашими КТ и какие из этих операций занимают больше всего времени.
Вывод или скрытие каждого блока, как и всей строки с этими деталями можно задать в настройках отладки.

[ +7493 KB (peak) ] – прирост памяти с момента последней КТ или со старта скрипта. Изменение памяти вычисляется либо по пику памяти, если он был достигнут за время после предыдущей КТ, или по значению на момент текущей КТ, если пика не было. В данном случае это первая КТ с момента старта скрипта, поэтому использовался пик памяти для всего скрипта до момента этой КТ. Вывод этого блока тоже опционален по настройкам отладки.

include -> /templates/default/controllers/comments/widgets/list/list.tpl.php (14) – файл и строка, откуда вызвана эта КТ.
Ниже - трассировка для этой КТ. В настройках отладки её можно отключить совсем, включить полную трассировку или задать глубину на нужное количество уровней.

string(26) "Администратор" – тип, длина и значение cmsUser::getInstance()->nickname. В этом месте можно вывести не только одно значение, об этом будет сказано чуть ниже.

Для некоторых значений в логе присутствуют всплывающие подсказки – поводите мышкой по строке и увидите.

Минимальный вызов ТК при всех выключенных опциях выведет только время с момента прошлой КТ и место вызова:
Код PHP:
  1. dbg();
Использование расширенной отладки. Часть 7. Контрольные точки


Теперь чуть подробнее про параметры функции вызова КТ

Имя точки – $name

Значение можно оставить пустым. Тогда в лог выведется «Debugx_dbg 1» - номер текущей КТ.
Имя также можно создавать динамически на основе переменных. Это удобно для вывода значений из цикла или при выводе меняющихся значений.
Если в функцию dbg() передать только один параметр, то она будет считать его данными для вывода, а имя точки будет отсутствовать.

Данные для вывода в лог – $data

Можно оставить пустым, если в этой КТ нужны лишь значения времени, памяти и т.п.
Если вы передаёте только одну переменную, то вам не нужно заботиться о правильном выводе переменных разного типа. Отладка выведет в максимально наглядном и читабельном виде и числовую/строковую переменную, и массив, и объект с использованием модифицированного вывода функции PHP var_dump(). Изменённый вывод более компактный, наглядный, чем функции print_r() и var_dump(), и имеет цветовую подсветку ключей, типов и значений.

Код PHP:
  1. $a = array('q', 123456, 'key_e'=>123.456);
  2. dbg('PointName', $a);
Использование расширенной отладки. Часть 7. Контрольные точки


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

Код PHP:
  1. $a = array('q', 123456, 'key_e'=>123.456, null, 'c:\path/file.ext'=>'file');
  2. $b = 'Это строка';
  3. $c = true;
  4. $d = false;
  5. dbg('PointName', array('array_a'=>$a, 'string'=>$b, 'bool true'=>$c, 'bool false'=>$d, 'float2'=>123.456e20));
Использование расширенной отладки. Часть 7. Контрольные точки


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

Например, несколько переменных в одной строке, если переменные не являются массивами или объектами:

Код PHP:
  1. $b = 'Это строка';
  2. $c = true;
  3. dbg('PointName', 'b = "' . $b . '", c = ' . $c);
Использование расширенной отладки. Часть 7. Контрольные точки


Очень удобно в КТ выводить объекты или части объектов. Например, вот взвод части объекта пользователя, касающейся его города:

Код PHP:
  1. dbg('PointName', cmsUser::getInstance()->city);
Использование расширенной отладки. Часть 7. Контрольные точки

Внимание! При большом количестве контрольных точек, выводящих большие комплексные объекты, будет сильно расходоваться память и будут тормозить сервер и браузер! Старайтесь выводить небольшое количество объектов за один раз или только нужные части объектов.


Принудительный вывод или приостановка вывода любых категорий лога – $debug_on

Иногда нужно увидеть только часть логов, которые происходят на определённом участке кода. Тогда можно в настройках отладки в Админке выключить вывод всего лога нужного типа и сделать две КТ, в начале и в конце нужного блока кода, включив в первой КТ вывод этого лога и выключив его во второй.
Например, для sql-запросов нужно третьим параметром в функцию dbg() передать массив с одним элементом 'database' и значением, приводящемся к true:
Код PHP:
  1. dbg('start', '', ['database' => 1]);
  2. // Начали выводиться SQL-запросы
  3. ...
  4. Ваш код
  5. ...
  6. dbg('stop', '', 0, ['database' => 1]);
  7. // Вывод запросов прекращён
Допустимые операции лога:
'dbg' - точки тладки
'database' - операции с базой данных
'autoload' - автозагрузки классов
'include' - подключения файлов
'event' - события
'hook' - хуки
'widget' - виджеты
'template' - шаблоны
'cache' - операции с кешем
'controller' - контроллер
'debugx' - события отладки

Допустимые значения:
true – принудительно включить вывод нужной категории лога
false – отключить вывод
null – использовать настройки из Админки (по умолчанию)

Подсказка: Параметры текущей КТ перекрывают параметры предыдущей. Например, в одной КТ можно включить вывод SQL-запросов, в следующей – добавить вывод инклудов, а в третьей – отключить вывод и запросов, и инклудов. Таким образом, можно сделать вывод разной информации после разных КТ в одном и том же логе.

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

На заметку: При заданных фильтрах на вкладке «База данных» выводятся только запросы, а логи подключения к БД не выводятся.

Отладка сообщает о переключении вывода лога в строках с КТ, а также показывает предупреждения при ошибках в параметре $debug_on. Например, для кода
Код PHP:
  1. dbg('Правильный', '', ['database'=>true, 'event'=>1, 'hook'=>'выводить']);
  2. dbg('Неправильный индекс abcde', '', ['event'=>1, 'hook'=>1, 'abcde'=>1]);
  3. dbg('Параметр $debug_on - не массив', '', 'не массив');
будет выведено
Спойлер

Дополнительные возможности

Контрольные точки на «живом» сайте (на сервере)

Контрольные точки можно использовать и на работающем сайте. При этом нужно соблюдать правила:
• Обязательно включите галку «Показывать отладочную информацию только администраторам» на вкладке «Общие» в Админке. Да и вообще, на сервере эту галку лучше не выключать, чтобы не пугать пользователей и не показывать им лишней информации.
Не выводите в КТ критично важную информацию!!! Например, вместо вывода всей информации о пользователе, содержащей хэш пароля и другие непубличные данные, выводите лишь ту часть, которая вам действительно нужна (как в примере выше про город пользователя).
Отключайте вывод КТ, если в данный момент не используете их на сайте.

Поддержка пользователей разработчиками и получение логов своих компонентов

Если вы – разработчик, то можете оставлять в тестовых (альфа-, бета-, пре-) версиях некоторое количество контрольных точек с настроенным выводом нужных вам переменных и названием вашего компонента в качестве префикса имени КТ (например, «photobattle_init», «photobattle_save»). При отключённой отладке они будут просто игнорироваться системой и никак не будут влиять на работу CMS. Зато при непонятном поведении тестового компонента, вам уже не нужно будет гадать самому или выуживать у пользователя информацию кучей вопросов. Вы просто сможете попросить пользователя включить вывод нужных вам логов, в том числе и точек отладки. И через минуту получите точную картину происходящего в компоненте, чтобы иметь возможность повторить ошибки у себя и исправить их.
В финальных релизах контрольные точки лучше убрать.

Естественно, использование контрольных точек в релизах своих продуктов возможно только при условии, что у пользователя установлена «Расширенная отладка».

Обратите внимание! На случай, если «Расширенная отладка» не установлена у клиентов, в своих компонентах для публичного тестирования правильнее подключать КТ с проверкой наличия функции dbg():
Код PHP:
  1. if (function_exists('dbg')) { dbg($name, $data); }
Важно! В случае, если оставляете свои КТ в коде компонента для публичного использования, убирайте из них включение/отключение логов (не используйте параметр $debug_on). Поскольку значения, указанные в параметрах КТ перекрывают значения из конфига отладки, они могут привести к выводу ненужных пользователям строк в логах или наоборот, скрыть нужные.

Основные отличия «Расширенной отладки» от xDebug

Дополнительные возможности «Расширенной отладки» по сравнению с xDebug:
• Отображает суммарные данные о работе скрипта и его частей в удобной, наглядной итоговой таблице.
• Позволяет очень наглядно и просто посмотреть параметры выполнения стандартных операций (запросов к БД, подключений файлов, событий, хуков, виджетов, запуска контроллера, инициализации и рендеринга шаблона).
• Позволяет получить последовательный список стандартных операций. В том числе на любом участке кода и с применением фильтров.
• Позволяет наглядно посмотреть состояние переменных или их частей (для массивов и объектов)
• Позволяет наглядно увидеть динамику состояния переменных – например, как изменяются переменные при итерациях в цикле или при вызове функции с разными параметрами. xDebug позволяет это увидеть лишь при последовательных остановках в заданных точках и требует запоминания или записывания значений для каждой итерации.
• Позволяет увидеть динамику изменения параметров выполнения скрипта (память, работа файловой системы, БД и PHP).
• Даёт возможность сохранить полученный лог вместе со всей страницей и отправить его разработчику или другому специалисту.
• Позволяет достаточно просто понять причины возникающих тормозов при работе сайта на локальном компьютере и на сервере без глубокого анализа выполнения скриптов через IDE или удалённое подключение к серверу через ssh.
• Как следствие, позволяет быстро найти узкие места сервера хостинга или протестировать новый хостинг на соответствие Инстанту.
• Позволяет быстро и наглядно проверить новые компоненты и шаблоны на оптимизированность по скорости и памяти.
• Не требует установки дополнительного ПО xDebug
• Не требует навыков работы с xDebug, тем более по ssh на удалённом сервере. Все операции, кроме вставки контрольных точек, делаются мышкой в несколько щелчков независимо от того, где находится сайт.
• Одинаково хорошо работает и на локальном компьютере, и на сервере.

Недостающие возможности «Расширенной отладки» по сравнению с xDebug:
• Нет возможности по шагам пройти весь код и увидеть куда и почему происходят переходы. Для этого нужно вставлять КТ в местах ветвления.
• Показывает только заданные переменные. Нельзя посмотреть другие переменные в нужных точках без их явного задания в КТ.
• Не позволяет «по горячему», при приостановленном в точке отладки скрипте, откорректировать нужную переменную и продолжить скрипт с новым значением.
• Отсутствует профилирование.

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

Вывод: «Расширенную отладку» можно и нужно использовать совместно с xDebug для более наглядного вывода на локальном компьютере и тем более для ситуаций, когда xDebug недоступен или неудобен.
Использование расширенной отладки. Часть 6. Данные и результаты операций | Использование расширенной отладки. Часть 8. Перехват ошибок
Комментарии (14)
Loadырь 21 декабря 2015 в 20:14 +3
WebMan, а это правда, что про вас говорят? Говорят, что вы пишете тексты в блоге тушью, тушью для ресниц, чтобы придать вашим текстам объем и выразительность? smile
WebMan 21 декабря 2015 в 20:30 +3
laugh Спасибо за наблюдательность. Но неправда. Я - мужчина и тушью (уже давно) не пользуюсь. Мне приходится использовать "встроенную косметику" сайта: жирность, наклон и стили заголовков. Хотя некоторые "мужские" секретики у меня, конечно, есть. joke
Def 21 декабря 2015 в 23:18 +2
супер!!! если бы еще уметь этим всем пользоваться, то уверен это бесценная информация!)
Val 21 декабря 2015 в 23:47 +2
Товарищи разработчики дополнений, я уже спрашивал в прошлом посте, но немного опоздал, поэтому повторю:
Кто как смотрит на то чтобы внести разработку WebMan'а в движок InstantCMS, или, проще говоря, добавить в "коробку"?
Отпишитесь в теме ниже? На сколько это вам будет полезно или бесполезно, пользуетесь или нет и т.д. Заранее спасибо всем кому не безразлично))
Loadырь 22 декабря 2015 в 00:00 +2
Я как разработчик "требую" это в коробку.
Но
Val 22 декабря 2015 в 08:40 0
Loadырь:
Можно рассмотреть вариант с "галочкой" при установке, типа "А не желаете ли вы, о любезный, использовать расширенный класс отладки на своём сайте" и хинт к нему "не знаете о чём речь, пройдите мимо"
Хорошая идея))
WebMan 22 декабря 2015 в 21:19 +1
"Все эти циферки и буковки" уже и так включаются/выключаются одной галочкой в Админке. smile
Можно сделать так, чтобы при установке CMS эта галочка по умолчанию была выключена, как это сделано со стандартной отладкой. Тогда любой вебмастер сможет её включить в нужный момент несколькими щелчками мышки.
WebMan 22 декабря 2015 в 21:23 0
А вот городить двойную установку с вопросом "хотите/нехотите?" - вот это как раз будет напрягать и разработчиков (держать в инстале по два варианта файлов и обновлять их), и пользователей (зачем им лишние вопросы?). Проще добавить эту отладку в "коробку" с выключенной "галкой".
Олег Васильевич я 22 декабря 2015 в 00:17 +2
А мнение не разработчиков не интересует? zlo
Val 22 декабря 2015 в 08:38 0
zst интересует мнение всех кто уже пользуется и будет пользоваться дальше)))
Но не соглашусь с вами, какой же вы не разработчик? А кто вам делает ваши замечательные шаблоны?)))
Олег Васильевич я 22 декабря 2015 в 11:35 +1
Не по делу: для меня все кто не знает хотя б PHP на приличном уровне, - любители; потому я в том числе.
По делу: разработчик всегда сможет установить для себя эту великолепную разработку и воспользоваться ею; вопрос в том. что делать с ней нам (какой толк от того что я увижу что где-то что-то обрабатывается медленно)? Поэтому моё мнение: кроме лишней головной боли для разработчиков системы внесение этой разработки в дистрибутив ничего не даст.
И чтобы не было вопросов: как любитель, считаю Отладку WebMan весьма полезной (по крайней мере, прибавка в скорости версии 2.3.0 и её заслуга).
WebMan, извините за полуфлуд!
Azami 22 декабря 2015 в 06:37 +1
Замечательная статья. Спасибо.
lezginka.ru 22 декабря 2015 в 07:18 0
как пользователь скажу - что хорошо бы отдельно, галочкой в админке вывести показатели по работе хостинга...т.к. бывает полезно сравнивать качество работы хостера
WebMan 22 декабря 2015 в 21:28 0
Это есть с самой первой версии - в основной таблице. Всё остальное можете просто не включать и не использовать.
Какие циферки что именно показывают про хостинг и движок уже описано в Определение проблем на сервере и в Если тормозят некоторые страницы сайта или ругается поддержка хостинга.
В следующей версии добавил ещё пару важных циферок в эту таблицу.