Memory leak?

[antoine-sachet]

I am running a plumber API in production and I am observing a slow increase of memory usage over time, about 2MB/day.

The API is running in a container on AWS Elastic Container Service using a serverless setup ("Fargate launch type" is what AWS call it). The container will get terminated when memory usage reaches 100%, which can be a matter of weeks when running with a minimalistic spec.

Plumber is the only thing running in the container, so I assume the memory usage / leak is linked to plumber or more generally to R.

Is this something other people have observed? Any idea what could cause it? How can I troubleshoot it?

FYI I am logging every request by writing to the console with the logging package (it all gets picked up by CloudWatch, AWS logging manager). I receive on average 5 requests per minute. Could that be the reason?

I appreciate this is not really a bug report, but it felt like an appropriate place to discuss plumber's memory usage over an extended period of time. This would probably get closed on SO.

Thanks

[schloerke]

This could also be related to issues with R in general. We've identified some issues with how asking if something exists in an environment causes a small mem leak.

2mb over ~7200 requests isn't too bad. I'll ask some of my team to get finer control over when/where the memory is leaking.

(Adding help wanted label so people see the issue.)

[schloerke]

if you are able to, run it inside profvis. Will be able to see where memory is allocated and (not) deallocated. https://rstudio.github.io/profvis/faq.html

It could be plumber, logging, R6, or even just R.

As far as I know, plumber is not tracking anything between requests. With the amount of environments in the R6 objects, which would require "exists in the environment" checks using symbols, it might be the underlying culprit.

cc @wch

[wch]

R6 shouldn't contribute to memory leaks by itself.

R itself can leak memory if there are random symbols being used; that's what the fastmap package is meant to solve. However, I don't see anywhere in plumber where random keys are used, so I don't think that plumber itself is the culprit either.

@antoine-sachet What does your code do? It's possible that it's your code (and not plumber) that is causing the leak.

[wch]

FWIW, when I use the following, I see no increase in the memory usage.

plumber.R:

#* Random numbers
#* @get /random
function(){
  rnorm(10)
}

#* Memory usage by the R process
#* @get /mem
function(){
  as.numeric(pryr::mem_used())
}

From the R console:

library(plumber)
r <- plumb("plumber.R")
r$run(port=8000)

From a terminal, I use curl and ab (ApacheBench).

First, find out how much memory is being used:

$ curl localhost:8000/mem
[48477016]

Then fetch /random 100 times using ab, and check memory usage:

$ ab -n 100 localhost:8000/random
 ...
$ curl localhost:8000/mem
[48484824]

Then make 5,000 requests to /random and check the memory:

$ ab -n 5000 localhost:8000/random
  ...
$ curl localhost:8000/mem
[48484824]

Given this result, I suspect the issue has to do not with plumber itself, but with the code you're running from plumber.

So it looks like there's an increase in memory usage in the beginning, but not after it's been warmed up.

My session info (I'm using a build of R-devel):

─ Session info ──────────────────────────────────────────────────────────────────────────────────────
 setting  value                                             
 version  R Under development (unstable) (2019-05-23 r76587)
 os       macOS Mojave 10.14                                
 system   x86_64, darwin18.0.0                              
 ui       RStudio                                           
 language (EN)                                              
 collate  en_US.UTF-8                                       
 ctype    en_US.UTF-8                                       
 tz       America/Chicago                                   
 date     2019-06-14                                        

─ Packages ──────────────────────────────────────────────────────────────────────────────────────────
 package     * version date       lib source           
 assertthat    0.2.1   2019-03-21 [1] CRAN (R 3.7.0)   
 cli           1.1.0   2019-03-19 [1] CRAN (R 3.7.0)   
 codetools     0.2-16  2018-12-24 [1] CRAN (R 3.7.0)   
 crayon        1.3.4   2017-09-16 [1] CRAN (R 3.7.0)   
 httpuv        1.5.1   2019-04-05 [1] CRAN (R 3.7.0)   
 jsonlite      1.6     2018-12-07 [1] CRAN (R 3.7.0)   
 later         0.8.0   2019-02-11 [1] CRAN (R 3.7.0)   
 magrittr      1.5     2014-11-22 [1] CRAN (R 3.7.0)   
 plumber     * 0.4.6   2018-06-05 [1] standard (@0.4.6)
 promises      1.0.1   2018-04-13 [1] CRAN (R 3.7.0)   
 pryr          0.1.4   2018-02-18 [1] CRAN (R 3.7.0)   
 R6            2.4.0   2019-02-14 [1] CRAN (R 3.7.0)   
 Rcpp          1.0.1   2019-03-17 [1] CRAN (R 3.7.0)   
 rstudioapi    0.10    2019-03-19 [1] CRAN (R 3.7.0)   
 sessioninfo   1.1.1   2018-11-05 [1] CRAN (R 3.7.0)   
 stringi       1.4.3   2019-03-12 [1] CRAN (R 3.7.0)   
 stringr       1.4.0   2019-02-10 [1] CRAN (R 3.7.0)   
 withr         2.1.2   2018-03-15 [1] CRAN (R 3.7.0)   

[1] /Users/winston/R/3.7
[2] /Library/Frameworks/R.framework/Versions/3.7-dev/Resources/library

[antoine-sachet]

Thanks both. I will run profvis later this week as soon as I have time. I have been on holiday last week and this is how things evolved:

The dev and prod services are running the exact same code, but the prod service has been receiving 300-400 requests per hour whereas the dev service has been idle. The containers have 512MB memory. That's an 11% increase over 10 days, around 5.6MB/day or about 0.5KB/request.

The API can do a lot of things but fortunately only 2 endpoints have been called and both are simple wrappers around an AWS comprehend query.

It's possible that it's your code (and not plumber) that is causing the leak.

I am hoping it is, that would be easier to fix :)

