IncompatibleClassChangeError при инструментировании запуска приложения SpringBoot с помощью Byte Buddy

Я хотел бы представить Byte Buddy моей компании, и я подготовил демо для своих коллег. Поскольку мы часто используем Spring, я подумал, что лучшим примером будет инструментарий приложения SpringBoot. Я решил добавить логи к методам RestController.

Инструментированное приложение представляет собой простой пример SpringBoot Hello World:

@RestController
public class HelloController {
  private static final String template = "Hello, %s!";

  @RequestMapping("/hello")
  public String greeting(
        @RequestParam(value = "name", defaultValue = "World") String name) {
      return String.format(template, name);
  }

  @RequestMapping("/browser")
  public String showUserAgent(HttpServletRequest request) {
      return request.getHeader("user-agent");
  }
}

А вот и мой агент Байт Бадди:

public class LoggingAgent {
    public static void premain(String agentArguments,
            Instrumentation instrumentation) {
        install(instrumentation);
    }

    public static void agentmain(String agentArguments,
            Instrumentation instrumentation) {
        install(instrumentation);
    }

    private static void install(Instrumentation instrumentation) {
        createAgent(RestController.class, "greeting")
                .installOn(instrumentation);
    }

    private static AgentBuilder createAgent(
            Class<? extends Annotation> annotationType, String methodName) {
        return new AgentBuilder.Default().type(
                ElementMatchers.isAnnotatedWith(annotationType)).transform(
                new AgentBuilder.Transformer() {
                    @Override
                    public DynamicType.Builder<?> transform(
                            DynamicType.Builder<?> builder,
                            TypeDescription typeDescription,
                            ClassLoader classLoader) {
                        return builder
                                .method(ElementMatchers.named(methodName))
                                .intercept(
                                        MethodDelegation
                                                .to(LoggingInterceptor.class)
                                                .andThen(
                                                        SuperMethodCall.INSTANCE));
                    }
                });
    }
}

Выполнение метода журналов перехватчиков:

public static void intercept(@AllArguments Object[] allArguments,
        @Origin Method method) {
    Logger logger = LoggerFactory.getLogger(method.getDeclaringClass());
    logger.info("Method {} of class {} called", method.getName(), method
            .getDeclaringClass().getSimpleName());

    for (Object argument : allArguments) {
        logger.info("Method {}, parameter type {}, value={}",
                method.getName(), argument.getClass().getSimpleName(),
                argument.toString());
    }
}

При выполнении с параметром -javaagent этот пример работает хорошо. Однако, когда я пытаюсь загрузить агент на работающей JVM с Attach API:

VirtualMachine vm = VirtualMachine.attach(args[0]);
vm.loadAgent(args[1]);
vm.detach();

У меня есть следующее исключение при первой попытке входа в систему:

Exception in thread "ContainerBackgroundProcessor[StandardEngine[Tomcat]]" java.lang.IncompatibleClassChangeError: Class ch.qos.logback.classic.spi.ThrowableProxy does not implement the requested interface ch.qos.logback.classic.spi.IThrowableProxy
    at ch.qos.logback.classic.pattern.ThrowableProxyConverter.subjoinExceptionMessage(ThrowableProxyConverter.java:180)
    at ch.qos.logback.classic.pattern.ThrowableProxyConverter.subjoinFirstLine(ThrowableProxyConverter.java:176)
    at ch.qos.logback.classic.pattern.ThrowableProxyConverter.recursiveAppend(ThrowableProxyConverter.java:159)
    at ch.qos.logback.classic.pattern.ThrowableProxyConverter.throwableProxyToString(ThrowableProxyConverter.java:151)
    at org.springframework.boot.logging.logback.ExtendedWhitespaceThrowableProxyConverter.throwableProxyToString(ExtendedWhitespaceThrowableProxyConverter.java:35)
    at ch.qos.logback.classic.pattern.ThrowableProxyConverter.convert(ThrowableProxyConverter.java:145)
    at ch.qos.logback.classic.pattern.ThrowableProxyConverter.convert(ThrowableProxyConverter.java:1)
    at ch.qos.logback.core.pattern.FormattingConverter.write(FormattingConverter.java:36)
    at ch.qos.logback.core.pattern.PatternLayoutBase.writeLoopOnConverters(PatternLayoutBase.java:114)
    at ch.qos.logback.classic.PatternLayout.doLayout(PatternLayout.java:141)
    at ch.qos.logback.classic.PatternLayout.doLayout(PatternLayout.java:1)
    at ch.qos.logback.core.encoder.LayoutWrappingEncoder.doEncode(LayoutWrappingEncoder.java:130)
    at ch.qos.logback.core.OutputStreamAppender.writeOut(OutputStreamAppender.java:187)
    at ch.qos.logback.core.OutputStreamAppender.subAppend(OutputStreamAppender.java:212)
    at ch.qos.logback.core.OutputStreamAppender.append(OutputStreamAppender.java:100)
    at ch.qos.logback.core.UnsynchronizedAppenderBase.doAppend(UnsynchronizedAppenderBase.java:84)
    at ch.qos.logback.core.spi.AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachableImpl.java:48)
    at ch.qos.logback.classic.Logger.appendLoopOnAppenders(Logger.java:270)
    at ch.qos.logback.classic.Logger.callAppenders(Logger.java:257)
    at ch.qos.logback.classic.Logger.buildLoggingEventAndAppend(Logger.java:421)
    at ch.qos.logback.classic.Logger.filterAndLog_0_Or3Plus(Logger.java:383)
    at ch.qos.logback.classic.Logger.log(Logger.java:765)
    at org.slf4j.bridge.SLF4JBridgeHandler.callLocationAwareLogger(SLF4JBridgeHandler.java:221)
    at org.slf4j.bridge.SLF4JBridgeHandler.publish(SLF4JBridgeHandler.java:303)
    at java.util.logging.Logger.log(Unknown Source)
    at java.util.logging.Logger.doLog(Unknown Source)
    at java.util.logging.Logger.logp(Unknown Source)
    at org.apache.juli.logging.DirectJDKLog.log(DirectJDKLog.java:181)
    at org.apache.juli.logging.DirectJDKLog.error(DirectJDKLog.java:147)
    at org.apache.catalina.core.ContainerBase$ContainerBackgroundProcessor.run(ContainerBase.java:1352)
    at java.lang.Thread.run(Unknown Source)

Я запускаю пример на 64-битном HotSpot с Java8:

java version "1.8.0_112"
Java(TM) SE Runtime Environment (build 1.8.0_112-b15)
Java HotSpot(TM) 64-Bit Server VM (build 25.112-b15, mixed mode)

Версия Byte Buddy - 1.4.32. Вот конфигурация агента Maven:

<project xmlns="http://maven.apache.org/POM/4.0.0" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:schemaLocation="http://maven.apache.org/POM/4.0.0 http://maven.apache.org/xsd/maven-4.0.0.xsd">
<modelVersion>4.0.0</modelVersion>

<groupId>pl.halun.demo.bytebuddy</groupId>
<artifactId>byte-buddy-agent-demo</artifactId>
<version>1.0</version>

<properties>
    <jdk.version>1.8</jdk.version>
    <project.build.sourceEncoding>UTF-8</project.build.sourceEncoding>
</properties>

<parent>
    <groupId>org.springframework.boot</groupId>
    <artifactId>spring-boot-starter-parent</artifactId>
    <version>1.4.1.RELEASE</version>
</parent>

<dependencies>
    <dependency>
        <groupId>net.bytebuddy</groupId>
        <artifactId>byte-buddy</artifactId>
        <version>1.4.32</version>
    </dependency>
    <dependency>
        <groupId>ch.qos.logback</groupId>
        <artifactId>logback-classic</artifactId>
    </dependency>
    <dependency>
        <groupId>org.springframework.boot</groupId>
        <artifactId>spring-boot-starter-web</artifactId>
    </dependency>
    <dependency>
        <groupId>javax.servlet</groupId>
        <artifactId>javax.servlet-api</artifactId>
        <scope>provided</scope>
    </dependency>
