Friday, 23 January 2015

Restructuring DotLiquid: Part 2

Bringing down the Hammer

I mentioned in Part 1 that DotLiquid's Condition hierarchy could do with being a bit more object oriented.

As conditions are a relatively small and isolated part of the API, it's a great place to start this series in earnest, so that's where I'll begin.

The Restructure

Here's a before and after of the Condition class hierarchy.

BEFORE

AFTER

First, I introduced a new interface, ICondition, and I did this for two reasons:

  1. Not all future developers will want to use the class ConditionBase as a base - they might have new code requirements or their own base class.
  2. No class that has a dependency on conditions should be forced to depend upon a specific implementation - by using the interface I make those classes compatible with any implementation.

Next, I refactored And and Or logic out of Expression and into their own classes. I did this because the code for And, Or and Expression may be logically cohesive, but it is not functionally cohesive. Incidentally, their code's lack of functional cohesion is what made them so easy to separate.

I made ConditionBase an abstract class to better indicate its purpose as a foundation, as opposed to a class that can be used effectively on its own.

I moved the static collection Operators out of ExpressionCondition and into its own class. This needs further work, as it shouldn't be static at all, but it's a start. More on this in a later post.

The IsElse property is a classic code smell because it will only be true on one occasion: when the Type is ElseCondition. Any logic that utilises the property would be better off inside the ElseCondition itself, thereby encapsulating the functionality, so I changed the signature of the Evaluate method to take a ConditionalStatementState object and moved the check for whether an ElseCondition should render inside ElseCondition.

// BEFORE
// =====================
// The owning block's render method:
var executeElseBlock = true;
foreach (var block in Blocks)
{
    if (block.IsElse)
    {
        if (executeElseBlock)
        {
           return RenderAll(block.Attachment, context, result);
        }
    }
    else if (block.Evaluate(context))
    {
        RenderAll(block.Attachment, context, result);
        executeElseBlock = false;
    }
}

// The ElseCondition's evaluate method:
public override bool Evaluate(Context context)
{
    return true;
}

// AFTER
// =====================
// The owning block's render method:
var state = new ConditionalStatementState(context);
foreach (var block in Blocks)
{
    if (block.Evaluate(state))
    {
        ++state.BlockRenderCount;
        var retCode = block.Render(context, result);
        if (retCode != ReturnCode.Return)
            return retCode;
    }
}

// The ElseCondition's evaluate method:
public override bool Evaluate(ConditionalStatementState state)
{
    return state.BlockRenderCount <= 0;
}

It's worth noting that I could have introduced an additional base class for AndCondition and OrCondition for which they override the evaluate method and share the Left and Right properties, but they do so little internally that it felt like overkill. Should they ever grow in size, an abstract base class can be retrofitted painlessly enough.

Summary

Overall, this is a great first step on the path to a clean and pure API, but there's still a lot more work to be done. I suspect that by the end of this series DotLiquid's API will be a significantly different beast, exposing the same functionality in a much more flexible API.

I'm really enjoying the challenge and, if you'd like me to clarify anything, feel free to let me know in the comments!

Wednesday, 21 January 2015

Restructuring DotLiquid: Part 1

Introduction

In the previous series, Optimising DotLiquid, the focus was to improve rendering performance. In this series, the focus is to improve DotLiquid's API.

With DotLiquid v2.0 on the far horizon, now is the perfect time to smooth any rough edges that have appeared over the course of development and distil the API into its purest, cleanest form.

What Makes a Great API?

Accessible

For an API to be accessible requires consistency in the naming convention it uses, it's method signatures and chosen design patterns. The API should also be minimalist, exposing no more public methods, objects or functionality beyond those that drive the end user's interaction with the API.

Flexible

A great API makes as few assumptions about how it will be used as possible. Keeping class coupling to a minimum, allowing the end user to pick and choose functionality with good object oriented design and keeping class dependencies to a minimum are all part of making an API flexible.

Extensible

A great API has to be easy to extend. This means making key methods virtual, classes concise and substitutable and avoiding any behind the scenes hack-magic. The principles of SOLID really come into their own when it comes to extensibility, because you never know which direction the next developer will want to go.

A Bird's Eye View

When fine tuning an API, implementation takes a back seat to architecture. After all, we're designing the interface by which developers interact with the library to achieve a goal, not how that goal is achieved.

The quickest way to get an architectural overview is to add a class diagram to the project. Here's the class diagram for DotLiquid as it stands at the end of Optimizing DotLiquid.

