Logger::getElapsedTime() - Code Metrics - Inspection of "Consistent behavior of `run()` method in widgets" - yiisoft/yii2 - Measure and Improve Code Quality continuously with Scrutinizer

Completed

Push — 2.1 ( c952e8...98ed49 )

by Carsten

created 2016-06-20 11:40 UTC

Logger::getElapsedTime() A

↳ Parent: Logger

Complexity

Conditions	1
Paths	1

Size

Total Lines	4
Code Lines	2

Duplication

Lines	0
Ratio	0 %

Code Coverage

Tests	0
CRAP Score	2

Importance

Changes

Metric	Value
dl	0
loc	4
rs	10
c	0
b	0
f	0
ccs	0
cts	2
cp	0
cc	1
eloc	2
nc	1
nop	0
crap	2

<?php
/**
 * @link http://www.yiiframework.com/
 * @copyright Copyright (c) 2008 Yii Software LLC
 * @license http://www.yiiframework.com/license/
 */

namespace yii\log;

use Yii;
use yii\base\Component;

/**
 * Logger records logged messages in memory and sends them to different targets if [[dispatcher]] is set.
 *
 * A Logger instance can be accessed via `Yii::getLogger()`. You can call the method [[log()]] to record a single log message.
 * For convenience, a set of shortcut methods are provided for logging messages of various severity levels
 * via the [[Yii]] class:
 *
 * - [[Yii::trace()]]
 * - [[Yii::error()]]
 * - [[Yii::warning()]]
 * - [[Yii::info()]]
 * - [[Yii::beginProfile()]]
 * - [[Yii::endProfile()]]
 *
 * When the application ends or [[flushInterval]] is reached, Logger will call [[flush()]]
 * to send logged messages to different log targets, such as [[FileTarget|file]], [[EmailTarget|email]],
 * or [[DbTarget|database]], with the help of the [[dispatcher]].
 *
 * @property array $dbProfiling The first element indicates the number of SQL statements executed, and the
 * second element the total time spent in SQL execution. This property is read-only.
 * @property float $elapsedTime The total elapsed time in seconds for current request. This property is
 * read-only.
 * @property array $profiling The profiling results. Each element is an array consisting of these elements:
 * `info`, `category`, `timestamp`, `trace`, `level`, `duration`. This property is read-only.
 *
 * @author Qiang Xue <[email protected]>
 * @since 2.0
 */
class Logger extends Component
{
    /**
     * 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;

    /**
     * @var array logged messages. This property is managed by [[log()]] and [[flush()]].
     * Each log message is of the following structure:
     *
     * ```
     * [
     *   [0] => message (mixed, can be a string or some complex data, such as an exception object)
     *   [1] => level (integer)
     *   [2] => category (string)
     *   [3] => timestamp (float, obtained by microtime(true))
     *   [4] => traces (array, debug backtrace, contains the application code call stacks)
     * ]
     * ```
     */
    public $messages = [];
    /**
     * @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 integer how much call stack information (file name and line number) should be logged for each message.
     * If it is greater than 0, at most that number of call stacks will be logged. Note that only application
     * call stacks are counted.
     */
    public $traceLevel = 0;
    /**
     * @var Dispatcher the message dispatcher
     */
    public $dispatcher;


    /**
     * Initializes the logger by registering [[flush()]] as a shutdown function.
     */
    public function init()
    {
        parent::init();
        register_shutdown_function(function () {
            // make regular flush before other shutdown functions, which allows session data collection and so on
            $this->flush();
            // make sure log entries written by shutdown functions are also flushed
            // ensure "flush()" is called last when there are multiple shutdown functions
            register_shutdown_function([$this, 'flush'], true);
        });
    }

    /**
     * Logs a message with the given type and category.
     * If [[traceLevel]] is greater than 0, additional call stack information about
     * the application code will be logged as well.
     * @param string|array $message the message to be logged. This can be a simple string or a more
     * complex data structure that will be handled by a [[Target|log target]].
     * @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`.
     * @param string $category the category of the message.
     */
    public function log($message, $level, $category = 'application')
    {
        $time = microtime(true);
        $traces = [];
        if ($this->traceLevel > 0) {
            $count = 0;
            $ts = debug_backtrace(DEBUG_BACKTRACE_IGNORE_ARGS);
            array_pop($ts); // remove the last trace since it would be the entry script, not very useful
            foreach ($ts as $trace) {
                if (isset($trace['file'], $trace['line']) && strpos($trace['file'], YII2_PATH) !== 0) {
                    unset($trace['object'], $trace['args']);
                    $traces[] = $trace;
                    if (++$count >= $this->traceLevel) {
                        break;
                    }
                }
            }
        }
        $this->messages[] = [$message, $level, $category, $time, $traces];
        if ($this->flushInterval > 0 && count($this->messages) >= $this->flushInterval) {
            $this->flush();
        }
    }

