We all know that awful feeling when a page is loading forever. We usually blame the hosting provider, the theme, or oftentimes a plugin. One common way to figure out which plugin is misbehaving is to start disabling plugins one by one, but unless you love clicking hundreds of times or more, there are better ways.
In this post, we’re going to explore one metric that can help us with this, Time To First Byte or TTFB for short.
What is TTFB?
TTFB is a browser metric for the response from the server, which tells us how much time was spent crunching bytes in PHP runtime. We can see this metric in Developer Console under the Network tab in your favorite browser.
What this doesn’t tell us is how much of that time is being shared between database, plugins, theme, outbound HTTP calls with plugins (license check for example), or perhaps a mail handler.
Luckily, there is an open source project that can give us that information.
Debugging Performance with OpenCensus
OpenCensus originates from Google where a set of libraries called Census are used to capture traces and metrics from the services. Down the line tools were open sourced and are now the basis for many cloud providers and application performance management vendors which use it to capture real-time metrics.
You can debug performance issues in your local development and monitor the performance of your WordPress installation.
Debugging Performance on a Demo Store
For this article, we are going to use https://demo-config.mywoocart.com/ which is one of the demo stores on WooCart.
We have created and open sourced a
docker-compose project that you can run on your store with detailed instructions on how to run it.
Our example uses the same project to inject tracing and consists of:
- Jaeger (UI for viewing the reports)
- Nginx+PHP-FPM+OpenCensus (tracing framework) combo
- MariaDB database
We want to see what is causing TTFB of 1450ms on
http://localhost/product-category/accessories/. Our example page is a list of all products from a specific category so there might be some weird things going on. 🙂
Opening Jeager UI we can see this long waterfall model of everything that was traced.
And right away two things stand out:
A mysterious curl call that is taking 300ms.
This function call seems to be responsible for determining the location of the user if Geolocation is turned on in WooCommerce. Since the request is coming from the private IP address (localhost) it determines public IP of our server to get Geolocation information. Not something that I was expecting from WooCommerce to do, as we can safely disable the Geolocation feature for local development.
load_template function call that is taking a whopping one second.
Again we can easily see which file is causing the problem.
Looks like a joker put a sleep function in there. This one is equally easy to resolve. By removing the sleep function we get to a nice 88ms of response time.
load_text_domain function is used to load translation (.mo) files into PHP runtime. Interestingly the parsing of large translation files is quite slow, in our case, it added 92ms to total load time. Because the operation is CPU bound it makes sense to cache it since it is executed on each page load.
And afterward with a simple caching enabled.
What else can we do?
One great feature of OpenCensus is that we can write tracers for any public or private function anywhere in our codebase.
Above is an example of adding tracing for the WordPress database class.
Or we might want to trace
get_option function call as sometimes plugin or theme developers stuff all sort of things to
options and mark keys for autoloading.
Check out opencensus-php documentation if you want to learn more.
How WooCart is helping you debug performance
We want OpenCensus to be readily available to store owners to point them to the load problems with their stores quickly. We are integrating reporting to the Plugin Usage tab which is gonna show collected metrics per plugin.
If you’d like to learn more about what we’re doing, contact us and let’s have a chat.