[JAVA/OS] /dev/random 관련 PRNG 오류

현재 Odroid HC2(XU4) 에다가 개인 서버를 구축하고 사용중인데,

 

plex랑.. 뭐 이것저것 올려서 사용중이다

 

근데, JAVA를 설치하고 개인 프로젝트를 올려서 사용하려고 하니, 처음에는 동작을 잘 하다가

 

어느 순간이 되면 JVM 자체가 종료되면서 덤프파일이 생겨버린다 ㅡ,ㅡ..

 

오류 내용은 다음과 같다

 

 

#
# A fatal error has been detected by the Java Runtime Environment:
#
#  SIGSEGV (0xb) at pc=0x7285dcb8, pid=20327, tid=0x6bf5f460
#
# JRE version: OpenJDK Runtime Environment (8.0_171-b11) (build 1.8.0_171-8u171-b11-0ubuntu0.18.04.1-b11)
# Java VM: OpenJDK Client VM (25.171-b11 mixed mode linux-aarch32 )
# Problematic frame:
# C  0x7285dcb8
#
# Failed to write core dump. Core dumps have been disabled. To enable core dumping, try "ulimit -c unlimited" before starting Java again
#
# If you would like to submit a bug report, please visit:
#   http://bugreport.java.com/bugreport/crash.jsp
#

시그널을 받은건

SIGSEGV

 이다.

 

SIGSEGV는

 

세그멘테이션 결함(Segmentation Fault)은 컴퓨터 소프트웨어의 실행 중에 일어날 수 있는 특수한 오류이다. 세그멘테이션 위반, 세그멘테이션 실패라고도 하며, 세그폴트(Segfault)로 줄여서 쓰기도 한다. 세그멘테이션 결함은 프로그램이 허용되지 않은 메모리 영역에 접근을 시도하거나, 허용되지 않은 방법으로 메모리 영역에 접근을 시도할 경우 발생한다.

from 위키

 

익히 알고있는 세그멘테이션 오류인데, 메모리 관련 접근이 잘못되었을 때 발생한다고 한다.

 

 

---------------  T H R E A D  ---------------

Current thread (0x6fc34400):  JavaThread "MessageBroker-1" [_thread_in_Java, id=20355, stack(0x6bf10000,0x6bf60000)]

siginfo: si_signo: 11 (SIGSEGV), si_code: 2 (SEGV_ACCERR), si_addr: 0x7285dcb8

 

그 밑에 쓰레드 관련 정보를 보게되면, Websocket을 사용하는 고로, MessageBroker의 쓰레드 정보가 나온다

 

여튼, 이렇게 에러를 추적해나가다 보면 아래와 같은 정보를 볼 수 있는데

 

 

---------------  P R O C E S S  ---------------

Java Threads: ( => current thread )
  0x6ba6ac00 JavaThread "XNIO-2 task-64" [_thread_blocked, id=20436, stack(0x66430000,0x66480000)]
  0x69e62000 JavaThread "XNIO-2 task-63" [_thread_blocked, id=20435, stack(0x66480000,0x664d0000)]
  0x69550000 JavaThread "XNIO-2 task-62" [_thread_blocked, id=20434, stack(0x664d0000,0x66520000)]
  0x69e60c00 JavaThread "XNIO-2 task-61" [_thread_blocked, id=20433, stack(0x66520000,0x66570000)]
  0x6ba43800 JavaThread "XNIO-2 task-60" [_thread_blocked, id=20432, stack(0x66570000,0x665c0000)]
  0x70221c00 JavaThread "XNIO-2 task-59" [_thread_blocked, id=20431, stack(0x665c0000,0x66610000)]
  0x694f9800 JavaThread "XNIO-2 task-58" [_thread_blocked, id=20430, stack(0x66610000,0x66660000)]
  0x6ed9fc00 JavaThread "XNIO-2 task-57" [_thread_blocked, id=20429, stack(0x66660000,0x666b0000)]
  0x694e8c00 JavaThread "XNIO-2 task-56" [_thread_blocked, id=20428, stack(0x666b0000,0x66700000)]
  0x6ed9ec00 JavaThread "XNIO-2 task-55" [_thread_blocked, id=20427, stack(0x66700000,0x66750000)]
  0x6e528800 JavaThread "XNIO-2 task-54" [_thread_blocked, id=20426, stack(0x66750000,0x667a0000)]
  0x6ba42000 JavaThread "XNIO-2 task-53" [_thread_blocked, id=20425, stack(0x667a0000,0x667f0000)]
  0x69e42c00 JavaThread "XNIO-2 task-52" [_thread_blocked, id=20424, stack(0x667f0000,0x66840000)]
  0x694f7400 JavaThread "XNIO-2 task-51" [_thread_blocked, id=20423, stack(0x66840000,0x66890000)]
  0x6f4cb000 JavaThread "XNIO-2 task-49" [_thread_blocked, id=20422, stack(0x66890000,0x668e0000)]
  0x6ba40c00 JavaThread "XNIO-2 task-50" [_thread_blocked, id=20421, stack(0x668e0000,0x66930000)]
  0x69e27000 JavaThread "XNIO-2 task-48" [_thread_blocked, id=20420, stack(0x66930000,0x66980000)]
  0x67106000 JavaThread "XNIO-2 task-47" [_thread_blocked, id=20419, stack(0x66980000,0x669d0000)]
  0x6e5f9c00 JavaThread "XNIO-2 task-46" [_thread_blocked, id=20418, stack(0x669d0000,0x66a20000)]
  0x6ba36400 JavaThread "XNIO-2 task-45" [_thread_blocked, id=20417, stack(0x66a20000,0x66a70000)]
  0x693c3000 JavaThread "XNIO-2 task-43" [_thread_blocked, id=20416, stack(0x66a70000,0x66ac0000)]
  0x69e25c00 JavaThread "XNIO-2 task-44" [_thread_blocked, id=20415, stack(0x66ac0000,0x66b10000)]
  0x6ba33000 JavaThread "XNIO-2 task-42" [_thread_blocked, id=20414, stack(0x66b10000,0x66b60000)]
  0x6e295800 JavaThread "XNIO-2 task-41" [_thread_blocked, id=20413, stack(0x66b60000,0x66bb0000)]
  0x67103000 JavaThread "XNIO-2 task-40" [_thread_blocked, id=20412, stack(0x66bb0000,0x66c00000)]
  0x6e595000 JavaThread "XNIO-2 task-39" [_thread_blocked, id=20411, stack(0x66c00000,0x66c50000)]

 

