论坛首页 Java企业应用论坛

透过JVM看Exception本质

浏览 42101 次
该帖已经被评为良好帖
作者 正文
   发表时间:2011-01-03   最后修改:2011-01-03
我的观点并没有变化...
需要一些时间,把LZ说的搞明白...
0 请登录后投票
   发表时间:2011-01-03   最后修改:2011-01-03
hmm,楼主坚持字节码角度分析的话,那送上下面的例子。
把楼主的代码稍微简化一下:
public class ExceptionTest {
    public static void newObject() {
        new Object();
    }

    public static void newException() {
        new Exception();
    }

    public static void catchException() {
        try {
            throw new Exception();
        } catch (Exception e) {
        }
    }
    
    public static void newCustomException() {
        new CustomException();
    }

    public static void main(String[] args) {
        CustomException.class.getName();
        newObject();
        newException();
        catchException();
        newCustomException();
    }
}

class CustomException extends Exception {
    @Override
    public Throwable fillInStackTrace() {
        return this;
    }
}

在main()的开头加了句getName()是为了在那个位置上触发CustomException的加载,免得它到newCustomException()的时候才加载,方便过滤日志。

然后找个fastdebug build的HotSpot,用下面的参数来跑:
java -XX:+TraceBytecodes ExceptionTest


把从main()开始到结束的部分提取出来,并忽略掉其中与类加载相关的部分之后,剩下的字节码序列(bytecode trace)是
[6872] static void ExceptionTest.main(jobject)
[6872]  5377751     0  ldc_w <unresolved klass at 5>
[6872]  5389978     3  invokevirtual 7 <getName> <()Ljava/lang/String;> 

[6872] virtual jobject java.lang.Class.getName()
[6872]  5390841     0  aload_0
[6872]  5390842     1  getfield 50 <name> <Ljava/lang/String;> 
[6872]  5390843     4  astore_1
[6872]  5390844     5  aload_1
[6872]  5390845     6  ifnonnull 19
[6872]  5390846     9  aload_0
[6872]  5390847    10  aload_0
[6872]  5390848    11  invokespecial 51 <getName0> <()Ljava/lang/String;> 
[6872]  5390849    14  dup
[6872]  5390850    15  astore_1
[6872]  5390851    16  putfield 50 <name> <Ljava/lang/String;> 
[6872]  5390852    19  aload_1
[6872]  5390853    20  areturn

[6872] static void ExceptionTest.main(jobject)
[6872]  5390854     6  pop
[6872]  5390855     7  invokestatic 8 <newObject> <()V> 

[6872] static void ExceptionTest.newObject()
[6872]  5390856     0  new 2 <java/lang/Object>
[6872]  5390857     3  dup
[6872]  5390858     4  invokespecial 1 <<init>> <()V> 

[6872] virtual void java.lang.Object.<init>()
[6872]  5390859     0  return_register_finalizer

[6872] static void ExceptionTest.newObject()
[6872]  5390860     7  pop
[6872]  5390861     8  return

[6872] static void ExceptionTest.main(jobject)
[6872]  5390862    10  invokestatic 9 <newException> <()V> 

[6872] static void ExceptionTest.newException()
[6872]  5390863     0  new 3 <java/lang/Exception>
[6872]  5390864     3  dup
[6872]  5390865     4  invokespecial 4 <<init>> <()V> 

[6872] virtual void java.lang.Exception.<init>()
[6872]  5390866     0  aload_0
[6872]  5390867     1  invokespecial 1 <<init>> <()V> 

[6872] virtual void java.lang.Throwable.<init>()
[6872]  5390868     0  aload_0
[6872]  5390869     1  invokespecial 1 <<init>> <()V> 

[6872] virtual void java.lang.Object.<init>()
[6872]  5390870     0  return_register_finalizer

[6872] virtual void java.lang.Throwable.<init>()
[6872]  5390871     4  aload_0
[6872]  5390872     5  aload_0
[6872]  5390873     6  putfield 2 <cause> <Ljava/lang/Throwable;> 
[6872]  5390874     9  aload_0
[6872]  5390875    10  invokevirtual 3 <fillInStackTrace> <()Ljava/lang/Throwable;> 
[6872]  5390876    13  pop
[6872]  5390877    14  return

[6872] virtual void java.lang.Exception.<init>()
[6872]  5390878     4  return

