Profiling your Website with Craft CMS 3’s Debug Toolbar

Craft CMS 3 has some big changes under the hood, one of which is the addi­tion of the Debug Tool­bar that helps you pro­file and debug your websites

Andrew Welch / nystudio107

With Craft CMS 3’s offi­cial release on April 4^th 2018 behind us, peo­ple are div­ing in and start­ing to get acquaint­ed with what’s new in Craft CMS 3.

The Craft 3 Beta Exec­u­tive Sum­ma­ry and Set­ting up a New Craft CMS 3 Project arti­cles cov­er this from a gestalt per­spec­tive. In this arti­cle, we’re going to delve into a spe­cif­ic top­ic: the all new Debug Toolbar.

In Craft 2.x, we got used to look­ing at the web con­sole to see debug­ging & per­for­mance infor­ma­tion on our web­site. In Craft 3, this has been vast­ly improved by con­sol­i­dat­ing all of it into the Debug Toolbar.

With the Debug Tool­bar, you now have one place to look for debug­ging & per­for­mance information.

The Debug Tool­bar is actu­al­ly com­ing from Yii2, with some extra mag­ic lay­ered on top by the Pix­el & Ton­ic folks. Best of all, it’s search­able, sortable, and infi­nite­ly more use­ful than the old Craft 2.x method of dump­ing infor­ma­tion to the web console.

Here’s what it looks like:

Enabling the Debug Toolbar

So how do we get this won­der­ful lit­tle beast to appear for us?

Next, you need to specif­i­cal­ly enable the Debug Tool­bar. This is done on a per-user basic, so we’ll need to go to our My Account page in the AdminCP:

Once you’re on the My Account page, click on the Pref­er­ences tab, and then check the Show the debug tool­bar on the front end and/​or Show the debug tool­bar on the Con­trol Pan­el check­box­es, depend­ing on where you want the tool­bar to appear.

That’s it! You should now have the fan­cy new Debug Tool­bar ready and wait­ing to help you out.

Since the pref­er­ence to show the Debug Tool­bar (or not) is tied to your account, you obvi­ous­ly have to be logged in as well. So if it is mys­te­ri­ous­ly not show­ing up for you, ensure that you’re still logged in!

Note that if devMode is not on, you can still use the Debug Tool­bar, but not as much infor­ma­tion will be logged. Only error and warning mes­sages as well as tim­ing pro­fil­ing infor­ma­tion will be logged if devMode is not on.

So what kinds of things can the Debug Tool­bar do for you? Read on to find out, we’ll cov­er a few use­ful things it can do for you!

Pro­fil­ing Data­base Queries

Now that we have the Debug Tool­bar up and run­ning, let’s use it for a very com­mon use-case: pro­fil­ing data­base queries.

We want our sites to be per­for­mant as dis­cussed in the A Pret­ty Web­site Isn’t Enough arti­cle; and a good start is cut­ting down on the num­ber of data­base queries we’re making.

Click­ing on the DB sec­tion of the Debug Tool­bar brings up the Data­base Queries panel:

Here we can look at all of the data­base queries that hap­pen when load­ing the web­page. While we want to reduce the num­ber of queries as much as pos­si­ble by uti­liz­ing tech­niques such as caching and eager load­ing, we want to focus on the queries that take the most time.

It’s not just about the num­ber of queries, it’s about how per­for­mant those queries are.

The nice thing about the Debug Tool­bar is that we can sort the queries by Dura­tion to find the non-per­for­mant queries that we should be focus­ing on.

This sure beats pag­ing through each query one by one: we can focus on the queries that mat­ter instead.

Pro tip : scroll all the way to the bot­tom of the page, and click on the Explain all link, and you’ll see a human-read­able sum­ma­ry of each query:

Sift­ing Through Logs

If you’ve done any amount of Craft CMS 2.x devel­op­ment, you’ve spent at least some time read­ing through the craft.log to fig­ure out what’s going wrong. Thank­ful­ly, the Debug Tool­bar makes this eas­i­er too!

Click­ing on the Logs sec­tion of the Debug Tool­bar brings up the Log Mes­sages panel:

All of the log­ging in Craft CMS 3 goes into one pri­ma­ry log file now, web.log, and the Debug Tool­bar lets you fil­ter through it all. Every­thing Craft logs, as well as every­thing plu­g­ins log is all in one place in the Debug Toolbar.

You can choose what type of log mes­sages to view, from least severe to most severe:

• Trace  — Log mes­sages that show the flow of the app
• Info  — Infor­ma­tion­al messages
• Warn­ing  — Warn­ing mes­sages about things that could be problematic
• Error  — Hard errors, things that are flat out wrong

By lim­it­ing the type of log mes­sages dis­played, you can find the impor­tant prob­lems much eas­i­er. In the Debug Tool­bar itself, Info = grey, Warn­ing = orange, Error = red.

You can also fur­ther fil­ter the mes­sages by Cat­e­go­ry by typ­ing in the text box below it:

This lets you very quick­ly search through the copi­ous log­ging that Craft does to quick­ly find what you’re look­ing for.

So much nicer than pag­ing through a mono­lith­ic log file in a text editor.

