标签归档:classloader

tomcat启动遇到NoSuchMethodError错误的排查思路

某个应用在日常环境运行ok,在预发布时却启动错误,异常日志如下:

Caused by: java.lang.NoSuchMethodError: 
org.jboss.netty.channel.socket.nio.NioClientSocketChannelFactory.
<init>(Ljava/util/concurrent/Executor;Ljava/util/concurrent/Executor;II)V

at com.taobao.xxx.client.rpc.net.XXXConnector.<init>(XXXConnector.java:43)

是调用netty的NioClientSocketChannelFactory的构造方法时找不到对应的方法,根据提示信息,这个方法的签名应该是这样:

NioClientSocketChannelFactory(Executor, Executor, int, int) 

绝大部分情况下,都是因为多个版本的jar包同时存在产生的冲突,去用户的war下搜索一下。

 for file in *.jar; do 
    echo $file;
    /opt/taobao/java/bin/jar tvf $file | grep NioClientSocketChannelFactory;  
 done

找到了两个jar里都包含那个类,这两个jar也是两个不同的netty版本:

netty-3.6.3.Final.jar
jboss.jboss-netty-3.2.5.Final.jar

分别解开,看看哪个版本里是有那个构造方法的,先看3.6.3 版本:

$/opt/taobao/java/bin/javap  org.jboss.netty.channel.socket.nio.NioClientSocketChannelFactory | grep Executor | grep int

public org.jboss.netty.channel.socket.nio.NioClientSocketChannelFactory(java.util.concurrent.Executor, java.util.concurrent.Executor, int);
public org.jboss.netty.channel.socket.nio.NioClientSocketChannelFactory(java.util.concurrent.Executor, java.util.concurrent.Executor, int, int);
public org.jboss.netty.channel.socket.nio.NioClientSocketChannelFactory(java.util.concurrent.Executor, int, org.jboss.netty.channel.socket.nio.WorkerPool);
public org.jboss.netty.channel.socket.nio.NioClientSocketChannelFactory(java.util.concurrent.Executor, int, org.jboss.netty.channel.socket.nio.WorkerPool, org.jboss.netty.util.Timer);

里面是包含了我们需要的那个方法的。再看 3.2.5 版本:

$/opt/taobao/java/bin/javap  org.jboss.netty.channel.socket.nio.NioClientSocketChannelFactory | grep Executor | grep int

public org.jboss.netty.channel.socket.nio.NioClientSocketChannelFactory(java.util.concurrent.Executor, java.util.concurrent.Executor, int);

签名里只有1个int参数,没有我们要用的那个。

可以判断这次是因为classloader优先加载了jboss.jboss-netty-3.2.5.Final.jar这个文件而导致问题的,那为何日常环境的机器上却没问题呢?对于classloader而言,找文件的过程取决于文件系统返回的顺序,简单的说,在linux上取决于两个inode的顺序,在这台预发布机器上,正好 3.2.5 版本的 inode 在前:

$ stat netty-3.6.3.Final.jar
  File: `netty-3.6.3.Final.jar'
  Size: 1202373     Blocks: 2368       IO Block: 4096   regular file
Device: 805h/2053d  Inode: 66912666    Links: 1
Access: (0644/-rw-r--r--)  Uid: (  594/   admin)   Gid: (  594/   admin)
Access: 2014-08-06 13:21:56.000000000 +0800
Modify: 2014-07-14 16:13:44.000000000 +0800
Change: 2014-08-06 13:21:54.000000000 +0800    

$ stat jboss.jboss-netty-3.2.5.Final.jar
  File: `jboss.jboss-netty-3.2.5.Final.jar'
  Size: 792314      Blocks: 1568       IO Block: 4096   regular file
Device: 805h/2053d  Inode: 66912474    Links: 1
Access: (0644/-rw-r--r--)  Uid: (  594/   admin)   Gid: (  594/   admin)
Access: 2014-08-06 13:21:56.000000000 +0800
Modify: 2014-07-14 16:14:18.000000000 +0800
Change: 2014-08-06 13:21:53.000000000 +0800

