线程池踩坑记 --load飙高的原因

去年处理过一个美图的问题,最近又碰到类似问题了,发现跟美图那个案例原因是一样的,在这里拿出来给大家分享一下。

应该是去年6月底,我们私有化发布了新版本,然后就拿去给美图客户安装部署了,美图的美拍应用访问量较大,新版本部署后问题不断,后来我接手去处理,在这之已出过不少问题,客户也不怎么配合了;

问题现象:美图客户的运维说,听云应用kafka积压消息,backend不工作了,重启后不久服务器load值飙高,最高能过万,美图方面不让直接去操作服务器,怀疑我们是否对自己的应用做过压测,让我们自己压测找问题,尴尬啊;最后好不容易拿到了错误日志,开始分析日志问题。

在这里先对load值简单说明一下,它是linux系统或unix系统下cpu的待处理和正在处理的任务的任务队列,有两个原因会导致load飙高, cpu处理不过来或io处理不过来导致等待处理的线程数飙升;

日志里面各种异常一大堆,肯定是某个地方出了问题导致的连锁反应,其中有这样的一些异常:

异常堆栈:


07-07 12:27:11 [pool-9-thread-4] ERROR c.n.n.d.b.p.MobileAppInteractionTraceMessageHandler - failed to write mobileapp interaction trace result to nbfs: unable to create new native thread
java.lang.OutOfMemoryError: unable to create new native thread
        at java.lang.Thread.start0(Native Method)
        at java.lang.Thread.start(Thread.java:714)
        at java.util.concurrent.ThreadPoolExecutor.addWorker(ThreadPoolExecutor.java:950)
        at java.util.concurrent.ThreadPoolExecutor.execute(ThreadPoolExecutor.java:1368)
        at sun.nio.ch.SimpleAsynchronousFileChannelImpl.implWrite(SimpleAsynchronousFileChannelImpl.java:393)
        at sun.nio.ch.AsynchronousFileChannelImpl.write(AsynchronousFileChannelImpl.java:251)
        at com.networkbench.nbfs.io.NBFSWriter.writeTo(NBFSWriter.java:284)
        at com.networkbench.newlens.datacollector.backend.processor.MobileAppInteractionTraceMessageHandler.receive(MobileAppInteractionTraceMessageHandler.java:131)
        at com.networkbench.newlens.datacollector.backend.processor.MobileAppInteractionTraceMessageHandler.receive(MobileAppInteractionTraceMessageHandler.java:35)
        at com.networkbench.newlens.datacollector.mq.processor.AvroWrappedMessageConsumer$1.run(AvroWrappedMessageConsumer.java:188)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
        at java.lang.Thread.run(Thread.java:745)
07-07 12:27:11 [pool-8-thread-2] ERROR c.n.n.d.b.p.MobileAppErrorTraceMessageHandler - failed to write error trace result to nbfs: unable to create new native thread
java.lang.OutOfMemoryError: unable to create new native thread
        at java.lang.Thread.start0(Native Method)
        at java.lang.Thread.start(Thread.java:714)
        at java.util.concurrent.ThreadPoolExecutor.addWorker(ThreadPoolExecutor.java:950)
        at java.util.concurrent.ThreadPoolExecutor.execute(ThreadPoolExecutor.java:1368)
        at sun.nio.ch.SimpleAsynchronousFileChannelImpl.implWrite(SimpleAsynchronousFileChannelImpl.java:393)
        at sun.nio.ch.AsynchronousFileChannelImpl.write(AsynchronousFileChannelImpl.java:251)
        at com.networkbench.nbfs.io.NBFSWriter.writeTo(NBFSWriter.java:284)
        at com.networkbench.newlens.datacollector.backend.processor.MobileAppErrorTraceMessageHandler.receive(MobileAppErrorTraceMessageHandler.java:150)
        at com.networkbench.newlens.datacollector.backend.processor.MobileAppErrorTraceMessageHandler.receive(MobileAppErrorTraceMessageHandler.java:38)
        at com.networkbench.newlens.datacollector.mq.processor.AvroWrappedMessageConsumer$1.run(AvroWrappedMessageConsumer.java:188)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)