This diagram tells me a lot about the state of the DotLiquid API as it currently stands.

The classes with a dotted outline are helper classes, extension classes and containers for commonly used resources. This is fine in a small project, but in an API this could be preventing a third party from tweaking core functionality. I'll be looking to see what can be refactored into instance classes that are provided as configuration to templates, improving flexibility and customisability.

The class Condition isn't respecting the Single Responsibility Principle. It currently has the responsibilities of evaluating an expression, evaluating an AND condition and evaluating an OR, too. ElseCondition and the property IsElse aren't the OOP ideal, either, so refactoring of the condition hierarchy will yield benefits for Extensibility.

The down arrow marked against quite a few of the methods in this diagram indicates the use of the internal access modifier. In the places that it's been used, it would appear that these methods are being used as back door access to functionality that isn't exposed publicly. This is a code smell that harms extensibility and may indicate deeper structural issues, so I'll be looking to do away with them completely.

The Tag class and associated hierarchy has a wide, shallow inheritance structure that is self-explanatory. This is an example of great Object Oriented Design. Other than a few public and internal methods I'd like to clean up, I doubt there's much work to be done to the already clean, accessible signature seen here.

What's Next?

In the next post of this series I'll single out an area of DotLiquid's architecture that could use improvement, explain why such improvements are needed and then implement the changes with before and after class diagrams...

It's going to be awesome!

Friday, 16 January 2015

Optimising DotLiquid: Part 6

Exceptions Should Be Exceptional

A recent merge into the main DotLiquid repository added support for the keywords continue and break using exceptions and try/catch further up the render chain for flow control.

There are two significant reasons why exceptions should never be used for controlling the flow of a program:

  1. Exceptions have a major performance impact.
  2. It is not obvious without serious digging where those exceptions will be handled or if they will be handled at all.

Having this exception-based implementation is better than not having an implementation, of course, but in this series' war on performance it is an obvious target.

Optimisation

The concept for this optimisation is simple enough: to replace the flow controlling exceptions and try/catch handling with proper program flow.

You can see the full changeset on GitHub, but below is a brief summary of the changes.

The break tag class

// BEFORE
// ==================================
public class Break : Tag
{
    public override void Render(
                            Context context, 
                            TextWriter result)
    {
        throw new BreakInterrupt();
    }
}

// AFTER
// ==================================
public class Break : Tag
{
    public override ReturnCode Render(
                                Context context, 
                                TextWriter result)
    {
        return ReturnCode.Break;
    }
}

Shared - the RenderAll loop body

// BEFORE
// ==================================
if (token is IRenderable)
    ((IRenderable) token).Render(context, result);
else
    result.Write(token.ToString());

// AFTER
// ==================================
var renderable = token as IRenderable;
if (renderable != null)
{
    var retCode = renderable.Render(context, result);
    if (retCode != ReturnCode.Return)
        return retCode;
}
else
    result.Write(token.ToString());

The for tag class - break and continue handling

// BEFORE
// ==================================
try
{
    RenderAll(NodeList, context, result);
}
catch (BreakInterrupt)
{
    break;
}
catch (ContinueInterrupt)
{
}

// AFTER
// ==================================
if (RenderAll(NodeList, context, result) == ReturnCode.Break)
    break;

A quick re-run of all of the Unit Tests tells me that this far-reaching changeset has maintained all the original expected behaviours.

Initial Timings

The below timings were all taken during the same time period on the same machine. They are based on 10,000 iterations per test.

Render Time (ms)Part 5With New Flow Control
Minimum 6.631110 5.78710
Maximum 8.65750 7.61880
Range 2.02640 1.83170
Average 6.87194 5.99984
Std. Deviation 0.20780 0.18964

Summary

Simply avoiding the anti-pattern of using exceptions to control program flow has reduced render time by more than 10%.

A minor side-effect of updating the program flow in this way is that anyone who has written their own tags will need to make the following changes:

  • The return Type of the Render method is now ReturnCode.
  • Wherever return is used, return ReturnCode.Return instead.
  • Whenever the result of RenderAll is not ReturnCode.Return, return that result immediately. (Example in Block.RenderAll)

This side effect only affects developers who have created their own tags, anyone downloading and using the library as-is will enjoy increased performance without having to make any changes.

Thursday, 15 January 2015

Optimising DotLiquid: Part 5

