当前位置: 首页 > 文档资料 > xdebug 中文文档 >

Function Trace

优质
小牛编辑
126浏览
2023-12-01

Xdebug allows you to log all function calls, including parameters and return values to a file in different formats.

Those so-called "function traces" can be a help for when you are new to an application or when you are trying to figure out what exactly is going on when your application is running. The function traces can optionally also show the values of variables passed to the functions and methods, and also return values. In the default traces those two elements are not available.

Output Formats

There are three output formats. One is meant as a human readable trace, another one is more suited for computer programs as it is easier to parse, and the last one uses HTML for formatting the trace. You can switch between the two different formats with the xdebug.trace_format setting. There are a few settings that control which information is written to the trace files. There are settings for including variables (xdebug.collect_params) and for including return VALUES (NULL, ": ", ret_ord( $char ), "\n";
}
?>

The Results

Below are the results with different settings of the xdebug.collect_params setting. As this is not a web environment the value of 2 does not have any meaning as tool tips don't work in text files.

TRACE START [2007-05-06 14:37:06]
    0.0003     114112   -> {main}() ../trace.php:0
    0.0004     114272     -> str_split() ../trace.php:8
    0.0153     117424     -> ret_ord() ../trace.php:10
    0.0165     117584       -> ord() ../trace.php:5
    0.0166     117584     -> ret_ord() ../trace.php:10
    0.0167     117584       -> ord() ../trace.php:5
    0.0168     117584     -> ret_ord() ../trace.php:10
    0.0168     117584       -> ord() ../trace.php:5
    0.0170     117584     -> ret_ord() ../trace.php:10
    0.0170     117584       -> ord() ../trace.php:5
    0.0172     117584     -> ret_ord() ../trace.php:10
    0.0172     117584       -> ord() ../trace.php:5
    0.0173     117584     -> ret_ord() ../trace.php:10
    0.0174     117584       -> ord() ../trace.php:5
    0.0177      41152
TRACE END   [2007-05-06 14:37:07]
TRACE START [2007-05-06 14:37:11]
    0.0003     114112   -> {main}() ../trace.php:0
    0.0004     114272     -> str_split(string(6)) ../trace.php:8
    0.0007     117424     -> ret_ord(string(1)) ../trace.php:10
    0.0007     117584       -> ord(string(1)) ../trace.php:5
    0.0009     117584     -> ret_ord(string(1)) ../trace.php:10
    0.0009     117584       -> ord(string(1)) ../trace.php:5
    0.0010     117584     -> ret_ord(string(1)) ../trace.php:10
    0.0011     117584       -> ord(string(1)) ../trace.php:5
    0.0012     117584     -> ret_ord(string(1)) ../trace.php:10
    0.0013     117584       -> ord(string(1)) ../trace.php:5
    0.0014     117584     -> ret_ord(string(1)) ../trace.php:10
    0.0014     117584       -> ord(string(1)) ../trace.php:5
    0.0016     117584     -> ret_ord(string(1)) ../trace.php:10
    0.0016     117584       -> ord(string(1)) ../trace.php:5
    0.0019      41152
TRACE END   [2007-05-06 14:37:11]
TRACE START [2007-05-06 14:37:13]
    0.0003     114112   -> {main}() ../trace.php:0
    0.0004     114272     -> str_split('Xdebug') ../trace.php:8
    0.0007     117424     -> ret_ord('X') ../trace.php:10
    0.0007     117584       -> ord('X') ../trace.php:5
    0.0009     117584     -> ret_ord('d') ../trace.php:10
    0.0009     117584       -> ord('d') ../trace.php:5
    0.0010     117584     -> ret_ord('e') ../trace.php:10
    0.0011     117584       -> ord('e') ../trace.php:5
    0.0012     117584     -> ret_ord('b') ../trace.php:10
    0.0013     117584       -> ord('b') ../trace.php:5
    0.0014     117584     -> ret_ord('u') ../trace.php:10
    0.0014     117584       -> ord('u') ../trace.php:5
    0.0016     117584     -> ret_ord('g') ../trace.php:10
    0.0016     117584       -> ord('g') ../trace.php:5
    0.0019      41152
