Skip to content

Commit 616cf8f

Browse files
nadaverellnadaverell
authored
Detect eventless post-bind startup stalls (#914)
1 parent bc0be2a commit 616cf8f

9 files changed

Lines changed: 537 additions & 25 deletions

File tree

‎internal/issues/category.go‎

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -41,7 +41,7 @@ func Classify(in classifyInput) issuesapi.Category {
4141
return issuesapi.CategoryAdmissionWebhookBlocking
4242
case "RBACForbidden":
4343
return issuesapi.CategoryRBACForbidden
44-
case "IPExhaustion", "SandboxCreationFailed":
44+
case "IPExhaustion", "SandboxCreationFailed", "PostBindStartupStall":
4545
// scheduled but stuck creating the sandbox — a startup-stage stall
4646
return issuesapi.CategoryContainerWaiting
4747
case "VolumeMultiAttach", "VolumeAttach", "VolumeMount":

‎internal/issues/category_test.go‎

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -21,6 +21,7 @@ func TestClassify(t *testing.T) {
2121
{"rbac forbidden", classifyInput{Source: SourceScheduling, Kind: "Deployment", Reason: "RBACForbidden"}, issuesapi.CategoryRBACForbidden},
2222
{"ip exhaustion is startup stall", classifyInput{Source: SourceScheduling, Kind: "Pod", Reason: "IPExhaustion"}, issuesapi.CategoryContainerWaiting},
2323
{"sandbox failed is startup stall", classifyInput{Source: SourceScheduling, Kind: "Pod", Reason: "SandboxCreationFailed"}, issuesapi.CategoryContainerWaiting},
24+
{"eventless post-bind startup stall", classifyInput{Source: SourceScheduling, Kind: "Pod", Reason: "PostBindStartupStall"}, issuesapi.CategoryContainerWaiting},
2425
{"volume multiattach", classifyInput{Source: SourceScheduling, Kind: "Pod", Reason: "VolumeMultiAttach"}, issuesapi.CategoryVolumeMountFailed},
2526
{"volume mount", classifyInput{Source: SourceScheduling, Kind: "Pod", Reason: "VolumeMount"}, issuesapi.CategoryVolumeMountFailed},
2627
{"terminating pod", classifyInput{Source: SourceProblem, Kind: "Pod", Reason: "Terminating stuck"}, issuesapi.CategoryTerminationStuck},

‎internal/issues/provider.go‎

Lines changed: 6 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -94,17 +94,20 @@ func (p *CacheProvider) DetectScheduling(namespaces []string) []k8s.Detection {
9494
detect := func(ns string) []k8s.Detection {
9595
out := k8s.DetectSchedulingProblems(p.cache, ns)
9696
out = append(out, k8s.DetectAdmissionProblems(p.cache, ns)...)
97-
out = append(out, k8s.DetectPostBindProblems(p.cache, ns)...)
9897
return out
9998
}
10099
if len(namespaces) == 0 {
101-
return detect("")
100+
out := detect("")
101+
out = append(out, k8s.DetectPostBindProblems(p.cache, "")...)
102+
return out
102103
}
103104
perNs := make([][]k8s.Detection, 0, len(namespaces))
104105
for _, ns := range namespaces {
105106
perNs = append(perNs, detect(ns))
106107
}
107-
return flattenNamespacedProblems(perNs)
108+
out := flattenNamespacedProblems(perNs)
109+
out = append(out, k8s.DetectPostBindProblemsForNamespaces(p.cache, namespaces)...)
110+
return out
108111
}
109112

110113
func (p *CacheProvider) DetectCAPIProblems(namespaces []string) []k8s.Detection {

‎internal/k8s/detect_scheduling.go‎

Lines changed: 253 additions & 20 deletions
Original file line numberDiff line numberDiff line change
@@ -485,8 +485,12 @@ func DetectSchedulingProblems(cache *ResourceCache, namespace string) []Detectio
485485
}
486486

487487
func podScheduledCondition(pod *corev1.Pod) *corev1.PodCondition {
488+
return podCondition(pod, corev1.PodScheduled)
489+
}
490+
491+
func podCondition(pod *corev1.Pod, condType corev1.PodConditionType) *corev1.PodCondition {
488492
for i := range pod.Status.Conditions {
489-
if pod.Status.Conditions[i].Type == corev1.PodScheduled {
493+
if pod.Status.Conditions[i].Type == condType {
490494
return &pod.Status.Conditions[i]
491495
}
492496
}
@@ -1026,16 +1030,21 @@ func classifyAdmissionFailure(msg string) (string, bool) {
10261030
// The pod was scheduled (a node accepted it) but the kubelet can't bring it
10271031
// up — stuck in ContainerCreating because the CNI can't hand out an IP or the
10281032
// CSI can't attach/mount a volume. radar otherwise treats ContainerCreating
1029-
// as benign, so these silently sit as "Pending". The failure detail lives in
1030-
// kubelet events (FailedCreatePodSandBox / FailedMount / FailedAttachVolume),
1031-
// so this detector is event-driven, cross-checked against still-stuck pods so
1032-
// a pod that recovered after a retry isn't falsely flagged.
1033+
// as benign, so these silently sit as "Pending". The best failure detail lives
1034+
// in kubelet events (FailedCreatePodSandBox / FailedMount / FailedAttachVolume),
1035+
// but events expire; when no recent event remains, a narrow fallback catches
1036+
// the CNI/sandbox shape: scheduled, old, ContainerCreating, and no Pod IP.
10331037

1034-
const postBindFailureWindow = 10 * time.Minute
1038+
const (
1039+
postBindFailureWindow = 10 * time.Minute
1040+
postBindCriticalAfter = 30 * time.Minute
1041+
podReadyToStartContainers = corev1.PodConditionType("PodReadyToStartContainers")
1042+
)
10351043

10361044
var postBindSeverity = map[string]string{
10371045
"IPExhaustion": "critical",
10381046
"SandboxCreationFailed": "high",
1047+
"PostBindStartupStall": "high",
10391048
"VolumeMultiAttach": "critical",
10401049
"VolumeAttach": "high",
10411050
"VolumeMount": "high",
@@ -1044,7 +1053,25 @@ var postBindSeverity = map[string]string{
10441053
// DetectPostBindProblems flags pods stuck in ContainerCreating due to CNI/IP
10451054
// or volume failures. namespace="" scans all namespaces.
10461055
func DetectPostBindProblems(cache *ResourceCache, namespace string) []Detection {
1047-
if cache == nil || cache.Events() == nil {
1056+
now := time.Now()
1057+
return detectPostBindProblems(cache, namespace, postBindStartupStallCounts(cache, []string{namespace}, now), now)
1058+
}
1059+
1060+
func DetectPostBindProblemsForNamespaces(cache *ResourceCache, namespaces []string) []Detection {
1061+
if len(namespaces) == 0 {
1062+
return DetectPostBindProblems(cache, "")
1063+
}
1064+
now := time.Now()
1065+
nodeStallCounts := postBindStartupStallCounts(cache, namespaces, now)
1066+
var out []Detection
1067+
for _, ns := range namespaces {
1068+
out = append(out, detectPostBindProblems(cache, ns, nodeStallCounts, now)...)
1069+
}
1070+
return out
1071+
}
1072+
1073+
func detectPostBindProblems(cache *ResourceCache, namespace string, nodeStallCounts map[string]int, now time.Time) []Detection {
1074+
if cache == nil {
10481075
return nil
10491076
}
10501077
stuck := stuckScheduledPods(cache, namespace)
@@ -1053,13 +1080,14 @@ func DetectPostBindProblems(cache *ResourceCache, namespace string) []Detection
10531080
}
10541081

10551082
var events []*corev1.Event
1056-
if namespace != "" {
1057-
events, _ = cache.Events().Events(namespace).List(labels.Everything())
1058-
} else {
1059-
events, _ = cache.Events().List(labels.Everything())
1083+
if eventLister := cache.Events(); eventLister != nil {
1084+
if namespace != "" {
1085+
events, _ = eventLister.Events(namespace).List(labels.Everything())
1086+
} else {
1087+
events, _ = eventLister.List(labels.Everything())
1088+
}
10601089
}
10611090

1062-
now := time.Now()
10631091
// One row per stuck pod, showing the CURRENT blocker. The kubelet
10641092
// re-emits a post-bind event per retry and the active cause can change
10651093
// (NetworkNotReady → FailedMount). Informer List order is arbitrary, so
@@ -1070,6 +1098,7 @@ func DetectPostBindProblems(cache *ResourceCache, namespace string) []Detection
10701098
reason string
10711099
}
10721100
latest := map[string]pbCandidate{}
1101+
expiredLatest := map[string]pbCandidate{}
10731102
var order []string
10741103
for _, e := range events {
10751104
if e.InvolvedObject.Kind != "Pod" {
@@ -1079,13 +1108,16 @@ func DetectPostBindProblems(cache *ResourceCache, namespace string) []Detection
10791108
if !ok {
10801109
continue
10811110
}
1082-
if t := eventLastTime(e); !t.IsZero() && now.Sub(t) > postBindFailureWindow {
1083-
continue
1084-
}
10851111
key := e.InvolvedObject.Namespace + "/" + e.InvolvedObject.Name
10861112
if _, isStuck := stuck[key]; !isStuck {
10871113
continue
10881114
}
1115+
if t := eventLastTime(e); !t.IsZero() && now.Sub(t) > postBindFailureWindow {
1116+
if cur, exists := expiredLatest[key]; !exists || t.After(eventLastTime(cur.ev)) {
1117+
expiredLatest[key] = pbCandidate{ev: e, reason: reason}
1118+
}
1119+
continue
1120+
}
10891121
if cur, exists := latest[key]; exists {
10901122
if eventLastTime(e).After(eventLastTime(cur.ev)) {
10911123
latest[key] = pbCandidate{ev: e, reason: reason}
@@ -1100,19 +1132,51 @@ func DetectPostBindProblems(cache *ResourceCache, namespace string) []Detection
11001132
for _, key := range order {
11011133
c := latest[key]
11021134
pod := stuck[key]
1103-
severity := postBindSeverity[c.reason]
1104-
if severity == "" {
1105-
severity = "high"
1106-
}
11071135
ageDur := now.Sub(pod.CreationTimestamp.Time)
1136+
severity := postBindProblemSeverity(c.reason, ageDur)
11081137
ownerGroup, ownerKind, ownerName := podOwnerKindName(cache, pod)
11091138
problems = append(problems, Detection{
11101139
Kind: "Pod",
11111140
Namespace: pod.Namespace,
11121141
Name: pod.Name,
11131142
Severity: severity,
11141143
Reason: c.reason,
1115-
Message: "stuck creating: " + strings.TrimSpace(c.ev.Message),
1144+
Message: postBindEventMessage(pod, c.reason, c.ev.Message, nodeStallCounts),
1145+
Age: FormatAge(ageDur),
1146+
AgeSeconds: int64(ageDur.Seconds()),
1147+
Duration: FormatAge(ageDur),
1148+
DurationSeconds: int64(ageDur.Seconds()),
1149+
OwnerGroup: ownerGroup,
1150+
OwnerKind: ownerKind,
1151+
OwnerName: ownerName,
1152+
})
1153+
}
1154+
1155+
var fallbackKeys []string
1156+
for key, pod := range stuck {
1157+
if _, hasRecentEvent := latest[key]; hasRecentEvent {
1158+
continue
1159+
}
1160+
if c, hasExpiredEvent := expiredLatest[key]; hasExpiredEvent && isVolumePostBindReason(c.reason) {
1161+
continue
1162+
}
1163+
if !isPostBindStartupStallPod(pod, now) {
1164+
continue
1165+
}
1166+
fallbackKeys = append(fallbackKeys, key)
1167+
}
1168+
sort.Strings(fallbackKeys)
1169+
for _, key := range fallbackKeys {
1170+
pod := stuck[key]
1171+
ageDur := now.Sub(pod.CreationTimestamp.Time)
1172+
ownerGroup, ownerKind, ownerName := podOwnerKindName(cache, pod)
1173+
problems = append(problems, Detection{
1174+
Kind: "Pod",
1175+
Namespace: pod.Namespace,
1176+
Name: pod.Name,
1177+
Severity: postBindProblemSeverity("PostBindStartupStall", ageDur),
1178+
Reason: "PostBindStartupStall",
1179+
Message: postBindFallbackMessage(pod, ageDur, nodeStallCounts),
11161180
Age: FormatAge(ageDur),
11171181
AgeSeconds: int64(ageDur.Seconds()),
11181182
Duration: FormatAge(ageDur),
@@ -1144,6 +1208,175 @@ func stuckScheduledPods(cache *ResourceCache, namespace string) map[string]*core
11441208
return out
11451209
}
11461210

1211+
func postBindProblemSeverity(reason string, age time.Duration) string {
1212+
if (reason == "SandboxCreationFailed" || reason == "PostBindStartupStall") && age >= postBindCriticalAfter {
1213+
return "critical"
1214+
}
1215+
severity := postBindSeverity[reason]
1216+
if severity == "" {
1217+
return "high"
1218+
}
1219+
return severity
1220+
}
1221+
1222+
func isPostBindStartupStallPod(pod *corev1.Pod, now time.Time) bool {
1223+
if pod == nil || pod.Status.Phase != corev1.PodPending || pod.Spec.NodeName == "" {
1224+
return false
1225+
}
1226+
if cond := podScheduledCondition(pod); cond != nil && cond.Status == corev1.ConditionFalse {
1227+
return false
1228+
}
1229+
if pod.CreationTimestamp.IsZero() || now.Sub(pod.CreationTimestamp.Time) <= postBindFailureWindow {
1230+
return false
1231+
}
1232+
if podHasStatusIP(pod) {
1233+
return false
1234+
}
1235+
for i := range pod.Status.ContainerStatuses {
1236+
if w := pod.Status.ContainerStatuses[i].State.Waiting; w != nil && w.Reason == "ContainerCreating" {
1237+
return true
1238+
}
1239+
}
1240+
return false
1241+
}
1242+
1243+
func podHasStatusIP(pod *corev1.Pod) bool {
1244+
if pod.Status.PodIP != "" {
1245+
return true
1246+
}
1247+
for _, ip := range pod.Status.PodIPs {
1248+
if ip.IP != "" {
1249+
return true
1250+
}
1251+
}
1252+
return false
1253+
}
1254+
1255+
func postBindStartupStallCounts(cache *ResourceCache, namespaces []string, now time.Time) map[string]int {
1256+
counts := map[string]int{}
1257+
if len(namespaces) == 0 {
1258+
namespaces = []string{""}
1259+
}
1260+
suppressed := expiredVolumePostBindPodKeys(cache, namespaces, now)
1261+
seen := map[string]bool{}
1262+
for _, namespace := range namespaces {
1263+
for _, pods := range listPodsByNamespace(cache, namespace) {
1264+
for _, pod := range pods {
1265+
key := pod.Namespace + "/" + pod.Name
1266+
if seen[key] {
1267+
continue
1268+
}
1269+
seen[key] = true
1270+
if suppressed[key] {
1271+
continue
1272+
}
1273+
if !isPostBindStartupStallPod(pod, now) {
1274+
continue
1275+
}
1276+
counts[pod.Spec.NodeName]++
1277+
}
1278+
}
1279+
}
1280+
return counts
1281+
}
1282+
1283+
func expiredVolumePostBindPodKeys(cache *ResourceCache, namespaces []string, now time.Time) map[string]bool {
1284+
out := map[string]bool{}
1285+
if cache == nil {
1286+
return out
1287+
}
1288+
eventLister := cache.Events()
1289+
if eventLister == nil {
1290+
return out
1291+
}
1292+
if len(namespaces) == 0 {
1293+
namespaces = []string{""}
1294+
}
1295+
latestTime := map[string]time.Time{}
1296+
latestReason := map[string]string{}
1297+
for _, namespace := range namespaces {
1298+
var events []*corev1.Event
1299+
if namespace != "" {
1300+
events, _ = eventLister.Events(namespace).List(labels.Everything())
1301+
} else {
1302+
events, _ = eventLister.List(labels.Everything())
1303+
}
1304+
for _, e := range events {
1305+
if e.InvolvedObject.Kind != "Pod" {
1306+
continue
1307+
}
1308+
reason, ok := classifyPostBindFailure(e.Reason, e.Message)
1309+
if !ok {
1310+
continue
1311+
}
1312+
t := eventLastTime(e)
1313+
if t.IsZero() || now.Sub(t) <= postBindFailureWindow {
1314+
continue
1315+
}
1316+
key := e.InvolvedObject.Namespace + "/" + e.InvolvedObject.Name
1317+
if cur, exists := latestTime[key]; !exists || t.After(cur) {
1318+
latestTime[key] = t
1319+
latestReason[key] = reason
1320+
}
1321+
}
1322+
}
1323+
for key, reason := range latestReason {
1324+
if isVolumePostBindReason(reason) {
1325+
out[key] = true
1326+
}
1327+
}
1328+
return out
1329+
}
1330+
1331+
func postBindEventMessage(pod *corev1.Pod, reason, eventMessage string, nodeStallCounts map[string]int) string {
1332+
msg := "stuck creating"
1333+
if pod.Spec.NodeName != "" {
1334+
msg += " on node " + pod.Spec.NodeName
1335+
}
1336+
if eventMessage = strings.TrimSpace(eventMessage); eventMessage != "" {
1337+
msg += ": " + eventMessage
1338+
}
1339+
return appendPostBindNodeCorrelation(msg, pod, reason, nodeStallCounts)
1340+
}
1341+
1342+
func postBindFallbackMessage(pod *corev1.Pod, age time.Duration, nodeStallCounts map[string]int) string {
1343+
parts := []string{fmt.Sprintf("container is ContainerCreating with no Pod IP after %s", FormatAge(age))}
1344+
if cond := podCondition(pod, podReadyToStartContainers); cond != nil && cond.Status == corev1.ConditionFalse {
1345+
parts = append(parts, "PodReadyToStartContainers=False")
1346+
}
1347+
msg := fmt.Sprintf("stuck before container start on node %s: %s; no matching recent kubelet event found; check kubelet, container runtime, and CNI on that node",
1348+
pod.Spec.NodeName, strings.Join(parts, "; "))
1349+
return appendPostBindNodeCorrelation(msg, pod, "PostBindStartupStall", nodeStallCounts)
1350+
}
1351+
1352+
func appendPostBindNodeCorrelation(msg string, pod *corev1.Pod, reason string, nodeStallCounts map[string]int) string {
1353+
if !isNetworkPostBindReason(reason) || pod.Spec.NodeName == "" {
1354+
return msg
1355+
}
1356+
if count := nodeStallCounts[pod.Spec.NodeName]; count > 1 {
1357+
return fmt.Sprintf("%s; same node has %d visible pods stuck before container start", msg, count)
1358+
}
1359+
return msg
1360+
}
1361+
1362+
func isNetworkPostBindReason(reason string) bool {
1363+
switch reason {
1364+
case "IPExhaustion", "SandboxCreationFailed", "PostBindStartupStall":
1365+
return true
1366+
default:
1367+
return false
1368+
}
1369+
}
1370+
1371+
func isVolumePostBindReason(reason string) bool {
1372+
switch reason {
1373+
case "VolumeMultiAttach", "VolumeAttach", "VolumeMount":
1374+
return true
1375+
default:
1376+
return false
1377+
}
1378+
}
1379+
11471380
// classifyPostBindFailure maps a kubelet event (reason + message) to a
11481381
// post-bind failure class, distinguishing IP exhaustion from generic sandbox
11491382
// failures and multi-attach from generic volume-attach errors.

0 commit comments

Comments
 (0)