分析这个堆栈要用到的知识点:这个异常堆栈涉及到线程池代码,如果你看过线程池的源码,那么分析起来就会比较轻松,否则可能不知道到我在说什么,这里不会去讲线程池源码,请自己找资料去了解,也可以往后翻我的博客,看我写过的一篇源码分析java程序员必精–从源码讲解java线程池ThreadPoolExecuter的实现原理 , 建议一定要弄懂线程池的实现,如果你经常分析线程堆栈就会知道,线程池用到的地方非常多,没有几个应用不使用线程池的;

根据开头的四行线程栈分析可以知线程池在执行addWorker方法时,无法创建线程,抛出了unable to create new native thread的异常,这个异常有点特殊,它并不是指java堆内存溢出了,它说明堆外操作系统的内存已经用尽了,java的线程在java里面只是一个Thread对象,这个Thread对象对应着一个操作系统的线程,每个线程都要分配线程栈,线程栈占用的是堆外操作系统内存,当操作系统内存用尽的时候,再创建线程就会抛出这个异常;

Java里面有以下几种操作会占用堆外的操作系统内存:

  1. 创建DirectBuffer对象;
    2 .map方式打开文件,会占用操作系统的pagecache;
  2. 创建线程;
    我们应用里面没有用到mmap的地方,那么就剩下1、3两种情况了;
    从load飙高,可知一定和3有关系,load值最高能过万,是什么原因导致创建了这么多的线程呢?

我们从后往前分析一下线程堆栈:

最后两行说明是线程池里面的线程在执行任务,如果熟悉线程池源码,一看就知道这是线程池Worker工作线程的run方法中调用runWorker执行任务,它的run方法中只有调用runWorker这一行代码:

	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)

倒数第三行到倒数第六行,一看就是在执行我们自己的业务代码:

	at com.networkbench.nbfs.io.NBFSWriter.writeTo(NBFSWriter.java:284)
        at com.networkbench.newlens.datacollector.backend.processor.MobileAppErrorTraceMessageHandler.receive(MobileAppErrorTraceMessageHandler.java:150)
        at com.networkbench.newlens.datacollector.backend.processor.MobileAppErrorTraceMessageHandler.receive(MobileAppErrorTraceMessageHandler.java:38)
        at com.networkbench.newlens.datacollector.mq.processor.AvroWrappedMessageConsumer$1.run(AvroWrappedMessageConsumer.java:188)

最后一行可知,runWorker方法中执行到了task.run方法,task就是AvroWrappedMessageConsumer$1这个类,正在调用业务代码,从业务代码可知是在处理ErrorTrace数据,ErrorTrace就是抓取到的错误堆栈信息,错误信息堆栈就像上面展示的异常堆栈一样,堆栈层级越多,trace信息就越大;这个trace信息会通过我们的NBFS组件写入到磁盘文件中去,NBFS组件是我们架构师写一个jar包,之前从来没有关注过它是如何实现的;

继续分析堆栈信息,接下来的两行就有意思了:

	at sun.nio.ch.SimpleAsynchronousFileChannelImpl.implWrite(SimpleAsynchronousFileChannelImpl.java:393)
    at sun.nio.ch.AsynchronousFileChannelImpl.write(AsynchronousFileChannelImpl.java:251)

这已经不是我们的业务代码了,并且已经到了sun包路径下的类了,sun包下的类一般都是和不同操作系统的实现有关,sun的jdk没有开源这个包下的源码,但是可以下载openjdk的源码来看,大部分代码都是一样的,从代码中可以看到是在执行AsynchronousFileChannelImpl.write()方法,这是java AIO中写文件的方法;

接下来的四行代码又涉及到了线程池:

        at java.lang.Thread.start0(Native Method)
        at java.lang.Thread.start(Thread.java:714)
        at java.util.concurrent.ThreadPoolExecutor.addWorker(ThreadPoolExecutor.java:950)
        at java.util.concurrent.ThreadPoolExecutor.execute(ThreadPoolExecutor.java:1368)

从打印的堆栈可以看出是线程池在执行了execute操作后,接着执行addWorker操作创建新的线程来执行任务,然后新的线程无法创建就oom了,这说明AIO写文件的时候用到了线程池来创建线程;


