诚毅小家|集美大学生活【集美大学,诚毅学院,水产学院,师范学院,美术学院,财经学院,体育学院,航海学院,集美学村,石鼓路,龙舟池】

 找回密码
 注册

QQ登录

只需一步,快速开始

搜索
热搜: 活动 交友 discuz
查看: 1638|回复: 16

【转自JavaEye】喜欢性能调优的同学可以看看,标题:sun的程序员也是程序员啊!

  [复制链接]
发表于 2010-5-7 07:52:50 | 显示全部楼层 |阅读模式
原文链接:http://www.javaeye.com/topic/659687

主题:sun的程序员也是程序员啊!


    依然是近期工作中发现的问题,真实案例,写下来分享给大家。

    在开始本文之前,援引同事对此案例的一句评语:sun的程序员也是程序员啊!

    开始讲故事吧,依然是performance tuning,还是老伎俩,加压力,做thread dump,然后检查。结果就发现有如下的线程,而且比率极大:dump出来大概总共70-80个工作线程,有5-6个在做这个事情,还有大概50个在等着做这个事情,也就是说大概80%+的工作线程都于此有关。" HTTPBC-OutboundReceiver-221 " daemon prio = 3 tid = 0x09872c00 nid = 0x4bf9 runnable [ 0xa7b56000 ]
   java.lang.Thread.State: RUNNABLE
    at java.util.zip.ZipFile.getEntry(Native Method)
    at java.util.zip.ZipFile.getEntry(ZipFile.java:
149 )
   
- locked < 0xbb09d458 > (a java.util.jar.JarFile)
    at java.util.jar.JarFile.getEntry(JarFile.java:
206 )
    at java.util.jar.JarFile.getJarEntry(JarFile.java:
189 )
    at sun.misc.URLClassPath$JarLoader.getResource(URLClassPath.java:
754 )
    at sun.misc.URLClassPath$JarLoader.findResource(URLClassPath.java:
732 )
    at sun.misc.URLClassPath$
1 .next(URLClassPath.java: 195 )
    at sun.misc.URLClassPath$
1 .hasMoreElements(URLClassPath.java: 205 )
    at java.net.URLClassLoader$
3 $ 1 .run(URLClassLoader.java: 393 )
    at java.security.AccessController.doPrivileged(Native Method)
    at java.net.URLClassLoader$
3 .next(URLClassLoader.java: 390 )
    at java.net.URLClassLoader$
3 .hasMoreElements(URLClassLoader.java: 415 )
    at sun.misc.CompoundEnumeration.next(CompoundEnumeration.java:
27 )
    at sun.misc.CompoundEnumeration.hasMoreElements(CompoundEnumeration.java:
36 )
    at sun.misc.CompoundEnumeration.next(CompoundEnumeration.java:
27 )
    at sun.misc.CompoundEnumeration.hasMoreElements(CompoundEnumeration.java:
36 )
    at sun.misc.CompoundEnumeration.next(CompoundEnumeration.java:
27 )
    at sun.misc.CompoundEnumeration.hasMoreElements(CompoundEnumeration.java:
36 )
    at sun.misc.CompoundEnumeration.next(CompoundEnumeration.java:
27 )
    at sun.misc.CompoundEnumeration.hasMoreElements(CompoundEnumeration.java:
36 )
    at sun.misc.CompoundEnumeration.next(CompoundEnumeration.java:
27 )
    at sun.misc.CompoundEnumeration.hasMoreElements(CompoundEnumeration.java:
36 )
    at com.sun.xml.ws.util.ServiceFinder$LazyIterator.hasNext(ServiceFinder.java:
357 )
    at com.sun.xml.ws.api.pipe.TransportTubeFactory.create(TransportTubeFactory.java:
129 )
    at com.sun.xml.ws.transport.DeferredTransportPipe.processRequest(DeferredTransportPipe.java:
112 )
    at com.sun.xml.ws.api.pipe.Fiber.__doRun(Fiber.java:
595 )
    at com.sun.xml.ws.api.pipe.Fiber._doRun(Fiber.java:
554 )
    at com.sun.xml.ws.api.pipe.Fiber.doRun(Fiber.java:
539 )
    at com.sun.xml.ws.api.pipe.Fiber.runSync(Fiber.java:
436 )
   