3.2.5版本的jar文件inode小于3.6.3版本的jar文件,被classloader优先找到了。

tomcat关闭应用时的清理工作(3): ThreadLocal

tomcat在关闭时,可能看到与ThreadLocal相关的警告:

Jan 24, 2014 7:18:52 AM org.apache.catalina.loader.WebappClassLoader checkThreadLocalMapForLeaks
SEVERE: The web application [] created a ThreadLocal with key of type 
[java.lang.ThreadLocal] (value [java.lang.ThreadLocal@4e61bc49]) and a value of type 
[com.alibaba.xxx.Entry] (value [...]) but failed to remove it when the web application was stopped. 
Threads are going to be renewed over time to try and avoid a probable memory leak.

用下面的例子来模拟一下

@WebServlet(name = "MainServlet", urlPatterns = { "/main" }, loadOnStartup = 1)
public class MainServlet extends HttpServlet {

    private static final long serialVersionUID = 1L;

    private static ThreadLocal<MyClass> tl = new ThreadLocal<MyClass>();

    public void doGet(HttpServletRequest req, HttpServletResponse resp)
            throws ServletException, IOException {

        MyClass m = tl.get();
        if (m == null) {
            tl.set(new MyClass());
        }
    }

}

class MyClass {}

请求一次之后,通过脚本会命令停止tomcat,会看到类似的日志:

七月 16, 2014 5:01:35 下午 org.apache.catalina.loader.WebappClassLoader checkThreadLocalMapForLeaks
严重: The web application [] created a ThreadLocal with key of type [java.lang.ThreadLocal] 
(value [java.lang.ThreadLocal@7da150]) and a value of type [org.r113.servlet3.MyClass] 
(value [org.r113.servlet3.MyClass@37e98b70]) but failed to remove it when the web application was stopped. 
Threads are going to be renewed over time to try and avoid a probable memory leak.

这个泄露其实是可能造成classloader的泄露,因为ThreadLocal引用了自定义的类MyClass,绑定到了当前的请求线程上,而请求线程又是线程池里的线程,生存周期可能会比较长。比如上面模拟的情况,要停止应用的时候,请求线程的ThreadLocal仍未释放,那么即使加载MyClass类的classLoader已经不会再被任何地方使用,可以被垃圾回收了,却因为这个MyClass被引用而得不到回收。

tomcat启动失败时的ClassNotFoundException

tomcat在部署应用时,如果部署失败,该应用会被stop,但如果该应用的WebappClassLoader被其它线程持有并且继续使用的话,可能发生异常。

应用部署失败被stop的时候,classLoader也被stop(因为WebappClassLoader实现了Lifecycle接口),stop的时候,相关的 files/jars/resoures/repositories/parent 等等都被清除掉了,同时标识应用是否启动的started状态也被设置为false;基本上该classloader已经不可用了。(除了还可以委托给j2seClassLoader这个bootstrap classloader,这个classloader实际运行时是ExtClassLoader)

假设应用里有一个类自己启动了一个线程,逻辑大致如下:

static {
    new Thread(){
        public void run(){
            // 1) 先sleep一段时间,确保应用完成初始化
            // 2) 然后执行一些逻辑
        }
    }.start();
}

上面线程在执行后续逻辑的时候,使用WebappClassLoader去加载类,如果在sleep的阶段app在tomcat中没有启动成功,被stop了,则后边的逻辑有些意思。

看一下loadClass方法:

    public synchronized Class<?> loadClass(String name, boolean resolve)
    throws ClassNotFoundException {

    if (log.isDebugEnabled())
        log.debug("loadClass(" + name + ", " + resolve + ")");
    Class<?> clazz = null;

    // Log access to stopped classloader
    if (!started) {
        try {
            throw new IllegalStateException(); //这里抛出异常,又被自己捕获
        } catch (IllegalStateException e) {
            log.warn(sm.getString("webappClassLoader.stopped", name));
        }
    }

    // (0) Check our previously loaded local class cache
    ...

    // (0.1) Check our previously loaded class cache
    ...

    // (0.2) Try loading the class with the system class loader, to prevent
    //       the webapp from overriding J2SE classes
    ...

    // (0.5) Permission to access this class when using a SecurityManager
    ...

    // (1) Delegate to our parent if requested
    ...

    // (2) Search local repositories
    ...

    // (3) Delegate to parent unconditionally
    ...

    throw new ClassNotFoundException(name);

}

