Req #80605 [Opn]: debug_backtrace line inconsistent, cannot trace object caller (/w example code)

From: Date: Sat, 09 Jan 2021 12:53:45 +0000
Subject: Req #80605 [Opn]: debug_backtrace line inconsistent, cannot trace object caller (/w example code)
References: 1  Groups: php.bugs 
Request: Send a blank email to php-bugs+get-231462@lists.php.net to get a copy of this message
Edit report at https://bugs.php.net/bug.php?id=80605&edit=1 ID: 80605 User updated by: ghbos at icloud dot com Reported by: ghbos at icloud dot com -Summary: debug_backtrace inconsistent, major improvement suggestions +Summary: debug_backtrace line inconsistent, cannot trace object caller (/w example code) Status: Open Type: Feature/Change Request Package: *General Issues PHP Version: Irrelevant Block user comment: N Private report: N New Comment: 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 } } Previous Comments: ------------------------------------------------------------------------ [2021-01-07 13:46:48] 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 ------------------------------------------------------------------------ -- Edit this bug report at https://bugs.php.net/bug.php?id=80605&edit=1

« previous php.bugs (#231462) next »