Why is Servery map only the Tomcat icon. Response Summary and Load also has no data

There's actually mysql in the data:

Everyone ... Please help me
Is there a problem with my configuration?
Hi @leogoing
that is very weird.
Is there anything strange going in the web/collector log?
Can you make sure data is inserted into ApplicationMapStatisticsCallee_Ver2, ApplicationMapStatisticsCaller_Ver2, and ApplicationMapStatisticsSelf_Ver2 tables?
I don't know what the log represents, but there is no error. I'll see if these tables's have any value : )
I found out why I didn't have mysql information, I used Tomcat DBCP pool, but it doesn't support this pool
so why Response Summary and Load has no data ?
Hi @leogoing
I think you should debugging and see detail log containg debug level.
There are various possibilities, but I suspect whether callee and caller data insert hbase table.
If you can not find strange log. show me full log when you request test server and call main page pinpoint web.
ApplicationMapStatisticsCallee_Ver2, ApplicationMapStatisticsCaller_Ver2, and ApplicationMapStatisticsSelf_Ver2 has no data.
Now, I've turned the log level to debug.
this is agent log:
2018-05-16 16:56:32 INFO Sending AgentInfo TAgentInfo(hostname:Hexindai-XX, ip:fe80:0:0:0:98d9:3aff:fee6:e556%3, ports:, agentId:settlment, applicationName:test, serviceType:1010, pid:6331, agentVersion:1.7.3, vmVersion:1.7.0_71, startTimestamp:1526027326774, serverMetaData:TServerMetaData(serverInfo:Apache Tomcat/7.0.73, vmArgs:[-Djava.util.logging.config.file=/export/home/tomcat/domains/settlement.hexindai.com/server1/conf/logging.properties, -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager, -Djava.library.path=/usr/local/lib, -Xms2048m, -Xmx4096m, -XX:MaxPermSize=512m, -Djava.awt.headless=true, -Dsun.net.client.defaultConnectTimeout=60000, -Dsun.net.client.defaultReadTimeout=60000, -Djmagick.systemclassloader=no, -Dnetworkaddress.cache.ttl=300, -Dsun.net.inetaddr.ttl=300, -Djdk.tls.ephemeralDHKeySize=2048, -Dcom.sun.management.jmxremote=true, -Djava.rmi.server.hostname=172.20.10.32, -Dcom.sun.management.jmxremote.port=9999, -Dcom.sun.management.jmxremote.ssl=false, -Dcom.sun.managementote.ssl=false, -Dcom.sun.management.jmxremote.authenticate=false, -javaagent:/export/apm/pinpoint-agent/pinpoint-bootstrap-1.7.3.jar, -Dpinpoint.agentId=settlment, -Dpinpoint.applicationName=test, -XX:+UnlockCommercialFeatures, -XX:+FlightRecorder, -Djava.endorsed.dirs=/export/servers/tomcat7.0.57/endorsed, -Dcatalina.base=/export/home/tomcat/domains/settlement.hexindai.com/server1, -Dcatalina.home=/export/servers/tomcat7.0.57, -Djava.io.tmpdir=/export/home/tomcat/domains/settlement.hexindai.com/server1/temp], serviceInfos:[TServiceInfo(serviceName:Catalina/localhost/, serviceLibs:[aspectjrt-1.7.4.jar, aspectjweaver-1.7.4.jar, classmate-1.1.0.jar, commons-beanutils-1.9.2.jar, commons-codec-1.9.jar, commons-collections-3.2.1.jar, commons-io-2.1.jar, commons-lang3-3.4.jar, commons-logging-1.2.jar, fastjson-1.2.15.jar, hibernate-validator-5.2.4.Final.jar, httpclient-4.5.2.jar, httpcore-4.4.4.jar, jackson-annotations-2.8.0.jar, jackson-core-2.8.11.jar, jackson-databind-2.8.11.jar, jboss-logging-3.2.1.Final.jar, jcl-over-slf4j-1.7.21.jar, joda-time-2.9.7.jar, jstl-1.2.jar, jul-to-slf4j-1.7.21.jar, log4j-over-slf4j-1.7.21.jar, logback-classic-1.1.7.jar, logback-core-1.1.7.jar, mybatis-3.4.1.jar, mybatis-spring-1.3.0.jar, mysql-connector-java-5.1.37.jar, settlement-common-0.0.1-SNAPSHOT.jar, settlement-rpc-0.0.1-SNAPSHOT.jar, slf4j-api-1.7.21.jar, spring-aop-4.3.1.RELEASE.jar, spring-beans-4.3.1.RELEASE.jar, spring-context-4.3.1.RELEASE.jar, spring-context-support-4.3.1.RELEASE.jar, spring-core-4.3.1.RELEASE.jar, spring-expression-4.3.1.RELEASE.jar, spring-jdbc-4.3.1.RELEASE.jar, spring-tx-4.3.1.RELEASE.jar, spring-web-4.3.1.RELEASE.jar, spring-webmvc-4.3.1.RELEASE.jar, tomcat-jdbc-7.0.54.jar, tomcat-juli-7.0.54.jar, validation-api-1.1.0.Final.jar])]), jvmInfo:TJvmInfo(version:0, vmVersion:1.7.0_71, gcType:PARALLEL))
2018-05-16 16:56:32 INFO AgentInfo sent.
2018-05-17 16:56:32 INFO Sending AgentInfo TAgentInfo(hostname:Hexindai-XX, ip:fe80:0:0:0:98d9:3aff:fee6:e556%3, ports:, agentId:settlment, applicationName:test, serviceType:1010, pid:6331, agentVersion:1.7.3, vmVersion:1.7.0_71, startTimestamp:1526027326774, serverMetaData:TServerMetaData(serverInfo:Apache Tomcat/7.0.73, vmArgs:[-Djava.util.logging.config.file=/export/home/tomcat/domains/settlement.hexindai.com/server1/conf/logging.properties, -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager, -Djava.library.path=/usr/local/lib, -Xms2048m, -Xmx4096m, -XX:MaxPermSize=512m, -Djava.awt.headless=true, -Dsun.net.client.defaultConnectTimeout=60000, -Dsun.net.client.defaultReadTimeout=60000, -Djmagick.systemclassloader=no, -Dnetworkaddress.cache.ttl=300, -Dsun.net.inetaddr.ttl=300, -Djdk.tls.ephemeralDHKeySize=2048, -Dcom.sun.management.jmxremote=true, -Djava.rmi.server.hostname=172.20.10.32, -Dcom.sun.management.jmxremote.port=9999, -Dcom.sun.management.jmxremote.ssl=false, -Dcom.sun.managementote.ssl=false, -Dcom.sun.management.jmxremote.authenticate=false, -javaagent:/export/apm/pinpoint-agent/pinpoint-bootstrap-1.7.3.jar, -Dpinpoint.agentId=settlment, -Dpinpoint.applicationName=test, -XX:+UnlockCommercialFeatures, -XX:+FlightRecorder, -Djava.endorsed.dirs=/export/servers/tomcat7.0.57/endorsed, -Dcatalina.base=/export/home/tomcat/domains/settlement.hexindai.com/server1, -Dcatalina.home=/export/servers/tomcat7.0.57, -Djava.io.tmpdir=/export/home/tomcat/domains/settlement.hexindai.com/server1/temp], serviceInfos:[TServiceInfo(serviceName:Catalina/localhost/, serviceLibs:[aspectjrt-1.7.4.jar, aspectjweaver-1.7.4.jar, classmate-1.1.0.jar, commons-beanutils-1.9.2.jar, commons-codec-1.9.jar, commons-collections-3.2.1.jar, commons-io-2.1.jar, commons-lang3-3.4.jar, commons-logging-1.2.jar, fastjson-1.2.15.jar, hibernate-validator-5.2.4.Final.jar, httpclient-4.5.2.jar, httpcore-4.4.4.jar, jackson-annotations-2.8.0.jar, jackson-core-2.8.11.jar, jackson-databind-2.8.11.jar, jboss-logging-3.2.1.Final.jar, jcl-over-slf4j-1.7.21.jar, joda-time-2.9.7.jar, jstl-1.2.jar, jul-to-slf4j-1.7.21.jar, log4j-over-slf4j-1.7.21.jar, logback-classic-1.1.7.jar, logback-core-1.1.7.jar, mybatis-3.4.1.jar, mybatis-spring-1.3.0.jar, mysql-connector-java-5.1.37.jar, settlement-common-0.0.1-SNAPSHOT.jar, settlement-rpc-0.0.1-SNAPSHOT.jar, slf4j-api-1.7.21.jar, spring-aop-4.3.1.RELEASE.jar, spring-beans-4.3.1.RELEASE.jar, spring-context-4.3.1.RELEASE.jar, spring-context-support-4.3.1.RELEASE.jar, spring-core-4.3.1.RELEASE.jar, spring-expression-4.3.1.RELEASE.jar, spring-jdbc-4.3.1.RELEASE.jar, spring-tx-4.3.1.RELEASE.jar, spring-web-4.3.1.RELEASE.jar, spring-webmvc-4.3.1.RELEASE.jar, tomcat-jdbc-7.0.54.jar, tomcat-juli-7.0.54.jar, validation-api-1.1.0.Final.jar])]), jvmInfo:TJvmInfo(version:0, vmVersion:1.7.0_71, gcType:PARALLEL))
2018-05-17 16:56:32 INFO AgentInfo sent.
This is collector log:
2018-05-18 10:02:01 DEBUG [Caller] test (USER) msg -> test (TOMCAT)[msg]
2018-05-18 10:02:01 DEBUG [Callee] test (TOMCAT) <- test (USER)[msg]
2018-05-18 10:02:01 DEBUG [Received] test (TOMCAT)[msg]
2018-05-18 10:02:01 DEBUG handle spanEvent size:9
2018-05-18 10:02:01 DEBUG [Caller] test (TOMCAT) msg -> REDIS (REDIS)[172.20.10.32:6000]
2018-05-18 10:02:01 DEBUG [Callee] REDIS (REDIS) <- test (TOMCAT)[172.20.10.32:8080]
2018-05-18 10:02:01 DEBUG [Caller] test (TOMCAT) msg -> REDIS (REDIS)[172.20.10.32:6000]
2018-05-18 10:02:01 DEBUG [Callee] REDIS (REDIS) <- test (TOMCAT)[172.20.10.32:8080]
2018-05-18 10:02:01 DEBUG [Caller] test (TOMCAT) msg -> REDIS (REDIS)[172.20.10.32:6000]
2018-05-18 10:02:01 DEBUG [Callee] REDIS (REDIS) <- test (TOMCAT)[172.20.10.32:8080]
2018-05-18 10:02:01 DEBUG [Caller] test (TOMCAT) msg -> REDIS (REDIS)[172.20.10.32:6000]
2018-05-18 10:02:01 DEBUG [Callee] REDIS (REDIS) <- test (TOMCAT)[172.20.10.32:8080]
2018-05-18 10:02:02 DEBUG flush HbaseMapStatisticsCallerDao to [ApplicationMapStatisticsCallee_Ver2] Increment:2
2018-05-18 10:02:02 DEBUG flush HbaseMapStatisticsCalleeDao to [ApplicationMapStatisticsCaller_Ver2] Increment:2
2018-05-18 10:02:02 DEBUG flush HbaseMapResponseTimeDao to [ApplicationMapStatisticsSelf_Ver2] Increment:1
2018-05-18 10:02:02 DEBUG Received TAgentStatBatch=TAgentStatBatch(agentId:settlment, startTimestamp:1526027326774, agentStats:[TAgentStat(agentId:settlment, startTimestamp:1526027326774, timestamp:1526608897449, collectInterval:5000, gc:TJvmGc(type:PARALLEL, jvmMemoryHeapUsed:823266240, jvmMemoryHeapMax:3817865216, jvmMemoryNonHeapUsed:68228640, jvmMemoryNonHeapMax:587202560, jvmGcOldCount:0, jvmGcOldTime:0), cpuLoad:TCpuLoad(jvmCpuLoad:0.001027221366204417, systemCpuLoad:0.027221366204417053), transaction:TTransaction(sampledNewCount:0, sampledContinuationCount:0, unsampledNewCount:0, unsampledContinuationCount:0), activeTrace:TActiveTrace(histogram:TActiveTraceHistogram(version:0, histogramSchemaType:2, activeTraceCount:[0, 0, 0, 0])), dataSourceList:TDataSourceList(dataSourceList:[]), responseTime:TResponseTime()), TAgentStat(agentId:settlment, startTimestamp:1526027326774, timestamp:1526608902449, collectInterval:5000, gc:TJvmGc(type:PARALLEL, jvmMemoryHeapUsed:823266240, jvmMemoryHeapMax:3817865216, jvmMemoryNonHeapUsed:68228640, jvmMemoryNonHeapMax:587202560, jvmGcOldCount:0, jvmGcOldTime:0), cpuLoad:TCpuLoad(jvmCpuLoad:0.0010178117048346056, systemCpuLoad:0.022391857506361322), transaction:TTransaction(sampledNewCount:0, sampledContinuationCount:0, unsampledNewCount:0, unsampledContinuationCount:0), activeTrace:TActiveTrace(histogram:TActiveTraceHistogram(version:0, histogramSchemaType:2, activeTraceCount:[0, 0, 0, 0])), dataSourceList:TDataSourceList(dataSourceList:[]), responseTime:TResponseTime()), TAgentStat(agentId:settlment, startTimestamp:1526027326774, timestamp:1526608907449, collectInterval:5000, gc:TJvmGc(type:PARALLEL, jvmMemoryHeapUsed:825141944, jvmMemoryHeapMax:3817865216, jvmMemoryNonHeapUsed:68228640, jvmMemoryNonHeapMax:587202560, jvmGcOldCount:0, jvmGcOldTime:0), cpuLoad:TCpuLoad(jvmCpuLoad:0.0020512820512820513, systemCpuLoad:0.03128205128205128), transaction:TTransaction(sampledNewCount:0, sampledContinuationCount:0, unsampledNewCount:0, unsampledContinuationCount:0), activeTrace:TActiveTrace(histogram:TActiveTraceHistogram(version:0, histogramSchemaType:2, activeTraceCount:[0, 0, 0, 0])), dataSourceList:TDataSourceList(dataSourceList:[]), responseTime:TResponseTime()), TAgentStat(agentId:settlment, startTimestamp:1526027326774, timestamp:1526608912449, collectInterval:5000, gc:TJvmGc(type:PARALLEL, jvmMemoryHeapUsed:825141944, jvmMemoryHeapMax:3817865216, jvmMemoryNonHeapUsed:68228640, jvmMemoryNonHeapMax:587202560, jvmGcOldCount:0, jvmGcOldTime:0), cpuLoad:TCpuLoad(jvmCpuLoad:5.081300813008131E-4, systemCpuLoad:0.04268292682926829), transaction:TTransaction(sampledNewCount:0, sampledContinuationCount:0, unsampledNewCount:0, unsampledContinuationCount:0), activeTrace:TActiveTrace(histogram:TActiveTraceHistogram(version:0, histogramSchemaType:2, activeTraceCount:[0, 0, 0, 0])), dataSourceList:TDataSourceList(dataSourceList:[]), responseTime:TResponseTime()), TAgentStat(agentId:settlment, startTimestamp:1526027326774, timestamp:1526608917449, collectInterval:5000, gc:TJvmGc(type:PARALLEL, jvmMemoryHeapUsed:825141944, jvmMemoryHeapMax:3817865216, jvmMemoryNonHeapUsed:68228640, jvmMemoryNonHeapMax:587202560, jvmGcOldCount:0, jvmGcOldTime:0), cpuLoad:TCpuLoad(jvmCpuLoad:0.0010230179028132991, systemCpuLoad:0.02557544757033248), transaction:TTransaction(sampledNewCount:0, sampledContinuationCount:0, unsampledNewCount:0, unsampledContinuationCount:0), activeTrace:TActiveTrace(histogram:TActiveTraceHistogram(version:0, histogramSchemaType:2, activeTraceCount:[0, 0, 0, 0])), dataSourceList:TDataSourceList(dataSourceList:[]), responseTime:TResponseTime()), TAgentStat(agentId:settlment, startTimestamp:1526027326774, timestamp:1526608922449, collectInterval:5000, gc:TJvmGc(type:PARALLEL, jvmMemoryHeapUsed:825217464, jvmMemoryHeapMax:3817865216, jvmMemoryNonHeapUsed:68228640, jvmMemoryNonHeapMax:587202560, jvmGcOldCount:0, jvmGcOldTime:0), cpuLoad:TCpuLoad(jvmCpuLoad:0.0021482277121374865, systemCpuLoad:0.07357679914070892), transaction:TTransaction(sampledNewCount:0, sampledContinuationCount:0, unsampledNewCount:0, unsampledContinuationCount:0), activeTrace:TActiveTrace(histogram:TActiveTraceHistogram(version:0, histogramSchemaType:2, activeTraceCount:[0, 0, 0, 0])), dataSourceList:TDataSourceList(dataSourceList:[]), responseTime:TResponseTime())])
2018-05-18 10:02:02 DEBUG Received TAgentStatBatch=TAgentStatBatch(agentId:settlment, startTimestamp:1526027326774, agentStats:[TAgentStat(agentId:settlment, startTimestamp:1526027326774, timestamp:1526608897449, collectInterval:5000, gc:TJvmGc(type:PARALLEL, jvmMemoryHeapUsed:823266240, jvmMemoryHeapMax:3817865216, jvmMemoryNonHeapUsed:68228640, jvmMemoryNonHeapMax:587202560, jvmGcOldCount:0, jvmGcOldTime:0), cpuLoad:TCpuLoad(jvmCpuLoad:0.001027221366204417, systemCpuLoad:0.027221366204417053), transaction:TTransaction(sampledNewCount:0, sampledContinuationCount:0, unsampledNewCount:0, unsampledContinuationCount:0), activeTrace:TActiveTrace(histogram:TActiveTraceHistogram(version:0, histogramSchemaType:2, activeTraceCount:[0, 0, 0, 0])), dataSourceList:TDataSourceList(dataSourceList:[]), responseTime:TResponseTime()), TAgentStat(agentId:settlment, startTimestamp:1526027326774, timestamp:1526608902449, collectInterval:5000, gc:TJvmGc(type:PARALLEL, jvmMemoryHeapUsed:823266240, jvmMemoryHeapMax:3817865216, jvmMemoryNonHeapUsed:68228640, jvmMemoryNonHeapMax:587202560, jvmGcOldCount:0, jvmGcOldTime:0), cpuLoad:TCpuLoad(jvmCpuLoad:0.0010178117048346056, systemCpuLoad:0.022391857506361322), transaction:TTransaction(sampledNewCount:0, sampledContinuationCount:0, unsampledNewCount:0, unsampledContinuationCount:0), activeTrace:TActiveTrace(histogram:TActiveTraceHistogram(version:0, histogramSchemaType:2, activeTraceCount:[0, 0, 0, 0])), dataSourceList:TDataSourceList(dataSourceList:[]), responseTime:TResponseTime()), TAgentStat(agentId:settlment, startTimestamp:1526027326774, timestamp:1526608907449, collectInterval:5000, gc:TJvmGc(type:PARALLEL, jvmMemoryHeapUsed:825141944, jvmMemoryHeapMax:3817865216, jvmMemoryNonHeapUsed:68228640, jvmMemoryNonHeapMax:587202560, jvmGcOldCount:0, jvmGcOldTime:0), cpuLoad:TCpuLoad(jvmCpuLoad:0.0020512820512820513, systemCpuLoad:0.03128205128205128), transaction:TTransaction(sampledNewCount:0, sampledContinuationCount:0, unsampledNewCount:0, unsampledContinuationCount:0), activeTrace:TActiveTrace(histogram:TActiveTraceHistogram(version:0, histogramSchemaType:2, activeTraceCount:[0, 0, 0, 0])), dataSourceList:TDataSourceList(dataSourceList:[]), responseTime:TResponseTime()), TAgentStat(agentId:settlment, startTimestamp:1526027326774, timestamp:1526608912449, collectInterval:5000, gc:TJvmGc(type:PARALLEL, jvmMemoryHeapUsed:825141944, jvmMemoryHeapMax:3817865216, jvmMemoryNonHeapUsed:68228640, jvmMemoryNonHeapMax:587202560, jvmGcOldCount:0, jvmGcOldTime:0), cpuLoad:TCpuLoad(jvmCpuLoad:5.081300813008131E-4, systemCpuLoad:0.04268292682926829), transaction:TTransaction(sampledNewCount:0, sampledContinuationCount:0, unsampledNewCount:0, unsampledContinuationCount:0), activeTrace:TActiveTrace(histogram:TActiveTraceHistogram(version:0, histogramSchemaType:2, activeTraceCount:[0, 0, 0, 0])), dataSourceList:TDataSourceList(dataSourceList:[]), responseTime:TResponseTime()), TAgentStat(agentId:settlment, startTimestamp:1526027326774, timestamp:1526608917449, collectInterval:5000, gc:TJvmGc(type:PARALLEL, jvmMemoryHeapUsed:825141944, jvmMemoryHeapMax:3817865216, jvmMemoryNonHeapUsed:68228640, jvmMemoryNonHeapMax:587202560, jvmGcOldCount:0, jvmGcOldTime:0), cpuLoad:TCpuLoad(jvmCpuLoad:0.0010230179028132991, systemCpuLoad:0.02557544757033248), transaction:TTransaction(sampledNewCount:0, sampledContinuationCount:0, unsampledNewCount:0, unsampledContinuationCount:0), activeTrace:TActiveTrace(histogram:TActiveTraceHistogram(version:0, histogramSchemaType:2, activeTraceCount:[0, 0, 0, 0])), dataSourceList:TDataSourceList(dataSourceList:[]), responseTime:TResponseTime()), TAgentStat(agentId:settlment, startTimestamp:1526027326774, timestamp:1526608922449, collectInterval:5000, gc:TJvmGc(type:PARALLEL, jvmMemoryHeapUsed:825217464, jvmMemoryHeapMax:3817865216, jvmMemoryNonHeapUsed:68228640, jvmMemoryNonHeapMax:587202560, jvmGcOldCount:0, jvmGcOldTime:0), cpuLoad:TCpuLoad(jvmCpuLoad:0.0021482277121374865, systemCpuLoad:0.07357679914070892), transaction:TTransaction(sampledNewCount:0, sampledContinuationCount:0, unsampledNewCount:0, unsampledContinuationCount:0), activeTrace:TActiveTrace(histogram:TActiveTraceHistogram(version:0, histogramSchemaType:2, activeTraceCount:[0, 0, 0, 0])), dataSourceList:TDataSourceList(dataSourceList:[]), responseTime:TResponseTime())])
2018-05-18 10:02:06 DEBUG Received SPAN=TSpan(agentId:msg, applicationName:test, agentStartTime:1525921566817, transactionId:00 01 E1 A0 8D C0 B4 2C D7 06, spanId:-6740084998874655828, startTime:1526608926267, elapsed:13, rpc:/hexin-msg/msg/asyncSendMsg, serviceType:1010, endPoint:172.20.10.32:8080, remoteAddr:172.20.10.56, annotations:[TAnnotation(key:46, value:
2018-05-18 10:02:06 DEBUG [Callee] test (TOMCAT) <- test (USER)[msg]
2018-05-18 10:02:06 DEBUG [Received] test (TOMCAT)[msg]
2018-05-18 10:02:06 DEBUG handle spanEvent size:9
2018-05-18 10:02:06 DEBUG [Caller] test (TOMCAT) msg -> REDIS (REDIS)[172.20.10.32:6000]
2018-05-18 10:02:06 DEBUG [Callee] REDIS (REDIS) <- test (TOMCAT)[172.20.10.32:8080]
2018-05-18 10:02:06 DEBUG [Caller] test (TOMCAT) msg -> REDIS (REDIS)[172.20.10.32:6000]
2018-05-18 10:02:06 DEBUG [Callee] REDIS (REDIS) <- test (TOMCAT)[172.20.10.32:8080]
2018-05-18 10:02:06 DEBUG [Caller] test (TOMCAT) msg -> REDIS (REDIS)[172.20.10.32:6000]
2018-05-18 10:02:06 DEBUG [Callee] REDIS (REDIS) <- test (TOMCAT)[172.20.10.32:8080]
2018-05-18 10:02:06 DEBUG [Caller] test (TOMCAT) msg -> REDIS (REDIS)[172.20.10.32:6000]
2018-05-18 10:02:06 DEBUG [Callee] REDIS (REDIS) <- test (TOMCAT)[172.20.10.32:8080]
2018-05-18 10:02:06 DEBUG flush HbaseMapStatisticsCallerDao to [ApplicationMapStatisticsCallee_Ver2] Increment:2
2018-05-18 10:02:06 DEBUG flush HbaseMapStatisticsCalleeDao to [ApplicationMapStatisticsCaller_Ver2] Increment:2
2018-05-18 10:02:06 DEBUG flush HbaseMapResponseTimeDao to [ApplicationMapStatisticsSelf_Ver2] Increment:1
2018-05-18 10:02:07 DEBUG Got ping response for sessionid: 0x100000742ef004f after 1ms
This is web log:
2018-05-18 10:07:49 DEBUG DispatcherServlet with name 'pinpoint-web' processing GET request for [/pinpoint-web-1.8.0-SNAPSHOT/configuration.pinpoint]
2018-05-18 10:07:49 DEBUG Looking up handler method for path /configuration.pinpoint
2018-05-18 10:07:49 DEBUG Returning handler method [public java.util.Map
2018-05-18 10:07:49 DEBUG Returning cached instance of singleton bean 'configController'
2018-05-18 10:07:49 DEBUG Last-Modified value for [/pinpoint-web-1.8.0-SNAPSHOT/configuration.pinpoint] is: -1
2018-05-18 10:07:49 DEBUG Looking up cache seconds for [/configuration.pinpoint]
2018-05-18 10:07:49 DEBUG Applying default cache seconds to [/configuration.pinpoint]
2018-05-18 10:07:50 DEBUG Written [{enableServerMapRealTime=false, editUserInfo=true, sendUsage=true, openSource=true, showActiveThreadDump=true, showApplicationStat=false, showActiveThread=true, version=1.8.0-SNAPSHOT}] as "application/json" using [org.springframework.http.converter.json.MappingJackson2HttpMessageConverter@d51f4b]
2018-05-18 10:07:50 DEBUG Null ModelAndView returned to DispatcherServlet with name 'pinpoint-web': assuming HandlerAdapter completed request handling
2018-05-18 10:07:50 DEBUG Successfully completed request
2018-05-18 10:07:50 DEBUG DispatcherServlet with name 'pinpoint-web' processing GET request for [/pinpoint-web-1.8.0-SNAPSHOT/configuration.pinpoint]
2018-05-18 10:07:50 DEBUG DispatcherServlet with name 'pinpoint-web' processing GET request for [/pinpoint-web-1.8.0-SNAPSHOT/configuration.pinpoint]
2018-05-18 10:07:50 DEBUG Looking up handler method for path /configuration.pinpoint
2018-05-18 10:07:50 DEBUG Looking up handler method for path /configuration.pinpoint
2018-05-18 10:07:50 DEBUG Returning cached instance of singleton bean 'sqlSessionFactory'
2018-05-18 10:07:50 DEBUG Returning handler method [public java.util.Map
2018-05-18 10:07:50 DEBUG Returning cached instance of singleton bean 'configController'
2018-05-18 10:07:50 DEBUG Last-Modified value for [/pinpoint-web-1.8.0-SNAPSHOT/configuration.pinpoint] is: -1
2018-05-18 10:07:50 DEBUG Looking up cache seconds for [/configuration.pinpoint]
2018-05-18 10:07:50 DEBUG Applying default cache seconds to [/configuration.pinpoint]
2018-05-18 10:07:50 DEBUG Returning handler method [public java.util.Map
2018-05-18 10:07:50 DEBUG Returning cached instance of singleton bean 'configController'
2018-05-18 10:07:50 DEBUG Last-Modified value for [/pinpoint-web-1.8.0-SNAPSHOT/configuration.pinpoint] is: -1
2018-05-18 10:07:50 DEBUG Looking up cache seconds for [/configuration.pinpoint]
2018-05-18 10:07:50 DEBUG Applying default cache seconds to [/configuration.pinpoint]
2018-05-18 10:07:50 DEBUG Written [{enableServerMapRealTime=false, editUserInfo=true, sendUsage=true, openSource=true, showActiveThreadDump=true, showApplicationStat=false, showActiveThread=true, version=1.8.0-SNAPSHOT}] as "application/json" using [org.springframework.http.converter.json.MappingJackson2HttpMessageConverter@d51f4b]
2018-05-18 10:07:50 DEBUG Null ModelAndView returned to DispatcherServlet with name 'pinpoint-web': assuming HandlerAdapter completed request handling
2018-05-18 10:07:50 DEBUG Successfully completed request
2018-05-18 10:07:50 DEBUG Written [{enableServerMapRealTime=false, editUserInfo=true, sendUsage=true, openSource=true, showActiveThreadDump=true, showApplicationStat=false, showActiveThread=true, version=1.8.0-SNAPSHOT}] as "application/json" using [org.springframework.http.converter.json.MappingJackson2HttpMessageConverter@d51f4b]
2018-05-18 10:07:50 DEBUG Null ModelAndView returned to DispatcherServlet with name 'pinpoint-web': assuming HandlerAdapter completed request handling
2018-05-18 10:07:50 DEBUG Successfully completed request
2018-05-18 10:07:50 DEBUG DispatcherServlet with name 'pinpoint-web' processing GET request for [/pinpoint-web-1.8.0-SNAPSHOT/configuration.pinpoint]
2018-05-18 10:07:50 DEBUG Looking up handler method for path /configuration.pinpoint
2018-05-18 10:07:50 DEBUG Returning handler method [public java.util.Map
2018-05-18 10:07:50 DEBUG Returning cached instance of singleton bean 'configController'
2018-05-18 10:07:50 DEBUG Last-Modified value for [/pinpoint-web-1.8.0-SNAPSHOT/configuration.pinpoint] is: -1
2018-05-18 10:07:50 DEBUG Looking up cache seconds for [/configuration.pinpoint]
2018-05-18 10:07:50 DEBUG Applying default cache seconds to [/configuration.pinpoint]
2018-05-18 10:07:50 DEBUG Written [{enableServerMapRealTime=false, editUserInfo=true, sendUsage=true, openSource=true, showActiveThreadDump=true, showApplicationStat=false, showActiveThread=true, version=1.8.0-SNAPSHOT}] as "application/json" using [org.springframework.http.converter.json.MappingJackson2HttpMessageConverter@d51f4b]
2018-05-18 10:07:50 DEBUG Null ModelAndView returned to DispatcherServlet with name 'pinpoint-web': assuming HandlerAdapter completed request handling
2018-05-18 10:07:50 DEBUG Successfully completed request
2018-05-18 10:07:50 DEBUG DispatcherServlet with name 'pinpoint-web' processing GET request for [/pinpoint-web-1.8.0-SNAPSHOT/configuration.pinpoint]
2018-05-18 10:07:50 DEBUG Looking up handler method for path /configuration.pinpoint
2018-05-18 10:07:50 DEBUG Returning handler method [public java.util.Map
2018-05-18 10:07:50 DEBUG Returning cached instance of singleton bean 'configController'
2018-05-18 10:07:50 DEBUG Last-Modified value for [/pinpoint-web-1.8.0-SNAPSHOT/configuration.pinpoint] is: -1
2018-05-18 10:07:50 DEBUG Looking up cache seconds for [/configuration.pinpoint]
2018-05-18 10:07:50 DEBUG Applying default cache seconds to [/configuration.pinpoint]
2018-05-18 10:07:50 DEBUG Written [{enableServerMapRealTime=false, editUserInfo=true, sendUsage=true, openSource=true, showActiveThreadDump=true, showApplicationStat=false, showActiveThread=true, version=1.8.0-SNAPSHOT}] as "application/json" using [org.springframework.http.converter.json.MappingJackson2HttpMessageConverter@d51f4b]
2018-05-18 10:07:50 DEBUG Null ModelAndView returned to DispatcherServlet with name 'pinpoint-web': assuming HandlerAdapter completed request handling
2018-05-18 10:07:50 DEBUG Successfully completed request
2018-05-18 10:07:50 DEBUG DispatcherServlet with name 'pinpoint-web' processing GET request for [/pinpoint-web-1.8.0-SNAPSHOT/applications.pinpoint]
2018-05-18 10:07:50 DEBUG Looking up handler method for path /applications.pinpoint
2018-05-18 10:07:50 DEBUG Returning handler method [public com.navercorp.pinpoint.web.view.ApplicationGroup com.navercorp.pinpoint.web.controller.MainController.getApplicationGroup()]
2018-05-18 10:07:50 DEBUG Returning cached instance of singleton bean 'mainController'
2018-05-18 10:07:50 DEBUG Last-Modified value for [/pinpoint-web-1.8.0-SNAPSHOT/applications.pinpoint] is: -1
2018-05-18 10:07:50 DEBUG Looking up cache seconds for [/applications.pinpoint]
2018-05-18 10:07:50 DEBUG Applying default cache seconds to [/applications.pinpoint]
2018-05-18 10:07:50 DEBUG DispatcherServlet with name 'pinpoint-web' processing GET request for [/pinpoint-web-1.8.0-SNAPSHOT/configuration.pinpoint]
2018-05-18 10:07:50 DEBUG Looking up handler method for path /configuration.pinpoint
2018-05-18 10:07:50 DEBUG Returning handler method [public java.util.Map
2018-05-18 10:07:50 DEBUG Returning cached instance of singleton bean 'configController'
2018-05-18 10:07:50 DEBUG Last-Modified value for [/pinpoint-web-1.8.0-SNAPSHOT/configuration.pinpoint] is: -1
2018-05-18 10:07:50 DEBUG Looking up cache seconds for [/configuration.pinpoint]
2018-05-18 10:07:50 DEBUG Applying default cache seconds to [/configuration.pinpoint]
2018-05-18 10:07:50 DEBUG /applications [elastic(STAND_ALONE:1000), test(TOMCAT:1010), test2(TOMCAT:1010)]
2018-05-18 10:07:50 DEBUG Written [{enableServerMapRealTime=false, editUserInfo=true, sendUsage=true, openSource=true, showActiveThreadDump=true, showApplicationStat=false, showActiveThread=true, version=1.8.0-SNAPSHOT}] as "application/json" using [org.springframework.http.converter.json.MappingJackson2HttpMessageConverter@d51f4b]
2018-05-18 10:07:50 DEBUG Null ModelAndView returned to DispatcherServlet with name 'pinpoint-web': assuming HandlerAdapter completed request handling
2018-05-18 10:07:50 DEBUG Successfully completed request
2018-05-18 10:07:50 DEBUG Creating instance of bean 'com.navercorp.pinpoint.web.view.ApplicationGroupSerializer'
2018-05-18 10:07:50 DEBUG Returning cached instance of singleton bean 'org.springframework.transaction.config.internalTransactionAdvisor'
2018-05-18 10:07:50 DEBUG Returning cached instance of singleton bean 'org.springframework.cache.config.internalCacheAdvisor'
2018-05-18 10:07:50 DEBUG Finished creating instance of bean 'com.navercorp.pinpoint.web.view.ApplicationGroupSerializer'
2018-05-18 10:07:50 DEBUG Creating instance of bean 'com.navercorp.pinpoint.web.view.ApplicationGroupSerializer'
2018-05-18 10:07:50 DEBUG Returning cached instance of singleton bean 'org.springframework.transaction.config.internalTransactionAdvisor'
2018-05-18 10:07:50 DEBUG Finished creating instance of bean 'com.navercorp.pinpoint.web.view.ApplicationGroupSerializer'
2018-05-18 10:07:50 DEBUG Creating instance of bean 'com.navercorp.pinpoint.web.view.ApplicationSerializer'
2018-05-18 10:07:50 DEBUG Returning cached instance of singleton bean 'org.springframework.transaction.config.internalTransactionAdvisor'
2018-05-18 10:07:50 DEBUG Returning cached instance of singleton bean 'org.springframework.cache.config.internalCacheAdvisor'
2018-05-18 10:07:50 DEBUG Finished creating instance of bean 'com.navercorp.pinpoint.web.view.ApplicationSerializer'
2018-05-18 10:07:50 DEBUG Written [com.navercorp.pinpoint.web.view.ApplicationGroup@7b80cd] as "application/json" using [org.springframework.http.converter.json.MappingJackson2HttpMessageConverter@d51f4b]
2018-05-18 10:07:50 DEBUG Null ModelAndView returned to DispatcherServlet with name 'pinpoint-web': assuming HandlerAdapter completed request handling
2018-05-18 10:07:50 DEBUG Successfully completed request
2018-05-18 10:07:51 DEBUG DispatcherServlet with name 'pinpoint-web' processing GET request for [/pinpoint-web-1.8.0-SNAPSHOT/applications.pinpoint]
2018-05-18 10:07:51 DEBUG DispatcherServlet with name 'pinpoint-web' processing GET request for [/pinpoint-web-1.8.0-SNAPSHOT/getServerMapDataV2.pinpoint]
2018-05-18 10:07:51 DEBUG Looking up handler method for path /applications.pinpoint
2018-05-18 10:07:51 DEBUG Looking up handler method for path /getServerMapDataV2.pinpoint
2018-05-18 10:07:51 DEBUG Returning handler method [public com.navercorp.pinpoint.web.view.ApplicationGroup com.navercorp.pinpoint.web.controller.MainController.getApplicationGroup()]
2018-05-18 10:07:51 DEBUG Returning cached instance of singleton bean 'mainController'
2018-05-18 10:07:51 DEBUG Last-Modified value for [/pinpoint-web-1.8.0-SNAPSHOT/applications.pinpoint] is: -1
2018-05-18 10:07:51 DEBUG Looking up cache seconds for [/applications.pinpoint]
2018-05-18 10:07:51 DEBUG Applying default cache seconds to [/applications.pinpoint]
2018-05-18 10:07:51 DEBUG Returning handler method [public com.navercorp.pinpoint.web.applicationmap.MapWrap com.navercorp.pinpoint.web.controller.MapController.getServerMapDataV2(java.lang.String,java.lang.String,long,long,int,int,boolean,boolean)]
2018-05-18 10:07:51 DEBUG Returning cached instance of singleton bean 'mapController'
2018-05-18 10:07:51 DEBUG Last-Modified value for [/pinpoint-web-1.8.0-SNAPSHOT/getServerMapDataV2.pinpoint] is: -1
2018-05-18 10:07:51 DEBUG Looking up cache seconds for [/getServerMapDataV2.pinpoint]
2018-05-18 10:07:51 DEBUG Applying default cache seconds to [/getServerMapDataV2.pinpoint]
2018-05-18 10:07:51 DEBUG /applications [elastic(STAND_ALONE:1000), test(TOMCAT:1010), test2(TOMCAT:1010)]
2018-05-18 10:07:51 DEBUG Written [com.navercorp.pinpoint.web.view.ApplicationGroup@17c8716] as "application/json" using [org.springframework.http.converter.json.MappingJackson2HttpMessageConverter@d51f4b]
2018-05-18 10:07:51 DEBUG Null ModelAndView returned to DispatcherServlet with name 'pinpoint-web': assuming HandlerAdapter completed request handling
2018-05-18 10:07:51 DEBUG Successfully completed request
2018-05-18 10:07:51 INFO getServerMap() application:test(TOMCAT:1010) range:Range{from=1526606824000, to=1526608024000, range=1200000} searchOption:SearchOption{callerSearchDepth=4, calleeSearchDepth=4, linkSelectorType=BIDIRECTIONAL, wasOnly=false}
2018-05-18 10:07:51 DEBUG SelectApplicationMap
2018-05-18 10:07:51 DEBUG Creating link data map for [test(TOMCAT:1010)]
2018-05-18 10:07:51 INFO depth search start. callerDepth:0, calleeDepth:0, size:1, nodes:[test(TOMCAT:1010)]
2018-05-18 10:07:51 DEBUG Finding Caller/Callee link data for test(TOMCAT:1010)
2018-05-18 10:07:51 DEBUG Finding Caller link data for test(TOMCAT:1010)
2018-05-18 10:07:51 DEBUG scan Time:Range{from=1526606819999, to=1526608020000, range s=1200}
2018-05-18 10:07:51 DEBUG ParallelDistributedScanner createTime: 2ms
2018-05-18 10:07:51 DEBUG ParallelDistributedScanner scanTime: 69ms
2018-05-18 10:07:51 DEBUG Caller data. null, Range{from=1526606824000, to=1526608024000, range=1200000}
2018-05-18 10:07:51 DEBUG Found Caller. count=0, caller=test(TOMCAT:1010), depth=0
2018-05-18 10:07:51 DEBUG Finding Callee link data for test(TOMCAT:1010)
2018-05-18 10:07:51 DEBUG scan time:Range{from=1526606819999, to=1526608020000, range s=1200}
2018-05-18 10:07:51 DEBUG ParallelDistributedScanner createTime: 1ms
2018-05-18 10:07:51 DEBUG ParallelDistributedScanner scanTime: 70ms
2018-05-18 10:07:51 DEBUG Callee data. null, Range{from=1526606824000, to=1526608024000, range=1200000}
2018-05-18 10:07:51 DEBUG Found Callee. count=0, callee=test(TOMCAT:1010), depth=0
2018-05-18 10:07:51 DEBUG depth search. callerDepth : 0, calleeDepth : 0
2018-05-18 10:07:51 INFO depth search end. callerDepth:0, calleeDepth:0
2018-05-18 10:07:51 INFO Building application map
2018-05-18 10:07:51 DEBUG node size:0
2018-05-18 10:07:51 DEBUG node size:0
2018-05-18 10:07:51 DEBUG allNode:[]
2018-05-18 10:07:51 DEBUG link size:0
2018-05-18 10:07:51 DEBUG link size:0
2018-05-18 10:07:51 INFO Building empty application map
2018-05-18 10:07:51 DEBUG unfiltered agentInfos [AgentInfo{applicationName='test', agentId='msg', startTimestamp=1525921566817, hostName='Hexindai-XX', ip='fe80:0:0:0:98d9:3aff:fee6:e556%docker0', ports='', serviceTypeCode=1010, pid=19733, vmVersion='1.8.0_131', agentVersion='1.7.3', jvmInfo=JvmInfoBo{version=0, jvmVersion='1.8.0_131', gcTypeName='PARALLEL'}, initialStartTimestamp=0, status=null}, AgentInfo{applicationName='test', agentId='settlment', startTimestamp=1526027326774, hostName='Hexindai-XX', ip='fe80:0:0:0:98d9:3aff:fee6:e556%3', ports='', serviceTypeCode=1010, pid=6331, vmVersion='1.7.0_71', agentVersion='1.7.3', jvmInfo=JvmInfoBo{version=0, jvmVersion='1.7.0_71', gcTypeName='PARALLEL'}, initialStartTimestamp=0, status=null}]
2018-05-18 10:07:51 DEBUG add agentInfos test(TOMCAT:1010) : [AgentInfo{applicationName='test', agentId='msg', startTimestamp=1525921566817, hostName='Hexindai-XX', ip='fe80:0:0:0:98d9:3aff:fee6:e556%docker0', ports='', serviceTypeCode=1010, pid=19733, vmVersion='1.8.0_131', agentVersion='1.7.3', jvmInfo=JvmInfoBo{version=0, jvmVersion='1.8.0_131', gcTypeName='PARALLEL'}, initialStartTimestamp=0, status=AgentStatus{agentId='msg', eventTimestamp=1526607735069, state=Running}}, AgentInfo{applicationName='test', agentId='settlment', startTimestamp=1526027326774, hostName='Hexindai-XX', ip='fe80:0:0:0:98d9:3aff:fee6:e556%3', ports='', serviceTypeCode=1010, pid=6331, vmVersion='1.7.0_71', agentVersion='1.7.3', jvmInfo=JvmInfoBo{version=0, jvmVersion='1.7.0_71', gcTypeName='PARALLEL'}, initialStartTimestamp=0, status=AgentStatus{agentId='settlment', eventTimestamp=1526607735004, state=Running}}]
2018-05-18 10:07:51 DEBUG buildPhysicalServer:[AgentInfo{applicationName='test', agentId='msg', startTimestamp=1525921566817, hostName='Hexindai-XX', ip='fe80:0:0:0:98d9:3aff:fee6:e556%docker0', ports='', serviceTypeCode=1010, pid=19733, vmVersion='1.8.0_131', agentVersion='1.7.3', jvmInfo=JvmInfoBo{version=0, jvmVersion='1.8.0_131', gcTypeName='PARALLEL'}, initialStartTimestamp=0, status=AgentStatus{agentId='msg', eventTimestamp=1526607735069, state=Running}}, AgentInfo{applicationName='test', agentId='settlment', startTimestamp=1526027326774, hostName='Hexindai-XX', ip='fe80:0:0:0:98d9:3aff:fee6:e556%3', ports='', serviceTypeCode=1010, pid=6331, vmVersion='1.7.0_71', agentVersion='1.7.3', jvmInfo=JvmInfoBo{version=0, jvmVersion='1.7.0_71', gcTypeName='PARALLEL'}, initialStartTimestamp=0, status=AgentStatus{agentId='settlment', eventTimestamp=1526607735004, state=Running}}]
2018-05-18 10:07:51 DEBUG selectResponseTime applicationName:test(TOMCAT:1010), Range{from=1526606824000, to=1526608024000, range=1200000}
2018-05-18 10:07:51 DEBUG scan time:Range{from=1526606819999, to=1526608020000, range s=1200}
2018-05-18 10:07:51 DEBUG ParallelDistributedScanner createTime: 2ms
2018-05-18 10:07:51 DEBUG ParallelDistributedScanner scanTime: 18ms
2018-05-18 10:07:51 DEBUG Self data []
2018-05-18 10:07:51 INFO ApplicationMap BuildTime: StopWatch 'ApplicationMap': running time (millis) = 402
ms % Task name
00223 055% ApplicationMap Hbase Io Fetch(Caller,Callee) Time
00179 045% ApplicationMap MapBuilding(Response) Time
2018-05-18 10:07:51 DEBUG Creating instance of bean 'com.navercorp.pinpoint.web.view.NodeSerializer'
2018-05-18 10:07:51 DEBUG Returning cached instance of singleton bean 'org.springframework.transaction.config.internalTransactionAdvisor'
2018-05-18 10:07:51 DEBUG Returning cached instance of singleton bean 'org.springframework.cache.config.internalCacheAdvisor'
2018-05-18 10:07:51 DEBUG Finished creating instance of bean 'com.navercorp.pinpoint.web.view.NodeSerializer'
2018-05-18 10:07:51 DEBUG Creating instance of bean 'com.navercorp.pinpoint.web.view.HistogramSerializer'
2018-05-18 10:07:51 DEBUG Returning cached instance of singleton bean 'org.springframework.transaction.config.internalTransactionAdvisor'
2018-05-18 10:07:51 DEBUG Returning cached instance of singleton bean 'org.springframework.cache.config.internalCacheAdvisor'
2018-05-18 10:07:51 DEBUG Finished creating instance of bean 'com.navercorp.pinpoint.web.view.HistogramSerializer'
2018-05-18 10:07:51 DEBUG Creating instance of bean 'com.navercorp.pinpoint.web.view.TimeCountSerializer'
2018-05-18 10:07:51 DEBUG Returning cached instance of singleton bean 'org.springframework.transaction.config.internalTransactionAdvisor'
2018-05-18 10:07:51 DEBUG Returning cached instance of singleton bean 'org.springframework.cache.config.internalCacheAdvisor'
2018-05-18 10:07:51 DEBUG Finished creating instance of bean 'com.navercorp.pinpoint.web.view.TimeCountSerializer'
2018-05-18 10:07:51 DEBUG Written [com.navercorp.pinpoint.web.applicationmap.MapWrap@127e2a4] as "application/json" using [org.springframework.http.converter.json.MappingJackson2HttpMessageConverter@d51f4b]
2018-05-18 10:07:51 DEBUG Null ModelAndView returned to DispatcherServlet with name 'pinpoint-web': assuming HandlerAdapter completed request handling
2018-05-18 10:07:51 DEBUG Successfully completed request
2018-05-18 10:07:51 DEBUG DispatcherServlet with name 'pinpoint-web' processing GET request for [/pinpoint-web-1.8.0-SNAPSHOT/configuration.pinpoint]
2018-05-18 10:07:51 DEBUG Looking up handler method for path /configuration.pinpoint
2018-05-18 10:07:51 DEBUG Returning handler method [public java.util.Map
2018-05-18 10:07:51 DEBUG Returning cached instance of singleton bean 'configController'
2018-05-18 10:07:51 DEBUG Last-Modified value for [/pinpoint-web-1.8.0-SNAPSHOT/configuration.pinpoint] is: -1
2018-05-18 10:07:51 DEBUG Looking up cache seconds for [/configuration.pinpoint]
2018-05-18 10:07:51 DEBUG Applying default cache seconds to [/configuration.pinpoint]
2018-05-18 10:07:51 DEBUG Written [{enableServerMapRealTime=false, editUserInfo=true, sendUsage=true, openSource=true, showActiveThreadDump=true, showApplicationStat=false, showActiveThread=true, version=1.8.0-SNAPSHOT}] as "application/json" using [org.springframework.http.converter.json.MappingJackson2HttpMessageConverter@d51f4b]
2018-05-18 10:07:51 DEBUG Null ModelAndView returned to DispatcherServlet with name 'pinpoint-web': assuming HandlerAdapter completed request handling
2018-05-18 10:07:51 DEBUG Successfully completed request
2018-05-18 10:07:52 DEBUG DispatcherServlet with name 'pinpoint-web' processing GET request for [/pinpoint-web-1.8.0-SNAPSHOT/getScatterData.pinpoint]
2018-05-18 10:07:52 DEBUG Looking up handler method for path /getScatterData.pinpoint
2018-05-18 10:07:52 DEBUG Returning handler method [public org.springframework.web.servlet.ModelAndView com.navercorp.pinpoint.web.controller.ScatterChartController.getScatterData(java.lang.String,long,long,int,int,int,boolean,java.lang.String,java.lang.String,int)]
2018-05-18 10:07:52 DEBUG Returning cached instance of singleton bean 'scatterChartController'
2018-05-18 10:07:52 DEBUG Last-Modified value for [/pinpoint-web-1.8.0-SNAPSHOT/getScatterData.pinpoint] is: -1
2018-05-18 10:07:52 DEBUG Looking up cache seconds for [/getScatterData.pinpoint]
2018-05-18 10:07:52 DEBUG Applying default cache seconds to [/getScatterData.pinpoint]
2018-05-18 10:07:52 DEBUG fetch scatter data. RANGE=Range{from=1526606824000, to=1526608024000, range=1200000}, X-Group-Unit:3947, Y-Group-Unit:57, LIMIT=5000, BACKWARD_DIRECTION:true, FILTER:
2018-05-18 10:07:52 DEBUG scanTraceScatterDataMadeOfDotGroup
2018-05-18 10:07:52 DEBUG ParallelDistributedScanner createTime: 1ms
2018-05-18 10:07:52 DEBUG ParallelDistributedScanner scanTime: 91ms
2018-05-18 10:07:52 INFO Fetch scatterData time : 103ms
2018-05-18 10:07:52 DEBUG Returning cached instance of singleton bean 'jsonView'
2018-05-18 10:07:52 DEBUG Rendering view [org.springframework.web.servlet.view.json.MappingJackson2JsonView: name 'jsonView'] in DispatcherServlet with name 'pinpoint-web'
2018-05-18 10:07:52 DEBUG Successfully completed request
Hi @leogoing
From your web log, there doesn't seem to be any caller/callee statistics data (in ApplicationMapStatisticsCallee_Ver2, ApplicationMapStatisticsCaller_Ver2) for the query.
...
2018-05-18 10:07:51 DEBUG Caller data. null, Range{from=1526606824000, to=1526608024000, range=1200000}
...
2018-05-18 10:07:51 DEBUG Callee data. null, Range{from=1526606824000, to=1526608024000, range=1200000}
...
Additionally, your collector log is from a different time frame compared to the web log.
While this certainly isn't the cause of your issue, it does make it difficult to figure out what exactly is going on.
Would it be possible to provide collector/web logs from the same time frame for a couple of transactions as well as a screen shot of the server map generated from them?
(Also, are your ApplicationMapStatisticsCallee_Ver2 and ApplicationMapStatisticsCaller_Ver2 still empty?)
This is the log of agent near that time
2018-05-18 10:00:09 INFO DefaultPinpointClientHandler@2bfa77f6 handleClosedPacket() started. channel:[id: 0x8a44aa1e, /172.20.10.32:32782 => /172.20.10.30:9994]
2018-05-18 10:00:09 INFO DefaultPinpointClientHandler@2bfa77f6 stateTo() completed. Socket state change success(updateWanted:BEING_CLOSE_BY_SERVER ,before:RUN_DUPLEX ,current:BEING_CLOSE_BY_SERVER).
2018-05-18 10:00:09 INFO DefaultPinpointClientHandler@2bfa77f6 channelClosed() started.
2018-05-18 10:00:09 INFO DefaultPinpointClientHandler@2bfa77f6 stateTo() completed. Socket state change success(updateWanted:CLOSED_BY_SERVER ,before:BEING_CLOSE_BY_SERVER ,current:CLOSED_BY_SERVER).
2018-05-18 10:00:09 INFO PinpointClientHandshaker@b6e5888 handshakeAbort() started.
2018-05-18 10:00:09 INFO PinpointClientHandshaker@b6e5888 unexpected state
2018-05-18 10:00:12 WARN try reconnect. connectAddress:DnsSocketAddressProvider{host='172.20.10.30', port=9994}
2018-05-18 10:00:12 INFO DefaultPinpointClientHandler@67f17372 initReconnect() started.
2018-05-18 10:00:12 INFO DefaultPinpointClientHandler@67f17372 stateTo() completed. Socket state change success(updateWanted:BEING_CONNECT ,before:NONE ,current:BEING_CONNECT).
2018-05-18 10:00:12 INFO DefaultPinpointClientHandler@67f17372 initReconnect() completed.
2018-05-18 10:00:12 INFO DefaultPinpointClientHandler@67f17372 channelClosed() started.
2018-05-18 10:00:12 INFO DefaultPinpointClientHandler@67f17372 exceptionCaught() occurred. state:BEING_CONNECT, caused:Connection refused: /172.20.10.30:9994.
2018-05-18 10:00:12 INFO DefaultPinpointClientHandler@67f17372 stateTo() completed. Socket state change success(updateWanted:CONNECT_FAILED ,before:BEING_CONNECT ,current:CONNECT_FAILED).
2018-05-18 10:00:12 INFO PinpointClientHandshaker@bf629cf handshakeAbort() started.
2018-05-18 10:00:12 INFO PinpointClientHandshaker@bf629cf unexpected state
2018-05-18 10:00:15 WARN try reconnect. connectAddress:DnsSocketAddressProvider{host='172.20.10.30', port=9994}
2018-05-18 10:00:15 INFO DefaultPinpointClientHandler@669f4ce9 initReconnect() started.
2018-05-18 10:00:15 INFO DefaultPinpointClientHandler@669f4ce9 stateTo() completed. Socket state change success(updateWanted:BEING_CONNECT ,before:NONE ,current:BEING_CONNECT).
2018-05-18 10:00:15 INFO DefaultPinpointClientHandler@669f4ce9 initReconnect() completed.
2018-05-18 10:00:15 INFO DefaultPinpointClientHandler@669f4ce9 channelClosed() started.
2018-05-18 10:00:15 INFO DefaultPinpointClientHandler@669f4ce9 exceptionCaught() occurred. state:BEING_CONNECT, caused:Connection refused: /172.20.10.30:9994.
2018-05-18 10:00:15 INFO DefaultPinpointClientHandler@669f4ce9 stateTo() completed. Socket state change success(updateWanted:CONNECT_FAILED ,before:BEING_CONNECT ,current:CONNECT_FAILED).
2018-05-18 10:00:15 INFO PinpointClientHandshaker@1e22cd1c handshakeAbort() started.
2018-05-18 10:00:15 INFO PinpointClientHandshaker@1e22cd1c unexpected state
2018-05-18 10:00:18 WARN try reconnect. connectAddress:DnsSocketAddressProvider{host='172.20.10.30', port=9994}
2018-05-18 10:00:18 INFO DefaultPinpointClientHandler@309b2bb6 initReconnect() started.
2018-05-18 10:00:18 INFO DefaultPinpointClientHandler@309b2bb6 stateTo() completed. Socket state change success(updateWanted:BEING_CONNECT ,before:NONE ,current:BEING_CONNECT).
2018-05-18 10:00:18 INFO DefaultPinpointClientHandler@309b2bb6 initReconnect() completed.
2018-05-18 10:00:18 INFO DefaultPinpointClientHandler@309b2bb6 channelClosed() started.
2018-05-18 10:00:18 INFO DefaultPinpointClientHandler@309b2bb6 stateTo() completed. Socket state change success(updateWanted:CONNECT_FAILED ,before:BEING_CONNECT ,current:CONNECT_FAILED).
2018-05-18 10:00:18 WARN DefaultPinpointClientHandler@309b2bb6 exceptionCaught() occurred. state:CONNECT_FAILED. Caused:Connection refused: /172.20.10.30:9994
2018-05-18 10:00:18 INFO PinpointClientHandshaker@5c1db9a4 handshakeAbort() started.
2018-05-18 10:00:18 INFO PinpointClientHandshaker@5c1db9a4 unexpected state
2018-05-18 10:00:21 WARN try reconnect. connectAddress:DnsSocketAddressProvider{host='172.20.10.30', port=9994}
2018-05-18 10:00:21 INFO DefaultPinpointClientHandler@243db162 initReconnect() started.
2018-05-18 10:00:21 INFO DefaultPinpointClientHandler@243db162 stateTo() completed. Socket state change success(updateWanted:BEING_CONNECT ,before:NONE ,current:BEING_CONNECT).
2018-05-18 10:00:21 INFO DefaultPinpointClientHandler@243db162 initReconnect() completed.
2018-05-18 10:00:21 INFO DefaultPinpointClientHandler@243db162 channelClosed() started.
2018-05-18 10:00:21 INFO DefaultPinpointClientHandler@243db162 exceptionCaught() occurred. state:BEING_CONNECT, caused:Connection refused: /172.20.10.30:9994.
2018-05-18 10:00:21 INFO DefaultPinpointClientHandler@243db162 stateTo() completed. Socket state change success(updateWanted:CONNECT_FAILED ,before:BEING_CONNECT ,current:CONNECT_FAILED).
2018-05-18 10:00:21 INFO PinpointClientHandshaker@38d94a94 handshakeAbort() started.
2018-05-18 10:00:21 INFO PinpointClientHandshaker@38d94a94 unexpected state
2018-05-18 10:00:25 WARN try reconnect. connectAddress:DnsSocketAddressProvider{host='172.20.10.30', port=9994}
2018-05-18 10:00:25 INFO DefaultPinpointClientHandler@7cf3a34e initReconnect() started.
2018-05-18 10:00:25 INFO DefaultPinpointClientHandler@7cf3a34e stateTo() completed. Socket state change success(updateWanted:BEING_CONNECT ,before:NONE ,current:BEING_CONNECT).
2018-05-18 10:00:25 INFO DefaultPinpointClientHandler@7cf3a34e initReconnect() completed.
2018-05-18 10:00:25 INFO DefaultPinpointClientHandler@7cf3a34e channelClosed() started.
2018-05-18 10:00:25 INFO DefaultPinpointClientHandler@7cf3a34e stateTo() completed. Socket state change success(updateWanted:CONNECT_FAILED ,before:BEING_CONNECT ,current:CONNECT_FAILED).
2018-05-18 10:00:25 INFO PinpointClientHandshaker@15dcfcd8 handshakeAbort() started.
2018-05-18 10:00:25 INFO PinpointClientHandshaker@15dcfcd8 unexpected state
2018-05-18 10:00:25 WARN DefaultPinpointClientHandler@7cf3a34e exceptionCaught() occurred. state:CONNECT_FAILED. Caused:Connection refused: /172.20.10.30:9994
2018-05-18 10:00:28 WARN try reconnect. connectAddress:DnsSocketAddressProvider{host='172.20.10.30', port=9994}
2018-05-18 10:00:28 INFO DefaultPinpointClientHandler@47f3cdbc initReconnect() started.
2018-05-18 10:00:28 INFO DefaultPinpointClientHandler@47f3cdbc stateTo() completed. Socket state change success(updateWanted:BEING_CONNECT ,before:NONE ,current:BEING_CONNECT).
2018-05-18 10:00:28 INFO DefaultPinpointClientHandler@47f3cdbc initReconnect() completed.
2018-05-18 10:00:28 INFO DefaultPinpointClientHandler@47f3cdbc channelClosed() started.
2018-05-18 10:00:28 INFO DefaultPinpointClientHandler@47f3cdbc exceptionCaught() occurred. state:BEING_CONNECT, caused:Connection refused: /172.20.10.30:9994.
2018-05-18 10:00:28 INFO DefaultPinpointClientHandler@47f3cdbc stateTo() completed. Socket state change success(updateWanted:CONNECT_FAILED ,before:BEING_CONNECT ,current:CONNECT_FAILED).
2018-05-18 10:00:28 INFO PinpointClientHandshaker@e8cdbae handshakeAbort() started.
2018-05-18 10:00:28 INFO PinpointClientHandshaker@e8cdbae unexpected state
2018-05-18 10:00:31 WARN try reconnect. connectAddress:DnsSocketAddressProvider{host='172.20.10.30', port=9994}
2018-05-18 10:00:31 INFO DefaultPinpointClientHandler@54b3ef9c initReconnect() started.
2018-05-18 10:00:31 INFO DefaultPinpointClientHandler@54b3ef9c stateTo() completed. Socket state change success(updateWanted:BEING_CONNECT ,before:NONE ,current:BEING_CONNECT).
2018-05-18 10:00:31 INFO DefaultPinpointClientHandler@54b3ef9c initReconnect() completed.
2018-05-18 10:00:31 INFO DefaultPinpointClientHandler@54b3ef9c channelClosed() started.
2018-05-18 10:00:31 INFO DefaultPinpointClientHandler@54b3ef9c exceptionCaught() occurred. state:BEING_CONNECT, caused:Connection refused: /172.20.10.30:9994.
2018-05-18 10:00:31 INFO DefaultPinpointClientHandler@54b3ef9c stateTo() completed. Socket state change success(updateWanted:CONNECT_FAILED ,before:BEING_CONNECT ,current:CONNECT_FAILED).
2018-05-18 10:00:31 INFO PinpointClientHandshaker@353bd3a6 handshakeAbort() started.
2018-05-18 10:00:31 INFO PinpointClientHandshaker@353bd3a6 unexpected state
2018-05-18 10:00:34 WARN try reconnect. connectAddress:DnsSocketAddressProvider{host='172.20.10.30', port=9994}
2018-05-18 10:00:34 INFO DefaultPinpointClientHandler@654dab0f initReconnect() started.
2018-05-18 10:00:34 INFO DefaultPinpointClientHandler@654dab0f stateTo() completed. Socket state change success(updateWanted:BEING_CONNECT ,before:NONE ,current:BEING_CONNECT).
2018-05-18 10:00:34 INFO DefaultPinpointClientHandler@654dab0f initReconnect() completed.
2018-05-18 10:00:34 INFO DefaultPinpointClientHandler@654dab0f channelClosed() started.
2018-05-18 10:00:34 INFO DefaultPinpointClientHandler@654dab0f exceptionCaught() occurred. state:BEING_CONNECT, caused:Connection refused: /172.20.10.30:9994.
2018-05-18 10:00:34 INFO DefaultPinpointClientHandler@654dab0f stateTo() completed. Socket state change success(updateWanted:CONNECT_FAILED ,before:BEING_CONNECT ,current:CONNECT_FAILED).
2018-05-18 10:00:34 INFO PinpointClientHandshaker@3c8a1f0f handshakeAbort() started.
2018-05-18 10:00:34 INFO PinpointClientHandshaker@3c8a1f0f unexpected state
2018-05-18 10:00:37 WARN try reconnect. connectAddress:DnsSocketAddressProvider{host='172.20.10.30', port=9994}
2018-05-18 10:00:37 INFO DefaultPinpointClientHandler@450433b0 initReconnect() started.
2018-05-18 10:00:37 INFO DefaultPinpointClientHandler@450433b0 stateTo() completed. Socket state change success(updateWanted:BEING_CONNECT ,before:NONE ,current:BEING_CONNECT).
2018-05-18 10:00:37 INFO DefaultPinpointClientHandler@450433b0 initReconnect() completed.
2018-05-18 10:00:37 INFO reconnect success DnsSocketAddressProvider{host='172.20.10.30', port=9994}, [id: 0xcf1b828e, /172.20.10.32:5700 => /172.20.10.30:9994]
2018-05-18 10:00:37 WARN reconnectClientHandler:DefaultPinpointClientHandler@450433b0{channel=[id: 0xcf1b828e, /172.20.10.32:5700 => /172.20.10.30:9994]state=SocketState(NONE->BEING_CONNECT)}
2018-05-18 10:00:37 INFO DefaultPinpointClientHandler@450433b0 channelConnected() started. channel:[id: 0xcf1b828e, /172.20.10.32:5700 => /172.20.10.30:9994]
2018-05-18 10:00:37 INFO DefaultPinpointClientHandler@450433b0 stateTo() completed. Socket state change success(updateWanted:CONNECTED ,before:BEING_CONNECT ,current:CONNECTED).
2018-05-18 10:00:37 INFO DefaultPinpointClientHandler@450433b0 stateTo() completed. Socket state change success(updateWanted:RUN_WITHOUT_HANDSHAKE ,before:CONNECTED ,current:RUN_WITHOUT_HANDSHAKE).
2018-05-18 10:00:37 INFO PinpointClientHandshaker@e00e2e3 handshakeStart() started. channel:[id: 0xcf1b828e, /172.20.10.32:5700 => /172.20.10.30:9994]
2018-05-18 10:00:37 INFO PinpointClientHandshaker@e00e2e3 do handshake(1/2147483647). channel:[id: 0xcf1b828e, /172.20.10.32:5700 => /172.20.10.30:9994].
2018-05-18 10:00:37 INFO PinpointClientHandshaker@e00e2e3 handshakeStart() completed. channel:[id: 0xcf1b828e, /172.20.10.32:5700 => /172.20.10.30:9994], data:{serviceType=1010, socketId=19, hostName=Hexindai-XX, agentId=msg, supportCommandList=[730, 740, 750, 710], ip=fe80:0:0:0:98d9:3aff:fee6:e556%docker0, pid=19733, supportServer=true, version=1.7.3, applicationName=test, startTimestamp=1525921566817}
2018-05-18 10:00:37 INFO DefaultPinpointClientHandler@450433b0 channelConnected() completed.
2018-05-18 10:00:37 INFO PinpointClientHandshaker@e00e2e3 handshakeComplete() started. responsePacket:ControlHandshakeResponsePacket{requestId=0, payloadLength=27}
2018-05-18 10:00:37 INFO PinpointClientHandshaker@e00e2e3 handshakeComplete() completed. handshake-response:{code=0, subCode=2}.
2018-05-18 10:00:37 INFO DefaultPinpointClientHandler@450433b0 handleHandshakePacket() started. message:ControlHandshakeResponsePacket{requestId=0, payloadLength=27}
2018-05-18 10:00:37 INFO DefaultPinpointClientHandler@450433b0 stateTo() completed. Socket state change success(updateWanted:RUN_DUPLEX ,before:RUN_WITHOUT_HANDSHAKE ,current:RUN_DUPLEX).
2018-05-18 10:00:37 INFO [id: 0xcf1b828e, /172.20.10.32:5700 => /172.20.10.30:9994] handleHandshakePacket() completed. code:DUPLEX_COMMUNICATION
2018-05-18 10:01:37 INFO PinpointClientHandshaker@e00e2e3 HandshakeJob completed.
2018-05-18 10:00:09 INFO DefaultPinpointClientHandler@2038a6da handleClosedPacket() started. channel:[id: 0x95bf2dea, /172.20.10.32:32780 => /172.20.10.30:9994]
2018-05-18 10:00:09 INFO DefaultPinpointClientHandler@2038a6da stateTo() completed. Socket state change success(updateWanted:BEING_CLOSE_BY_SERVER ,before:RUN_DUPLEX ,current:BEING_CLOSE_BY_SERVER).
2018-05-18 10:00:09 INFO DefaultPinpointClientHandler@2038a6da channelClosed() started.
2018-05-18 10:00:09 INFO DefaultPinpointClientHandler@2038a6da stateTo() completed. Socket state change success(updateWanted:CLOSED_BY_SERVER ,before:BEING_CLOSE_BY_SERVER ,current:CLOSED_BY_SERVER).
2018-05-18 10:00:09 INFO PinpointClientHandshaker@1c110083 handshakeAbort() started.
2018-05-18 10:00:09 INFO PinpointClientHandshaker@1c110083 unexpected state
2018-05-18 10:00:12 WARN try reconnect. connectAddress:DnsSocketAddressProvider{host='172.20.10.30', port=9994}
2018-05-18 10:00:12 INFO DefaultPinpointClientHandler@7b4747a5 initReconnect() started.
2018-05-18 10:00:12 INFO DefaultPinpointClientHandler@7b4747a5 stateTo() completed. Socket state change success(updateWanted:BEING_CONNECT ,before:NONE ,current:BEING_CONNECT).
2018-05-18 10:00:12 INFO DefaultPinpointClientHandler@7b4747a5 initReconnect() completed.
2018-05-18 10:00:12 INFO DefaultPinpointClientHandler@7b4747a5 channelClosed() started.
2018-05-18 10:00:12 INFO DefaultPinpointClientHandler@7b4747a5 exceptionCaught() occurred. state:BEING_CONNECT, caused:Connection refused: /172.20.10.30:9994.
2018-05-18 10:00:12 INFO DefaultPinpointClientHandler@7b4747a5 stateTo() completed. Socket state change success(updateWanted:CONNECT_FAILED ,before:BEING_CONNECT ,current:CONNECT_FAILED).
2018-05-18 10:00:12 INFO PinpointClientHandshaker@5fa5c191 handshakeAbort() started.
2018-05-18 10:00:12 INFO PinpointClientHandshaker@5fa5c191 unexpected state
2018-05-18 10:00:15 WARN try reconnect. connectAddress:DnsSocketAddressProvider{host='172.20.10.30', port=9994}
2018-05-18 10:00:15 INFO DefaultPinpointClientHandler@d183d9a initReconnect() started.
2018-05-18 10:00:15 INFO DefaultPinpointClientHandler@d183d9a stateTo() completed. Socket state change success(updateWanted:BEING_CONNECT ,before:NONE ,current:BEING_CONNECT).
2018-05-18 10:00:15 INFO DefaultPinpointClientHandler@d183d9a initReconnect() completed.
2018-05-18 10:00:15 INFO DefaultPinpointClientHandler@d183d9a channelClosed() started.
2018-05-18 10:00:15 INFO DefaultPinpointClientHandler@d183d9a exceptionCaught() occurred. state:BEING_CONNECT, caused:Connection refused: /172.20.10.30:9994.
2018-05-18 10:00:15 INFO DefaultPinpointClientHandler@d183d9a stateTo() completed. Socket state change success(updateWanted:CONNECT_FAILED ,before:BEING_CONNECT ,current:CONNECT_FAILED).
2018-05-18 10:00:15 INFO PinpointClientHandshaker@6cb4cb2 handshakeAbort() started.
2018-05-18 10:00:15 INFO PinpointClientHandshaker@6cb4cb2 unexpected state
2018-05-18 10:00:18 WARN try reconnect. connectAddress:DnsSocketAddressProvider{host='172.20.10.30', port=9994}
2018-05-18 10:00:18 INFO DefaultPinpointClientHandler@61ea844c initReconnect() started.
2018-05-18 10:00:18 INFO DefaultPinpointClientHandler@61ea844c stateTo() completed. Socket state change success(updateWanted:BEING_CONNECT ,before:NONE ,current:BEING_CONNECT).
2018-05-18 10:00:18 INFO DefaultPinpointClientHandler@61ea844c initReconnect() completed.
2018-05-18 10:00:18 INFO DefaultPinpointClientHandler@61ea844c channelClosed() started.
2018-05-18 10:00:18 INFO DefaultPinpointClientHandler@61ea844c exceptionCaught() occurred. state:BEING_CONNECT, caused:Connection refused: /172.20.10.30:9994.
2018-05-18 10:00:18 INFO DefaultPinpointClientHandler@61ea844c stateTo() completed. Socket state change success(updateWanted:CONNECT_FAILED ,before:BEING_CONNECT ,current:CONNECT_FAILED).
2018-05-18 10:00:18 INFO PinpointClientHandshaker@3da22bd0 handshakeAbort() started.
2018-05-18 10:00:18 INFO PinpointClientHandshaker@3da22bd0 unexpected state
2018-05-18 10:00:22 WARN try reconnect. connectAddress:DnsSocketAddressProvider{host='172.20.10.30', port=9994}
2018-05-18 10:00:22 INFO DefaultPinpointClientHandler@6252a1a5 initReconnect() started.
2018-05-18 10:00:22 INFO DefaultPinpointClientHandler@6252a1a5 stateTo() completed. Socket state change success(updateWanted:BEING_CONNECT ,before:NONE ,current:BEING_CONNECT).
2018-05-18 10:00:22 INFO DefaultPinpointClientHandler@6252a1a5 initReconnect() completed.
2018-05-18 10:00:22 INFO DefaultPinpointClientHandler@6252a1a5 channelClosed() started.
2018-05-18 10:00:22 INFO DefaultPinpointClientHandler@6252a1a5 exceptionCaught() occurred. state:BEING_CONNECT, caused:Connection refused: /172.20.10.30:9994.
2018-05-18 10:00:22 INFO DefaultPinpointClientHandler@6252a1a5 stateTo() completed. Socket state change success(updateWanted:CONNECT_FAILED ,before:BEING_CONNECT ,current:CONNECT_FAILED).
2018-05-18 10:00:22 INFO PinpointClientHandshaker@e8f4e22 handshakeAbort() started.
2018-05-18 10:00:22 INFO PinpointClientHandshaker@e8f4e22 unexpected state
2018-05-18 10:00:25 WARN try reconnect. connectAddress:DnsSocketAddressProvider{host='172.20.10.30', port=9994}
2018-05-18 10:00:25 INFO DefaultPinpointClientHandler@5cf7bcff initReconnect() started.
2018-05-18 10:00:25 INFO DefaultPinpointClientHandler@5cf7bcff stateTo() completed. Socket state change success(updateWanted:BEING_CONNECT ,before:NONE ,current:BEING_CONNECT).
2018-05-18 10:00:25 INFO DefaultPinpointClientHandler@5cf7bcff initReconnect() completed.
2018-05-18 10:00:25 INFO DefaultPinpointClientHandler@5cf7bcff exceptionCaught() occurred. state:BEING_CONNECT, caused:Connection refused: /172.20.10.30:9994.
2018-05-18 10:00:25 INFO DefaultPinpointClientHandler@5cf7bcff channelClosed() started.
2018-05-18 10:00:25 INFO DefaultPinpointClientHandler@5cf7bcff stateTo() completed. Socket state change success(updateWanted:CONNECT_FAILED ,before:BEING_CONNECT ,current:CONNECT_FAILED).
2018-05-18 10:00:25 INFO PinpointClientHandshaker@6be0745d handshakeAbort() started.
2018-05-18 10:00:25 INFO PinpointClientHandshaker@6be0745d unexpected state
2018-05-18 10:00:28 WARN try reconnect. connectAddress:DnsSocketAddressProvider{host='172.20.10.30', port=9994}
2018-05-18 10:00:28 INFO DefaultPinpointClientHandler@3a6791af initReconnect() started.
2018-05-18 10:00:28 INFO DefaultPinpointClientHandler@3a6791af stateTo() completed. Socket state change success(updateWanted:BEING_CONNECT ,before:NONE ,current:BEING_CONNECT).
2018-05-18 10:00:28 INFO DefaultPinpointClientHandler@3a6791af initReconnect() completed.
2018-05-18 10:00:28 INFO DefaultPinpointClientHandler@3a6791af channelClosed() started.
2018-05-18 10:00:28 INFO DefaultPinpointClientHandler@3a6791af stateTo() completed. Socket state change success(updateWanted:CONNECT_FAILED ,before:BEING_CONNECT ,current:CONNECT_FAILED).
2018-05-18 10:00:28 INFO PinpointClientHandshaker@6432aabd handshakeAbort() started.
2018-05-18 10:00:28 INFO PinpointClientHandshaker@6432aabd unexpected state
2018-05-18 10:00:28 WARN DefaultPinpointClientHandler@3a6791af exceptionCaught() occurred. state:CONNECT_FAILED. Caused:Connection refused: /172.20.10.30:9994
2018-05-18 10:00:31 WARN try reconnect. connectAddress:DnsSocketAddressProvider{host='172.20.10.30', port=9994}
2018-05-18 10:00:31 INFO DefaultPinpointClientHandler@4e62f2cb initReconnect() started.
2018-05-18 10:00:31 INFO DefaultPinpointClientHandler@4e62f2cb stateTo() completed. Socket state change success(updateWanted:BEING_CONNECT ,before:NONE ,current:BEING_CONNECT).
2018-05-18 10:00:31 INFO DefaultPinpointClientHandler@4e62f2cb initReconnect() completed.
2018-05-18 10:00:31 INFO DefaultPinpointClientHandler@4e62f2cb exceptionCaught() occurred. state:BEING_CONNECT, caused:Connection refused: /172.20.10.30:9994.
2018-05-18 10:00:31 INFO DefaultPinpointClientHandler@4e62f2cb channelClosed() started.
2018-05-18 10:00:31 INFO DefaultPinpointClientHandler@4e62f2cb stateTo() completed. Socket state change success(updateWanted:CONNECT_FAILED ,before:BEING_CONNECT ,current:CONNECT_FAILED).
2018-05-18 10:00:31 INFO PinpointClientHandshaker@35819516 handshakeAbort() started.
2018-05-18 10:00:31 INFO PinpointClientHandshaker@35819516 unexpected state
2018-05-18 10:00:34 WARN try reconnect. connectAddress:DnsSocketAddressProvider{host='172.20.10.30', port=9994}
2018-05-18 10:00:34 INFO DefaultPinpointClientHandler@563492b1 initReconnect() started.
2018-05-18 10:00:34 INFO DefaultPinpointClientHandler@563492b1 stateTo() completed. Socket state change success(updateWanted:BEING_CONNECT ,before:NONE ,current:BEING_CONNECT).
2018-05-18 10:00:34 INFO DefaultPinpointClientHandler@563492b1 initReconnect() completed.
2018-05-18 10:00:34 INFO DefaultPinpointClientHandler@563492b1 exceptionCaught() occurred. state:BEING_CONNECT, caused:Connection refused: /172.20.10.30:9994.
2018-05-18 10:00:34 INFO DefaultPinpointClientHandler@563492b1 channelClosed() started.
2018-05-18 10:00:34 INFO DefaultPinpointClientHandler@563492b1 stateTo() completed. Socket state change success(updateWanted:CONNECT_FAILED ,before:BEING_CONNECT ,current:CONNECT_FAILED).
2018-05-18 10:00:34 INFO PinpointClientHandshaker@21550abf handshakeAbort() started.
2018-05-18 10:00:34 INFO PinpointClientHandshaker@21550abf unexpected state
2018-05-18 10:00:37 WARN try reconnect. connectAddress:DnsSocketAddressProvider{host='172.20.10.30', port=9994}
2018-05-18 10:00:37 INFO DefaultPinpointClientHandler@3ee5be65 initReconnect() started.
2018-05-18 10:00:37 INFO DefaultPinpointClientHandler@3ee5be65 stateTo() completed. Socket state change success(updateWanted:BEING_CONNECT ,before:NONE ,current:BEING_CONNECT).
2018-05-18 10:00:37 INFO DefaultPinpointClientHandler@3ee5be65 initReconnect() completed.
2018-05-18 10:00:37 INFO reconnect success DnsSocketAddressProvider{host='172.20.10.30', port=9994}, [id: 0xe90ae318, /172.20.10.32:5704 => /172.20.10.30:9994]
2018-05-18 10:00:37 WARN reconnectClientHandler:DefaultPinpointClientHandler@3ee5be65{channel=[id: 0xe90ae318, /172.20.10.32:5704 => /172.20.10.30:9994]state=SocketState(NONE->BEING_CONNECT)}
2018-05-18 10:00:37 INFO DefaultPinpointClientHandler@3ee5be65 channelConnected() started. channel:[id: 0xe90ae318, /172.20.10.32:5704 => /172.20.10.30:9994]
2018-05-18 10:00:37 INFO DefaultPinpointClientHandler@3ee5be65 stateTo() completed. Socket state change success(updateWanted:CONNECTED ,before:BEING_CONNECT ,current:CONNECTED).
2018-05-18 10:00:37 INFO DefaultPinpointClientHandler@3ee5be65 stateTo() completed. Socket state change success(updateWanted:RUN_WITHOUT_HANDSHAKE ,before:CONNECTED ,current:RUN_WITHOUT_HANDSHAKE).
2018-05-18 10:00:37 INFO PinpointClientHandshaker@34c43aa3 handshakeStart() started. channel:[id: 0xe90ae318, /172.20.10.32:5704 => /172.20.10.30:9994]
2018-05-18 10:00:37 INFO PinpointClientHandshaker@34c43aa3 do handshake(1/2147483647). channel:[id: 0xe90ae318, /172.20.10.32:5704 => /172.20.10.30:9994].
2018-05-18 10:00:37 INFO PinpointClientHandshaker@34c43aa3 handshakeStart() completed. channel:[id: 0xe90ae318, /172.20.10.32:5704 => /172.20.10.30:9994], data:{socketId=19, applicationName=test, startTimestamp=1526027326774, agentId=settlment, hostName=Hexindai-XX, supportServer=true, pid=6331, serviceType=1010, ip=fe80:0:0:0:98d9:3aff:fee6:e556%3, version=1.7.3, supportCommandList=[750, 730, 710, 740]}
2018-05-18 10:00:37 INFO DefaultPinpointClientHandler@3ee5be65 channelConnected() completed.
2018-05-18 10:00:37 INFO PinpointClientHandshaker@34c43aa3 handshakeComplete() started. responsePacket:ControlHandshakeResponsePacket{requestId=0, payloadLength=27}
2018-05-18 10:00:37 INFO PinpointClientHandshaker@34c43aa3 handshakeComplete() completed. handshake-response:{code=0, subCode=2}.
2018-05-18 10:00:37 INFO DefaultPinpointClientHandler@3ee5be65 handleHandshakePacket() started. message:ControlHandshakeResponsePacket{requestId=0, payloadLength=27}
2018-05-18 10:00:37 INFO DefaultPinpointClientHandler@3ee5be65 stateTo() completed. Socket state change success(updateWanted:RUN_DUPLEX ,before:RUN_WITHOUT_HANDSHAKE ,current:RUN_DUPLEX).
2018-05-18 10:00:37 INFO [id: 0xe90ae318, /172.20.10.32:5704 => /172.20.10.30:9994] handleHandshakePacket() completed. code:DUPLEX_COMMUNICATION
2018-05-18 10:01:37 INFO PinpointClientHandshaker@34c43aa3 HandshakeJob completed.
collector log
grep '2018-05-18 10:07:5' apache-tomcat-7.0.82-1/logs/ -R
apache-tomcat-7.0.82-1/logs/catalina.out:2018-05-18 10:07:53 DEBUG Received TAgentStatBatch=TAgentStatBatch(agentId:msg, startTimestamp:1525921566817, agentStats:[TAgentStat(agentId:msg, startTimestamp:1525921566817, timestamp:1526609248283, collectInterval:5000, gc:TJvmGc(type:PARALLEL, jvmMemoryHeapUsed:155958352, jvmMemoryHeapMax:1864368128, jvmMemoryNonHeapUsed:157613368, jvmMemoryNonHeapMax:-1, jvmGcOldCount:4, jvmGcOldTime:16157), cpuLoad:TCpuLoad(jvmCpuLoad:0.0020181634712411706, systemCpuLoad:0.022199798183652877), transaction:TTransaction(sampledNewCount:0, sampledContinuationCount:0, unsampledNewCount:0, unsampledContinuationCount:0), activeTrace:TActiveTrace(histogram:TActiveTraceHistogram(version:0, histogramSchemaType:2, activeTraceCount:[0, 0, 0, 0])), dataSourceList:TDataSourceList(dataSourceList:[]), responseTime:TResponseTime()), TAgentStat(agentId:msg, startTimestamp:1525921566817, timestamp:1526609253283, collectInterval:5000, gc:TJvmGc(type:PARALLEL, jvmMemoryHeapUsed:158750848, jvmMemoryHeapMax:1864368128, jvmMemoryNonHeapUsed:157613368, jvmMemoryNonHeapMax:-1, jvmGcOldCount:4, jvmGcOldTime:16157), cpuLoad:TCpuLoad(jvmCpuLoad:0.010219724067450179, systemCpuLoad:0.02401635155850792), transaction:TTransaction(sampledNewCount:0, sampledContinuationCount:0, unsampledNewCount:0, unsampledContinuationCount:0), activeTrace:TActiveTrace(histogram:TActiveTraceHistogram(version:0, histogramSchemaType:2, activeTraceCount:[0, 0, 0, 0])), dataSourceList:TDataSourceList(dataSourceList:[]), responseTime:TResponseTime()), TAgentStat(agentId:msg, startTimestamp:1525921566817, timestamp:1526609258283, collectInterval:5000, gc:TJvmGc(type:PARALLEL, jvmMemoryHeapUsed:158984752, jvmMemoryHeapMax:1864368128, jvmMemoryNonHeapUsed:157613368, jvmMemoryNonHeapMax:-1, jvmGcOldCount:4, jvmGcOldTime:16157), cpuLoad:TCpuLoad(jvmCpuLoad:0.0020090406830738324, systemCpuLoad:0.03164239075841286), transaction:TTransaction(sampledNewCount:0, sampledContinuationCount:0, unsampledNewCount:0, unsampledContinuationCount:0), activeTrace:TActiveTrace(histogram:TActiveTraceHistogram(version:0, histogramSchemaType:2, activeTraceCount:[0, 0, 0, 0])), dataSourceList:TDataSourceList(dataSourceList:[]), responseTime:TResponseTime()), TAgentStat(agentId:msg, startTimestamp:1525921566817, timestamp:1526609263283, collectInterval:5000, gc:TJvmGc(type:PARALLEL, jvmMemoryHeapUsed:159125616, jvmMemoryHeapMax:1864368128, jvmMemoryNonHeapUsed:157613368, jvmMemoryNonHeapMax:-1, jvmGcOldCount:4, jvmGcOldTime:16157), cpuLoad:TCpuLoad(jvmCpuLoad:0.001525165226232842, systemCpuLoad:0.022877478393492627), transaction:TTransaction(sampledNewCount:0, sampledContinuationCount:0, unsampledNewCount:0, unsampledContinuationCount:0), activeTrace:TActiveTrace(histogram:TActiveTraceHistogram(version:0, histogramSchemaType:2, activeTraceCount:[0, 0, 0, 0])), dataSourceList:TDataSourceList(dataSourceList:[]), responseTime:TResponseTime()), TAgentStat(agentId:msg, startTimestamp:1525921566817, timestamp:1526609268283, collectInterval:5000, gc:TJvmGc(type:PARALLEL, jvmMemoryHeapUsed:159250728, jvmMemoryHeapMax:1864368128, jvmMemoryNonHeapUsed:157613368, jvmMemoryNonHeapMax:-1, jvmGcOldCount:4, jvmGcOldTime:16157), cpuLoad:TCpuLoad(jvmCpuLoad:0.0020408163265306124, systemCpuLoad:0.015816326530612247), transaction:TTransaction(sampledNewCount:0, sampledContinuationCount:0, unsampledNewCount:0, unsampledContinuationCount:0), activeTrace:TActiveTrace(histogram:TActiveTraceHistogram(version:0, histogramSchemaType:2, activeTraceCount:[0, 0, 0, 0])), dataSourceList:TDataSourceList(dataSourceList:[]), responseTime:TResponseTime()), TAgentStat(agentId:msg, startTimestamp:1525921566817, timestamp:1526609273283, collectInterval:5000, gc:TJvmGc(type:PARALLEL, jvmMemoryHeapUsed:159482544, jvmMemoryHeapMax:1864368128, jvmMemoryNonHeapUsed:157613368, jvmMemoryNonHeapMax:-1, jvmGcOldCount:4, jvmGcOldTime:16157), cpuLoad:TCpuLoad(jvmCpuLoad:0.002554931016862545, systemCpuLoad:0.01788451711803781), transaction:TTransaction(sampledNewCount:0, sampledContinuationCount:0, unsampledNewCount:0, unsampledContinuationCount:0), activeTrace:TActiveTrace(histogram:TActiveTraceHistogram(version:0, histogramSchemaType:2, activeTraceCount:[0, 0, 0, 0])), dataSourceList:TDataSourceList(dataSourceList:[]), responseTime:TResponseTime())])
apache-tomcat-7.0.82-1/logs/catalina.out:2018-05-18 10:07:53 DEBUG Received TAgentStatBatch=TAgentStatBatch(agentId:msg, startTimestamp:1525921566817, agentStats:[TAgentStat(agentId:msg, startTimestamp:1525921566817, timestamp:1526609248283, collectInterval:5000, gc:TJvmGc(type:PARALLEL, jvmMemoryHeapUsed:155958352, jvmMemoryHeapMax:1864368128, jvmMemoryNonHeapUsed:157613368, jvmMemoryNonHeapMax:-1, jvmGcOldCount:4, jvmGcOldTime:16157), cpuLoad:TCpuLoad(jvmCpuLoad:0.0020181634712411706, systemCpuLoad:0.022199798183652877), transaction:TTransaction(sampledNewCount:0, sampledContinuationCount:0, unsampledNewCount:0, unsampledContinuationCount:0), activeTrace:TActiveTrace(histogram:TActiveTraceHistogram(version:0, histogramSchemaType:2, activeTraceCount:[0, 0, 0, 0])), dataSourceList:TDataSourceList(dataSourceList:[]), responseTime:TResponseTime()), TAgentStat(agentId:msg, startTimestamp:1525921566817, timestamp:1526609253283, collectInterval:5000, gc:TJvmGc(type:PARALLEL, jvmMemoryHeapUsed:158750848, jvmMemoryHeapMax:1864368128, jvmMemoryNonHeapUsed:157613368, jvmMemoryNonHeapMax:-1, jvmGcOldCount:4, jvmGcOldTime:16157), cpuLoad:TCpuLoad(jvmCpuLoad:0.010219724067450179, systemCpuLoad:0.02401635155850792), transaction:TTransaction(sampledNewCount:0, sampledContinuationCount:0, unsampledNewCount:0, unsampledContinuationCount:0), activeTrace:TActiveTrace(histogram:TActiveTraceHistogram(version:0, histogramSchemaType:2, activeTraceCount:[0, 0, 0, 0])), dataSourceList:TDataSourceList(dataSourceList:[]), responseTime:TResponseTime()), TAgentStat(agentId:msg, startTimestamp:1525921566817, timestamp:1526609258283, collectInterval:5000, gc:TJvmGc(type:PARALLEL, jvmMemoryHeapUsed:158984752, jvmMemoryHeapMax:1864368128, jvmMemoryNonHeapUsed:157613368, jvmMemoryNonHeapMax:-1, jvmGcOldCount:4, jvmGcOldTime:16157), cpuLoad:TCpuLoad(jvmCpuLoad:0.0020090406830738324, systemCpuLoad:0.03164239075841286), transaction:TTransaction(sampledNewCount:0, sampledContinuationCount:0, unsampledNewCount:0, unsampledContinuationCount:0), activeTrace:TActiveTrace(histogram:TActiveTraceHistogram(version:0, histogramSchemaType:2, activeTraceCount:[0, 0, 0, 0])), dataSourceList:TDataSourceList(dataSourceList:[]), responseTime:TResponseTime()), TAgentStat(agentId:msg, startTimestamp:1525921566817, timestamp:1526609263283, collectInterval:5000, gc:TJvmGc(type:PARALLEL, jvmMemoryHeapUsed:159125616, jvmMemoryHeapMax:1864368128, jvmMemoryNonHeapUsed:157613368, jvmMemoryNonHeapMax:-1, jvmGcOldCount:4, jvmGcOldTime:16157), cpuLoad:TCpuLoad(jvmCpuLoad:0.001525165226232842, systemCpuLoad:0.022877478393492627), transaction:TTransaction(sampledNewCount:0, sampledContinuationCount:0, unsampledNewCount:0, unsampledContinuationCount:0), activeTrace:TActiveTrace(histogram:TActiveTraceHistogram(version:0, histogramSchemaType:2, activeTraceCount:[0, 0, 0, 0])), dataSourceList:TDataSourceList(dataSourceList:[]), responseTime:TResponseTime()), TAgentStat(agentId:msg, startTimestamp:1525921566817, timestamp:1526609268283, collectInterval:5000, gc:TJvmGc(type:PARALLEL, jvmMemoryHeapUsed:159250728, jvmMemoryHeapMax:1864368128, jvmMemoryNonHeapUsed:157613368, jvmMemoryNonHeapMax:-1, jvmGcOldCount:4, jvmGcOldTime:16157), cpuLoad:TCpuLoad(jvmCpuLoad:0.0020408163265306124, systemCpuLoad:0.015816326530612247), transaction:TTransaction(sampledNewCount:0, sampledContinuationCount:0, unsampledNewCount:0, unsampledContinuationCount:0), activeTrace:TActiveTrace(histogram:TActiveTraceHistogram(version:0, histogramSchemaType:2, activeTraceCount:[0, 0, 0, 0])), dataSourceList:TDataSourceList(dataSourceList:[]), responseTime:TResponseTime()), TAgentStat(agentId:msg, startTimestamp:1525921566817, timestamp:1526609273283, collectInterval:5000, gc:TJvmGc(type:PARALLEL, jvmMemoryHeapUsed:159482544, jvmMemoryHeapMax:1864368128, jvmMemoryNonHeapUsed:157613368, jvmMemoryNonHeapMax:-1, jvmGcOldCount:4, jvmGcOldTime:16157), cpuLoad:TCpuLoad(jvmCpuLoad:0.002554931016862545, systemCpuLoad:0.01788451711803781), transaction:TTransaction(sampledNewCount:0, sampledContinuationCount:0, unsampledNewCount:0, unsampledContinuationCount:0), activeTrace:TActiveTrace(histogram:TActiveTraceHistogram(version:0, histogramSchemaType:2, activeTraceCount:[0, 0, 0, 0])), dataSourceList:TDataSourceList(dataSourceList:[]), responseTime:TResponseTime())])
apache-tomcat-7.0.82-1/logs/catalina.out:2018-05-18 10:07:54 DEBUG Got ping response for sessionid: 0x100000742ef004e after 1ms
apache-tomcat-7.0.82-1/logs/catalina.out:2018-05-18 10:07:55 DEBUG Got ping response for sessionid: 0x100000742ef004d after 1ms
apache-tomcat-7.0.82-1/logs/catalina.out:2018-05-18 10:07:58 DEBUG Got ping response for sessionid: 0x100000742ef004f after 2ms
I have just contacted the distributed tracing system. I have no idea about these. Thank you very much for your reply.
I've been sitting there for a while.
I checked that their time should be the same.
ApplicationMapStatisticsCallee_Ver2, ApplicationMapStatisticsCaller_Ver2 is still empty
The agent log has some weird stuff going on - it seems to have logs for both agentId=msg and agentId=settlment. I'm not quite sure what's going on there, please provide a bit more detail on how your applications are set up along with the agent.
Also, the collector log you provided doesn't have any logs for transactions, so nothing should show up in the server map.
Yes, I have two agent.
I added this to the start shell in two application:
export CATALINA_OPTS="$CATALINA_OPTS -javaagent:/export/apm/pinpoint-agent/pinpoint-bootstrap-1.7.3.jar -Dpinpoint.agentId=settlment -Dpinpoint.applicationName=test"
Do you mean that I don't have transactions in my app? What does transaction mean? The database transaction or a complete request?
Are the agent ids same for the 2 applications? Note that agent ids must be globally unique so you will have to give different java processes different agent ids if this is the case.
Also, where is the agentId=msg coming from?
Regarding the transaction log, sorry, I should've been more clear - transaction as in a single, complete request (across multiple nodes if applicable) that shows up in the server map.
When a request hits an application the agent traces everything related to that request and sends it over to the collector. The collector then stores this data into hbase tables (including ApplicationMapStatisticsCallee_Ver2 and ApplicationMapStatisticsCaller_Ver2) and leaves a DEBUG log. Pinpoint web then reads this data from hbase to create the server map.
The collector log above is missing this.
To simplify the testing process, could you try the following?
If the server map and the load charts still don't show anything, please attach the whole DEBUG log for the agent, collector and web so we can take a look at it.
Their ids are different, and I only show one of them. OK I'll try. Thank you very much
Hello, I have the same problem. How did you solve it? thanks
This issue/proposal has been automatically marked as stale because it hasn't had any recent activity. It will automatically be closed if no further activity occurs for 20days. If you think this should still be open, or the problem still persists, just pop a reply in the comments and one of the maintainers will (try!) to follow up. Thank you for your interest and contribution to the Pinpoint Community.
Hello, I have the same problem. How did you solve it? thanks
@Xylus @leogoing
Hi @NiLtheGazettE
Please attach the agent, collector and web's DEBUG log that includes the requests not showing up on the server map so we can take a look.
Guys I've given up
I've got the same issue, but I've opened a new issue ( https://github.com/naver/pinpoint/issues/4673 ) for the sake of order
I solved my issue. Check my https://github.com/naver/pinpoint/issues/4673 post for you may find the solution there too
THX ,has solved it
This issue/proposal has been automatically marked as stale because it hasn't had any recent activity. It will automatically be closed if no further activity occurs for 20days. If you think this should still be open, or the problem still persists, just pop a reply in the comments and one of the maintainers will (try!) to follow up. Thank you for your interest and contribution to the Pinpoint Community.
Most helpful comment
Hi @leogoing
that is very weird.
Is there anything strange going in the web/collector log?
Can you make sure data is inserted into ApplicationMapStatisticsCallee_Ver2, ApplicationMapStatisticsCaller_Ver2, and ApplicationMapStatisticsSelf_Ver2 tables?