loadClass方法里判断了started状态,未启动的情况下,抛出异常,又自己捕获,仅仅记录了一下日志。然后继续后边的逻辑,先从cache里找,然后委托j2se classloader,再委派parent classloader,以及从本地仓库寻找。找不到抛出ClassNotFoundException

前面提过应用在stop时webappclassloader里的cache/parent等有关资源都被清空了,如果应用里启动的线程后续逻辑要求找的类,不是j2seclassloader可以找得到的类的话,就会抛出异常。

很多情况下,开发人员总是被这个ClassNotFoundException所迷惑, 如果仔细看日志的话,已经给出了应用被stopped的信息:

2014-6-17 21:58:42 org.apache.catalina.loader.WebappClassLoader loadClass  
信息: Illegal access: this web application instance has been stopped already.    

Pandora的启动优化

pandora3进行了很多重构,上周花了几天时间对启动过程做了一些优化。官方的tomcat只部署一个及简单的servlet应用,在我的机器上启动过程大概在1秒左右,如果应用使用了spring-mvc框架,启动过程大约在2000-2400毫秒左右。

如果使用Ali-Tomcat,启动过程中要先启动pandora容器,同一个spring-mvc的样例应用,总启动时间在4-5秒左右。优化的手段主要有2点:1) 部分模块异步化加载(前提是其它模块以及应用的启动对该模块没有依赖)。 2) 在自定义的classloader.loadClass方法里针对java7开启并行加载(在我的场景下所加载的类大约1000-2000个,使用4个线程,性能上约有20-30%的提升)。

java7的classloader所支持的并行加载,实质是把原先loadClass方法原先粗粒度的锁synchronized(this)换成了细粒度的锁synchronized (getClassLoadingLock(name)),为每个class都分配一个锁。这部分特性其实可以移植到自定义的Classloader实现里来,使得jdk6上也可以享用并行加载。

自定义的classloader要使用jdk7的并行加载机制,需要在静态构造块里注册为可并行加载:

static {
    ClassLoader.registerAsParallelCapable();
}

注意它要求当前classloader所有的父类都进行注册才行,比如我们在自定义的 MyClassLoader中覆盖了loadClass方法, 假设它的父类是 ClassLoaderBase,而ClassLoaderBase又继承自系统的URLClassLoader,那么要求URLClassLoaderClassLoaderBase 都必须在静态块中有注册声明可并行加载才行(URLClassLoader及其父类在jdk代码中是有注册的)。

另外,使用spring-mvc框架的应用,之所以比普通的servlet启动时慢,很大一部分原因是在于servlet3的web-fragment.xml合并的过程比较耗时。这个过程是在Pandora3启动后,输出应用启动日志过程中体会到的一个明显的“卡顿”:

2014/06/18 10:36:09:588 [INFO] Pandora - Container started. time elapsed: 439 ms
2014-06-18 10:36:10,740 org.springframework.web.servlet.FrameworkServlet initServletBean

这中间居然耗费了将近1.2秒,通过开启日志debug,发现主要的耗时在 WebXml.merge 方法上。原因是servlet3引入了web模块化配置,对原先的web.xml可以由多个“片段”组成,这些片段使用web-fragment.xml来描述,可以对一组servlet/Filter/Listener + web-fragment.xml 打成一个jar,即一个web模块。

这种做法带来一定灵活性,但要求应用在启动时,必须对WEB-INF/lib下的jar,以及其它路径下classloader可访问的jar(这部分可配置,默认包含)进行检查,合并web-fragment.xml片段。

Tomcat对jar中的web-fragment.xml的扫描主要通过JarScanner实现的,它也提供了配置来忽略哪些jar文件;在conf/catalina.properties里定义了tomcat.util.scan.DefaultJarScanner.jarsToSkip对哪些jar文件忽略。

