Kubernetes Pod 内存 - Java GC 日志

11
在Kubernetes仪表板上,有一个Pod,其中内存使用量(字节)显示为904.38Mi
该Pod持有使用-Xms512m -Xmx1024m运行的Java应用程序,并在Kubernetes部署文件中设置requests.memory = 512Mlimits.memory = 1.5G
我启用了GC日志并在Pod日志中看到以下内容:
[2020-04-29T15:41:32.051+0000] GC(1533) Phase 1: Mark live objects
[2020-04-29T15:41:32.133+0000] GC(1533) Phase 1: Mark live objects 81.782ms
[2020-04-29T15:41:32.133+0000] GC(1533) Phase 2: Compute new object addresses
[2020-04-29T15:41:32.145+0000] GC(1533) Phase 2: Compute new object addresses 11.235ms
[2020-04-29T15:41:32.145+0000] GC(1533) Phase 3: Adjust pointers
[2020-04-29T15:41:32.199+0000] GC(1533) Phase 3: Adjust pointers 54.559ms
[2020-04-29T15:41:32.199+0000] GC(1533) Phase 4: Move objects
[2020-04-29T15:41:32.222+0000] GC(1533) Phase 4: Move objects 22.406ms
[2020-04-29T15:41:32.222+0000] GC(1533) Pause Full (Allocation Failure) 510M->127M(680M) 171.359ms
[2020-04-29T15:41:32.222+0000] GC(1532) DefNew: 195639K->0K(195840K)
[2020-04-29T15:41:32.222+0000] GC(1532) Tenured: 422769K->130230K(500700K)
[2020-04-29T15:41:32.222+0000] GC(1532) Metaspace: 88938K->88938K(1130496K)
[2020-04-29T15:41:32.228+0000] GC(1532) Pause Young (Allocation Failure) 603M->127M(614M) 259.018ms
[2020-04-29T15:41:32.228+0000] GC(1532) User=0.22s Sys=0.05s Real=0.26s

Kubernetes如何达到了904.38Mi的使用量?如果我理解正确,当前使用量仅为:
DefNew (young) -      0k
Tenured        - 130230K
Metaspace      -  88938K
Sum            - 216168K

运行ps命令显示除了这个Java应用程序之外,Pod上没有其他进程在运行。
有人能解释一下吗?

(编辑) 当Pod第一次启动并运行几分钟时,内存使用量显示为约500MB,然后让请求进来,它将突增到900MB-1GB,然后当所有内容都被处理后,尽管基于GC日志堆已经正常地进行了垃圾回收,但是k8s仪表板上的内存使用情况不会降至900MB以下。


你能否尝试在容器中运行 free -m 命令?它可以告诉你容器实际使用了多少内存,并可能帮助你发现Java进程不知道的泄漏问题。 - Yaron Idan
@YaronIdan 在容器中使用 free -m 是无用的。只需尝试在容器内运行 docker run -m...,然后执行 free -m 即可。 - Eugene
你使用的是哪个Java版本? - Pankaj
1
@Pankaj,祖鲁11 - lorraine batol
2个回答

18
这里有很多事情要处理,我们逐一来看。似乎您每个pod使用单个容器(尽管您可以每个pod使用许多容器)。requests.memory和limits.memory是特定于容器的,Kubernetes将所有容器的限制之和作为pod的limits和requests。
因此,请考虑一下-您正在说pod显示904.38Mi,但您显示的是requests.memory和limits.memory,这是每个容器的。这就是我认为您每个pod使用一个容器的原因。这是一个一般性介绍,没有回答您的问题,但我们会解决这个问题。
然后是一个pod由docker启动的事实,docker由kubectl启动,并读取requires.memory和limits.memory。为了使这更简单:在limits.memory中设置的内容将作为docker-m传递。因此,在您的情况下,用于docker进程的总内存为1.5GC。请记住,这是整个进程的限制,而不仅仅是堆。Java进程不仅仅是堆,您可以使用-Xms512m-Xmx1024m进行指定。所以回答你的问题:
Kubernetes如何得出904.38Mi的使用情况?
这是整个进程当前正在占用的,而不仅仅是堆。从您发布的非常短的日志文件中可以看出,您的应用程序运行良好。
编辑
实际上,我的环境中没有kubernetes仪表板来专门测试这一点,因此必须安装它才能真正了解发生了什么。我有一个提示针对大多数事情,但为了确保,我进行了一些测试。
首先要做的是:仪表板中的那个数字是什么意思?花了一段时间才找到/理解,但那是进程实际驻留内存,这实际上是一件非常好的事情。
任何明智的操作系统都知道,当有人从中请求内存时,它很少需要/利用全部内存,因此,它以懒惰的方式将内存分配给它。这在k8s中很容易证明。假设我有一个jdk-13 JVM并使用以下命令启动它:
kubectl run jdk-13 
    --image=jdk-13 
    --image-pull-policy=Never 
    --limits "memory=100Mi" 
    --requests "memory=10Mi" 
    --command -- /bin/sh -c "while true; do sleep 5; done".

