Skip to content

[R-pkg-devel] Unexpected multi-core CPU usage in package tests

3 messages · Ivan Krylov, Jon Clayden

Original
Jon Clayden
# 
Dear all,

I'm slightly going out of my mind trying to resolve a CRAN rejection
based on the note

    Flavor: r-devel-linux-x86_64-debian-gcc
    Check: tests, Result: NOTE
        Running 'tinytest.R' [20s/5s]
      Running R code in 'tinytest.R' had CPU time 4.4 times elapsed time

This applies to package 'tractor.base', which contains no compiled
code and is not parallelised, but has (first-party) package 'mmand' as
a dependency, which uses OpenMP where available.

Further investigation suggests that skipping the tests that use that
package doesn't resolve the issue, and indeed it seems to occur in
another dependency, 'RNifti', which doesn't use OpenMP, and has no
hard dependencies of its own except 'Rcpp'.

My testing route is to install the packages within the
'rocker/r-devel' Docker container, which is Debian-based, then use
'time' to evaluate CPU usage. Note that, even though 'RNifti' does not
use OpenMP, setting OMP_NUM_THREADS changes its CPU usage:

    # /usr/bin/time Rscript -e "library(RNifti);
testthat::test_dir('tests/testthat')"
    ...
    5.46user 4.88system 0:04.06elapsed 254%CPU (0avgtext+0avgdata
387244maxresident)k
    0inputs+8032outputs (208major+97868minor)pagefaults 0swaps

    # /usr/bin/time env OMP_NUM_THREADS=1 Rscript -e "library(RNifti);
testthat::test_dir('tests/testthat')"
    ...
    3.54user 0.13system 0:03.67elapsed 100%CPU (0avgtext+0avgdata
382060maxresident)k
    0inputs+8032outputs (222major+98893minor)pagefaults 0swaps

I see similar results for packages using 'tinytest' as well as
'testthat'. I am not requesting parallelised testing from either
framework.

So, my questions are

(i) is there something wrong with this evaluation that's leading me astray?
(ii) what might the source of this unexpected parallelism be?
(iii) how can I reliably meet CRAN's requirement not to use too many
CPU cores, other than setting OMP_NUM_THREADS before starting R, which
I can't control?

Thanks in advance.

All the best,
Jon
1 day later
Ivan Krylov
# 
? Tue, 27 Feb 2024 11:14:19 +0000
Jon Clayden <jon.clayden at gmail.com> ?????:
I think that's because rocker/r-devel uses parallel OpenBLAS:

$ podman run --rm -it docker.io/rocker/r-devel \
 R -q -s -e 'sessionInfo()' | grep -A1 BLAS
BLAS:   /usr/lib/x86_64-linux-gnu/openblas-pthread/libblas.so.3 
LAPACK: /usr/lib/x86_64-linux-gnu/openblas-pthread/libopenblasp-r0.3.24.so;  LAPACK version 3.11.0

The incoming CRAN check machine either sets the BLAS parallellism to 1
or uses a non-parallel BLAS. With rocker/r-devel, you can run R with
the environment variable OPENBLAS_NUM_THREADS set to 1. It's been
effective in the past to run R -d gdb and set a breakpoint on
pthread_create before launching the test. (In theory, it may be
required to set a breakpoint on every system call that may be used to
create threads, including various variations of clone(), subject to
variations between operating systems, but pthread_create has been
enough for me so far.)

With OPENBLAS_NUM_THREADS=1, I'm only seeing OpenMP threads created by
the mmand package during tests for your package tractor.base, and the
latest commit (that temporary disables testing of mmand) doesn't hit
the breakpoint or raise any NOTEs at all.
Jon Clayden
#
On Wed, 28 Feb 2024 at 17:36, Ivan Krylov <ikrylov at disroot.org> wrote:
Very many thanks for testing this, Ivan. I did come across the
breakpoint suggestion when searching on this, and tried it, but I ran
into some problems with gdb within the container. Your experiments
confirm that my yardstick was just misleading me; I will add support
for explicitly setting the thread count within mmand, which should
give me a longer-term solution.

Thanks again,
Jon