Hacking Blackfire

Last week, we’ve introduced the new blackfire upload command and we explained how you can use it to upload existing profiles coming from XHProf or any tools able to generate a Callgrind output.

Besides the “standard” Callgrind file format, Blackfire also accepts its own “proprietary” format. Even if the format might change as we are still in beta, I’d like to describe its syntax and how you can use it to visualize your own homemade call graphs.

A call graph is made of nodes and edges; here is the simplest file that can be interpreted and displayed by Blackfire:

file-format: BlackfireProbe
cost-dimensions: wt

main()//1 3000

Blackfire uses a human readable text-based format; its content is made of two distinct parts: theheaders and the profile data (nodes and edges description).

In the above example, the only interesting header is cost-dimensions, a list of dimensions you have data for (wt represents the Wall Time). Then, we define the root node of the graph,main(), which has been called once (//1), and 3000 is the associated wall time in microseconds (3 ms).

Save this profile in a file and upload it:

$ blackfire upload profile1.bf

If you don’t have a Blackfire account yet, create one now and follow our getting started guide to install the Blackfire agent package (no need to install the probe or the companion) or have a look at a shared profile I have created for this profile.

You should see something like this:

Let’s do something more interesting by adding some edges:

file-format: BlackfireProbe
cost-dimensions: wt

main()//1 3000
main()==>child1//1 2000
main()==>child2//1 1000

Except for the main node, nodes are defined by their edges; child1 and child2 are children of the main() node and represents 66% (2ms out of 3ms) and 33% (1ms out of 3ms) of the total Wall Time respectively:

Save and upload this profile or open mine.

If a node is called more than once, increase the count (ct):

file-format: BlackfireProbe
cost-dimensions: wt

main()//1 3000
main()==>child1//10 2000
main()==>child2//5 1000

Note that the Wall Time should represent the total time for all node calls (child1 was called 10 times for a total of 2ms):

Again, save this profile and upload it or have a look at mine.

Node names can be anything you want, but we have some display conventions. Try this profile for instance:

file-format: BlackfireProbe
cost-dimensions: wt

main()//1 3000
main()==>child1(foo)//10 2000
main()==>somewhere::child2//5 1000

Have a look at this shared profile to visualize the effect of using :: in a node name.

As of now, we’ve only used the Wall Time dimension, but Blackfire supports many other ones (custom ones are planned for a future release):

• wt: Wall Time (in microseconds);
• cpu: CPU time (in microseconds);
• pmu: Peak memory usage (in octets);
• nw: Network usage (in octets).

Blackfire supports quite a few headers, but only two of them are really interesting:

• request-start: The time the call graph was generated (a Unix timestamp);
• profile-title: The Profile title.

As a real-world example, here is a profile, in the Blackfire format, generated by the Twig profiler:

file-format: BlackfireProbe
cost-dimensions: wt mu pmu
request-start: 1422517098.4374
profile-title: [Hacking Blackfire] Twig Call Graph

main()//1 492405 3119512 48036928
main()==>index//1 386898 1189224 46032280
index==>base//1 386882 1186832 46032088
base==>base::block(header)//1 4 1184 0
base==>index::block(content)//1 255887 769336 29830616
index::block(content)==>included//4 129496 399096 14851464
index::block(content)==>base::block(content)//1 94527 302272 14868960
base::block(content)==>included//1 29978 99928 0
base==>base::block(footer)//1 130950 413216 16200984
base::block(footer)==>included//1 32325 99928 0
base::block(footer)==>base::macro(foo)//1 6 800 0

Twig users can easily generate such profiles and the documentation explains how to do it for your own templates very easily. You can also read the Twig profiler dumper code to see the implementation.

Note that by default, Blackfire aggregates, and hides from display, nodes with insignificant costs. For small profiles, do not hesitate to tweak the frontend options to allow all nodes and edges to be displayed:

And of course, after uploading custom call graphs, you benefit from all the Blackfire features like profile comparisons.

I was very excited the first time I visualized Twig template renders in Blackfire and I’m very curious to know how you will use this feature in your own projects. Share your experiments with us on Twitter by using the #blackfireio hashtag.

Happy hacking!