Profiling
Xdebug's built-in profiler allows you to find bottlenecks in your script and visualize those with an external tool such as KCacheGrind or WinCacheGrind.
Introduction
Xdebug's Profiler is a powerful tool that gives you the ability to analyse your PHP code and determine bottlenecks or generally see which parts of your code are slow and could use a speed boost. Since Xdebug 2.6, the profiler also collects information about how much memory is being used, and which functions and methods increase memory usage.
The profiler in Xdebug outputs profiling information in the form of a Cachegrind compatible file. This allows you to use the excellent KCacheGrind tool (Linux, KDE) to analyse your profiling data. If you are on Linux you can install KCacheGrind with your favourite package manager.
If you are on Windows, there are precompiled QCacheGrind binaries available. (QCacheGrind is KCacheGrind without KDE bindings).
If you are on Mac OSX, there are instructions on how to build QCacheGrind too.
Users of Windows can alternatively use WinCacheGrind. The functionality is different from KCacheGrind so the section that documents the use of KCacheGrind on this page doesn't apply to this program. WinCacheGrind currently does not support the file and function compression for cachegrind files that Xdebug 2.3 introduces yet.
There is also an alternative profile information presentation tool called xdebugtoolkit, a web based front-end called Webgrind, and a Java based tool called XCallGraph.
In case you can not use KDE (or do not want to use KDE) the kcachegrind package also comes with a perl script "ct_annotate" which produces ASCII output from the profiler trace files.
Starting The Profiler
Profiling is enabled by setting xdebug.mode to profile
. This
instructs Xdebug to start writing profiling information into the dump directory
configured with the
xdebug.output_dir
directive. The name of the generated file always starts with
"cachegrind.out." and ends with either the PID
(process ID) of the PHP (or Apache) process or the crc32 hash of the
directory containing the initially debugged script. Make sure you have enough
space in your xdebug.output_dir as the amount of information generated by the profiler can be
enormous for complex scripts, for example up to 500MB for a complex application
like eZ Publish.
You can also selectively enable the profiler by setting
xdebug.start_with_request#trigger to trigger
. You can then enable
the profiler by using an environment value, a GET/POST parameter, or COOKIE
variable of the name XDEBUG_SESSION
. The FireFox and Chrome
extensions that can be used to enable the step debugger (see
HTTP Debug Sessions) can also be used
with this setting.
From Xdebug 2.6 onwards, Xdebug adds the HTTP header
X-Xdebug-Profile-Filename
to a request that is being profiled.
This header contains the name of the file that holds the profiling information
for that request.
Analysing Profiles
After a profile information file has been generated you can open it with KCacheGrind:
Once the file is opened you have plenty of information available in the
different panes of KCacheGrind. On the left side you find the "Flat Profile"
pane showing all functions in your script sorted by time spent in this function,
and all its children.
The second column "Self" shows the time spent in this function (without its
children), the third column "Called" shows how often a specific function was
called and the last column "Function" shows the name of the function. Xdebug
changes internal PHP function names by prefixing the function name with
"php::" and include files are handled in a special way too. Calls to include
(and include_once, require and require_once) are followed by "::" and the
filename of the included file. In the screenshot on the left you can see this
for "include::/home/httpd/ez_34/v..." and an example of an internal PHP
function is "php::mysql_query".
The numbers in the first two columns can be
either percentages of the full running time of the script (like in the
example) or absolute time (1 unit is 1/1.000.000th of a second). You can
switch between the two modes with the button you see on the right.
The pane on the right contains an upper and lower pane. The upper one
shows information about which functions called the current selected function
("eztemplatedesignresource->executecompiledtemplate in the screenshot).
The lower pane shows information about the functions that the current selected
function called.
The "Cost" column in the upper pane shows the time spent in the current selected function while being called from the function in the list. The numbers in the Cost column added up will always be 100%. The "Cost" column in the lower pane shows the time spent while calling the function from the list. While adding the numbers in this list up, you will most likely never reach 100% as the selected function itself will also takes time to execute.
The "All Callers" and "All Calls" tabs show not only the direct calls from
which the function was called respectively all directly made
function calls but also function calls made more levels up and down.
The upper pane in the screenshot on the left shows all functions calling the
current selected one, both directly and indirectly with other functions
inbetween them on the stack. The "Distance" column shows how many function
calls are between the listed and the current selected one (-1). If there are
different distances between two functions, it is shown as a range (for example
"5-24"). The number in parentheses is the median distance. The lower pane is
similar except that it shows information on functions called from the current
selected one, again either direct or indirect.
Related Settings and Functions
- string xdebug.log =
- integer xdebug.log_level = 7
- string xdebug.mode = develop
- string xdebug.output_dir = /tmp
- integer xdebug.profiler_append = 0
- string xdebug.profiler_output_name = cachegrind.out.%p
- string xdebug.start_with_request = default
- string xdebug.trigger_value = ""
- xdebug_get_profiler_filename() : mixed
- xdebug_info() : void
Settings
string xdebug.log = #
Configures Xdebug's log file.
Xdebug will log to this file all file creations issues, Step Debugging connection attempts, failures, and debug communication.
Enable this functionality by setting the value to a absolute path. Make sure
that the system user that PHP runs at (such as www-data
if you are
running with Apache) can create and write to the file.
The file is opened in append-mode, and will therefore not be overwritten by default. There is no concurrency protection available.
The log file will include any attempt that Xdebug makes to connect to an IDE:
[2693358] Log opened at 2020-09-02 07:19:09.616195 [2693358] [Step Debug] INFO: Connecting to configured address/port: localhost:9003. [2693358] [Step Debug] ERR: Could not connect to debugging client. Tried: localhost:9003 (through xdebug.client_host/xdebug.client_port) :-( [2693358] [Profiler] ERR: File '/foo/cachegrind.out.2693358' could not be opened. [2693358] [Profiler] WARN: /foo: No such file or directory [2693358] [Tracing] ERR: File '/foo/trace.1485761369' could not be opened. [2693358] [Tracing] WARN: /foo: No such file or directory [2693358] Log closed at 2020-09-02 07:19:09.617510
It includes the opening time (2020-09-02 07:19:09.616195
), the
IP/Hostname and port Xdebug is trying to connect to
(localhost:9003
), and whether it succeeded (Connected to
client :-)
). The number in brackets ([2693358]
) is the
Process ID.
It includes:
[2693358]
- process ID in brackets
2020-09-02 07:19:09.616195
- opening time
For Step Debugging:
INFO: Connecting to configured address/port: localhost:9003. ERR: Could not connect to debugging client. Tried: localhost:9003 (through xdebug.client_host/xdebug.client_port) :-(
For Profiling:
ERR: File '/foo/cachegrind.out.2693358' could not be opened. WARN: /foo: No such file or directory
For Function Trace:
ERR: File '/foo/trace.1485761369' could not be opened. WARN: /foo: No such file or directory
All warnings and errors are described on the Description of errors page, with
detailed instructions on how to resolve the problem, if possible. All errors are always logged through
PHP's internal logging mechanism (configured with error_log
in php.ini
). All warnings and errors also show up in the
diagnostics log that you can view by calling xdebug_info().
Step Debugger Communication
The debugging log can also log the communication between Xdebug and an IDE.
This communication is in XML, and starts with the <init
XML
element:
<init xmlns="urn:debugger_protocol_v1" xmlns:xdebug="https://xdebug.org/dbgp/xdebug" fileuri="file:///home/httpd/www.xdebug.org/html/router.php" language="PHP" xdebug:language_version="7.4.11-dev" protocol_version="1.0" appid="2693358" idekey="XDEBUG_ECLIPSE"> <engine version="3.0.0-dev"><![CDATA[Xdebug]]></engine> <author><![CDATA[Derick Rethans]]></author> <url><![CDATA[https://xdebug.org]]></url> <copyright><![CDATA[Copyright (c) 2002-2020 by Derick Rethans]]></copyright> </init>
The fileuri
attribute lists the entry point of your
application, which can be useful to compare to breakpoint_set
commands to see if path mappings are set-up correctly.
Beyond the <init
element, you will find the configuration of
features:
<- feature_set -i 4 -n extended_properties -v 1 -> <response xmlns="urn:debugger_protocol_v1" xmlns:xdebug="https://xdebug.org/dbgp/xdebug" command="feature_set" transaction_id="4" feature="extended_properties" success="1"> </response>
<- step_into -i 9 -> <response xmlns="urn:debugger_protocol_v1" xmlns:xdebug="https://xdebug.org/dbgp/xdebug" command="step_into" transaction_id="9" status="break" reason="ok"> <xdebug:message filename="file:///home/httpd/www.xdebug.org/html/router.php" lineno="3"> </xdebug:message> </response>
You can read about DBGP - A common debugger protocol specification at its dedicated documation page.
The xdebug.log_level setting controls how much information is logged.
Note: Many Linux distributions now use systemd, which
implements private tmp directories. This means that when PHP
is run through a web server or as PHP-FPM, the /tmp
directory is
prefixed with something akin to:
/tmp/systemd-private-ea3cfa882b4e478993e1994033fc5feb-apache.service-FfWZRg
This setting can additionally be configured through the
XDEBUG_CONFIG
environment variable.
integer xdebug.log_level = 7 #
Configures which logging messages should be added to the log file.
The log file is configured with the xdebug.log setting.
The following levels are supported:
Level | Name | Example |
---|---|---|
0 | Criticals | Errors in the configuration |
1 | Errors | Connection errors |
3 | Warnings | Connection warnings |
5 | Communication | Protocol messages |
7 | Information | Information while connecting |
10 | Debug | Breakpoint resolving information |
Criticals, errors, and warnings always show up in the diagnostics log that you can view by calling xdebug_info().
Criticals and errors are additionally logged through
PHP's internal logging mechanism (configured with error_log
in php.ini
).
This setting can additionally be configured through the
XDEBUG_CONFIG
environment variable.
string xdebug.mode = develop #
This setting controls which Xdebug features are enabled.
This setting can only be set in php.ini
or
files like 99-xdebug.ini
that are read when a PHP process starts
(directly, or through php-fpm), but not in .htaccess
and
.user.ini
files where are read per-request.
The following values are accepted:
off
- Nothing is enabled. Xdebug does no work besides checking whether functionality is enabled. Use this setting if you want close to 0 overhead.
develop
- Enables Development Aids including the overloaded var_dump().
coverage
- Enables Code Coverage Analysis to generate code coverage reports, mainly in combination with PHPUnit.
debug
- Enables Step Debugging. This can be used to step through your code while it is running, and analyse values of variables.
gcstats
- Enables Garbage Collection Statistics to collect statistics about PHP's Garbage Collection Mechanism.
profile
- Enables Profiling, with which you can analyse performance bottlenecks with tools like KCacheGrind.
trace
- Enables the Function Trace feature, which allows you record every function call, including arguments, variable assignment, and return value that is made during a request to a file.
You can enable multiple modes at the same time by comma separating their
identifiers as value to xdebug.mode: xdebug.mode=develop,trace
.
You can also set the mode by setting the XDEBUG_MODE
environment
variable on the command-line; this will take precedence over the xdebug.mode
setting.
string xdebug.output_dir = /tmp #
The directory where Xdebug will write tracing, profiling, and garbage collection statistics to. This directory needs to be writable for the system user with which PHP is running.
This setting can be changed in php.ini
, .htaccess
(and equivalent files), and within a PHP file with ini_set()
.
In some cases (when profiling, or when
xdebug.start_with_request=yes
with tracing), Xdebug
creates the file before the script runs. In that case, changes made through
ini_set()
will not be taken into account.
This setting can additionally be configured through the
XDEBUG_CONFIG
environment variable.
integer xdebug.profiler_append = 0 #
When this setting is set to 1, profiler files will not be overwritten when a new request would map to the same file (depending on the xdebug.profiler_output_name setting. Instead the file will be appended to with the new profile.
string xdebug.profiler_output_name = cachegrind.out.%p #
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.
See the xdebug.trace_output_name documentation for the supported specifiers.
This setting can additionally be configured through the
XDEBUG_CONFIG
environment variable.
string xdebug.start_with_request = default #
A Function Trace, Garbage Collection Statistics, Profiling, or Step Debugging can be activated at the start of a PHP request. Whether this happens depends on the value of this setting:
yes
-
The functionality starts when the PHP request starts, and before any PHP code is run.
For example xdebug.mode=
trace
and xdebug.start_with_request=yes
starts a Function Trace for the whole request. no
-
The functionality does not get activated when the request starts.
You can still start a Function Trace with xdebug_start_trace(), Step Debugging with xdebug_break(), or Garbage Collection Statistics with xdebug_start_gcstats().
trigger
-
The functionality only gets activated when a specific trigger is present when the request starts.
The name of the trigger is
XDEBUG_TRIGGER
, and Xdebug checks for its presence in either$_ENV
(environment variable),$_GET
or$_POST
variable, or$_COOKIE
(HTTP cookie name).There is also a legacy fallback to a functionality specific trigger name:
XDEBUG_PROFILE
(for Profiling),XDEBUG_TRACE
(for a Function Trace), andXDEBUG_SESSION
(for Step Debugging).Debug session management for Step Debugging is also available through
XDEBUG_SESSION_START
.With xdebug.trigger_value you can control which specific trigger value will activate the trigger. If xdebug.trigger_value is set to an empty string, any value will be accepted.
default
-
The
default
value depends on xdebug.mode:- debug:
trigger
- gcstats:
no
- profile:
yes
- trace:
trigger
- debug:
string xdebug.trigger_value = "" #
This setting can be used when xdebug.start_with_request is set to
trigger
, which is the default for Step Debugging and Function Trace.
In trigger
mode, Xdebug will only start its
functionality when the XDEBUG_TRIGGER
is set in the environment,
or when the XDEBUG_TRIGGER
GET, POST, or COOKIE variable is
set.
Normally, Xdebug does not look at which value is actually used. If this setting is set to a non-empty string, then Xdebug will only trigger if the value matches the value of this setting.
With the following settings:
xdebug.mode=profile xdebug.start_with_request=trigger xdebug.trigger_value=StartProfileForMe
Xdebug's profiler will only start when either the environment variable
XDEBUG_TRIGGER
is set to StartProfileForMe
, the GET
or POST variable XDEBUG_TRIGGER
is set to
StartProfileForMe
, or when the cookie XDEBUG_TRIGGER
has the value StartProfileForMe
.
See also:
- xdebug.start_with_request#trigger
- For how the triggering mechanism works, and which environment and server variables Xdebug acts on.
Functions
xdebug_get_profiler_filename() : mixed #
Returns the profile information filename
Returns the name of the file which is used to save profile information to, or
false
if the profiler is not active.
xdebug_info() : void #
Show diagnostic information
This function returns an HTML page which shows diagnostic information. It is analogous to PHP's phpinfo() function.
The HTML output includes which mode is active, what the settings are, and diagnostic information in case there are problems with debugging connections, opening of files, etc.
Each warning and error in the diagnostics log also links through to the Description of errors documentation page.