Skip to content

Commit

Permalink
Support wall-clock time profiling on Unix (PR#18076).
Browse files Browse the repository at this point in the history
git-svn-id: https://svn.r-project.org/R/trunk@84898 00db46b3-68df-0310-9c12-caf00c1e9a41
  • Loading branch information
kalibera committed Aug 7, 2023
1 parent 9b34947 commit 8b6057c
Show file tree
Hide file tree
Showing 4 changed files with 247 additions and 98 deletions.
8 changes: 5 additions & 3 deletions src/library/utils/R/Rprof.R
Original file line number Diff line number Diff line change
@@ -1,7 +1,7 @@
# File src/library/utils/R/Rprof.R
# Part of the R package, https://www.R-project.org
#
# Copyright (C) 1995-2013 The R Core Team
# Copyright (C) 1995-2023 The R Core Team
#
# This program is free software; you can redistribute it and/or modify
# it under the terms of the GNU General Public License as published by
Expand All @@ -19,12 +19,14 @@
Rprof <- function(filename = "Rprof.out", append = FALSE, interval = 0.02,
memory.profiling = FALSE, gc.profiling = FALSE,
line.profiling = FALSE, filter.callframes = FALSE,
numfiles = 100L, bufsize = 10000L)
numfiles = 100L, bufsize = 10000L,
event = c("default", "cpu", "wall"))
{
event <- match.arg(event)
if(is.null(filename)) filename <- ""
invisible(.External(C_Rprof, filename, append, interval, memory.profiling,
gc.profiling, line.profiling, filter.callframes,
numfiles, bufsize))
numfiles, bufsize, event))
}

Rprofmem <- function(filename = "Rprofmem.out", append = FALSE, threshold = 0)
Expand Down
84 changes: 52 additions & 32 deletions src/library/utils/man/Rprof.Rd
Original file line number Diff line number Diff line change
@@ -1,6 +1,6 @@
% File src/library/utils/man/Rprof.Rd
% Part of the R package, https://www.R-project.org
% Copyright 1995-2022 R Core Team
% Copyright 1995-2023 R Core Team
% Distributed under GPL 2 or later

\name{Rprof}
Expand All @@ -13,7 +13,8 @@
Rprof(filename = "Rprof.out", append = FALSE, interval = 0.02,
memory.profiling = FALSE, gc.profiling = FALSE,
line.profiling = FALSE, filter.callframes = FALSE,
numfiles = 100L, bufsize = 10000L)
numfiles = 100L, bufsize = 10000L,
event = c("default", "cpu", "wall"))
}
\arguments{
\item{filename}{
Expand All @@ -24,49 +25,68 @@ Rprof(filename = "Rprof.out", append = FALSE, interval = 0.02,
logical: should the file be over-written or appended to?
}
\item{interval}{
real: time interval between samples.
real: distance (time interval) between samples.
}
\item{memory.profiling}{logical: write memory use information to the file?}
\item{gc.profiling}{logical: record whether GC is running?}
\item{line.profiling}{logical: write line locations to the file?}
\item{filter.callframes}{logical: filter out intervening call frames
of the call tree. See the filtering out call frames section.}
\item{numfiles, bufsize}{integers: line profiling memory allocation}
\item{event}{
character: profiling event, character vector of length one,
\code{"wall"} for wall-clock time and \code{"cpu"} for CPU
time, both measured in seconds. \code{"default"} is the default
event on the platform, one of the two. See the \sQuote{Details}.
}
}
\details{
Enabling profiling automatically disables any existing profiling to
another or the same file.
Profiling works by writing out the call stack every \code{interval}
seconds, to the file specified. Either the \code{\link{summaryRprof}}
function or the wrapper script \command{R CMD Rprof} can be used to
process the output file to produce a summary of the usage; use
\command{R CMD Rprof --help} for usage information.
How time is measured varies by platform:
\describe{
\item{On Windows:}{
Exactly what the time interval measures is subtle: it is time that the
\R process is running and executing an \R command. It is not however just
CPU time, for if \code{readline()} is waiting for input, that counts
(on Windows, but not on a Unix-alike).
Note that the timing interval cannot be too small, for the time spent
in each profiling step is added to the interval. What is feasible is
machine-dependent, but 10ms seemed as small as advisable on a 1GHz machine.
}
\item{On Unix-alikes}{it is the CPU
time of the \R process, so for example excludes time when \R is waiting
for input or for processes run by \code{\link{system}} to return.
Note that the timing interval cannot usefully be too small: once the
timer goes off, the information is not recorded until the next timing
click (probably in the range 1--10 ms).
}
}
On Linux, the interval needs to be at least 10ms, on all other platforms
at least 1ms. Shorter intervals will be rounded up with a warning.
seconds (units of the profiling event), to the file specified. Either the
\code{\link{summaryRprof}} function or the wrapper script \command{R CMD
Rprof} can be used to process the output file to produce a summary of the
usage; use \command{R CMD Rprof --help} for usage information.
Exactly what is measured is subtle and depends on the profiling event.
With \code{"wall"} (the default and only supported event on Windows): it
is time that the \R process is running and executing an \R command. It is
not however just CPU time, for if \code{readline()} is waiting for input,
that counts as well.
With \code{"cpu"} (the default on Unix and typically the preferred event
for identifying performance bottlenecks), it is CPU time of the \R process,
so for example excludes time when \R is waiting for input or for processes
run by \code{\link{system}} to return. It may go slower than
\code{"wall"} when the process is often waiting for I/O to finish, but it
may go faster with actively computing concurrent threads (say via OpenMP)
on a multi-core system.
Note that the (timing) interval cannot be too small. With \code{"cpu"},
the time spent in each profiling step is currently added to the interval.
With all profiling events, the computation in each profiling step causes
perturbation to the observed system and biases the results. What is
feasible is machine-dependent. On Linux, R requires the interval to be at
least 10ms, on all other platforms at least 1ms. Shorter intervals will
be rounded up with a warning.
The \code{"default"} profiling event is \code{"wall"} on Windows and
\code{"cpu"} on Unix.
Support for \code{"wall"} event on Unix is new and considered
experimental. To reduce the risk of missing a sample, R tries to use the
(real-time) FIFO scheduling policy with the maximum scheduling priority
for an internal thread which initiates collection of each sample. If
setting that priority fails, it tries to use the maximum scheduling
priority of the current scheduling policy, falling back to the current
scheduling parameters. On Linux, regular users are typically not allowed
to use the real-time scheduling priorities. This can be usually allowed
via PAM (e.g. \file{/etc/security/limits.conf}), see the OS documentation
for details. The priorities only matter when profiling a system under
high load.
Functions will only be recorded in the profile log if they put a
context on the call stack (see \code{\link{sys.calls}}). Some
Expand Down
4 changes: 2 additions & 2 deletions src/library/utils/src/init.c
Original file line number Diff line number Diff line change
@@ -1,6 +1,6 @@
/*
* R : A Computer Language for Statistical Data Analysis
* Copyright (C) 2012-2022 The R Core Team.
* Copyright (C) 2012-2023 The R Core Team.
*
* This program is free software; you can redistribute it and/or modify
* it under the terms of the GNU General Public License as published by
Expand Down Expand Up @@ -80,7 +80,7 @@ static const R_ExternalMethodDef ExtEntries[] = {
EXTDEF(download, 6),
#endif
EXTDEF(unzip, 7),
EXTDEF(Rprof, 9),
EXTDEF(Rprof, 10),
EXTDEF(Rprofmem, 3),

EXTDEF(countfields, 6),
Expand Down
Loading

0 comments on commit 8b6057c

Please sign in to comment.