1
16
17 package util
18
19 import (
20 "strings"
21 "testing"
22 "time"
23
24 "github.com/stretchr/testify/assert"
25
26 "k8s.io/component-base/metrics/testutil"
27 "k8s.io/kubernetes/pkg/kubelet/metrics"
28 "k8s.io/utils/clock"
29 testingclock "k8s.io/utils/clock/testing"
30 )
31
32 const (
33 metricsNameNodeStartupPreKubelet = "kubelet_node_startup_pre_kubelet_duration_seconds"
34 metricsNameNodeStartupPreRegistration = "kubelet_node_startup_pre_registration_duration_seconds"
35 metricsNameNodeStartupRegistration = "kubelet_node_startup_registration_duration_seconds"
36 metricsNameNodeStartupPostRegistration = "kubelet_node_startup_post_registration_duration_seconds"
37 metricsNameNodeStartup = "kubelet_node_startup_duration_seconds"
38 )
39
40 func TestNodeStartupLatencyNoEvents(t *testing.T) {
41 t.Run("metrics registered; no incoming events", func(t *testing.T) {
42 metrics.Register()
43 defer clearMetrics()
44
45 tracker := &basicNodeStartupLatencyTracker{
46 bootTime: frozenTime.Add(-100 * time.Millisecond),
47 kubeletStartTime: frozenTime,
48 clock: clock.RealClock{},
49 }
50
51 wants := `
52 # HELP kubelet_node_startup_duration_seconds [ALPHA] Duration in seconds of node startup in total.
53 # TYPE kubelet_node_startup_duration_seconds gauge
54 kubelet_node_startup_duration_seconds 0
55 # HELP kubelet_node_startup_post_registration_duration_seconds [ALPHA] Duration in seconds of node startup after registration.
56 # TYPE kubelet_node_startup_post_registration_duration_seconds gauge
57 kubelet_node_startup_post_registration_duration_seconds 0
58 # HELP kubelet_node_startup_pre_kubelet_duration_seconds [ALPHA] Duration in seconds of node startup before kubelet starts.
59 # TYPE kubelet_node_startup_pre_kubelet_duration_seconds gauge
60 kubelet_node_startup_pre_kubelet_duration_seconds 0
61 # HELP kubelet_node_startup_pre_registration_duration_seconds [ALPHA] Duration in seconds of node startup before registration.
62 # TYPE kubelet_node_startup_pre_registration_duration_seconds gauge
63 kubelet_node_startup_pre_registration_duration_seconds 0
64 # HELP kubelet_node_startup_registration_duration_seconds [ALPHA] Duration in seconds of node startup during registration.
65 # TYPE kubelet_node_startup_registration_duration_seconds gauge
66 kubelet_node_startup_registration_duration_seconds 0
67 `
68 if err := testutil.GatherAndCompare(metrics.GetGather(), strings.NewReader(wants),
69 metricsNameNodeStartupPreKubelet,
70 metricsNameNodeStartupPreRegistration,
71 metricsNameNodeStartupRegistration,
72 metricsNameNodeStartupPostRegistration,
73 metricsNameNodeStartup,
74 ); err != nil {
75 t.Error(err)
76 }
77
78 assert.Equal(t, frozenTime.Add(-100*time.Millisecond), tracker.bootTime)
79 assert.Equal(t, frozenTime, tracker.kubeletStartTime)
80 assert.True(t, tracker.firstRegistrationAttemptTime.IsZero())
81 assert.True(t, tracker.firstRegisteredNewNodeTime.IsZero())
82 assert.True(t, tracker.firstNodeReadyTime.IsZero())
83 })
84 }
85
86 func TestRecordAllTimestamps(t *testing.T) {
87 t.Run("all timestamps are recorded", func(t *testing.T) {
88 metrics.Register()
89 defer clearMetrics()
90
91 fakeClock := testingclock.NewFakeClock(frozenTime)
92 tracker := &basicNodeStartupLatencyTracker{
93 bootTime: frozenTime.Add(-100 * time.Millisecond),
94 kubeletStartTime: frozenTime,
95 clock: fakeClock,
96 }
97
98 fakeClock.Step(800 * time.Millisecond)
99 tracker.RecordAttemptRegisterNode()
100
101 assert.Equal(t, frozenTime.Add(800*time.Millisecond), tracker.firstRegistrationAttemptTime)
102
103 fakeClock.Step(400 * time.Millisecond)
104 tracker.RecordRegisteredNewNode()
105
106 assert.Equal(t, frozenTime.Add(1200*time.Millisecond), tracker.firstRegisteredNewNodeTime)
107
108 fakeClock.Step(1100 * time.Millisecond)
109 tracker.RecordNodeReady()
110
111 assert.Equal(t, frozenTime.Add(2300*time.Millisecond), tracker.firstNodeReadyTime)
112
113 wants := `
114 # HELP kubelet_node_startup_duration_seconds [ALPHA] Duration in seconds of node startup in total.
115 # TYPE kubelet_node_startup_duration_seconds gauge
116 kubelet_node_startup_duration_seconds 2.4
117 # HELP kubelet_node_startup_post_registration_duration_seconds [ALPHA] Duration in seconds of node startup after registration.
118 # TYPE kubelet_node_startup_post_registration_duration_seconds gauge
119 kubelet_node_startup_post_registration_duration_seconds 1.1
120 # HELP kubelet_node_startup_pre_kubelet_duration_seconds [ALPHA] Duration in seconds of node startup before kubelet starts.
121 # TYPE kubelet_node_startup_pre_kubelet_duration_seconds gauge
122 kubelet_node_startup_pre_kubelet_duration_seconds 0.1
123 # HELP kubelet_node_startup_pre_registration_duration_seconds [ALPHA] Duration in seconds of node startup before registration.
124 # TYPE kubelet_node_startup_pre_registration_duration_seconds gauge
125 kubelet_node_startup_pre_registration_duration_seconds 0.8
126 # HELP kubelet_node_startup_registration_duration_seconds [ALPHA] Duration in seconds of node startup during registration.
127 # TYPE kubelet_node_startup_registration_duration_seconds gauge
128 kubelet_node_startup_registration_duration_seconds 0.4
129 `
130 if err := testutil.GatherAndCompare(metrics.GetGather(), strings.NewReader(wants),
131 metricsNameNodeStartupPreKubelet,
132 metricsNameNodeStartupPreRegistration,
133 metricsNameNodeStartupRegistration,
134 metricsNameNodeStartupPostRegistration,
135 metricsNameNodeStartup,
136 ); err != nil {
137 t.Error(err)
138 }
139 })
140 }
141
142 func TestRecordAttemptRegister(t *testing.T) {
143 t.Run("record attempt register node", func(t *testing.T) {
144 metrics.Register()
145 defer clearMetrics()
146
147 fakeClock := testingclock.NewFakeClock(frozenTime)
148 tracker := &basicNodeStartupLatencyTracker{
149 bootTime: frozenTime.Add(-100 * time.Millisecond),
150 kubeletStartTime: frozenTime,
151 clock: fakeClock,
152 }
153
154 fakeClock.Step(600 * time.Millisecond)
155 tracker.RecordAttemptRegisterNode()
156
157 assert.Equal(t, frozenTime.Add(600*time.Millisecond), tracker.firstRegistrationAttemptTime)
158 assert.True(t, tracker.firstRegisteredNewNodeTime.IsZero())
159 assert.True(t, tracker.firstNodeReadyTime.IsZero())
160
161 wants := `
162 # HELP kubelet_node_startup_duration_seconds [ALPHA] Duration in seconds of node startup in total.
163 # TYPE kubelet_node_startup_duration_seconds gauge
164 kubelet_node_startup_duration_seconds 0
165 # HELP kubelet_node_startup_post_registration_duration_seconds [ALPHA] Duration in seconds of node startup after registration.
166 # TYPE kubelet_node_startup_post_registration_duration_seconds gauge
167 kubelet_node_startup_post_registration_duration_seconds 0
168 # HELP kubelet_node_startup_pre_kubelet_duration_seconds [ALPHA] Duration in seconds of node startup before kubelet starts.
169 # TYPE kubelet_node_startup_pre_kubelet_duration_seconds gauge
170 kubelet_node_startup_pre_kubelet_duration_seconds 0
171 # HELP kubelet_node_startup_pre_registration_duration_seconds [ALPHA] Duration in seconds of node startup before registration.
172 # TYPE kubelet_node_startup_pre_registration_duration_seconds gauge
173 kubelet_node_startup_pre_registration_duration_seconds 0
174 # HELP kubelet_node_startup_registration_duration_seconds [ALPHA] Duration in seconds of node startup during registration.
175 # TYPE kubelet_node_startup_registration_duration_seconds gauge
176 kubelet_node_startup_registration_duration_seconds 0
177 `
178 if err := testutil.GatherAndCompare(metrics.GetGather(), strings.NewReader(wants),
179 metricsNameNodeStartupPreKubelet,
180 metricsNameNodeStartupPreRegistration,
181 metricsNameNodeStartupRegistration,
182 metricsNameNodeStartupPostRegistration,
183 metricsNameNodeStartup,
184 ); err != nil {
185 t.Error(err)
186 }
187 })
188 }
189
190 func TestRecordAttemptRegisterTwice(t *testing.T) {
191 t.Run("record attempt register node twice", func(t *testing.T) {
192 metrics.Register()
193 defer clearMetrics()
194
195 fakeClock := testingclock.NewFakeClock(frozenTime)
196 tracker := &basicNodeStartupLatencyTracker{
197 bootTime: frozenTime.Add(-100 * time.Millisecond),
198 kubeletStartTime: frozenTime,
199 clock: fakeClock,
200 }
201
202 fakeClock.Step(600 * time.Millisecond)
203 tracker.RecordAttemptRegisterNode()
204
205 fakeClock.Step(300 * time.Millisecond)
206 tracker.RecordAttemptRegisterNode()
207
208 assert.Equal(t, frozenTime.Add(600*time.Millisecond), tracker.firstRegistrationAttemptTime)
209 assert.True(t, tracker.firstRegisteredNewNodeTime.IsZero())
210 assert.True(t, tracker.firstNodeReadyTime.IsZero())
211 })
212 }
213
214 func TestSkippingRecordRegisteredNewNode(t *testing.T) {
215 t.Run("record register new node twice", func(t *testing.T) {
216 metrics.Register()
217 defer clearMetrics()
218
219 fakeClock := testingclock.NewFakeClock(frozenTime)
220 tracker := &basicNodeStartupLatencyTracker{
221 bootTime: frozenTime.Add(-100 * time.Millisecond),
222 kubeletStartTime: frozenTime,
223 clock: fakeClock,
224 }
225
226 fakeClock.Step(100 * time.Millisecond)
227 tracker.RecordAttemptRegisterNode()
228
229 fakeClock.Step(500 * time.Millisecond)
230 tracker.RecordRegisteredNewNode()
231
232 fakeClock.Step(300 * time.Millisecond)
233 tracker.RecordRegisteredNewNode()
234
235 assert.Equal(t, frozenTime.Add(600*time.Millisecond), tracker.firstRegisteredNewNodeTime)
236
237 wants := `
238 # HELP kubelet_node_startup_duration_seconds [ALPHA] Duration in seconds of node startup in total.
239 # TYPE kubelet_node_startup_duration_seconds gauge
240 kubelet_node_startup_duration_seconds 0
241 # HELP kubelet_node_startup_post_registration_duration_seconds [ALPHA] Duration in seconds of node startup after registration.
242 # TYPE kubelet_node_startup_post_registration_duration_seconds gauge
243 kubelet_node_startup_post_registration_duration_seconds 0
244 # HELP kubelet_node_startup_pre_kubelet_duration_seconds [ALPHA] Duration in seconds of node startup before kubelet starts.
245 # TYPE kubelet_node_startup_pre_kubelet_duration_seconds gauge
246 kubelet_node_startup_pre_kubelet_duration_seconds 0.1
247 # HELP kubelet_node_startup_pre_registration_duration_seconds [ALPHA] Duration in seconds of node startup before registration.
248 # TYPE kubelet_node_startup_pre_registration_duration_seconds gauge
249 kubelet_node_startup_pre_registration_duration_seconds 0.1
250 # HELP kubelet_node_startup_registration_duration_seconds [ALPHA] Duration in seconds of node startup during registration.
251 # TYPE kubelet_node_startup_registration_duration_seconds gauge
252 kubelet_node_startup_registration_duration_seconds 0.5
253 `
254 if err := testutil.GatherAndCompare(metrics.GetGather(), strings.NewReader(wants),
255 metricsNameNodeStartupPreKubelet,
256 metricsNameNodeStartupPreRegistration,
257 metricsNameNodeStartupRegistration,
258 metricsNameNodeStartupPostRegistration,
259 metricsNameNodeStartup,
260 ); err != nil {
261 t.Error(err)
262 }
263 })
264
265 t.Run("record register new node without previous step", func(t *testing.T) {
266 metrics.Register()
267 defer clearMetrics()
268
269 fakeClock := testingclock.NewFakeClock(frozenTime)
270 tracker := &basicNodeStartupLatencyTracker{
271 bootTime: frozenTime.Add(-100 * time.Millisecond),
272 kubeletStartTime: frozenTime,
273 clock: fakeClock,
274 }
275
276 fakeClock.Step(700 * time.Millisecond)
277 tracker.RecordRegisteredNewNode()
278
279 assert.True(t, tracker.firstRegisteredNewNodeTime.IsZero())
280
281 wants := `
282 # HELP kubelet_node_startup_duration_seconds [ALPHA] Duration in seconds of node startup in total.
283 # TYPE kubelet_node_startup_duration_seconds gauge
284 kubelet_node_startup_duration_seconds 0
285 # HELP kubelet_node_startup_post_registration_duration_seconds [ALPHA] Duration in seconds of node startup after registration.
286 # TYPE kubelet_node_startup_post_registration_duration_seconds gauge
287 kubelet_node_startup_post_registration_duration_seconds 0
288 # HELP kubelet_node_startup_pre_kubelet_duration_seconds [ALPHA] Duration in seconds of node startup before kubelet starts.
289 # TYPE kubelet_node_startup_pre_kubelet_duration_seconds gauge
290 kubelet_node_startup_pre_kubelet_duration_seconds 0
291 # HELP kubelet_node_startup_pre_registration_duration_seconds [ALPHA] Duration in seconds of node startup before registration.
292 # TYPE kubelet_node_startup_pre_registration_duration_seconds gauge
293 kubelet_node_startup_pre_registration_duration_seconds 0
294 # HELP kubelet_node_startup_registration_duration_seconds [ALPHA] Duration in seconds of node startup during registration.
295 # TYPE kubelet_node_startup_registration_duration_seconds gauge
296 kubelet_node_startup_registration_duration_seconds 0
297 `
298 if err := testutil.GatherAndCompare(metrics.GetGather(), strings.NewReader(wants),
299 metricsNameNodeStartupPreKubelet,
300 metricsNameNodeStartupPreRegistration,
301 metricsNameNodeStartupRegistration,
302 metricsNameNodeStartupPostRegistration,
303 metricsNameNodeStartup,
304 ); err != nil {
305 t.Error(err)
306 }
307 })
308 }
309
310 func TestSkippingRecordNodeReady(t *testing.T) {
311 t.Run("record node ready twice", func(t *testing.T) {
312 metrics.Register()
313 defer clearMetrics()
314
315 fakeClock := testingclock.NewFakeClock(frozenTime)
316 tracker := &basicNodeStartupLatencyTracker{
317 bootTime: frozenTime.Add(-100 * time.Millisecond),
318 kubeletStartTime: frozenTime,
319 clock: fakeClock,
320 }
321
322 fakeClock.Step(100 * time.Millisecond)
323 tracker.RecordAttemptRegisterNode()
324
325 fakeClock.Step(200 * time.Millisecond)
326 tracker.RecordRegisteredNewNode()
327
328 fakeClock.Step(300 * time.Millisecond)
329 tracker.RecordNodeReady()
330
331 fakeClock.Step(700 * time.Millisecond)
332 tracker.RecordNodeReady()
333
334 assert.Equal(t, frozenTime.Add(600*time.Millisecond), tracker.firstNodeReadyTime)
335
336 wants := `
337 # HELP kubelet_node_startup_duration_seconds [ALPHA] Duration in seconds of node startup in total.
338 # TYPE kubelet_node_startup_duration_seconds gauge
339 kubelet_node_startup_duration_seconds 0.7
340 # HELP kubelet_node_startup_post_registration_duration_seconds [ALPHA] Duration in seconds of node startup after registration.
341 # TYPE kubelet_node_startup_post_registration_duration_seconds gauge
342 kubelet_node_startup_post_registration_duration_seconds 0.3
343 # HELP kubelet_node_startup_pre_kubelet_duration_seconds [ALPHA] Duration in seconds of node startup before kubelet starts.
344 # TYPE kubelet_node_startup_pre_kubelet_duration_seconds gauge
345 kubelet_node_startup_pre_kubelet_duration_seconds 0.1
346 # HELP kubelet_node_startup_pre_registration_duration_seconds [ALPHA] Duration in seconds of node startup before registration.
347 # TYPE kubelet_node_startup_pre_registration_duration_seconds gauge
348 kubelet_node_startup_pre_registration_duration_seconds 0.1
349 # HELP kubelet_node_startup_registration_duration_seconds [ALPHA] Duration in seconds of node startup during registration.
350 # TYPE kubelet_node_startup_registration_duration_seconds gauge
351 kubelet_node_startup_registration_duration_seconds 0.2
352 `
353 if err := testutil.GatherAndCompare(metrics.GetGather(), strings.NewReader(wants),
354 metricsNameNodeStartupPreKubelet,
355 metricsNameNodeStartupPreRegistration,
356 metricsNameNodeStartupRegistration,
357 metricsNameNodeStartupPostRegistration,
358 metricsNameNodeStartup,
359 ); err != nil {
360 t.Error(err)
361 }
362 })
363
364 t.Run("record node ready without previous step", func(t *testing.T) {
365 metrics.Register()
366 defer clearMetrics()
367
368 fakeClock := testingclock.NewFakeClock(frozenTime)
369 tracker := &basicNodeStartupLatencyTracker{
370 bootTime: frozenTime.Add(-100 * time.Millisecond),
371 kubeletStartTime: frozenTime,
372 clock: fakeClock,
373 }
374
375 fakeClock.Step(100 * time.Millisecond)
376 tracker.RecordAttemptRegisterNode()
377
378 fakeClock.Step(700 * time.Millisecond)
379 tracker.RecordNodeReady()
380
381 assert.True(t, tracker.firstNodeReadyTime.IsZero())
382
383 wants := `
384 # HELP kubelet_node_startup_duration_seconds [ALPHA] Duration in seconds of node startup in total.
385 # TYPE kubelet_node_startup_duration_seconds gauge
386 kubelet_node_startup_duration_seconds 0
387 # HELP kubelet_node_startup_post_registration_duration_seconds [ALPHA] Duration in seconds of node startup after registration.
388 # TYPE kubelet_node_startup_post_registration_duration_seconds gauge
389 kubelet_node_startup_post_registration_duration_seconds 0
390 # HELP kubelet_node_startup_pre_kubelet_duration_seconds [ALPHA] Duration in seconds of node startup before kubelet starts.
391 # TYPE kubelet_node_startup_pre_kubelet_duration_seconds gauge
392 kubelet_node_startup_pre_kubelet_duration_seconds 0
393 # HELP kubelet_node_startup_pre_registration_duration_seconds [ALPHA] Duration in seconds of node startup before registration.
394 # TYPE kubelet_node_startup_pre_registration_duration_seconds gauge
395 kubelet_node_startup_pre_registration_duration_seconds 0
396 # HELP kubelet_node_startup_registration_duration_seconds [ALPHA] Duration in seconds of node startup during registration.
397 # TYPE kubelet_node_startup_registration_duration_seconds gauge
398 kubelet_node_startup_registration_duration_seconds 0
399 `
400 if err := testutil.GatherAndCompare(metrics.GetGather(), strings.NewReader(wants),
401 metricsNameNodeStartupPreKubelet,
402 metricsNameNodeStartupPreRegistration,
403 metricsNameNodeStartupRegistration,
404 metricsNameNodeStartupPostRegistration,
405 metricsNameNodeStartup,
406 ); err != nil {
407 t.Error(err)
408 }
409 })
410 }
411
412 func clearMetrics() {
413 metrics.NodeStartupPreKubeletDuration.Set(0)
414 metrics.NodeStartupPreRegistrationDuration.Set(0)
415 metrics.NodeStartupRegistrationDuration.Set(0)
416 metrics.NodeStartupPostRegistrationDuration.Set(0)
417 metrics.NodeStartupDuration.Set(0)
418 }
419
View as plain text