如果你读过,ThreadPoolExecutor源码就会知道addWorker方法在execute方法中有3个地方会调用到,而出异常的时候线程池的状态一定是RUNNING状态 ,所以在RUNNING状态下,有以下三种情况会去调用AddWorker:

  1. 线程池中线程数小于corePoolSize,这时候会直接执行addWorker方法创建一个新的线程执行任务(如果创建线程池的时候设置的corePoolSize为0,那么这一步的addWorker不会有机会执行);

  2. . 线程池中线程数大于等于corePoolSize,任务就会进入到队列里面,如果这时候线程池中线程数为0,那么就会执行addWorker方法创建一个新的工作线程,去任务队列里取任务执行(执行到这一步,一种情况是线程池的corePoolSize设置为0,于是就可以跳过步骤1,直接执行到了这一步,还有一种情况是设置了allowCoreThreadTimeOut为true,执行到步骤一的时候,所有线程都存活,执行到步骤2的时候全部线程都超时了,但是出现这种情况的几率比中彩票还低);

  3. 线程池中的线程数大于等于corePoolSize,任务入队失败,说明任务队列已经满了,则会调用addWorker方法去创建一个新的线程,只要线程池中线程数不大于maximumPoolSize,就会创建成功;


从异常堆栈看,线程池中的线程数不大于maximumPoolSize,因为已经执行到了addWorker方法的Thread.start()线程的方法了,说明是可以执行到创建线程对象这一步的,只是在启动线程的时候,因为无法申请到线程栈内存,导致了oom;

根据系统运行情况,当时kafka数据积压,io操作频繁,所以线程池一定是全速运转,线程池中线程数量不太可能小于corePoolSize;

所以addWorker只可能是执行第二步和第三步,只能分析到这里了,已经没有什么思路了;

但是如果你还知道线程池线程池相关的更多知识,你就能分析到问题可能发生的原因:


这里就又用到线程池实现的知识了,先想一下java内置的几种线程池的坑:

  1. Executors.newFixedThreadPool(10);
    固定大小的线程池,它的实现
new ThreadPoolExecutor(10, 10, 0L, TimeUnit.MILLISECONDS,new LinkedBlockingQueue<Runnable>());

初始化一个指定线程数的线程池,其中corePoolSize == maximumPoolSize,使用LinkedBlockingQuene作为阻塞队列,超时时间为0,当线程池没有可执行任务时,也不会释放线程。
因为队列LinkedBlockingQueue大小为默认的Integer.MAX_VALUE,可以无限的往里面添加任务,直到内存溢出;

2.Executors.newCachedThreadPool();

缓存线程池,它的实现:

new ThreadPoolExecutor(0,Integer.MAX_VALUE,60L, TimeUnit.SECONDS,new SynchronousQueue<Runnable>());

初始化一个可以缓存线程的线程池,默认超时时间60s,线程池的最小线程数时0,但是最大线程数为Integer.MAX_VALUE,即2147483647,内部使用SynchronousQueue作为阻塞队列;

因为线程池的最大值了Integer.MAX_VALUE,会导致无限创建线程;所以,使用该线程池时,一定要注意控制并发的任务数,如果短时有大量任务要执行,就会创建大量的线程,导致严重的性能问题(线程上下文切换带来的开销),线程创建占用堆外内存,如果任务对象也不小,它就会使堆外内存和堆内内存其中的一个先耗尽,导致oom;

3.Executors.newSingleThreadExecutor()
单线程线程池,它的实现

new FinalizableDelegatedExecutorService(
	new ThreadPoolExecutor(1, 1,0L, 
			            TimeUnit.MILLISECONDS,
			            new LinkedBlockingQueue<Runnable>()
			            )
);

同newFixedThreadPool线程池一样,队列用的是LinkedBlockingQueue,队列大小为默认的Integer.MAX_VALUE,可以无限的往里面添加任务,直到内存溢出;


从现象来看很有可能是使用了第二种线程池创建的方式:Executors.newCachedThreadPool();

