Просмотр исходного текста страницы R:Профилирование кода

{{CC-BY-4.0|author=автором Артём Клевцов}}

== Пакет base ==

Описанные выше функции {{Inline-code|system.time()|lang="rsplus"}}, {{Inline-code|benchmark()|lang="rsplus"}}, {{Inline-code|microbenchmark()|lang="rsplus"}} позволяют оценить общее время выполнения выражения и нивелировать возможные вариации за счет множества попыток, однако для более полной оценки и определения стратегии оптимизации кода необходимо также выявлять и «узкие» места в выполняемом коде. К подобным «узким» местам можно отнести те вызовы, которые занимают наибольшее количество времени или расходуют больше всего памяти (при профилирования расхода памяти). Существуют специальные пакеты, предназначенные для организации профилирования или для более наглядной демонстрации результатов, однако далее пойдет речь о функции {{Inline-code|Rprof()|lang="rsplus"}} из пакета {{Inline-code|base|lang="rsplus"}}.

Принцип работы функции {{Inline-code|Rprof()|lang="rsplus"}} таков: с заданным интервалом (аргумент {{Inline-code|interval|lang="rsplus"}}) делаются «снимки» вызовов и записываются в файл. Следует помнить о том, что {{Inline-code|Rprof()|lang="rsplus"}} делает «снимки» каждые 0.02 секунды (значение по умолчанию), поэтому если выражение выполняется быстрее, то {{Inline-code|Rprof()|lang="rsplus"}} не сможет его отследить. В таком случае периодичность «снимков» можно задать вручную с помощью аргумента {{Inline-code|interval|lang="rsplus"}}. Также можно увеличить объём данных, чтобы код выполнялся дольше.

Ещё одной специфической особенностью профилирования является то, что при профилирования записываются абсолютно все вызовы. Например, если вы используется функцию {{Inline-code|replicate()|lang="rsplus"}} для организации повторного выполнения выражения, то вызовы {{Inline-code|replicate()|lang="rsplus"}} также будут записаны в лог, что может затруднить его анализ. Аналогичная ситуация будет происходить при вызове скрипта через функцию {{Inline-code|source()|lang="rsplus"}}

Обратим внимание, что при профилировании мы можем использовать многократное выполнение анализируемой функции для сбора более надёжной статистики вызовов.

В качестве примера ниже представлены шаги процесса профилирования функции, которая рассчитывает первичные описательные статистики (среднее, медиану, стандартное отклонение, минимум и максимум) по сгенерированным <math>10^6</math> нормально распределённым значениям.

<syntaxhighlight lang="rsplus">
> x <- rnorm(10^6)
</syntaxhighlight>

Объявим данную функцию:

<syntaxhighlight lang="rsplus">
desc <- function(x) {
  n <- length(x)
  mean <- mean(x)
  median <- median(x)
  sd <- sd(x)
  min <- min(x)
  max <- max(x)
  return(c(n, mean, median, sd, min, max))
}
</syntaxhighlight>

Шаг 1. Создание временного файла для записи лога профилирования (необязательно):

<syntaxhighlight lang="rsplus">
> tmp.log <- tempfile(pattern = "prof-", fileext = ".log")
</syntaxhighlight>

Посмотреть путь и имя временного файла лога можно, введя имя переменной {{Inline-code|tmp.log|lang="rsplus"}}:

<syntaxhighlight lang="rsplus">
> tmp.log
[1] "/tmp/RtmpAvhCfO/prof-23b61d761805.log"
</syntaxhighlight>

Шаг 2. Собственно процедура профилирования:

<syntaxhighlight lang="rsplus">
# Включаем профилирование
> Rprof(tmp.log)
# Выполняем код
> for (i in seq_len(100))
+   invisible(desc(x))
# отключаем профилирование
> Rprof(NULL)
</syntaxhighlight>

Шаг 3. Вывод результатов:

<syntaxhighlight lang="rsplus">
> summaryRprof(tmp.log)
</syntaxhighlight>

Шаг 4. Удаляем временный файл:

<syntaxhighlight lang="rsplus">
> unlink(tmp.log)
</syntaxhighlight>

Рассмотрим результаты профилирования функции {{Inline-code|desc()|lang="rsplus"}}:

<syntaxhighlight lang="rsplus">
> summaryRprof(tmp.log)
$by.self
               self.time self.pct total.time total.pct
