java - 为什么 java newInstance 卡在 getDeclaredConstructors0 处？

Question

我们使用mozlia rhino生成动态类，然后通过自定义类加载器加载JsClass，如下所示

DynamicClassLoader loader = new DynamicClassLoader(JavaScriptFactory.class.getClassLoader());
Class<?> jsClass = loader.loadClass("D://","com.huawei.xxx");
jsClass.newInstance();

如你所见，每个JsClass都有一个单独的类加载器，当用户修改js时，我们也会通过这段代码重新加载JsClass，

现在，我们面临一个问题，当调用 jsClass.newInstance() 时，某些线程在 getDeclaredConstructors0 处挂起很长一段时间(3s-1000s)，通常应该小于 10ms。有人可以告诉我可能的原因吗？非常感谢!

JDK: 1.8.0.60

Tomcat : 7.0.59

JvmArgs:

-Dnop -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager -DDN=mateinfo_app -server -Duser.timezone=GMT -Dsun.rmi.dgc.client.gcInterval=3600000 -Dsun.rmi.dgc.server.gcInterval=3600000 -XX:+UseParNewGC -XX:+UseConcMarkSweepGC -XX:CMSInitiatingOccupancyFraction=80 -XX:+DisableExplicitGC -XX:+PrintGC -XX:+PrintGCDateStamps -XX:+PrintHeapAtGC -XX:+PrintGCDetails -Xloggc:/opt/mateinfo/logs/app/tomcat-gc-20160601-233343.log -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=/opt/mateinfo/logs/app/oom-20160601-233343.bin -XX:OnOutOfMemoryError=./deal-oom.sh -Xms3260m -Xmx3260m -Xmn800m -XX:MetaspaceSize=800m -XX:MaxMetaspaceSize=800m -XX:SurvivorRatio=16 -XX:+OptimizeStringConcat -Xverify:all -Dsoapui.log4j.config=/opt/mateinfo/app/lib/log4j.properties -Dlog4j.ignoreTCL=true -XX:-OmitStackTraceInFastThrow -Xrunjdwp:transport=dt_socket,address=8000,server=y,suspend=n -Dcom.sun.management.jmxremote -Dcom.sun.management.jmxremote.port=8050 -Dcom.sun.management.jmxremote.ssl=false -Dcom.sun.management.jmxremote.authenticate=false -Djava.net.preferIPv4Stack=true -Djava.endorsed.dirs=/opt/mateinfo/app/endorsed -classpath /opt/mateinfo/app/bin/bootstrap.jar:/opt/mateinfo/app/bin/tomcat-juli.jar -Dcatalina.base=/opt/mateinfo/app -Dcatalina.home=/opt/mateinfo/app -Djava.io.tmpdir=/opt/mateinfo/app/temp org.apache.catalina.startup.Bootstrap start

线程转储:

----------------- 7123 -----------------
0x00007f9d44cdc6d5       __pthread_cond_wait + 0xc5
0x00007f9d43cc157c       _ZN15JvmtiRawMonitor11SimpleEnterEP6Thread + 0xdc
0x00007f9d43cc1c07       _ZN15JvmtiRawMonitor9raw_enterEP6Thread + 0xd7
0x00007f9d43c9a2ed      _ZN8JvmtiEnv15RawMonitorEnterEP15JvmtiRawMonitor + 0xad
0x00007f9d429c4df8       debugMonitorEnter + 0x38
0x00007f9d429b1451      event_callback + 0x2e1
0x00007f9d429b1e8e      cbClassPrepare + 0x8e
0x00007f9d43cb0beb      _ZN11JvmtiExport18post_class_prepareEP10JavaThreadP5Klass + 0x15b
0x00007f9d43b59f31       _ZN13InstanceKlass15link_class_implE19instanceKlassHandlebP6Thread + 0x3f1
0x00007f9d43b5a0d4      _ZN13InstanceKlass10link_classEP6Thread + 0x54
0x00007f9d43c3ec49       _ZL33get_class_declared_methods_helperP7JNIEnv_P7_jclasshbP5KlassP6Thread + 0xc9
0x00007f9d43c3f28e       JVM_GetClassDeclaredConstructors + 0xce

"app-JavaScriptFactory-7-thread-1" #41621 prio=5 os_prio=0 tid=0x00007f9d1d7f9800 nid=0x1bd3 runnable [0x00007f9c8040e000]
   java.lang.Thread.State: RUNNABLE
         at java.lang.Class.getDeclaredConstructors0(Native Method)
         at java.lang.Class.privateGetDeclaredConstructors(Class.java:2671)
         at java.lang.Class.getConstructor0(Class.java:3075)
         at java.lang.Class.newInstance(Class.java:412)
         at com.huawei.sdm.integration.message.runtime.handler.script.JsBeanGenerateRunner.excute(JsBeanGenerateRunner.java:82)
         at com.huawei.mateinfo.context.support.CommonCallable.call(CommonCallable.java:31)
         at java.util.concurrent.FutureTask.run(FutureTask.java:266)
         at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
         at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
         at java.lang.Thread.run(Thread.java:745)

