1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
|
//go:build integration && perftest
// +build integration,perftest
package main
import (
"encoding/csv"
"fmt"
"io"
"os"
"strconv"
"strings"
"time"
)
type Logger struct {
out *csv.Writer
}
func NewLogger(writer io.Writer) *Logger {
l := &Logger{
out: csv.NewWriter(writer),
}
err := l.out.Write([]string{
"ID", "Attempt",
"Latency",
"DNSStart", "DNSDone", "DNSDur",
"ConnectStart", "ConnectDone", "ConnectDur",
"TLSStart", "TLSDone", "TLSDur",
"WriteReq", "RespFirstByte", "WaitRespFirstByte",
"Error",
})
if err != nil {
fmt.Fprintf(os.Stderr, "failed to write header trace, %v\n", err)
}
return l
}
func (l *Logger) RecordTrace(trace *RequestTrace) {
req := RequestReport{
ID: trace.ID,
TotalLatency: durToMSString(trace.TotalLatency()),
Retries: trace.Retries(),
}
for i, a := range trace.Attempts() {
attempt := AttemptReport{
Reused: a.Reused,
SDKMarshal: durToMSString(a.SendStart.Sub(a.Start)),
ReqWritten: durToMSString(a.RequestWritten.Sub(a.SendStart)),
Latency: durToMSString(a.Finish.Sub(a.Start)),
Err: a.Err,
}
if !a.FirstResponseByte.IsZero() {
attempt.RespFirstByte = durToMSString(a.FirstResponseByte.Sub(a.SendStart))
attempt.WaitRespFirstByte = durToMSString(a.FirstResponseByte.Sub(a.RequestWritten))
}
if !a.Reused {
attempt.DNSStart = durToMSString(a.DNSStart.Sub(a.SendStart))
attempt.DNSDone = durToMSString(a.DNSDone.Sub(a.SendStart))
attempt.DNS = durToMSString(a.DNSDone.Sub(a.DNSStart))
attempt.ConnectStart = durToMSString(a.ConnectStart.Sub(a.SendStart))
attempt.ConnectDone = durToMSString(a.ConnectDone.Sub(a.SendStart))
attempt.Connect = durToMSString(a.ConnectDone.Sub(a.ConnectStart))
attempt.TLSHandshakeStart = durToMSString(a.TLSHandshakeStart.Sub(a.SendStart))
attempt.TLSHandshakeDone = durToMSString(a.TLSHandshakeDone.Sub(a.SendStart))
attempt.TLSHandshake = durToMSString(a.TLSHandshakeDone.Sub(a.TLSHandshakeStart))
}
req.Attempts = append(req.Attempts, attempt)
var reqErr string
if attempt.Err != nil {
reqErr = strings.Replace(attempt.Err.Error(), "\n", `\n`, -1)
}
err := l.out.Write([]string{
strconv.Itoa(int(req.ID)),
strconv.Itoa(i + 1),
attempt.Latency,
attempt.DNSStart, attempt.DNSDone, attempt.DNS,
attempt.ConnectStart, attempt.ConnectDone, attempt.Connect,
attempt.TLSHandshakeStart, attempt.TLSHandshakeDone, attempt.TLSHandshake,
attempt.ReqWritten,
attempt.RespFirstByte,
attempt.WaitRespFirstByte,
reqErr,
})
if err != nil {
fmt.Fprintf(os.Stderr, "failed to write request trace, %v\n", err)
}
l.out.Flush()
}
}
func durToMSString(v time.Duration) string {
ms := float64(v) / float64(time.Millisecond)
return fmt.Sprintf("%0.6f", ms)
}
type RequestReport struct {
ID int64
TotalLatency string
Retries int
Attempts []AttemptReport
}
type AttemptReport struct {
Reused bool
Err error
SDKMarshal string `json:",omitempty"`
DNSStart string `json:",omitempty"`
DNSDone string `json:",omitempty"`
DNS string `json:",omitempty"`
ConnectStart string `json:",omitempty"`
ConnectDone string `json:",omitempty"`
Connect string `json:",omitempty"`
TLSHandshakeStart string `json:",omitempty"`
TLSHandshakeDone string `json:",omitempty"`
TLSHandshake string `json:",omitempty"`
ReqWritten string `json:",omitempty"`
RespFirstByte string `json:",omitempty"`
WaitRespFirstByte string `json:",omitempty"`
Latency string `json:",omitempty"`
}
|
