Отладочный таймер и пример интеграции в Yii

Песочные часы

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

Для вывода текущего времени исполнения в Yii можно расставить в любое место кода строки

echo sprintf('%0.3f',Yii::getLogger()->getExecutionTime());

Этот код выведет число миллисекунд, прощедших с начала выполнения скрипта.

Для упрощения вставки таких «датчиков» в код можно написать простой класс

class DTimer
{
    protected static $startTime;
    protected static $points = array();
 
    public static function run()
    {
        self::$startTime = microtime(true);
    }
 
    public static function log($message='')
    {
        if (self::$startTime === null)
            self::run();
 
        self::$points[] = array('message'=>$message, 'time'=>sprintf('%0.3f', microtime(true) - self::$startTime));
    }
 
    public static function show()
    {
        $oldtime = 0;
 
        echo '
            <table style="width:auto !important; position:fixed; right:0; top:0; z-index:200; background:#fff !important">
             <tr>
                <th></th>
                <th>Diff</th>
                <th>Time</th>
            </tr>
        ';
 
        foreach(self::$points as $item){
 
            $message = $item['message'];
            $time = $item['time'] * 1000;
            $diff = ($item['time'] - $oldtime) * 1000;
 
            echo "
                <tr>
                    <td>{$message}</td>
                    <td style='text-align:right; width:50px'>{$diff}</td>
                    <td style='text-align:right; width:50px''>{$time}</td>
                </tr>
            ";
 
            $oldtime = $item['time'];
        };
        echo "</table>\n";
    }
}

и запустить его в файле index.php:

require_once('DTimer.php');
DTimer::run();

Теперь можно расставить по коду контрольные точки

DTimer::log('start');
$this->superCommand1();
DTimer::log('Command1');
 
$this->superCommand2();
 
// чтобы не учитывать время исполнения superCommand2() 
// поставим здесь ещё одну точку
DTimer::log('reset');
$this->superCommand3();
DTimer::log('Command3');

и после выполнения скрипта вывести таблицу с результатами

DTimer::show();

Таблица появится в правом верхнем углу окна. Она покажет прошедшие интервалы и общее время для каждого вызова:

Diff Time
start 10 10
Command1 9 19
reset 12 31
Command3 18 49

А теперь небольшая хитрость. Если точек нужно много, но лень указывать метки вручную, то можно использовать автоподстановку номеров строк значением __LINE__:

DTimer::log(__LINE__);
$this->superCommand1();
DTimer::log(__LINE__);
$this->superCommand2();
DTimer::log(__LINE__);
$this->superCommand3();
DTimer::log(__LINE__);
$this->superCommand4();
DTimer::log(__LINE__);
$this->superCommand5();
DTimer::log(__LINE__);
$this->superCommand6();
DTimer::log(__LINE__);

Аналогично можно пофантазировать и использовать другие константы (напрмер __METHOD__, __CLASS__).

Применение таймера в Yii

Теперь мы знаем, как можно расставлять контрольные точки в код и отслеживать их прохождение в любом скрипте. Рассмотрим теперь возможность удобно следить за временем выполнения в Yii Framework.

Подключим и запустим наш таймер в начале файла index.php:

require_once('DTimer.php');
DTimer::run();

Теперь дополним наш базовый контроллер. Чтобы засечь момент времени перед выполнением действия (action) контроллера переопределим метод beforeAction(). Классический action оканчивается рендерингом представления, поэтому добавим контрольную точку и в beforeRender():

class Controller extends CController
{
    // ...
 
    protected function beforeAction($action)
    {
        DTimer::log('system');
        return parent::beforeAction($action);
    }
 
    protected function beforeRender($viev)
    {
        DTimer::log('action');
        return parent::beforeRender($viev);
    }
 
}

Таким образом, по этим двум точкам мы уже можем отслеживать время инициальзации фреймворка и время работы экшена.

Для получения более полной информации нам нужно залезть внуть метода CController::render(). Скопируем этот метод из класса CController в наш контроллер и расставим в нём контрольные точки. Также перенесём в него точку DTimer::log('action') и уберём за ненадобностью опустевший метод beforeRender():

class Controller extends CController
{
    // ...
 
    protected function beforeAction($action)
    {
        DTimer::log('system');
        return parent::beforeAction($action);
    }
 
    public function render($view,$data=null,$return=false)
    {
        DTimer::log('action');
 
        if($this->beforeRender($view))
        {
            DTimer::log('beforeRender');
 
            $output=$this->renderPartial($view,$data,true);
            DTimer::log('render');
 
            if(($layoutFile=$this->getLayoutFile($this->layout))!==false){
                $output=$this->renderFile($layoutFile,array('content'=>$output),true);
                DTimer::log('renderLayout');
            }
 
            $this->afterRender($view,$output);
            DTimer::log('afterRender');
 
            $output=$this->processOutput($output);
            DTimer::log('processOutput');
 
            if($return)
                return $output;
            else {
                echo $output;
                DTimer::show();
            }
        }
    }
}

Чтобы таблица диагностики не выскакивала на рабочем сайте можно добавить условие для вывода только в режиме отладки:

else {
    echo $output;
    if (YII_DEBUG) 
        DTimer::show();
}

На этом всё. Теперь мы видим, сколько времени занимает каждый этап и знаем, где именно нужно проводить оптимизацию:

Diff Time
system 67 67
action 17 84
beforeRender 2 86
render 60 146
renderLayout 64 210
afterRender 0 210
processOutput 1 211

Кроме того, «датчики» можно расставлять в любом месте кода (иногда полезно проверить виджеты, модели, поведения и т.д.). Чтобы не заблудиться можно использовать запись

DTimer::log(__METHOD__ . ' ' . __LINE__);

Все «показания» появятся в таблице по порядку их следования в коде.

Другие статьи

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

Если Вы вдруг решили подключить ноутбук к компьютеру с Windows7, то при обнаружении новой сети система спросит у Вас, какой тип сети установить (Домашняя, Рабочая или Общественная). Это стандартно. Но пользователи Win7 столкнутся с казусом, что при подключении в «Центре управления сетями и общим доступом» новая сеть становится неопознанной и общественной, если не указать для IPv4-адреса основной шлюз.

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

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

Комментарии

 

Виталий Сиротенко

Yii::beginProfile
Yii::endProfile
не то?

Ответить

 

Дмитрий Елисеев

То. Но это только в Yii.

Ответить

 

Виталий Сиротенко

просто пример для Yii был, я добавил этот класс в проект на Yii
а потом нашел для себя
Yii::beginProfile
Yii::endProfile
и решил с вами поделиться :)

ps спасибо за отличные уроки по Yii вашем на сайте

можно задать вам вопрос по Yii но не по этой теме, второй день бьюсь?

Ответить

 

Дмитрий Елисеев

Можно. Отправьте через обратную связь.

Ответить

Оставить комментарий

Войти | Завести аккаунт


(никто не увидит)



Можно использовать теги <p> <ul> <li> <b> <i> <a> <pre>