메뉴 건너뛰기

검색창 닫기

Korea Oracle User Group

Admin

ORA-3136 inbound connection time out & JDBC Io exception: Connection reset

Talros 2023.02.24 14:11 조회 수 : 1319 추천:1


 개발자로 부터 디비로 접속 하는 과정에서 간헐적으로 에러가 발생을 한다는 문의를 받게 되어 로그를 확인 해보니 비슷한 시간대에 ORA-3136 이 발생 하는 것을 확인 했습니다.

 

[2023-02-09 16:31:06.127] [ERROR] [main] [CommandLineJobRunner][355] Job Terminated in error: Error creating bean with name 'jobOperator' defined in class path resource [batch-context.xml]: Cannot resolve reference to bean 'jobLauncher' while setting bean property 'jobLauncher'; nested exception is org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'jobLauncher' defined in class path resource [batch-context.xml]: Cannot resolve reference to bean 'jobRepository' while setting bean property 'jobRepository'; nested exception is org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'jobRepository' defined in class path resource [batch-context.xml]: Invocation of init method failed; nested exception is org.springframework.jdbc.support.MetaDataAccessException: Could not get Connection for extracting meta data; nested exception is org.springframework.jdbc.UserSyncFromCandyMenualJob: Could not get JDBC Connection; nested exception is org.apache.commons.dbcp.Job Terminated in error: Err: Cannot create PoolableConnectionFactory (Io exception: Connection reset)

 

 해당 에러가 alert log 에 발생을 하는 이유는 

 오라클 넷 파라미터인 SQLNET.INBOUND_CONNECT_TIMEOUT 과 INBOUND_CONNECT_TIMEOUT_listener_name (디폴트 60초) 에 의해
 클라이언트가 자격 증명을 제공하지 못하거나 어떠한 이유든지 60초 이내에 인증 프로세스를 마치지 못하는 경우 이러한 오류가 발생됩니다.

 

 : 예 ) alert log 에서 발생한 로그

 

Thu Feb 23 15:57:49 2023   << 메시지가 발생 한 시점
 
 
***********************************************************************
 
Fatal NI connect error 12170.
 
  VERSION INFORMATION:
        TNS for Linux: Version 12.1.0.2.0 - Production
        Oracle Bequeath NT Protocol Adapter for Linux: Version 12.1.0.2.0 - Production
        TCP/IP NT Protocol Adapter for Linux: Version 12.1.0.2.0 - Production
  Time: 23-2월 -2023 15:57:49
  Tracing not turned on.
  Tns error struct:
    ns main err code: 12535
    
TNS-12535: TNS:작동이 중단중입니다
    ns secondary err code: 12606
    nt main err code: 0
    nt secondary err code: 0
    nt OS err code: 0
  Client address: (ADDRESS=(PROTOCOL=tcp)(HOST=192.168.0.10)(PORT=47704))   << 포트 번호를 확인 합니다.
Thu Feb 23 15:57:49 2023
WARNING: inbound connection timed out (ORA-3136)

 

: 예 ) listener.log

 

23-2월 -2023 15:56:49 * (CONNECT_DATA=(SID=testdb)(CID=(PROGRAM=JDBC Thin Client)(HOST=__jdbc__)(USER=oracle))) * (ADDRESS=(PROTO
COL=tcp)(HOST=192.168.0.10)(PORT=47704)) * establish * testdb * 0. << alert log 에서 확인 한 포트와 같은 접속 로그를 보면 
60초 전에 접속을 한 것을 확인 할 수 있다.

 

오라클에서 가이드 하는 점검 방법 입니다.

1. 데이터베이스 서버에 로컬 연결 성공 및 속도를 확인한다.
2. 로컬 연결이 빠른 경우, 네트워크 관리자의 도움하에 네트워크 지연을 확인한다.
3. 데이터베이스 성능 저하 여부를 확인한다.
4. 경고 로그에 중요한 오류를 확인하고 먼저 해결한다. 예, ORA-600 또는 ORA-7445.
    이런 중요한 오류는 데이터베이스 서버의 속도 저하를 일으킬 수 있다.

 

클라이언트 서버 역시 OS,서버,네트워크 부하를 확인 했지만 이상이 없었습니다.

 

클라이언트가 60초 이내에 접속을 못 하는 다른 사례를 확인 하기 위해 조사 하는 중 jdbc 관련 된 내용을 하나 발견 했습니다.

 

JDBC - Version 11.2.0.1.0 and later
Information in this document applies to any platform.
JDBC connection establishment with 11.2.x databases uses a new connection mechanism (o5logon) that requires the use of random numbers. These numbers are typically generated by a special device (/dev/random). However, this random number generator relies on entropy in order to generate sufficiently random numbers. This entropy comes from things like mouse pointer movement and keyboard entry. When there is insufficient entropy, the random number generator will not return any numbers. When this happens, the o5logon used by the JDBC library stalls, and has to wait until sufficient entropy is available. To address this issue, /dev/urandom is used instead. This device does not block, so JDBC connection establishment is not delayed.

 

