Profiling your Website with Craft CMS 3’s Debug Toolbar

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 Toolbar, you now have one place to look for debugging & performance 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:

Link 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!

Link Profiling Database 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 number of queries, it’s about how performant 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:

Link Sifting 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.

Link Overall Performance 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.

Link Twig Template Performance 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:

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 collect profiling data before you have performance problems, 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.

Link Plugin 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:

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.

Link Wrapping 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!