多线程_java多线程环境下栈信息分析思路

导读:Java多线程开发给程序带来好处的同时,由于多线程程序导致的问题也越来越多,而且对问题的查找和分析解决对于菜鸟程序原来是是件头疼的事。下面我就项目中使用多线程开发程序过程中遇到的问题做详细的分析和解决思路的分享。本人也属菜鸟,忘大神指点。

项目描述:

工作中要编写一份程序用于爬取某某网站上的大量图片。从HBase里面遍历出所有的爬取任务,开启固定大小的线程池Executors.newFixedThreadPool(100),提交线程,线程每个线程做的事情是使用FileUtils.copyURLToFile去从Url下载图片,保存到本地。详细代码如下:

主线程:

public static void getAllRecord (String tableName,String prefix,String dir) {
         HTable table = null;
        try{
            table = new HTable(conf, tableName);
             Scan s = new Scan();  

             s.setFilter(new PrefixFilter(prefix.getBytes()));
             ResultScanner ss = table.getScanner(s);
             ExecutorService executor = Executors.newFixedThreadPool(100);
             for(Result r:ss){
                 try {
                    TimeUnit.SECONDS.sleep(2);
                } catch (InterruptedException e) {
                    // TODO Auto-generated catch block
                    e.printStackTrace();
                }
                 Thread task = new Thread(new DownLoadPicTask(r,dir,tableName));
                 executor.submit(task);

             }
             executor.shutdown();
        } catch (IOException e){  

        }finally{
          ...关闭资源
        }
    }

任务线程:

public static String downloadFromUrl(String url,String dir,String cityName,String id) {  

        try {
            URL httpurl = new URL(url);
            String fileName = getFileNameFromUrl(url);
            System.out.println(fileName);
            File f = new File(dir + File.separator+ cityName+ File.separator+id+File.separator+ fileName);
            FileUtils.copyURLToFile(httpurl, f);

            FileInputStream fis = new FileInputStream(f);
            BufferedImage bufferedImg = ImageIO.read(fis);
            int imgWidth = bufferedImg.getWidth();
            int imgHeight = bufferedImg.getHeight();
            bufferedImg = null;
            fis.close();
            if(imgWidth<500&&imgHeight<500){
                FileUtils.deleteQuietly(f);
                return null;
            }
            return imgWidth + "," + imgHeight;
        } catch (Exception e) {
          return null;
        } 

    }

问题:

执行了很久很久,理论上如果任务都执行完成的话线程池会销毁,主线程会结束,可是结果是没有。第一想法是肯定哪里死锁了。于是打开Java VisualVM查看。

可以看到pool-4(也即我们自己的线程)大部分处于等待状态。

Jstack调出所有的stack信息:

"pool-4-thread-21" prio=6 tid=0x000000000d662800 nid=0x2364 waiting on condition [0x000000001175f000]
   java.lang.Thread.State: WAITING (parking)
    at sun.misc.Unsafe.park(Native Method)
    - parking to wait for  <0x0000000780faa230> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
    at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186)
    at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043)
    at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
    at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
    at java.lang.Thread.run(Thread.java:745)

   Locked ownable synchronizers:
    - None

"pool-4-thread-20" prio=6 tid=0x000000000d662000 nid=0x32f8 waiting on condition [0x00000000114ef000]
   java.lang.Thread.State: WAITING (parking)
    at sun.misc.Unsafe.park(Native Method)
    - parking to wait for  <0x0000000780faa230> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
    at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186)
    at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043)
    at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
    at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
    at java.lang.Thread.run(Thread.java:745)

   Locked ownable synchronizers:
    - None

上述大概有100个线程的stack信息,这里只列出两条。

关于虚拟机的stack信息分析可以参考文章:《三个实例演示 Java Thread Dump 日志分析

初步分析:

大部分线程(主:“大部分”,这里没说全部的原因后面跟着我的分析思路会说明)处于WAITING等待状态。 都在等待<0x0000000780faa230> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)这么一个资源。

既然线程们都在等待某个资源,那么这个资源是什么呢?

