오라클 리스너 로그에 기록되는 오류. <unknown connect data> * 12537 또는 12569

내가 온사이트 상주 지원했던 곳에서의 경험을 기록한다.

오라클 리스너 로그에 아래의 내용이 반복적으로 기록되고 있었다.
IBM AIX의 경우 아래의 메시지 형태를 갖고 있다.

2020-08-24 19:24:20 * <unknown connect data> * 12537 TNS-12537: TNS:connection closed TNS-12560: TNS:protocol adapter error TNS-00507: Connection closed IBM/AIX RISC System/6000 Error: 55: Operation now in progress

또는

14-SEP-2017 13:11:20 * <unknown connect data> * 12569 TNS-12569: TNS:packet checksum failure

고객 사이트의 경우 첫번째 메시지가 반복되고 있었다.
너무 많은 양이 기록되다 보니 단시간에 리스너 로그의 사이즈까지 비정상적으로 커져 문제가 된다.

이 에러는 쉽게 테스트가 가능하다.
ssh ssh -p <리스너 포트> <oracle계정>@<DB서버 호스트>
이 명령을 수행하고 중지만 해도 리스너 로그에 동일한 내용이 기록된다.
즉, 어디에선가 리스너 포트로 패킷을 계속 날리고 있는 것이다. 하지만 정상적인 sqlnet 패킷이 아니기 때문에 리스너는 이해하지 못하는 패킷으로 기록하고 있는 것이다.

그럼 어디에서 DB의 리스너 포트를 계속 찔러보는 건가?
리스너는 Trace file에 추가로 자세한 내용을 기록하고 있다. Trace file에서 확인 할 수 있다.

먼저 리스너 Trace file에서 "ns=12537" 에러메시지를 찾는다.

... [2020-08-24 19:24:29:546] ntt2err: Read unexpected EOF ERROR on 14 [2020-08-24 19:24:29:546] ntt2err: exit [2020-08-24 19:24:29:546] nsprecv: error exit [2020-08-24 19:24:29:546] nserror: entry [2020-08-24 19:24:29:546] nserror: nsres: id=5, op=68, ns=12537, ns2=12560; nt[0]=507, nt[1]=0, nt[2]=0; ora[0]=0, ora[1]=0, ora[2]=0 [2020-08-24 19:24:29:546] nscon: error exit [2020-08-24 19:24:29:546] nsdo: nsctxrnk=0 [2020-08-24 19:24:29:546] nsdo: error exit ...

에러를 찾은 곳에서 위로 올라가 보면 아래와 같이 Accepted Entry 구문과 함께 기록된 IP를 확인 할 수 있다.

... [2020-08-24 19:24:29:542] nsevfnt: cxd: 0x1058e5b0 stage 0: NT events set:CONNECTION REQUEST [2020-08-24 19:24:29:542] nsevfnt: cxd: 0x1058e5b0 stage 0: NS events set:INCOMING CALL ... [2020-08-24 19:24:29:543] snlinGetNameInfo: entry [2020-08-24 19:24:29:543] snlinGetNameInfo: exit [2020-08-24 19:24:29:543] nttvlser: valid node check on incoming node xx.xx.40.32 [2020-08-24 19:24:29:543] nttvlser: Accepted Entry: xx.xx.40.32 ...

위의 로그 내용은 오라클 MOS문서(Doc ID 1664901.1)에 있는 내용이다. 내가 온사이트 지원했던 고객 사이트에서 실제로 동일한 경험을 했기 때문에 기술했다. (고객 사이트에서 로그를 가지고 나올 수는 없으니까)

자, 어느 머신에서 오라클 DB서버로 계속 찔러보고 있는지까지 알아냈다.
그럼 어떻게 할 것인가?
오라클 MOS문서(Doc ID 1664901.1)에서는 추가로 이에 대한 내용까지 언급하고 있다.
아래의 경우 12569가 기록된다고 하였다.
1. Apache Tomcat에서 리스너 포트가 설정되어 있는 경우
2. WebLogic의 ONS 세팅에서 ONS 포트가 아닌 SCAN포트로 잘못 설정한 경우
3. F5 Network의 big-IP 로드밸런싱 스위치장비에서 TCP포트를 스캔하는 경우

이외에도 리스너 로그의 Trace file에 기록된 IP로 해당 장비에서 왜 리스너 포트로 찔러보는지 면밀하게 분석해 잘못 셋업된 것인지 그렇지 않다면 변경이 가능한지 후속작업을 해야 할 것이다.

수시로 로깅이 되는 것을 봤을때 대부분의 경우 Health Check세팅을 정상적으로 해 놓지 않았을 가능성이 높다. DB포트만 찔러보는 형태이기 때문에 위와 같은 오류가 계속 로깅되는 것이다.
예를 들어 3번 F5의 L4/L7 로드밸런싱 스위치의 경우 엔지니어들은 Application까지는 잘 모르는 경우들이 대부분이다.
F5 Networks의 AskF5 페이지를 보면 Oracle database를 비롯한 다양한 제품군의 Health Check Monitoring을 위한 내용들이 나온다. 중간을 보면 Oracle database모니터링 셋업부분이 나온다.
이 내용에 따르면 정상적으로 셋업한 경우 F5스위치에서는 일정시간(Interval)마다 셋업한 오라클 DB account 로 login/logout을 함으로써 DB의 정상유무를 판단한다.
DBA는 F5에 들어가 있는 오라클 계정에 대하여 알고 있어야 하는데 이게 쉬운게 아닐 것이다.
게다가 셋업한 계정을 알고 있는 것으로 끝나지 않는다.
- DB계정 생성. 서비스 계정을 F5에 셋업할 것인가? 당연히 안된다. 이것도 면밀한 분석이 이루어 져야 한다.
다른 SW인 Apache Tomcat, WebLogic에서도 동일한 방법으로 Health Check를 한다면 위에서 생성한 DB계정으로 함께 사용하면 될 것이다.
- DB계정의 프로파일 셋업.
- DB계정의 권한 셋업
- 패스워드 만료 Unlimited 필요

DB계정을 이렇게 계정을 셋업한다고 끝나지 않는다. 패스워드 만료가 없는 계정은 보안 위배인데 어떻게 해야 할까...
보안 담당자가 있다면 협의가 필요할 것이다. 만약 시스템 정기PM(Periodic Maintenance)가 있다면 정기PM때 패스워드를 변경해주는 것도 방법이 될 수 있다. 하지만 다른 할일이 많은데 Health Check를 위한 DB계정 패스워드 변경까지 관리 범위에 넣게 된다면 일이 상당히 커질 것 같다. 패스워드 관리 솔루션등 다양한 방법에 대한 고민이 필요해 보인다.

신경쓸게 한두가지가 아니다. DBA는 피곤하다.

* 참고 문서 : 오라클 MOS문서 Doc ID 1664901.1 (오라클 MOS 접속 계정 필요)

* 관련 글
2022.05.02 - [IT] - 오라클 리스너(Listener) 로그 분석 Shell : 접속 IP목록