TRACE END   [2007-05-06 14:37:13]
TRACE START [2007-05-06 14:37:16]
    0.0003     114112   -> {main}() ../trace.php:0
    0.0004     114272     -> str_split('Xdebug') ../trace.php:8
    0.0007     117424     -> ret_ord($c = 'X') ../trace.php:10
    0.0007     117584       -> ord('X') ../trace.php:5
    0.0009     117584     -> ret_ord($c = 'd') ../trace.php:10
    0.0009     117584       -> ord('d') ../trace.php:5
    0.0010     117584     -> ret_ord($c = 'e') ../trace.php:10
    0.0011     117584       -> ord('e') ../trace.php:5
    0.0012     117584     -> ret_ord($c = 'b') ../trace.php:10
    0.0013     117584       -> ord('b') ../trace.php:5
    0.0014     117584     -> ret_ord($c = 'u') ../trace.php:10
    0.0014     117584       -> ord('u') ../trace.php:5
    0.0016     117584     -> ret_ord($c = 'g') ../trace.php:10
    0.0016     117584       -> ord('g') ../trace.php:5
    0.0019      41152
TRACE END   [2007-05-06 14:37:16]

Besides the xdebug.collect_params settings there is another number of settings that affect the output of trace files. The first tab "default" shows the same as the default as above. The second tab "show_mem_delta=1" also shows the memory usage difference between two different lines in the output file.

On the "collect_return=1" tab the return values of all the function calls are also visible. This you turn on with the xdebug.collect_return setting.

The tab called "collect_assignments=1" shows variable assignments, which can be turned on with the xdebug.collect_assignments setting.

The last tab shows a different output format that is much easier to parse, but harder to read. The xdebug.trace_format setting is therefore mostly useful if there is an additional tool to interpret the trace files.

TRACE START [2007-05-06 14:37:06]
    0.0003     114112   -> {main}() ../trace.php:0
    0.0004     114272     -> str_split() ../trace.php:8
    0.0153     117424     -> ret_ord() ../trace.php:10
    0.0165     117584       -> ord() ../trace.php:5
    0.0166     117584     -> ret_ord() ../trace.php:10
    0.0167     117584       -> ord() ../trace.php:5
    0.0168     117584     -> ret_ord() ../trace.php:10
    0.0168     117584       -> ord() ../trace.php:5
    0.0170     117584     -> ret_ord() ../trace.php:10
    0.0170     117584       -> ord() ../trace.php:5
    0.0172     117584     -> ret_ord() ../trace.php:10
    0.0172     117584       -> ord() ../trace.php:5
    0.0173     117584     -> ret_ord() ../trace.php:10
    0.0174     117584       -> ord() ../trace.php:5
    0.0177      41152
TRACE END   [2007-05-06 14:37:07]
TRACE START [2007-05-06 14:37:26]
    0.0003     114112  +114112   -> {main}() ../trace.php:0
    0.0004     114272     +160     -> str_split('Xdebug') ../trace.php:8
    0.0007     117424    +3152     -> ret_ord($c = 'X') ../trace.php:10
    0.0007     117584     +160       -> ord('X') ../trace.php:5
    0.0009     117584       +0     -> ret_ord($c = 'd') ../trace.php:10
    0.0009     117584       +0       -> ord('d') ../trace.php:5
    0.0011     117584       +0     -> ret_ord($c = 'e') ../trace.php:10
    0.0011     117584       +0       -> ord('e') ../trace.php:5
    0.0013     117584       +0     -> ret_ord($c = 'b') ../trace.php:10
    0.0013     117584       +0       -> ord('b') ../trace.php:5
    0.0014     117584       +0     -> ret_ord($c = 'u') ../trace.php:10
    0.0015     117584       +0       -> ord('u') ../trace.php:5
    0.0016     117584       +0     -> ret_ord($c = 'g') ../trace.php:10
    0.0017     117584       +0       -> ord('g') ../trace.php:5
    0.0019      41152
