You can not select more than 25 topics Topics must start with a letter or number, can include dashes ('-') and can be up to 35 characters long.

316 lines
12KB

  1. <?php
  2. /**
  3. * @link http://www.yiiframework.com/
  4. * @copyright Copyright (c) 2008 Yii Software LLC
  5. * @license http://www.yiiframework.com/license/
  6. */
  7. namespace yii\log;
  8. use Yii;
  9. use yii\base\Component;
  10. /**
  11. * Logger records logged messages in memory and sends them to different targets if [[dispatcher]] is set.
  12. *
  13. * A Logger instance can be accessed via `Yii::getLogger()`. You can call the method [[log()]] to record a single log message.
  14. * For convenience, a set of shortcut methods are provided for logging messages of various severity levels
  15. * via the [[Yii]] class:
  16. *
  17. * - [[Yii::trace()]]
  18. * - [[Yii::error()]]
  19. * - [[Yii::warning()]]
  20. * - [[Yii::info()]]
  21. * - [[Yii::beginProfile()]]
  22. * - [[Yii::endProfile()]]
  23. *
  24. * When the application ends or [[flushInterval]] is reached, Logger will call [[flush()]]
  25. * to send logged messages to different log targets, such as [[FileTarget|file]], [[EmailTarget|email]],
  26. * or [[DbTarget|database]], with the help of the [[dispatcher]].
  27. *
  28. * @property array $dbProfiling The first element indicates the number of SQL statements executed, and the
  29. * second element the total time spent in SQL execution. This property is read-only.
  30. * @property float $elapsedTime The total elapsed time in seconds for current request. This property is
  31. * read-only.
  32. * @property array $profiling The profiling results. Each element is an array consisting of these elements:
  33. * `info`, `category`, `timestamp`, `trace`, `level`, `duration`. This property is read-only.
  34. *
  35. * @author Qiang Xue <qiang.xue@gmail.com>
  36. * @since 2.0
  37. */
  38. class Logger extends Component
  39. {
  40. /**
  41. * Error message level. An error message is one that indicates the abnormal termination of the
  42. * application and may require developer's handling.
  43. */
  44. const LEVEL_ERROR = 0x01;
  45. /**
  46. * Warning message level. A warning message is one that indicates some abnormal happens but
  47. * the application is able to continue to run. Developers should pay attention to this message.
  48. */
  49. const LEVEL_WARNING = 0x02;
  50. /**
  51. * Informational message level. An informational message is one that includes certain information
  52. * for developers to review.
  53. */
  54. const LEVEL_INFO = 0x04;
  55. /**
  56. * Tracing message level. An tracing message is one that reveals the code execution flow.
  57. */
  58. const LEVEL_TRACE = 0x08;
  59. /**
  60. * Profiling message level. This indicates the message is for profiling purpose.
  61. */
  62. const LEVEL_PROFILE = 0x40;
  63. /**
  64. * Profiling message level. This indicates the message is for profiling purpose. It marks the
  65. * beginning of a profiling block.
  66. */
  67. const LEVEL_PROFILE_BEGIN = 0x50;
  68. /**
  69. * Profiling message level. This indicates the message is for profiling purpose. It marks the
  70. * end of a profiling block.
  71. */
  72. const LEVEL_PROFILE_END = 0x60;
  73. /**
  74. * @var array logged messages. This property is managed by [[log()]] and [[flush()]].
  75. * Each log message is of the following structure:
  76. *
  77. * ```
  78. * [
  79. * [0] => message (mixed, can be a string or some complex data, such as an exception object)
  80. * [1] => level (integer)
  81. * [2] => category (string)
  82. * [3] => timestamp (float, obtained by microtime(true))
  83. * [4] => traces (array, debug backtrace, contains the application code call stacks)
  84. * ]
  85. * ```
  86. */
  87. public $messages = [];
  88. /**
  89. * @var integer how many messages should be logged before they are flushed from memory and sent to targets.
  90. * Defaults to 1000, meaning the [[flush]] method will be invoked once every 1000 messages logged.
  91. * Set this property to be 0 if you don't want to flush messages until the application terminates.
  92. * This property mainly affects how much memory will be taken by the logged messages.
  93. * A smaller value means less memory, but will increase the execution time due to the overhead of [[flush()]].
  94. */
  95. public $flushInterval = 1000;
  96. /**
  97. * @var integer how much call stack information (file name and line number) should be logged for each message.
  98. * If it is greater than 0, at most that number of call stacks will be logged. Note that only application
  99. * call stacks are counted.
  100. */
  101. public $traceLevel = 0;
  102. /**
  103. * @var Dispatcher the message dispatcher
  104. */
  105. public $dispatcher;
  106. /**
  107. * Initializes the logger by registering [[flush()]] as a shutdown function.
  108. */
  109. public function init()
  110. {
  111. parent::init();
  112. register_shutdown_function(function () {
  113. // make regular flush before other shutdown functions, which allows session data collection and so on
  114. $this->flush();
  115. // make sure log entries written by shutdown functions are also flushed
  116. // ensure "flush()" is called last when there are multiple shutdown functions
  117. register_shutdown_function([$this, 'flush'], true);
  118. });
  119. }
  120. /**
  121. * Logs a message with the given type and category.
  122. * If [[traceLevel]] is greater than 0, additional call stack information about
  123. * the application code will be logged as well.
  124. * @param string|array $message the message to be logged. This can be a simple string or a more
  125. * complex data structure that will be handled by a [[Target|log target]].
  126. * @param integer $level the level of the message. This must be one of the following:
  127. * `Logger::LEVEL_ERROR`, `Logger::LEVEL_WARNING`, `Logger::LEVEL_INFO`, `Logger::LEVEL_TRACE`,
  128. * `Logger::LEVEL_PROFILE_BEGIN`, `Logger::LEVEL_PROFILE_END`.
  129. * @param string $category the category of the message.
  130. */
  131. public function log($message, $level, $category = 'application')
  132. {
  133. $time = microtime(true);
  134. $traces = [];
  135. if ($this->traceLevel > 0) {
  136. $count = 0;
  137. $ts = debug_backtrace(DEBUG_BACKTRACE_IGNORE_ARGS);
  138. array_pop($ts); // remove the last trace since it would be the entry script, not very useful
  139. foreach ($ts as $trace) {
  140. if (isset($trace['file'], $trace['line']) && strpos($trace['file'], YII2_PATH) !== 0) {
  141. unset($trace['object'], $trace['args']);
  142. $traces[] = $trace;
  143. if (++$count >= $this->traceLevel) {
  144. break;
  145. }
  146. }
  147. }
  148. }
  149. $this->messages[] = [$message, $level, $category, $time, $traces];
  150. if ($this->flushInterval > 0 && count($this->messages) >= $this->flushInterval) {
  151. $this->flush();
  152. }
  153. }
  154. /**
  155. * Flushes log messages from memory to targets.
  156. * @param boolean $final whether this is a final call during a request.
  157. */
  158. public function flush($final = false)
  159. {
  160. $messages = $this->messages;
  161. // https://github.com/yiisoft/yii2/issues/5619
  162. // new messages could be logged while the existing ones are being handled by targets
  163. $this->messages = [];
  164. if ($this->dispatcher instanceof Dispatcher) {
  165. $this->dispatcher->dispatch($messages, $final);
  166. }
  167. }
  168. /**
  169. * Returns the total elapsed time since the start of the current request.
  170. * This method calculates the difference between now and the timestamp
  171. * defined by constant `YII_BEGIN_TIME` which is evaluated at the beginning
  172. * of [[\yii\BaseYii]] class file.
  173. * @return float the total elapsed time in seconds for current request.
  174. */
  175. public function getElapsedTime()
  176. {
  177. return microtime(true) - YII_BEGIN_TIME;
  178. }
  179. /**
  180. * Returns the profiling results.
  181. *
  182. * By default, all profiling results will be returned. You may provide
  183. * `$categories` and `$excludeCategories` as parameters to retrieve the
  184. * results that you are interested in.
  185. *
  186. * @param array $categories list of categories that you are interested in.
  187. * You can use an asterisk at the end of a category to do a prefix match.
  188. * For example, 'yii\db\*' will match categories starting with 'yii\db\',
  189. * such as 'yii\db\Connection'.
  190. * @param array $excludeCategories list of categories that you want to exclude
  191. * @return array the profiling results. Each element is an array consisting of these elements:
  192. * `info`, `category`, `timestamp`, `trace`, `level`, `duration`.
  193. */
  194. public function getProfiling($categories = [], $excludeCategories = [])
  195. {
  196. $timings = $this->calculateTimings($this->messages);
  197. if (empty($categories) && empty($excludeCategories)) {
  198. return $timings;
  199. }
  200. foreach ($timings as $i => $timing) {
  201. $matched = empty($categories);
  202. foreach ($categories as $category) {
  203. $prefix = rtrim($category, '*');
  204. if (($timing['category'] === $category || $prefix !== $category) && strpos($timing['category'], $prefix) === 0) {
  205. $matched = true;
  206. break;
  207. }
  208. }
  209. if ($matched) {
  210. foreach ($excludeCategories as $category) {
  211. $prefix = rtrim($category, '*');
  212. foreach ($timings as $i => $timing) {
  213. if (($timing['category'] === $category || $prefix !== $category) && strpos($timing['category'], $prefix) === 0) {
  214. $matched = false;
  215. break;
  216. }
  217. }
  218. }
  219. }
  220. if (!$matched) {
  221. unset($timings[$i]);
  222. }
  223. }
  224. return array_values($timings);
  225. }
  226. /**
  227. * Returns the statistical results of DB queries.
  228. * The results returned include the number of SQL statements executed and
  229. * the total time spent.
  230. * @return array the first element indicates the number of SQL statements executed,
  231. * and the second element the total time spent in SQL execution.
  232. */
  233. public function getDbProfiling()
  234. {
  235. $timings = $this->getProfiling(['yii\db\Command::query', 'yii\db\Command::execute']);
  236. $count = count($timings);
  237. $time = 0;
  238. foreach ($timings as $timing) {
  239. $time += $timing['duration'];
  240. }
  241. return [$count, $time];
  242. }
  243. /**
  244. * Calculates the elapsed time for the given log messages.
  245. * @param array $messages the log messages obtained from profiling
  246. * @return array timings. Each element is an array consisting of these elements:
  247. * `info`, `category`, `timestamp`, `trace`, `level`, `duration`.
  248. */
  249. public function calculateTimings($messages)
  250. {
  251. $timings = [];
  252. $stack = [];
  253. foreach ($messages as $i => $log) {
  254. list($token, $level, $category, $timestamp, $traces) = $log;
  255. $log[5] = $i;
  256. if ($level == Logger::LEVEL_PROFILE_BEGIN) {
  257. $stack[] = $log;
  258. } elseif ($level == Logger::LEVEL_PROFILE_END) {
  259. if (($last = array_pop($stack)) !== null && $last[0] === $token) {
  260. $timings[$last[5]] = [
  261. 'info' => $last[0],
  262. 'category' => $last[2],
  263. 'timestamp' => $last[3],
  264. 'trace' => $last[4],
  265. 'level' => count($stack),
  266. 'duration' => $timestamp - $last[3],
  267. ];
  268. }
  269. }
  270. }
  271. ksort($timings);
  272. return array_values($timings);
  273. }
  274. /**
  275. * Returns the text display of the specified level.
  276. * @param integer $level the message level, e.g. [[LEVEL_ERROR]], [[LEVEL_WARNING]].
  277. * @return string the text display of the level
  278. */
  279. public static function getLevelName($level)
  280. {
  281. static $levels = [
  282. self::LEVEL_ERROR => 'error',
  283. self::LEVEL_WARNING => 'warning',
  284. self::LEVEL_INFO => 'info',
  285. self::LEVEL_TRACE => 'trace',
  286. self::LEVEL_PROFILE_BEGIN => 'profile begin',
  287. self::LEVEL_PROFILE_END => 'profile end',
  288. self::LEVEL_PROFILE => 'profile'
  289. ];
  290. return isset($levels[$level]) ? $levels[$level] : 'unknown';
  291. }
  292. }