- locked < 0xe8e3e200 > (a com.sun.xml.ws.api.pipe.Fiber)
    at com.sun.xml.ws.api.pipe.helper.AbstractTubeImpl.process(AbstractTubeImpl.java:
106 )
    at com.sun.xml.ws.tx.client.TxClientPipe.process(TxClientPipe.java:
177 )
    at com.sun.xml.ws.api.pipe.helper.PipeAdapter.processRequest(PipeAdapter.java:
115 )
    at com.sun.xml.ws.api.pipe.Fiber.__doRun(Fiber.java:
595 )
    at com.sun.xml.ws.api.pipe.Fiber._doRun(Fiber.java:
554 )
    at com.sun.xml.ws.api.pipe.Fiber.doRun(Fiber.java:
539 )
    at com.sun.xml.ws.api.pipe.Fiber.runSync(Fiber.java:
436 )
   
- locked < 0xe8e3e200 > (a com.sun.xml.ws.api.pipe.Fiber)
    at com.sun.xml.ws.client.Stub.process(Stub.java:
248 )
    at com.sun.xml.ws.client.dispatch.DispatchImpl.doInvoke(DispatchImpl.java:
180 )
    at com.sun.xml.ws.client.dispatch.DispatchImpl.invoke(DispatchImpl.java:
206 )
    at com.sun.jbi.httpsoapbc.OutboundMessageProcessor.outboundCall(OutboundMessageProcessor.java:
1256 )
    at com.sun.jbi.httpsoapbc.OutboundMessageProcessor.dispatch(OutboundMessageProcessor.java:
1296 )
    at com.sun.jbi.httpsoapbc.OutboundMessageProcessor.processRequestReplyOutbound(OutboundMessageProcessor.java:
747 )
    at com.sun.jbi.httpsoapbc.OutboundMessageProcessor.processMessage(OutboundMessageProcessor.java:
257 )
    at com.sun.jbi.httpsoapbc.OutboundAction.run(OutboundAction.java:
63 )
    at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:
886 )
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:
908 )
    at java.lang.Thread.run(Thread.java:
619 )




    忘了介绍一下背景:openESB运行于 glassfish平台,一个bepl 调用4个webservice.上面的线程HTTPBC-OutboundReceiver 是openESB中作为客户端调用webservice的工作线程,从调用栈中可以看到:
1. task被executor执行
2. jbi中的httpsoapbc用来处理消息
3. com.sun.xml.ws.client使用Stub来处理信息,标准的webservice调用
4. 最重要的两行,我们后面再来看这里发生了什么
    at com.sun.xml.ws.api.pipe.TransportTubeFactory.create(TransportTubeFactory.java:129)
    at com.sun.xml.ws.transport.DeferredTransportPipe.processRequest(DeferredTransportPipe.java:112)
5. ServiceFinder,通过Iterator.hasNext在做游历
6. java的classloader在find resource
7. 为了从jar包中装载resouce,需要处理解压缩,java.util.zip被调用

    OK,现在整体看,在处理webservice的调用过程中,需要在classpath路径下载入资源,而且看样子这个资源的载入还是很耗cpu时间的。
 楼主| 发表于 2010-5-7 07:53:10 | 显示全部楼层
本帖最后由 gk2004busy 于 2010-5-7 07:56 编辑

先看看在装载什么资源,上面的调用明显是jax-ws,glassfish下跑的是metro的实现。在glassfish目录下找到webservice-rt.jar,打开看META-INF/MANIFEST.MF,找到Name: jaxws-rt.jar这段,发现有Implementation-Version: 2.1.3.1,上metro的官网,找metor 相应版本的源文件,最接近的是2.1.3。下载下来查看源码,恩,开源就是好啊。

    首先找到ServiceFinder类,代码片段:com.sun.xml.ws.util.ServiceFinder$LazyIterator.hasNext(ServiceFinder.java: 357 )
