Laravel Octane with FrankenPHP doesn't start when xdebug installed

philbates35 commented 9 months ago

What happened?

As requested in https://github.com/laravel/octane/issues/829#issuecomment-1931959730, I'm opening the issue here.

Octane Version

2.3.1

Laravel Version

10.42.0

PHP Version

8.3

What server type are you using?

FrankenPHP

Server Version

1.0

Database Driver & Version

No response

Description

Octane is immediately being killed when using the FrankenPHP Docker image with xdebug installed. When xdebug isn't installed, everything works fine.

Probably one for @dunglas.

Steps To Reproduce

After cloning this repo (which is basically just a fresh Laravel app) and cp .env.example .env, make the following simple change to Dockerfile:

FROM dunglas/frankenphp:1.0-php8.3

RUN install-php-extensions \
    @composer \
-   pcntl;
+   pcntl \
+   xdebug;

# https://getcomposer.org/doc/03-cli.md#composer-allow-superuser
ENV COMPOSER_ALLOW_SUPERUSER=1

RUN cp $PHP_INI_DIR/php.ini-development $PHP_INI_DIR/php.ini; \
    sed -i 's/variables_order = "GPCS"/variables_order = "EGPCS"/' $PHP_INI_DIR/php.ini;

ENTRYPOINT ["/bin/sh", "-c" , "composer install && php artisan octane:start --server=frankenphp --host=localhost --port=443 --admin-port=2019 --https"]

Then on the terminal run:

docker-compose up --build
...
php_1  | 91 packages you are using are looking for funding.
php_1  | Use the `composer fund` command to find out more!
php_1  | 
php_1  |    INFO  Server running…
php_1  |   Local: https://localhost:443 
php_1  |   Press Ctrl+C to stop the server
php_1  | 
php_1  | 
php_1  |    WARN  automatic HTTP->HTTPS redirects are disabled
php_1  |    WARN  installing root certificate (you might be prompted for password)
php_1  |    WARN  stapling OCSP
laravel-starter_php_1 exited with code 139

When we don't install xdebug in the Dockerfile though (as is the case on the linked repo), Octane runs indefinitely as expected.

There's nothing in laravel.log so I don't even know where to start debugging this, let me know what you need and I'll be more than happy to help!

Build Type

Docker (Debian Bookworm)

Worker Mode

Yes

Operating System

GNU/Linux

CPU Architecture

x86_64

Relevant log output

No response

Renrhaf commented 9 months ago

Hi, I am facing the same issue

jameshulse commented 8 months ago

It could be worth enabling the xdebug log inside your container and seeing if it shows anything useful.

philbates35 commented 8 months ago

@jameshulse @dunglas

FROM dunglas/frankenphp:1.0-php8.3

RUN install-php-extensions \
    @composer \
-   pcntl;
+   pcntl \
+   xdebug;

# https://getcomposer.org/doc/03-cli.md#composer-allow-superuser
ENV COMPOSER_ALLOW_SUPERUSER=1

RUN cp $PHP_INI_DIR/php.ini-development $PHP_INI_DIR/php.ini; \
-    sed -i 's/variables_order = "GPCS"/variables_order = "EGPCS"/' $PHP_INI_DIR/php.ini;
+    sed -i 's/variables_order = "GPCS"/variables_order = "EGPCS"/' $PHP_INI_DIR/php.ini; \
+    echo "xdebug.log = /app/xdebug.log" >> $PHP_INI_DIR/php.ini;

ENTRYPOINT ["/bin/sh", "-c" , "composer install && php artisan octane:start --server=frankenphp --host=localhost --port=443 --admin-port=2019 --https"]

Then running docker-compose up --build results in the following output in xdebug.log, doesn't seem particularly useful.

[140574732696256] Log opened at 2024-02-15 12:59:33.383263
[140574732696256] [Config] INFO: Control socket set up succesfully: '@xdebug-ctrl.140574732696256'
[139953736878784] Log opened at 2024-02-15 12:59:35.351162
[139953736878784] [Config] INFO: Control socket set up succesfully: '@xdebug-ctrl.139953736878784'
[139953736878784] Log closed at 2024-02-15 12:59:35.505509

[140574732696256] Log closed at 2024-02-15 12:59:35.519468

[140415846279872] Log opened at 2024-02-15 12:59:35.536260
[140415846279872] [Config] INFO: Control socket set up succesfully: '@xdebug-ctrl.140415846279872'
[139826684757696] Log opened at 2024-02-15 12:59:35.800862
[139826684757696] [Config] INFO: Control socket set up succesfully: '@xdebug-ctrl.139826684757696'
[139826529568448] Log opened at 2024-02-15 12:59:35.801303
[139826529568448] [Config] INFO: Control socket set up succesfully: '@xdebug-ctrl.139826529568448'
[139826674271936] Log opened at 2024-02-15 12:59:35.801666
[139826674271936] [Config] INFO: Control socket set up succesfully: '@xdebug-ctrl.139826674271936'
[139826550539968] Log opened at 2024-02-15 12:59:35.802157
[139826550539968] [Config] INFO: Control socket set up succesfully: '@xdebug-ctrl.139826550539968'
[139826384864960] Log opened at 2024-02-15 12:59:35.802778
[139826384864960] [Config] INFO: Control socket set up succesfully: '@xdebug-ctrl.139826384864960'
[139826405836480] Log opened at 2024-02-15 12:59:35.803353
[139826405836480] [Config] INFO: Control socket set up succesfully: '@xdebug-ctrl.139826405836480'
[139826663786176] Log opened at 2024-02-15 12:59:35.803974
[139826663786176] [Config] INFO: Control socket set up succesfully: '@xdebug-ctrl.139826663786176'
[139826395350720] Log opened at 2024-02-15 12:59:35.806661
[139826395350720] [Config] INFO: Control socket set up succesfully: '@xdebug-ctrl.139826395350720'
[139826653300416] Log opened at 2024-02-15 12:59:35.814005
[139826653300416] [Config] INFO: Control socket set up succesfully: '@xdebug-ctrl.139826653300416'
[139826498111168] Log opened at 2024-02-15 12:59:35.815169
[139826498111168] [Config] INFO: Control socket set up succesfully: '@xdebug-ctrl.139826498111168'
[139826632328896] Log opened at 2024-02-15 12:59:35.815730
[139826632328896] [Config] INFO: Control socket set up succesfully: '@xdebug-ctrl.139826632328896'
[139826508596928] Log opened at 2024-02-15 12:59:35.816353
[139826508596928] [Config] INFO: Control socket set up succesfully: '@xdebug-ctrl.139826508596928'
[139826540054208] Log opened at 2024-02-15 12:59:35.820545
[139826540054208] [Config] INFO: Control socket set up succesfully: '@xdebug-ctrl.139826540054208'
[139826374379200] Log opened at 2024-02-15 12:59:35.816816
[139826374379200] [Config] INFO: Control socket set up succesfully: '@xdebug-ctrl.139826374379200'
[139826519082688] Log opened at 2024-02-15 12:59:35.838275
[139826519082688] [Config] INFO: Control socket set up succesfully: '@xdebug-ctrl.139826519082688'
[139826642814656] Log opened at 2024-02-15 12:59:35.840468
[139826642814656] [Config] INFO: Control socket set up succesfully: '@xdebug-ctrl.139826642814656'
[140415846279872] Log closed at 2024-02-15 12:59:37.283565