"sort.int"          2.54    52.70       3.04     63.07
"is.na"             0.70    14.52       0.70     14.52
".Call"             0.44     9.13       0.44      9.13
"min"               0.38     7.88       0.38      7.88
"any"               0.32     6.64       0.32      6.64
"max"               0.26     5.39       0.26      5.39
"mean.default"      0.18     3.73       0.18      3.73

$by.total
                 total.time total.pct self.time self.pct
"desc"                 4.82    100.00      0.00     0.00
"median"               3.56     73.86      0.00     0.00
"median.default"       3.56     73.86      0.00     0.00
"mean"                 3.22     66.80      0.00     0.00
"sort.int"             3.04     63.07      2.54    52.70
"sort"                 3.04     63.07      0.00     0.00
"sort.default"         3.04     63.07      0.00     0.00
"is.na"                0.70     14.52      0.70    14.52
".Call"                0.44      9.13      0.44     9.13
"sd"                   0.44      9.13      0.00     0.00
"var"                  0.44      9.13      0.00     0.00
"min"                  0.38      7.88      0.38     7.88
"any"                  0.32      6.64      0.32     6.64
"max"                  0.26      5.39      0.26     5.39
"mean.default"         0.18      3.73      0.18     3.73

$sample.interval
[1] 0.02

$sampling.time
[1] 4.82
</syntaxhighlight>

Результатом подобных операций является 2 таблицы, отсортированные по разным основаниям: по времени выполнения функции ({{Inline-code|self.time|lang="rsplus"}}) и общему времени выполнения функции ({{Inline-code|total.time|lang="rsplus"}}). В столбцах представлены абсолютные и относительные (в процентах) показатели времени выполнения.

При профилировании скриптов включение опции {{Inline-code|line.profiling|lang="rsplus"}} проставляет номера строк в которых производился вызов, что позволяет проанализировать производительность всего кода: 

<syntaxhighlight lang="rsplus">
> Rprof(tmp.log, line.profiling = TRUE)
> source("/path/scritpt.R")
> Rprof(NULL)
> summaryRprof(tmp.log)
> unlink(tmp.log)
</syntaxhighlight>

== Пакет proftools ==

Также может оказаться полезной функция {{Inline-code|flatProfile()|lang="rsplus"}} из пакета {{Inline-code|proftools|lang="rsplus"}}. Данная функция выводит таблицу, сходную с таблицей «by.total» возвращаемую функцией {{Inline-code|summaryRprof()|lang="rsplus"}}, в одну и сортирует их по общему времени выполнения в процентах или по времени выполнения функции в процентах, если указать {{Inline-code|byTotal = FALSE|lang="rsplus"}}:

<syntaxhighlight lang="rsplus">
> library(proftools)
> flatProfile(readProfileData(tmp.log))
               total.pct total.time self.pct self.time
desc              100.00       4.82     0.00      0.00
median             73.86       3.56     0.00      0.00
median.default     73.86       3.56     0.00      0.00
mean               66.80       3.22     0.00      0.00
sort               63.07       3.04     0.00      0.00
sort.default       63.07       3.04     0.00      0.00
sort.int           63.07       3.04    52.70      2.54
is.na              14.52       0.70    14.52      0.70
.Call               9.13       0.44     9.13      0.44
sd                  9.13       0.44     0.00      0.00
var                 9.13       0.44     0.00      0.00
min                 7.88       0.38     7.88      0.38
any                 6.64       0.32     6.64      0.32
max                 5.39       0.26     5.39      0.26
mean.default        3.73       0.18     3.73      0.18
</syntaxhighlight>

Функция интересна тем, что предоставляет более компактный вывод при той же информативности, что и функция {{Inline-code|summaryRprof()|lang="rsplus"}}.

== Пакет profr ==

Пакет {{Inline-code|profr|lang="rsplus"}} предоставляет несколько функций для упрощения процесса профилирования, а также позволяет графически представить результаты профилирования. Результаты работы функции {{Inline-code|profr|lang="rsplus"}} представляют собой таблицу, с хронологическим перечислением вызовов. Поэтому при использовании данной функции необходимо использовать однократное выполнение выражения. Вышеприведённый листинг по профилированию работы функции {{Inline-code|desc()|lang="rsplus"}} будет выглядеть следующим образом:

<syntaxhighlight lang="rsplus">
> library(profr)
> prof <- profr(desc(x))
> print(prof)
Read 3 items
                f level time start  end  leaf source
