Bug 2040399 - Excessive memory usage by the kubelet
Summary: Excessive memory usage by the kubelet
Keywords:
Status: CLOSED DUPLICATE of bug 2041641
Alias: None
Product: OpenShift Container Platform
Classification: Red Hat
Component: Node
Version: 4.8
Hardware: Unspecified
OS: Unspecified
high
medium
Target Milestone: ---
: ---
Assignee: Harshal Patil
QA Contact: Sunil Choudhary
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2022-01-13 16:08 UTC by Juan Luis de Sousa-Valadas
Modified: 2022-03-11 04:03 UTC (History)
6 users (show)

Fixed In Version:
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed: 2022-03-11 04:03:52 UTC
Target Upstream Version:
Embargoed:


Attachments (Terms of Use)

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?


Note You need to log in before you can comment on or make changes to this bug.