一个神奇的bug：OOM？优雅终止线程？系统内存占用较高？

时间  2021-06-01
标签 java linux sql apache segmentfault api 数组 安全 app jvm 栏目 Java 繁體版
原文   原文链接
摘要：该项目是DAYU平台的数据开发（DLF），数据开发中一个重要的功能就是ETL（数据清洗）。ETL由源端到目的端，中间的业务逻辑通常由用户本身编写的SQL模板实现，velocity是其中涉及的一种模板语言。

Velocity之OOM

Velocity的基本使用

Velocity模板语言的基本使用代码以下：java

1. 初始化模板引擎

2. 获取模板文件

3. 设置变量

4. 输出

在ETL业务中，Velocity模板的输出是用户的ETL SQL语句集，至关于.sql文件。这里官方提供的api须要传入一个java.io.Writer类的对象用于存储模板的生成的SQL语句集。而后，这些语句集会根据咱们的业务作SQL语句的拆分，逐个执行。linux

java.io.Writer类是一个抽象类，在JDK1.8中有多种实现，包括但不只限于如下几种：sql

因为云环境对用户文件读写建立等权限的安全性要求比较苛刻，所以，咱们使用了java.io.StringWriter，其底层是StringBuffer对象，StringBuffer底层是char数组。apache

简单模板Hellovelocity.vm：segmentfault

复制代码; "复制代码")api

set($iAMVariable = 'good!')

set($person.password = '123')

Welcome ${name} to velocity.com
today is ${date}数组

foreach($one in $list)

$one

end

Name: ${person.name}
Password: ${person.password}安全

复制代码; "复制代码")app

HelloVelocity.java

复制代码; "复制代码")jvm

package com.xlf;

import org.apache.velocity.Template;
import org.apache.velocity.VelocityContext;
import org.apache.velocity.app.VelocityEngine;
import org.apache.velocity.runtime.RuntimeConstants;
import org.apache.velocity.runtime.resource.loader.ClasspathResourceLoader;

import java.io.StringWriter;
import java.util.ArrayList;
import java.util.Date;
import java.util.List; public class HelloVelocity { public static void main(String[] args) { // 初始化模板引擎

VelocityEngine ve = new VelocityEngine();
    ve.setProperty(RuntimeConstants.RESOURCE_LOADER, "classpath");
    ve.setProperty("classpath.resource.loader.class", ClasspathResourceLoader.class.getName());
    ve.init(); // 获取模板文件
    Template template = ve.getTemplate("Hellovelocity.vm");
    VelocityContext ctx = new VelocityContext(); // 设置变量
    ctx.put("name", "velocity");
    ctx.put("date", (new Date()));

    List temp = new ArrayList();
    temp.add("Hey");
    temp.add("Volecity!");
    ctx.put("list", temp);

    Person person = new Person();
    ctx.put("person", person); // 输出
    StringWriter sw = new StringWriter();
    template.merge(ctx, sw);
    System.out.println(sw.toString());
}

}

复制代码; "复制代码")

控制台输出

OOM重现

大模板文件BigVelocity.template.vm

（文件字数超出博客限制，稍后在附件中给出~~）

模板文件自己就379kb不算大，关键在于其中定义了一个包含90000多个元素的String数组，数组的每一个元素都是”1”，而后写了79层嵌套循环，循环的每一层都是遍历该String数组；最内层循环调用了一次:

show table;

这意味着这个模板将生成包含96372的79次方个SQL语句，其中每个SQL语句都是：

show table;

将如此巨大的字符量填充进StringWriter对象里面，至少须要10的380屡次方GB的内存空间，这几乎是不现实的。所以OOM溢出是必然的。

BigVelocity.java

复制代码; "复制代码")

package com.xlf;

import org.apache.velocity.Template;
import org.apache.velocity.VelocityContext;
import org.apache.velocity.app.VelocityEngine;
import org.apache.velocity.runtime.RuntimeConstants;
import org.apache.velocity.runtime.resource.loader.ClasspathResourceLoader;

