View Issue Details

IDProjectCategoryView StatusLast Update
0002021XdebugStep Debuggingpublic2021-10-04 09:29
Reporterneclimdul Assigned Toderick  
PrioritynormalSeveritycrashReproducibilityalways
Status closedResolutionfixed 
PlatformlinuxOSalpineOS Version3.12
Product Version3.0.4 
Target Version3.1devFixed in Version3.1.0 
Summary0002021: Segmentation fault due to NULL bytes in internal anonymous class names
Description#0 0x00007fb913a0ce87 in strlen () from /lib/ld-musl-x86_64.so.1
No symbol table info available.
#1 0x00007fb9131f8acd in return_stackframe (nr=<optimized out>) at /tmp/xdebug-3.0.4/src/debugger/handler_dbgp.c:491
        ta = 0x7fb913210eaa "filename"
        tv = 0x0
        fse = <optimized out>
        fse_prev = 0x558fec00cd08
        tmp_fname = 0x558fecae8140 "__TwigTemplate_0279bfe316a0f801ca5ed61604c97480866742f477ee94f97f0117d5b7591e33->doDisplay"
        tmp_filename = 0x0
        tmp = 0x558fecae75a0
0000002 0x00007fb9131fc63b in xdebug_dbgp_handle_stack_get (retval=0x7ffd3ed12538, context=<optimized out>, args=<optimized out>)
    at /tmp/xdebug-3.0.4/src/debugger/handler_dbgp.c:1891
        fse = <optimized out>
        i = <optimized out>
        stackframe = <optimized out>
        depth = <optimized out>
        error = <optimized out>
        message = <optimized out>
        error_entry = <optimized out>
        ta = <optimized out>
        tv = <optimized out>
        ta = <optimized out>
        tv = <optimized out>
        ta = <optimized out>
        tv = <optimized out>
0000003 0x00007fb9131ff438 in xdebug_dbgp_parse_option (flags=0, retval=<optimized out>, line=0x558fecaa9460 "stack_get -i 20", context=0x7fb91321de58 <xdebug_globals+376>)
    at /tmp/xdebug-3.0.4/src/debugger/handler_dbgp.c:2200
        ret = 0
        command = 0x7fb91321d520 <dbgp_commands+384>
        cmd = <optimized out>
        res = 0
        args = <optimized out>
        error = <optimized out>
        cmd = <optimized out>
        res = <optimized out>
        ret = <optimized out>
        args = <optimized out>
        command = <optimized out>
        error = <optimized out>
        ta = <optimized out>
        tv = <optimized out>
        ta = <optimized out>
        tv = <optimized out>
        ta = <optimized out>
        tv = <optimized out>
        message = <optimized out>
        error_entry = <optimized out>
        ta = <optimized out>
        tv = <optimized out>
        message = <optimized out>
        error_entry = <optimized out>
        ta = <optimized out>
        tv = <optimized out>
        message = <optimized out>
        error_entry = <optimized out>
0000004 xdebug_dbgp_cmdloop (context=0x7fb91321de58 <xdebug_globals+376>, bail=1) at /tmp/xdebug-3.0.4/src/debugger/handler_dbgp.c:2310
        option = 0x558fecaa9460 "stack_get -i 20"
        length = <optimized out>
        ret = <optimized out>
        response = 0x558fecae6c40
0000005 0x00007fb9132003a0 in xdebug_dbgp_breakpoint (context=0x7fb91321de58 <xdebug_globals+376>, stack=<optimized out>, filename=<optimized out>, lineno=117,
    type=<optimized out>, exception=0x0, code=0x0, message=0x0) at /tmp/xdebug-3.0.4/src/debugger/handler_dbgp.c:2634
        response = 0x558fecae5cc0
        error_container = 0x558fecae5e80
0000006 0x00007fb9131f5f8e in xdebug_debugger_statement_call (filename=0x558fec9c17a0, lineno=lineno@entry=117) at /tmp/xdebug-3.0.4/src/debugger/debugger.c:207
        le = <optimized out>
        extra_brk_info = <optimized out>
        fse = <optimized out>
        level = 0
        func_nr = 0
0000007 0x00007fb9131df837 in xdebug_statement_call (frame=<optimized out>) at /tmp/xdebug-3.0.4/xdebug.c:732
        op_array = <optimized out>
        lineno = 117
