首页 > 解决方案 > kubernetes pod 内存 - java gc 日志

问题描述

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

此 pod 包含使用-Xms512m -Xmx1024m, 和 kubernetes 部署文件 -> requests.memory = 512M,运行的 java 应用程序limits.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,然后当所有处理完毕后,内存使用k8s 仪表板不会低于 900mb,即使基于 GC 日志,堆是 GC'ed ok。

标签: javakubernetesmemory-managementgarbage-collectionkubernetes-metrics

解决方案


这里发生了很多事情。让我们一次拿走每一个。

似乎每个 pod 都使用一个容器(尽管每个 pod 可以有很多容器)。和特定于容器requests.memory,Kubernetes 计算每个pod作为所有容器限制的总和。limits.memorylimitsrequests

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

pod然后是 a由 开头的事实docker,它以kubectland 开头,读取为requires.memoryand limits.memory。为了使这更简单一点:您设置的limits.memory内容将作为docker -m. 因此,在您的情况下,用于 docker 进程的总内存为1.5GC. 请记住,这是整个进程的限制,而不仅仅是堆。java 进程远不止堆,你用-Xms512m -Xmx1024m. 所以回答你的问题:

Kubernetes 是如何达到 904.38Mi 使用率的?

这是整个过程目前正在采取的,而不仅仅是堆。从您发布的非常短的日志文件中 - 您的应用程序很好。

编辑

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

首先要做的事情是:仪表板中的数字是什么意思?花了一段时间才找到/理解,但那是进程的实际常驻内存,这实际上是一件非常好的事情。

任何理智的人都OS知道,当有人向它请求内存时,它很少需要/利用它,因此,它以一种懒惰的方式给它内存。这在 中很容易证明k8s。假设我有一个jdk-13JVM 并启动它:

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...because开头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,但是当前的内存利用率是多少,也就是占用的驻留内存是多少?

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

好的,所以当前的内存利用率只有4MB. 如果您这样做,您可以“确保”这确实是准确的:

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

并在该吊舱问题内:

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 秒分配1MB2 分钟左右。当我在仪表板中查看此过程时,我确实看到在某个时间点,内存会增长。程序结束后,仪表板会报告内存下降。好的!这意味着内存被归还并且 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占用了内存,就不太急于将它还给操作系统。在极少数情况下它可以做到这一点,这里是一个例子,或者你可以指示它这样做

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

以下是您将看到的内容:

堆3

事实上,你应该关心这个

这种行为在资源按使用付费的容器环境中尤其不利。即使在虚拟机由于不活动而仅使用其分配的内存资源的一小部分的阶段,G1 也会保留所有 Java 堆。这导致客户一直为所有资源付费,而云提供商无法充分利用他们的硬件。

PS 我还要补充一点,其他pod 也在遭受痛苦,因为一个 pod 决定在特定的峰值处尽可能多地占用内存,并且永远不会将其归还。


推荐阅读