added execution times to debug console

NEWS

@@ -1,3 +1,5 @@
+    - added execution time to DEBUG console (Monte)
+    - fixed bug where DEBUG console would not appear with cached content (Monte)
     - added support for postfilter functions that are applied to compiled
       template right after compilation. (Andrei)
     - fixed the name of clear_compile_tpl() API function to clear_compiled_tpl.

Smarty.addons.php

@@ -690,6 +690,9 @@ function smarty_func_assign_debug_info($args, &$smarty_obj) {
 	$smarty_obj->assign("_debug_vals",array_values($assigned_vars));
 	$smarty_obj->assign("_debug_config_keys",array_keys($config_vars));
 	$smarty_obj->assign("_debug_config_vals",array_values($config_vars));
+	$smarty_obj->assign("_debug_times_keys",array_keys($smarty_obj->_smarty_debug_times));
+	$smarty_obj->assign("_debug_times_vals",array_values($smarty_obj->_smarty_debug_times));
+	
 	$smarty_obj->assign("_debug_tpls",$included_templates);
 	return true;
 }

Smarty.class.php

@@ -31,7 +31,7 @@
  *
  * Or, write to:
  * Monte Ohrt
- * CTO, ispi
+ * Director of Technology, ispi
  * 237 S. 70th suite 220
  * Lincoln, NE 68510
  *
@@ -198,6 +198,7 @@ class Smarty
     var $_inclusion_depth      =   0;          // current template inclusion depth
     var $_compile_id           =   null;       // for different compiled templates
     var $_smarty_debug_id      =   'SMARTY_DEBUG'; // id in query string to turn on debug mode
+    var $_smarty_debug_times   =   array();    // exec times in milliseconds
     
 
 /*======================================================================*\
@@ -494,7 +495,19 @@ class Smarty
     {
         global $HTTP_SERVER_VARS, $QUERY_STRING, $HTTP_COOKIE_VARS;
 
-        $this->_compile_id = $compile_id;
+        if ($this->debugging_ctrl == 'URL'
+				&& (!empty($QUERY_STRING)
+				&& strstr($QUERY_STRING,$this->_smarty_debug_id))) {
+			$this->debugging = true;
+		}
+			
+		if($this->debugging)
+		{
+			// capture time for debugging info
+			$debug_start_time = $this->_get_microtime();	
+		}
+			
+		$this->_compile_id = $compile_id;
         $this->_inclusion_depth = 0;
         $this->_included_tpls = array();
 
@@ -513,7 +526,15 @@ class Smarty
                     $results = $this->_process_cached_inserts($results);
                 }
                 if ($display) {
-                    echo $results; return;
+                    echo $results;
+					if ($this->debugging)
+					{
+						// capture time for debugging info
+						$this->_smarty_debug_times["total"] = $this->_get_microtime() - $debug_start_time;	
+
+						echo $this->_generate_debug_output();
+					}
+					return;
                 } else {
                     return $results;
                 }
@@ -579,7 +600,13 @@ class Smarty
 		
         if ($display) {
             if (isset($results)) { echo $results; }
-            if ($this->debugging || ($this->debugging_ctrl == 'URL' && (!empty($QUERY_STRING) && strstr($QUERY_STRING,$this->_smarty_debug_id)))) { echo $this->_generate_debug_output(); }
+            if ($this->debugging)
+				{
+					// capture time for debugging info
+					$this->_smarty_debug_times["TOTAL"] = $this->_get_microtime() - $debug_start_time;	
+
+					echo $this->_generate_debug_output();
+				}
             return;
         } else {
             if (isset($results)) { return $results; }
@@ -897,6 +924,9 @@ function _generate_debug_output() {
 \*======================================================================*/
     function _process_cached_inserts($results)
     {
+		if($this->debugging)
+		{ $debug_start_time = $this->_get_microtime(); }
+				
         preg_match_all('!'.$this->_smarty_md5.'{insert_cache (.*)}'.$this->_smarty_md5.'!Uis',
                        $results, $match);
         list($cached_inserts, $insert_args) = $match;
@@ -914,6 +944,9 @@ function _generate_debug_output() {
             $results = str_replace($cached_inserts[$i], $replace, $results);
         }
 
+        if ($this->debugging)
+		{ $this->_smarty_debug_times["insert_".$name] = $this->_get_microtime() - $debug_start_time; }
+			
         return $results;
     } 
 
