Logger.php 8.09 KB
Newer Older
w  
Qiang Xue committed
1 2 3 4 5
<?php
/**
 * Logger class file
 *
 * @link http://www.yiiframework.com/
Qiang Xue committed
6
 * @copyright Copyright &copy; 2008 Yii Software LLC
w  
Qiang Xue committed
7 8 9 10 11 12 13 14 15 16 17 18
 * @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.
 *
19 20 21 22
 * Logger provides a set of events for further customization:
 *
 * - `flush`. Raised on logs flush.
 *
w  
Qiang Xue committed
23 24 25 26 27
 * @author Qiang Xue <qiang.xue@gmail.com>
 * @since 2.0
 */
class Logger extends \yii\base\Component
{
Qiang Xue committed
28 29 30 31 32 33
	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
34 35 36 37 38 39

	/**
	 * @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
40
	 * A smaller value means less memory, but will increase the execution time due to the overhead of [[flush()]].
w  
Qiang Xue committed
41 42 43
	 */
	public $flushInterval = 1000;
	/**
Qiang Xue committed
44
	 * @var array logged messages. This property is mainly managed by [[log()]] and [[flush()]].
w  
Qiang Xue committed
45 46 47 48
	 * Each log message is of the following structure:
	 *
	 * ~~~
	 * array(
Qiang Xue committed
49
	 *   [0] => message (mixed)
w  
Qiang Xue committed
50 51 52 53 54
	 *   [1] => level (string)
	 *   [2] => category (string)
	 *   [3] => timestamp (float, obtained by microtime(true))
	 * )
	 * ~~~
w  
Qiang Xue committed
55 56 57 58 59 60 61
	 */
	public $messages = array();

	/**
	 * Logs an error message.
	 * An error message is typically logged when an unrecoverable error occurs
	 * during the execution of an application.
Qiang Xue committed
62
	 * @param mixed $message the message to be logged.
w  
Qiang Xue committed
63 64 65 66 67 68 69 70 71 72 73
	 * @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.
Qiang Xue committed
74
	 * @param mixed $message the message to be logged.
w  
Qiang Xue committed
75 76 77 78 79 80 81 82 83 84 85
	 * @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.
Qiang Xue committed
86
	 * @param mixed $message the message to be logged.
w  
Qiang Xue committed
87 88
	 * @param string $category the category of the message.
	 */
w  
Qiang Xue committed
89
	public function warning($message, $category = 'application')
w  
Qiang Xue committed
90
	{
Qiang Xue committed
91
		$this->log($message, self::LEVEL_WARNING, $category);
w  
Qiang Xue committed
92 93 94 95 96 97
	}

	/**
	 * 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).
Qiang Xue committed
98
	 * @param mixed $message the message to be logged.
w  
Qiang Xue committed
99 100 101 102
	 * @param string $category the category of the message.
	 */
	public function info($message, $category = 'application')
	{
Qiang Xue committed
103
		$this->log($message, self::LEVEL_INFO, $category);
w  
Qiang Xue committed
104 105 106 107 108 109
	}

	/**
	 * 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
110 111
	 * @param string $token token for the code block
	 * @param string $category the category of this log message
w  
Qiang Xue committed
112 113
	 * @see endProfile
	 */
Qiang Xue committed
114
	public function beginProfile($token, $category = 'application')
w  
Qiang Xue committed
115
	{
Qiang Xue committed
116
		$this->log($token, self::LEVEL_PROFILE_BEGIN, $category);
w  
Qiang Xue committed
117 118 119 120 121
	}

	/**
	 * 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
122 123
	 * @param string $token token for the code block
	 * @param string $category the category of this log message
w  
Qiang Xue committed
124 125
	 * @see beginProfile
	 */
Qiang Xue committed
126
	public function endProfile($token, $category = 'application')
w  
Qiang Xue committed
127
	{
Qiang Xue committed
128
		$this->log($token, self::LEVEL_PROFILE_END, $category);
w  
Qiang Xue committed
129 130 131 132 133 134 135 136
	}