JDBC 11.2.0.1 버전 이후 접속 메카니즘 변경으로 난수가 필요 하게 되었습니다.  JDBC 에서 사용 하는 난수는 /dev/random 에서 생산 후 저장 하는 entropy pool 에서 꺼내 쓰게

되는데 기본 적으로 해당 풀을 소모하다 일정 수치 이하로 내려 가게 되면 난수가 생성 될 때 까지 대기를 하게 되어 접속이 지연 될 수 있고 이를 해결 하기 위해 난수 생성 대기를 하지

않는  /dev/urandom  를 이용 하라는 내용 입니다.

 

실제 위의 사례에 의한 것인지 테스트 해보기로 하였습니다.

 

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
# 테스트에 사용한 스크립트 
 
import java.sql.*;
public class DBConnTest {
 
public static void main(String[] args) {
 
  Connection conn=null;
 
  try {
 
        Class.forName("oracle.jdbc.driver.OracleDriver");
        System.out.println("JDBC Driver Loading Success");
        long start = System.currentTimeMillis();
        conn=DriverManager.getConnection("jdbc:oracle:thin:@192.168.0.10:1521:testdb", "system", "oracle");
        System.out.println(args[0] + " Connected..");
        long stop = System.currentTimeMillis();
        System.out.println(args[0] + " connected Time" + (stop - start) + " ms.");
 
        conn.close();
 
  } catch (ClassNotFoundException cnfe) {
        System.out.println(args[0] + " Not Found Class.."+cnfe.getMessage());
  } catch(SQLException se){
        System.out.println(args[0] + " " + se.getMessage());
  } finally {
        if(conn != null)   try {conn.close();} catch (SQLException e) { e.printStackTrace();}
   }
 }
}

 

엔트로피 확인을 위한 스크립트

 

1
2
3
4
5
while [ 1 ];do
date
cat /proc/sys/kernel/random/entropy_avail
sleep 1
done

 

java 를 실행

 



testora.localdomain@oracle:testdb:/home/oracle/DBA/script/SHELL/java> java DBConnTest 1 &
[1] 28535
testora.localdomain@oracle:testdb:/home/oracle/DBA/script/SHELL/java> java DBConnTest 2 &
[2] 28536
testora.localdomain@oracle:testdb:/home/oracle/DBA/script/SHELL/java> java DBConnTest 3 &
[3] 28537
testora.localdomain@oracle:testdb:/home/oracle/DBA/script/SHELL/java> java DBConnTest 4 &
[4] 28538
testora.localdomain@oracle:testdb:/home/oracle/DBA/script/SHELL/java> java DBConnTest 5 &
[5] 28539
testora.localdomain@oracle:testdb:/home/oracle/DBA/script/SHELL/java> java DBConnTest 6 &
[6] 28540
testora.localdomain@oracle:testdb:/home/oracle/DBA/script/SHELL/java> java DBConnTest 7 &
[7] 28541
testora.localdomain@oracle:testdb:/home/oracle/DBA/script/SHELL/java> java DBConnTest 8 &
[8] 28542
testora.localdomain@oracle:testdb:/home/oracle/DBA/script/SHELL/java> java -Doracle.jdbc.Trace=true -Djava.util.logging.config.file=/home/oracle/DBA/script/SHELL/java/Logging.properties DBConnTest 9 &  << 9번 째 프로세스에는 Trace 를 남김
[9] 28551
testora.localdomain@oracle:testdb:/home/oracle/DBA/script/SHELL/java> java DBConnTest 10 &
[10] 28673
testora.localdomain@oracle:testdb:/home/oracle/DBA/script/SHELL/java> JDBC Driver Loading Success
  BC Driver Loading Success
JDBC Driver Loading Success
JDBC Driver Loading Success
JDBC Driver Loading Success
JDBC Driver Loading Success
JDBC Driver Loading Success
JDBC Driver Loading Success
JDBC Driver Loading Success
JDBC Driver Loading Success
7 Connected..
7 connected Time3252 ms.
6 Connected..
6 connected Time37429 ms.
4 Connected..
4 connected Time41950 ms.
10 Connected..
10 connected Time43501 ms.
1 Connected..
1 connected Time52981 ms.
2 IO Error: Connection reset    << 프로그램 접속이 안되고 에러가 발생
9 IO Error: Connection reset    << 9 번째 역시 접속이 안되고 에러가 발생 
8 IO Error: Connection reset
3 IO Error: Connection reset
5 IO Error: Connection reset

 

 

