CPU cores not being used. Performance issue.

[gnat]

Hello I'm doing a comparison between caddy + php-fpm and frankenphp. Really excited about this project, but performance isn't anywhere in line with what I was expecting.

Is there something I'm obviously missing or have misconfigured? Seems like frankenphp just isn't utilising the resources available to it.

• index.php
  • <?php echo "hello";
• tested using hey
  • ulimit -n 1000000 before running hey
  • ./hey -z 10s -c 1000 http://127.0.0.1:8888/index.php

caddy + php-fpm

• ulimit -n 1000000 before running caddy
• 🟢 ~16,000 r/s. Full saturation of all cpu cores. Great!

php-fpm.conf

[main]
pm = static
pm.max_children = 1000
pm.max_requests = 1000

frankenphp

• ulimit -n 1000000 before running frankenphp (caddy)
• 🔴 ~400 r/s. Cores barely seeing any saturation of cpu, maybe 20% at most. 😦

Caddyfile

frankenphp {
	num_threads 1000
}

Any help appreciated! Thanks for the otherwise awesome project.

[withinboredom]

After messing around ... I see RPS soar to anywhere from 400 - 1000 RPS on real server hardware and then crash down to about 100 RPS after a few minutes and unable to recover. I set GOMAXPROCS to 1000 and indeed, see 1000+ threads being utilized but almost 0 CPU. Setting GOMAXPROCS up (much) higher seems to let the RPS get higher and eventually recover, but I wonder what is going on...

cc: @dunglas

[dunglas]

Thanks!

We shouldn't have to call pthread_exit() because we use a thread pool library, threads are never destroyed because they are reused. But yet, the issue is probably somewhere in this part.

[withinboredom]

Current version:

frankenphp --version
FrankenPHP 9d56f2530a2573d922e5fdf52c1af80c3da20d2b PHP 8.2.12 Caddy v2.7.5 h1:HoysvZkLcN2xJExEepaFHK92Qgs7xAiCFydN5x5Hs6Q=

[withinboredom]

Ah, yeah, forgot about the thread pool. Hmm.

I have a theory that seems to make some sense. GOMAXPROCS and frankenphp threads option need to be balanced. In other words, if you have 1000 frankenphp threads, they are at most, going to be creating that many Go threads that will get locked to the frankenphp threads. So, if GOMAXPROCS is the same number or smaller, you'll start running into issues.

Still testing that out.

[dunglas]

The syscall, locked to thread goroutines look normal: https://groups.google.com/g/golang-nuts/c/wxMP7TpNGbY/m/0sFFpilQEgAJ

The threads option is not really related to GOMAXPROCS. threads controls how many C threads to start (the C thread pool that will execute PHP scripts).

@gnat @withinboredom could you try to increase the number of C threads to see if it improves (or degrades) the numbers?

[withinboredom]

Threw hey at it this time (useful little tool) and got totally different results. I ran hey from a nearby node (not exactly on the LAN, but in the same DC and has a direct-ish 1Gbit connection), hitting beta.getswytch.com (an empty page unless logged in, but a bunch of stuff going on to generate it).

Man, this thing can go:

It's nearly pushing the node to thermal throttle...

Anyway, here's some fancy stats in various conditions.

Less procs than threads

Environment:

            - name: FRANKENPHP_CONFIG
              value: |
                num_threads 500
            - name: GOMAXPROCS
              value: '250'
            - name: GOGC
              value: "400"
            - name: CADDY_GLOBAL_OPTIONS
              value: debug
            - name: CADDY_ADMIN
              value: ':2019'

Results:

Summary:
  Total:        60.6352 secs
  Slowest:      3.3463 secs
  Fastest:      0.2423 secs
  Average:      0.8286 secs
  Requests/sec: 1201.1679


Response time histogram:
  0.242 [1]     |
  0.553 [7744]  |■■■■■■■■
  0.863 [39199] |■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■
  1.173 [18205] |■■■■■■■■■■■■■■■■■■■
  1.484 [5510]  |■■■■■■
  1.794 [1562]  |■■
  2.105 [455]   |
  2.415 [113]   |
  2.725 [30]    |
  3.036 [8]     |
  3.346 [6]     |


Latency distribution:
  10% in 0.5459 secs
  25% in 0.6403 secs
  50% in 0.7731 secs
  75% in 0.9559 secs
  90% in 1.1882 secs
  95% in 1.3593 secs
  99% in 1.7391 secs

Details (average, fastest, slowest):
  DNS+dialup:   0.0025 secs, 0.2423 secs, 3.3463 secs
  DNS-lookup:   0.0013 secs, 0.0000 secs, 0.1379 secs
  req write:    0.0000 secs, 0.0000 secs, 0.0109 secs
  resp wait:    0.8260 secs, 0.0525 secs, 3.3462 secs
  resp read:    0.0001 secs, 0.0000 secs, 0.0065 secs

Status code distribution:
  [200] 72833 responses

Observations:

Memory usage: 4.9 gb after 8 minutes, 21 seconds
Threads: 737 (total)
CPU Max-ish: 70%

Equal procs and threads