import java.io.StringWriter; public class BigVelocity { public static void main(String[] args) { // 初始化模板引擎

VelocityEngine ve = new VelocityEngine();
    ve.setProperty(RuntimeConstants.RESOURCE_LOADER, "classpath");
    ve.setProperty("classpath.resource.loader.class", ClasspathResourceLoader.class.getName());
    ve.init(); // 获取模板文件
    Template template = ve.getTemplate("BigVelocity.template.vm");
    VelocityContext ctx = new VelocityContext();
    StringWriter sw = new StringWriter();
    template.merge(ctx, sw);
}

}

复制代码; "复制代码")

控制台输出

OOM缘由分析

Velocity模板生成的结果写入StringWriter对象中，如前面分析，其底层是一个char数组。直接产生OOM的代码在于java.util.Array.copyOf()函数：

StringWriter底层char数组容量极限测试

StringWriterOOMTest.java

复制代码; "复制代码")

package com.xlf;

import java.io.StringWriter; public class StringWriterOOMTest { public static void main(String[] args) {

System.out.println("The maximum value of Integer is: " + Integer.MAX_VALUE);
    StringWriter sw = new StringWriter(); int count = 0; for (int i = 0; i < 100000; i++) { for (int j = 0; j < 100000; j++) {
            sw.write("This will cause OOMn");
            System.out.println("sw.getBuffer().length(): " + sw.getBuffer().length() + ", count: " + (++count));
        }
    }
}

}

复制代码; "复制代码")

Jvm参数设置（参考硬件配置）

环境：JDK8 + Windows10台式机 + 32GB内存 + 1TB SSD + i7-8700

若是你的硬件配置不充分，请勿轻易尝试！

测试结果

StringWriterOOMTest运行时的整个进程内存大小在Windows任务管理器中达10300多MB时，程序中止。

控制台输出

测试结果分析

char数组元素最大值不会超过Integer.MAX_VALUE，回事很是接近的一个值，我这里相差20多。网上搜索了一番，比较靠谱的说法是：确实比Integer.MAX_VALUE小一点，不会等于Integer.MAX_VALUE，是由于char[]对象还有一些别的空间占用，好比对象头，应该说是这些空间加起来不能超过Integer.MAX_VALUE。若是有读者感兴趣，能够自行探索下别的类型数组的元素个数。我这里也算是一点拙见，抛砖引玉。

OOM解决方案

缘由总结

经过上面一系列重现与分析，咱们知道了OOM的根本缘由是模板文件渲染而成的StringWriter对象过大。具体表如今：

  1. 若是系统没有足够大的内存空间分配给JVM，会致使OOM，由于这部份内存并非无用内存，JVM不能回收
  2. 若是系统有足够大的内存空间分配给JVM，char数组中的元素个数在接近于MAX_VALUE会抛出OOM错误。

解决方案

前面分析过，出于安全的缘由，咱们只能用StringWriter对象去接收模板渲染结果的输出。不能用文件。因此只能在StringWriter自己去作文章进行改进了：

继承StringWriter类，重写其write方法为：

复制代码; "复制代码")

StringWriter sw = new StringWriter() { public void write(String str) { int length = this.getBuffer().length() + str.length(); // 限制大小为10MB

if (length > 10 * 1024 * 1024) { this.getBuffer().delete(0, this.getBuffer().length()); throw new RuntimeException("Velocity template size exceeds limit!");
    } this.getBuffer().append(str);
}

};

复制代码; "复制代码")

其余代码保持不变

BigVelocitySolution.java

复制代码; "复制代码")

package com.xlf;

import org.apache.velocity.Template;
import org.apache.velocity.VelocityContext;
import org.apache.velocity.app.VelocityEngine;
import org.apache.velocity.runtime.RuntimeConstants;
import org.apache.velocity.runtime.resource.loader.ClasspathResourceLoader;