JDBC trace 내용 에서 포트를 확인

 


Feb 24, 2023 1:26:58 PM oracle.net.ns.NSProtocol establishConnection
TRACE_20: 39BA5A14 Debug: Session Attributes:
sdu=8192, tdu=2097152
nt: host=192.168.0.10, port=1521
    socket_timeout=60000, socketOptions={20=false, 18=false, 17=0, 2=60000, 24=50, 23=40, 1=NO, 0=YES}
    socket=Socket[addr=/192.168.0.10,port=1521,localport=50303]

ntInputStream : java.net.SocketInputStream@38082d64
 

 

alert log 에서 같은 포트의 메세지 확인

 


Fatal NI connect error 12170.

  VERSION INFORMATION:
        TNS for Linux: Version 12.1.0.2.0 - Production
        Oracle Bequeath NT Protocol Adapter for Linux: Version 12.1.0.2.0 - Production
        TCP/IP NT Protocol Adapter for Linux: Version 12.1.0.2.0 - Production
  Time: 24-2월 -2023 13:27:58
  Tracing not turned on.
  Tns error struct:
    ns main err code: 12535
    
TNS-12535: TNS:작동이 중단중입니다
    ns secondary err code: 12606
    nt main err code: 0
    nt secondary err code: 0
    nt OS err code: 0
  Client address: (ADDRESS=(PROTOCOL=tcp)(HOST=192.168.0.10)(PORT=50303))
Fri Feb 24 13:27:58 2023
WARNING: inbound connection timed out (ORA-3136)

 

listener log 에서 1분 전 접속 후 에러 확인

 

24-2월 -2023 13:26:58 * (CONNECT_DATA=(SID=testdb)(CID=(PROGRAM=JDBC Thin Client)(HOST=__jdbc__)(USER=oracle))) * (ADDRESS=(PROTO
COL=tcp)(HOST=192.168.0.10)(PORT=50303)) * establish * testdb * 0

 

 

엔트로피 확인 내용

 


Fri Feb 24 13:27:53 KST 2023
55
Fri Feb 24 13:27:54 KST 2023
21
Fri Feb 24 13:27:55 KST 2023
42
Fri Feb 24 13:27:56 KST 2023
50
Fri Feb 24 13:27:57 KST 2023
21
Fri Feb 24 13:27:58 KST 2023
3
Fri Feb 24 13:27:59 KST 2023
3
Fri Feb 24 13:28:00 KST 2023
35
Fri Feb 24 13:28:01 KST 2023
53
Fri Feb 24 13:28:02 KST 2023
10
Fri Feb 24 13:28:03 KST 2023
25
Fri Feb 24 13:28:04 KST 2023
45
Fri Feb 24 13:28:05 KST 2023
55
Fri Feb 24 13:28:06 KST 2023
2
Fri Feb 24 13:28:07 KST 2023
32
Fri Feb 24 13:28:08 KST 2023
49
Fri Feb 24 13:28:09 KST 2023
10
Fri Feb 24 13:28:10 KST 2023
20
Fri Feb 24 13:28:11 KST 2023
45
Fri Feb 24 13:28:12 KST 2023
60
Fri Feb 24 13:28:13 KST 2023
60
Fri Feb 24 13:28:14 KST 2023
18
Fri Feb 24 13:28:15 KST 2023
61
Fri Feb 24 13:28:16 KST 2023
148
Fri Feb 24 13:28:17 KST 2023
128
Fri Feb 24 13:28:18 KST 2023
132
Fri Feb 24 13:28:19 KST 2023
132

 

 

 접속 테스트 이후 엔트로피가 100 이상으로 회복 하는 것을 확인 할 수 있다.

 

 난수를 /dev/urandom 으로 변경 후 접속 테스트

 

 -Djava.security.egd=file:///dev/urandom 옵션으로 강제로 변경

 



