服务启动时突然停住，疑似死锁，如何使用jstack或者VisualVm定位？

Question

问题描述

在Mac上每次启动服务，启动过程中就停止了（正常的情况下会继续启动其他的服务和更多的守护线程），但是进程没挂，还在运行。Windows系统上启动是正常的。

问题出现的环境背景及自己尝试过哪些方法

初步怀疑是线程死锁造成的，尝试使用jstack查看是否死锁，如下。
localhost:~ Charles$ jstack 3579
2018-08-19 12:34:21
Full thread dump Java HotSpot(TM) 64-Bit Server VM (25.151-b12 mixed mode):

"dna-3" #27 daemon prio=5 os_prio=31 tid=0x00007fad6e47a800 nid=0xd07 in Object.wait() [0x0000700007913000]
java.lang.Thread.State: TIMED_WAITING (on object monitor)

at java.lang.Object.wait(Native Method)
at com.jiuqi.dna.core.spi.work.WorkingManager.getWorkToDo(WorkingManager.java:412)
- locked <0x00000007a4f389b0> (a com.jiuqi.dna.core.spi.work.WorkingThread)
at com.jiuqi.dna.core.spi.work.WorkingThread.run(WorkingThread.java:42)

"HashSessionScavenger-0" #26 daemon prio=5 os_prio=31 tid=0x00007fad6f0ab000 nid=0xc07 in Object.wait() [0x000070000582d000]
java.lang.Thread.State: TIMED_WAITING (on object monitor)

at java.lang.Object.wait(Native Method)
at java.util.TimerThread.mainLoop(Timer.java:552)
- locked <0x00000007a2c2ae20> (a java.util.TaskQueue)
at java.util.TimerThread.run(Timer.java:505)

"MySQL Statement Cancellation Timer" #24 daemon prio=5 os_prio=31 tid=0x00007fad6d18e000 nid=0x5d03 in Object.wait() [0x0000700007810000]
java.lang.Thread.State: WAITING (on object monitor)

at java.lang.Object.wait(Native Method)
at java.lang.Object.wait(Object.java:502)
at java.util.TimerThread.mainLoop(Timer.java:526)
- locked <0x00000007a264c358> (a java.util.TaskQueue)
at java.util.TimerThread.run(Timer.java:505)

"dna-2" #23 daemon prio=5 os_prio=31 tid=0x00007fad6cc0f000 nid=0x9c03 in Object.wait() [0x000070000770d000]
java.lang.Thread.State: TIMED_WAITING (on object monitor)

at java.lang.Object.wait(Native Method)
at com.jiuqi.dna.core.spi.work.WorkingManager.getWorkToDo(WorkingManager.java:412)
- locked <0x00000007a2325ea0> (a com.jiuqi.dna.core.spi.work.WorkingThread)
at com.jiuqi.dna.core.spi.work.WorkingThread.run(WorkingThread.java:42)

"Attach Listener" #22 daemon prio=9 os_prio=31 tid=0x00007fad689a9000 nid=0x9e03 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE

"Worker-JM" #21 prio=5 os_prio=31 tid=0x00007fad6ba21800 nid=0x9f03 in Object.wait() [0x0000700007507000]
java.lang.Thread.State: WAITING (on object monitor)

at java.lang.Object.wait(Native Method)
at org.eclipse.core.internal.jobs.InternalWorker.run(InternalWorker.java:58)
- locked <0x00000006c00156e8> (a java.util.ArrayList)

"Bundle File Closer" #20 daemon prio=5 os_prio=31 tid=0x00007fad67db5000 nid=0xa103 in Object.wait() [0x0000700007404000]
java.lang.Thread.State: WAITING (on object monitor)

at java.lang.Object.wait(Native Method)
at java.lang.Object.wait(Object.java:502)
at org.eclipse.osgi.framework.eventmgr.EventManager$EventThread.getNextEvent(EventManager.java:400)
- locked <0x00000006c001d548> (a org.eclipse.osgi.framework.eventmgr.EventManager$EventThread)
at org.eclipse.osgi.framework.eventmgr.EventManager$EventThread.run(EventManager.java:336)

