search

raphw / byte-buddy

Runtime code generation for the Java virtual machine.
https://bytebuddy.net
Apache License 2.0
6.31k stars 807 forks source link

tomcat throws NoClassDefFoundError when running with agent #1108

Closed WestFarmer closed 3 years ago

WestFarmer commented 3 years ago

bytebuddy version 1.11.15 tomcat version : 8.5.64 JAVA version 1.8.0_271

07-Sep-2021 15:25:24.357 严重 [localhost-startStop-1] org.apache.catalina.core.ContainerBase.addChildInternal ContainerBase.addChild: start: 
    org.apache.catalina.LifecycleException: 无法启动组件[StandardEngine[Catalina].StandardHost[localhost].StandardContext[/examples]]
        at org.apache.catalina.util.LifecycleBase.handleSubClassException(LifecycleBase.java:440)
        at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:198)
        at org.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase.java:743)
        at org.apache.catalina.core.ContainerBase.addChild(ContainerBase.java:719)
        at org.apache.catalina.core.StandardHost.addChild(StandardHost.java:705)
        at org.apache.catalina.startup.HostConfig.deployDirectory(HostConfig.java:1176)
        at org.apache.catalina.startup.HostConfig$DeployDirectory.run(HostConfig.java:1917)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
        at java.util.concurrent.FutureTask.run(FutureTask.java:266)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
        at java.lang.Thread.run(Thread.java:748)
    Caused by: java.lang.NoClassDefFoundError: javax/servlet/ServletContainerInitializer
        at java.lang.ClassLoader.defineClass1(Native Method)
        at java.lang.ClassLoader.defineClass(ClassLoader.java:756)
        at java.security.SecureClassLoader.defineClass(SecureClassLoader.java:142)
        at java.net.URLClassLoader.defineClass(URLClassLoader.java:468)
        at java.net.URLClassLoader.access$100(URLClassLoader.java:74)
        at java.net.URLClassLoader$1.run(URLClassLoader.java:369)
        at java.net.URLClassLoader$1.run(URLClassLoader.java:363)
        at java.security.AccessController.doPrivileged(Native Method)
        at java.net.URLClassLoader.findClass(URLClassLoader.java:362)
        at java.lang.ClassLoader.loadClass(ClassLoader.java:418)
        at sun.misc.Launcher$AppClassLoader.loadClass(Launcher.java:355)
        at java.lang.ClassLoader.loadClass(ClassLoader.java:405)
        at java.lang.ClassLoader.loadClass(ClassLoader.java:351)
        at java.lang.Class.forName0(Native Method)
        at java.lang.Class.forName(Class.java:348)
        at org.apache.catalina.loader.WebappClassLoaderBase.loadClass(WebappClassLoaderBase.java:1358)
        at org.apache.catalina.loader.WebappClassLoaderBase.loadClass(WebappClassLoaderBase.java:1195)
        at java.lang.Class.forName0(Native Method)
        at java.lang.Class.forName(Class.java:348)
        at org.apache.catalina.startup.WebappServiceLoader.loadServices(WebappServiceLoader.java:232)
        at org.apache.catalina.startup.WebappServiceLoader.load(WebappServiceLoader.java:203)
        at org.apache.catalina.startup.ContextConfig.processServletContainerInitializers(ContextConfig.java:1587)
        at org.apache.catalina.startup.ContextConfig.webConfig(ContextConfig.java:1088)
        at org.apache.catalina.startup.ContextConfig.configureStart(ContextConfig.java:779)
        at org.apache.catalina.startup.ContextConfig.lifecycleEvent(ContextConfig.java:299)
        at org.apache.catalina.util.LifecycleBase.fireLifecycleEvent(LifecycleBase.java:123)
        at org.apache.catalina.core.StandardContext.startInternal(StandardContext.java:5069)
        at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:183)
        ... 10 more
    Caused by: java.lang.ClassNotFoundException: javax.servlet.ServletContainerInitializer
        at java.net.URLClassLoader.findClass(URLClassLoader.java:382)
        at java.lang.ClassLoader.loadClass(ClassLoader.java:418)
        at sun.misc.Launcher$AppClassLoader.loadClass(Launcher.java:355)
        at java.lang.ClassLoader.loadClass(ClassLoader.java:351)
        ... 38 more

running with:

-javaagent:jdbcld.jar=/export/logs/jdbcld,DEBUG,org.apache.tomcat.dbcp.dbcp2.DelegatingConnection

my agent class:

package org.wxt.xtools.agents;

import java.io.ByteArrayOutputStream;
import java.io.IOException;
import java.io.InputStream;
import java.io.OutputStream;
import java.lang.instrument.Instrumentation;
import java.net.InetSocketAddress;
import java.util.Map;
import java.util.concurrent.ExecutorService;
import java.util.concurrent.Executors;
import java.util.concurrent.ThreadFactory;
import java.util.concurrent.TimeUnit;

import org.slf4j.LoggerFactory;
import org.wxt.xtools.agents.utils.StringUtils;

