search

pinpoint-apm / pinpoint

APM, (Application Performance Management) tool for large-scale distributed systems.
https://pinpoint-apm.gitbook.io/
Apache License 2.0
13.42k stars 3.76k forks source link

Agent not attaching to java application server(spring based application) #5547

Closed chatmachine closed 5 years ago

chatmachine commented 5 years ago

What version of pinpoint are you using?

master/v1.8.3

Describe your problem**

Agent not attaching to java application server(spring based application) jdk1.7 and jre1.8

What have you done?

After adding -javaagent to startup option for application server

pinpoint agent [com.navercorp.pinpoint.profiler.DefaultAgent] starting... Exception in thread "main" java.lang.reflect.InvocationTargetException Caused by: java.lang.ClassNotFoundException: org/apache/xerces/jaxp/DocumentBuilderFactoryImpl at java.lang.Class.forName0(Native Method) at java.lang.Class.forName(Class.java:348) at javax.xml.parsers.FactoryFinder.getProviderClass(FactoryFinder.java:124) at javax.xml.parsers.FactoryFinder.newInstance(FactoryFinder.java:188) ... 36 more FATAL ERROR in native method: processing of -javaagent failed

If I remove agent and start server,the application server starts up with org/apache/xerces/jaxp/DocumentBuilderFactoryImpl ,not sure why it doesn't find when agent is there

chatmachine commented 5 years ago

-Djavax.xml.parsers.DocumentBuilderFactory=org.apache.xerces.jaxp.DocumentBuilderFactoryImpl This option is there when the server starts without attaching agent.Not sure ,when we attach agent why this is not found.

chatmachine commented 5 years ago

Can we hack/force this on startup?I tried without success,not sure its known bug

Xylus commented 5 years ago

Hi @chatmachine It looks like you're using the parser from xerces for your application. By specifying -Djavax.xml.parsers.DocumentBuilderFactory option, the parser used by pinpoint agent for logging will also be affected. Since the xerces dependency will not be in the boot class path, it will not be visible to the agent, resulting in your issue.

