Tracing PHP Applications with xdebug
Welcome to the second series of our story about xdebug. The xdebug installation and its basic features were discussed in the first series. In this article we will look at tracing the program.
The previous series of the cycle Introducing xdebug
Creating a trace log
Instead of manually adding various debugging output functions, we can use xdebug to create a trace log. The trace log is a list of calls to functions and methods of the class throughout the execution of the script. The advantage is that each call will be reflected in the log
The trace log usually differs from run to run, as it depends on incoming data that is different from the request to request.
Tracing the trace log helps us to understand how our program runs, but it is very difficult to visualize all possible branches, unless our program is very simple. One if suggests two possible paths for program development. With each further if, the number of (theoretically) possible paths of development is multiplied by 2. It is because of this that testing large programs is quite difficult: there are too many different paths of development and each must be tested.
Now let's start creating the trace log. xdebug supports two different logging formats. By default, logies are created in a format that is pleasant to the human eye, and it is convenient to read and analyze them. If you want to process the trace log with any program (intended for processing xdebug logs), you need to configure xdebug in a different format. This format (computer-readable) is easily processed by the program (log analyzer), because it contains fixed-length columns.
If you want to get a trace log for each script that you run, add the following commands
in php.ini. Do not forget to restart your web server after changing php.ini.
The second line defines the path by which xdebug will save logs. By default, this path is set to / tmp, this is a good choice for, but will cause problems in Windows, since c: \ tmp (it is assumed that c: is the current disk) is usually not created. Therefore, you need to create a directory in Windows (or register an existing one) in which xdebug will save the trace logs, otherwise it will not work.
The execution of functions and methods will be very slow since each of their calls, as well as the results will be recorded in the log.
Tracing part of the application
')
Since the size of the trace log is growing very quickly, a good solution is to create a log only for the “interesting” parts of the application, for example, creating a trace log during the initialization phase.
Let's take a look at how to create a trace log for a small recursive function (factorial calculation), in this example we will start and finish the trace in real time. If you have activated tracing in php.ini, you will see a warning that tracing has already been started for your script.
As you can see by the path and file name, the program is running in Windows. If you are working in Unix, you must use a different file name. The xdebug_start_trace function starts tracing recording, and xdebug_stop_trace stops. When this code is launched, approximately such a log file will be generated:
In each row, the first column shows the total time the code was run. The second column shows the amount of memory that the script currently occupies. The last column shows the file, line and function name. xdebug indents each function according to the stack space for readability.
If you want xdebug to show the difference in memory usage, add
in php.ini. The difference is the difference between memory usage between the current line and the previous one. You can add this setting at runtime using the ini_set function, but only after the trace begins.
The xdebug_start_trace function has a second optional parameter. You can use one or more of the following three settings: XDEBUG_TRACE_APPEND adds to the existing trace file. When XDEBUG_TRACE_COMPUTERIZED is set, xdebug creates a trace log in a readable format by the analyzer. Using this parameter is the same as setting the xdebug.trace_format parameter to 1. The XDEBUG_TRACE_HTML parameter sets the format of the trace log in HTML.
The following screenshot shows the HTML trace log format:
Adding information to the trace log
We can also configure xdebug to save us the parameters we pass to the functions. This is very useful to better understand how the program runs.
Saving parameters to the trace log is set with the xdebug.collect_params parameter described in the previous article. xdebug.collect_params accepts numeric values, 0 means no additional information, 4 means you need to display the name of the variable and all the information about each function parameter. A value of 3 will display the names and values ​​of the variables cropped in accordance with the settings of the parameters xdebug.var_display_max_data, debug.var_display_max_children and xdebug.var_display_max_depth described in the previous article.
Below is an excerpt from the trace log with preservation of function parameters:
Let's add more information. Using
we will configure xdebug to save the return values ​​for each function. This will make the log a little difficult to read, but look at the log of our function, you will see what value is returned at each stage of the recursion:
As you can see in this example, the xdebug.show_mem_delta parameter is set.
Caption Tracing Log
Up to now, we have clearly indicated the name of the trace log. This is not always convenient. If you need to view the logs depending on the incoming data or the state of the application, it is good that xdebug itself automatically assign a name. xdebug can assign a name depending on what you use, the xdebug.auto_trace parameter or the xdebug_start_trace () function to activate tracing. If in the last example you pass an empty argument as parameters to the xdebug_start_trace function, xdebug automatically selects a name for the file.
The name of the generated xdebug file always starts with “trace.” And has the extension .xt. The part of the name between the default dots is the CRC from the working directory. By setting xdebug.trace_output_name you can define another name for the trace log. xdebug.trace_output_name takes a string as an argument; a string can contain various qualifiers. Below is a list of the most important qualifiers:
Using a clever combination of these qualifiers, you can force xdebug to create a different number of trace logs and understand which log belongs to which script, depending on the name of the virtual host or requests.
In most cases, you will want to create a single script run. Therefore, xdebug will overwrite the existing log with the specified name. You can configure xdebug to add information to the current using the following setting.
in php.ini.
If you need to know at startup what name xdebug will select to write the log, you can call the function xdebug_get_tracefile_name ().
Conclusion
Being able to use function tracing is a very useful thing that xdebug gives us. You can create logies of your programs without adding calls to various functions. All function calls will be displayed without explicit help function calls.
You can use various utilities like grep to find the necessary information or section in the trace log, or write a small program in PHP that will parse this file for you. Tracing is not a replacement for the debugger. The debugger will be discussed in the fourth part of the story.
You do not need to activate tracing on combat vehicles, this will greatly degrade performance, each line of the program will be reflected in the trace log.
The next article will be devoted to Profiling PHP Applications With xdebug.
The previous series of the cycle Introducing xdebug
Creating a trace log
Instead of manually adding various debugging output functions, we can use xdebug to create a trace log. The trace log is a list of calls to functions and methods of the class throughout the execution of the script. The advantage is that each call will be reflected in the log
The trace log usually differs from run to run, as it depends on incoming data that is different from the request to request.
Tracing the trace log helps us to understand how our program runs, but it is very difficult to visualize all possible branches, unless our program is very simple. One if suggests two possible paths for program development. With each further if, the number of (theoretically) possible paths of development is multiplied by 2. It is because of this that testing large programs is quite difficult: there are too many different paths of development and each must be tested.
Now let's start creating the trace log. xdebug supports two different logging formats. By default, logies are created in a format that is pleasant to the human eye, and it is convenient to read and analyze them. If you want to process the trace log with any program (intended for processing xdebug logs), you need to configure xdebug in a different format. This format (computer-readable) is easily processed by the program (log analyzer), because it contains fixed-length columns.
If you want to get a trace log for each script that you run, add the following commands
xdebug.auto_trace = On
xdebug.trace_output_dir = c: \ data
in php.ini. Do not forget to restart your web server after changing php.ini.
The second line defines the path by which xdebug will save logs. By default, this path is set to / tmp, this is a good choice for, but will cause problems in Windows, since c: \ tmp (it is assumed that c: is the current disk) is usually not created. Therefore, you need to create a directory in Windows (or register an existing one) in which xdebug will save the trace logs, otherwise it will not work.
The execution of functions and methods will be very slow since each of their calls, as well as the results will be recorded in the log.
Tracing part of the application
')
Since the size of the trace log is growing very quickly, a good solution is to create a log only for the “interesting” parts of the application, for example, creating a trace log during the initialization phase.
Let's take a look at how to create a trace log for a small recursive function (factorial calculation), in this example we will start and finish the trace in real time. If you have activated tracing in php.ini, you will see a warning that tracing has already been started for your script.
xdebug_start_trace ('c: /data/fac.xt');
print fac (7);
function fac ($ x)
{
if (0 == $ x) return 1;
return $ x * fac ($ x - 1);
}
xdebug_stop_trace ();
As you can see by the path and file name, the program is running in Windows. If you are working in Unix, you must use a different file name. The xdebug_start_trace function starts tracing recording, and xdebug_stop_trace stops. When this code is launched, approximately such a log file will be generated:
TRACE START [2007-10-26 12:18:48]
0.0068 53384 -> fac () C: \ www \ fac.php: 5
0.0069 53584 -> fac () C: \ www \ fac.php: 10
0.0069 53840 -> fac () C: \ www \ fac.php: 10
0.0070 54096 -> fac () C: \ www \ fac.php: 10
0.0070 54376 -> fac () C: \ www \ fac.php: 10
0.0071 54656 -> fac () C: \ www \ fac.php: 10
0.0072 54936 -> fac () C: \ www \ fac.php: 10
0.0072 55216 -> fac () C: \ www \ fac.php: 10
0.0073 55392 -> xdebug_stop_trace () C: \ www \ fac.php: 13
0.0237 55392
TRACE END [2007-10-26 12:18:48]
In each row, the first column shows the total time the code was run. The second column shows the amount of memory that the script currently occupies. The last column shows the file, line and function name. xdebug indents each function according to the stack space for readability.
If you want xdebug to show the difference in memory usage, add
xdebug.show_mem_delta = On
in php.ini. The difference is the difference between memory usage between the current line and the previous one. You can add this setting at runtime using the ini_set function, but only after the trace begins.
The xdebug_start_trace function has a second optional parameter. You can use one or more of the following three settings: XDEBUG_TRACE_APPEND adds to the existing trace file. When XDEBUG_TRACE_COMPUTERIZED is set, xdebug creates a trace log in a readable format by the analyzer. Using this parameter is the same as setting the xdebug.trace_format parameter to 1. The XDEBUG_TRACE_HTML parameter sets the format of the trace log in HTML.
The following screenshot shows the HTML trace log format:
Adding information to the trace log
We can also configure xdebug to save us the parameters we pass to the functions. This is very useful to better understand how the program runs.
Saving parameters to the trace log is set with the xdebug.collect_params parameter described in the previous article. xdebug.collect_params accepts numeric values, 0 means no additional information, 4 means you need to display the name of the variable and all the information about each function parameter. A value of 3 will display the names and values ​​of the variables cropped in accordance with the settings of the parameters xdebug.var_display_max_data, debug.var_display_max_children and xdebug.var_display_max_depth described in the previous article.
Below is an excerpt from the trace log with preservation of function parameters:
0.0033 54320 -> fac ($ x = 7) C: \ www \ fac.php: 6
0.0034 54432 -> fac ($ x = 6) C: \ www \ fac.php: 11
Let's add more information. Using
xdebug.collect_return = On
we will configure xdebug to save the return values ​​for each function. This will make the log a little difficult to read, but look at the log of our function, you will see what value is returned at each stage of the recursion:
TRACE START [2007-10-26 12:30:04]
0.0133 55704 +48 -> fac ($ x = 7) C: \ www \ fac.php: 8
0.0133 55840 +136 -> fac ($ x = 6) C: \ www \ fac.php: 13
0.0134 56096 +256 -> fac ($ x = 5) C: \ www \ fac.php: 13
0.0134 56352 +256 -> fac ($ x = 4) C: \ www \ fac.php: 13
0.0134 56632 +280 -> fac ($ x = 3) C: \ www \ fac.php: 13
0.0135 56912 +280 -> fac ($ x = 2) C: \ www \ fac.php: 13
0.0135 57192 +280 -> fac ($ x = 1) C: \ www \ fac.php: 13
0.0135 57472 +280 -> fac ($ x = 0) C: \ www \ fac.php: 13
> => 1
> => 1
> => 2
> => 6
> => 24
> => 120
> => 720
> => 5040
0.0140 57648 +176 -> xdebug_stop_trace () C: \ www \ fac.php: 26
0.0140 57648
TRACE END [2007-10-26 12:30:04]
As you can see in this example, the xdebug.show_mem_delta parameter is set.
Caption Tracing Log
Up to now, we have clearly indicated the name of the trace log. This is not always convenient. If you need to view the logs depending on the incoming data or the state of the application, it is good that xdebug itself automatically assign a name. xdebug can assign a name depending on what you use, the xdebug.auto_trace parameter or the xdebug_start_trace () function to activate tracing. If in the last example you pass an empty argument as parameters to the xdebug_start_trace function, xdebug automatically selects a name for the file.
The name of the generated xdebug file always starts with “trace.” And has the extension .xt. The part of the name between the default dots is the CRC from the working directory. By setting xdebug.trace_output_name you can define another name for the trace log. xdebug.trace_output_name takes a string as an argument; a string can contain various qualifiers. Below is a list of the most important qualifiers:
- % c - working directory CRC
- % p - process ID
- % r is a random number
- % u - current time with microseconds
- % H - $ _SERVER ['HTTP_HOST']
- % R - $ _SERVER ['REQUEST_URI']
Using a clever combination of these qualifiers, you can force xdebug to create a different number of trace logs and understand which log belongs to which script, depending on the name of the virtual host or requests.
In most cases, you will want to create a single script run. Therefore, xdebug will overwrite the existing log with the specified name. You can configure xdebug to add information to the current using the following setting.
xdebug.trace_options = 1
in php.ini.
If you need to know at startup what name xdebug will select to write the log, you can call the function xdebug_get_tracefile_name ().
Conclusion
Being able to use function tracing is a very useful thing that xdebug gives us. You can create logies of your programs without adding calls to various functions. All function calls will be displayed without explicit help function calls.
You can use various utilities like grep to find the necessary information or section in the trace log, or write a small program in PHP that will parse this file for you. Tracing is not a replacement for the debugger. The debugger will be discussed in the fourth part of the story.
You do not need to activate tracing on combat vehicles, this will greatly degrade performance, each line of the program will be reflected in the trace log.
The next article will be devoted to Profiling PHP Applications With xdebug.
Source: https://habr.com/ru/post/31463/
All Articles