php.net |  support |  documentation |  report a bug |  advanced search |  search howto |  statistics |  random bug |  login
Request #80605 debug_backtrace line inconsistent, cannot trace object caller (/w example code)
Submitted: 2021-01-07 13:46 UTC Modified: 2021-01-09 12:53 UTC
From: ghbos at icloud dot com Assigned:
Status: Open Package: *General Issues
PHP Version: Irrelevant OS:
Private report: No CVE-ID: None
Have you experienced this issue?
Rate the importance of this bug to you:

 [2021-01-07 13:46 UTC] ghbos at icloud dot com
Description:
------------
Dear php colleagues

Every now and then a php developer dives deep into the darkest corners of php hacking away trying to do the impossible. Now I’ve done exactly this trying to use magic methods (__call/__callStatic) and debug_backtrace() to predict function call chain lengths by parsing debug file:line info. This "function call chain" endeavour has appealed to more developers judging from the records in the bug register (search debug_backtrace) but are mostly absent of a clear examples or feature suggestion/modification.

I’ve encountered three issues with debug_backtrace that once resolved, would vastly improve the usability of debug_backtrace for building applications.

debug_backtrace() “line” traces the line where a function call (by means of parentheses) ends.
1. TestObject::function(function(){
2.     return “foo”;
3. }); // <— debug_backtrace line ends up here for execution of “TestObject::function”

This works like a charm, except when using arrays as arguments (array() or []).
1. TestObject::function(array(
2.     "foo”, // <— debug_backtrace line ends up at the first item of the array
3.     “bar”,
4. )); // <— while it would be more consistent to end up here

SUGGESTION/BUG FIX: make debug_backtrace line information consistent when using arrays as arguments


debug_backtrace() furthermore is clear about where a function is executed providing a ‘line’ but not what.

If you would put all your code into a single line, debug_backtrace line information is useless tracing back to the same line for every function call.

FEATURE SUGGESTION: add the starting position of the function call (similar to strpos) in addition to the line information

1. foo(); bar(); TestObject::function(“baz”);

debug_backtrace then returns line: 1, col: 0 for foo()
debug_backtrace then returns line: 1, col: 6 for bar()
debug_backtrace then returns line: 1, col: 13 for TestObject::function(..)

Of course if the goal is to find out what was executed on a line, you can also include the entire function chain but maybe that’s a bit too luxurious?

debug_backtrace() does not allow you to “backtrace” local function variables used in the previous function call, similar to using get_defined_vars() locally.

I’ve encountered many situations where this might be useful since you don’t want to pass get_defined_vars() to every function when the function requires this (stackoverflow agrees).


Researching this feature ended up at xdebug that does include this option using xdebug.show_local_var = 1.


FEATURE SUGGESTION: add FLAG to debug_backtrace DEBUG_BACKTRACE_PROVIDE_LOCAL_VARS
This would include an array in the backtrace, similar to calling get_defined_vars() within the actual function.

Of course this would consume more memory but the limit should deal with that.



I believe these additions/modifications improve php, opening new doors for new ways of writing applications.



I’m curious to see the community’s response, and hopefully receive word of implementation plans.

Cheers, Gijs


Patches

Add a Patch

Pull Requests

Add a Pull Request

History

AllCommentsChangesGit/SVN commitsRelated reports
 [2021-01-09 12:53 UTC] ghbos at icloud dot com
-Summary: debug_backtrace inconsistent, major improvement suggestions +Summary: debug_backtrace line inconsistent, cannot trace object caller (/w example code)
 [2021-01-09 12:53 UTC] ghbos at icloud dot com
I've created a src and test file (phpunit) to illustrate the problem. Just copy, paste and execute tests!

FILE: DebugBacktraceExample.php (3 classes)

<?php

class TestObject {
    static $count = 0;

    public function _function(string $func, string $file = null, int $line = null) {
        return sprintf("%s:%s:%d", $func, basename($file), $line);
    }