I think you have 2 options.

  1. Use the DocumentBuilderFactoryImpl available in jre (rt.jar)
    Set -Djavax.xml.parsers.DocumentBuilderFactory=com.sun.org.apache.xerces.internal.jaxp.DocumentBuilderFactoryImpl (Not entirely sure but this may be java's default implementation, in which case you could maybe just remove this option). This will also change the DocumentBuilderFactoryImpl used by your application (I'm assuming your application is using this as you've set the -Djavax.xml.parsers.DocumentBuilderFactory option) to the one in the jre, which might have an effect on your application.
  2. Add xerces and it's dependencies to boot class path
    Add -Xbootclasspath/a:$PATH_TO_XERCES_JAR;$PATH_TO_XERCES_DEPENDENCY_JARS (while keeping your -Djavax.xml.parsers.DocumentBuilderFactory=org.apache.xerces.jaxp.DocumentBuilderFactoryImpl option). I tested using xercesImpl-2.12.0.jar, and it required xml-apis-1.4.01.jar, so I had to add both of them to -Xbootclasspath/a:.
chatmachine commented 5 years ago

Thank you so much ,this was resolved .I hit the next issue and trying to resolve "2019-05-03 20:52:39 INFO DefaultPinpointClientHandler@716e431d handleHandshakePacket() started. message:ControlHandshakeResponsePacket{requestId=0, payloadLength=27} 2019-05-03 20:52:39 INFO DefaultPinpointClientHandler@716e431d stateTo() completed. Socket state change success(updateWanted:RUN_DUPLEX ,before:RUN_WITHOUT_HANDSHAKE ,current:RUN_DUPLEX). 2019-05-03 20:52:39 INFO [id: 0x411f0686, /127.0.0.1:51206 => /127.0.0.1:9994] handleHandshakePacket() completed. code:DUPLEX_COMMUNICATION 2019-05-03 20:52:41 WARN request timed out while waiting for response. 2019-05-03 20:52:41 INFO request fail. request:com.navercorp.pinpoint.profiler.metadata.ApiMetaData@7dabafe3 Caused:timeout com.navercorp.pinpoint.rpc.PinpointSocketException: timeout at com.navercorp.pinpoint.rpc.DefaultFuture.fireTimeout(DefaultFuture.java:120) at com.navercorp.pinpoint.rpc.DefaultFuture.run(DefaultFuture.java:235) at org.jboss.netty.util.HashedWheelTimer$HashedWheelTimeout.expire(HashedWheelTimer.java:556) at org.jboss.netty.util.HashedWheelTimer$HashedWheelBucket.expireTimeouts(HashedWheelTimer.java:632) at org.jboss.netty.util.HashedWheelTimer$Worker.run(HashedWheelTimer.java:369) at org.jboss.netty.util.ThreadRenamingRunnable.run(ThreadRenamingRunnable.java:108) at java.lang.Thread.run(Thread.java:748) 2019-05-03 20:52:41 INFO Stopping pinpoint Agent. 2019-05-03 20:52:41 INFO AgentInfoSender stopped "

chatmachine commented 5 years ago

2019-05-03 23:43:12 INFO Sending AgentInfo TAgentInfo(hostname:localhost, ip:10.9.163.10, ports:, agentId:1, applicationName:core-app, serviceType:1000, pid:42402, agentVersion:1.8.3, vmVersion:1.8.0_172, startTimestamp:1556926391116, serverMetaData:TServerMetaData(serverInfo*****, gcType:PARALLEL), container:false) 2019-05-03 23:43:15 WARN request timed out while waiting for response.

chatmachine commented 5 years ago

TCP:// localhost => 127.0.0.1:9994 [SUCCESS] => 0:0:0:0:0:0:0:1:9994 [FAIL] UDP-SPAN:// localhost => 127.0.0.1:9996 [SUCCESS] => 0:0:0:0:0:0:0:1:9996 [FAIL] TCP:// localhost => 127.0.0.1:9994 [SUCCESS] => 0:0:0:0:0:0:0:1:9994 [FAIL]

FYI, i am using hbase 1.3 and its on different machine.Is above problem due to collector? Collector and web components are deployed on tomcat and agent is successfully attached .Hbase is on remote machine.My understanding is Agent will populate hbase Agentinfo and collector will get stats from agent wgich will be pushed to hbase

Xylus commented 5 years ago

Try setting 127.0.0.1 instead of localhost in your agent's pinpoint.config file. Your ::1 loopback seems to be failing.

chatmachine commented 5 years ago

Used IP(masking) but STAT fails ,rest pass,any cluse UDP-SPAN://{IP} => {IP}:9996 [SUCCESS]

TCP:// IP => IP:9994 [SUCCESS]

UDP-SPAN:// IP => IP:9996 [SUCCESS]

TCP:// IP => IP:9994 [SUCCESS]

Xylus commented 5 years ago

stat data uses 9995 port, check if the port's not blocked.

chatmachine commented 5 years ago

what do cluster.listen.ip and cluster.connect.address signify in pinpoint-web.properies and pinpoint-collector.properties?Arenot they referring to same thing(hostname and ip address)

chatmachine commented 5 years ago

Port 9995 is not blocked nc command shows success

chatmachine commented 5 years ago

NETWORKTEST.SH OUTPUT https://gist.github.com/chatmachine/c8cb9991cf92745e77323052c270a6e7

chatmachine commented 5 years ago

2019-05-07 08:15:28 WARN discard retry message(RetryMessage{retryCount=3, maxRetryCount=3, bytes=106, messageDescription='ApiMetaData'}). 2019-05-07 08:15:28 INFO request fail. request:RetryMessage{retryCount=3, maxRetryCount=3, bytes=243, messageDescription='ApiMetaData'}, caused:timeout com.navercorp.pinpoint.rpc.PinpointSocketException: timeout at com.navercorp.pinpoint.rpc.DefaultFuture.fireTimeout(DefaultFuture.java:120) at com.navercorp.pinpoint.rpc.DefaultFuture.run(DefaultFuture.java:235) at org.jboss.netty.util.HashedWheelTimer$HashedWheelTimeout.expire(HashedWheelTimer.java:556) at org.jboss.netty.util.HashedWheelTimer$HashedWheelBucket.expireTimeouts(HashedWheelTimer.java:632) at org.jboss.netty.util.HashedWheelTimer$Worker.run(HashedWheelTimer.java:369) at org.jboss.netty.util.ThreadRenamingRunnable.run(ThreadRenamingRunnable.java:108) at java.lang.Thread.run(Thread.java:748) 2019-05-07 08:15:28 WARN discard retry message(RetryMessage{retryCount=3, maxRetryCount=3, bytes=243, messageDescription='ApiMetaData'}). 2019-05-07 08:18:57 INFO Sending AgentInfo TAgentInfo(hostname:localhost, ip:10.9.163.10, ports:, agentId:1, applicationName:core-app, serviceType:1210, pid:89000, agentVersion:1.8.3, vmVersion:1.8.0_172, startTimestamp:1557216836252, serverMetaData:TServerMetaData(serverInfo:, vmArgs:[-Djava.io.tmpdir=/tmp, -enableassertions, -Xss512k, -XX:+HeapDumpOnOutOfMemoryError, -XX:-UseCodeCacheFlushing, -XX:+TieredCompilation, -XX:-UseBiasedLocking, -XX:HeapDumpPath=/var/tmp, -XX:ErrorFile=/home/user/shelt/app/220/patch/core/phillips/logs/phillips/hs_err_pid%p.log, -XX:StackShadowPages=20, -Doracle.net.ssl_version=1.2, -Duser.timezone=GMT, -Djavax.net.ssl.trustStore=/home/user/shelt/app/220/patch/core/phillips-test/config/cacerts_phillips_external.bcfks, -Djavax.net.ssl.trustStoreType=bcfks, -Dorg.eclipse.jetty948.util.log.class=klein948.jetty948.phillipsLog, -Dorg.eclipse.jetty948.LEVEL=WARN, -Djava.awt.headless=true, -Djava.library.path=/home/user/shelt/app/220/patch/core/jetty948/platform/linux64, -DisDev=true, -Dapp=sandeepdh-wsl1.internal.company.com, -Dconfig=/home/user/shelt/app/220/patch/core/phillips/config, -DconfigFile=, -Dsettings=/home/user/shelt/app/220/patch/core/phillips/config/settings, -Djava.security.egd=file:/dev/./urandom, -DsettingsPath=dev.mydev.landmark.-.-, -Dapp.home=/home/user/shelt/app/220/patch/core/phillips, -Dbuild.home=/home/user/shelt/app/220/patch/core/build, -Dphillips-test.home=/home/user/shelt/app/220/patch/core/phillips-test, -Dicuformat=false, -DforceUseIcuLocale=false, -Djava.locale.providers=JRE,SPI, -Djava.ext.dirs=/home/user/shelt/tools/Linux/jdk/openjdk1.8.0_172_x64/jre/lib/ext, -Djava.endorsed.dirs=/home/user/shelt/app/220/patch/core/phillips/alternative_endorsed_jdk1.8.0_172_x64, -Djavax.xml.parsers.DocumentBuilderFactory=org.apache.xerces.jaxp.DocumentBuilderFactoryImpl, -Djavax.xml.parsers.SAXParserFactory=org.apache.xerces.jaxp.SAXParserFactoryImpl, -Dorg.apache.xerces.xni.parser.XMLParserConfiguration=org.apache.xerces.parsers.SecureProcessingConfiguration, -Djdk.xml.entityExpansionLimit=64000, -Dcom.google.gdata.DisableCookieHandler=true, -Djavax.xml.transform.TransformerFactory=org.apache.xalan.processor.TransformerFactoryImpl, -Dnet.spy.log.LoggerImpl=net.spy.memcached.compat.log.SunLogger, -Djavax.xml.stream.XMLInputFactory=com.sun.xml.internal.stream.XMLInputFactoryImpl, -Djavax.xml.stream.XMLOutputFactory=com.sun.xml.internal.stream.XMLOutputFactoryImpl, -Djavax.xml.stream.XMLEventFactory=com.sun.xml.internal.stream.events.XMLEventFactoryImpl, -Djdk.tls.rejectClientInitiatedRenegotiation=true, -Djavax.xml.soap.MetaFactory=com.sun.xml.internal.messaging.saaj.soap.SAAJMetaFactoryImpl, -Dorg.apache.xml.security.ignoreLineBreaks=false, -Xmx16g, -XX:MetaspaceSize=4g, -XX:MaxMetaspaceSize=4g, -XX:MinMetaspaceFreeRatio=0, -XX:MaxMetaspaceFreeRatio=100, -XX:ReservedCodeCacheSize=256m, -XX:+TieredCompilation, -Xverify:none, -XX:TieredStopAtLevel=1, -Xbootclasspath/a:/home/user/shelt/app/220/patch/core/ext/xerces_xercesImpl/2.12.0/jars/xercesImpl-2.12.0.jar:/home/user/shelt/app/220/patch/core/ext/xml-apis_xml-apis/1.4.01/jars/xml-apis-1.4.01.jar, -javaagent:/home/user/Downloads/Agent/pinpoint-bootstrap-1.8.3.jar, -Dpinpoint.applicationName=core-app, -Dpinpoint.agentId=1, -Djava.noMemAlloc, -Ddummy, -Dptest.warmupLoops=1, -Dptest.benchmarkLoops=1, -Dptest.isRunningOnVpod=false, -Dptest.testSuite=, -Dptest.testName=, -Dptest.testSuiteSuffix=, -Dtest.runSoapMessageValidator=true, -Dptest.stableMetrics=true, -Dphillips.enableFips=false, -Dphillips.enableRDRAND=true, -Dcontainer=Jetty948, -Dcaas-client.connect-to-superpod-caas=false, -Dcaas-client.pc.connect-to-superpod-caas=false, -Dcaas.overridemcdtocaas=false, -Djetty.h2.enabled=false, -Dlauncher.use.osgi=true, -Dsun.net.http.allowRestrictedHeaders=true, -Dorg.apache.jasper.compiler.disablejsr199=true, -XX:-DoEscapeAnalysis, -XX:+UnlockExperimentalVMOptions, -XX:SymbolTableSize=500107, -Dphillips.app.java_home=/home/user/shelt/tools/Linux/jdk/openjdk1.8.0_172_x64, -Dphillips.app.java_runtime_home=/home/user/shelt/tools/Linux/jdk/openjdk1.8.0_172_x64, -Dorg.eclipse.jetty94.http.HttpGenerator.STRICT=true, -Dorg.eclipse.jetty948.http.HttpGenerator.STRICT=true, -Dsystem.jvm.warmup.on=config, -Dsystem.jvm.warmup.delay.seconds=-1, -Dping.test.approle=false, -Dping.cpu.threshold=-1, -Dsystem.pre.shutdown.group.timeout.seconds=10, -Dsystem.shutdown.group.timeout.seconds=15, -Dsystem.jvm.shutdown.group.timeout.seconds=10, -Dsystem.shutdown.lb.interval.seconds=-1, -Dsystem.shutdown.request.wait.seconds=-1, -Dsystem.shutdown.task.wait.seconds=-1, -Dsystem.shutdown.gracefulwait.seconds=-1, -Dsystem.shutdown.sigtermwait.seconds=-1, -Dextra.webcontainer.classpath=/home/user/shelt/app/220/patch/core/ext/org.apache.taglibs_taglibs-standard-impl/1.2.5/jars/taglibs-standard-impl-1.2.5.jar, -Dtomcat.util.scan.StandardJarScanFilter.jarsToSkip=manifest-classpathMAIN.rundev-debugAppJavaCall.jar,org.eclipse.osgi-.jar,launcher.jar,commons-io-.jar,guava-.jar,commons-util-.jar,commons-text-.jar,forceloader-core-*.jar,tools.jar, -Dsun.io.unicode.encoding=UnicodeLittle, -Dsun.nio.cs.map=Windows-31J/Shift_JIS, -Doracle.jdbc.maxCachedBufferSize=17, -XX:CompileCommand=exclude,com/caucho/vfs/JniFilePathImpl.nativeCanRead, -XX:CompileCommand=exclude,com/caucho/vfs/JniStream.readNative, -XX:CompileCommand=exclude,org/eclipse/jetty/util/URIUtil.canonicalPath, -Dcom.sun.management.jmxremote, -Dcom.sun.management.jmxremote.rmi.port=6113, -Dcom.sun.management.jmxremote.port=6113, -Dcom.sun.management.jmxremote.password.file=/home/user/shelt/app/220/patch/core/phillips/conf/jmxremote.pwd, -Dcom.sun.management.jmxremote.access.file=/home/user/shelt/app/220/patch/core/phillips/conf/jmxremote.access, -Dcom.sun.management.jmxremote.ssl=false, -Dklein.configdir=/home/user/shelt/app/220/patch/core/phillips/conf/Jetty948, -DdevMode=true, -Dosgi.bundlefile.limit=0, -Dorg.apache.jasper.compiler.disablejsr199=true, -XX:-OmitStackTraceInFastThrow, -Xrunjdwp:transport=dt_socket,server=y,suspend=n,address=6103, -Xdebug, -Xnoagent, -DtestMode=true, -Dssl.protocols=TLSv1.1,TLSv1.2, -DFTestConfig=/home/user/shelt/app/220/patch/core/phillips-test/func/config, -Dwarden.agent.rate=30, -Dstartup.notification.type=DEFAULT, -Djvmm.histogram.export.period.seconds=60, -Djava.beans.introspector.skip.customizer.lookup=true, -Dsystem.pre.shutdown.group.timeout.seconds=10, -Dmemcached.dir=/home/user/shelt/tools/Linux/memcached/1.4.24.2/x86_64, -Dhttps.protocols=TLSv1.1,TLSv1.2, -Dturbo.spring.lazy.init=true, -Djvmm.tam.threshold.gc.bytes=50000000, -Dwebdriver.blackberry.tools=/home/user/shelt/tools/Linux/blackberryseleniumsdk/cordova-blackberry/bin/dependencies/bb-tools/bin, -Dtest.func.postscrutinyfilter=0, -Dlikwid_topology.binary.path=/home/user/shelt/tools/Linux/likwid-topology/3.0/likwid-topology, -Dsystem.jvm.shutdown.group.timeout.seconds=10, -Djetty.graceful_shutdown_stop_time_millis=0, -Djvmm.tam.enabled=false, -Ddeferred.work.manager.start.to.app.ready=true, -Djdk.tls.server.protocols=TLSv1.1,TLSv1.2, -Dtime.to.stabilize.enabled=true, -Dcorda.home=/home/user/shelt/app/220/patch/core/charts/config/corda, -Drequire.consistent.schema.version=false, -Dperfeng.runtime.preappend.classpath=/home/user/.m2/repository/xerces/xercesImpl/2.12.0/xercesImpl-2.12.0.jar , -Dversion=220, -Djava.net.preferIPv4Stack=true, -Dturbo.spring.bean.type.cache=true, -Dmonitoringlib.logging.jvmperfcounters.trackblock=false, -Dbuild.home=/home/user/shelt/app/220/patch/core/build, -Dsystem.shutdown.group.timeout.seconds=15, -Dmonitoringlib.logging.jvmperfcounters.trackcpu=true, -Djava.beans.introspector.skip.all.beaninfo.lookup=true, -Dtest.func.signup_threads_factor=0.5, -Dperflib.profiler.frame.cache.size=1000000, -Dlauncher.osgi.scanning.missing_resource.initialsize=200, -Dcentrifuge.enabled=true, -Dstartup.logPath=/home/user/shelt/app/220/patch/core/phillips/logs/phillips/startup.log, -Dlauncher.osgi.scanning.caching.threads=8, -Dtest.func.listeners=, -Dtest.func.num_threads=4, -Dphillips.override.response.buffer.size=524288, -Dturbo.spring.scalable.bean.factory.enabled=true, -Dcoverage.apex.list=/home/user/shelt/app/220/patch/core/build/apexclasses.lst, -Djvmm.mam.disabled=false, -Dturbo.spring.reflection.cache=true, -Dk4a.serviceDiscovery=true, -Dcom.company.customdomain.CustomDomainSslContextFactory.fips=false, -Dutil.pid.directory=/home/user/shelt/app/220/patch/core/phillips/logs, -Dperflib.profiler.stack.cache.size=250000, -Dcentrifuge.config=centrifuge/centrifuge-dev.conf, -Dwarden.agent.persister.frame.cache.size=100000, -Dlauncher.osgi.scanning.classpath_entries=5000, -Dlauncher.use.forceloader=false, -Dwarden.agent.enabled=false, -Dcom.company.secrets.bcfips.tlscallout=false, -Dk4a.keysMountPoint=/tmp/dktool_repo/user, -Dcontainer=Jetty948, -Dmonitoringlib.logging.jvmperfcounters.tracksafepoint=false, -Dtest.dev_team_info=DevTeamInfo.xml, -Dsayonara.enable=false, -Dwarden.agent.persister.stack.cache.size=200000, -Dstandard.hdr.histogram.mbean.sync.async.enabled=true, -Dsettings.path=dev.mydev.landmark.-.-, -Dperf.counter.snapshotter.enabled=true, -Dk4a.secretsFile=..

chatmachine commented 5 years ago

above log can be seen here. https://gist.github.com/chatmachine/9f413169db4e19e1bb2f02fd38ef6bdc just fyi ...I am not using jmx remote port in pinpoint config anywhere

Xylus commented 5 years ago

Thanks for the update. Hmm, how does your collector log look? Do you think you can post your collector log?

chatmachine commented 5 years ago

The pinpoint UI doesn't show the application in drop down.Looks like it has not identified though agent was connected successfully

chatmachine commented 5 years ago

ServerDistribution 1)hbase running on separate machine in local mode. 2)App (with Agent connected) and pinpoint-collector-1.8.3.war and ROOT.war are running on other server 3)Hbase has all the tables and is succesfully running.I see pinpoint related studd in logs but no entry in table /10.9.163.10:48824 2019-05-06 14:33:48,801 INFO [ProcessThread(sid:0 cport:-1):] server.PrepRequestProcessor: Got user-level KeeperException when processing sessionid:0x16a8ed2c5800007 type:create cxid:0x25 zxid:0x46e2 txntype:-1 reqpath:n/a Error Path:/pinpoint-cluster/collector/47630@Error:KeeperErrorCode = NodeExists for /pinpoint-cluster/collector/47630@ tomcat host is where collector and ROOT.war are deployed and app is running with agent attached

Xylus commented 5 years ago

1) That's fine. 2) By ROOT.war, do you mean pinpoint-web? Also, they're not all running in the same Tomcat instance (single java process), right? If so, try running them separately. 3) From your logs, it seems like the issue lies between your agent and the collector. How does your collector log look? Is your collector properly receiving data from your agent?

