View Issue Details

IDProjectCategoryView StatusLast Update
0000938XdebugStep Debuggingpublic2020-03-24 17:14
Reporternajcik Assigned Toderick  
PrioritynormalSeveritymajorReproducibilityalways
Status closedResolutionfixed 
Product Version2.2.2 
Target Version2.7.0alpha1Fixed in Version2.7.0alpha1 
Summary0000938: Unreliable debugging of forking processes
Description

If you decide to remote debug code that use pnctl_fork() function at least both eclipse and xdc 1.0b5 either crash or don't stop at desired breaking points.

Steps To Reproduce

Just assume I have a working environment that allows for remote debugging e.g.:
a php-cli that is configured to remotely trigger a debugging session at a debug client (eclipse 4.2/pdt and xdc1.0b5 in my case)

Consider following script:

01: <?php
02: echo "started\n";
03: if ($child = pcntl_fork()) {
04: sleep(5);
05: print "hello from parent\n"; //breakpoint no. 1 here
06: $status;
07: pcntl_waitpid($child, $status);
08: print "finished\n";
09: } else {
10: print "hello from child\n"; //breakpoint no. 2 here
11:}

Let's say we set the breakpoints at line 05 and 10.
Apparently the first breakpoint to occur is at line 10. If we resume execution after more the 5 seconds of investigation it's not possible to stop at line 5.

Additional Information

I assume that xdebug does not provide enough information back to the client so it knows it actually talks with more then one process. As far as I know when forking occurs the open connections are shared between the forked processes. So the open connection to the IDE / xdebug client is shared between the two forked processes too and can make a lot of confusion in the clients.
This situation can be observed in Eclipse w/PDT because when it switches to debug perspective it always indicates it talks to a single process even though you might have forked many.
This is completely different when you debug a webpage that spawns many php cgi instances which response to multiple ajax calls and this situaltion is well handled in Eclipse.

I've tried earlier versions of xdebug too. The same behavior.

TagsNo tags attached.
Attached Files
xdebug-pcntl-fork-reference-implementation.php (4,637 bytes)   
<?php
declare(strict_types=1);

class Wheel
{
    const SIGNAL_NUMBER        = 'signo';
    const MAX_NUMBER_OF_SPOKES = 3;
    protected $_spokes      = [];
    protected $_waitSignals = [
        SIGCHLD,
        SIGALRM,
        SIGINT,
        SIGTERM,
    ];
    protected $_info        = [];
    protected $_spoke;

    public function start(): Wheel
    {
        $this->_initialize();
        while ($this->getNumberOfSpokes() < self::MAX_NUMBER_OF_SPOKES) {
            $spoke = new Spoke();
            $spoke->appendPath($this->_getSpoke()->getPath());
            $spoke->start();
            $this->_spokes[$spoke->getProcessId()] = $spoke;
        }
        pcntl_sigprocmask(SIG_BLOCK, $this->_waitSignals);

        while (true) {
            $this->_info = [];
            pcntl_sigwaitinfo($this->_waitSignals, $this->_info);

            switch ($this->_info[self::SIGNAL_NUMBER]) {
                case SIGCHLD:
                    while ($processId = pcntl_wait($status, WNOHANG)) {
                        unset($this->_spokes[$processId]);
                        $spoke = new Spoke();
                        $spoke->appendPath($this->_getSpoke()->getPath());
                        $spoke->start();
                        $this->_spokes[$spoke->getProcessId()] = $spoke;
                    }
                    break;
                case SIGALRM:
                    pcntl_alarm(8);
                    break;
                case SIGINT:
                case SIGTERM:
                    $this->terminateChildProcesses();
                    break 2;
                default:
                    throw new \UnexpectedValueException('Unexpected blocked signal.');
            }
        }
    }

    public function setSpoke(Spoke $spoke): Wheel
    {
        $this->_spoke = $spoke;

        return $this;
    }

    protected function _getSpoke(): Spoke
    {
        if ($this->_spoke === null) {
            throw new \LogicException('Spoke is not set.');
        }

        return $this->_spoke;
    }

    protected function _initialize(): Wheel
    {
        register_shutdown_function([$this, 'terminateChildProcesses']);
        pcntl_signal(SIGTERM, [$this, 'terminateChildProcesses']);
        pcntl_signal(SIGINT, [$this, 'terminateChildProcesses']);

        return $this;
    }