즉, 모든 쓰레드가 현재 블럭 상태인것이다..

 

 그러다가 MessageBroker 부분에서 특정 메서드를 실행하던 중 터지고 만것인데

 

 

 

위 그림을 보면, Thread가 Runnable일 때, 특정 조건에 따라 블럭킹이 될 수도 있고, waiting이 될 수도 있고.. 한데 

 

아무것도 하지 않은 상태로 JVM을 켜두고 하루쯤 지나니 이런 현상이 발생했다.

 

그래서 또 에러를 추적하던 도중 MessageBroker의 특정 메서드 부분을 찾게 됨.

 

 

Stack: [0x6bf10000,0x6bf60000],  sp=0x6bf5e01c,  free space=312k
Native frames: (J=compiled Java code, j=interpreted, Vv=VM code, C=native code)
C  0x7285dcb8
j  sun.security.provider.NativePRNG.engineNextBytes([B)V+4
j  java.security.SecureRandom.nextBytes([B)V+5
j  java.util.UUID.randomUUID()Ljava/util/UUID;+11
j  org.hibernate.id.uuid.StandardRandomStrategy.generateUUID(Lorg/hibernate/engine/spi/SharedSessionContractImplementor;)Ljava/util/UUID;+0
j  org.hibernate.internal.AbstractSharedSessionContract.(Lorg/hibernate/internal/SessionFactoryImpl;Lorg/hibernate/internal/SessionCreationOptions;)V+25
j  org.hibernate.internal.AbstractSessionImpl.(Lorg/hibernate/internal/SessionFactoryImpl;Lorg/hibernate/internal/SessionCreationOptions;)V+3
j  org.hibernate.internal.SessionImpl.(Lorg/hibernate/internal/SessionFactoryImpl;Lorg/hibernate/internal/SessionCreationOptions;)V+3
j  org.hibernate.internal.SessionFactoryImpl$SessionBuilderImpl.openSession()Lorg/hibernate/Session;+25
j  org.hibernate.internal.SessionFactoryImpl.buildEntityManager(Ljavax/persistence/SynchronizationType;Ljava/util/Map;)Lorg/hibernate/Session;+36
j  org.hibernate.internal.SessionFactoryImpl.createEntityManager()Lorg/hibernate/Session;+7
j  org.hibernate.internal.SessionFactoryImpl.createEntityManager()Ljavax/persistence/EntityManager;+1
j  org.springframework.orm.jpa.JpaTransactionManager.createEntityManagerForTransaction()Ljavax/persistence/EntityManager;+45
j  org.springframework.orm.jpa.JpaTransactionManager.doBegin(Ljava/lang/Object;Lorg/springframework/transaction/TransactionDefinition;)V+50
j  org.springframework.transaction.support.AbstractPlatformTransactionManager.getTransaction(Lorg/springframework/transaction/TransactionDefinition;)Lorg/springframework/transaction/TransactionStatus;+204
j  org.springframework.transaction.interceptor.TransactionAspectSupport.createTransactionIfNecessary(Lorg/springframework/transaction/PlatformTransactionManager;Lorg/springframework/transaction/interceptor/TransactionAttribute;Ljava/lang/String;)Lorg/springframework/transaction/interceptor/TransactionAspectSupport$TransactionInfo;+37
j  org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(Ljava/lang/reflect/Method;Ljava/lang/Class;Lorg/springframework/transaction/interceptor/TransactionAspectSupport$InvocationCallback;)Ljava/lang/Object;+64
j  org.springframework.transaction.interceptor.TransactionInterceptor.invoke(Lorg/aopalliance/intercept/MethodInvocation;)Ljava/lang/Object;+42
J 189291 C1 org.springframework.aop.framework.ReflectiveMethodInvocation.proceed()Ljava/lang/Object; (107 bytes) @ 0xb327ab58 [0xb327a9a0+0x1b8]
j  org.springframework.dao.support.PersistenceExceptionTranslationInterceptor.invoke(Lorg/aopalliance/intercept/MethodInvocation;)Ljava/lang/Object;+1
J 189291 C1 org.springframework.aop.framework.ReflectiveMethodInvocation.proceed()Ljava/lang/Object; (107 bytes) @ 0xb327ab58 [0xb327a9a0+0x1b8]
j  org.springframework.data.jpa.repository.support.CrudMethodMetadataPostProcessor$CrudMethodMetadataPopulatingMethodInterceptor.invoke(Lorg/aopalliance/intercept/MethodInvocation;)Ljava/lang/Object;+89

 

spring framework 내부에서 JPA를 사용하고 있었는데, 이 JPA를 담당하는 EntityManager에서 내부적으로 generateUUID() 를 호출하는 것 같다.

 

그럼 그 UUID를 가지고 뭐 객체를 구분한다던지.. 하는 목적으로 생성하는 것 같은데

 

문제는, 이 UUID를 생성하는 부분에서 오류가 난 것..

 

개발 소스말고 UUID를 생성하는 부분을 찾아가보면, 위에 스택에 찍힌것 처럼

sun.security.provider.NativePRNG.engineNextBytes([B)V+4 를 호출하게 된다.

 

이 내부 구현은 /dev/random 의 랜덤한 값을 읽어서 그것을 가져오는 기능으로 구현이 되어있다.

 

근데, /dev/random은 말이 많은 편이다. 지금 PRNG Blocking이라고 검색만 해봐도

 

/dev/random으로 인하여 발생하는 문제가 많은것 같다.

 

https://unix.stackexchange.com/questions/324209/when-to-use-dev-random-vs-dev-urandom/324210

• /dev/random blocks when it runs out of entropy
• The amount of entropy is conservatively estimated, but not counted
• /dev/urandom will never block, reading from /dev/random can halt processes execution.

/dev/random을 설명한 부분인데

 

"/dev/random은 내부의 entropy가 가득찼을 경우(다 소진되었을 경우) BLOCK이 된다"

 

가 가장 큰 문제라고 보여진다.

 

JPA 특성 상, 많은 수의 UUID를 생성하고 사용할텐데(Entity의 상태 변경, flush 후 새로 객체 생성 등..)

 

그럴때 /dev/random에서 읽어오는 NativePRNG.engineNextBytes()가 문제가 되는 것으로 판단했다.

 

그래서.. 해결책은, /dev/random을 사용하는 대신에, /dev/urandom을 사용하는걸 고려해보기로 했다.

 

urandom의 특징은, 절대 블럭킹이 걸리지 않는다는 것이고, 엔트로피 조건이 갖춰지지 않아도 난수생성을 한다

성능이 /dev/random보다 빠르다는 점도 있다

 

 

JVM을 시작할 때 옵션을 줘서 변경을 할 수 있다

 

-Djava.security.egd=file:/dev/./urandom

 

현재 개인서버(odroid) 에서 사용하는 JVM옵션은 다음과 같다

 

-Xms1024m -Xmx1024m -server -Djava.security.egd=file:/dev/./urandom

 

램이 2기가라서, 시스템이 사용하는 메모리를 고려했을 때, 1기가 정도가 적당할 것 같아서 설정했고, -server로 서버 설정(같은 로직 반복 최적화)

그리고.. 마지막으로 urandom을 사용해서 random generate부분을 변경해보기로 했다.

 

아직 적용만 해보고 경과를 안봤는데, 경과에 따라 여기에 추가로 기재할 예정이다.

 

-- p.s

2018.06.19

-- openjdk 환경에서 해당 옵션을 주고도 현상 재발생함

특정 시간이 지나는게 아닌, 어느 메서드가 호출되는 순간 랜덤하게 발생

openjdk -> oracle jdk로 변경 후 경과 지켜보기로

 

Current thread (0x71883000):  JavaThread "XNIO-2 task-54" [_thread_in_Java, id=8588, stack(0x66ce0000,0x66d30000)]

siginfo: si_signo: 11 (SIGSEGV), si_code: 1 (SEGV_MAPERR), si_addr: 0x01640117

 

2018.06.19

현재 odroid(개인서버) 의 swap 영역이 아예 안잡혀있음(램만 2기가)

혹시나 스왑영역이 세그멘테이션 폴트에 영향이 있을지 몰라서 2기가 정도의 스왑영역을 생성 적용

경과 지켜봐야 함

참고 : http://blog.dalli.kr/archives/1372

 

 

2018.06.28

Oracle JDK, 스왑영역 설정 후 해당 증상 재발하지 않는 중

 

Oracle JDK로 변경 후 문제해결이 된것이 아닌것 같아서, OpenJDK로 변경 후 경과 지켜보는 중..