Logger.php 8.98 KB
Newer Older
w  
Qiang Xue committed
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19
<?php
/**
 * Logger class file
 *
 * @author Qiang Xue <qiang.xue@gmail.com>
 * @link http://www.yiiframework.com/
 * @copyright Copyright &copy; 2008-2012 Yii Software LLC
 * @license http://www.yiiframework.com/license/
 */

namespace yii\logging;

/**
 * Logger records logged messages in memory.
 *
 * When [[flushInterval]] is reached or when application terminates, it will
 * call [[flush]] to send logged messages to different log targets, such as
 * file, email, Web.
 *
20 21 22 23
 * Logger provides a set of events for further customization:
 *
 * - `flush`. Raised on logs flush.
 *
w  
Qiang Xue committed
24 25 26 27 28
 * @author Qiang Xue <qiang.xue@gmail.com>
 * @since 2.0
 */
class Logger extends \yii\base\Component
{
Qiang Xue committed
29 30 31 32 33 34
	const LEVEL_ERROR = 'error';
	const LEVEL_WARNING = 'warning';
	const LEVEL_INFO = 'info';
	const LEVEL_TRACE = 'trace';
	const LEVEL_PROFILE_BEGIN = 'profile-begin';
	const LEVEL_PROFILE_END = 'profile-end';
w  
Qiang Xue committed
35 36 37 38 39 40 41 42 43 44 45

	/**
	 * @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.
	 * A smaller value means less memory, but will increase the execution time due to the overhead of [[flush]].
	 */
	public $flushInterval = 1000;
	/**
	 * @var boolean this property will be passed as the parameter to [[flush]] when it is
w  
Qiang Xue committed
46 47 48
	 * called due to the [[flushInterval]] is reached. Defaults to true, meaning the flushed
	 * messages will be exported to the actual storage medium (e.g. DB, email) defined by each
	 * log target. If false, the flushed messages will be kept in the memory of each log target.
w  
Qiang Xue committed
49 50
	 * @see flushInterval
	 */
w  
Qiang Xue committed
51
	public $autoExport = true;
w  
Qiang Xue committed
52 53
	/**
	 * @var array logged messages. This property is mainly managed by [[log]] and [[flush]].
w  
Qiang Xue committed
54 55 56 57 58 59 60 61 62 63
	 * Each log message is of the following structure:
	 *
	 * ~~~
	 * array(
	 *   [0] => message (string)
	 *   [1] => level (string)
	 *   [2] => category (string)
	 *   [3] => timestamp (float, obtained by microtime(true))
	 * )
	 * ~~~
w  
Qiang Xue committed
64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97
	 */
	public $messages = array();

	/**
	 * Logs an error message.
	 * An error message is typically logged when an unrecoverable error occurs
	 * during the execution of an application.
	 * @param string $message the message to be logged.
	 * @param string $category the category of the message.
	 */
	public function error($message, $category = 'application')
	{
		$this->log($message, self::LEVEL_ERROR, $category);
	}

	/**
	 * Logs a trace message.
	 * Trace messages are logged mainly for development purpose to see
	 * the execution work flow of some code.
	 * @param string $message the message to be logged.
	 * @param string $category the category of the message.
	 */
	public function trace($message, $category = 'application')
	{
		$this->log($message, self::LEVEL_TRACE, $category);
	}

	/**
	 * Logs a warning message.
	 * A warning message is typically logged when an error occurs while the execution
	 * can still continue.
	 * @param string $message the message to be logged.
	 * @param string $category the category of the message.
	 */
w  
Qiang Xue committed
98
	public function warning($message, $category = 'application')
w  
Qiang Xue committed
99 100 101 102 103 104 105 106 107 108 109 110 111 112 113 114 115 116 117 118
	{
		$this->log($message, self::LEVEL_TRACE, $category);
	}

	/**
	 * Logs an informative message.
	 * An informative message is typically logged by an application to keep record of
	 * something important (e.g. an administrator logs in).
	 * @param string $message the message to be logged.
	 * @param string $category the category of the message.
	 */
	public function info($message, $category = 'application')
	{
		$this->log($message, self::LEVEL_TRACE, $category);
	}

	/**
	 * Marks the beginning of a code block for profiling.
	 * This has to be matched with a call to [[endProfile]] with the same category name.
	 * The begin- and end- calls must also be properly nested. For example,
Qiang Xue committed
119 120
	 * @param string $token token for the code block
	 * @param string $category the category of this log message
w  
Qiang Xue committed
121 122
	 * @see endProfile
	 */
Qiang Xue committed
123
	public function beginProfile($token, $category)
w  
Qiang Xue committed
124
	{
Qiang Xue committed
125
		$this->log($token, self::LEVEL_PROFILE_BEGIN, $category);
w  
Qiang Xue committed
126 127 128 129 130
	}

	/**
	 * Marks the end of a code block for profiling.
	 * This has to be matched with a previous call to [[beginProfile]] with the same category name.
Qiang Xue committed
131 132
	 * @param string $token token for the code block
	 * @param string $category the category of this log message
w  
Qiang Xue committed
133 134
	 * @see beginProfile
	 */
Qiang Xue committed
135
	public function endProfile($token, $category)
w  
Qiang Xue committed
136
	{
Qiang Xue committed
137
		$this->log($token, self::LEVEL_PROFILE_END, $category);
w  
Qiang Xue committed
138 139 140 141 142 143 144 145
	}