    public function terminateChildProcesses(): Wheel
    {
        if (!empty($this->_processes)) {
            /** @var Spoke $spoke */
            foreach ($this->_spokes as $spoke) {
                $processId = $spoke->getProcessId();
                if (rand(1, 0)) {
                    posix_kill($processId, SIGKILL);
                }else {
                    posix_kill($processId, SIGTERM);
                }
                unset($this->_processes[$processId]);
            }
        }

        return $this;
    }

    public function getNumberOfSpokes(): int
    {
        return count($this->_spokes);
    }
}

class Spoke
{
    const FORK_FAILURE_CODE = -1;
    protected $_parentProcessId;
    protected $_processId;
    protected $_wheel;
    protected $_path = '';

    public function start(): Spoke
    {
        $processId = pcntl_fork();
        if ($processId === self::FORK_FAILURE_CODE) {
            throw new \RuntimeException('Failed to fork a new spoke.');
        }elseif ($processId > 0) {
            $this->_initialize($processId);
        }else {
            $this->_initialize();
            if (substr_count($this->getPath(), '/') <= 3) {
                $this->_startNewWheel();
            }
            exit(0);
        }

        return $this;
    }

    public function getProcessId(): int
    {
        if ($this->_processId === null) {
            throw new \LogicException('Process ID is not set.');
        }

        return $this->_processId;
    }

    protected function _startNewWheel(): Spoke
    {
        $this->_wheel = new Wheel();
        $this->_wheel->setSpoke($this);
        $this->_wheel->start();

        return $this;
    }

    protected function _initialize(int $processId = null): Spoke
    {
        if ($processId === null) {
            $this->_parentProcessId = posix_getppid();
            $this->_processId = posix_getpid();
            $this->appendPath((string)$this->getProcessId());
        }else {
            $this->_processId = $processId;
        }

        return $this;
    }

    public function getPath(): string
    {
        return $this->_path;
    }

    public function appendPath(string $path): Spoke
    {
        $this->_path .= '/' . $path;

        return $this;
    }
}

$spoke = new Spoke();
$spoke->start();

return;
xdebug-pcntl-fork-reference-implementation-0.php (6,532 bytes)   
<?php
declare(strict_types=1);

class Logger
{
    protected $_spoke;

    public function log(string $message): Logger
    {
        $spokePath = $this->_getSpoke()->getPath();
        $format = "%s | %s\n";
        fwrite(STDOUT, sprintf($format, $spokePath, $message));

        return $this;
    }

    public function setSpoke(Spoke $spoke): Logger
    {
        if ($this->_spoke === null) {
            $this->_spoke = $spoke;
        }else {
            throw new \LogicException('Spoke is already set.');
        }

        return $this;
    }

    protected function _getSpoke(): Spoke
    {
        if ($this->_spoke === null) {
            throw new \LogicException('Spoke is not set.');
        }

        return $this->_spoke;
    }
}

class Wheel
{
    const SIGNAL_NUMBER        = 'signo';
    const MAX_NUMBER_OF_SPOKES = 3;
    protected $_spokes      = [];
    protected $_waitSignals = [
        SIGCHLD,
        SIGALRM,
        SIGINT,
        SIGTERM,
    ];
    protected $_info        = [];
    protected $_spoke;
    protected $_logger;

    public function start(): Wheel
    {
        $this->_initialize();
        while ($this->getNumberOfSpokes() < self::MAX_NUMBER_OF_SPOKES) {
            $spoke = new Spoke();
            $spoke->appendPath($this->_getSpoke()->getPath());
            $spoke->start();
            $this->_getLogger()->log("Initialized spoke with PID [{$spoke->getProcessId()}].");
            $this->_spokes[$spoke->getProcessId()] = $spoke;
        }
        pcntl_sigprocmask(SIG_BLOCK, $this->_waitSignals);

        while (true) {
            $this->_info = [];
            $this->_getLogger()->log("Waiting for signal.");
            pcntl_sigwaitinfo($this->_waitSignals, $this->_info);

            switch ($this->_info[self::SIGNAL_NUMBER]) {
                case SIGCHLD:
                    $this->_getLogger()->log("Received SIGCHLD.");
                    while ($processId = pcntl_wait($status, WNOHANG)) {
                        $this->_getLogger()->log("Spoke with PID[$processId] exited.");
                        unset($this->_spokes[$processId]);
                        $spoke = new Spoke();
                        $spoke->appendPath($this->_getSpoke()->getPath());
                        $spoke->start();
                        $this->_getLogger()->log("Added new spoke with PID[{$spoke->getProcessId()}].");
                        $this->_spokes[$spoke->getProcessId()] = $spoke;
                    }
                    break;
                case SIGALRM:
                    $this->_getLogger()->log("Received SIGALRM.");
                    pcntl_alarm(8);
                    break;
                case SIGINT:
                case SIGTERM:
                    $this->_getLogger()->log("Received SIGINT or SIGTERM.");
                    $this->terminateChildProcesses();
                    break 2;
                default:
                    throw new \UnexpectedValueException('Unexpected blocked signal.');
            }
        }
    }

