<?
class Logger extends AbstractController {
/**
* Logger class is implemented a more sophisticated and usable error handling.
*
* Normally all error messages are sent through the API class by using one of two
* ways:
*
* 1. throwing exception, which is caught by Api class (unless you catch it yourself)
* 2. calling $this->fatal() which would throw exception for you (useful when calling
* from PHP4 compatible components)
*
* additionally there are way to pass info and warnings by calling:
*
* $this->warning();
* $this->info();
* $this->debug();
*
* Debug information will reach logs only if debug mode is set.
*
* ==[ Controling debug info ]===================================================
*
* AModules3 support two ways to set debug mode. Global and Local.
*
* Global mode is set by setting $api->debug to true. Local mode is set by setting
* particular object's $this->debug to true.
*
* In local mode only debug info generated by particular object will be sent
* through
*
* This class does not manage debug modes, which is a task for Api and all other
* objects.
*
* $config['debug']=true; // turns on global debug mode.
*
*
* ==[ Severity ]================================================================
*
* AModules3 have 4 severity types: debug, info, warning and fatal.
*
* Expected exceptions might be reported as warnings and uncaught exceptions
* are fatal. Forms have their own validation and errors on the form is
* completely separate system.
*
* Sample fatal errors:
* - unable to execute query
* - method not found
* - mandatory data is not specified
* fatal errors will automatically terminate application execution.
*
* Warnings messages:
* - duplicate child added to the object with same name
* - method is called without specifying important argument
*
* Sample info messages:
* - user tried to access restricted page
* - monthly log rotation routine finished successfuly
* - user information is automatically converted (from format used in previous version)
* Info messages are passed as strings without extended information.
*
* Debug messages
* - called some function which might contain errors or being debuged
* - user logged in or logged out
* - when debuging, even more messages might be sent as debug()
* WARNING: please keep debug information to the minimum. Debug information is
* accompanied with extended information. Debug information is always saved into
* logs or is available on the screen.
*
* AModules3 core tries not to produce any debug or info messages to keep files
* clean. Even if it does, those calls might eventually be cleaned out.
*
*
* ==[ Configuring logger ]======================================================
* Logger uses 2 output destinations, and 3 ways to restrict output information.
*
* Output destination: stdout (webpage), logs
* Restrict options: 'full', 'light', null
*
* stdout is different for ApiCLI and ApiWeb classes. Web output might contact
* tags or even some AJAX elements. Logs and ApiCLI uses the same output
* format.
*
* Web output for info, warning and debug messages relies on templates
* but fatal messages are template independent.
*
* ==[ Output restriction ]======================================================
* null: this option will surpress all output. When used with logs, you won't
* even need an empty directory. Web output will be clean of any messages.
*
* If fatal error occurs, if 'null' is used with web output, you will see
* message (public_error_message), instead of the actual error.
*
*
* light: only message is outputed. Even if debug mode is on, backtraces and
* additional information is stripped off. This method is best if you are using
* application for intranet and know uses or if you are doing beta testing.
* This output won't contain any sensitive information such as table names, field
* names, actual data)
*
* when used with logs, each message takes one line.
*
* full: this will output all the information available including:
* error message
* line/file/function where error message occured (guessed)
* additional information (such as last_query and error_message from DBlite)
* complete backtrace.
*
* when used with logs, each message takes several lines.
*
* ==[ Activation ]==================================================================
* To start using this class in your applicaion you should:
*
* $api->add('Logger');
*
* If you do not activate Logger, output will be similar to:
* web_output='full';
* log_output=null;
*
* ==[ Extending ]====================================================================
*
* You can extend this class to add additional features. Please notify me if you think
* something essential is missing out
*
* hide@address.com
*
* Debug functions were contributed my hide@address.com
*/
// AModules3 compatibility
public $owner;
public $api;
// Configuration;
public $web_output='full'; // $config['logger']['web_output']
public $log_output=null; // $config['logger']['log_output']
public $public_error_message=null;
// This message will be outputed to user in case of
// fatal error. When running in production mode, you
// shouldn't show any debug info to user, but log them
// instead
public $log_dir; // Directory where logs are created. It should be
// used solely by AModules3. If not set, then
// /var/log/amodules3/<realm> will be used.
//
// You can change in $config['logger']['log_dir']
private $log_file; // File we are currently logging to
public $details=array();
private $html_stdout=false;
private $header_sent=0;
function init(){
$this->log_output=$this->api->getConfig('logger/log_output',null);
$this->web_output=$this->api->getConfig('logger/web_output','full');
if(!$this->web_output){
$this->public_error_message=$this->api
->getConfig('debug_public_error_message',
'We are currently having some technical difficulties. '.
'Please retry later.');
}
if($this->log_output){
$this->log_dir=$this->api->getConfig('logger/log_dir',
"/var/log/amodules3/".$this->api->name);
$this->openLogFile();
if(rand(1,50)==1)$this->cleanupLogDirectory();
}
if($this->log_output=='full'||$this->web_output=='full'){
// Full logging will require some preparations
$this->gatherDetails();
}
if($this->api instanceof ApiWeb){
$this->html_stdout=true;
}
$this->api->addHook('caught-exception',array($this,'caughtException'));
$this->api->addHook('output-fatal',array($this,'outputFatal'));
$this->api->addHook('output-warning',array($this,'outputWarning'));
$this->api->addHook('output-info',array($this,'outputInfo'));
$this->api->addHook('output-debug',array($this,'outputDebug'));
}
function gatherDetails(){
// Get IP address
if (isset($_SERVER['REMOTE_ADDR'])) {
//FIXME: generates warning - array_shift wants variable
//$this->details['IP Address']=(isset($_SERVER["HTTP_X_FORWARDED_FOR"]) ? array_shift(explode(',', $_SERVER["HTTP_X_FORWARDED_FOR"])) : $_SERVER["REMOTE_ADDR"]);
}
if (isset($_SERVER['QUERY_STRING'])) {
$this->details['Query String']=$_SERVER['QUERY_STRING'];
}
if (isset($_SERVER['REDIRECT_SCRIPT_URI'])) {
$this->details['Original Query']=$_SERVER['REDIRECT_SCRIPT_URI'];
}
if (isset($_SERVER['HTTP_REFERER'])) {
$this->details['Referer']=$_SERVER['HTTP_REFERER'];
}
if (isset($_SERVER['HTTP_USER_AGENT'])) {
$this->details['Version']=$_SERVER['HTTP_USER_AGENT'];
}
if (isset($_SERVER['SERVER_PORT'])) {
$this->details['Port']=$_SERVER['SERVER_PORT'];
}
}
function findFrame($function_name,$shift=0){
$backtrace=debug_backtrace();
while($bt=array_shift($backtrace)){
if($bt['function']==$function_name){
while($shift--)$bt=array_shift($backtrace);
return $bt;
}
}
return array();
}
function caughtException($e){
$e->shift-=1;
if($this->log_output){
//$frame=$this->findFrame('warning',$shift);
$frame=$e->my_backtrace[$e->shift];
$this->logLine($this->txtLine(get_class($e).": ".$e->getMessage(),$frame),2);
}
if(!$this->web_output){
echo $this->public_error_message;
exit;
}
echo "<h2>".get_class($e)."</h2>\n";
echo '<p><font color=red>' . $e->getMessage() . '</font></p>';
echo '<p><font color=red>' . $e->getAdditionalMessage() . '</font></p>';
echo '<p><font color=blue>' . $e->getMyFile() . ':' . $e->getMyLine() . '</font></p>';
echo $this->backtrace($e->shift,$e->getMyTrace());
exit;
}
function outputWarning($msg,$shift=0){
// first, let's see if we should log this
$frame=$this->findFrame('warning',$shift);
if($this->log_output){
$this->logLine($this->txtLine("warning: $msg",$frame),'warning');
}
if(!$this->web_output){
return true;
}else{
echo $this->html_stdout?
$this->htmlLine("$msg",$frame,'warning'):
$this->txtLine("$msg",$frame,'warning');
return true;
}
}
function outputDebug($msg,$shift=0){
// first, let's see if we should log this
$frame=$this->findFrame('debug');
if($this->log_output){
$this->logLine($this->txtLine("info: $msg",$frame),'fatal');
}
if(!$this->web_output){
return true;
}else{
echo $this->html_stdout?
$this->htmlLine("$msg",$frame,'debug'):
$this->txtLine("$msg",$frame,'debug');
return true;
}
}
function outputInfo($msg,$shift=0,$nohtml=false){
if($this->log_output){
$this->logLine($this->txtLine("info: $msg"));
}
if($this->web_output && !$nohtml){
echo $this->html_stdout?
$this->htmlLine("$msg",null,'info'):
$this->txtLine("$msg",null,'info');
}
return true;
}
function outputFatal($msg,$shift=0){
// first, let's see if we should log this
$frame=$this->findFrame('fatal');
if($this->log_output){
$this->logLine($this->txtLine("fatal: $msg",$frame),'fatal');
}
if(!$this->web_output){
echo $this->public_error_message;
}else{
if($this->html_stdout){
echo "<h2>Fatal error</h2>\n";
}
echo $this->html_stdout?
$this->htmlLine("$msg",$frame,'fatal'):
$this->txtLine("$msg",$frame,'fatal');
if($this->html_stdout){
echo $this->backtrace('fatal');
}else{
echo "Stack trace:\n";
echo $this->txtBacktrace('fatal');
}
}
exit;
}
function htmlLine($msg,$frame=array(),$prefix=null){
if(!$frame){
return "<font style='font-family: verdana; font-size:10px'><font color=blue>warning: </font> <font color=red><b>$msg</b></font></font><br>";
}else{
$errfile=dirname($frame['file']).'/<b>'.basename($frame['file']).'</b>';
return "<font style='font-family: verdana; font-size:10px'><font color=blue>$errfile:".$frame['line']."</font> <font color=red>".($prefix?"$prefix: ":"")."<b>$msg</b></font></font><br>";
}
}
function txtLine($msg,$frame=array(),$prefix=null){
if(!$frame){
return "$prefix: $msg\n";
}else{
return basename($frame['file'])." on line ".$frame['line'].', path: '.dirname($frame['file'])."\n\n".
($prefix?"$prefix: ":"")."$msg\n\n";
}
}
function logLine($msg,$shiftfunc=null){
if($this->log_output==='full'){
if(!$this->header_sent++){
fputs($this->log_file,"\n\n".
"============================================================\n".
"$msg".
"------------------------------------------------------------\n".
"Date: ".date("d-M-Y H:i:s")."\n");
foreach($this->details as $key=>$val){
fputs($this->log_file,"$key: $val\n");
}
fputs($this->log_file,
"------------------------------------------------------------\n".
" Stack trace\n".
$this->txtBacktrace($shiftfunc).
"\n"
);
}else{
fputs($this->log_file,$msg);
}
}else{
fputs($this->log_file,"[".date("d-M-Y H:i:s")."] $msg");
}
fflush($this->log_file);
}
function logVar($var,$msg="",$shiftfunc=null){
//creating an $msg from variable
$msg.="(".gettype($var)."):";
if(is_array($var)||is_object($var))$msg .= print_r($var, true);
else$msg .= $var;
$this->logLine($msg."\n", $shiftfunc);
}
function openLogFile(){
if(!is_writable($this->log_dir)){
// Directory is not writable, let's first try to create it
if(!mkdir($this->log_dir,0750)){
throw new BaseException("You must specify valid 'debug_log_dir' inside your config.php if you are are using Logger class in production mode");
}
}
$filename='am3_error_log';
$full_filename=$this->log_dir.DIRECTORY_SEPARATOR.$filename;
if(is_link($full_filename))throw new BaseError("Log file is a symlink. Are you trying to make me overwrite somethingn?");
ini_set('error_log',$full_filename);
//$full_filename=tempnam($this->log_dir,$filename);
$new_file = (file_exists($full_filename))?false:true;
$this->log_file=fopen($full_filename,"a");
if(!$this->log_file)throw new IOException("Cannot open log file");
if ($new_file) chmod($full_filename,0777); //TODO: Check for correct grants!
}
function writeLogMessage(){
}
function backtrace($sh=null,$backtrace=null){
$output = "<div >\n";
$output .= "<b>Stack trace:</b><br /><table style='border: 1px solid black; padding: 3px; text-align: left; font-family: verdana; font-size: 10px' width=100% cellspacing=0 cellpadding=0 border=0>\n";
if(!isset($backtrace)) $backtrace=debug_backtrace();
$n=0;
foreach($backtrace as $bt){
$n++;
$args = '';
if(!isset($bt['args']))continue;
foreach($bt['args'] as $a){
if(!empty($args)){
$args .= ', ';
}
switch (gettype($a)) {
case 'integer':
case 'double':
$args .= $a;
break;
case 'string':
$a = htmlspecialchars(substr($a, 0, 128)).((strlen($a) > 128) ? '...' : '');
$args .= "\"$a\"";
break;
case 'array':
$args .= "Array(".count($a).")";
break;
case 'object':
$args .= "Object(".get_class($a).")";
break;
case 'resource':
$args .= "Resource(".strstr($a, '#').")";
break;
case 'boolean':
$args .= $a ? 'True' : 'False';
break;
case 'NULL':
$args .= 'Null';
break;
default:
$args .= 'Unknown';
}
}
if(($sh==null && strpos($bt['file'],'/amodules3/lib/')===false) || (!is_int($sh) && $bt['function']==$sh)){
$sh=$n;
}
$output .= "<tr><td valign=top align=right><font color=".($sh==$n?'red':'blue').">".dirname($bt['file'])."/".
"<b>".basename($bt['file'])."</b></font></td>";
$output .= "<td valign=top nowrap><font color=".($sh==$n?'red':'blue').">:{$bt['line']}</font> </td>";
$output .= "<td valign=top><font color=".($sh==$n?'red':'green').">{$bt['class']}{$bt['type']}<b>{$bt['function']}</b>($args)</font></td></tr>\n";
}
$output .= "</table></div>\n";
return $output;
}
function cleanupLogDirectory(){
// we should try to take care of our own log file cleanup
}
function txtBacktrace($sh=null,$backtrace=null){
if(!isset($backtrace)) $backtrace=debug_backtrace();
$output='';
$n=0;
foreach($backtrace as $bt){
$n++;
$args = '';
if(!isset($bt['args']))$bt['args']=array();
foreach($bt['args'] as $a){
if(!empty($args)){
$args .= ', ';
}
switch (gettype($a)) {
case 'integer':
case 'double':
$args .= $a;
break;
case 'string':
$a = (substr($a, 0, 128)).((strlen($a) > 128) ? '...' : '');
$args .= "\"$a\"";
break;
case 'array':
$args .= "Array(".count($a).")";
break;
case 'object':
$args .= "Object(".get_class($a).")";
break;
case 'resource':
$args .= "Resource(".strstr($a, '#').")";
break;
case 'boolean':
$args .= $a ? 'True' : 'False';
break;
case 'NULL':
$args .= 'Null';
break;
default:
$args .= 'Unknown';
}
}
if($sh){
if(is_int($sh)){
if($sh>0){
$sh--;
continue;
}
}elseif($bt['function']!=$sh){
$sh=null;
continue;
}
}
$output .= $bt['file'].":".$bt['line']." ";
$output .= "{$bt['class']}{$bt['type']}{$bt['function']}($args)\n";
}
return $output;
}
/*
// Debug functions
var $filename;
var $err_message;
var $_current_ip;
var $_prev_exec_time;
*/
// TODO for mvs, review the following functions ;)
function Debug($filename) {
if (is_null($filename))
$filename = dirname(__FILE__).DIRECTORY_SEPARATOR.'debug.log';
$this->filename = $filename;
if (isset($_SERVER['REMOTE_ADDR'])) {
$this->_current_ip = (isset($_SERVER["HTTP_X_FORWARDED_FOR"]) ? array_shift(explode(',', $_SERVER["HTTP_X_FORWARDED_FOR"])) : $_SERVER["REMOTE_ADDR"]);
}
}
function _sec2time($sec) {
$res = '';
if ($sec<0) {
$sec = -$sec;
$res = '-'.$res;
}
if ($sec!=floor($sec)) {
$msec = round(($sec - floor($sec))*1000);
$msec = '.'.str_pad($msec,3,'0', STR_PAD_LEFT);
$sec = floor($sec);
}
$hours = floor($sec/3600);
$min = floor(($sec - $hours*3600)/60);
$sec = $sec - $hours*3600 - $min*60;
if ($hours > 0)
$res .= str_pad($hours,2,'0', STR_PAD_LEFT).':';
if (($hours > 0) or ($min > 0))
$res .= str_pad($min,2,'0', STR_PAD_LEFT).':';
$res .= str_pad($sec,2,'0', STR_PAD_LEFT).$msec;
return $res;
}
function _microtime_float() {
list($usec, $sec) = explode(" ", microtime());
return ((float)$usec + (float)$sec);
}
// print
function p($message, $file = null, $line = null) {
$res = true;
$time_diff_str = '';
if (!empty($this->_prev_exec_time)) {
$time_diff = $this->_microtime_float() - $this->_prev_exec_time;
if ($time_diff < 1) $time_diff_str = $this->_sec2time($time_diff);
}
$details = ((empty($this->_current_ip))?'':$this->_current_ip.' - ').
((!empty($file))?basename($file).' (line '.$line.')':'');
if (!empty($details)) $details = ' ***** '.$details.' *****';
$message = '['.date('d-M-Y H:i:s') . '] '.$time_diff_str.$details.
"\n\n". $message . "\n\n";
$new_file = (file_exists($this->filename))?false:true;
$fh = @fopen($this->filename,'a');
if (($fh !== false) and (is_resource($fh))) {
@flock($fh, LOCK_EX);
if (!@fwrite($fh, $message)) {
$this->err_message = "Cannot write to file ($this->filename)";
error_log($this->err_message.' in '.__FILE__.' on line '.__LINE__,0);
$res = false;
}
@flock($fh, LOCK_UN);
@fclose($fh);
if ($new_file) chmod($this->filename,0777);
}
else {
$this->err_message = 'Cannot open file ('.$this->filename.')'.
' in '.__FILE__.' on line '.__LINE__.' for save message: '."\n".$message;
error_log($this->err_message,0);
$res = false;
}
$this->_prev_exec_time = $this->_microtime_float();
return $res;
}
}