0000008 0x0000558fea2eaa12 in zend_llist_apply_with_argument ()
No symbol table info available.
0000009 0x0000558fea0382eb in ?? ()
No symbol table info available.
0000010 0x0000558fea03f64e in ?? ()
No symbol table info available.
0000011 0x00007fb9131e1d9a in xdebug_execute_ex (execute_data=0x7fb910a06fb0) at /tmp/xdebug-3.0.4/src/base/base.c:765
        op_array = 0x558fec9efc80
        edata = <optimized out>
        fse = 0x558fec00ce98
        function_nr = 481001
        code_coverage_function_name = 0x0
        code_coverage_filename = 0x0
        code_coverage_init = 0
0000012 0x0000558fea37b526 in execute_ex ()
Steps To ReproduceWorking through a simplified use case still. Currently triggering why trying to write/debug tests in Drupal phpunit test suite. The twig template class name in the backtrace and the null filename suggest to me maybe there's some sort of dynamic class involved.
Additional InformationSeems similar/duplicate of the earlier issue 0001407? That rightfully asked for a test case so I'll get one.

Running in alpine container but musl is def a less common runtime so i'll try to get the test case running in ubuntu as well.
TagsNo tags attached.
Operating System
PHP Version7.4.20-7.4.29

Activities

neclimdul

2021-09-23 19:25

reporter   ~0006045

This debug_print_backtrace() seems to support the assumption this is connected to a dynamic class. There's an eval in the stack. That eval is running a generated.