	/**
	 * 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.
	 * @param string $level the level of the message. This must be one of the following:
w  
Qiang Xue committed
146
	 * 'trace', 'info', 'warning', 'error', 'profile'.
w  
Qiang Xue committed
147 148 149 150
	 * @param string $category the category of the message.
	 */
	public function log($message, $level, $category)
	{
Qiang Xue committed
151
		if (YII_DEBUG && YII_TRACE_LEVEL > 0 && $level <= self::LEVEL_TRACE) {
w  
Qiang Xue committed
152 153 154
			$traces = debug_backtrace();
			$count = 0;
			foreach ($traces as $trace) {
Qiang Xue committed
155
				if (isset($trace['file'], $trace['line']) && strpos($trace['file'], YII_PATH) !== 0) {
w  
Qiang Xue committed
156 157 158 159 160 161 162 163 164 165 166 167 168 169 170
					$message .= "\nin " . $trace['file'] . ' (' . $trace['line'] . ')';
					if (++$count >= YII_TRACE_LEVEL) {
						break;
					}
				}
			}
		}

		$this->messages[] = array($message, $level, $category, microtime(true));
		if (count($this->messages) >= $this->flushInterval && $this->flushInterval > 0) {
			$this->flush($this->autoExport);
		}
	}

	/**
w  
Qiang Xue committed
171
	 * Removes all recorded messages from the memory.
172
	 * This method will raise a `flush` event.
w  
Qiang Xue committed
173 174
	 * The attached event handlers can process the log messages before they are removed.
	 * @param boolean $export whether to notify log targets to export the filtered messages they have received.
w  
Qiang Xue committed
175
	 */
w  
Qiang Xue committed
176
	public function flush($export = false)
w  
Qiang Xue committed
177
	{
w  
Qiang Xue committed
178 179
		$this->onFlush(new \yii\base\Event($this, array('export' => $export, 'flush' => true)));
		$this->messages = array();
w  
Qiang Xue committed
180 181 182
	}

	/**
183
	 * Raises a `flush` event.
w  
Qiang Xue committed
184
	 * @param \yii\base\Event $event the event parameter
w  
Qiang Xue committed
185
	 */
w  
Qiang Xue committed
186
	public function onFlush($event)
w  
Qiang Xue committed
187
	{
188
		$this->trigger('flush', $event);
w  
Qiang Xue committed
189 190 191 192 193 194 195 196 197 198 199 200 201 202 203 204
	}

	/**
	 * 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.
	 */
	public function getExecutionTime()
	{
		return microtime(true) - YII_BEGIN_TIME;
	}

	/**
	 * Returns the profiling results.
w  
Qiang Xue committed
205 206 207 208 209 210 211 212 213 214 215
	 *
	 * 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\',
	 * such as 'yii\db\dao\Connection'.
	 * @param array $excludeCategories list of categories that you are interested in.
	 * @return array the profiling results. Each array element has the following structure:
Qiang Xue committed
216
	 *  `array($token, $category, $time)`.
w  
Qiang Xue committed
217
	 */
w  
Qiang Xue committed
218
	public function getProfiling($categories = array(), $excludeCategories = array())
w  
Qiang Xue committed
219
	{
w  
Qiang Xue committed
220 221 222
		$timings = $this->calculateTimings();
		if (empty($categories) && empty($excludeCategories)) {
			return $timings;
w  
Qiang Xue committed
223
		}
w  
Qiang Xue committed
224 225 226 227 228

		foreach ($timings as $i => $timing) {
			$matched = empty($categories);
			foreach ($categories as $category) {
				$prefix = rtrim($category, '*');
Qiang Xue committed
229
				if (strpos($timing[1], $prefix) === 0 && ($timing[1] === $category || $prefix !== $category)) {
w  
Qiang Xue committed
230 231 232 233 234 235 236 237 238
					$matched = true;
					break;
				}
			}

			if ($matched) {
				foreach ($excludeCategories as $category) {
					$prefix = rtrim($category, '*');
					foreach ($timings as $i => $timing) {
Qiang Xue committed
239
						if (strpos($timing[1], $prefix) === 0 && ($timing[1] === $category || $prefix !== $category)) {
w  
Qiang Xue committed
240 241 242 243 244 245 246 247 248
							$matched = false;
							break;
						}
					}
				}
			}

			if (!$matched) {
				unset($timings[$i]);
w  
Qiang Xue committed
249 250
			}
		}
w  
Qiang Xue committed
251
		return array_values($timings);
w  
Qiang Xue committed
252 253 254 255
	}

	private function calculateTimings()
	{
w  
Qiang Xue committed
256
		$timings = array();
w  
Qiang Xue committed
257 258 259

		$stack = array();
		foreach ($this->messages as $log) {
Qiang Xue committed
260
			if ($log[1] === self::LEVEL_PROFILE_BEGIN) {
w  
Qiang Xue committed
261
				$stack[] = $log;
Qiang Xue committed
262 263
			} elseif ($log[1] === self::LEVEL_PROFILE_END) {
				list($token, $level, $category, $timestamp) = $log;
Qiang Xue committed
264 265 266 267
				if (($last = array_pop($stack)) !== null && $last[0] === $token) {
					$timings[] = array($token, $category, $timestamp - $last[3]);
				} else {
					throw new \yii\base\Exception("Unmatched profiling block: $token");
w  
Qiang Xue committed
268 269 270 271 272 273 274
				}
			}
		}

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

w  
Qiang Xue committed
278
		return $timings;
w  
Qiang Xue committed
279 280 281
	}

}