[java] Java에서 메모리 누수 / 가비지 수집 문제 추적

Program / 글쓴이

이것은 내가 지금 몇 달 동안 추적하려고 시도한 문제입니다. xml 피드를 처리하고 결과를 데이터베이스에 저장하는 Java 앱이 실행 중입니다. 추적하기 매우 어려운 간헐적 인 리소스 문제가있었습니다.

배경 :
프로덕션 박스 (문제가 가장 눈에 띄는 곳)에서 저는 박스에 특별히 접근 할 수없고 Jprofiler를 실행할 수 없습니다. 이 상자는 centos 5.2, tomcat6 및 java 1.6.0.11을 실행하는 64 비트 쿼드 코어, 8GB 머신입니다. 이 java-opts로 시작합니다.

JAVA_OPTS="-server -Xmx5g -Xms4g -Xss256k -XX:MaxPermSize=256m -XX:+PrintGCDetails -
XX:+PrintGCTimeStamps -XX:+UseConcMarkSweepGC -XX:+PrintTenuringDistribution -XX:+UseParNewGC"

기술 스택은 다음과 같습니다.

  • Centos 64 비트 5.2
  • 자바 6u11
  • 톰캣 6
  • Spring / WebMVC 2.5
  • 최대 절전 모드 3
  • 석영 1.6.1
  • DBCP 1.2.1
  • MySQL 5.0.45
  • Ehcache 1.5.0
  • (물론 다른 종속성, 특히 자카르타-커먼스 라이브러리)

문제를 재현 할 수있는 가장 가까운 방법은 메모리 요구 사항이 낮은 32 비트 컴퓨터입니다. 내가 통제 할 수 있다는 것. 필자는 JProfiler를 사용하여이 문제를 조사하고 많은 성능 문제를 해결했습니다 (동기화 문제, xpath 쿼리 사전 컴파일 / 캐싱, 스레드 풀 감소, 불필요한 최대 절전 모드 사전 가져 오기 제거, 처리 중 과도한 “캐시 워밍”제거).

각각의 경우에 프로파일 러는 이러한 것들이 어떤 이유로 든 엄청난 양의 리소스를 차지하는 것으로 나타 났으며 변경 사항이 들어 오면 더 이상 기본 리소스 돼지가 아님을 보여주었습니다.

문제 :
JVM이 메모리 사용 설정을 완전히 무시하고 모든 메모리를 채우고 응답하지 않는 것 같습니다. 이는 정기 폴링 (5 분 기준 및 1 분 재시도)을 기대하는 최종 고객과 상자가 응답하지 않는다는 알림을 지속적으로 받고 다시 시작해야하는 운영 팀의 문제입니다. 이 상자에는 다른 중요한 실행이 없습니다.

문제 는 가비지 수집 인 것으로 보입니다 . ConcurrentMarkSweep (위에서 언급 한대로) 수집기를 사용하고 있습니다. 원래 STW 수집기가 JDBC 시간 초과를 일으키고 점점 느려졌 기 때문입니다. 로그에 따르면 메모리 사용량이 증가함에 따라 cms 오류가 발생하기 시작하고 원래의 stop-the-world 수집기로 돌아가서 제대로 수집되지 않는 것으로 보입니다.

그러나 jprofiler로 실행하면 “Run GC”버튼은 증가하는 풋 프린트를 보여주지 않고 메모리를 깔끔하게 정리하는 것처럼 보이지만 jprofiler를 프로덕션 박스에 직접 연결할 수없고 검증 된 핫스팟 해결이 작동하지 않는 것 같습니다. 가비지 컬렉션 블라인드 튜닝의 부두가 남았습니다.