带着疑问我们搜索了整个stack信息,发现只有pool-4-thread-**线程在同样的位置有这个0x0000000780faa230东西。然后这个东西是什么呢?

AbstractQueuedSynchronizer提供了一个基于FIFO队列,可以用于构建锁或者其他相关同步装置的基础框架。
Condition是一个条件功能的class,必须放在Lock代码块内,如同wait,notify方法放在synchronized块一样。
Condition的(await,signal)与object的(wait,notify)相比,提供了更为通用和灵活的解决方案,可以让多种条件的线程之间相互通信。

更多详细关于AbstractQueuedSynchronizer的可以参看:
《AbstractQueuedSynchronizer的介绍和原理分析》AbstractQueuedSynchronizer

说了这么多,参考了大量的上述文献,还是一头雾水是不是?

线程处于闲等状态,不能获取某个资源/条件(java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject),那么肯定是被某个线程占用了。

FileUtils.copyURLToFile的问题

基于这么个思路,我在次查看了所有线程状态,终于发现在100个线程中被我遗漏的3个正在运行的线程:
其中之一如下:

"pool-4-thread-15" prio=6 tid=0x000000000d65e000 nid=0x28e4 runnable [0x00000000109fe000]
   java.lang.Thread.State: RUNNABLE
    at java.net.SocketInputStream.socketRead0(Native Method)
    at java.net.SocketInputStream.read(SocketInputStream.java:152)
    at java.net.SocketInputStream.read(SocketInputStream.java:122)
    at java.io.BufferedInputStream.fill(BufferedInputStream.java:235)
    at java.io.BufferedInputStream.read1(BufferedInputStream.java:275)
    at java.io.BufferedInputStream.read(BufferedInputStream.java:334)
    - locked <0x00000007810fa6c0> (a java.io.BufferedInputStream)
    at sun.net.www.http.HttpClient.parseHTTPHeader(HttpClient.java:687)
    at sun.net.www.http.HttpClient.parseHTTP(HttpClient.java:633)
    at sun.net.www.protocol.http.HttpURLConnection.getInputStream(HttpURLConnection.java:1323)
    - locked <0x00000007810fa770> (a sun.net.www.protocol.http.HttpURLConnection)
    at java.net.URL.openStream(URL.java:1037)
    at org.apache.commons.io.FileUtils.copyURLToFile(FileUtils.java:1460)
    at com.esf.crawler.bootsStrap.DownLoadPicTask.downloadFromUrl(DownLoadPicTask.java:139)
    at com.esf.crawler.bootsStrap.DownLoadPicTask.run(DownLoadPicTask.java:101)
    at java.lang.Thread.run(Thread.java:745)
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
    at java.util.concurrent.FutureTask.run(FutureTask.java:262)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
    at java.lang.Thread.run(Thread.java:745)

   Locked ownable synchronizers:
    - <0x00000007810e2060> (a java.util.concurrent.ThreadPoolExecutor$Worker)

没错!!!这就是罪魁祸首,这3个线程正处于运行状态(RUNNABLE)。

根据stack信息我们可以发现现在正在执行下载操作里的FileUtils.copyURLToFile方法,而该方法在读取socket流而没有结束(at java.net.SocketInputStream.read(SocketInputStream.java:152))

问题应该就是这里了!

那为什么读取不会结束呢?网络读取如果不能完成应该超时退出啊。带着这个问题我打开了下载网络图片的方法(见上面)。

FileUtils.copyURLToFile(httpurl, f);

翻看FileUtils.copyURLToFile的api:

public static void copyURLToFile(URL source,File destination)throws IOException
public static void copyURLToFile(URL source,File destination,int connectionTimeout,int readTimeout)throws IOException

可以看到我使用的是第一个方法。
它有一个警告:

Warning: this method does not set a connection or read timeout and thus might block forever. Use copyURLToFile(URL, File, int, int)with reasonable timeouts to prevent this.

也即是如果没有设置连接超时和读超时时间的话,可能会由于某些异常而永久阻塞。

那好吧,改成有超时设置的函数。

重新执行!结果还是不是我预想的>_<

HBase超时