    public function _whoIsCallingMe(string $func, string $file = null, int $line = null) {
        $i = -1; // Count calling occurences in line
        $line = trim(file($file)[$line - 1]); // Calling line
        $identity = ""; // Result

        // Extract function, then remove from line, until no longer possible
        while(($next = preg_match("/\\$([a-zA-Z0-9]+)->$func\(.*?\)/", $line, $matches)) !== false && $i !== self::$count) {
            $identity = $matches[1]; // Set as identity
            $line = str_replace($matches[0], "", $line); // Clear match
            $i++;
        }

        self::$count += 1; // Increase global counter

        return $identity;
    }

    public function __call($func, $args) {
        $args[1] = debug_backtrace()[0]["file"];
        $args[2] = debug_backtrace()[0]["line"];
        return call_user_func_array([$this, "_$func"], $args);
    }
}

class TestObjectCopy extends TestObject { }

class Imposter {
    public function whoIsCallingMe(string $func) {
        return "booh!";
    }
}


FILE: DebugBacktraceExampleTest.php (PHPUNIT)

<?php
use PHPUnit\Framework\TestCase;

final class DebugBacktraceExampleTest extends TestCase {
    # CASE(S): debug_backtrace line information is inconsistent for array input
    public function testFunction1() {
        $result = (new TestObject)->function(__FUNCTION__); // <- line goes here
        $expectation = "testFunction1:DebugBacktraceExampleTest.php:8";
        $this->assertEquals($expectation, $result);
    }

    public function testFunction2() {
        $result = (new TestObject)->function((function($func){
            return $func; 
        })(__FUNCTION__)); // <- line goes here
        $expectation = "testFunction3:DebugBacktraceExampleTest.php:15";
        $this->assertEquals($expectation, $result);
    }

    public function testFunctionArrayFailure() {
        $result = (new TestObject)->function(implode("", array(
            "", // <- line goes here ???
            __FUNCTION__
        ))); // <-- seems to be the right place?
        $expectation = "testFunctionArrayFailure:DebugBacktraceExampleTest.php:25"; // Fail
        $this->assertEquals($expectation, $result);
    }

    # GOAL: use debug_backtrace file:line information to identify what object calls the 'whoIsCallingMe' function
    # PROBLEM: whoIsCallingMe is called twice on the same line
    # SOLUTION: keep count of occurences already encountered in the same line (see TestObject::$count)
    public function testWhoIsCallingMe()
    {
        $testObject1 = new TestObject();
        $testObject2 = new TestObjectCopy();
        $result = $testObject1->whoIsCallingMe('whoIsCallingMe') . " - " . $testObject2->whoIsCallingMe('whoIsCallingMe');
        $expectation = "testObject1 - testObject2";
        $this->assertEquals($expectation, $result);
    }

    # GOAL: use debug_backtrace file:line information to identify what object calls the 'whoIsCallingMe' function
    # PROBLEM: debug_backtrace file:line cannot be used to identify the caller on a line unambiguously because we included an 'imposter' as illustrated below
    # SOLUTION: not possible ?
    # OPTION 1 (cheapest): add '(int) col' to debug_backtrace adding the (strpos) start position of the function call start
    # OPTION 2 (expensive): introduce DEBUG_BACKTRACE_PROVIDE_LOCAL_VARS flag to debug_backtrace, adding local vars to trace stack revealing key/values (similar to get_defined_vars()).
    public function testWhoIsCallingMeWithImposter()
    {
        $testObject1 = new TestObject();
        $testObject2 = new Imposter();
        $testObject3 = new TestObjectCopy();
        $result = $testObject1->whoIsCallingMe('whoIsCallingMe') . " - " . $testObject2->whoIsCallingMe('whoIsCallingMe') . " - " . $testObject3->whoIsCallingMe('whoIsCallingMe');
        $expectation = "testObject1 - booh! - testObject3"; // Fail, receives testObject1 - booh! - testObject2
        $this->assertEquals($expectation, $result);
    }

    protected function tearDown() : void 
    {
        TestObject::$count = 0; // Reset for tests testWhoIsCallingMe/testWhoIsCallingMeWithImposter
    }
}
 
PHP Copyright © 2001-2021 The PHP Group
All rights reserved.
Last updated: Sun Mar 07 07:01:23 2021 UTC