fanbinit/rhymix
1
0
Fork 0
mirror of https://github.com/Lastorder-DC/rhymix.git synced 2026-01-04 01:01:41 +09:00
Code Issues Projects Releases Packages Wiki Activity

Migrate addon, trigger, and widget logging functions to Debug class

Browse source
This commit is contained in:
Kijin Sung 2016-02-16 11:01:45 +09:00
parent 0947bafa66
commit 516479cf20
7 changed files with 188 additions and 147 deletions
Download patch file Download diff file Expand all files Collapse all files

7
classes/db/DB.class.php
View file

@ -396,13 +396,6 @@ class DB
}
$this->setQueryLog($log);
$log_args = new stdClass;
$log_args->query = $this->query;
$log_args->query_id = $this->query_id;
$log_args->caller = $log['called_method'] . '() in ' . $log['called_file'];
$log_args->connection = $log['connection'];
writeSlowlog('query', $elapsed_time, $log_args);
}
/**

7
classes/display/DisplayHandler.class.php
View file

@ -122,12 +122,13 @@ class DisplayHandler extends Handler
self::$response_size = $this->content_size = strlen($output);
ModuleHandler::triggerCall('display', 'after', $output);
// debugOutput output
// Output the page content and debug data.
$debug = $this->getDebugInfo($output);
print $output;
print $debug;
flushSlowlog();
// Flush the slow query/trigger/widget log.
ModuleHandler::triggerCall('common.flushDebugInfo', 'after', new stdClass);
}
/**

51
classes/module/ModuleHandler.class.php
View file

@ -1200,17 +1200,20 @@ class ModuleHandler extends Handler
}
$before_each_trigger_time = microtime(true);
$output = $oModule->{$called_method}($obj);
$after_each_trigger_time = microtime(true);
$elapsed_time_trigger = $after_each_trigger_time - $before_each_trigger_time;
$slowlog = new stdClass;
$slowlog->caller = $trigger_name . '.' . $called_position;
$slowlog->called = $module . '.' . $called_method;
$slowlog->called_extension = $module;
if($trigger_name != 'XE.writeSlowlog') writeSlowlog('trigger', $elapsed_time_trigger, $slowlog);
if ($trigger_name !== 'common.flushDebugInfo')
{
$trigger_target = $module . ($type === 'class' ? '' : $type) . '.' . $called_method;
Rhymix\Framework\Debug::addTrigger(array(
'name' => $trigger_name . '.' . $called_position,
'target' => $trigger_target,
'target_plugin' => $module,
'elapsed_time' => $after_each_trigger_time - $before_each_trigger_time,
));
}
if(is_object($output) && method_exists($output, 'toBool') && !$output->toBool())
{
@ -1222,7 +1225,39 @@ class ModuleHandler extends Handler
$trigger_functions = $oModuleModel->getTriggerFunctions($trigger_name, $called_position);
foreach($trigger_functions as $item)
{
$before_each_trigger_time = microtime(true);
$item($obj);
$after_each_trigger_time = microtime(true);
if ($trigger_name !== 'common.writeSlowlog')
{
if (is_string($item))
{
$trigger_target = $item;
}
elseif (is_array($item) && count($item))
{
if (is_object($item[0]))
{
$trigger_target = get_class($item[0]) . '.' . strval($item[1]);
}
else
{
$trigger_target = implode('.', $item);
}
}
else
{
$trigger_target = 'closure';
}
Rhymix\Framework\Debug::addTrigger(array(
'name' => $trigger_name . '.' . $called_position,
'target' => $trigger_target,
'target_plugin' => null,
'elapsed_time' => $after_each_trigger_time - $before_each_trigger_time,
));
}
if(is_object($output) && method_exists($output, 'toBool') && !$output->toBool())
{

84
common/framework/debug.php
View file

@ -15,7 +15,9 @@ class Debug
protected static $_errors = array();
protected static $_queries = array();
protected static $_slow_queries = array();
protected static $_triggers = array();
protected static $_slow_triggers = array();
protected static $_widgets = array();
protected static $_slow_widgets = array();
/**
@ -63,6 +65,16 @@ class Debug
return self::$_slow_queries;
}
/**
* Get all triggers.
*
* @return array
*/
public static function getTriggers()
{
return self::$_triggers;
}
/**
* Get all slow triggers.
*
@ -73,6 +85,16 @@ class Debug
return self::$_slow_triggers;
}
/**
* Get all widgets.
*
* @return array
*/
public static function getWidgets()
{
return self::$_widgets;
}
/**
* Get all slow widgets.
*
@ -80,7 +102,7 @@ class Debug
*/
public static function getSlowWidgets()
{
return self::$_slow_triggers;
return self::$_slow_widgets;
}
/**
@ -188,7 +210,7 @@ class Debug
*/
public static function addQuery($query)
{
self::$_queries[] = (object)array(
$query_object = (object)array(
'type' => 'Query',
'time' => microtime(true),
'message' => $query['result'] === 'success' ? 'success' : $query['errstr'],
@ -202,36 +224,64 @@ class Debug
'method' => $query['called_method'],
'backtrace' => $query['backtrace'],
);
self::$_queries[] = $query_object;
if ($query_object->query_time && $query_object->query_time >= config('debug.log_slow_queries'))
{
self::$_slow_queries[] = $query_object;
}
}
/**
* Add a slow query to the log.
* Add a trigger to the log.
*
* @return bool
*/
public static function addSlowQuery()
public static function addTrigger($trigger)
{
$trigger_object = (object)array(
'type' => 'Trigger',
'time' => microtime(true),
'message' => null,
'file' => null,
'line' => null,
'backtrace' => array(),
'trigger_name' => $trigger['name'],
'trigger_target' => $trigger['target'],
'trigger_plugin' => $trigger['target_plugin'],
'trigger_time' => $trigger['elapsed_time'],
);
self::$_triggers[] = $trigger_object;
if ($trigger_object->trigger_time && $trigger_object->trigger_time >= config('debug.log_slow_triggers'))
{
self::$_slow_triggers[] = $trigger_object;
}
}
/**
* Add a slow trigger to the log.
* Add a widget to the log.
*
* @return bool
*/
public static function addSlowTrigger()
{
}
/**
* Add a slow widget to the log.
*
* @return bool
*/
public static function addSlowWidget()
public static function addWidget($widget)
{
$widget_object = (object)array(
'type' => 'Widget',
'time' => microtime(true),
'message' => null,
'file' => null,
'line' => null,
'backtrace' => array(),
'widget_name' => $widget['name'],
'widget_time' => $widget['elapsed_time'],
);
self::$_widgets[] = $widget_object;
if ($widget_object->widget_time && $widget_object->widget_time >= config('debug.log_slow_widgets'))
{
self::$_slow_widgets[] = $widget_object;
}
}
/**
@ -240,7 +290,7 @@ class Debug
* @param Exception $e
* @return void
*/
public static function exceptionHandler(\Exception $e)
public static function exceptionHandler($e)
{
// Find out the file where the error really occurred.
$errfile = self::translateFilename($e->getFile());

67
common/legacy.php
View file

@ -712,67 +712,7 @@ function debugPrint($entry = null)
*/
function writeSlowlog($type, $elapsed_time, $obj)
{
static $config = null;
if (!$config)
{
$config = config('debug');
}
if (!Rhymix\Framework\Debug::isEnabledForCurrentUser())
{
return;
}
if (!$config['log_slow_queries'] && !$config['log_slow_triggers'] && !$config['log_slow_widgets'])
{
return;
}
static $log_filename = array(
'query' => 'files/_slowlog_query.php',
'trigger' => 'files/_slowlog_trigger.php',
'widget' => 'files/_slowlog_widget.php'
);
$log_file = RX_BASEDIR . $log_filename[$type];
$write_file = true;
$buff = array();
$buff[] = '<?php exit(); ?>';
$buff[] = date('c');
if ($type == 'query' && $config['log_slow_queries'] > 0 && $elapsed_time > $config['log_slow_queries'])
{
$buff[] = $obj->query;
$buff[] = "\tQuery ID : " . $obj->query_id;
$buff[] = "\tCaller : " . $obj->caller;
$buff[] = "\tConnection : " . $obj->connection;
}
elseif ($type == 'trigger' && $config['log_slow_triggers'] > 0 && $elapsed_time > $config['log_slow_triggers'])
{
$buff[] = "\tCaller : " . $obj->caller;
$buff[] = "\tCalled : " . $obj->called;
}
elseif ($type == 'widget' && $config['log_slow_widgets'] > 0 && $elapsed_time > $config['log_slow_widgets'])
{
$buff[] = "\tWidget : " . $obj->called;
}
else
{
$write_file = false;
}
if($write_file)
{
$buff[] = sprintf("\t%0.6f sec", $elapsed_time);
$buff[] = PHP_EOL . PHP_EOL;
file_put_contents($log_file, implode(PHP_EOL, $buff), FILE_APPEND);
}
if($type != 'query')
{
$trigger_args = $obj;
$trigger_args->_log_type = $type;
$trigger_args->_elapsed_time = $elapsed_time;
ModuleHandler::triggerCall('XE.writeSlowlog', 'after', $trigger_args);
}
// no-op
}
/**
@ -780,10 +720,7 @@ function writeSlowlog($type, $elapsed_time, $obj)
*/
function flushSlowlog()
{
$trigger_args = new stdClass();
$trigger_args->_log_type = 'flush';
$trigger_args->_elapsed_time = 0;
ModuleHandler::triggerCall('XE.writeSlowlog', 'after', $trigger_args);
// no-op
}
/**

110
modules/addon/addon.controller.php
View file

@ -34,8 +34,8 @@ class addonController extends addon
$site_module_info = Context::get('site_module_info');
$site_srl = $site_module_info->site_srl;
$addon_path = _XE_PATH_ . 'files/cache/addons/';
$addon_file = $addon_path . $site_srl . $type . '.acivated_addons.cache.php';
$addon_path = RX_BASEDIR . 'files/cache/addons/';
$addon_file = $addon_path . 'addons.' . intval($site_srl) . '.' . $type . '.php';
if($this->addon_file_called)
{
@ -46,7 +46,7 @@ class addonController extends addon
FileHandler::makeDir($addon_path);
if(!file_exists($addon_file))
if(!file_exists($addon_file) || filemtime($addon_file) < filemtime(__FILE__))
{
$this->makeCacheFile($site_srl, $type);
}
@ -88,57 +88,78 @@ class addonController extends addon
|| ($type == "pc" && $val->is_used != 'Y')
|| ($type == "mobile" && $val->is_used_m != 'Y')
|| ($gtype == 'global' && $val->is_fixed != 'Y')
|| !is_dir(_XE_PATH_ . 'addons/' . $addon))
|| !is_dir(RX_BASEDIR . 'addons/' . $addon))
{
continue;
}
$extra_vars = unserialize($val->extra_vars);
if(!$extra_vars)
{
$extra_vars = new stdClass;
}
$mid_list = $extra_vars->mid_list;
if(!is_array($mid_list) || count($mid_list) < 1)
if(!is_array($mid_list))
{
$mid_list = NULL;
$mid_list = array();
}
// Initialize
$buff[] = '$before_time = microtime(true);';
$buff[] = '$rm = \'' . $extra_vars->xe_run_method . "';";
$buff[] = '$ml = array(';
if($mid_list)
// Run method and mid list
$run_method = $extra_vars->xe_run_method ?: 'run_selected';
$buff[] = '$rm = \'' . $run_method . "';";
$buff[] = '$ml = ' . var_export(array_fill_keys($mid_list, true), true) . ';';
// Addon filename
$buff[] = sprintf('$addon_file = RX_BASEDIR . \'addons/%s/%s.addon.php\';', $addon, $addon);
// Addon configuration
$buff[] = '$addon_info = unserialize(' . var_export(serialize($extra_vars), true) . ');';
// Decide whether to run in this mid
if ($run_method === 'no_run_selected')
{
foreach($mid_list as $mid)
{
$buff[] = "'$mid' => 1,";
}
$buff[] = '$run = !isset($ml[$_m]);';
}
$buff[] = ');';
$buff[] = sprintf('$addon_file = \'./addons/%s/%s.addon.php\';', $addon, $addon);
if($val->extra_vars)
elseif (!count($mid_list))
{
unset($extra_vars);
$extra_vars = base64_encode($val->extra_vars);
$buff[] = '$run = true;';
}
$addon_include = sprintf('unset($addon_info); $addon_info = unserialize(base64_decode(\'%s\')); @include($addon_file);', $extra_vars);
$buff[] = 'if(file_exists($addon_file)){';
$buff[] = 'if($rm === \'no_run_selected\'){';
$buff[] = 'if(!isset($ml[$_m])){';
$buff[] = $addon_include;
$buff[] = '}}else{';
$buff[] = 'if(isset($ml[$_m]) || count($ml) === 0){';
$buff[] = $addon_include;
$buff[] = '}}}';
$buff[] = '$after_time = microtime(true);';
$buff[] = '$addon_time_log = new stdClass();';
$buff[] = '$addon_time_log->caller = $called_position;';
$buff[] = '$addon_time_log->called = "' . $addon . '";';
$buff[] = '$addon_time_log->called_extension = "' . $addon . '";';
$buff[] = 'writeSlowlog("addon",$after_time-$before_time,$addon_time_log);';
else
{
$buff[] = '$run = isset($ml[$_m]);';
}
// Write debug info
$buff[] = 'if ($run && file_exists($addon_file)):';
$buff[] = ' include($addon_file);';
$buff[] = ' $after_time = microtime(true);';
$buff[] = ' if (class_exists("Rhymix\\\\Framework\\\\Debug")):';
$buff[] = ' Rhymix\\Framework\\Debug::addTrigger(array(';
$buff[] = ' "name" => "addon." . $called_position,';
$buff[] = ' "target" => "' . $addon . '",';
$buff[] = ' "target_plugin" => "' . $addon . '",';
$buff[] = ' "elapsed_time" => $after_time - $before_time,';
$buff[] = ' ));';
$buff[] = ' endif;';
$buff[] = 'endif;';
$buff[] = '';
}
$addon_path = _XE_PATH_ . 'files/cache/addons/';
FileHandler::makeDir($addon_path);
$addon_file = $addon_path . ($gtype == 'site' ? $site_srl : '') . $type . '.acivated_addons.cache.php';
// Write file in new location
$addon_path = RX_BASEDIR . 'files/cache/addons/';
$addon_file = $addon_path . 'addons.' . ($gtype == 'site' ? intval($site_srl) : 'G') . '.' . $type . '.php';
FileHandler::writeFile($addon_file, join(PHP_EOL, $buff));
// Remove file from old location
$old_addon_file = $addon_path . ($gtype == 'site' ? $site_srl : '') . $type . '.acivated_addons.cache.php';
if (file_exists($old_addon_file))
{
FileHandler::removeFile($old_addon_file);
}
}
/**
@ -176,12 +197,17 @@ class addonController extends addon
*/
function removeAddonConfig($site_srl)
{
$addon_path = _XE_PATH_ . 'files/cache/addons/';
$addon_file = $addon_path . $site_srl . '.acivated_addons.cache.php';
$addon_path = RX_BASEDIR . 'files/cache/addons/';
$addon_file = $addon_path . 'addons.' . intval($site_srl) . '.' . $type . '.php';
if(file_exists($addon_file))
{
FileHandler::removeFile($addon_file);
}
$old_addon_file = $addon_path . ($gtype == 'site' ? $site_srl : '') . $type . '.acivated_addons.cache.php';
if (file_exists($old_addon_file))
{
FileHandler::removeFile($old_addon_file);
}
$args = new stdClass();
$args->site_srl = $site_srl;

9
modules/widget/widget.controller.php
View file

@ -644,11 +644,10 @@ class widgetController extends widget
// Debug widget creation time information added to the results
$elapsed_time = microtime(true) - $start;
$GLOBALS['__widget_excute_elapsed__'] += $elapsed_time;
$slowlog = new stdClass;
$slowlog->caller = "widget.execute";
$slowlog->called = $widget;
$slowlog->called_extension = $widget;
writeSlowlog('widget', $elapsed_time, $slowlog);
Rhymix\Framework\Debug::addWidget(array(
'name' => $widget,
'elapsed_time' => $elapsed_time,
));
// Return result
return $output;