se/SE/se-lib/DebugExecutionTime.php

<?php

/* usage 1 - log to memory and print report:
	Lib::loadClass('DebugExecutionTime');
	$dbgExecTime = new DebugExecutionTime();
	$dbgExecTime->activate();
	$dbgExecTime->log('start');
	...
	$dbgExecTime->log('end');
	$dbgExecTime->printDebug();
*/
/* usage 2 - log to file:
	Lib::loadClass('DebugExecutionTime');
	$dbgExecTime = new DebugExecutionTime();
	$dbgExecTime->setLogFile('UNIQ_FILE_NAME', $format = 'csv'); // $format: 'csv', 'json'
	$dbgExecTime->logToFile('start');
	...
	$dbgExecTime->logToFile('end');
*/
class DebugExecutionTime {

	private $_log = array();
	private $_logByGroups = array();
	private $_isActive = false;
	private $_lastTime = 0;
	private $_logFile = null;
	private $_logFormat = null;

	public function __construct() {
		$this->_log = array();
	}

	public function activate() {
		$this->_isActive = true;
	}

	public function setLogFile($fileName, $format = 'csv') { // @param $format = 'csv', 'json'
		if (!file_exists($fileName)) @touch($fileName);
		if (!file_exists($fileName)) return; // log error?
		$this->_logFile = $fileName;
		switch ($format) {
			case 'json'; $this->_logFormat = 'json'; break;
			default: $this->_logFormat = 'csv';
		}
	}

	public function logToFile($msg) {
		if (!$this->_logFile) return;
		static $_idRequest = null;
		static $_lastMicroTime = null;
		// $timeDiff = (!$lastTime)
		// ? ''
		// : V::milisecondsStringDiff($dbg['date'], $lastTime); // TODO: $dbg['date'] - $lastTime;
		$microTime = date("Y-m-d H:i:s") . substr((string)microtime(), 1, 6);
		$info = [
			'date' => $microTime,
			'diff' => ($_lastMicroTime) ? V::milisecondsStringDiff($microTime, $_lastMicroTime) : '',
			'req' => $_idRequest,
			'mem' => memory_get_usage(true),
			'msg' => $msg,
		];
		$_lastMicroTime = $microTime;
		if (null === $_idRequest && 'csv' === $this->_logFormat) {
			error_log(
				implode("\t", array_keys($info)) . "\n"
				, 3
				, $this->_logFile
			);
		}
		if (null === $_idRequest) {
			$_idRequest = substr(md5(date("Y-m-d") . Request::getUserIp() . V::get('REQUEST_TIME', '', $_SERVER)), 0, 6);
			$info['req'] = $_idRequest;
		}
		switch ($this->_logFormat) {
			case 'csv': {
				error_log(
					implode("\t", array_values($info)) . "\n"
					, 3
					, $this->_logFile
				);
			} break;
			case 'json': {
				error_log(
					json_encode($info) . "\n"
					, 3
					, $this->_logFile
				);
			} break;
		}
	}

	/*
	 * @param $msg string or NULL (NULL to log only group stats)
	 */
	public function log($msg, $groups = array()) {
		if (!$this->_isActive) return;
		$curTime = microtime(true);
		$execTime = (!$this->_lastTime)? 0 : $curTime - $this->_lastTime;
		$this->_lastTime = $curTime;

		$this->_log[] = array($msg, $execTime);

		foreach ($groups as $group) {
			if (!array_key_exists($group, $this->_logByGroups)) $this->_logByGroups[$group] = 0;
			$this->_logByGroups[$group] += $execTime;
		}
	}

	public function getLastExecTime() {
		if (!$this->_isActive) return null;
		$logTotal = count($this->_log);
		if ($logTotal < 2) return null;
		return $this->_log[$logTotal - 1][1];
	}

	public function getTotalExecTime() {
		if (!$this->_isActive) return null;
		$logTotal = count($this->_log);
		if ($logTotal < 2) return null;
		$sumExecTime = 0;
		foreach ($this->_log as $log) $sumExecTime += $log[1];
		return $sumExecTime;
	}

	public function printDebug() {
		if (!$this->_isActive) return;
		$sumExecTime = 0;
		foreach ($this->_log as $log) $sumExecTime += $log[1];
		?>
		<table>
			<tr>
				<td style="vertical-align:top;">
					<div style="max-height:300px;overflow:auto">
		<table style="text-align:left;" border="1" cellspacing="0" cellpadding="1">
			<thead>
				<tr>
					<th>msg</th>
					<th>time</th>
				</tr>
			</thead>
			<tfoot>
				<th style="text-align:right">total:</th>
				<th style="font-family:monospace;text-align:right;font-weight:bold;"><?php echo number_format($sumExecTime, 6); ?></th>
			</tfoot>
			<tbody>
				<?php foreach ($this->_log as $log) : ?>
					<?php if (null === $log[0]) continue; ?>
					<tr>
						<td><?php echo $log[0]; ?></td>
						<td style="font-family:monospace;text-align:right;"><?php echo number_format($log[1], 6); ?></td>
					</tr>
				<?php endforeach; ?>
			</tbody>
		</table>
					</div>
				</td>
				<td style="vertical-align:top;">

		<?php if (!empty($this->_logByGroups)) : ?>
		<table style="text-align:left;" border="1" cellspacing="0" cellpadding="1">
			<thead>
				<tr>
					<th>group</th>
					<th>time</th>
					<th>time left</th>
					<th>time %</th>
				</tr>
			</thead>
			<tbody>
				<?php foreach ($this->_logByGroups as $group => $execTime) : ?>
					<tr>
						<th><?php echo $group; ?></th>
						<td style="font-family:monospace;text-align:right;"><?php echo number_format($execTime, 6); ?></td>
						<td style="font-family:monospace;text-align:right;"><?php echo number_format($sumExecTime - $execTime, 6); ?></td>
						<td style="font-family:monospace;text-align:right;"><?php echo (!$execTime)? 0 : round($execTime * 100 / $sumExecTime); ?>%</td>
					</tr>
				<?php endforeach; ?>
			</tbody>
		</table>
		<?php endif; ?>

				</td>
			</tr>
		</table>
		<?php
	}

}