结合这个线程池的特性和上面分析的addWorker调用的两种可能性,那么就可以推断出addWorker方法一定执行的是步骤3的addWorker方法;
为什么这么肯定呢?因为这个线程池的corePoolSize大小为0,所以步骤1的addWorker方法一定不会执行到,步骤二对于这个线程池更是不可能执行到了,因为这个线程池用的队列是SynchronousQueue,对于生产线程,除非队列里面已经存在消费线程在等待,可以直接匹配,否则入队永远返回的是false,就直接跳到步骤3的addWorker方法,如果队列里面已经存在消费者线程可以匹配,那么线程池中的线程数就不会是0,所以步骤二的addWorker方法也是不可能执行到的;

我们去看一下linux openjdk1.8源码来验证一下(注意一定是linux的,不能是window的,前面提到了,涉及到sun包下的代码不同操作系统是不一样的),根据异常堆栈给出的信息,从linux openjdk1.8的源码包里面找到sun.nio.ch.SimpleAsynchronousFileChannelImpl的implWrite方法的393行(这里是394行比异常线程栈指示的行号多了一行):

 @Override
    <A> Future<Integer> implWrite(final ByteBuffer src,
                                  final long position,
                                  final A attachment,
                                  final CompletionHandler<Integer,? super A> handler){
        if (position < 0)
            throw new IllegalArgumentException("Negative position");
        if (!writing)
            throw new NonWritableChannelException();

        // complete immediately if channel is closed or no bytes remaining
        if (!isOpen() || (src.remaining() == 0)) {
            Throwable exc = (isOpen()) ? null : new ClosedChannelException();
            if (handler == null)
                return CompletedFuture.withResult(0, exc);
            Invoker.invokeIndirectly(handler, attachment, 0, exc, executor);
            return null;
        }

        final PendingFuture<Integer,A> result = (handler == null) ?
            new PendingFuture<Integer,A>(this) : null;

	//创建Runnable任务
        Runnable task = new Runnable() {
            public void run() {
                int n = 0;
                Throwable exc = null;

                int ti = threads.add();
                try {
                    begin();
                    do {
			//通过IOUtil.write方法将数据src写入到fdObj指向的文件
                        n = IOUtil.write(fdObj, src, position, nd);
                    } while ((n == IOStatus.INTERRUPTED) && isOpen());
                    if (n < 0 && !isOpen())
                        throw new AsynchronousCloseException();
                } catch (IOException x) {
                    if (!isOpen())
                        x = new AsynchronousCloseException();
                    exc = x;
                } finally {
                    end();
                    threads.remove(ti);
                }
                if (handler == null) {
                    result.setResult(n, exc);
                } else {
                    Invoker.invokeUnchecked(handler, attachment, n, exc);
                }
            }
        };
	//这里就是线程堆栈指示的393行,通过线程池执行任务;
        executor.execute(task);
        return result;
    }
}

我们就去看看这个线程池是怎么创建的,这里的execute对象是SimpleAsynchronousFileChannelImpl类的父类AsynchronousFileChannelImpl的一个成员变量,它会在SimpleAsynchronousFileChannelImpl的构造方法中传入进来:

   SimpleAsynchronousFileChannelImpl(FileDescriptor fdObj,
                                      boolean reading,
                                      boolean writing,
                                      ExecutorService executor)
    {
        super(fdObj, reading, writing, executor);
    }

然后调用父类的构造方法,赋值给成员变量;

 protected AsynchronousFileChannelImpl(FileDescriptor fdObj,
                                          boolean reading,
                                          boolean writing,
                                          ExecutorService executor)
    {
        this.fdObj = fdObj;
        this.reading = reading;
        this.writing = writing;
        this.executor = executor;//赋值给成员变量
    }

如果细心点你就会发现,SimpleAsynchronousFileChannelImpl的构造方法没有public修饰符,我们无法在不是同一个包里面的类里直接new它;

如果要获取它的实例对象,SimpleAsynchronousFileChannelImpl类有一个public static的open方法,通过这个方法可以创建SimpleAsynchronousFileChannelImpl对象,并且在这里发现线程池创建相关的代码逻辑:

 public static AsynchronousFileChannel open(FileDescriptor fdo,
                                               boolean reading,
                                               boolean writing,
                                               ThreadPool pool)
    {
        // Executor is either default or based on pool parameters
        ExecutorService executor = (pool == null) ?
            DefaultExecutorHolder.defaultExecutor : pool.executor();//如果没有传入线程池,那么就使用默认的DefaultExecutorHolder.defaultExecutor;
        return new SimpleAsynchronousFileChannelImpl(fdo, reading, writing, executor);//调用构造方法创建对象实例
    }

