Yii2 profiling helper for consoletest environment¶

<?php
namespace common\tests;

use Codeception\Util\Debug;
use yii\console\Application;
use yii\db\ActiveQuery;
use yii\db\Connection;
use yii\helpers\ArrayHelper;
use yii\helpers\Console;
use yii\helpers\VarDumper;

/**
 * Useful set for performance optimization in console scripts, and test researches
 *
 * Trait ProfilingInspectorTrait
 *
 * @package common\tests
 */
trait ProfilingInspectorTrait
{

    /**
     * @param \yii\db\Query|ActiveQuery $query
     * @param \yii\db\Connection        $db
     */
    protected function showQuery(\yii\db\Query $query, Connection $db)
    {
        $sql = $query->prepare($db->queryBuilder)->createCommand($db)->rawSql;
        $this->resolvedOutput($sql, __FUNCTION__);
    }

    /**
     * @param \yii\db\Query|ActiveQuery $query
     * @param \yii\db\Connection        $db
     */
    protected function explainQuery(\yii\db\Query $query, Connection $db)
    {
        $sql = $query->prepare($db->queryBuilder)->createCommand($db)->rawSql;
        $sql = 'EXPLAIN: ' . implode(PHP_EOL, $db->createCommand('EXPLAIN ' . $sql)->queryColumn('QUERY PLAN'));
        $this->resolvedOutput($sql, __FUNCTION__);
    }

    /**
     * @param \yii\db\Query|ActiveQuery $query
     * @param \yii\db\Connection        $db
     */
    protected function analyzeQuery(\yii\db\Query $query, Connection $db)
    {
        $sql = $query->prepare($db->queryBuilder)->createCommand($db)->rawSql;
        $sql = 'ANALYZE: ' . implode(PHP_EOL, $db->createCommand('EXPLAIN ANALYZE ' . $sql)->queryColumn('QUERY PLAN'));
        $this->resolvedOutput($sql, __FUNCTION__);
    }

    /**
     * Show execution time for specified callback and time elapsed from app start
     * Return real function result
     *
     * @example
     *         $result=$this->timeIt(function(){
     *         $data = User::find()->where(['<','id', 100])->all();
     *         return ArrayHelper::map($data,'id','name');
     *         });
     *
     * @param \Closure $function
     * @param string   $comment Additional log comment
     *
     * @return mixed
     */
    protected function timeIt(\Closure $function, string $comment = '')
    {
        $mStart = microtime(true);
        $result = $function();
        $mEnd = microtime(true);
        $this->resolvedOutput(
            [
                'timeDelta' => ($mEnd - $mStart),
                'elapsedTime'=>\Yii::getLogger()->elapsedTime
            ],
            __FUNCTION__ . ':' . $comment
        );
        return $result;
    }

    /**
     * Show execution time, memory usage, and peek memory check for specified callback
     * Return real function result
     *
     * @example
     *           $result1=$this->inspectIt(function(){
     *           $data = User::find()->where(['<','id', 100])->all();
     *           return ArrayHelper::map($data,'id','name');
     *           },'Object result');
     *           $result2 = $this->inspectIt(function(){
     *           $data = User::find()->where(['<','id', 100])->asArray()->all();
     *           $result = ArrayHelper::map($data,'id','name');
     *           unset($data);
     *           return $result;
     *           },'As Array result');
     *
     * @param \Closure $function
     * @param string   $comment Additional log comment
     *
     * @return mixed
     */
    protected function inspectIt(\Closure $function, string $comment = '')
    {
        $start = \Yii::getLogger()->elapsedTime;
        $start_memory = memory_get_usage();
        $start_peek = memory_get_peak_usage();
        $result = $function();
        $end_memory = memory_get_usage();
        $end_peek = memory_get_peak_usage();
        $end = \Yii::getLogger()->elapsedTime;
        $this->resolvedOutput(
            [
                'timeDelta' => ($end - $start),
                'memory'    => [
                    'from'                => \Yii::$app->formatter->asSize($start_memory),
                    'to'                  => \Yii::$app->formatter->asSize($end_memory),
                    'delta'               => \Yii::$app->formatter->asSize(($end_memory - $start_memory)),
                    'peekMemoryIncreased' => ($end_peek > $start_peek) ? \Yii::$app->formatter->asSize($start_peek)
                        . ' +' . \Yii::$app->formatter->asSize($end_peek - $start_peek) : 'no',
                ],
            ],
            __FUNCTION__ . ':' . $comment
        );
        return $result;
    }

    /**
     * Show profile log for specified callback
     * Return real function result
     *
     * @example
     *         $result=$this->profileIt(function(){
     *         $data = User::find()->where(['<','id', 100])->all();
     *         return ArrayHelper::map($data,'id','name');
     *         });
     *
     * @param \Closure $function
     * @param string   $comment Additional log comment
     *
     * @return mixed
     */
    protected function profileIt(\Closure $function, string $comment = '')
    {
        $id = uniqid('profile_');
        \Yii::beginProfile($id, __FUNCTION__ . ':' . $id);
        $result = $function();
        \Yii::endProfile($id, __FUNCTION__ . ':' . $id);
        $profile = \Yii::getLogger()->getProfiling([]);
        $map = ArrayHelper::getColumn($profile, 'info');
        $profile = array_slice($profile, array_search($id, $map));
        unset($map);
        $this->resolvedOutput($profile, __FUNCTION__ . ':' . $id . ':' . $comment);
        return $result;
    }

    /**
     * @param $message
     */
    protected function resolvedOutput($message, $subj = ''): void
    {
        $divider = '============= ' . $subj . ' ===============';
        if (YII_ENV_TEST === true) {
            Debug::debug($divider);
            Debug::debug($message);
        } elseif (\Yii::$app instanceof Application) {
            Console::output(Console::ansiFormat($divider . PHP_EOL, [Console::FG_BLUE]));
            Console::output(Console::ansiFormat(VarDumper::export($message) . PHP_EOL, [Console::FG_GREEN]));
        } else {
            \Yii::trace($message, get_called_class().':'.$subj);
        }
    }

}