plumber not releasing memory #496
Labels
difficulty: advanced
Best for maintainers to address
difficulty: intermediate
Enterprising community members could help
help wanted
Solution is well-specified enough that any community member could fix
out of focus
Maintainers will not fix bug, but the issue should remain open until a resolution is found.
Comments
|
I think I experienced something similar before but never had a chance to take a deep look at it... The memory is not increased infinitely but is larger than my expectation. However, since I use plumber on Docker containers, I'm not sure it's because the docker container does not collect the memory in time or an issue of plumber... |
|
I am able to reproduce this as well. It is not clear where it is happening. Profvis shows a minor mem leak compared to the process memory increase. @wch and I will be investigating. Even using the route below causes the mem leak. So it's not caused by creating the data. Seems to be when transferring the data. big_dt <- dplyr::bind_rows(replicate(10000, mtcars, simplify = F))
#* @get /getData3
function() {
return(big_dt)
} |
|
Thank you both for looking into this. @shrektan Originally, I experienced this using a docker container, but I switched to simple hosting for debugging purposes, where I was able to reproduce the error. So it's definitely a plumber problem. @schloerke I tried calling Let me know, if I can help finding the cause. |
|
Thoughts:
Final thoughtGiven that I've added a file (and execution output) below to reproduce the whole investigation. `mem_test.R` filelibrary(magrittr)
n <- 100
routes <- c("rbind", "bind_rows", "return")
init_file <- function() {
cat("route, row, mem_used, procmem, time\n", file = "memleak.csv")
}
cat_row <- function(route, i, mem_used, procmem, time) {
row <- paste(route, i, mem_used, procmem, time, sep = ", ")
cat(row, "\n", file = "memleak.csv", append = TRUE, sep = "")
}
profile_plumber <- function(route = "getData", port = 12321) {
pr <- progress::progress_bar$new(
total = n,
format = "[:bar] :current/:total eta::eta; :elapsedfull; mem_used: :mem_used; procmem: :procmem\n",
show_after = 0,
clear = FALSE
)
now <- as.numeric(Sys.time())
base_url <- paste0("127.0.0.1:", port, "/")
for (i in 1:n) {
# ask route
now <- as.numeric(Sys.time())
httr::GET(paste0(base_url, route))
after <- as.numeric(Sys.time())
# get mem stats
mem_used <- httr::GET(paste0(base_url, "mem_used")) %>% httr::content() %>% magrittr::extract2(1)
procmem <- httr::GET(paste0(base_url, "procmem")) %>% httr::content() %>% magrittr::extract2(1)
pr$tick(tokens = list(
mem_used = mem_used,
procmem = procmem
))
# save
cat_row(route, i, mem_used, procmem, after - now)
}
}
profile_plot <- function() {
library(ggplot2)
readr::read_csv("memleak.csv") %>%
dplyr::select(-time) %>%
tidyr::pivot_longer(names_to = "fn", values_to = "memory", c("mem_used", "procmem")) %>%
dplyr::mutate(
route = factor(route, levels = routes),
memory = sub(" M[i]*B", "", memory) %>% as.numeric()
) %>%
{
dt <- .
ggplot(dt, aes(row, memory, color = fn)) +
geom_line() +
facet_grid(. ~ route) +
labs(y = "memory (MiB)")
} %>%
ggsave(filename = paste0("memleak.png"), width = 10, height = 6)
}
cat(file = "plumber.R",
'#* @get /rbind
function(n = 10000) {
data=do.call(rbind, replicate(n, mtcars, simplify = F))
return(data)
}
#* @get /bind_rows
function(n = 10000) {
dt <- replicate(n, mtcars, simplify = F)
data <- dplyr::bind_rows(dt)
return(data)
}
big_dt <- dplyr::bind_rows(replicate(10000, mtcars, simplify = F))
#* @get /return
function() {
return(big_dt)
}
#* @get /procmem
function() {
# basically calling ps u -p `Sys.getpid()` and getting the rss value
current_mem <- memuse::swap.unit(memuse::Sys.procmem()[[1]], unit = "MiB")
size_mem <- memuse::mu.size(current_mem)
unit_mem <- memuse::mu.unit(current_mem)
mem <- paste0(round(size_mem, 1), " ", unit_mem)
return(mem)
}
#* @get /mem_used
function() {
capture.output({print(pryr::mem_used())})
}
')
port <- httpuv::randomPort()
init_file()
for (route in routes) {
message("Starting plumber API")
proc <- callr::r_bg(function(p) {
plumber::plumb("plumber.R")$run(port = p)
}, list(p = port))
message("...sleeping...")
Sys.sleep(3)
message("Profiling server: ", route)
profile_plumber(route, port)
message("Stopping plumber API")
proc$kill()
message("...sleeping...")
Sys.sleep(3)
}
message("Generate Image")
profile_plot()Execution output |
|
A little more context: the We found that the amount of memory reported by We don't think it's a memory leak for a couple of reasons. First, the memory use appears to be asymptotic. Secondly, the memory use increase even if plumber isn't involved. If you repeatedly call So it seems that the increase in memory usage is probably due to some sort of cache or buffers. I don't know enough about R's internals to say exactly what it is, though. |
|
I was able to reproduce this error using a basic R function to prove that it's not a problem for plumber: In the beginning, the R process allocated 35 MB RAM. After the first call of Normally this wouldn't be much of a problem for a R script running once in a while. But as plumber ususally ist up 24/7 this leads to a huge memory leak. Should we report this to the developers of R? In my use case, I am deploying plumber in a docker container (replication factor: 15) using HAProxy as load balancer. If large datasets are requested one after another, this causes the memory usage of each container to grow to significant sizes making it impossible to host on ordinary machines. The only solution I found was restarting the container. Thank you for your help. |
|
Adding reprex output... test_mem <- function(n = 100) {
# generate data
ignore <- do.call(rbind, replicate(n, ggplot2::diamonds, simplify = F))
return()
}
print_mem <- function() {
withAutoprint({
gc()
pryr::mem_used()
memuse::Sys.procmem()
})
}
print_mem()
#> > gc()
#> used (Mb) gc trigger (Mb) limit (Mb) max used (Mb)
#> Ncells 476833 25.5 1030405 55.1 NA 663948 35.5
#> Vcells 887935 6.8 8388608 64.0 32768 1822016 14.0
#> > pryr::mem_used()
#> Registered S3 method overwritten by 'pryr':
#> method from
#> print.bytes Rcpp
#> 34.2 MB
#> > memuse::Sys.procmem()
#> Size: 85.660 MiB
test_mem()
#> NULL
print_mem()
#> > gc()
#> used (Mb) gc trigger (Mb) limit (Mb) max used (Mb)
#> Ncells 689509 36.9 1288835 68.9 NA 1030405 55.1
#> Vcells 1667893 12.8 76694957 585.2 32768 94968494 724.6
#> > pryr::mem_used()
#> 52 MB
#> > memuse::Sys.procmem()
#> Size: 2.477 GiB
test_mem()
#> NULL
print_mem()
#> > gc()
#> used (Mb) gc trigger (Mb) limit (Mb) max used (Mb)
#> Ncells 690815 36.9 1288835 68.9 NA 1030405 55.1
#> Vcells 1670977 12.8 68087749 519.5 32768 94968494 724.6
#> > pryr::mem_used()
#> 52.1 MB
#> > memuse::Sys.procmem()
#> Size: 2.164 GiBCreated on 2019-10-10 by the reprex package (v0.3.0) |
|
@schloerke I can't reproduce your code on Mac. Do you use Mac as well? I've run the code several times. The first time, the total memory used increases by about 50 MB. The other runs show no increases in memory use at all (yeah, maybe for one time increase 150MB but reduced in the later runs). Is it possible even if R has told the system "I have released some memory. When you need it please come and take it back" but the system currently has plenty of memories so it doesn't ask R to return that part of memory back? |
|
@shrektan I am on Mac as well. I'm able to reproduce your situation as well. I've found that after a certain threshold, the memory is not reclaimed by the OS.
Yes. I believe this is what we are seeing. Also... Linux does not reclaim memory from a process. Docker is running linux. Therefore once the memory is obtained by the R process, it'll never leave. I do not know why the already obtained memory is not being repurposed, causing the R process to balloon in memory usage.😞 Funny website about linux memory Reclaim <= 1 GB, but fails to reclaim 2.5 GBprint_mem <- function() {
withAutoprint({
gc()
pryr::mem_used()
memuse::Sys.procmem()
})
}
print_mem()
#> > gc()
#> used (Mb) gc trigger (Mb) limit (Mb) max used (Mb)
#> Ncells 476978 25.5 1030820 55.1 NA 663948 35.5
#> Vcells 888952 6.8 8388608 64.0 32768 1821939 14.0
#> > pryr::mem_used()
#> Registered S3 method overwritten by 'pryr':
#> method from
#> print.bytes Rcpp
#> 34.2 MB
#> > memuse::Sys.procmem()
#> Size: 89.531 MiB
x <- rnorm(1e8)
print_mem()
#> > gc()
#> used (Mb) gc trigger (Mb) limit (Mb) max used (Mb)
#> Ncells 579261 31.0 1030820 55.1 NA 725551 38.8
#> Vcells 101089962 771.3 147978526 1129.0 32768 101529869 774.7
#> > pryr::mem_used()
#> 841 MB
#> > memuse::Sys.procmem()
#> Size: 856.555 MiB
# ~850mb. Great!
rm(x)
print_mem()
#> > gc()
#> used (Mb) gc trigger (Mb) limit (Mb) max used (Mb)
#> Ncells 579291 31.0 1030820 55.1 NA 725551 38.8
#> Vcells 1090032 8.4 118382821 903.2 32768 101529869 774.7
#> > pryr::mem_used()
#> 41.2 MB
#> > memuse::Sys.procmem()
#> Size: 93.613 MiB
# ~90mb. Great!
x <- rnorm(1e8)
# ~ 1 GB used
print_mem()
#> > gc()
#> used (Mb) gc trigger (Mb) limit (Mb) max used (Mb)
#> Ncells 579313 31.0 1030820 55.1 NA 725551 38.8
#> Vcells 101090068 771.3 148161554 1130.4 32768 101529869 774.7
#> > pryr::mem_used()
#> 841 MB
#> > memuse::Sys.procmem()
#> Size: 856.574 MiB
# ~850mb. Great!
rm(x)
print_mem()
#> > gc()
#> used (Mb) gc trigger (Mb) limit (Mb) max used (Mb)
#> Ncells 579343 31.0 1030820 55.1 NA 725551 38.8
#> Vcells 1090138 8.4 118529244 904.4 32768 101529869 774.7
#> > pryr::mem_used()
#> 41.2 MB
#> > memuse::Sys.procmem()
#> Size: 93.648 MiB
# ~90mb. Great!
ignore <- do.call(rbind, replicate(100, ggplot2::diamonds, simplify = F))
print_mem()
#> > gc()
#> used (Mb) gc trigger (Mb) limit (Mb) max used (Mb)
#> Ncells 689584 36.9 1291022 69.0 NA 1030820 55.1
#> Vcells 45506049 347.2 91110460 695.2 32768 101529869 774.7
#> > pryr::mem_used()
#> 403 MB
#> > memuse::Sys.procmem()
#> Size: 2.972 GiB
# ~3GB. Great!
rm(ignore)
print_mem()
#> > gc()
#> used (Mb) gc trigger (Mb) limit (Mb) max used (Mb)
#> Ncells 689588 36.9 1291022 69.0 NA 1030820 55.1
#> Vcells 1669033 12.8 72888368 556.1 32768 101529869 774.7
#> > pryr::mem_used()
#> 52 MB
#> > memuse::Sys.procmem()
#> Size: 2.724 GiB
# Not ~90mb. :-(
ignore <- do.call(rbind, replicate(100, ggplot2::diamonds, simplify = F))
print_mem()
#> > gc()
#> used (Mb) gc trigger (Mb) limit (Mb) max used (Mb)
#> Ncells 689630 36.9 1291022 69.0 NA 1030820 55.1
#> Vcells 45506150 347.2 97159884 741.3 32768 101529869 774.7
#> > pryr::mem_used()
#> 403 MB
#> > memuse::Sys.procmem()
#> Size: 2.753 GiB
rm(ignore)
print_mem()
#> > gc()
#> used (Mb) gc trigger (Mb) limit (Mb) max used (Mb)
#> Ncells 689628 36.9 1291022 69.0 NA 1030820 55.1
#> Vcells 1669130 12.8 77727908 593.1 32768 101529869 774.7
#> > pryr::mem_used()
#> 52 MB
#> > memuse::Sys.procmem()
#> Size: 2.670 GiB
# Not ~90mb. :-(
for (i in 1:20) {
print_mem()
}
#> > gc()
#> used (Mb) gc trigger (Mb) limit (Mb) max used (Mb)
#> Ncells 691274 37.0 1291022 69.0 NA 1030820 55.1
#> Vcells 1672723 12.8 39796690 303.7 32768 101529869 774.7
#> > pryr::mem_used()
#> 52.1 MB
#> > memuse::Sys.procmem()
#> Size: 2.670 GiB
#> > gc()
#> used (Mb) gc trigger (Mb) limit (Mb) max used (Mb)
#> Ncells 691278 37.0 1291022 69.0 NA 1030820 55.1
#> Vcells 1672770 12.8 20375906 155.5 32768 101529869 774.7
#> > pryr::mem_used()
#> 52.1 MB
#> > memuse::Sys.procmem()
#> Size: 2.670 GiB
#> > gc()
#> used (Mb) gc trigger (Mb) limit (Mb) max used (Mb)
#> Ncells 691280 37.0 1291022 69.0 NA 1030820 55.1
#> Vcells 1672787 12.8 10432464 79.6 32768 101529869 774.7
#> > pryr::mem_used()
#> 52.1 MB
#> > memuse::Sys.procmem()
#> Size: 2.670 GiB
#> > gc()
#> used (Mb) gc trigger (Mb) limit (Mb) max used (Mb)
#> Ncells 691283 37.0 1291022 69.0 NA 1030820 55.1
#> Vcells 1672819 12.8 10432464 79.6 32768 101529869 774.7
#> > pryr::mem_used()
#> 52.1 MB
#> > memuse::Sys.procmem()
#> Size: 2.670 GiB
#> > gc()
#> used (Mb) gc trigger (Mb) limit (Mb) max used (Mb)
#> Ncells 691285 37.0 1291022 69.0 NA 1030820 55.1
#> Vcells 1672843 12.8 10432464 79.6 32768 101529869 774.7
#> > pryr::mem_used()
#> 52.1 MB
#> > memuse::Sys.procmem()
#> Size: 2.670 GiB
#> > gc()
#> used (Mb) gc trigger (Mb) limit (Mb) max used (Mb)
#> Ncells 691287 37.0 1291022 69.0 NA 1030820 55.1
#> Vcells 1672867 12.8 10432464 79.6 32768 101529869 774.7
#> > pryr::mem_used()
#> 52.1 MB
#> > memuse::Sys.procmem()
#> Size: 2.670 GiB
#> > gc()
#> used (Mb) gc trigger (Mb) limit (Mb) max used (Mb)
#> Ncells 691289 37.0 1291022 69.0 NA 1030820 55.1
#> Vcells 1672891 12.8 10432464 79.6 32768 101529869 774.7
#> > pryr::mem_used()
#> 52.1 MB
#> > memuse::Sys.procmem()
#> Size: 2.670 GiB
#> > gc()
#> used (Mb) gc trigger (Mb) limit (Mb) max used (Mb)
#> Ncells 691291 37.0 1291022 69.0 NA 1030820 55.1
#> Vcells 1672915 12.8 10432464 79.6 32768 101529869 774.7
#> > pryr::mem_used()
#> 52.1 MB
#> > memuse::Sys.procmem()
#> Size: 2.670 GiB
#> > gc()
#> used (Mb) gc trigger (Mb) limit (Mb) max used (Mb)
#> Ncells 691293 37.0 1291022 69.0 NA 1030820 55.1
#> Vcells 1672939 12.8 10432464 79.6 32768 101529869 774.7
#> > pryr::mem_used()
#> 52.1 MB
#> > memuse::Sys.procmem()
#> Size: 2.670 GiB
#> > gc()
#> used (Mb) gc trigger (Mb) limit (Mb) max used (Mb)
#> Ncells 691295 37.0 1291022 69.0 NA 1030820 55.1
#> Vcells 1672963 12.8 10432464 79.6 32768 101529869 774.7
#> > pryr::mem_used()
#> 52.1 MB
#> > memuse::Sys.procmem()
#> Size: 2.670 GiB
#> > gc()
#> used (Mb) gc trigger (Mb) limit (Mb) max used (Mb)
#> Ncells 691297 37.0 1291022 69.0 NA 1030820 55.1
#> Vcells 1672987 12.8 10432464 79.6 32768 101529869 774.7
#> > pryr::mem_used()
#> 52.1 MB
#> > memuse::Sys.procmem()
#> Size: 2.670 GiB
#> > gc()
#> used (Mb) gc trigger (Mb) limit (Mb) max used (Mb)
#> Ncells 691299 37.0 1291022 69.0 NA 1030820 55.1
#> Vcells 1673011 12.8 10432464 79.6 32768 101529869 774.7
#> > pryr::mem_used()
#> 52.1 MB
#> > memuse::Sys.procmem()
#> Size: 2.670 GiB
#> > gc()
#> used (Mb) gc trigger (Mb) limit (Mb) max used (Mb)
#> Ncells 691301 37.0 1291022 69.0 NA 1030820 55.1
#> Vcells 1673035 12.8 10432464 79.6 32768 101529869 774.7
#> > pryr::mem_used()
#> 52.1 MB
#> > memuse::Sys.procmem()
#> Size: 2.670 GiB
#> > gc()
#> used (Mb) gc trigger (Mb) limit (Mb) max used (Mb)
#> Ncells 691303 37.0 1291022 69.0 NA 1030820 55.1
#> Vcells 1673059 12.8 10432464 79.6 32768 101529869 774.7
#> > pryr::mem_used()
#> 52.1 MB
#> > memuse::Sys.procmem()
#> Size: 2.670 GiB
#> > gc()
#> used (Mb) gc trigger (Mb) limit (Mb) max used (Mb)
#> Ncells 691305 37.0 1291022 69.0 NA 1030820 55.1
#> Vcells 1673083 12.8 10432464 79.6 32768 101529869 774.7
#> > pryr::mem_used()
#> 52.1 MB
#> > memuse::Sys.procmem()
#> Size: 2.670 GiB
#> > gc()
#> used (Mb) gc trigger (Mb) limit (Mb) max used (Mb)
#> Ncells 691307 37.0 1291022 69.0 NA 1030820 55.1
#> Vcells 1673107 12.8 10432464 79.6 32768 101529869 774.7
#> > pryr::mem_used()
#> 52.1 MB
#> > memuse::Sys.procmem()
#> Size: 2.670 GiB
#> > gc()
#> used (Mb) gc trigger (Mb) limit (Mb) max used (Mb)
#> Ncells 691309 37.0 1291022 69.0 NA 1030820 55.1
#> Vcells 1673131 12.8 10432464 79.6 32768 101529869 774.7
#> > pryr::mem_used()
#> 52.1 MB
#> > memuse::Sys.procmem()
#> Size: 2.670 GiB
#> > gc()
#> used (Mb) gc trigger (Mb) limit (Mb) max used (Mb)
#> Ncells 691311 37.0 1291022 69.0 NA 1030820 55.1
#> Vcells 1673155 12.8 10432464 79.6 32768 101529869 774.7
#> > pryr::mem_used()
#> 52.1 MB
#> > memuse::Sys.procmem()
#> Size: 2.670 GiB
#> > gc()
#> used (Mb) gc trigger (Mb) limit (Mb) max used (Mb)
#> Ncells 691313 37.0 1291022 69.0 NA 1030820 55.1
#> Vcells 1673179 12.8 10432464 79.6 32768 101529869 774.7
#> > pryr::mem_used()
#> 52.1 MB
#> > memuse::Sys.procmem()
#> Size: 2.670 GiB
#> > gc()
#> used (Mb) gc trigger (Mb) limit (Mb) max used (Mb)
#> Ncells 691315 37.0 1291022 69.0 NA 1030820 55.1
#> Vcells 1673203 12.8 10432464 79.6 32768 101529869 774.7
#> > pryr::mem_used()
#> 52.1 MB
#> > memuse::Sys.procmem()
#> Size: 2.670 GiB |
|
So it should be a more general issue about how OS manages the memory? As of Docker containers, There're options to constrain the memory usage of a Docker container and it may help in such cases. |
|
@shrektan I don't think limiting the memory for docker containers is the right way to go, as this disables the possibility to process large datasets. @schloerke Can you further explain this for me?
|
|
Well, you can set soft limits on it which will allow large datasets while may does the trick. |
|
Hi here. It looks like the issue is related to how glibc manages memory. And this is usually linux specific. More details here. Also I've reported this to r-bugzilla some time ago. I would appreciate if some of you guys (especially @wch as you are very experienced in r-internals) can review my bug report and confirm it to r-core (as such things were recently requested in r-developer blog) As a solution I recommend to switch to another implementation of malloc (such as jemalloc). This is exactly what we do in RestRserve: |
|
Wow this actually fixes the bug. |
|
@dselivanov I think that you understand this domain better than I do -- I don't feel that I would be able to help here. Have you also tried asking about the memory issue on the r-devel mailing list? |
|
Yes, I've opened bugzilla report after discussion on r devel. Links to r devel threads are in the ticket. |
schloerke
added
difficulty: intermediate
|
@dselivanov how can I create a bugzilla account? I can't find a page for signing up. |
|
|
The topic of this issue has wandered a little, but on the subject of experimenting with R memory usage it might also be worth investigating the |
|
@atheriel I think I've tried all those environment variables at some point. No one of them seem had any effect. |
Closed
|
Closing this issue in favor of solution provided by @dselivanov in #496 (comment) It seems really fair that the standard memory leak is due to a inefficient malloc linux library. Changing the library had good success according to the comments. |
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
System details
Output of
sessioninfo::session_info():Example application or steps to reproduce the problem
Describe the problem in detail
Requesting large datasets via plumber results in a large memory consumption of the plumber process which is ok. After the request ist finished, this memory is not released by the garbage collection. This means, if 4 GB were allocated for serving the request, the process will keep the allocated memory forever until restarted. Even after requesting a small dataset after the large one, the memory won't be released. I'm not quite sure if this is actually a bug or if I am doing something wrong.
Thanks for your help!
The text was updated successfully, but these errors were encountered: