r - R：如何让system.time打印出被计时的表达式？

Question

我有大量R相互调用的函数，它们可能需要很长时间，所以我使用以下方法调用它们system.time：

f1 <- function () {
  print(system.time(f1.1()))
  print(system.time(f1.2()))
  print(system.time(f1.3()))
}
...
f <- function () {
  print(system.time(f1()))
  print(system.time(f2()))
  print(system.time(f3()))
}

然后输出f()看起来像

             user            system           elapsed 
129.599 (2.16min)  0.663 (663.00ms) 130.438 (2.17min) 
    wrote 447,337,021 bytes
              user             system            elapsed 
2746.37 (45.77min)  145.299 (2.42min) 2896.68 (48.28min) 
            user           system          elapsed 
 9.544 (9.54sec) 0.755 (755.00ms)  10.3 (10.30sec) 

并且需要一些时间来弄清楚函数和时序之间的对应关系。

我试过这个功能：

verbose <- function (expr) {
  ret <- system.time(expr)
  cat("<<<<<<")
  print(expr)
  print(ret)
}
> verbose(Sys.sleep(2))
<<<<<<NULL
           user          system         elapsed 
     0 (0.00ms)      0 (0.00ms) 2.002 (2.00sec) 

唉，它打印NULL而不是Sys.sleep(2)（即，值而不是表达式）。

那么，如何保存expr's 的打印表示以verbose供将来输出？

Answer 1

您的函数verbose可以通过添加substitute打印您传递给参数的值expr。

将行更改print(expr)为

print(substitute(expr))

然后

> verbose(Sys.sleep(2))
<<<<<<Sys.sleep(2)
   user  system elapsed 
  0.023   0.007   2.009 

Answer 2

虽然不完全符合您的要求，但我使用以下包装器System.time作为我的个人 utils 文件的一部分：

  s.t <- function(expr, msg="", verbose=TRUE, gcFirst=FALSE, title="") { 
  # wrapper for system.time
  # title is an alternate for msg, where user needs simply give a name to the section being timed.
  # msg is for a custome message before the sytem.time output

    ret <- capture.output(system.time(expr=expr, gcFirst=gcFirst))
    ret <- paste(ret, collapse="\n")

    if (nchar(title))
      msg <- paste0("Time to complete ", title, ":")

    if (verbose){
      if (nchar(msg) == 0)
        cat(ret)
      else 
        cat(paste(msg, collapse=""), ret, sep="\n")
    }
  }  

---

我将它与一个可选verbose标志结合使用，以便我可以在需要时轻松关闭所有计时。