重新启动后一段时间后100个线程还是全部休眠,参看debug日志,发现下面异常:

Exception in thread "main" java.lang.RuntimeException: org.apache.hadoop.hbase.client.ScannerTimeoutException: 200243ms passed since the last invocation, timeout is currently set to 60000
    at org.apache.hadoop.hbase.client.AbstractClientScanner$1.hasNext(AbstractClientScanner.java:94)
    at com.esf.crawler.bootsStrap.AjkPicDownload.getAllRecord(AjkPicDownload.java:32)
    at com.esf.crawler.bootsStrap.AjkPicDownload.main(AjkPicDownload.java:75)
Caused by: org.apache.hadoop.hbase.client.ScannerTimeoutException: 200243ms passed since the last invocation, timeout is currently set to 60000
    at org.apache.hadoop.hbase.client.ClientScanner.next(ClientScanner.java:370)
    at org.apache.hadoop.hbase.client.AbstractClientScanner$1.hasNext(AbstractClientScanner.java:91)
    ... 2 more
Caused by: org.apache.hadoop.hbase.UnknownScannerException: org.apache.hadoop.hbase.UnknownScannerException: Name: 1679, already closed?
    at org.apache.hadoop.hbase.regionserver.HRegionServer.scan(HRegionServer.java:3053)
    at org.apache.hadoop.hbase.protobuf.generated.ClientProtos$ClientService$2.callBlockingMethod(ClientProtos.java:29497)
    at org.apache.hadoop.hbase.ipc.RpcServer.call(RpcServer.java:2012)
    at org.apache.hadoop.hbase.ipc.CallRunner.run(CallRunner.java:98)
    at org.apache.hadoop.hbase.ipc.SimpleRpcScheduler.consumerLoop(SimpleRpcScheduler.java:168)
    at org.apache.hadoop.hbase.ipc.SimpleRpcScheduler.access$000(SimpleRpcScheduler.java:39)
    at org.apache.hadoop.hbase.ipc.SimpleRpcScheduler$1.run(SimpleRpcScheduler.java:111)
    at java.lang.Thread.run(Thread.java:745)

    at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
    at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:57)
    at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
    at java.lang.reflect.Constructor.newInstance(Constructor.java:526)
    at org.apache.hadoop.ipc.RemoteException.instantiateException(RemoteException.java:106)
    at org.apache.hadoop.ipc.RemoteException.unwrapRemoteException(RemoteException.java:95)
    at org.apache.hadoop.hbase.protobuf.ProtobufUtil.getRemoteException(ProtobufUtil.java:285)
    at org.apache.hadoop.hbase.client.ScannerCallable.call(ScannerCallable.java:204)
    at org.apache.hadoop.hbase.client.ScannerCallable.call(ScannerCallable.java:59)
    at org.apache.hadoop.hbase.client.RpcRetryingCaller.callWithRetries(RpcRetryingCaller.java:114)
    at org.apache.hadoop.hbase.client.RpcRetryingCaller.callWithRetries(RpcRetryingCaller.java:90)
    at org.apache.hadoop.hbase.client.ClientScanner.next(ClientScanner.java:354)
    ... 3 more
Caused by: org.apache.hadoop.hbase.ipc.RemoteWithExtrasException(org.apache.hadoop.hbase.UnknownScannerException): org.apache.hadoop.hbase.UnknownScannerException: Name: 1679, already closed?
    at org.apache.hadoop.hbase.regionserver.HRegionServer.scan(HRegionServer.java:3053)
    at org.apache.hadoop.hbase.protobuf.generated.ClientProtos$ClientService$2.callBlockingMethod(ClientProtos.java:29497)
    at org.apache.hadoop.hbase.ipc.RpcServer.call(RpcServer.java:2012)
    at org.apache.hadoop.hbase.ipc.CallRunner.run(CallRunner.java:98)
    at org.apache.hadoop.hbase.ipc.SimpleRpcScheduler.consumerLoop(SimpleRpcScheduler.java:168)
    at org.apache.hadoop.hbase.ipc.SimpleRpcScheduler.access$000(SimpleRpcScheduler.java:39)
    at org.apache.hadoop.hbase.ipc.SimpleRpcScheduler$1.run(SimpleRpcScheduler.java:111)
    at java.lang.Thread.run(Thread.java:745)

    at org.apache.hadoop.hbase.ipc.RpcClient.call(RpcClient.java:1453)
    at org.apache.hadoop.hbase.ipc.RpcClient.callBlockingMethod(RpcClient.java:1657)
    at org.apache.hadoop.hbase.ipc.RpcClient$BlockingRpcChannelImplementation.callBlockingMethod(RpcClient.java:1715)
    at org.apache.hadoop.hbase.protobuf.generated.ClientProtos$ClientService$BlockingStub.scan(ClientProtos.java:29900)
    at org.apache.hadoop.hbase.client.ScannerCallable.call(ScannerCallable.java:174)
    ... 7 more