A New Frontier

The Optimising DotLiquid series is so far off to a very promising start. With the core classes significantly improved, its now time to optimise the DotLiquid featureset as a whole, and that means I need a new test template.

The New Template

The new template is designed to incorporate all flow control, iteration and variable tags. A number of different parameter variations for each tag have also been included.

It's ugly, but it does the job:

{% for x in (1..5) %}
<h1>Tests all except filters</h1>
Also doesn't use INCLUDE or EXTENDS, to be tested later
<div>
<h2>Variable Tags</h3>
<h3>Assign</h3>
{% assign handle = 'cake' -%}
{{ handle }}
<h3>Capture</h3>
{% capture my_variable %}I am being captured.{% endcapture -%}
{{ my_variable }}
</div>
<div>
<h2>Control Flow Tags</h2>
<h3>Case (non-else)</h3>
{% case handle -%}
  {% when 'cake' -%}
     This is a cake
  {% when 'cookie' -%}
     This is a cookie
  {% else -%}
     This is not a cake nor a cookie
{% endcase -%}
<h3>Case (else)</h3>
{% case handle -%}
  {% when 'a' -%}
     This is a cake
  {% when 'b' -%}
     This is a cookie
  {% else -%}
     The else statement was reached
{% endcase -%}
<h3>If equals (non-else)</h3>
{% if user.name == 'Steve Jackson' -%}
  Equals failed on match
{% elsif user.name == 'Steve Lillis' -%}
  Equals was a success
{% else -%}
  Equals failed to else
{% endif -%}
<h3>If not equals (non-else)</h3>
{% if user.name != 'Steve Jackson' -%}
  Not equals was a success
{% else -%}
  Not equals failed
{% endif -%}
<h3>If (else)</h3>
{% if user.name == 'Steve Jackson' -%}
  Unexpected user
{% else -%}
  Else body reached
{% endif -%}
<h3>Unless</h3>
{% unless user.name == 'Steve Jackson' -%}
  Unless worked
{% else -%}
  Unless failed
{% endunless -%}
</div>
<div>
<h2>Iteration Tags</h2>
<h3>For (with cycle)</h3>
{% for item in user.items -%}
 {% cycle 'one', 'two', 'three' %}: {{ item.description }} 
{% endfor -%}
<h3>For (reversed)</h3>
{% for item in user.items reversed -%}
 {% cycle 'one', 'two', 'three' -%}: 
        {% if item.description == 'First Item' -%} 
  {{ item.description | upcase -}} 
 {% else -%} 
  {{ item.description -}} 
 {% endif -%}
{% endfor -%}
<h3>For (Limit: 2)</h3>
{% for item in user.items limit:2 -%}
 {% cycle 'one', 'two', 'three' %}: {{ item.description }} 
{% endfor -%}
<h3>For (Offset: 2)</h3>
{% for item in user.items offset:2 -%}
 {% cycle 'one', 'two', 'three' %}: {{ item.description }} 
{% endfor -%}
<h3>For Range</h3>
{% for i in (1..4) -%}{{ i -}},
{% endfor -%}
<h3>For Range (Continue on 2)</h3>
{% for i in (1..4) -%} {% if i == 2 %} {% continue %} 
{% endif %} {{ i -}},
{% endfor -%}
<h3>For Range (Break on 2)</h3>
{% for i in (1..4) -%} {% if i == 2 %} {% break %} 
{% endif %} {{ i -}},
{% endfor -%}
<h3>Table Row (Cols:2, Limit:4)</h3>
<table>
{% tablerow item in user.items cols:2 limit:4 %}
  {{ item.Description }}
  {{ item.Cost }}
{% endtablerow %}
</table>
</div>
{% endfor %}

Initial Timings

The below timings were all taken during the same time period on the same machine. They are based on 10,000 iterations per test.

Render Time (ms)Original CodeWith Optimisations
Minimum 15.89480 6.52180
Maximum 20.14610 8.96140
Range 4.25130 2.43960
Average 16.35774 6.76287
Std. Deviation 0.42730 0.20170

Summary

The optimisations made thus far have had a distinct impact but ~6.8 milliseconds to render is still much higher than I'd like, especially if a reduced render time is only a few minor improvements away.

In the next post ill be overhauling how the break and continue keywords are implemented in DotLiquid, as I've noticed that they're currently using exceptions to control program flow.

Wednesday, 14 January 2015

Optimising DotLiquid: Part 4