EDIT, I also did similar by setting error_log = /app/error.log in php.ini in the Dockerfile, but when Octane is killed there's nothing in error.log so it doesn't seem like its a PHP error (error_reporting is set to E_ALL).

dunglas commented 8 months ago

Next step is to run FrankenPHP with GDB to get a stack trace.

philbates35 commented 8 months ago

@dunglas based on the simple Dockerfile I posted in the previous comment, could you let me know how to do that? Apologies I'm not familar with GDB.

dunglas commented 8 months ago

The easiest way is to use the dev Dockerfile we provide: https://github.com/dunglas/frankenphp/blob/main/CONTRIBUTING.md

It's not very easy but I'll take a look when I'll be back from vacation if still needed.

philbates35 commented 8 months ago

Thanks @dunglas I may just leave it for you :+1: let me know if you need anything else from me to help out!

MeCapron commented 8 months ago

Can also confirm this issue that may not be only related to Laravel.

I can reproduce it in a clean Docker with API Platform. Doing two requests at the very same time produces the same result whenever xdebug is enabled.

I'm using Symfony docker : https://github.com/dunglas/symfony-docker/blob/main/Dockerfile without any tweak.

Didn't try on a latest version, still relying on 1.0 of the frankenphp image.

Restarting the container by passing xdebug to off "fixes" the problem

Please let me now if you want a repository to reproduce the issue

dunglas commented 8 months ago

This may be an issue with Xebug and ZTS builds. @derickr, maybe you have an idea of what's going on?

derickr commented 8 months ago

I can't really say much without an actual cause and GDB trace here. Does it not start? Does it crash? There is simply not enough information here.

