Echo-Zeitstempel im R-Batch-Modus

Question

Ich möchte die Ausführungsdauer von Anweisungen innerhalb eines R-Skripts im Batch-Modus besser verstehen. Gibt es einen guten Weg, dies zu tun?

Ich hatte einen Gedanken darüber, wie ich das gerne sehen würde. Bei Ausführung im Stapel wurde die Quelle in der angegebenen Protokolldatei wiedergegeben. Gibt es eine Möglichkeit, einen Zeitstempel neben dem Quellcode in dieser Protokolldatei anzuzeigen?

> R CMD BATCH script.R script.Rout 

Hier ist der Ausgang, den ich heute sehe.

> tail -f script.Rout 
... 
> # features related to the date 
> trandateN <- as.integer(trandate) 
> dayOfWeek <- as.integer(wday(trandate)) 
> holiday <- mapply(isHoliday, trandate) 

Ich möchte etwas sehen, wie ...

> tail -f script.Rout 
... 
2013-06-27 11:18:01 > # features related to the date 
2013-06-27 11:18:01 > trandateN <- as.integer(trandate) 
2013-06-27 11:18:05 > dayOfWeek <- as.integer(wday(trandate)) 
2013-06-27 11:19:02 > holiday <- mapply(isHoliday, trandate) 

Answer 1

Sie können addTaskCallback verwenden, wie ein Protokoll jeder Top-Level-Ausführung erstellen folgt.

.log <- data.frame(time=character(0), expr=character(0)) 
.logger <- function(expr, value, ok, visible) { # formals described in ?addTaskCallback 
    time <- as.character(Sys.time()) 
    expr <- deparse(expr) 
    .log <<- rbind(.log, data.frame(time, expr)) 
    return(TRUE) # required of task callback functions 
} 
.save.log <- function() { 
    if (exists('.logger')) write.csv(.log, 'log.csv') 
} 
addTaskCallback(.logger) 

x <- 1:10 
y <- mean(x) 

.save.log() 
.log 
#      time      expr 
# 1 2013-06-27 12:01:45.837 addTaskCallback(.logger) 
# 2 2013-06-27 12:01:45.866    x <- 1:10 
# 3 2013-06-27 12:01:45.876    y <- mean(x) 
# 4 2013-06-27 12:01:45.900    .save.log() 

Natürlich stattdessen die Todsünde begehen eine data.frame reihenweise wachsen, wie ich hier, könnten Sie einfach eine Verbindung zu öffnen und schreiben, die unmittelbar in Datei, mit on.exit die Verbindung geschlossen wird.

Und wenn Sie darüber ordentlich sein wollen, können Sie das Logging-Setup in eine Funktion packen ziemlich schön.

.log <- function() { 
    .logger <<- local({ 
     log <- data.frame(time=character(0), expr=character(0)) 
     function(expr, value, ok, visible) { 
      time <- as.character(Sys.time()) 
      expr <- deparse(expr) 
      log <<- rbind(log, data.frame(time, expr)) 
      return(TRUE) 
     } 
    }) 
    invisible(addTaskCallback(.logger)) 
} 

.save.log <- function() { 
    if (exists('.logger')) 
     write.csv(environment(.logger)$log, 'log.csv') 
} 

.log() 
x <- 1:10 
y <- mean(x) 
.save.log() 

Answer 2

Siehe ?Sys.time. Es gibt eine POSIXct Datetime zurück, die Sie bei der Ausgabe in eine Protokolldatei formatieren müssen.

cat(format(Sys.time()), " is the current time\n")