@@ -924,12 +957,18 @@ function _generate_debug_output() {
 \*======================================================================*/
 function _run_insert_handler($args)
 {
+	if($this->debugging)
+	{ $debug_start_time = $this->_get_microtime(); }
+
     if ($this->caching) {
         $arg_string = serialize($args);
         return $this->_smarty_md5."{insert_cache $arg_string}".$this->_smarty_md5;
     } else {
         $function_name = 'insert_'.$args['name'];
-        return $function_name($args, $this);
+        $content = $function_name($args, $this);
+		if ($this->debugging)
+		{ $this->_smarty_debug_times["insert_".$args['name']] = $this->_get_microtime() - $debug_start_time; }
+		return $content;
     }
 }
 
@@ -1129,6 +1168,18 @@ function _run_mod_handler()
         trigger_error("Smarty error: $error_msg", $error_type);
     }
 
+/*======================================================================*\
+	Function:	_get_microtime
+	Purpose:	Get seconds and microseconds
+\*======================================================================*/
+	function _get_microtime()
+	{
+		$mtime = microtime();
+		$mtime = explode(" ", $mtime);
+		$mtime = (double)($mtime[1]) + (double)($mtime[0]);
+		return ($mtime);
+	}
+
 }
 
 /* vim: set expandtab: */

demo/templates/debug.tpl

@@ -25,6 +25,10 @@
 	{sectionelse}
 		_smarty_console.document.write("<tr bgcolor=#eeeeee><td colspan=2><tt><i>no config vars assigned</i></tt></td></tr>");	
 	{/section}
+	_smarty_console.document.write("<tr bgcolor=#cccccc><td colspan=2><b>Template execution time (in seconds):</b></td></tr>");
+	{section name=exec_time loop=$_debug_times_keys}
+		_smarty_console.document.write("<tr bgcolor={if %exed_time.index% is even}#eeeeee{else}#fafafa{/if}><td><tt>{if $_debug_times_keys[exec_time] eq "TOTAL"}<b>{$_debug_times_keys[exec_time]}</b>{else}{$_debug_times_keys[exec_time]}{/if}</td><td>{$_debug_times_vals[exec_time]}</tt></td></tr>");
+	{/section}
 	_smarty_console.document.write("</table>");
 	_smarty_console.document.write("</BODY></HTML>");
 	_smarty_console.document.close();

libs/Smarty.class.php

@@ -31,7 +31,7 @@
  *
  * Or, write to:
  * Monte Ohrt
- * CTO, ispi
+ * Director of Technology, ispi
  * 237 S. 70th suite 220
  * Lincoln, NE 68510
  *
@@ -198,6 +198,7 @@ class Smarty
     var $_inclusion_depth      =   0;          // current template inclusion depth
     var $_compile_id           =   null;       // for different compiled templates
     var $_smarty_debug_id      =   'SMARTY_DEBUG'; // id in query string to turn on debug mode