Low Hanging Fruit

I've already snagged some low hanging fruit in the Optimising DotLiquid series by avoiding rework and respecting regex. DotLiquid's rendering is now more than twice as fast.

There's still more gains for the taking, though, and now that I'm familiar with the codebase I've turned my sights squarely on the Hash class.

The Hash class is used everywhere in DotLiquid for storing and retrieving the current scope's data, so even a small performance gain should have a large impact.

Optimisations

I replaced occasions of checking a Dictionary for a key before getting the value with a single call to TryGetValue.

// BEFORE
// ==================================
if (_nestedDictionary.ContainsKey(key))
    return _nestedDictionary[key];

// AFTER
// ==================================
object result;
if (_nestedDictionary.TryGetValue(key, out result))
    return result;

The class For, which renders loop blocks, used the reflection-based method Hash.FromAnonymousObject in every iteration. I avoided the overhead of reflection by setting the values directly instead.

// BEFORE
// ==================================
context["forloop"] = Hash.FromAnonymousObject(new
{
    name = _name,
    length = length,
    index = index + 1,
    index0 = index,
    rindex = length - index,
    rindex0 = length - index - 1,
    first = (index == 0),
    last = (index == length - 1)
});

// AFTER
// ==================================
var forHash = new Hash();

forHash["name"] = _name;
forHash["length"] = length;
forHash["index"] = index + 1;
forHash["index0"] = index;
forHash["rindex"] = length - index;
forHash["rindex0"] = length - index - 1;
forHash["first"] = (index == 0);
forHash["last"] = (index == length - 1);

context["forloop"] = forHash;

A few performance critical paths cast the same object to the same Type more than once. I replaced double casts with the as operator and a null check.

// BEFORE
// ==================================
if ((obj is IIndexable) 
    && ((IIndexable) obj)
            .ContainsKey((string) part))
    return true;

// AFTER
// ==================================
var indexable = obj as IIndexable;
if (indexable != null 
    && indexable.ContainsKey((string) part))
    return true;

The frequently visited IDictionary.this[object key] implementation in Hash checks the object's Type is string and throws an exception if not. Since the subsequent cast to string will throw an InvalidCastException under that circumstance anyway, I removed the check to improve performance.

// BEFORE
// ==================================
if (!(key is string))
    throw new NotSupportedException();
return GetValue((string) key);

// AFTER
// ==================================
return GetValue((string) key);

I removed an unnecessary null-check in the performance critical method Hash.GetValue.

// BEFORE
// ==================================
if (_defaultValue != null)
    return _defaultValue;

return null;

// AFTER
// ==================================
return _defaultValue;

I avoided assigning values retrieved from the Hash back into the Hash.

// BEFORE
// ==================================
context.Registers["for"] = context.Registers["for"] 
                         ?? new Hash(0);

// AFTER
// ==================================
object forRegister = context.Registers["for"];
if (forRegister == null)
{
    forRegister = new Hash(0);
    context.Registers["for"] = forRegister;
}

Timings

The below timings were all taken during the same time period on the same machine. They are based on 10,000 iterations per test.

Render Time (ms)Original CodePart 3 CodeHash Improvements
Minimum 3.42810 1.50950 1.33320
Maximum 5.76840 2.99220 2.60190
Range 2.34030 1.48270 1.26870
Average 3.61269 1.56977 1.38641
Std. Deviation 0.17960 0.07936 0.06621

Summary

DotLiquid's rendering is now two and a half times faster. It's worth noting too that due the nested nature of rendering, as a template grows in size and complexity the performance savings will grow exponentially.

The next step now is to put together a mega-template that uses every single DotLiquid feature, then improve performance even further!

Tuesday, 13 January 2015

Optimising DotLiquid: Part 3

Respecting Regex

Regular expressions are a powerful tool. They're so powerful, in fact, that it's easy to get carried away.

As you might expect from a solution that relies on parsing raw text into program flow, DotLiquid uses Regex extensively. In this part of the Optimising DotLiquid series, I'll be improving how DotLiquid works with Regex.

The Optimisation

The original code for DotLiquid uses the static method Regex.Match extensively to determine whether or not given inputs match various regular expressions.

Regex.Match checks for a cached instance of the Regex class for the given expression and creates one if it doesn't exist. Regex.Match then returns the result of invoking the instance's Match method with the original input.