"dna-scheduler" #18 daemon prio=5 os_prio=31 tid=0x00007fad6815f800 nid=0xa203 in Object.wait() [0x0000700007301000]
java.lang.Thread.State: TIMED_WAITING (on object monitor)

at java.lang.Object.wait(Native Method)
at com.jiuqi.dna.core.spi.work.WorkingManager$Scheduler.doWork(WorkingManager.java:504)
- locked <0x00000006c0005ce8> (a com.jiuqi.dna.core.spi.work.WorkingManager$Scheduler)
at com.jiuqi.dna.core.spi.work.WorkingThread.run(WorkingThread.java:45)

"Framework Event Dispatcher" #17 daemon prio=5 os_prio=31 tid=0x00007fad67a43800 nid=0xa403 in Object.wait() [0x00007000071fe000]
java.lang.Thread.State: WAITING (on object monitor)

at java.lang.Object.wait(Native Method)
at java.lang.Object.wait(Object.java:502)
at org.eclipse.osgi.framework.eventmgr.EventManager$EventThread.getNextEvent(EventManager.java:400)
- locked <0x00000006c000e9e8> (a org.eclipse.osgi.framework.eventmgr.EventManager$EventThread)
at org.eclipse.osgi.framework.eventmgr.EventManager$EventThread.run(EventManager.java:336)

"Start Level Event Dispatcher" #16 daemon prio=5 os_prio=31 tid=0x00007fad68148800 nid=0xa603 runnable [0x00007000070f2000]
java.lang.Thread.State: RUNNABLE

