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

Я знаю почему тормозит ваша Java

B901ed2c8433cd33ebbc1ad2085eea51?s=47 aragozin
September 06, 2017

Я знаю почему тормозит ваша Java

B901ed2c8433cd33ebbc1ad2085eea51?s=128

aragozin

September 06, 2017
Tweet

More Decks by aragozin

Other Decks in Programming

Transcript

  1. Я знаю, почему тормозит ваша Алексей Рагозин alexey.ragozin@gmail.com Java

  2. После месяцев упорного труда с кучей нового функционала оттестированное и

    проверенное ваше приложение в эксплуатации! И всё идёт хорошо, пока …
  3. Пользователи начинают жаловаться на тормоза Логи забиваются ошибками Руководство начитает

    нервничать И тебе нужно срочно всё исправить!
  4. Что может пойти нетак? Server Browser Application Database

  5. Что может пойти нетак? Server Browser Application Database Caching JavaScript

    HTTP Network Network SQL performance CPU Memory / Swapping Disk IO Virtualization
  6. Три правила Правило 1. Формулировка цели  Какова цель оптимизации?

     Как будет измерен результат?  Формулировка должна быть понятна всем сторонам! Бизнес транзакция ≠ Страница Бизнес транзакция ≠ SQL транзакция Страница ≠ HTTP запрос HTTP запрос ≠ SQL транзакция
  7. Три правила Правило 2. Система – Чёрный ящик  Вы

    не можете знать, что происходит внутри системы!  Не важно, кто писал код, и как он выглядит  Нужно опираться на факты, а не на суждения  Любую гипотезу нужно проверять
  8. Три правила Три типа информации, которую даёт профайлер  Ложь

    – неверно истолкованные данные  Откровенная ложь – неверно измеренные результаты  Статистика – данные, которые помогают решить проблему
  9. Три правила Правило 3. “Научный” подход  Перепроверяйте результаты 

    Не оптимизируйте результаты профайлера  Используйте статистику
  10. Дерево анализа Поддерево сервера приложений Server CPU consumption What application

    threads are doing? Low Application CPU consumption High Low Server CPU starvation? High Which threads consume CPU? JVM threads Application threads GC? Profiling CPU hotspots Sleep Wait IO Contention? Who is blocking us? ?
  11. Классы проблем в Java коде Вычислительные (CPU Bound)  Вычислительная

    сложность  “Голодание” нитей (CPU starvation) Многопоточность  Соревнование за ресурсы (contention)  Ожидание выделенного потока  Взаимные блокировки потоков (deadlocks) Память и сборка мусора  Слишком часты сборки мусора  Ненормально большие GC паузы  Частые полные сборки (Full GC)
  12. Профайлеры и Профайлеры Instrumentation built into JVM Java Visual VM

    JVMTI JMX Byte Code Instrumentation
  13. JVisualVM Предварительный осмотр

  14. JProfiler Предварительный осмотр

  15. SJK ttop > java –jar sjk.jar ttop -p 12345 -n

    20 -o CPU 2016-11-07T00:09:50.091+0400 Process summary process cpu=268.35% application cpu=244.42% (user=222.50% sys=21.93%) other: cpu=23.93% GC cpu=6.28% (young=1.62%, old=4.66%) heap allocation rate 1218mb/s safe point rate: 1.5 (events/s) avg. safe point pause: 43.24ms safe point sync time: 0.03% processing time: 6.39% (wallclock time) [000056] user=17.45% sys= 0.62% alloc= 106mb/s - hz._hzInstance_2_dev.generic-operation.thread-0 [000094] user=17.76% sys= 0.31% alloc= 113mb/s - hz._hzInstance_3_dev.generic-operation.thread-1 [000093] user=16.83% sys= 0.00% alloc= 111mb/s - hz._hzInstance_3_dev.generic-operation.thread-0 [000020] user=16.06% sys= 0.15% alloc= 108mb/s - hz._hzInstance_1_dev.generic-operation.thread-0 [000021] user=15.44% sys= 0.15% alloc= 110mb/s - hz._hzInstance_1_dev.generic-operation.thread-1 [000057] user=14.36% sys= 0.00% alloc= 110mb/s - hz._hzInstance_2_dev.generic-operation.thread-1 [000105] user=13.59% sys= 0.00% alloc= 72mb/s - hz._hzInstance_3_dev.cached.thread-1 [000079] user=13.43% sys= 0.15% alloc= 67mb/s - hz._hzInstance_2_dev.cached.thread-3 [000042] user=10.96% sys= 0.62% alloc= 65mb/s - hz._hzInstance_1_dev.cached.thread-2 [000174] user=10.65% sys= 0.31% alloc= 66mb/s - hz._hzInstance_3_dev.cached.thread-7 [000123] user= 8.96% sys= 0.00% alloc= 55mb/s - hz._hzInstance_4_dev.response [000129] user= 7.72% sys= 0.31% alloc= 21mb/s - hz._hzInstance_4_dev.generic-operation.thread-0 [000168] user= 6.95% sys= 0.62% alloc= 33mb/s - hz._hzInstance_1_dev.cached.thread-6 [000178] user= 7.57% sys= 0.00% alloc= 32mb/s - hz._hzInstance_2_dev.cached.thread-9 [000166] user= 6.48% sys= 0.46% alloc= 33mb/s - hz._hzInstance_1_dev.cached.thread-5 [000130] user= 6.02% sys= 0.62% alloc= 20mb/s - hz._hzInstance_4_dev.generic-operation.thread-1 https://github.com/aragozin/jvm-tools Предварительный осмотр
  16. Mission Control Предварительный осмотр

  17. Техники профилирования Сэмплирование Анализ случайной выборки событий  Сэмплирование стеков

    потоков  Сэмплирование аллокации памяти Трассировка Анализ всех событий определённого типа  Трассировка вызовов методов  Трассировка операций определённого класса
  18. Техники профилирования Сэмплирование Анализ случайной выборки событий  Сэмплирование стеков

    потоков  Сэмплирование аллокации памяти Трассировка Анализ всех событий определённого типа  Трассировка вызовов методов  Трассировка операций определённого класса
  19. Сэмплирование потоков Task.run() wait() process() getBody() read() parse() handle() load()

    read() Time encode() wait() process() getBody() read() parse() handle() load() read() encode() wait() process() getBody() read() parse() handle() encode() 10 Task.run 7 3 process() 4 handle() 3 encode() 2 ... 1 ... 1 load() geBody() 2 1 read() parse() 1 3 wait() ...
  20. JVisualVM Анализ результатов сэмплирования

  21. Mission Control Анализ результатов сэмплирования

  22. JProfiler Анализ результатов сэмплирования

  23. flame graph with SJK Анализ результатов сэмплирования https://github.com/aragozin/jvm-tools

  24. JEE world example JBoss + Seam + Hibernate

  25. Анализ результатов сэмплирования Command sjk ssa -f tracedump.std --categorize -tf

    **.CoyoteAdapter.service -nc JDBC=**.jdbc Hibernate=org.hibernate "Facelets compile=com.sun.faces.facelets.compiler.Compiler.compile" "Seam bijection=org.jboss.seam.**.aroundInvoke/!**.proceed" JSF.execute=com.sun.faces.lifecycle.LifecycleImpl.execute JSF.render=com.sun.faces.lifecycle.LifecycleImpl.render Other=** Report Total samples 2732050 100.00% JDBC 405439 14.84% Hibernate 802932 29.39% Facelets compile 395784 14.49% Seam bijection 385491 14.11% JSF.execute 290355 10.63% JSF.render 297868 10.90% Other 154181 5.64% 0.00% 10.00% 20.00% 30.00% 40.00% 50.00% 60.00% 70.00% 80.00% 90.00% 100.00% Time Other JSF.render JSF.execute Seam bijection Facelets compile Hibernate JDBC Excel Категоризация по шаблонам
  26. Ограничения сэмплирования Сильные стороны  Малые накладные расходы  Не

    нужна конфигурация  Позволяет обнаружить  Данные сравнимы между запусками и версиями кода Недостатки  Ограниченная точность измерений  Нельзя оценить реальное время вызова/операции  Детализация ограничена структурой кода
  27. Инструментация и трассировка Инструментация  Профайлер меняет выполняемый код приложения

    налету  Существенные накладные расходы  Параметры вызова могут быть включены в трассировку Трассировка методов  Время и число вызовов метода  Временная линия выполнения кода
  28. https://github.com/chewiebug/GCViewer GC Viewer Динамика сборки мусора

  29. -XX:InitialTenuringThreshold=8 Initial value for tenuring threshold (number of collections before

    object will be promoted to old space) -XX:+UseTLAB Use thread local allocation blocks in eden -XX:MaxTenuringThreshold=15 Max value for tenuring threshold -XX:PretenureSizeThreshold=2m Max object size allowed to be allocated in young space (large objects will be allocated directly in old space). Thread local allocation bypasses this check, so if TLAB is large enough object exciding size threshold still may be allocated in young space. -XX:+AlwaysTenure Promote all objects surviving young collection immediately to tenured space (equivalent of -XX:MaxTenuringThreshold=0) -XX:+NeverTenure Objects from young space will never get promoted to tenured space unless survivor space is not enough to keep them -XX:+ResizeTLAB Let JVM resize TLABs per thread -XX:TLABSize=1m Initial size of thread’s TLAB -XX:MinTLABSize=64k Min size of TLAB -XX:+UseCMSInitiatingOccupancyOnly Only use predefined occupancy as only criterion for starting a CMS collection (disable adaptive behaviour) -XX:CMSInitiatingOccupancyFraction=70 Percentage CMS generation occupancy to start a CMS cycle. A negative value means that CMSTriggerRatio is used. -XX:CMSBootstrapOccupancy=50 Percentage CMS generation occupancy at which to initiate CMS collection for bootstrapping collection stats. -XX:CMSTriggerRatio=70 Percentage of MinHeapFreeRatio in CMS generation that is allocated before a CMS collection cycle commences. -XX:CMSWaitDuration=30000 Once CMS collection is triggered, it will wait for next young collection to perform initial mark right after. This parameter specifies how long CMS can wait for young collection -XX:+CMSScavengeBeforeRemark Force young collection before remark phase -XX:+CMSScheduleRemarkEdenSizeThreshold If Eden used is below this value, don't try to schedule remark -XX:CMSScheduleRemarkEdenPenetration=20 Eden occupancy % at which to try and schedule remark pause -XX:CMSScheduleRemarkSamplingRatio=4 Start sampling Eden top at least before young generation occupancy reaches 1/ of the size at which we plan to schedule remark -XX:+CMSIncrementalMode Enable incremental CMS mode. Incremental mode was meant for severs with small number of CPU, but may be used on multicore servers to benefit from more conservative initiation strategy. -XX:+CMSClassUnloadingEnabled If not enabled, CMS will not clean permanent space. You may need to enable it for containers such as JEE or OSGi. -XX:ConcGCThreads=2 Number of parallel threads used for concurrent phase. -XX:ParallelGCThreads=16 Number of parallel threads used for stop-the-world phases. -XX:+DisableExplicitGC JVM will ignore application calls to System.gc() -XX:+ExplicitGCInvokesConcurrent Let System.gc() trigger concurrent collection instead of full GC -XX:+ExplicitGCInvokesConcurrentAndUnloadsClasses Same as above but also triggers permanent space collection. -XX:PrintCMSStatistics=1 Print additional CMS statistics. Very verbose if n=2. -XX:+PrintCMSInitiationStatistics Print CMS initiation details -XX:+CMSDumpAtPromotionFailure Dump useful information about the state of the CMS old generation upon a promotion failure -XX:+CMSPrintChunksInDump (with optin above) Add more detailed information about the free chunks -XX:+CMSPrintObjectsInDump (with optin above) Add more detailed information about the allocated objects by Alexey Ragozin – http://blog.ragozin.info HotSpot JVM options cheatsheet Young space tenuring Thread local allocation Parallel processing -XX:+CMSOldPLABMin=16 -XX:+CMSOldPLABMax=1024 Min and max size of CMS gen PLAB caches per worker per block size CMS initiating options CMS Stop-the-World pauses tuning Misc CMS options CMS Diagnostic options - Options for “deterministic” CMS, they disable some heuristics and require careful validation Concurrent Mark Sweep (CMS) All concrete numbers in JVM options in this card are for illustrational purposes only! -XX:+ParallelRefProcEnabled Enable parallel processing of references during GC pause -XX:SoftRefLRUPolicyMSPerMB=1000 Factor for calculating soft reference TTL based on free heap size -XX:OnOutOfMemoryError=… Command to be executed in case of out of memory. E.g. “kill -9 %p” on Unix or “taskkill /F /PID %p” on Windows. -XX:G1HeapRegionSize=32m Size of heap region -XX:MaxGCPauseMillis=500 Target GC pause duration. G1 is not deterministic, so no guaranties for GC pause to satisfy this limit. -XX:G1ReservePercent=10 Percentage of heap to keep free. Reserved memory is used as last resort to avoid promotion failure. -XX:G1ConfidencePercent=50 Confidence level for MMU/pause prediction -XX:G1HeapWastePercent=10 If garbage level is below threshold, G1 will not attempt to reclaim memory further -XX:G1MixedGCCountTarget=8 Target number of mixed collections after a marking cycle -XX:InitiatingHeapOccupancyPercent=45 Percentage of (entire) heap occupancy to trigger concurrent GC Garbage First (G1) -XX:+CMSParallelRemarkEnabled Whether parallel remark is enabled (enabled by default) -XX:+CMSParallelSurvivorRemarkEnabled Whether parallel remark of survivor space enabled, effective only with option above (enabled by default) -XX:+CMSConcurrentMTEnabled Use multiple threads for concurrent phases. CMS Concurrency options -XX:+CMSParallelInitialMarkEnabled Whether parallel initial mark is enabled (enabled by default) -XX:CMSTriggerInterval=60000 Periodically triggers_ CMS collection. Useful for deterministic object finalization. http://blog.ragozin.info/2016/10/hotspot-jvm-garbage-collection-options.html Young collector Old collectior JVM Flags Serial (DefNew) Parallel scavenge (PSYoungGen) Parallel scavenge (PSYoungGen) Parallel (ParNew) Serial (DefNew) Parallel (ParNew) Serial Mark Sweep Compact Serial Mark Sweep Compact (PSOldGen) Parallel Mark Sweep Compact (ParOldGen) Concurrent Mark Sweep Concurrent Mark Sweep Serial Mark Sweep Compact -XX:+UseSerialGC -XX:+UseParallelGC -XX:+UseParallelOldGC -XX:+UseParNewGC -XX:-UseParNewGC1 -XX:+UseConcMarkSweepGC -XX:+UseParNewGC -XX:+UseConcMarkSweepGC -XX:+UseG1GC Garbage First (G1) 1 - Notice minus before UseParNewGC, which is explicitly disables parallel mode -verbose:gc or -XX:+PrintGC Print basic GC info -XX:+PrintGCDetails Print more details GC info -XX:+PrintGCTimeStamps Print timestamps for each GC event (seconds count from start of JVM) -XX:+PrintGCDateStamps Print date stamps at garbage collection events: 2011-09-08T14:20:29.557+0400: [GC... -Xloggc:<file> Redirects GC output to a file instead of console -XX:+PrintTLAB Print TLAB allocation statistics -XX:+PrintReferenceGC Print times for special (weak, JNI, etc) reference processing during STW pause -XX:+PrintJNIGCStalls Reports if GC is waiting for native code to unpin object in memory -XX:+PrintClassHistogramAfterFullGC Prints class histogram after full GC -XX:+PrintClassHistogramBeforeFullGC Prints class histogram before full GC -XX:+UseGCLogFileRotation Enable GC log rotation -XX:GCLogFileSize=512m Size threshold for GC log file -XX:NumberOfGCLogFiles=5 Number GC log files -XX:+PrintGCCause Add cause of GC in log -XX:+PrintHeapAtGC Print heap details on GC -XX:+PrintAdaptiveSizePolicy Print young space sizing decisions -XX:+PrintHeapAtSIGBREAK Print heap details on signal -XX:+PrintPromotionFailure Print additional information for promotion failure -XX:+PrintPLAB Print survivor PLAB details -XX:+PrintOldPLAB Print old space PLAB details -XX:+PrintGCTaskTimeStamps Print timestamps for individual GC worker thread tasks (very verbose) -XX:+PrintGCApplicationStoppedTime Print summary after each JVM safepoint (including non-GC) -XX:+PrintGCApplicationConcurrentTime Print time for each concurrent phase of GC GC Log rotation More logging options -XX:+PrintTenuringDistribution Print detailed demography of young space after each collection GC log detail options -Xms256m or -XX:InitialHeapSize=256m Initial size of JVM heap (young + old) -Xmx2g or -XX:MaxHeapSize=2g Max size of JVM heap (young + old) -XX:NewSize=64m -XX:MaxNewSize=64m Absolute (initial and max) size of young space (Eden + 2 Survivours) -XX:NewRatio=3 Alternative way to specify size of young space. Sets ratio of young vs old space (e.g. -XX:NewRatio=2 means that young space will be 2 time smaller than old space, i.e. 1/3 of heap size). -XX:SurvivorRatio=15 Sets size of single survivor space relative to Eden space size (e.g. -XX:NewSize=64m -XX:SurvivorRatio=6 means that each Survivor space will be 8m and Eden will be 48m). -XX:MetaspaceSize=512m -XX:MaxMetaspaceSize=1g Initial and max size of JVM’s metaspace space -Xss256k (size in bytes) or -XX:ThreadStackSize=256 (size in Kbytes) Thread stack size -XX:MaxDirectMemorySize=2g Maximum amount of memory available for NIO off-heap byte buffers - Highly recommended option Memory sizing options by Alexey Ragozin – http://blog.ragozin.info Available combinations of garbage collection algorithms in HotSpot JVM - Highly recommended option HotSpot JVM options cheatsheet All concrete numbers in JVM options in this card are for illustrational purposes only! Java Process Memory JVM Memory Java Heap Non-JVM Memory (native libraries) Non-Heap Young Gen Old Gen Eden Survivor 0 Survivor 1 Thread Stacks Metaspace Compressed Class Space Code Cache NIO Direct Buffers Other JVM Memmory -Xms/-Xmx -XX:CompressedClassSpaceSize=1g Memory reserved for compressed class space (64bit only) -XX:InitialCodeCacheSize=256m -XX:ReservedCodeCacheSize=512m Initial size and max size of code cache area Настройка сборка мусора
  30. Динамика сборки мусора Mission Control

  31. Mission Control Сэмплирование аллокации памяти

  32. Flight Recorder Vs. Visual VM Method sampling Method tracing 

    Generic  IO Allocation sampling Heap dump inspection Startup profiling Continuous profiling Flight Recorder Only Java code Low overhead No Built-in events Low overhead No Yes May require license Visual VM On Safepoints High overhead Yes - High overhead Yes No No Java Visual VM
  33. Заключение  Профайлер не скажет вам, где проблема  Три

    правила  JVisual VM и Mission Control – эффективные инструменты при правильном использовании  Сохраняйте спокойствие!
  34. KEEP CALM AND MAKE YOUR JAVA FAST AGAIN Алексей Рагозин

    alexey.ragozin@gmai.com http://blog.ragozin.info