Potential Memory Leak - Githubissues

dfsoeten commented 5 months ago

What happened?

Hi all. I've been running a Sulu application on GCP Cloud Run for a couple of weeks now, served by FrankenPHP, and I'm encountering a odd issue potentially caused by a memory leak in FrankenPHP.

In the metrics of my application I observe the following pattern:

Memory utilisation:

Request latencies:

Memory usage of the container seems to gradually increase as time goes on. Around the 25%-27%, with 2Gi allocated, the underlying PHP worker seems to crash or fail in some way resulting in request timeouts. Personally I'm not sure exactly how FrankenPHP handles PHP processing, so please excuse my explanation here.

Besides the above observations, there seem no relevant error logs related to FrankenPHP or my Sulu application. Response codes simply jump from 200 to 504.

In addition to the above I've ran some profiles with Blackfire in a attempt to see what's going on. The memory usage for each request is around ~80mb. Which for me doesn't explain the above.

Any help further diagnosing what's going on would be much appreciated!

Potentially related issues I've also been digging through the issues here on GitHub, and the following might seem related:

458
366
440

FrankenPHP version FrankenPHP v1.1.4 PHP 8.3.7 Caddy v2.7.6 h1:w0NymbG2m9PcvKWsrXO6EEkY9Ru4FJK8uQbYcev1p3A=

Build Type

Docker (Debian Bookworm)

Worker Mode

No

Operating System

GNU/Linux

CPU Architecture

x86_64

PHP configuration

Relevant log output

No response

dunglas commented 5 months ago

Could you try to gather some memory profiles? You can follow these instructions to do so (they also work for FrankenPHP): https://mercure.rocks/docs/hub/debug

Maybe @withinboredom has other tips to track memory leaks?

withinboredom commented 5 months ago

Around the 25%-27%, with 2Gi allocated

Did you set the GOMEMLIMIT? Go will use all available physical memory (not the memory limit!) and it needs to be set in order to tell Go how much memory it should use. You can use this approximation:

FRANKENPHP_THREADS = (2*CPU_COUNT) // by default
GOMEMLIMIT = MEMORY_LIMIT - (FRANKENPHP_THREADS * PHP_MEMORY_LIMIT)

So if you have 16 cores, 2gb of memory, and 128 MB PHP memory limit, then GOMEMLIMIT should be 2000 - ((2*16) * 128) = -2096 -- in other words, I'd be overcommitted on memory and need to reduce the frankenphp threads or risk an OOM. If I reduce the frankenphp threads to 6, GOMEMLIMIT could be set to 1.2Gi and be able to handle traffic.

I just checked an application I have and don't see a memory leak. That isn't saying there isn't one (I was wrong before and I could be wrong again), just that I'm not currently reproducing it.

withinboredom commented 5 months ago

In the meantime, I'll go run a few load tests and see if I can see a memory leak.

withinboredom commented 5 months ago

I don't see any evidence of a memory leak with GOMEMLIMIT=1000000000 # 1gb.