注意 requests.memory=10Milimits.memory=100Mi。从一开始阅读答案,你已经知道特定的pod将以docker -m 100m...启动,因为limits.memory=100Mi。这很容易证明,只需sh进入pod

 kubectl exec -it jdk-13-b8d656977-rpzrg -- /bin/sh

并找出cgroup的内容:

 # cat /sys/fs/cgroup/memory/memory.limit_in_bytes
 104857600 // 100MB

非常好!因此,Pod的内存限制最大为100 MB,但是当前的内存利用率是多少?也就是说,占用了多少驻留内存?

kubectl top pod
   NAME                          CPU(cores)   MEMORY(bytes)
   jdk-13-b8d656977-rpzrg           1m           4Mi

好的,当前的内存利用率只有4MB。 如果你执行以下操作,可以“确保”这确实准确无误:

kubectl exec -it jdk-13-b8d656977-rpzrg -- /bin/sh

并且在该 pod 内出现问题:

top -o %MEM

请注意,{{RES}}内存与仪表板或{{kubectl top pod}}报告的内存相当。
现在让我们进行一个测试。假设我在该pod中有这个非常简单的代码:
// run this with: java "-Xlog:gc*=debug" -Xmx100m -Xms20m  HeapTest
import java.time.temporal.ChronoUnit;
import java.util.Arrays;
import java.util.concurrent.TimeUnit;
import java.util.concurrent.locks.LockSupport;

public class HeapTest {

    public static void main(String[] args) throws Exception {

        // allocate 1 MB every 3 seconds
        for (int i = 0; i < 40; ++i) {
            byte[] b = new byte[1024 * 1024 * 1];
            b[i] = 1;
            System.out.println(Arrays.hashCode(b));
            LockSupport.parkNanos(TimeUnit.of(ChronoUnit.SECONDS).toNanos(3));
        }
    }
}

    

我每3秒分配1MB的内存,持续约2分钟。当我在仪表盘中查看此进程时,我确实看到某个时间点内存增长。程序结束后,仪表板报告内存下降。好的!这意味着内存已经归还,RSS内存下降。在仪表盘中的显示如下:

enter image description here

现在让我们稍微改变一下这段代码。让我们添加一些GC,永远不要完成这个进程(就像典型的spring-boot应用程序一样):

import java.time.temporal.ChronoUnit;
import java.util.Arrays;
import java.util.concurrent.TimeUnit;
import java.util.concurrent.locks.LockSupport;

public class HeapTest {

    public static void main(String[] args) throws Exception {

        // allocate 1 MB every 3 seconds
        for (int i = 0; i < 40; ++i) {
            byte[] b = new byte[1024 * 1024 * 1];
            b[i] = 1;
            System.out.println(Arrays.hashCode(b));
            LockSupport.parkNanos(TimeUnit.of(ChronoUnit.SECONDS).toNanos(3));
        }
        for (int i = 0; i < 10; i++) {
            Thread.sleep(500);
            System.gc();
        }
        
        while (true) {
            try {
                Thread.sleep(TimeUnit.of(ChronoUnit.SECONDS).toMillis(5));
                Thread.onSpinWait();
            } catch (Exception e) {
                throw new RuntimeException(e);
            }
        }

    }
}

我使用以下方式运行此程序:

java "-Xlog:heap*=debug" 
     "-Xlog:gc*=debug" 
     "-Xlog:ergo*=debug" 
     -Xmx100m 
     -Xms20m
     HeapTest