import java.io.StringWriter; public class BigVelocitySolution { public static void main(String[] args) { // 初始化模板引擎

VelocityEngine ve = new VelocityEngine();
    ve.setProperty(RuntimeConstants.RESOURCE_LOADER, "classpath");
    ve.setProperty("classpath.resource.loader.class", ClasspathResourceLoader.class.getName());
    ve.init(); // 获取模板文件
    Template template = ve.getTemplate("BigVelocity.template.vm");
    VelocityContext ctx = new VelocityContext();
    StringWriter sw = new StringWriter() { public void write(String str) { int length = this.getBuffer().length() + str.length(); // 限制大小为10MB
            if (length > 10 * 1024 * 1024) { this.getBuffer().delete(0, this.getBuffer().length()); throw new RuntimeException("Velocity template size exceeds limit!");
            } this.getBuffer().append(str);
        }
    };
    template.merge(ctx, sw);
}

}

复制代码; "复制代码")

控制台输出

若是velocity模板渲染后的sql语句集大小在容许的范围内，这些语句集会根据咱们的业务作SQL语句的拆分，逐句执行。

如何优雅终止线程

在后续逐句执行sql语句的过程当中，每一句sql都是调用的周边服务（DLI，OBS，MySql等）去执行的，结果每次都会返回给咱们的做业开发调度服务（DLF）后台。咱们的DLF平台支持及时中止做业的功能，也就是说假如这个做业在调度过程当中要执行10000条SQL，我要在中途中止不执行后面的SQL了——这样的功能是支持的。

在修改上面提到OOM那个bug并经过测试后，测试同窗发现咱们的做业没法中止下来，换句话说，咱们做业所在的java线程没法中止。

线程中止失败重现

一番debug与代码深刻研读以后，发现咱们项目中确实是调用了对应的线程对象的interrupt方法thread.interrupt();去终止线程的。

那么为何调用了interrupt方法依旧没法终止线程？

TestForInterruptedException.java

复制代码; "复制代码")

package com.xlf; public class TestForInterruptedException { public static void main(String[] args) {

StringBuilder sb = new StringBuilder(); for (int i = 0; i < 10; i++) {
        sb.append("show tables;n");
    } int i = 0; for (String str : sb.toString().split("n")) { if (i > 4) {
            Thread.currentThread().interrupt();
            System.out.println(i + " after interrupt");
        }
        System.out.println(str);
        System.out.println(i++);
    }

}

}

复制代码; "复制代码")

控制台输出

测试结果分析

TestForInterruptedException.main函数中作的事情足够简单，先产生一个大一点的字符串，拆分红10段小字符串，for循环中逐段打印小字符串；并企图从第5段（初始段为0）开始，去终止线程。结果发现线程并无终止！

这是怎么回事？为何调用了线程的interrupt方法并无终止线程？或者说是由于jvm须要一点时间去响应这个方法？其实并不是如此，感兴趣的同窗能够把循环次数加的更大一些，在循环开始几回就进行interrupt，你会发现结果仍是这样。

