R devel - Jan 2023 - rhub vs. CRAN fedora-*-devel, using armadillo & slapack

On 10/01/2023 4:07 p.m., Sebastian Meyer wrote:
> Am 10.01.23 um 21:28 schrieb Duncan Murdoch:
>> On 10/01/2023 2:05 p.m., Ivan Krylov wrote:
>>> On Tue, 10 Jan 2023 16:27:53 +0000
>>> RICHET Yann <yann.richet at irsn.fr> wrote:
>>>
>>>> In facts, 10 threads are asked by armadillo for some LinAlg,
which
>>>> backs to two threads as warned.
>>>
>>> I think you're right about your tests de-facto using two
threads, but
>>> it might be a good idea to _default_ to up to two threads in tests
and
>>> examples. This is especially valuable for third-party developers
who
>>> have to mass-test packages (one of which could be rlibkriging) in
>>> parallel.
>>>
>>>> - is there any reason that could explain that fedora-*-devel is
so
>>>> slow for this package or compilation of Rcpp/testthat ?
>>>
>>> Compilation time is definitely not the reason. Something in tests/*
>>> actually runs for 30 minutes by itself.
>>>
>>>> - is there any chance that I can get a deeper log of what
happened ?
>>>
>>> If you split your tests into separate files under tests/*.R instead
of
>>> using a single tests/testthat.R calling the rest of the tests, R
will
>>> be able to show you the individual test file that hung and maybe
the
>>> line where it happened. (Also, you'll get per-file timing.) But
that
>>> is potentially a huge investment: you may have to rewrite the tests
to
>>> work outside the testthat harness, and you'd also have to
prepare
>>> another CRAN submission just to have those tests run. It's also
against
>>> CRAN policy to knowingly submit a package with unfixed ERRORs.
>>>
>>> (Currently, R can only tell you that the tests hung in the
>>> test_check('rlibkriging') call in the tests/testthat.R,
which isn't
>>> precise enough.)
>>
>> You can specify a different "reporter" in the test_check()
call, and it
>> will print more useful information.? I don't think there's a
perfect
>> one, but
>>
>>   ? test_check('rlibkriging', reporter = "progress")
>>
>> should at least show you the tests that finished running before the
>> timeout.
> 
> I had similar problems with testthat and timeouts when mass-checking
> packages on patched R versions. My notes say
> 
>> ## testthat's 'LocationReporter' does cat() after each
expectation
>> ## so we can see results even if timeout is reached
>> options(testthat.default_check_reporter = c("Location",
"Check"))
> 
> The help("LocationReporter") says: "This reporter simply
prints the
> location of every expectation and error. This is useful if you're
trying
> to figure out the source of a segfault, or you want to figure out which
> code triggers a C/C++ breakpoint"
> 
> HTH!
Yes, that looks like it would pin down the location of the problem. 
Here's some sample output from it:

   Running ?testthat.R? [41s/42s]
Running the tests in ?tests/testthat.R? failed.
Last 13 lines of output:
   Start test: can use constructed calls in verify_output() (#945)
     'test-verify-output.R:55' [success]
   End test: can use constructed calls in verify_output() (#945)

   Start test: verify_output() doesn't use cli unicode by default
     'test-verify-output.R:65' [success]
     'test-verify-output.R:73' [success]
   End test: verify_output() doesn't use cli unicode by default

   Start test: verify_output() handles carriage return
     'test-verify-output.R:82' [success]
   End test: verify_output() handles carriage return

   Error: Test failures
   Execution halted

One other thing:  you enabled this by using

   options(testthat.default_check_reporter = c("Location",
"Check"))

before running the tests; the package writer could do the same thing by 
using

   test_check('rlibkriging', reporter = c("Location",
"Check"))

Duncan Murdoch

Thank you all, for these advices.

So I try to fix OMP_THREADS, cleanup tests, and display explicitly what test is
running by moving in tests/ instead of tests/testthat/...
Next step should be to investigate blocking test using a reporter (maybe
"list").
For now, waiting for CRAN results...

Yann

-----Message d'origine-----
De?: Duncan Murdoch <murdoch.duncan at gmail.com> 
Envoy??: mercredi 11 janvier 2023 00:36
??: Sebastian Meyer <seb.meyer at fau.de>; Ivan Krylov <krylov.r00t at
gmail.com>; RICHET Yann <yann.richet at irsn.fr>
Cc?: Pascal Hav? <pascal at haveneer.com>; R-devel at r-project.org
Objet?: Re: [Rd] rhub vs. CRAN fedora-*-devel, using armadillo & slapack

On 10/01/2023 4:07 p.m., Sebastian Meyer wrote:
> Am 10.01.23 um 21:28 schrieb Duncan Murdoch:
>> On 10/01/2023 2:05 p.m., Ivan Krylov wrote:
>>> On Tue, 10 Jan 2023 16:27:53 +0000
>>> RICHET Yann <yann.richet at irsn.fr> wrote:
>>>
>>>> In facts, 10 threads are asked by armadillo for some LinAlg,
which
>>>> backs to two threads as warned.
>>>
>>> I think you're right about your tests de-facto using two
threads,
>>> but it might be a good idea to _default_ to up to two threads in 
>>> tests and examples. This is especially valuable for third-party 
>>> developers who have to mass-test packages (one of which could be 
>>> rlibkriging) in parallel.
>>>
>>>> - is there any reason that could explain that fedora-*-devel is
so
>>>> slow for this package or compilation of Rcpp/testthat ?
>>>
>>> Compilation time is definitely not the reason. Something in tests/*
>>> actually runs for 30 minutes by itself.
>>>
>>>> - is there any chance that I can get a deeper log of what
happened ?
>>>
>>> If you split your tests into separate files under tests/*.R instead
>>> of using a single tests/testthat.R calling the rest of the tests, R
>>> will be able to show you the individual test file that hung and 
>>> maybe the line where it happened. (Also, you'll get per-file 
>>> timing.) But that is potentially a huge investment: you may have to
>>> rewrite the tests to work outside the testthat harness, and
you'd
>>> also have to prepare another CRAN submission just to have those 
>>> tests run. It's also against CRAN policy to knowingly submit a
package with unfixed ERRORs.
>>>
>>> (Currently, R can only tell you that the tests hung in the
>>> test_check('rlibkriging') call in the tests/testthat.R,
which isn't
>>> precise enough.)
>>
>> You can specify a different "reporter" in the test_check()
call, and
>> it will print more useful information.? I don't think there's a
>> perfect one, but
>>
>>   ? test_check('rlibkriging', reporter = "progress")
>>
>> should at least show you the tests that finished running before the 
>> timeout.
> 
> I had similar problems with testthat and timeouts when mass-checking 
> packages on patched R versions. My notes say
> 
>> ## testthat's 'LocationReporter' does cat() after each
expectation ##
>> so we can see results even if timeout is reached 
>> options(testthat.default_check_reporter = c("Location",
"Check"))
> 
> The help("LocationReporter") says: "This reporter simply
prints the
> location of every expectation and error. This is useful if you're 
> trying to figure out the source of a segfault, or you want to figure 
> out which code triggers a C/C++ breakpoint"
> 
> HTH!
Yes, that looks like it would pin down the location of the problem. 
Here's some sample output from it:

   Running ?testthat.R? [41s/42s]
Running the tests in ?tests/testthat.R? failed.
Last 13 lines of output:
   Start test: can use constructed calls in verify_output() (#945)
     'test-verify-output.R:55' [success]
   End test: can use constructed calls in verify_output() (#945)

   Start test: verify_output() doesn't use cli unicode by default
     'test-verify-output.R:65' [success]
     'test-verify-output.R:73' [success]
   End test: verify_output() doesn't use cli unicode by default

   Start test: verify_output() handles carriage return
     'test-verify-output.R:82' [success]
   End test: verify_output() handles carriage return

   Error: Test failures
   Execution halted

One other thing:  you enabled this by using

   options(testthat.default_check_reporter = c("Location",
"Check"))

before running the tests; the package writer could do the same thing by using

   test_check('rlibkriging', reporter = c("Location",
"Check"))

Duncan Murdoch