dwtools (version 0.8.3.9)

timing: Measure timing and expression metadata

Description

Collect expressions, timings, nrows in-out when possible. Optionally log to database.

Usage

timing(expr, in.n = NA_integer_, tag = NA_character_, .timing = TRUE, .timing.name = getOption("dwtools.timing.name"), .timing.conn.name = getOption("dwtools.timing.conn.name"), verbose = getOption("dwtools.timing.verbose"))

Arguments

expr

expression.

in.n

integer manually provided input object nrow.

tag

character custom processing message to be logged with that entry. Vector will be collapse to scalar by getOption("dwtools.tag.sep",";").

.timing

logical easy escape timing function without timing.

.timing.name

character

.timing.conn.name

character, when NULL then timings logs are stored in-memory, see get.timing.

verbose

integer, if greater than 0 then print debugging messages. It will use tag argument. It is designed to serve verbose functionallity for user processes, not for the dwtools functions.

Details

Use option options("dwtools.timing"=TRUE) to turn on timing measurment in functions which supports timing measurement (e.g. db, build_hierarchy). To log timing to db connection, setup options("dwtools.db.conns", provide connection name to options("dwtools.timing.conn.name"="sqlite1") and target table options("dwtools.timing.name"="dwtools_timing") (default) otherwise timing will logged to in-memory table, which can be accessed by get.timing().

See Also

get.timing, db, build_hierarchy, dbCopy

Examples

suppressPackageStartupMessages(library(dwtools))

# populate DT
DT = dw.populate(N=1e5, scenario="fact")

# classic time measurement
system.time(
  DT[,lapply(.SD,sum),by=list(geog_code,time_code,curr_code),.SDcols=c("amount","value")]
)

# timing to R session memory
options("dwtools.timing.conn.name"=NULL) # default
r = timing(
  DT[,lapply(.SD,sum),by=list(geog_code,time_code,curr_code),.SDcols=c("amount","value")],
  in.n = nrow(DT)
)
print(r)
get.timing() # trunc expression field
get.timing(FALSE) # return full expression field
get.timing(TRUE) # omit expr field

# some more timing
invisible(sapply(1:3/10, function(time) timing(Sys.sleep(time))))
get.timing()
# timing and keep parameters value instead of variable symbol
invisible(sapply(3:1/10, function(time) eval(bquote(timing(Sys.sleep(.(time)))))))
get.timing()
purge.timing() # clear in-memory timing logs
get.timing()

# timing to db
library(RSQLite)
sqlite1 = list(drvName="SQLite",dbname="sqlite1.db")
sqlite1$conn = dbConnect(SQLite(), dbname=sqlite1$dbname)
options("dwtools.db.conns"=list(sqlite1=sqlite1))
options("dwtools.timing.conn.name"="sqlite1")
#options("dwtools.timing.name"="dwtools_timing") # default, timing table name
r = timing(
  DT[,lapply(.SD,sum),by=list(geog_code,time_code,curr_code),.SDcols=c("amount","value")],
  nrow(DT)
)
get.timing() # no in-memory logs
db("dwtools_timing") # query timing log from db

# timing db function, scalar
r = timing(db(DT, "sales"), nrow(DT))
db("dwtools_timing")
db("sales")
db("DROP TABLE sales")

# timing vectorized db function
r = db(DT, c("sales","sales_20141211"),timing=TRUE) # insert DT to two tables, including timing
db("dwtools_timing")

# auto timing, supported functions: db, build_hierarchy, dbCopy
options("dwtools.timing"=TRUE)
r = db(DT, "sales")
db("dwtools_timing")

# timing logs to in-memory (still by auto timing option)
options("dwtools.timing.conn.name"=NULL)
r = db(DT, c("sales","sales_20141211")) # insert DT to two tables
get.timing()

## clean up

dbDisconnect(sqlite1$conn)
file.remove(sqlite1$dbname)
options("dwtools.db.conns"=NULL,"dwtools.timing.conn.name"=NULL,"dwtools.timing"=FALSE)