在检查日志(就像您的示例中一样)时,我确实看到堆已经被很好地回收了。但是当我查看仪表板时,内存没有下降(不像之前的示例)。

enter image description here

一旦 G1GC 占用内存,它就不太愿意将其归还给操作系统。虽然有时候会发生这种情况,例如 一个例子 或者 您可以指示它这样做,但两种方法都相当痛苦。相反,有些 GC 算法更加智能(并且通常要好得多)。我个人喜欢 Shenandoah 算法,让我们看看它的工作原理。如果我稍微更改一下代码(以便更好地证明我的观点):
import java.time.temporal.ChronoUnit;
import java.util.Arrays;
import java.util.concurrent.TimeUnit;
import java.util.concurrent.locks.LockSupport;

public class HeapTest {

    public static void main(String[] args) throws Exception {

        // allocate 1/4 MB every 100 ms
        for (int i = 0; i < 6000; ++i) {
            byte[] b = new byte[1024 * 256];
            b[i] = 1;
            System.out.println(Arrays.hashCode(b));
            LockSupport.parkNanos(TimeUnit.of(ChronoUnit.MILLIS).toNanos(100));
        }

        while (true) {
            try {
                Thread.sleep(TimeUnit.of(ChronoUnit.SECONDS).toMillis(5));
                Thread.onSpinWait();
            } catch (Exception e) {
                throw new RuntimeException(e);
            }
        }

    }
}

并使用以下命令运行:

 java "-Xlog:gc*=debug" 
      "-Xlog:ergo*=debug" 
      "-Xlog:heap*=debug" 
       -XX:+UnlockExperimentalVMOptions 
       -XX:+UseShenandoahGC 
       -XX:+ShenandoahUncommit 
       -XX:ShenandoahGCHeuristics=compact  
       -Xmx1g 
       -Xms1m  
       HeapTest

以下是你将要看到的内容:

heap3

而且你确实应该关心这个问题:

在容器环境中,这种行为特别不利,因为资源是按使用付费的。即使在虚拟机由于闲置而只使用其分配的内存资源的一小部分的阶段,G1也会保留所有Java堆。这导致客户始终支付所有资源的费用,云提供商无法充分利用其硬件。

P.S. 我还要补充一点,就是其他Pod也会受到影响,因为一个Pod决定尽可能多地占用内存,而在特定的峰值时从未归还。


谢谢 @Eugene,是的,每个 Pod 只有一个容器。实际上,我问这个问题的另一个原因是因为在启动时使用的大约只有 500MB,然后在接收请求进行处理时会突然增加到 900MB-1GB,然后在所有进程完成后,它似乎不会再次低于 900MB,但从 GC 日志来看,堆已经很好地被 GC 处理了。因此,如果堆被 GC 处理了,我想知道它没有被回收的内存去了哪里。 - lorraine batol
@村民,你不需要添加更多的日志,因为从你的日志中可以看到内存已经被垃圾回收了,但它并没有返回给操作系统,而是仍然是JVM管理下的堆内存。 - Eugene
谢谢@Eugene,您能详细说明为什么它没有返回给操作系统吗?这是否意味着k8s仪表板上的内存使用量不会下降? - lorraine batol

1

GC处理进程使用的内存子集。 JVM内存中有一些区域不受垃圾回收的影响。

以下是几个未包含在堆/元空间中的内存区域:

  • 线程堆栈空间
  • 压缩类空间
  • JIT编译代码
  • NIO直接缓冲区内存

上面的列表并不完整,这些只是最大的内存消耗者。

这里是JVM内存层次结构图,附带相关的配置选项。

总之,实际的JVM内存需求总是大于堆限制的。

这取决于应用程序的性质,可以通过经验确定。

更新

Java本机内存跟踪可以在JVM中启用,以提供有关不同功能区域的内存使用情况的详细报告。


谢谢,@Alexey Regozin,我有没有办法检查那些其他的内存区域以了解它们的用途? - lorraine batol
1
@villager 添加了本地内存跟踪的链接 - Alexey Ragozin

网页内容由stack overflow 提供, 点击上面的
可以查看英文原文,
原文链接