Skip to content
Snippets Groups Projects

update ahlogger

Merged Hahn Axel (hahn) requested to merge 5997-no-autocomplete into master
1 file
+ 344
292
Compare changes
  • Side-by-side
  • Inline
<?php
<?php
/**
/**
* Debug logging during a client request.
* ----------------------------------------------------------------------
* So you can measure any action find bottlenecks in your code.
*
*
* Debug logging during a client request.
* Source: https://github.com/axelhahn/ahlogger
* So you can measure any action find bottlenecks in your code.
*
*
* USAGE:
* Licence: GNU GPL 3.0
* (1) Trigger a message with add() to add a marker
* Source: https://github.com/axelhahn/ahlogger
* (2) The render() method lists all items in a table with time since start
* Docs: https://www.axel-hahn.de/docs/ahlogger/
* and the delta to the last message.
*
*
* USAGE:<br>
* @author www.axel-hahn.de
* (1) Trigger a message with add() to add a marker<br>
*/
* (2) The render() method lists all items in a table with time since start
class logger {
* and the delta to the last message. <br>
*
protected $aMessages = [];
* @author www.axel-hahn.de
protected $bShowDebug = false;
*
protected $_iMemStart = false;
* ----------------------------------------------------------------------
* 2016-02-26 init
/**
* 2016-11-19 add memory usage
* constuctor
* (...)
* @param string $sInitMessage init message
* 2022-09-25 add memory tracking, add cli renderer
* @return boolean
* 2022-09-27 css updates
*/
* 2022-10-02 add emoji chars
public function __construct($sInitMessage = "Logger was initialized.") {
* 2022-10-16 mark longest action with an icon
$this->_iMemStart=memory_get_usage();
* 2022-12-15 make it compatible to PHP 8.2; add doc + comments
$this->enableDebug(true);
* 2023-05-15 fix _getBar() - division by zero
$this->add($sInitMessage);
* ----------------------------------------------------------------------
$this->sCssPrefix='debug-'.md5(microtime(true));
*/
return true;
class logger {
}
/**
/**
* @var {array} array of added messages
* add a logging message
*/
* @param type $sMessage
protected $aMessages = [];
* @param type $sLevel
* @return boolean
/**
*/
* @var {bool} flag: show debug infos? default: false
public function add($sMessage, $sLevel = "info") {
*/
if (!$this->bShowDebug){
protected $bShowDebug = false;
return false;
}
/**
$this->aMessages[] = array(
* @var {int} memory usage on start
'time' => microtime(true),
*/
'message' => $sMessage,
protected $_iMemStart = false;
'level' => preg_replace('/[^a-z0-9\-\_]/', '', $sLevel),
'memory' => memory_get_usage()
/**
);
* @var {string} dynamic prefix for used css - it is set in the cronstructor
*/
return true;
protected $sCssPrefix = '';
}
// ----------------------------------------------------------------------
/**
// CONSTRUCTOR
* enable / disable debugging
// ----------------------------------------------------------------------
* @param type $bEnable
* @return type
/**
*/
* constuctor
public function enableDebug($bEnable=true){
* @param string $sInitMessage init message
return $this->bShowDebug=!!$bEnable;
* @return boolean
}
*/
public function __construct($sInitMessage = "Logger was initialized.") {
/**
$this->_iMemStart=memory_get_usage();
* enable client debugging by a given array of allowed ip addresses
$this->enableDebug(true);
* @param array $aIpArray list of ip addresses in a flat array
$this->add($sInitMessage);
* @return boolean
$this->sCssPrefix='debug-'.md5(microtime(true));
*/
return true;
public function enableDebugByIp($aIpArray){
}
$this->enableDebug(false);
if (!$_SERVER || !is_array($_SERVER) || !array_key_exists("REMOTE_ADDR", $_SERVER)){
// ----------------------------------------------------------------------
return false;
// PUBLIC METHODS
}
// ----------------------------------------------------------------------
if (array_search($_SERVER['REMOTE_ADDR'], $aIpArray)!==false){
$this->enableDebug(true);
/**
}
* add a logging message
}
* @param type $sMessage
* @param type $sLevel
protected function _prepareRendering(){
* @return boolean
$iMem=memory_get_usage();
*/
$this->add('<hr>');
public function add($sMessage, $sLevel = "info") {
$this->add('Memory on start: ' . number_format($this->_iMemStart, 0, '.', ',') . " bytes");
if (!$this->bShowDebug){
$this->add('Memory on end: ' . number_format($iMem, 0, '.', ',') . " bytes");
return false;
$this->add('Memory peak: ' . number_format(memory_get_peak_usage(), 0, '.', ',') . " bytes");
}
$this->aMessages[] = array(
$aReturn=[
'time' => microtime(true),
'totaltime' => false,
'message' => $sMessage,
'level' => false,
'level' => preg_replace('/[^a-z0-9\-\_]/', '', $sLevel),
'warnings' => '',
'memory' => memory_get_usage()
'errors' => '',
);
'maxrowid' => false,
'maxtime' => false,
return true;
'result' => []
}
];
$sStarttime = $this->aMessages[0]["time"];
/**
$iLasttime = $sStarttime;
* enable / disable debugging
$iCounter = 0;
* @param type $bEnable
$sMaxRowId = false;
* @return type
$iMaxtime = -1;
*/
$iMaxmem = -1;
public function enableDebug($bEnable=true){
$bHasWarning = false;
return $this->bShowDebug=!!$bEnable;
$bHasError = false;
}
foreach ($this->aMessages as $aLogentry) {
/**
$iCounter++;
* enable client debugging by a given array of allowed ip addresses
* @param array $aIpArray list of ip addresses in a flat array
if($aLogentry["level"]=="warning"){
* @return boolean
$bHasWarning=true;
*/
}
public function enableDebugByIp($aIpArray){
if($aLogentry["level"]=="error"){
$this->enableDebug(false);
$bHasError=true;
if (!$_SERVER || !is_array($_SERVER) || !array_key_exists("REMOTE_ADDR", $_SERVER)){
}
return false;
}
$sTrId = $this->sCssPrefix.'debugTableRow' . $iCounter;
if (array_search($_SERVER['REMOTE_ADDR'], $aIpArray)!==false){
$iDelta = $aLogentry["time"] - $iLasttime;
$this->enableDebug(true);
if ($iDelta > $iMaxtime) {
}
$iMaxtime = $iDelta;
}
$sMaxRowId = $sTrId;
}
/**
$iMaxmem=max($aLogentry["memory"], $iMaxmem);
* helper function: prepare array of added massages before output
* - detect warnings and errors
* - detect needed time for each action
if (($iDelta > 1) || $aLogentry["level"] == "warning") {
* - detect longest action
$aReturn['warnings'].='<a href="#' . $sTrId . '" title="' . sprintf("%01.4f", $iDelta) . ' s">' . $iCounter . '</a>&nbsp;';
* - detect maximum of memory usage
}
* - calculate total time
if ($aLogentry["level"] == "error") {
*
$aReturn['errors'].='<a href="#' . $sTrId . '" title="' . sprintf("%01.4f", $iDelta) . ' s">' . $iCounter . '</a>&nbsp;';
* @return array
}
*/
$aReturn['entries'][]=[
protected function _prepareRendering(){
'time'=>$aLogentry["time"],
$iMem=memory_get_usage();
'level'=>$aLogentry["level"],
$this->add('<hr>');
'message'=>$aLogentry["message"],
$this->add('Memory on start: ' . number_format($this->_iMemStart, 0, '.', ',') . " bytes");
'memory'=>sprintf("%01.2f", $aLogentry["memory"]/1024/1024), // MB
$this->add('Memory on end: ' . number_format($iMem, 0, '.', ',') . " bytes");
$this->add('Memory peak: ' . number_format(memory_get_peak_usage(), 0, '.', ',') . " bytes");
'trid'=>$sTrId,
'trclass'=>$aLogentry["level"],
$aReturn=[
'counter'=>$iCounter,
'totaltime' => false,
'timer'=>sprintf("%01.3f", $aLogentry["time"] - $sStarttime),
'level' => false,
'delta'=>sprintf("%01.0f", $iDelta*1000),
'warnings' => '',
];
'errors' => '',
$iLasttime = $aLogentry["time"];
'maxrowid' => false,
}
'maxtime' => false,
$aReturn['level']=($bHasWarning
'result' => []
? ($bHasError ? 'error' : 'warning')
];
: ''
$sStarttime = $this->aMessages[0]["time"];
);
$iLasttime = $sStarttime;
$aReturn['maxrowid']=$sMaxRowId;
$iCounter = 0;
$aReturn['maxtime']=sprintf("%01.3f", $iMaxtime);
$sMaxRowId = false;
$aReturn['maxmem']=sprintf("%01.2f", $iMaxmem/1024/1024);
$iMaxtime = -1;
$aReturn['totaltime']=sprintf("%01.3f", $aLogentry['time']-$aReturn['entries'][0]['time']);
$iMaxmem = -1;
return $aReturn;
$bHasWarning = false;
}
$bHasError = false;
/**
foreach ($this->aMessages as $aLogentry) {
* get html code for a progressbar with divs
$iCounter++;
* @param {int|float} $iVal value between 0..max value
* @param {int|float} $iMax max value
if($aLogentry["level"]=="warning"){
* @return {string}
$bHasWarning=true;
*/
}
protected function _getBar($iVal, $iMax){
if($aLogentry["level"]=="error"){
$iWidth=$iVal/$iMax*100;
$bHasError=true;
return '<div class="bar"><div class="progress" style="width: '.$iWidth.'%;">&nbsp;</div></div>';
}
}
$sTrId = $this->sCssPrefix.'debugTableRow' . $iCounter;
/**
$iDelta = $aLogentry["time"] - $iLasttime;
* render output of all logging messages
if ($iDelta > $iMaxtime) {
*/
$iMaxtime = $iDelta;
public function render() {
$sMaxRowId = $sTrId;
if (!$this->bShowDebug){
}
return false;
$iMaxmem=max($aLogentry["memory"], $iMaxmem);
}
$aData=$this->_prepareRendering();
if (($iDelta > 1) || $aLogentry["level"] == "warning") {
/*
$aReturn['warnings'].='<a href="#' . $sTrId . '" title="' . sprintf("%01.4f", $iDelta) . ' s">' . $iCounter . '</a>&nbsp;';
Array
}
(
if ($aLogentry["level"] == "error") {
[totaltime] => 0.006
$aReturn['errors'].='<a href="#' . $sTrId . '" title="' . sprintf("%01.4f", $iDelta) . ' s">' . $iCounter . '</a>&nbsp;';
[errors] =>
}
[warnings] => 3
$aReturn['entries'][]=[
[maxrowid] => debugTableRow3
'time'=>$aLogentry["time"],
[maxtime] => 0.005
'level'=>$aLogentry["level"],
[result] => Array
'message'=>$aLogentry["message"],
(
'memory'=>sprintf("%01.2f", $aLogentry["memory"]/1024/1024), // MB
)
'trid'=>$sTrId,
[entries] => Array
'trclass'=>$aLogentry["level"],
mit Elementen
'counter'=>$iCounter,
Array
'timer'=>sprintf("%01.3f", $aLogentry["time"] - $sStarttime),
(
'delta'=>sprintf("%01.0f", $iDelta*1000),
[time] => 1663959608.2566
];
[level] => info
$iLasttime = $aLogentry["time"];
[message] => Logger was initialized.
}
[memory] => 538056
$aReturn['level']=($bHasWarning
[trid] => debugTableRow1
? ($bHasError ? 'error' : 'warning')
[trclass] => info
: ''
[trstyle] =>
);
[counter] => 1
$aReturn['maxrowid']=$sMaxRowId;
[timer] => 0.000
$aReturn['maxtime']=sprintf("%01.3f", $iMaxtime);
[delta] => 0.000
$aReturn['maxmem']=sprintf("%01.2f", $iMaxmem/1024/1024);
)
$aReturn['totaltime']=sprintf("%01.3f", $aLogentry['time']-$aReturn['entries'][0]['time']);
*/
return $aReturn;
}
$sOut='';
// echo '<pre>'; print_r($aData); die();
/**
foreach ($aData['entries'] as $aLogentry){
* get html code for a progressbar with divs
$sOut.='<tr class="'.$this->sCssPrefix.'-level-' . $aLogentry["level"] . ''.($aLogentry["trid"]==$aData["maxrowid"] ? ' '.$this->sCssPrefix.'-maxrow' : '').'" '
* @param {int|float} $iVal value between 0..max value
.'id="' . $aLogentry["trid"] . '">' .
* @param {int|float} $iMax max value
'<td>' . $aLogentry["counter"] . '</td>' .
* @return {string}
'<td>' . $aLogentry["level"] . '</td>' .
*/
'<td>' . $aLogentry["timer"] . '</td>' .
protected function _getBar($iVal, $iMax){
'<td>' . $this->_getBar($aLogentry["delta"], $aData["maxtime"]*1000). $aLogentry["delta"] .' ms</td>' .
return $iMax>0
'<td>' . $this->_getBar($aLogentry["memory"], $aData["maxmem"]) . $aLogentry["memory"] .' MB'. '</td>' .
? '<div class="bar"><div class="progress" style="width: '.($iVal/$iMax*100).'%;">&nbsp;</div></div>'
'<td>' . $aLogentry["message"] . '</td>' .
: ''
'</tr>';
;
}
}
if ($sOut){
$sOut = '
/**
<style>
* render output of all logging messages
.'.$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; }
public function render() {
.'.$this->sCssPrefix.'-info .content {padding: 0.5em; }
if (!$this->bShowDebug){
.'.$this->sCssPrefix.'-info .content .total {font-size: 160%; color: rgba(0,0,0,0.5); margin: 0.3em 0; display: inline-block;}
return false;
}
.'.$this->sCssPrefix.'-messages {margin: 5em 2em 2em;}
$aData=$this->_prepareRendering();
.'.$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; }
Array
.'.$this->sCssPrefix.'-messages table th{background: none;}
(
.'.$this->sCssPrefix.'-messages table th.barcol{min-width: 7em; position: relative;}
[totaltime] => 0.006
.'.$this->sCssPrefix.'-messages table td{padding: 3px; vertical-align: top;}
[errors] =>
.'.$this->sCssPrefix.'-messages table th:hover{background:#aaa !important;}
[warnings] => 3
[maxrowid] => debugTableRow3
.'.$this->sCssPrefix.'-level-info{background: #e0e8f8; color:#124}
[maxtime] => 0.005
.'.$this->sCssPrefix.'-level-warning{background: #fcf8e3; color: #980;}
[result] => Array
.'.$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'].'">
[entries] => Array
<div class="head">ahLogger</div>
mit Elementen
<div class="content">
Array
<span class="total">⏱️ ' . $aData['totaltime'] . '&nbsp;s</span><br>
(
🪲 <a href="#'.$this->sCssPrefix.'-messages">Debug infos</a> | 🔺 <a href="#">top</a><br>
[time] => 1663959608.2566
<span>longest&nbsp;action: ⏱️&nbsp;<a href="#' . $aData['maxrowid'] . '">' . ($aData['maxtime']*1000) . '&nbsp;ms</a></span>
[level] => info
' . ($aData['errors'] ? '<br><span>‼️ Errors: '.$aData['errors'] . '</span>' : '').'
[message] => Logger was initialized.
' . ($aData['warnings'] ? '<br><span>⚠️ Warnings: '.$aData['warnings'] . '</span>' : '').'
[memory] => 538056
</div>
[trid] => debugTableRow1
</div>
[trclass] => info
[trstyle] =>
<div id="'.$this->sCssPrefix.'-messages" class="'.$this->sCssPrefix.' '.$this->sCssPrefix.'-messages">
[counter] => 1
DEBUG :: LOG MESSAGES<br>'
[timer] => 0.000
. ($aData['errors'] ? '<span>Errors: '.$aData['errors'] . '</span><br>' : '')
[delta] => 0.000
. ($aData['warnings'] ? '<span>Warnings: '.$aData['warnings'] . '</span><br>' : '')
)
.'<br>
*/
<table >
<thead>
$sOut='';
<tr>
// echo '<pre>'; print_r($aData); die();
<th>#</th>
foreach ($aData['entries'] as $aLogentry){
<th>level</th>
$sOut.='<tr class="'.$this->sCssPrefix.'-level-' . $aLogentry["level"] . ''.($aLogentry["trid"]==$aData["maxrowid"] ? ' '.$this->sCssPrefix.'-maxrow' : '').'" '
<th>time [s]</th>
.'id="' . $aLogentry["trid"] . '">' .
<th class="barcol">delta</th>
'<td>' . $aLogentry["counter"] . '</td>' .
<th class="barcol">memory</th>
'<td>' . $aLogentry["level"] . '</td>' .
<th>message</th>
'<td>' . $aLogentry["timer"] . '</td>' .
</tr></thead><tbody>
'<td>' . $this->_getBar($aLogentry["delta"], $aData["maxtime"]*1000). $aLogentry["delta"] .' ms'.($aLogentry["delta"]==$aData['maxtime']*1000 ? ' ⏱️' : '').'</td>' .
' . $sOut . '</tbody></table>'
'<td>' . $this->_getBar($aLogentry["memory"], $aData["maxmem"]) . $aLogentry["memory"] .' MB'. '</td>' .
;
'<td>' . $aLogentry["message"] . '</td>' .
}
'</tr>';
return $sOut;
}
}
if ($sOut){
/**
$sOut = '
* render output of all logging messages for cli output
<style>
* @return string
.'.$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; }
public function renderCli(){
.'.$this->sCssPrefix.'-info .content {padding: 0.5em; }
if (!$this->bShowDebug){
.'.$this->sCssPrefix.'-info .content .total {font-size: 160%; color: rgba(0,0,0,0.5); margin: 0.3em 0; display: inline-block;}
return false;
}
.'.$this->sCssPrefix.'-messages {margin: 5em 2em 2em;}
$aData=$this->_prepareRendering();
.'.$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;}
$sOut='';
.'.$this->sCssPrefix.'-messages table{background: #fff; color: #222;table-layout:fixed; }
foreach ($aData['entries'] as $aLogentry){
.'.$this->sCssPrefix.'-messages table th{background: none;}
$sOut.=$aLogentry["timer"].' | '
.'.$this->sCssPrefix.'-messages table th.barcol{min-width: 7em; position: relative;}
.$aLogentry["delta"].' ms | '
.'.$this->sCssPrefix.'-messages table td{padding: 3px; vertical-align: top;}
.$aLogentry["level"].' | '
.'.$this->sCssPrefix.'-messages table th:hover{background:#aaa !important;}
.(sprintf("%01.3f", $aLogentry["memory"]/1024/1024)).' MB | '
.$aLogentry["message"].' '
.'.$this->sCssPrefix.'-level-info{background: #e0e8f8; color:#124}
. "\n"
.'.$this->sCssPrefix.'-level-warning{background: #fcf8e3; color: #980;}
;
.'.$this->sCssPrefix.'-level-error{background: #fce0e0; color: #944;}
}
.'.$this->sCssPrefix.'-maxrow{color:#f33; font-weight: bold;}
$sOut.="\nTotal time: ".$aData['totaltime'] . "\n";
</style>
return $sOut;
<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 id="'.$this->sCssPrefix.'-messages" class="'.$this->sCssPrefix.' '.$this->sCssPrefix.'-messages">
 
DEBUG :: LOG MESSAGES<br>'
 
. ($aData['errors'] ? '<span>Errors: '.$aData['errors'] . '</span><br>' : '')
 
. ($aData['warnings'] ? '<span>Warnings: '.$aData['warnings'] . '</span><br>' : '')
 
.'<br>
 
<table >
 
<thead>
 
<tr>
 
<th>#</th>
 
<th>level</th>
 
<th>time [s]</th>
 
<th class="barcol">delta</th>
 
<th class="barcol">memory</th>
 
<th>message</th>
 
</tr></thead><tbody>
 
' . $sOut . '</tbody></table>'
 
;
 
}
 
return $sOut;
 
}
 
/**
 
* render output of all logging messages for cli output
 
* @return string
 
*/
 
public function renderCli(){
 
if (!$this->bShowDebug){
 
return false;
 
}
 
$aData=$this->_prepareRendering();
 
 
$sOut='';
 
foreach ($aData['entries'] as $aLogentry){
 
$sOut.=$aLogentry["timer"].' | '
 
.$aLogentry["delta"].' ms | '
 
.$aLogentry["level"].' | '
 
.(sprintf("%01.3f", $aLogentry["memory"]/1024/1024)).' MB | '
 
.$aLogentry["message"].' '
 
. "\n"
 
;
 
}
 
$sOut.="\nTotal time: ".$aData['totaltime'] . "\n";
 
return $sOut;
 
}
 
}
Loading