PHP trace with XDebug

Created by: gwideman, Nov 20, 2011 11:59 pm
Revised by: gwideman, Nov 22, 2011 8:41 pm (18 revisions)

Overview

Notes on using XDebug to capture a log containing a tractable call tree.
The task at hand is to capture the call activity of a PHP script run by Apache. Hence the development environment looks like this:
  • PHP IDE PhpStorm. Invokes...
    • Firefox, supplying specific URL, possibly including additional arguments that XDebug recognizes. Requests page from...
      • Local Apache web server, which invokes
        • PHP, which gets settings from php.ini
          • PHP loads and communicates with XDebug dll
            • XDebug
              • communicates with IDE via sockets
              • saves messages to log file
                • We want to capture call information to this log file.
Notes:
  • I may discover that capturing a suitable trace in the log file actually doesn't require the involvement of the IDE, and can perhaps be done without it.

Reference pages

XDebug settings and functions pertaining to logging

Settings to place in php.ini

NOTE: Restart Apache after changing php.ini to pick up new values.
Category
Setting
Values
Description






Log file
xdebug.trace_output_dir




xdebug.trace_output_name




xdebug.trace_options

1 = append to trace file if it exists. 0 (default) = overwrite






Select data per call
xdebug.collect_params

Non-zero = collect parameters passed to functions
  • 0 = None.
  • 1 = Type and number of elements (f.e. string(6), array(8)).
  • 2 = Type and number of elements, with a tool tip for the full information
  • 3 = Full variable contents (with limits set by xdebug.var_display_max_children, xdebug.var_display_max_data and xdebug.var_display_max_depth.)
  • 4 = Full variable contents and variable name.


xdebug.collect_return

1 = write return values to trace file. Default 0


xdebug.collect_vars

1 = analyze variables used in scope (slow).


xdebug.collect_assignments

1 = include variable assignments in execution traces






Format
xdebug.trace_format

  • 0 = human readable indented format. time index, memory usage, memory delta (xdebug.show_mem_delta=1), level, function name, function parameters (xdebug.collect_params=1), filename and line number.
  • 1 = computer readable format with different record type for enter stack frame and exit. See docs for fields.
    • File line 2 says "File format: 2", which seems incorrect
  • 2 = HTML format


xdebug.show_mem_delta

1 = show mem delta for each call






Behavior
xdebug.auto_trace

1 = enable trace just before script runs. Includes the auto_prepend_file


xdebug.trace_enable_trigger

1 = trigger trace using XDEBUG_TRACE GET/POST parameter, or set cookie XDEBUG_TRACE. To prevent Xdebug generating trace files for every request, set xdebug.auto_trace to 0.
(Could not get this to work. This setting doesn't seem to be used in the XDebug source code.)
Doh! See: [xdebug-general] Re: Is trace_enable_trigger defunct? Not implemented in Xdebug 2.1.2!






Limits
xdebug.var_display_max_depth

Max levels of array elements and object properties that are displayed in trace output. Default 3.


xdebug.var_display_max_data

Max string length for output of variables. Default 512.


xdebug.var_display_max_children

Max number of array children and object properties that are displayed in trace output. Default 128


























Functions to call from the subject php code

Category
Function
Description

ini_set()
Sets the value of a configuration option. I.e., substitute or override for settings in php.ini file. http://www.php.net/manual/en/function.ini-set.php

void xdebug_start_trace(
string trace_file_path
[, integer options] )
Start tracing at this line of code.
Trace file path is absolute, or relative to cwd. If no path given (empty string? No arg?) then xdebug uses setting xdebug.trace_output_dir.
options is a bitmap:
  • XDEBUG_TRACE_APPEND: 1 = append, 0 = overwrite
  • XDEBUG_TRACE_COMPUTERIZED:
    • 2 = Act as though xdebug.trace_format=1 (more elaborate format, but less human readable).
    • 0 = Simpler format
  • XDEBUG_TRACE_HTML: 4 = Output HTML table. 0 = output ordinary text




void xdebug_stop_trace()
Stop tracing and close output file.




string xdebug_get_tracefile_name()
Get name of output file. Useful in conjunction with xdebug.auto_trace, apparently.



Data display functions

Are these relevant? Where does their output go?

xdebug_var_dump()


xdebug.show_local_vars

Arguments to send via the URL

Supposedly, appending the parameter XDEBUG_TRACE to the URL should trigger the trace (if php.ini setting xdebug.trace_enable_trigger=1.
Examples I tried:
This is because this functionality was missing from Xdebug 2.1.2; not implemented until Xdebug 2.2.

What worked

To invoke trace and create trace file

Bracketing the code in index.php with:
xdebug_start_trace(); // no args needed</span>
[...]
xdebug_stop_trace();

Is IDE needed?

No, tracing can be invoked without the an IDE being involved

Examination of trace file formats

XDebug outputs different formats and fields depending on values of settings.
Setting
Value tested
Description
xdebug.trace_format
0 and 1 tested
0=indented or 1="computer" are useful
xdebug.collect_params
4
1..4 give increasing amount of info
xdebug.collect_return
1
1 for return value (and include it on separate line)
xdebug.collect_vars
1?
to have xdebug figure out variable names (is this needed for collect_params=4 names?)
xdebug.show_mem_delta
1
to show memory increase or decrease
xdebug.collect_assignments
0
1 = additional lines for assignment statements

But I need a proper accounting of fields presented in the most informative formats. Here's my survey of columns actually produced.

Data
format=0
format=1
Comment
Call





Call level
Indent level
Col 1


Call number
(not explicit)
Col 2
For reconciling records (lines) for call and return

Call vs return
-
Col 3
Call =0, Ret = 1

Delta time
Col 1
Col 4


Memory
Col 2
Col 5


Delta memory
Col 3
-


"->"
Col 4
-
Indicates call

Statement
Col 5 (incl spaces)
-
Format like PHP syntax, function(args and values)

Function name
-
Col 6
Just the function name

Builtin vs User func
(Not avail)
Col 7
0 = builtin; 1 = user function

Source file path:line
Col 6
-


Source file path

Col 8


Line num

Col 9


List of args
(included in Statement)
Col 10...n
List of items like
  • var = value
  • array(index => value...)
  • just value (builtin funcs)





Return





Call level
Indent level
Col 1


Call number
(not explicit)
Col 2
For reconciling records (lines) for call and return

Call vs return
-
Col 3
Call =0, Ret = 1

Delta time
-
Col 4


Memory
-
Col 5


Delta memory
-
-


">=>"
Col 1
-
Indicates return

Return value
Col 2
(Not avail)
Format 1 doesn't show return value





Conclusions:
  • Unless "computer style" output (format=1) is fixed, my trace analyzer program would have to use format=0 in order to include return value.
  • The format=0 output lacks a field that explicitly distinguishes between built-in function and user function. However, that can be deduced from whether or not the immediately following record is a return record. So looks like format=0 is the target for analysis tools.