장장 10시간의 트러블슈팅 과정을 서술하였다.
개요
1. premain에서 내가 만든 ClassTransFormer 구현체를 생성하고, @Transform에서 이 Agent가 설치된 서버의 Class를 읽어오는 목표를 세웠다.
처음에 확인 차 모든 'transform'마다 print를 통해 className을 출력하게 하였다.
2. 이 서버는 Springboot인데, src/main/java 내부의 모든 Class가 스캔되지 않는 문제가 발생했다.
spring 어노테이션이 달리지 않은 일반 Class 파일이 1의 과정에서 출력되지 않는다.
3. 하지만 해당 클래스 파일에 @Configuration의 어노테이션을 붙이면 1의 과정에서 정상적으로 출력된다. 그러나 이렇게 진행할 경우 서버 빌드 과정에서 에러가 발생한다.
stackoverflow에 글을 올려보긴 했는데, 그렇게 좋은 답변이 달리지는 않았다.
(Instrument API, Agent)My ClassFileTransformer's transform method fails to recognize a specific class in Springboot
Background: Hello, I am developing an Agent through bytecode manipulation. Using the Instrument API, I aimed to read all classes before class loading by utilizing premain - ClassFileTransformer. My...
stackoverflow.com
해결 과정
원인 추측
클래스 로딩 시점: Spring Boot는 내부적으로 커스텀 클래스 로더를 사용할 수 있다.
이 커스텀 클래스 로더가 일부 클래스를 로딩하는 시점이 Java Agent가 활성화되는 시점보다 늦을 경우, 해당 클래스들은 변환 과정에서 누락될 수 있다. 이는 특히 @Configuration과 같은 어노테이션이 달린 클래스가 Spring Boot에 의해 특별히 처리되는 경우 더욱 명확하게 발생한다.
이를 위해 디버깅용 코드를 작성하여 결과를 확인하였다.
package org.agent.util.transform;
import lombok.extern.slf4j.Slf4j;
import org.agent.util.asm.AsmCodeFactory;
import java.lang.instrument.ClassFileTransformer;
import java.security.ProtectionDomain;
/**
* Springboot Class 누락 버그 테스트용
*/
@Slf4j
public class DebugTransformer implements ClassFileTransformer {
@Override
public byte[] transform(ClassLoader loader, String className, Class<?> classBeingRedefined,
ProtectionDomain protectionDomain, byte[] classfileBuffer) {
if(className.contains("dummy")) {
long currentTime = System.currentTimeMillis();
System.out.println("\n");
System.out.println("Class Name: " + className.replace("/", "."));
System.out.println("Timestamp: " + currentTime);
if (loader != null) {
System.out.println("Class Loader: " + loader.getClass().getName());
} else {
System.out.println("Class Loader: Bootstrap Loader");
}
return classfileBuffer; // 변환하지 않은 경우 null을 반환
}
return classfileBuffer;
}
}
로그 분석
로그를 보면, 클래스가 로드될 때 사용되는 클래스 로더는 RestartClassLoader인 것을 확인할 수 있다.
이는 Spring Boot의 개발자 도구(devtools) 모듈에 의해 제공되는 클래스 로더로, 어플리케이션을 재시작하지 않고도 클래스를 다시 로드할 수 있는 기능을 제공한다.
RestartClassLoader는 주로 개발 중에 사용되며, 변경된 클래스를 빠르게 재로드하기 위해 사용된다. 하지만 이 클래스 로더는 특정 조건에 따라 어떤 클래스는 로드하고 어떤 클래스는 로드하지 않을 수 있다는 정보를 확인할 수 있었다.
Build Gradle DevTool 제거
Loader는 변경되었지만, 여전히 값을 확인할 수 없다.
클래스 로드 확인
Instrumentation 인터페이스의 addTransformer 메소드에 canRetransform 플래그를 true로 설정하여, 이미 로드된 클래스도 변환할 수 있도록 하였다.
결과는 다음과 같았다. 그냥 Class 인식 자체를 하지 못하는 듯 하다.
Connected to the target VM, address: '127.0.0.1:49460', transport: 'socket'
/$$$$$$ /$$$$$$ /$$ /$$ /$$$$$$ /$$
/$$__ $$ /$$__ $$| $$$ /$$$ /$$__ $$ | $$
| $$ \ $$| $$ \__/| $$$$ /$$$$ | $$ \ $$ /$$$$$$ /$$$$$$ /$$$$$$$ /$$$$$$
| $$$$$$$$| $$$$$$ | $$ $$/$$ $$ | $$$$$$$$ /$$__ $$ /$$__ $$| $$__ $$|_ $$_/
| $$__ $$ \____ $$| $$ $$$| $$ | $$__ $$| $$ \ $$| $$$$$$$$| $$ \ $$ | $$
| $$ | $$ /$$ \ $$| $$\ $ | $$ | $$ | $$| $$ | $$| $$_____/| $$ | $$ | $$ /$$
| $$ | $$| $$$$$$/| $$ \/ | $$ | $$ | $$| $$$$$$$| $$$$$$$| $$ | $$ | $$$$/
|__/ |__/ \______/ |__/ |__/ |__/ |__/ \____ $$ \_______/|__/ |__/ \___/
/$$ \ $$
| $$$$$$/
\______/
nowTime : 2024-02-14T15:20:12.414801 my Agent has been invoked with args: null
15:20:12.604 [main] WARN org.agent.util.transform.Chap03Transformer -- [TRANSFORM] Find ClassName : dummy
15:20:12.626 [main] WARN org.agent.util.asm.AsmCodeFactory -- [Print]SetF 코드 출력 완료
Error: Unable to initialize main class com.dummy.jdbcserver.JdbcServerApplication
Caused by: java.lang.NoClassDefFoundError: com/dummy/jdbcserver/GetFSetF
Disconnected from the target VM, address: '127.0.0.1:49460', transport: 'socket'
Process finished with exit code 1
클래스 패스(classpath) 확인
-cp 또는 -classpath 옵션은 Java 명령을 실행할 때 클래스 파일들이 위치한 디렉토리를 Java 가상 머신(JVM)에 알려주는 역할을 한다.
이 옵션을 통해 JVM이 프로그램을 실행하는 데 필요한 클래스들을 찾을 수 있도록 할 수 있다.
run/debug configuration에서 서버 실행시 javaagent의 인수를 확인해보았다.
설정한 클래스 패스 옵션 -cp jdbcServer.main을 확인해봐야 할 것 같다.
jdbcServer.main은 IntelliJ IDEA에서 관리하는 모듈(내 파일 이름이 포함된) 이름이며, 실제 파일 시스템 경로는 jdbcServer/main이 아니라 IntelliJ IDEA가 자동으로 관리하는 빌드 디렉토리 내에 해당하는 경로일 것이다.
모듈
IntelliJ IDEA에서 모듈의 클래스패스는 일반적으로 다음과 같은 디렉토리를 포함한다.
- src/main/java: 소스 코드가 있는 디렉토리
- src/main/resources: 리소스 파일이 있는 디렉토리
- build/classes: 컴파일된 클래스 파일이 저장되는 곳
Project Structure의 Modules를 통해 내가 cp로 지정했던 jdbcServer.main을 확인하였다.
package까지는 보이는데, 실제 Class 파일이 보이지 않는다. 이것이 문제인 것 같다.
IntelliJ가 기대하는 경로에 클래스 파일이 실제로 존재하지 않는다면, 이는 빌드 프로세스가 예상대로 작동하지 않았거나, IntelliJ가 빌드 결과를 제대로 감지하지 못하는 것으로 추측된다.
하지만 결론적으로 이 문제는 아니었다.
어쨌든 실제 파일 경로에 .class 파일이 생겼으니까
프로젝트 파일 경로\build\classes\java\main\com\dummy\jdbcserver\example_asm\chap3 ..
이렇게 하위 폴더를 확인해볼것. "\build\classes" 하위 폴더의 .class파일을 참조할 것이다.
원점 : 왜 Class가 Context Scan, 혹은 다음 상황에서만 인식되는가?
package com.dummy.jdbcserver;
import com.dummy.jdbcserver.example_asm.chap3.GetFSetF;
import org.springframework.boot.SpringApplication;
import org.springframework.boot.autoconfigure.SpringBootApplication;
import org.springframework.scheduling.annotation.EnableScheduling;
@EnableScheduling
@SpringBootApplication
public class JdbcServerApplication {
public static void main(String[] args) {
GetFSetF getFSetF = new GetFSetF();
SpringApplication.run(JdbcServerApplication.class, args);
}
}
이렇게 객체 인스턴스를 메인에서 선언할 경우 transformer가 이를 인식할 수 있음을 확인할 수 있었다.
@Configuration 어노테이션이 클래스에 붙어있으면, 그 클래스는 스프링의 컴포넌트 스캔에 의해 자동으로 탐지되고 로드된다.
결국 이것의 공통점은 JVM이 premain에서 먼저 확인하는 것이 아니라, context scan 이후 transform 동작한다는 것이다.
원래는 Java Agent가 premain을 통해 초기화될 때, Agent는 JVM이 시작될 때부터 로드되는 모든 클래스에 대한 알림을 받는다.
= Agent가 스프링 어플리케이션의 초기화 이후에 설정되거나, 스프링의 컴포넌트 스캔이 완료된 후에 초기화되면, 일부 클래스는 Agent의 변환 과정을 놓칠 수 있다. 이 문제라고 확신한다.
Agent 초기화 시점 확인
Connected to the target VM, address: '127.0.0.1:51501', transport: 'socket'
/$$$$$$ /$$$$$$ /$$ /$$ /$$$$$$ /$$
/$$__ $$ /$$__ $$| $$$ /$$$ /$$__ $$ | $$
| $$ \ $$| $$ \__/| $$$$ /$$$$ | $$ \ $$ /$$$$$$ /$$$$$$ /$$$$$$$ /$$$$$$
| $$$$$$$$| $$$$$$ | $$ $$/$$ $$ | $$$$$$$$ /$$__ $$ /$$__ $$| $$__ $$|_ $$_/
| $$__ $$ \____ $$| $$ $$$| $$ | $$__ $$| $$ \ $$| $$$$$$$$| $$ \ $$ | $$
| $$ | $$ /$$ \ $$| $$\ $ | $$ | $$ | $$| $$ | $$| $$_____/| $$ | $$ | $$ /$$
| $$ | $$| $$$$$$/| $$ \/ | $$ | $$ | $$| $$$$$$$| $$$$$$$| $$ | $$ | $$$$/
|__/ |__/ \______/ |__/ |__/ |__/ |__/ \____ $$ \_______/|__/ |__/ \___/
/$$ \ $$
| $$$$$$/
\______/
nowTime : 2024-02-14T17:36:17.499529700 my Agent has been invoked with args: null
Class Name: com.dummy.jdbcserver.JdbcServerApplication
Timestamp: 1707899777662
Class Loader: jdk.internal.loader.ClassLoaders$AppClassLoader
====================================
Spring Application starting!!!!!!!
====================================
Class Name: com.dummy.jdbcserver.example_asm.chap3.GetFSetF
Timestamp: 1707899777664
Class Loader: jdk.internal.loader.ClassLoaders$AppClassLoader
virtual THREAD FACTORY
... 생략
놀라운 사실을 확인했다.
1. 일단 Agent의 premain에서 transfer가 먼저 실행된다.
2. 하지만 1의 과정에서 main에 속하는 'JdbcServerApplication' 만을 스캔한다. 즉, premain이 실행되는 시점에 JVM이 JdbcServerApplication 클래스만 로드했음을 의미한다.
3. 이후 Spring이 run되며 Context Scan 등 스프링의 로직이 실행된다.
4. 그 다음 1의 과정을 반복한다. 여기서는 모든 파일이 다시 확인되는 것을 알 수 있다.
스프링 부트 어플리케이션의 경우, 클래스 로드는 두 가지 상황에서 발생하는 것 같다.
- 어플리케이션 시작 시: main 메소드에서 직접 참조하는 클래스들은 어플리케이션 시작과 함께 즉시 로드된다.
- 스프링 부트 초기화 중: 스프링 부트는 내부적으로 컴포넌트 스캔을 수행하고, 어노테이션이 붙은 클래스들을 찾아서 로드한. 이 로딩은 SpringApplication.run 호출 이후에 발생한다.
문제의 해결이자, 동작 이유 확인
(정리)
결론적으로 이 문제의 원인은, classpath와 Spring의 문제에 기반했다.
1. javaassist의 cp를 springboot의 main으로 잡아 실행한 결과, 각 class의 로드 상태를 확인할 수 있었다.
2. 먼저 main에 속한 'ServerApplication' 의 Class가 먼저 스캔된다. (A)
3. 이후 Spring이 실행되고(아마 ClassLoader가 변경되는 것 같다) 이후 나머지 Class가 전부 로드된다. (B)
4. 문제는 Instrument API를 통해 조작하고자 했던 로직이 (A)에만 적용되고, (B)에는 적용되지 않는것이었다.
즉, 문제는 클래스 로드 시점이었다.
해결을 위해 (A)인 main에서 명시적으로 스캔되지 않는 Class를 호출하였다. 이렇게 하면 (A)단계에서 원하는 클래스가 스캔된다는 점을 이용한 것이다.
( 가장 먼저 스캔되는 main 내부에서 Class를 선언하면, 어노테이션이 붙지 않더라도 스캔된다는 점)
기존 @Configuration을 통해 스캔이 되었던 이유는 스프링 부트 이후 동적으로 로드되는, 스프링 부트 초기화 중의 Spring ClassLoader를 사용하여 부트한 것이었다. (2번째 부트 스캔 과정)
Connected to the target VM, address: '127.0.0.1:51624', transport: 'socket'
/$$$$$$ /$$$$$$ /$$ /$$ /$$$$$$ /$$
/$$__ $$ /$$__ $$| $$$ /$$$ /$$__ $$ | $$
| $$ \ $$| $$ \__/| $$$$ /$$$$ | $$ \ $$ /$$$$$$ /$$$$$$ /$$$$$$$ /$$$$$$
| $$$$$$$$| $$$$$$ | $$ $$/$$ $$ | $$$$$$$$ /$$__ $$ /$$__ $$| $$__ $$|_ $$_/
| $$__ $$ \____ $$| $$ $$$| $$ | $$__ $$| $$ \ $$| $$$$$$$$| $$ \ $$ | $$
| $$ | $$ /$$ \ $$| $$\ $ | $$ | $$ | $$| $$ | $$| $$_____/| $$ | $$ | $$ /$$
| $$ | $$| $$$$$$/| $$ \/ | $$ | $$ | $$| $$$$$$$| $$$$$$$| $$ | $$ | $$$$/
|__/ |__/ \______/ |__/ |__/ |__/ |__/ \____ $$ \_______/|__/ |__/ \___/
/$$ \ $$
| $$$$$$/
\______/
nowTime : 2024-02-14T17:48:25.316855700 my Agent has been invoked with args: null
Class Name: com.dummy.jdbcserver.JdbcServerApplication
Timestamp: 1707900505482
Class Loader: jdk.internal.loader.ClassLoaders$AppClassLoader
Class Name: com.dummy.jdbcserver.example_asm.chap3.GetFSetF
Timestamp: 1707900505483
Class Loader: jdk.internal.loader.ClassLoaders$AppClassLoader
2번째 스캔 시작!
virtual THREAD FACTORY
. ____ _ __ _ _
/\\ / ___'_ __ _ _(_)_ __ __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
\\/ ___)| |_)| | | | | || (_| | ) ) ) )
' |____| .__|_| |_|_| |_\__, | / / / /
=========|_|==============|___/=/_/_/_/
:: Spring Boot :: (v3.2.2)
2024-02-14T17:48:25.809+09:00 INFO 7072 --- [ main] c.d.jdbcserver.JdbcServerApplication : Starting JdbcServerApplication using Java 21.0.2 with PID 7072
2024-02-14T17:48:25.811+09:00 INFO 7072 --- [ main] c.d.jdbcserver.JdbcServerApplication : No active profile set, falling back to 1 default profile: "default"
Class Name: com.dummy.jdbcserver.proxytest.DataSourceConfig
Timestamp: 1707900506011
Class Loader: jdk.internal.loader.ClassLoaders$AppClassLoader
'프로젝트 > APM MiddleWare' 카테고리의 다른 글
| [A Java bytecode engineering library] - [Core API] 3. Method[2/3] (1) | 2026.01.27 |
|---|---|
| [ASM 바이트코드 작성] if문과 예외를 포함한 메서드 추가 예제(중요) (0) | 2026.01.27 |
| [ASM Docs]MethodVisitor 하위 메서드들 Docs를 통해 알아보기 (1) | 2026.01.27 |
| [ASM] static과 인스턴스 필드 생성자 호출 - <clinit>, <init> (0) | 2026.01.27 |
| Transaction : Out of shared memory, DeadLock (24.07.01) (0) | 2024.10.08 |