chatmachine commented 5 years ago

Thanks Xylus !yes ,ROOT.war is pinpoint-web .Also ,yes ,pinpoint-collector and pinpoint-web were running same JVM .Should i deploy both to separate containers?Thanks gain

Xylus commented 5 years ago

That would help in figuring out the issue, yes. Also, please check the collector log afterwards as mentioned above.

chatmachine commented 5 years ago

Cool thanks.I will share the details. Question, if pinpoint-web, pinpoint-collector (both on same jvm) and agent are on same machine and hbase on the separate machine, though i am using hbase zookeeper address (in configs), can we also use separate zookeeper on first machine(with collector ,agent and web)?

chatmachine commented 5 years ago

If I click on pinpoint-collector.war on tomcat ,what should be response?I get resource not available

Xylus commented 5 years ago

can we also use separate zookeeper on first machine(with collector ,agent and web)?

Hbase uses zookeeper internally to manage it's master/region servers so you'll have to configure your ZK according to their specification. Pinpoint simply connects to this ZK for hbase client calls. (We also use ZK for realtime agent data, which by default uses the ZK provided by hbase)

If I click on pinpoint-collector.war on tomcat ,what should be response?I get resource not available

Pinpoint collector does not have an http endpoint, and is not meant to be called from a browser.

chatmachine commented 5 years ago

