발생내용
IBM JVM 1.5 SR7, 1.4 SR11에서는 동일 로직임에도 불구하고 hang up 현상이 발생합니다.
원인분석
일반적으로 java에서 close() signal이 발생을 하면, 기존 SR7 이전 버전에서는 native shutdown 루틴은 block되지 않기 때문에 hang up 현상이 발생하지 않았습니다.
하지만 IBM JVM 1.5 SR7, 1.4 SR11에서는 동일 로직임에도 불구하고 hang up 현상이 발생합니다.
타 OS와 비교 분석을 해보면,
일반적으로 다른 OS에서는 java에서 close() 호출 시, native poll에서 “POLLNVAL”이라는 event가 발생한 뒤, socket이 close되는 작업이 수행됩니다.
=========================
POLLNVAL : The specified fd value does not belong to an open file.
This flag is only valid in the revents member; it is not used in the events member.
=========================
하지만 AIX의 경우,
java에서 close를 이벤트로 인식하지 않는 것으로 보여집니다. 때문에 close() 호출 시, native poll에서 특정 이벤트가 발생하지 않고 wait()상태로 전이가 됩니다.
즉, 정리하자면, Java의 close() 후, socket 종료 루틴에 의해 fd를 lock합니다. 하지만 이미 이전에 해당 fd를 관리하는 poll에는 어떠한 이벤트를 발생하지 않기 때문에 hang up현상이 발생하는 것으로 보여집니다.
IBM Java1.5SR7에서 native IO 사용시 hang up이 발생하는 원인은 AIX에서의 java1.5 SR7에서 socket close()시 logic이 변경되어 발생하는 것으로 추정합니다.
UPDATE=======
이슈는 CR370915에서 진행되었던 내용으로,IBM의 AIX JVM 1.5 SR7의 경우 socket close시 hang 현상이 발생하는 문제입니다.
발생하는 경우는,Performance Pack(Native IO)이 on된 상태에서,socket에 대해 polling을 하는 도중에KeepAlive 시간이 경과하여 scheduler가 해당 socket을 close 하려 할 때hang이 되는 현상입니다.
thread dump를 보면 보통 다음과 같은 stack trace를 볼 수 있습니다.
=='[ACTIVE] ExecuteThread: '5' for queue: 'weblogic.kernel.Default (self-tuning)'' (TID:0x438F2000, sys_thread_t:0x438F9EF8, state:R, native ID:0x0037F035) prio=5
at java/net/PlainSocketImpl.socketClose0(Native Method)at java/net/PlainSocketImpl.socketPreClose(PlainSocketImpl.java:744(Compiled Code))
at java/net/PlainSocketImpl.close(PlainSocketImpl.java:568(Compiled Code))
at java/net/SocksSocketImpl.close(SocksSocketImpl.java:1049(Compiled Code))
at java/net/Socket.close(Socket.java:1341(Compiled Code))
at weblogic/socket/WeblogicSocket.close(WeblogicSocket.java:80(Compiled Code))
at weblogic/socket/SocketMuxer.closeSocket(SocketMuxer.java:449(Compiled Code))
at weblogic/socket/SocketMuxer.cancelIo(SocketMuxer.java:773)
at weblogic/socket/SocketMuxer$TimerListenerImpl.timerExpired(SocketMuxer.java:976(CompiledCode))
at weblogic/timers/internal/TimerImpl.run(TimerImpl.java:273(Compiled Code))
at weblogic/work/SelfTuningWorkManagerImpl$WorkAdapterImpl.run(SelfTuningWorkManagerImpl.java:464(CompiledCode))
at weblogic/work/ExecuteThread.execute(ExecuteThread.java:197(Compiled Code))
at weblogic/work/ExecuteThread.run(ExecuteThread.java:172(Compiled Code))
'ExecuteThread: '7' for queue: 'weblogic.socket.Muxer'' (TID:0x3511B500, sys_thread_t:0x34FAD6C8, state:R, native ID:0x003E80CB) prio=5
at weblogic/socket/PosixSocketMuxer.poll(Native Method)
at weblogic/socket/PosixSocketMuxer.processSockets(PosixSocketMuxer.java:102)
at weblogic/socket/SocketReaderRequest.run(SocketReaderRequest.java:29)
at weblogic/socket/SocketReaderRequest.execute(SocketReaderRequest.java:42)
at weblogic/kernel/ExecuteThread.execute(ExecuteThread.java:145)
at weblogic/kernel/ExecuteThread.run(ExecuteThread.java:117)
==타이밍 이슈로 IBM AIX 최신 JVM에서만 발생합니다.
Hi, I have similar issue on IBM AIX 5.3/JVM 1.5 SR 9/Weblgic, seems JVM could not close tcpip socket quickly.
답글삭제Could you provide me with more information?
(I could not see korea languge) :-)
thanks a lot!
Jiang Yang