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的过程中会比较耗时。