프로젝트/Pinpoint, Scouter 구축(APM)
[Pinpoint]startTimestamp must be less than endTimestamp 에러
블랑v
2024. 1. 24. 13:43
오류 상황
java.lang.IllegalArgumentException: startTimestamp must be less than endTimestamp
at com.navercorp.pinpoint.web.vo.timeline.inspector.AgentStatusTimelineBuilder$AgentLifeCycle.<init>(AgentStatusTimelineBuilder.java:311)
at com.navercorp.pinpoint.web.vo.timeline.inspector.AgentStatusTimelineBuilder$AgentLifeCycle.<init>(AgentStatusTimelineBuilder.java:300)
at com.navercorp.pinpoint.web.vo.timeline.inspector.AgentStatusTimelineBuilder.createAgentLifeCycle(AgentStatusTimelineBuilder.java:236)
at com.navercorp.pinpoint.web.vo.timeline.inspector.AgentStatusTimelineBuilder.createAgentLifeCycles(AgentStatusTimelineBuilder.java:207)
at com.navercorp.pinpoint.web.vo.timeline.inspector.AgentStatusTimelineBuilder.createTimelineSegments(AgentStatusTimelineBuilder.java:196)
at com.navercorp.pinpoint.web.vo.timeline.inspector.AgentStatusTimelineBuilder.build(AgentStatusTimelineBuilder.java:100)
at com.navercorp.pinpoint.web.service.AgentInfoServiceImpl.getAgentStatusTimeline(AgentInfoServiceImpl.java:341)
at com.navercorp.pinpoint.web.controller.AgentInfoController.getAgentStatusTimeline(AgentInfoController.java:167)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:197)
at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:141)
at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:106)
at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:894)
at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:808)
at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:87)
at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:1060)
at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:962)
at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:1006)
at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:898)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:645)
at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:883)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:750)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:227)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162)
at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:53)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:189)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162)
at com.navercorp.pinpoint.web.servlet.RewriteForV2Filter.doFilter(RewriteForV2Filter.java:93)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:189)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162)
at org.springframework.web.filter.ShallowEtagHeaderFilter.doFilterInternal(ShallowEtagHeaderFilter.java:106)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:189)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162)
at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:201)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:189)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162)
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:202)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:97)
at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:542)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:143)
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:92)
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:78)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:357)
at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:374)
at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:65)
at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:893)
at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1707)
at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
at java.lang.Thread.run(Thread.java:750)
원인 분석
이 오류의 원인은 시간 관련 데이터 처리에 있다.
Pinpoint Inspector는 에이전트의 상태 변화와 메트릭을 시간에 따라 표시한다.
에러 메시지를 해석해 보자면, 시작 타임스탬프(startTimestamp)가 종료 타임스탬프(endTimestamp)보다 크거나 같을 때 발생합니다. 이는 로그 데이터의 시간 순서가 올바르지 않음을 나타낸다.
아마도 문제는 데이터 수집 과정에서의 버그, 시스템 시계의 불일치, 또는 데이터베이스 내의 잘못된 데이터로 인해 발생하는 것이 주 이유일 것이다.
해결 과정
1. time data 확인 (Server log)
먼저 시작 시간이 늦은 데이터를 확인해봐야 할 것 같다.
01-23 06:36:17.017 [nio-8180-exec-9] WARN c.n.p.w.c.ControllerExceptionHandler -- Failed to execute controller methods. message:startTimestamp must be less than endTimestamp, request:RequestInfo{method='GET', url='http://192.168.56.1:8180/getAgentStatusTimeline.pinpoint', headers={referer=[http://192.168.56.1:8180/inspector/AiwacsTestServer@TOMCAT/5m/2024-01-23-06-36-09/Agent240122], accept-language=[ko-KR,ko;q=0.9,en-US;q=0.8,en;q=0.7], cookie=[_ga=GA1.1.779371622.1705393100; _gid=GA1.1.425655985.1705881482; SCOUTER=x3esu769oiv91d; _gat=1; _ga_QZJBSCYW27=GS1.1.1706068835.25.1.1706069174.0.0.0], host=[192.168.56.1:8180], connection=[keep-alive], accept-encoding=[gzip, deflate], accept=[application/json, text/plain, */*], user-agent=[Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/120.0.0.0 Safari/537.36]}, parameters={agentId=[Agent240122], from=[1705958469000], exclude=[10199], to=[1705959369000]}}.
Web log중 일부
01-23 06:36:17.017 [nio-8180-exec-9] WARN c.n.p.w.c.ControllerExceptionHandler
-- Failed to execute controller methods.
message:startTimestamp must be less than endTimestamp,
request:RequestInfo{
method='GET',
url='http://192.168.56.1:8180/getAgentStatusTimeline.pinpoint',
headers={
referer=[http://192.168.56.1:8180/inspector/AiwacsTestServer@TOMCAT/5m/2024-01-23-06-36-09/Agent240122],
accept-language=[ko-KR,ko;q=0.9,en-US;q=0.8,en;q=0.7],
cookie=[_ga=GA1.1.779371622.1705393100; _gid=GA1.1.425655985.1705881482; SCOUTER=x3esu769oiv91d; _gat=1; _ga_QZJBSCYW27=GS1.1.1706068835.25.1.1706069174.0.0.0],
host=[192.168.56.1:8180],
connection=[keep-alive],
accept-encoding=[gzip, deflate],
accept=[application/json, text/plain, */*],
user-agent=[Mozilla/5.0 (Windows NT 10.0; Win64; x64)
AppleWebKit/537.36 (KHTML, like Gecko) Chrome/120.0.0.0 Safari/537.36]},
parameters={agentId=[Agent240122], from=[1705958469000], exclude=[10199], to=[1705959369000]
}
}.
parameter를 살펴보면 to - from이 양수인 것으로 보아 시간이 크게 문제가 있지는 않은 것 같다.
2. 서버 시간 동기화 문제 확인
date 명령어로 서버의 시간을 확인해보자.
Collector 시간 확인
Tomcat 서버 시간 확인
확실히 서버 시간이 한시간 밀려있음을 확인할 수 있다. 이를 동일하게 바꿔주도록 하자.
자세한 방법은 다음 포스팅에서 정리하였다.
https://csg1353.tistory.com/152
[CentOS] 표준 시간대 변경 및 동기화
리눅스 상에서 표준 시간대를 재설정하고, 동기화하는 명령어를 정리하였다. 1. Timezone 변경 서버의 시간대를 KST 한국 기준으로 변경하려면 다음과 같이 설정하자. sudo timedatectl set-timezone Asia/Seoul
csg1353.tistory.com
3. 이전 데이터 삭제(초기화)
하지만, 이렇게 설정해도 여전히 에러가 발생한다.
이전 수집 데이터의 문제라고 판단하여 hbase 하위 폴더를 삭제하고 테이블을 다시 설치하기로 하였다.
테스트용 서버라 이렇게 가능한 것이니, 혹시 따라하는 사용자가 있다면 주의할 것!! 초기화랑 동일하다.
hbase 설치 폴더 - bin 이동. 이후 start-hbase.sh 실행.
이후, pinpoint에서 제공하는 table 설치 스크립트를 시작하자.
기본적으로 hbase-create.hbase일 것이다.
./hbase shell hbase-create.hbase