Yii SQL Profiling of AJAX calls

You can try to extend CFileLogRoute in the manner proposed below and enable it in application's configuration like this:

'log'=>array(    'class'=>'CLogRouter',    'routes'=>array(        array(            'class'=>'ProfileLogRoute',            'levels' => "profile"        )    ))

In this case all profiled queries will be written to a log file located in protected/runtime directory (overriding of processLogs method is implemented likewise summary report of CProfileWebRoute...unfortunately CProfileWebRoute is derived from CWebLogRoute):

<?php  class ProfileLogRoute extends CFileLogRoute{    protected function processLogs($logs)    {        $logFile=$this->getLogPath().DIRECTORY_SEPARATOR.$this->getLogFile();        if(@filesize($logFile)>$this->getMaxFileSize()*1024)            $this->rotateFiles();        $fp=@fopen($logFile,'a');        @flock($fp,LOCK_EX);        $profileStack = array();        $profileResults = array();        foreach ($logs as $log)        {            if ($log[1] === CLogger::LEVEL_PROFILE)            {                $message = $log[0];                if (!strncasecmp($message, 'begin:', 6))                {                    $log[0] = substr($message,6);                    $profileStack[] = $log;                }                else if(!strncasecmp($message, 'end:', 4))                {                    $token = substr($message,4);                    if(($last = array_pop($profileStack)) !== null && $last[0] === $token)                    {                        $info = array(                            'delta' => $log[3] - $last[3],                            'category' => $last[2],                            'time' => $last[3]                        );                        $this->aggregateResult($token, $info, $profileResults);                    }                    else                    {                        throw new CException(Yii::t('yii','CProfileLogRoute found a mismatching code block "{token}". Make sure the calls to Yii::beginProfile() and Yii::endProfile() be properly nested.',                            array('{token}'=>$token)));                    }                }            }            else            {                @fwrite($fp,$this->formatLogMessage($log[0],$log[1],$log[2],$log[3]));            }        }        if (!empty($profileResults))        {            $now = microtime(true);            while(($last = array_pop($profileStack)) !== null)            {                $info = array(                    'delta' => $now - $last[3],                    'category' => $last[2],                    'time' => $last[3]                );                $token = $last[0];                $this->aggregateResult($token, $info, $profileResults);            }            $entries = array_values($profileResults);            $func = create_function('$a,$b','return $a["total"]<$b["total"]?1:0;');            usort($entries, $func);            foreach ($entries as $entry)            {                $message = sprintf("Min: % 11.8f    Max: % 11.8f    Total: % 11.8f    Calls: % 3d    %s", $entry['min'], $entry['max'], $entry['total'], $entry['calls'], $entry['token']);                @fwrite($fp, $this->formatLogMessage($message, CLogger::LEVEL_PROFILE, $entry['category'], $entry['time']));            }        }        @flock($fp,LOCK_UN);        @fclose($fp);    }    protected function aggregateResult($token, $info, &$results)    {        if (isset($results[$token]))        {            if ($info['delta'] < $results[$token]['min'])                $results[$token]['min'] = $info['delta'];            else if($info['delta'] > $results[$token]['max'])                $results[$token]['max'] = $info['delta'];            $results[$token]['calls']++;            $results[$token]['total'] += $info['delta'];            return;        }        $results[$token] = array(            'token' => $token,            'calls' => 1,            'min' => $info['delta'],            'max' => $info['delta'],            'total' => $info['delta'],            'category' => $info['category'],            'time' => $info['time']        );    }}

If you want to know how Yii measures a time of SQL execution you can look at the source code of CDbCommand class - queryInternal method, to be more precise. Profiling is between Yii::beginProfile('system.db.CDbCommand.query...') and Yii::endProfile('system.db.CDbCommand.query...') calls. As you can see both these calls are within the same method, as the result the time of profiling doesn't include a network transfer. Probably, the issue is that your remote database server runs under huge load.

There is a property of the CProfileLogRoute class called ignoreAjaxInFireBug which defaults to "true" by setting it to false you can get your profiling info on ajax requests.

http://www.yiiframework.com/doc/api/1.1/CWebLogRoute#ignoreAjaxInFireBug-detail

'log'=>array(    'class'=>'CLogRouter',    'routes'=>array(                    array(                        'class'=>'CProfileLogRoute',                        'ignoreAjaxInFireBug'=>false,                        'levels'=>'error, warning, trace, info, profile',                    ),        ),

I don't believe ou need to use firebug for that work (it's kind of a misnomer). If you do however, just download firefox and install firebug and then your problem is still solved.