Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

FrankenPHP crashes on high loads #791

Closed
mo7zayed opened this issue Dec 22, 2023 · 63 comments
Closed

FrankenPHP crashes on high loads #791

mo7zayed opened this issue Dec 22, 2023 · 63 comments
Labels
needs more info

Comments

@mo7zayed
Copy link

Octane Version

v2.2.5

Laravel Version

10.38.2

PHP Version

8.2.13

What server type are you using?

FrankenPHP

Server Version

v1.0.1

Database Driver & Version

No response

Description

When I run a load test a fresh laravel app using apache utils tools ab the server suddenly caches. for example

pc@pc:~$ ab -n 100 -c 10 https://127.0.0.1:8000/
This is ApacheBench, Version 2.3 <$Revision: 1879490 $>
Copyright 1996 Adam Twiss, Zeus Technology Ltd, https://www.zeustech.net/
Licensed to The Apache Software Foundation, https://www.apache.org/

Benchmarking 127.0.0.1 (be patient)...apr_socket_recv: Connection refused (111)
Total of 11 requests completed

This issue happens when the concurrency is high, when running 10 times the number of requests with low concurrency I get great results, Note that this scenario doesn't always happen, It happens randomly when load testing with high concurrency

pc@pc:~$ ab -n 1000 -c 1 https://127.0.0.1:8000/
This is ApacheBench, Version 2.3 <$Revision: 1879490 $>
Copyright 1996 Adam Twiss, Zeus Technology Ltd, https://www.zeustech.net/
Licensed to The Apache Software Foundation, https://www.apache.org/

Benchmarking 127.0.0.1 (be patient)
Completed 100 requests
Completed 200 requests
Completed 300 requests
Completed 400 requests
Completed 500 requests
Completed 600 requests
Completed 700 requests
Completed 800 requests
Completed 900 requests
Completed 1000 requests
Finished 1000 requests


Server Software:        Caddy
Server Hostname:        127.0.0.1
Server Port:            8000

Document Path:          /
Document Length:        27514 bytes