at java.lang.ClassLoader$NativeLibrary.load(Native Method)
at java.lang.ClassLoader.loadLibrary0(ClassLoader.java:1941)
- locked <0x00000006c08a7350> (a java.util.Vector)
- locked <0x00000006c08a78b8> (a java.util.Vector)
at java.lang.ClassLoader.loadLibrary(ClassLoader.java:1824)
at java.lang.Runtime.load0(Runtime.java:809)
- locked <0x00000006c0333e98> (a java.lang.Runtime)
at java.lang.System.load(System.java:1086)
at java.lang.ClassLoader$NativeLibrary.load(Native Method)
at java.lang.ClassLoader.loadLibrary0(ClassLoader.java:1941)
- locked <0x00000006c08a7350> (a java.util.Vector)
- locked <0x00000006c08a78b8> (a java.util.Vector)
at java.lang.ClassLoader.loadLibrary(ClassLoader.java:1845)
at java.lang.Runtime.loadLibrary0(Runtime.java:870)
- locked <0x00000006c0333e98> (a java.lang.Runtime)
at java.lang.System.loadLibrary(System.java:1122)
at java.awt.Toolkit$3.run(Toolkit.java:1636)
at java.awt.Toolkit$3.run(Toolkit.java:1634)
at java.security.AccessController.doPrivileged(Native Method)
at java.awt.Toolkit.loadLibraries(Toolkit.java:1633)
at java.awt.Toolkit.<clinit>(Toolkit.java:1668)
at sun.awt.AppContext$2.run(AppContext.java:277)
at sun.awt.AppContext$2.run(AppContext.java:266)
at java.security.AccessController.doPrivileged(Native Method)
at sun.awt.AppContext.initMainAppContext(AppContext.java:266)
at sun.awt.AppContext.access$400(AppContext.java:135)
at sun.awt.AppContext$3.run(AppContext.java:321)
- locked <0x00000007a2cab5b8> (a sun.awt.AppContext$GetAppContextLock)
at sun.awt.AppContext$3.run(AppContext.java:304)
at java.security.AccessController.doPrivileged(Native Method)
at sun.awt.AppContext.getAppContext(AppContext.java:303)
at javax.imageio.spi.IIORegistry.getDefaultInstance(IIORegistry.java:154)
at javax.imageio.ImageIO.<clinit>(ImageIO.java:66)
at org.apache.cxf.common.logging.JDKBugHacks.doHacks(JDKBugHacks.java:59)
at org.apache.cxf.common.logging.Log4jLogger.<clinit>(Log4jLogger.java:55)
at java.lang.Class.forName0(Native Method)
at java.lang.Class.forName(Class.java:348)
at org.apache.cxf.common.logging.LogUtils.<clinit>(LogUtils.java:99)
at org.apache.cxf.transport.servlet.AbstractCXFServlet.getLogger(AbstractCXFServlet.java:52)
at org.apache.cxf.transport.servlet.AbstractCXFServlet.<clinit>(AbstractCXFServlet.java:43)
at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
at java.lang.Class.newInstance(Class.java:442)
at org.eclipse.jetty.servlet.ServletContextHandler$Context.createServlet(ServletContextHandler.java:1075)
at org.eclipse.jetty.servlet.ServletHolder.newInstance(ServletHolder.java:957)
at org.eclipse.jetty.servlet.ServletHolder.initServlet(ServletHolder.java:514)
at org.eclipse.jetty.servlet.ServletHolder.doStart(ServletHolder.java:344)
at org.eclipse.jetty.util.component.AbstractLifeCycle.start(AbstractLifeCycle.java:64)
- locked <0x00000007a2ac7228> (a java.lang.Object)
at org.eclipse.jetty.servlet.ServletHandler.initialize(ServletHandler.java:791)
at org.eclipse.jetty.servlet.ServletContextHandler.startContext(ServletContextHandler.java:265)
at org.eclipse.jetty.server.handler.ContextHandler.doStart(ContextHandler.java:717)
at org.eclipse.jetty.util.component.AbstractLifeCycle.start(AbstractLifeCycle.java:64)
- locked <0x00000007a2a2d120> (a java.lang.Object)
at org.eclipse.jetty.server.handler.HandlerWrapper.doStart(HandlerWrapper.java:95)
at org.eclipse.jetty.server.Server.doStart(Server.java:282)
at org.eclipse.jetty.util.component.AbstractLifeCycle.start(AbstractLifeCycle.java:64)
- locked <0x00000007a2a5d078> (a java.lang.Object)
at com.jiuqi.dna.core.jetty.JettyServer.tryStart(JettyServer.java:503)
- locked <0x00000006c0016eb8> (a com.jiuqi.dna.core.jetty.JettyServer)
at com.jiuqi.dna.core.impl.ApplicationImpl.tryStartServer(ApplicationImpl.java:1049)
at com.jiuqi.dna.core.impl.ApplicationImpl.<init>(ApplicationImpl.java:328)
at com.jiuqi.dna.core.impl.ApplicationImpl.startApp(ApplicationImpl.java:642)
at com.jiuqi.dna.core.impl.ApplicationLauncherImpl.launch(ApplicationLauncherImpl.java:28)
at com.jiuqi.dna.core.impl.ApplicationLauncherImpl.launch(ApplicationLauncherImpl.java:1)
at com.jiuqi.dna.core.jetty.AppLauncherTracker.addingService(AppLauncherTracker.java:29)
at com.jiuqi.dna.core.jetty.AppLauncherTracker.addingService(AppLauncherTracker.java:1)
at org.osgi.util.tracker.ServiceTracker$Tracked.customizerAdding(ServiceTracker.java:932)
at org.osgi.util.tracker.ServiceTracker$Tracked.customizerAdding(ServiceTracker.java:1)
at org.osgi.util.tracker.AbstractTracked.trackAdding(AbstractTracked.java:256)
at org.osgi.util.tracker.AbstractTracked.track(AbstractTracked.java:229)
at org.osgi.util.tracker.ServiceTracker$Tracked.serviceChanged(ServiceTracker.java:894)
at org.eclipse.osgi.internal.serviceregistry.FilteredServiceListener.serviceChanged(FilteredServiceListener.java:107)
at org.eclipse.osgi.framework.internal.core.BundleContextImpl.dispatchEvent(BundleContextImpl.java:861)
at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:230)
at org.eclipse.osgi.framework.eventmgr.ListenerQueue.dispatchEventSynchronous(ListenerQueue.java:148)
at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.publishServiceEventPrivileged(ServiceRegistry.java:819)
at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.publishServiceEvent(ServiceRegistry.java:771)
at org.eclipse.osgi.internal.serviceregistry.ServiceRegistrationImpl.register(ServiceRegistrationImpl.java:130)
at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.registerService(ServiceRegistry.java:214)
at org.eclipse.osgi.framework.internal.core.BundleContextImpl.registerService(BundleContextImpl.java:433)
at org.eclipse.osgi.framework.internal.core.BundleContextImpl.registerService(BundleContextImpl.java:451)
at org.eclipse.osgi.framework.internal.core.BundleContextImpl.registerService(BundleContextImpl.java:950)
at com.jiuqi.dna.core.impl.Activator.start(Activator.java:43)
at org.eclipse.osgi.framework.internal.core.BundleContextImpl$1.run(BundleContextImpl.java:711)
at java.security.AccessController.doPrivileged(Native Method)
at org.eclipse.osgi.framework.internal.core.BundleContextImpl.startActivator(BundleContextImpl.java:702)
at org.eclipse.osgi.framework.internal.core.BundleContextImpl.start(BundleContextImpl.java:683)
at org.eclipse.osgi.framework.internal.core.BundleHost.startWorker(BundleHost.java:381)
at org.eclipse.osgi.framework.internal.core.AbstractBundle.resume(AbstractBundle.java:390)
at org.eclipse.osgi.framework.internal.core.Framework.resumeBundle(Framework.java:1177)
at org.eclipse.osgi.framework.internal.core.StartLevelManager.resumeBundles(StartLevelManager.java:559)
at org.eclipse.osgi.framework.internal.core.StartLevelManager.resumeBundles(StartLevelManager.java:544)
at org.eclipse.osgi.framework.internal.core.StartLevelManager.incFWSL(StartLevelManager.java:457)
at org.eclipse.osgi.framework.internal.core.StartLevelManager.doSetStartLevel(StartLevelManager.java:243)
- locked <0x00000006c0018470> (a java.lang.Object)
at org.eclipse.osgi.framework.internal.core.StartLevelManager.dispatchEvent(StartLevelManager.java:438)
at org.eclipse.osgi.framework.internal.core.StartLevelManager.dispatchEvent(StartLevelManager.java:1)
at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:230)
at org.eclipse.osgi.framework.eventmgr.EventManager$EventThread.run(EventManager.java:340)