通过一番探索，线程终止的方法无外乎两种：

  • 使用该Thread对象的stop()方法能让线程立刻中止，可是这种方法太过于暴力，实际上并不会被使用到，详见JDK1.8的注释：
  • Deprecated. This method is inherently unsafe. Stopping a thread with Thread.stop causes it to unlock all of the monitors that it has locked (as a natural consequence of the unchecked ThreadDeath exception propagating up the stack). If any of the objects previously protected by these monitors were in an inconsistent state, the damaged objects become visible to other threads, potentially resulting in arbitrary behavior. Many uses of stop should be replaced by code that simply modifies some variable to indicate that the target thread should stop running. The target thread should check this variable regularly, and return from its run method in an orderly fashion if the variable indicates that it is to stop running. If the target thread waits for long periods (on a condition variable, for example), the interrupt method should be used to interrupt the wait…
  • 第二种方法就是上面JDK注释中提到的设置标志位的作法。这类作法又分为两种，不管哪种都须要去被终止的线程自己去“主动”地判断该标志位的状态：
  1. 设置一个常规的标志位，好比：boolean类型变量的true/ false, 根据变量的状态去决定线程是否继续运行——代码里去主动判断变量状态。这种通常用在循环中，检测到相应状态就break, return或者throw exception。
  2. 使用Thead类的实例方法interrupt去终止该thread对象表明的线程。可是interrupt方法本质上也是设置了一个中断标识位，并且该标志位一旦被捕获（读取），“大部分时候”就会被重置（失效）。所以它并不保证线程必定可以中止，并且不保证立刻可以中止，有以下几类状况：
  3. interrupt方法设置的中断标识位后，若是该线程日后的程序执行逻辑中执行了Object类的wait/join/sleep，这3个方法会及时捕获interrupt标志位，重置并抛出InterruptedException。
  4. 相似于上一点，java.nio.channels包下的InterruptibleChannel类也会去主动捕获interrupt标志位，即线程处于InterruptibleChannel的I/O阻塞中也会被中断，以后标志位一样会被重置，而后channel关闭，抛出java.nio.channels.ClosedByInterruptException；一样的例子还有java.nio.channels.Selector，详见JavaDoc
  5. Thread类的实例方法isInterrupted()也能去捕获中断标识位并重置标识位，这个方法用在须要判断程序终止的地方，能够理解为主动且显式地去捕获中断标识位。
  6. 值得注意的是：抛出与捕获InterruptedException并不涉及线程标识位的捕获与重置
  7. 怎么理解我前面说的中断标识位一旦被捕获，“大部分时候”就会被重置？Thread类中有private native boolean isInterrupted(boolean ClearInterrupted);当传参为false时就能在中断标识位被捕获后不重置。然而通常状况它只会用于两个地方
  8. Thread类的static方法：此处会重置中断标识位，并且没法指定某个线程对象，只能是当前线程去判断

  1. Thread类的实例方法：这个方法也是经常使用的判断线程中断标识位的方法，并且不会重置标识位。

小结

要终止线程，目前JDK中可行的作法有：

  1. 本身设置变量去标识一个线程是否已中断
  2. 合理利用JDK自己的线程中断标识位去判断线程是否中断

这两个作法都须要后续作相应处理好比去break循环，return方法或者抛出异常等等。

线程什么时候终止？

线程终止缘由通常来说有两种：

  1. 线程执行完他的正常代码逻辑，天然结束。
  2. 线程执行中抛出Throwable对象且不被显式捕获，JVM会终止线程。众所周知：Throwable类是Exception和Error的父类！

线程异常终止ExplicitlyCatchExceptionAndDoNotThrow.java

复制代码; "复制代码")

package com.xlf; public class ExplicitlyCatchExceptionAndDoNotThrow { public static void main(String[] args) throws Exception {

boolean flag = true;
    System.out.println("Main started！"); try { throw new InterruptedException();
    } catch (InterruptedException exception) {
        System.out.println("InterruptedException is caught!");
    }
    System.out.println("Main doesn't stop！"); try { throw new Throwable();
    } catch (Throwable throwable) {
        System.out.println("Throwable is caught!");
    }
    System.out.println("Main is still here！"); if (flag) { throw new Exception("Main is dead!");
    }
    System.out.println("You'll never see this!");
}

}

复制代码; "复制代码")

控制台输出

测试结果分析

这个测试验证了前面关于线程异常终止的结论：

线程执行中抛出Throwable对象且不被显式捕获，JVM会终止线程。

优雅手动终止线程

线程执行中须要手动终止，最好的作法就是设置标识位（能够是interrupt也能够是本身定义的），而后及时捕获标识位并抛出异常，在业务逻辑的最后去捕获异常并作一些收尾的清理动做：好比统计任务执行失败成功的比例，或者关闭某些流等等。这样，程序的执行就兼顾到了正常与异常的状况并获得了优雅的处理。

TerminateThreadGracefully.java

复制代码; "复制代码")

package com.xlf; public class TerminateThreadGracefully { public static void main(String[] args) {

StringBuilder sb = new StringBuilder(); for (int i = 0; i < 10; i++) {
        sb.append("show tables;n");
    } int i = 0; try { for (String str : sb.toString().split("n")) { if (i > 4) {
                Thread.currentThread().interrupt(); if (Thread.currentThread().isInterrupted()) { throw new InterruptedException();
                }
                System.out.println(i + " after interrupt");
            }
            System.out.println(str);
            System.out.println(i++);
        }
    } catch (InterruptedException exception) { // TODO：此处可能作一些清理工做
        System.out.println(Thread.currentThread().isInterrupted());
    }
    System.out.println("Thread main stops normally!");
}

}

