Finalize debug data format and allow all statistics to be collected

classes/db/DB.class.php

@@ -372,13 +372,13 @@ class DB
 		{
 			if($call['function'] == 'executeQuery' || $call['function'] == 'executeQueryArray')
 			{
-				$log['backtrace'] = array_slice($bt, $no);
 				$call_no = $no;
 				$call_no++;
 				$log['called_file'] = $bt[$call_no]['file'];
 				$log['called_line'] = $bt[$call_no]['line'];
 				$call_no++;
 				$log['called_method'] = $bt[$call_no]['class'].$bt[$call_no]['type'].$bt[$call_no]['function'];
+				$log['backtrace'] = array_slice($bt, $call_no, 1);
 				break;
 			}
 		}

classes/display/DisplayHandler.class.php

@@ -11,7 +11,7 @@
  */
 class DisplayHandler extends Handler
 {
-
+	public static $response_size = 0;
 	var $content_size = 0; // /< The size of displaying contents
 	var $gz_enabled = FALSE; // / <a flog variable whether to call contents after compressing by gzip
 	var $handler = NULL;
@@ -81,7 +81,6 @@ class DisplayHandler extends Handler
 		Context::getInstance()->checkSessionStatus();
 
 		// header output
-
 		$httpStatusCode = $oModule->getHttpStatusCode();
 		if($httpStatusCode && $httpStatusCode != 200)
 		{
@@ -119,16 +118,14 @@ class DisplayHandler extends Handler
 			ini_set('zlib.output_compression', true);
 		}
 
-		// results directly output
-		print $output;
-		$this->content_size = strlen($output);
-
 		// call a trigger after display
+		self::$response_size = $this->content_size = strlen($output);
 		ModuleHandler::triggerCall('display', 'after', $output);
 
 		// debugOutput output
-		$this->content_size = strlen($output);
+		$debug = $this->getDebugInfo($output);
-		print $this->getDebugInfo($output);
+		print $output;
+		print $debug;
 
 		flushSlowlog();
 	}
@@ -145,6 +142,8 @@ class DisplayHandler extends Handler
 		{
 			return;
 		}
+		
+		// Check if debugging info should be visible to the current user.
 		$display_to = config('debug.display_to');
 		switch ($display_to)
 		{
@@ -172,19 +171,16 @@ class DisplayHandler extends Handler
 				return;
 		}
 		
-		// Set some useful variables.
-		$basedir_len = strlen(RX_BASEDIR);
-		$timestamp = sprintf('[%s]', Rhymix\Framework\DateTime::formatTimestampForCurrentUser('Y-m-d H:i:s P', RX_TIME));
-		
-		// Collect debug information.
-		$entries = Rhymix\Framework\Debug::getEntries();
-		$errors = config('debug.log_errors') ? Rhymix\Framework\Debug::getErrors() : null;
-		$queries = config('debug.log_queries') ? Rhymix\Framework\Debug::getQueries() : null;
-		
 		// Print debug information.
 		switch ($display_type = config('debug.display_type'))
 		{
 			case 'panel':
+				$data = Rhymix\Framework\Debug::getDebugData();
+				$json_options = defined('JSON_PRETTY_PRINT') ? (JSON_PRETTY_PRINT | JSON_UNESCAPED_UNICODE) : 0;
+				$panel_html = '<div id="rhymix_debug_panel"></div>';
+				$panel_script = 'var rhymix_debug_content = ' . json_encode($data, $json_options) . ';';
+				$replace_html = '<div id="rhymix_debug_panel">' . "\n" . '<script>' . "\n" . $panel_script . "\n" . '</script>' . "\n" . '</div>';
+				$output = str_replace($panel_html, $replace_html, $output);
 				break;
 				
 			case 'comment':
@@ -195,6 +191,7 @@ class DisplayHandler extends Handler
 					return;
 				}
 				ob_start();
