Skip to content

Commit 4fd8bd9

Browse files
authored
Merge pull request #118568 from qiutongs/node-startup-latency
Create a node startup latency tracker
2 parents 963400f + d3eb082 commit 4fd8bd9

File tree

8 files changed

+638
-41
lines changed

8 files changed

+638
-41
lines changed

cmd/kubelet/app/server.go

Lines changed: 4 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -834,6 +834,10 @@ func run(ctx context.Context, s *options.KubeletServer, kubeDeps *kubelet.Depend
834834
kubeDeps.PodStartupLatencyTracker = kubeletutil.NewPodStartupLatencyTracker()
835835
}
836836

837+
if kubeDeps.NodeStartupLatencyTracker == nil {
838+
kubeDeps.NodeStartupLatencyTracker = kubeletutil.NewNodeStartupLatencyTracker()
839+
}
840+
837841
// TODO(vmarmol): Do this through container config.
838842
oomAdjuster := kubeDeps.OOMAdjuster
839843
if err := oomAdjuster.ApplyOOMScoreAdj(0, int(s.OOMScoreAdj)); err != nil {

pkg/kubelet/kubelet.go

Lines changed: 28 additions & 23 deletions
Original file line numberDiff line numberDiff line change
@@ -248,29 +248,30 @@ type Dependencies struct {
248248
Options []Option
249249

250250
// Injected Dependencies
251-
Auth server.AuthInterface
252-
CAdvisorInterface cadvisor.Interface
253-
Cloud cloudprovider.Interface
254-
ContainerManager cm.ContainerManager
255-
EventClient v1core.EventsGetter
256-
HeartbeatClient clientset.Interface
257-
OnHeartbeatFailure func()
258-
KubeClient clientset.Interface
259-
Mounter mount.Interface
260-
HostUtil hostutil.HostUtils
261-
OOMAdjuster *oom.OOMAdjuster
262-
OSInterface kubecontainer.OSInterface
263-
PodConfig *config.PodConfig
264-
ProbeManager prober.Manager
265-
Recorder record.EventRecorder
266-
Subpather subpath.Interface
267-
TracerProvider trace.TracerProvider
268-
VolumePlugins []volume.VolumePlugin
269-
DynamicPluginProber volume.DynamicPluginProber
270-
TLSOptions *server.TLSOptions
271-
RemoteRuntimeService internalapi.RuntimeService
272-
RemoteImageService internalapi.ImageManagerService
273-
PodStartupLatencyTracker util.PodStartupLatencyTracker
251+
Auth server.AuthInterface
252+
CAdvisorInterface cadvisor.Interface
253+
Cloud cloudprovider.Interface
254+
ContainerManager cm.ContainerManager
255+
EventClient v1core.EventsGetter
256+
HeartbeatClient clientset.Interface
257+
OnHeartbeatFailure func()
258+
KubeClient clientset.Interface
259+
Mounter mount.Interface
260+
HostUtil hostutil.HostUtils
261+
OOMAdjuster *oom.OOMAdjuster
262+
OSInterface kubecontainer.OSInterface
263+
PodConfig *config.PodConfig
264+
ProbeManager prober.Manager
265+
Recorder record.EventRecorder
266+
Subpather subpath.Interface
267+
TracerProvider trace.TracerProvider
268+
VolumePlugins []volume.VolumePlugin
269+
DynamicPluginProber volume.DynamicPluginProber
270+
TLSOptions *server.TLSOptions
271+
RemoteRuntimeService internalapi.RuntimeService
272+
RemoteImageService internalapi.ImageManagerService
273+
PodStartupLatencyTracker util.PodStartupLatencyTracker
274+
NodeStartupLatencyTracker util.NodeStartupLatencyTracker
274275
// remove it after cadvisor.UsingLegacyCadvisorStats dropped.
275276
useLegacyCadvisorStats bool
276277
}
@@ -552,6 +553,7 @@ func NewMainKubelet(kubeCfg *kubeletconfiginternal.KubeletConfiguration,
552553
keepTerminatedPodVolumes: keepTerminatedPodVolumes,
553554
nodeStatusMaxImages: nodeStatusMaxImages,
554555
tracer: tracer,
556+
nodeStartupLatencyTracker: kubeDeps.NodeStartupLatencyTracker,
555557
}
556558

557559
if klet.cloud != nil {
@@ -1293,6 +1295,9 @@ type Kubelet struct {
12931295

12941296
// OpenTelemetry Tracer
12951297
tracer trace.Tracer
1298+
1299+
// Track node startup latencies
1300+
nodeStartupLatencyTracker util.NodeStartupLatencyTracker
12961301
}
12971302

12981303
// ListPodStats is delegated to StatsProvider, which implements stats.Provider interface

pkg/kubelet/kubelet_node_status.go

Lines changed: 10 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -52,6 +52,9 @@ func (kl *Kubelet) registerWithAPIServer() {
5252
if kl.registrationCompleted {
5353
return
5454
}
55+
56+
kl.nodeStartupLatencyTracker.RecordAttemptRegisterNode()
57+
5558
step := 100 * time.Millisecond
5659

5760
for {
@@ -85,6 +88,7 @@ func (kl *Kubelet) registerWithAPIServer() {
8588
func (kl *Kubelet) tryRegisterWithAPIServer(node *v1.Node) bool {
8689
_, err := kl.kubeClient.CoreV1().Nodes().Create(context.TODO(), node, metav1.CreateOptions{})
8790
if err == nil {
91+
kl.nodeStartupLatencyTracker.RecordRegisteredNewNode()
8892
return true
8993
}
9094

@@ -633,6 +637,12 @@ func (kl *Kubelet) patchNodeStatus(originalNode, node *v1.Node) (*v1.Node, error
633637
}
634638
kl.lastStatusReportTime = kl.clock.Now()
635639
kl.setLastObservedNodeAddresses(updatedNode.Status.Addresses)
640+
641+
readyIdx, readyCondition := nodeutil.GetNodeCondition(&updatedNode.Status, v1.NodeReady)
642+
if readyIdx >= 0 && readyCondition.Status == v1.ConditionTrue {
643+
kl.nodeStartupLatencyTracker.RecordNodeReady()
644+
}
645+
636646
return updatedNode, nil
637647
}
638648

pkg/kubelet/kubelet_test.go

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -268,6 +268,7 @@ func newTestKubeletWithImageList(
268268
kubelet.podManager = kubepod.NewBasicPodManager()
269269
podStartupLatencyTracker := kubeletutil.NewPodStartupLatencyTracker()
270270
kubelet.statusManager = status.NewManager(fakeKubeClient, kubelet.podManager, &statustest.FakePodDeletionSafetyProvider{}, podStartupLatencyTracker, kubelet.getRootDir())
271+
kubelet.nodeStartupLatencyTracker = kubeletutil.NewNodeStartupLatencyTracker()
271272

272273
kubelet.containerRuntime = fakeRuntime
273274
kubelet.runtimeCache = containertest.NewFakeRuntimeCache(kubelet.containerRuntime)

pkg/kubelet/metrics/metrics.go

Lines changed: 55 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -33,6 +33,11 @@ const (
3333
KubeletSubsystem = "kubelet"
3434
NodeNameKey = "node_name"
3535
NodeLabelKey = "node"
36+
NodeStartupPreKubeletKey = "node_startup_pre_kubelet_duration_seconds"
37+
NodeStartupPreRegistrationKey = "node_startup_pre_registration_duration_seconds"
38+
NodeStartupRegistrationKey = "node_startup_registration_duration_seconds"
39+
NodeStartupPostRegistrationKey = "node_startup_post_registration_duration_seconds"
40+
NodeStartupKey = "node_startup_duration_seconds"
3641
PodWorkerDurationKey = "pod_worker_duration_seconds"
3742
PodStartDurationKey = "pod_start_duration_seconds"
3843
PodStartSLIDurationKey = "pod_start_sli_duration_seconds"
@@ -736,6 +741,51 @@ var (
736741
StabilityLevel: metrics.ALPHA,
737742
},
738743
)
744+
745+
NodeStartupPreKubeletDuration = metrics.NewGauge(
746+
&metrics.GaugeOpts{
747+
Subsystem: KubeletSubsystem,
748+
Name: NodeStartupPreKubeletKey,
749+
Help: "Duration in seconds of node startup before kubelet starts.",
750+
StabilityLevel: metrics.ALPHA,
751+
},
752+
)
753+
754+
NodeStartupPreRegistrationDuration = metrics.NewGauge(
755+
&metrics.GaugeOpts{
756+
Subsystem: KubeletSubsystem,
757+
Name: NodeStartupPreRegistrationKey,
758+
Help: "Duration in seconds of node startup before registration.",
759+
StabilityLevel: metrics.ALPHA,
760+
},
761+
)
762+
763+
NodeStartupRegistrationDuration = metrics.NewGauge(
764+
&metrics.GaugeOpts{
765+
Subsystem: KubeletSubsystem,
766+
Name: NodeStartupRegistrationKey,
767+
Help: "Duration in seconds of node startup during registration.",
768+
StabilityLevel: metrics.ALPHA,
769+
},
770+
)
771+
772+
NodeStartupPostRegistrationDuration = metrics.NewGauge(
773+
&metrics.GaugeOpts{
774+
Subsystem: KubeletSubsystem,
775+
Name: NodeStartupPostRegistrationKey,
776+
Help: "Duration in seconds of node startup after registration.",
777+
StabilityLevel: metrics.ALPHA,
778+
},
779+
)
780+
781+
NodeStartupDuration = metrics.NewGauge(
782+
&metrics.GaugeOpts{
783+
Subsystem: KubeletSubsystem,
784+
Name: NodeStartupKey,
785+
Help: "Duration in seconds of node startup in total.",
786+
StabilityLevel: metrics.ALPHA,
787+
},
788+
)
739789
)
740790

741791
var registerMetrics sync.Once
@@ -748,6 +798,11 @@ func Register(collectors ...metrics.StableCollector) {
748798
legacyregistry.MustRegister(PodWorkerDuration)
749799
legacyregistry.MustRegister(PodStartDuration)
750800
legacyregistry.MustRegister(PodStartSLIDuration)
801+
legacyregistry.MustRegister(NodeStartupPreKubeletDuration)
802+
legacyregistry.MustRegister(NodeStartupPreRegistrationDuration)
803+
legacyregistry.MustRegister(NodeStartupRegistrationDuration)
804+
legacyregistry.MustRegister(NodeStartupPostRegistrationDuration)
805+
legacyregistry.MustRegister(NodeStartupDuration)
751806
legacyregistry.MustRegister(CgroupManagerDuration)
752807
legacyregistry.MustRegister(PodWorkerStartDuration)
753808
legacyregistry.MustRegister(PodStatusSyncDuration)
Lines changed: 103 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,103 @@
1+
/*
2+
Copyright 2023 The Kubernetes Authors.
3+
4+
Licensed under the Apache License, Version 2.0 (the "License");
5+
you may not use this file except in compliance with the License.
6+
You may obtain a copy of the License at
7+
8+
http://www.apache.org/licenses/LICENSE-2.0
9+
10+
Unless required by applicable law or agreed to in writing, software
11+
distributed under the License is distributed on an "AS IS" BASIS,
12+
WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
13+
See the License for the specific language governing permissions and
14+
limitations under the License.
15+
*/
16+
17+
package util
18+
19+
import (
20+
"sync"
21+
"time"
22+
23+
"k8s.io/kubernetes/pkg/kubelet/metrics"
24+
"k8s.io/utils/clock"
25+
)
26+
27+
type NodeStartupLatencyTracker interface {
28+
// This function may be called across Kubelet restart.
29+
RecordAttemptRegisterNode()
30+
// This function should not be called across Kubelet restart.
31+
RecordRegisteredNewNode()
32+
// This function may be called across Kubelet restart.
33+
RecordNodeReady()
34+
}
35+
36+
type basicNodeStartupLatencyTracker struct {
37+
lock sync.Mutex
38+
39+
bootTime time.Time
40+
kubeletStartTime time.Time
41+
firstRegistrationAttemptTime time.Time
42+
firstRegisteredNewNodeTime time.Time
43+
firstNodeReadyTime time.Time
44+
45+
// For testability
46+
clock clock.Clock
47+
}
48+
49+
func NewNodeStartupLatencyTracker() NodeStartupLatencyTracker {
50+
bootTime, err := GetBootTime()
51+
if err != nil {
52+
bootTime = time.Time{}
53+
}
54+
return &basicNodeStartupLatencyTracker{
55+
bootTime: bootTime,
56+
kubeletStartTime: time.Now(),
57+
clock: clock.RealClock{},
58+
}
59+
}
60+
61+
func (n *basicNodeStartupLatencyTracker) RecordAttemptRegisterNode() {
62+
n.lock.Lock()
63+
defer n.lock.Unlock()
64+
65+
if !n.firstRegistrationAttemptTime.IsZero() {
66+
return
67+
}
68+
69+
n.firstRegistrationAttemptTime = n.clock.Now()
70+
}
71+
72+
func (n *basicNodeStartupLatencyTracker) RecordRegisteredNewNode() {
73+
n.lock.Lock()
74+
defer n.lock.Unlock()
75+
76+
if n.firstRegistrationAttemptTime.IsZero() || !n.firstRegisteredNewNodeTime.IsZero() {
77+
return
78+
}
79+
80+
n.firstRegisteredNewNodeTime = n.clock.Now()
81+
82+
if !n.bootTime.IsZero() {
83+
metrics.NodeStartupPreKubeletDuration.Set(n.kubeletStartTime.Sub(n.bootTime).Seconds())
84+
}
85+
metrics.NodeStartupPreRegistrationDuration.Set(n.firstRegistrationAttemptTime.Sub(n.kubeletStartTime).Seconds())
86+
metrics.NodeStartupRegistrationDuration.Set(n.firstRegisteredNewNodeTime.Sub(n.firstRegistrationAttemptTime).Seconds())
87+
}
88+
89+
func (n *basicNodeStartupLatencyTracker) RecordNodeReady() {
90+
n.lock.Lock()
91+
defer n.lock.Unlock()
92+
93+
if n.firstRegisteredNewNodeTime.IsZero() || !n.firstNodeReadyTime.IsZero() {
94+
return
95+
}
96+
97+
n.firstNodeReadyTime = n.clock.Now()
98+
99+
metrics.NodeStartupPostRegistrationDuration.Set(n.firstNodeReadyTime.Sub(n.firstRegisteredNewNodeTime).Seconds())
100+
if !n.bootTime.IsZero() {
101+
metrics.NodeStartupDuration.Set(n.firstNodeReadyTime.Sub(n.bootTime).Seconds())
102+
}
103+
}

0 commit comments

Comments
 (0)