내가 시도한 것 :

  • 핫스팟 프로파일 링 및 수정.
  • STW, 병렬 및 CMS 가비지 수집기를 사용합니다.
  • 최소 / 최대 힙 크기를 1 / 2,2 / 4,4 / 5,6 / 6 증분으로 실행합니다.
  • 최대 1Gb까지 256M 단위로 permgen 공간으로 실행됩니다.
  • 위의 많은 조합.
  • 또한 JVM [tuning reference] (http://java.sun.com/javase/technologies/hotspot/gc/gc_tuning_6.html)을 참조했지만이 동작을 설명하는 내용이나 _which_ 조정의 예를 찾을 수 없습니다. 이와 같은 상황에서 사용할 매개 변수입니다.
  • 또한 오프라인 모드에서 jprofiler를 시도하여 jconsole, visualvm과 연결했지만 내 gc 로그 데이터를 방해하는 것을 찾을 수없는 것 같습니다.

안타깝게도 문제는 산발적으로 나타나고 예측할 수없는 것처럼 보이며 문제없이 며칠 또는 일주일 동안 실행할 수 있거나 하루에 40 번 실패 할 수 있으며 지속적으로 잡을 수있는 유일한 것은 가비지 컬렉션이 작동하고 있습니다.

사람에 관한 조언을 제공 할 수 있습니다 :
a)는 JVM (8 개) 물리적 공연과 미만 6에서 최대 출력으로 구성 스왑 공간 2GB의 사용 이유는
사실을 설명하는 것이 B) GC 튜닝에 대한 참조 또는 적절한 예제를 제공합니다 고급 컬렉션을 사용할 때와 어떤 종류의 설정을 사용하는지.
c) 가장 일반적인 자바 메모리 누수에 대한 참조 (저는 주장되지 않은 참조를 이해하지만 라이브러리 / 프레임 워크 수준에서 의미하거나 해시 맵과 같은 데이터 구조에서 더 이질적인 것을 의미합니다).

제공 할 수있는 모든 통찰력에 감사드립니다.


Emil H 편집 :
1) 예, 제 개발 클러스터는 미디어 서버까지 프로덕션 데이터의 미러입니다. 가장 큰 차이점은 32/64 비트와 사용 가능한 RAM의 양으로, 쉽게 복제 할 수 없지만 코드와 쿼리 및 설정은 동일합니다.

2) JaxB에 의존하는 레거시 코드가 있지만 스케줄링 충돌을 피하기 위해 작업을 재정렬 할 때 하루에 한 번 실행되기 때문에 일반적으로 해당 실행이 제거되었습니다. 기본 파서는 java.xml.xpath 패키지를 호출하는 XPath 쿼리를 사용합니다. 하나는 쿼리가 미리 컴파일되지 않았고 두 개는 하드 코딩 된 문자열에 있었기 때문에 이것은 몇 가지 핫스팟의 소스였습니다. 스레드 세이프 캐시 (해시 맵)를 만들고 xpath 쿼리에 대한 참조를 최종 정적 문자열로 팩터링하여 리소스 소비를 크게 줄였습니다. 쿼리는 여전히 처리의 많은 부분을 차지하지만 애플리케이션의 주요 책임이기 때문입니다.

3) 추가 참고 사항, 다른 주요 소비자는 JAI의 이미지 작업 (피드에서 이미지 재 처리)입니다. 나는 자바의 그래픽 라이브러리에 익숙하지 않지만 내가 발견 한 것에서 그것들은 특별히 새지 않습니다.

(지금까지 답변 해 주셔서 감사합니다, 여러분!)

업데이트 :
VisualVM을 사용하여 프로덕션 인스턴스에 연결할 수 있었지만 GC 시각화 / run-GC 옵션을 비활성화했습니다 (로컬에서 볼 수는 있지만). 흥미로운 점 : VM의 힙 할당은 JAVA_OPTS를 따르고 있으며 실제 할당 된 힙은 1-1.5 기가 편안하게 앉아 있으며 누출되지 않는 것처럼 보이지만 상자 수준 모니터링은 여전히 ​​누출 패턴을 보여 주지만 VM 모니터링에 반영되지 않습니다. 이 상자에서 실행중인 다른 항목이 없어서 당황합니다.

답변

글쎄, 마침내이 문제를 일으키는 문제를 발견했으며 다른 사람이 이러한 문제를 겪을 경우를 대비하여 자세한 답변을 게시하고 있습니다.

