Note: This bug is displayed in read-only format because the product is no longer active in Red Hat Bugzilla.

Bug 2040399

Summary: Excessive memory usage by the kubelet
Product: OpenShift Container Platform Reporter: Juan Luis de Sousa-Valadas <jdesousa>
Component: NodeAssignee: Harshal Patil <harpatil>
Node sub component: Kubelet QA Contact: Sunil Choudhary <schoudha>
Status: CLOSED DUPLICATE Docs Contact:
Severity: medium    
Priority: high CC: aos-bugs, harpatil, igreen, keyoung, kir, kkarampo
Version: 4.8   
Target Milestone: ---   
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2022-03-11 04:03:52 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:

Description Juan Luis de Sousa-Valadas 2022-01-13 16:08:54 UTC
Description of problem:
Customer reports that the kubelet is consuming an excessive amount of memory (over 30GB of RSS for a node with about 280 pods running: 
root       10524 84.4 25.0 82381044 32914988 ?   -    Jan10 1024:17 kubelet

After doing some inspection it looks to me like the issue is with cAdvisor:


Total: 26.38GB
ROUTINE ======================== k8s.io/kubernetes/vendor/github.com/google/cadvisor/container/libcontainer.newContainerStats in /builddir/build/BUILD/openshift-4.8.0/_output/local/go/src/k8s.io/kubernetes/vendor/github.com/google/cadvisor/container/libcontainer/handler.go
    8.17GB     9.78GB (flat, cum) 37.06% of Total
         .          .    898:	}
         .          .    899:
         .          .    900:}
         .          .    901:
         .          .    902:func newContainerStats(libcontainerStats *libcontainer.Stats, includedMetrics container.MetricSet) *info.ContainerStats {
    8.17GB     8.17GB    903:	ret := &info.ContainerStats{
         .          .    904:		Timestamp: time.Now(),
         .          .    905:	}
         .          .    906:
         .          .    907:	if s := libcontainerStats.CgroupStats; s != nil {
         .          .    908:		setCPUStats(s, ret, includedMetrics.Has(container.PerCpuUsageMetrics))
         .          .    909:		if includedMetrics.Has(container.DiskIOMetrics) {
         .     1.61GB    910:			setDiskIoStats(s, ret)
         .          .    911:		}
         .          .    912:		setMemoryStats(s, ret)
         .          .    913:		if includedMetrics.Has(container.MemoryNumaMetrics) {
         .          .    914:			setMemoryNumaStats(s, ret)
         .          .    915:		}


ROUTINE ======================== k8s.io/kubernetes/vendor/github.com/google/cadvisor/manager.(*containerData).housekeeping in /builddir/build/BUILD/openshift-4.8.0/_output/local/go/src/k8s.io/kubernetes/vendor/github.com/google/cadvisor/manager/container.go
         0    15.66GB (flat, cum) 59.34% of Total
         .          .    526:	// Housekeep every second.
         .          .    527:	klog.V(3).Infof("Start housekeeping for container %q\n", cd.info.Name)
         .          .    528:	houseKeepingTimer := cd.clock.NewTimer(0 * time.Second)
         .          .    529:	defer houseKeepingTimer.Stop()
         .          .    530:	for {
         .    15.65GB    531:		if !cd.housekeepingTick(houseKeepingTimer.C(), longHousekeeping) {

It seems that cAdvisor doesn't remove the metrics for older containers, I see lots of errors like:

Jan 07 11:56:08 <redacted> hyperkube[10978]: I0107 11:56:08.499748   10978 kubelet.go:1982] "SyncLoop (PLEG): event for pod" pod="<ns>/<pod name>" event=&{ID:50981e01-233e-407a-8ca8-75883d6cb090 Type:ContainerDied Data:dd4f2e48eb1834edea49e94c81fa41eb69d6940e767756c046207711ab191346}     <----- container died
<snip>
Jan 07 12:19:49 <redacted> hyperkube[10978]: E0107 12:19:49.344355   10978 cadvisor_stats_provider.go:147] "Unable to fetch pod log stats" err="open /var/log/pods/<ns>_<pod name>-27359274-5nmk4_50981e01-233e-407a-8ca8-75883d6cb090: no such file or directory" pod="<ns>/<pod name>" <-- 20 minutes later it's trying to get pod logs? Seems wrong.

I see 3529 UUIDs in the logs showing this problem.

Checking the logs a bit further I see that the cAdvisor manager complains in the function GetRequestedContainersInfo:
Jan 11 08:36:25 <redacted>[10524]: W0111 08:36:25.082346   10524 manager.go:696] Error getting data for container /kubepods.slice/kubepods-burstable.slice/kubepods-burstable-pod262101dc_6d7c_4fa9_aa52_ba83d3d48fb8.slice/crio-cc51feadfae60d8eec5be88d8e867ef1b18e8cc70328c207e50a02b155f4b979.scope because of race condition

I see this entry thousands of times and with several different container IDs. Unfortunately I'm not familiar enough with the kubelet to triage this further in a reasonable amount of time.

Version-Release number of selected component (if applicable):
4.8.12

How reproducible:
Extremely hard, there is exactly one occurence confirmed in just one node.

Steps to Reproduce:
Unknown, this could be a race condition

Actual results:
Excessive CPU consumption in cAdvisor

Expected results:

Additional info:
The kubelet has not been restarted

Comment 11 Ken Young 2022-02-11 22:46:31 UTC
Can we move this to ON_QA for 4.9?