memory not being released in nested plan(multisession)

[seth127]

reposted from this stackoverflow at Henrik's request

Recently I've been playing with doing some parallel processing in R using future (and future.apply and furrr) which has been great mostly, but I've stumbled onto something that I can't explain. It's possible that this is a bug somewhere, but it may also be sloppy coding on my part. If anyone can explain this behavior it would be much appreciated.

The setup

I'm running simulations on different subgroups of my data. For each group, I want to run the simulation n times and then calculate some summary stats on the results. Here is some example code to reproduce my basic setup and demonstrate the issue I'm seeing:

library(tidyverse)
library(future)
library(future.apply)

# Helper functions

#' Calls out to `free` to get total system memory used
sys_used <- function() {
  .f <- system2("free", "-b", stdout = TRUE)
  as.numeric(unlist(strsplit(.f[2], " +"))[3])
}

#' Write time, and memory usage to log file in CSV format
#' @param .f the file to write to 
#' @param .id identifier for the row to be written
mem_string <- function(.f, .id) {
  .s <- paste(.id, Sys.time(), sys_used(), Sys.getpid(), sep = ",")
  write_lines(.s, .f, append = TRUE)
}

# Inputs
fake_inputs <- 1:16
nsim <- 100
nrows <- 1e6

log_file <- "future_mem_leak_log.csv"
if (fs::file_exists(log_file)) fs::file_delete(log_file)

test_cases <- list(
  list(
    name = "multisession-sequential",
    plan = list(multisession, sequential)
  ),
  list(
    name = "sequential-multisession",
    plan = list(sequential, multisession)
  )
)

# Test code

for (.t in test_cases) {
  plan(.t$plan)
  
  # loop over subsets of the data 
  final_out <- future_lapply(fake_inputs, function(.i) {
    # loop over simulations
    out <- future_lapply(1:nsim, function(.j) {
      # in real life this would be doing simulations, 
      # but here we just create "results" using rnorm()
      res <- data.frame(
        id = rep(.j, nrows),
        col1 = rnorm(nrows) * .i,
        col2 = rnorm(nrows) * .i,
        col3 = rnorm(nrows) * .i,
        col4 = rnorm(nrows) * .i,
        col5 = rnorm(nrows) * .i,
        col6 = rnorm(nrows) * .i
      )

      # write memory usage to file
      mem_string(log_file, .t$name)

      # in real life I would write res to file to read in later, but here we
      # only return head of df so we know the returned value isn't filling up memory
      res %>% slice_head(n = 10) 
    })
  })

  # clean up any leftover objects before testing the next plan
  try(rm(final_out))
  try(rm(out))
  try(rm(res))
}

The outer loop is for testing two parallelization strategies: whether to parallelize over the subsets of data or over the 100 simulations.

Some caveats

• I realize that parallelizing over the simulations is not the ideal design, and also that chunking that data to send 10-20 simulations to each core would be more efficient, but that's not really the point here. I'm just trying to understand what is happening in memory.
• I also considered that maybe plan(multicore) would be better here (though I'm sure if it would) but I'm more interested in figuring out what's happening with plan(multisession)

The results

I ran this on an 8-vCPU Linux EC2 (I can give more specs if people need them) and created the following plot from the results (plotting code at the bottom for reproducibility):

First off, plan(list(multisession, sequential)) is faster (as expected, see caveat above), but what I'm confused about is the memory profile. The total system memory usage remains pretty constant for plan(list(multisession, sequential)) which I would expect, because I assumed the res object is overwritten each time through the loop.

However, the memory usage for plan(list(sequential, multisession)) steadily grows as the program runs. It appears that each time through the loop the res object is created and then hangs around in limbo somewhere, taking up memory. In my real example this got large enough that it filled my entire (32GB) system memory and killed the process about halfway through.

Plot twist: it only happens when nested

And here's the part that really has me confused! When I changed the outer future_lapply to just regular lapply and set plan(multisession) I don't see it! From my reading of this "Future: Topologies" vignette this should be the same as plan(list(sequential, multisession)) but the plot doesn't show the memory growing at all (in fact, it's almost identical to plan(list(multisession, sequential)) in the above plot)

Note on other options