上述异常是HBase使用的Scan超时,超过了默认的6000的默认值。然后抛出异常,程序终结。也就是不在从HBase的Scaner里遍历出记录,产生任务Task。导致100线程无任务而空等。
原来我在上面程序中加入了线程休眠的代码,导致Scaner的超时。原本使用sleep代码只是为了让任务不要过早启动太多,结果导致的这个异常。

至此大致的问题已经找到了。

总结: 从出现问题到定位,再到分析解决。过程中不免会经过一起看是错误的猜想,我们还是要不同不但的分析推理验证尽可能的想法。一步一查找线索。多线程问题的出现无非就是由于同步,并发等情况下造成的死锁,资源竞争等等。

通过JDK里面提供的工具进行检测和导出相应的堆栈信息。能够分析dump日志里面线程各种状态产生的原因,及找到解决该问题的相应方案。

dump里线程状态大致如下:

  1. 死锁,Deadlock(重点关注) 
  2. 执行中,Runnable
  3. 等待资源,Waiting on condition(重点关注)
  4. 等待获取监视器,Waiting on monitor entry(重点关注)
  5. 暂停,Suspended
  6. 对象等待中,Object.wait() 或 TIMED_WAITING
  7. 阻塞,Blocked(重点关注)  
  8. 停止,Parked

分析出原因后进而定位到相应的代码。改之!!!

参考:

三个实例演示 Java Thread Dump 日志分析
《AbstractQueuedSynchronizer的介绍和原理分析》AbstractQueuedSynchronizer
Java线程池使用说明

(转自:多线程任务下FileUtils.copyURLToFile引起的线程阻塞问题及Java虚拟机stac, 感谢原作者分享。)

时间: 2024-10-22 15:21:37

多线程_java多线程环境下栈信息分析思路的相关文章

【转载】linux环境下tcpdump源代码分析

linux环境下tcpdump源代码分析 原文时间 2013-10-11 13:13:02   原文链接   主题 Tcpdump 作者:韩大卫 @ 吉林师范大学 tcpdump.c 是tcpdump 工具的main.c, 本文旨对tcpdump的框架有简单了解,只展示linux平台使用的一部分核心代码. Tcpdump 的使用目的就是打印出指定条件的报文,即使有再多的正则表达式作为过滤条件.所以只要懂得tcpdump -nXXi eth0 的实现原理即可. 进入main之前,先看一些头文件 n

20150430 调试分析之 根据内核报错信息栈信息分析错误

20150430 调试分析之 根据内核报错信息栈信息分析错误 2015-04-30 Lover雪儿 还是沿用上篇文章的程序,继续研究内核报错信息 文章地址:http://www.cnblogs.com/lihaiyan/p/4470353.html 错误驱动源文件: 加载错误驱动程序 1 [email protected] /mnt/nfs/module/37_debug_err_led# echo 1 > /dev/errdule/37_debug_err_led# echo 1 > /de

c++多线程在异常环境下的等待

c++11开始支持多线程编程,相关的类和函数封装在标准库头文件<thread>中,而c++多线程编程很重要的一点就是当用户创建一个std::thread对象,关联了可调用对象后,需要在该thread对象销毁前调用join()或detach().其中join()函数用于结合线程,确保在创建该thread对象的函数退出前,该线程执行完毕;而detach()函数则表示分离线程,即让线程在后台运行,线程的所有权和控制权交给c++运行时库.若thread对象销毁前没有调用join()或detach(),