Thanks Xylus.Looks like .collector Agent communication issue is resolved.However,I saw something which I was unaware of as a dependency to make the End to End flow work "2019-05-08 14:37:08 INFO Handle lifecycle event - pinpointServer:DefaultPinpointServer@274567e8(remote:/10.9.163.10:48265, state:RUN_DUPLEX, healthCheckState:RECEIVED), state:Running 2019-05-08 14:40:54 ERROR can't select user org.springframework.transaction.CannotCreateTransactionException: Could not open JDBC Connection for transaction; nested exception is java.sql.SQLException: Cannot create PoolableConnectionFactory (Communications link failure" https://gist.github.com/chatmachine/9609f5b05cb6230cd6f018266a19cb6f

More details in gist below.Also .question,till I add MySQL DB component in the set up whether I wont be able to populate Application name in web ui(as i dont see anything now)?If there is more detail regarding this ,please point me to it.Thanks

chatmachine commented 5 years ago

Is there a way to bypass web and just check basic functionality (which is having data written to hbase)?

chatmachine commented 5 years ago

How to populate application name in web ui?

chatmachine commented 5 years ago

Is SPRING_BOOT right choice for application server? wondering because this is latest I see in tomcat longs after restarting tomcat (after increasing heap).Our app server is custom or hybrid based on jetty and has spring features...Please find the gist below:

https://gist.github.com/chatmachine/c1ab08d7cf22b84ac2ed69f93d002c81

And application runs out of heapspace after that.I increated heap to 16G and probably can do more

chatmachine commented 5 years ago

Appserver log is more encouraging showing pinpoint client related activity on port 9994 2019-05-08 23:50:26 WARN reconnectClientHandler:DefaultPinpointClientHandler@680cbecc{channel=[id: 0xe54e58ad, /:10409 => /:9994]state=SocketState(NONE->BEING_CONNECT)}

Xylus commented 5 years ago

More details in gist below.Also .question,till I add MySQL DB component in the set up whether I wont be able to populate Application name in web ui(as i dont see anything now)?If there is more detail regarding this ,please point me to it.Thanks

You shouldn't need MySQL. That is for setting up alarm, which you can add later once you have the system up and running. Application names in the Web UI are read from hbase, not MySQL as well. (If you are getting the error above without having configured for alarm, you might be using an outdated master branch. Please use 1.8.3 release in this case, or update master)

Is there a way to bypass web and just check basic functionality (which is having data written to hbase)?

You can check your collector log for this.

How to populate application name in web ui?

This is done automatically. Once the agent starts, it sends data (including it's application name) to the collector. The collector then stores these into hbase. Web queries hbase and displays them in the UI.

Is SPRING_BOOT right choice for application server? wondering because this is latest I see in tomcat longs after restarting tomcat (after increasing heap).Our app server is custom or hybrid based on jetty and has spring features...Please find the gist below:

Your gist log (which I'm assuming is your application server's log) has pinpoint-web logs. Why is that?

I'm getting a feeling this is all getting a bit mixed up. Try to step back and try one thing at a time.

  1. Start hbase.
  2. Start collector (don't attach pinpoint agent). Check your collector log and see if it started up okay.
  3. Start your application server (attach pinpoint agent to this). Check your agent log to see if there's no error, and your collector log to see if it has received data from the agent.
  4. Start web (don't attach pinpoint agent). Check your web log for error.

Details to installation can be found here.

chatmachine commented 5 years ago

Thanks ,this is resolved.I can see the core app in web ui but still metrics I have to see

chatmachine commented 5 years ago

Is there a guide on setting up the profiler entry point?Just entering com.<>.* doesn't show code paths and transaction times.I was able to see heap and other resource usage .Thank you so much Xylus

Xylus commented 5 years ago

@chatmachine You have to enter the fully qualified class name and specify the method as well. For example, profiler.entrypoint=com.test.namespace.SomeController.methodFoo,com.test.namespace.SomeController.methodBar. Normally though you shouldn't have to do this unless you're trying to trace something custom, as the agent should start traces automatically by intercepting Tomcat/Jetty acceptors.

chatmachine commented 5 years ago

If its a custom jetty container ,do we we have to specify the custom container name(say, jetty1111, or something else is also needed?

chatmachine commented 5 years ago

We have Main class in starter package and I believe its jetty server embedded in springboot

chatmachine commented 5 years ago

I feel ,my issue is related to this based on exception i saw when i chose server type= jetty and let the system detect it from starter.Main.. Is there a resolution you can suggest.Also ,I see of plugins get loaded while the agent start (from logs).Is there a way to selectively load this plugins? https://github.com/naver/pinpoint/issues/1387 "Pinpoint inserts interceptors into target methods and those interceptors implement AroundInterceptor which is loaded by bootstrap classloader. If AroundInterceptor is not loaded by bootstrap classloader, you cannot trace classes loaded by the bootstrap classloader."

i can add my pinpoint config if you want

Xylus commented 5 years ago

If it's a jetty server embedded in spring boot, the agent should automatically detect your application as a spring boot app if launched via java -jar command. Either way, even if your application type isn't detected, or you've set it manually, jetty calls should be traced.

Do you think you can post your full agent DEBUG log (including the startup log, and logs printed after you make a few jetty calls)? You can also mail it to me if you'd like.

chatmachine commented 5 years ago

Should i enabled debug by changing any of these (like bytecode.dump.asm=true)?

My recent log snippets and pinpoint.config options of interest https://gist.github.com/chatmachine/5650c0161aa21a4d51b85f3acbb38fb7

# bytecode dump option # java bytecode debug option bytecode.dump.enable=false #bytecode.dump.classlist=com.naver.user.UserService,com.pinpoint.debug.TestClass bytecode.dump.classlist= bytecode.dump.bytecode=false bytecode.dump.verify=false bytecode.dump.asm=false

My recent log

Xylus commented 5 years ago

@chatmachine Oh no, I meant the agent's log4j log level. You can find the agent's log4j.xml in $PINPOINT_AGENT/lib directory.

chatmachine commented 5 years ago

This is what I see after enabling DEBUG 2019-05-16 00:28:22 DEBUG tryAfter() returns false: interceptorScopeTransaction: InterceptorScopeInvocation(ORACLE_SCOPE)[depth=1], executionPoint: BOUNDARY. Skip interceptor class com.navercorp.pinpoint.bootstrap.plugin.jdbc.interceptor.PreparedStatementCreateInterceptor 2019-05-16 00:28:22 DEBUG AFTER oracle.jdbc.driver.T4CConnection args:({?=call cContext.clearContext(?)}) result:OracleCallableStatementWrapper 2019-05-16 00:28:22 DEBUG BEFORE oracle.jdbc.driver.OracleCallableStatementWrapper args:(1, 3) 2019-05-16 00:28:22 DEBUG AFTER oracle.jdbc.driver.OracleCallableStatementWrapper args:(1, 3) result:null 2019-05-16 00:28:22 DEBUG AFTER oracle.jdbc.driver.OracleCallableStatementWrapper oracle.jdbc.driver.OraclePreparedStatementWrapper setString(ILjava/lang/String;)V args:(2, 1) result:null

2019-05-16 00:28:22 DEBUG BEFORE oracle.jdbc.driver.T4CConnection args:() 2019-05-16 00:28:22 DEBUG AFTER oracle.jdbc.driver.T4CConnection args:() result:null 2019-05-16 00:28:22 DEBUG BEFORE oracle.jdbc.driver.T4CConnection args:({?=call cPushNotification.get_max_scn_nc()}) 2019-05-16 00:28:22 DEBUG tryBefore() returns false: interceptorScopeTransaction: InterceptorScopeInvocation(ORACLE_SCOPE)[depth=1], executionPoint: BOUNDARY. Skip interceptor class com.navercorp.pinpoint.bootstrap.plugin.jdbc.interceptor.PreparedStatementCreateInterceptor 2019-05-16 00:28:22 DEBUG tryAfter() returns false: interceptorScopeTransaction: InterceptorScopeInvocation(ORACLE_SCOPE)[depth=1], executionPoint: BOUNDARY. Skip interceptor class com.navercorp.pinpoint.bootstrap.plugin.jdbc.interceptor.PreparedStatementCreateInterceptor 2019-05-16 00:28:22 DEBUG AFTER oracle.jdbc.driver.T4CConnection args:({?=call cPushNotification.get_max_scn_nc()}) result:OracleCallableStatementWrapper 2019-05-16 00:28:22 DEBUG BEFORE oracle.jdbc.driver.OracleCallableStatementWrapper args:(1, 3) 2019-05-16 00:28:22 DEBUG AFTER oracle.jdbc.driver.OracleCallableStatementWrapper args:(1, 3) result:null 2019-05-16 00:28:22 DEBUG BEFORE oracle.jdbc.driver.OracleCallableStatementWrapper args:() 2019-05-16 00:28:22 DEBUG AFTER oracle.jdbc.driver.OracleCallableStatementWrapper args:() result:false 2019-05-16 00:28:22 DEBUG BEFORE oracle.jdbc.driver.T4CConnection args:(SELECT / SessionMemoryUsage / value FROM v$mystat WHERE "STATISTIC#" = ?) 2019-05-16 00:28:22 DEBUG tryBefore() returns false: interceptorScopeTransaction: InterceptorScopeInvocation(ORACLE_SCOPE)[depth=1], executionPoint: BOUNDARY. Skip interceptor class com.navercorp.pinpoint.bootstrap.plugin.jdbc.interceptor.PreparedStatementCreateInterceptor 2019-05-16 00:28:22 DEBUG tryAfter() returns false: interceptorScopeTransaction: InterceptorScopeInvocation(ORACLE_SCOPE)[depth=1], executionPoint: BOUNDARY. Skip interceptor class com.navercorp.pinpoint.bootstrap.plugin.jdbc.interceptor.PreparedStatementCreateInterceptor 2019-05-16 00:28:22 DEBUG AFTER oracle.jdbc.driver.T4CConnection args:(SELECT / SessionMemoryUsage / value FROM v$mystat WHERE "STATISTIC#" = ?) result:OraclePreparedStatementWrapper 2019-05-16 00:28:22 DEBUG AFTER oracle.jdbc.driver.OraclePreparedStatementWrapper oracle.jdbc.driver.OraclePreparedStatementWrapper setInt(II)V args:(1, 37) result:null 2019-05-16 00:28:22 DEBUG BEFORE oracle.jdbc.driver.OraclePreparedStatementWrapper args:() 2019-05-16 00:28:22 DEBUG AFTER oracle.jdbc.driver.OraclePreparedStatementWrapper args:() result:OracleResultSetImpl 2019-05-16 00:28:22 DEBUG BEFORE oracle.jdbc.driver.T4CConnection args:({?=call cContext.clearContext(?)}) 2019-05-16 00:28:22 DEBUG tryBefore() returns false: interceptorScopeTransaction: InterceptorScopeInvocation(ORACLE_SCOPE)[depth=1], executionPoint: BOUNDARY. Skip interceptor class com.navercorp.pinpoint.bootstrap.plugin.jdbc.interceptor.PreparedStatementCreateInterceptor 2019-05-16 00:28:22 DEBUG tryAfter() returns false: interceptorScopeTransaction: InterceptorScopeInvocation(ORACLE_SCOPE)[depth=1], executionPoint: BOUNDARY. Skip interceptor class com.navercorp.pinpoint.bootstrap.plugin.jdbc.interceptor.PreparedStatementCreateInterceptor 2019-05-16 00:28:22 DEBUG AFTER oracle.jdbc.driver.T4CConnection args:({?=call cContext.clearContext(?)}) result:OracleCallableStatementWrapper 2019-05-16 00:28:22 DEBUG BEFORE oracle.jdbc.driver.OracleCallableStatementWrapper args:(1, 3) 2019-05-16 00:28:22 DEBUG AFTER oracle.jdbc.driver.OracleCallableStatementWrapper args:(1, 3) result:null 2019-05-16 00:28:22 DEBUG AFTER oracle.jdbc.driver.OracleCallableStatementWrapper oracle.jdbc.driver.OraclePreparedStatementWrapper setString(ILjava/lang/String;)V args:(2, 1) result:null

2019-05-16 00:28:22 DEBUG BEFORE oracle.jdbc.driver.T4CConnection args:() 2019-05-16 00:28:22 DEBUG AFTER oracle.jdbc.driver.T4CConnection args:() result:null 2019-05-16 00:28:22 DEBUG BEFORE oracle.jdbc.driver.T4CConnection args:({call cConduitSqlBroker.poll_events_for_cache_desc(?,?,?)}) 2019-05-16 00:28:22 DEBUG tryBefore() returns false: interceptorScopeTransaction: InterceptorScopeInvocation(ORACLE_SCOPE)[depth=1], executionPoint: BOUNDARY. Skip interceptor class com.navercorp.pinpoint.bootstrap.plugin.jdbc.interceptor.PreparedStatementCreateInterceptor 2019-05-16 00:28:22 DEBUG tryAfter() returns false: interceptorScopeTransaction: InterceptorScopeInvocation(ORACLE_SCOPE)[depth=1], executionPoint: BOUNDARY. Skip interceptor class com.navercorp.pinpoint.bootstrap.plugin.jdbc.interceptor.PreparedStatementCreateInterceptor 2019-05-16 00:28:22 DEBUG AFTER oracle.jdbc.driver.T4CConnection args:({call cConduitSqlBroker.poll_events_for_cache_desc(?,?,?)}) result:OracleCallableStatementWrapper 2019-05-16 00:28:22 DEBUG AFTER oracle.jdbc.driver.OracleCallableStatementWrapper oracle.jdbc.driver.OraclePreparedStatementWrapper setArray(ILjava/sql/Array;)V args:(1, ARRAY) result:null 2019-05-16 00:28:22 DEBUG AFTER oracle.jdbc.driver.OracleCallableStatementWrapper oracle.jdbc.driver.OraclePreparedStatementWrapper setInt(II)V args:(2, 8001) result:null 2019-05-16 00:28:22 DEBUG BEFORE oracle.jdbc.driver.OracleCallableStatementWrapper args:(3, -10)

2019-05-16 00:28:22 DEBUG BEFORE oracle.jdbc.driver.OracleCallableStatementWrapper args:() 2019-05-16 00:28:22 DEBUG AFTER oracle.jdbc.driver.OracleCallableStatementWrapper args:() result:false 2019-05-16 00:28:22 DEBUG BEFORE oracle.jdbc.driver.T4CConnection args:(SELECT / SessionMemoryUsage / value FROM v$mystat WHERE "STATISTIC#" = ?) 2019-05-16 00:28:22 DEBUG tryBefore() returns false: interceptorScopeTransaction: InterceptorScopeInvocation(ORACLE_SCOPE)[depth=1], executionPoint: BOUNDARY. Skip interceptor class com.navercorp.pinpoint.bootstrap.plugin.jdbc.interceptor.PreparedStatementCreateInterceptor 2019-05-16 00:28:22 DEBUG tryAfter() returns false: interceptorScopeTransaction: InterceptorScopeInvocation(ORACLE_SCOPE)[depth=1], executionPoint: BOUNDARY. Skip interceptor class com.navercorp.pinpoint.bootstrap.plugin.jdbc.interceptor.PreparedStatementCreateInterceptor 2019-05-16 00:28:22 DEBUG AFTER oracle.jdbc.driver.T4CConnection args:(SELECT / SessionMemoryUsage / value FROM v$mystat WHERE "STATISTIC#" = ?) result:OraclePreparedStatementWrapper 2019-05-16 00:28:22 DEBUG AFTER oracle.jdbc.driver.OraclePreparedStatementWrapper oracle.jdbc.driver.OraclePreparedStatementWrapper setInt(II)V args:(1, 37) result:null 2019-05-16 00:28:22 DEBUG BEFORE oracle.jdbc.driver.OraclePreparedStatementWrapper args:() 2019-05-16 00:28:22 DEBUG AFTER oracle.jdbc.driver.OraclePreparedStatementWrapper args:() result:OracleResultSetImpl 2019-05-16 00:28:22 DEBUG BEFORE oracle.jdbc.driver.T4CConnection args:({?=call cContext.clearContext(?)}) 2019-05-16 00:28:22 DEBUG tryBefore() returns false: interceptorScopeTransaction: InterceptorScopeInvocation(ORACLE_SCOPE)[depth=1], executionPoint: BOUNDARY. Skip interceptor class com.navercorp.pinpoint.bootstrap.plugin.jdbc.interceptor.PreparedStatementCreateInterceptor 2019-05-16 00:28:22 DEBUG tryAfter() returns false: interceptorScopeTransaction: InterceptorScopeInvocation(ORACLE_SCOPE)[depth=1], executionPoint: BOUNDARY. Skip interceptor class com.navercorp.pinpoint.bootstrap.plugin.jdbc.interceptor.PreparedStatementCreateInterceptor 2019-05-16 00:28:22 DEBUG AFTER oracle.jdbc.driver.T4CConnection args:({?=call cContext.clearContext(?)}) result:OracleCallableStatementWrapper 2019-05-16 00:28:22 DEBUG BEFORE oracle.jdbc.driver.OracleCallableStatementWrapper args:(1, 3) 2019-05-16 00:28:22 DEBUG AFTER oracle.jdbc.driver.OracleCallableStatementWrapper args:(1, 3) result:null 2019-05-16 00:28:22 DEBUG AFTER oracle.jdbc.driver.OracleCallableStatementWrapper oracle.jdbc.driver.OraclePreparedStatementWrapper setString(ILjava/lang/String;)V args:(2, 1) result:null

I can mail the full log

stale[bot] commented 5 years ago

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.