+				$data = Rhymix\Framework\Debug::getDebugData();
 				include RX_BASEDIR . 'common/tpl/debug_comment.html';
 				$content = ob_get_clean();
 				if ($display_type === 'file')

classes/display/HTMLDisplayHandler.php

@@ -86,10 +86,7 @@ class HTMLDisplayHandler
 
 			if(Context::get('layout') != 'none')
 			{
-				if(__DEBUG__ == 3)
+				$start = microtime(true);
-				{
-					$start = microtime(true);
-				}
 
 				Context::set('content', $output, false);
 
@@ -142,10 +139,7 @@ class HTMLDisplayHandler
 				$pathInfo = pathinfo($layout_file);
 				$onlyLayoutFile = $pathInfo['filename'];
 
-				if(__DEBUG__ == 3)
+				$GLOBALS['__layout_compile_elapsed__'] = microtime(true) - $start;
-				{
-					$GLOBALS['__layout_compile_elapsed__'] = microtime(true) - $start;
-				}
 
 				if(stripos($_SERVER['HTTP_USER_AGENT'], 'MSIE') !== FALSE && (Context::get('_use_ssl') == 'optional' || Context::get('_use_ssl') == 'always'))
 				{
@@ -168,10 +162,7 @@ class HTMLDisplayHandler
 			return;
 		}
 
-		if(__DEBUG__ == 3)
+		$start = microtime(true);
-		{
-			$start = microtime(true);
-		}
 
 		// move <style ..></style> in body to the header
 		$output = preg_replace_callback('!<style(.*?)>(.*?)<\/style>!is', array($this, '_moveStyleToHeader'), $output);
@@ -218,10 +209,7 @@ class HTMLDisplayHandler
 			$output = preg_replace_callback('@<textarea[^>]*\sname="' . $keys . '".+</textarea>@isU', array(&$this, '_preserveTextAreaValue'), $output);
 		}
 
-		if(__DEBUG__ == 3)
+		$GLOBALS['__trans_content_elapsed__'] = microtime(true) - $start;
-		{
-			$GLOBALS['__trans_content_elapsed__'] = microtime(true) - $start;
-		}
 
 		// Remove unnecessary information
 		$output = preg_replace('/member\_\-([0-9]+)/s', 'member_0', $output);

classes/template/TemplateHandler.class.php

@@ -42,16 +42,13 @@ class TemplateHandler
 	{
 		static $oTemplate = NULL;
 
-		if(__DEBUG__ == 3)
+		if(!isset($GLOBALS['__TemplateHandlerCalled__']))
 		{
-			if(!isset($GLOBALS['__TemplateHandlerCalled__']))
+			$GLOBALS['__TemplateHandlerCalled__'] = 1;
-			{
+		}
-				$GLOBALS['__TemplateHandlerCalled__'] = 1;
+		else
-			}
+		{
-			else
+			$GLOBALS['__TemplateHandlerCalled__']++;
-			{
-				$GLOBALS['__TemplateHandlerCalled__']++;
-			}
 		}
 
 		if(!$oTemplate)
@@ -118,10 +115,7 @@ class TemplateHandler
 	public function compile($tpl_path, $tpl_filename, $tpl_file = '')
 	{
 		// store the starting time for debug information
-		if(__DEBUG__ == 3)
+		$start = microtime(true);
-		{
-			$start = microtime(true);
-		}
 
 		// initiation
 		$this->init($tpl_path, $tpl_filename, $tpl_file);
@@ -155,10 +149,7 @@ class TemplateHandler
 		}
 
 		// store the ending time for debug information
-		if(__DEBUG__ == 3)
+		$GLOBALS['__template_elapsed__'] += microtime(true) - $start;
-		{
-			$GLOBALS['__template_elapsed__'] += microtime(true) - $start;
-		}
 
 		return $output;
 	}

classes/xml/XmlParser.class.php

