kubernetes pod 内存 - java gc 日志

kubernetes pod memory - java gc logs

在 kubernetes 仪表板上,有一个 pod,其中内存使用情况(字节)显示为 904.38Mi

此 pod 包含 java 应用程序 运行 和 -Xms512m -Xmx1024m,以及 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 上没有其他进程 运行ning。
任何人都可以对此有所了解吗?

(已编辑) 当pod刚启动的时候让运行几分钟,内存使用显示只有500mb左右,然后让请求进来它会爆发到900mb-1gb,然后当所有处理完后,内存使用在 k8s 仪表板上不会低于 900mb,即使基于 GC 日志,堆 GC'ed ok。

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

以下是堆/元空间中不包含的一些内存区域

  • 线程堆栈Space
  • 压缩ClassSpace
  • JIT 编译代码
  • NIO直接缓冲内存

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

Here is JVM memory hierarchy diagram 具有相关的配置选项。

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

多大取决于应用的性质,可以根据经验确定。

更新

Java Native Memory Tracking 可以在 JVM 中启用,以提供与跨不同功能区域的内存使用情况相关的详细报告。

这里发生了很多事情。让我们一个接一个。

似乎每个 pod 使用一个容器(尽管每个 pod 可以有 许多 个容器)。 requests.memorylimits.memory 特定于 容器 ,Kubernetes 为每个 pod[= 计算 limitsrequests 132=] 作为所有容器限制的总和。

所以想一想 - 你是说 pod 显示 904.38Mi,但你显示 requests.memorylimits.memory,这是每个 容器。这就是为什么我假设每个 pod 有一个容器。这是一个一般性的介绍,无法回答您的问题 - 但我们会到达那里。

然后是 poddocker 开始的事实,它以 kubectl 开始,读作 requires.memorylimits.memory。为了使这更简单一点:您在 limits.memory 中设置的内容将作为 docker -m 传递。因此,在您的情况下,用于 docker 进程的总内存为 1.5GC。请记住,这是 整个 进程限制,而不仅仅是堆。 java 进程比用 -Xms512m -Xmx1024m 指定的堆要多得多。所以回答你的问题:

How did kubernetes arrived at 904.38Mi usage?

这是整个进程目前占用的,而不仅仅是堆。从您发布的非常短的日志文件来看 - 您的应用程序很好。

编辑

实际上我的环境中没有 kubernetes 仪表板来专门测试它,所以必须安装它才能真正了解发生了什么。我对大多数事情都有暗示,但为了确定,我做了一些测试。

首先要注意的是:仪表板中的数字是什么意思?花了一段时间find/understand,不过就是the actual resident memory of the process,这其实是一件很不错的事情。

任何理智的 OS 都知道,当有人向它请求内存时,它很少 needs/utilizes 全部,因此,它以懒惰的方式将内存提供给它。这在 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 MBmax,但是current内存利用率是多少,也就是占用的常驻内存是多少?

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 内存下降。这是它在仪表板中的样子:

现在让我们稍微更改一下这段代码。让我们在那里添加一些 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

在检查日志时(就像在您的示例中一样),我确实看到堆收集得很好。但是当我查看仪表板时,内存并没有下降(与前面的示例不同)。

一旦G1GC占用内存,就不太急于将它还给OS。它可以在极少数情况下做到这一点,这里是 or you can instruct it to do so.

这两种方法都相当痛苦,相反 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

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

而你should, for a fact care about this:

This behavior is particularly disadvantageous in container environments where resources are paid by use. Even during phases where the VM only uses a fraction of its assigned memory resources due to inactivity, G1 will retain all of the Java heap. This results in customers paying for all resources all the time, and cloud providers not being able to fully utilize their hardware.

P.S。我还要补充一点,other pods 也在受苦,因为一个 pod 决定在特定峰值时尽可能多地占用内存,并且从不放弃它回来了。