Xdebug 2.3: Profiler File Compression

This is the seventh (and last) article in a series about new features in Xdebug 2.3, which was first released on February 22nd.

When making profiling dumps with Xdebug, the file size can not really be ignored. Even with a simple Drupal page a profile file is easily close to 1Mb.

For each function call, the file contains the location and name of the calling function, and then a list of functions that have been called. For example, the following snippet shows that the _cache_get_object function in /home/httpd/drupal-test/drupal-7.15/includes/cache.inc calls variable_get in /home/httpd/drupal-test/drupal-7.15/includes/bootstrap.inc twice, and DrupalDatabaseCache->__construct once:

fl=/home/httpd/drupal-test/drupal-7.15/includes/cache.inc
fn=_cache_get_object
22 68
cfl=/home/httpd/drupal-test/drupal-7.15/includes/bootstrap.inc
cfn=variable_get
calls=1 0 0
27 4
cfl=/home/httpd/drupal-test/drupal-7.15/includes/bootstrap.inc
cfn=variable_get
calls=1 0 0
29 2
cfl=/home/httpd/drupal-test/drupal-7.15/includes/cache.inc
cfn=DrupalDatabaseCache->__construct
calls=1 0 0
31 5

In those 15 lines, you can already spot a lot of duplicated information. The Callgrind Profile Format which Xdebug uses for writing profiling information allows for Name Compression. This allows a write, such as Xdebug, to simple refer to longer strings by a number. This number is assigned the first time a certain file name or function name is encountered. The above snippet, from the same request of a Drupal site, with Name Compression enabled now looks like:

fl=(4)
fn=(53) _cache_get_object
22 80
cfl=(2)
cfn=(45)
calls=1 0 0
27 4
cfl=(2)
cfn=(45)
calls=1 0 0
29 3
cfl=(4)
cfn=(52)
calls=1 0 0
31 5

Every file name and function name, except for _cache_get_object has been previously defined, and hence, is not repeated in its entirety, but just by its identifier. This sort of compression makes the profiling files a lot smaller. In this case, my simple-Drupal-profiling file went down from 926Kb to 385Kb.


Other parts in this series:

Shortlink

This article has a short URL available: http://drck.me/profilecomp23-bp6

Comments

No comments yet

Xdebug 2.3: Shared Secret to Enable Tracing or Profiling

This is the sixth article in a series about new features in Xdebug 2.3, which was first released on February 22nd.

Xdebug's profiling and trace file capabilities can both be triggered by a cookie, GET or POST variable, as long as you have enabled xdebug.profiler_enable_trigger and/or xdebug.trace_enable_trigger. With these triggers enabled, basically anybody could initiate a profile run, or trace file, by simply sending the XDEBUG_PROFILE or XDEBUG_TRACE cookies with an HTTP request.

Although you should not really run Xdebug in production, you can see that this is not an optimal solution.

Xdebug 2.3 adds supports for shared secrets for the trace file and profiler triggers through the xdebug.trace_enable_trigger_value and xdebug.profiler_enable_trigger_value. If these settings are changed from their default (empty string), then the value of XDEBUG_PROFILE needs to match the value of xdebug.profiler_enable_trigger_value, and the value of XDEBUG_TRACE needs to match the value of xdebug.trace_enable_trigger_value in order for the profiling to start, or the trace file to be generated.

Often users would use one of the browser extensions for triggering profile runs or enabling tracing, these extensions need to be updated. The author of The easiest Xdebug, Nikita Nikitin, managed to get an updated version out before I could complete this article. It now has support for supplying your own values for XDEBUG_TRACE and XDEBUG_PROFILE:

The other two browser helpers have not been updated yet. I have emailed the author of Chrome's Xdebug helper, and I have filled an issue for Safari's xdebug-helper-for-safari on Github. Let's hope they get updated soon too.


Other parts in this series:

Shortlink

This article has a short URL available: http://drck.me/sharedsecret23-bow

Comments

No comments yet

Xdebug 2.3: Improvements to Tracing

This is the fifth article in a series about new features in Xdebug 2.3, which was first released on February 22nd.

In this instalment we are going to have a look at the additions to the trace file functionality. Trace files are a way to document every function call, and if you enable it, variable assignment and function's return values — including when these functions were called, and how much memory PHP was using at the moment of function entry (and exit).

Xdebug 2.3 adds a new type of parameter rendering for stack traces and function traces through the xdebug.collect_params setting. Existing options are 1/2 for just the variable type, 3 for a string description, and 4 for a string description and a variable name. Xdebug 2.3 now also features a base64 encoded serialized representation of the variable's contents (option 5). Which means that the following lines:

$a = array(1, "foo", M_PI);
var_dump($a);

show up in the following 5 ways with different variations of the xdebug.collect_params setting:

  1. var_dump(array(3))

  2. var_dump(array(3))

  3. var_dump(array (0 => 1, 1 => 'foo', 2 => 3.1415926535898))

  4. var_dump(array (0 => 1, 1 => 'foo', 2 => 3.1415926535898))

  5. var_dump(YTozOntpOjA7aToxO2k6MTtzOjM6ImZvbyI7aToyO2Q6My4xNDE1OTI2NTM1ODk3OTMxO30=)