However, there are these bugs, that could be related (but still can't reproduce in a small example):

JanMikes commented 8 months ago

Hi, having same issue on arm (M1 mac), frankenphp (both worker, no worker) + xdebug (symfony app). CPU usage instantly after 1st request goes to 100% usage for all cores.

Is there any debug info i could provide to help identify the issue?

dunglas commented 8 months ago

@JanMikes a backtrace gathered with GDB (or LLDB if you are on Mac and not using Docker) when the bug occurs would be awesome. A minimal reproducer that we can use to track the issue would also help a lot.

DennisdeBest commented 7 months ago

I have the same problem. As soon as a page gets loaded all the cpu cores get stuck at 100%.

I use the dunglas/frankenphp:1.1.0-alpine image.

When commenting out

RUN set -eux; \
    install-php-extensions \
        xdebug \
    ;

And rebuilding everything works fine.

This is the php dev config

xdebug.client_host=host.docker.internal
xdebug.mode=develop
xdebug.client_port=9003
xdebug.discover_client_host=1
xdebug.max_nesting_level=256
xdebug.start_with_request='trigger'
xdebug.idekey=PHPSTORM
xdebug.log_level=0
xdebug.use_compression=true

memory_limit=2G

I set up a gdb with logging for the initial page load where the CPU spikes. Having never used gdb before I am not sure if this is helpful or if more is needed.

Already logging to gdb.txt.

Thread 35 (LWP 91 "frankenphp"):
#0  0x00000000004795e3 in ?? ()
#1  0x000000000043c750 in ?? ()
#2  0x000000c000101548 in ?? ()
#3  0x0000000000000080 in ?? ()
#4  0x0000000000000000 in ?? ()

Thread 34 (LWP 90 "frankenphp"):
#0  0x00000000004795e3 in ?? ()
#1  0x000000000043c750 in ?? ()
#2  0x000000c000236948 in ?? ()
#3  0x0000000000000080 in ?? ()
#4  0x0000000000000000 in ?? ()

Thread 33 (LWP 89 "frankenphp"):
#0  0x00000000004795e3 in ?? ()
#1  0x000000000043c750 in ?? ()
#2  0x000000c000518d48 in ?? ()
#3  0x0000000000000080 in ?? ()
#4  0x0000000000000000 in ?? ()

Thread 32 (LWP 88 "frankenphp"):
#0  0x00000000004795e3 in ?? ()
#1  0x000000000043c750 in ?? ()
#2  0x000000c000600948 in ?? ()
#3  0x0000000000000080 in ?? ()
#4  0x0000000000000000 in ?? ()

Thread 31 (LWP 87 "thpool-15"):
#0  __cp_end () at src/thread/x86_64/syscall_cp.s:29
#1  0x000079ef4bb3f4fc in __syscall_cp_c (nr=202, u=<optimized out>, v=<optimized out>, w=<optimized out>, x=<optimized out>, y=<optimized out>, z=0) at src/thread/pthread_cancel.c:33
#2  0x000079ef4bb3ea2e in __futex4_cp (to=<optimized out>, val=2, op=128, addr=0x79eeedddb594) at src/thread/__timedwait.c:24
#3  __timedwait_cp (addr=addr@entry=0x79eeedddb594, val=val@entry=2, clk=clk@entry=0, at=at@entry=0x0, priv=128, priv@entry=1) at src/thread/__timedwait.c:52
#4  0x000079ef4bb3f894 in __pthread_cond_timedwait (c=0x79eefe6c21e8, m=0x79eefe6c21c0, ts=0x0) at src/thread/pthread_cond_timedwait.c:100
#5  0x0000000001792c3b in ?? ()
#6  0x000079ef4bb4022e in start (p=0x79eeedddb6f0) at src/thread/pthread_create.c:207
#7  0x000079ef4bb4282f in __clone () at src/thread/x86_64/clone.s:22
Backtrace stopped: frame did not save the PC

Thread 30 (LWP 86 "thpool-14"):
#0  __cp_end () at src/thread/x86_64/syscall_cp.s:29
#1  0x000079ef4bb3f4fc in __syscall_cp_c (nr=202, u=<optimized out>, v=<optimized out>, w=<optimized out>, x=<optimized out>, y=<optimized out>, z=0) at src/thread/pthread_cancel.c:33
#2  0x000079ef4bb3ea2e in __futex4_cp (to=<optimized out>, val=2, op=128, addr=0x79eeede5e594) at src/thread/__timedwait.c:24
#3  __timedwait_cp (addr=addr@entry=0x79eeede5e594, val=val@entry=2, clk=clk@entry=0, at=at@entry=0x0, priv=128, priv@entry=1) at src/thread/__timedwait.c:52
#4  0x000079ef4bb3f894 in __pthread_cond_timedwait (c=0x79eefe6c21e8, m=0x79eefe6c21c0, ts=0x0) at src/thread/pthread_cond_timedwait.c:100
#5  0x0000000001792c3b in ?? ()
#6  0x000079ef4bb4022e in start (p=0x79eeede5e6f0) at src/thread/pthread_create.c:207
#7  0x000079ef4bb4282f in __clone () at src/thread/x86_64/clone.s:22
Backtrace stopped: frame did not save the PC

Thread 29 (LWP 85 "thpool-13"):
#0  __cp_end () at src/thread/x86_64/syscall_cp.s:29
#1  0x000079ef4bb3f4fc in __syscall_cp_c (nr=202, u=<optimized out>, v=<optimized out>, w=<optimized out>, x=<optimized out>, y=<optimized out>, z=0) at src/thread/pthread_cancel.c:33
#2  0x000079ef4bb3ea2e in __futex4_cp (to=<optimized out>, val=2, op=128, addr=0x79eeedee1594) at src/thread/__timedwait.c:24
#3  __timedwait_cp (addr=addr@entry=0x79eeedee1594, val=val@entry=2, clk=clk@entry=0, at=at@entry=0x0, priv=128, priv@entry=1) at src/thread/__timedwait.c:52
#4  0x000079ef4bb3f894 in __pthread_cond_timedwait (c=0x79eefe6c21e8, m=0x79eefe6c21c0, ts=0x0) at src/thread/pthread_cond_timedwait.c:100
#5  0x0000000001792c3b in ?? ()
#6  0x000079ef4bb4022e in start (p=0x79eeedee16f0) at src/thread/pthread_create.c:207
#7  0x000079ef4bb4282f in __clone () at src/thread/x86_64/clone.s:22
Backtrace stopped: frame did not save the PC

Thread 28 (LWP 84 "thpool-12"):
#0  __cp_end () at src/thread/x86_64/syscall_cp.s:29
#1  0x000079ef4bb3f4fc in __syscall_cp_c (nr=202, u=<optimized out>, v=<optimized out>, w=<optimized out>, x=<optimized out>, y=<optimized out>, z=0) at src/thread/pthread_cancel.c:33
#2  0x000079ef4bb3ea2e in __futex4_cp (to=<optimized out>, val=2, op=128, addr=0x79eeedf64594) at src/thread/__timedwait.c:24
#3  __timedwait_cp (addr=addr@entry=0x79eeedf64594, val=val@entry=2, clk=clk@entry=0, at=at@entry=0x0, priv=128, priv@entry=1) at src/thread/__timedwait.c:52
#4  0x000079ef4bb3f894 in __pthread_cond_timedwait (c=0x79eefe6c21e8, m=0x79eefe6c21c0, ts=0x0) at src/thread/pthread_cond_timedwait.c:100
#5  0x0000000001792c3b in ?? ()
#6  0x000079ef4bb4022e in start (p=0x79eeedf646f0) at src/thread/pthread_create.c:207
#7  0x000079ef4bb4282f in __clone () at src/thread/x86_64/clone.s:22
Backtrace stopped: frame did not save the PC

Thread 27 (LWP 83 "thpool-11"):
#0  __cp_end () at src/thread/x86_64/syscall_cp.s:29
#1  0x000079ef4bb3f4fc in __syscall_cp_c (nr=202, u=<optimized out>, v=<optimized out>, w=<optimized out>, x=<optimized out>, y=<optimized out>, z=0) at src/thread/pthread_cancel.c:33
#2  0x000079ef4bb3ea2e in __futex4_cp (to=<optimized out>, val=2, op=128, addr=0x79eeedfe7594) at src/thread/__timedwait.c:24
#3  __timedwait_cp (addr=addr@entry=0x79eeedfe7594, val=val@entry=2, clk=clk@entry=0, at=at@entry=0x0, priv=128, priv@entry=1) at src/thread/__timedwait.c:52
#4  0x000079ef4bb3f894 in __pthread_cond_timedwait (c=0x79eefe6c21e8, m=0x79eefe6c21c0, ts=0x0) at src/thread/pthread_cond_timedwait.c:100
#5  0x0000000001792c3b in ?? ()
#6  0x000079ef4bb4022e in start (p=0x79eeedfe76f0) at src/thread/pthread_create.c:207
#7  0x000079ef4bb4282f in __clone () at src/thread/x86_64/clone.s:22
Backtrace stopped: frame did not save the PC

Thread 26 (LWP 82 "thpool-10"):
#0  __cp_end () at src/thread/x86_64/syscall_cp.s:29
#1  0x000079ef4bb3f4fc in __syscall_cp_c (nr=202, u=<optimized out>, v=<optimized out>, w=<optimized out>, x=<optimized out>, y=<optimized out>, z=0) at src/thread/pthread_cancel.c:33
#2  0x000079ef4bb3ea2e in __futex4_cp (to=<optimized out>, val=2, op=128, addr=0x79eeee06a594) at src/thread/__timedwait.c:24
#3  __timedwait_cp (addr=addr@entry=0x79eeee06a594, val=val@entry=2, clk=clk@entry=0, at=at@entry=0x0, priv=128, priv@entry=1) at src/thread/__timedwait.c:52
#4  0x000079ef4bb3f894 in __pthread_cond_timedwait (c=0x79eefe6c21e8, m=0x79eefe6c21c0, ts=0x0) at src/thread/pthread_cond_timedwait.c:100
#5  0x0000000001792c3b in ?? ()
#6  0x000079ef4bb4022e in start (p=0x79eeee06a6f0) at src/thread/pthread_create.c:207
#7  0x000079ef4bb4282f in __clone () at src/thread/x86_64/clone.s:22
Backtrace stopped: frame did not save the PC

Thread 25 (LWP 81 "thpool-9"):
#0  __cp_end () at src/thread/x86_64/syscall_cp.s:29
#1  0x000079ef4bb3f4fc in __syscall_cp_c (nr=202, u=<optimized out>, v=<optimized out>, w=<optimized out>, x=<optimized out>, y=<optimized out>, z=0) at src/thread/pthread_cancel.c:33
#2  0x000079ef4bb3ea2e in __futex4_cp (to=<optimized out>, val=2, op=128, addr=0x79eeee0ed594) at src/thread/__timedwait.c:24
#3  __timedwait_cp (addr=addr@entry=0x79eeee0ed594, val=val@entry=2, clk=clk@entry=0, at=at@entry=0x0, priv=128, priv@entry=1) at src/thread/__timedwait.c:52
#4  0x000079ef4bb3f894 in __pthread_cond_timedwait (c=0x79eefe6c21e8, m=0x79eefe6c21c0, ts=0x0) at src/thread/pthread_cond_timedwait.c:100
#5  0x0000000001792c3b in ?? ()
#6  0x000079ef4bb4022e in start (p=0x79eeee0ed6f0) at src/thread/pthread_create.c:207
#7  0x000079ef4bb4282f in __clone () at src/thread/x86_64/clone.s:22
Backtrace stopped: frame did not save the PC

Thread 24 (LWP 80 "thpool-8"):
#0  __cp_end () at src/thread/x86_64/syscall_cp.s:29
#1  0x000079ef4bb3f4fc in __syscall_cp_c (nr=202, u=<optimized out>, v=<optimized out>, w=<optimized out>, x=<optimized out>, y=<optimized out>, z=0) at src/thread/pthread_cancel.c:33
#2  0x000079ef4bb3ea2e in __futex4_cp (to=<optimized out>, val=2, op=128, addr=0x79eeee170594) at src/thread/__timedwait.c:24
#3  __timedwait_cp (addr=addr@entry=0x79eeee170594, val=val@entry=2, clk=clk@entry=0, at=at@entry=0x0, priv=128, priv@entry=1) at src/thread/__timedwait.c:52
#4  0x000079ef4bb3f894 in __pthread_cond_timedwait (c=0x79eefe6c21e8, m=0x79eefe6c21c0, ts=0x0) at src/thread/pthread_cond_timedwait.c:100
#5  0x0000000001792c3b in ?? ()
#6  0x000079ef4bb4022e in start (p=0x79eeee1706f0) at src/thread/pthread_create.c:207
#7  0x000079ef4bb4282f in __clone () at src/thread/x86_64/clone.s:22
Backtrace stopped: frame did not save the PC

Thread 23 (LWP 79 "thpool-7"):
#0  __cp_end () at src/thread/x86_64/syscall_cp.s:29
#1  0x000079ef4bb3f4fc in __syscall_cp_c (nr=202, u=<optimized out>, v=<optimized out>, w=<optimized out>, x=<optimized out>, y=<optimized out>, z=0) at src/thread/pthread_cancel.c:33
#2  0x000079ef4bb3ea2e in __futex4_cp (to=<optimized out>, val=2, op=128, addr=0x79eeee1f3594) at src/thread/__timedwait.c:24
#3  __timedwait_cp (addr=addr@entry=0x79eeee1f3594, val=val@entry=2, clk=clk@entry=0, at=at@entry=0x0, priv=128, priv@entry=1) at src/thread/__timedwait.c:52
#4  0x000079ef4bb3f894 in __pthread_cond_timedwait (c=0x79eefe6c21e8, m=0x79eefe6c21c0, ts=0x0) at src/thread/pthread_cond_timedwait.c:100
#5  0x0000000001792c3b in ?? ()
#6  0x000079ef4bb4022e in start (p=0x79eeee1f36f0) at src/thread/pthread_create.c:207
#7  0x000079ef4bb4282f in __clone () at src/thread/x86_64/clone.s:22
Backtrace stopped: frame did not save the PC

Thread 22 (LWP 78 "thpool-6"):
#0  __cp_end () at src/thread/x86_64/syscall_cp.s:29
#1  0x000079ef4bb3f4fc in __syscall_cp_c (nr=202, u=<optimized out>, v=<optimized out>, w=<optimized out>, x=<optimized out>, y=<optimized out>, z=0) at src/thread/pthread_cancel.c:33
#2  0x000079ef4bb3ea2e in __futex4_cp (to=<optimized out>, val=2, op=128, addr=0x79eeee276594) at src/thread/__timedwait.c:24
#3  __timedwait_cp (addr=addr@entry=0x79eeee276594, val=val@entry=2, clk=clk@entry=0, at=at@entry=0x0, priv=128, priv@entry=1) at src/thread/__timedwait.c:52
#4  0x000079ef4bb3f894 in __pthread_cond_timedwait (c=0x79eefe6c21e8, m=0x79eefe6c21c0, ts=0x0) at src/thread/pthread_cond_timedwait.c:100
#5  0x0000000001792c3b in ?? ()
#6  0x000079ef4bb4022e in start (p=0x79eeee2766f0) at src/thread/pthread_create.c:207
#7  0x000079ef4bb4282f in __clone () at src/thread/x86_64/clone.s:22
Backtrace stopped: frame did not save the PC

Thread 21 (LWP 77 "thpool-5"):
#0  __cp_end () at src/thread/x86_64/syscall_cp.s:29
#1  0x000079ef4bb3f4fc in __syscall_cp_c (nr=202, u=<optimized out>, v=<optimized out>, w=<optimized out>, x=<optimized out>, y=<optimized out>, z=0) at src/thread/pthread_cancel.c:33
#2  0x000079ef4bb3ea2e in __futex4_cp (to=<optimized out>, val=2, op=128, addr=0x79eeee2f9594) at src/thread/__timedwait.c:24
#3  __timedwait_cp (addr=addr@entry=0x79eeee2f9594, val=val@entry=2, clk=clk@entry=0, at=at@entry=0x0, priv=128, priv@entry=1) at src/thread/__timedwait.c:52
#4  0x000079ef4bb3f894 in __pthread_cond_timedwait (c=0x79eefe6c21e8, m=0x79eefe6c21c0, ts=0x0) at src/thread/pthread_cond_timedwait.c:100
#5  0x0000000001792c3b in ?? ()
#6  0x000079ef4bb4022e in start (p=0x79eeee2f96f0) at src/thread/pthread_create.c:207
#7  0x000079ef4bb4282f in __clone () at src/thread/x86_64/clone.s:22
Backtrace stopped: frame did not save the PC

Thread 20 (LWP 76 "thpool-4"):
#0  __cp_end () at src/thread/x86_64/syscall_cp.s:29
#1  0x000079ef4bb3f4fc in __syscall_cp_c (nr=202, u=<optimized out>, v=<optimized out>, w=<optimized out>, x=<optimized out>, y=<optimized out>, z=0) at src/thread/pthread_cancel.c:33
#2  0x000079ef4bb3ea2e in __futex4_cp (to=<optimized out>, val=2, op=128, addr=0x79eeee37c594) at src/thread/__timedwait.c:24
#3  __timedwait_cp (addr=addr@entry=0x79eeee37c594, val=val@entry=2, clk=clk@entry=0, at=at@entry=0x0, priv=128, priv@entry=1) at src/thread/__timedwait.c:52
#4  0x000079ef4bb3f894 in __pthread_cond_timedwait (c=0x79eefe6c21e8, m=0x79eefe6c21c0, ts=0x0) at src/thread/pthread_cond_timedwait.c:100
#5  0x0000000001792c3b in ?? ()
#6  0x000079ef4bb4022e in start (p=0x79eeee37c6f0) at src/thread/pthread_create.c:207
#7  0x000079ef4bb4282f in __clone () at src/thread/x86_64/clone.s:22
Backtrace stopped: frame did not save the PC

Thread 19 (LWP 75 "thpool-3"):
#0  0x000079ef02467e67 in zif_xdebug_error_reporting () from /usr/local/lib/php/extensions/no-debug-zts-20230831/xdebug.so
#1  0x000079ef4ab25263 in ?? () from /usr/local/lib/libphp.so
#2  0x000079ef4ab26195 in ?? () from /usr/local/lib/libphp.so
#3  0x000079ef4ab25199 in ?? () from /usr/local/lib/libphp.so
#4  0x000079ef4ab26195 in ?? () from /usr/local/lib/libphp.so
#5  0x000079ef4ab25199 in ?? () from /usr/local/lib/libphp.so
#6  0x000079ef4ab26195 in ?? () from /usr/local/lib/libphp.so
#7  0x000079ef4ab25199 in ?? () from /usr/local/lib/libphp.so
#8  0x000079ef4ab26195 in ?? () from /usr/local/lib/libphp.so
#9  0x000079ef4ab25199 in ?? () from /usr/local/lib/libphp.so
#10 0x000079ef4ab26195 in ?? () from /usr/local/lib/libphp.so
#11 0x000079ef4aeab81e in ?? () from /usr/local/lib/libphp.so
#12 0x000079ef4aed5af9 in execute_ex () from /usr/local/lib/libphp.so
#13 0x000079ef4aedfc43 in zend_execute () from /usr/local/lib/libphp.so
#14 0x000079ef4ae676e0 in zend_execute_scripts () from /usr/local/lib/libphp.so
#15 0x000079ef4adf6038 in php_execute_script () from /usr/local/lib/libphp.so
#16 0x00000000017950b1 in ?? ()
#17 0x0000000001792857 in ?? ()
#18 0x0000000000477448 in ?? ()
#19 0x0000000002ebf060 in ?? ()
#20 0x0000000000000001 in ?? ()
#21 0x000000c000600c00 in ?? ()
#22 0x000000c000a00340 in ?? ()
#23 0x000079eeee3ff528 in ?? ()
#24 0x00000000000002c0 in ?? ()
#25 0x000000c000a1c340 in ?? ()
#26 0x000000c0006139f8 in ?? ()
#27 0x000000000047584a in ?? ()
#28 0x000079eeee3ff538 in ?? ()
#29 0x0000000000000000 in ?? ()

Thread 18 (LWP 74 "thpool-2"):
#0  0x000079ef02467e63 in zif_xdebug_error_reporting () from /usr/local/lib/php/extensions/no-debug-zts-20230831/xdebug.so
#1  0x000079ef4ab25263 in ?? () from /usr/local/lib/libphp.so
#2  0x000079ef4ab26195 in ?? () from /usr/local/lib/libphp.so
#3  0x000079ef4ab25199 in ?? () from /usr/local/lib/libphp.so
#4  0x000079ef4ab26195 in ?? () from /usr/local/lib/libphp.so
#5  0x000079ef4ab25199 in ?? () from /usr/local/lib/libphp.so
#6  0x000079ef4ab26195 in ?? () from /usr/local/lib/libphp.so
#7  0x000079ef4ab25199 in ?? () from /usr/local/lib/libphp.so
#8  0x000079ef4ab26195 in ?? () from /usr/local/lib/libphp.so
#9  0x000079ef4ab25199 in ?? () from /usr/local/lib/libphp.so
#10 0x000079ef4ab26195 in ?? () from /usr/local/lib/libphp.so
#11 0x000079ef4aeab81e in ?? () from /usr/local/lib/libphp.so
#12 0x000079ef4aed5af9 in execute_ex () from /usr/local/lib/libphp.so
#13 0x000079ef4aedfc43 in zend_execute () from /usr/local/lib/libphp.so
#14 0x000079ef4ae676e0 in zend_execute_scripts () from /usr/local/lib/libphp.so
#15 0x000079ef4adf6038 in php_execute_script () from /usr/local/lib/libphp.so
#16 0x00000000017950b1 in ?? ()
#17 0x0000000001792857 in ?? ()
#18 0x0000000000477448 in ?? ()
#19 0x000000c00006ef00 in ?? ()
#20 0x000000c00006ef00 in ?? ()
#21 0x000079eefe49c528 in ?? ()
#22 0x000000000044bd91 in ?? ()
#23 0x000000c000073900 in ?? ()
#24 0x00000000000002c0 in ?? ()
#25 0x000000c0008a0340 in ?? ()
#26 0x000000c000b00bb0 in ?? ()
#27 0x000000000047584a in ?? ()
#28 0x000079eefe49c538 in ?? ()
#29 0x0000000000000000 in ?? ()

Thread 17 (LWP 73 "thpool-1"):
#0  0x000079ef02467e5a in zif_xdebug_error_reporting () from /usr/local/lib/php/extensions/no-debug-zts-20230831/xdebug.so
#1  0x000079ef4ab25263 in ?? () from /usr/local/lib/libphp.so
#2  0x000079ef4ab26195 in ?? () from /usr/local/lib/libphp.so
#3  0x000079ef4ab25199 in ?? () from /usr/local/lib/libphp.so
#4  0x000079ef4ab26195 in ?? () from /usr/local/lib/libphp.so
#5  0x000079ef4ab25199 in ?? () from /usr/local/lib/libphp.so
#6  0x000079ef4ab26195 in ?? () from /usr/local/lib/libphp.so
#7  0x000079ef4ab25199 in ?? () from /usr/local/lib/libphp.so
#8  0x000079ef4ab26195 in ?? () from /usr/local/lib/libphp.so
#9  0x000079ef4ab25199 in ?? () from /usr/local/lib/libphp.so
#10 0x000079ef4ab26195 in ?? () from /usr/local/lib/libphp.so
#11 0x000079ef4aeab81e in ?? () from /usr/local/lib/libphp.so
#12 0x000079ef4aed5af9 in execute_ex () from /usr/local/lib/libphp.so
#13 0x000079ef4aedfc43 in zend_execute () from /usr/local/lib/libphp.so
#14 0x000079ef4ae676e0 in zend_execute_scripts () from /usr/local/lib/libphp.so
#15 0x000079ef4adf6038 in php_execute_script () from /usr/local/lib/libphp.so
#16 0x00000000017950b1 in ?? ()
#17 0x0000000001792857 in ?? ()
#18 0x0000000000477448 in ?? ()
#19 0x0000000002ebf060 in ?? ()
#20 0x0000000000000001 in ?? ()
#21 0x000000c000581400 in ?? ()
#22 0x000000c0008a0340 in ?? ()
#23 0x000079eefe51f528 in ?? ()
#24 0x00000000000002c0 in ?? ()
#25 0x000000c0007be1a0 in ?? ()
#26 0x000000c000b049f8 in ?? ()
#27 0x000000000047584a in ?? ()
#28 0x000079eefe51f538 in ?? ()
#29 0x0000000000000000 in ?? ()

Thread 16 (LWP 72 "thpool-0"):
#0  __cp_end () at src/thread/x86_64/syscall_cp.s:29
#1  0x000079ef4bb3f4fc in __syscall_cp_c (nr=202, u=<optimized out>, v=<optimized out>, w=<optimized out>, x=<optimized out>, y=<optimized out>, z=0) at src/thread/pthread_cancel.c:33
#2  0x000079ef4bb3ea2e in __futex4_cp (to=<optimized out>, val=2, op=128, addr=0x79eefe5a2594) at src/thread/__timedwait.c:24
#3  __timedwait_cp (addr=addr@entry=0x79eefe5a2594, val=val@entry=2, clk=clk@entry=0, at=at@entry=0x0, priv=128, priv@entry=1) at src/thread/__timedwait.c:52
#4  0x000079ef4bb3f894 in __pthread_cond_timedwait (c=0x79eefe6c21e8, m=0x79eefe6c21c0, ts=0x0) at src/thread/pthread_cond_timedwait.c:100
#5  0x0000000001792c3b in ?? ()
#6  0x000079ef4bb4022e in start (p=0x79eefe5a26f0) at src/thread/pthread_create.c:207
#7  0x000079ef4bb4282f in __clone () at src/thread/x86_64/clone.s:22
Backtrace stopped: frame did not save the PC

Thread 15 (LWP 71 "frankenphp"):
#0  0x00000000004795e3 in ?? ()
#1  0x000000000043c750 in ?? ()
#2  0x000000c00009c148 in ?? ()
#3  0x0000000000000080 in ?? ()
#4  0x0000000000000000 in ?? ()

Thread 14 (LWP 70 "frankenphp"):
#0  0x00000000004795e3 in ?? ()
#1  0x000000000043c750 in ?? ()
#2  0x000000c000236548 in ?? ()
#3  0x0000000000000080 in ?? ()
#4  0x0000000000000000 in ?? ()

Thread 13 (LWP 69 "frankenphp"):
#0  0x00000000004795e3 in ?? ()
#1  0x000000000043c750 in ?? ()
#2  0x000000c000600548 in ?? ()
#3  0x0000000000000080 in ?? ()
#4  0x0000000000000000 in ?? ()

Thread 12 (LWP 68 "frankenphp"):
#0  0x00000000004795e3 in ?? ()
#1  0x000000000043c750 in ?? ()
#2  0x000000c000518548 in ?? ()
#3  0x0000000000000080 in ?? ()
#4  0x0000000000000000 in ?? ()

Thread 11 (LWP 67 "frankenphp"):
#0  0x00000000004795e3 in ?? ()
#1  0x000000000043c750 in ?? ()
#2  0x000000c000100948 in ?? ()
#3  0x0000000000000080 in ?? ()
#4  0x0000000000000000 in ?? ()

Thread 10 (LWP 66 "frankenphp"):
#0  0x00000000004795e3 in ?? ()
#1  0x000000000043c750 in ?? ()
#2  0x000000c000600148 in ?? ()
#3  0x0000000000000080 in ?? ()
#4  0x0000000000000000 in ?? ()

Thread 9 (LWP 65 "frankenphp"):
#0  0x00000000004795e3 in ?? ()
#1  0x000000000043c750 in ?? ()
#2  0x0000000002ed7300 in ?? ()
#3  0x0000000000000080 in ?? ()
#4  0x0000000000000000 in ?? ()

Thread 8 (LWP 64 "frankenphp"):
#0  0x00000000004795e3 in ?? ()
#1  0x000000000043c750 in ?? ()
#2  0x000000c000580148 in ?? ()
#3  0x0000000000000080 in ?? ()
#4  0x0000000000000000 in ?? ()

Thread 7 (LWP 63 "frankenphp"):
#0  0x00000000004795e3 in ?? ()
#1  0x000000000043c750 in ?? ()
#2  0x000000c000100548 in ?? ()
#3  0x0000000000000080 in ?? ()
#4  0x0000000000000000 in ?? ()

Thread 6 (LWP 62 "frankenphp"):
#0  0x000000000040ac6e in ?? ()
#1  0x000000000040abe5 in ?? ()
#2  0x000000000040abe5 in ?? ()
#3  0x0000000000000000 in ?? ()

Thread 5 (LWP 61 "frankenphp"):
#0  0x00000000004795e3 in ?? ()
#1  0x000000000043c750 in ?? ()
#2  0x0000000002ed70f8 in ?? ()
#3  0x0000000000000080 in ?? ()
#4  0x0000000000000000 in ?? ()

Thread 4 (LWP 60 "frankenphp"):
#0  0x00000000004795e3 in ?? ()
#1  0x000000000043c750 in ?? ()
#2  0x000000c00009cd48 in ?? ()
#3  0x0000000000000080 in ?? ()
#4  0x0000000000000000 in ?? ()

Thread 3 (LWP 59 "frankenphp"):
#0  0x00000000004795e3 in ?? ()
#1  0x000000000043c750 in ?? ()
#2  0x000000c00009c948 in ?? ()
#3  0x0000000000000080 in ?? ()
#4  0x0000000000000000 in ?? ()

Thread 2 (LWP 58 "frankenphp"):
#0  0x00000000004795e3 in ?? ()
#1  0x000000000043c7c5 in ?? ()
#2  0x0000000002ea6640 in ?? ()
#3  0x0000000000000080 in ?? ()
#4  0x000079ef031d67e0 in ?? ()
#5  0x0000000000000000 in ?? ()

Thread 1 (LWP 1 "frankenphp"):
#0  0x00000000004795e3 in ?? ()
#1  0x000000000043c750 in ?? ()
#2  0x0000000002ea5848 in ?? ()
#3  0x0000000000000080 in ?? ()
#4  0x0000000000000000 in ?? ()
Continuing.
[New LWP 209]

Thread 19 "thpool-3" received signal SIG35, Real-time event 35.
[Switching to LWP 75]
0x000079ef02467e67 in zif_xdebug_error_reporting () from /usr/local/lib/php/extensions/no-debug-zts-20230831/xdebug.so
Continuing.

Thread 17 "thpool-1" received signal SIG35, Real-time event 35.
[Switching to LWP 73]
0x000079ef02467e5a in zif_xdebug_error_reporting () from /usr/local/lib/php/extensions/no-debug-zts-20230831/xdebug.so
Continuing.

Thread 18 "thpool-2" received signal SIG35, Real-time event 35.
[Switching to LWP 74]
0x000079ef02467e63 in zif_xdebug_error_reporting () from /usr/local/lib/php/extensions/no-debug-zts-20230831/xdebug.so
Continuing.
[New LWP 210]

Thread 21 "thpool-5" received signal SIG35, Real-time event 35.
[Switching to LWP 77]
0x000079ef02467e5a in zif_xdebug_error_reporting () from /usr/local/lib/php/extensions/no-debug-zts-20230831/xdebug.so
Continuing.

Thread 24 "thpool-8" received signal SIG35, Real-time event 35.
[Switching to LWP 80]
0x000079ef02467e5a in zif_xdebug_error_reporting () from /usr/local/lib/php/extensions/no-debug-zts-20230831/xdebug.so
Continuing.

Thread 23 "thpool-7" received signal SIG35, Real-time event 35.
[Switching to LWP 79]
0x000079ef02467e63 in zif_xdebug_error_reporting () from /usr/local/lib/php/extensions/no-debug-zts-20230831/xdebug.so
Detaching from program: /usr/local/bin/frankenphp, process 1
[Inferior 1 (process 1) detached]

I created a small repository for this : https://github.com/DennisdeBest/frankenphp_xdebug

The problem appeared as soon as I added the LiipImagineBundle

dunglas commented 7 months ago

Thanks for the reproducer. This is a known issue. Downgrading PHP to 8.2 seems to prevent the issue. Downgrading XDebug itself seems to work too.

derickr commented 7 months ago

Had anybody been able to reproduce this with a one liner not using docker?

DennisdeBest commented 7 months ago

thanks @dunglas I have no problem when moving from dunglas/frankenphp:1.1.0-alpine (php 8.3.3) to dunglas/frankenphp:1.1-php8.2.16-alpine regardless of the xdebug version

dunglas commented 7 months ago

@derickr I managed to reproduce the issue (a segmentation fault that seems related to an infinite recursion) without Docker (on Ubuntu, bare metal x86_64):

Compile PHP with the standard ZTS flags (I tested with master):

./configure \
    --enable-embed \
    --enable-zts \
    --disable-zend-signals \
    --enable-debug

Compile XDebug as usual

Use this minimal php.ini:

zend_extension = /path/to/xdebug.so
xdebug_mode = debug
xdebug.start_with_request = yes

Compile FrankenPHP:

curl -L https://github.com/dunglas/frankenphp/archive/refs/heads/main.tar.gz | tar x
cd frankenphp-main/caddy/frankenphp
CGO_CFLAGS=$(php-config --includes) CGO_LDFLAGS="$(php-config --ldflags) $(php-config --libs)" go build

Use this minimal reproducer:

<?php

error_reporting(0);
sleep(1);
echo 'OK';

Start FrankenPHP (you may need to update LD_LIBRARY_PATH to add the directory containing your libphp.so, you know the drill:
```
/path/to/frankenphp php-server -l :8000
```
Set a breakpoint somewhere in the PHP file
Load it in the browser and hit refresh several times quickly (the problem seems to happen only when concurrent requests are received)

I get this stack trace:

Thread 21 "thpool-7" received signal SIGSEGV, Segmentation fault.
[Switching to Thread 0x7fff71ffb640 (LWP 241904)]
zif_xdebug_error_reporting (execute_data=0x7fff710150a0, return_value=0x7fff71ff93f0) at /home/tilleuls/workspace/xdebug/src/base/base.c:1631
1631        XG_BASE(orig_error_reporting_func)(INTERNAL_FUNCTION_PARAM_PASSTHRU);
(gdb) bt
#0  zif_xdebug_error_reporting (execute_data=0x7fff710150a0, return_value=0x7fff71ff93f0) at /home/tilleuls/workspace/xdebug/src/base/base.c:1631
#1  0x00007fffac194617 in zif_xdebug_error_reporting (execute_data=0x7fff710150a0, return_value=0x7fff71ff93f0) at /home/tilleuls/workspace/xdebug/src/base/base.c:1631
#2  0x00007fffac194617 in zif_xdebug_error_reporting (execute_data=0x7fff710150a0, return_value=0x7fff71ff93f0) at /home/tilleuls/workspace/xdebug/src/base/base.c:1631
#3  0x00007fffac194617 in zif_xdebug_error_reporting (execute_data=0x7fff710150a0, return_value=0x7fff71ff93f0) at /home/tilleuls/workspace/xdebug/src/base/base.c:1631
#4  0x00007fffac194617 in zif_xdebug_error_reporting (execute_data=0x7fff710150a0, return_value=0x7fff71ff93f0) at /home/tilleuls/workspace/xdebug/src/base/base.c:1631
#5  0x00007fffac194617 in zif_xdebug_error_reporting (execute_data=0x7fff710150a0, return_value=0x7fff71ff93f0) at /home/tilleuls/workspace/xdebug/src/base/base.c:1631
#6  0x00007fffac194617 in zif_xdebug_error_reporting (execute_data=0x7fff710150a0, return_value=0x7fff71ff93f0) at /home/tilleuls/workspace/xdebug/src/base/base.c:1631
#7  0x00007fffac194617 in zif_xdebug_error_reporting (execute_data=0x7fff710150a0, return_value=0x7fff71ff93f0) at /home/tilleuls/workspace/xdebug/src/base/base.c:1631
#8  0x00007fffac194617 in zif_xdebug_error_reporting (execute_data=0x7fff710150a0, return_value=0x7fff71ff93f0) at /home/tilleuls/workspace/xdebug/src/base/base.c:1631
#9  0x00007fffac194617 in zif_xdebug_error_reporting (execute_data=0x7fff710150a0, return_value=0x7fff71ff93f0) at /home/tilleuls/workspace/xdebug/src/base/base.c:1631
#10 0x00007fffac194617 in zif_xdebug_error_reporting (execute_data=0x7fff710150a0, return_value=0x7fff71ff93f0) at /home/tilleuls/workspace/xdebug/src/base/base.c:1631
#11 0x00007fffac194617 in zif_xdebug_error_reporting (execute_data=0x7fff710150a0, return_value=0x7fff71ff93f0) at /home/tilleuls/workspace/xdebug/src/base/base.c:1631
#12 0x00007fffac194617 in zif_xdebug_error_reporting (execute_data=0x7fff710150a0, return_value=0x7fff71ff93f0) at /home/tilleuls/workspace/xdebug/src/base/base.c:1631
#13 0x00007fffac194617 in zif_xdebug_error_reporting (execute_data=0x7fff710150a0, return_value=0x7fff71ff93f0) at /home/tilleuls/workspace/xdebug/src/base/base.c:1631

LucianoVandi commented 7 months ago

I am experiencing the same issue with API Platform, regardless of the Xdebug extension, and after downgrading to the tag 1.1.1-php8.2-alpine. See https://github.com/api-platform/api-platform/issues/2670

dunglas commented 7 months ago

Fixed by https://github.com/xdebug/xdebug/pull/958.

SirMishaa commented 6 months ago

Looks like the documentation forgot to be changed, since it's now fixed https://frankenphp.dev/fr/docs/known-issues/

Should I make a PR ?

Renrhaf commented 6 months ago

The new xDebug version was released with the fix : https://github.com/xdebug/xdebug/releases/tag/3.3.2

dunglas / frankenphp