TRACE END   [2007-05-06 14:37:26]
TRACE START [2007-05-06 14:37:35]
    0.0003     114112   -> {main}() ../trace.php:0
    0.0004     114272     -> str_split('Xdebug') ../trace.php:8
                          >=> array (0 => 'X', 1 => 'd', 2 => 'e', 3 => 'b', 4 => 'u', 5 => 'g')
    0.0007     117424     -> ret_ord($c = 'X') ../trace.php:10
    0.0007     117584       -> ord('X') ../trace.php:5
                            >=> 88
                          >=> 88
    0.0009     117584     -> ret_ord($c = 'd') ../trace.php:10
    0.0009     117584       -> ord('d') ../trace.php:5
                            >=> 100
                          >=> 100
    0.0011     117584     -> ret_ord($c = 'e') ../trace.php:10
    0.0011     117584       -> ord('e') ../trace.php:5
                            >=> 101
                          >=> 101
    0.0013     117584     -> ret_ord($c = 'b') ../trace.php:10
    0.0013     117584       -> ord('b') ../trace.php:5
                            >=> 98
                          >=> 98
    0.0015     117584     -> ret_ord($c = 'u') ../trace.php:10
    0.0016     117584       -> ord('u') ../trace.php:5
                            >=> 117
                          >=> 117
    0.0017     117584     -> ret_ord($c = 'g') ../trace.php:10
    0.0018     117584       -> ord('g') ../trace.php:5
                            >=> 103
                          >=> 103
                        >=> 1
    0.0021      41152
TRACE END   [2007-05-06 14:37:35]
Version: 2.0.0RC4-dev
TRACE START [2007-05-06 18:29:01]
1	0	0	0.010870	114112	{main}	1	../trace.php	0
2	1	0	0.032009	114272	str_split	0	../trace.php	8
2	1	1	0.032073	116632
2	2	0	0.033505	117424	ret_ord	1	../trace.php	10
3	3	0	0.033531	117584	ord	0	../trace.php	5
3	3	1	0.033551	117584
2	2	1	0.033567	117584
2	4	0	0.033718	117584	ret_ord	1	../trace.php	10
3	5	0	0.033740	117584	ord	0	../trace.php	5
3	5	1	0.033758	117584
2	4	1	0.033770	117584
2	6	0	0.033914	117584	ret_ord	1	../trace.php	10
3	7	0	0.033936	117584	ord	0	../trace.php	5
3	7	1	0.033953	117584
2	6	1	0.033965	117584
2	8	0	0.034108	117584	ret_ord	1	../trace.php	10
3	9	0	0.034130	117584	ord	0	../trace.php	5
3	9	1	0.034147	117584
2	8	1	0.034160	117584
2	10	0	0.034302	117584	ret_ord	1	../trace.php	10
3	11	0	0.034325	117584	ord	0	../trace.php	5
3	11	1	0.034342	117584
2	10	1	0.034354	117584
2	12	0	0.034497	117584	ret_ord	1	../trace.php	10
3	13	0	0.034519	117584	ord	0	../trace.php	5
3	13	1	0.034536	117584
2	12	1	0.034549	117584
1	0	1	0.034636	117584
TRACE END   [2007-05-06 18:29:01]

VIM syntax file

Xdebug ships with a VIM syntax file that syntax highlights the trace files: xt.vim. In order to make VIM recognise this new format you need to perform the following steps:

  1. Copy the xt.vim file to ~/.vim/syntax
  2. Edit, or create, ~/.vim/filetype.vim and add the following lines:
    augroup filetypedetect
    au BufNewFile,BufRead *.xt  setf xt
    augroup END
    

With those settings made an opened trace file looks like:

TRACE START [2007-05-15 20:06:02]
    0.0003     115208   -> {main}() ../trace.php:0
    0.0004     115368     -> str_split() ../trace.php:8
    0.0006     118520     -> ret_ord() ../trace.php:10
    0.0007     118680       -> ord() ../trace.php:5
    0.0008     118680     -> ret_ord() ../trace.php:10
    0.0009     118680       -> ord() ../trace.php:5
    0.0010     118680     -> ret_ord() ../trace.php:10
    0.0010     118680       -> ord() ../trace.php:5
    0.0012     118680     -> ret_ord() ../trace.php:10
    0.0012     118680       -> ord() ../trace.php:5
    0.0014     118680     -> ret_ord() ../trace.php:10
    0.0014     118680       -> ord() ../trace.php:5
    0.0016     118680     -> ret_ord() ../trace.php:10
    0.0016     118680       -> ord() ../trace.php:5
    0.0019      54880
TRACE END   [2007-05-15 20:06:02]

Folding also sorta works so you can use zc and zo to fold away parts of the trace files.

Related Settings and Functions

Settings


boolean xdebug.auto_trace = false #

