Logger.php 8.17 KB
Newer Older
w  
Qiang Xue committed
1 2 3
<?php
/**
 * @link http://www.yiiframework.com/
Qiang Xue committed
4
 * @copyright Copyright (c) 2008 Yii Software LLC
w  
Qiang Xue committed
5 6 7 8
 * @license http://www.yiiframework.com/license/
 */

namespace yii\logging;
Qiang Xue committed
9 10 11

use \yii\base\Component;
use \yii\base\InvalidConfigException;
12

w  
Qiang Xue committed
13 14 15
/**
 * Logger records logged messages in memory.
 *
Qiang Xue committed
16 17
 * When the application ends or [[flushInterval]] is reached, Logger will call [[flush()]]
 * to send logged messages to different log targets, such as file, email, Web.
w  
Qiang Xue committed
18 19 20 21
 *
 * @author Qiang Xue <qiang.xue@gmail.com>
 * @since 2.0
 */
Qiang Xue committed
22
class Logger extends Component
w  
Qiang Xue committed
23
{
Qiang Xue committed
24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57
	/**
	 * Error message level. An error message is one that indicates the abnormal termination of the
	 * application and may require developer's handling.
	 */
	const LEVEL_ERROR = 0x01;
	/**
	 * Warning message level. A warning message is one that indicates some abnormal happens but
	 * the application is able to continue to run. Developers should pay attention to this message.
	 */
	const LEVEL_WARNING = 0x02;
	/**
	 * Informational message level. An informational message is one that includes certain information
	 * for developers to review.
	 */
	const LEVEL_INFO = 0x04;
	/**
	 * Tracing message level. An tracing message is one that reveals the code execution flow.
	 */
	const LEVEL_TRACE = 0x08;
	/**
	 * Profiling message level. This indicates the message is for profiling purpose.
	 */
	const LEVEL_PROFILE = 0x40;
	/**
	 * Profiling message level. This indicates the message is for profiling purpose. It marks the
	 * beginning of a profiling block.
	 */
	const LEVEL_PROFILE_BEGIN = 0x50;
	/**
	 * Profiling message level. This indicates the message is for profiling purpose. It marks the
	 * end of a profiling block.
	 */
	const LEVEL_PROFILE_END = 0x60;

w  
Qiang Xue committed
58 59 60 61 62 63

	/**
	 * @var integer how many messages should be logged before they are flushed from memory and sent to targets.
	 * Defaults to 1000, meaning the [[flush]] method will be invoked once every 1000 messages logged.
	 * Set this property to be 0 if you don't want to flush messages until the application terminates.
	 * This property mainly affects how much memory will be taken by the logged messages.
Qiang Xue committed
64
	 * A smaller value means less memory, but will increase the execution time due to the overhead of [[flush()]].
w  
Qiang Xue committed
65 66 67
	 */
	public $flushInterval = 1000;
	/**
Qiang Xue committed
68
	 * @var array logged messages. This property is mainly managed by [[log()]] and [[flush()]].
w  
Qiang Xue committed
69 70 71 72
	 * Each log message is of the following structure:
	 *
	 * ~~~
	 * array(
Qiang Xue committed
73
	 *   [0] => message (mixed, can be a string or some complex data, such as an exception object)
Qiang Xue committed
74
	 *   [1] => level (integer)
w  
Qiang Xue committed
75 76 77 78
	 *   [2] => category (string)
	 *   [3] => timestamp (float, obtained by microtime(true))
	 * )
	 * ~~~
w  
Qiang Xue committed
79 80
	 */
	public $messages = array();
Qiang Xue committed
81 82 83 84
	/**
	 * @var Router the log target router registered with this logger.
	 */
	public $router;
Qiang Xue committed
85

w  
Qiang Xue committed
86

87 88 89 90 91 92
	/**
	 * @var string
	 */
	private $_tag;


Qiang Xue committed
93 94 95 96 97 98 99 100 101
	/**
	 * Initializes the logger by registering [[flush()]] as a shutdown function.
	 */
	public function init()
	{
		parent::init();
		register_shutdown_function(array($this, 'flush'), true);
	}

w  
Qiang Xue committed
102 103 104 105 106
	/**
	 * Logs a message with the given type and category.
	 * If `YII_DEBUG` is true and `YII_TRACE_LEVEL` is greater than 0, then additional
	 * call stack information about application code will be appended to the message.
	 * @param string $message the message to be logged.
Qiang Xue committed
107 108 109
	 * @param integer $level the level of the message. This must be one of the following:
	 * `Logger::LEVEL_ERROR`, `Logger::LEVEL_WARNING`, `Logger::LEVEL_INFO`, `Logger::LEVEL_TRACE`,
	 * `Logger::LEVEL_PROFILE_BEGIN`, `Logger::LEVEL_PROFILE_END`.
w  
Qiang Xue committed
110 111
	 * @param string $category the category of the message.
	 */
Qiang Xue committed
112
	public function log($message, $level, $category = 'application')
w  
Qiang Xue committed
113
	{
Qiang Xue committed
114 115
		$time = microtime(true);
		if (YII_DEBUG && YII_TRACE_LEVEL > 0) {
w  
Qiang Xue committed
116 117 118
			$traces = debug_backtrace();
			$count = 0;
			foreach ($traces as $trace) {
Qiang Xue committed
119
				if (isset($trace['file'], $trace['line']) && strpos($trace['file'], YII_PATH) !== 0) {
Qiang Xue committed
120
					$message .= "\nin {$trace['file']} ({$trace['line']})";
w  
Qiang Xue committed
121 122 123 124 125 126
					if (++$count >= YII_TRACE_LEVEL) {
						break;
					}
				}
			}
		}
Qiang Xue committed
127
		$this->messages[] = array($message, $level, $category, $time);
128
		if ($this->flushInterval > 0 && count($this->messages) >= $this->flushInterval) {
Qiang Xue committed
129
			$this->flush();
w  
Qiang Xue committed
130 131 132 133
		}
	}

	/**
134
	 * Flushes log messages from memory to targets.
Qiang Xue committed
135
	 * This method will trigger an [[EVENT_FLUSH]] or [[EVENT_FINAL_FLUSH]] event depending on the $final value.
Qiang Xue committed
136
	 * @param boolean $final whether this is a final call during a request.
w  
Qiang Xue committed
137
	 */
Qiang Xue committed
138
	public function flush($final = false)
w  
Qiang Xue committed
139
	{
Qiang Xue committed
140 141 142
		if ($this->router) {
			$this->router->dispatch($this->messages, $final);
		}
w  
Qiang Xue committed
143
		$this->messages = array();
w  
Qiang Xue committed
144 145
	}

Qiang Xue committed
146 147 148 149 150 151 152 153 154 155 156 157 158 159 160 161 162 163 164
	/**
	 * @return string a tag that uniquely identifies the current request.
	 */
	public function getTag()
	{
		if ($this->_tag === null) {
			$this->_tag = date('Ymd-His', microtime(true));
		}
		return $this->_tag;
	}

	/**
	 * @param string $tag a tag that uniquely identifies the current request.
	 */
	public function setTag($tag)
	{
		$this->_tag = $tag;
	}

w  
Qiang Xue committed
165 166 167 168 169 170 171
	/**
	 * Returns the total elapsed time since the start of the current request.
	 * This method calculates the difference between now and the timestamp
	 * defined by constant `YII_BEGIN_TIME` which is evaluated at the beginning
	 * of [[YiiBase]] class file.
	 * @return float the total elapsed time in seconds for current request.
	 */
Qiang Xue committed
172
	public function getElapsedTime()
w  
Qiang Xue committed
173 174 175 176 177 178
	{
		return microtime(true) - YII_BEGIN_TIME;
	}

	/**
	 * Returns the profiling results.
w  
Qiang Xue committed
179 180 181 182 183 184 185 186
	 *
	 * By default, all profiling results will be returned. You may provide
	 * `$categories` and `$excludeCategories` as parameters to retrieve the
	 * results that you are interested in.
	 *
	 * @param array $categories list of categories that you are interested in.
	 * You can use an asterisk at the end of a category to do a prefix match.
	 * For example, 'yii\db\*' will match categories starting with 'yii\db\',
Qiang Xue committed
187
	 * such as 'yii\db\Connection'.
188
	 * @param array $excludeCategories list of categories that you want to exclude
w  
Qiang Xue committed
189
	 * @return array the profiling results. Each array element has the following structure:
Qiang Xue committed
190
	 *  `array($token, $category, $time)`.
w  
Qiang Xue committed
191
	 */
w  
Qiang Xue committed
192
	public function getProfiling($categories = array(), $excludeCategories = array())
w  
Qiang Xue committed
193
	{
w  
Qiang Xue committed
194 195 196
		$timings = $this->calculateTimings();
		if (empty($categories) && empty($excludeCategories)) {
			return $timings;
w  
Qiang Xue committed
197
		}
w  
Qiang Xue committed
198 199 200 201 202

		foreach ($timings as $i => $timing) {
			$matched = empty($categories);
			foreach ($categories as $category) {
				$prefix = rtrim($category, '*');
Qiang Xue committed
203
				if (strpos($timing[1], $prefix) === 0 && ($timing[1] === $category || $prefix !== $category)) {
w  
Qiang Xue committed
204 205 206 207 208 209 210 211 212
					$matched = true;
					break;
				}
			}

			if ($matched) {
				foreach ($excludeCategories as $category) {
					$prefix = rtrim($category, '*');
					foreach ($timings as $i => $timing) {
Qiang Xue committed
213
						if (strpos($timing[1], $prefix) === 0 && ($timing[1] === $category || $prefix !== $category)) {
w  
Qiang Xue committed
214 215 216 217 218 219 220 221 222
							$matched = false;
							break;
						}
					}
				}
			}

			if (!$matched) {
				unset($timings[$i]);
w  
Qiang Xue committed
223 224
			}
		}
w  
Qiang Xue committed
225
		return array_values($timings);
w  
Qiang Xue committed
226 227
	}

228 229 230 231 232 233 234 235 236 237 238 239 240 241 242 243 244 245
	/**
	 * Returns the statistical results of DB queries.
	 * The results returned include the number of SQL statements executed and
	 * the total time spent.
	 * @return array the first element indicates the number of SQL statements executed,
	 * and the second element the total time spent in SQL execution.
	 */
	public function getDbProfiling()
	{
		$timings = $this->getProfiling(array('yii\db\Command::query', 'yii\db\Command::execute'));
		$count = count($timings);
		$time = 0;
		foreach ($timings as $timing) {
			$time += $timing[1];
		}
		return array($count, $time);
	}

w  
Qiang Xue committed
246 247
	private function calculateTimings()
	{
w  
Qiang Xue committed
248
		$timings = array();
w  
Qiang Xue committed
249 250 251

		$stack = array();
		foreach ($this->messages as $log) {
Qiang Xue committed
252 253
			list($token, $level, $category, $timestamp) = $log;
			if ($level == self::LEVEL_PROFILE_BEGIN) {
w  
Qiang Xue committed
254
				$stack[] = $log;
Qiang Xue committed
255
			} elseif ($level == self::LEVEL_PROFILE_END) {
Qiang Xue committed
256 257 258
				if (($last = array_pop($stack)) !== null && $last[0] === $token) {
					$timings[] = array($token, $category, $timestamp - $last[3]);
				} else {
Qiang Xue committed
259
					throw new InvalidConfigException("Unmatched profiling block: $token");
w  
Qiang Xue committed
260 261 262 263 264 265 266
				}
			}
		}

		$now = microtime(true);
		while (($last = array_pop($stack)) !== null) {
			$delta = $now - $last[3];
Qiang Xue committed
267
			$timings[] = array($last[0], $last[2], $delta);
w  
Qiang Xue committed
268 269
		}

w  
Qiang Xue committed
270
		return $timings;
w  
Qiang Xue committed
271 272
	}
}