This is probably more useful with the computerized trace files that are easier to parse.


In Xdebug 2.3, normal (human readable) trace files now also show the time index and memory usage for function exit lines. Function exit lines are generated when xdebug.collect_return is set to 1. Which means that with with Xdebug 2.2 you would see:

TRACE START [2015-03-28 18:48:39]
  0.0008     275928   -> test1() …/closure-trace.phpt:27
  0.0008     276848     -> {closure:…/closure-trace.phpt:20-22}() …/closure-trace.phpt:24
  0.0009     277168       -> strlen() …/closure-trace.phpt:21
                           >=> 3
                         >=> 3
                       >=> NULL
  0.0010     276056   -> xdebug_stop_trace() …/closure-trace.phpt:28
  0.0010     276184
TRACE END   [2015-03-28 18:48:39]

But in Xdebug 2.3 you instead see:

TRACE START [2015-03-28 18:48:45]
  0.0008     269144   -> test1() …/closure-trace.phpt:27
  0.0009     270096     -> {closure:…/closure-trace.phpt:20-22}() …/closure-trace.phpt:24
  0.0009     270336       -> strlen() …/closure-trace.phpt:21
  0.0010     270504        >=> 3
  0.0010     270216      >=> 3
  0.0010     269264    >=> NULL
  0.0011     269264   -> xdebug_stop_trace() …/closure-trace.phpt:28
  0.0011     269384
TRACE END   [2015-03-28 18:48:45]

This makes it easier to see how much time and memory a specific function call took, similarly to what already was shown for "computerized" trace files.


And lastly, the computerized format (xdebug.trace_format=1), has now support for showing return values as well. The return value is part of a new "frame" for a function.

Take the following invocation of PHP:

php -dxdebug.collect_params=0 -dxdebug.collect_return=1 \
        -dxdebug.trace_format=1 \
        -r '$a = array(1, "foo", M_PI); xdebug_start_trace("/tmp/trace"); echo
        serialize($a);' \
>/dev/null && cat /tmp/trace.xt

In Xdebug 2.2 this shows:

TRACE START [2015-03-29 00:08:34]
2    1    1    0.000417    267192
2    2    0    0.000547    266848    serialize   0   Command line code   1   1   array (0 => 1, 1 => 'foo', 2 => 3.1415926535898)
2    2    1    0.000626    267024
1    0    1    0.000695    266968
               0.000925    8536
TRACE END   [2015-03-29 00:08:34]

But Xdebug 2.3 has an extra "return frame" with the return value:

TRACE START [2015-03-29 00:10:11]
2    1    1    0.000462    263152
2    2    0    0.000520    262928    serialize   0   Command line code   1   1   array (0 => 1, 1 => 'foo', 2 => 3.1415926535898)
2    2    1    0.000594    263096
2    2    R                          'a:3:{i:0;i:1;i:1;s:3:"foo";i:2;d:3.1415926535897931;}'
1    0    1    0.000676    263040
               0.000881    8512
TRACE END   [2015-03-29 00:10:11]

Function 2 (the call to serialize) now has an entry frame (0) and exit frame (1) showing the time index and memory usage, as well as the new R frame showing the return value. Unlike human readable traces it is not on the same line as the exit frame because of backwards compatibility reasons.


Other parts in this series:

Shortlink

This article has a short URL available: http://drck.me/tracing23-bom

Comments

No comments yet

Xdebug 2.3: Improvements to Debugging

This is the fourth article in a series about new features in Xdebug 2.3, which was first released on February 22nd.

In this article we are looking at the improvements towards "remote" debugging.


The first improvement is the addition to view the values of user defined constants. In Xdebug this works by defining another context. Existing contexts are local variables, and super globals. In PhpStorm, they show up in the same "Variables" box:

Xdebug 2.3 defines a third context, "User defined constants". This new third context also shows up in PhpStorm's "Variables" box:

However, if you have lots of constants, that becomes annoying. Follow (or comment on) issue WI-21691 if you want to see this changed.

Other IDEs, such as Komodo, handle this by having a separate tab for constants:

It is actually clever enough to create a new tab for every new context that I come up with, as they haven't hard coded it.


Another new debugging feature is to be able to set an exception breakpoint on all exceptions, by using * as the exception name. Xdebug 2.3 also breaks on exception classes that are inherited from the ones you set a breakpoint on. With the following code:

<?php
class BaseException extends Exception {}
class ChildException extends BaseException {}

echo "start\n";

try
{
        echo "first try\n";
        throw new ChildException("No noes!");
}
catch ( ChildException $e )
{
        echo "eat it\n";
}

echo "end\n";
?>

And the following exception breakpoints configured in PhpStorm:

Xdebug will now interrupt the script when it hits line 11 because an exception breakpoint for both BaseException (the parent of the exception that we are throwing) and * are configured.


The third feature that I would like to highlight is related to the additions to debugging exceptions. Xdebug now includes the exception's error code in the reply to the IDE. However, it does not seem that PhpStorm allows me to see which exception it broke on, and what its message and error code are.