[6872] static void ExceptionTest.newException()
[6872]  5390879     7  pop
[6872]  5390880     8  return

[6872] static void ExceptionTest.main(jobject)
[6872]  5390881    13  invokestatic 10 <catchException> <()V> 

[6872] static void ExceptionTest.catchException()
[6872]  5390882     0  new 3 <java/lang/Exception>
[6872]  5390883     3  dup
[6872]  5390884     4  invokespecial 4 <<init>> <()V> 

[6872] virtual void java.lang.Exception.<init>()
[6872]  5390885     0  aload_0
[6872]  5390886     1  invokespecial 1 <<init>> <()V> 

[6872] virtual void java.lang.Throwable.<init>()
[6872]  5390887     0  aload_0
[6872]  5390888     1  invokespecial 1 <<init>> <()V> 

[6872] virtual void java.lang.Object.<init>()
[6872]  5390889     0  return_register_finalizer

[6872] virtual void java.lang.Throwable.<init>()
[6872]  5390890     4  aload_0
[6872]  5390891     5  aload_0
[6872]  5390892     6  putfield 2 <cause> <Ljava/lang/Throwable;> 
[6872]  5390893     9  aload_0
[6872]  5390894    10  invokevirtual 3 <fillInStackTrace> <()Ljava/lang/Throwable;> 
[6872]  5390895    13  pop
[6872]  5390896    14  return

[6872] virtual void java.lang.Exception.<init>()
[6872]  5390897     4  return

[6872] static void ExceptionTest.catchException()
[6872]  5390898     7  athrow
[6872]  5390899     8  astore_0
[6872]  5390900     9  return

[6872] static void ExceptionTest.main(jobject)
[6872]  5390901    16  invokestatic 11 <newCustomException> <()V> 

[6872] static void ExceptionTest.newCustomException()
[6872]  5390902     0  new 5 <CustomException>
[6872]  5390903     3  dup
[6872]  5390904     4  invokespecial 6 <<init>> <()V> 

[6872] virtual void CustomException.<init>()
[6872]  5390905     0  aload_0
[6872]  5390906     1  invokespecial 1 <<init>> <()V> 

[6872] virtual void java.lang.Exception.<init>()
[6872]  5390907     0  aload_0
[6872]  5390908     1  invokespecial 1 <<init>> <()V> 

[6872] virtual void java.lang.Throwable.<init>()
[6872]  5390909     0  aload_0
[6872]  5390910     1  invokespecial 1 <<init>> <()V> 

[6872] virtual void java.lang.Object.<init>()
[6872]  5390911     0  return_register_finalizer

[6872] virtual void java.lang.Throwable.<init>()
[6872]  5390912     4  aload_0
[6872]  5390913     5  aload_0
[6872]  5390914     6  putfield 2 <cause> <Ljava/lang/Throwable;> 
[6872]  5390915     9  aload_0
[6872]  5390916    10  invokevirtual 3 <fillInStackTrace> <()Ljava/lang/Throwable;> 

[6872] virtual jobject CustomException.fillInStackTrace()
[6872]  5390917     0  aload_0
[6872]  5390918     1  areturn

[6872] virtual void java.lang.Throwable.<init>()
[6872]  5390919    13  pop
[6872]  5390920    14  return

[6872] virtual void java.lang.Exception.<init>()
[6872]  5390921     4  return

[6872] virtual void CustomException.<init>()
[6872]  5390922     4  return

[6872] static void ExceptionTest.newCustomException()
[6872]  5390923     7  pop
[6872]  5390924     8  return

[6872] static void ExceptionTest.main(jobject)
[6872]  5390925    19  return

这个日志中,每段字节码的开头都有方法名,说明该字节码指令属于哪个方法;
每行开头的方括号内是线程ID;
在字节码指令的行中,线程ID之后的是字节码计数器,也就是解释器执行到当前位置已经执行了多少条字节码。中间有不连续的地方因为把类加载的代码过滤掉了;
再后面是当前字节码在方法内的偏移量(也就是bci);
然后是字节码指令的名字,和参数(如果有的话)。

看这个bytecode trace,到底整个执行过程中都经过了那些字节码指令一目了然。
留意到Throwable.fillInStackTrace()在HotSpot里是native的,所以在5390894跟5390895之间看不到该方法的实现;而它做的事情嘛……呵呵

完整的trace日志请看附件。注意:解压后日志有211MB左右,请有所准备…
0 请登录后投票
   发表时间:2011-01-03   最后修改:2011-01-03

