В R есть встроенная утилита для профилирования производительности и памяти — Rprof. Наберите в консоли
Профайлер работает так:
Например:
Результат будет выглядеть примерно так:
Много информации!
Примечание: sample.interval = 0.02 определяет частоту, с которой Rprofile анализирует стек вызовов и производит измерения. Т.о. Rprofile работает только через опрос. Следовательно, summaryRprof может отличаться каждый раз, когда вы профилируете код. Могут быть не только небольшие отличия в числах, но и, например, недостающие элементы. Скажем, потому что в один из запусков измерение было случайно сделано во время выполнения кода, а при другом запуске выполнение произошло между двумя измерениями.
Давайте рассмотрим показательный пример. Допустим, есть следующие функции:
Да, ужасно и бессмысленно, но они прекрасно подходят для этого примера: их выполнение занимает определенное время.
Итак, давайте профилировать:
Что будет выглядеть так:
Отлично. Можно увидеть, что combn занимает около трех четвертей времени выполнения, а paste — только одну четверть.
Погодите-ка: matrix? Откуда это берется? Эта функция должна вызываться или внутри combn, или paste. Не проблема, поскольку matrix занимает только 2,3% общего времени. Но все равно интересно разобраться, правда?
Пакет prof.tree Артема Клевцова, доступный на CRAN или на github, предоставляет другой способ анализа этих данных. Он позволяет отобразить данные профилирования в виде дерева:
Результат выглядит примерно так:
Сюрприз! Matrix вызывается из combn, а не из paste!
Обратите внимание: pr — структура data.tree, так что для нее доступны все операции data.tree. Например, можно собрать информацию по конкретным функциям (по имени):
И так же, как и выше, это даст нам 73.56%.
Также можно ограничить количество выводимых вершин, удалив все поддеревья с процентом, превышающим, скажем, 5%:
Вот результат:
Или можно использовать графический инструмент data.tree, чтобы визуализировать это:
График будет выглядеть примерно так:
?Rprof, чтобы узнать о ней больше.Профайлер работает так:
- запускаете профайлер, вызывая Rprof и передавая имя файла, где будут храниться данные профилирования
- вызываете функции R, которые хотите проанализировать
- вызываете
Rprof(NULL), чтобы остановить профайлер - анализируете файл, созданный Rprof, как правило, с помощью
summaryRprof
Например:
Rprof(tmp <- tempfile())
example(glm)
Rprof()
summaryRprof(tmp)
unlink(tmp)
Результат будет выглядеть примерно так:
$by.self
self.time self.pct total.time total.pct
"str.default" 0.02 14.29 0.10 71.43
"deparse" 0.02 14.29 0.04 28.57
"as.name" 0.02 14.29 0.02 14.29
"formals" 0.02 14.29 0.02 14.29
"make.names" 0.02 14.29 0.02 14.29
"parent.frame" 0.02 14.29 0.02 14.29
"pmatch" 0.02 14.29 0.02 14.29
$by.total
total.time total.pct self.time self.pct
"eval" 0.14 100.00 0.00 0.00
"withVisible" 0.14 100.00 0.00 0.00
"str.default" 0.10 71.43 0.02 14.29
"<Anonymous>" 0.10 71.43 0.00 0.00
"capture.output" 0.10 71.43 0.00 0.00
"doTryCatch" 0.10 71.43 0.00 0.00
"evalVis" 0.10 71.43 0.00 0.00
".rs.valueContents" 0.10 71.43 0.00 0.00
".rs.valueFromStr" 0.10 71.43 0.00 0.00
"str" 0.10 71.43 0.00 0.00
"try" 0.10 71.43 0.00 0.00
"tryCatch" 0.10 71.43 0.00 0.00
"tryCatchList" 0.10 71.43 0.00 0.00
"tryCatchOne" 0.10 71.43 0.00 0.00
"do.call" 0.08 57.14 0.00 0.00
"strSub" 0.08 57.14 0.00 0.00
"deparse" 0.04 28.57 0.02 14.29
"example" 0.04 28.57 0.00 0.00
"FUN" 0.04 28.57 0.00 0.00
"lapply" 0.04 28.57 0.00 0.00
"match" 0.04 28.57 0.00 0.00
"source" 0.04 28.57 0.00 0.00
"as.name" 0.02 14.29 0.02 14.29
"formals" 0.02 14.29 0.02 14.29
"make.names" 0.02 14.29 0.02 14.29
"parent.frame" 0.02 14.29 0.02 14.29
"pmatch" 0.02 14.29 0.02 14.29
"anova" 0.02 14.29 0.00 0.00
"anova.glm" 0.02 14.29 0.00 0.00
"data.frame" 0.02 14.29 0.00 0.00
"deParse" 0.02 14.29 0.00 0.00
".deparseOpts" 0.02 14.29 0.00 0.00
".getXlevels" 0.02 14.29 0.00 0.00
"glm" 0.02 14.29 0.00 0.00
"%in%" 0.02 14.29 0.00 0.00
"match.call" 0.02 14.29 0.00 0.00
"mode" 0.02 14.29 0.00 0.00
"NextMethod" 0.02 14.29 0.00 0.00
"paste" 0.02 14.29 0.00 0.00
"sapply" 0.02 14.29 0.00 0.00
"str.data.frame" 0.02 14.29 0.00 0.00
"summary" 0.02 14.29 0.00 0.00
"%w/o%" 0.02 14.29 0.00 0.00
$sample.interval
[1] 0.02
$sampling.time
[1] 0.14
Много информации!
Примечание: sample.interval = 0.02 определяет частоту, с которой Rprofile анализирует стек вызовов и производит измерения. Т.о. Rprofile работает только через опрос. Следовательно, summaryRprof может отличаться каждый раз, когда вы профилируете код. Могут быть не только небольшие отличия в числах, но и, например, недостающие элементы. Скажем, потому что в один из запусков измерение было случайно сделано во время выполнения кода, а при другом запуске выполнение произошло между двумя измерениями.
Показательный пример профилирования
Давайте рассмотрим показательный пример. Допустим, есть следующие функции:
Do_1 <- function() {
combn(1:20, 5)
for (i in 1:15) Do_2()
for (i in 1:25) Do_4()
}
Do_2 <- function() {
combn(1:15, 5)
for (i in 1:5) Do_3()
}
Do_3 <- function() {
combn(1:14, 5)
for (i in 1:20) Do_4()
}
Do_4 <- function() {
paste(1:1000)
combn(1:11, 5)
}
Да, ужасно и бессмысленно, но они прекрасно подходят для этого примера: их выполнение занимает определенное время.
Итак, давайте профилировать:
Do_1
:
Rprof(tmp <- tempfile())
Do_1()
Rprof(NULL)
summaryRprof(tmp)
Что будет выглядеть так:
$by.self
self.time self.pct total.time total.pct
"combn" 1.24 71.26 1.28 73.56
"paste" 0.46 26.44 0.46 26.44
"matrix" 0.04 2.30 0.04 2.30
$by.total
total.time total.pct self.time self.pct
"Do_1" 1.74 100.00 0.00 0.00
"Do_2" 1.72 98.85 0.00 0.00
"Do_3" 1.68 96.55 0.00 0.00
"Do_4" 1.48 85.06 0.00 0.00
"combn" 1.28 73.56 1.24 71.26
"paste" 0.46 26.44 0.46 26.44
"matrix" 0.04 2.30 0.04 2.30
Отлично. Можно увидеть, что combn занимает около трех четвертей времени выполнения, а paste — только одну четверть.
Погодите-ка: matrix? Откуда это берется? Эта функция должна вызываться или внутри combn, или paste. Не проблема, поскольку matrix занимает только 2,3% общего времени. Но все равно интересно разобраться, правда?
Анализ данных профилирования с prof.tree
Пакет prof.tree Артема Клевцова, доступный на CRAN или на github, предоставляет другой способ анализа этих данных. Он позволяет отобразить данные профилирования в виде дерева:
library(prof.tree)
pr <- prof.tree(tmp)
print(pr, limit = NULL)
Результат выглядит примерно так:
levelName real percent env
1 calls 1.74 100.0 %
2 °--Do_1 1.74 100.0 % R_GlobalEnv
3 ¦--Do_2 1.72 98.9 % R_GlobalEnv
4 ¦ ¦--Do_3 1.68 96.6 % R_GlobalEnv
5 ¦ ¦ ¦--combn 0.22 12.6 % utils
6 ¦ ¦ ¦ °--matrix 0.02 1.1 % base
7 ¦ ¦ °--Do_4 1.46 83.9 % R_GlobalEnv
8 ¦ ¦ ¦--combn 1.02 58.6 % utils
9 ¦ ¦ ¦ °--matrix 0.02 1.1 % base
10 ¦ ¦ °--paste 0.44 25.3 % base
11 ¦ °--combn 0.04 2.3 % utils
12 °--Do_4 0.02 1.1 % R_GlobalEnv
13 °--paste 0.02 1.1 % base
Сюрприз! Matrix вызывается из combn, а не из paste!
Обратите внимание: pr — структура data.tree, так что для нее доступны все операции data.tree. Например, можно собрать информацию по конкретным функциям (по имени):
library(data.tree)
SumByFunction <- function(name) {
sum(pr$Get("real", filterFun = function(node) node$name == name))/pr$real
}
SumByFunction("combn")
И так же, как и выше, это даст нам 73.56%.
Также можно ограничить количество выводимых вершин, удалив все поддеревья с процентом, превышающим, скажем, 5%:
print(pr, limit = NULL, pruneFun = function(x) x$percent > 0.05)
Вот результат:
levelName real percent env
1 calls 1.74 100.0 %
2 °--Do_1 1.74 100.0 % R_GlobalEnv
3 °--Do_2 1.72 98.9 % R_GlobalEnv
4 °--Do_3 1.68 96.6 % R_GlobalEnv
5 ¦--combn 0.22 12.6 % utils
6 °--Do_4 1.46 83.9 % R_GlobalEnv
7 ¦--combn 1.02 58.6 % utils
8 °--paste 0.44 25.3 % base
Или можно использовать графический инструмент data.tree, чтобы визуализировать это:
cols <- colorRampPalette(c("green", "red"))(101)
SetNodeStyle(pr,
style = "filled,rounded",
shape = "box",
fontname = "helvetica",
fillcolor = function(node) cols[round(node$percent * 100) + 1],
tooltip = function(node) node$real)
plot(pr)
График будет выглядеть примерно так:
Поделиться с друзьями