I actually originally found this with furrr::future_map_dfr() but to be sure it wasn't a bug in furrr, I tried it with future.apply::future_lapply() and got the results shown. I tried to code this up with just future::future() and got very different results, but quite possibly because what I coded up wasn't actually equivalent. I don't have much experience with using futures directly without the abstraction layer provided by either furrr or future.apply.

Again, any insight on this is much appreciated.

Plotting code

library(tidyverse)

logDat <- read_csv("future_mem_leak_log.csv",
                   col_names = c("plan", "time", "sys_used", "pid")) %>%
  group_by(plan) %>% 
  mutate(
    start = min(time), 
    time_elapsed = as.numeric(difftime(time, start, units = "secs"))
  )

ggplot(logDat, aes(x = time_elapsed/60, y = sys_used/1e9, group = plan, colour = plan)) + 
  geom_line() + 
  xlab("Time elapsed (in mins)") + ylab("Memory used (in GB)") +
  ggtitle("Memory Usage\n  list(multisession, sequential) vs list(sequential, multisession)") 

[seth127]

Here's the sessionInfo()

> sessionInfo()
R version 4.0.3 (2020-10-10)
Platform: x86_64-pc-linux-gnu (64-bit)
Running under: Ubuntu 18.04.5 LTS

Matrix products: default
BLAS/LAPACK: /opt/intel/compilers_and_libraries_2020.0.166/linux/mkl/lib/intel64_lin/libmkl_gf_lp64.so

locale:
 [1] LC_CTYPE=en_US.UTF-8       LC_NUMERIC=C              
 [3] LC_TIME=en_US.UTF-8        LC_COLLATE=en_US.UTF-8    
 [5] LC_MONETARY=en_US.UTF-8    LC_MESSAGES=en_US.UTF-8   
 [7] LC_PAPER=en_US.UTF-8       LC_NAME=C                 
 [9] LC_ADDRESS=C               LC_TELEPHONE=C            
[11] LC_MEASUREMENT=en_US.UTF-8 LC_IDENTIFICATION=C       

attached base packages:
[1] stats     graphics  grDevices utils     datasets  methods   base     

other attached packages:
 [1] pryr_0.1.4         future.apply_1.6.0 future_1.21.0      forcats_0.5.0     
 [5] stringr_1.4.0      dplyr_1.0.5        purrr_0.3.4        readr_1.4.0       
 [9] tidyr_1.1.3        tibble_3.1.0       ggplot2_3.3.2      tidyverse_1.3.0   

loaded via a namespace (and not attached):
 [1] tidyselect_1.1.0  listenv_0.8.0     haven_2.3.1       colorspace_2.0-0 
 [5] vctrs_0.3.6       generics_0.1.0    utf8_1.2.1        rlang_0.4.10     
 [9] pillar_1.5.1      glue_1.4.2        withr_2.4.1       DBI_1.1.0        
[13] dbplyr_2.0.0      modelr_0.1.8      readxl_1.3.1      lifecycle_1.0.0  
[17] munsell_0.5.0     gtable_0.3.0      cellranger_1.1.0  rvest_0.3.6      
[21] codetools_0.2-18  ps_1.6.0          parallel_4.0.3    fansi_0.4.2      
[25] broom_0.7.3       Rcpp_1.0.6        scales_1.1.1      backports_1.2.1  
[29] debugme_1.1.0     jsonlite_1.7.2    parallelly_1.22.0 fs_1.5.0         
[33] hms_1.0.0         digest_0.6.27     stringi_1.5.3     grid_4.0.3       
[37] cli_2.3.1         tools_4.0.3       magrittr_2.0.1    crayon_1.4.1     
[41] pkgconfig_2.0.3   ellipsis_0.3.1    xml2_1.3.2        reprex_0.3.0     
[45] lubridate_1.7.9.2 assertthat_0.2.1  httr_1.4.2        rstudioapi_0.13  
[49] R6_2.5.0          globals_0.14.0    compiler_4.0.3   

[seth127]

Ok, I tried it with options(mc.cores = 2L) and I still see it:

I watched htop to make sure it was really only using 2 cores (it was) and you can see some differences in the plots, which make sense given the lower number of cores, but the same pattern is still there.

