Test suite hits 2GB limit on 32bit R-devel

[mattdowle]

I've just seen this occur, here :
https://ci.appveyor.com/project/Rdatatable/data-table/build/1.0.2337/job/3rppwcw31ent8g1r

Jan saw it too today here :
#2761 (comment)

So, despite all our efforts, there's still more to do.

The error I saw is similar to Jan's :

  Running test id 1667.1      Error: memory exhausted (limit reached?)
  Error: memory exhausted (limit reached?)
  Error: memory exhausted (limit reached?)
  Execution halted

That message is R's, here :
https://github.com/wch/r-source/blob/trunk/src/main/memory.c#L2059
and looking at the context there (inside an err_malloc function) suggests AppVeyor instance is declining R's malloc request. (i.e. it doesn't seem like some kind of stack limit inside R itself).

@jangorecki

• What is the memory limit of an AppVeyor instance? I had a quick look and 4GB came up quickly but I'm not sure if that's correct. If it is 4GB I don't see how we are reaching that.
• We never knew before, but now with your new memtest charts, it seems the max memory used is towards the end of the test suite and reaches 160MB. If that's right, it seems very low. I can't imagine AppVeyor's limit being that low. Certainly a lot less than 4GB and we know it now passes on your 2GB instance.
• I already reduced the memory usage of the non-equi-join tests in PR Nqjoin efficiency 2 #2733. I'm fairly confident that helped a lot and that the memory usage is no longer in that area.
• According to the memtest charts there are 3 large step-ups in memory usage very early in the test suite. If the mem usage table could be sorted by change and the top 10 printed at the end of the test suite then we could see which tests those step-ups are for. If the data used in those 3 tests is rm()'d after those tests, then perhaps more memory will be available for the tests at the end. However, as I said above, it's strange that the memtest charts show only 160MB being used! Reducing those 3 tests will be wasted effort if, somehow, the memtest results are not capturing the actual mem usage on AppVeyor.
• A long shot ... might it be that a Suggests package test is running on AppVeyor which eats more RAM, which does not run in the environment used to create the memtest charts.

[HughParsonage]

Isn't i386 limited to 2 GB?

[mattdowle]

@HughParsonage Oh ... yes! Just checked and yes both jobs failed just on 32bit. Thanks!

So it's not AppVeyor then. It's just a 32bit / 2GB issue. That leaves us with why there's a gap between the 160MB in memtest chart and 2GB. If the memtest scale is 10x out (does the output of ps change scale perhaps and needs to be fixed scale by passing a parameter?) then that would make more sense: 1600MB for R would then make sense to try to reduce by focussing on the 3 tests towards the start of the test suite.

(I guess internal R object headers have increased a little bit in R-devel, causing, on 32-bit, R-release to be just under the 2GB limit and R-devel to be just over. Explaining why it's just R-devel.)

[jangorecki]

Failed build that happened to me was on

Platform: x86_64-w64-mingw32/x64 (64-bit)
Running under: Windows Server 2012 R2 x64 (build 9600)

* using platform: x86_64-w64-mingw32 (64-bit)

And there were no suggested packages installed

Packages suggested but not available for checking:
  'bit64' 'curl' 'knitr' 'xts' 'nanotime' 'zoo' 'chron' 'reshape2'
  'testthat' 'GenomicRanges'

Probably we shouldn't use ps -o rss. There are many topics discussing that ps don't give proper memory measurement, also that RSS overestimate (surprisingly). I checked multiple sizes of data created in R and ps does not change unit, always returns KB.
Will try to add another tool to memtest then.

[mattdowle]

Just on that error, although yes the platform is 64bit, the multiarch R CMD check runs tests for both 32bit and 64bit. When I checked your fail, I downloaded the failure.zip artifact and looked inside both i386 and x64 directories. Just the i386 directory contained the main.fail file while x64 directory contained main.out passing ok.
Yes agree 'ps' next then. I can't think why the pattern of RAM usage makes sense but not the scale. The figures not being perfect makes sense, but not 10x off.

Oh ... how about just free -m. That's the one that matters and is reliable as far as I know. Deltas will work on that figure. In CI no other processes will be running, but if they are somehow, then we want to know anyway.

[jangorecki]

I checked locally memory usage with supposedly good tool /usr/bin/time --verbose (which is different app from bash time).
Results shows that R-devel is actually eating much less memory than R 3.4.4 (at least on Linux).
Still it is far from 2GB limit, anyway it doesn't seems to be related to test suite. More something about R-devel and memory management on 32bit Windows - maybe recent memory optimization does not play well on 32bit Win.
Next step to debug this issue would be to measure memory on Windows.
Building vignettes raises RSS by ~800MB on R 3.4.4 but they are disabled in appveyor script.

R 3.4.4

R CMD check took 364MB RSS.

	Command being timed: "R CMD check data.table_1.10.5.tar.gz --ignore-vignettes --no-manual"
	Maximum resident set size (kbytes): 364648

test.data.table took 351MB RSS.

	Command being timed: "Rscript -e require(data.table); test.data.table()"
	Maximum resident set size (kbytes): 351236

R-devel (2018-04-06)

R CMD check took 224MB RSS.

	Command being timed: "/home/jan/R-devel/bin/R CMD check data.table_1.10.5.tar.gz --ignore-vignettes --no-manual"
	Maximum resident set size (kbytes): 224640

test.data.table took 207MB RSS.

	Command being timed: "/home/jan/R-devel/bin/Rscript -e require(data.table); test.data.table()"
	Maximum resident set size (kbytes): 207032

[mattdowle]

Just happened on win-builder ...
https://win-builder.r-project.org/0UGUaRk3ifo2/

** running tests for arch 'i386' ... [81s] ERROR
  Running 'autoprint.R' [1s]
  Comparing 'autoprint.Rout' to 'autoprint.Rout.save' ... OK
  Running 'knitr.R' [1s]
  Comparing 'knitr.Rout' to 'knitr.Rout.save' ... OK
  Running 'main.R' [76s]
  Running 'testthat.R' [2s]
Running the tests in 'tests/main.R' failed.
Complete output:
  > require(data.table)
  Loading required package: data.table
  > test.data.table()  # runs the main test suite of 5,000+ tests in /inst/tests/tests.Rraw
  Running D:/temp/Rtmpqkla50/RLIBS_169b8128a64aa/data.table/tests/tests.Rraw 
  
  Running test id 1.1      
  Running test id 1.2      
...
  Running test id 1648.086      
  Running test id 1648.087      
  Running test id 1648.088      
  Running test id 1648.089      
  Running test id 1648.09      
  Running test id 1648.091      Error: cannot allocate vector of size 4 Kb
  Execution halted
** running tests for arch 'x64' ... [135s] OK

so, as before, it's ok on 64bit but not 32bit.

[MichaelChirico]

have we done something like -- every 500 tests, clean up all the stale test objects laying around (x, y, DT, DT1, DT2, dt, df, ...)? should be minor but might help