Skip to content
Snippets Groups Projects
Commit 5781e9bb authored by Hahn Axel (hahn)'s avatar Hahn Axel (hahn)
Browse files

update ahlogger

parent 75c56872
No related branches found
No related tags found
1 merge request!455997 no autocomplete
...@@ -2,14 +2,22 @@ ...@@ -2,14 +2,22 @@
/** /**
* Debug logging during a client request. * Debug logging during a client request.
* So you can measure any action find bottlenecks in your code.
* *
* @author hahn * Source: https://github.com/axelhahn/ahlogger
*
* USAGE:
* (1) Trigger a message with add() to add a marker
* (2) The render() method lists all items in a table with time since start
* and the delta to the last message.
*
* @author www.axel-hahn.de
*/ */
class logger { class logger {
protected $aMessages=array();
protected $bShowDebug=true;
protected $_iMemStart = false;
protected $aMessages = [];
protected $bShowDebug = false;
protected $_iMemStart = false;
/** /**
* constuctor * constuctor
...@@ -18,34 +26,12 @@ class logger { ...@@ -18,34 +26,12 @@ class logger {
*/ */
public function __construct($sInitMessage = "Logger was initialized.") { public function __construct($sInitMessage = "Logger was initialized.") {
$this->_iMemStart=memory_get_usage(); $this->_iMemStart=memory_get_usage();
$this->enableDebug(true);
$this->add($sInitMessage); $this->add($sInitMessage);
$this->sCssPrefix='debug-'.md5(microtime(true));
return true; return true;
} }
/**
* enable / disable debugging
* @param type $bEnable
* @return type
*/
public function enableDebug($bEnable=false){
return $this->bShowDebug=$bEnable;
}
/**
* enable client debugging by a given array of allowed ip addresses
* @param array $aIpArray
* @return boolean
*/
public function enableDebugByIp($aIpArray){
$this->enableDebug(false);
if (!$_SERVER || !is_array($_SERVER) || !array_key_exists("REMOTE_ADDR", $_SERVER)){
return false;
}
if (array_search($_SERVER['REMOTE_ADDR'], $aIpArray)!==false){
$this->enableDebug(true);
}
}
/** /**
* add a logging message * add a logging message
* @param type $sMessage * @param type $sMessage
...@@ -56,94 +42,228 @@ class logger { ...@@ -56,94 +42,228 @@ class logger {
if (!$this->bShowDebug){ if (!$this->bShowDebug){
return false; return false;
} }
global $aCfg;
$this->aMessages[] = array( $this->aMessages[] = array(
'time' => microtime(true), 'time' => microtime(true),
'message' => $sMessage, 'message' => $sMessage,
'level'=>$sLevel 'level' => preg_replace('/[^a-z0-9\-\_]/', '', $sLevel),
'memory' => memory_get_usage()
); );
if ($sLevel=="MAIL"){
mail($aCfg["emailDeveloper"], "studmed - booking tool - Logmessage", $sMessage);
}
return true; return true;
} }
/** /**
* render output of all logging messages * enable / disable debugging
* @param type $bEnable
* @return type
*/ */
public function render(){ public function enableDebug($bEnable=true){
if (!$this->bShowDebug){ return $this->bShowDebug=!!$bEnable;
}
/**
* enable client debugging by a given array of allowed ip addresses
* @param array $aIpArray list of ip addresses in a flat array
* @return boolean
*/
public function enableDebugByIp($aIpArray){
$this->enableDebug(false);
if (!$_SERVER || !is_array($_SERVER) || !array_key_exists("REMOTE_ADDR", $_SERVER)){
return false; return false;
} }
$sOut=''; if (array_search($_SERVER['REMOTE_ADDR'], $aIpArray)!==false){
$this->enableDebug(true);
}
}
protected function _prepareRendering(){
$iMem=memory_get_usage(); $iMem=memory_get_usage();
$this->add('<hr>'); $this->add('<hr>');
$this->add('Memory on start: ' . number_format($this->_iMemStart, 0, '.', ',') . " bytes"); $this->add('Memory on start: ' . number_format($this->_iMemStart, 0, '.', ',') . " bytes");
$this->add('Memory on end: ' . number_format($iMem, 0, '.', ',') . " bytes"); $this->add('Memory on end: ' . number_format($iMem, 0, '.', ',') . " bytes");
$this->add('Memory peak: ' . number_format(memory_get_peak_usage(), 0, '.', ',') . " bytes"); $this->add('Memory peak: ' . number_format(memory_get_peak_usage(), 0, '.', ',') . " bytes");
$aReturn=[
'totaltime' => false,
'level' => false,
'warnings' => '',
'errors' => '',
'maxrowid' => false,
'maxtime' => false,
'result' => []
];
$sStarttime = $this->aMessages[0]["time"]; $sStarttime = $this->aMessages[0]["time"];
$iLasttime = $sStarttime;
$iCounter = 0; $iCounter = 0;
$sMaxRowId = false; $sMaxRowId = false;
$iMaxtime = -1; $iMaxtime = -1;
$sWarnings=false; $iMaxmem = -1;
$bHasWarning = false;
$iLasttime=$sStarttime; $bHasError = false;
foreach ($this->aMessages as $aLogentry) { foreach ($this->aMessages as $aLogentry) {
$iCounter++; $iCounter++;
$sTrId='debugTableRow'.$iCounter;
if($aLogentry["level"]=="warning"){
$bHasWarning=true;
}
if($aLogentry["level"]=="error"){
$bHasError=true;
}
$sTrId = $this->sCssPrefix.'debugTableRow' . $iCounter;
$iDelta = $aLogentry["time"] - $iLasttime; $iDelta = $aLogentry["time"] - $iLasttime;
if ($iDelta > $iMaxtime) { if ($iDelta > $iMaxtime) {
$iMaxtime = $iDelta; $iMaxtime = $iDelta;
$sMaxRowId = $sTrId; $sMaxRowId = $sTrId;
} }
$iMaxmem=max($aLogentry["memory"], $iMaxmem);
$sStyle=($iDelta > 1)?'color: #f82;':''; if (($iDelta > 1) || $aLogentry["level"] == "warning") {
if (($iDelta > 1)){ $aReturn['warnings'].='<a href="#' . $sTrId . '" title="' . sprintf("%01.4f", $iDelta) . ' s">' . $iCounter . '</a>&nbsp;';
$sWarnings.='<a href="#'.$sTrId.'" title="'.sprintf("%01.4f", $iDelta).' s">'.$iCounter.'</a>&nbsp;';
} }
$sOut.='<tr class="'.$aLogentry["level"].'" id="'.$sTrId.'" style="'.$sStyle.'">'. if ($aLogentry["level"] == "error") {
'<td>'.$iCounter.'</td>'. $aReturn['errors'].='<a href="#' . $sTrId . '" title="' . sprintf("%01.4f", $iDelta) . ' s">' . $iCounter . '</a>&nbsp;';
'<td>'.sprintf("%01.3f", $aLogentry["time"]-$sStarttime).'</td>'. }
'<td>'.sprintf("%01.3f", $iDelta).'</td>'. $aReturn['entries'][]=[
'<td>'.$aLogentry["level"].'</td>'. 'time'=>$aLogentry["time"],
'<td>'.$aLogentry["message"].'</td>'. 'level'=>$aLogentry["level"],
'</tr>'; 'message'=>$aLogentry["message"],
'memory'=>sprintf("%01.2f", $aLogentry["memory"]/1024/1024), // MB
'trid'=>$sTrId,
'trclass'=>$aLogentry["level"],
'counter'=>$iCounter,
'timer'=>sprintf("%01.3f", $aLogentry["time"] - $sStarttime),
'delta'=>sprintf("%01.0f", $iDelta*1000),
];
$iLasttime = $aLogentry["time"]; $iLasttime = $aLogentry["time"];
}
$aReturn['level']=($bHasWarning
? ($bHasError ? 'error' : 'warning')
: ''
);
$aReturn['maxrowid']=$sMaxRowId;
$aReturn['maxtime']=sprintf("%01.3f", $iMaxtime);
$aReturn['maxmem']=sprintf("%01.2f", $iMaxmem/1024/1024);
$aReturn['totaltime']=sprintf("%01.3f", $aLogentry['time']-$aReturn['entries'][0]['time']);
return $aReturn;
}
/**
* get html code for a progressbar with divs
* @param {int|float} $iVal value between 0..max value
* @param {int|float} $iMax max value
* @return {string}
*/
protected function _getBar($iVal, $iMax){
$iWidth=$iVal/$iMax*100;
return '<div class="bar"><div class="progress" style="width: '.$iWidth.'%;">&nbsp;</div></div>';
} }
$iTotal=$iLasttime-$sStarttime;
if ($sWarnings){ /**
$sWarnings='<br>warnings:&nbsp;'.$sWarnings; * render output of all logging messages
*/
public function render() {
if (!$this->bShowDebug){
return false;
} }
$aData=$this->_prepareRendering();
/*
Array
(
[totaltime] => 0.006
[errors] =>
[warnings] => 3
[maxrowid] => debugTableRow3
[maxtime] => 0.005
[result] => Array
(
)
if ($sOut) $sOut=' [entries] => Array
<div style="position: fixed; right: 1em; top: 6em; background: rgba(255,80,80, 0.1); padding: 0.5em;"> mit Elementen
<span style="font-size: 130%;">total:&nbsp;'.sprintf("%01.3f", $iTotal).'&nbsp;s</span><br> Array
<span>longest&nbsp;action:&nbsp;<a href="#'.$sMaxRowId.'">'.sprintf("%01.3f", $iMaxtime).'&nbsp;s</a></span> (
<span>'.$sWarnings.'</span> [time] => 1663959608.2566
[level] => info
[message] => Logger was initialized.
[memory] => 538056
[trid] => debugTableRow1
[trclass] => info
[trstyle] =>
[counter] => 1
[timer] => 0.000
[delta] => 0.000
)
*/
$sOut='';
// echo '<pre>'; print_r($aData); die();
foreach ($aData['entries'] as $aLogentry){
$sOut.='<tr class="'.$this->sCssPrefix.'-level-' . $aLogentry["level"] . ''.($aLogentry["trid"]==$aData["maxrowid"] ? ' '.$this->sCssPrefix.'-maxrow' : '').'" '
.'id="' . $aLogentry["trid"] . '">' .
'<td>' . $aLogentry["counter"] . '</td>' .
'<td>' . $aLogentry["level"] . '</td>' .
'<td>' . $aLogentry["timer"] . '</td>' .
'<td>' . $this->_getBar($aLogentry["delta"], $aData["maxtime"]*1000). $aLogentry["delta"] .' ms</td>' .
'<td>' . $this->_getBar($aLogentry["memory"], $aData["maxmem"]) . $aLogentry["memory"] .' MB'. '</td>' .
'<td>' . $aLogentry["message"] . '</td>' .
'</tr>';
}
if ($sOut){
$sOut = '
<style>
.'.$this->sCssPrefix.'-info {position: fixed; top: 6em; right: 1em; background: rgba(200,228,255, 0.8); border: 1px solid; z-index: 99999;}
.'.$this->sCssPrefix.'-info .head {background: rgba(0,0,0,0.4); color: #fff;padding: 0em 0.5em 0.2em; }
.'.$this->sCssPrefix.'-info .content {padding: 0.5em; }
.'.$this->sCssPrefix.'-info .content .total {font-size: 160%; color: rgba(0,0,0,0.5); margin: 0.3em 0; display: inline-block;}
.'.$this->sCssPrefix.'-messages {margin: 5em 2em 2em;}
.'.$this->sCssPrefix.'-messages .bar {background: rgba(0,0,0,0.03); height: 1.4em; position: absolute; width: 6em; border-right: 1px solid rgba(0,0,0,0.2);}
.'.$this->sCssPrefix.'-messages .progress {background: rgba(100,140,180,0.2); height: 1.4em; padding: 0;}
.'.$this->sCssPrefix.'-messages table{background: #fff; color: #222;table-layout:fixed; }
.'.$this->sCssPrefix.'-messages table th{background: none;}
.'.$this->sCssPrefix.'-messages table th.barcol{min-width: 7em; position: relative;}
.'.$this->sCssPrefix.'-messages table td{padding: 3px; vertical-align: top;}
.'.$this->sCssPrefix.'-messages table th:hover{background:#aaa !important;}
.'.$this->sCssPrefix.'-level-info{background: #e0e8f8; color:#124}
.'.$this->sCssPrefix.'-level-warning{background: #fcf8e3; color: #980;}
.'.$this->sCssPrefix.'-level-error{background: #fce0e0; color: #944;}
.'.$this->sCssPrefix.'-maxrow{color:#f33; font-weight: bold;}
</style>
<div class="'.$this->sCssPrefix.' '.$this->sCssPrefix.'-info '.$this->sCssPrefix.'-level-'.$aData['level'].'">
<div class="head">ahLogger</div>
<div class="content">
<span class="total">⏱️ ' . $aData['totaltime'] . '&nbsp;s</span><br>
🪲 <a href="#'.$this->sCssPrefix.'-messages">Debug infos</a> | 🔺 <a href="#">top</a><br>
<span>longest&nbsp;action: ⏱️&nbsp;<a href="#' . $aData['maxrowid'] . '">' . ($aData['maxtime']*1000) . '&nbsp;ms</a></span>
' . ($aData['errors'] ? '<br><span>‼️ Errors: '.$aData['errors'] . '</span>' : '').'
' . ($aData['warnings'] ? '<br><span>⚠️ Warnings: '.$aData['warnings'] . '</span>' : '').'
</div>
</div> </div>
<br>
<br> <div id="'.$this->sCssPrefix.'-messages" class="'.$this->sCssPrefix.' '.$this->sCssPrefix.'-messages">
<br> DEBUG :: LOG MESSAGES<br>'
<br> . ($aData['errors'] ? '<span>Errors: '.$aData['errors'] . '</span><br>' : '')
<br> . ($aData['warnings'] ? '<span>Warnings: '.$aData['warnings'] . '</span><br>' : '')
<h3>DEBUG</h3><br> .'<br>
<table class="datatable table table-striped debugtable"> <table >
<thead> <thead>
<tr> <tr>
<th>#</th> <th>#</th>
<th>delta to start time</th>
<th>delta to previuos</th>
<th>level</th> <th>level</th>
<th>time [s]</th>
<th class="barcol">delta</th>
<th class="barcol">memory</th>
<th>message</th> <th>message</th>
</tr></thead><tbody> </tr></thead><tbody>
' . $sOut . '</tbody></table>' ' . $sOut . '</tbody></table>'
. '<script>$(\'#'.$sMaxRowId.'\').css(\'color\', \'#f00\');</script>'; ;
}
return $sOut; return $sOut;
} }
/** /**
...@@ -154,32 +274,19 @@ class logger { ...@@ -154,32 +274,19 @@ class logger {
if (!$this->bShowDebug){ if (!$this->bShowDebug){
return false; return false;
} }
$sOut=''; $aData=$this->_prepareRendering();
$sStarttime=$this->aMessages[0]["time"];
$iCounter=0; $sOut='';
$sMaxRowId=false; foreach ($aData['entries'] as $aLogentry){
$iMaxtime=-1; $sOut.=$aLogentry["timer"].' | '
$sWarnings=false; .$aLogentry["delta"].' ms | '
.$aLogentry["level"].' | '
$iLasttime=$sStarttime; .(sprintf("%01.3f", $aLogentry["memory"]/1024/1024)).' MB | '
foreach ($this->aMessages as $aLogentry){
$iCounter++;
$iDelta=$aLogentry["time"]-$iLasttime;
$sOut.=$aLogentry["level"].' '
. $iCounter.' '
.sprintf("%01.3f", $aLogentry["time"]-$sStarttime).' '
.sprintf("%01.3f", $iDelta).' '
.$aLogentry["level"].' '
.$aLogentry["message"].' ' .$aLogentry["message"].' '
. "\n" . "\n"
; ;
$iLasttime=$aLogentry["time"];
} }
// $iTotal=$iLasttime-$sStarttime; $sOut.="\nTotal time: ".$aData['totaltime'] . "\n";
return $sOut; return $sOut;
} }
} }
0% Loading or .
You are about to add 0 people to the discussion. Proceed with caution.
Please register or to comment