LinShunKang / MyPerf4J

High performance Java APM. Powered by ASM. Try it. Test it. If you feel its better, use it.
BSD 3-Clause "New" or "Revised" License
3.41k stars 540 forks source link

[MyPerf4J] WARN [pool-860-thread-4] ProfilingAspect.profiling(): methodTagId=668, methodTag=null, startNanos: 16906482417446846, IGNORED!!! #61

Closed just2d closed 4 years ago

just2d commented 4 years ago

问题描述 加载模块正常,但是所有的方法都无法记录,并且在日志中报错:

[MyPerf4J] WARN [pool-860-thread-4] ProfilingAspect.profiling(): methodTagId=668, methodTag=null, startNanos: 16906482417446846, IGNORED!!!

如下代码是已经被执行了 image

但是在执行这个的时候 ,就还是会是false,所以return image

运行环境

JVM启动参数 /usr/java/bin/java -Djava.util.logging.config.file=/home/me/app/.default/conf/logging.properties -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager -Djava.security.egd=file:/dev/./urandom -Dlog4j.defaultInitOverride=true -Dorg.apache.tomcat.util.http.ServerCookie.ALLOW_EQUALS_IN_VALUE=true -Dorg.apache.tomcat.util.http.ServerCookie.ALLOW_HTTP_SEPARATORS_IN_V0=true -server -Xms4g -Xmx4g -XX:PermSize=96m -XX:MaxPermSize=384m -Xmn2g -XX:+UseConcMarkSweepGC -XX:+UseCMSCompactAtFullCollection -XX:CMSMaxAbortablePrecleanTime=5000 -XX:+CMSClassUnloadingEnabled -XX:+UseCMSInitiatingOccupancyOnly -XX:CMSInitiatingOccupancyFraction=80 -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=/home/me/logs/java.hprof -Xloggc:/home/me/logs/gc.log -XX:+PrintGCDetails -XX:+PrintGCDateStamps -Djava.awt.headless=true -Dsun.net.client.defaultConnectTimeout=10000 -Dsun.net.client.defaultReadTimeout=30000 -XX:MaxDirectMemorySize=1g -XX:SurvivorRatio=10 -XX:+ExplicitGCInvokesConcurrent -Dsun.rmi.dgc.server.gcInterval=2592000000 -Dsun.rmi.dgc.client.gcInterval=2592000000 -XX:ParallelGCThreads=4 -DJM.LOG.PATH=/home/me/logs -Dfile.encoding=UTF-8 -Dhsf.publish.delayed=true -javaagent:/home/me/app/target/myApp.war/WEB-INF/lib/MyPerf4J-ASM-3.0.0.jar -DMyPerf4JPropFile=/tmp/MyPerf4J.properties -Dproject.name=myApp -Djava.endorsed.dirs=/usr/tomcat/endorsed -classpath /usr/tomcat/bin/bootstrap.jar:/usr/tomcat/bin/tomcat-juli.jar -Dcatalina.logs=/home/me/app/logs/catalina -Dcatalina.base=/home/me/app/.default -Dcatalina.home=/usr/tomcat -Djava.io.tmpdir=/home/me/app/.default/temp org.apache.catalina.startup.Bootstrap start

配置文件

app_name = myApp

metrics.exporter = log.standard metrics.log.method = /tmp/logs/MyPerf4J/metrics.log filter.packages.include = com.me;

filter.packages.exclude = cn.perf4j.demo.dao.DemoDAOImpl

recorder.mode = accurate recorder.size.timing_arr = 100

filter.methods.exclude_private=false

recorder.size.timing_map = 2 metrics.time_slice.method = 2000 recorders.backup_count = 1

异常堆栈 无异常打印,如下是组件正常加载的日志

2020-09-15 15:31:49.875 [MyPerf4J] INFO [main] Thanks sincerely for using MyPerf4J. 2020-09-15 15:31:50.008 [MyPerf4J] INFO [main] influxdb.host is not configured, so use '127.0.0.1' as default host. 2020-09-15 15:31:50.008 [MyPerf4J] INFO [main] influxdb.port is not configured, so use '8086' as default port. 2020-09-15 15:31:50.013 [MyPerf4J] INFO [main] ClassLevelMapping is blank, so use default mappings. 2020-09-15 15:31:50.032 [MyPerf4J] INFO [main] Loading .cheetah_SysGenProfilingFile to init profiling params.

2020-09-15 15:32:09.129 [MyPerf4J] INFO [localhost-startStop-1] ProfilingTransformer.transform(org.apache.catalina.loader.WebappClassLoader, com/me/myApp/init/SystemInitListener, classBeingRedefined, protectionDomain, 2080)... 2020-09-15 15:32:09.177 [MyPerf4J] INFO [localhost-startStop-1] ProfilingTransformer.transform(org.apache.catalina.loader.WebappClassLoader, com/me/myApp/web/filter/DecryptRequestFilter, classBeingRedefined, protectionDomain, 1759)... 2020-09-15 15:32:09.183 [MyPerf4J] INFO [localhost-startStop-1] ProfilingTransformer.transform(org.apache.catalina.loader.WebappClassLoader, com/me/myApp/exception/ParamException, classBeingRedefined, protectionDomain, 931)... 2020-09-15 15:32:09.185 [MyPerf4J] INFO [localhost-startStop-1] ProfilingTransformer.transform(org.apache.catalina.loader.WebappClassLoader, com/me/myApp/exception/BaseException, classBeingRedefined, protectionDomain, 843)... 2020-09-15 15:32:09.186 [MyPerf4J] INFO [localhost-startStop-1] ProfilingTransformer.transform(org.apache.catalina.loader.WebappClassLoader, com/me/myApp/web/filter/EncryptResponseFilter, classBeingRedefined, protectionDomain, 1630)... 2020-09-15 15:32:09.188 [MyPerf4J] INFO [localhost-startStop-1] ProfilingTransformer.transform(org.apache.catalina.loader.WebappClassLoader, com/me/myApp/web/filter/ParameterChangeRequestFilter, classBeingRedefined, protectionDomain, 1738)... 2020-09-15 15:32:09.189 [MyPerf4J] INFO [localhost-startStop-1] ProfilingTransformer.transform(org.apache.catalina.loader.WebappClassLoader, com/me/myApp/web/filter/LogFilter, classBeingRedefined, protectionDomain, 2801)...

LinShunKang commented 4 years ago

你好,根据你给的 JVM 启动参数,你应该是把 MyPerf4J-ASM.jar 打到 tomcat 的 war 包里了,这样可能会存在同一个类被不同的 ClassLoader 多次加载的问题,你不要把 MyPerf4J-ASM.jar 打到 tomcat 的 war 包里,然后再次启动应该就好了。