楼主分析在理
异常怎么用,貌似搜索帖子一大吧,楼主这个帖子论证了:异常是一件非常耗费资源的事情!

gdpglc”的争执主要在异常怎样使用,这个真的是仁者见仁阿。

 

逻辑易懂,找到性能的本质所在就可以了!

呵呵,添加点个人使用异常体会 : ) 

  • 异常:不符合预期的情况时就会发生。
  • 什么时候需要异常:任何非预期的情况,包括输入或者非预期的逻辑,都需要抛出异常。
  • checked异常:checked exception不要用,直接包装到Runtime异常中,交给上层处理。
  • 异常显示友好:在系统外部,异常必须优雅的展示,而不是导致当前线程或者进程崩溃。
  • 自定义异常:如果存在特殊的异常处理策略时,定义自定义异常,这样可以针对特定异常进行处理。
  • 异常记录:一般在组件(如jar包)边界记录异常,或者人机交互层记录异常。

 

0 请登录后投票
   发表时间:2011-01-03   最后修改:2011-01-03
一个具体的问题:
之前LZ测试了一下validateInteger的执行时间,执行100000次的时间是:
字符串为非整数,验证方式1:2029725263ns

我想请教一下:
这是一个累加的时间。你之前讲过和另一个方法比,时间差200倍,我想请问,这200倍是以怎样的形式体现到应用程序中的?
我想有如下具体问题需要明确:

第一. 进行10万次调用,影不影响单次调用时间?
       在并发情况下,两个线程分别调用validateInteger,会不会互相增加对方的调用时间?

第二. 在一个多线程系统中,每个线程需要调用validateInteger一次。那么,当并发量具增,会不会因为validateInteger产生性能问题?如果会,达到多少并发会产生?

这里明确一下性能问题:使用户明显感觉到程序响应时间变长了。假设一个用户对应一个线程,响应时间延迟一秒。
这里还得假设这个线程,仅有validatInteger操作。


第三. 我想第二的余量应该是相当大的。那就是结论,只有在内存中反复的调用validateInteger时,才会产生显著的,可以影响程序响应时间的情况,是不是这样呢?

我想了想,这些似乎可以测试,但是当线程多时,线程切换本身也会代来开销,这样测试必然是不准的。不知LZ有没有估算的办法?

我先做一个简单估算:
假设所有validateInteger是互斥的。
那同时有50000个线程并发调用validateInteger时,最后一个会被延迟大约1秒。假设这时用户是可以容忍的。
那可以简单估算一下当前应用有多少用户。
同时请求的有:50000个。
同时在线的有:50000*10=500000
已注册用户应达到:500000*10=5000000


0 请登录后投票
   发表时间:2011-01-03  
强帖!学习一下。
话说gdpglc同学的态度感觉好多了么,呵呵。
0 请登录后投票
   发表时间:2011-01-03   最后修改:2011-01-03
gdpglc 写道
一个具体的问题:
之前LZ测试了一下validateInteger的执行时间,执行100000次的时间是:
字符串为非整数,验证方式1:2029725263ns

我想请教一下:
这是一个累加的时间。你之前讲过和另一个方法比,时间差200倍,我想请问,这200倍是以怎样的形式体现到应用程序中的?
我想有如下具体问题需要明确:

第一. 进行10万次调用,影不影响单次调用时间?
       在并发情况下,两个线程分别调用validateInteger,会不会互相增加对方的调用时间?

第二. 在一个多线程系统中,每个线程需要调用validateInteger一次。那么,当并发量具增,会不会因为validateInteger产生性能问题?如果会,达到多少并发会产生?

这里明确一下性能问题:使用户明显感觉到程序响应时间变长了。假设一个用户对应一个线程,响应时间延迟一秒。
这里还得假设这个线程,仅有validatInteger操作。


第三. 我想第二的余量应该是相当大的。那就是结论,只有在内存中反复的调用validateInteger时,才会产生显著的,可以影响程序响应时间的情况,是不是这样呢?

我想了想,这些似乎可以测试,但是当线程多时,线程切换本身也会代来开销,这样测试必然是不准的。不知LZ有没有估算的办法?

