Skip to content
Permalink
Branch: master
Find file Copy path
Find file Copy path
Fetching contributors…
Cannot retrieve contributors at this time
98 lines (71 sloc) 3.59 KB
---
converter: markdown
metadata:
title: Measuring Execution Time of Liquid Code Fragments (time_diff)
description: This guide will help you measure the execution time of Liquid code fragments using the time_diff filter.
slug: best-practices/performance/measuring-execution-time-liquid-time-diff
searchable: true
---
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.
* [How platformOS Works](/how-platformos-works)
* [Get Started](/get-started)
* [Liquid filter: time_diff](/api-reference/liquid/platformos-filters#time_diff)
* [Liquid filter: to_time](/api-reference/liquid/platformos-filters#to_time)
* [Creating application Logs](/best-practices/qa/creating-application-logs)
## Steps
Measuring the execution time of Liquid code fragments using the `time_diff` Liquid filter is a three-step process:
1. Identify measuring points
2. Add `to_time` and `time_diff` filters
3. See results in logs
### 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.
```liquid
{% raw %}
{% 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 %}
{% endraw %}
```
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
{% raw %}
{% 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 %}
{% 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" %}
{% endraw %}
```
### Step 3: See 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 see how it works on a real webpage go to the [live example](https://examples.platform-os.com/programmers/with_companies_2) page.
[Source code](https://github.com/mdyd-dev/marketplace-nearme-example/tree/master/modules/n_plus_one) 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 Models](/tutorials/models/loading-related-models)
You can’t perform that action at this time.