+    var $_smarty_debug_times   =   array();    // exec times in milliseconds
     
 
 /*======================================================================*\
@@ -494,7 +495,19 @@ class Smarty
     {
         global $HTTP_SERVER_VARS, $QUERY_STRING, $HTTP_COOKIE_VARS;
 
-        $this->_compile_id = $compile_id;
+        if ($this->debugging_ctrl == 'URL'
+				&& (!empty($QUERY_STRING)
+				&& strstr($QUERY_STRING,$this->_smarty_debug_id))) {
+			$this->debugging = true;
+		}
+			
+		if($this->debugging)
+		{
+			// capture time for debugging info
+			$debug_start_time = $this->_get_microtime();	
+		}
+			
+		$this->_compile_id = $compile_id;
         $this->_inclusion_depth = 0;
         $this->_included_tpls = array();
 
@@ -513,7 +526,15 @@ class Smarty
                     $results = $this->_process_cached_inserts($results);
                 }
                 if ($display) {
-                    echo $results; return;
+                    echo $results;
+					if ($this->debugging)
+					{
+						// capture time for debugging info
+						$this->_smarty_debug_times["total"] = $this->_get_microtime() - $debug_start_time;	
+
+						echo $this->_generate_debug_output();
+					}
+					return;
                 } else {
                     return $results;
                 }
@@ -579,7 +600,13 @@ class Smarty
 		
         if ($display) {
             if (isset($results)) { echo $results; }
-            if ($this->debugging || ($this->debugging_ctrl == 'URL' && (!empty($QUERY_STRING) && strstr($QUERY_STRING,$this->_smarty_debug_id)))) { echo $this->_generate_debug_output(); }
+            if ($this->debugging)
+				{
+					// capture time for debugging info
+					$this->_smarty_debug_times["TOTAL"] = $this->_get_microtime() - $debug_start_time;	
+
+					echo $this->_generate_debug_output();
+				}
             return;
         } else {
             if (isset($results)) { return $results; }
@@ -897,6 +924,9 @@ function _generate_debug_output() {
 \*======================================================================*/
     function _process_cached_inserts($results)
     {
+		if($this->debugging)
+		{ $debug_start_time = $this->_get_microtime(); }
+				
         preg_match_all('!'.$this->_smarty_md5.'{insert_cache (.*)}'.$this->_smarty_md5.'!Uis',
                        $results, $match);
         list($cached_inserts, $insert_args) = $match;
@@ -914,6 +944,9 @@ function _generate_debug_output() {
             $results = str_replace($cached_inserts[$i], $replace, $results);
         }
 
+        if ($this->debugging)
+		{ $this->_smarty_debug_times["insert_".$name] = $this->_get_microtime() - $debug_start_time; }
+			
         return $results;
     } 
 
@@ -924,12 +957,18 @@ function _generate_debug_output() {
 \*======================================================================*/
 function _run_insert_handler($args)
 {
+	if($this->debugging)
+	{ $debug_start_time = $this->_get_microtime(); }
+
     if ($this->caching) {
         $arg_string = serialize($args);
         return $this->_smarty_md5."{insert_cache $arg_string}".$this->_smarty_md5;
     } else {
         $function_name = 'insert_'.$args['name'];
-        return $function_name($args, $this);
+        $content = $function_name($args, $this);
+		if ($this->debugging)
+		{ $this->_smarty_debug_times["insert_".$args['name']] = $this->_get_microtime() - $debug_start_time; }
+		return $content;
     }
 }
 
@@ -1129,6 +1168,18 @@ function _run_mod_handler()
         trigger_error("Smarty error: $error_msg", $error_type);
     }
 
+/*======================================================================*\
+	Function:	_get_microtime
+	Purpose:	Get seconds and microseconds
+\*======================================================================*/
+	function _get_microtime()
+	{
+		$mtime = microtime();
+		$mtime = explode(" ", $mtime);
+		$mtime = (double)($mtime[1]) + (double)($mtime[0]);
+		return ($mtime);
+	}
+
 }
 
 /* vim: set expandtab: */

templates/debug.tpl

@@ -25,6 +25,10 @@
 	{sectionelse}
 		_smarty_console.document.write("<tr bgcolor=#eeeeee><td colspan=2><tt><i>no config vars assigned</i></tt></td></tr>");	
 	{/section}
+	_smarty_console.document.write("<tr bgcolor=#cccccc><td colspan=2><b>Template execution time (in seconds):</b></td></tr>");
+	{section name=exec_time loop=$_debug_times_keys}
+		_smarty_console.document.write("<tr bgcolor={if %exed_time.index% is even}#eeeeee{else}#fafafa{/if}><td><tt>{if $_debug_times_keys[exec_time] eq "TOTAL"}<b>{$_debug_times_keys[exec_time]}</b>{else}{$_debug_times_keys[exec_time]}{/if}</td><td>{$_debug_times_vals[exec_time]}</tt></td></tr>");
+	{/section}
 	_smarty_console.document.write("</table>");
 	_smarty_console.document.write("</BODY></HTML>");
 	_smarty_console.document.close();