Понимание вывода профилировщика Firebug

Question

Я пытался использовать профилировщик Firebug, чтобы лучше понять источник некоторых проблем с производительностью JavaScript, которые мы видим, но я немного смущен выводом.

Когда я профилирую некоторый код, профилировщик сообщает Профиль (464,323 мс, 26,412 вызовов) . Я подозреваю, что 464,323 мс - это сумма времени выполнения этих 26,412 вызовов.

Однако, когда я углубляюсь в подробные результаты, я вижу отдельные результаты со средним временем выполнения , превышающим 464,323 мс, например, результат с наибольшим средним временем сообщает о следующих деталях:

Calls: **1**
Percent: **0%**
Own Time: **0.006 ms**
Time: **783.506 ms**
Avg: **783.506 ms**
Min: **783.506 ms**
Max: **783.506 ms**

Другие отчеты о результатах:

Calls: **4**
Percent: **0.01%**
Own Time: **0.032 ms**
Time: **785.279 ms**
Avg: **196.32 ms**
Min: **0.012 ms**
Max: **783.741 ms**

Между этими двумя результатами сумма результатов по времени намного превышает 464,323.

Итак, что означают эти различные числа? Кому я должен доверять?

Answer 1

В каждом столбце есть описание того, что это значит, если вы наведите курсор мыши на него в Firebug. Я предполагаю, что вы можете прочитать о том, как каждый столбец работает самостоятельно. Тем не менее, вы определенно столкнулись с каким-то странным поведением, которое необходимо объяснить.

собственное время - это количество времени, которое функция потратила на выполнение кода внутри себя. Если функция не вызывает никаких других функций, то собственное время должно совпадать с время . Однако, если есть вызовы вложенных функций, то время также подсчитывает время, потраченное на их выполнение. Следовательно, время почти всегда будет больше, чем собственное время , и в большинстве случаев будет превышать общее время, указанное профилировщиком.

Тем не менее, одна функция время не должна превышать общее время регистрации профилировщика для вызовов JavaScript. Эта проблема определенно является ошибкой, и я понимаю, почему у вас возникают проблемы с доверием Firebug, когда он дает такой парадоксальный результат. Мне кажется, я нашел причину возникновения этой ошибки: AJAX.

Похоже, что вызовы AJAX приводят к тому, что столбцы, в которых учитываются вложенные вызовы функций, сообщают неверную информацию. В итоге они подсчитывают время выполнения JavaScript и запроса к серверу.

Эту ошибку профилировщика можно воспроизвести, выполнив следующие действия:

1. Перейдите на любой сайт, который использует AJAX. (Я использовал http://juicystudio.com/experiments/ajax/index.php)
2. Включить отладку консоли / скрипта.
3. Включите профилировщик.
4. Сделайте AJAX-вызов. (Несколько могут осветить проблему больше.)
5. Остановите профилировщик, проверьте вывод.

В этом примере, что касается времени против собственного времени , собственного времени каждой функции складывается из общего времени профилировщика, но * В столбце 1048 * time указывается время, затраченное AJAX-вызовом на соединение с сервером. Это означает, что столбец time неверен, если вам нужна только скорость выполнения JavaScript.

Это становится хуже: так как время , среднее время , мин и макс все подсчитывают вызовы вложенных функций, они все неверно, если вы используете AJAX. Кроме того, любая функция, которая в конечном итоге использует AJAX (при вызове вложенной функции), также будет сообщать неверное время. Это означает, что целый ряд функций может сообщать неверную информацию! Так что пока не доверяйте ни одному из этих столбцов, пока Firebug не решит проблему. (Возможно, они предполагали, что поведение будет таким, хотя в лучшем случае сбивает с толку, если оставить это так.)

Если вы не используете AJAX, возникает другая проблема; дайте нам знать, если вы или нет.

Answer 2

Из Учебник по Firebug - ведение журнала, профилирование и CommandLine (часть II) : (примеры там хорошие)

Столбцы и описание профилировщика

Столбец функции : Отображается название каждой функции.
Колонка вызова : Показывает количество вызовов определенной функции.
Столбец процентов : показывает длительность каждой функции в процентах.
Столбец времени : Показывает продолжительность выполнения от начальной точки функции до конечной точки функции.
Средний столбец : Показывает среднее время выполнения определенной функции. Если вы вызываете функцию только один раз, вы не увидите различий. Если вы звоните более одного раза, вы увидите разницу.
Формула для этого столбца:
Avg = собственный Ttime / Call;
Мин. Столбец и Макс. Столбец : Показывает минимальное время выполнения определенной функции.
Столбец файла : имя файла, в котором находится функция.

Answer 3

Если я правильно понимаю вещи, это выглядит примерно так:

В первой строке вы увидите, что Собственное время "всего 0,006 мс". Это означает, что, хотя время, потраченное на эту функцию, составляло 783,506 мс, большая часть была потрачена внутри функций, вызванных из этой функции.

Когда я использую Firebug для оптимизации кода, я стараюсь сократить «собственное время» функций, которые вызываются чаще всего. (очевидно, проверяя также любые ненужные вызовы функций для полного удаления)

Answer 4

Насколько я понимаю, это то, как это работает ... общее время профилировщика является суммой столбца «Свое время». Однако вы можете заметить, что некоторые значения single Time могут превышать общее время профилировщика. Эти сверхурочные были потрачены вне JavaScript, например. в вызове плагина. Если ваша функция JS выполняет, например, плагин, и ожидает, чтобы функция плагина вернулась в JS, то эти времена ожидания НЕ будут сообщаться общим временем профилировщика, но будут включены в столбец «Время».