#278 debug 환경 개선.

- query 목록에 query id와 파일 및 메소드명 표시
- 실행 중 중단 시 중단 시점의 파일과 메소드명 표시
This commit is contained in:
bnu 2014-01-10 03:36:57 +09:00
parent 7845927721
commit 25ca3e1d14
6 changed files with 84 additions and 44 deletions

View file

@ -436,19 +436,24 @@ class DB
$elapsed_time = $this->act_finish - $this->act_start;
$this->elapsed_time = $elapsed_time;
$GLOBALS['__db_elapsed_time__'] += $elapsed_time;
$bt = debug_backtrace(DEBUG_BACKTRACE_IGNORE_ARGS);
$bt = $bt[6];
$site_module_info = Context::get('site_module_info');
$log = array();
$log['query'] = $this->query;
$log['elapsed_time'] = $elapsed_time;
$log['connection'] = $this->connection;
$log['query_id'] = $this->query_id;
$log['module'] = $site_module_info->module;
$log['act'] = Context::get('act');
$log['time'] = date('Y-m-d H:i:s');
$log['called_file'] = $bt['file'].':'.$bt['line'];
$log['called_method'] = $bt['class'].$bt['type'].$bt['function'];
// leave error log if an error occured (if __DEBUG_DB_OUTPUT__ is defined)
if($this->isError())
{
$site_module_info = Context::get('site_module_info');
$log['module'] = $site_module_info->module;
$log['act'] = Context::get('act');
$log['time'] = date('Y-m-d H:i:s');
$log['result'] = 'Failed';
$log['errno'] = $this->errno;
$log['errstr'] = $this->errstr;

View file

@ -197,10 +197,10 @@ class DisplayHandler extends Handler
// display DB query history
if((__DEBUG__ & 4) && $GLOBALS['__db_queries__'])
{
$queries_output = array(array('Result', 'Query ID', 'Query', 'Elapsed time'));
$queries_output = array(array('Result/'.PHP_EOL.'Elapsed time', 'Query ID', 'Query'));
foreach($GLOBALS['__db_queries__'] as $query)
{
$queries_output[] = array($query['result'], $query['query_id'], $query['query'], sprintf('%0.5f', $query['elapsed_time']));
$queries_output[] = array($query['result'] . PHP_EOL . sprintf('%0.5f', $query['elapsed_time']), str_replace(_XE_PATH_, '', $query['called_file']) . PHP_EOL . $query['called_method'] . '()' . PHP_EOL . $query['query_id'], $query['query']);
}
$firephp->fb(
array(
@ -215,7 +215,7 @@ class DisplayHandler extends Handler
else
{
$buff = "";
$buff = array();
// display total execution time and Request/Response info
if(__DEBUG__ & 2)
{
@ -225,29 +225,29 @@ class DisplayHandler extends Handler
}
// Request/Response information
$buff .= "\n- Request/ Response info\n";
$buff .= sprintf("\tRequest URI \t\t\t: %s:%s%s%s%s\n", $_SERVER['SERVER_NAME'], $_SERVER['SERVER_PORT'], $_SERVER['PHP_SELF'], $_SERVER['QUERY_STRING'] ? '?' : '', $_SERVER['QUERY_STRING']);
$buff .= sprintf("\tRequest method \t\t\t: %s\n", $_SERVER['REQUEST_METHOD']);
$buff .= sprintf("\tResponse method \t\t: %s\n", Context::getResponseMethod());
$buff .= sprintf("\tResponse contents size\t\t: %d byte\n", $this->content_size);
$buff[] = "\n- Request/ Response info";
$buff[] = sprintf("\tRequest URI \t\t\t: %s:%s%s%s%s", $_SERVER['SERVER_NAME'], $_SERVER['SERVER_PORT'], $_SERVER['PHP_SELF'], $_SERVER['QUERY_STRING'] ? '?' : '', $_SERVER['QUERY_STRING']);
$buff[] = sprintf("\tRequest method \t\t\t: %s", $_SERVER['REQUEST_METHOD']);
$buff[] = sprintf("\tResponse method \t\t: %s", Context::getResponseMethod());
$buff[] = sprintf("\tResponse contents size\t: %d byte", $this->content_size);
// total execution time
$buff .= sprintf("\n- Total elapsed time : %0.5f sec\n", $end - __StartTime__);
$buff[] = sprintf("\n- Total elapsed time : %0.5f sec", $end - __StartTime__);
$buff .= sprintf("\tclass file load elapsed time \t: %0.5f sec\n", $GLOBALS['__elapsed_class_load__']);
$buff .= sprintf("\tTemplate compile elapsed time\t: %0.5f sec (%d called)\n", $GLOBALS['__template_elapsed__'], $GLOBALS['__TemplateHandlerCalled__']);
$buff .= sprintf("\tXmlParse compile elapsed time\t: %0.5f sec\n", $GLOBALS['__xmlparse_elapsed__']);
$buff .= sprintf("\tPHP elapsed time \t\t: %0.5f sec\n", $end - __StartTime__ - $GLOBALS['__template_elapsed__'] - $GLOBALS['__xmlparse_elapsed__'] - $GLOBALS['__db_elapsed_time__'] - $GLOBALS['__elapsed_class_load__']);
$buff .= sprintf("\tDB class elapsed time \t\t: %0.5f sec\n", $GLOBALS['__dbclass_elapsed_time__'] - $GLOBALS['__db_elapsed_time__']);
$buff[] = sprintf("\tclass file load elapsed time \t: %0.5f sec", $GLOBALS['__elapsed_class_load__']);
$buff[] = sprintf("\tTemplate compile elapsed time\t: %0.5f sec (%d called)", $GLOBALS['__template_elapsed__'], $GLOBALS['__TemplateHandlerCalled__']);
$buff[] = sprintf("\tXmlParse compile elapsed time\t: %0.5f sec", $GLOBALS['__xmlparse_elapsed__']);
$buff[] = sprintf("\tPHP elapsed time \t\t\t\t: %0.5f sec", $end - __StartTime__ - $GLOBALS['__template_elapsed__'] - $GLOBALS['__xmlparse_elapsed__'] - $GLOBALS['__db_elapsed_time__'] - $GLOBALS['__elapsed_class_load__']);
$buff[] = sprintf("\tDB class elapsed time \t\t\t: %0.5f sec", $GLOBALS['__dbclass_elapsed_time__'] - $GLOBALS['__db_elapsed_time__']);
// widget execution time
$buff .= sprintf("\n\tWidgets elapsed time \t\t: %0.5f sec", $GLOBALS['__widget_excute_elapsed__']);
$buff[] = sprintf("\tWidgets elapsed time \t\t\t: %0.5f sec", $GLOBALS['__widget_excute_elapsed__']);
// layout execution time
$buff .= sprintf("\n\tLayout compile elapsed time \t: %0.5f sec", $GLOBALS['__layout_compile_elapsed__']);
$buff[] = sprintf("\tLayout compile elapsed time \t: %0.5f sec", $GLOBALS['__layout_compile_elapsed__']);
// Widgets, the editor component replacement time
$buff .= sprintf("\n\tTrans Content \t\t\t: %0.5f sec\n", $GLOBALS['__trans_content_elapsed__']);
$buff[] = sprintf("\tTrans Content \t\t\t\t\t: %0.5f sec", $GLOBALS['__trans_content_elapsed__']);
}
// DB Logging
if(__DEBUG__ & 4)
@ -259,21 +259,23 @@ class DisplayHandler extends Handler
if($GLOBALS['__db_queries__'])
{
$buff .= sprintf("\n- DB Queries : %d Queries. %0.5f sec\n", count($GLOBALS['__db_queries__']), $GLOBALS['__db_elapsed_time__']);
$buff[] = sprintf("\n- DB Queries : %d Queries. %0.5f sec", count($GLOBALS['__db_queries__']), $GLOBALS['__db_elapsed_time__']);
$num = 0;
foreach($GLOBALS['__db_queries__'] as $query)
{
$buff .= sprintf("\t%02d. %s\n\t\t%0.6f sec. ", ++$num, $query['query'], $query['elapsed_time']);
if($query['result'] == 'Success')
{
$buff .= "Query Success\n";
$query_result = "Query Success";
}
else
{
$buff .= sprintf("Query $s : %d\n\t\t\t %s\n", $query['result'], $query['errno'], $query['errstr']);
$query_result = sprintf("Query $s : %d\n\t\t\t %s", $query['result'], $query['errno'], $query['errstr']);
}
$buff .= sprintf("\t\tConnection: %s\n", $query['connection']);
$buff[] = sprintf("\t%02d. %s\n\t\t%0.6f sec. %s.", ++$num, $query['query'], $query['elapsed_time'], $query_result);
$buff[] = sprintf("\t\tConnection: %s.", $query['connection']);
$buff[] = sprintf("\t\tQuery ID: %s", $query['query_id']);
$buff[] = sprintf("\t\tCalled: %s. %s()", str_replace(_XE_PATH_, '', $query['called_file']), $query['called_method']);
}
}
}
@ -281,23 +283,25 @@ class DisplayHandler extends Handler
// Output in HTML comments
if($buff && __DEBUG_OUTPUT__ == 1 && Context::getResponseMethod() == 'HTML')
{
$buff = sprintf("[%s %s:%d]\n%s\n", date('Y-m-d H:i:s'), $file_name, $line_num, print_r($buff, true));
$buff = implode("\r\n", $buff);
$buff = sprintf("[%s %s:%d]\r\n%s", date('Y-m-d H:i:s'), $file_name, $line_num, print_r($buff, true));
if(__DEBUG_PROTECT__ == 1 && __DEBUG_PROTECT_IP__ != $_SERVER['REMOTE_ADDR'])
{
$buff = 'The IP address is not allowed. Change the value of __DEBUG_PROTECT_IP__ into your IP address in config/config.user.inc.php or config/config.inc.php';
}
return "<!--\r\n" . $buff . "\r\n-->";
return "<!--\r\n" . implode("\r\n", $buff) . "\r\n-->";
}
// Output to a file
if($buff && __DEBUG_OUTPUT__ == 0)
{
$debug_file = _XE_PATH_ . 'files/_debug_message.php';
$buff = sprintf("[%s %s:%d]\n%s\n", date('Y-m-d H:i:s'), $file_name, $line_num, print_r($buff, true));
$buff = implode(PHP_EOL, $buff);
$buff = sprintf("[%s]\n%s", date('Y-m-d H:i:s'), print_r($buff, true));
$buff = str_repeat('=', 40) . "\n" . $buff . str_repeat('-', 40);
$buff = str_repeat('=', 80) . "\n" . $buff . "\n" . str_repeat('-', 80);
$buff = "\n<?php\n/*" . $buff . "*/\n?>\n";
if (!@file_put_contents($debug_file, $buff, FILE_APPEND|LOCK_EX))

View file

@ -674,6 +674,7 @@ class ModuleHandler extends Handler
$message = $oModule->getMessage();
$messageType = $oModule->getMessageType();
$redirectUrl = $oModule->getRedirectUrl();
if($messageType == 'error') debugPrint($message, 'ERROR');
if(!$procResult)
{

View file

@ -384,6 +384,7 @@ class ModuleObject extends Object
// pass if stop_proc is true
if($this->stop_proc)
{
debugPrint($this->message, 'ERROR');
return false;
}

View file

@ -749,19 +749,24 @@ function getEncodeEmailAddress($email)
*/
function debugPrint($debug_output = NULL, $display_option = TRUE, $file = '_debug_message.php')
{
static $debug_file;
static $debug_file_exist;
if(!(__DEBUG__ & 1))
{
return;
}
static $firephp;
$bt = debug_backtrace();
$bt = debug_backtrace(DEBUG_BACKTRACE_IGNORE_ARGS);
if(is_array($bt))
{
$first = array_shift($bt);
$bt_debug_print = array_shift($bt);
$bt_called_function = array_shift($bt);
}
$file_name = array_pop(explode(DIRECTORY_SEPARATOR, $first['file']));
$line_num = $first['line'];
$file_name = str_replace(_XE_PATH_, '', $bt_debug_print['file']);
$line_num = $bt_debug_print['line'];
$function = $bt_called_function['class'] . $bt_called_function['type'] . $bt_called_function['function'];
if(__DEBUG_OUTPUT__ == 2 && version_compare(PHP_VERSION, '6.0.0') === -1)
{
@ -769,14 +774,19 @@ function debugPrint($debug_output = NULL, $display_option = TRUE, $file = '_debu
{
$firephp = FirePHP::getInstance(TRUE);
}
$type = FirePHP::INFO;
$label = sprintf('[%s:%d] (m:%s)', $file_name, $line_num, FileHandler::filesize(memory_get_usage()));
$label = sprintf('[%s:%d] %s() (m:%s)', $file_name, $line_num, $function, FileHandler::filesize(memory_get_usage()));
// Check a FirePHP option
if($display_option === 'TABLE')
{
$label = $display_option;
}
if($display_option === 'ERROR')
{
$type = $display_option;
}
// Check if the IP specified by __DEBUG_PROTECT__ option is same as the access IP.
if(__DEBUG_PROTECT__ === 1 && __DEBUG_PROTECT_IP__ != $_SERVER['REMOTE_ADDR'])
{
@ -784,7 +794,7 @@ function debugPrint($debug_output = NULL, $display_option = TRUE, $file = '_debu
$label = NULL;
}
$firephp->fb($debug_output, $label);
$firephp->fb($debug_output, $label, $type);
}
else
{
@ -792,16 +802,34 @@ function debugPrint($debug_output = NULL, $display_option = TRUE, $file = '_debu
{
return;
}
$debug_file = _XE_PATH_ . 'files/' . $file;
$debug_output = sprintf("[%s %s:%d] - mem(%s)\n%s\n", date('Y-m-d H:i:s'), $file_name, $line_num, FileHandler::filesize(memory_get_usage()), print_r($debug_output, TRUE));
if($display_option === TRUE)
$print = array();
if($debug_file_exist === NULL) $print[] = '<?php exit() ?>';
if(!$debug_file) $debug_file = _XE_PATH_ . 'files/' . $file;
if(!$debug_file_exist) $debug_file_exist = file_exists($debug_file);
if($display_option === TRUE || $display_option === 'ERROR')
{
$debug_output = str_repeat('=', 40) . "\n" . $debug_output . str_repeat('-', 40);
$print[] = str_repeat('=', 80);
}
$debug_output = "\n<?php\n/*" . $debug_output . "*/\n?>\n";
@file_put_contents($debug_file, $debug_output, FILE_APPEND|LOCK_EX);
$print[] = sprintf("[%s %s:%d] %s() - mem(%s)", date('Y-m-d H:i:s'), $file_name, $line_num, $function, FileHandler::filesize(memory_get_usage()));
$type = gettype($debug_output);
if(!in_array($type, array('array', 'object', 'resource')))
{
if($display_option === 'ERROR') $print[] = 'ERROR : ' . var_export($debug_output, TRUE);
else $print[] = $type . '(' . var_export($debug_output, TRUE) . ')';
$print[] = PHP_EOL.PHP_EOL;
}
else
{
$print[] = print_r($debug_output, TRUE);
$print[] = PHP_EOL;
}
@file_put_contents($debug_file, implode(PHP_EOL, $print), FILE_APPEND|LOCK_EX);
}
}

View file

@ -124,7 +124,7 @@ class moduleModel extends module
$site_info = $oCacheHandler->get($domain_cache_key);
}
if(!isset($site_info))
if(!$site_info)
{
$args = new stdClass();
$args->domain = $domain;
@ -132,6 +132,7 @@ class moduleModel extends module
$site_info = $output->data;
if($oCacheHandler->isSupport()) $oCacheHandler->put($domain_cache_key, $site_info);
}
if($site_info && $vid)
{
Context::set('vid', $site_info->domain, true);
@ -1343,7 +1344,7 @@ class moduleModel extends module
$args->site_srl = $site_srl;
$output = executeQuery('module.getModuleConfig', $args);
$config = unserialize($output->data->config);
if(!$config) $config = new stdClass;
//insert in cache
if($oCacheHandler->isSupport())
{