The default cache size for Regex.Match is 15, so more than 15 expressions being used in calls to Regex.Match across the application will result in unnecessary work recreating instances that were created previously but then dumped.

It's also worth noting that when trying to save fractions of a millisecond, as I am in this series, repeatedly looking up a cached value is wasteful.

Using static references to pre-compiled Regex instances instead of relying on Regex.Match to handle caching and persistence completely sidesteps both of these issues.

An example can be seen below and you can view the full changeset on GitHub.

// BEFORE
// ==================================
private object Resolve(string key)
{
    [...]
    var match = Regex.Match(R.Q(@"^'(.*)'$"), key);
    if (match.Success)
        return match.Groups[1].Value;
    [...]

// AFTER
// ==================================
private static Regex _singleQuotesRegex 
    = new Regex(R.Q(@"^'(.*)'$"), RegexOptions.Compiled);

private object Resolve(string key)
{
    [...]
    var match = _singleQuotesRegex.Match(key);
    if (match.Success)
        return match.Groups[1].Value;
    [...]

Check out this excellent article on compiling Regex for more information on when and when not to use compiled Regex in C#.

Timings

The below timings were all taken during the same time period on the same machine. They are based on 10,000 iterations per test.
Render Time (ms)Original CodePart 2 CodeRegexOptions.Compiled
Minimum 3.46160 3.35360 1.47660
Maximum 5.74940 5.29750 2.90560
Range 2.28780 1.94390 1.42900
Average 3.64991 3.54096 1.53506
Std. Deviation 0.16530 0.17852 0.07369

Analysis

With these changes DotLiquid rendering is now more than twice as fast!

The average time to render has been reduced to just 42% of the original average render time, with very little impact on the readability and memory usage of the code. It's a definite win.

What's Next?

There might be places where Regex isn't needed at all and simple string operations would be a better fit so I'll be reviewing the code for such opportunities.

For the next part of this series I'll also be looking at how DotLiquid rendering handles loops, cycles, assignments and case statements and potentially cutting similar performance corners as I did in Optimising DotLiquid: Part 2.

Stay tuned!

Monday, 12 January 2015

Optimising DotLiquid: Part 2

What to Improve First?

Choosing where to focus optimisation attention is all about identifying performance hotspots. Hotspots are code paths with a single, long execution time or paths that have short execution times but are visited frequently.

Using a simple divide and conquer approach, I broadly identified the areas that made up the majority of the ~4ms of rendering in the initial timings.

The biggest costs came from the main infrastructure class Context which manages the template's memory stack while it is rendered and the class Condition which evaluates the if and unless statements that are used frequently in the test template.

First Pass of Optimisations

In this pass I focused on making small, simple changes that eliminate unnecessary rework occurring within some of the most frequently called methods. I re-ran the tests after each change was applied to ensure that no individual change was raising the execution time back up. In the cases that this did occur, I undid the change.

I've provided the changes and relevant example code below and you can see the full changeset on GitHub.

The Condition Class

I amended the class to keep a reference to the operation delegate whenever the operation string is set instead of every time the condition is evaluated, reducing the number of times the lookup occurs from thousands to just a handful.

// BEFORE
// ==================================
private static bool InterpretCondition(
                            string left, 
                            string right, 
                            string op, 
                            Context context)
{
        if (string.IsNullOrEmpty(op))
        {
            object result = context[left];
            return (result != null 
                    && (!(result is bool) 
                        || (bool) result));
        }

        var leftObject = context[left];
        var rightObject = context[right];

        ConditionOperatorDelegate opDelegate;
        if (!Operators.TryGetValue(
                            op, 
                            out opDelegate))
            throw new Exceptions.ArgumentException(...);

    return opDelegate(leftObject, rightObject);
}

public virtual bool Evaluate(Context context)
{
    context = context ?? new Context();
    bool result = InterpretCondition(
                            Left, 
                            Right, 
                            Operator, 
                            context);
    ...

// AFTER
// ==================================
private string _operatorString;
private ConditionOperatorDelegate _operatorDelegate;

private string Operator
{
    get { return _operatorString; }
    set
    {
        _operatorString = value;
        if (string.IsNullOrEmpty(value))
            _operatorDelegate = (l, r) => NoOperator(l);
        else if (!Operators.TryGetValue(
                                value, 
                                out _operatorDelegate))
            throw new Exceptions.ArgumentException(...);
    }
}

public virtual bool Evaluate(Context context)
{
    // The whole InterpretCondition method is avoided
    var result = _operatorDelegate(
                        context[_left], 
                        context[_right]);
    ...

I replaced comparisons against arbitrary strings "and" and "or" with byte comparisons against constants fields named And and Or.

// BEFORE
// ==================================
switch (_childRelation)
{
    case "and":
         return result && _childCondition.Evaluate(context);
    case "or":
         ...

// AFTER
// ==================================
if (_childRelation == And) // And is a const byte value
    return result && _childCondition.Evaluate(context);

if (_childRelation == Or) // Or is a const byte value
    ... 

I replaced occurrences of double casting with a single as operator and null check.

// BEFORE
// ==================================
    if (left is Symbol)
        return ((Symbol)left).EvaluationFunction(right);
    ...

// AFTER
// ==================================
    var symbolLeft = left as Symbol;
    if (symbolLeft != null)
        return symbolLeft.EvaluationFunction(right);
    ...

The Context Class

I stored a reference to the first and last scopes in the context's list of scopes and replaced all lookups with the new references.

// BEFORE
// ==================================
    context.Scopes.Last()[_to] = _from.Render(context);
    ...
    var orphanedBlocks = 
        ((List<Block>)context.Scopes[0]["extends"]) 
               ?? new List<Block>();
    ...

// AFTER
// ==================================
    context.GlobalScope[_to] = _from.Render(context);
    ...
    var orphanedBlocks = 
        ((<Block>)context.LocalScope["extends"]) 
               ?? new List<Block>();
    ...

Timings

The timings seen below were all taken during the same time period on the same machine. They are based on 10,000 iterations per test.

Before OptimisationsAfter Optimisations
Minimum (ms) 3.45680 3.36080
Maximum (ms) 4.95130 4.97570
Range (ms) 1.49450 1.61490
Average (ms) 3.64347 3.54507
Standard Deviation (ms) 0.16981 0.18134

Analysis

A reduction in average execution time of ~0.1ms may not seem like a lot, but it represents a 3% reduction in the total time taken to render, which is a sizeable chunk.

It's worth noting that micro-optimisation is not often required, but in the case of trying to bring down a ~4ms execution time, micro-optimisations are exactly what I needed!

Summary

The careful adjustments made during this pass had a small but notable impact and were a great way to get used to the DotLiquid codebase.

I expect to make a huge performance boost in the next pass of optimisations by replacing all the uses of static method Regex.Match with pre-compiled Regex instance equivalents.

Exciting stuff!

Friday, 9 January 2015

Optimising DotLiquid: Part 1

Introduction

A colleague recently introduced me to a very interesting open source library for content templating called DotLiquid. It's actually a .NET port of a system originally produced for Ruby, and that system originated from Shopify! This kind of legacy is good, because it (usually) means that an API has stood the test of time for being fast and easy to work with.

Intrigued, I downloaded the source for DotLiquid and was pleased to find that not only is the provided API easy to understand and work with without knowing the underlying code, but the source itself has a very well structured Object Oriented architecture, too.

Digging a bit deeper I found a few places that can potentially be improved for better performance. How big the performance gain will be depends on the size and complexity of the content being passed in to be rendered.

How important that performance gain will be really depends on how time critical your rendering of content is. If you're using the templating system for rarely updated web page content, the time saved by these changes will likely be negligible, but if you're rendering a thousand different content pieces in quick succession using the same template then every millisecond saved per render is a whole second saved per batch.

Templates in DotLiquid can be parsed and cached in advance but rendering needs to occur for each piece of content using that template, so in this series I'll be working on improving the performance of DotLiquid's render method specifically.

Testing Performance: Never Guess

The most important thing to do when making efforts to optimise code is to build a reliable way to take before and after performance measurements. By taking measurements in this way, it can be said for certain whether a change to the source had a positive, negative or negligible impact on how it performs.

As the ambition of this series is to improve the speed at which DotLiquid renders content, I have written a simple method for taking timings as my performance metric.

static void RunTest(int iterations)
{
    var template = Template.Parse(TemplateCode);

    var stopwatch = new Stopwatch();
    var timings = new List<double>();
            
    for (var i = 0; i < iterations; ++i)
    {
        var hash = Hash.FromAnonymousObject(GetFreshTestObject());

        stopwatch.Reset();
        stopwatch.Start();

        template.Render(hash);

        stopwatch.Stop();

        timings.Add(stopwatch.Elapsed.TotalMilliseconds);
    }

    Console.WriteLine(@"Iterations: {0}", iterations);

    Console.WriteLine(@"   Average: {0:0.00000}ms", 
                      timings.Average());

    Console.WriteLine(@"   Std Dev: {0:0.00000}ms", 
                      CalculateStdDev(timings));

    Console.WriteLine(@"   Minimum: {0:0.00000}ms", 
                      timings.Min());

    Console.WriteLine(@"   Maximum: {0:0.00000}ms", 
                      timings.Max());

    Console.WriteLine();
}

static void Main()
{
    // Warm up
    Console.WriteLine("Warm up");
    RunTest(100);

    // Real tests
    Console.WriteLine("Real tests");
    RunTest(10000);
    RunTest(1000);
            
    Console.ReadKey();
}

You may notice that I run a warm up test first. C#'s JIT compiler has to compile the code on first execution and I don't want the extra time taken to compile to impact the timings. The warm up run gets JIT compilation out of the way.

To ensure that performance testing results are as reliable as possible, I'll be running the Release build because it is properly optimised and I'll be running it outside of the IDE to remove the IDE's performance impact.

The Test Template

I'll be using the same DotLiquid template throughout the series to keep the parameters of the test consistent. I've used a variety of tags so that optimisations that only affect one tag type will still be included in the timings.

<div>
<p><b>
{% if user.name == 'Steve Lillis' -%}
  Welcome back
{% else -%}
  I don't know you!
{% endif -%}
</b></p>
{% unless user.name == 'Steve Thompson' -%}
  <i>Unless example</i>
{% endunless -%}
{% comment %}A comment for comments sake{% endcomment %}
<ul>
<li>This entry and something about baked goods</li>
<li>
{% assign handle = 'cake' -%}
{% case handle -%}
  {% when 'cake' -%}
     This is a cake
  {% when 'cookie' -%}
     This is a cookie
  {% else -%}
     This is not a cake nor a cookie
{% endcase -%}
</li>
</ul>
</div>
<p>{{ user.name | upcase }} has the following items:</p>
<table>
{% for item in user.items -%}
  <tr>
     <td>
        {% cycle 'one', 'two', 'three' %}
     </td>
     <td>
        {{ item.description }} 
        {% assign handle = 'cake' -%}
        {% case handle -%}
          {% when 'cake' -%}
             This is a cake
          {% when 'cookie' -%}
             This is a cookie
          {% else -%}
             This is not a cake nor a cookie
        {% endcase -%}
     </td>
     <td>
        {{ item.cost }}
     </td>
  </tr>
{% endfor -%}
{% for item in user.items reversed -%}
  <tr>
     <td>
        {% cycle 'one', 'two', 'three' %}
     </td>
     <td>
        {% if item.description == 'First Item' -%}
            {{ item.description | upcase }}
        {% else %}
            {{ item.description }}
        {% endif %}
     </td>
     <td>
        {{ item.cost }}
     </td>
  </tr>
{% endfor -%}
</table>

Initial Timings

Iterations:100010000
Minimum (ms) 3.44020 3.42810
Maximum (ms) 8.25000 7.02620
Range (ms) 4.80980 3.59810
Average (ms) 3.95568 3.76747
Standard Deviation (ms) 0.41129 0.23009

Early Analysis

I only have the initial timings, having made no changes to the code yet, but there's already some points of note.

The standard deviation for 1k and 10k iterations only differs by a fairly negligible ~0.2ms, but the maximum time any one iteration took differs by ~1.2ms. This discrepancy combined with a preliminary examination of DotLiquid's code suggests that excessive object allocation on the heap could be triggering garbage collection, which I'd want to avoid if I can.

The average in both cases is a lot closer to the minimum than the maximum, even when taking the standard deviation into account. This could imply that the first time a DotLiquid template is rendered it caches values to save time on subsequent renders. It might be possible to improve initial render performance by moving the caching out of rendering and into parsing or even compile time. A very brief look over the codebase reveals a few Regexes that aren't pre-compiled, there may be similar savings elsewhere too.

The difference in average between 1k and 10k is just ~0.2ms, hardly a difference at all. This tells me that the render method has been built with consideration to being called multiple times on a single template object, so I likely won't have to make many improvements to how the render method cleans up.

Going Forward

That's it for now. In the next post in this series I'll be investigating the DotLiquid codebase, making changes and hopefully presenting some improved timings. Wish me luck!