frankenphp
frankenphp copied to clipboard
Only a few frankenphp workers processing requests
What happened?
Today, frankenphp used a limited number of workers, while 16 are defined. This caused severe slow down as these few workers were not enough to handle the load.
You can see here that most of the threads are idling:
mathieu@jobim:~$ top -H -p 3406309
top - 17:29:06 up 109 days, 8:33, 3 users, load average: 3.62, 3.64, 3.64
Threads: 44 total, 1 running, 43 sleeping, 0 stopped, 0 zombie
%Cpu(s): 16.0 us, 3.0 sy, 0.0 ni, 80.8 id, 0.0 wa, 0.0 hi, 0.1 si, 0.0 st
MiB Mem : 64036.7 total, 2389.0 free, 25173.4 used, 45994.4 buff/cache
MiB Swap: 0.0 total, 0.0 free, 0.0 used. 38863.3 avail Mem
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
3406309 root 20 0 8249916 4.1g 172384 S 89.7 6.6 61,41 frankenphp
3407079 root 20 0 8249916 4.1g 172384 R 50.0 6.6 280:17.55 thpool-1
3407085 root 20 0 8249916 4.1g 172384 S 38.0 6.6 276:08.85 thpool-7
3407087 root 20 0 8249916 4.1g 172384 S 1.0 6.6 65:32.70 thpool-9
3406921 root 20 0 8249916 4.1g 172384 S 0.3 6.6 2:34.98 frankenphp
3406928 root 20 0 8249916 4.1g 172384 S 0.3 6.6 3:30.36 frankenphp
3671077 root 20 0 8249916 4.1g 172384 S 0.3 6.6 2:56.62 frankenphp
3406918 root 20 0 8249916 4.1g 172384 S 0.0 6.6 11:52.41 frankenphp
3406919 root 20 0 8249916 4.1g 172384 S 0.0 6.6 1:19.07 frankenphp
3406920 root 20 0 8249916 4.1g 172384 S 0.0 6.6 3:38.10 frankenphp
3406922 root 20 0 8249916 4.1g 172384 S 0.0 6.6 0:00.00 frankenphp
3406923 root 20 0 8249916 4.1g 172384 S 0.0 6.6 0:00.00 frankenphp
3406924 root 20 0 8249916 4.1g 172384 S 0.0 6.6 0:00.00 frankenphp
3406925 root 20 0 8249916 4.1g 172384 S 0.0 6.6 0:44.93 frankenphp
3406926 root 20 0 8249916 4.1g 172384 S 0.0 6.6 2:24.26 frankenphp
3406927 root 20 0 8249916 4.1g 172384 S 0.0 6.6 3:35.66 frankenphp
3406929 root 20 0 8249916 4.1g 172384 S 0.0 6.6 3:23.16 frankenphp
3406930 root 20 0 8249916 4.1g 172384 S 0.0 6.6 2:49.76 frankenphp
3406931 root 20 0 8249916 4.1g 172384 S 0.0 6.6 3:32.09 frankenphp
3406932 root 20 0 8249916 4.1g 172384 S 0.0 6.6 3:33.59 frankenphp
3406933 root 20 0 8249916 4.1g 172384 S 0.0 6.6 0:05.41 frankenphp
3406985 root 20 0 8249916 4.1g 172384 S 0.0 6.6 3:13.59 frankenphp
3407078 root 20 0 8249916 4.1g 172384 S 0.0 6.6 253:46.62 thpool-0
3407080 root 20 0 8249916 4.1g 172384 S 0.0 6.6 239:37.47 thpool-2
3407081 root 20 0 8249916 4.1g 172384 S 0.0 6.6 189:19.62 thpool-3
3407082 root 20 0 8249916 4.1g 172384 S 0.0 6.6 236:08.54 thpool-4
3407083 root 20 0 8249916 4.1g 172384 S 0.0 6.6 180:47.48 thpool-5
3407084 root 20 0 8249916 4.1g 172384 S 0.0 6.6 210:54.56 thpool-6
3407086 root 20 0 8249916 4.1g 172384 S 0.0 6.6 220:59.68 thpool-8
3407088 root 20 0 8249916 4.1g 172384 S 0.0 6.6 215:54.24 thpool-10
3407089 root 20 0 8249916 4.1g 172384 S 0.0 6.6 212:52.88 thpool-11
3407090 root 20 0 8249916 4.1g 172384 S 0.0 6.6 163:46.71 thpool-12
3407091 root 20 0 8249916 4.1g 172384 S 0.0 6.6 213:10.89 thpool-13
3407092 root 20 0 8249916 4.1g 172384 S 0.0 6.6 181:53.55 thpool-14
3407093 root 20 0 8249916 4.1g 172384 S 0.0 6.6 276:34.06 thpool-15
3407094 root 20 0 8249916 4.1g 172384 S 0.0 6.6 208:10.89 thpool-16
3407261 root 20 0 8249916 4.1g 172384 S 0.0 6.6 3:30.64 frankenphp
3407262 root 20 0 8249916 4.1g 172384 S 0.0 6.6 0:43.38 frankenphp
3407263 root 20 0 8249916 4.1g 172384 S 0.0 6.6 3:31.33 frankenphp
3414330 root 20 0 8249916 4.1g 172384 S 0.0 6.6 3:35.45 frankenphp
3442002 root 20 0 8249916 4.1g 172384 S 0.0 6.6 3:24.22 frankenphp
3808272 root 20 0 8249916 4.1g 172384 S 0.0 6.6 2:51.34 frankenphp
3808273 root 20 0 8249916 4.1g 172384 S 0.0 6.6 2:25.92 frankenphp
3808274 root 20 0 8249916 4.1g 172384 S 0.0 6.6 2:59.37 frankenphp
Compare with threads after restart, where most of the thpool threads are active:
mathieu@jobim:~/docker$ top -H -p 1113899
top - 17:31:55 up 109 days, 8:35, 3 users, load average: 5.69, 4.72, 4.06
Threads: 42 total, 1 running, 41 sleeping, 0 stopped, 0 zombie
%Cpu(s): 16.7 us, 1.9 sy, 0.0 ni, 81.3 id, 0.0 wa, 0.0 hi, 0.2 si, 0.0 st
MiB Mem : 64036.7 total, 7045.3 free, 23454.6 used, 42987.7 buff/cache
MiB Swap: 0.0 total, 0.0 free, 0.0 used. 40582.1 avail Mem
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
1113899 root 20 0 6733516 2.4g 148800 S 99.9 3.9 4:53.49 frankenphp
1114269 root 20 0 6733516 2.4g 148800 R 14.3 3.9 0:20.99 thpool-2
1114281 root 20 0 6733516 2.4g 148800 S 13.3 3.9 0:16.88 thpool-14
1114282 root 20 0 6733516 2.4g 148800 S 12.0 3.9 0:18.31 thpool-15
1114278 root 20 0 6733516 2.4g 148800 S 11.3 3.9 0:16.67 thpool-11
1114283 root 20 0 6733516 2.4g 148800 S 9.3 3.9 0:19.92 thpool-16
1114277 root 20 0 6733516 2.4g 148800 S 8.3 3.9 0:17.33 thpool-10
1114280 root 20 0 6733516 2.4g 148800 S 8.3 3.9 0:18.84 thpool-13
1114267 root 20 0 6733516 2.4g 148800 S 7.7 3.9 0:17.21 thpool-0
1114274 root 20 0 6733516 2.4g 148800 S 7.7 3.9 0:16.44 thpool-7
1114272 root 20 0 6733516 2.4g 148800 S 5.7 3.9 0:16.72 thpool-5
1114273 root 20 0 6733516 2.4g 148800 S 5.7 3.9 0:17.78 thpool-6
1114275 root 20 0 6733516 2.4g 148800 S 5.7 3.9 0:18.36 thpool-8
1114270 root 20 0 6733516 2.4g 148800 S 5.0 3.9 0:19.17 thpool-3
1114279 root 20 0 6733516 2.4g 148800 S 4.7 3.9 0:19.31 thpool-12
1114268 root 20 0 6733516 2.4g 148800 S 3.3 3.9 0:16.85 thpool-1
1114271 root 20 0 6733516 2.4g 148800 S 2.0 3.9 0:16.62 thpool-4
1114229 root 20 0 6733516 2.4g 148800 S 0.7 3.9 0:00.72 frankenphp
1114232 root 20 0 6733516 2.4g 148800 S 0.7 3.9 0:00.30 frankenphp
1114230 root 20 0 6733516 2.4g 148800 S 0.3 3.9 0:00.28 frankenphp
1114231 root 20 0 6733516 2.4g 148800 S 0.3 3.9 0:00.30 frankenphp
1114237 root 20 0 6733516 2.4g 148800 S 0.3 3.9 0:00.29 frankenphp
1114240 root 20 0 6733516 2.4g 148800 S 0.3 3.9 0:00.10 frankenphp
1114241 root 20 0 6733516 2.4g 148800 S 0.3 3.9 0:00.22 frankenphp
1114436 root 20 0 6733516 2.4g 148800 S 0.3 3.9 0:00.17 frankenphp
1114617 root 20 0 6733516 2.4g 148800 S 0.3 3.9 0:00.14 frankenphp
1115510 root 20 0 6733516 2.4g 148800 S 0.3 3.9 0:00.14 frankenphp
1115511 root 20 0 6733516 2.4g 148800 S 0.3 3.9 0:00.11 frankenphp
1114233 root 20 0 6733516 2.4g 148800 S 0.0 3.9 0:00.00 frankenphp
1114234 root 20 0 6733516 2.4g 148800 S 0.0 3.9 0:00.13 frankenphp
1114235 root 20 0 6733516 2.4g 148800 S 0.0 3.9 0:00.00 frankenphp
1114236 root 20 0 6733516 2.4g 148800 S 0.0 3.9 0:00.14 frankenphp
1114238 root 20 0 6733516 2.4g 148800 S 0.0 3.9 0:00.08 frankenphp
1114239 root 20 0 6733516 2.4g 148800 S 0.0 3.9 0:00.15 frankenphp
1114242 root 20 0 6733516 2.4g 148800 S 0.0 3.9 0:00.00 frankenphp
1114243 root 20 0 6733516 2.4g 148800 S 0.0 3.9 0:00.24 frankenphp
1114244 root 20 0 6733516 2.4g 148800 S 0.0 3.9 0:00.19 frankenphp
1114245 root 20 0 6733516 2.4g 148800 S 0.0 3.9 0:01.42 frankenphp
1114276 root 20 0 6733516 2.4g 148800 S 0.0 3.9 0:00.00 thpool-9
1114469 root 20 0 6733516 2.4g 148800 S 0.0 3.9 0:00.20 frankenphp
1114516 root 20 0 6733516 2.4g 148800 S 0.0 3.9 0:00.13 frankenphp
1115509 root 20 0 6733516 2.4g 148800 S 0.0 3.9 0:00.00 frankenphp
History of total CPU usage: you can clearly see where I restarted the docker container and frankenphp was able to use more resources:
It was in this state for about 1 hour.
I don't have any further diagnostics as I had to solve this problem urgently.
Build Type
Docker (Debian Bookworm)
Worker Mode
Yes
Operating System
GNU/Linux
CPU Architecture
x86_64
Relevant log output
No response
This may be related to https://github.com/dunglas/frankenphp/issues/578.
We need to find a way to understand what is blocking.
Another snapshot with a few observations:
- the top frankenphp thread is often at 99.9% - are we hitting a bottleneck of the main thread here?
- thpool-7 is clearly not doing anything since a long time (
cpu0% andtimemuch lower than other thpool threads) - there's still a memory leak here, but an order of magnitude lower than in earlier frankenphp versions
Threads: 42 total, 0 running, 42 sleeping, 0 stopped, 0 zombie
%Cpu(s): 17.2 us, 1.8 sy, 0.0 ni, 80.7 id, 0.0 wa, 0.0 hi, 0.2 si, 0.0 st
MiB Mem : 64036.7 total, 2522.2 free, 27570.6 used, 43502.9 buff/cache
MiB Swap: 0.0 total, 0.0 free, 0.0 used. 36466.1 avail Mem
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
112139 root 20 0 10.0g 6.5g 229132 S 99.9 10.4 6d+4h frankenphp
112524 root 20 0 10.0g 6.5g 229132 S 22.3 10.4 9,11 thpool-13
112522 root 20 0 10.0g 6.5g 229132 S 17.3 10.4 9,16 thpool-11
112517 root 20 0 10.0g 6.5g 229132 S 16.9 10.4 9,13 thpool-6
112514 root 20 0 10.0g 6.5g 229132 S 15.0 10.4 9,15 thpool-3
112526 root 20 0 10.0g 6.5g 229132 S 11.0 10.4 9,13 thpool-15
112520 root 20 0 10.0g 6.5g 229132 S 8.3 10.4 9,13 thpool-9
112513 root 20 0 10.0g 6.5g 229132 S 8.0 10.4 9,12 thpool-2
112516 root 20 0 10.0g 6.5g 229132 S 8.0 10.4 9,12 thpool-5
112511 root 20 0 10.0g 6.5g 229132 S 7.0 10.4 9,11 thpool-0
112515 root 20 0 10.0g 6.5g 229132 S 5.6 10.4 9,11 thpool-4
112525 root 20 0 10.0g 6.5g 229132 S 5.6 10.4 9,17 thpool-14
112527 root 20 0 10.0g 6.5g 229132 S 5.6 10.4 9,10 thpool-16
112512 root 20 0 10.0g 6.5g 229132 S 3.0 10.4 9,13 thpool-1
112523 root 20 0 10.0g 6.5g 229132 S 2.0 10.4 238:52.08 thpool-12
112519 root 20 0 10.0g 6.5g 229132 S 1.3 10.4 9,18 thpool-8
112487 root 20 0 10.0g 6.5g 229132 S 0.7 10.4 10:17.80 frankenphp
112482 root 20 0 10.0g 6.5g 229132 S 0.3 10.4 33:49.28 frankenphp
112483 root 20 0 10.0g 6.5g 229132 S 0.3 10.4 10:27.16 frankenphp
112488 root 20 0 10.0g 6.5g 229132 S 0.3 10.4 10:30.22 frankenphp
112495 root 20 0 10.0g 6.5g 229132 S 0.3 10.4 10:21.99 frankenphp
112529 root 20 0 10.0g 6.5g 229132 S 0.3 10.4 6:21.43 frankenphp
112582 root 20 0 10.0g 6.5g 229132 S 0.3 10.4 10:10.89 frankenphp
267509 root 20 0 10.0g 6.5g 229132 S 0.3 10.4 2:05.72 frankenphp
112484 root 20 0 10.0g 6.5g 229132 S 0.0 10.4 10:44.28 frankenphp
112485 root 20 0 10.0g 6.5g 229132 S 0.0 10.4 10:28.45 frankenphp
112486 root 20 0 10.0g 6.5g 229132 S 0.0 10.4 0:00.00 frankenphp
112489 root 20 0 10.0g 6.5g 229132 S 0.0 10.4 10:30.10 frankenphp
112490 root 20 0 10.0g 6.5g 229132 S 0.0 10.4 10:13.67 frankenphp
112491 root 20 0 10.0g 6.5g 229132 S 0.0 10.4 10:09.71 frankenphp
112492 root 20 0 10.0g 6.5g 229132 S 0.0 10.4 0:00.00 frankenphp
112493 root 20 0 10.0g 6.5g 229132 S 0.0 10.4 10:40.34 frankenphp
112494 root 20 0 10.0g 6.5g 229132 S 0.0 10.4 0:00.00 frankenphp
112496 root 20 0 10.0g 6.5g 229132 S 0.0 10.4 0:01.97 frankenphp
112518 root 20 0 10.0g 6.5g 229132 S 0.0 10.4 145:54.01 thpool-7
112521 root 20 0 10.0g 6.5g 229132 S 0.0 10.4 9,13 thpool-10
112528 root 20 0 10.0g 6.5g 229132 S 0.0 10.4 9:44.18 frankenphp
112580 root 20 0 10.0g 6.5g 229132 S 0.0 10.4 10:50.71 frankenphp
112581 root 20 0 10.0g 6.5g 229132 S 0.0 10.4 10:27.89 frankenphp
112583 root 20 0 10.0g 6.5g 229132 S 0.0 10.4 8:36.71 frankenphp
113843 root 20 0 10.0g 6.5g 229132 S 0.0 10.4 10:21.58 frankenphp
1041453 root 20 0 10.0g 6.5g 229132 S 0.0 10.4 7:02.90 frankenphp