2015. július 12., vasárnap 6:05:36 UTC+2 időpontban
[email protected] a
következőt írta:
go version is 1.5 beta 1, the same was on "stock" 1.3.3 from Debian repos
OS: Debian 8.1 x64
I'm stress testing (with loader.io) this type of code in Go to create an
array of 100 items along with some other basic variables and parse them all
in the template:
package main
import (
"html/template"
"net/http"
)
var templates map[string]*template.Template
// Load templates on program initialisation
func init() {
if templates == nil {
templates = make(map[string]*template.Template)
}
templates["index.html"] = template.Must(template.ParseFiles("index.html"))
}
func handler(w http.ResponseWriter, r *http.Request) {
type Post struct {
Id int
Title, Content string
}
var Posts [100]Post
// Fill posts
for i := 0; i < 100; i++ {
Posts[i] = Post{i, "Sample Title", "Lorem Ipsum Dolor Sit Amet"}
}
type Page struct {
Title, Subtitle string
Posts [100]Post
}
var p Page
p.Title = "Index Page of My Super Blog"
p.Subtitle = "A blog about everything"
p.Posts = Posts
tmpl := templates["index.html"]
tmpl.ExecuteTemplate(w, "index.html", p)
}
func main() {
http.HandleFunc("/", handler)
http.ListenAndServe(":8888", nil)
}
My test with Loader is using 5k concurrent connections/s through 1 minute.
The problem is, just after a few seconds after starting the test, I get a
high average latency (almost 10s) and as a result 5k successful responses
and the test stops because it reaches the Error Rate of 50% (timeouts).
On the same machine, PHP gives 50k+.
I understand that it's not Go performance issue, but probably something
related to html/template. Go can easily manage hard enough calculations a
lot faster than anything like PHP of course, but when it comes to parsing
the data to the template, why is it so awful?
Any workarounds, or probably I'm just doing it wrong (I'm new to Go)?
P.S. Actually even with 1 item it's exactly the same... 5-6k and stopping
after huge amount of timeouts. But that's probably because the array with
posts is staying of the same length.
TL;DR: this is a very artificial, very specific test, please don't decide
on its result!
Go does what it's written down, only - no magic caching, JITing &so on.
If you wan't some comparison, than do it on a real application! For this
nonsense payload, I can cache the whole generated template, and write it
unconditionally, which means 5500 req/s instead of 156 req/s - see below!
http://play.golang.org/p/XU1SNjb2KcWith GOMAXPROCS=1, 1000 concurrent requests (same machine):
[email protected]:/tmp$ boom -n 10000 -c 1000
http://localhost:888810000 / 10000 Boooooooooooooooooooooooooooooooooooooooooooooooooooooooooo!
100.00 %
Summary:
Total: 15.3071 secs.
Slowest: 15.2237 secs.
Fastest: 0.0022 secs.
Average: 1.1133 secs.
Requests/sec: 653.2921
Status code distribution:
[200] 10000 responses
Response time histogram:
0.002 [1] |
1.524 [8480] |∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎
3.046 [495] |∎∎
4.569 [749] |∎∎∎
6.091 [4] |
7.613 [123] |
9.135 [13] |
10.657 [4] |
12.179 [0] |
13.702 [0] |
15.224 [131] |
Latency distribution:
10% in 0.1168 secs.
25% in 0.2253 secs.
50% in 0.4019 secs.
75% in 1.2766 secs.
90% in 3.0859 secs.
95% in 3.5142 secs.
99% in 15.1037 secs.
With GOMAXPROCS=1, 5000 concurrent requests:
[email protected]:/tmp$ boom -n 10000 -c 5000
http://localhost:888810000 / 10000 Boooooooooooooooooooooooooooooooooooooooooooooooooooooooooo!
100.00 %
Summary:
Total: 63.6932 secs.
Slowest: 63.2481 secs.
Fastest: 0.0021 secs.
Average: 7.9291 secs.
Requests/sec: 157.0026
Status code distribution:
[200] 10000 responses
Response time histogram:
0.002 [1] |
6.327 [5988] |∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎
12.651 [1461] |∎∎∎∎∎∎∎∎∎
18.976 [1355] |∎∎∎∎∎∎∎∎∎
25.300 [0] |
31.625 [567] |∎∎∎
37.950 [592] |∎∎∎
44.274 [0] |
50.599 [0] |
56.923 [0] |
63.248 [36] |
Latency distribution:
10% in 0.3334 secs.
25% in 0.9190 secs.
50% in 1.7652 secs.
75% in 15.1519 secs.
90% in 31.2858 secs.
95% in 31.8165 secs.
99% in 32.1586 secs.
With GOMAXPROCS=8, 5000 concurrent requests (phisical CPUs: 4)
[email protected]:/tmp$ boom -n 10000 -c 5000
http://localhost:888810000 / 10000 Boooooooooooooooooooooooooooooooooooooooooooooooooooooooooo!
100.00 %
Summary:
Total: 64.2826 secs.
Slowest: 63.5283 secs.
Fastest: 0.0020 secs.
Average: 8.7877 secs.
Requests/sec: 155.5630
Status code distribution:
[200] 10000 responses
Response time histogram:
0.002 [1] |
6.355 [6796] |∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎
12.707 [855] |∎∎∎∎∎
19.060 [956] |∎∎∎∎∎
25.413 [0] |
31.765 [771] |∎∎∎∎
38.118 [352] |∎∎
44.470 [0] |
50.823 [0] |
57.176 [0] |
63.528 [269] |∎
Latency distribution:
10% in 0.5582 secs.
25% in 1.2234 secs.
50% in 3.3164 secs.
75% in 7.7569 secs.
90% in 31.3622 secs.
95% in 32.0004 secs.
99% in 63.3140 secs.
What I've spoken about (simplest
handler):
http://play.golang.org/p/p-Yab4yN1U[email protected]:/tmp$ boom -n 10000 -c 5000
http://localhost:888810000 / 10000 Boooooooooooooooooooooooooooooooooooooooooooooooooooooooooo!
100.00 %
Summary:
Total: 63.9838 secs.
Slowest: 63.2345 secs.
Fastest: 0.0025 secs.
Average: 6.7039 secs.
Requests/sec: 156.2896
Status code distribution:
[200] 10000 responses
Response time histogram:
0.003 [1] |
6.326 [6410] |∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎
12.649 [1766] |∎∎∎∎∎∎∎∎∎∎∎
18.972 [1033] |∎∎∎∎∎∎
25.295 [0] |
31.619 [723] |∎∎∎∎
37.942 [12] |
44.265 [0] |
50.588 [0] |
56.911 [0] |
63.234 [55] |
Latency distribution:
10% in 0.4180 secs.
25% in 1.1932 secs.
50% in 3.1853 secs.
75% in 7.4987 secs.
90% in 15.7431 secs.
95% in 31.2491 secs.
99% in 31.5867 secs.
You should cache as much as possible, and don't repeat what's already
cached:
http://play.golang.org/p/F85MmNQi1_[email protected]:/tmp$ boom -n 10000 -c 5000
http://localhost:888810000 / 10000 Boooooooooooooooooooooooooooooooooooooooooooooooooooooooooo!
100.00 %
Summary:
Total: 1.8361 secs.
Slowest: 1.6736 secs.
Fastest: 0.0015 secs.
Average: 0.6732 secs.
Requests/sec: 5446.2187
Status code distribution:
[200] 10000 responses
Response time histogram:
0.001 [1] |
0.169 [26] |
0.336 [202] |∎
0.503 [1766] |∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎
0.670 [2754] |∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎
0.838 [4308] |∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎∎
1.005 [412] |∎∎∎
1.172 [173] |∎
1.339 [3] |
1.506 [172] |∎
1.674 [183] |∎
Latency distribution:
10% in 0.4224 secs.
25% in 0.5773 secs.
50% in 0.6800 secs.
75% in 0.7444 secs.
90% in 0.8201 secs.
95% in 1.0264 secs.
99% in 1.6086 secs.