GC日志:

{Heap before GC invocations=331320 (full 1587):
par new generation   total 773696K, used 732120K [0x00000006f4400000, 0x0000000726400000, 0x0000000726400000)
  eden space 728192K, 100% used [0x00000006f4400000, 0x0000000720b20000, 0x0000000720b20000)
  from space 45504K,   8% used [0x0000000723790000, 0x0000000723b66170, 0x0000000726400000)
  to   space 45504K,   0% used [0x0000000720b20000, 0x0000000720b20000, 0x0000000723790000)
concurrent mark-sweep generation total 2519040K, used 2123204K [0x0000000726400000, 0x00000007c0000000, 0x00000007c0000000)
Metaspace       used 341907K, capacity 402760K, committed 687488K, reserved 1640448K
  class space    used 38870K, capacity 47018K, committed 95616K, reserved 1048576K
2016-05-31T12:47:08.303+0000: 550384.634: [GC (GCLocker Initiated GC) 2016-05-31T12:47:08.303+0000: 550384.634: [ParNew: 732120K->2438K(773696K), 0.0228934 secs] 2855324K->2125771K(3292736K), 0.0231999 secs] [Times: user=0.07 sys=0.00, real=0.03 secs]
Heap after GC invocations=331321 (full 1587):
par new generation   total 773696K, used 2438K [0x00000006f4400000, 0x0000000726400000, 0x0000000726400000)
  eden space 728192K,   0% used [0x00000006f4400000, 0x00000006f4400000, 0x0000000720b20000)
  from space 45504K,   5% used [0x0000000720b20000, 0x0000000720d81bc8, 0x0000000723790000)
  to   space 45504K,   0% used [0x0000000723790000, 0x0000000723790000, 0x0000000726400000)
concurrent mark-sweep generation total 2519040K, used 2123332K [0x0000000726400000, 0x00000007c0000000, 0x00000007c0000000)
Metaspace       used 341907K, capacity 402760K, committed 687488K, reserved 1640448K
  class space    used 38870K, capacity 47018K, committed 95616K, reserved 1048576K
}
2016-05-31T12:47:08.334+0000: 550384.665: [GC (CMS Initial Mark) [1 CMS-initial-mark: 2123332K(2519040K)] 2135637K(3292736K), 0.0151574 secs] [Times: user=0.03 sys=0.00, real=0.01 secs]
2016-05-31T12:47:08.349+0000: 550384.681: [CMS-concurrent-mark-start]
{Heap before GC invocations=331321 (full 1588):
par new generation   total 773696K, used 730630K [0x00000006f4400000, 0x0000000726400000, 0x0000000726400000)
  eden space 728192K, 100% used [0x00000006f4400000, 0x0000000720b20000, 0x0000000720b20000)
  from space 45504K,   5% used [0x0000000720b20000, 0x0000000720d81bc8, 0x0000000723790000)
  to   space 45504K,   0% used [0x0000000723790000, 0x0000000723790000, 0x0000000726400000)
concurrent mark-sweep generation total 2519040K, used 2123332K [0x0000000726400000, 0x00000007c0000000, 0x00000007c0000000)
Metaspace       used 341907K, capacity 402760K, committed 687488K, reserved 1640448K
  class space    used 38870K, capacity 47018K, committed 95616K, reserved 1048576K
2016-05-31T12:47:09.419+0000: 550385.751: [GC (Allocation Failure) 2016-05-31T12:47:09.419+0000: 550385.751: [ParNew: 730630K->11995K(773696K), 0.0311341 secs] 2853963K->2135459K(3292736K), 0.0314510 secs] [Times: user=0.10 sys=0.00, real=0.03 secs]
Heap after GC invocations=331322 (full 1588):
par new generation   total 773696K, used 11995K [0x00000006f4400000, 0x0000000726400000, 0x0000000726400000)
  eden space 728192K,   0% used [0x00000006f4400000, 0x00000006f4400000, 0x0000000720b20000)
  from space 45504K,  26% used [0x0000000723790000, 0x0000000724346f10, 0x0000000726400000)
  to   space 45504K,   0% used [0x0000000720b20000, 0x0000000720b20000, 0x0000000723790000)
concurrent mark-sweep generation total 2519040K, used 2123463K [0x0000000726400000, 0x00000007c0000000, 0x00000007c0000000)
Metaspace       used 341907K, capacity 402760K, committed 687488K, reserved 1640448K
  class space    used 38870K, capacity 47018K, committed 95616K, reserved 1048576K
}

Answer 1

看起来应用程序正在调试器下运行。 Thread Dump 表明线程卡在 JDWP 代理内部。

尝试禁用调试器。或者，您可以通过添加以下代理选项来打开 JDWP 日志记录:

logfile=/path/to/jdwp.log,logflags=255