[Piwik-svn] r476 - in trunk: misc modules modules/LogStats modules/LogStats/Generator
svnmaster at piwik.org
svnmaster at piwik.org
Sun May 11 20:35:46 CEST 2008
Author: matt
Date: 2008-05-11 20:35:43 +0200 (Sun, 11 May 2008)
New Revision: 476
Modified:
trunk/misc/generateVisits.php
trunk/modules/ErrorHandler.php
trunk/modules/FrontController.php
trunk/modules/LogStats.php
trunk/modules/LogStats/Db.php
trunk/modules/LogStats/Generator.php
trunk/modules/LogStats/Generator/LogStats.php
trunk/modules/LogStats/Generator/Visit.php
trunk/modules/LogStats/Visit.php
trunk/modules/Piwik.php
Log:
- refactoring, cleaning visit generation and SQL profiling
Modified: trunk/misc/generateVisits.php
===================================================================
--- trunk/misc/generateVisits.php 2008-05-11 16:58:02 UTC (rev 475)
+++ trunk/misc/generateVisits.php 2008-05-11 18:35:43 UTC (rev 476)
@@ -51,8 +51,8 @@
$generator->setMaximumUrlDepth(3);
//$generator->disableProfiler();
$generator->setIdSite( $idSite = 1 );
-$minVisits = 8;
-$maxVisits = 9;
+$minVisits = 5;
+$maxVisits = 15;
$nbActions = 15;
$daysToCompute = 1;
@@ -79,7 +79,7 @@
// we add silent fail because of headers already sent error.
// although this should'nt happen because we use a OB_START at the top of this page...
// but I couldnt find where those headers were sent...
- $nbActionsTotalThisDay = @$generator->generate($visits,$actions);
+ $nbActionsTotalThisDay = $generator->generate($visits,$actions);
$actionsPerVisit = round($nbActionsTotalThisDay / $visits);
print("Generated $visits visits and $actionsPerVisit actions per visit for the ".date("Y-m-d", $startTime)."<br>\n");
@@ -88,7 +88,6 @@
flush();
}
-
echo "<br>Total actions: $nbActionsTotal";
echo "<br>Total requests per sec: ". round($nbActionsTotal / $t->getTime(),0);
echo "<br>".$t;
Modified: trunk/modules/ErrorHandler.php
===================================================================
--- trunk/modules/ErrorHandler.php 2008-05-11 16:58:02 UTC (rev 475)
+++ trunk/modules/ErrorHandler.php 2008-05-11 18:35:43 UTC (rev 476)
@@ -27,7 +27,7 @@
{
return;
}
-
+
ob_start();
debug_print_backtrace();
$backtrace = ob_get_contents();
Modified: trunk/modules/FrontController.php
===================================================================
--- trunk/modules/FrontController.php 2008-05-11 16:58:02 UTC (rev 475)
+++ trunk/modules/FrontController.php 2008-05-11 18:35:43 UTC (rev 476)
@@ -182,7 +182,7 @@
function __destruct()
{
try {
- Piwik::printZendProfiler();
+ Piwik::printSqlProfilingReportZend();
Piwik::printQueryCount();
} catch(Exception $e) {}
Modified: trunk/modules/LogStats/Db.php
===================================================================
--- trunk/modules/LogStats/Db.php 2008-05-11 16:58:02 UTC (rev 475)
+++ trunk/modules/LogStats/Db.php 2008-05-11 18:35:43 UTC (rev 476)
@@ -53,7 +53,7 @@
* Enables the SQL profiling.
* For each query, saves in the DB the time spent on this query.
* Very useful to see the slow query under heavy load.
- * You can then use Piwik::printLogStatsSQLProfiling();
+ * You can then use Piwik::printSqlProfilingReportLogStats();
* to display the SQLProfiling report and see which queries take time, etc.
*/
static public function enableProfiling()
@@ -76,12 +76,20 @@
*/
public function connect()
{
+ if(self::$profiling)
+ {
+ $timer = $this->initProfiler();
+ }
$pdoConnect = new PDO($this->dsn, $this->username, $this->password);
$pdoConnect->setAttribute(PDO::ATTR_ERRMODE, PDO::ERRMODE_EXCEPTION);
$this->connection = $pdoConnect;
-
// we delete the password from this object "just in case" it could be printed
$this->password = '';
+
+ if(self::$profiling)
+ {
+ $this->recordQueryProfile('connect', $timer);
+ }
}
/**
@@ -91,7 +99,10 @@
*/
public function disconnect()
{
- $this->recordProfiling();
+ if(self::$profiling)
+ {
+ $this->recordProfiling();
+ }
$this->connection = null;
}
@@ -170,11 +181,10 @@
{
return false;
}
- try {
+ try {
if(self::$profiling)
{
- require_once "Timer.php";
- $t = new Piwik_Timer;
+ $timer = $this->initProfiler();
}
$sth = $this->connection->prepare($query);
@@ -182,19 +192,29 @@
if(self::$profiling)
{
- if(!isset($this->queriesProfiling[$query])) $this->queriesProfiling[$query] = array('sum_time_ms' => 0, 'count' => 0);
- $time = $t->getTimeMs(2);
- $time += $this->queriesProfiling[$query]['sum_time_ms'];
- $count = $this->queriesProfiling[$query]['count'] + 1;
- $this->queriesProfiling[$query] = array('sum_time_ms' => $time, 'count' => $count);
+ $this->recordQueryProfile($query, $timer);
}
-
return $sth;
} catch (PDOException $e) {
throw new Exception("Error query: ".$e->getMessage());
}
}
+ protected function initProfiler()
+ {
+ require_once "Timer.php";
+ return new Piwik_Timer;
+ }
+
+ protected function recordQueryProfile( $query, $timer )
+ {
+ if(!isset($this->queriesProfiling[$query])) $this->queriesProfiling[$query] = array('sum_time_ms' => 0, 'count' => 0);
+ $time = $timer->getTimeMs(2);
+ $time += $this->queriesProfiling[$query]['sum_time_ms'];
+ $count = $this->queriesProfiling[$query]['count'] + 1;
+ $this->queriesProfiling[$query] = array('sum_time_ms' => $time, 'count' => $count);
+ }
+
/**
* Returns the last inserted ID in the DB
* Wrapper of PDO::lastInsertId()
@@ -211,31 +231,28 @@
*/
public function recordProfiling()
{
- if(self::$profiling)
+ if(is_null($this->connection))
{
- if(is_null($this->connection))
- {
- return;
- }
+ return;
+ }
+
+ // turn off the profiler so we don't profile the following queries
+ self::$profiling = false;
- // turn off the profiler so we don't profile the following queries
- self::$profiling = false;
-
- foreach($this->queriesProfiling as $query => $info)
- {
- $time = $info['sum_time_ms'];
- $count = $info['count'];
+ foreach($this->queriesProfiling as $query => $info)
+ {
+ $time = $info['sum_time_ms'];
+ $count = $info['count'];
- $queryProfiling = "INSERT INTO ".$this->prefixTable('log_profiling')."
- (query,count,sum_time_ms) VALUES (?,$count,$time)
- ON DUPLICATE KEY
- UPDATE count=count+$count,sum_time_ms=sum_time_ms+$time";
- $this->query($queryProfiling,array($query));
- }
-
- // turn back on profiling
- self::$profiling = true;
+ $queryProfiling = "INSERT INTO ".$this->prefixTable('log_profiling')."
+ (query,count,sum_time_ms) VALUES (?,$count,$time)
+ ON DUPLICATE KEY
+ UPDATE count=count+$count,sum_time_ms=sum_time_ms+$time";
+ $this->query($queryProfiling,array($query));
}
+
+ // turn back on profiling
+ self::$profiling = true;
}
}
Modified: trunk/modules/LogStats/Generator/LogStats.php
===================================================================
--- trunk/modules/LogStats/Generator/LogStats.php 2008-05-11 16:58:02 UTC (rev 475)
+++ trunk/modules/LogStats/Generator/LogStats.php 2008-05-11 18:35:43 UTC (rev 476)
@@ -38,6 +38,7 @@
*/
protected function endProcess()
{
+ $this->disconnectDb();
}
/**
@@ -48,6 +49,5 @@
protected function getNewVisitObject()
{
return new Piwik_LogStats_Generator_Visit($this->db);
- }
-
+ }
}
\ No newline at end of file
Modified: trunk/modules/LogStats/Generator/Visit.php
===================================================================
--- trunk/modules/LogStats/Generator/Visit.php 2008-05-11 16:58:02 UTC (rev 475)
+++ trunk/modules/LogStats/Generator/Visit.php 2008-05-11 18:35:43 UTC (rev 476)
@@ -48,4 +48,9 @@
return date("Y-m-d H:i:s",$timestamp);
}
+ protected function updateCookie()
+ {
+ @parent::updateCookie();
+ }
+
}
Modified: trunk/modules/LogStats/Generator.php
===================================================================
--- trunk/modules/LogStats/Generator.php 2008-05-11 16:58:02 UTC (rev 475)
+++ trunk/modules/LogStats/Generator.php 2008-05-11 18:35:43 UTC (rev 476)
@@ -231,7 +231,7 @@
{
if($this->profiling)
{
- Piwik::printLogStatsSQLProfiling();
+ Piwik::printSqlProfilingReportLogStats();
}
}
@@ -337,8 +337,7 @@
{
if($this->reinitProfilingAtEveryRequest)
{
- $db = Zend_Registry::get('db');
- $all = $db->query('TRUNCATE TABLE '.Piwik::prefixTable('log_profiling').'' );
+ $all = Zend_Registry::get('db')->query('TRUNCATE TABLE '.Piwik::prefixTable('log_profiling').'' );
}
}
}
@@ -371,9 +370,6 @@
$nbActionsTotal += $nbActions;
}
-// print("<br> Generated $nbVisits visits.");
-// print("<br> Generated $nbActionsTotal actions.");
-
return $nbActionsTotal;
}
Modified: trunk/modules/LogStats/Visit.php
===================================================================
--- trunk/modules/LogStats/Visit.php 2008-05-11 16:58:02 UTC (rev 475)
+++ trunk/modules/LogStats/Visit.php 2008-05-11 18:35:43 UTC (rev 476)
@@ -350,7 +350,7 @@
/**
* Update the cookie information.
*/
- private function updateCookie()
+ protected function updateCookie()
{
printDebug("We manage the cookie...");
Modified: trunk/modules/LogStats.php
===================================================================
--- trunk/modules/LogStats.php 2008-05-11 16:58:02 UTC (rev 475)
+++ trunk/modules/LogStats.php 2008-05-11 18:35:43 UTC (rev 476)
@@ -229,9 +229,14 @@
if($GLOBALS['DEBUGPIWIK'] === true)
{
- Piwik::printLogStatsSQLProfiling($this->db);
+ Piwik::printSqlProfilingReportLogStats($this->db);
}
+ $this->disconnectDb();
+ }
+
+ protected function disconnectDb()
+ {
if(isset($this->db))
{
$this->db->disconnect();
Modified: trunk/modules/Piwik.php
===================================================================
--- trunk/modules/Piwik.php 2008-05-11 16:58:02 UTC (rev 475)
+++ trunk/modules/Piwik.php 2008-05-11 18:35:43 UTC (rev 476)
@@ -216,7 +216,7 @@
Piwik::log("Total queries = $queryCount (total sql time = ".round($totalTime,2)."s)");
}
- static public function printLogStatsSQLProfiling( $db = null )
+ static public function printSqlProfilingReportLogStats( $db = null )
{
function maxSumMsFirst($a,$b)
{
@@ -240,25 +240,23 @@
}
usort($all, 'maxSumMsFirst');
- $str='<br><br>Query Profiling<br>----------------------<br>';
+ $infoIndexedByQuery = array();
foreach($all as $infoQuery)
{
$query = $infoQuery['query'];
$count = $infoQuery['count'];
$sum_time_ms = $infoQuery['sum_time_ms'];
- $avg_time_ms = round($infoQuery['avg_time_ms'],1);
- $query = str_replace("\t", "", $query);
-
- $str .= " $query <br>
- $count times, <b>$sum_time_ms ms total</b><br>
- $avg_time_ms ms average<br>
- <br>";
+ $infoIndexedByQuery[$query] = array('count' => $count, 'sumTimeMs' => $sum_time_ms);
}
-
- Piwik::log($str);
+ Piwik::getSqlProfilingQueryBreakdownOutput($infoIndexedByQuery);
}
- static function printZendProfiler()
+ /**
+ * Outputs SQL Profiling reports
+ * It is automatically called when enabling the SQL profiling in the config file enable_sql_profiler
+ *
+ */
+ static function printSqlProfilingReportZend()
{
$profiler = Zend_Registry::get('db')->getProfiler();
@@ -267,27 +265,26 @@
throw new Exception("To display the profiler you should enable enable_sql_profiler on your config/config.ini.php file");
}
- $indexByQuery = array();
+ $infoIndexedByQuery = array();
foreach($profiler->getQueryProfiles() as $query)
{
- if(isset($indexByQuery[$query->getQuery()]))
+ if(isset($infoIndexedByQuery[$query->getQuery()]))
{
$existing = $indexByQuery[$query->getQuery()];
}
else
{
- $existing = array( 'count' => 0, 'sumTimeSeconds' => 0);
+ $existing = array( 'count' => 0, 'sumTimeMs' => 0);
}
$new = array( 'count' => $existing['count'] + 1,
- 'sumTimeSeconds' => $existing['count'] + $query->getElapsedSecs()
- );
- $indexByQuery[$query->getQuery()] = $new;
+ 'sumTimeMs' => $existing['count'] + $query->getElapsedSecs() * 1000);
+ $infoIndexedByQuery[$query->getQuery()] = $new;
}
function sortTimeDesc($a,$b)
{
- return $a['sumTimeSeconds'] < $b['sumTimeSeconds'];
+ return $a['sumTimeMs'] < $b['sumTimeMs'];
}
- uasort( $indexByQuery, 'sortTimeDesc');
+ uasort( $infoIndexedByQuery, 'sortTimeDesc');
Piwik::log('<hr><b>SQL Profiler</b>');
Piwik::log('<hr><b>Summary</b>');
@@ -306,14 +303,27 @@
$str .= '<br>Queries per second: ' . round($queryCount / $totalTime,1) . "\n";
$str .= '<br>Longest query length: ' . round($longestTime,3) . " seconds (<code>$longestQuery</code>) \n";
Piwik::log($str);
-
+ Piwik::getSqlProfilingQueryBreakdownOutput($infoIndexedByQuery);
+ }
+
+ static private function getSqlProfilingQueryBreakdownOutput( $infoIndexedByQuery )
+ {
Piwik::log('<hr><b>Breakdown by query</b>');
- foreach($indexByQuery as $query => $queryInfo)
+ $output = '';
+ foreach($infoIndexedByQuery as $query => $queryInfo)
{
- $timeMs = round($queryInfo['sumTimeSeconds'] * 1000,1);
+ $timeMs = round($queryInfo['sumTimeMs'],1);
$count = $queryInfo['count'];
- Piwik::log("Executed <b>$count</b> time". ($count==1?'':'s') ." in <b>".$timeMs."ms</b> total = <code>$query</code>");
+ $avgTimeString = '';
+ if($count > 1)
+ {
+ $avgTimeMs = $timeMs / $count;
+ $avgTimeString = " (average = <b>". round($avgTimeMs,1) . "ms</b>)";
+ }
+ $query = str_replace(array("\t","\n"), "", $query);
+ $output .= "Executed <b>$count</b> time". ($count==1?'':'s') ." in <b>".$timeMs."ms</b> $avgTimeString <pre>\t$query</pre>";
}
+ Piwik::log($output);
}
static public function printTimer()
More information about the Piwik-svn
mailing list