如果我们没有给它指定线程池的话,那么它会使用DefaultExecutorHolder.defaultExecutor默认的线程池;

DefaultExecutorHolder是SimpleAsynchronousFileChannelImpl类里面有一个内部类:

    // lazy initialization of default thread pool for file I/O
    private static class DefaultExecutorHolder {
        static final ExecutorService defaultExecutor =
            ThreadPool.createDefault().executor();//调用了ThreadPool这个类createDefault()方法创建线默认的线程池
    }

又找到ThreadPool.createDefault()方法:

 static ThreadPool createDefault() {
        // default the number of fixed threads to the hardware core count
        int initialSize = getDefaultThreadPoolInitialSize();
        if (initialSize < 0)
            initialSize = Runtime.getRuntime().availableProcessors();
        // default to thread factory that creates daemon threads
        ThreadFactory threadFactory = getDefaultThreadPoolThreadFactory();
        if (threadFactory == null)
            threadFactory = defaultThreadFactory;

		//看这一行,正是使用了Executors.newCachedThreadPool(threadFactory)方法来创建的线程池
        // create thread pool
        ExecutorService executor = Executors.newCachedThreadPool(threadFactory);
        return new ThreadPool(executor, false, initialSize);
    }

这就解释通了为什么,操作系统oom,无法创建更多线程,load值飙高;

然后我就去找我们NBFS组件里,进一步验证:

//这里是打开channel的代码
public class LocalAsynchronousFileChannelManager extends AbstractFileChannelManager implements FileChannelManager{
    @Override
    public Channel createFileChannel(final String fileName) throws IOException {
        if (fileName == null) {
            throw new IllegalArgumentException("fileName not specified: " + fileName);
        }
        final Path path = Paths.get(fileName, new String[0]);
        final File dir = path.getParent().toFile();
        if (!dir.exists()) {
            dir.mkdirs();
        }
		//open的时候没有指定线程池:
        return AsynchronousFileChannel.open(path, StandardOpenOption.WRITE, StandardOpenOption.CREATE);
    }
}

果然,没有指定线程池,要解决这个问题,只要指定一个合理的最大线程数量的线程池即可;

最后理了一下问题发生的原因:因为客户trace量比较多,当消息积压的时候,会不断的往磁盘写数据,客户是服务器是使用nfs挂载的磁盘,所以读写能力会受到网络状况的影响,当网络繁忙,或网络状况不好的时候,写入数据的速度已经超过了网络或磁盘io的能力,导致写线程被阻塞,而新的任务又不断往线程池里面放,每放一个任务,线程池就要创建一个新的线程,最后的现象就是load值不断飙高,直到最后导致oom;

导致系统oom的原因还有另外一个,因为是使用AIO,往文件里面写数据的时候,它会自动将我们传入的数据由HeapByteBuffer转换为DirectByteBuffer;前面也讲到DirectByteBuffer也会占用堆外内存,这部分的源码我就不分析了,感兴趣的可以自己去看下,所以是数据的DirectByteBuffer与线程栈一起耗尽了堆外内存;

另外通过分析源码,还发现原来linux下java写文件的AIO之所以不会被阻塞,其实是使用线程池模拟的啊;

ps:
另外一种导致load飙高的问题,这个问题我们也经常用到,也和这个nbfs组件有点关联,因为我们使用nbfs写磁盘通过nfs方式挂载了磁盘,当网络繁忙,或nfs出现问题时,也会导致load值飙高,且进程状态会变为D,下面是摘抄的其它博文的对D进程状态的说明:

涉及进程的D状态: uninterruptible sleep (不可打断的睡眠状态)

[1] http://www.dewen.io/q/5664