    public function setSpoke(Spoke $spoke): Wheel
    {
        $this->_spoke = $spoke;

        return $this;
    }

    protected function _getSpoke(): Spoke
    {
        if ($this->_spoke === null) {
            throw new \LogicException('Spoke is not set.');
        }

        return $this->_spoke;
    }

    protected function _initialize(): Wheel
    {
        register_shutdown_function([$this, 'terminateChildProcesses']);
        pcntl_signal(SIGTERM, [$this, 'terminateChildProcesses']);
        pcntl_signal(SIGINT, [$this, 'terminateChildProcesses']);

        return $this;
    }

    public function terminateChildProcesses(): Wheel
    {
        if (!empty($this->_processes)) {
            /** @var Spoke $spoke */
            foreach ($this->_spokes as $spoke) {
                $processId = $spoke->getProcessId();
                if (rand(1, 0)) {
                    posix_kill($processId, SIGKILL);
                }else {
                    posix_kill($processId, SIGTERM);
                }
                unset($this->_processes[$processId]);
            }
        }

        return $this;
    }

    public function getNumberOfSpokes(): int
    {
        return count($this->_spokes);
    }

    protected function _getLogger(): Logger
    {
        if ($this->_logger === null) {
            $this->_logger = new Logger();
            $this->_logger->setSpoke($this->_getSpoke());
        }

        return $this->_logger;
    }
}

class Spoke
{
    const FORK_FAILURE_CODE = -1;
    protected $_parentProcessId;
    protected $_processId;
    protected $_wheel;
    protected $_path = '';
    protected $_logger;

    public function start(): Spoke
    {
        $processId = pcntl_fork();
        if ($processId === self::FORK_FAILURE_CODE) {
            throw new \RuntimeException('Failed to fork a new spoke.');
        }elseif ($processId > 0) {
            $this->_initialize($processId);
        }else {
            $this->_initialize();
            sleep(random_int(10, 3600));
            if (substr_count($this->getPath(), '/') <= 3) {
                $this->_startNewWheel();
            }
            exit(0);
        }

        return $this;
    }

    public function getProcessId(): int
    {
        if ($this->_processId === null) {
            throw new \LogicException('Process ID is not set.');
        }

        return $this->_processId;
    }

    protected function _startNewWheel(): Spoke
    {
        $this->_wheel = new Wheel();
        $this->_wheel->setSpoke($this);
        $this->_wheel->start();

        return $this;
    }

    protected function _initialize(int $processId = null): Spoke
    {
        if ($processId === null) {
            $this->_parentProcessId = posix_getppid();
            $this->_processId = posix_getpid();
            $this->appendPath((string)$this->getProcessId());
        }else {
            $this->_processId = $processId;
            $this->appendPath((string)$this->getProcessId());
        }

        return $this;
    }

    public function getPath(): string
    {
        return $this->_path;
    }

    public function appendPath(string $path): Spoke
    {
        $this->_path .= $path . '/';

        return $this;
    }

    protected function _getLogger(): Logger
    {
        if ($this->_logger === null) {
            $this->_logger = new Logger();
            $this->_logger->setSpoke($this);
        }

        return $this->_logger;
    }
}

$spoke = new Spoke();
$spoke->start();

return;
Operating SystemLinux
PHP Version5.3.3

Activities

derick

2014-02-27 19:49

administrator   ~0002715

Changing this to a feature request, but I have no idea on how to do this (yet).

jimp

2016-03-10 21:11

reporter   ~0003568