Pro tip: if you click on the C icon at the far left of the Debug Tool­bar, it’ll go full screen so you can see more information.

Over­all Per­for­mance Profiling

The Debug Tool­bar also has some pret­ty amaz­ing per­for­mance pro­fil­ing tools that let you see exact­ly what’s hap­pen­ing when your web­pages are loaded.

Click­ing on the Time sec­tion of the Debug Tool­bar brings up the Per­for­mance Pro­fil­ing panel:

Here you can see the over­all time that the page took to load, as well as the peak mem­o­ry usage while the page was loaded.

You can also see the per­for­mance tim­ings bro­ken down in a more fine­ly grained man­ner, and you can sort by Dura­tion or fil­ter by Cat­e­go­ry , just as you can in oth­er parts of the Debug Toolbar.

The data shown in the Info col­umn on the right will be indent­ed to show its nest­ing level.

Click­ing on Time­line on the left brings up a visu­al dis­play of how your web­page loads:

This gives you a real­ly nice visu­al­iza­tion of how your page loads; and you can fil­ter the Dura­tion by 10ms or so, in order to see only the things that take a sig­nif­i­cant amount of time.

Twig Tem­plate Per­for­mance Profiling

All of this pro­fil­ing is pret­ty amaz­ing, but it’s only show­ing us pro­fil­ing infor­ma­tion that Craft or plu­g­ins might be record­ing. What if we want­ed to pro­file our own Twig tem­plates? Read on!

Often times we might want to pro­file spe­cif­ic sec­tions of our Twig tem­plates. To make this pos­si­ble, I cre­at­ed a free Craft CMS 3 plu­g­in called Twig Pro­fil­er that allows you to wrap chunks of code that you want profiled:

{% profile "woof" %}
    {# code goes here #}
{% endprofile %}

Just install the Twig Pro­fil­er plu­g­in via the Plu­g­in Store in the Craft CMS 3 AdminCP, and away you go!

The para­me­ter you pass in (woof in the above exam­ple) should be unique per pro­file block, so you can iden­ti­ty it when look­ing at the pro­fil­ing data.

Reload your page, and then click on the Time sec­tion of the Debug Tool­bar, and you’ll see your pro­file data:

The Cat­e­go­ry will always have Twig Pro­fil­er list­ed in it, so you can fil­ter on that to find your pro­fil­ing data quick­ly. Twig Pro­fil­er will also append the name of the cur­rent­ly ren­der­ing tem­plate, to give you some addi­tion­al context.

Click­ing on the Time­line sec­tion on the left will show you a visu­al time­line of the pro­file data:

You can have as many {% profile %} block tags a page as you like, and they can wrap around any Twig code you like (include, block, what­ev­er). You can also nest {% profile %} block tags as much as you like.

A good approach is to include {% profile %} tags in all the {% block %} tags in your layout tem­plates, so that you’ll auto­mat­i­cal­ly be pro­fil­ing your templates.

You can add more fine-grained {% profile %} tags in your tem­plates as needed.

You want to col­lect pro­fil­ing data before you have per­for­mance prob­lems, not after.

Since the tags add lit­tle to no over­head, there’s no harm in hav­ing them there. Then if you do have per­for­mance issues, you’ll have the req­ui­site pro­fil­ing data at your fingertips.

Under the hood, it uses the exact same method that Craft/​Yii2 use to record pro­fil­ing data.

Anoth­er tool that can be help­ful for diag­nos­ing Twig tem­plates is a free Craft CMS 3 plu­g­in we cre­at­ed called Tem­plate Com­ments. This plu­g­in adds a HTML com­ment with per­for­mance tim­ings to demar­cate {% block %}s and each Twig tem­plate that is included or extended:

Just install the Tem­plate Com­ments plu­g­in via the Plu­g­in Store in the Craft CMS 3 AdminCP, and it’ll auto­mat­i­cal­ly start adding these HTML com­ments to your tem­plates in local dev. If devMode is off, it does­n’t even install itself.

In addi­tion to the per­for­mance tim­ings, the com­ments that delin­eate each {% block %} and tem­plate that is included makes it eas­i­er to track down what is com­ing from where.

Plu­g­in Developers

If you’re a plu­g­in devel­op­er, do your­self (and your users!) a favor by wrap­ping impor­tant chunks of code with:

Craft::beginProfile('someUniqueIdentifier', __METHOD__ );
// Insert code here
Craft::endProfile('someUniqueIdentifier', __METHOD__ );

This allows you to assess the impact of your plu­g­in on the per­for­mance of the page loads. It’s sim­ple, easy to do, and future-you will thank your­self for doing it.

This is the exact method that Craft/​Yii2 and also Twig Pro­fil­er uses to log pro­fil­ing data.

Check out the Per­for­mance Pro­fil­ing sec­tion of the Yii2 docs for details.

Wrap­ping Up

The Debug Tool­bar can be an enor­mous help in under­stand­ing how your web­pages are load­ing; and it does even more than described here.

Hope­ful­ly this intro­duc­tion has giv­en you enough to get you up and running.

Hap­py profiling!

Further Reading

If you want to be notified about new articles, follow nystudio107 on Twitter.

Copyright ©2020 nystudio107. Designed by nystudio107