"State Data Manager" #15 daemon prio=5 os_prio=31 tid=0x00007fad6983c000 nid=0x5903 waiting on condition [0x0000700006ff8000]
java.lang.Thread.State: TIMED_WAITING (sleeping)

at java.lang.Thread.sleep(Native Method)
at org.eclipse.osgi.internal.baseadaptor.StateManager.run(StateManager.java:297)
at java.lang.Thread.run(Thread.java:748)

"Framework Active Thread" #14 prio=5 os_prio=31 tid=0x00007fad680e2800 nid=0xa803 in Object.wait() [0x0000700006ef5000]
java.lang.Thread.State: TIMED_WAITING (on object monitor)

at java.lang.Object.wait(Native Method)
at org.eclipse.osgi.framework.internal.core.Framework.run(Framework.java:1863)
- locked <0x00000006c000ef48> (a org.eclipse.osgi.framework.internal.core.Framework)
at java.lang.Thread.run(Thread.java:748)

"Service Thread" #12 daemon prio=9 os_prio=31 tid=0x00007fad69808000 nid=0x5503 runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE

"C1 CompilerThread3" #11 daemon prio=9 os_prio=31 tid=0x00007fad66017800 nid=0x3d03 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE

"C2 CompilerThread2" #10 daemon prio=9 os_prio=31 tid=0x00007fad66017000 nid=0x4003 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE

"C2 CompilerThread1" #9 daemon prio=9 os_prio=31 tid=0x00007fad67821800 nid=0x4103 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE

"C2 CompilerThread0" #8 daemon prio=9 os_prio=31 tid=0x00007fad67820800 nid=0x3a03 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE

"JDWP Command Reader" #7 daemon prio=10 os_prio=31 tid=0x00007fad66027800 nid=0x3803 runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE

"JDWP Event Helper Thread" #6 daemon prio=10 os_prio=31 tid=0x00007fad6680f000 nid=0x4203 runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE

"JDWP Transport Listener: dt_socket" #5 daemon prio=10 os_prio=31 tid=0x00007fad66804800 nid=0x4407 runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE

"Signal Dispatcher" #4 daemon prio=9 os_prio=31 tid=0x00007fad66035800 nid=0x4507 runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE

"Finalizer" #3 daemon prio=8 os_prio=31 tid=0x00007fad68065000 nid=0x4c03 in Object.wait() [0x00007000063d4000]
java.lang.Thread.State: WAITING (on object monitor)

at java.lang.Object.wait(Native Method)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:143)
- locked <0x00000006c001d7b8> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:164)
at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:209)

"Reference Handler" #2 daemon prio=10 os_prio=31 tid=0x00007fad68062000 nid=0x4e03 in Object.wait() [0x00007000062d1000]
java.lang.Thread.State: WAITING (on object monitor)

at java.lang.Object.wait(Native Method)
at java.lang.Object.wait(Object.java:502)
at java.lang.ref.Reference.tryHandlePending(Reference.java:191)
- locked <0x00000006c0005fb8> (a java.lang.ref.Reference$Lock)
at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:153)

"main" #1 prio=5 os_prio=31 tid=0x00007fad68001800 nid=0x307 in Object.wait() [0x00007ffee239b000]
java.lang.Thread.State: TIMED_WAITING (on object monitor)

at java.lang.Object.wait(Native Method)
at org.eclipse.core.runtime.internal.adaptor.Semaphore.acquire(Semaphore.java:55)
- locked <0x00000006c0025b08> (a org.eclipse.core.runtime.internal.adaptor.Semaphore)
at org.eclipse.core.runtime.adaptor.EclipseStarter.updateSplash(EclipseStarter.java:1276)
at org.eclipse.core.runtime.adaptor.EclipseStarter.setStartLevel(EclipseStarter.java:1238)
at org.eclipse.core.runtime.adaptor.EclipseStarter.startup(EclipseStarter.java:289)
at org.eclipse.core.runtime.adaptor.EclipseStarter.run(EclipseStarter.java:176)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at org.eclipse.equinox.launcher.Main.invokeFramework(Main.java:656)
at org.eclipse.equinox.launcher.Main.basicRun(Main.java:592)
at org.eclipse.equinox.launcher.Main.run(Main.java:1498)
at org.eclipse.equinox.launcher.Main.main(Main.java:1471)

"VM Thread" os_prio=31 tid=0x00007fad68061800 nid=0x5003 runnable

"GC task thread#0 (ParallelGC)" os_prio=31 tid=0x00007fad6800d800 nid=0x1f07 runnable

"GC task thread#1 (ParallelGC)" os_prio=31 tid=0x00007fad6800e000 nid=0x1b03 runnable

"GC task thread#2 (ParallelGC)" os_prio=31 tid=0x00007fad6800e800 nid=0x1d03 runnable

"GC task thread#3 (ParallelGC)" os_prio=31 tid=0x00007fad6800f800 nid=0x2a03 runnable

"GC task thread#4 (ParallelGC)" os_prio=31 tid=0x00007fad68010000 nid=0x5303 runnable

"GC task thread#5 (ParallelGC)" os_prio=31 tid=0x00007fad68010800 nid=0x2c03 runnable

"GC task thread#6 (ParallelGC)" os_prio=31 tid=0x00007fad68011000 nid=0x5203 runnable

"GC task thread#7 (ParallelGC)" os_prio=31 tid=0x00007fad68012000 nid=0x2f03 runnable

"VM Periodic Task Thread" os_prio=31 tid=0x00007fad67845800 nid=0xa903 waiting on condition

JNI global references: 4275

你期待的结果是什么？实际看到的错误信息又是什么？

希望熟悉的同学指点指点，是否是死锁造成的，如何继续定位？

Answer 1

启动参数加 -Djava.awt.headless=true 试下

Answer 2

没有发生死锁，发生死锁的话，会有明显的提示（Found one Java-level deadlock），看线程的情况，应该卡在了jar加载上面，这个也能解释为什么在不同开发环境现象不同