import com.google.gson.Gson;
import com.sun.net.httpserver.HttpExchange;
import com.sun.net.httpserver.HttpHandler;
import com.sun.net.httpserver.HttpServer;

import ch.qos.logback.classic.Level;
import ch.qos.logback.classic.Logger;
import ch.qos.logback.classic.LoggerContext;
import ch.qos.logback.classic.encoder.PatternLayoutEncoder;
import ch.qos.logback.classic.spi.ILoggingEvent;
import ch.qos.logback.core.FileAppender;
import net.bytebuddy.agent.builder.AgentBuilder;
import net.bytebuddy.asm.Advice;
import net.bytebuddy.description.type.TypeDescription;
import net.bytebuddy.dynamic.DynamicType;
import net.bytebuddy.implementation.MethodDelegation;
import static net.bytebuddy.matcher.ElementMatchers.*;
import net.bytebuddy.utility.JavaModule;

/**
 * A agent for helping detecting JDBC connection leak in java. You can run this with below JVM options: <br />
 * <span style="padding-left:2em;color:blue">-javaagent:/path/to/agent.jar:agentArgs</span> <br />
 * agentArgs must follow pattern of: <br />
 * <span style="padding-left:2em;color:red">log_dir,log_level,connection_class</span><br />
 * <ul>
 *  <li>log_dir: where to output agent logs, if no lead '/' specified, will be a relative path to targeting JVM's working directory.</li>
 * <li>log_level: logging level for this agent, can be ALL | TRACE | DEBUG | INFO | WARN | ERROR | OFF, default to DEBUG.</li>
 * <li>connection_class: target class to intercept, usually should be a wrapping class provide by connection pool libraries.</li>
 * </ul>
 * @author ggfan
 *
 */
public class JDBCLeakDetector {

    protected static Logger log;

    public static void premain(String agentArgs, Instrumentation inst) throws InstantiationException, IOException {
        System.out.println("========================== JDBC Leak Detector Agent ==========================");

        String[] args = agentArgs.split(",");

        LoggerContext logCtx = (LoggerContext) LoggerFactory.getILoggerFactory();

        PatternLayoutEncoder logEncoder = new PatternLayoutEncoder();
        logEncoder.setContext(logCtx);
        logEncoder.setPattern("%-12date{YYYY-MM-dd HH:mm:ss.SSS} %-5level - %msg%n");
        logEncoder.start();
        FileAppender<ILoggingEvent> logFileAppender = new FileAppender<ILoggingEvent>();
        logFileAppender.setContext(logCtx);
        logFileAppender.setName("logFile");
        logFileAppender.setEncoder(logEncoder);
        logFileAppender.setAppend(false);
        logFileAppender.setFile(args[0] + "/jdbcld.log");
        logFileAppender.start();
        log = logCtx.getLogger("JDBCLeakDetector");
        log.setAdditive(false);
        log.setLevel(Level.toLevel(args[1]));
        log.addAppender(logFileAppender);

        HttpServer server = HttpServer.create(new InetSocketAddress(8000), 0);

        server.createContext("/report", new ReportHandler());
        server.createContext("/data", new DataHandler());
        server.createContext("/stack", new StackHandler());
        ExecutorService es = Executors.newCachedThreadPool(new ThreadFactory() {
            int count = 0;
            @Override
            public Thread newThread(Runnable r) {
                Thread t = new Thread(r);
                t.setDaemon(true);
                t.setName("JDBCLD-HTTP-SERVER" + count++);
                return t;
            }

        });
        server.setExecutor(es);
        server.start();

        // how to properly close ?
        Runtime.getRuntime().addShutdownHook(new Thread() {
            @Override
            public void run() {
                server.stop(5);
                log.info("internal httpserver has been closed.");
                es.shutdown();
                try {
                    if (!es.awaitTermination(60, TimeUnit.SECONDS)) {
                        log.warn("executor service of internal httpserver not closing in 60 seconds");
                        es.shutdownNow();
                        if (!es.awaitTermination(60, TimeUnit.SECONDS))
                            log.error("executor service of internal httpserver not closing in 120 seconds, give up");
                    }else {
                        log.info("executor service of internal httpserver closed.");
                    }
                } catch (InterruptedException ie) {
                    log.warn("thread interrupted, shutdown executor service of internal httpserver");
                    es.shutdownNow();
                    Thread.currentThread().interrupt();
                }
            }
        });

        AgentBuilder.Transformer ct = new AgentBuilder.Transformer() {
            @Override
            public DynamicType.Builder<?> transform(DynamicType.Builder<?> builder, TypeDescription typeDescription,
                    ClassLoader classLoader, JavaModule javaModule) {
                return builder.visit(Advice.to(ConnectInterceptor.class).on(isConstructor()));
            }
        };

        AgentBuilder.Transformer transformer = new AgentBuilder.Transformer() {
            @Override
            public DynamicType.Builder<?> transform(DynamicType.Builder<?> builder, TypeDescription typeDescription,
                    ClassLoader classLoader, JavaModule javaModule) {
                return builder.method(not(isAbstract()).and(not(named("hashCode"))).and(isPublic()))
                        .intercept(MethodDelegation.to(ConnectInterceptor.class));
            }
        };

        AgentBuilder.Listener listener = new AgentBuilder.Listener.WithErrorsOnly(
                new AgentBuilder.Listener.StreamWriting(System.out));

        new AgentBuilder.Default().type(named(args[2])).transform(ct)
                .transform(transformer).with(listener).installOn(inst);

    }

