forked from googleapis/google-cloud-go
/
proftest_test.go
313 lines (305 loc) · 13.7 KB
/
proftest_test.go
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
136
137
138
139
140
141
142
143
144
145
146
147
148
149
150
151
152
153
154
155
156
157
158
159
160
161
162
163
164
165
166
167
168
169
170
171
172
173
174
175
176
177
178
179
180
181
182
183
184
185
186
187
188
189
190
191
192
193
194
195
196
197
198
199
200
201
202
203
204
205
206
207
208
209
210
211
212
213
214
215
216
217
218
219
220
221
222
223
224
225
226
227
228
229
230
231
232
233
234
235
236
237
238
239
240
241
242
243
244
245
246
247
248
249
250
251
252
253
254
255
256
257
258
259
260
261
262
263
264
265
266
267
268
269
270
271
272
273
274
275
276
277
278
279
280
281
282
283
284
285
286
287
288
289
290
291
292
293
294
295
296
297
298
299
300
301
302
303
304
305
306
307
308
309
310
311
312
313
// Copyright 2020 Google LLC
//
// Licensed under the Apache License, Version 2.0 (the "License");
// you may not use this file except in compliance with the License.
// You may obtain a copy of the License at
//
// http://www.apache.org/licenses/LICENSE-2.0
//
// Unless required by applicable law or agreed to in writing, software
// distributed under the License is distributed on an "AS IS" BASIS,
// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
// See the License for the specific language governing permissions and
// limitations under the License.
package proftest
import (
"regexp"
"testing"
"time"
)
func TestParseBenchmarkNumber(t *testing.T) {
benchNumRE, err := regexp.Compile("benchmark (\\d+):")
if err != nil {
t.Fatalf("failed to get benchmark regexp: %v", err)
}
numBenchmarks := 150
for _, tc := range []struct {
desc string
line string
wantBenchNum int
wantErr bool
}{
{
desc: "zero parsed successfully as benchmark number",
line: "benchmark 0: 2020/05/15 23:37:56 start uploading profile",
wantBenchNum: 0,
},
{
desc: "benchmark number for empty line can be parsed",
line: "benchmark 5:",
wantBenchNum: 5,
},
{
desc: "multi-digit benchmark number can be parsed",
line: "benchmark 149: line",
wantBenchNum: 149,
},
{
desc: "benchmark number can be parsed when it is not at the start of the line",
line: "Mon May 18 00:00:00 UTC 2020: benchmark 5: line",
wantBenchNum: 5,
},
{
desc: "an error is returned when benchmark number is outside the expected range of benchmark numbers",
line: "benchmark 150: line",
wantErr: true,
},
{
desc: "an error is returned when benchmark number is not a number",
line: "benchmark abc: 2020/05/15 23:40:46 creating a new profile via profiler service",
wantErr: true,
},
} {
t.Run(tc.desc, func(t *testing.T) {
benchNum, err := parseBenchmarkNumber(tc.line, numBenchmarks, benchNumRE)
if (err != nil) != tc.wantErr {
t.Errorf("got err = %v; want (err != nil) = %v", err, tc.wantErr)
}
if tc.wantErr {
return
}
if benchNum != tc.wantBenchNum {
t.Errorf("got benchmark number = %v, want %v", benchNum, tc.wantBenchNum)
}
})
}
}
func TestParseLogTime(t *testing.T) {
for _, tc := range []struct {
desc string
line string
wantTime time.Time
wantErr bool
}{
{
desc: "a valid timestamp is parsed correctly",
line: "Fri May 15 23:39:53 UTC 2020: benchmark 31: creating a new profile via profiler service",
wantTime: time.Date(2020, 5, 15, 23, 39, 53, 0, time.UTC),
},
{
desc: "an error is returned when the timestamp is invalid",
line: "Fri May 15 26:39:53 UTC 2020: benchmark 31: creating a new profile via profiler service",
wantErr: true,
},
} {
t.Run(tc.desc, func(t *testing.T) {
logTime, err := parseLogTime(tc.line)
if (err != nil) != tc.wantErr {
t.Errorf("got err = %v; want (err != nil) = %v", err, tc.wantErr)
}
if tc.wantErr {
return
}
if !logTime.Equal(tc.wantTime) {
t.Errorf("got log time = %v, want %v", logTime, tc.wantTime)
}
})
}
}
func TestParseBackoffDuration(t *testing.T) {
for _, tc := range []struct {
desc string
line string
wantBackoffDur time.Duration
wantErr bool
}{
{
desc: "a valid backoff duration is parsed correctly when at the end of the message",
line: "Fri May 15 22:05:01 UTC 2020: benchmark 0: action throttled, backoff for 32m0s",
wantBackoffDur: 32 * time.Minute,
},
{
desc: "a valid backoff duration is parsed correctly when at the end of a message ending with a period",
line: "Fri May 15 22:05:01 UTC 2020: benchmark 0: failed to create profile, will retry: rpc error: code = Aborted desc = generic::aborted: action throttled, backoff for 32m0s.",
wantBackoffDur: 32 * time.Minute,
},
{
desc: "a valid backoff duration in a structured log statement is parsed correctly",
line: `Mon Dec 20 20:21:40 UTC 2021: benchmark 39: {"timestamp":"2021-12-20T20:21:39.973Z","severity":"DEBUG","logging.googleapis.com/insertId":"..........K231soqV4EIcG8w42yR2.3","message":"Must wait 35m to create profile: Error: generic::aborted: action throttled, backoff for 35m0s","logName":"projects/{{projectId}}/logs/%40google-cloud%2Fprofiler","resource":{"type":"gae_app","labels":{"module_id":"profiler-backoff-test-node12-2021-12-20-12-18-47-077307-0800","zone":"us-east4-b"}}}`,
wantBackoffDur: 35 * time.Minute,
},
{
desc: "a valid backoff duration is parsed correctly when in the middle of the message",
line: "Fri May 15 22:05:01 UTC 2020: benchmark 0: failed to create profile, will retry: rpc error: code = Aborted desc = generic::aborted: action throttled, backoff for 32m0s ... more information",
wantBackoffDur: 32 * time.Minute,
},
{
desc: "a floating-point backoff duration is parsed correctly",
line: "Fri May 15 22:05:01 UTC 2020: benchmark 0: failed to create profile, will retry: rpc error: code = Aborted desc = generic::aborted: action throttled, backoff for 2000.000s",
wantBackoffDur: 2000 * time.Second,
},
{
desc: "an error is returned when the backoff duration is invalid",
line: "Fri May 15 22:05:01 UTC 2020: benchmark 0: failed to create profile, will retry: rpc error: code = Aborted desc = generic::aborted: action throttled, backoff for 32..0.s",
wantErr: true,
},
{
desc: "a backoff duration specifying hours, minutes, seconds, milliseconds and microseconds is parsed correctly.",
line: "Fri May 15 22:05:01 UTC 2020: benchmark 0: failed to create profile, will retry: rpc error: code = Aborted desc = generic::aborted: action throttled, backoff for 1h1m1s1ms1us",
wantBackoffDur: time.Hour + time.Minute + time.Second + time.Millisecond + time.Microsecond,
},
{
desc: "a backoff duration at the start of the message is parsed correctly",
line: "1h1m1s1ms",
wantBackoffDur: time.Hour + time.Minute + time.Second + time.Millisecond,
},
} {
t.Run(tc.desc, func(t *testing.T) {
backoffDur, err := parseBackoffDuration(tc.line)
if (err != nil) != tc.wantErr {
t.Errorf("got err = %v; want (err != nil) = %v", err, tc.wantErr)
}
if tc.wantErr {
return
}
if backoffDur != tc.wantBackoffDur {
t.Errorf("backoff duration: got %v, want %v", backoffDur, tc.wantBackoffDur)
}
})
}
}
func TestCheckSerialOutputForBackoffs(t *testing.T) {
for _, tc := range []struct {
desc string
logs string
numBenchmarks int
serverBackoffSubstring string
createProfileSubstring string
benchmarkNumPrefix string
wantErr bool
}{
{
desc: "no error when one benchmark running and the next profile is created after backoff interval",
logs: `
Fri May 15 22:05:00 UTC 2020: benchmark 0: creating a new profile via profiler service
Fri May 15 22:05:01 UTC 2020: benchmark 0: failed to create profile, will retry: rpc error: code = Aborted desc = generic::aborted: action throttled, backoff for 32m0s
Fri May 15 22:37:01 UTC 2020: benchmark 0: creating a new profile via profiler service
`,
numBenchmarks: 1,
serverBackoffSubstring: "action throttled, backoff for",
createProfileSubstring: "creating a new profile via profiler service",
benchmarkNumPrefix: "benchmark",
},
{
desc: "no error when one benchmark running and the next profile is created 1 minute after backoff interval has elapsed",
logs: `
Fri May 15 22:05:00 UTC 2020: benchmark 0: creating a new profile via profiler service
Fri May 15 22:05:01 UTC 2020: benchmark 0: failed to create profile, will retry: rpc error: code = Aborted desc = generic::aborted: action throttled, backoff for 50m0s
Fri May 15 22:56:01 UTC 2020: benchmark 0: creating a new profile via profiler service
`,
numBenchmarks: 1,
serverBackoffSubstring: "action throttled, backoff for",
createProfileSubstring: "creating a new profile via profiler service",
benchmarkNumPrefix: "benchmark",
},
{
desc: "no error when one benchmark running and the next profile is created 1 minute before backoff interval has elapsed",
logs: `
Fri May 15 22:05:00 UTC 2020: benchmark 0: creating a new profile via profiler service
Fri May 15 22:05:01 UTC 2020: benchmark 0: failed to create profile, will retry: rpc error: code = Aborted desc = generic::aborted: action throttled, backoff for 45m0s
Fri May 15 22:49:01 UTC 2020: benchmark 0: creating a new profile via profiler service
`,
numBenchmarks: 1,
serverBackoffSubstring: "action throttled, backoff for",
createProfileSubstring: "creating a new profile via profiler service",
benchmarkNumPrefix: "benchmark",
},
{
desc: "error when one benchmark running and the next profile is created more than 1 minute before backoff interval has elapsed",
logs: `
Fri May 15 22:05:00 UTC 2020: benchmark 0: creating a new profile via profiler service
Fri May 15 22:05:01 UTC 2020: benchmark 0: failed to create profile, will retry: rpc error: code = Aborted desc = generic::aborted: action throttled, backoff for 32m0s
Fri May 15 22:36:00 UTC 2020: benchmark 0: creating a new profile via profiler service
`,
numBenchmarks: 1,
serverBackoffSubstring: "action throttled, backoff for",
createProfileSubstring: "creating a new profile via profiler service",
benchmarkNumPrefix: "benchmark",
wantErr: true,
},
{
desc: "error when one benchmark running and the next profile is created more than 1 minute after backoff interval has elapsed",
logs: `
Fri May 15 22:05:00 UTC 2020: benchmark 0: creating a new profile via profiler service
Fri May 15 22:05:01 UTC 2020: benchmark 0: failed to create profile, will retry: rpc error: code = Aborted desc = generic::aborted: action throttled, backoff for 32m0s
Fri May 15 22:38:02 UTC 2020: benchmark 0: creating a new profile via profiler service
`,
numBenchmarks: 1,
serverBackoffSubstring: "action throttled, backoff for",
createProfileSubstring: "creating a new profile via profiler service",
benchmarkNumPrefix: "benchmark",
wantErr: true,
},
{
desc: "error when there are no log entries indicating server-specifed backoff",
logs: `
Fri May 15 22:05:00 UTC 2020: benchmark 0: creating a new profile via profiler service
Fri May 15 22:37:01 UTC 2020: benchmark 0: creating a new profile via profiler service
`,
numBenchmarks: 1,
serverBackoffSubstring: "action throttled, backoff for",
createProfileSubstring: "creating a new profile via profiler service",
benchmarkNumPrefix: "benchmark",
wantErr: true,
},
{
desc: "error when missing CreateProfile requests after server specified backoff",
logs: `
Fri May 15 22:05:00 UTC 2020: benchmark 0: creating a new profile via profiler service
Fri May 15 22:05:00 UTC 2020: benchmark 1: creating a new profile via profiler service
Fri May 15 22:05:01 UTC 2020: benchmark 0: failed to create profile, will retry: rpc error: code = Aborted desc = generic::aborted: action throttled, backoff for 15m0s
Fri May 15 22:05:01 UTC 2020: benchmark 1: failed to create profile, will retry: rpc error: code = Aborted desc = generic::aborted: action throttled, backoff for 32m0s
Fri May 15 22:37:01 UTC 2020: benchmark 1: creating a new profile via profiler service
`,
numBenchmarks: 2,
serverBackoffSubstring: "action throttled, backoff for",
createProfileSubstring: "creating a new profile via profiler service",
benchmarkNumPrefix: "benchmark",
wantErr: true,
},
{
desc: "no error when no missing CreateProfile requests after server specified backoff because benchmarks finished before next request could happen.",
logs: `
Fri May 15 22:05:00 UTC 2020: benchmark 0: creating a new profile via profiler service
Fri May 15 22:05:00 UTC 2020: benchmark 1: creating a new profile via profiler service
Fri May 15 22:05:01 UTC 2020: benchmark 0: failed to create profile, will retry: rpc error: code = Aborted desc = generic::aborted: action throttled, backoff for 32m0s
Fri May 15 22:05:01 UTC 2020: benchmark 1: failed to create profile, will retry: rpc error: code = Aborted desc = generic::aborted: action throttled, backoff for 32m0s
Fri May 15 22:37:01 UTC 2020: benchmark 0: creating a new profile via profiler service
`,
numBenchmarks: 2,
serverBackoffSubstring: "action throttled, backoff for",
createProfileSubstring: "creating a new profile via profiler service",
benchmarkNumPrefix: "benchmark",
},
{
desc: "no error when there are non-benchmark logs",
logs: `
Fri May 15 22:00:00 UTC 2020: prologue
Fri May 15 22:05:00 UTC 2020: benchmark 0: creating a new profile via profiler service
Fri May 15 22:05:01 UTC 2020: benchmark 0: failed to create profile, will retry: rpc error: code = Aborted desc = generic::aborted: action throttled, backoff for 32m0s
Fri May 15 22:37:01 UTC 2020: benchmark 0: creating a new profile via profiler service
Fri May 15 22:40:00 UTC 2020: epilogue
`,
numBenchmarks: 1,
serverBackoffSubstring: "action throttled, backoff for",
createProfileSubstring: "creating a new profile via profiler service",
benchmarkNumPrefix: "benchmark",
},
} {
t.Run(tc.desc, func(t *testing.T) {
if err := CheckSerialOutputForBackoffs(tc.logs, tc.numBenchmarks, tc.serverBackoffSubstring, tc.createProfileSubstring, tc.benchmarkNumPrefix); (err != nil) != tc.wantErr {
t.Errorf("got err = %v; want (err != nil) = %v", err, tc.wantErr)
}
})
}
}