프로세스가 작동하는 동안 jmap을 시도했지만 이로 인해 일반적으로 jvm이 더 중단되고 –force로 실행해야합니다. 이로 인해 많은 데이터가 누락되거나 적어도 둘 사이의 참조가 누락 된 것처럼 보이는 힙 덤프가 발생했습니다. 분석을 위해 나는 많은 데이터를 제공하지만 그것을 해석하는 방법에 있어서는 많지 않은 jhat을 시도했다. 둘째, 이클립스 기반 메모리 분석 도구 ( http://www.eclipse.org/mat/ )를 사용해 보았는데, 힙이 대부분 바람둥이와 관련된 클래스임을 보여주었습니다.

문제는 jmap이 응용 프로그램의 실제 상태를보고하지 않고 종료시 클래스 만 포착하는 것이 었습니다. 대부분은 tomcat 클래스였습니다.

몇 번 더 시도한 결과 매우 많은 수의 모델 개체가 있음을 알았습니다 (실제로 데이터베이스에서 공개로 표시된 것보다 2-3 배 더 많음).

이를 사용하여 느린 쿼리 로그와 관련없는 몇 가지 성능 문제를 분석했습니다. 추가 지연로드 ( http://docs.jboss.org/hibernate/core/3.3/reference/en/html/performance.html )를 시도 하고 몇 가지 최대 절전 모드 작업을 직접 jdbc 쿼리로 대체했습니다 (대부분 jdbc 대체는 조인 테이블에서 직접 작동했으며 mysql이 로깅하는 다른 비효율적 인 쿼리를 대체했습니다.

이러한 단계는 프런트 엔드 성능의 일부를 개선했지만 여전히 누출 문제를 해결하지 못했으며 앱은 여전히 ​​불안정하고 예측할 수 없게 작동했습니다.

마지막으로 -XX : + HeapDumpOnOutOfMemoryError 옵션을 찾았습니다. 이것은 마침내 애플리케이션의 상태를 정확하게 보여주는 매우 큰 (~ 6.5GB) hprof 파일을 생성했습니다. 아이러니하게도 파일이 너무 커서 jhat은 16GB의 램이있는 상자에서도 파일을 분석 할 수 없었습니다. 다행히도 MAT는 멋진 그래프를 생성하고 더 나은 데이터를 보여주었습니다.

이번에는 단일 쿼츠 스레드가 6GB 힙 중 4.5GB를 차지하고 있었고 그 중 대부분은 최대 절전 모드 StatefulPersistenceContext ( https://www.hibernate.org/hib_docs/v3/api/org/hibernate 였습니다. /engine/StatefulPersistenceContext.html ). 이 클래스는 내부적으로 최대 절전 모드에서 기본 캐시로 사용됩니다 (EHCache가 지원하는 두 번째 수준 및 쿼리 캐시를 비활성화했습니다).

이 클래스는 최대 절전 모드의 대부분의 기능을 활성화하는 데 사용되므로 직접 비활성화 할 수 없습니다 (직접 해결할 수는 있지만 스프링은 상태 비 저장 세션을 지원하지 않음). 성숙한 제품의 주요 메모리 누수. 그런데 왜 지금 새는 걸까요?

글쎄요, 그것은 사물의 조합이었습니다. 쿼츠 스레드 풀은 threadLocal이라는 특정 사물로 인스턴스화되고, 스프링은 세션 팩토리를 주입했습니다. 쿼츠 스레드 수명주기가 시작될 때 세션을 생성 한 다음 다시 사용하여 최대 절전 모드 세션을 사용한 다양한 수정 작업. Hibernate는 예상되는 동작 인 세션에서 캐싱되었습니다.

문제는 스레드 풀이 세션을 해제하지 않았기 때문에 최대 절전 모드가 상주하고 세션의 수명주기 동안 캐시를 유지한다는 것입니다. 이것은 springs hibernate template 지원을 사용했기 때문에 세션의 명시적인 사용이 없었습니다 (우리는 dao-> manager-> driver-> quartz-job 계층을 사용하고 있으며 dao는 spring을 통해 hibernate 구성으로 주입되므로 작업은 다음과 같습니다. 템플릿에서 직접 수행).

따라서 세션이 닫히지 않았고, 최대 절전 모드는 캐시 개체에 대한 참조를 유지하고 있었으므로 가비지 수집되지 않았으므로 새 작업이 실행될 때마다 스레드의 로컬 캐시를 계속 채울 것입니다. 서로 다른 작업 간의 공유. 또한 이것은 쓰기 집약적 인 작업 (읽기 거의 없음)이기 때문에 캐시가 대부분 낭비되어 객체가 계속 생성되었습니다.

해결책 : 명시 적으로 session.flush () 및 session.clear ()를 호출하는 dao 메서드를 만들고 각 작업을 시작할 때 해당 메서드를 호출합니다.

이 앱은 모니터링 문제, 메모리 오류 또는 다시 시작없이 며칠 동안 실행되었습니다.

모든 사람의 도움에 감사 드리며, 모든 것이 예상했던대로 정확히 수행되고 있었기 때문에 추적하기가 매우 까다로운 버그 였지만 결국 3 줄 방법으로 모든 문제를 해결할 수있었습니다.

답변

JMX가 활성화 된 상태에서 프로덕션 박스를 실행할 수 있습니까?

-Dcom.sun.management.jmxremote
-Dcom.sun.management.jmxremote.port=<port>
...

JMX를 사용한 모니터링 및 관리

그런 다음 JConsole, VisualVM ?

jmap 으로 힙 덤프를해도 괜찮 습니까?

그렇다면 JProfiler (이미 가지고 있음), jhat , VisualVM, Eclipse MAT 를 사용하여 누출에 대한 힙 덤프를 분석 할 수 있습니다 . 또한 누수 / 패턴을 찾는 데 도움이 될 수있는 힙 덤프를 비교하십시오.

그리고 자카르타 커먼즈를 언급했듯이. 클래스 로더 보유와 관련된 jakarta-commons-logging을 사용할 때 문제가 있습니다. 그 수표를 잘 읽으려면

메모리 누수 사냥꾼의 하루 ( release(Classloader))

답변

힙 이외의 메모리가 누수되는 것처럼 보이며 힙이 안정적이라고 언급했습니다. 고전적인 후보는로드 된 클래스 객체와 인턴 된 문자열의 두 가지로 구성된 permgen (영구 생성)입니다. 당신이 VisualVM과 연결 한보고한다 있기 때문에이 증가 계속있을 경우 당신은,로드 된 클래스의 양을 보일 수 있어야 로드를 클래스 (중요, VisualVM과는 지금까지로드 된 클래스의 총량을 보여줍니다이 상승하는 경우, 그것은 괜찮습니다하지만 로드 된 클래스의 양은 일정 시간 후에 안정화되어야합니다.)

permgen 누출로 판명되면 permgen 분석을위한 도구가 힙에 비해 다소 부족하기 때문에 디버깅이 까다로워집니다. 가장 좋은 방법은 서버에서 반복적으로 (매시간?) 호출하는 작은 스크립트를 시작하는 것입니다.

jmap -permstat <pid> > somefile<timestamp>.txt

해당 매개 변수가있는 jmap은로드 된 클래스의 개요와 해당 크기 (바이트)의 추정치를 생성합니다.이 보고서는 특정 클래스가 언로드되지 않는지 식별하는 데 도움이 될 수 있습니다. (참고 : 프로세스 ID를 의미하며 파일을 구별하기 위해 생성 된 타임 스탬프 여야 함)

특정 클래스가로드되고 언로드되지 않은 것으로 식별되면 이러한 클래스가 생성 될 수있는 위치를 정신적으로 파악할 수 있습니다. 그렇지 않으면 jhat을 사용하여 jmap -dump로 생성 된 덤프를 분석 할 수 있습니다. 정보가 필요한 경우 향후 업데이트를 위해 보관하겠습니다.

답변

직접 할당 된 ByteBuffer를 찾습니다.

javadoc에서.

이 클래스의 allocateDirect 팩토리 메소드를 호출하여 직접 바이트 버퍼를 생성 할 수 있습니다. 이 메서드에서 반환 된 버퍼는 일반적으로 간접 버퍼보다 ​​할당 및 할당 해제 비용이 다소 높습니다. 직접 버퍼의 내용은 일반적인 가비지 수집 힙 외부에있을 수 있으므로 응용 프로그램의 메모리 풋 프린트에 미치는 영향이 명확하지 않을 수 있습니다. 따라서 기본 시스템의 기본 I / O 작업의 영향을받는 크고 수명이 긴 버퍼에 주로 직접 버퍼를 할당하는 것이 좋습니다. 일반적으로 프로그램 성능에서 측정 가능한 이득을 얻을 때만 직접 버퍼를 할당하는 것이 가장 좋습니다.

아마도 Tomcat 코드는 I / O에 이것을 사용합니다. 다른 커넥터를 사용하도록 Tomcat을 구성하십시오.

주기적으로 System.gc ()를 실행하는 스레드를 가질 수 없음. “-XX : + ExplicitGCInvokesConcurrent”는 흥미로운 옵션 일 수 있습니다.

답변

어떤 JAXB? JAXB가 파마 공간 스터 퍼라는 것을 알았습니다.

또한 현재 JDK 6과 함께 제공 되는 visualgc 가 메모리에서 무슨 일이 일어나고 있는지 확인하는 좋은 방법이라는 것을 알게되었습니다. 그것은 에덴, 세대, 파마 공간과 GC의 일시적인 행동을 아름답게 보여줍니다. 프로세스의 PID 만 있으면됩니다. 아마도 JProfile에서 작업하는 동안 도움이 될 것입니다.

그리고 Spring 추적 / 로깅 측면은 어떻습니까? 아마도 간단한 측면을 작성하고 선언적으로 적용하고 그런 식으로 가난한 사람의 프로파일 러를 수행 할 수 있습니다.

답변

“안타깝게도 문제도 산발적으로 나타나고 예측할 수없는 것 같습니다. 문제없이 며칠 또는 일주일 동안 실행할 수 있습니다. 또는 하루에 40 번 실패 할 수 있습니다. 가비지 컬렉션이 작동한다는 것입니다. “

이것은 하루에 최대 40 번 실행되고 며칠 동안 더 이상 실행되지 않는 사용 사례와 관련이있는 것 같습니다. 나는 당신이 단지 증상만을 추적하지 않기를 바랍니다. 이것은 애플리케이션의 행위자 (사용자, 작업, 서비스)의 동작을 추적하여 범위를 좁힐 수 있어야합니다.

XML 가져 오기로 인해 이런 일이 발생하는 경우 충돌 40 일의 XML 데이터를 충돌이없는 날에 가져온 데이터와 비교해야합니다. 아마도 그것은 당신의 코드에서 찾을 수없는 일종의 논리적 문제 일 것입니다.

답변

몇 가지 차이점이있는 동일한 문제가있었습니다 ..

내 기술은 다음과 같습니다.

성배 2.2.4

바람둥이 7

석영 플러그인 1.0

내 응용 프로그램에서 두 개의 데이터 소스를 사용합니다. 이것이 버그 원인을 결정하는 특수성입니다 ..

고려해야 할 또 다른 사항은 쿼츠 플러그인, @liam이 말한 것처럼 쿼츠 스레드에 최대 절전 세션을 주입하고 쿼츠 스레드는 내가 응용 프로그램을 마칠 때까지 여전히 살아 있다는 것입니다.

내 문제는 플러그인이 세션 및 두 데이터 소스를 처리하는 방식과 결합 된 grails ORM의 버그였습니다.

Quartz 플러그인에는 최대 절전 세션을 초기화하고 파괴하는 리스너가 있습니다.

public class SessionBinderJobListener extends JobListenerSupport {

    public static final String NAME = "sessionBinderListener";

    private PersistenceContextInterceptor persistenceInterceptor;

    public String getName() {
        return NAME;
    }

    public PersistenceContextInterceptor getPersistenceInterceptor() {
        return persistenceInterceptor;
    }

    public void setPersistenceInterceptor(PersistenceContextInterceptor persistenceInterceptor) {
        this.persistenceInterceptor = persistenceInterceptor;
    }

    public void jobToBeExecuted(JobExecutionContext context) {
        if (persistenceInterceptor != null) {
            persistenceInterceptor.init();
        }
    }

    public void jobWasExecuted(JobExecutionContext context, JobExecutionException exception) {
        if (persistenceInterceptor != null) {
            persistenceInterceptor.flush();
            persistenceInterceptor.destroy();
        }
    }
}

제 경우에는 persistenceInterceptor인스턴스 AggregatePersistenceContextInterceptor목록이 있습니다.HibernatePersistenceContextInterceptor . 각 데이터 소스에 대해 하나씩.

모든 작업은 AggregatePersistenceContextInterceptor 수정이나 처리없이 HibernatePersistence에 전달 된 것과 .

우리가 호출하는 경우 init()에 HibernatePersistenceContextInterceptor그는 아래의 정적 변수를 증가

private static ThreadLocal<Integer> nestingCount = new ThreadLocal<Integer>();

나는 그 정적 카운트의 목적을 모른다. 나는 그가 데이터 소스 당 하나씩 두 번 증가한다는 것을 알고 있습니다.AggregatePersistence구현으로 있습니다.

여기까지 나는 단지 시나리오를 설명한다.

이제 문제가 발생합니다 …

쿼츠 작업이 끝나면 플러그인은 리스너를 호출하여 소스 코드에서 볼 수 있듯이 최대 절전 세션을 플러시하고 파괴합니다 SessionBinderJobListener.

플러시는 완벽하게 발생하지만 파괴는 아닙니다. 왜냐하면 HibernatePersistence최대 절전 세션을 닫기 전에 한 번의 유효성 검사를 수행 하기 때문입니다 nestingCount. 값이 1보다 큰지 검사 합니다. 대답이 예이면 세션을 닫지 않습니다.

Hibernate가 한 일을 단순화 :

if(--nestingCount.getValue() > 0)
    do nothing;
else
    close the session;

그것이 내 메모리 누수의 기본입니다. 쿼츠 스레드는 세션에 사용 된 모든 객체와 함께 여전히 살아 있습니다. ORM이 세션을 닫지 않기 때문에 두 개의 데이터 소스가 있기 때문에 발생하는 버그 때문입니다.

이를 해결하기 위해 리스너를 커스터마이징하고, clear before destroy를 호출하고, destroy를 두 번 호출합니다 (각 데이터 소스에 대해 하나씩). 내 세션이 명확하고 파괴되었는지 확인하고 파괴가 실패하면 적어도 그는 분명했습니다.