+'#0 Drupal\Core\Template\TwigSandboxPolicy->checkMethodAllowed() called at [/app/vendor/twig/twig/src/Extension/SandboxExtension.php:84]\n
+#1 Twig\Extension\SandboxExtension->checkMethodAllowed() called at [/app/vendor/twig/twig/src/Extension/CoreExtension.php:1505]\n
+0000002 twig_get_attribute() called at [/app/vendor/twig/twig/src/Environment.php(418) : eval()'d code:39]\n
+0000003 __TwigTemplate_0279bfe316a0f801ca5ed61604c97480866742f477ee94f97f0117d5b7591e33->doDisplay() called at [/app/vendor/twig/twig/src/Template.php:405]\n
+0000004 Twig\Template->displayWithErrorHandling() called at [/app/vendor/twig/twig/src/Template.php:378]\n
+0000005 Twig\Template->display() called at [/app/vendor/twig/twig/src/Template.php:390]\n
+0000006 Twig\Template->render() called at [/app/vendor/twig/twig/src/TemplateWrapper.php:45]\n
+0000007 Twig\TemplateWrapper->render() called at [/app/vendor/twig/twig/src/Environment.php:318]\n
+0000008 Twig\Environment->render() called at [/app/core/tests/Drupal/Tests/Core/Template/TwigSandboxTest.php:244]\n
+0000009 Drupal\Tests\Core\Template\TwigSandboxTest->testOverrideCollision() called at [/app/sites/simpletest/TestCase.php:1474]\n
+0000010 PHPUnit\Framework\TestCase->runTest() called at [/app/sites/simpletest/TestCase.php:1094]\n
+0000011 PHPUnit\Framework\TestCase->runBare() called at [/app/vendor/phpunit/phpunit/src/Framework/TestResult.php:703]\n
+0000012 PHPUnit\Framework\TestResult->run() called at [/app/sites/simpletest/TestCase.php:822]\n
+0000013 PHPUnit\Framework\TestCase->run() called at [/app/vendor/phpunit/phpunit/src/Framework/TestSuite.php:627]\n
+0000014 PHPUnit\Framework\TestSuite->run() called at [/app/vendor/phpunit/phpunit/src/Framework/TestSuite.php:627]\n
+0000015 PHPUnit\Framework\TestSuite->run() called at [/app/vendor/phpunit/phpunit/src/TextUI/TestRunner.php:656]\n
+0000016 PHPUnit\TextUI\TestRunner->doRun() called at [/app/vendor/phpunit/phpunit/src/TextUI/Command.php:235]\n
+0000017 PHPUnit\TextUI\Command->run() called at [/app/vendor/phpunit/phpunit/src/TextUI/Command.php:194]\n
+0000018 PHPUnit\TextUI\Command::main() called at [/app/vendor/phpunit/phpunit/phpunit:92]\n

neclimdul

2021-09-23 19:28

reporter   ~0006046

simplified test case
eval_segfault.php (104 bytes)   
<?php

class foo {
    function test() {
      xdebug_break();
    }
}

eval('(new foo)->test();');




eval_segfault.php (104 bytes)   

neclimdul

2021-09-23 19:55

reporter   ~0006047

Realized I'd seem something similar a while back doing weird things with prophecy mocks which lead me to work out a simplified test case for a similar crash in xdebug_dbgp_breakpoint
eval_segfault2.php (243 bytes)   
<?php

eval('
class foo {
  protected $foo = "bar";
  public function bar() {
    xdebug_break();
    echo $this->foo;
  }
}
');

$tmp = new class() extends foo {
  function baz() {
    // step into this.
    $this->bar();
  }
};
$tmp->baz();
eval_segfault2.php (243 bytes)   

neclimdul

2021-09-27 17:24

reporter   ~0006052

This has really been frying my brain trying to get failing on my ubuntu install. Digging in further though maybe I can give more info as to maybe why but this is getting out of my ability to debug.

I started stepping through the code more inside the alpine container. I was sort of following the wrong rabbit hole for a bit because on the latest code its actually failing on 389 and tmp_filename is null since its eval but we're in the wrong code branch.

So started digging in more, clearly check_evaled_code should not have let the code get here for the eval statement. cloned xdebug, built without optimizations and started stepping through and... no error. Everything ran cleanly without a segfault. Turned on -O2 and back to a segfault. O boy, the best sort of bugs, compiler optimizations.

So started digging into check_evaled_code and I can see this.

```
461 end_marker = ZSTR_VAL(filename_in) + ZSTR_LEN(filename_in) - strlen("eval()'d code");
(gdb) n
462 if (end_marker >= ZSTR_VAL(filename_in) && strcmp("eval()'d code", end_marker) == 0) {
(gdb) info locals
end_marker = 0x7f76c486e1ee "eval()'d code"
ei = 0x558b4d2cfa40
(gdb) p (int) strcmp("eval()'d code", end_marker)
$1 = 0
```

So the string comparison should work and it _seems_ like maybe the >= is being broken? Now, my C is a bit rusty so I'm drawing a blank on how that >= would behave with char* and what its trying to accomplish but it seems like its being optimized in some way that's breaking the expectation.

Since it seems like we're into compiler quirks, my ubuntu environment has gcc 10.3.0 and the alpine environment i'm testing this in is 9.3.0.

derick

2021-10-01 12:24

administrator   ~0006064

Hi,

I've tracked this down to a different cause that you stipulated, although I can see how you came to that conclusion.
Thanks for the short and succinct reproducible case.

PR is going to be on the way with a test case, and a fix for a different issue in a moment, and this will be part of 3.1.0.

cheers,
Derick

derick

2021-10-01 16:21

administrator   ~0006069

https://github.com/xdebug/xdebug/pull/791

Issue History

Date Modified Username Field Change
2021-09-23 19:14 neclimdul New Issue
2021-09-23 19:25 neclimdul Note Added: 0006045
2021-09-23 19:28 neclimdul Note Added: 0006046
2021-09-23 19:28 neclimdul File Added: eval_segfault.php
2021-09-23 19:55 neclimdul Note Added: 0006047
2021-09-23 19:55 neclimdul File Added: eval_segfault2.php
2021-09-27 17:24 neclimdul Note Added: 0006052
2021-10-01 12:24 derick Target Version => 3.1dev
2021-10-01 12:24 derick Summary Segmentation fault in return_stackframe => Segmentation fault due to NULL bytes in internal anonymous class names
2021-10-01 12:24 derick Note Added: 0006064
2021-10-01 16:21 derick Note Added: 0006069
2021-10-01 16:52 derick Assigned To => derick
2021-10-01 16:52 derick Status new => closed
2021-10-01 16:52 derick Resolution open => fixed
2021-10-01 16:52 derick Fixed in Version => 3.1dev
2021-10-04 09:29 derick Fixed in Version 3.1dev => 3.1.0