Skip to content

Commit

Permalink
Add standard deviation for requests (#253)
Browse files Browse the repository at this point in the history 
The adds standard deviation to detailed analysis and compares for requests and TTFB. Examples:

Analysis:
```
λ warp analyze -analyze.v warp-get-2020-06-24[154208]-jmuM.csv.zst
...
Operation: GET (574228). Ran 1m0s. Size: 10000 bytes. Concurrency: 100.

Requests considered: 573756:
 * Avg: 10ms, 50%: 10ms, 90%: 15ms, 99%: 24ms, Fastest: 0s, Slowest: 117ms, StdDev: 5ms
 * TTFB: Avg: 10ms, Best: 0s, 25th: 8ms, Median: 10ms, 75th: 13ms, 90th: 15ms, 99th: 23ms, Worst: 116ms StdDev: 5ms
 * First Access: Avg: 10ms, 50%: 10ms, 90%: 15ms, 99%: 20ms, Fastest: 1ms, Slowest: 25ms, StdDev: 4ms
 * First Access TTFB: Avg: 10ms, Best: 1ms, 25th: 8ms, Median: 10ms, 75th: 13ms, 90th: 15ms, 99th: 20ms, Worst: 25ms StdDev: 4ms
 * Last Access: Avg: 10ms, 50%: 10ms, 90%: 15ms, 99%: 19ms, Fastest: 1ms, Slowest: 22ms, StdDev: 4ms
 * Last Access TTFB: Avg: 10ms, Best: 1ms, 25th: 8ms, Median: 10ms, 75th: 13ms, 90th: 15ms, 99th: 19ms, Worst: 22ms StdDev: 4ms
```

Compare:
```
λ go build&&warp cmp -analyze.v warp-get-2020-06-24[154208]-jmuM.csv.zst warp-get-2020-06-24[153319]-hBwl.csv.zst
576728 operations loaded... Done!
581688 operations loaded... Done!
-------------------
Operation: PUT
* Average: -5.22% (-0.5 MiB/s) throughput, -5.22% (-48.8) obj/s
* Requests: Avg: +4.15ms (+4%), P50: +4.6619ms (+4%), P99: +4.3328ms (+2%), Best: +3.7533ms (+17%), Worst: -82.0389ms (-24%) StdDev: +1.059646ms (+6%)
* Fastest: -4.42% (-0.4 MiB/s) throughput, -4.42% (-42.9) obj/s
* 50% Median: -4.42% (-0.4 MiB/s) throughput, -4.42% (-42.9) obj/s
* Slowest: -13.69% (-1.2 MiB/s) throughput, -13.69% (-130.1) obj/s
```

Throughput stddev doesn't make much sense. And since requests are reflective of throughput we have what we need.
  • Loading branch information
@klauspost
klauspost authored Mar 21, 2023
1 parent d78528e commit 1e2e1f3
Show file tree
Hide file tree
Showing 6 changed files with 69 additions and 7 deletions.
6 changes: 5 additions & 1 deletion cli/analyze.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -472,6 +472,7 @@ func printRequestAnalysis(ctx *cli.Context, ops aggregate.Operation, details boo
", 99%: ", time.Duration(reqs.Dur99Millis)*time.Millisecond,
", Fastest: ", time.Duration(reqs.FastestMillis)*time.Millisecond,
", Slowest: ", time.Duration(reqs.SlowestMillis)*time.Millisecond,
", StdDev: ", time.Duration(reqs.StdDev)*time.Millisecond,
"\n")

if reqs.FirstByte != nil {
Expand All @@ -487,6 +488,7 @@ func printRequestAnalysis(ctx *cli.Context, ops aggregate.Operation, details boo
", 99%: ", time.Duration(reqs.Dur99Millis)*time.Millisecond,
", Fastest: ", time.Duration(reqs.FastestMillis)*time.Millisecond,
", Slowest: ", time.Duration(reqs.SlowestMillis)*time.Millisecond,
", StdDev: ", time.Duration(reqs.StdDev)*time.Millisecond,
"\n")
if reqs.FirstByte != nil {
console.Print(" * First Access TTFB: ", reqs.FirstByte, "\n")
Expand All @@ -501,6 +503,7 @@ func printRequestAnalysis(ctx *cli.Context, ops aggregate.Operation, details boo
", 99%: ", time.Duration(reqs.Dur99Millis)*time.Millisecond,
", Fastest: ", time.Duration(reqs.FastestMillis)*time.Millisecond,
", Slowest: ", time.Duration(reqs.SlowestMillis)*time.Millisecond,
", StdDev: ", time.Duration(reqs.StdDev)*time.Millisecond,
"\n")
if reqs.FirstByte != nil {
console.Print(" * Last Access TTFB: ", reqs.FirstByte, "\n")
Expand All @@ -522,7 +525,8 @@ func printRequestAnalysis(ctx *cli.Context, ops aggregate.Operation, details boo
"Fastest:", time.Duration(reqs.FastestMillis)*time.Millisecond,
"Slowest:", time.Duration(reqs.SlowestMillis)*time.Millisecond,
"50%:", time.Duration(reqs.DurMedianMillis)*time.Millisecond,
"90%:", time.Duration(reqs.Dur90Millis)*time.Millisecond)
"90%:", time.Duration(reqs.Dur90Millis)*time.Millisecond,
"StdDev:", time.Duration(reqs.StdDev)*time.Millisecond)
if reqs.FirstByte != nil {
console.Println("\t- First Byte:", reqs.FirstByte)
}
Expand Down
17 changes: 17 additions & 0 deletions pkg/aggregate/requests.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -28,32 +28,48 @@ import (
type SingleSizedRequests struct {
// Skipped if too little data.
Skipped bool `json:"skipped"`

// Object size per operation. Can be 0.
ObjSize int64 `json:"obj_size"`

// Total number of requests.
Requests int `json:"requests"`

// Average request duration.
DurAvgMillis int `json:"dur_avg_millis"`

// Median request duration.
DurMedianMillis int `json:"dur_median_millis"`

// 90% request time.
Dur90Millis int `json:"dur_90_millis"`

// 99% request time.
Dur99Millis int `json:"dur_99_millis"`

// Fastest request time.
FastestMillis int `json:"fastest_millis"`

// Slowest request time.
SlowestMillis int `json:"slowest_millis"`

// StdDev is the standard deviation of requests.
StdDev int `json:"std_dev_millis"`

// DurPct is duration percentiles.
DurPct [101]int `json:"dur_percentiles_millis"`

// Time to first byte if applicable.
FirstByte *TTFB `json:"first_byte,omitempty"`

// FirstAccess is filled if the same object is accessed multiple times.
// This records the first touch of the object.
FirstAccess *SingleSizedRequests `json:"first_access,omitempty"`
LastAccess *SingleSizedRequests `json:"last_access,omitempty"`

// Host names, sorted.
HostNames []string

// Request times by host.
ByHost map[string]SingleSizedRequests `json:"by_host,omitempty"`
}
Expand All @@ -64,6 +80,7 @@ func (a *SingleSizedRequests) fill(ops bench.Operations) {
a.Requests = len(ops)
a.ObjSize = ops.FirstObjSize()
a.DurAvgMillis = durToMillis(ops.AvgDuration())
a.StdDev = durToMillis(ops.StdDev())
a.DurMedianMillis = durToMillis(ops.Median(0.5).Duration())
a.Dur90Millis = durToMillis(ops.Median(0.9).Duration())
a.Dur99Millis = durToMillis(ops.Median(0.99).Duration())
Expand Down
7 changes: 5 additions & 2 deletions pkg/aggregate/ttfb.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -34,6 +34,7 @@ type TTFB struct {
P90Millis int `json:"p90_millis"`
P99Millis int `json:"p99_millis"`
SlowestMillis int `json:"slowest_millis"`
StdDevMillis int `json:"std_dev_millis"`
PercentilesMillis [101]int `json:"percentiles_millis"`
}

Expand All @@ -42,15 +43,16 @@ func (t TTFB) String() string {
if t.AverageMillis == 0 {
return ""
}
return fmt.Sprintf("Avg: %v, Best: %v, 25th: %v, Median: %v, 75th: %v, 90th: %v, 99th: %v, Worst: %v",
return fmt.Sprintf("Avg: %v, Best: %v, 25th: %v, Median: %v, 75th: %v, 90th: %v, 99th: %v, Worst: %v StdDev: %v",
time.Duration(t.AverageMillis)*time.Millisecond,
time.Duration(t.FastestMillis)*time.Millisecond,
time.Duration(t.P25Millis)*time.Millisecond,
time.Duration(t.MedianMillis)*time.Millisecond,
time.Duration(t.P75Millis)*time.Millisecond,
time.Duration(t.P90Millis)*time.Millisecond,
time.Duration(t.P99Millis)*time.Millisecond,
time.Duration(t.SlowestMillis)*time.Millisecond)
time.Duration(t.SlowestMillis)*time.Millisecond,
time.Duration(t.StdDevMillis)*time.Millisecond)
}

// TtfbFromBench converts from bench.TTFB
Expand All @@ -66,6 +68,7 @@ func TtfbFromBench(t bench.TTFB) *TTFB {
P75Millis: durToMillis(t.P75),
P90Millis: durToMillis(t.P90),
P99Millis: durToMillis(t.P99),
StdDevMillis: durToMillis(t.StdDev),
FastestMillis: durToMillis(t.Best),
}
for i, v := range t.Percentiles[:] {
Expand Down
16 changes: 14 additions & 2 deletions pkg/bench/analyze.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -62,6 +62,7 @@ type TTFB struct {
P90 time.Duration
P99 time.Duration
Worst time.Duration
StdDev time.Duration
Percentiles [101]time.Duration `json:"percentiles_millis"`
}

Expand Down Expand Up @@ -121,7 +122,18 @@ func (o Operations) TTFB(start, end time.Time) TTFB {
ttfb := op.TTFB()
res.Average += ttfb
}
avg := float64(res.Average) / float64(len(filtered))
res.Average /= time.Duration(len(filtered))
res.StdDev = 0
if len(filtered) > 1 {
var stdDev float64
for _, op := range filtered {
ttfb := op.TTFB()
d := float64(ttfb) - avg
stdDev += d * d
}
res.StdDev = time.Duration(math.Sqrt(stdDev / float64(len(filtered)-1)))
}
return res
}

Expand Down Expand Up @@ -361,6 +373,6 @@ func (t TTFB) String() string {
if t.Average == 0 {
return ""
}
return fmt.Sprintf("Average: %v, Median: %v, Best: %v, Worst: %v",
t.Average.Round(time.Millisecond), t.Median.Round(time.Millisecond), t.Best.Round(time.Millisecond), t.Worst.Round(time.Millisecond))
return fmt.Sprintf("Average: %v, Median: %v, Best: %v, Worst: %v, StdDev: %v",
t.Average.Round(time.Millisecond), t.Median.Round(time.Millisecond), t.Best.Round(time.Millisecond), t.Worst.Round(time.Millisecond), t.StdDev.Round(time.Millisecond))
}
16 changes: 14 additions & 2 deletions pkg/bench/compare.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -64,6 +64,7 @@ func (c *CmpReqs) Compare(before, after Operations) {
P75: a.P75 - b.P75,
P90: a.P90 - b.P90,
P99: a.P99 - b.P99,
StdDev: a.StdDev - b.StdDev,
}
}

Expand All @@ -78,6 +79,7 @@ type CmpRequests struct {
P90 time.Duration
P99 time.Duration
Worst time.Duration
StdDev time.Duration
}

func (c *CmpRequests) fill(ops Operations) {
Expand All @@ -92,14 +94,15 @@ func (c *CmpRequests) fill(ops Operations) {
c.P90 = ops.Median(0.9).Duration()
c.P99 = ops.Median(0.99).Duration()
c.Worst = ops.Median(1).Duration()
c.StdDev = ops.StdDev()
}

// String returns a human readable representation of the TTFB comparison.
func (c *CmpReqs) String() string {
if c == nil {
return ""
}
return fmt.Sprintf("Avg: %s%v (%s%.f%%), P50: %s%v (%s%.f%%), P99: %s%v (%s%.f%%), Best: %s%v (%s%.f%%), Worst: %s%v (%s%.f%%)",
return fmt.Sprintf("Avg: %s%v (%s%.f%%), P50: %s%v (%s%.f%%), P99: %s%v (%s%.f%%), Best: %s%v (%s%.f%%), Worst: %s%v (%s%.f%%) StdDev: %s%v (%s%.f%%)",
plusPositiveD(c.Average),
c.Average.Round(time.Millisecond/20),
plusPositiveD(c.Average),
Expand All @@ -120,6 +123,10 @@ func (c *CmpReqs) String() string {
c.Worst,
plusPositiveD(c.Worst),
100*(float64(c.After.Worst)-float64(c.Before.Worst))/float64(c.Before.Worst),
plusPositiveD(c.StdDev),
c.StdDev,
plusPositiveD(c.StdDev),
100*(float64(c.After.StdDev)-float64(c.Before.StdDev))/float64(c.Before.StdDev),
)
}

Expand Down Expand Up @@ -186,6 +193,7 @@ func (t TTFB) Compare(after TTFB) *TTFBCmp {
P75: after.P75 - t.P75,
P90: after.P90 - t.P90,
P99: after.P99 - t.P99,
StdDev: after.StdDev - t.StdDev,
},
Before: t,
After: after,
Expand All @@ -197,7 +205,7 @@ func (t *TTFBCmp) String() string {
if t == nil {
return ""
}
return fmt.Sprintf("Avg: %s%v (%s%.f%%), P50: %s%v (%s%.f%%), P99: %s%v (%s%.f%%), Best: %s%v (%s%.f%%), Worst: %s%v (%s%.f%%)",
return fmt.Sprintf("Avg: %s%v (%s%.f%%), P50: %s%v (%s%.f%%), P99: %s%v (%s%.f%%), Best: %s%v (%s%.f%%), Worst: %s%v (%s%.f%%) StdDev: %s%v (%s%.f%%)",
plusPositiveD(t.Average),
t.Average.Round(time.Millisecond/20),
plusPositiveD(t.Average),
Expand All @@ -218,6 +226,10 @@ func (t *TTFBCmp) String() string {
t.Worst,
plusPositiveD(t.Worst),
100*(float64(t.After.Worst)-float64(t.Before.Worst))/float64(t.Before.Worst),
plusPositiveD(t.StdDev),
t.StdDev,
plusPositiveD(t.StdDev),
100*(float64(t.After.StdDev)-float64(t.Before.StdDev))/float64(t.Before.StdDev),
)
}

Expand Down
14 changes: 14 additions & 0 deletions pkg/bench/ops.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -589,6 +589,20 @@ func (o Operations) AvgDuration() time.Duration {
return total / time.Duration(len(o))
}

// StdDev returns the standard deviation.
func (o Operations) StdDev() time.Duration {
if len(o) <= 1 {
return 0
}
avg := o.AvgDuration()
var total float64
for _, op := range o {
delta := float64(avg - op.Duration())
total += delta * delta
}
return time.Duration(math.Sqrt(total / float64(len(o)-1)))
}

// SizeSegment is a size segment.
type SizeSegment struct {
Smallest int64
Expand Down

0 comments on commit 1e2e1f3

Please sign in to comment.