Concurrency Level:      1
Time taken for tests:   4.885 seconds
Complete requests:      1000
Failed requests:        0
Total transferred:      28621000 bytes
HTML transferred:       27514000 bytes
Requests per second:    204.72 [#/sec] (mean)
Time per request:       4.885 [ms] (mean)
Time per request:       4.885 [ms] (mean, across all concurrent requests)
Transfer rate:          5721.89 [Kbytes/sec] received

Connection Times (ms)
              min  mean[+/-sd] median   max
Connect:        0    0   0.0      0       0
Processing:     1    5  36.6      1     399
Waiting:        1    1   0.7      1      11
Total:          1    5  36.6      1     399

Percentage of the requests served within a certain time (ms)
  50%      1
  66%      1
  75%      1
  80%      1
  90%      1
  95%      2
  98%      5
  99%    161
 100%    399 (longest request)

While debugging this, I noticed when running ./frankenphp -v I see that the used php version is 8.3.0 while my local php version is used to serve the application is 8.2.13

Steps To Reproduce

Here is a github repo containing a fresh laravel app with latest octane installed, just pull and
run the following commands

  • composer i
  • cp .env.example .env
  • php artisan key:generate
  • php artisan octane:install --server=frankenphp
  • php artisan octane:start --server=frankenphp

Then in another terminal tab run
ab -n 1000 -c 10 https://127.0.0.1:8000/

https://github.com/mo7zayed/frankenphp-issue
@nunomaduro
Copy link
Member

Can you use php artisan octane:start --server=frankenphp --log-level=debug, and grab the logs related to the crash?

@mo7zayed
Copy link
Author

@nunomaduro Sure, You can find the logs here

{"level":"info","ts":1703278647.0544071,"msg":"using provided configuration","config_file":"/home/mo7zayed/Desktop/work/mo7zayed/habd/frankenphp-issue/vendor/laravel/octane/src/Commands/stubs/Caddyfile","config_adapter":""}
{"level":"info","ts":1703278647.0557559,"logger":"admin","msg":"admin endpoint started","address":"localhost:2019","enforce_origin":false,"origins":["//localhost:2019","//[::1]:2019","//127.0.0.1:2019"]}
{"level":"info","ts":1703278647.0559845,"logger":"tls.cache.maintenance","msg":"started background certificate maintenance","cache":"0xc00006b280"}
{"level":"info","ts":1703278647.105399,"msg":"FrankenPHP started 🐘","php_version":"8.3.0"}
{"level":"info","ts":1703278647.1055713,"logger":"http.log","msg":"server running","name":"srv0","protocols":["h1","h2","h3"]}
{"level":"info","ts":1703278647.1056757,"msg":"autosaved config (load with --resume flag)","file":"/home/mo7zayed/.config/caddy/autosave.json"}
{"level":"info","ts":1703278647.1056812,"msg":"serving initial configuration"}
{"level":"warn","ts":1703278647.1084278,"logger":"tls","msg":"storage cleaning happened too recently; skipping for now","storage":"FileStorage:/home/mo7zayed/.local/share/caddy","instance":"399ac890-5e06-4a17-98b9-93c0047fb96c","try_again":1703365047.1084266,"try_again_in":86399.99999977}
{"level":"info","ts":1703278647.1084647,"logger":"tls","msg":"finished cleaning storage units"}
{"level":"info","ts":1703278710.5418673,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"34276","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.137580343,"size":27514,"status":200,"resp_headers":{"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.0"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Fri, 22 Dec 2023 20:58:30 GMT"],"Pragma":["no-cache"]}}
{"level":"info","ts":1703278710.5800052,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"34396","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.034518561,"size":27514,"status":200,"resp_headers":{"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Fri, 22 Dec 2023 20:58:30 GMT"],"Pragma":["no-cache"],"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.0"]}}
{"level":"info","ts":1703278710.5829577,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"34380","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.037392477,"size":27514,"status":200,"resp_headers":{"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Fri, 22 Dec 2023 20:58:30 GMT"],"Pragma":["no-cache"],"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.0"]}}
{"level":"info","ts":1703278710.5847366,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"34346","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.039129869,"size":27514,"status":200,"resp_headers":{"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.0"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Fri, 22 Dec 2023 20:58:30 GMT"],"Pragma":["no-cache"],"Expires":["-1"]}}
{"level":"info","ts":1703278710.5867207,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"34694","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.041195794,"size":27514,"status":200,"resp_headers":{"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Fri, 22 Dec 2023 20:58:30 GMT"],"Pragma":["no-cache"],"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.0"]}}
{"level":"info","ts":1703278710.588303,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"34678","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.042501492,"size":27514,"status":200,"resp_headers":{"Cache-Control":["private, must-revalidate"],"Date":["Fri, 22 Dec 2023 20:58:30 GMT"],"Pragma":["no-cache"],"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.0"],"Content-Type":["text/html; charset=UTF-8"]}}
{"level":"info","ts":1703278710.5899355,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"34670","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.044166405,"size":27514,"status":200,"resp_headers":{"Date":["Fri, 22 Dec 2023 20:58:30 GMT"],"Pragma":["no-cache"],"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.0"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"]}}
{"level":"info","ts":1703278710.5922215,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"34320","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.046417094,"size":27514,"status":200,"resp_headers":{"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.0"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Fri, 22 Dec 2023 20:58:30 GMT"],"Pragma":["no-cache"],"Expires":["-1"]}}
{"level":"info","ts":1703278710.5963607,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"34448","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.050532259,"size":27514,"status":200,"resp_headers":{"Pragma":["no-cache"],"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.0"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Fri, 22 Dec 2023 20:58:30 GMT"]}}
{"level":"info","ts":1703278710.596912,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"34336","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.052590114,"size":27514,"status":200,"resp_headers":{"X-Powered-By":["PHP/8.3.0"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Fri, 22 Dec 2023 20:58:30 GMT"],"Pragma":["no-cache"],"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"]}}
{"level":"info","ts":1703278710.5971634,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"34730","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.052131965,"size":27514,"status":200,"resp_headers":{"Pragma":["no-cache"],"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.0"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Fri, 22 Dec 2023 20:58:30 GMT"]}}
{"level":"info","ts":1703278710.597541,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"34472","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.053017848,"size":27514,"status":200,"resp_headers":{"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Fri, 22 Dec 2023 20:58:30 GMT"],"Pragma":["no-cache"],"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.0"]}}
{"level":"info","ts":1703278710.597548,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"34410","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.052555975,"size":27514,"status":200,"resp_headers":{"Server":["Caddy"],"X-Powered-By":["PHP/8.3.0"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Fri, 22 Dec 2023 20:58:30 GMT"],"Pragma":["no-cache"],"Expires":["-1"],"Set-Cookie":[]}}
{"level":"info","ts":1703278710.5976424,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"34760","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.052591155,"size":27514,"status":200,"resp_headers":{"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.0"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Fri, 22 Dec 2023 20:58:30 GMT"],"Pragma":["no-cache"],"Expires":["-1"]}}
{"level":"info","ts":1703278710.5977588,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"34302","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.053335849,"size":27514,"status":200,"resp_headers":{"Date":["Fri, 22 Dec 2023 20:58:30 GMT"],"Pragma":["no-cache"],"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.0"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"]}}
{"level":"info","ts":1703278710.5978084,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"34620","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.053401989,"size":27514,"status":200,"resp_headers":{"Cache-Control":["private, must-revalidate"],"Date":["Fri, 22 Dec 2023 20:58:30 GMT"],"Pragma":["no-cache"],"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.0"],"Content-Type":["text/html; charset=UTF-8"]}}
{"level":"info","ts":1703278710.5982041,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"34578","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.05358116,"size":27514,"status":200,"resp_headers":{"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.0"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Fri, 22 Dec 2023 20:58:30 GMT"],"Pragma":["no-cache"],"Expires":["-1"]}}
{"level":"info","ts":1703278710.598243,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"34370","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.05391941,"size":27514,"status":200,"resp_headers":{"Server":["Caddy"],"X-Powered-By":["PHP/8.3.0"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Fri, 22 Dec 2023 20:58:30 GMT"],"Pragma":["no-cache"],"Expires":["-1"],"Set-Cookie":[]}}
{"level":"info","ts":1703278710.598253,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"34752","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.053312111,"size":27514,"status":200,"resp_headers":{"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.0"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Fri, 22 Dec 2023 20:58:30 GMT"],"Pragma":["no-cache"]}}
{"level":"info","ts":1703278710.5983367,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"34450","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.053632762,"size":27514,"status":200,"resp_headers":{"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.0"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Fri, 22 Dec 2023 20:58:30 GMT"],"Pragma":["no-cache"],"Expires":["-1"]}}
{"level":"info","ts":1703278710.5988786,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"34288","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.054835668,"size":27514,"status":200,"resp_headers":{"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.0"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Fri, 22 Dec 2023 20:58:30 GMT"],"Pragma":["no-cache"]}}
{"level":"info","ts":1703278710.5990226,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"34466","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.054490132,"size":27514,"status":200,"resp_headers":{"Pragma":["no-cache"],"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.0"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Fri, 22 Dec 2023 20:58:30 GMT"]}}
{"level":"info","ts":1703278710.599067,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"34546","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.054211583,"size":27514,"status":200,"resp_headers":{"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.0"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Fri, 22 Dec 2023 20:58:30 GMT"],"Pragma":["no-cache"]}}
{"level":"info","ts":1703278710.5992312,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"34744","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.054372868,"size":27514,"status":200,"resp_headers":{"Cache-Control":["private, must-revalidate"],"Date":["Fri, 22 Dec 2023 20:58:30 GMT"],"Pragma":["no-cache"],"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.0"],"Content-Type":["text/html; charset=UTF-8"]}}
{"level":"info","ts":1703278710.5992477,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"34308","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.054861109,"size":27514,"status":200,"resp_headers":{"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Fri, 22 Dec 2023 20:58:30 GMT"],"Pragma":["no-cache"],"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.0"]}}
{"level":"info","ts":1703278710.5992756,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"34572","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.0531472,"size":27514,"status":200,"resp_headers":{"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.0"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Fri, 22 Dec 2023 20:58:30 GMT"],"Pragma":["no-cache"]}}
{"level":"info","ts":1703278710.5993197,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"34710","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.05320893,"size":27514,"status":200,"resp_headers":{"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Fri, 22 Dec 2023 20:58:30 GMT"],"Pragma":["no-cache"],"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.0"]}}
{"level":"info","ts":1703278710.5993226,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"34496","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.05383485,"size":27514,"status":200,"resp_headers":{"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.0"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Fri, 22 Dec 2023 20:58:30 GMT"],"Pragma":["no-cache"]}}
{"level":"info","ts":1703278710.599455,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"34528","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"Accept":["*/*"],"User-Agent":["ApacheBench/2.3"]}},"bytes_read":0,"user_id":"","duration":0.054962966,"size":27514,"status":200,"resp_headers":{"Cache-Control":["private, must-revalidate"],"Date":["Fri, 22 Dec 2023 20:58:30 GMT"],"Pragma":["no-cache"],"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.0"],"Content-Type":["text/html; charset=UTF-8"]}}
{"level":"info","ts":1703278710.599462,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"34424","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.053090641,"size":27514,"status":200,"resp_headers":{"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.0"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Fri, 22 Dec 2023 20:58:30 GMT"],"Pragma":["no-cache"],"Expires":["-1"]}}
{"level":"info","ts":1703278710.5994709,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"34724","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.053420904,"size":27514,"status":200,"resp_headers":{"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.0"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Fri, 22 Dec 2023 20:58:30 GMT"],"Pragma":["no-cache"],"Expires":["-1"]}}
{"level":"info","ts":1703278710.5995014,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"34514","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.054798648,"size":27514,"status":200,"resp_headers":{"Pragma":["no-cache"],"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.0"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Fri, 22 Dec 2023 20:58:30 GMT"]}}
{"level":"info","ts":1703278710.6000152,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"34652","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.055450844,"size":27514,"status":200,"resp_headers":{"X-Powered-By":["PHP/8.3.0"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Fri, 22 Dec 2023 20:58:30 GMT"],"Pragma":["no-cache"],"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"]}}
{"level":"info","ts":1703278710.6000674,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"34606","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.055660284,"size":27514,"status":200,"resp_headers":{"Pragma":["no-cache"],"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.0"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Fri, 22 Dec 2023 20:58:30 GMT"]}}
{"level":"info","ts":1703278710.6000736,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"34590","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.055221305,"size":27514,"status":200,"resp_headers":{"Server":["Caddy"],"X-Powered-By":["PHP/8.3.0"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Fri, 22 Dec 2023 20:58:30 GMT"],"Pragma":["no-cache"],"Expires":["-1"],"Set-Cookie":[]}}
{"level":"info","ts":1703278710.6003792,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"34438","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.05405191,"size":27514,"status":200,"resp_headers":{"X-Powered-By":["PHP/8.3.0"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Fri, 22 Dec 2023 20:58:30 GMT"],"Pragma":["no-cache"],"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"]}}
{"level":"info","ts":1703278710.6003947,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"34706","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.054883808,"size":27514,"status":200,"resp_headers":{"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Fri, 22 Dec 2023 20:58:30 GMT"],"Pragma":["no-cache"],"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.0"]}}
{"level":"info","ts":1703278710.6006112,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"34476","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.054089621,"size":27514,"status":200,"resp_headers":{"Cache-Control":["private, must-revalidate"],"Date":["Fri, 22 Dec 2023 20:58:30 GMT"],"Pragma":["no-cache"],"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.0"],"Content-Type":["text/html; charset=UTF-8"]}}
{"level":"info","ts":1703278710.6006556,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"34544","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.055783055,"size":27514,"status":200,"resp_headers":{"Pragma":["no-cache"],"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.0"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Fri, 22 Dec 2023 20:58:30 GMT"]}}
{"level":"info","ts":1703278710.600694,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"34362","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.056397008,"size":27514,"status":200,"resp_headers":{"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.0"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Fri, 22 Dec 2023 20:58:30 GMT"],"Pragma":["no-cache"],"Expires":["-1"]}}
{"level":"info","ts":1703278710.6006925,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"34808","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.021929652,"size":27514,"status":200,"resp_headers":{"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.0"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Fri, 22 Dec 2023 20:58:30 GMT"],"Pragma":["no-cache"]}}
{"level":"info","ts":1703278710.600713,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"34784","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.021931883,"size":27514,"status":200,"resp_headers":{"Pragma":["no-cache"],"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.0"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Fri, 22 Dec 2023 20:58:30 GMT"]}}
{"level":"info","ts":1703278710.6007485,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"34848","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.021955732,"size":27514,"status":200,"resp_headers":{"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Fri, 22 Dec 2023 20:58:30 GMT"],"Pragma":["no-cache"],"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.0"]}}
{"level":"info","ts":1703278710.60079,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"34774","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.02201847,"size":27514,"status":200,"resp_headers":{"X-Powered-By":["PHP/8.3.0"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Fri, 22 Dec 2023 20:58:30 GMT"],"Pragma":["no-cache"],"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"]}}
{"level":"info","ts":1703278710.600825,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"34840","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.022006786,"size":27514,"status":200,"resp_headers":{"Date":["Fri, 22 Dec 2023 20:58:30 GMT"],"Pragma":["no-cache"],"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.0"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"]}}
{"level":"info","ts":1703278710.6011488,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"34798","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.022285025,"size":27514,"status":200,"resp_headers":{"Pragma":["no-cache"],"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.0"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Fri, 22 Dec 2023 20:58:30 GMT"]}}
{"level":"info","ts":1703278710.601734,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"34878","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.022701753,"size":27514,"status":200,"resp_headers":{"X-Powered-By":["PHP/8.3.0"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Fri, 22 Dec 2023 20:58:30 GMT"],"Pragma":["no-cache"],"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"]}}
{"level":"info","ts":1703278710.6017647,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"34920","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.022681354,"size":27514,"status":200,"resp_headers":{"Pragma":["no-cache"],"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.0"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Fri, 22 Dec 2023 20:58:30 GMT"]}}
{"level":"info","ts":1703278710.6018746,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"34906","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"Accept":["*/*"],"User-Agent":["ApacheBench/2.3"]}},"bytes_read":0,"user_id":"","duration":0.022851334,"size":27514,"status":200,"resp_headers":{"Pragma":["no-cache"],"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.0"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Fri, 22 Dec 2023 20:58:30 GMT"]}}
{"level":"info","ts":1703278710.601926,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"34930","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.022837165,"size":27514,"status":200,"resp_headers":{"X-Powered-By":["PHP/8.3.0"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Fri, 22 Dec 2023 20:58:30 GMT"],"Pragma":["no-cache"],"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"]}}
{"level":"info","ts":1703278710.6020398,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"34564","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.057159439,"size":27514,"status":200,"resp_headers":{"Pragma":["no-cache"],"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.0"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Fri, 22 Dec 2023 20:58:30 GMT"]}}
{"level":"info","ts":1703278710.6020498,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"34876","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.02302111,"size":27514,"status":200,"resp_headers":{"Cache-Control":["private, must-revalidate"],"Date":["Fri, 22 Dec 2023 20:58:30 GMT"],"Pragma":["no-cache"],"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.0"],"Content-Type":["text/html; charset=UTF-8"]}}
{"level":"info","ts":1703278710.6023126,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"35000","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.023119063,"size":27514,"status":200,"resp_headers":{"X-Powered-By":["PHP/8.3.0"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Fri, 22 Dec 2023 20:58:30 GMT"],"Pragma":["no-cache"],"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"]}}
{"level":"info","ts":1703278710.6023335,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"34300","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.058024362,"size":27514,"status":200,"resp_headers":{"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Fri, 22 Dec 2023 20:58:30 GMT"],"Pragma":["no-cache"],"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.0"]}}
{"level":"info","ts":1703278710.6023352,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"34488","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.055891685,"size":27514,"status":200,"resp_headers":{"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.0"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Fri, 22 Dec 2023 20:58:30 GMT"],"Pragma":["no-cache"],"Expires":["-1"]}}
{"level":"info","ts":1703278710.602359,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"34828","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.023444957,"size":27514,"status":200,"resp_headers":{"Cache-Control":["private, must-revalidate"],"Date":["Fri, 22 Dec 2023 20:58:30 GMT"],"Pragma":["no-cache"],"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.0"],"Content-Type":["text/html; charset=UTF-8"]}}
{"level":"info","ts":1703278710.6023803,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"34662","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"Accept":["*/*"],"User-Agent":["ApacheBench/2.3"]}},"bytes_read":0,"user_id":"","duration":0.056901968,"size":27514,"status":200,"resp_headers":{"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.0"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Fri, 22 Dec 2023 20:58:30 GMT"],"Pragma":["no-cache"],"Expires":["-1"]}}
{"level":"info","ts":1703278710.6027055,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"34884","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.023720455,"size":27514,"status":200,"resp_headers":{"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.0"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Fri, 22 Dec 2023 20:58:30 GMT"],"Pragma":["no-cache"]}}
{"level":"info","ts":1703278710.6028612,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"34548","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.058334233,"size":27514,"status":200,"resp_headers":{"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.0"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Fri, 22 Dec 2023 20:58:30 GMT"],"Pragma":["no-cache"]}}
{"level":"info","ts":1703278710.6028814,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"34512","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.056406775,"size":27514,"status":200,"resp_headers":{"Cache-Control":["private, must-revalidate"],"Date":["Fri, 22 Dec 2023 20:58:30 GMT"],"Pragma":["no-cache"],"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.0"],"Content-Type":["text/html; charset=UTF-8"]}}
{"level":"info","ts":1703278710.602912,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"34946","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.023767663,"size":27514,"status":200,"resp_headers":{"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.0"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Fri, 22 Dec 2023 20:58:30 GMT"],"Pragma":["no-cache"]}}
{"level":"info","ts":1703278710.6032517,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"34980","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.023964471,"size":27514,"status":200,"resp_headers":{"Cache-Control":["private, must-revalidate"],"Date":["Fri, 22 Dec 2023 20:58:30 GMT"],"Pragma":["no-cache"],"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.0"],"Content-Type":["text/html; charset=UTF-8"]}}
{"level":"info","ts":1703278710.6033928,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"34864","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.024396463,"size":27514,"status":200,"resp_headers":{"Date":["Fri, 22 Dec 2023 20:58:30 GMT"],"Pragma":["no-cache"],"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.0"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"]}}
{"level":"info","ts":1703278710.6035028,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"34898","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.024419416,"size":27514,"status":200,"resp_headers":{"Date":["Fri, 22 Dec 2023 20:58:30 GMT"],"Pragma":["no-cache"],"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.0"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"]}}
{"level":"info","ts":1703278710.6035457,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"35080","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.024092112,"size":27514,"status":200,"resp_headers":{"Date":["Fri, 22 Dec 2023 20:58:30 GMT"],"Pragma":["no-cache"],"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.0"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"]}}
{"level":"info","ts":1703278710.603793,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"35046","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.024444522,"size":27514,"status":200,"resp_headers":{"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.0"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Fri, 22 Dec 2023 20:58:30 GMT"],"Pragma":["no-cache"]}}
{"level":"info","ts":1703278710.6039145,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"35134","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.024452005,"size":27514,"status":200,"resp_headers":{"Date":["Fri, 22 Dec 2023 20:58:30 GMT"],"Pragma":["no-cache"],"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.0"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"]}}
{"level":"info","ts":1703278710.6040564,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"35070","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.024599411,"size":27514,"status":200,"resp_headers":{"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.0"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Fri, 22 Dec 2023 20:58:30 GMT"],"Pragma":["no-cache"],"Expires":["-1"]}}
{"level":"info","ts":1703278710.6041012,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"34824","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.025129942,"size":27514,"status":200,"resp_headers":{"Date":["Fri, 22 Dec 2023 20:58:30 GMT"],"Pragma":["no-cache"],"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.0"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"]}}
{"level":"info","ts":1703278710.6042073,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"34932","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.025066573,"size":27514,"status":200,"resp_headers":{"Pragma":["no-cache"],"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.0"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Fri, 22 Dec 2023 20:58:30 GMT"]}}
{"level":"info","ts":1703278710.60431,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"35104","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.024867585,"size":27514,"status":200,"resp_headers":{"Pragma":["no-cache"],"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.0"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Fri, 22 Dec 2023 20:58:30 GMT"]}}
{"level":"info","ts":1703278710.6043496,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"35092","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.02489229,"size":27514,"status":200,"resp_headers":{"Pragma":["no-cache"],"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.0"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Fri, 22 Dec 2023 20:58:30 GMT"]}}
{"level":"info","ts":1703278710.6044285,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"35136","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.024760461,"size":27514,"status":200,"resp_headers":{"Pragma":["no-cache"],"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.0"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Fri, 22 Dec 2023 20:58:30 GMT"]}}
{"level":"info","ts":1703278710.6044564,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"35022","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.024683048,"size":27514,"status":200,"resp_headers":{"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.0"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Fri, 22 Dec 2023 20:58:30 GMT"],"Pragma":["no-cache"],"Expires":["-1"]}}
{"level":"info","ts":1703278710.6048126,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"35214","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"Accept":["*/*"],"User-Agent":["ApacheBench/2.3"]}},"bytes_read":0,"user_id":"","duration":0.025002209,"size":27514,"status":200,"resp_headers":{"Date":["Fri, 22 Dec 2023 20:58:30 GMT"],"Pragma":["no-cache"],"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.0"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"]}}
{"level":"info","ts":1703278710.605104,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"34956","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.025888098,"size":27514,"status":200,"resp_headers":{"X-Powered-By":["PHP/8.3.0"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Fri, 22 Dec 2023 20:58:30 GMT"],"Pragma":["no-cache"],"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"]}}
{"level":"info","ts":1703278710.6053603,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"34968","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.026108034,"size":27514,"status":200,"resp_headers":{"Date":["Fri, 22 Dec 2023 20:58:30 GMT"],"Pragma":["no-cache"],"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.0"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"]}}
{"level":"info","ts":1703278710.6053681,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"35180","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.025167848,"size":27514,"status":200,"resp_headers":{"Server":["Caddy"],"X-Powered-By":["PHP/8.3.0"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Fri, 22 Dec 2023 20:58:30 GMT"],"Pragma":["no-cache"],"Expires":["-1"],"Set-Cookie":[]}}
{"level":"info","ts":1703278710.6054304,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"34882","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.026442364,"size":27514,"status":200,"resp_headers":{"Pragma":["no-cache"],"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.0"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Fri, 22 Dec 2023 20:58:30 GMT"]}}
{"level":"info","ts":1703278710.6054323,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"34950","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.026188972,"size":27514,"status":200,"resp_headers":{"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.0"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Fri, 22 Dec 2023 20:58:30 GMT"],"Pragma":["no-cache"]}}
{"level":"info","ts":1703278710.6058016,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"35012","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"Accept":["*/*"],"User-Agent":["ApacheBench/2.3"]}},"bytes_read":0,"user_id":"","duration":0.026507888,"size":27514,"status":200,"resp_headers":{"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.0"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Fri, 22 Dec 2023 20:58:30 GMT"],"Pragma":["no-cache"]}}
{"level":"info","ts":1703278710.6058059,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"34506","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.059272515,"size":27514,"status":200,"resp_headers":{"Server":["Caddy"],"X-Powered-By":["PHP/8.3.0"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Fri, 22 Dec 2023 20:58:30 GMT"],"Pragma":["no-cache"],"Expires":["-1"],"Set-Cookie":[]}}
{"level":"info","ts":1703278710.6059926,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"35186","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"Accept":["*/*"],"User-Agent":["ApacheBench/2.3"]}},"bytes_read":0,"user_id":"","duration":0.026077578,"size":27514,"status":200,"resp_headers":{"Pragma":["no-cache"],"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.0"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Fri, 22 Dec 2023 20:58:30 GMT"]}}
{"level":"info","ts":1703278710.606124,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"35024","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.02679778,"size":27514,"status":200,"resp_headers":{"Server":["Caddy"],"X-Powered-By":["PHP/8.3.0"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Fri, 22 Dec 2023 20:58:30 GMT"],"Pragma":["no-cache"],"Expires":["-1"],"Set-Cookie":[]}}
{"level":"info","ts":1703278710.6061711,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"35120","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.026701839,"size":27514,"status":200,"resp_headers":{"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Fri, 22 Dec 2023 20:58:30 GMT"],"Pragma":["no-cache"],"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.0"]}}
{"level":"info","ts":1703278710.6062176,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"35034","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.0267646,"size":27514,"status":200,"resp_headers":{"Server":["Caddy"],"X-Powered-By":["PHP/8.3.0"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Fri, 22 Dec 2023 20:58:30 GMT"],"Pragma":["no-cache"],"Expires":["-1"],"Set-Cookie":[]}}
{"level":"info","ts":1703278710.6062338,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"35144","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.026756229,"size":27514,"status":200,"resp_headers":{"Pragma":["no-cache"],"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.0"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Fri, 22 Dec 2023 20:58:30 GMT"]}}
{"level":"info","ts":1703278710.6062338,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"34952","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"Accept":["*/*"],"User-Agent":["ApacheBench/2.3"]}},"bytes_read":0,"user_id":"","duration":0.026933102,"size":27514,"status":200,"resp_headers":{"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Fri, 22 Dec 2023 20:58:30 GMT"],"Pragma":["no-cache"],"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.0"]}}
{"level":"info","ts":1703278710.6062644,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"34996","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.02696234,"size":27514,"status":200,"resp_headers":{"X-Powered-By":["PHP/8.3.0"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Fri, 22 Dec 2023 20:58:30 GMT"],"Pragma":["no-cache"],"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"]}}
{"level":"info","ts":1703278710.606281,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"34916","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.027166443,"size":27514,"status":200,"resp_headers":{"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.0"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Fri, 22 Dec 2023 20:58:30 GMT"],"Pragma":["no-cache"],"Expires":["-1"]}}
{"level":"info","ts":1703278710.6063015,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"35198","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.026350817,"size":27514,"status":200,"resp_headers":{"Server":["Caddy"],"X-Powered-By":["PHP/8.3.0"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Fri, 22 Dec 2023 20:58:30 GMT"],"Pragma":["no-cache"],"Expires":["-1"],"Set-Cookie":[]}}
{"level":"info","ts":1703278710.6065323,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"35242","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.021616301,"size":27514,"status":200,"resp_headers":{"X-Powered-By":["PHP/8.3.0"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Fri, 22 Dec 2023 20:58:30 GMT"],"Pragma":["no-cache"],"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"]}}
{"level":"info","ts":1703278710.6067188,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"35160","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.026759299,"size":27514,"status":200,"resp_headers":{"Cache-Control":["private, must-revalidate"],"Date":["Fri, 22 Dec 2023 20:58:30 GMT"],"Pragma":["no-cache"],"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.0"],"Content-Type":["text/html; charset=UTF-8"]}}
{"level":"info","ts":1703278710.606723,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"35202","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.026680872,"size":27514,"status":200,"resp_headers":{"Cache-Control":["private, must-revalidate"],"Date":["Fri, 22 Dec 2023 20:58:30 GMT"],"Pragma":["no-cache"],"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.0"],"Content-Type":["text/html; charset=UTF-8"]}}
{"level":"info","ts":1703278710.606889,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"35168","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"Accept":["*/*"],"User-Agent":["ApacheBench/2.3"]}},"bytes_read":0,"user_id":"","duration":0.026900403,"size":27514,"status":200,"resp_headers":{"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.0"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Fri, 22 Dec 2023 20:58:30 GMT"],"Pragma":["no-cache"]}}
{"level":"info","ts":1703278710.606913,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"35228","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.0260876,"size":27514,"status":200,"resp_headers":{"X-Powered-By":["PHP/8.3.0"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Fri, 22 Dec 2023 20:58:30 GMT"],"Pragma":["no-cache"],"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"]}}
{"level":"info","ts":1703278710.6070192,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"35232","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.023574232,"size":27514,"status":200,"resp_headers":{"Cache-Control":["private, must-revalidate"],"Date":["Fri, 22 Dec 2023 20:58:30 GMT"],"Pragma":["no-cache"],"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.0"],"Content-Type":["text/html; charset=UTF-8"]}}

@mo7zayed
Copy link
Author

@nunomaduro Sometimes when I start the server randomly using php artisan octane:start --server=frankenphp --log-level=debug

{"level":"info","ts":1703279449.4357417,"msg":"using provided configuration","config_file":"/home/mo7zayed/Desktop/work/mo7zayed/habd/frankenphp-issue/vendor/laravel/octane/src/Commands/stubs/Caddyfile","config_adapter":""}
{"level":"info","ts":1703279449.4369097,"logger":"admin","msg":"admin endpoint started","address":"localhost:2019","enforce_origin":false,"origins":["//localhost:2019","//[::1]:2019","//127.0.0.1:2019"]}
{"level":"info","ts":1703279449.4370534,"logger":"tls.cache.maintenance","msg":"started background certificate maintenance","cache":"0xc0006a0280"}

Another log

{"level":"info","ts":1703279611.1767733,"msg":"using provided configuration","config_file":"/home/mo7zayed/Desktop/work/mo7zayed/habd/frankenphp-issue/vendor/laravel/octane/src/Commands/stubs/Caddyfile","config_adapter":""}
{"level":"info","ts":1703279611.1779628,"logger":"admin","msg":"admin endpoint started","address":"localhost:2019","enforce_origin":false,"origins":["//127.0.0.1:2019","//localhost:2019","//[::1]:2019"]}
{"level":"info","ts":1703279611.1781075,"logger":"tls.cache.maintenance","msg":"started background certificate maintenance","cache":"0xc00006bf80"}
{"level":"info","ts":1703279611.1782486,"logger":"http.log","msg":"server running","name":"srv0","protocols":["h1","h2","h3"]}
{"level":"warn","ts":1703279611.180945,"logger":"tls","msg":"storage cleaning happened too recently; skipping for now","storage":"FileStorage:/home/mo7zayed/.local/share/caddy","instance":"399ac890-5e06-4a17-98b9-93c0047fb96c","try_again":1703366011.1809442,"try_again_in":86399.99999979}
{"level":"info","ts":1703279611.181011,"logger":"tls","msg":"finished cleaning storage units"}

@nunomaduro
Copy link
Member

cc @dunglas

@dunglas
Copy link
Contributor

dunglas commented Dec 24, 2023

Thanks for the reproducer. I'll be on vacation during the next 2 weeks, but I'll try to reproduce when I'll be back.

I assume that you're using Linux, right?

To investigate deeper we have to:

  1. Identify if it's FrankenPHP itself (likely) or just the Octane wrapper that crashes. To do so, it would be nice if Octane could report crashes of the started process (and the status code) @nunomaduro
  2. If it's FrankenPHP, the next step will be to use a debug build (https://frankenphp.dev/docs/static/, and set DEBUG_SYMBOLS=1) and run it using GDB to get a back trace

@foremtehan
Copy link
Contributor

same happened to me:

image

@dunglas
Copy link
Contributor

dunglas commented Dec 26, 2023

Do you know if the server stopped (crashed) or if it is still running?

@foremtehan
Copy link
Contributor

Yeah, it has crashed and no longer running

@ariaieboy
Copy link

I can confirm this issue tested on laravel sail + fresh laravel install using windows wsl2 and local PHP installation.

@nunomaduro nunomaduro mentioned this issue Dec 29, 2023
Closed
@abishekrsrikaanth
Copy link

I am on Mac Sonomo 14.2 and in my case the octane server crashes frequently with FrankenPHP and when code changes in the product, and when --watch is used to run the octane server. Here is the debug log

Here is the command line I run the server

php artisan octane:start --port=8011 --log-level=debug --watch --server=frankenphp

INFO  Application change detected. Restarting workers…
{"level":"info","ts":1703875073.0187871,"logger":"admin.api","msg":"received request","method":"GET","host":"localhost:2030","uri":"/config/apps/frankenphp","remote_ip":"127.0.0.1","remote_port":"63873","headers":{"User-Agent":["GuzzleHttp/7"]}}
{"level":"info","ts":1703875073.020648,"logger":"admin.api","msg":"received request","method":"PATCH","host":"localhost:2030","uri":"/config/apps/frankenphp","remote_ip":"127.0.0.1","remote_port":"63875","headers":{"Cache-Control":["must-revalidate"],"Content-Length":["120"],"Content-Type":["application/json"],"User-Agent":["GuzzleHttp/7"]}}
{"level":"info","ts":1703875073.0238662,"logger":"admin","msg":"admin endpoint started","address":"localhost:2030","enforce_origin":false,"origins":["//127.0.0.1:2030","//localhost:2030","//[::1]:2030"]}
{"level":"info","ts":1703875073.024548,"logger":"http.log","msg":"server running","name":"srv0","protocols":["h1","h2","h3"]}
{"level":"info","ts":1703875073.0826108,"msg":"FrankenPHP started 🐘","php_version":"8.3.1"}
{"level":"info","ts":1703875073.082638,"logger":"http","msg":"servers shutting down with eternal grace period"}
{"level":"info","ts":1703875073.082677,"msg":"FrankenPHP stopped 🐘"}
{"level":"info","ts":1703875073.0829198,"msg":"autosaved config (load with --resume flag)","file":"/Users/abisheksrikaanth/Library/Application Support/Caddy/autosave.json"}
{"level":"info","ts":1703875073.111255,"logger":"admin","msg":"stopped previous server","address":"localhost:2030"}

INFO  Application change detected. Restarting workers…
{"level":"info","ts":1703875092.738181,"logger":"admin.api","msg":"received request","method":"GET","host":"localhost:2030","uri":"/config/apps/frankenphp","remote_ip":"127.0.0.1","remote_port":"63878","headers":{"User-Agent":["GuzzleHttp/7"]}}
{"level":"info","ts":1703875092.745216,"logger":"admin.api","msg":"received request","method":"PATCH","host":"localhost:2030","uri":"/config/apps/frankenphp","remote_ip":"127.0.0.1","remote_port":"63880","headers":{"Cache-Control":["must-revalidate"],"Content-Length":["120"],"Content-Type":["application/json"],"User-Agent":["GuzzleHttp/7"]}}
{"level":"info","ts":1703875092.747081,"logger":"admin","msg":"admin endpoint started","address":"localhost:2030","enforce_origin":false,"origins":["//[::1]:2030","//127.0.0.1:2030","//localhost:2030"]}

@mo7zayed
Copy link
Author

@nunomaduro @dunglas
Any updates about this issue?

@dunglas
Copy link
Contributor

dunglas commented Jan 18, 2024

This will likely be fixed in the latest patch release of PHP.

@LauJosefsen
Copy link
Contributor

This will likely be fixed in the latest patch release of PHP.

When you say latest and likely in the same sentence, does that mean a future release or an already released patch? If already released, what patch should I test with?

@driesvints
Copy link
Member

@dunglas did you mean v8.2.15? Because that's out now.

@RVxLab
Copy link

RVxLab commented Jan 26, 2024

I am on Mac Sonomo 14.2 and in my case the octane server crashes frequently with FrankenPHP and when code changes in the product, and when --watch is used to run the octane server. Here is the debug log

Here is the command line I run the server

php artisan octane:start --port=8011 --log-level=debug --watch --server=frankenphp

INFO  Application change detected. Restarting workers…
{"level":"info","ts":1703875073.0187871,"logger":"admin.api","msg":"received request","method":"GET","host":"localhost:2030","uri":"/config/apps/frankenphp","remote_ip":"127.0.0.1","remote_port":"63873","headers":{"User-Agent":["GuzzleHttp/7"]}}
{"level":"info","ts":1703875073.020648,"logger":"admin.api","msg":"received request","method":"PATCH","host":"localhost:2030","uri":"/config/apps/frankenphp","remote_ip":"127.0.0.1","remote_port":"63875","headers":{"Cache-Control":["must-revalidate"],"Content-Length":["120"],"Content-Type":["application/json"],"User-Agent":["GuzzleHttp/7"]}}
{"level":"info","ts":1703875073.0238662,"logger":"admin","msg":"admin endpoint started","address":"localhost:2030","enforce_origin":false,"origins":["//127.0.0.1:2030","//localhost:2030","//[::1]:2030"]}
{"level":"info","ts":1703875073.024548,"logger":"http.log","msg":"server running","name":"srv0","protocols":["h1","h2","h3"]}
{"level":"info","ts":1703875073.0826108,"msg":"FrankenPHP started 🐘","php_version":"8.3.1"}
{"level":"info","ts":1703875073.082638,"logger":"http","msg":"servers shutting down with eternal grace period"}
{"level":"info","ts":1703875073.082677,"msg":"FrankenPHP stopped 🐘"}
{"level":"info","ts":1703875073.0829198,"msg":"autosaved config (load with --resume flag)","file":"/Users/abisheksrikaanth/Library/Application Support/Caddy/autosave.json"}
{"level":"info","ts":1703875073.111255,"logger":"admin","msg":"stopped previous server","address":"localhost:2030"}

INFO  Application change detected. Restarting workers…
{"level":"info","ts":1703875092.738181,"logger":"admin.api","msg":"received request","method":"GET","host":"localhost:2030","uri":"/config/apps/frankenphp","remote_ip":"127.0.0.1","remote_port":"63878","headers":{"User-Agent":["GuzzleHttp/7"]}}
{"level":"info","ts":1703875092.745216,"logger":"admin.api","msg":"received request","method":"PATCH","host":"localhost:2030","uri":"/config/apps/frankenphp","remote_ip":"127.0.0.1","remote_port":"63880","headers":{"Cache-Control":["must-revalidate"],"Content-Length":["120"],"Content-Type":["application/json"],"User-Agent":["GuzzleHttp/7"]}}
{"level":"info","ts":1703875092.747081,"logger":"admin","msg":"admin endpoint started","address":"localhost:2030","enforce_origin":false,"origins":["//[::1]:2030","//127.0.0.1:2030","//localhost:2030"]}

Can you see this happening on 8.3.2? I can see some of the same fixes in 8.2.15 and 8.3.2.

@cmizzi
Copy link

cmizzi commented Jan 29, 2024 •
edited

Tested on PHP 8.2.15 and 8.3.2, and this issue still exists. I also did the test with a really simple FrankenPHP code (without Laravel), and there's no issue with ab or other HTTP benchmark tools. It looks related to the Laravel Octane bridge with FrankenPHP.

<?php

ignore_user_abort(true);

$handler = static function () {
    echo "Hello, world!";
};

$running = true;

while ($running) {
    $running = \frankenphp_handle_request($handler);
    gc_collect_cycles();
}

@driesvints
Copy link
Member

@dunglas ^

@dunglas
Copy link
Contributor

dunglas commented Jan 29, 2024

The patches are these:

@nogamenofun98
Copy link

nogamenofun98 commented Feb 5, 2024 •
edited

Hi @dunglas,

I noticed frankenphp had release version 1.1.0 and php also had release 8.2.15, both included the respective PR commit.
Does this means this issue is resolved now or need to wait laravel octane to update also?

@dunglas
Copy link
Contributor

dunglas commented Feb 5, 2024

The PHP patch hasn't been released yet (it will be included in the next patch version) but the fix included in FrankenPHP 1.1 is maybe enough.
Octane should upgrade automatically to FrankenPHP 1.1. The easier way to find out if this is fixed is to try 😅

@binaryfire
Copy link

binaryfire commented Feb 5, 2024 •
edited

You'll need to delete your existing binary and re-start Octane to download the latest version. The current minimum version is pinned at 1.0.2:

octane/src/Commands/Concerns/InstallsFrankenPhpDependencies.php

Line 22 in 8f9d0da

protected $requiredFrankenPhpVersion = '1.0.2';

@nogamenofun98
Copy link 

% ab -n 1000 -c 10 https://127.0.0.1:8000/
This is ApacheBench, Version 2.3 <$Revision: 1903618 $>
Copyright 1996 Adam Twiss, Zeus Technology Ltd, https://www.zeustech.net/
Licensed to The Apache Software Foundation, https://www.apache.org/

Benchmarking 127.0.0.1 (be patient)
Completed 100 requests
Completed 200 requests
Completed 300 requests
Completed 400 requests
Completed 500 requests
Completed 600 requests
Completed 700 requests
Completed 800 requests
Completed 900 requests
Completed 1000 requests
Finished 1000 requests


Server Software:        Caddy
Server Hostname:        127.0.0.1
Server Port:            8000

Document Path:          /
Document Length:        1638 bytes

Concurrency Level:      10
Time taken for tests:   8.368 seconds
Complete requests:      1000
Failed requests:        0
Total transferred:      2769000 bytes
HTML transferred:       1638000 bytes
Requests per second:    119.50 [#/sec] (mean)
Time per request:       83.681 [ms] (mean)
Time per request:       8.368 [ms] (mean, across all concurrent requests)
Transfer rate:          323.15 [Kbytes/sec] received

Connection Times (ms)
              min  mean[+/-sd] median   max
Connect:        0    0   0.2      0       4
Processing:     6   73  89.3     38    1140
Waiting:        6   73  89.3     38    1139
Total:          6   73  89.3     38    1140

Percentage of the requests served within a certain time (ms)
  50%     38
  66%     57
  75%     76
  80%    111
  90%    193
  95%    279
  98%    347
  99%    396
 100%   1140 (longest request)

seems like is working? I didnt try out before i upgrade to frankenphp 1.1.0 and php8.2 tho

@mo7zayed
Copy link
Author

mo7zayed commented Feb 7, 2024

@binaryfire @nogamenofun98
the issue still there when running with high concurrency ab -n 1000 -c 100 https://127.0.0.1:8000/

frankenphp -v

FrankenPHP v1.1.0 PHP 8.3.2 Caddy v2.7.6 h1:w0NymbG2m9PcvKWsrXO6EEkY9Ru4FJK8uQbYcev1p3A=

php artisan octane:start --server=frankenphp --log-level=debug

mo7zayed@mo7zayed:~/Desktop/work/mo7zayed/habd/frankenphp-issue$ php artisan octane:start --server=frankenphp --log-level=debug
{"level":"info","ts":1707319244.5531957,"msg":"using provided configuration","config_file":"/home/mo7zayed/Desktop/work/mo7zayed/habd/frankenphp-issue/vendor/laravel/octane/src/Commands/stubs/Caddyfile","config_adapter":""}
{"level":"info","ts":1707319244.5544229,"logger":"admin","msg":"admin endpoint started","address":"localhost:2019","enforce_origin":false,"origins":["//localhost:2019","//[::1]:2019","//127.0.0.1:2019"]}
{"level":"info","ts":1707319244.554588,"logger":"tls.cache.maintenance","msg":"started background certificate maintenance","cache":"0xc000135b00"}
{"level":"info","ts":1707319244.6014946,"msg":"FrankenPHP started 🐘","php_version":"8.3.2"}
{"level":"info","ts":1707319244.6016219,"logger":"http.log","msg":"server running","name":"srv0","protocols":["h1","h2","h3"]}
{"level":"info","ts":1707319244.6017444,"msg":"autosaved config (load with --resume flag)","file":"/home/mo7zayed/.config/caddy/autosave.json"}
{"level":"info","ts":1707319244.601749,"msg":"serving initial configuration"}
{"level":"warn","ts":1707319244.604494,"logger":"tls","msg":"storage cleaning happened too recently; skipping for now","storage":"FileStorage:/home/mo7zayed/.local/share/caddy","instance":"399ac890-5e06-4a17-98b9-93c0047fb96c","try_again":1707405644.6044931,"try_again_in":86399.999999691}
{"level":"info","ts":1707319244.6045303,"logger":"tls","msg":"finished cleaning storage units"}
{"level":"info","ts":1707319249.5749884,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"35480","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.135632514,"size":27514,"status":200,"resp_headers":{"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.2"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Wed, 07 Feb 2024 15:20:49 GMT"],"Pragma":["no-cache"]}}
{"level":"info","ts":1707319249.619355,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"35862","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.040484327,"size":27514,"status":200,"resp_headers":{"Cache-Control":["private, must-revalidate"],"Date":["Wed, 07 Feb 2024 15:20:49 GMT"],"Pragma":["no-cache"],"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.2"],"Content-Type":["text/html; charset=UTF-8"]}}
{"level":"info","ts":1707319249.6216817,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"35854","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.042802276,"size":27514,"status":200,"resp_headers":{"Cache-Control":["private, must-revalidate"],"Date":["Wed, 07 Feb 2024 15:20:49 GMT"],"Pragma":["no-cache"],"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.2"],"Content-Type":["text/html; charset=UTF-8"]}}
{"level":"info","ts":1707319249.6238704,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"35832","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.0449992,"size":27514,"status":200,"resp_headers":{"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.2"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Wed, 07 Feb 2024 15:20:49 GMT"],"Pragma":["no-cache"],"Expires":["-1"]}}
{"level":"info","ts":1707319249.625515,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"35850","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.046624696,"size":27514,"status":200,"resp_headers":{"Cache-Control":["private, must-revalidate"],"Date":["Wed, 07 Feb 2024 15:20:49 GMT"],"Pragma":["no-cache"],"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.2"],"Content-Type":["text/html; charset=UTF-8"]}}
{"level":"info","ts":1707319249.6281385,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"35874","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"Accept":["*/*"],"User-Agent":["ApacheBench/2.3"]}},"bytes_read":0,"user_id":"","duration":0.049255577,"size":27514,"status":200,"resp_headers":{"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.2"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Wed, 07 Feb 2024 15:20:49 GMT"],"Pragma":["no-cache"],"Expires":["-1"]}}
{"level":"info","ts":1707319249.6336591,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"35712","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.055294461,"size":27514,"status":200,"resp_headers":{"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Wed, 07 Feb 2024 15:20:49 GMT"],"Pragma":["no-cache"],"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.2"]}}
{"level":"info","ts":1707319249.6337557,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"35648","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.056218609,"size":27514,"status":200,"resp_headers":{"Date":["Wed, 07 Feb 2024 15:20:49 GMT"],"Pragma":["no-cache"],"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.2"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"]}}
{"level":"info","ts":1707319249.6337779,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"35598","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.05582133,"size":27514,"status":200,"resp_headers":{"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.2"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Wed, 07 Feb 2024 15:20:49 GMT"],"Pragma":["no-cache"]}}
{"level":"info","ts":1707319249.6359093,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"35912","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.058125784,"size":27514,"status":200,"resp_headers":{"Pragma":["no-cache"],"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.2"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Wed, 07 Feb 2024 15:20:49 GMT"]}}
{"level":"info","ts":1707319249.6360104,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"35780","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.057115792,"size":27514,"status":200,"resp_headers":{"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.2"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Wed, 07 Feb 2024 15:20:49 GMT"],"Pragma":["no-cache"],"Expires":["-1"]}}
{"level":"info","ts":1707319249.6362917,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"35704","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.058490671,"size":27514,"status":200,"resp_headers":{"Date":["Wed, 07 Feb 2024 15:20:49 GMT"],"Pragma":["no-cache"],"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.2"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"]}}
{"level":"info","ts":1707319249.636529,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"35816","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.058823379,"size":27514,"status":200,"resp_headers":{"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.2"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Wed, 07 Feb 2024 15:20:49 GMT"],"Pragma":["no-cache"],"Expires":["-1"]}}
{"level":"info","ts":1707319249.636589,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"35792","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.058264716,"size":27514,"status":200,"resp_headers":{"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.2"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Wed, 07 Feb 2024 15:20:49 GMT"],"Pragma":["no-cache"]}}
{"level":"info","ts":1707319249.6366494,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"35918","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.058939208,"size":27514,"status":200,"resp_headers":{"Server":["Caddy"],"X-Powered-By":["PHP/8.3.2"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Wed, 07 Feb 2024 15:20:49 GMT"],"Pragma":["no-cache"],"Expires":["-1"],"Set-Cookie":[]}}
{"level":"info","ts":1707319249.6368454,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"35794","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"Accept":["*/*"],"User-Agent":["ApacheBench/2.3"]}},"bytes_read":0,"user_id":"","duration":0.058600462,"size":27514,"status":200,"resp_headers":{"X-Powered-By":["PHP/8.3.2"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Wed, 07 Feb 2024 15:20:49 GMT"],"Pragma":["no-cache"],"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"]}}
{"level":"info","ts":1707319249.636907,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"35586","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"Accept":["*/*"],"User-Agent":["ApacheBench/2.3"]}},"bytes_read":0,"user_id":"","duration":0.059374452,"size":27514,"status":200,"resp_headers":{"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.2"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Wed, 07 Feb 2024 15:20:49 GMT"],"Pragma":["no-cache"],"Expires":["-1"]}}
{"level":"info","ts":1707319249.6369631,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"35564","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.059686996,"size":27514,"status":200,"resp_headers":{"X-Powered-By":["PHP/8.3.2"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Wed, 07 Feb 2024 15:20:49 GMT"],"Pragma":["no-cache"],"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"]}}
{"level":"info","ts":1707319249.6372929,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"35904","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.059141035,"size":27514,"status":200,"resp_headers":{"Cache-Control":["private, must-revalidate"],"Date":["Wed, 07 Feb 2024 15:20:49 GMT"],"Pragma":["no-cache"],"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.2"],"Content-Type":["text/html; charset=UTF-8"]}}
{"level":"info","ts":1707319249.638458,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"35632","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.060936682,"size":27514,"status":200,"resp_headers":{"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Wed, 07 Feb 2024 15:20:49 GMT"],"Pragma":["no-cache"],"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.2"]}}
{"level":"info","ts":1707319249.638476,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"35808","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.060681099,"size":27514,"status":200,"resp_headers":{"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.2"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Wed, 07 Feb 2024 15:20:49 GMT"],"Pragma":["no-cache"]}}
{"level":"info","ts":1707319249.6384945,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"35506","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.061327262,"size":27514,"status":200,"resp_headers":{"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Wed, 07 Feb 2024 15:20:49 GMT"],"Pragma":["no-cache"],"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.2"]}}
{"level":"info","ts":1707319249.6384957,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"35664","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.060114824,"size":27514,"status":200,"resp_headers":{"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Wed, 07 Feb 2024 15:20:49 GMT"],"Pragma":["no-cache"],"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.2"]}}
{"level":"info","ts":1707319249.6385448,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"35926","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.060798612,"size":27514,"status":200,"resp_headers":{"Pragma":["no-cache"],"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.2"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Wed, 07 Feb 2024 15:20:49 GMT"]}}
{"level":"info","ts":1707319249.6385489,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"35738","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.061030575,"size":27514,"status":200,"resp_headers":{"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.2"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Wed, 07 Feb 2024 15:20:49 GMT"],"Pragma":["no-cache"],"Expires":["-1"]}}
{"level":"info","ts":1707319249.6385581,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"35522","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.061386924,"size":27514,"status":200,"resp_headers":{"X-Powered-By":["PHP/8.3.2"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Wed, 07 Feb 2024 15:20:49 GMT"],"Pragma":["no-cache"],"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"]}}
{"level":"info","ts":1707319249.6385934,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"35740","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.061016102,"size":27514,"status":200,"resp_headers":{"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.2"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Wed, 07 Feb 2024 15:20:49 GMT"],"Pragma":["no-cache"]}}
{"level":"info","ts":1707319249.6385915,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"35646","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"Accept":["*/*"],"User-Agent":["ApacheBench/2.3"]}},"bytes_read":0,"user_id":"","duration":0.060946704,"size":27514,"status":200,"resp_headers":{"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.2"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Wed, 07 Feb 2024 15:20:49 GMT"],"Pragma":["no-cache"]}}
{"level":"info","ts":1707319249.6386025,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"35658","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.06131577,"size":27514,"status":200,"resp_headers":{"Date":["Wed, 07 Feb 2024 15:20:49 GMT"],"Pragma":["no-cache"],"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.2"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"]}}
{"level":"info","ts":1707319249.6387227,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"35494","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.061580674,"size":27514,"status":200,"resp_headers":{"X-Powered-By":["PHP/8.3.2"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Wed, 07 Feb 2024 15:20:49 GMT"],"Pragma":["no-cache"],"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"]}}
{"level":"info","ts":1707319249.6387908,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"35818","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"Accept":["*/*"],"User-Agent":["ApacheBench/2.3"]}},"bytes_read":0,"user_id":"","duration":0.059937917,"size":27514,"status":200,"resp_headers":{"Cache-Control":["private, must-revalidate"],"Date":["Wed, 07 Feb 2024 15:20:49 GMT"],"Pragma":["no-cache"],"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.2"],"Content-Type":["text/html; charset=UTF-8"]}}
{"level":"info","ts":1707319249.6389155,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"35696","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.060775779,"size":27514,"status":200,"resp_headers":{"Cache-Control":["private, must-revalidate"],"Date":["Wed, 07 Feb 2024 15:20:49 GMT"],"Pragma":["no-cache"],"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.2"],"Content-Type":["text/html; charset=UTF-8"]}}
{"level":"info","ts":1707319249.63896,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"35520","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.061784968,"size":27514,"status":200,"resp_headers":{"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.2"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Wed, 07 Feb 2024 15:20:49 GMT"],"Pragma":["no-cache"],"Expires":["-1"]}}
{"level":"info","ts":1707319249.6391969,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"35604","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"Accept":["*/*"],"User-Agent":["ApacheBench/2.3"]}},"bytes_read":0,"user_id":"","duration":0.06090024,"size":27514,"status":200,"resp_headers":{"Pragma":["no-cache"],"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.2"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Wed, 07 Feb 2024 15:20:49 GMT"]}}
{"level":"info","ts":1707319249.6392758,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"35496","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.062049696,"size":27514,"status":200,"resp_headers":{"Server":["Caddy"],"X-Powered-By":["PHP/8.3.2"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Wed, 07 Feb 2024 15:20:49 GMT"],"Pragma":["no-cache"],"Expires":["-1"],"Set-Cookie":[]}}
{"level":"info","ts":1707319249.6395855,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"35760","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.060607462,"size":27514,"status":200,"resp_headers":{"Date":["Wed, 07 Feb 2024 15:20:49 GMT"],"Pragma":["no-cache"],"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.2"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"]}}
{"level":"info","ts":1707319249.6396341,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"35754","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.060593694,"size":27514,"status":200,"resp_headers":{"Server":["Caddy"],"X-Powered-By":["PHP/8.3.2"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Wed, 07 Feb 2024 15:20:49 GMT"],"Pragma":["no-cache"],"Expires":["-1"],"Set-Cookie":[]}}
{"level":"info","ts":1707319249.6397827,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"35574","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.062558146,"size":27514,"status":200,"resp_headers":{"Cache-Control":["private, must-revalidate"],"Date":["Wed, 07 Feb 2024 15:20:49 GMT"],"Pragma":["no-cache"],"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.2"],"Content-Type":["text/html; charset=UTF-8"]}}
{"level":"info","ts":1707319249.6398168,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"35746","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.060757556,"size":27514,"status":200,"resp_headers":{"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Wed, 07 Feb 2024 15:20:49 GMT"],"Pragma":["no-cache"],"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.2"]}}
{"level":"info","ts":1707319249.6401708,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"35618","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.062114074,"size":27514,"status":200,"resp_headers":{"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.2"],"Content-Type":["text/html; charset=UTF-8"],"Cache-Control":["private, must-revalidate"],"Date":["Wed, 07 Feb 2024 15:20:49 GMT"],"Pragma":["no-cache"],"Expires":["-1"]}}
{"level":"info","ts":1707319249.6402214,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"127.0.0.1","remote_port":"35672","client_ip":"127.0.0.1","proto":"HTTP/1.0","method":"GET","host":"127.0.0.1:8000","uri":"/","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"bytes_read":0,"user_id":"","duration":0.061841638,"size":27514,"status":200,"resp_headers":{"Cache-Control":["private, must-revalidate"],"Date":["Wed, 07 Feb 2024 15:20:49 GMT"],"Pragma":["no-cache"],"Expires":["-1"],"Set-Cookie":[],"Server":["Caddy"],"X-Powered-By":["PHP/8.3.2"],"Content-Type":["text/html; charset=UTF-8"]}}

@nogamenofun98
Copy link

Hi @mo7zayed , sorry I didnt understand that log which part is showing the error? is it as long as it show got http.log.access.log then means got error?
i see the log there all status is 200, didnt see got restart octane server also

I also got tried run with high concurrency, got the same log as yours, but the ab command there showing all 1000 request is completed

@Orrison
Copy link

Orrison commented Feb 8, 2024

@nogamenofun98 I wonder if the log is also displaying what I am seeing.

Octane crashes using FrankenPHP under high load with no error message or anything. The process just stops.

I get this issue without even using stress test software. Just reloading the page over and over again eventually it happens.

@dunglas
Copy link
Contributor

dunglas commented Feb 8, 2024

Are you using Linux or Mac?

@mo7zayed
Copy link
Author

mo7zayed commented Mar 5, 2024

@dunglas it's crashing on Linux and when using laravel sail, Can you try with laravel sail since you are on mac?

@LauJosefsen
Copy link
Contributor

LauJosefsen commented Mar 5, 2024 •
edited

I cloned the repo and ran the ab command several times on Mac but got no crash. Does anyone have a way to reproduce? Is it a Linux-only bug?

I've only tested FrankenPHP on Linux (AMD64) in a docker swarm setup, would you be interested in a minimal docker-compose or swarm setup? If so I can try to throw something together, if I can still reproduce the issue.

@dunglas
Copy link
Contributor

dunglas commented Mar 5, 2024

I just tried with fresh installs of Sail (8.3 template) and of the official Docker image (https://laravel.com/docs/10.x/octane#frankenphp-via-docker), and no crash (Apple Silicon).

@LauJosefsen, a reproducer that crashes would be really helpful. I can get an AMD64 computer if necessary.

@binaryfire
Copy link

I cloned the reproduction repo and ran 3 consecutive tests on Ubuntu 22.04 (WSL2). No crashes. Results:

Run 1:
image

Run 2:
image

Run 3:
image

I'll spin up a VPS and re-run the tests but if it works on WSL2 I'm pretty sure it's going to work on the VPS too.

@binaryfire
Copy link

Ok that's interesting... It did crash on the test server:

image

@dunglas
Copy link
Contributor

dunglas commented Mar 6, 2024

@binaryfire the process stopped? Could you give me the details of the VPS you used so I can try to reproduce on the same environnement?

@binaryfire
Copy link

binaryfire commented Mar 6, 2024 •
edited

@dunglas Yeah, it stopped. Sometimes after 50-60 requests, sometimes 100-200. Do you want me to set up a test VPS for you and give you access?

@dunglas
Copy link
Contributor

dunglas commented Mar 6, 2024

@binaryfire that would be awesome if possible (a root access or at least a GDB installation will likely be necessary to debug). Thank you very much!

@binaryfire
Copy link

@dunglas No worries! Will do it later tonight and DM you the details on X

@LauJosefsen
Copy link
Contributor

LauJosefsen commented Mar 6, 2024 •
edited

@LauJosefsen, a reproducer that crashes would be really helpful. I can get an AMD64 computer if necessary.

I have attached a Dockerfile that inits a laravel project, and a docker compose to start it. I actually get an immediate segfault with this setup. (Exit 139) Running on popos with kernel version Linux 6.6.10-76060610-generic x86_64 and docker version 25.0.3.

FROM composer:2.7.1 AS composer

FROM php:8.3.3-apache

ENV COMPOSER_ALLOW_SUPERUSER 1

# Install git
RUN apt-get update && apt-get install -y git libzip-dev \
    && apt-get clean

# Install ZIP required for newing a Laravel project, and pcntl for Octane.
RUN docker-php-ext-install zip pcntl

# Composer installation
ENV COMPOSER_HOME /tmp/
COPY --link --from=composer /usr/bin/composer /usr/bin/composer

# Make new laravel app
RUN composer create-project laravel/laravel example-app

WORKDIR /var/www/html/example-app

RUN composer install

RUN composer require laravel/octane

# install frankenphp
RUN php artisan octane:install --server=frankenphp

CMD ["php", "artisan", "octane:start", "--server=frankenphp"]
services:
  laravel:
    build:
      context: .
      dockerfile: Dockerfile
    ports:
      - "8000:8000"

Run it with

docker compose up --build

I get the output

 ✔ Container frankenphp-laravel-1  Created                                                                                                                                                                                                                                                                                                                                                                                    0.0s 
Attaching to laravel-1
laravel-1  | 
laravel-1  |    INFO  Server running…
laravel-1  | 
laravel-1  |   Local: https://127.0.0.1:8000 
laravel-1  | 
laravel-1  |   Press Ctrl+C to stop the server
laravel-1  | 
laravel-1 exited with code 139

@binaryfire
Copy link

@dunglas Have sent you a DM on X. VPS which reproduces the problem is ready to go.

@dunglas dunglas mentioned this issue Mar 8, 2024
Merged
@sneycampos
Copy link

Could be a problem in Octane? i've faced a problem something like:
call a endpoint with sleep(30) multiple times (using insomnia plugin to parallel calls or chrome tab groups)
Octane stopped to respond for a few seconds and crashed (supervisord spinned up again)

Think is related to worker numbers, if you get more requests and there aren't workers available to process the request it "stops"

Tried with 10 workers and crashed
Tried with 50 workers and received 100% of requests

@binaryfire could you increase your octane workers and run the tests again? something like 20 workers? It's recommended 1 worker per core but...

@dunglas
Copy link
Contributor

dunglas commented Mar 8, 2024

Thanks to the help of @binaryfire, I managed to reproduce on a Linux box.

This is a problem with the OpenSSL PHP extension, which doesn't look directly to FrankenPHP. As a workaround, using the Docker image instead of the static build seems to fix the issue.

Here is the stack trace:

Stack trace 
#1  0x0000783330654ec3 in __libc_free (p=0x7832da600cb0) at src/malloc/mallocng/free.c:105
#2  0x000078332fef89f0 in EVP_CIPHER_CTX_reset ()
#3  0x000078332f15bf83 in php_openssl_encrypt (data=0x7832d67946a8 "cdcfc94a44f1372ecc088f6e0abca9d4c1416db0|XFaOVGRiKdwkZpamJ3fb2fXpv4vvguazIfVNxK8R", data_len=81, method=0x7832d7995220 "aes-256-cbc", method_len=11,
    password=0x7832d67acd88 "\036\216/a\363-\257e\332Wu㖂&\033%\341\307\036O\243hOX(\257\204\346j\334\t", password_len=32, options=0, iv=0x7832d6686558 "\\\226\024Y\204:#b\276+1b\332\034%\225", iv_len=16, tag=0x7832d7818a40, tag_len=16,
    aad=0x783330d21ef5 "", aad_len=0) at /go/src/app/dist/static-php-cli/source/php-src/ext/openssl/openssl.c:7700
#4  0x000078332f15c126 in zif_openssl_encrypt (execute_data=0x7832d78189a0, return_value=0x7832d7818970) at /go/src/app/dist/static-php-cli/source/php-src/ext/openssl/openssl.c:7719
#5  0x000078332ef7351f in ZEND_DO_ICALL_SPEC_RETVAL_USED_HANDLER () at /go/src/app/dist/static-php-cli/source/php-src/Zend/zend_vm_execute.h:1337
#6  execute_ex (ex=0x7832d78171d0) at /go/src/app/dist/static-php-cli/source/php-src/Zend/zend_vm_execute.h:57216
#7  0x000078332edcfec2 in zend_call_function (fci=0x7832dafe9720, fci_cache=0x7832dafe96f0) at /go/src/app/dist/static-php-cli/source/php-src/Zend/zend_execute_API.c:957
#8  0x000078332eca9591 in zif_frankenphp_handle_request (execute_data=<optimized out>, return_value=0x7832d7817140) at frankenphp.c:371
#9  0x000078332ef7351f in ZEND_DO_ICALL_SPEC_RETVAL_USED_HANDLER () at /go/src/app/dist/static-php-cli/source/php-src/Zend/zend_vm_execute.h:1337
#10 execute_ex (ex=0x7832d7817020) at /go/src/app/dist/static-php-cli/source/php-src/Zend/zend_vm_execute.h:57216
#11 0x000078332ef908a7 in zend_execute (op_array=0x7832d7866000, return_value=0x0) at /go/src/app/dist/static-php-cli/source/php-src/Zend/zend_vm_execute.h:61604
#12 0x000078332edfca5c in zend_execute_scripts (type=8, retval=0x0, file_count=3) at /go/src/app/dist/static-php-cli/source/php-src/Zend/zend.c:1881
#13 0x000078332ed3d05a in php_execute_script (primary_file=0x7832dafef660) at /go/src/app/dist/static-php-cli/source/php-src/main/main.c:2523
#14 0x000078332ecaa4f1 in frankenphp_execute_script (file_name=0x7832d946ab00 "4b48bc1af71891ab467ffde5c30d1b724928ab8c9dee168d597ce7f9e1dc9498") at frankenphp.c:825
#15 0x000078332eca7c37 in _cgo_d49d0ae4a108_Cfunc_frankenphp_execute_script (v=0xc000810dd8) at /tmp/go-build/cgo-gcc-prolog:55
#16 0x000078332d966a01 in runtime.asmcgocall () at /usr/local/go/src/runtime/asm_amd64.s:918
#17 0x000000c0008016c0 in ?? ()
#18 0x00007832dafef7d0 in ?? ()
#19 0x00007832dafef834 in ?? ()
#20 0x0000000000000000 in ?? ()

@binaryfire
Copy link

@dunglas Yep, I'm seeing the same thing. Here's the stack trace from one of my bare metal servers:

Thread 15 "thpool-0" received signal SIGSEGV, Segmentation fault.
[Switching to LWP 2433692]
get_meta (p=p@entry=0x7f41742bbcb0 "HTTP/1.0") at src/malloc/mallocng/meta.h:141
141     src/malloc/mallocng/meta.h: No such file or directory.
(gdb) bt
#0  get_meta (p=p@entry=0x7f41742bbcb0 "HTTP/1.0") at src/malloc/mallocng/meta.h:141
#1  0x00007f41ca5b7ec3 in __libc_free (p=0x7f41742bbcb0) at src/malloc/mallocng/free.c:105
#2  0x00007f41c9e5b9f0 in EVP_CIPHER_CTX_reset ()
#3  0x00007f41c90bef83 in php_openssl_encrypt (data=0x7f41749ec478 "392bde1585ab0bd096105de5526b9a82c44ac7b1|WsQYiV8jNxq8upssNbiRPvSaWTTu5OWmoi2F9zR7", data_len=81, method=0x7f4174804f40 "aes-256-cbc", method_len=11,
    password=0x7f4172fc3d38 "#\031\067\352\032\030\343\224\355\263{\227\066gƱq\202\207\231_2pަ\005v\231\306\b\\(", password_len=32, options=0, iv=0x7f41749951c8 "\323{\217\330\064fUr\220\260J\021J\021E\222", iv_len=16,
    tag=0x7f4174817a40, tag_len=16, aad=0x7f41cac84ef5 "", aad_len=0) at /go/src/app/dist/static-php-cli/source/php-src/ext/openssl/openssl.c:7700
#4  0x00007f41c90bf126 in zif_openssl_encrypt (execute_data=0x7f41748179a0, return_value=0x7f4174817970) at /go/src/app/dist/static-php-cli/source/php-src/ext/openssl/openssl.c:7719
#5  0x00007f41c8ed651f in ZEND_DO_ICALL_SPEC_RETVAL_USED_HANDLER () at /go/src/app/dist/static-php-cli/source/php-src/Zend/zend_vm_execute.h:1337
#6  execute_ex (ex=0x7f41748161d0) at /go/src/app/dist/static-php-cli/source/php-src/Zend/zend_vm_execute.h:57216
#7  0x00007f41c8d32ec2 in zend_call_function (fci=0x7f417d4e8720, fci_cache=0x7f417d4e86f0) at /go/src/app/dist/static-php-cli/source/php-src/Zend/zend_execute_API.c:957
#8  0x00007f41c8c0c591 in zif_frankenphp_handle_request (execute_data=<optimized out>, return_value=0x7f4174816140) at frankenphp.c:371
#9  0x00007f41c8ed651f in ZEND_DO_ICALL_SPEC_RETVAL_USED_HANDLER () at /go/src/app/dist/static-php-cli/source/php-src/Zend/zend_vm_execute.h:1337
#10 execute_ex (ex=0x7f4174816020) at /go/src/app/dist/static-php-cli/source/php-src/Zend/zend_vm_execute.h:57216
#11 0x00007f41c8ef38a7 in zend_execute (op_array=0x7f417486b000, return_value=0x0) at /go/src/app/dist/static-php-cli/source/php-src/Zend/zend_vm_execute.h:61604
#12 0x00007f41c8d5fa5c in zend_execute_scripts (type=8, retval=0x0, file_count=3) at /go/src/app/dist/static-php-cli/source/php-src/Zend/zend.c:1881
#13 0x00007f41c8ca005a in php_execute_script (primary_file=0x7f417d4ee660) at /go/src/app/dist/static-php-cli/source/php-src/main/main.c:2523
#14 0x00007f41c8c0d4f1 in frankenphp_execute_script (file_name=0x7f41c7161f90 "\001") at frankenphp.c:825
#15 0x00007f41c8c0ac37 in _cgo_d49d0ae4a108_Cfunc_frankenphp_execute_script (v=0xc000807dd8) at /tmp/go-build/cgo-gcc-prolog:55
#16 0x00007f41c78c9a01 in runtime.asmcgocall () at /usr/local/go/src/runtime/asm_amd64.s:918
#17 0x000000c000603880 in ?? ()
#18 0x00007f417d4ee7d0 in ?? ()
#19 0x00007f417d4ee834 in ?? ()
#20 0x0000000000000000 in ?? ()
(gdb)

@binaryfire
Copy link

@sneycampos Worker count doesn't make a difference for me. I'm able to reproduce the problem with 1, 10 and 20 workers.

@dunglas dunglas mentioned this issue Mar 9, 2024
Open
@crrodriguez
Copy link

SO what's going on in frame 2 and 3.. can someone share a complete trace ?
Looks like EVP_CIPHER_CTX_reset(cipher_ctx); is stepping into 🐶 💩 or almost certainly trying to free willy but is free already.

@dunglas
Copy link
Contributor

dunglas commented Mar 11, 2024

@crrodriguez the stack trace looks complete, it looks like Musl's hardened allocator crashes when calling EVP_CIPHER_CTX_reset(), this smells like a double-free issue or something like that.

@dunglas
Copy link
Contributor

dunglas commented Mar 12, 2024

The bug is being tracked upstream: php/php-src#13648
It seems to only affect projects using a recent version of OpenSSL with a recent version of Musl (it's the case of the static binary of FrankenPHP).

In the meantime, a workaround is to use the Docker image instead of the static binary, or to compile a dynamically linked build of FrankenPHP.

As this bug isn't in Octane (nor in FrankenPHP directly), I think that this issue can be closed or locked.

@driesvints
Copy link
Member

Thanks @dunglas

@ia-kaishen
Copy link

anyone managed to load test with docker / php built from source?
i tried php built from source but still crashing under high load

@sneycampos
Copy link

anyone managed to load test with docker / php built from source?

i tried php built from source but still crashing under high load

Maybe is related to php/php-src#13648

@dunglas
Copy link
Contributor

dunglas commented Mar 20, 2024

@sneycampos yes it is!
@ia-kaishen do you have a stack trace? I didn't manage to reproduce the problem with glibc, I have the crash only with musl+mallocng and musl+mimalloc. If it breaks also with glibc, this would allow @bukka and I to eliminate the allocator bug hypothesis and indicate a bug in PHP or OpenSSL.

@sneycampos
Copy link

sneycampos commented Mar 20, 2024 •
edited

Complementing @dunglas, if you don't have time, tell me how did you run your tests and i can try to get the stack trace. I have Ubuntu amd64 and arm64 available. @dunglas if you need a vps amd64 or arm64 tell me and i can spin up for you in hetzner in my account.

@dunglas
Copy link
Contributor

dunglas commented Mar 20, 2024

For the record, I created a guide explaining how to gather a stack trace with Octane and similar solutions: https://frankenphp.dev/docs/contributing/#debugging-segmentation-faults-with-static-builds
It uses static builds, but once you have a dynamic build (https://frankenphp.dev/docs/compile/), the process is the same.

@smortexa smortexa mentioned this issue Apr 9, 2024
Merged
smortexa added a commit to exaco/laravel-octane-dockerfile that referenced this issue Apr 9, 2024
@smortexa
Overhaul (#69)
1f9cd51 
Fixes #64
Prevents laravel/octane#791
Potentially fix for #66
@AlliBalliBaba AlliBalliBaba mentioned this issue May 23, 2024
Merged
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
needs more info
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests