Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

pinpoint agent 동작시 아래와 같은 IOException 발생 #1129

Closed
imjaebong opened this issue Oct 29, 2015 · 3 comments
Closed

pinpoint agent 동작시 아래와 같은 IOException 발생 #1129

imjaebong opened this issue Oct 29, 2015 · 3 comments
Assignees

Comments

@imjaebong
Copy link

안녕하세요.
windows 2012 에서 Agent를 동작시키면 아래과 같은 IO Exception이 발생하고 있습니다.
Collector는 다른 서버에 동작하고 있습니다.
어떤 부분을 검토해야 하나요?
방화벽 ? 아님 다른 설정???
참고로 설치한 버전은 GIT을 통해 MASTER 버전을 받아서 설치했습니다.

2015-10-29 15:17:41 [INFO ](c.n.p.r.s.DefaultPinpointServer :368) DefaultPinpointServer@7c9aff86 handleHandshake(). ResponseCode:SIMPLEX_COMMUNICATION
2015-10-29 15:17:41 [INFO ](c.n.p.r.c.PinpointClientHandshaker :239) PinpointClientHandshaker@77045ffc handshakeAbort method started.
2015-10-29 15:17:41 [INFO ](c.n.p.r.s.DefaultPinpointServer :373) DefaultPinpointServer@7c9aff86 handleHandshake() completed.
2015-10-29 15:17:41 [INFO ](c.n.p.r.c.PinpointClientHandshaker :247) PinpointClientHandshaker@77045ffc handshakeAbort method completed.
2015-10-29 15:17:41 [WARN ](o.j.n.c.SimpleChannelHandler :76) EXCEPTION, please implement com.navercorp.pinpoint.rpc.server.PinpointServerAcceptor$PinpointServerChannelHandler.exceptionCaught() for proper handling.
java.io.IOException: 현재 연결은 사용자의 호스트 시스템의 소프트웨어의 의해 중단되었습니다
at sun.nio.ch.SocketDispatcher.read0(Native Method)
at sun.nio.ch.SocketDispatcher.read(SocketDispatcher.java:43)
at sun.nio.ch.IOUtil.readIntoNativeBuffer(IOUtil.java:223)
at sun.nio.ch.IOUtil.read(IOUtil.java:192)
at sun.nio.ch.SocketChannelImpl.read(SocketChannelImpl.java:379)
at org.jboss.netty.channel.socket.nio.NioWorker.read(NioWorker.java:64)
at org.jboss.netty.channel.socket.nio.AbstractNioWorker.process(AbstractNioWorker.java:109)
at org.jboss.netty.channel.socket.nio.AbstractNioSelector.run(AbstractNioSelector.java:312)
at org.jboss.netty.channel.socket.nio.AbstractNioWorker.run(AbstractNioWorker.java:90)
at org.jboss.netty.channel.socket.nio.NioWorker.run(NioWorker.java:178)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)

@koo-taejin
Copy link
Member

전달주신 로그만을 가지고는 원인을 파악하기가 어렵습니다.

해당 시간대의 콜렉터, 에이전트의 양 로그를 전달주신다면 조금더 파악에 용이할 것 같네요.
(로그전달은 DEBUF 레벨로 설정후 전달을 부탁드립니다.)

추가로 내부적으로도 콜렉터 에이전트 서버간의 데이터 전달에 문제는 없는지 확인을 해보시는게 좋을 것 같습니다.

@koo-taejin koo-taejin self-assigned this Oct 29, 2015
@imjaebong
Copy link
Author

권한이 없어서 파일을 올리지 못하네요
log Level 은 INFO로 하여 찍은 데이터를 처음부터 에러가발생하는 시점까지 보내드립니다.
로그 Level로 DEBUG로 하면 IOException이 발생하지 않습니다..
그리고 Collector로 데이터를 잘 전달되고 있는것 같도
HBASE에서 잘 저장되고 있습니다.
그런데 WEB 상에는 데이터가 나오는게 하나도 없습니다.
1
2

2015-10-29 13:49:27 [INFO ](c.n.p.r.s.PinpointServerAcceptor :158) bind() /127.0.0.1:65535
2015-10-29 13:49:27 [INFO ](c.n.p.r.s.PinpointServerAcceptor :342) channelConnected channel:[id: 0xaa38a921, /127.0.0.1:58015 => /127.0.0.1:65535]
2015-10-29 13:49:27 INFO DefaultPinpointClientHandler@3232bf23 channelConnected() started. channel:[id: 0x02a2b348, /127.0.0.1:58015 => /127.0.0.1:65535]
2015-10-29 13:49:27 INFO DefaultPinpointClientHandler@3232bf23 stateTo() completed. Socket state change success(updateWanted:CONNECTED ,before:NONE ,current:CONNECTED).
2015-10-29 13:49:27 INFO DefaultPinpointClientHandler@3232bf23 stateTo() completed. Socket state change success(updateWanted:RUN_WITHOUT_HANDSHAKE ,before:CONNECTED ,current:RUN_WITHOUT_HANDSHAKE).
2015-10-29 13:49:27 [INFO ](c.n.p.r.c.PinpointClientHandshaker :82) PinpointClientHandshaker@4e318ff7 handshakeStart method started.
2015-10-29 13:49:27 [INFO ](c.n.p.r.s.DefaultPinpointServer :118) DefaultPinpointServer@566749c5 start() started. channel:[id: 0xaa38a921, /127.0.0.1:58015 => /127.0.0.1:65535].
2015-10-29 13:49:27 INFO DoNothingChannelStateEventHandler eventPerformed(). pinpointServer:DefaultPinpointServer@566749c5(remote:/127.0.0.1:58015, state:CONNECTED), code:CONNECTED
2015-10-29 13:49:27 INFO DefaultPinpointServer@566749c5 stateTo() completed. Socket state change success(updateWanted:CONNECTED ,before:NONE ,current:CONNECTED).
2015-10-29 13:49:27 INFO DoNothingChannelStateEventHandler eventPerformed(). pinpointServer:DefaultPinpointServer@566749c5(remote:/127.0.0.1:58015, state:RUN_WITHOUT_HANDSHAKE), code:RUN_WITHOUT_HANDSHAKE
2015-10-29 13:49:27 INFO DefaultPinpointServer@566749c5 stateTo() completed. Socket state change success(updateWanted:RUN_WITHOUT_HANDSHAKE ,before:CONNECTED ,current:RUN_WITHOUT_HANDSHAKE).
2015-10-29 13:49:27 [INFO ](c.n.p.r.s.DefaultPinpointServer :123) DefaultPinpointServer@566749c5 start() completed.
2015-10-29 13:49:27 [INFO ](c.n.p.r.c.PinpointClientHandshaker :116) PinpointClientHandshaker@4e318ff7 handshakeStart method completed. channel:[id: 0x02a2b348, /127.0.0.1:58015 => /127.0.0.1:65535], data:{socketId=1}
2015-10-29 13:49:27 [INFO ](c.n.p.r.s.DefaultPinpointServer :353) DefaultPinpointServer@566749c5 handleHandshake() started. Packet:ControlHandshakePacket{requestId=0, payloadLength=17}
2015-10-29 13:49:27 INFO DefaultPinpointClientHandler@3232bf23 channelConnected() completed.
2015-10-29 13:49:27 INFO handleHandshake properties:{socketId=1}
2015-10-29 13:49:27 INFO DefaultPinpointClientHandler@3232bf23 stateTo() completed. Socket state change success(updateWanted:BEING_CLOSE_BY_CLIENT ,before:RUN_WITHOUT_HANDSHAKE ,current:BEING_CLOSE_BY_CLIENT).
2015-10-29 13:49:27 INFO DoNothingChannelStateEventHandler eventPerformed(). pinpointServer:DefaultPinpointServer@566749c5(remote:/127.0.0.1:58015, state:RUN_SIMPLEX), code:RUN_SIMPLEX
2015-10-29 13:49:27 INFO DefaultPinpointServer@566749c5 stateTo() completed. Socket state change success(updateWanted:RUN_SIMPLEX ,before:RUN_WITHOUT_HANDSHAKE ,current:RUN_SIMPLEX).
2015-10-29 13:49:27 INFO DefaultPinpointClientHandler@3232bf23 channelClosed() started.
2015-10-29 13:49:27 [INFO ](c.n.p.r.s.DefaultPinpointServer :368) DefaultPinpointServer@566749c5 handleHandshake(). ResponseCode:SIMPLEX_COMMUNICATION
2015-10-29 13:49:27 INFO DefaultPinpointClientHandler@3232bf23 stateTo() completed. Socket state change success(updateWanted:CLOSED_BY_CLIENT ,before:BEING_CLOSE_BY_CLIENT ,current:CLOSED_BY_CLIENT).
2015-10-29 13:49:27 [INFO ](c.n.p.r.s.DefaultPinpointServer :373) DefaultPinpointServer@566749c5 handleHandshake() completed.
2015-10-29 13:49:27 [INFO ](c.n.p.r.c.PinpointClientHandshaker :239) PinpointClientHandshaker@4e318ff7 handshakeAbort method started.
2015-10-29 13:49:27 [WARN ](o.j.n.c.SimpleChannelHandler :76) EXCEPTION, please implement com.navercorp.pinpoint.rpc.server.PinpointServerAcceptor$PinpointServerChannelHandler.exceptionCaught() for proper handling.
java.io.IOException: 현재 연결은 사용자의 호스트 시스템의 소프트웨어의 의해 중단되었습니다
at sun.nio.ch.SocketDispatcher.read0(Native Method)
at sun.nio.ch.SocketDispatcher.read(SocketDispatcher.java:43)
at sun.nio.ch.IOUtil.readIntoNativeBuffer(IOUtil.java:223)
at sun.nio.ch.IOUtil.read(IOUtil.java:192)
at sun.nio.ch.SocketChannelImpl.read(SocketChannelImpl.java:379)
at org.jboss.netty.channel.socket.nio.NioWorker.read(NioWorker.java:64)
at org.jboss.netty.channel.socket.nio.AbstractNioWorker.process(AbstractNioWorker.java:109)
at org.jboss.netty.channel.socket.nio.AbstractNioSelector.run(AbstractNioSelector.java:312)
at org.jboss.netty.channel.socket.nio.AbstractNioWorker.run(AbstractNioWorker.java:90)
at org.jboss.netty.channel.socket.nio.NioWorker.run(NioWorker.java:178)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
2015-10-29 13:49:27 [INFO ](c.n.p.r.c.PinpointClientHandshaker :247) PinpointClientHandshaker@4e318ff7 handshakeAbort method completed.
2015-10-29 13:49:27 INFO DoNothingChannelStateEventHandler eventPerformed(). pinpointServer:DefaultPinpointServer@566749c5(remote:/127.0.0.1:58015, state:UNEXPECTED_CLOSE_BY_CLIENT), code:UNEXPECTED_CLOSE_BY_CLIENT
2015-10-29 13:49:27 INFO DefaultPinpointServer@566749c5 stateTo() completed. Socket state change success(updateWanted:UNEXPECTED_CLOSE_BY_CLIENT ,before:RUN_SIMPLEX ,current:UNEXPECTED_CLOSE_BY_CLIENT).
2015-10-29 13:49:27 [INFO ](c.n.p.p.l.Slf4jLoggerBinder :347) PLoggerFactory.initialize() bind:com.navercorp.pinpoint.profiler.logging.Slf4jLoggerBinder cl:com.navercorp.pinpoint.bootstrap.PinpointURLClassLoader@2596b73e

@koo-taejin
Copy link
Member

전달주신 로그처럼 최초에 발생하고 위처럼 이미지가 잘 보인다면. 정상적인 상황입니다.
커넥션 체크의 개념으로 최초에 연결이 가능여부를 확인하고 정상적인 연결을 한 후 종료하는 로직이 있기 때문입니다.

web에 아무데이터가 보이지 않는것은 agent가 설치된 톰캣서버에 요청을 보내시면 될 것 같습니다.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

2 participants