Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

html/template: escapeTemplate is inefficient #10605

Closed
chowey opened this issue Apr 29, 2015 · 7 comments
Closed

html/template: escapeTemplate is inefficient #10605

chowey opened this issue Apr 29, 2015 · 7 comments
Labels
FrozenDueToAge
Milestone
Go1.5

Comments

@chowey
Copy link

chowey commented Apr 29, 2015

I have been profiling the execution of our templates using the "html/template" package.

The time to parse and execute a template was around 100ms. I realize that the first time the template is executed, "html/template" escapes it using the internal escapeTemplate() function. Still it seemed extremely slow to me.

Using the "pprof" tool, I found the culprit:

template.ExecuteTemplate  4.78s
...
template.escapeTemplate   4.30s
...
template.tSpecialTagEnd   3.96s
...
strings.ToLower           3.37s

That seems like a lot of time spent lower-casing a string. By inserting a counter into the tSpecialTagEnd function, I found out that strings.ToLower is being called 4320 times per request.

The offending function looks like this:

// tSpecialTagEnd is the context transition function for raw text and RCDATA
// element states.
func tSpecialTagEnd(c context, s []byte) (context, int) {
    if c.element != elementNone {
        if i := strings.Index(strings.ToLower(string(s)), specialTagEndMarkers[c.element]); i != -1 {
            return context{}, i
        }
    }
    return c, len(s)
}

It occurs to me that:

  • the byte slice s is cast to a string each time (new memory allocation)
  • the size of this string is proportional to the length of the document
  • the string is lower-cased (new memory allocation)
  • the lower-cased string is indexed to find the first occurrence of the specialTagEndMarker
  • the lower-cased string is discarded, to be re-computed next time
  • this is repeated 4320 times
  • if the number of calls to tSpecialTagEnd increases linearly with file size, the time complexity is O(n^2)

The time complexity could be reduced to O(n) by either:

  • lower-casing the string once and caching it
  • indexing while lower-casing, instead of lower-casing the whole string before indexing it

It also seems unnecessary to use the strings package when the bytes package can lower-case just fine. This would save an allocation.

I tried another template file that was over 1MB (about 20 html documents surrounded by "if" statements), and the ExecuteTemplate function took 20 seconds.
@josharian josharian changed the title html/template catastrophicly slow on escapeTemplate html/template: escapeTemplate is inefficient Apr 29, 2015
@josharian josharian added this to the Go1.5Maybe milestone Apr 29, 2015
@bradfitz
Copy link
Contributor

/cc @robpike

@dspezia
Copy link
Contributor

dspezia commented Apr 29, 2015

I could reproduce by generating a HTML template including numerous "<textarea>" elements. It does not seem very difficult to fix. I'm working on it.

@chowey
Copy link
Author

chowey commented Apr 29, 2015

I don't know why, but this doesn't seem limited to "textarea", etc. elements. I think tSpecialTagEnd must be being called much more frequently than this.

Here is a benchmark of a contrived template. It is formed by concatenating a bunch of wikipedia articles surrounded by "if" statements:

package main

import (
    "bytes"
    "fmt"
    "html/template"
    "io/ioutil"
    "net/http"
    "testing"
)

var documents = []string{
    "http://en.wikipedia.org/wiki/William_Shakespeare",
    "http://af.wikipedia.org/wiki/William_Shakespeare",
    "http://bs.wikipedia.org/wiki/William_Shakespeare",
    "http://es.wikipedia.org/wiki/William_Shakespeare",
    "http://hr.wikipedia.org/wiki/William_Shakespeare",
    "http://it.wikipedia.org/wiki/William_Shakespeare",
    "http://pam.wikipedia.org/wiki/William_Shakespeare",
    "http://la.wikipedia.org/wiki/Gulielmus_Shakesperius",
    "http://mk.wikipedia.org/wiki/%D0%92%D0%B8%D0%BB%D0%B8%D1%98%D0%B0%D0%BC_%D0%A8%D0%B5%D0%BA%D1%81%D0%BF%D0%B8%D1%80",
    "http://pl.wikipedia.org/wiki/William_Szekspir",
    "http://ru.wikipedia.org/wiki/%D0%A8%D0%B5%D0%BA%D1%81%D0%BF%D0%B8%D1%80,_%D0%A3%D0%B8%D0%BB%D1%8C%D1%8F%D0%BC",
    "http://sr.wikipedia.org/wiki/%D0%92%D0%B8%D0%BB%D0%B8%D1%98%D0%B0%D0%BC_%D0%A8%D0%B5%D0%BA%D1%81%D0%BF%D0%B8%D1%80",
    "http://sv.wikipedia.org/wiki/William_Shakespeare",
    "http://th.wikipedia.org/wiki/%E0%B8%A7%E0%B8%B4%E0%B8%A5%E0%B9%80%E0%B8%A5%E0%B8%B5%E0%B8%A2%E0%B8%A1_%E0%B9%80%E0%B8%8A%E0%B8%81%E0%B8%AA%E0%B9%80%E0%B8%9B%E0%B8%B5%E0%B8%A2%E0%B8%A3%E0%B9%8C",
    "http://zh.wikipedia.org/wiki/%E5%A8%81%E5%BB%89%C2%B7%E8%8E%8E%E5%A3%AB%E6%AF%94%E4%BA%9A",
}