8            desc     1 0.04  0.00 0.04 FALSE   <NA>
9          median     2 0.02  0.00 0.02 FALSE  stats
10             sd     2 0.02  0.02 0.04 FALSE  stats
11 median.default     3 0.02  0.00 0.02 FALSE  stats
12            var     3 0.02  0.02 0.04 FALSE  stats
13           mean     4 0.02  0.00 0.02 FALSE   base
14          .Call     4 0.02  0.02 0.04  TRUE   base
15           sort     5 0.02  0.00 0.02 FALSE   base
16   sort.default     6 0.02  0.00 0.02 FALSE   base
17       sort.int     7 0.02  0.00 0.02  TRUE   base
</syntaxhighlight>

Содержание столбцов:
* «f» --- название функции;
* «level» --- уровень в иерархии вызовов;
* «time» --- общее время выполнения функции;
* «start» --- время начала выполнения функции;
* «end» --- время окончания выполнения функции;
* «leaf» --- TRUE, если функция вызывается другими функциями;
* «source» --- название пакеты, содержащего данную функцию.

Графическое представление результатов профилирования осуществляется с помощью стандартной функции {{Inline-code|plot()|lang="rsplus"}} или {{Inline-code|ggplot()|lang="rsplus"}}:

<syntaxhighlight lang="rsplus">
> ggplot(prof)
</syntaxhighlight>

[[Файл:Profr-ggplot-desc.png|600px|center]]

== Функция proftable() ==

