Как определить наиболее трудоемкие части сценария

Question

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

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

Как это эффективно отследить?

Answer 1

Рассмотрим следующие три функции: Start(), End() и Timestamps().

Чтобы начать отслеживать время процесса, вы добавляете функцию Start() в начале кода, который собираетесь обрабатывать. Вы должны указать метку, которая описывает, какой код отслеживается по времени, и вы должны указать, в какую глобальную переменную вы хотите сохранить метки времени.

Эквивалентно, End() прекратит отслеживать время последнего отслеживаемого процесса. Здесь вам нужно только указать глобальную переменную в качестве аргумента. Нет необходимости применять End() в явном виде, потому что запуск нового экземпляра отслеживания времени с Start() сделает это автоматически. Тем не менее, End() полезно, если вы явно хотите завершить отслеживание времени.

И, наконец, Timestamps() суммирует все метки времени по их меткам, а функция предоставит среднее значение, коэффициент вариации, количество временных меток с этой меткой и общее время, потраченное на метки времени с этой меткой. Эти результаты будут напечатаны на консоли.

library(dplyr)

Функция Start():

Start <- function(label, time_stamps){

  # ————————————————————————————————————————————————————————————————————————————
  # See if timestamp exists and create a new global env variable if not
  # ————————————————————————————————————————————————————————————————————————————

  time_stamps_exists <- exists(as.character(substitute(time_stamps)), envir=.GlobalEnv)

  if (!time_stamps_exists){
    assign(
      x = deparse(substitute(time_stamps)), 
      value = data.frame(
        label = character(),
        start = character(),
        end = character(),
        duration = numeric(),
        stringsAsFactors = F
      ), 
      env = .GlobalEnv)
  }


  # ————————————————————————————————————————————————————————————————————————————
  # Get the global env variable
  # ————————————————————————————————————————————————————————————————————————————

  df <- get(
    x = deparse(substitute(time_stamps)), 
    envir = .GlobalEnv)


  # ————————————————————————————————————————————————————————————————————————————
  # Add end stamp and duration on last instance if not done yet
  # ————————————————————————————————————————————————————————————————————————————

  if (nrow(df) > 0 && is.na(df$end[nrow(df)])){
    end_stamp <- 
      as.POSIXlt(Sys.time(), "%Y-%m-%d %H:%M:%OS3", tz = "CET") %>% 
      format(., "%Y-%m-%d %H:%M:%OS3")

    df$end[nrow(df)] <- end_stamp

    df$duration[nrow(df)] <- 
      difftime(
        df$end[nrow(df)], 
        df$start[nrow(df)], 
        units=c("secs")) %>%
      as.numeric()
  }


  # ————————————————————————————————————————————————————————————————————————————
  # Create new row
  # ————————————————————————————————————————————————————————————————————————————

  df. <- data.frame(
    label = label,
    start = 
      as.POSIXlt(Sys.time(), "%Y-%m-%d %H:%M:%OS3", tz = "CET") %>% 
      format(., "%Y-%m-%d %H:%M:%OS3"),
    end = as.POSIXct("", format="%Y-%m-%d"),
    duration = NaN,
    stringsAsFactors = F
  )

  df <- rbind(df, df.)


  # ————————————————————————————————————————————————————————————————————————————
  # Save to global env variable
  # ————————————————————————————————————————————————————————————————————————————

  assign(
    x = deparse(substitute(time_stamps)), 
    value = df, 
    env = .GlobalEnv)
}

Функция End():

End <- function(time_stamps, label = NULL){

  # ————————————————————————————————————————————————————————————————————————————
  # Get the global env variable
  # ————————————————————————————————————————————————————————————————————————————

  df <- get(
    x = deparse(substitute(time_stamps)),
    envir = .GlobalEnv)


  # ————————————————————————————————————————————————————————————————————————————
  # Add end stamp and duration on last instance if not done yet
  # ————————————————————————————————————————————————————————————————————————————

  end_stamp <-
    as.POSIXlt(Sys.time(), "%Y-%m-%d %H:%M:%OS3", tz = "CET") %>%
    format(., "%Y-%m-%d %H:%M:%OS3")

  df$end[nrow(df)] <- end_stamp

  df$duration[nrow(df)] <-
    difftime(
      df$end[nrow(df)],
      df$start[nrow(df)],
      units=c("secs")) %>%
    as.numeric()


  # ————————————————————————————————————————————————————————————————————————————
  # Save to global env variable
  # ————————————————————————————————————————————————————————————————————————————

  assign(
    x = deparse(substitute(time_stamps)),
    value = df,
    env = .GlobalEnv)

  if (!is.null(label)){
    printf("Ended %s", label)
  }
}

The Timestamps() function

Timestamps <- function(time_stamps, end_last = FALSE, head = NULL){

  # ————————————————————————————————————————————————————————————————————————————
  # Get the global env variable
  # ————————————————————————————————————————————————————————————————————————————

  df <- get(
    x = deparse(substitute(time_stamps)), 
    envir = .GlobalEnv)


  # ————————————————————————————————————————————————————————————————————————————
  # End last timestmap if necessary and reload the global env variable
  # ————————————————————————————————————————————————————————————————————————————

  if (nrow(df) > 0 && is.na(df$end[nrow(df)])){
    End(time_stamps, "timestamp to study summary")

    df <- get(
      x = deparse(substitute(time_stamps)), 
      envir = .GlobalEnv)
  }


  # ————————————————————————————————————————————————————————————————————————————
  # Create summary to be printed
  # ————————————————————————————————————————————————————————————————————————————

  output <- data.frame(
    label = unique(df$label),
    mean  = c(NaN),
    cv    = c(NaN),
    n     = c(NaN)
  )

  for (row in 1:nrow(output)) {
    label_in_question <- output$label[row]

    durations <- df$duration[df$label == label_in_question]

    output$mean[row] <- mean(durations)
    output$cv[row] <- cv(durations)
    output$n[row] <- sum(df$label == label_in_question)
  }

  output$total_time <- output$mean * output$n

  output <- output[order(output$mean, decreasing = TRUE),]

  if (!is.null(head)){
    print(head(output, head))
  }else{
    print(output)
  }
}

Пример

for (i in 1:3) {
  Start("Running the 1st for loop", foo)
  Sys.sleep(2)
  End(foo)
}

Timestamps(foo)

Однако, если End() не вызывается до следующего Start(), тогда отметка времени последнего экземпляра будет автоматически остановлена ​​перед начиная новый экземпляр. Приведенный выше код эквивалентен следующему коду и дает такие же результаты, как и следующий код:

for (i in 1:3) {
  Start("Running the 1st for loop", foo)
  Sys.sleep(2)
}

Timestamps(foo, end_last = TRUE)

И, наконец, выполнение Timestamps(foo) выводит следующий вывод:

   label                     mean   cv          n  total_time
1  Running the 1st for loop  2.004  0.08643715  3  6.012