For now, you will have to do with the raw XML result (after formatting):

-> run -i 6
<?xml version="1.0" encoding="iso-8859-1"?>
<response
        xmlns="urn:debugger_protocol_v1"
        xmlns:xdebug="http://xdebug.org/dbgp/xdebug"
        command="run" transaction_id="6"
        status="break" reason="ok"
>
        <xdebug:message
                filename="file:///tmp/xdebug-dbgp-test.php" lineno="28"
                exception="FooBarException" code="43"
        >
                <![CDATA[this should still break]]>
        </xdebug:message>
</response>

I have created issue WI-26880 in their issue tracker as a feature request.


And the last thing that has changed with debugging in Xdebug 2.3 is that now Xdebug will try to log when you do not have sufficient permissions to create a socket. For example when you have SELinux turned on but not properly configured. The new message is:

E: No permission connecting to client. This could be SELinux related. :-(


Other parts in this series:

Shortlink

This article has a short URL available: http://drck.me/debugs23-bod

Comments

Awesome features, thanks for keeping Xdebug alive!

MongoDB 3.0 features: Big Polygon

MongoDB has had geospatial query support since MongoDB 1.4. In subsequent versions we have added a range of new features, such as GeoJSON in MongoDB 2.4. In this post I will cover a new feature in MongoDB 3.0 for searching polygons that are larger than a hemisphere.

Finding objects in a specific area (polygon) can be done with the $geoWithin operator as illustrated below:

<?php
$c = (new MongoClient())->demo->points;

$c->find( [
    'loc' => [
        '$geoWithin' => [
            'type' => 'Polygon',
            'coordinates' => [ [
                [ -0.91, 51.74 ],
                [ -0.91, 51.27 ],
                [  0.67, 51.27 ],
                [  0.67, 51.74 ],
                [ -0.91, 51.74 ]
            ] ]
        ]
    ]
] );
?>

The GeoJSON format, which we use in this query as argument to the $geoWithin operator, defines a polygon as an array of linear rings, which themselves are a list of coordinate pairs beginning and ending with the same point to form a closed ring. The first linear ring is required and defines the exterior boundary of the polygon. Subsequent rings, if specified, would define interior boundaries (i.e. holes) within the polygon.

As an image, the geometry in this query looks like:

The GeoJSON format specification does not give any meaning about the direction or winding of points. The application is left to determine which side of the geometry is the search area. Both of the following images are possible interpretations when just taking the GeoJSON specification into account:

The interpretation of which part forms the search area would of course provide very different results! Because GeoJSON does not address winding, sometimes applications make wrong decisions.

MongoDB deterministically chooses the area that is the "smallest of the two". For our query, it would consider the polygon that is shown first of the two interpretations shown above.

This logic works for most applications, but it falls apart when you want to find objects within a polygon that spans more than a hemisphere.

In the small example of London, you would certainly expect the smallest area, the one that covers London to be the search area. But when we consider this much larger polygon (a circle centred around 25°N, 90°E with a diameter of 115°), then it is not so obvious:

When the polygon is larger than a hemisphere, i.e. larger than half of the Earth's surface, the "smallest of the two" is actually the area we intended to exclude. From MongoDB 3.0 a custom coordinate reference system (CRS) is supported, which forces geospatial queries with a polygon search area to consider the direction of coordinates in deciding which side is the search area. Consistent with KML, and WKT/WKB, the search area is determined to be the area that is on the left hand side of the direction of points. MongoDB calls this "strict winding". With strict winding enabled through our custom CRS, the following two possibilities can be considered:

MongoDB's implementation of GeoJSON allows us to specify a custom coordinate reference system on any geometry object via a crs property. Currently MongoDB only supports our custom CRS, urn:x-mongodb:crs:strictwinding:EPSG:4326, to specify strict winding. In the future, MongoDB could also support others, such as UTM, the US National Grid, or the UK's Ordnance Survey National Grid. The addition of support for this crs property is called "Big Polygon support" in MongoDB.

In a query, our custom CRS would appear as an extra argument within the $geoWithin or $geoIntersects criteria, on the same level as type and coordinates:

<?php
$c = (new MongoClient())->demo->points;

$c->find( [
    'loc' => [
        '$geoWithin' => [
            'type' => 'Polygon',
            'coordinates' => [ [
                [ -0.91, 51.74 ],
                [ -0.91, 51.27 ],
                [  0.67, 51.27 ],
                [  0.67, 51.74 ],
                [ -0.91, 51.74 ]
            ] ],
            'crs' => [
                'type' => 'name',
                'properties' => [
                    'name' => 'urn:x-mongodb:crs:strictwinding:EPSG:4326'
                ]
            ]
        ]
    ]
] );
?>

The use of the custom CRS is only relevant when searching an area that is larger than a hemisphere. In most cases, the default "smallest of the two" behaviour will be sufficient and you will not need to specify a custom CRS.

Shortlink

This article has a short URL available: http://drck.me/bigpolygon-bo2

Comments

No comments yet

Life Line