When this setting is set to on, the tracing of function calls will be enabled just before the script is run. This makes it possible to trace code in the auto_prepend_file.


boolean xdebug.collect_assignments = false #

Introduced in Xdebug >= 2.1

This setting, defaulting to 0, controls whether Xdebug should add variable assignments to function traces. Assign-by-var (=&) assignments are included too.


boolean xdebug.collect_includes = true #

This setting, defaulting to 1, controls whether Xdebug should write the filename used in include(), include_once(), require() or require_once() to the trace files.


integer xdebug.collect_params = 0 #

This setting, defaulting to 0, controls whether Xdebug should collect the parameters passed to functions when a function call is recorded in either the function trace or the stack trace.

The setting defaults to 0 because for very large scripts it may use huge amounts of memory and therefore make it impossible for the huge script to run. You can most safely turn this setting on, but you can expect some problems in scripts with a lot of function calls and/or huge data structures as parameters. Xdebug 2 will not have this problem with increased memory usage, as it will never store this information in memory. Instead it will only be written to disk. This means that you need to have a look at the disk usage though.

This setting can have four different values. For each of the values a different amount of information is shown. Below you will see what information each of the values provides. See also the introduction of the feature Stack Traces for a few screenshots.

ValueArgument Information Shown
0None.
1Type and number of elements (f.e. string(6), array(8)).
2

Type and number of elements, with a tool tip for the full information 1.