我先做一个简单估算:
假设所有validateInteger是互斥的。
那同时有50000个线程并发调用validateInteger时,最后一个会被延迟大约1秒。假设这时用户是可以容忍的。
那可以简单估算一下当前应用有多少用户。
同时请求的有:50000个。
同时在线的有:50000*10=500000
已注册用户应达到:500000*10=5000000



我写的观点是:“这个方法如果调用次数不多,怎么写都无所谓,如果次数多还是不要这样用的好”

放在有用户交互的系统中,譬如你写的使用在验证方面,我觉得属于上面第一个“如果”的情况,你只要觉得代码清晰,后续维护的人好看好懂,那怎么写都无所谓。

但Java不一定只用来做WEB、ERP、MIS这些强交互式应用,譬如在ETL类的应用中,提一个这样的需求(好像在JE上看到迅雷还是腾讯有这样的面试题),给你一个10T的数据文件,每行一个字符串,判断其中有多少整数,这样用异常的写法自然就不太合适(估计用我写的那个也不合适@_@)。

但也不必悲观的说大数据量的事情找C/C++来干。有JIT的介入后,Java和C/C++本质上都是执行native code,这时拼的就是编译器输出代码的智能程度。Java JIT编译优势是在运行期能根据profiling做很多静态编译中不敢做的激进优化,大不了逆向优化退回来,但劣势是编译时间就是运行时间,不敢做耗时太长的编译优化。

另外,如果涉及到同步互斥,那异常导致方法退出时要比我楼顶描写的做更多的事情,具体见虚拟机规范:
引用
    If the current frame represents an invocation of a synchronized method, the monitor acquired or reentered on invocation of the method is released or exited (respectively) as if by execution of a monitorexit instruction.
0 请登录后投票
   发表时间:2011-01-03  
实例、分析俱全,LZ真不错。

用异常做流程控制还是比较损失系统性能的,有些企业系统压力不太在乎这点损失,但一些每天pv上亿的互联网站,就要斤斤计较的算计系统性能,作为程序员来讲,用硬件来弥补代码上的缺陷,不是一件值得骄傲的事情
0 请登录后投票
   发表时间:2011-01-03  
强帖。。。学习了!
0 请登录后投票
   发表时间:2011-01-03  
lz, 感觉你的测试用例有点问题,我修改了一下:
    public void catchException() {  
        long l = System.nanoTime();
        Exception e = new Exception();
        for (int i = 0; i < testTimes; i++) {  
            try {  
            	throw e;
            } catch (Exception e1) {  
            }  
        }  
        System.out.println("建立、抛出并接住异常对象:" + (System.nanoTime() - l));  
    }


这是我改正后得到的结果:
建立对象:865088
建立异常对象:12278747
建立、抛出并接住异常对象:2129125

看得出逻辑部分速度还不算慢,最慢的是建立异常对象的时间。
通过比较,和普通对象相比,多出了一个fillInStackTrace的过程,看来这个地方是性能瓶颈

通过修改方法:
    public void newException() {  
        Exception e = new Exception(); 
        long l = System.nanoTime();  
        for (int i = 0; i < testTimes; i++) {
        	e.fillInStackTrace();
        }  
        System.out.println("建立异常对象:" + (System.nanoTime() - l));  
    }

可以验证我们的结论。fillInStackTrace是一个native方法,javadoc:
Fills in the execution stack trace. This method records within this Throwable object information about the current state of the stack frames for the current thread.
显然需要和当前虚拟机执行线程的执行环境交互,导致了性能较差
0 请登录后投票
   发表时间:2011-01-03   最后修改:2011-01-03
其实LZ可以再往下细扣一下,为啥new Exception会慢,profile一看主要就是慢在一个native方法调用上fillInStackTrace。

该方法的主要作用就是获取当前线程执行栈,用于日志记录和以后分析所用

一般针对业务逻辑,其实可以不太关注具体的线程调用栈,我们大家应该关注的是业务异常message和code

所以我还是比较喜欢用异常来进行逻辑控制和返回,首先代码风格上会比较清晰

可以参考下:复写了RumtimeException的一个native方法,在测试过程中性能几乎就和if..else一样了
public static class ServiceException extends RumtimeException {

@Override
public Throwable fillInStackTrace() {
     return this;
}
}


具体的测试分析,可以看下我同事的测试文档 : http://www.blogjava.net/stone2083/archive/2010/07/09/325649.html
0 请登录后投票
论坛首页 Java企业应用版

跳转论坛:
Global site tag (gtag.js) - Google Analytics