We've identified some issues with how asking if something exists in an environment causes a small mem leak.

This may well be it, because the AWS queries require credentials which are looked up using the aws.signature package whose function locate.credentials is looking for credentials in various places.

I'll have to look into it further. Do you have any reference or threads about this "small mem leak" issue?

[mhasanbulli]

Hello. I am seeing a very similar issue with our API endpoint. We have deployed a couple of containers into AWS ECS with EC2 back-end setup. We are using an application load balancer. Our memory increase is more drastic. We send in a small file to be processed. Initial memory usage is around 80MB. After about 1000 API calls, the containers reaches 100% memory and it terminates. I can reproduce the same memory increase with the default Plumber example. Every time I call localhost:8000/mean, I can see memory usage creeps up in docker stats.

[wch]

@mhasanbulli I'm not able to reproduce the problem with the default example. It does increase memory at first, but I believe this is probably due to some internal caching in R, or at the system level.

Here's what I did. First, I ran the Docker image with this command line:

docker run --rm -p 8000:8000 trestletech/plumber

Then, in another terminal, I ran docker stats. It showed this:

CONTAINER           CPU %               MEM USAGE / LIMIT     MEM %               NET I/O             BLOCK I/O           PIDS
4932b4eba80f        0.01%               60.97MiB / 19.51GiB   0.31%               7.87kB / 0B         0B / 0B             2

When I visited http://127.0.0.1:8000/mean, the memory increased by about 300KB each time. However, after a certain point, it stops increasing.

I used Apachebench to send 1000 requests to the endpoint, with the following:

ab -n 1000 http://127.0.0.1:8000/mean

Eventually, the memory topped out at 89.64MiB, as shown below:

CONTAINER           CPU %               MEM USAGE / LIMIT     MEM %               NET I/O             BLOCK I/O           PIDS
4932b4eba80f        0.00%               89.64MiB / 19.51GiB   0.45%               502kB / 512kB       0B / 0B             3

After this point, the memory would still increase when I sent 1000 more requests to it, but it increased a much slower rate. (1000 requests might result in an increase of 0.02MiB, for example.)

It is entirely possible that your application is leaking memory somewhere, but it must be due to something that's is not covered by the basic plumber example. It could be in your application code, or it could be in other parts of the plumber code, but we would need a minimal reproducible example in order to track it down.

[schloerke]

Setting this Issue to out of focus until a reprex is available.

The rewrite of how POST body values are parsed should help with files that are being POSTed. https://github.com/rstudio/plumber/pull/550/files#diff-f0d8c4442132a6ea9b7dee1b528f1797

[robayo]

Hi,
Just checking in if anyone has found a solution to this problem. Myself has seen this problem when receiving GET of very large data sets. I've seen RAM increases of that persist over time when having concurrent API calls due to the memory not being released. Right now, the plumber API is on Posit connect.

[schloerke]

Locking old thread.

If you have a reprex API that you can show has a memory leak, please open a new issue referencing this one. Thank you

[schloerke]

Closing this issue in favor of solution provided by Dmitry 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.