使用spring-mvc框架的应用,依赖了一堆spring的jar,而这些jar没有在默认的忽略列表里,在扫描和合并web-fragment.xml的过程中会比较耗时。

scala类型系统:21) type specialization与类爆炸

Type Specialization的paper,这里也已经有翻译了。简单的说,就是出于性能考虑,避免基础类型的装箱拆箱,为基础类型保留了特定的实现。

class V[@specialized T]{
    var i:T = _
}

上面用了specialized注释,除了定义一个泛型的V[A],之外,编译器还会额外生成9个特定的类型:

% scalac V.scala && ll
-rw-r--r--  1 hongjiang  wheel  1060 11  5 16:07 V$mcB$sp.class
-rw-r--r--  1 hongjiang  wheel  1070 11  5 16:07 V$mcC$sp.class
-rw-r--r--  1 hongjiang  wheel  1066 11  5 16:07 V$mcD$sp.class
-rw-r--r--  1 hongjiang  wheel  1063 11  5 16:07 V$mcF$sp.class
-rw-r--r--  1 hongjiang  wheel  1065 11  5 16:07 V$mcI$sp.class
-rw-r--r--  1 hongjiang  wheel  1060 11  5 16:07 V$mcJ$sp.class
-rw-r--r--  1 hongjiang  wheel  1063 11  5 16:07 V$mcS$sp.class
-rw-r--r--  1 hongjiang  wheel  1032 11  5 16:07 V$mcV$sp.class
-rw-r--r--  1 hongjiang  wheel  1063 11  5 16:07 V$mcZ$sp.class
-rw-r--r--  1 hongjiang  wheel  3549 11  5 16:07 V.class
-rw-r--r--  1 hongjiang  wheel    41 11  5 16:07 V.scala

hongjiang@whj-mbp /tmp/dd % javap V\$mcD\$sp     
Compiled from "V.scala"
public class V$mcD$sp extends V{
    public double i$mcD$sp;
    public double i$mcD$sp();
    public double i();              // 这个是针对double类型的
    public void i$mcD$sp_$eq(double);
    public void i_$eq(double);
    public boolean specInstance$();
    public void i_$eq(java.lang.Object);
    public java.lang.Object i();
    public V$mcD$sp();
}

从上面看到,哪些匿名类的类名中的:B,C,D,F,I,J,S,V,Z,分别对应 byte,char,double,float,int,long,short,void(scala里的Unit), boolean

在类型参数比较多的情况下,specialization会产生类爆炸的情况,参考stackoverflow上的一个例子

class Huge[@specialized A, @specialized B, @specialized C](
  val a: A, val b: B, val c: C
) {} // 730 files, 2.9 MB

上面的类产生了730个文件:9x9x9+1。之前在模拟perm gen的oom时,用到过这个特性。

//2012.5.30
在REPL下,模拟perm gen的oom案例:

虽然perm gen确实在不断增加,并且可能会OOM(如果perm gen设置比较小的话),但通过jconsole的类加载来看并非把这些定义的class都load了;对比了前后的class load

之前:3797 个class被load

运行一次:

class Test[@specialized A, @specialized B, @specialized C, @specialized D]

之后:4180 ,增加了383个而不是 9x9x9x9=6561个 why?

通过jvisualvm工具dump了前后的内存对比,scala.tools.nsc.io.VirtualFile 实例数从2增加到了 6573,增长了 6571 个,并且每运行一次都会增加 6571个,比6561多出10个

继续测试

class Test[@specialized A] 

也是会使 VirtualFile 新增 19个而非9个,另外多出来的10个实例还没有清楚是什么。

classloader问题:import my.package._ 是否会load该包下所有的class?

在scalal REPL下做的实验

scala > import java.util._

通过jconsole观察确实新load了98个class(java.util包下的所有的类)

准备了一个 whj.jar 其package为a,里面有1000个class

scala > import a._

却发现新增只有1,2百,而非全部1000个。不清楚是jvm还是scala对class太多的情况做了处理?