@@ -89,10 +89,7 @@ class XmlParser
 	function parse($input = '', $arg1 = NULL, $arg2 = NULL)
 	{
 		// Save the compile starting time for debugging
-		if(__DEBUG__ == 3)
+		$start = microtime(true);
-		{
-			$start = microtime(true);
-		}
 
 		$this->lang = Context::getLangType();
 
@@ -141,10 +138,7 @@ class XmlParser
 
 		$output = array_shift($this->output);
 		// Save compile starting time for debugging
-		if(__DEBUG__ == 3)
+		$GLOBALS['__xmlparse_elapsed__'] += microtime(true) - $start;
-		{
-			$GLOBALS['__xmlparse_elapsed__'] += microtime(true) - $start;
-		}
 
 		return $output;
 	}

common/framework/debug.php

@@ -132,16 +132,6 @@ class Debug
 			return;
 		}
 		
-		// Find out the file where the error really occurred.
-		if (isset(self::$_aliases[$errfile]))
-		{
-			$errfile = self::$_aliases[$errfile];
-		}
-		if (!strncmp($errfile, \RX_BASEDIR, strlen(\RX_BASEDIR)))
-		{
-			$errfile = substr($errfile, strlen(\RX_BASEDIR));
-		}
-		
 		// Get the backtrace.
 		$backtrace_args = defined('\DEBUG_BACKTRACE_IGNORE_ARGS') ? \DEBUG_BACKTRACE_IGNORE_ARGS : 0;
 		$backtrace = debug_backtrace($backtrace_args);
@@ -223,16 +213,8 @@ class Debug
 	 */
 	public static function exceptionHandler(\Exception $e)
 	{
-		// Find out the file where the exception really occurred.
+		// Find out the file where the error really occurred.
-		$errfile = $e->getFile();
+		$errfile = self::translateFilename($e->getFile());
-		if (isset(self::$_aliases[$errfile]))
-		{
-			$errfile = self::$_aliases[$errfile];
-		}
-		if (!strncmp($errfile, \RX_BASEDIR, strlen(\RX_BASEDIR)))
-		{
-			$errfile = substr($errfile, strlen(\RX_BASEDIR));
-		}
 		
 		// If the exception was thrown in a Rhymix Framework class, find out where that class was called.
 		$backtrace = $e->getTrace();
@@ -247,16 +229,8 @@ class Debug
 			}
 			else
 			{
-				$caller_errfile = $trace['file'];
+				$caller_errfile = self::translateFilename($trace['file']);
 				$caller_errline = $trace['line'];
-				if (isset(self::$_aliases[$caller_errfile]))
-				{
-					$caller_errfile = self::$_aliases[$caller_errfile];
-				}
-				if (!strncmp($caller_errfile, \RX_BASEDIR, strlen(\RX_BASEDIR)))
-				{
-					$caller_errfile = substr($caller_errfile, strlen(\RX_BASEDIR));
-				}
 			}
 		}
 		
@@ -292,15 +266,8 @@ class Debug
 			return;
 		}
 		
-		// Find out the file where the fatal error really occurred.
+		// Find out the file where the error really occurred.
-		if (isset(self::$_aliases[$errinfo['file']]))
+		$errinfo['file'] = self::translateFilename($errinfo['file']);
-		{
-			$errinfo['file'] = self::$_aliases[$errinfo['file']];
-		}
-		if (!strncmp($errinfo['file'], \RX_BASEDIR, strlen(\RX_BASEDIR)))
-		{
-			$errinfo['file'] = substr($errinfo['file'], strlen(\RX_BASEDIR));
-		}
 		
 		// Add the entry to the error log.
 		$message = sprintf('%s in %s on line %d', $errinfo['message'], $errinfo['file'], intval($errinfo['line']));
@@ -311,6 +278,25 @@ class Debug
 		self::displayErrorScreen($log_entry);
 	}
 	
