In this nineteenth article in the R series, we shall learn about profiling R code.
We will use R version 4.2.1 installed on Parabola GNU/Linux-libre (x86-64) for the code snippets in this article.
$ R --version R version 4.2.1 (2022-06-23) -- “Funny-Looking Kid” Copyright (C) 2022 The R Foundation for Statistical Computing Platform: x86_64-pc-linux-gnu (64-bit) R is free software and comes with ABSOLUTELY NO WARRANTY. You are welcome to redistribute it under the terms of the GNU General Public License versions 2 or 3. For more information about these matters see https://www.gnu.org/licenses/.
system.time
Consider the ‘Bank Marketing Data Set’ for a Portuguese banking institution available from the UCI Machine Learning Repository available at https://archive.ics.uci.edu/ml/datasets/Bank+Marketing. The data can be used for public research use. There are four data sets available, and we will use the read.csv() function to import the data from a ‘full-bank.csv’ file. The system.time() function on an R expression provides the user, system and total time for the program, as shown below:
> system.time(bank <- read.csv(file=”bank-full.csv”, sep=”;”)) user system elapsed 0.129 0.000 0.135 > bank[1:3,] age job marital education default balance housing loan contact day 1 58 management married tertiary no 2143 yes no unknown 5 2 44 technician single secondary no 29 yes no unknown 5 3 33 entrepreneur married secondary no 2 yes yes unknown 5 month duration campaign pdays previous poutcome y 1 may 261 1 -1 0 unknown no 2 may 151 1 -1 0 unknown no 3 may 76 1 -1 0 unknown no
Another example is computing the cross-product of two matrices. The rnorm() function generates values for the normal distribution. It accepts ‘n’ number of observations along with values for mean and standard deviation. In the following code snippet, we are generating two matrices, ‘m’ and ‘n’, with 30 rows and 15,000 columns, and computing the cross-product between them using the crossprod() function. This is actually faster than calling ‘t(m) %*% y’.
> m = matrix(rnorm(30*15000, mean=0, sd=4), 30, 15000) > n = matrix(rnorm(30*15000, mean=0, sd=4), 30, 15000) > system.time(crossprod(m, n)) user system elapsed 3.716 0.339 4.058
object.size()
The object.size() function gives an estimate for the memory used by an object. It accepts an R object as its argument. You can also pass it a logical value for ‘quote’ to indicate if the result should be displayed within quotes. The ‘units’ argument can specify the units for printing the values. The following standards for the units are accepted – ‘legacy’, ‘IEC’, and ‘SI’. A numeric data type consumes 48 bytes, and with the data there is an additional 8 bytes of overhead.
> object.size(numeric()) 48 bytes > object.size(2) 56 bytes > object.size(m) 3600216 byte
Rprof and summaryRprof
The time spent by various R functions can be displayed using the Rprof() function. It takes the following arguments:
| Argument | Description |
| filename |
Output filename to store results. Use NULL to stop profiling |
| append | Logical value to append results or overwrite the file |
| interval | The time interval between taking samples. Default is 0.02 |
| memory.profiling | Logical value to write memory information to output file |
You can create a ‘profile.out’ results file using the Rprof() function to profile the crossprod()* function, as illustrated below:
> Rprof(filename = “profile.out”, append = FALSE, interval = 0.03, memory.profiling=TRUE)
> crossprod(m, n)
[,1] [,2] [,3] [,4] [,5]
[1,] 1.596159e+02 -8.97348864 -7.103962e+01 3.863508e+01 -1.168697e+02
[2,] -3.959816e+01 13.93104995 -7.210794e+01 3.495264e+01 4.697674e+01
[3,] 1.329374e+02 -80.40730081 5.745854e+01 -7.841128e+01 -8.069322e+01
[4,] 7.727353e+00 78.42727385 1.142679e+01 -9.473472e+01 -4.733995e+01
[5,] 1.341396e+02 -50.23056812 7.478321e+01 -5.869277e+01 -9.588495e+00
[6,] 1.741993e+01 45.03771290 5.569390e+01 -2.684412e+01 5.295564e+01
...
> Rprof(NULL)
After the profiling is stopped by using the ‘Rprof(NULL)’ command, the results can be viewed using the summaryRprof() function:
> summaryRprof(filename = “profile.out”)
$by.self
self.time self.pct total.time total.pct
“crossprod” 3.96 100 3.96 100
$by.total
total.time total.pct self.time self.pct
“crossprod” 3.96 100 3.96 100
$sample.interval
[1] 0.03
$sampling.time
[1] 3.96
Since we are only running the ‘crossprod()’ function, the output shows that it takes all the time in the computation. The ‘summaryRprof()’ function accepts the following arguments:
| Argument | Description |
| filename | The file generated by Rprof() |
| The file generated by Rprof() | Memory information |
| lines | Line information |
| index | Stack trace memory information |
| diff | Logical value to indicate the difference in memory |
| exclude | Any functions to filter out in the output |
The memory=“stat” option to the summaryRprof() function displays the maximum memory usage, as shown below:
> summaryRprof(filename = “profile.out”, memory=”stat”)
index: “crossprod”
vsize.small max.vsize.small vsize.large max.vsize.large
11749 1597864 13309000 1799964112
nodes max.nodes duplications tot.duplications
113647 15456000 0 0
samples
136
The time series memory information can be printed using the memory=“tseries” option, as follows:
> summaryRprof(filename = “profile.out”, memory=”tseries”)
vsize.small vsize.large nodes duplications stack:2
0.03 1597864 10059904 15456000 0 “crossprod”
0.06 0 1799964112 0 0 “crossprod”
0.09 0 0 0 0 “crossprod”
0.12 0 0 0 0 “crossprod”
0.15 0 0 0 0 “crossprod”
0.18 0 0 0 0 “crossprod”
0.21 0 0 0 0 “crossprod”
...
The contents of the profile.out file are provided for reference:
$ cat profile.out memory profiling: sample.interval=30000 :199733:1257488:15456000:0:”crossprod” :199459:226253002:15412208:0:”crossprod” :199459:226253002:15412208:0:”crossprod” :199459:226253002:15412208:0:”crossprod” :199459:226253002:15412208:0:”crossprod” ...
memory.profile()
The memory.profile() function provides memory usage information based on the object type. For example:
> memory.profile()
NULL symbol pairlist closure environment promise
1 6943 139922 3134 970 5923
language special builtin char logical integer
35223 47 697 8089 5501 24059
double complex character ... any list
1085 1 39918 0 0 11122
expression bytecode externalptr weakref raw S4 1 8843 976 1166 399 917
Rprofmem()
A more detailed memory profiling can be accomplished using the Rprofmem() function. It accepts the following arguments:
| Argument | Description |
| filename | The file to write output results |
| append | Logical value to indicate to append or overwrite the file |
| threshold | Allocations larger than R’s large vector heap will be reported |
You can initialise ‘Rprofmem()’ and then execute the ‘crossprod()’ function as illustrated in the example below. The ‘Rprofmem(NULL)’ command is used to stop the profiling. The contents of the output file show the memory used by the ‘crossprod()’ function.
> Rprofmem(“Rprofmem.out”, threshold=1000)
> crossprod(m, n)
[,1] [,2] [,3] [,4] [,5]
[1,] -33.86416785 -6.161515e+01 1.376119e+02 -1.494083e+01 5.784715e+01
[2,] -59.34911436 6.868712e+01 -1.899812e+01 -6.986599e+01 -1.165873e+02
[3,] -151.68100670 -7.330638e+01 -1.320967e+02 9.607252e+01 1.459454e+02
[4,] 132.50907447 4.157651e+01 7.621391e+01 -4.062714e+00 -9.967460e+01
[5,] -53.53606072 5.132813e+01 -3.571266e+01 -2.835573e+00 6.216842e+01
[6,] 41.33625436 -1.246898e+02 1.150376e+02 -7.413852e+01 -9.574722e-03
...
> Rprofmem(NULL)
$ cat Rprofmem.out
1800000048 :”crossprod”
60056 :
...
lineprof
The lineprof() built-in is used to provide profiling information for every line in an R program. You can install the same using the following steps:
> install.packages(“devtools”) > library(devtools) Loading required package: usethis > devtools::install_github(“hadley/lineprof”) Downloading GitHub repo hadley/lineprof@HEAD ... ** testing if installed package can be loaded from temporary location ** checking absolute paths in shared objects and dynamic libraries ** testing if installed package can be loaded from final location ** testing if installed package keeps a record of temporary installation path * DONE (lineprof)
Consider a function ‘f’ that creates two matrices, doubles its contents, and computes their cross-product. The usage of the ‘lineprof’ function is shown below:
> f <- function() {
+ m = matrix(rnorm(30*15000, mean=0, sd=4), 30, 15000)
+ n = matrix(rnorm(30*15000, mean=0, sd=4), 30, 15000)
+ a <- m * 2
+ b <- n * 2
+ crossprod(a, b)
+ }
> l <- lineprof(f())
> l
time alloc release dups ref src
1 0.005 2.151 0.000 0 c(“matrix”, “rnorm”) matrix/rnorm
2 0.410 214.577 0.878 0 “crossprod” crossprod
We again observe that the ‘crossprod()’ function takes the maximum memory allocation and computation time.
gc()
The gc() function triggers the garbage collection to free memory. It also displays information on available memory, as shown below:
> gc()
used (Mb) gc trigger (Mb) max used (Mb)
Ncells 294146 15.8 661162 35.4 464793 24.9
Vcells 2457665 18.8 220002509 1678.5 227627845 1736.7
tracemem()
The tracemem() function is used to debug memory usage issues in R. It can print a message whenever a marked object for tracing is copied. In the following example, we create an ‘a’ matrix and track its memory usage with the ‘tracemem’ function. The matrix is copied to a ‘b’ matrix, and its contents are then modified. This triggers a printing of the memory address in the output. You can finally stop tracing an R object with the untracemem() function, as shown below:
> a <- matrix(1:8, nrow=2)
> a
[,1] [,2] [,3] [,4]
[1,] 1 3 5 7
[2,] 2 4 6 8
> tracemem(a)
[1] “<0x563f0483c808>”
> b <- a
> b[1] <- 10
tracemem[0x563f0483c808 -> 0x563f04838078]:
tracemem[0x563f04838078 -> 0x563f04c850e8]:
> b
[,1] [,2] [,3] [,4]
[1,] 10 3 5 7
[2,] 2 4 6 8
> a
[,1] [,2] [,3] [,4]
[1,] 1 3 5 7
[2,] 2 4 6 8
> untracemem(a)
You are encouraged to read the help pages of the above R functions to learn more about their arguments, options and usage.