</dependencies>
<build>
    <plugins>
        <plugin>
            <groupId>org.apache.maven.plugins</groupId>
            <artifactId>maven-compiler-plugin</artifactId>
            <configuration>
                <source>${jdk.version}</source>
                <target>${jdk.version}</target>
            </configuration>
        </plugin>
        <plugin>
            <groupId>org.apache.maven.plugins</groupId>
            <artifactId>maven-assembly-plugin</artifactId>
            <configuration>
                <descriptorRefs>
                    <descriptorRef>jar-with-dependencies</descriptorRef>
                </descriptorRefs>
                <finalName>${project.artifactId}-${project.version}-full</finalName>
                <appendAssemblyId>false</appendAssemblyId>
                <archive>
                    <manifestEntries>
                        <Premain-Class>pl.halun.demo.bytebuddy.logging.LoggingAgent</Premain-Class>
                        <Agent-Class>pl.halun.demo.bytebuddy.logging.LoggingAgent</Agent-Class>
                        <Can-Redefine-Classes>true</Can-Redefine-Classes>
                        <Can-Retransform-Classes>true</Can-Retransform-Classes>
                        <Can-Set-Native-Method-Prefix>true</Can-Set-Native-Method-Prefix>
                    </manifestEntries>
                </archive>
            </configuration>
            <executions>
                <execution>
                    <id>assemble-all</id>
                    <phase>package</phase>
                    <goals>
                        <goal>single</goal>
                    </goals>
                </execution>
            </executions>
        </plugin>
    </plugins>
</build>

А вот файл pom для инструментированного приложения:

<?xml version="1.0" encoding="UTF-8"?>
<project xmlns="http://maven.apache.org/POM/4.0.0" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
xsi:schemaLocation="http://maven.apache.org/POM/4.0.0 http://maven.apache.org/xsd/maven-4.0.0.xsd">
<modelVersion>4.0.0</modelVersion>

<groupId>pl.halun.demo.bytebuddy.instrumented.app</groupId>
<artifactId>byte-buddy-agent-demo-instrumented-app</artifactId>
<version>1.0</version>
<packaging>jar</packaging>

<parent>
    <groupId>org.springframework.boot</groupId>
    <artifactId>spring-boot-starter-parent</artifactId>
    <version>1.4.1.RELEASE</version>
</parent>

<dependencies>
    <dependency>
        <groupId>org.springframework.boot</groupId>
        <artifactId>spring-boot-starter-web</artifactId>
    </dependency>
</dependencies>

<properties>
    <java.version>1.8</java.version>
</properties>

<build>
    <plugins>
        <plugin>
            <groupId>org.springframework.boot</groupId>
            <artifactId>spring-boot-maven-plugin</artifactId>
        </plugin>
    </plugins>
</build>

<repositories>
    <repository>
        <id>spring-releases</id>
        <url>https://repo.spring.io/libs-release</url>
    </repository>
</repositories>
<pluginRepositories>
    <pluginRepository>
        <id>spring-releases</id>
        <url>https://repo.spring.io/libs-release</url>
    </pluginRepository>
</pluginRepositories>

С моей точки зрения, это очень ценная возможность добавить логи на работающем сервере, и я не хочу терять эту часть демо. Я пытался экспериментировать с различными стратегиями переопределения, но до сих пор, похоже, ничего не получалось.

1 ответ

Решение

То, что вы наблюдаете, является классической версией конфликта, я думаю. Spring Boot, скорее всего, поставляется с версией ThrowableProxy это несовместимо с версией, добавленной с помощью агента Java. При загрузке агента Java во время выполнения версия Spring уже загружена, тогда как вложение при запуске предшествует связанной с агентом версией в пути к классам, куда загружается версия вашего агента.

Java-агенты обычно добавляются в путь к классам. Здесь также находится ваше загрузочное приложение Spring. Вы должны убедиться, что агент Java не содержит зависимостей, несовместимых с зависимостями вашего приложения, или вам нужно затенять все зависимости, чтобы избежать таких конфликтов.

