요약: 잘못된 코드(또는 잘못된 코드의 작성자)를 비난하는 것은 성능 병목 현상을 찾아내고 Java™ 애플리케이션의 속도를 향상시키는 데 아무런 도움이 되지 않으며 그 어느 것도 추측할 수 없습니다. 이 기사를 통해 Ted Neward는 Java 성능 모니터링 도구에 대한 관심을 촉구하고 있으며 먼저 Java 5의 내장 프로파일러인 JConsole을 사용하여 성능 데이터를 수집 및 분석하는 방법에 대한 5가지 팁을 소개합니다.
Java 프로그래밍에 대해 알고 있다고 생각하는가? 하지만 실제로는 대부분의 개발자가 작업을 수행하기에 충분할 정도만 알고 있을 뿐 Java 플랫폼에 대해서는 자세히 알고 있지 않다. 이 시리즈에서 Ted Neward는 Java 플랫폼의 핵심 기능에 대한 자세한 설명을 통해 까다로운 프로그래밍 과제를 해결하는 데 도움이 되는 알려져 있지 않은 사실을 밝힌다.
애플리케이션 성능이 나쁠 경우 많은 개발자는 공황 상태에 빠지고 만다. 그리고 이러한 성능 저하에는 합당한 이유가 있기 마련이다. Java 애플리케이션 병목 현상의 소스를 추적하는 작업은 역사적으로 매우 어려운 작업 중 하나이다. 왜냐하면 Java 가상 머신에 블랙박스 효과가 있을 뿐만 아니라 전통적으로 Java 플랫폼용 프로파일링 도구가 부족하기 때문이다.
하지만 Java 5에서 JConsole이 등장하면서 모든 것이 바뀌었다. JConsole은 명령행과 GUI 쉘에서 작동하는 내장 Java 성능 프로파일러이다. 이 프로파일러는 완벽하지는 않지만 지식이 풍부한 책임자가 성능 문제점을 지적할 때 적절하게 대응할 수 있는 방법을 제공할 뿐만 아니라 Papa Google에 문의하는 것보다 전체적으로 훨씬 더 좋은 결과를 제공한다.
5가지 사항시리즈의 이 기사에서는 JConsole(또는 유사한 기능을 그래픽으로 제공하는 VisualVM)을 사용하여 Java 애플리케이션 성능을 모니터링하고 Java 코드의 병목 현상을 추적하는 데 사용할 수 있는 5가지 쉬운 방법을 설명한다.
많은 Java 개발자가 Java 5 이후로 프로파일러 도구가 JDK에 포함되어 있다는 사실을 모르고 있다. JConsole(또는 최근 Java 플랫폼 릴리스의 경우에는 VisualVM)은 Java 컴파일러처럼 쉽게 실행할 수 있는 내장 프로파일러이다. JDK가PATH에 있는 명령 프롬프트에서jconsole을 실행하거나 GUI 쉘에서 JDK 설치 디렉토리로 이동한 후 bin 폴더를 열고jconsole을 두 번 클릭한다.
프로파일러 도구가 실행되면 실행 중인 Java의 버전과 동시에 실행 중인 다른 Java 프로그램의 수에 따라 연결할 프로세스의 URL을 묻는 대화 상자가 표시되거나 연결할 수많은 다른 로컬 Java 프로세스가 나열되며, 나열된 목록에 JConsole 프로세스 자체가 포함되기도 한다.
JConsole 또는 VisualVM
JConsole은 Java 5 이후 모든 Java 플랫폼 릴리스에 포함되어 있다. VisualVM은 NetBeans 플랫폼을 기반으로 업데이트된 프로파일러이며 Java 6 업데이트 12 이후로 처음 포함되었다. 대부분의 작업 환경이 아직까지 Java 6으로 업그레이드되지 않았기 때문에 이 기사에서는 JConsole에 중점을 두고 설명한다. 하지만 대부분의 팁은 두 프로파일러 모두와 관련된다. (참고: Java 6에 포함되고 있는 VisualVM은 독립형 다운로드이기도 하다. VisualVM을 다운로드하려면참고자료를 참조한다.)
Java 5에서 Java 프로세스는 기본적으로 프로파일링되도록 설정되지 않는다. 시동 시에 명령행 인수-Dcom.sun.management.jmxremote를 전달하면 Java 5 VM이 연결을 열게 되며 그러면 프로파일러가 연결을 찾을 수 있다. JConsole에서 프로세스가 선택되면 프로세스를 두 번 클릭하여 프로파일링을 시작할 수 있다.
프로파일러에는 고유한 오버헤드가 있으므로 이 오버헤드를 먼저 확인하는 것이 좋다. JConsole의 오버헤드를 가장 쉽게 확인하는 방법은 먼저 애플리케이션 자체를 실행한 다음 프로파일러 하에서 애플리케이션을 다시 실행하여 그 차이를 측정하는 것이다. (이 경우 애플리케이션이 너무 크거나 작아서도 안 된다. 필자는 주로 JDK에 포함된 SwingSet2 데모 애플리케이션을 사용한다.) 따라서 필자는 먼저 가비지 콜렉션 회수를 보기 위해-verbose:gc를 사용하여 SwingSet2를 실행했다. 그런 다음 동일한 애플리케이션을 다시 실행한 후 JConsole 프로파일러를 연결했다. JConsole이 연결된 경우에는 GC 회수 스트림이 지속적으로 발생한 반면 그렇지 않은 경우에는 회수 스트림이 발생하지 않았다. 바로 이러한 차이가 프로파일러의 성능 오버헤드이다.
웹 애플리케이션 프로파일러는 소켓을 통한 프로파일링용 연결을 가정하므로 원격으로 실행 중인 애플리케이션을 모니터링/프로파일링하도록 JConsole(또는 JVMTI 기반 프로파일러)을 설정하는 간단한 구성만 수행하면 된다.
예를 들어, Tomcat이 "webserver"라는 시스템에서 실행 중이고 JVM에서 JMX를 사용하고 있고 포트 9004를 청취하고 있을 경우 JConsole(또는 기타 JMX 클라이언트)에서 JMX에 연결하려면 "service:jmx:rmi:///jndi/rmi://webserver:9004/jmxrmi"라는 JMX URL이 필요하다.
기본적으로 원격 데이터 센터에서 실행 중인 애플리케이션을 프로파일링하는 데 필요한 항목은 JMX URL이다. (JMX와 JConsole을 사용하여 원격 모니터링 및 관리를 수행하는 방법에 대한 자세한 정보는참고자료를 참조한다.)
일반적으로 애플리케이션 코드의 성능 문제점을 찾는 방법은 매우 다양하지만 몇 가지 형태로 예측할 수 있다. 초기 Java 시절부터 프로그래밍해 온 개발자는 오래된 IDE를 시작한 후 코드 베이스의 주요 부분에 대한 코드 검토를 시작하여 소스에서 익숙한 "빨간색 플래그"(예: 동기화된 블록, 오브젝트 할당 등)를 찾는 경향이 있다. 프로그래밍 경력이 수 년 이내인 개발자는 아마도 JVM에서 지원하는-X플래그를 자세히 보면서 가비지 콜렉터를 최적화하는 방법을 찾을 것이다. 그리고 초보 개발자라면 코드를 다시 작성하는 일이 없도록 하기 위해 누군가가 JVM의 마술 같은 "make it go fast" 스위치를 찾아놓았을 것을 기대하면서 Google을 검색할 것이다.
이러한 접근 방법 모두 본질적으로 잘못된 방법은 아니지만 일종의 무모한 도전이다. 성능 문제점에 대한 가장 효과적으로 대응하는 방법은 프로파일러를 사용하는 것이다. 그리고 오늘날에는 Java 플랫폼에 프로파일러가 내장되어 있으므로 사용하지 않을 이유가 없다.
JConsole에는 다음 탭을 포함하여 통계 수집에 유용한 여러 가지 탭이 있다.
Memory: JVM 가비지 콜렉터의 다양한 힙에 대한 활동을 추적한다.
Threads: 대상 JVM의 현재 스레드 활동을 조사한다.
Classes: 한 VM에 로드된 총 클래스 수를 검사한다.
이러한 탭(및 연관된 그래프)은 모두 Java 5 이상의 모든 VM이 JVM에 내장된 JMX 서버에 등록하는 JMX 오브젝트의 기능이다. 지정된 JVM에서 사용할 수 있는 전체 Bean 목록이 MBeans 탭에 나열되며, 해당 데이터를 보거나 이러한 조작을 실행하는 데 필요한 제한된 사용자 인터페이스와 일부 메타데이터가 함께 제공된다. (하지만 알림 등록은 JConsole 사용자 인터페이스의 범위에 해당되지 않는다.)
Tomcat 프로세스에서OutOfMemoryError가 지속적으로 발생하고 있다고 가정하자. 어떻게 된 일인지 알아보기 위해 JConsole을 열고 Classes 탭을 클릭한 다음 클래스 수를 계속 살펴본다. 클래스 수가 지속적으로 올라가면 애플리케이션 서버 또는 코드의 어느 부분에선가ClassLoader누수가 발생하고 있으며 머지 않아PermGen공간이 소진될 것이라고 간주할 수 있다. 문제점을 자세히 확인할 필요가 있는 경우에는 Memory 탭을 검사한다.
프로덕션 환경에서는 많은 작업이 빠르게 수행되기 때문에 애플리케이션 프로파일러에 할애할 수 있는 시간이 많지 않을 것이다. 대신 Java 환경의 모든 사항에 대한 스냅샷을 작성하여 저장한 후 나중에 살펴볼 수 있다. JConsole에서 이 작업을 수행할 수 있으며 VisualVM에서는 더 효과적으로 수행할 수 있다.
먼저 MBeans 탭으로 이동한 후com.sun.management노드와HotSpotDiagnostic노드를 차례로 연다. 그런 다음Operations를 선택하고 오른쪽 분할창에 있는 "dumpHeap" 단추를 누른다. 첫 번째("String") 입력 상자에 덤프할 파일 이름을 입력하여 dumpHeap에 전달하면 전체 JVM 힙에 대한 스냅샷이 작성되어 해당 파일에 기록된다.
나중에 다양한 상용 프로파일러를 사용하여 파일을 분석하거나 VisualVM을 사용하여 스냅샷을 분석할 수 있다. (VisualVM은 Java 6에서 사용할 수 있으며 독립형 다운로드로도 사용할 수 있다.)
프로파일러 유틸리티로서 JConsole이 좋은 도구임에 틀림 없지만 그보다 더 좋은 도구도 있다. 분석 추가 기능이나 멋진 사용자 인터페이스를 갖춘 프로파일러도 있고 기본적으로 JConsole보다 더 많은 데이터를 추적하는 프로파일러도 있다.
JConsole의 진정한 매력은 전체 프로그램이 "평범한 구형 Java"로 작성되어 있다는 것이다. 이는 곧 Java 개발자라면 누구나 이와 같은 유틸리티를 작성할 수 있다는 것을 의미한다. 실제로 JDK에는 JConsole용 새 플러그인을 작성하여 JConsole을 사용자 정의하는 방법을 보여 주는 예제가 포함되어 있다(참고자료참조). NetBeans를 기반으로 빌드된 VisualVM에서는 플러그인 개념을 훨씬 더 잘 활용한다.
JConsole(또는 VisualVM이나 기타 도구)이 원하는 기능을 제공하지 않거나, 추적하려는 항목을 추적하지 않거나, 원하는 방식으로 추적하지 않을 경우 사용자가 직접 코드를 작성할 수 있다. Java 코드가 너무 복잡해 보일지도 모르지만 언제라도 Groovy, JRuby 또는 기타 JVM 언어를 활용하여 코드를 빠르게 작성할 수 있다.
실제로 가장 필요한 것은 JMX를 통해 연결되는 사용하기 편리한 명령 도구이며, 원하는 데이터를 원하는 방식으로 정확히 추적할 수 있다.
Java 성능 모니터링은 JConsole이나 VisualVM에서 끝나지 않는다. JDK에는 대부분의 개발자가 모르고 있는 수많은 도구가 있다.이 시리즈의 다음 기사에서는 필요한 성능 데이터를 더 자세히 살펴보는 데 도움이 되는 실험 수준의 몇 가지 명령 도구에 대해 살펴본다. 이러한 도구는 일반적으로 특정 데이터를 중점적으로 다루기 때문에 완전한 프로파일러에 비해 규모가 작은 경량 도구이다. 따라서 성능 오버헤드도 발생하지 않는다.
"Mustang JConsole"(Mandy Chung 저, Java.net, 2008년 5월): JConsole Plugin API를 사용하여 사용자 정의 플러그인을 빌드하는 방법에 대해 간략하게 소개한다.
"Acquiring JVM Runtime Information"(Dustin Marx 저, Dustin's Software Development Cogitations and Speculations, 2009년 6월): JConsole과 VisualVM을 포함한 JDK의 내장 모니터링 및 관리 도구에 대한 데모를 볼 수 있다.
"Build your own profiler"(Andrew Wilcox 저, developerWorks, 2006년 3월): Java 5 에이전트 인터페이스와 AOP를 사용하여 사용자 정의 프로파일러인 Java Interactive Profiler를 빌드하는 방법을 보여 준다.
1. Disable Memory Page Trimming
VMWARE에서 사용하고 난 뒤 사용하지 않는 자원을 환원하는 작업을 끈다. (가상시스템 작업량을 줄인다.)
(Select: VM > Settings > Options > Advanced > Disable memory page trimming 체크 함)
2. Disable real-time anti-virus protection (실시간 바이러스 백신 보호를 사용하지 말아라)
실시간으로 바이러스 백신을 켜두는 것은 도움이 되지 않는다.
차라리 VMWARE 파일 자체를 실시간 바이러스 검사를 하라
3. Disable memory sharing
VMWARE 상에서 메모리와 다른 응용 프로그램간에 메모리 공유 금지 옵션 추가
.vmx 파일내에 다음 라인 추가
sched.mem.pshare.enable = “FALSE”
-- Implicit Cursor를 사용하는 경우
@ukja102
@mysid
@mon_on &v_sid
begin
for r in (select * from t1) loop
null;
end loop;
end;
/
@mon_off
spool result1.txt
@mon_show
spool off
@ukja102
@mysid
@mon_on &v_sid
-- Explicit Cursor를 사용하는 경우
declare
cursor v_cursor is
select * from t1
;
v_rec v_cursor%rowtype;
begin
open v_cursor;
loop
fetch v_cursor into v_rec;
exit when v_cursor%notfound;
end loop;
close v_cursor;
end;
/
@mon_off
spool result2.txt
@mon_show
spool off
여기서 한가지 질문을 던진다.
성능을 어떻게 비교할 것인가?
불행하게도 많은 사람들이 시작시간과 끝시간을 재는 것으로 만족한다. 그러지 말자.
Oracle은 성능을 비교하기 위한 많은 뷰들을 제공한다. 이들을 잘 활용해야 한다.
우선 v$sess_time_model 뷰를 통해 Time 정보를 비교한다. 이 뷰를 이용하면 별도의 코드를 통해 시간을 측정하지 않아도 된다.
sql execute elapsed time 25,827 6,044,618 6,018,791
DB CPU 29,331 6,034,029 6,004,698
PL/SQL execution elapsed time 60 558,753 558,693
parse time elapsed 1,509 131,440 129,931
-- Implicit Cursor를 사용한 경우
STAT_NAME VALUE1 VALUE2 DIFF
---------------------------------------- ------------ ------------ ------------
DB time 59,773 1,777,125 1,717,352
sql execute elapsed time 40,140 1,721,534 1,681,394
DB CPU 51,929 1,683,972 1,632,043
parse time elapsed 42,324 256,573 214,249
-- Explicit Cursor를 사용한 경우
STAT_NAME VALUE1 VALUE2 DIFF
---------------------------------------- ------------ ------------ ------------
DB time 29,622 6,051,808 6,022,186
sql execute elapsed time 25,827 6,044,618 6,018,791
DB CPU 29,331 6,034,029 6,004,698
PL/SQL execution elapsed time 60 558,753 558,693
parse time elapsed 1,509 131,440 129,931
Implicit Cursor가 모든 면에서 Explicit Cursor에 비해 현격한 성능 우위를 보이는 것을 알 수 있다.
그 이유가 무엇인지 가장 쉽게 알 수 있는 방법은? Statistics을 봐야 한다. v$sesstat 뷰를 통해 본 차이는 다음과 같다.
session pga memory max 1,498,708 1,891,924 393,216
session pga memory 1,498,708 1,891,924 393,216
session uga memory max 1,151,372 1,413,336 261,964
session logical reads 72 200,261 200,189
-- Implicit Cursor인 경우
NAME VALUE1 VALUE2 DIFF
---------------------------------------- ------------ ------------ ------------
table scan rows gotten 62 914,002 913,940
session pga memory max 1,826,388 2,154,068 327,680
session uga memory max 1,282,300 1,544,264 261,964
session pga memory 1,826,388 1,957,460 131,072
session logical reads 275 3,249 2,974
-- Explicit Cursor인 경우
NAME VALUE1 VALUE2 DIFF
---------------------------------------- ------------ ------------ ------------
table scan rows gotten 62 69,366,045 69,365,983
session pga memory max 1,498,708 1,891,924 393,216
session pga memory 1,498,708 1,891,924 393,216
session uga memory max 1,151,372 1,413,336 261,964
session logical reads 72 200,261 200,189
차이가 무엇인가?
놀랍게도 일량(Reads)의 차이가 절대적이라는것을 알 수 있다. logical reads가 10배 정도 차이나며 그 차이로 인해 성능의 차이가 왔다.
이 차이는 어디서 온 것인가?
Fetch Array Size에서 온 것이다. 한번에 많은 로우를 Fetch하면 Block을 방문해야할횟수가 줄어들며 그만큼 Logical Reads가 줄어든다. Implicit Cursor를 사용하는 경우에 Oracle은 내부적으로 10개를 한번에 Fetch한다. 반면에 Explicit Cursor를 사용하는 경우에는 한번에 한 개의 Row만 Fetch한다. 그 결과로 Logical Reads가 대략 10배의 차이가 나게 된다. 그 만큼 성능이 느린 것이다.
Explicit Cursor를 Implicit Cursor보다 빠르게 하는 유일한 방법은 Bulk Collection을 사용하는 것이다. 아래와 같이...
fetch v_cursor bulk collect into c1t, c2t; -- Do it bulk!!!
close v_cursor;
end;
/
@mon_off
spool result3.txt
@mon_show
spool off
@ukja102
@mysid
@mon_on &v_sid
declare
cursor v_cursor is
select * from t1
;
type c1tab is table of t1.c1%type;
type c2tab is table of t2.c2%type;
c1t c1tab;
c2t c2tab;
begin
open v_cursor;
fetch v_cursor bulk collect into c1t, c2t; -- Do it bulk!!!
close v_cursor;
end;
/
@mon_off
spool result3.txt
@mon_show
spool off
sql execute elapsed time 24,547 1,493,775 1,469,228
PL/SQL execution elapsed time 59 5,512 5,453
parse time elapsed 1,302 4,793 3,491
-- Implicit Cursor를 사용한 경우
STAT_NAME VALUE1 VALUE2 DIFF
---------------------------------------- ------------ ------------ ------------
DB time 59,773 1,777,125 1,717,352
sql execute elapsed time 40,140 1,721,534 1,681,394
DB CPU 51,929 1,683,972 1,632,043
parse time elapsed 42,324 256,573 214,249
-- Explicit Cursor + Bulk Collection을 사용한 경우
STAT_NAME VALUE1 VALUE2 DIFF
---------------------------------------- ------------ ------------ ------------
DB time 28,024 1,503,542 1,475,518
DB CPU 18,620 1,489,167 1,470,547
sql execute elapsed time 24,547 1,493,775 1,469,228
PL/SQL execution elapsed time 59 5,512 5,453
parse time elapsed 1,302 4,793 3,491
Bulk Collection과 함께 Explicit Cursor를 사용한 경우 오히려 성능이 더 뛰어나다. 그 이유는?