private static final String  prefix = " META-INF/services/ " ;
    if (configs   == null ) {
        String fullName
= prefix + service.getName();
            
if (loader == null )
                configs
= ClassLoader.getSystemResources(fullName);
            
else
                configs
= loader.getResources(fullName);
    }



    非常通用的做法,META-INF/services/下查找资源看改用哪个实现。

    逆推找到类TransportTubeFactory中对此的调用代码:
    public static Tube create(@Nullable ClassLoader classLoader,

                                 @NotNull ClientTubeAssemblerContext context) {
        
for (TransportTubeFactory factory : ServiceFinder.find(TransportTubeFactory. class ,classLoader)) {
            Tube tube
= factory.doCreate(context);
            
if (tube != null ) {
                TransportTubeFactory.logger.fine(factory.getClass()
+ " successfully created " + tube);
               
return tube;
            }
        }



    代码的意图很明显,create()方法在classpath下找到TransportTubeFactory的实现,然后逐个尝试创建Tube对象。

    疑问就来了,为什么每次请求都要create, 这里的create明显是重量级的,需要到classpath下去查找一下某个Factory的实现。明显不合理,继续逆推代码,在类DeferredTransportPipe中找到对create的调用:
    public NextAction processRequest(@NotNull Packet request) {
        
if (request.endpointAddress == address)
            
// cache hit
             return transport.processRequest(request);
        .....
        address
= request.endpointAddress;
        transport
= TransportTubeFactory.create(classLoader, newContext);



    不出意料的,这里有cache: 如果endpoint address和上次相同,直接重用,否则就调用create方法。从前面的现象看,cache没有命中,至少没有全部命中。

    由于我们的测试的案例是连续调用4个不同的webservice,当然每个webservice的endpoint address是不同的。因此第一反应是这里transport cache机制被四个webservice的client端公用,因此每次调用只有1/4的概率和上次相同,其他的3/4就只能重新创建。之后花费了大量时间和精力去查看openesb的代码,过程不提,结果就是无果。

    再回头来看这个cache的地方,有点奇怪为什么不命中。好在可以做remote debug,debug进入,到if(request.endpointAddress==address ) 这行,发现果然没有命中,但是随即检查request.endpointAddress和 address的值,非常惊讶的发现里面的实际值是相同的!!

    直接晕倒!if (request.endpointAddress == address )



    值相同而==不成立,那么就是说这里的request.endpointAddress 和 address 并不是一般的enum或者类型安全枚举, ==的检测根本不成立。

    这是sun的代码啊,sun的程序员也会犯这种低级错误?用 == 来比较普通对象而不是用equals()方法?

    继续看EndpointAddress 这个类,无语了:

1. 这是个普通的类,根本不是enum或者类型安全枚举,有两个publish的构造函数,理论上,使用者可以随意创建任意数量的实例
2. 没有重载equals方法,因此即使改用equals方法来提到==的检查也是无意义的,默认的equals()还是检查对象引用

    因此,再来看DeferredTransportPipe中的这段试图重用cache的代码
    public NextAction processRequest(@NotNull Packet request) {
        
if (request.endpointAddress == address)
            
// cache hit
             return transport.processRequest(request);



    这里的"if(request.endpointAddress==address)"能否成立,完全取决于客户端的调用方法:如果调用方保证每次相同endpointAddress的请求,request.endpointAddress都会是同一个实例,则这里的cache可以命中。否则这个cache毫无意义,还是需要每次重新创建重量级的transport对象。我们的测试案例中,很明显,openESB的程序员,没有考虑到DeferredTransportPipe这里的"特殊"要求,每次调用传入的request.endpointAddress虽然里面的实际值相同,但是每次都是不同的实例。因此 == 不成立,cache不命中。

    查找了一下相关的类和接口定义,对于方法public NextAction processRequest(Packet request) 和 Packet中的endpointAddress属性,没有任何javadoc说明要求Packet中的endpointAddress属性需要做到相同地址只使用一个对象实例。

    看Packet中的endpointAddress的设值代码:
    public void setEndPointAddressString(String s) {
        
if (s == null )
            
this .endpointAddress = null ;
        
else
             this .endpointAddress = EndpointAddress.create(s);
    }
   
public static EndpointAddress create(String url) {
        
try {
            
return new EndpointAddress(url);
        }
catch (URISyntaxException e) {
            
throw new WebServiceException( " Illegal endpoint address: " + url,e);
        }
    }



    明显每次通过调用setEndPointAddressString()设置时都会产生一个新的EndpointAddress实例。看代码时还意外的发现,
public EndpointAddress endpointAddress;



    这个endpointAddress属性居然是public的!! 看样子,DeferredTransportPipe类的开发者,是寄希望于调用者不要通过Packet.setEndPointAddressString(String s)来设置,而是希望直接使用public的属性,这样才有希望命中cache!这分明是在挖坑,而且明显现在openESB的开发者被坑进去了!

    鄙视啊鄙视,这样的代码,居然是sun的程序员写出来的,还放在metro里面,而metro作为默认的jax-ws实现被放在jdk中...... 很是无语。

    无奈之下,修改代码,将 == 去掉,自己简单的判断一下endpointAddress的实际值
        if (address != null && address.getURI() != null

             && request.endpointAddress.getURI().equals(address.getURI())) {
            
// cache hit
             return transport.processRequest(request);
        }



    将编译出来的class文件,替换glassfish/lib/webservice-rt.jar中的相同文件,重新测试。再次thread dump,发现问题解决了。

    期间看了一下DeferredTransportPipe类的各个version的代码,这里的 == 一直都没有改,难道sun就一直没有发现这里有问题?有兴趣的可以通过下面的地址使用fisheye来查看这个类的代码:

http://fisheye5.cenqua.com/browse/jax-ws-sources/jaxws-ri/rt/src/com/sun/xml/ws/transport/DeferredTransportPipe.java?r1=1.3&r2=1.3.4.1&u=-1


    总结:用 == 来比较非enum或者类型安全枚举的对象实例,这种错误一般只有初学者才犯,万万没有想到,在metro这样级别的代码中也能出现。无限感叹啊,再次援引同事的评语作为本文的结束语:

    sun的程序员也是程序员啊!
发表于 2010-5-7 11:07:16 | 显示全部楼层
:m20纯粹来帮顶的。。。

完全看不懂。。
 楼主| 发表于 2010-5-7 12:48:50 | 显示全部楼层
回复 3# 小E


    傻丫头,最近连发的几篇文章都是有用意的,希望能够激励在坛子里游荡的有想法的IT工程师苗子~~~~
发表于 2010-5-7 12:50:26 | 显示全部楼层
回复 4# gk2004busy


    :loveliness: 继续帮顶。
发表于 2010-5-9 01:18:33 | 显示全部楼层
呵呵,没打算学JAVA
 楼主| 发表于 2010-5-17 23:02:46 | 显示全部楼层
回复 6# longcjx


    :)  看个人喜好了
发表于 2010-5-18 09:37:11 | 显示全部楼层
眼花。:sleep
发表于 2010-5-18 10:44:16 | 显示全部楼层
路过·················································································································································································
发表于 2010-5-18 15:12:25 | 显示全部楼层
回复  longcjx


      看个人喜好了
gk2004busy 发表于 2010-5-17 23:02



    :) 不知学长可以介绍学VC++的人给我不,我目前在学这方面
 楼主| 发表于 2010-5-19 19:41:04 | 显示全部楼层
回复 10# longcjx


    c和c++的有,VC的还真不清楚~~~公司这边服务器都是linux的~~
 楼主| 发表于 2010-5-19 19:42:03 | 显示全部楼层
回复 8# |.|.國王.饒舎.


    眼花总是难免的……你又何苦一网情深……
发表于 2010-5-19 20:16:41 | 显示全部楼层
回复  longcjx


    c和c++的有,VC的还真不清楚~~~公司这边服务器都是linux的~~
gk2004busy 发表于 2010-5-19 19:41



    嗯,就是要c和c++的
发表于 2010-5-21 09:11:48 | 显示全部楼层
求翻译成中文。。
 楼主| 发表于 2010-5-23 21:08:18 | 显示全部楼层
本帖最后由 gk2004busy 于 2010-5-24 00:29 编辑

回复 13# longcjx


    以后工作之前到一些公司做实习的话,会有机会接触到许多牛人,在校期间还是先打牢基础比较重要
您需要登录后才可以回帖 登录 | 注册

本版积分规则

QQ|Archiver|手机版|小黑屋|诚毅小家 ( 小家社区工作室 闽ICP备05007965号 )

GMT+8, 2024-5-3 13:28 , Processed in 0.137765 second(s), 24 queries .

Powered by Discuz! X3.4

Copyright © 2001-2021, Tencent Cloud.

快速回复 返回顶部 返回列表