Logger.php 12 KB

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