“上图阐释了一个进程运行的情况,首先,运行的时候,进程会向内核请求一些服务,内核就会将程序挂起进程,并将进程放到parked队列,通常这些进程只会在parked队列中停留很短的时间,在ps(1)列表中是不会出现的。但是如果内核因为某些原因不能提供相应服务的话。例如,进程要读某一个特定的磁盘块,但是磁盘控制器坏了,这时,除非进程完成读磁盘,否则内核无法将该进程移出parked队列,此时该进程标志位就会被置为D。由于进程只有在运行的时候才能接受到signals,所以此时在parked队列上的进程也就无法接收到信号了。解决这个问题的方法要么是给资源给该进程,要么是reboot
通俗一点说,产生D状态的原因出现uninterruptible sleep状态的进程一般是因为在等待IO,例如磁盘IO、网络IO等。在发出的IO请求得不到相应之后,进程一般就会转入uninterruptible sleep状态,例如若NFS服务端关闭时,如果没有事先amount相关目录。在客户端执行df的话就会挂住整个会话,再用ps axf查看的话会发现df进程状态位已经变成D。”

[2] http://blog.kevac.org/2013/02/uninterruptible-sleep-d-state.html

Sometimes you will see processes on your linux box that are in D state as shown by ps, top, htop or similar. D means uninterruptible sleep. As opposed to normal sleep, you can’t do anything with these processes (i.e. kill them).

[3]http://blog.xupeng.me/2009/07/09/linux-uninterruptible-sleep-state/

D 状态是 uninterruptible sleep,Linux 进程有两种睡眠状态,一种 interruptible sleep,处在这种睡眠状态的进程是可以通过给它发信号来唤醒的,比如发 HUP 信号给 nginx 的 master 进程可以让 nginx 重新加载配置文件而不需要重新启动 nginx 进程;另外一种睡眠状态是 uninterruptible sleep,处在这种状态的进程不接受外来的任何信号,这也是为什么之前我无法用 kill 杀掉这些处于 D 状态的进程,无论是 kill, kill -9 还是 kill -15,因为它们压根儿就不受这些信号的支配。

进程为什么会被置于 uninterruptible sleep 状态呢?处于 uninterruptible sleep 状态的进程通常是在等待 IO,比如磁盘 IO,网络 IO,其他外设 IO,如果进程正在等待的 IO 在较长的时间内都没有响应,那么就很会不幸地被 ps 看到了,同时也就意味着很有可能有 IO 出了问题,可能是外设本身出了故障,也可能是比如挂载的远程文件系统已经不可访问了,我这里遇到的问题就是由 down 掉的 NFS 服务器引起的。

正是因为得不到 IO 的相应,进程才进入了 uninterruptible sleep 状态,所以要想使进程从 uninterruptible sleep 状态恢复,就得使进程等待的 IO 恢复,比如如果是因为从远程挂载的 NFS 卷不可访问导致进程进入 uninterruptible sleep 状态的,那么可以通过恢复该 NFS 卷的连接来使进程的 IO 请求得到满足,除此之外,要想干掉处在 D 状态进程就只能重启整个 Linux 系统了。

[4]http://www.orczhou.com/index.php/2010/05/how-to-kill-an-uninterruptible-sleep-process/
这个是最详细的,但是也很难理解;为什么IO的uninterruptible sleep会导致load变高呢?

“进入该状态的进程,会一直等待NFS,不接受任何信号,当然也就无法被杀死(kill/fuser -k)。因为进程一直在运行队列(running queue)中,所以还会导致主机的Load上升(虽然主机并不繁忙)。如果由于这个原因被卡住的进程很多的话,主机的Load可能会看起来非常高。”

  • 3
    点赞
  • 7
    收藏
    觉得还不错? 一键收藏
  • 6
    评论
评论 6
添加红包

请填写红包祝福语或标题

红包个数最小为10个

红包金额最低5元

当前余额3.43前往充值 >
需支付:10.00
成就一亿技术人!
领取后你会自动成为博主和红包主的粉丝 规则
hope_wisdom
发出的红包
实付
使用余额支付
点击重新获取
扫码支付
钱包余额 0

抵扣说明:

1.余额是钱包充值的虚拟货币,按照1:1的比例进行支付金额的抵扣。
2.余额无法直接购买下载,可以购买VIP、付费专栏及课程。

余额充值