Upgrade to Pro — share decks privately, control downloads, hide ads and more …

Threads, Needles, Stacks, Heaps

Threads, Needles, Stacks, Heaps

Troubleshooting Java applications has the reputation of a dark art and is often compared to finding the needle in a haystack. Using tools bundled with the JDK and the OS, a few open source packages and lightweight approaches can help you zero in on a some common scenarios. We will explore working with local and remote JVMs, the myriad of startup flags, analyzing and correlating thread dumps with cpu consumption, system vs application level instrumentation, getting around in an unfamiliar production environment and if we don’t forget, memory games.
If you could use more visibility into your Java application during development and production runs this talk is filled with practical tips, from the high level to the gritty details.

Ovidiu Dimulescu

February 25, 2014

More Decks by Ovidiu Dimulescu

Other Decks in Programming


  1. ! ! ! Threads, Needles, Stacks, Heaps DevNexus, 2014 Ovidiu

    Dimulescu ! @odimulescu www.odimulescu.com
  2. The opinions and views expressed in this talk are my

    own, and do not necessarily reflect the opinions or views of my employer.
  3. • Oracle HotSpot • OpenJDK HotSpot • Oracle JRockit *

    • IBM JVM • Azul Systems Zing JVM * • Waratek CloudVM * Landscape - JVMs
  4. • Why is the application slow? • Why does the

    application have hiccups? • Why is CPU pegged? • Why are we running out of memory? • … • Why _______ ? Landscape - Pain points
  5. #### Measure Anything, Measure Everything ! “ If Engineering at

    Etsy has a religion, it’s the Church of Graphs. If it moves, we track it …” http://codeascraft.com/2011/02/15/measure-anything-measure-everything/
  6. • Complex apps architecture and environments • Insufficient historical data

    • Weak inter-systems correlation • Platforms disparity • No one size fits all • Folklore, outdated information • High barrier to entry for effective diagnostics Landscape - Challenges
  7. • Profiling, debugging, monitoring, thread analysis, coverage analysis, etc. !

    • Native Agents - Full » -agentlib:<agent-lib-name>=<options> » -agentpath:<path-to-agent>=<options> » hprof, jdwp agents included JVM TI - JVM Tool Interface
  8. • Profiling, debugging, monitoring, thread analysis, coverage analysis, etc. !

    • Native Agents - Full » -agentlib:<agent-lib-name>=<options> » -agentpath:<path-to-agent>=<options> » hprof, jdwp agents included ! • Java Agents - Instrumentation only (java.lang.instrument.*) » -javaagent:agent-name.jar » multiple supported, management-agent.jar provided JVM TI - JVM Tool Interface
  9. JVM TI - JVM Tool Interface TI Agent I JVM

    TI Agent II event action event action TI Client Attach API load agent
  10. JMX - Java Management Extensions MBeanServer Standard MBeans Dynamic MBeans

    MXBeans Connector Connector Adaptor Adaptor Probes Agent Clients Remote Management JMX Console Custom Console RMI HTTP Browser HTTP SNMP SNMP J V M
  11. JMX - Java Management Extensions MBeanServer Standard MBeans Dynamic MBeans

    MXBeans Connector Connector Adaptor Adaptor Probes Agent Clients Remote Management JMX Console Custom Console RMI HTTP Browser HTTP SNMP SNMP J V M
  12. JMX - Java Management Extensions Explicit ! -Dcom.sun.management.jmxremote -Dcom.sun.management.jmxremote.authenticate=false -Dcom.sun.management.jmxremote.port=1234

    -Dcom.sun.management.jmxremote.ssl=false -Dcom.sun.management.jmxremote.password.file=/path/to/pw/file -Dcom.sun.management.jmxremote.access.file=/path/to/access/file -Djava.rmi.server.hostname=<resolvable_from_clients> ! Attach API ! Unless -XX:+DisableAttachMechanism
  13. JMX - Java Management Extensions • De facto standard •

    Wide support • RMI not firewall friendly, dynamic ports • RMI connector heavy, Observer effect • MBeans need to behave
  14. • jcmd (JDK 7+) • jinfo • jhat • jmap

    • jps • jstat / jstatd • jstack HotSpot - Command Line Tools http://docs.oracle.com/javase/7/docs/webnotes/tsg/TSG-VM/html/tooldescr.html
  15. Heap Analysers ! » MAT » Heapster » HeapAudit Open

    Source Tools GC Visualization ! » VisualVM » GCViewer » GCHisto » gcviz JMX Clients ! » MC5J » VisualVM » jmxterm » CRaSH Code Libraries * ! » Coda Hale Metrics » Javalution » Trove » FastUtil
  16. -X are non-standard, not guaranteed to be supported on all

    VM implementations, and are subject to change without notice in subsequent releases of the JDK. ! $ java -X … -Xloggc:<file> log GC status to a file with time stamps -Xms<size> set initial Java heap size -Xmx<size> set maximum Java heap size -Xss<size> set java thread stack size -Xprof output cpu profiling data … Flags
  17. -XX are not stable and are subject to change without

    notice ! Boolean -XX:+<option> or -XX:-<option> ! Numeric -XX:<option>=<number>[unit] Unit: ‘k’, ‘K’, ‘m’, ‘M’, ‘g’, ‘G’ - 32768 or 32k ! String -XX:<option>=<string> Flags
  18. $ java -XX:+PrintFlagsInitial -version $ java -XX:+PrintFlagsFinal -version $ java

    -XX:+PrintCommandLineFlags -version ! • product - An officially supported, internal JVM option • rw - Dynamically writable • C1 - Client JIT Compiler • C2 - Server JIT Compiler • pd - Platform Dependent • lp64 - 64bit VM only • manageable - Externally defined and dynamically writable • diagnostic - VM debugging • experimental - Not officially supported ! -XX:+UnlockExperimentalVMOptions -XX:+UnlockDiagnosticVMOptions Flags
  19. • ms • mx • PermSize • MaxPermSize • NewSize

    • MaxNewSize • NewRatio • UseCompressedOps • HeapDumpOnOutOfMemoryError • HeapDumpPath Flags - Memory
  20. Flags - GC Logging • verbose:gc • loggc • PrintGCDetails

    • PrintGCTimeStamps • PrintGCDateStamps • UseGCLogFileRotation • NumberOfGCLogFiles=10 • GCLogFileSize=50M • PrintTenuringDistribution • PrintGCApplicationStoppedTime
  21. Flags - GC • verbose:class • TraceClassLoading • TraceClassUnloading •

    TraceClassResolution • UseParallelGC • UseParallelOldGC • UseParNewGC • UseConcMarkSweepGC • GCTimeLimit • GCHeapFreeLimit
  22. Threads Type Regular Daemon Name Automatic Custom * Parent Group

    Not Null* Priority MIN - NORM - MAX State Thread.State
  23. Thread Dump $ jstack <pid> $ jcmd <pid> Thread.print (JDK

    7+) ! Output to terminal ! $ kill -3 <pid> or kill -SIGQUIT <pid> ! Outputs to JVM’s stdout ! JMX ! VisualVM, JConsole, etc.
  24. Thread Dump » Dump identifier ! 2014-02-15 15:05:42 Full thread

    dump Java HotSpot(TM) 64-Bit Server VM (24.45-b08 mixed mode)
  25. Thread Dump "main" prio=5 tid=0x0000000101028800 nid=0x507 runnable [0x00007fff5fbfd000] java.lang.Thread.State: RUNNABLE

    at org.eclipse.swt.internal.cocoa.OS.objc_msgSend_bool(Native Method) at org.eclipse.swt.internal.cocoa.NSRunLoop.runMode(NSRunLoop.java:42) at org.eclipse.swt.widgets.Display.sleep(Display.java:4565) at org.eclipse.ui.application.WorkbenchAdvisor.eventLoopIdle(WorkbenchAdvisor.java:364) at org.eclipse.ui.internal.ide.application.IDEWorkbenchAdvisor.eventLoopIdle(IDEWorkbenchAdvisor.java:917) at org.eclipse.ui.internal.Workbench$3.eventLoopIdle(Workbench.java:459) at org.eclipse.e4.ui.internal.workbench.swt.PartRenderingEngine$9.run(PartRenderingEngine.java:1026) at org.eclipse.core.databinding.observable.Realm.runWithDefault(Realm.java:332) at org.eclipse.e4.ui.internal.workbench.swt.PartRenderingEngine.run(PartRenderingEngine.java:916) at org.eclipse.e4.ui.internal.workbench.E4Workbench.createAndRunUI(E4Workbench.java:86) at org.eclipse.ui.internal.Workbench$5.run(Workbench.java:585) at org.eclipse.core.databinding.observable.Realm.runWithDefault(Realm.java:332) at org.eclipse.ui.internal.Workbench.createAndRunWorkbench(Workbench.java:540) at org.eclipse.ui.PlatformUI.createAndRunWorkbench(PlatformUI.java:149) at org.eclipse.ui.internal.ide.application.IDEApplication.start(IDEApplication.java:124) at org.eclipse.equinox.internal.app.EclipseAppHandle.run(EclipseAppHandle.java:196) at org.eclipse.core.runtime.internal.adaptor.EclipseAppLauncher.runApplication(EclipseAppLauncher.java:110) at org.eclipse.core.runtime.internal.adaptor.EclipseAppLauncher.start(EclipseAppLauncher.java:79) at org.eclipse.core.runtime.adaptor.EclipseStarter.run(EclipseStarter.java:353) at org.eclipse.core.runtime.adaptor.EclipseStarter.run(EclipseStarter.java:180) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:606) at org.eclipse.equinox.launcher.Main.invokeFramework(Main.java:629) at org.eclipse.equinox.launcher.Main.basicRun(Main.java:584) at org.eclipse.equinox.launcher.Main.run(Main.java:1438)
  26. Thread Dump "C2 CompilerThread1" daemon prio=5 tid=0x0033 nid=0x6703 waiting on

    condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE ! "C2 CompilerThread0" daemon prio=5 tid=0x0011 nid=0x6503 waiting on condition [0x0000000000] java.lang.Thread.State: RUNNABLE ! "Signal Dispatcher" daemon prio=5 tid=0x0022 nid=0x6303 runnable [0x0000000000000000] java.lang.Thread.State: RUNNABLE ! "Finalizer" daemon prio=5 tid=0x0044 nid=0x5f03 in Object.wait() [0x000000010b88b000] java.lang.Thread.State: WAITING (on object monitor) ! "Reference Handler" daemon prio=5 tid=0x0055 nid=0x5d03 in Object.wait() [0x000000010b788000] java.lang.Thread.State: WAITING (on object monitor) ! "VM Thread" prio=5 tid=0x0066 nid=0x5b03 runnable ! "GC task thread#0 (ParallelGC)" prio=5 tid=0x000000010102d000 nid=0x5303 runnable ! "GC task thread#1 (ParallelGC)" prio=5 tid=0x0000000101038800 nid=0x5503 runnable ! "GC task thread#2 (ParallelGC)" prio=5 tid=0x0000000101039000 nid=0x5703 runnable ! "GC task thread#3 (ParallelGC)" prio=5 tid=0x0000000101039800 nid=0x5903 runnable ! "VM Periodic Task Thread" prio=5 tid=0x0000000101058000 nid=0x6b03 waiting on condition In general the VM thread is in one of three states: waiting to execute a VM operation, synchronizing all threads in preparation for a VM operation, or executing a VM operation. If you suspect that a hang is a HotSpot VM bug rather than an application or class library deadlock, then pay special attention to the VM thread.
  27. Thread Dump » Dump identifier ! » Application Threads !

    » VM Threads ! » JNI References Count ! JNI global references: 759
  28. Thread Dump » Dump identifier ! » Application Threads !

    » VM Threads ! » JNI References Count ! » Heap Utilization Summary *
  29. Thread Dump PSYoungGen total 75776K, used 69708K [0x07f55, 0x07fb48, 0x08)

    eden space 75264K, 92% used [0x07f550,0x07f98fb028,0x07f9e8) from space 512K, 18% used [0x07fa18,0x07fa1980,0x07fa20) to space 11264K, 0% used [0x07fa98,0x07fa98,0x07fb48) ! ParOldGen total 59392K, used 46432K [0x07e0, 0x07e3a0, 0x07f550) object space 59392K, 78% used [0x07e0,0x07e2d58270,0x07e3a0) ! PSPermGen total 71680K, used 47149K [0x07d0, 0x07d460, 0x07e0) object space 71680K, 65% used [0x07d0,0x07d2e0b6c8,0x07d460)
  30. Thread Dump “Thread I" prio=5 tid=0x0100 nid=0x1ef runnable [0x01acff] java.lang.Thread.State:

    RUNNABLE ! “Thread 3" prio=5 tid=0x0300 nid=0x3dd in Object.wait() [0x0366] java.lang.Thread.State: TIMED_WAITING (on object monitor) ! “Thread 4" prio=5 tid=0x0400 nid=0x4ab in Object.wait() [0x0477] java.lang.Thread.State: WAITING (on object monitor) ! “Thread 5" prio=5 tid=0x0500 nid=0x5bd waiting for monitor entry [0x0523] java.lang.Thread.State: BLOCKED (on object monitor) ! “Thread 2" prio=5 tid=0x0200 nid=0x2ef waiting on condition [0x02b8] java.lang.Thread.State: TIMED_WAITING (sleeping) ! “Thread 6" prio=5 tid=0x0600 nid=0x6ef waiting on condition [0x06b8] java.lang.Thread.State: TIMED_WAITING (sleeping)
  31. • Java heap space • PermGen space • GC overhead

    limit exceeded • unable to create new native thread OOEM - Flavors
  32. • Java heap space • PermGen space • GC overhead

    limit exceeded • unable to create new native thread • Requested array size exceeds VM limit • request <size> bytes for <reason>. Out of swap space? • <reason> <stack trace> (Native method) • Direct buffer memory OOEM - Flavors
  33. • Sizing » Heap Areas (Eden, Old, PermGen, etc.) »

    Tenuring Threshold » Thread Stack ! • Collectors choice » Type (Parallel, ParallelOld, CMS, G1) » Options (# of threads, etc.) OOEM - JVM Configuration
  34. • Containers » Classloaders leaks ! • Frameworks » Reflection

    » Dynamic proxies OOEM - Application Runtime
  35. • Objects structure overhead ! • Collections waste » Fill

    ratio consideration » Never shrink » Up to 2 x expansion algorithms ! • Use of Finalizers, 2 x GC cycles OOEM - Application
  36. • JVM Fundamentals • Tools of the trade • Instrument

    the app • Telemetry • Culture Summary
  37. http://www.kdgregory.com/index.php?page=java.outOfMemory http://www.infoq.com/articles/Java_Garbage_Collection_Distilled http://java-is-the-new-c.blogspot.com/2013/07/tuning-and-benchmarking-java-7s-garbage.html http://blog.ragozin.info/2012/10/safepoints-in-hotspot-jvm.html https://code.google.com/p/java-allocation-instrumenter/ https://weblogs.java.net/blog/kcpeppe/archive/2013/12/11/case-study-jvm-hotspot-flags http://resources.ej-technologies.com/jprofiler/help/doc/indexRedirect.html?http&&&resources.ej-technologies.com/jprofiler/help/doc/helptopics/config/ background.html http://openjdk.java.net/groups/hotspot/docs/RuntimeOverview.html http://docs.oracle.com/javase/7/docs/platform/jvmti/jvmti.html

    http://docs.oracle.com/javase/7/docs/webnotes/tsg/TSG-VM/html/toc.html http://docs.oracle.com/javase/7/docs/technotes/guides/rmi/faq.html http://olegz.wordpress.com/2009/03/23/jmx-connectivity-through-the-firewall/ http://www.uml-diagrams.org/examples/java-6-thread-state-machine-diagram-example.html http://www.javacodegeeks.com/2012/03/jvm-how-to-analyze-thread-dump.html http://www.javabeat.net/introduction-to-java-agents/ https://blog.heroku.com/archives/2013/12/3/end_monolithic_app http://openjdk.java.net/jeps/137 http://docs.oracle.com/javase/7/docs/technotes/guides/jfr/toc.html http://www.youtube.com/playlist?list=PLKCk3OyNwIzsEVDq6zErLW7HSkY7aqdeT Resources