跟踪函数名称、开始时间和完成时间答案

【问题标题】：Track functions name, when started and when finished跟踪函数名称、开始时间和完成时间
【发布时间】：2022-09-26 00:53:02
【问题描述】：

我正在尝试跟踪函数的名称、开始和结束。也就是说，当一个函数执行时，我尝试获取函数的名称、启动时间和完成时间。我使用两个函数，\"on.exit()\" 和 \"match.call()\"。他们工作完美。

abcde<-function(){
  cat(paste(\"\\n function started:\",match.call(),\"\\n \",Sys.time(),\"\\n\"))
  on.exit({
    cat(paste(\"\\n function finished:\",match.call(),\"\\n \",Sys.time(),\"\\n\"))
   })
  Sys.sleep(2)
}
abcde()

我正在尝试创建一个功能来执行此操作（因为我有太多功能）：

mf_on_exit_start<-function(match_call=match.call()){
  cat(paste(\"\\n function started:\",match_call,\"\\n \",Sys.time(),\"\\n\"))
  on.exit({
    cat(paste(\"\\n function finished:\",match_call,\"\\n \",Sys.time(),\"\\n\"))
  })
}
abcdef<-function(){
  mf_on_exit_start(match.call())
  Sys.sleep(2)
}
abcdef()

但不幸的是，该功能不起作用！

标签： r

【解决方案1】：

您的方法需要您的 mf_on_exit_start 在其调用者中设置 on.exit（即在 abcdef() 中），但这是不可能的。 on.exit 始终仅适用于当前函数。

为了做你想做的事，你需要重新组织事情，以便on.exit 发生在abcdef() 的调用者中。例如，

with_mf <- function(expr) {
  call <- deparse(substitute(expr))
  cat(paste("\n function started:",call,"\n ",Sys.time(),"\n"))
  on.exit({
    cat(paste("\n function finished:",call,"\n ",Sys.time(),"\n"))
  })
  expr
}

abcdef<-function(){
  Sys.sleep(2)
}

with_mf(abcdef())
#> 
#>  function started: abcdef() 
#>   2022-07-16 05:07:27 
#> 
#>  function finished: abcdef() 
#>   2022-07-16 05:07:29

^{由reprex package (v2.0.1) 于 2022 年 7 月 16 日创建}

【讨论】：

【解决方案2】：

最好的方法是使用装饰器功能。

counter<-function(fn){
  force(fn)
  cnt<-0
  inner <- function(...){
    cnt <<- cnt+1
    message(sprintf("Function %s was called %s times",
                    as.character(match.call()[[1]]), cnt))
    message(paste("\n function started:",match.call()[[1]],"\n ",Sys.time(),"\n"))
    on.exit({
      message(paste("\n function finished:",match.call()[[1]],"\n ",Sys.time(),"\n"))
      
    })
    return(fn(...))
  }
  return(inner)
  
}

add<-function(a,b){
  Sys.sleep(3)
  return(a+b)
}
add<-counter(add)
add(1,2)
Function add was called 1 times

function started: add 
2022-09-25 20:21:12 


function finished: add 
2022-09-25 20:21:15 

[1] 3
add(2,6)
Function add was called 2 times

function started: add 
2022-09-25 20:21:15 


function finished: add 
2022-09-25 20:21:18 

[1] 8
mult<-function(a,b) {
  Sys.sleep(2)
  return(a*b)
}
mult<-counter(mult)
mult(2,6)
Function mult was called 1 times

function started: mult 
2022-09-25 20:21:18 


function finished: mult 
2022-09-25 20:21:20 

[1] 12

我们实质上修改了“add”函数（或 mult 函数），将其包装在另一个为其添加了一些功能的函数中。我们说我们用函数“counter”装饰了函数“add”，我们称“counter”函数为装饰器函数。

另一个例子是here

【讨论】：