[HenrikBengtsson]

Hi I don't think parallelly 1.23.0 or 1.26.0 would matter because in the end of the day they set up the same type of PSOCK workers.

I've done a major rewrites in the future devel version, but nothing comes to mind that could explain this.

So, I've tried to reproduce this using CentOS 7 and R 4.1.0, but I can't. If you have the time, you could do a divide-and-conquer approach to narrow in on a specific version between future 1.21.0 and future devel, by starting with a commit in the middle, e.g.

remote::install_github("HenrikBengtsson/future@20d5247")

and then do another divide and conquer in one direction or the other.

[seth127]

Just a quick update so I don't leave you hanging here: I can't reproduce it with any version installed from a Github hash. I had been installing it from a CRAN-like snapshot repo that we use and I can still reproduce the issue when I install from there (both with the reprex above and with my original code) but even when I do remotes::install_github("HenrikBengtsson/future@0a723c7") (this is the hash for the 1.21.0 release tag which, as far as I know, should be the same as what's coming from the MPN snapshot) I cannot reproduce it. I can't reproduce it by installing future from CRAN with install.packages("future", repos = "https://cran.rstudio.com" either.

Suffice to say this is weird and it's making me look at our snapshotting process and also the workflow we do with renv to ensure reproducibility. My guess is that somehow this is fouling up the new sessions that get launched by plan(multisession) but I'm not sure yet.

Anyway, I'll let you know if anything future-related comes from this. Thanks again for being so on top of this discussion.

[HenrikBengtsson]

Thanks for the follow-up. Yes, this is odd, but as usual, there's almost always a reasonable explanation to it, but we just don't know.

I don't think we need to do more investigation now, and let's hope you won't experience it with the upcoming future 1.22.0. I do think this helped identify one issue with RngFutureWarning:s as discussed in #508 (reply in thread), which I fixed going forward.

Thanks again for you detailed, brilliant troubleshooting reports.

[dpastoor]

ok the mystery continues - i can reproduce this as well (unsurprisingly using the same templated infra and setup). Thus I started my dive in as well.

Where I'm at now... is that I can actually reproduce both the memory leak...and the lack of it via both our MPN mirror of CRAN and the tag itself installed through remotes.

Now, where this gets interesting - if I instead install where I swap in the src tarball from the github release into our toolchain, the memory leak goes away. In carefully watching, I noticed something else - during this pattern the only thing that happens is the tarball get directly installed from source

basically:

* installing *source* package ‘future’ ...\n** using staged installation\n** R\n** demo\n** inst\n** tests\n** byte-compile and prepare package for lazy loading\n** help\n*** installing help indices\n*** copying figures\n** building package indices\n** installing vignettes\n** testing if installed package can be loaded from temporary location\n** testing if installed package can be loaded from final location\n** testing if installed package keeps a record of temporary installation path\n* creating tarball\npackaged installation of ‘future’ as ‘future_1.21.0_R_x86_64-pc-linux-gnu.tar.gz’\n* DONE (future)\n

The contrast - our tool pkgr does a two pass install, where it firsts installs in a temp dir and grabs the binary, then installs the binary into the final directory. neither remotes nor the patched fix go through that two pass install, just directly install from src into the directory

So the next step is to tease apart is it the fact that the remotes is using the install, or the fact that

[dpastoor]

ok - i have narrowed it down pretty confidently do there is something not 100% right in how pkgr builds the binary and stores it for installation. Unfortunately, I don't know why - its just shelling out to R CMD INSTALL --build. I had actually studied pkgbuild::build() as the reference for it. But pkgr installing a binary built via pkgbuild works with no leaks, and R CMD INSTALL against the intermediate binary its a problem

devinp@ip-10-128-41-119:~/parallel_benchmarking$ R CMD INSTALL ~/.cache/pkgr/MPN-3444ed675c5f/binary/4.0/future_1.21.0_R_x86_64-pc-linux-gnu.tar.gz
* installing to library ‘/data/home/devinp/parallel_benchmarking/renv/library/R-4.0/x86_64-pc-linux-gnu’
* installing *binary* package ‘future’ ...
* DONE (future)