Рассмотрим ещё один способ представления результатов профилирования --- функция {{Inline-code|proftable()|lang="rsplus"}}, написанная Noam Ross. Исходный код данной функции доступен под лицензией GNU GPL v2 и размещён в открытом доступе на [https://github.com/noamross/noamtools/blob/master/R/proftable.R github].

Мы переработали данную функцию, удалив зависимость от пакета {{Inline-code|plyr|lang="rsplus"}} и существенно ускорив её. Код модифицированного варианта доступен в [https://bitbucket.org/psylab/r-scripts/src/master/proftable.R git-репозитории]. Импортировать данный скрипт можно с помощью функции {{Inline-code|source_url()|lang="rsplus"}}, которая входит в состав пакета {{Inline-code|devtools|lang="rsplus"}}<ref>Штатная функция {{Inline-code|source()|lang="rsplus"}} из пакета {{Inline-code|base|lang="rsplus"}} не поддерживает загрузку файлов по протоколу https.</ref>:

<syntaxhighlight lang="rsplus">
> library(devtools)
> source_url("https://bitbucket.org/psylab/r-scripts/raw/master/proftable.R")
</syntaxhighlight>

Для корректной работы функции {{Inline-code|proftable()|lang="rsplus"}} необходимо провести профилирование с включённой опцией {{Inline-code|line.profiling|lang="rsplus"}}. Для удобства последующего анализа результатов можно сохранить функцию и её вызов в файл скрипта и вызывать его с помощью функции {{Inline-code|source()|lang="rsplus"}}. Скрипт для профилирования имеет следующее содержимое:

<syntaxhighlight lang="rsplus" line>
desc <- function(x) {
    n <- length(x)
    mean <- mean(x)
    median <- median(x)
    sd <- sd(x)
    min <- min(x)
    max <- max(x)
    return(c(n, mean, median, sd, min, max))
}

for (i in seq_len(100)) desc(x)
</syntaxhighlight>

Процедура профилирования осуществляется описанным выше способом:

<syntaxhighlight lang="rsplus">
> Rprof(tmp.log, line.profiling = TRUE)
> source("/tmp/script.R")
> Rprof(NULL)
</syntaxhighlight>

Результаты работы функции {{Inline-code|proftable()|lang="rsplus"}} представлены ниже.

<syntaxhighlight lang="rsplus">
> proftable(tmp.log)
 PctTime Call                                                                         
 54.464  1#4 > median > median.default > mean > sort > sort.default > sort.int        
 10.268  1#5 > sd > var > .Call                                                       
  7.143  1#7 > max                                                                    
  5.804  1#4 > median > median.default > is.na                                        
  5.357  1#4 > median > median.default > mean > sort > sort.default > sort.int > is.na
  5.357  1#6 > min                                                                    
  4.464  1#3 > mean > mean.default                                                    
  3.571  1#4 > median > median.default > any                                          
  3.125  1#4 > median > median.default > mean > sort > sort.default > sort.int > any  
  0.446  1#4 > median                                                                 

Files:
/tmp/RtmpAvhCfO/file23b65745e7ba.R

Parent Call: source > withVisible > eval > eval > 1#11 > desc

Total Time: 4.48 seconds
Percent of run time represented: 100%
</syntaxhighlight>

Разберём вывод функции {{Inline-code|proftable()|lang="rsplus"}}. В первом столбце отображается время выполнения того или иного вызова, во втором --- название вызываемой функции. Далее по цепочке приведена иерархия вызовов. Весь вывод отсортирован по времени выполнения вызовов по убыванию. Вывод наглядно демонстрирует наиболее медленные вызовы вплоть до самого низкого уровня иерархии.

Обратите внимание, что функция {{Inline-code|proftable()|lang="rsplus"}} имеет второй аргумент --- {{Inline-code|lines|lang="rsplus"}}, который отвечает за количество строк в выводе (значение по умолчанию - 10).

== Выводы ==

Из примера выше мы можем сделать вывод, что наиболее медленной функцией из состава функции {{Inline-code|desc()|lang="rsplus"}} является функция {{Inline-code|median()|lang="rsplus"}}, которая через некоторую последовательность вызовов вызывает функцию {{Inline-code|sort.int()|lang="rsplus"}}. Именно функция {{Inline-code|sort.int()|lang="rsplus"}} является наиболее «узким» местом всех расчётов.

Иногда, чтобы выяснить какой функции принадлежит тот или иной вызов, приходится анализировать содержимое функций. Чтобы увидеть содержимое функции, можно воспользоваться функцией {{Inline-code|getAnywhere()|lang="rsplus"}}. Например:

<syntaxhighlight lang="rsplus">
getAnywhere(median.default)
A single object matching ‘median.default’ was found
It was found in the following places
  package:stats
  registered S3 method for median from namespace stats
  namespace:stats
with value

function (x, na.rm = FALSE) 
{
    if (is.factor(x) || is.data.frame(x)) 
        stop("need numeric data")
    if (length(names(x))) 
        names(x) <- NULL
    if (na.rm) 
        x <- x[!is.na(x)]
    else if (any(is.na(x))) 
        return(x[FALSE][NA])
    n <- length(x)
    if (n == 0L) 
        return(x[FALSE][NA])
    half <- (n + 1L)%/%2L
    if (n%%2L == 1L) 
        sort(x, partial = half)[half]
    else mean(sort(x, partial = half + 0L:1L)[half + 0L:1L])
}
<bytecode: 0x3c8f828>
<environment: namespace:stats>
</syntaxhighlight>

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

С учётом выявленных «узких» мест нашей функции и проанализировав исходный код функций, мы можем оптимизировать нашу исходную функцию для достижения максимальной производительности. Наш вариант оптимизированной функции будет выглядеть следюущим образом:

<syntaxhighlight lang="rsplus">
desc <- function(x) {
    n <- length(x)
    mean <- sum(x) / n
    sd <- sqrt(sum((x - mean)^2) / (n - 1))
    min <- min(x)
    max <- max(x)
    half <- (n + 1L) %/% 2L
    if (n %% 2L == 1L)
        median <- .Internal(psort(x, half))[half]
    else
        median <- sum(.Internal(psort(x, c(half, half + 1)))[c(half, half + 1)]) / 2L
    return(c(n, mean, median, sd, min, max))
}
</syntaxhighlight>

Вместо функций {{Inline-code|median()|lang="rsplus"}} и {{Inline-code|sd()|lang="rsplus"}} мы использовали общеизвестные формулы. А для расчёта медианы была взята часть оригинальной функции {{Inline-code|median.default|lang="rsplus"}}, в которой вызов функций {{Inline-code|sort()|lang="rsplus"}} был заменён на более быстрый вызов {{Inlince-code|.internal(psort)|lang="rsplus}}.

== Примечания ==

<references />

== Ссылки ==

* Luke Tierney and Riad Jarjour (2013). proftools: Profile Output Processing Tools for R. R package version 0.1-0.
*: http://CRAN.R-project.org/package=proftools
* Hadley Wickham (2011). profr: An alternative display for profiling information. R package version 0.2.
*: http://CRAN.R-project.org/package=profr
* Noam Ross (2013). noamtools: Convenience functions. R package version 0.1.
*: https://github.com/noamross/noamtools

[[Категория:R]]
[[Категория:Оптимизация кода]]