    static class ReportHandler implements HttpHandler {
        @Override
        public void handle(HttpExchange t) throws IOException {
            // RuntimeException will be ignored silently, but we want to know them
            try {
                t.getResponseHeaders().set("Content-Type", "text/html; charset=UTF-8");
                OutputStream os = t.getResponseBody();
                InputStream is = JDBCLeakDetector.class.getResourceAsStream("/report.html");
                ByteArrayOutputStream tmpos = new ByteArrayOutputStream();
                int nRead = 0, total = 0;
                byte[] data = new byte[4096];
                while ((nRead = is.read(data, 0, data.length)) != -1) {
                    total += nRead;
                    tmpos.write(data, 0, nRead);
                }
                tmpos.flush();
                t.getResponseHeaders().set("Content-Length", "" + total);
                t.sendResponseHeaders(200, total);
                os.write(tmpos.toByteArray());
                os.flush();
                os.close();
                tmpos.close();
            } catch (Exception e) {
                e.printStackTrace();
                throw e;
            }
        }
    }

    static class DataHandler implements HttpHandler {
        @Override
        public void handle(HttpExchange t) throws IOException {
            try {
                OutputStream os = t.getResponseBody();
                t.getResponseHeaders().set("Content-Type", "applcation/json");
                Gson gson = new Gson();
                String s = gson.toJson(ConnectInterceptor.getInfo());
                t.getResponseHeaders().set("Content-Length", "" + s.getBytes().length);
                t.sendResponseHeaders(200, s.getBytes().length);
                os.write(s.getBytes());
                os.close();
            } catch (Exception e) {
                e.printStackTrace();
                throw e;
            }
        }
    }

    static class StackHandler implements HttpHandler {
        @Override
        public void handle(HttpExchange t) throws IOException {
            try {
                Map<String, String> paras = StringUtils.queryToMap(t.getRequestURI().getQuery());
                if(paras != null) {
                    String s = paras.get("shash");
                    if(s != null) {
                        log.debug("loading stack trace for {}", s);
                        String stack = ConnectInterceptor.getStack(s);
                        t.sendResponseHeaders(200, stack.getBytes().length);
                        t.getResponseBody().write(stack.getBytes());
                        t.getResponseBody().flush();
                        t.getRequestBody().close();
                    }
                }
            } catch (Exception e) {
                e.printStackTrace();
                throw e;
            }
        }
    }

}
raphw commented 3 years ago

Your Java agent is loaded by the system class loader by default (sun.misc.Launcher$AppClassLoade) which might be a different class loader than that loading javax.servlet.ServletContainerInitializer. As a result, you get this exception. The instrumented code will delegate via MethodDelegation to your ConnectInterceptor which cannot see the type. Rather use Advice which inlines code such that it's on the same loader.

When communicating back to your agent, you still need to make sure that your agent code can be seen by the instrumented code. The only reliable approach to this is to inject some code into the boot loader.

WestFarmer commented 3 years ago

@raphw sorry for late reply, can you enlight me with some code

Rather use Advice which inlines code such that it's on the same loader

WestFarmer commented 3 years ago

turn on tomcat class loading log, I see this:

13-Sep-2021 17:18:54.028 详细 [localhost-startStop-1] org.apache.catalina.loader.WebappClassLoaderBase.findResources     findResources(META-INF/services/javax.servlet.ServletContainerInitializer)
13-Sep-2021 17:18:54.030 详细 [localhost-startStop-1] org.apache.catalina.loader.WebappClassLoaderBase.loadClass loadClass(ch.qos.logback.classic.servlet.LogbackServletContainerInitializer, false)
13-Sep-2021 17:18:54.030 详细 [localhost-startStop-1] org.apache.catalina.loader.WebappClassLoaderBase.loadClass   Delegating to parent classloader1 java.net.URLClassLoader@5579bb86

my agent is using logback which has a META-INF/services/javax.servlet.ServletContainerInitializer, this cause tomcat to load javax.servlet.ServletContainerInitializer

raphw commented 3 years ago

Within your advice class, you can refer to the classes that you'd expect in your application such as Servlet. But you cannot guarantee that this class is visible outside of your advice. If you wanted to extract information from your advice, you would need to do so in form of types that are available outside of the class loader, such as String. If you wanted to inject utility classes, Byte Buddy offers ClassInjector to add classes to the appropriate class loader.

WestFarmer commented 3 years ago

@raphw I can't find any example of ClassInjector in bytebuddy's documentation, can you share some example code? And my agent is using slf4j which is confilcting with application dependencies, what's the common way to solve such issues? you talk at another level, I can't catch you... sorry.

raphw commented 3 years ago

Have a look at the unit tests.