Environment:

            - name: FRANKENPHP_CONFIG
              value: |
                num_threads 500
            - name: GOMAXPROCS
              value: '500'
            - name: GOGC
              value: "400"
            - name: CADDY_GLOBAL_OPTIONS
              value: debug
            - name: CADDY_ADMIN
              value: ':2019'

Results:

Summary:
  Total:        61.2683 secs
  Slowest:      3.7932 secs
  Fastest:      0.3272 secs
  Average:      0.8195 secs
  Requests/sec: 1212.5851


Response time histogram:
  0.327 [1]     |
  0.674 [24396] |■■■■■■■■■■■■■■■■■■■■■■■■■■
  1.020 [37461] |■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■
  1.367 [9246]  |■■■■■■■■■■
  1.714 [2050]  |■■
  2.060 [461]   |
  2.407 [191]   |
  2.753 [246]   |
  3.100 [169]   |
  3.447 [54]    |
  3.793 [18]    |


Latency distribution:
  10% in 0.5380 secs
  25% in 0.6380 secs
  50% in 0.7604 secs
  75% in 0.9221 secs
  90% in 1.1407 secs
  95% in 1.3172 secs
  99% in 1.9787 secs

Details (average, fastest, slowest):
  DNS+dialup:   0.0037 secs, 0.3272 secs, 3.7932 secs
  DNS-lookup:   0.0024 secs, 0.0000 secs, 0.2272 secs
  req write:    0.0000 secs, 0.0000 secs, 0.0293 secs
  resp wait:    0.8156 secs, 0.0817 secs, 3.7931 secs
  resp read:    0.0001 secs, 0.0000 secs, 0.0047 secs

Status code distribution:
  [200] 74293 responses

Memory usage: 4.4 gb after 4 minutes, 56 seconds
Threads: 1000 (total)
Cpu Max-ish: 60%

More procs than threads

Environment:

            - name: FRANKENPHP_CONFIG
              value: |
                num_threads 500
            - name: GOMAXPROCS
              value: '1000'
            - name: GOGC
              value: "400"
            - name: CADDY_GLOBAL_OPTIONS
              value: debug
            - name: CADDY_ADMIN
              value: ':2019'

Results:

Summary:
  Total:        60.5793 secs
  Slowest:      2.3661 secs
  Fastest:      0.1662 secs
  Average:      0.6860 secs
  Requests/sec: 1451.3377


Response time histogram:
  0.166 [1]     |
  0.386 [632]   |■
  0.606 [36118] |■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■
  0.826 [37128] |■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■
  1.046 [11595] |■■■■■■■■■■■■
  1.266 [2163]  |■■
  1.486 [253]   |
  1.706 [28]    |
  1.926 [2]     |
  2.146 [0]     |
  2.366 [1]     |


Latency distribution:
  10% in 0.5609 secs
  25% in 0.5826 secs
  50% in 0.6842 secs
  75% in 0.7414 secs
  90% in 0.8592 secs
  95% in 0.9571 secs
  99% in 1.1451 secs

Details (average, fastest, slowest):
  DNS+dialup:   0.0021 secs, 0.1662 secs, 2.3661 secs
  DNS-lookup:   0.0012 secs, 0.0000 secs, 0.1530 secs
  req write:    0.0001 secs, 0.0000 secs, 0.0424 secs
  resp wait:    0.6837 secs, 0.0289 secs, 2.3661 secs
  resp read:    0.0001 secs, 0.0000 secs, 0.0126 secs

Status code distribution:
  [200] 87921 responses

Observations:

Memory usage: 4.8 gb after 3 minutes, 44 seconds
Threads: 961 (total)
Cpu Max-ish: 45%

Conclusion

According to the docs, GOMAXPROCS kills these sleeping threads, but this incurs an overhead (aka, more CPU usage), and thus less RPS total, when GOMAXPROCS is less than or equal to the number of C threads. Having more sleeping threads lying around means that more memory will be utilized, but more RPS. So, there is a tradeoff in the number of Go threads + FrankenPHP threads.

Want less CPU usage, and more RPS? Give it more PROCS than frankenphp threads, but it will use slightly more memory. Note that my environment included a GOGC value of 400% (to prevent GC from occurring during this test), and setting it to 50% on the last test reduces the memory usage to 3.6gb and RPS by ~100. So, there are some further tunings to be made.

In the end, it requires tuning for whatever load you're giving it ... we just have to figure out all the knobs. There are probably some on the PHP side as well, I just haven't fiddled with it.

[gnat]

could you try to increase the number of C threads to see if it improves (or degrades) the numbers?

Yup this is the first thing I tried before posting this discussion- it unfortunately has no effect as far as I can tell.

[gnat]

Congrats on the big 1.1.0!

Unfortunately still experiencing the exact same issue with the latest release.

• htop reports very little CPU usage by frankenphp.
• GOMAXPROCS seems to do nothing to frankenphp.
• caddy + php-fpm drastically outperforms frankenphp by over 10x because it's leveraging all cores to the maximum on the CPU. (htop confirms full CPU saturation.)