复制代码; "复制代码")

控制台输出

为什么项目中的线程终止失败？

咱们项目中确实是调用了对应的线程对象的interrupt方法thread.interrupt();去终止线程的。

那么为何线程不能相应中断标识位并终止呢？

回到咱们项目的业务逻辑：

整个job分为模板读取、渲染以及SQL执行三个阶段，通常而言前两个阶段时间会比较快。在后续逐句执行sql语句的过程当中，每一句sql都是调用的周边服务（DLI，OBS，MySql等）去执行的，结果每次都会返回给咱们的做业开发调度服务（DLF）后台。咱们的DLF平台支持及时中止做业的功能，也就是说假如这个做业在调度过程当中要执行10000条SQL，我要在中途中止不执行后面的SQL了——这样的功能是支持的。

所以问题就出在了SQL执行的过程。通过屡次debug发现：在SQL执行过程当中须要每次都往OBS（华为自研，第三方包）中写log，该过程不可略去。调用该线程对象的interrupt方法thread.interrupt()，interrupt标识位最先被OBS底层用到的java.util.concurrent. CountDownLatch类的await()方法捕获到，重置标识位并抛出异常，而后在一层层往上抛的时候被转变成了别的异常类型，并且不能根据最终抛的异常类型去判断是不是因为咱们手动终止job引发的。

对于第三方包OBS根据本身的底层逻辑去处理CountDownLatch抛的异常，这本无可厚非。可是咱们的程序终止不了！为了达到终止线程的作法，我在其中加入了一个自定义的标志变量，当调用thread.interrupt()的时候去设置变量的状态，并在几个关键点好比OBS写log以后去判断个人自定义标识位的状态，若是状态改变了就抛出RuntimeException（能够不被捕获，最小化改动代码）。而且为了能重用线程池里的线程对象，在每次job开始的地方去从重置这一自定义标识位。最终达到了优雅手动终止job的目的。

这一部分的源码涉及项目细节就不贴出来了，可是相关的逻辑前面已经代码展现过。

系统内存占用较高且不许确

在线程中运行过程当中定义的普通的局部变量，非ThreadLocal型，通常而言会随着线程结束而获得回收。我所遇到的现象是上面的那个线程没法中止的bug解决以后，线程停下来了，可是在linux上运行top命令相应进程内存占用仍是很高。

  1. 首先我用jmap -histo:alive pid命令对jvm进行进行了强制GC，发现此时堆内存确实基本上没用到多少（不关老年带仍是年轻带都大概是1%左右。）可是top命令看到的占用大概在18% * 7G（linux总内存）左右。
  2. 其次，我用了jcmd命令去对对外内存进行分析，排斥了堆外内存泄露的问题
  3. 而后接下来就是用jstack命令查看jvm进程的各个线程都是什么样的状态。与job有关的几个线程所有是waiting on condition状态（线程结束，线程池将他们挂起的）。
  4. 那么，如今获得一个初步的结论就是：无论是该jvm进程用到的堆内存仍是堆外内存，都很小（相对于top命令显式的18% * 8G占用量而言）。因此是否能够猜测：jvm只是向操做系统申请了这么多内存暂时没有归还回去，留待下次线程池有新任务时继续复用呢？本文最后一部分试验就围绕着一点展开。

现象重现

在以下试验中

设置jvm参数为：

-Xms100m -Xmx200m -verbose:gc -XX:+PrintGCDetails -XX:+PrintGCTimeStamps

其意义在于：

限制jvm初始内存为100M，最大堆内存为200M。并在jvm发生垃圾回收时及时打印详细的GC信息以及时间戳。而个人代码里要作的事情就是重现jvm内存不够而不得不发生垃圾回收。同时观察操做系统层面该java进程的内存占用。

SystemMemoryOccupiedAndReleaseTest.java

复制代码; "复制代码")

package com.xlf;