3Full variable contents (with the limits respected as set by xdebug.var_display_max_children, xdebug.var_display_max_data and xdebug.var_display_max_depth.
4Full variable contents and variable name.
5PHP serialized variable contents, without the name.

1 in the CLI version of PHP it will not have the tool tip, nor in output files.


boolean xdebug.collect_return = false #

This setting, defaulting to 0, controls whether Xdebug should write the return value of function calls to the trace files.


integer xdebug.show_mem_delta = 0 #

When this setting is set to something != 0 Xdebug's human-readable generated trace files will show the difference in memory usage between function calls. If Xdebug is configured to generate computer-readable trace files then they will always show this information.


boolean xdebug.trace_enable_trigger = false #

Introduced in Xdebug >= 2.2

When this setting is set to 1, you can trigger the generation of trace files by using the XDEBUG_TRACE GET/POST parameter, or set a cookie with the name XDEBUG_TRACE. This will then write the trace data to defined directory. In order to prevent Xdebug to generate trace files for each request, you need to set xdebug.auto_trace to 0. Access to the trigger itself can be configured through xdebug.trace_enable_trigger_value.


string xdebug.trace_enable_trigger_value = "" #

Introduced in Xdebug >= 2.3

This setting can be used to restrict who can make use of the XDEBUG_TRACE functionality as outlined in xdebug.trace_enable_trigger. When changed from its default value of an empty string, the value of the cookie, GET or POST argument needs to match the shared secret set with this setting in order for the trace file to be generated.


integer xdebug.trace_format = 0 #

The format of the trace file.

ValueDescription
0shows a human readable indented trace file with: time index, memory usage, memory delta (if the setting xdebug.show_mem_delta is enabled), level, function name, function parameters (if the setting xdebug.collect_params is enabled), filename and line number.
1writes a computer readable format which has two different records. There are different records for entering a stack frame, and leaving a stack frame. The table below lists the fields in each type of record. Fields are tab separated.
2writes a trace formatted in (simple) HTML.

Fields for the computerized format:

Record type123456789101112 - ...
Entrylevelfunction #always '0'time indexmemory usagefunction nameuser-defined (1) or internal function (0)name of the include or require filefilenameline numberno. of argumentsarguments (as many as specified in field 11) - tab separated
Exitlevelfunction #always '1'time indexmemory usageempty
Returnlevelfunction #always 'R'emptyreturn valueempty

See the introduction of Function Trace for a few examples.


integer xdebug.trace_options = 0 #

When set to '1' the trace files will be appended to, instead of being overwritten in subsequent requests.


string xdebug.trace_output_dir = /tmp #

The directory where the tracing files will be written to, make sure that the user who the PHP will be running as has write permissions to that directory.


string xdebug.trace_output_name = trace.%c #

This setting determines the name of the file that is used to dump traces into. The setting specifies the format with format specifiers, very similar to sprintf() and strftime(). There are several format specifiers that can be used to format the file name. The '.xt' extension is always added automatically.

The possible format specifiers are:

SpecifierMeaningExample FormatExample Filename
%ccrc32 of the current working directorytrace.%ctrace.1258863198.xt
%ppidtrace.%ptrace.5174.xt
%rrandom numbertrace.%rtrace.072db0.xt
%s

script name 2

cachegrind.out.%scachegrind.out._home_httpd_html_test_xdebug_test_php
%ttimestamp (seconds)trace.%ttrace.1179434742.xt
%utimestamp (microseconds)trace.%utrace.1179434749_642382.xt
%H$_SERVER['HTTP_HOST']trace.%Htrace.kossu.xt
%R$_SERVER['REQUEST_URI']trace.%Rtrace._test_xdebug_test_php_var=1_var2=2.xt
%U$_SERVER['UNIQUE_ID'] 3trace.%Utrace.TRX4n38AAAEAAB9gBFkAAAAB.xt
%Ssession_id (from $_COOKIE if set)trace.%Strace.c70c1ec2375af58f74b390bbdd2a679d.xt
%%literal %trace.%%trace.%%.xt

2 This one is only available for trace file names since Xdebug 2.6.

3 New in version 2.2. This one is set by Apache's mod_unique_id module


integer xdebug.var_display_max_children = 128 #

Controls the amount of array children and object's properties are shown when variables are displayed with either xdebug_var_dump(), xdebug.show_local_vars or through Function Trace.

To disable any limitation, use -1 as value.

This setting does not have any influence on the number of children that is send to the client through the Step Debugging feature.


integer xdebug.var_display_max_data = 512 #

Controls the maximum string length that is shown when variables are displayed with either xdebug_var_dump(), xdebug.show_local_vars or through Function Trace.

To disable any limitation, use -1 as value.

This setting does not have any influence on the number of children that is send to the client through the Step Debugging feature.


integer xdebug.var_display_max_depth = 3 #

Controls how many nested levels of array elements and object properties are when variables are displayed with either xdebug_var_dump(), xdebug.show_local_vars or through Function Trace.

The maximum value you can select is 1023. You can also use -1 as value to select this maximum number.

This setting does not have any influence on the number of children that is send to the client through the Step Debugging feature.

Functions


xdebug_get_tracefile_name() : mixed #

Returns the name of the function trace file

Returns the name of the file which is used to trace the output of this script to, or null if tracing is not active. This is useful when traces are made with xdebug.auto_trace is enabled.


xdebug_start_trace( ?string $traceFile = null, int $options = 0 ) : string #

Starts a new function trace

Start tracing function calls from this point to the file in the $trace_file parameter. If no filename is given, then the trace file will be placed in the directory as configured by the xdebug.trace_output_dir setting.

In case a file name is given as first parameter, the name is relative to the current working directory. This current working directory might be different than you expect it to be, so please use an absolute path in case you specify a file name. Use the PHP function getcwd() to figure out what the current working directory is.

The name of the trace file is "{trace_file}.xt". If xdebug.auto_trace is enabled, then the format of the filename is "{filename}.xt" where the "{filename}" part depends on the xdebug.trace_output_name setting. The options parameter is a bitfield; currently there are three options:

The options parameter is a bitfield; currently there are three options:

XDEBUG_TRACE_APPEND (1)
makes the trace file open in append mode rather than overwrite mode
XDEBUG_TRACE_COMPUTERIZED (2)
creates a trace file with the format as described under 1 "xdebug.trace_format".
XDEBUG_TRACE_HTML (4)
creates a trace file as an HTML table
XDEBUG_TRACE_NAKED_FILENAME (8)
Normally, Xdebug always adds ".xt" to the end of the filename that you pass in as first argument to this function. With the XDEBUG_TRACE_NAKED_FILENAME flag set, ".xt" is not added.

The settings xdebug.collect_assignments, xdebug.collect_includes, xdebug.collect_params and xdebug.collect_return influence what information is logged to the trace file and the setting xdebug.trace_format influences the format of the trace file.

The full path and filename to which Xdebug traces is returned from this function. This will be either the filename you pass in (potentially with ".xt" added), or the auto generated filename if no filename has been passed in.


xdebug_stop_trace() : string #

Stops the current function trace

Stop tracing function calls and closes the trace file.

The function returns the filename of the file where the trace was written to.