    /**
     * Flushes log messages from memory to targets.
     * @param boolean $final whether this is a final call during a request.
     */
    public function flush($final = false)
    {
        $messages = $this->messages;
        // https://github.com/yiisoft/yii2/issues/5619
        // new messages could be logged while the existing ones are being handled by targets
        $this->messages = [];
        if ($this->dispatcher instanceof Dispatcher) {
            $this->dispatcher->dispatch($messages, $final);
        }
    }

    /**
     * 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 [[\yii\BaseYii]] class file.
     * @return float the total elapsed time in seconds for current request.
     */
    public function getElapsedTime()
    {
        return microtime(true) - YII_BEGIN_TIME;
    }

    /**
     * Returns the profiling results.
     *
     * 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\Connection`.
     * @param array $excludeCategories list of categories that you want to exclude
     * @return array the profiling results. Each element is an array consisting of these elements:
     * `info`, `category`, `timestamp`, `trace`, `level`, `duration`.
     */
    public function getProfiling($categories = [], $excludeCategories = [])
    {
        $timings = $this->calculateTimings($this->messages);
        if (empty($categories) && empty($excludeCategories)) {
            return $timings;
        }

        foreach ($timings as $i => $timing) {
            $matched = empty($categories);
            foreach ($categories as $category) {
                $prefix = rtrim($category, '*');
                if (($timing['category'] === $category || $prefix !== $category) && strpos($timing['category'], $prefix) === 0) {
                    $matched = true;
                    break;
                }
            }

            if ($matched) {
                foreach ($excludeCategories as $category) {
                    $prefix = rtrim($category, '*');
                    foreach ($timings as $i => $timing) {
                        if (($timing['category'] === $category || $prefix !== $category) && strpos($timing['category'], $prefix) === 0) {
                            $matched = false;
                            break;
                        }
                    }
                }
            }

            if (!$matched) {
                unset($timings[$i]);
            }
        }

        return array_values($timings);
    }

    /**
     * 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([
            'yii\db\Command::query',
            'yii\db\Command::execute',
        ]);
        $count = count($timings);
        $time = 0;
        foreach ($timings as $timing) {
            $time += $timing['duration'];
        }

        return [$count, $time];
    }

    /**
     * Calculates the elapsed time for the given log messages.
     * @param array $messages the log messages obtained from profiling
     * @return array timings. Each element is an array consisting of these elements:
     * `info`, `category`, `timestamp`, `trace`, `level`, `duration`.
     */
    public function calculateTimings($messages)
    {
        $timings = [];
        $stack = [];

        foreach ($messages as $i => $log) {
            list($token, $level, $category, $timestamp, $traces) = $log;
<?php

function returnThreeValues() {
    return array('a', 'b', 'c');
}

list($a, $b, $c) = returnThreeValues();

print $a . " - " . $c;
            $log[5] = $i;
            if ($level == self::LEVEL_PROFILE_BEGIN) {
                $stack[] = $log;
            } elseif ($level == self::LEVEL_PROFILE_END) {
                if (($last = array_pop($stack)) !== null && $last[0] === $token) {
                    $timings[$last[5]] = [
                        'info' => $last[0],
                        'category' => $last[2],
                        'timestamp' => $last[3],
                        'trace' => $last[4],
                        'level' => count($stack),
                        'duration' => $timestamp - $last[3],
                    ];
                }
            }
        }

        ksort($timings);

        return array_values($timings);
    }


    /**
     * Returns the text display of the specified level.
     * @param integer $level the message level, e.g. [[LEVEL_ERROR]], [[LEVEL_WARNING]].
     * @return string the text display of the level
     */
    public static function getLevelName($level)
    {
        static $levels = [
            self::LEVEL_ERROR => 'error',
            self::LEVEL_WARNING => 'warning',
            self::LEVEL_INFO => 'info',
            self::LEVEL_TRACE => 'trace',
            self::LEVEL_PROFILE_BEGIN => 'profile begin',
            self::LEVEL_PROFILE_END => 'profile end',
        ];

        return isset($levels[$level]) ? $levels[$level] : 'unknown';
    }
}


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

yiisoft / yii2

Push — 2.1 ( c952e8...98ed49 )

Logger::getElapsedTime() A

Complexity

Size

Duplication

Code Coverage

Importance

Duplication Side-by-Side

Filter issues like