I am having this same problem. I am finding the debugging works, even though the debugger is technically reacting to two different processes after the fork. But when the parent process exits I lose the XDebug socket to my client and debugging is over. Therefore my PHP daemon CLI app can only be debugged right up until the first process exits after the pnctl_fork() call.

Userland control of enabling and disabling the debugger (and I assume the profiler is affected, too) would allow my program to restart the debugger after the fork. I am already doing that for DB connections, and that feature would also allow me to determine a separate port for the daemon process and the child process.

derick

2016-12-12 00:16

administrator   ~0004030

I think I have an idea on how to solve this, but I won't want to commit to a version for this yet.

jimp

2016-12-13 21:27

reporter   ~0004046

Derick,

Thank you for the attention to this issue. I am available to help test the solution, if you need feedback. I think it is sufficient to allow a forked child to establish a new connection manually, which also could allow for more powerful debugging. For example, a PHP application could connect to the debug listener on demand in response to application-specific criteria.

cmqlabs

2017-02-22 01:19

reporter   ~0004219

Do you have any update on this feature? Do you know when it will be available?

derick

2017-02-24 10:56

administrator   ~0004220

Sorry, I've no idea yet.

brad@rhift.com

2018-01-04 19:37

reporter   ~0004548

Hey Derick - can this feature be funded? If so, I'd be very interested in talking to you about what you think that it would take to get this done from a financial perspective. This would be extremely useful. Thanks!

brad@rhift.com

2018-01-20 14:14

reporter   ~0004567

Hi Derick - attached is a reference implementation to check an implementation of this feature request against. Thanks for taking a look!

derick

2018-03-30 10:33

administrator   ~0004623

This issue has been addressed and merged into Xdebug's master branch on Git. It will form part of the 2.7.0alpha1 release. It's implementation was generously supported by @brad.

jimp

2018-03-31 05:00

reporter   ~0004628

I looked at the code changes and I think this will fix my problem as well. If I'm understanding correctly, Xdebug will now compare the PID to the previously known PID of an established debugging session, so a new connection will be automatically made for the child process and therefore avoid having a shared socket descriptor between processes that gets closed when any process exits.

I'm really looking forward to trying this out. Thanks Derick and Brad!

najcik

2018-04-05 12:37

reporter   ~0004631

Thank you!

Issue History

Date Modified Username Field Change
2013-03-25 12:30 najcik New Issue
2014-02-27 19:49 derick Note Added: 0002715
2014-02-27 19:49 derick Category Debug client (console) => Feature/Change request
2016-03-10 21:11 jimp Note Added: 0003568
2016-12-12 00:16 derick Note Added: 0004030
2016-12-12 00:16 derick Assigned To => derick
2016-12-12 00:16 derick Status new => confirmed
2016-12-13 21:27 jimp Note Added: 0004046
2017-02-22 01:19 cmqlabs Note Added: 0004219
2017-02-24 10:56 derick Note Added: 0004220
2018-01-04 19:37 brad@rhift.com Note Added: 0004548
2018-01-19 11:16 derick Target Version => 2.7.0dev
2018-01-20 14:12 brad@rhift.com File Added: xdebug-pcntl-fork-reference-implementation.php
2018-01-20 14:14 brad@rhift.com Note Added: 0004567
2018-02-07 21:05 brad@rhift.com File Added: xdebug-pcntl-fork-reference-implementation-0.php
2018-03-30 10:33 derick Note Added: 0004623
2018-03-30 10:33 derick Status confirmed => closed
2018-03-30 10:33 derick Resolution open => fixed
2018-03-30 10:33 derick Fixed in Version => 2.7.0dev
2018-03-31 05:00 jimp Note Added: 0004628
2018-04-01 13:47 derick Fixed in Version 2.7.0dev => 2.7.0alpha1
2018-04-05 12:37 najcik Note Added: 0004631
2019-01-22 21:54 derick Fixed in Version 2.7.0alpha1 => 2.7.0rc1
2019-01-22 21:58 derick Target Version 2.7.0dev => 2.7.0rc1
2019-02-01 18:28 derick Fixed in Version 2.7.0rc1 => 2.7.0alpha1
2019-02-01 18:28 derick Target Version 2.7.0rc1 => 2.7.0alpha1
2020-03-12 16:43 derick Category Feature/Change request => Step Debugging