k6 run load-test.js --no-connection-reuse

          /\      |‾‾| /‾‾/   /‾‾/
     /\  /  \     |  |/  /   /  /
    /  \/    \    |     (   /   ‾‾\
   /          \   |  |\  \ |  (‾)  |
  / __________ \  |__| \__\ \_____/ .io

     execution: local
        script: load-test.js
        output: -

     scenarios: (100.00%) 1 scenario, 100 max VUs, 30m30s max duration (incl. graceful stop):
              * default: 100 looping VUs for 30m0s (gracefulStop: 30s)

     ✓ is status 200
     ✓ is echoed

     checks.........................: 100.00% ✓ 2495990    ✗ 0
     data_received..................: 5.2 GB  2.9 MB/s
     data_sent......................: 6.2 GB  3.4 MB/s
     http_req_blocked...............: avg=472.39µs min=0s           med=417.57µs max=516.12ms p(90)=574.11µs p(95)=700.86µs
     http_req_connecting............: avg=415.5µs  min=-115677784ns med=362.85µs max=516.08ms p(90)=512.94µs p(95)=632.53µs
     http_req_duration..............: avg=144.44ms min=-35910032ns  med=153.18ms max=746.2ms  p(90)=173.77ms p(95)=181.34ms
       { expected_response:true }...: avg=144.44ms min=-35910032ns  med=153.18ms max=746.2ms  p(90)=173.77ms p(95)=181.34ms
     http_req_failed................: 0.00%   ✓ 0          ✗ 1247995
     http_req_receiving.............: avg=12.22ms  min=-107522904ns med=11.95ms  max=630.43ms p(90)=16ms     p(95)=22.88ms
     http_req_sending...............: avg=71.37µs  min=13.87µs      med=61.95µs  max=140.59ms p(90)=98.83µs  p(95)=111.21µs
     http_req_tls_handshaking.......: avg=0s       min=0s           med=0s       max=0s       p(90)=0s       p(95)=0s
     http_req_waiting...............: avg=132.14ms min=0s           med=140.39ms max=725.4ms  p(90)=158.54ms p(95)=165.21ms
     http_reqs......................: 1247995 689.389555/s
     iteration_duration.............: avg=144.22ms min=15.19ms      med=153.61ms max=491.57ms p(90)=173.94ms p(95)=180.93ms
     iterations.....................: 1247995 689.389555/s
     vus............................: 100     min=100      max=100
     vus_max........................: 100     min=100      max=100

running (30m10.3s), 000/100 VUs, 1247995 complete and 0 interrupted iterations
default ✓ [======================================] 100 VUs  30m0s

Note that this doesn't necessarily mean that there isn't one, but just that I cannot reproduce it. If you have a way of reproducing it in prod, feel free to send me an email and maybe we can figure out what is going on.

dfsoeten commented 5 months ago

Hey again, thanks for all the replies!

In my original post I forgot to mention that I've upgraded from FrankenPHP effb5805f13dac718202183d1d1c8325a9ed561d PHP 8.3.2 Caddy v2.7.6 h1:w0NymbG2m9PcvKWsrXO6EEkY9Ru4FJK8uQbYcev1p3A= to FrankenPHP v1.1.4 PHP 8.3.7 Caddy v2.7.6 h1:w0NymbG2m9PcvKWsrXO6EEkY9Ru4FJK8uQbYcev1p3A=. However, the memory consumption trend did continue, hence why assumed the PHP process was going to crash eventually. After closely monitoring my application over the last couple of days that issue seems to be gone.

Based on your suggestion @withinboredom, I've set the GOMEMLIMIT to 1094MiB. This doesn seem to have any notable effect:

I'll attempt to run some memory profiles in a bit.

dfsoeten commented 5 months ago

I'm having some issues observing the profiling data. Running go tool pprof -http=:8080 http://localhost:2019/debug/pprof/heap and/or go tool pprof -http=:8080 http://localhost:2019/debug/pprof/allocs results in output like this:

Fetching profile over HTTP from http://localhost:2019/debug/pprof/heap
Saved profile in /var/www/pprof/pprof.frankenphp.alloc_objects.alloc_space.inuse_objects.inuse_space.001.pb.gz
Serving web UI on http://localhost:8080
http://localhost:8080

and:

Fetching profile over HTTP from http://localhost:2019/debug/pprof/allocs
Saved profile in /var/www/pprof/pprof.frankenphp.alloc_objects.alloc_space.inuse_objects.inuse_space.002.pb.gz
Serving web UI on http://localhost:8080
http://localhost:8080

When trying to access localhost:8080 or localhost:2019 I get the following message: The connection was reset. This discussion here seems similar to what I'm encountering. Suggesting I open port 2019? Like so:

# docker-compose.yaml
...
    ports:
      - '8000:8000'
      - '8080:8080'
      - '2019:2019'
...

Excuse my ignorance!

withinboredom commented 5 months ago

Just like PHP, Go is a garbage collected language. That means after every request, whatever was left over is just left in memory to eventually to be garbage collected. PHP nor Go will really do that until there is memory pressure and Docker memory limits do not create memory pressure when its usage within the limits is high (IIRC, citation needed).

Using GOMEMLIMIT creates an artificial pressure on Go (technically, it creates a memory target, but that is effectively the same for our purposes). If the combined memory usage of ALL your processes is over the Docker memory limit, a random process in your container will be killed. You either need to provide the container with enough memory, or tune your processes to stay within the limit.

dunglas commented 5 months ago

Closing for now. Please reopen if you can confirm the issue.

bendavies commented 1 month ago

Around the 25%-27%, with 2Gi allocated

Did you set the GOMEMLIMIT? Go will use all available physical memory (not the memory limit!) and it needs to be set in order to tell Go how much memory it should use. You can use this approximation:
FRANKENPHP_THREADS = (2*CPU_COUNT) // by default
GOMEMLIMIT = MEMORY_LIMIT - (FRANKENPHP_THREADS * PHP_MEMORY_LIMIT)
So if you have 16 cores, 2gb of memory, and 128 MB PHP memory limit, then GOMEMLIMIT should be 2000 - ((2*16) * 128) = -2096 -- in other words, I'd be overcommitted on memory and need to reduce the frankenphp threads or risk an OOM. If I reduce the frankenphp threads to 6, GOMEMLIMIT could be set to 1.2Gi and be able to handle traffic.

I just checked an application I have and don't see a memory leak. That isn't saying there isn't one (I was wrong before and I could be wrong again), just that I'm not currently reproducing it.

@withinboredom i'm not following this sorry. The GOMEMLIMIT ends up negative in your example? What am I missing?

bendavies commented 1 month ago

ah, so you're saying the above example is not good as GOMEMLIMIT ends up negative so may up using more memory than available?

withinboredom commented 1 month ago

Yes, if you calculate a negative limit, then you do not have enough memory and are overcommitting.

I keep meaning to write a guide. I may start that tonight.

bendavies commented 1 month ago

thanks @withinboredom !

Also note my comments here around workers, threads, php and go memory limits, and how all these things are connected and should be configured: https://github.com/dunglas/frankenphp/pull/1004

dunglas / frankenphp

Potential Memory Leak #786

What happened?

458

366

440

Build Type

Worker Mode

Operating System

CPU Architecture

PHP configuration

Relevant log output