Tomcat:云环境下的Tomcat设计思路——Tomcat的多实例安装

Cloud现在是一个热门的技术,Tomcat是学习Java的人一般都会接触的Web服务器,如果在Cloud环境下使用Tomcat,又当如何呢?不可避免的,要安装多个Tomcat了,这里称之为Tomcat实例,进而通过云平台来多Tomcat进行管理. 如何在一台机器上安装多个Tomcat实例呢? 这个问题想必使用过Tomcat的人都知道: 1)  下载Tomcat.zip 2)  解压,后的Tomcat拷贝1份,每一份就称之为一个实例,并修改Tomcat实例的tomcat_home/conf/se

Linux下栈帧分析

我们知道C语言中,每个栈帧对应着一个未运行完的函数.栈帧中保存了该函数的返回地址和局部变量.栈帧也叫过程活动记录,是编译器用来实现函数调用的一种数据结构.那么在Linux下gcc编译器栈帧是怎么实现的呢? 首先来看下面这段代码: 这段代码的运行结果是会导致虚拟机重启.通过代码可以看到我们在fun函数中写了让系统重启的代码然而我们在main函数中并没有调用fun函数,却仍旧导致了系统重启. 首先要我们知道栈是从高地址向低地址生长的,每个函数的每次调用,都有它自己独立的一个栈帧,这个栈帧中维持着所需

车载环境下的噪声分析

想要降低汽车噪声,就要了解汽车室内噪声环境, 汽车噪声系统框图 外部激励:风噪.路噪以及环境噪声等激励噪声 内部激励:悬架系统.变速箱系统.发动机等系统在行车时造成的 振动激励噪声 车腔噪声以非线性形式传导,通常将其传导方式分为固体传导和空气传导 固体传导:车辆悬架系统.发动机.变速器.制动系统等振动部件通过汽车底盘传输至车身,后经车身的振动产生辐射噪声引起车腔内的噪声 空气传导:汽车行驶时与空气摩擦噪声等通过壁板辐射进入车内的噪声 汽车的主要噪声源和传播途径 由于被动噪声控制(Passive

ssh环境下客户信息管理系统学习问题(二)

问题1: 这是包冲突的问题,jar包中存在两个冲突的包,可以看到上面的Referenced Libraries中存在asm.jar和asm-2.2.3.jar两个包,这两个包冲突了,所以应该把asm-2.2.3.jar这个包删掉,重新运行后可以发现就没上面说的那个问题了. 问题2: 经检查,发现是数据库配置那里的名称打错了(如下图代码片段),所以我们在写代码的时候一定要注意不要打错关键词或是其它地方应使用相同的名词的时候. <?xml version="1.0" encoding

OS X 在Cisco无线环境下丢包分析 part 2

part 1说到,单播的ARP请求最终都被网关丢弃了,从而造成了丢包.先说我最终怎么解决的吧,我最终把核心交换上针对无线VLAN的arp inspection和dhcp snooping删掉了,然后出于安全考虑,启用了WLC(Wireless Controller)上的一个feature,该feature相当于是DHCP snooping和arp inspection的结合,功能是不让客户端私自配静态IP,只允许DHCP获取,那么有这个feature做保障,我也就放心的删掉了核心交换上的arp

HttpClient在多线程环境下踩坑总结

问题现场 在多线程环境下使用HttpClient组件对某个HTTP服务发起请求,运行一段时间之后发现客户端主机CPU利用率呈现出下降趋势,而不是一个稳定的状态. 而且,从程序日志中判断有线程处于夯住的状态,应该是被阻塞了. 问题排查 一开始找不到原因,怀疑是多线程并发导致的死锁问题,但是通过代码审查并未定位到任何可能的多线程并发问题. 甚至开始怀疑是否是因为内存资源不够引起JVM频繁GC到导致业务线程被暂停,但是从GC的日志输出结果看,GC是正常的. 于是,进入一种丈二和尚摸不着头脑头脑的状态,