There may be a mis-configuration of frankenphp being overlooked by the devs?

...maybe the runtime config isn't being propagated?

[withinboredom]

I cannot reproduce your numbers. I can completely saturate a 1Gb connection using your original post, using about 60% of my CPU. What architecture are you running on, how much bandwidth do you have, etc?

[gnat]

How can you saturate a 1Gb connection at 1,000 r/s (..unless your requests are ~1 Mb each)? The numbers seem off by many orders of magnitude.

[gdaszuta]

I was wondering what is happening on my app that I was testing in two variants – with or without Symfony Runtime – Performance with runtime (measured as fulfilled requests) was around 12% of that without runtime. The answer was, memory limit in php.ini – with 1G limit, in Worker mode, FrankenPHP was utilizing only 2 cores. After raising this to 16G, response rate in Worker mode in comparison to legacy mode raised to 440%.

So it does seems, that memory limit is global per all threads – which sort of makes sense, I guess?

[gnat]

• Can confirm FrankenPHP seems to be only utilising roughly 2 cores.

• Stress test: ulimit -n 1000000; ./hey -z 10s -c 1000 http://127.0.0.1/index.php
• index.php: <?php echo "hello";
• memory_limit=20G did nothing in my case, still identical performance.

Testing in non-worker, normal PHP mode.

[gdaszuta]

Maybe it's configuration difference?

I am running something like that:

version: '2'
services:
  runtime:
    build:
      context: .
    ports:
      - 8068:8068
    volumes:
        - .:/app

    environment:
      - SERVER_NAME=http://localhost:8068
      - FRANKENPHP_CONFIG=worker ./public/index.php
      - APP_RUNTIME=Runtime\FrankenPhpSymfony\Runtime

  noruntime:
    build:
      context: .
    ports:
      - 8067:8067
    volumes:
        - .:/app
    environment:
      - SERVER_NAME=http://localhost:8067

FROM dunglas/frankenphp:1.1.0-php8.2

ARG COMPOSER_SHA=76a7060ccb93902cd7576b67264ad91c8a2700e2
WORKDIR /usr/local/bin

RUN apt update \
 && apt install -y git p7zip-full

RUN curl https://raw.githubusercontent.com/composer/getcomposer.org/${COMPOSER_SHA}/web/installer -s | php -- --quiet \
 && chmod +x composer.phar \
 && ln -fs composer.phar composer

RUN curl -sS https://get.symfony.com/cli/installer | bash \
 && mv /root/.symfony5/bin/symfony /usr/local/bin/symfony

RUN apt install -y htop

WORKDIR /app

And with symfony demo it was running fine on both containers, and with my production app, runtime mode was painfully slow. Raising memory_limit seems to solve this problem, and introduce some other problems (but they might be not related to frankenphp).

[withinboredom]

Have you tried a different load testing tool? I've noticed some issues with Hey + caddy, in general (related to FIN and FIN ACK packets).

[gnat]

Note: Vanilla Caddy will utilise as many cores as it needs, so it puzzles me as to why this is an issue with FrankenPHP

[gnat]

Until this is resolved, one can simply run multiple copies of frankenphp at the same time to get an order of magnitude higher throughput (each copy of frankenphp roughly doubles performance) until you saturate your CPU. @dunglas

./frankenphp run --watch
can look like:
for i in {1..20}; do ./frankenphp run --watch & done

This isn't ideal, as FrankenPHP should be capable of leveraging more CPU's on its own, but is a short term solution.

[nickchomey]

Does this run 20 different instances of caddy and frankenphp?

[dunglas]

Version 1.2.2 should improve the situation (especially for benchmarks and stress tests) thanks to #898.

[withinboredom]

I'm still looking into this, but I did find a point of contention in worker mode. If I can factor it out, we likely can increase the speed of worker mode. I can confirm something fishy with cgi-mode; but I haven't found the culprit yet. I'm still trawling through traces.

[withinboredom]

Ok. So this affects both equally, but cgi mode more, for some reason.

Essentially creating a new cgo handle produces a global lock, which means no thread can access any handle until the first one is finished creating it. If you have high load, you can end up with a large number of threads just waiting to create handles.

This is a pretty easy fix and will increase performance dramatically. I should have a PR 🔜

[withinboredom]

Ok, made some progress! I have a PoC with the following changes:

• lock-free cgo handles
• not destroying the file handle

The results are not as good as I was expecting. Most of the performance gains are in worker mode ... actually, pretty much all of them ... with a gain of about 10%. The more cores/workers there are, the better the perf improvement will be. I will def open a PR for the lock-free cgo handles, and try to upstream it as well. It's super niche, but probably worth it to include in go and it was tricky af to get right.

There appears to be another bottleneck here, and I'm 99% sure it is on the php side after staring at go stack traces for awhile now.

[dunglas]

10% improvement is huge! Thanks a lot for working on this.

[withinboredom]

Found it...!!! Its really dumb...

A few PRs are on the way.

[withinboredom]

This should be addressed in #933 (which makes cgi-mode faster than worker mode) and #934 (which makes worker mode as fast as cgi-mode)