	/**
	 * 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
137
	 * 'trace', 'info', 'warning', 'error', 'profile'.
w  
Qiang Xue committed
138 139
	 * @param string $category the category of the message.
	 */
Qiang Xue committed
140
	public function log($message, $level, $category = 'application')
w  
Qiang Xue committed
141
	{
Qiang Xue committed
142 143
		$time = microtime(true);
		if (YII_DEBUG && YII_TRACE_LEVEL > 0) {
w  
Qiang Xue committed
144 145 146
			$traces = debug_backtrace();
			$count = 0;
			foreach ($traces as $trace) {
Qiang Xue committed
147
				if (isset($trace['file'], $trace['line']) && strpos($trace['file'], YII_PATH) !== 0) {
Qiang Xue committed
148
					$message .= "\nin {$trace['file']} ({$trace['line']})";
w  
Qiang Xue committed
149 150 151 152 153 154
					if (++$count >= YII_TRACE_LEVEL) {
						break;
					}
				}
			}
		}
Qiang Xue committed
155
		$this->messages[] = array($message, $level, $category, $time);
w  
Qiang Xue committed
156
		if (count($this->messages) >= $this->flushInterval && $this->flushInterval > 0) {
Qiang Xue committed
157
			$this->flush();
w  
Qiang Xue committed
158 159 160 161
		}
	}

	/**
w  
Qiang Xue committed
162
	 * Removes all recorded messages from the memory.
163
	 * This method will raise a `flush` event.
w  
Qiang Xue committed
164
	 */
Qiang Xue committed
165
	public function flush()
w  
Qiang Xue committed
166
	{
Qiang Xue committed
167
		$this->trigger('flush');
w  
Qiang Xue committed
168
		$this->messages = array();
w  
Qiang Xue committed
169 170 171 172 173 174 175 176 177 178 179 180 181 182 183 184
	}

	/**
	 * 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
185 186 187 188 189 190 191 192
	 *
	 * 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
193
	 * such as 'yii\db\Connection'.
w  
Qiang Xue committed
194 195
	 * @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
196
	 *  `array($token, $category, $time)`.
w  
Qiang Xue committed
197
	 */
w  
Qiang Xue committed
198
	public function getProfiling($categories = array(), $excludeCategories = array())
w  
Qiang Xue committed
199
	{
w  
Qiang Xue committed
200 201 202
		$timings = $this->calculateTimings();
		if (empty($categories) && empty($excludeCategories)) {
			return $timings;
w  
Qiang Xue committed
203
		}
w  
Qiang Xue committed
204 205 206 207 208

		foreach ($timings as $i => $timing) {
			$matched = empty($categories);
			foreach ($categories as $category) {
				$prefix = rtrim($category, '*');
Qiang Xue committed
209
				if (strpos($timing[1], $prefix) === 0 && ($timing[1] === $category || $prefix !== $category)) {
w  
Qiang Xue committed
210 211 212 213 214 215 216 217 218
					$matched = true;
					break;
				}
			}

			if ($matched) {
				foreach ($excludeCategories as $category) {
					$prefix = rtrim($category, '*');
					foreach ($timings as $i => $timing) {
Qiang Xue committed
219
						if (strpos($timing[1], $prefix) === 0 && ($timing[1] === $category || $prefix !== $category)) {
w  
Qiang Xue committed
220 221 222 223 224 225 226 227 228
							$matched = false;
							break;
						}
					}
				}
			}

			if (!$matched) {
				unset($timings[$i]);
w  
Qiang Xue committed
229 230
			}
		}
w  
Qiang Xue committed
231
		return array_values($timings);
w  
Qiang Xue committed
232 233 234 235
	}

	private function calculateTimings()
	{
w  
Qiang Xue committed
236
		$timings = array();
w  
Qiang Xue committed
237 238 239

		$stack = array();
		foreach ($this->messages as $log) {
Qiang Xue committed
240
			if ($log[1] === self::LEVEL_PROFILE_BEGIN) {
w  
Qiang Xue committed
241
				$stack[] = $log;
Qiang Xue committed
242 243
			} elseif ($log[1] === self::LEVEL_PROFILE_END) {
				list($token, $level, $category, $timestamp) = $log;
Qiang Xue committed
244 245 246 247
				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
248 249 250 251 252 253 254
				}
			}
		}

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

w  
Qiang Xue committed
258
		return $timings;
w  
Qiang Xue committed
259 260 261
	}

}