testora.localdomain@oracle:testdb:/home/oracle/DBA/script/SHELL/java> java -Djava.security.egd=file:///dev/urandom DBConnTest 1 &
[1] 30011
testora.localdomain@oracle:testdb:/home/oracle/DBA/script/SHELL/java> java -Djava.security.egd=file:///dev/urandom DBConnTest 2 &
[2] 30012
testora.localdomain@oracle:testdb:/home/oracle/DBA/script/SHELL/java> java -Djava.security.egd=file:///dev/urandom DBConnTest 3 &
[3] 30015
testora.localdomain@oracle:testdb:/home/oracle/DBA/script/SHELL/java> java -Djava.security.egd=file:///dev/urandom DBConnTest 4 &
[4] 30017
testora.localdomain@oracle:testdb:/home/oracle/DBA/script/SHELL/java> java -Djava.security.egd=file:///dev/urandom DBConnTest 5 &
[5] 30052
testora.localdomain@oracle:testdb:/home/oracle/DBA/script/SHELL/java> java -Djava.security.egd=file:///dev/urandom DBConnTest 6 &
[6] 30059
testora.localdomain@oracle:testdb:/home/oracle/DBA/script/SHELL/java> java -Djava.security.egd=file:///dev/urandom DBConnTest 7 &
[7] 30061
testora.localdomain@oracle:testdb:/home/oracle/DBA/script/SHELL/java> java -Djava.security.egd=file:///dev/urandom DBConnTest 8 &
[8] 30066
testora.localdomain@oracle:testdb:/home/oracle/DBA/script/SHELL/java> java -Djava.security.egd=file:///dev/urandom -Doracle.jdbc.Trace=true -Djava.util.logging.config.file=/home/oracle/DBA/script/SHELL/java/Logging.properties DBConnTest 9 &
[9] 30074
testora.localdomain@oracle:testdb:/home/oracle/DBA/script/SHELL/java> java -Djava.security.egd=file:///dev/urandom DBConnTest 10 &
[10] 30086
testora.localdomain@oracle:testdb:/home/oracle/DBA/script/SHELL/java> JDBC Driver Loading Success
JDBC Driver Loading Success
JDBC Driver Loading Success
JDBC Driver Loading Success
JDBC Driver Loading Success
JDBC Driver Loading Success
JDBC Driver Loading Success
JDBC Driver Loading Success
JDBC Driver Loading Success
JDBC Driver Loading Success
3 Connected..
3 connected Time3470 ms.
6 Connected..
6 connected Time3141 ms.
7 Connected..
7 connected Time3500 ms.
10 Connected..
10 connected Time3091 ms.
1 Connected..
1 connected Time4026 ms.
2 Connected..
2 connected Time4266 ms.
4 Connected..
4 connected Time4108 ms.
5 Connected..
5 connected Time3873 ms.
9 Connected..
9 connected Time3247 ms.
8 Connected..
8 connected Time3430 ms.

 

디비 시스템의 부하가 없음에도 클라이언트 접속 에러가 발생을 하면 위의 사례를 확인 해보면 좋을 거 같습니다.

 

참조 문서 : 문제해결 가이드 ORA-3136: WARNING Inbound Connection Timed Out (Doc ID 2115564.1)

 

, , , , , , 이 게시물을
목록
번호 제목 글쓴이 날짜 조회 수
34 Windows 접속 에러 ORA-12638 [1] file Talros 2024.02.14 413
33 Python 을 이용해 파일 업로드 해 보기 [1] file Talros 2023.04.19 987
32 수집된 통계가 바로 반영되지 않고 원할 때 반영하도록 하는 방식 명품관 2023.04.04 667
31 ORA-28014: Cannot Drop Administrative Users 에러 현상 [1] 명품관 2023.03.27 1052
» ORA-3136 inbound connection time out & JDBC Io exception: Connection reset [1] Talros 2023.02.24 1319
29 default 값을 포함한 컬럼 추가시 오라클 버전별 개선 사항 [1] 명품관 2023.01.17 1168
28 mbr(multi block read) 과 sbr(single block read) 사이에 과연 어떤 방식을 선택해야 할까요? [1] 명품관 2022.09.16 717
27 Schema password 재 사용 불가능 하게 하기 [1] Talros 2022.01.26 1961
26 Pga 메모리 설정관련 내용 [1] 우뽕 2021.03.05 2307
25 DB option Enable / Disable 정리 방법 - Mos 참고 file 우뽕 2021.01.31 1387
24 RECO 프로세스 트레이스 발생 하면서 ORA-02019 에러 발생시 명품관 2021.01.12 1414
23 OS 터미널 접속 없이 오라클 접속을 통해 OS CPU 사용율 모니터링 하기 [3] file 명품관 2020.12.22 1118
22 SQL Plan Management(SPM) - 3 Manual Plan Capture 명품관 2020.06.01 1042
21 SQL Plan Management(SPM) - 2 DBMS_SPM.CONFIG로 필터링 file 명품관 2020.03.26 917
20 SQL Plan Management(SPM) - 1 파라미터의 기능 확인 명품관 2020.03.19 1417
19 [12cR2 이상] 오브젝트 이름 30자이상 사용 가능 우뽕 2020.01.22 7932
18 Alert log 에서 갑자기 패치 정보가 나타나는 현상 Talros 2019.09.23 1971
17 External Table 기능을 사용해 파일 읽기 명품관 2017.04.05 1082
16 DBMS_SCHEDULER을 통해 OS 레벨(EXTERNAL)의 shell 수행하기 명품관 2017.04.05 5915
15 오라클 패치 정보를 조회할 수 있는 뷰 DBA_REGISTRY_SQLPATCH 명품관 2017.03.02 5834
쓰기 태그
위로