From sfalcon at fhcrc.org  Sun May 14 21:37:30 2006
From: sfalcon at fhcrc.org (Seth Falcon)
Date: Sun, 14 May 2006 12:37:30 -0700
Subject: [Rd] Suggestion for system.time()
In-Reply-To: <20060514140852.GA8854@phenix.sram.qc.ca> (=?iso-8859-1?Q?Fra?=
	=?iso-8859-1?Q?n=E7ois?= Pinard's message of "Sun, 14 May 2006 10:08:52
	-0400")
References: <20060514140852.GA8854@phenix.sram.qc.ca>
Message-ID: <m21wuwqtxh.fsf@ziti.local>

Fran?ois Pinard <pinard at iro.umontreal.ca> writes:

> Hi, people.  A tiny suggestion for the system.time function.
>
> Could the returned vector have names?  These could be like:
>
>    c("User", "System", "Elapsed", "Sub.User", "Sub.System")
>
> That would then produce self-documenting output.

Here's a function you could try.  It names the result as you
suggested.  It also can be nested, which system.time cannot, because
it uses on.exit without specifying add=TRUE.

timeit <- function (expr, gcFirst = TRUE) 
{
    nms <- c("User", "System", "Elapsed", "Sub.User", "Sub.System")
    if (!exists("proc.time")) {
        ans <- rep(as.numeric(NA), 5)
        names(ans) <- nms
        return(ans)
    }
    loc.frame <- parent.frame()
    if (gcFirst) 
        gc(FALSE)
    expr <- substitute(expr)
    time <- proc.time()
    show_time <- function() {
        t <- proc.time() - time
        names(t) <- nms
        cat("Timing stopped at:\n")
        print(t)
        t 
    }
    tryCatch(eval(expr, envir = loc.frame),
             error=function(e) {
                 msg <- paste("Error in", deparse(conditionCall(e)),
                              ":", conditionMessage(e), "\n")
                 cat(msg)
             })
    show_time()
}


## Examples


> t <- timeit(z <- rnorm(10000))
Timing stopped at:
      User     System    Elapsed   Sub.User Sub.System 
     0.007      0.001      0.008      0.000      0.000 
> t
      User     System    Elapsed   Sub.User Sub.System 
     0.007      0.001      0.008      0.000      0.000 

## Nested calls.  I dunno, could be useful in some debugging 
## situations *shrug*


> t <- timeit({z <- rnorm(10000);timeit(q <- runif(50000))})
Timing stopped at:
      User     System    Elapsed   Sub.User Sub.System 
     0.012      0.002      0.014      0.000      0.000 
Timing stopped at:
      User     System    Elapsed   Sub.User Sub.System 
     0.090      0.003      0.146      0.000      0.000 
> t
      User     System    Elapsed   Sub.User Sub.System 
     0.090      0.003      0.146      0.000      0.000 


## With an error

> t <- timeit(plot(foobarbaz))
Error in plot(foobarbaz) : object "foobarbaz" not found 
Timing stopped at:
      User     System    Elapsed   Sub.User Sub.System 
     0.002      0.000      0.038      0.000      0.000 
> t
      User     System    Elapsed   Sub.User Sub.System 
     0.002      0.000      0.038      0.000      0.000



[Rd] Suggestion for system.time()
Seth Falcon