Measuring Execution Time of Liquid Code

This guide will help you measure the execution time of Liquid code fragments using the time_diff filter. You can use this quick and simple method to find out which part of a page is slow.

Requirements

This is an advanced tutorial. To follow it, you should be familiar with basic platformOS concepts, the topics in the Get Started section, the time_diff and to_time Liquid filters, and how to create application logs.

• platformOS Workflow
• Get Started
• Liquid filter: time_diff
• Liquid filter: to_time
• Creating application Logs

Steps

Measuring the execution time of Liquid code fragments using the time_diff Liquid filter is a three-step process:

Step 1: Identify measuring points

Assuming there is a problem somewhere, you have to decide which parts to measure. Take a look at this sample snippet.

{% graphql g = 'modules/n_plus_one/n1_programmers' %}

{% for programmer in g.programmers.results %}
  <tr>
    <td>{{ programmer.properties.email }}</td>
    <td>{{ programmer.properties.title }}</td>
    <td>{{ programmer.company.properties.name }}</td>
  </tr>
{% endfor %}

There are two suspicious parts that could cause the results to be displayed slowly:

1. GraphQL query
2. for loop rendering records

Step 2: Add to_time and time_diff filters

Use the to_time and time_diff filters to measure execution times.
The graph_duration and render_duration variables store partial execution times in milliseconds. The total_duration variable stores the overall execution time of the code block.

{% liquid
  assign __start = "now" | to_time
  graphql g = 'modules/n_plus_one/programmers'
  assign __graph = "now" | to_time
%}

{% for programmer in g.programmers.results %}
  <tr>
    <td>{{ programmer.properties.email }}</td>
    <td>{{ programmer.properties.title }}</td>
    <td>{{ programmer.company.properties.name }}</td>
  </tr>
{% endfor %}

{% liquid
  assign __render = "now" | to_time
  assign _total_duration = __start | time_diff: __render
  assign _graph_duration = __start | time_diff: __graph
  assign _render_duration = __graph | time_diff: __render
  log _total_duration, type: "benchmark-total"
  log _graph_duration, type: "benchmark-graph"
  log _render_duration, type: "benchmark-render"
%}

Step 3: Check results in logs

Test results are sent to your instance log stream and can be accessed by using the
pos-cli logs tool.

Live example and source code

To check how it works on a real webpage go to the live example page.
Source code can be found on GitHub.

Next steps

Congratulations! You know how to measure the execution time of Liquid code fragments using the time_diff filter. Check out another tutorial that uses this method for testing two different solutions.

• Loading Related Records