Однако есть еще одна проблема: при написании Java-агента, подключенного во время выполнения, вы встречаете дополнительные ограничения на большинстве JVM, где в HotSpot вам не разрешено изменять формат файла класса для любого уже загруженного класса. Существует также вероятность того, что ваш класс уже загружен там, где в данный момент не будет никакого эффекта, поскольку вы не включаете ретрансформацию.

Агент с поддержкой времени выполнения должен будет использовать Advice компонент, который вставляет код в целевой код, а не используя классическую модель делегирования:

class MyAdvice {
  @Advice.OnMethodEnter
  static void intercept(@Advice.BoxedArguments Object[] allArguments,
                        @Advice.Origin Method method) {
    Logger logger = LoggerFactory.getLogger(method.getDeclaringClass());
    logger.info("Method {} of class {} called", method.getName(), method
                  .getDeclaringClass().getSimpleName());

    for (Object argument : allArguments) {
      logger.info("Method {}, parameter type {}, value={}",
               method.getName(), argument.getClass().getSimpleName(),
               argument.toString());
    }
  }
}

Вы можете использовать вышеупомянутый класс совета, зарегистрировав его как посетителя. Такие посетители относятся только к объявленным методам, то есть не к унаследованным методам, и включают свой код в существующие методы. Таким образом, запись в журнал не будет видна в стеке вызовов, и также станет законным преобразование уже загруженных классов:

new AgentBuilder.Default()
  .disableClassFormatChanges()
  .with(AgentBuilder.RedefinitionStrategy.RETRANSFORMATION)
  .type(isAnnotatedWith(annotationType))
  .transform(new AgentBuilder.Transformer() {
      @Override
      public DynamicType.Builder<?> transform(
          DynamicType.Builder<?> builder,
          TypeDescription typeDescription,
          ClassLoader classLoader) {
        return builder.visit(Advice.to(MyAdvice.class).on(named(methodName)));
      }
   });

Что касается вложения, посмотрите в byte-buddy-agent проект, который позволяет позвонить:

ByteBuddyAgent.attach(agentJar, processId);

Вышеупомянутый помощник поддерживает другие виртуальные машины, где API вложения часто находится в другом пространстве имен.

Обновление: вот проблема Spring Boot. Spring Boot создает пользовательские загрузчики классов, у которых системный загрузчик классов (путь к классам) является родительским. Эти загрузчики классов сначала рассматривают классы из системного загрузчика классов. При добавлении агента все загрузочное приложение Spring находится как в загрузчике классов, так и в этих загрузчиках дочерних классов. Класс как IThrowableProxy теперь существует дважды в двух загрузчиках классов, но не считается равным JVM. В зависимости от состояния виртуальной машины некоторые классы могут быть уже связаны с исходным IThrowableProxy тогда как другие классы загружаются после того, как агент был присоединен и связан с новым IThrowableProxy от агента. Оба класса не равны, и ошибка, которую вы видите, выдается, когда виртуальная машина жалуется, что класс не реализует правильный IThrowableProxy (но предыдущий). Если агент подключен при запуске, эта проблема не существует как путь к классу IThrowableProxy всегда загружен

Исправить эту непростую ошибку, в конце концов, Byte Buddy не может помочь вам с такими проблемами пути к классам, и Spring Boot совершенно свободно интерпретирует контракт загрузчика классов. Самый простой способ - не использовать типы Spring Boot в вашем агенте. Вы все еще можете сопоставить аннотацию, например, с

isAnnotatedWith(named("org.springframework.web.bind.annotation.RestController"))

Вопрос в том, как вы можете общаться с Spring Boot. Одним из возможных решений будет добавление всех общих классов в путь к классам при запуске. Как правило, я избегаю использования общих классов, но использую их только в Advice классы, где код встроен в загрузчик классов целевого приложения. Просто установите зависимость Spring Boot в предоставленную область, сам код совета никогда не выполняется.

Другие вопросы по тегам