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

Merge branch 'feature/slowlog' into develop

Browse source
This commit is contained in:
bnu 2014-09-15 15:30:48 +09:00
commit f4083d8092
3 changed files with 76 additions and 73 deletions
Download patch file Download diff file Expand all files Collapse all files

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

@ -447,7 +447,8 @@ class DB
$log['act'] = Context::get('act');
$log['time'] = date('Y-m-d H:i:s');
$bt = debug_backtrace();
$bt = version_compare(PHP_VERSION, '5.3.6', '>=') ? debug_backtrace(DEBUG_BACKTRACE_IGNORE_ARGS) : debug_backtrace();
foreach($bt as $no => $call)
{
if($call['function'] == 'executeQuery' || $call['function'] == 'executeQueryArray')
@ -455,6 +456,7 @@ class DB
$call_no = $no;
$call_no++;
$log['called_file'] = $bt[$call_no]['file'].':'.$bt[$call_no]['line'];
$log['called_file'] = str_replace(_XE_PATH_ , '', $log['called_file']);
$call_no++;
$log['called_method'] = $bt[$call_no]['class'].$bt[$call_no]['type'].$bt[$call_no]['function'];
break;
@ -487,20 +489,12 @@ class DB
$this->setQueryLog($log);
// if __LOG_SLOW_QUERY__ if defined, check elapsed time and leave query log
if(__LOG_SLOW_QUERY__ > 0 && $elapsed_time > __LOG_SLOW_QUERY__)
{
$buff = '';
$log_file = _XE_PATH_ . 'files/_db_slow_query.php';
if(!file_exists($log_file))
{
$buff = '<?php exit(); ?' . '>' . "\n";
}
$buff .= sprintf("%s\t%s\n\t%0.6f sec\tquery_id:%s\n\n", date("Y-m-d H:i"), $this->query, $elapsed_time, $this->query_id);
@file_put_contents($log_file, $buff, FILE_APPEND|LOCK_EX);
}
$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);
}
/**

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

@ -1152,7 +1152,7 @@ class ModuleHandler extends Handler
$before_trigger_time = NULL;
if(__LOG_SLOW_TRIGGER__> 0)
{
$before_trigger_time = microtime(true);
$before_trigger_time = microtime(true);
}
foreach($triggers as $item)
@ -1160,12 +1160,6 @@ class ModuleHandler extends Handler
$module = $item->module;
$type = $item->type;
$called_method = $item->called_method;
$before_each_trigger_time = NULL;
if(__LOG_SLOW_TRIGGER__> 0)
{
$before_each_trigger_time = microtime(true);
}
// todo why don't we call a normal class object ?
$oModule = getModule($module, $type);
@ -1174,63 +1168,24 @@ class ModuleHandler extends Handler
continue;
}
$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(is_object($output) && method_exists($output, 'toBool') && !$output->toBool())
{
return $output;
}
unset($oModule);
//store after trigger call time
$after_each_trigger_time = NULL;
//init value to 0
$elapsed_time_trigger = 0;
if(__LOG_SLOW_TRIGGER__> 0)
{
$after_each_trigger_time = microtime(true);
$elapsed_time_trigger = ($after_each_trigger_time - $before_each_trigger_time) * 1000;
}
// if __LOG_SLOW_TRIGGER__ is defined, check elapsed time and leave trigger time log
if(__LOG_SLOW_TRIGGER__> 0 && $elapsed_time_trigger > __LOG_SLOW_TRIGGER__)
{
$buff = '';
$log_file = _XE_PATH_ . 'files/_db_slow_trigger.php';
if(!file_exists($log_file))
{
$buff = '<?php exit(); ?' . '>' . "\n";
}
$buff .= sprintf("%s\t%s.%s.%s.%s(%s)\n\t%0.6f msec\n\n", date("Y-m-d H:i"), $item->trigger_name,$item->module,$item->called_method,$item->called_position,$item->type, $elapsed_time_trigger);
@file_put_contents($log_file, $buff, FILE_APPEND|LOCK_EX);
}
}
//store after trigger call time
$after_trigger_time = NULL;
//init value to 0
$elapsed_time = 0;
if(__LOG_SLOW_TRIGGER__> 0)
{
$after_trigger_time = microtime(true);
$elapsed_time = ($after_trigger_time - $before_trigger_time) * 1000;
}
// if __LOG_SLOW_TRIGGER__ is defined, check elapsed time and leave trigger time log
if(__LOG_SLOW_TRIGGER__> 0 && $elapsed_time > __LOG_SLOW_TRIGGER__)
{
$buff = '';
$log_file = _XE_PATH_ . 'files/_slow_trigger.php';
if(!file_exists($log_file))
{
$buff = '<?php exit(); ?' . '>' . "\n";
}
$buff .= sprintf("%s\t%s.totaltime\n\t%0.6f msec\n\n", date("Y-m-d H:i"), $trigger_name,$elapsed_time);
@file_put_contents($log_file, $buff, FILE_APPEND|LOCK_EX);
}
return new Object();

54
config/func.inc.php
View file

@ -838,6 +838,60 @@ function debugPrint($debug_output = NULL, $display_option = TRUE, $file = '_debu
}
}
/**
* @param string $type query, trigger
* @param float $elapsed_time
* @param object $obj
*/
function writeSlowlog($type, $elapsed_time, $obj)
{
static $log_filename = array(
'query' => 'files/_slowlog_query.php',
'trigger' => 'files/_slowlog_trigger.php',
'addon' => 'files/_slowlog_addon.php'
);
$write_file = true;
$log_file = _XE_PATH_ . $log_filename[$type];
$buff = array();
$buff[] = '<?php exit(); ?>';
$buff[] = date('c');
if($type == 'trigger' && __LOG_SLOW_TRIGGER__ > 0 && $elapsed_time > __LOG_SLOW_TRIGGER__)
{
$buff[] = "\tCaller : " . $obj->caller;
$buff[] = "\tCalled : " . $obj->called;
}
else if($type == 'query' && __LOG_SLOW_QUERY__ > 0 && $elapsed_time > __LOG_SLOW_QUERY__)
{
$buff[] = $obj->query;
$buff[] = "\tQuery ID : " . $obj->query_id;
$buff[] = "\tCaller : " . $obj->caller;
$buff[] = "\tConnection : " . $obj->connection;
}
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);
}
$trigger_args = $obj;
$trigger_args->_log_type = $type;
$trigger_args->_elapsed_time = $elapsed_time;
if($type != 'query')
{
ModuleHandler::triggerCall('XE.writeSlowlog', 'after', $trigger_args);
}
}
/**
* microtime() return
*