var languages = []string{"en", "af", "bs", "es", "hr", "it", "pam", "la", "mk", "pl", "ru", "sr", "sv", "th", "zh"}

func BenchmarkTemplate(b *testing.B) {
    // craft a big template
    var buf bytes.Buffer
    for i, lang := range languages {
        if i == 0 {
            fmt.Fprintf(&buf, "<<<if eq . %q>>>", lang)
        } else {
            fmt.Fprintf(&buf, "<<<else if eq . %q>>>", lang)
        }
        resp, err := http.Get(documents[i])
        if err != nil {
            b.Fatal(err)
        }
        if _, err = buf.ReadFrom(resp.Body); err != nil {
            b.Fatal(err)
        }
        resp.Body.Close()
    }
    fmt.Fprintf(&buf, "<<<end>>>")

    // benchmark
    b.ResetTimer()
    for i := 0; i < b.N; i++ {
        tpl, err := template.New("wiki").Delims("<<<", ">>>").Parse(buf.String())
        if err != nil {
            b.Fatal(err)
        }
        if err = tpl.Execute(ioutil.Discard, "en"); err != nil {
            b.Fatal(err)
        }
    }
}

This benchmark took 35s to run once on my machine.

@chowey
Copy link
Author

chowey commented Apr 29, 2015

Here is my stab at a faster tSpecialTagEnd:

func tSpecialTagEnd(c context, s []byte) (context, int) {
    if c.element != elementNone {
        marker := []byte(specialTagEndMarkers[c.element])
        n := bytes.IndexByte(s, '<')
        for i := 0; n != -1 && i != -1; i = bytes.IndexByte(s[n:], '<') {
            n += i
            if n+len(marker) > len(s) {
                break
            }
            next := bytes.ToLower(s[n : n+len(marker)])
            if bytes.Equal(next, marker) {
                return context{}, n
            }
            n++
        }
    }
    return c, len(s)
}

This takes advantage of the fact that each marker starts with <, which does not need lowercasing. I think bytes.IndexByte is fast.

This dropped the same benchmark from 35s down to 0.45s.

@dspezia
Copy link
Contributor

dspezia commented Apr 29, 2015

Here is my version:

// tSpecialTagEnd is the context transition function for raw text and RCDATA
// element states.
func tSpecialTagEnd(c context, s []byte) (context, int) {
    if c.element != elementNone {
        if i := indexTagEnd(s, specialTagEndMarkers[c.element]); i != -1 {
            return context{}, i
        }
    }
    return c, len(s)
}

// indexTagEnd finds the index of a special tag end in a case insensitive way, or returns -1
func indexTagEnd(s []byte, tag []byte) int {
    pfx := tag[:2]
    res := 0
    for len(s) > 0 {
        // Try to find the tag end prefix first
        i := bytes.Index(s, pfx)
        if i == -1 {
            return i
        }
        // Try to match the actual tag if there is still space for it
        if i+len(tag) <= len(s) && bytes.EqualFold(tag, s[i:i+len(tag)]) {
            return res + i
        }
        s = s[i+2:]
        res += i + 2
    }
    return -1
}

I'm preparing a CL.

@dspezia
Copy link
Contributor

dspezia commented Apr 29, 2015

Mailed https://go-review.googlesource.com/#/c/9502/

@gopherbot
Copy link

CL https://golang.org/cl/9502 mentions this issue.

@mikioh mikioh modified the milestones: Go1.5, Go1.5Maybe May 27, 2015
@golang golang locked and limited conversation to collaborators Jun 25, 2016
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Assignees
No one assigned
Labels
FrozenDueToAge
Projects
None yet
Milestone
Go1.5
Development

No branches or pull requests
6 participants
@bradfitz @josharian @mikioh @dspezia @chowey @gopherbot