import java.util.concurrent.SynchronousQueue;
import java.util.concurrent.ThreadFactory;
import java.util.concurrent.ThreadPoolExecutor;
import java.util.concurrent.TimeUnit; public class SystemMemoryOccupiedAndReleaseTest { public static void main(String[] args) { try {

System.out.println("start");
        Thread.sleep(5000);
    } catch (InterruptedException e) {
        e.printStackTrace();
    }

    ThreadPoolExecutor executor = new ThreadPoolExecutor(3, 3, 30, TimeUnit.SECONDS, new SynchronousQueue<Runnable>(), new ThreadFactory() { public Thread newThread(Runnable r) { return new Thread(r);
            }
        }, new ThreadPoolExecutor.AbortPolicy()); try {
        System.out.println("(executor已初始化):");
        Thread.sleep(1000);
    } catch (InterruptedException e) {
        e.printStackTrace();
    }

    Thread t1 = new Thread(new Runnable() {
        {
            System.out.println("t1 已经初始化");
        }
        @Override public void run() { byte[] b = new byte[100 * 1024 * 1024];
            System.out.println("t1分配了100M空间给数组"); try {
                Thread.sleep(5000);
            } catch (InterruptedException e) {
                e.printStackTrace(); throw new RuntimeException("t1 stop");
            }
            System.out.println("t1 stop");
        }
    }, "t1"); try {
        Thread.sleep(1000);
    } catch (InterruptedException e) {
        e.printStackTrace();
    }

    Thread t2 = new Thread(new Runnable() {
        {
            System.out.println("t2 已经初始化");
        }
        @Override public void run() { byte[] b = new byte[100 * 1024 * 1024];
            System.out.println("t2分配了100M空间给数组"); try {
                Thread.sleep(5000);
            } catch (InterruptedException e) {
                e.printStackTrace(); throw new RuntimeException("t2 stop");
            }
            System.out.println("t2 stop");
        }
    }, "t2"); try {
        Thread.sleep(1000);
    } catch (InterruptedException e) {
        e.printStackTrace();
    }

    Thread t3 = new Thread(new Runnable() {
        {
            System.out.println("t3 已经初始化");
        }
        @Override public void run() { byte[] b = new byte[100 * 1024 * 1024];
            System.out.println("t3分配了100M空间给数组"); try {
                Thread.sleep(5000);
            } catch (InterruptedException e) {
                e.printStackTrace(); throw new RuntimeException("t3 stop");
            }
            System.out.println("t3 stop");
        }
    }, "t3"); try {
        Thread.sleep(1000);
    } catch (InterruptedException e) {
        e.printStackTrace();
    }

    executor.execute(t1);
    System.out.println("t1 executed!"); try {
        Thread.sleep(10000);
    } catch (InterruptedException e) {
        e.printStackTrace();

    }
    executor.execute(t2);
    System.out.println("t2 executed!"); try {
        Thread.sleep(10000);
    } catch (InterruptedException e) {
        e.printStackTrace();

    }
    executor.execute(t3);
    System.out.println("t3 executed!"); try {
        Thread.sleep(10000);
    } catch (InterruptedException e) {
        e.printStackTrace();

    }

    System.out.println("jmap -histo:live pid by cmd:"); try {
        Thread.sleep(20000);
    } catch (InterruptedException e) {
        e.printStackTrace();

    }
    System.out.println("After jmap!"); // You may run jmap -heap pid using cmd here // executor.shutdown();

}
}

VelocityExperiment.zip 19.40KB

本文分享自华为云社区《一个神奇的bug：OOM？优雅终止线程？系统内存占用较高？》，原文做者：UnstoppableRock。

点击关注，第一时间了解华为云新鲜技术~

相关文章
相关标签/搜索
每日一句
    每一个你不满意的现在，都有一个你没有努力的曾经。
本站公众号
   欢迎关注本站公众号,获取更多信息
联系我们 最近搜索 最新文章 沪ICP备13005482号-10 MyBatis教程 SQL 教程 MySQL教程 Java 教程 Thymeleaf 教程 Hibernate教程 Spring教程 Redis教程