+	/**
+	 * Translate filenames.
+	 * 
+	 * @param string $filename
+	 * @return string
+	 */
+	public static function translateFilename($filename)
+	{
+		if (isset(self::$_aliases[$filename]))
+		{
+			$filename = self::$_aliases[$filename];
+		}
+		if (!strncmp($filename, \RX_BASEDIR, strlen(\RX_BASEDIR)))
+		{
+			$filename = substr($filename, strlen(\RX_BASEDIR));
+		}
+		return $filename;
+	}
+	
 	/**
 	 * Register all error handlers.
 	 * 
@@ -356,6 +342,63 @@ class Debug
 		exit;
 	}
 	
+	/**
+	 * Get all debug information as an object.
+	 * 
+	 * @return object
+	 */
+	public static function getDebugData()
+	{
+		// Collect debug information.
+		$data = (object)array(
+			'timestamp' => DateTime::formatTimestampForCurrentUser('Y-m-d H:i:s P', RX_TIME),
+			'url' => getCurrentPageUrl(),
+			'request' => (object)array(
+				'method' => $_SERVER['REQUEST_METHOD'] . ($_SERVER['REQUEST_METHOD'] !== \Context::getRequestMethod() ? (' (' . \Context::getRequestMethod() . ')') : ''),
+				'size' => intval($_SERVER['CONTENT_LENGTH']),
+			),
+			'response' => (object)array(
+				'method' => \Context::getResponseMethod(),
+				'size' => \DisplayHandler::$response_size,
+			),
+			'timing' => (object)array(
+				'total' => sprintf('%0.4f sec', microtime(true) - \RX_MICROTIME),
+				'template' => sprintf('%0.4f sec (count: %d)', $GLOBALS['__template_elapsed__'], $GLOBALS['__TemplateHandlerCalled__']),
+				'xmlparse' => sprintf('%0.4f sec', $GLOBALS['__xmlparse_elapsed__']),
+				'db_query' => sprintf('%0.4f sec (count: %d)', $GLOBALS['__db_elapsed_time__'], count(self::$_queries)),
+				'db_class' => sprintf('%0.4f sec', $GLOBALS['__dbclass_elapsed_time__'] - $GLOBALS['__db_elapsed_time__']),
+				'layout' => sprintf('%0.4f sec', $GLOBALS['__layout_compile_elapsed__']),
+				'widget' => sprintf('%0.4f sec', $GLOBALS['__widget_excute_elapsed__']),
+				'trans' => sprintf('%0.4f sec', $GLOBALS['__trans_content_elapsed__']),
+			),
+			'entries' => self::$_entries,
+			'errors' => config('debug.log_errors') ? self::$_errors : null,
+			'queries' => config('debug.log_queries') ? self::$_queries : null,
+		);
+		
+		// Clean up the backtrace.
+		foreach (array('entries', 'errors', 'queries') as $key)
+		{
+			foreach ($data->$key as &$entry)
+			{
+				if (isset($entry->file))
+				{
+					$entry->file = self::translateFilename($entry->file);
+				}
+				if (isset($entry->backtrace) && is_array($entry->backtrace))
+				{
+					foreach ($entry->backtrace as &$backtrace)
+					{
+						$backtrace['file'] = self::translateFilename($backtrace['file']);
+						unset($backtrace['object'], $backtrace['args']);
+					}
+				}
+			}
+		}
+		
+		return $data;
+	}
+	
 	/**
 	 * Convert a PHP error number to the corresponding error name.
 	 * 

common/tpl/common_layout.html

@@ -71,7 +71,8 @@ xe.msg_select_menu = "{$lang->msg_select_menu}";
 {$content}
 {Context::getHtmlFooter()}
 <!-- ETC -->
-<div class="wfsr"></div>
+<div id="rhymix_waiting" class="wfsr"></div>
+<div id="rhymix_debug_panel"></div>
 {@ $js_body_files = Context::getJsFile('body') }
 <block loop="$js_body_files => $key, $js_file">
 <block cond="$js_file['targetie']"><!--[if {$js_file['targetie']}]></block><script src="{$js_file['file']}"></script><block cond="$js_file['targetie']"><![endif]--></block>

common/tpl/debug_comment.html

@@ -1,25 +1,25 @@
 <?php if (!defined('RX_BASEDIR')) exit; ?>
 
-<?php echo $timestamp . "\n"; ?>
+<?php echo '[' . $data->timestamp . ']' . "\n"; ?>
 
 Request / Response
 ==================
-Request URL:         <?php echo getCurrentPageUrl() . "\n"; ?>
+Request URL:         <?php echo $data->url . "\n"; ?>
-Request Method:      <?php echo $_SERVER['REQUEST_METHOD'] . ($_SERVER['REQUEST_METHOD'] !== Context::getRequestMethod() ? (' (' . Context::getRequestMethod() . ')') : '') . "\n"; ?>
+Request Method:      <?php echo $data->request->method . "\n" ?>
-Request Body Size:   <?php echo intval($_SERVER['CONTENT_LENGTH']) . "\n"; ?>
+Request Body Size:   <?php echo $data->request->size . "\n" ?>
-Response Method:     <?php echo Context::getResponseMethod() . "\n"; ?>
+Response Method:     <?php echo $data->response->method . "\n"; ?>
-Response Body Size:  <?php echo $this->content_size . "\n"; ?>
+Response Body Size:  <?php echo $data->response->size . "\n"; ?>
 
 Page Generation Time
 ====================
-Total Time:              <?php echo sprintf('%0.4f sec', microtime(true) - RX_MICROTIME) . "\n"; ?>
+Total Time:              <?php echo $data->timing->total . "\n"; ?>
-Template Compile Time:   <?php echo sprintf('%0.4f sec (count: %d)', $GLOBALS['__template_elapsed__'], $GLOBALS['__TemplateHandlerCalled__']) . "\n"; ?>
+Template Compile Time:   <?php echo $data->timing->template . "\n"; ?>
-XML Parsing Time:        <?php echo sprintf('%0.4f sec', $GLOBALS['__xmlparse_elapsed__']) . "\n"; ?>
+XML Parsing Time:        <?php echo $data->timing->xmlparse . "\n"; ?>
-DB Query Time:           <?php echo sprintf('%0.4f sec (count: %d)', $GLOBALS['__db_elapsed_time__'], count($queries)) . "\n"; ?>
+DB Query Time:           <?php echo $data->timing->db_query . "\n"; ?>
-DB Processing Time:      <?php echo sprintf('%0.4f sec', $GLOBALS['__dbclass_elapsed_time__'] - $GLOBALS['__db_elapsed_time__']) . "\n"; ?>
+DB Processing Time:      <?php echo $data->timing->db_class . "\n"; ?>
-Layout Processing Time:  <?php echo sprintf('%0.4f sec', $GLOBALS['__layout_compile_elapsed__']) . "\n"; ?>
+Layout Processing Time:  <?php echo $data->timing->layout . "\n"; ?>
-Widget Processing Time:  <?php echo sprintf('%0.4f sec', $GLOBALS['__widget_excute_elapsed__']) . "\n"; ?>
+Widget Processing Time:  <?php echo $data->timing->widget . "\n"; ?>
-Content Transform Time:  <?php echo sprintf('%0.4f sec', $GLOBALS['__trans_content_elapsed__']) . "\n"; ?>
+Content Transform Time:  <?php echo $data->timing->trans . "\n"; ?>
 
 Resource Usage
 ==============
@@ -30,11 +30,11 @@ Debug Entries
 =============
 <?php
 	$entry_count = 0;
-	if (!count($entries))
+	if (!count($data->entries))
 	{
 		echo 'None' . "\n";
 	}
-	foreach ($entries as $entry)
+	foreach ($data->entries as $entry)
 	{
 		if (is_scalar($entry->message))
 		{
@@ -47,10 +47,6 @@ Debug Entries
 		echo sprintf('%02d. %s', ++$entry_count, $entry->message) . "\n";
 		foreach ($entry->backtrace as $key => $backtrace)
 		{
-			if (!strncmp($backtrace['file'], RX_BASEDIR, $basedir_len))
-			{
-				$backtrace['file'] = substr($backtrace['file'], $basedir_len);
-			}
 			echo sprintf('    - %s line %d', $backtrace['file'], $backtrace['line']) . "\n";
 		}
 	}
@@ -58,24 +54,20 @@ Debug Entries
 
 PHP Errors and Warnings
 =======================
-<?php if ($errors === null): ?>
+<?php if ($data->errors === null): ?>
 Error logging is disabled.
 <?php else: ?>
 <?php
 	$error_count = 0;
-	if (!count($errors))
+	if (!count($data->errors))
 	{
 		echo 'None' . "\n";
 	}
-	foreach ($errors as $error)
+	foreach ($data->errors as $error)
 	{
 		echo sprintf('%02d. %s: %s', ++$error_count, $error->type, $error->message) . "\n";
 		foreach ($error->backtrace as $key => $backtrace)
 		{
-			if (!strncmp($backtrace['file'], RX_BASEDIR, $basedir_len))
-			{
-				$backtrace['file'] = substr($backtrace['file'], $basedir_len);
-			}
 			echo sprintf('    - %s line %d', $backtrace['file'], $backtrace['line']) . "\n";
 		}
 	}
@@ -84,21 +76,17 @@ Error logging is disabled.
 
 Database Queries
 ================
-<?php if ($queries === null): ?>
+<?php if ($data->queries === null): ?>
 Query logging is disabled.
 <?php else: ?>
 <?php
 	$query_count = 0;
-	if (!count($queries))
+	if (!count($data->queries))
 	{
 		echo 'None'. "\n";
 	}
-	foreach ($queries as $query)
+	foreach ($data->queries as $query)
 	{
-		if (!strncmp($query->file, RX_BASEDIR, $basedir_len))
-		{
-			$query->file = substr($query->file, $basedir_len);
-		}
 		$query_caller = sprintf('%s line %d (%s)', $query->file, $query->line, $query->method);
 		$query_result = ($query->message === 'success') ? 'success' : sprintf('error %d %s', $query->error_code, $query->message);
 		echo sprintf('%02d. %s', ++$query_count, $query->query_string) . "\n";

common/tpl/mobile_layout.html

@@ -60,7 +60,7 @@ var default_url = "{Context::getDefaultUrl()}";
 {Context::getBodyHeader()}
 {$content}
 {Context::getHtmlFooter()}
-
+<div id="rhymix_debug_panel"></div>
 <!--// ETC -->
 {@ $js_body_files = Context::getJsFile('body') }
 <!--@foreach($js_body_files as $key => $js_file)-->

modules/widget/widget.controller.php

@@ -442,8 +442,8 @@ class widgetController extends widget
 	function execute($widget, $args, $javascript_mode = false, $escaped = true)
 	{
 		// Save for debug run-time widget
-		if(__DEBUG__==3) $start = microtime(true);
+		$start = microtime(true);
-		$before = microtime(true);
+		
 		// urldecode the value of args haejum
 		$object_vars = get_object_vars($args);
 		if(count($object_vars))
@@ -640,13 +640,10 @@ class widgetController extends widget
 		if($args->widgetstyle) $widget_content_body = $this->compileWidgetStyle($args->widgetstyle,$widget, $widget_content_body, $args, $javascript_mode);
 
 		$output = $widget_content_header . $widget_content_body . $widget_content_footer;
+
 		// Debug widget creation time information added to the results
-		if(__DEBUG__==3) $GLOBALS['__widget_excute_elapsed__'] += microtime(true) - $start;
+		$elapsed_time = microtime(true) - $start;
-
+		$GLOBALS['__widget_excute_elapsed__'] += $elapsed_time;
-		$after = microtime(true);
-
-		$elapsed_time = $after - $before;
-
 		$slowlog = new stdClass;
 		$slowlog->caller = "widget.execute";
 		$slowlog->called = $widget;