php.net |  support |  documentation |  report a bug |  advanced search |  search howto |  statistics |  random bug |  login
Bug #70188 debug_backtrace + register_tick_function do not always work
Submitted: 2015-08-03 12:11 UTC Modified: 2015-08-03 17:54 UTC
From: emilio dot pinn at gmail dot com Assigned: cmb (profile)
Status: Not a bug Package: *General Issues
PHP Version: Irrelevant OS: Ubuntu
Private report: No CVE-ID: None
View Add Comment Developer Edit
Welcome! If you don't have a Git account, you can't do anything here.
You can add a comment by following this link or if you reported this bug, you can edit this bug over here.
(description)
Block user comment
Status: Assign to:
Package:
Bug Type:
Summary:
From: emilio dot pinn at gmail dot com
New email:
PHP Version: OS:

 

 [2015-08-03 12:11 UTC] emilio dot pinn at gmail dot com
Description:
------------
The following simple profiling script does not work on certain codes, e.g. with the vanilla installation of Joomla v3.4.2. It works with other complex CMS e.g. with WordPress.

To easily prepend the profiling PHP script to the application, I used 

php_value auto_prepend_file "/tmp/instrumentation.php"

In the .htaccess in the web root. Then, paste the test script in "/tmp/instrumentation.php". The output you can see in "/var/log/apache2/error.log" is just a series of "NO BACKTRACE" strings.

PHP version; PHP 5.5.9-1ubuntu4.11 (cli) (built: Jul  2 2015 15:23:08) 

Test script:
---------------
<?php
function printname() {
  $bt = debug_backtrace();
  if (count($bt) <= 1) {
    error_log('NO BACKTRACE: ' . print_r($bt, true));
  }
  else {
    error_log('FUNCTION NAME: ' . $bt[1]['function']);
  }
}

declare(ticks=1);
register_tick_function('printname');
?>

Expected result:
----------------
I expect a result like the following when I open the "/var/log/apache2/error.log"

[:error] [pid 9091] [client 127.0.0.1:55726] FUNCTION NAME: function1
[:error] [pid 9091] [client 127.0.0.1:55726] FUNCTION NAME: function2
[:error] [pid 9091] [client 127.0.0.1:55726] FUNCTION NAME: function3
[:error] [pid 9091] [client 127.0.0.1:55726] FUNCTION NAME: function4
...


As this happens using the same test script with other code.



Actual result:
--------------
[:error] [pid 7555] [client 127.0.0.1:55742] NO BACKTRACE: Array\n(\n    [0] => Array\n        (\n            [file] => /tmp/instrumentation.php\n            [line] => 14\n            [function] => printname\n            [args] => Array\n                (\n                )\n\n        )\n\n)
[:error] [pid 7555] [client 127.0.0.1:55742] NO BACKTRACE: Array\n(\n    [0] => Array\n        (\n            [file] => /tmp/instrumentation.php\n            [line] => 16\n            [function] => printname\n            [args] => Array\n                (\n                )\n\n        )\n\n)

Patches

Add a Patch

Pull Requests

Add a Pull Request

History

AllCommentsChangesGit/SVN commitsRelated reports
 [2015-08-03 12:51 UTC] cmb@php.net
-Status: Open +Status: Not a bug -Assigned To: +Assigned To: cmb
 [2015-08-03 12:51 UTC] cmb@php.net
Sorry, but your problem does not imply a bug in PHP itself.  For a
list of more appropriate places to ask for help using PHP, please
visit http://www.php.net/support.php as this bug system is not the
appropriate forum for asking support questions.  Due to the volume
of reports we can not explain in detail here why your report is not
a bug.  The support channels will be able to provide an explanation
for you.

Thank you for your interest in PHP.

If there is only a single stack frame, debug_backtrace() is
supposed to return an array with a single element. Change
`count($bt) <= 1` to `count($bt) < 1` or `empty($bt)`.
 [2015-08-03 12:57 UTC] emilio dot pinn at gmail dot com
Hi, thanks for your prompt response.

The very strange behaviour is that in the conditions I described, debug_backtrace() returns just a single element backtrace, instead of the complete backtrace of any invoked functions. I can't understand why this strange behaviour.
 [2015-08-03 13:41 UTC] cmb@php.net
-Status: Not a bug +Status: Feedback
 [2015-08-03 13:41 UTC] cmb@php.net
On further consideration the behavior is somewhat strange. Anyhow,
to properly diagnose the problem, we need a short but complete
example script to be able to reproduce this bug ourselves. 

A proper reproducing script starts with <?php, is max. 10-20 lines
long and does not require any external resources such as
databases, etc. If the script requires a database to demonstrate
the issue, please make sure it creates all necessary tables,
stored procedures etc.

Please avoid embedding huge scripts into the report.
 [2015-08-03 15:26 UTC] emilio dot pinn at gmail dot com
-Status: Feedback +Status: Assigned
 [2015-08-03 15:26 UTC] emilio dot pinn at gmail dot com
Hello,

The test script is already included in the bug ticket, you have just to include it at every requests done to a joomla installation e.g. using "php_value auto_prepend_file" option in its .htaccess file. 

Let me know if you need any further information.
 [2015-08-03 16:58 UTC] cmb@php.net
-Status: Assigned +Status: Open -Assigned To: cmb +Assigned To:
 [2015-08-03 16:58 UTC] cmb@php.net
I can't reproduce the described behavior with Joomla 3.4.3. A
single request to the home page (front-end) causes a 1.5 MB log
file to be generated, which contains 24652 FUNCTION NAME and only
14 NO BACKTRACE messages.
 [2015-08-03 17:51 UTC] emilio dot pinn at gmail dot com
-Status: Open +Status: Closed
 [2015-08-03 17:51 UTC] emilio dot pinn at gmail dot com
I update the system and now it works. Please kill this, and thanks for your support.
 [2015-08-03 17:54 UTC] cmb@php.net
-Status: Closed +Status: Not a bug -Assigned To: +Assigned To: cmb
 
PHP Copyright © 2001-2024 The PHP Group
All rights reserved.
Last updated: Sun May 19 02:01:35 2024 UTC