View Issue Details

IDProjectCategoryView StatusLast Update
0001778XdebugStacktracespublic2020-05-02 09:25
Reporterflip101Assigned Toderick 
PrioritynormalSeveritymajorReproducibilityalways
Status assignedResolutionopen 
Platform64OSUbuntuOS Version19.10
Product Version2.9.3 
Target VersionFixed in Version 
Summary0001778: Running xdebug with php built in php server does not give always give trace file
Descriptionxdebug does not always seem to generate a trace file with use of built-in php server.

Zend Engine v3.4.0, Copyright (c) Zend Technologies
    with Zend OPcache v7.4.4, Copyright (c), by Zend Technologies
    with Xdebug v2.9.3, Copyright (c) 2002-2020, by Derick Rethans
Steps To ReproduceDownload phpBB 3.3.0 from https://download.phpbb.com/pub/release/3.3/3.3.0/phpBB-3.3.0.zip

Have two tabs open in browser:
* main site (user facing)
* admin panel

Open web developer tools request tab

Refresh user page, observe that two trace files are generated:
* 3.4 MB starting on index.php
* 1.8 MB starting on app.php

No request to app.php can be seen from the web developer tools. Maybe code started in `index.php` does `exec()`. Don't know what is going on here. Anyway on to the actual bug ..

Refresh admin page, no trace file is generated. <-- actual bug
Additional Informationxdebug.auto_trace = true
xdebug.collect_assignments = true
xdebug.collect_params = 4
xdebug.collect_return = true
xdebug.trace_format = 2
xdebug.trace_output_dir = .
xdebug.trace_output_name = trace.%u_%c


Server started with:
php -S localhost:8002 --php-ini php.ini

attached file php.ini in phpBB3 project directory. Confirmed this php.ini was loaded by putting phpinfo() call in index.php script temporarily
Tagstrace
Operating SystemUbuntu 19.10 64 bits
PHP Version7.4.0-7.4.4

Activities

flip101

2020-04-13 16:54

reporter  

php.ini (72,712 bytes)
trace.1586795796_559915_2119121762.xt (3,416,983 bytes)
trace.1586795796_799767_2119121762.xt (1,746,652 bytes)

flip101

2020-04-13 19:26

reporter   ~0005383

xdebug does generate the trace file. What i observed was probably caused by setting `xdebug.trace_output_dir` to `.`. I assume now one of the three following situations:

1. the `.` directory does not get resolved on script start but represents the current working directory of the scripts (which can be changed in the script)
2. the php script starts another instance of php ... i find this a bit unlikely because it would be hard to pass variables. But at the moment i have no other way to explain the double trace files.
3. the webserver does not hit a frontcontroller explicitly but looks up scripts from their perspective directory, which it also sets `.`

In the case of phpBB3 the admin panel trace files can be found under `adm`.

I was expecting `.` to refer to the directory where from the php built in webserver was starting from.

I don't regard this as a code bug in xdebug now. Possibly an opportunity to explain this somewhere in the documentation of xdebug.

I don't see how i can close this bug (as on github).

derick

2020-04-13 19:44

administrator   ~0005384

It'd be curious to see why this actually happens... If you don't mind trying to following! Instead of starting just "php -S", can you start it under strace?

Like:

strace -ff -o /tmp/strace.log php -S localhost:8002 --php-ini php.ini

And then provide the /tmp/strace.log.* files as an attachment?

I'm pretty sure that your guess "1" is not correct, but both 2 and 3 are possible, and the strace log file might give a hint.

If you don't care enough, let me know, and I'll just close the report.

cheers,
Derick

flip101

2020-04-14 15:02

reporter   ~0005386

I'm getting a segfault at the moment

zend_extension = /home/flip101/php/php-src_7.4.4/install/lib/php/extensions/debug-non-zts-20190902/xdebug.so

[xdebug]
xdebug.auto_trace = true
xdebug.collect_assignments = true
xdebug.collect_params = 5
xdebug.collect_return = true
xdebug.trace_format = 0
xdebug.trace_output_dir = /home/flip101/php/phpBB3/dumps
xdebug.trace_output_name = trace.%p

# also tried the default by not setting the next line
xdebug.max_nesting_level = 2048

traces-17250-1586875723.tar.xz (442,244 bytes)

flip101

2020-04-14 15:03

reporter   ~0005387

By the way ... i shortened the paths in the trace files to reduce clutter. They don't really match the config i just posted, but you can see in the file that i got the traces.

derick

2020-04-16 10:59

administrator   ~0005392

If you look at the trace file, you'll see that (for example line 4646) the __sleep method keeps calling itself. It seems that this is because Xdebug tries to serialize a variable, but while doing that, it calls __sleep, which then causes Xdebug to try to serialise that same variable, over and over again:

#37427 0x00005603b6c17026 in php_var_serialize_call_sleep (retval=0x7ffd45de9c50, struc=0x7ffd45de9c60) at /php-7.4.4/ext/standard/var.c:729
#37428 0x00005603b6c18446 in php_var_serialize_intern (buf=0x7ffd45dea140, struc=0x5603b90f6118, var_hash=0x7f058268e480) at /php-7.4.4/ext/standard/var.c:1077
#37429 0x00005603b6c186c6 in php_var_serialize (buf=0x7ffd45dea140, struc=0x5603b90f6118, data=0x7ffd45dea118) at /php-7.4.4/ext/standard/var.c:1123
#37430 0x00007f0586f50100 in xdebug_get_zval_value_serialized (val=0x5603b90f6118, debug_zval=0, options=0x0) at /php-7.4.4/xdebug-2.9.4/src/lib/var_export_serialized.c:42
#37431 0x00007f0586f73da9 in add_single_value (str=0x7ffd45dea200, zv=0x5603b90f6118, collection_level=5) at /php-7.4.4/xdebug-2.9.4/src/tracing/trace_textual.c:109
#37432 0x00007f0586f7422a in xdebug_trace_textual_function_entry (ctxt=0x5603b90d37a0, fse=0x5603b90f5620, function_nr=1899) at /php-7.4.4/xdebug-2.9.4/src/tracing/trace_textual.c:178
#37433 0x00007f0586f77679 in xdebug_tracing_execute_internal (function_nr=1899, fse=0x5603b90f5620) at /php-7.4.4/xdebug-2.9.4/src/tracing/tracing.c:783
#37434 0x00007f0586f3cdc8 in xdebug_execute_internal (current_execute_data=0x7f0587018b70, return_value=0x7f0587018b40) at /php-7.4.4/xdebug-2.9.4/src/base/base.c:449
#37435 0x00005603b6e0c08e in ZEND_DO_FCALL_SPEC_RETVAL_USED_HANDLER () at /php-7.4.4/Zend/zend_vm_execute.h:1732
#37436 0x00005603b6e0f12c in ZEND_USER_OPCODE_SPEC_HANDLER () at /php-7.4.4/Zend/zend_vm_execute.h:2647
#37437 0x00005603b6e71f87 in execute_ex (ex=0x7f0587018aa0) at /php-7.4.4/Zend/zend_vm_execute.h:53893
#37438 0x00007f0586f3cacc in xdebug_execute_ex (execute_data=0x7f0587018aa0) at /php-7.4.4/xdebug-2.9.4/src/base/base.c:380
#37439 0x00005603b6d7d155 in zend_call_function (fci=0x7ffd45dea660, fci_cache=0x7ffd45dea580) at /php-7.4.4/Zend/zend_execute_API.c:812
#37440 0x00005603b6d7c6a7 in _call_user_function_ex (object=0x7ffd45dea7c0, function_name=0x7ffd45dea6e0, retval_ptr=0x7ffd45dea7b0, param_count=0, params=0x0, no_separation=1) at /php-7.4.4/Zend/zend_execute_API.c:644
#37441 0x00005603b6c17026 in php_var_serialize_call_sleep (retval=0x7ffd45dea7b0, struc=0x7ffd45dea7c0) at /php-7.4.4/ext/standard/var.c:729
#37442 0x00005603b6c18446 in php_var_serialize_intern (buf=0x7ffd45deaca0, struc=0x5603b90f5980, var_hash=0x7f058268e6c0) at /php-7.4.4/ext/standard/var.c:1077
#37443 0x00005603b6c186c6 in php_var_serialize (buf=0x7ffd45deaca0, struc=0x5603b90f5980, data=0x7ffd45deac78) at /php-7.4.4/ext/standard/var.c:1123
#37444 0x00007f0586f50100 in xdebug_get_zval_value_serialized (val=0x5603b90f5980, debug_zval=0, options=0x0) at /php-7.4.4/xdebug-2.9.4/src/lib/var_export_serialized.c:42
#37445 0x00007f0586f73da9 in add_single_value (str=0x7ffd45dead60, zv=0x5603b90f5980, collection_level=5) at /php-7.4.4/xdebug-2.9.4/src/tracing/trace_textual.c:109
#37446 0x00007f0586f7422a in xdebug_trace_textual_function_entry (ctxt=0x5603b90d37a0, fse=0x5603b90f4970, function_nr=1897) at /php-7.4.4/xdebug-2.9.4/src/tracing/trace_textual.c:178
#37447 0x00007f0586f7746a in xdebug_tracing_execute_ex (function_nr=1897, fse=0x5603b90f4970) at /php-7.4.4/xdebug-2.9.4/src/tracing/tracing.c:744
#37448 0x00007f0586f3c92d in xdebug_execute_ex (execute_data=0x7f0587018a30) at /php-7.4.4/xdebug-2.9.4/src/base/base.c:338


This causes infinite recursion that then causes a crash.

If we can extract the code from /phpBB3/cache/production/container_4335734bbdd20f586549a504dff5f80c.ph (around line 4627) into something simpler, I might figure out what is the problem without having to debug all of phpbb.

derick

2020-04-30 09:53

administrator   ~0005409

My last comment sort of hinted at wondering whether you can simplify that code, as I am not familiar at all with phpBB3.

flip101

2020-05-02 09:25

reporter   ~0005410

I'm also not familiar with xdebug. I dove straight into xdebug to figure out how phpBB3 works but i didn't get far.

Issue History

Date Modified Username Field Change
2020-04-13 16:54 flip101 New Issue
2020-04-13 16:54 flip101 Tag Attached: trace
2020-04-13 16:54 flip101 File Added: php.ini
2020-04-13 16:54 flip101 File Added: trace.1586795796_559915_2119121762.xt
2020-04-13 16:54 flip101 File Added: trace.1586795796_799767_2119121762.xt
2020-04-13 19:26 flip101 Note Added: 0005383
2020-04-13 19:44 derick Assigned To => derick
2020-04-13 19:44 derick Status new => feedback
2020-04-13 19:44 derick Note Added: 0005384
2020-04-14 15:02 flip101 File Added: traces-17250-1586875723.tar.xz
2020-04-14 15:02 flip101 Note Added: 0005386
2020-04-14 15:02 flip101 Status feedback => assigned
2020-04-14 15:03 flip101 Note Added: 0005387
2020-04-16 10:59 derick Status assigned => feedback
2020-04-16 10:59 derick Note Added: 0005392
2020-04-30 09:53 derick Note Added: 0005409
2020-05-02 09:25 flip101 Note Added: 0005410
2020-05-02 09:25 flip101 Status feedback => assigned